search

qbittorrent / qBittorrent

qBittorrent BitTorrent client
https://www.qbittorrent.org
Other
28.19k stars 3.97k forks source link

Add torrent dialog's 'Save at' drop down slow to populate directories/autocomplete #13903

Open Snowknight26 opened 3 years ago

Snowknight26 commented 3 years ago

qBittorrent 4.3.1 on Windows 10 20H2 (19042.630). (10.0.19042)

Seemingly ever since upgrading from 4.2.x to 4.3.x, the file path input field/drop down is very slow to populate directories and have autocomplete start working.

For example, let's say I have the following folder structure:

If I change Torrent Management Mode in the add torrent dialog to Manual then start typing in a path I want to save the torrent to, such as "Z:\files\k" (to list all directories under "files" that start with the letter "k"), the list of directories is very slow to populate. I have to wait until qBittorrent enumerates all the folders alphabetically prior to the letter "k" before autocomplete starts working, but even then I need to delete "k", such that the path is now simply "Z:\files\", then retype "k" before any folders that start with "k" appear.

It's actually so slow in some directories (tried with one that has ~8k subdirectories) that while the drop down is showing, I can continually drag the scrollbar to the very bottom of the drop down and see the directory list load.

I've seen this happen on two different machines now, one where the directory list being emulated is that of a ReFS partition and another is that of an NTFS partition.

Windows Explorer and other utilities that enumerate the directories show no such slow down.

Snowknight26 commented 3 years ago

I ran Process Monitor during directory enumeration and captured a log of qBittorrent.exe's filesystem activity:

https://mega.nz/file/Ixc22DhT#3Sa62Z8K-pqGkyzr0pYQfKlaEy1axJkVwUzEehtE0iE

In this example, I typed 'Z:\Music\' followed by an extra 'Y' a few seconds later (to get 'Z:\Music\Y'). The beginning of the capture shows the filesystem access.

Event 1: 2021-03-03 1:38:09.2917399 PM Event 10953: 2021-03-03 1:38:41.5170610 PM

Took roughly 32 seconds to enumerate the folder that itself has ~3600 child folders.

Event 32 shows qBittorrent.exe the QueryDirectory operation being run, taking 0.0329342 seconds to return 601 entries. Event 1857 shows another QueryDirectory operation being run, requesting the next set of entries. This took 0.0175179s. etc.

All in all, actually enumerating the entire folder takes ~0.1 seconds. The rest of the time is spent on accessing each individual folder 3 times, though I don't know why.

Based on looking at a couple QueryOpen operations, the first of the 3 QueryOpen operations per folder seems to take anywhere from ~33ms to under 1ms. Considering it's doing this for every folder, 32 seconds / 3600 folders = ~8.88ms per folder. Yeah, that makes sense.

I guess if OS hasn't cached the data that is being retrieved by the QueryOpen operations (GetFileAttributesExW) then it takes upwards of ~30ms to query them, but roughly 500 microseconds (0.5ms) if the OS has cached the data.

Though it's not included in the log file (I must not have included full stack traces for events), here's a stack trace for one of the QueryOpen operations that takes upwards of ~30ms:

0   FLTMGR.SYS  FltDecodeParameters + 0x1e3b    0xfffff80572c9608b  C:\WINDOWS\System32\drivers\FLTMGR.SYS
1   FLTMGR.SYS  FltDecodeParameters + 0x240 0xfffff80572c94490  C:\WINDOWS\System32\drivers\FLTMGR.SYS
2   FLTMGR.SYS  FltQueryInformationFile + 0x5d1 0xfffff80572ccb5c1  C:\WINDOWS\System32\drivers\FLTMGR.SYS
3   ntoskrnl.exe    NtAllocateLocallyUniqueId + 0x244   0xfffff805756b98b4  C:\WINDOWS\system32\ntoskrnl.exe
4   ntoskrnl.exe    NtDeviceIoControlFile + 0x2290  0xfffff805755fed80  C:\WINDOWS\system32\ntoskrnl.exe
5   ntoskrnl.exe    SeOpenObjectAuditAlarmWithTransaction + 0x58ce  0xfffff8057562795e  C:\WINDOWS\system32\ntoskrnl.exe
6   ntoskrnl.exe    ObOpenObjectByNameEx + 0x1fa    0xfffff805755eb25a  C:\WINDOWS\system32\ntoskrnl.exe
7   ntoskrnl.exe    NtCreateFile + 0xd5e    0xfffff8057566de4e  C:\WINDOWS\system32\ntoskrnl.exe
8   ntoskrnl.exe    setjmpex + 0x7ce8   0xfffff805754074b8  C:\WINDOWS\system32\ntoskrnl.exe
9   ntdll.dll   NtQueryFullAttributesFile + 0x14    0x7ff91274eed4  C:\WINDOWS\SYSTEM32\ntdll.dll
10  KERNELBASE.dll  GetFileAttributesExW + 0x9c 0x7ff9100a5c9c  C:\WINDOWS\System32\KERNELBASE.dll
11  qbittorrent.exe QFileSystemEngine::fillMetaData + 0x2bf 0x7ff68bea12af  C:\Program Files\qBittorrent\qbittorrent.exe
12  qbittorrent.exe QFileInfoGatherer::getFileInfos + 0x3b0 0x7ff68ba71c30  C:\Program Files\qBittorrent\qbittorrent.exe
13  qbittorrent.exe QFileInfoGatherer::run + 0x186  0x7ff68ba71526  C:\Program Files\qBittorrent\qbittorrent.exe
14  qbittorrent.exe QThreadPrivate::start + 0xeb    0x7ff68bdb54ab  C:\Program Files\qBittorrent\qbittorrent.exe
15  qbittorrent.exe thread_start<unsigned int (__cdecl*)(void *),1> + 0x50, minkernel\crts\ucrt\src\appcrt\startup\thread.cpp(89)   0x7ff68bfd0a10  C:\Program Files\qBittorrent\qbittorrent.exe
16  KERNEL32.DLL    BaseThreadInitThunk + 0x14  0x7ff9125c7034  C:\WINDOWS\System32\KERNEL32.DLL
17  ntdll.dll   RtlUserThreadStart + 0x21   0x7ff9126fd241  C:\WINDOWS\SYSTEM32\ntdll.dll

QFileSystemEngine::fillMetaData seems to be the culprit.

Stack trace of the 2nd and 3rd QueryOpen operations that are always fast, taking about 30 microseconds:

0   FLTMGR.SYS  FltDecodeParameters + 0x1e3b    0xfffff80572c9608b  C:\WINDOWS\System32\drivers\FLTMGR.SYS
1   FLTMGR.SYS  FltDecodeParameters + 0x240 0xfffff80572c94490  C:\WINDOWS\System32\drivers\FLTMGR.SYS
2   FLTMGR.SYS  FltQueryInformationFile + 0x5d1 0xfffff80572ccb5c1  C:\WINDOWS\System32\drivers\FLTMGR.SYS
3   ntoskrnl.exe    NtAllocateLocallyUniqueId + 0x244   0xfffff805756b98b4  C:\WINDOWS\system32\ntoskrnl.exe
4   ntoskrnl.exe    NtDeviceIoControlFile + 0x2290  0xfffff805755fed80  C:\WINDOWS\system32\ntoskrnl.exe
5   ntoskrnl.exe    SeOpenObjectAuditAlarmWithTransaction + 0x58ce  0xfffff8057562795e  C:\WINDOWS\system32\ntoskrnl.exe
6   ntoskrnl.exe    ObOpenObjectByNameEx + 0x1fa    0xfffff805755eb25a  C:\WINDOWS\system32\ntoskrnl.exe
7   ntoskrnl.exe    NtCreateFile + 0xd5e    0xfffff8057566de4e  C:\WINDOWS\system32\ntoskrnl.exe
8   ntoskrnl.exe    setjmpex + 0x7ce8   0xfffff805754074b8  C:\WINDOWS\system32\ntoskrnl.exe
9   ntdll.dll   NtQueryFullAttributesFile + 0x14    0x7ff91274eed4  C:\WINDOWS\SYSTEM32\ntdll.dll
10  KERNELBASE.dll  GetFileAttributesExW + 0x9c 0x7ff9100a5c9c  C:\WINDOWS\System32\KERNELBASE.dll
11  qbittorrent.exe _waccess_s + 0x4e, minkernel\crts\ucrt\src\appcrt\filesystem\waccess.cpp(20)    0x7ff68bfdaa3e  C:\Program Files\qBittorrent\qbittorrent.exe
12  qbittorrent.exe _waccess + 0x9, minkernel\crts\ucrt\src\appcrt\filesystem\waccess.cpp(53)   0x7ff68bfda9e5  C:\Program Files\qBittorrent\qbittorrent.exe
13  qbittorrent.exe QFileSystemEngine::fillPermissions + 0x594  0x7ff68bea0b2c  C:\Program Files\qBittorrent\qbittorrent.exe
14  qbittorrent.exe QFileSystemEngine::fillMetaData + 0x3de 0x7ff68bea13ce  C:\Program Files\qBittorrent\qbittorrent.exe
15  qbittorrent.exe QFileInfoGatherer::getFileInfos + 0x3b0 0x7ff68ba71c30  C:\Program Files\qBittorrent\qbittorrent.exe
16  qbittorrent.exe QFileInfoGatherer::run + 0x186  0x7ff68ba71526  C:\Program Files\qBittorrent\qbittorrent.exe
17  qbittorrent.exe QThreadPrivate::start + 0xeb    0x7ff68bdb54ab  C:\Program Files\qBittorrent\qbittorrent.exe
18  qbittorrent.exe thread_start<unsigned int (__cdecl*)(void *),1> + 0x50, minkernel\crts\ucrt\src\appcrt\startup\thread.cpp(89)   0x7ff68bfd0a10  C:\Program Files\qBittorrent\qbittorrent.exe
19  KERNEL32.DLL    BaseThreadInitThunk + 0x14  0x7ff9125c7034  C:\WINDOWS\System32\KERNEL32.DLL
20  ntdll.dll   RtlUserThreadStart + 0x21   0x7ff9126fd241  C:\WINDOWS\SYSTEM32\ntdll.dll

_waccess_s determines read/write permissions but still once again called from inside QFileSystemEngine::fillMetaData, so that's not it.

Whatever else QFileSystemEngine::fillMetaData is doing is taking forever when querying the filesystem, causing the directory list to load extremely slowly.

FranciscoPombal commented 3 years ago

Possibly a Qt bug, or maybe qBittorrent is using it wrong in some way. Any chance you can profile this further?

Snowknight26 commented 3 years ago

I'm not sure I know how to get a deeper dive into this without understanding the qBittorrent source code, which I definitely don't.

The only thing I can do is bring up the fact that it seems like the way the the save path combobox is populated (by FileSystemPathEdit::selectedPathChanged?) is inefficient.

Snowknight26 commented 3 years ago

One thing I noticed is that FileZilla Server also has this same issue, which made me investigate what it and qBittorrent do in common. I compared it to how Explorer enumerates directories and here's what I found using Process Monitor.

Note: the word 'file' can refer to both a file or folder.. I guess the OS doesn't differentiate the two, at least as far as how the functions are called in Microsoft's documentation.

Explorer: Calls NtQueryDirectoryFile (listed as QueryDirectory in ProcMon), passing FileBothDirectoryInformation to the FileInformationClass parameter, which causes the function to return (if successful) a FILE_BOTH_DIR_INFORMATION object that contains file/folder properties, times, etc. It continues calling NtQueryDirectoryFile until the return value is STATUS_NO_MORE_FILES, which signals that the directory has no more files. The FILE_BOTH_DIR_INFORMATION objects returned from all the calls contains the data for every file in the folder.

Testing this on a folder with ~4k subfolders, that took ~200ms and 10 calls to NtQueryDirectoryFile.

qBittorrent: Does the same thing as Explorer but after each NtQueryDirectoryFile call, it also calls NTQueryInformationFile (listed as QueryOpen in ProcMon), passing FileNetworkOpenInformation to FileInformationClass parameter (I guess for file timestamps?), for every file returned in the FILE_BOTH_DIR_INFORMATION struct.

Explorer and qBittorrent require the same number of calls to NtQueryDirectoryFile to retrieve all the files/folders (10), but qBittorrent then calls NTQueryInformationFile an extra ~4k times, once for each subfolder/file, simply to retrieve redundant info. It already has file timestamps from NtQueryDirectoryFile.

That's where the extra delay in populating the dropdown is coming from. This probably affects other areas in qBittorrent too, not just the dropdown.

ghost commented 2 years ago

Anyone still facing this please test the latest actions build from master branch as some patches have been merged there.

Snowknight26 commented 1 year ago

Anyone still facing this please test the latest actions build from master branch as some patches have been merged there.

Still happens with 4.5.2.

The behavior might be worse now because the autocomplete feature is hidden behind Ctrl+Space, with the caveat being that if you partially completed the path, but the path isn't actually a valid path (such as by entering C:\somepa to autocomplete to C:\somepath), the autocomplete entries won't appear.