Strange bug when downloading large number of files (>20K)

I tried to submit this but the ticket didn't show up so I don't know if something went wrong. If the other ticket eventually shows up, please delete this one.

I encounter a strange problem while downloading all files from large folders in FlashFXP 5.4.0 Build 3939. I have two different folders, one with more than 20K files and one with more than 90K files, and on both folders, FlashFXP goes nuts after downloading a little more than 1000 files. For the first 10xx files, everything looks normal:

[06:31:32] [L] TYPE I
[06:31:32] [L] 200 Type set to I
[06:31:32] [L] PASV
[06:31:32] [L] 227 Entering Passive Mode (redacted,196,153).
[06:31:32] [L] Opening data connection IP: redacted PORT: 50329
[06:31:32] [L] RETR 41aYa11VOgL-60x60.jpg
[06:31:32] [L] 150 Opening BINARY mode data connection for 41aYa11VOgL-60x60.jpg (1618 bytes)
[06:31:32] [L] 226 Transfer complete
[06:31:32] Download: 41aYa11VOgL-60x60.jpg 1 KB in 0,00 seconds (1,6 KB/s)
[06:31:32] [L] TYPE I
[06:31:32] [L] 200 Type set to I
[06:31:32] [L] PASV
[06:31:32] [L] 227 Entering Passive Mode (redacted,196,200).
[06:31:32] [L] Opening data connection IP: redacted PORT: 50376
[06:31:32] [L] RETR 41aYa11VOgL-175x175.jpg
[06:31:32] [L] 150 Opening BINARY mode data connection for 41aYa11VOgL-175x175.jpg (8109 bytes)
[06:31:32] [L] 226 Transfer complete
[06:31:32] Download: 41aYa11VOgL-175x175.jpg 7 KB in 0,00 seconds (7,9 KB/s)
[06:31:32] [L] TYPE I
[06:31:32] [L] 200 Type set to I
[06:31:32] [L] PASV
[06:31:32] [L] 227 Entering Passive Mode (redacted,196,188).
[06:31:32] [L] Opening data connection IP: redacted PORT: 50364
[06:31:32] [L] RETR 41aYa11VOgL-200x150.jpg
[06:31:32] [L] 150 Opening BINARY mode data connection for 41aYa11VOgL-200x150.jpg (8134 bytes)
[06:31:32] [L] 226 Transfer complete
[06:31:32] Download: 41aYa11VOgL-200x150.jpg 7 KB in 0,00 seconds (7,9 KB/s)

And then, it continues like this, issuing MLSD for each and every file again:

[06:29:09] [L] PASV
[06:29:09] [L] 227 Entering Passive Mode (redacted,196,251).
[06:29:09] [L] Opening data connection IP: redacted PORT: 50427
[06:29:09] [L] MLSD
[06:29:09] [L] 150 Opening BINARY mode data connection for MLSD
[06:29:13] [L] 226 Transfer complete
[06:29:14] [L] List Complete: 12,39 MB in 5 seconds (2,36 MB/s)
[06:29:14] [L] TYPE I
[06:29:14] [L] 200 Type set to I
[06:29:14] [L] MLST 41Axp-ZfYpL-50x50.jpg
[06:29:14] [L] 250-Start of list for 41Axp-ZfYpL-50x50.jpg
[06:29:14] [L] modify=20160225110948;perm=adfrw;size=1029;type=fi le;unique=803U3A05D6F;UNIX.group=1008;UNIX.mode=06 44;UNIX.owner=1010; /sneakertick.de/wp-content/uploads/2016/02/41Axp-ZfYpL-50x50.jpg
[06:29:14] [L] 250 End of list
[06:29:14] [L] TYPE I
[06:29:14] [L] 200 Type set to I
[06:29:14] [L] PASV
[06:29:14] [L] 227 Entering Passive Mode (redacted,196,5).
[06:29:14] [L] Opening data connection IP: redacted PORT: 50181
[06:29:14] [L] RETR 41Axp-ZfYpL-50x50.jpg
[06:29:14] [L] 150 Opening BINARY mode data connection for 41Axp-ZfYpL-50x50.jpg (1029 bytes)
[06:29:14] [L] 226 Transfer complete
[06:29:14] Download: 41Axp-ZfYpL-50x50.jpg 1 KB in 0,02 seconds (1,0 KB/s)
[06:29:14] [L] PASV
[06:29:14] [L] 227 Entering Passive Mode (redacted,196,2).
[06:29:14] [L] Opening data connection IP: redacted PORT: 50178
[06:29:14] [L] MLSD
[06:29:14] [L] 150 Opening BINARY mode data connection for MLSD
[06:29:19] [L] 226 Transfer complete
[06:29:19] [L] List Complete: 12,39 MB in 5 seconds (2,40 MB/s)
[06:29:19] [L] TYPE I
[06:29:20] [L] 200 Type set to I
[06:29:20] [L] MLST 41Axp-ZfYpL-60x60.jpg
[06:29:20] [L] 250-Start of list for 41Axp-ZfYpL-60x60.jpg
[06:29:20] [L] modify=20160225110948;perm=adfrw;size=1141;type=fi le;unique=803U3A05D70;UNIX.group=1008;UNIX.mode=06 44;UNIX.owner=1010; /sneakertick.de/wp-content/uploads/2016/02/41Axp-ZfYpL-60x60.jpg
[06:29:20] [L] 250 End of list
[06:29:20] [L] TYPE I
[06:29:20] [L] 200 Type set to I
[06:29:20] [L] PASV
[06:29:20] [L] 227 Entering Passive Mode (redacted,195,136).
[06:29:20] [L] Opening data connection IP: redacted PORT: 50056
[06:29:20] [L] RETR 41Axp-ZfYpL-60x60.jpg
[06:29:20] [L] 150 Opening BINARY mode data connection for 41Axp-ZfYpL-60x60.jpg (1141 bytes)
[06:29:20] [L] 226 Transfer complete
[06:29:20] Download: 41Axp-ZfYpL-60x60.jpg 1 KB in 0,00 seconds (1,1 KB/s)
[06:29:20] [L] PASV
[06:29:20] [L] 227 Entering Passive Mode (redacted,197,63).
[06:29:20] [L] Opening data connection IP: redacted PORT: 50495
[06:29:20] [L] MLSD
[06:29:20] [L] 150 Opening BINARY mode data connection for MLSD
[06:29:24] [L] 226 Transfer complete
[06:29:25] [L] List Complete: 12,39 MB in 5 seconds (2,33 MB/s)
[06:29:25] [L] TYPE I
[06:29:25] [L] 200 Type set to I
[06:29:25] [L] MLST 41Axp-ZfYpL-175x175.jpg
[06:29:25] [L] 250-Start of list for 41Axp-ZfYpL-175x175.jpg
[06:29:25] [L] modify=20160225110948;perm=adfrw;size=5178;type=fi le;unique=803U3A05D6A;UNIX.group=1008;UNIX.mode=06 44;UNIX.owner=1010; /sneakertick.de/wp-content/uploads/2016/02/41Axp-ZfYpL-175x175.jpg
[06:29:25] [L] 250 End of list
[06:29:25] [L] TYPE I
[06:29:25] [L] 200 Type set to I
[06:29:25] [L] PASV
[06:29:25] [L] 227 Entering Passive Mode (redacted,195,130).
[06:29:25] [L] Opening data connection IP: redacted PORT: 50050
[06:29:25] [L] RETR 41Axp-ZfYpL-175x175.jpg
[06:29:25] [L] 150 Opening BINARY mode data connection for 41Axp-ZfYpL-175x175.jpg (5178 bytes)
[06:29:25] [L] 226 Transfer complete
[06:29:25] Download: 41Axp-ZfYpL-175x175.jpg 5 KB in 0,02 seconds (5,1 KB/s)
[06:29:25] [L] PASV
[06:29:25] [L] 227 Entering Passive Mode (redacted,196,129).
[06:29:25] [L] Opening data connection IP: redacted PORT: 50305
[06:29:26] [L] MLSD
[06:29:26] [L] 150 Opening BINARY mode data connection for MLSD
[06:29:30] [L] 226 Transfer complete
[06:29:31] [L] List Complete: 12,39 MB in 5 seconds (2,40 MB/s)

The problem can be temporarily cured by stopping the queue and disconnecting. After Ctrl+Z to continue the transfer, the first 1000 or so files are transferred properly, then the same as above happens again. Simply stopping and continuing the transfer does NOT work and result in still seeing MLSD for each file.

This is terribly annoying because I need to download these files right now and the useless MLSD downloads 12 MB of data for each and every file, causing a tremendous slowdown (see the timestamps), not to mention the wasted transfer volume. Is there anything I can to to track this further down? I can provide a login for testing and create more detailed logs upon instructions.

Thank you for your bug report.

I reviewed your session log and after changing a few settings was able to successfully reproduced this issue exactly as you described.

There are a number of settings that all play a role in determining the behavior and different combinations result in slightly different outcomes, the most obvious is when the site profile setting "[ ] Cache directories" is unchecked, combined with my other settings, this resulted in what might be a flawed logic where the directory is refreshed after every file transfer.

The first thing we need to determine is whether or not you have directory caching turned on or off.

So please let me know, is the cache directories feature turned on or off?

Preferences / Connection / Folder Cache / Enable cache is disabled. I remember I had problems with the remote folder list after complex deletions (lots of files and folders), so I disabled cache quite some time ago and never turned it back on.

Refresh on File Transfer and Expire after are also unchecked.

Regards,
Andre

I am reworking the logic and I should have a new build for you to test in the next day or two, in the mean-time if you can turn caching on it should resolve the issue.

I managed to download the bunch with another program meanwhile, I still love FlashFXP best because of the extensive list of keyboard shortcuts and smooth UI (not to mention the robust transfer skills, FlashFXP for President ), I'll be glad to test again with the new build when it's ready.

Honestly, FlashFXP is so complete, it only lacks "just" one feature: Simultaneous transfer of multiple files to cut down transfer overhead time. I usually upload or download huge numbers of small files, and tools like filezilla can save a lot of time in that situation with their parallel transfers. Yet it's still not quite an alternative for me, I dislike the UI and I'm missing all my keyboard shortcuts dearly.

Ah well, sorry for wandering off-topic.

This should address the issue, unzip the flashfxp.exe into your FlashFXP program folder overwriting the previous build.

Download ffxp5.4.0.3940c.zip

When caching is off the current folder is stored in memory (cached) for retrieving the date/time, this is needed when preserving the date/time on transfer, but with caching off this information was not available, making bulk file transfers even slower because more commands needed to be sent to the server.

I still need to do additional testing to see if there is any other unexpected side effects caused by making this change.

Unfortunately, this version crashes right away, after only 272 milliseconds of runtime, even before the GUI shows up. I just get the crashlogger GUI.

Where should I send the bugreport? Here is a preview of the interesting part:

WideChar Test       : 0
callstack crc       : $3973cf4b, $9bc15300, $9bc15300
exception number    : 1
exception class     : ERegistryException
exception message   : Failed to get data for 'DesktopShortcut'.

main thread ($1930):
00800019 +0095 flashfxp.exe TntRegistry           TTntRegistry.GetData
007ffd96 +0052 flashfxp.exe TntRegistry           TTntRegistry.ReadInteger
007ffe8f +003f flashfxp.exe TntRegistry           TTntRegistry.ReadBool
00a1cba9 +024d flashfxp.exe FlashFXP     878  +35 _ImportDataFilesFromDefaultFolder
00a1f9ed +1465 flashfxp.exe FlashFXP    1590 +570 initialization
757f62c2 +0022 KERNEL32.DLL                       BaseThreadInitThunk

This should fix the crash on startup, for some reason its not liking the registry data for that value, not sure why, I've updated the error handling to handle the failure as non-fatal.

ffxp5.4.0.3940d.zip