Bug 465357

Summary: Dolphin's UI freezes when stat() is slow
Product: [Applications] dolphin Reporter: Andrew Gunnerson <accounts+kde>
Component: generalAssignee: Dolphin Bug Assignee <dolphin-bugs-null>
Status: RESOLVED FIXED    
Severity: normal CC: davispuh, kde, kfm-devel, miranda, nate, rare_energy
Priority: NOR    
Version: 22.12.2   
Target Milestone: ---   
Platform: Other   
OS: Linux   
Latest Commit: Version Fixed In: 23.04
Sentry Crash Report:
Attachments: A patch to skip directory counts when KFileItem::isSlow
A tiny library to intentionally slow down stat() for testing

Description Andrew Gunnerson 2023-02-06 03:51:20 UTC
Created attachment 155992 [details]
A patch to skip directory counts when KFileItem::isSlow

SUMMARY

When stat() does not complete quickly, Dolphin's UI freezes until it returns.

This seems to be the root cause for the freezes I'm encountering. Specifically, when I try to access a `cifs` mount point, Dolphin kicks off `KDirectoryContentsCounter.scanDirectory()` for all the subdirectories visible on screen. The opendir/readdir calls are enough to slow down the server to the point where each stat takes a couple of seconds. Once stat starts slowing down, the Dolphin's UI stops responding.

I've been working around the problem by making Dolphin skip `KDirectoryContentsCounter.scanDirectory()` if `KFileItem::isSlow()` is true (patch attached). Even though this hides the issue, I wonder if it may be good to have anyway since it matches the behavior of kio smb://, where directory counts don't happen.

STEPS TO REPRODUCE

To avoid the need to connect to a slow server, I've attached an LD_PRELOAD'able library to help reproduce this. It slows down all stat calls to paths under /home/, except for paths containing "/." so that Dolphin's startup isn't slowed down when reading configs.

1. $ g++ -shared -fPIC slow_stat.cpp -o slow_stat.so
2. $ LD_PRELOAD=$(pwd)/slow_stat.so dolphin
3. Navigate to somewhere under /home/
4. Try to perform UI actions, like hovering over items, selecting, right clicking, opening menus, etc.

OBSERVED RESULT

Dolphin's UI freezes until stat returns

EXPECTED RESULT

Dolphin should ideally remain responsive while stat occurs

SOFTWARE/OS VERSIONS

Windows: n/a
macOS: n/a
Linux/KDE Plasma: Fedora 37
KDE Plasma Version: 5.26.5
KDE Frameworks Version: 5.102.0
Qt Version: 5.15.8

ADDITIONAL INFORMATION

(Patch for my workaround is attached)

I've also tried compiling the latest commit in dolphin (580f3bf0d5c8735cf230208fd6e4b288a3e55722) and there's no change in behavior.
Comment 1 Andrew Gunnerson 2023-02-06 03:51:57 UTC
Created attachment 155993 [details]
A tiny library to intentionally slow down stat() for testing
Comment 2 Nate Graham 2023-02-07 18:16:54 UTC
> Specifically, when I try to access a `cifs` mount point
For just this reason, it's not recommended to manually mount network shares. Is there a reason why you have to do this, and accessing the share from its network URL when needed doesn't work for you?

Regardless, skipping directory counts for known slow paths would probably help indeed. Can you please submit it at https://invent.kde.org/system/dolphin/-/merge_requests?
Comment 3 Andrew Gunnerson 2023-02-07 20:19:42 UTC
(In reply to Nate Graham from comment #2)
> > Specifically, when I try to access a `cifs` mount point
> For just this reason, it's not recommended to manually mount network shares.
> Is there a reason why you have to do this, and accessing the share from its
> network URL when needed doesn't work for you?

Yeah, unfortunately, kio smb:// isn't quite fast enough for my (admittedly unusual) use case. I'm connecting to a very high bandwidth server and frequently access files both from GUI apps and the CLI. With kernel cifs mounts, I get around ~3 GiB/s sequential reads/writes, and Dolphin + smb:// only hits around ~500 MiB/s and kio-fuse around ~80 MiB/s.

> Regardless, skipping directory counts for known slow paths would probably
> help indeed. Can you please submit it at
> https://invent.kde.org/system/dolphin/-/merge_requests?

Sure thing!
Comment 4 Nate Graham 2023-02-07 20:23:04 UTC
In addition, bug reports about the poor throughput would be appreciated. It's not acceptable for KDE code to be so slow!
Comment 5 Andrew Gunnerson 2023-02-08 02:42:00 UTC
I submitted an MR for skipping directory counts when KFileItem::isSlow() here: https://invent.kde.org/system/dolphin/-/merge_requests/507

---

Regarding the slow stat() calls blocking the UI, I did some further investigation. The stat() calls are coming from KIO::WorkerThread threads, not the UI thread. The stack trace looks something like this:

    Thread 14 (Thread 0x7fffbd7fa6c0 (LWP 255122) "KIO::WorkerThre"):
    #0  stat (pathname=0x7fff9c00abe8 "/home/chenxiaolong", statbuf=0x7fffbd7f9780) at slow_stat.cpp:35
    #1  0x00007ffff6f16646 in acl_get_file (path_p=0x7fff9c00abe8 "/home/chenxiaolong", type=16384) at libacl/acl_get_file.c:73
    #2  0x00007fffd80be93e in createUDSEntry(QString const&, QByteArray const&, KIO::UDSEntry&, QFlags<KIO::StatDetail>, QString const&) [clone .lto_priv.0] () from /usr/lib64/qt5/plugins/kf5/kio/kio_file.so
    #3  0x00007fffd80c64c6 in FileProtocol::stat(QUrl const&) () from /usr/lib64/qt5/plugins/kf5/kio/kio_file.so
    #4  0x00007ffff790ff15 in KIO::SlaveBase::dispatch(int, QByteArray const&) () from /lib64/libKF5KIOCore.so.5
    #5  0x00007ffff790869e in KIO::SlaveBase::dispatchLoop() () from /lib64/libKF5KIOCore.so.5
    #6  0x00007ffff7983553 in KIO::WorkerThread::run() () from /lib64/libKF5KIOCore.so.5
    #7  0x00007ffff5ae8507 in QThreadPrivate::start (arg=0x555555683ff0) at thread/qthread_unix.cpp:330
    #8  0x00007ffff54ae12d in start_thread (arg=<optimized out>) at pthread_create.c:442
    #9  0x00007ffff552fbc0 in clone3 () at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:81

Since the UI is freezing despite the slow stat calls being on another thread, I'm assuming there's a StatJob::exec()/KJob::exec() call somewhere forcing the UI to wait for its completion. Unfortunately, I've had no luck at all tracking down where the job came from.
Comment 6 Dāvis 2023-02-08 02:56:38 UTC
By the way it's not even that unusual use case. I have both NFS and Samba mounts in `/etc/fstab` aswell. Several reasons :P And I have been doing this for like 10 years or so :D

And KDE/Dolphin issue is not really about that but that it does IO in the main thread which should never be done there. Even if you try KDE on slow HDD you can see it clearly how laggy and slow everything is.

The correct way to handle this would be to move all IO to different thread and make everything async.

But that would be pretty significant change and I actually have been working on solving some parts of this. I hope to submit my patches in coming months. Specifically I'm implementing multi-threaded file metadata loading and some refactorings regarding that. Also this will require changes across few framework libraries.

Basically I have 24-core CPU with 32 GB RAM so KDE/Dolphin should take full advantage of that. Currently for some things we're basically limited to 1 thread on Dolphin.

If you take look at this publication https://www.researchgate.net/figure/NVMe-SSD-multithread-reading-throughput-for-4-kilobytes-blocks-and-up-to-256-threads_fig28_349520331
you can see that even on fast NVME drives if you add more threads you get more performance. For Dolphin this doesn't really matter since it's not really doing any serious IO work but it shows why using more than 1 thread can be worth it.
Comment 7 Dāvis 2023-02-08 03:33:43 UTC
(In reply to Andrew Gunnerson from comment #5)
[...]
> Since the UI is freezing despite the slow stat calls being on another
> thread, I'm assuming there's a StatJob::exec()/KJob::exec() call somewhere
> forcing the UI to wait for its completion. Unfortunately, I've had no luck
> at all tracking down where the job came from.

There are bunch of places that does IO. Eg. see https://invent.kde.org/system/dolphin/-/blob/master/src/kitemviews/kfileitemmodelrolesupdater.cpp#L1283 (`isDir()`) and https://invent.kde.org/system/dolphin/-/blob/master/src/kitemviews/kfileitemmodelrolesupdater.cpp#L837 (specifically `KFileMetaData::UserMetaData` there inside `KBalooRolesProvider::roleValues`)

Things that are related to `KBalooRolesProvider` and `KFileMetaData` I'll be fixing with my multi-threaded implementation. Basically moving whole `KBalooRolesProvider` to a threadpool. Another refactoring I'm doing is that I'm removing it from Dolphin because we actually have 2 different implementations for this thing...
Comment 8 Andrew Gunnerson 2023-02-08 04:19:32 UTC
Thanks for the info, Dāvis! Looking forward to the upcoming changes :)

I'm quite new to the KIO and Dolphin code bases, but happy to help wherever I can if needed.
Comment 9 Nate Graham 2023-02-11 01:46:19 UTC
Your patch was merged!
Comment 10 Andrew Gunnerson 2023-02-11 05:06:24 UTC
Woohoo!

Any chance we could leave this issue open? The patch is good enough for my use case, but the general problem still exists.
Comment 11 Nate Graham 2023-02-11 05:18:00 UTC
The general problem will remain for some time and I expect it to require dozens of fixes throughout the software stack. Better to track issues individually; knock 'em down as we find 'em.
Comment 12 Michael 2023-02-11 06:20:29 UTC
(In reply to Dāvis from comment #6)
> The correct way to handle this would be to move all IO to different thread
> and make everything async.
> 
> But that would be pretty significant change and I actually have been working
> on solving some parts of this. I hope to submit my patches in coming months.
> Specifically I'm implementing multi-threaded file metadata loading and some
> refactorings regarding that. Also this will require changes across few
> framework libraries.
> 
> Basically I have 24-core CPU with 32 GB RAM so KDE/Dolphin should take full
> advantage of that. Currently for some things we're basically limited to 1
> thread on Dolphin.

👏👏👏🎉🎉🎉
Overjoyed to hear this!
Comment 13 Méven Car 2023-04-07 08:11:23 UTC
*** Bug 426039 has been marked as a duplicate of this bug. ***