Wrong data returned (possibly after an ABOR command)

[nickj]

It appears that after an ABOR command, incorrect data may be returned. In my specific case, I was trying to download file chunks, and providing offsets to FileZilla. The first chunk returned (offset 0) is correct. However, subsequent downloads return incorrect data.

This is the C# pseudocode used:

[code]
public async Task TestFileZilla()
{

var ftpClient = GetUiFtpClient();
await ftpClient.ConnectAsyc().ConfigureAwait(false);

var ftpBuffer = new byte[1024 * 1024];
var fileBuffer = new byte[1024 * 1024];

var random = new Random();

these are pointing to the same file
var remoteFile = "/test/Artifacts.zip";
var localFile = "c:
test
Artifacts.zip";

for (var i = 0; i < 10; i++)
{

just randomly check the byte stream for a >= 100MB file
var offset = random.Next(0, 100 * 1024 * 1024);

underlying rebex call is -> GetDownloadStreamAsync(path, SeekOrigin.Begin, offset);
using var ftpStream = await ftpClient.OpenFileAsync(remoteFile, offset).ConfigureAwait(false);

using var fileStream = new FileStream(localFile, FileMode.Open, FileAccess.Read);
fileStream.Seek(offset, SeekOrigin.Begin);

var ftpBytesRead = await ftpStream.ReadAsync(ftpBuffer, 0, ftpBuffer.Length).ConfigureAwait(false);
var fileBytesRead = await fileStream.ReadAsync(fileBuffer, 0, fileBuffer.Length).ConfigureAwait(false);

for (var j = 0; j < Math.Min(ftpBytesRead, fileBytesRead); j++)
{

if (ftpBuffer[j] == fileBuffer[j])

continue;

Console.WriteLine($"Byte mismatch on loop {i} at buffer offset {j}. Expecting {fileBuffer[j]}, got {ftpBuffer[j]}.");
break;

}

}

}
code

I asked the Rebex support staff to verify their library is issuing the correct calls, and this is their response:

So this indeed looks like a FileZilla issue, and it occurs even when I use an offset of “1” every time.

To rule out a client-side issue, I captured the FTP traffic using Wireshark and analyzed it. The control connection looks OK, with the client attempting to download the same file twice:

TYPE I
200 Type set to I

PASV
227 Entering Passive Mode (10,0,0,196,230,208)
REST 1
350 Restarting at 1
RETR /incoming/Artifacts.zip
150 Starting data transfer.
ABOR
426 Data connection closed; transfer aborted.
226 ABOR command successful.

PASV
227 Entering Passive Mode (10,0,0,196,230,209)
REST 1
350 Restarting at 1
RETR /incoming/Artifacts.zip
150 Starting data transfer.
ABOR
426 Data connection closed; transfer aborted.
226 ABOR command successful.

However, data that was transmitted over the second data connection is clearly wrong. Apparently, instead of sending file data that starts at offset 1, FileZilla sends data from seemingly semi-random offsets such as 0x40001 or 0xA0001. So interestingly, FileZilla got the lower 16 bits of the offset correctly, but then used wrong value for the next 16 bits.

Out of interest, I added ftpClient.GetList() as the first call in your “for (var i = 0; i < 10; i++)“ loop, and the results were even weirder – on the second iteration, the server actually transmitted some part of Artifacts.zip data instead of the directory listing.
Because I also had “ftpClient.LogWriter = new ConsoleLogWriter(LogLevel.Debug)“ in the code, this actually showed up like this:

2023-01-09 17:00:52.526 INFO Ftp(1)[1] Command: TYPE A
2023-01-09 17:00:52.527 INFO Ftp(1)[1] Response: 200 Type set to A
2023-01-09 17:00:52.527 INFO Ftp(1)[1] Command: PASV
2023-01-09 17:00:52.528 INFO Ftp(1)[1] Response: 227 Entering Passive Mode (10,0,0,196,236,89)
2023-01-09 17:00:52.528 INFO Ftp(1)[1] Command: REST 0
2023-01-09 17:00:52.529 INFO Ftp(1)[1] Response: 350 Restarting at 0
2023-01-09 17:00:52.529 DEBUG Ftp(1)[1] Info: Establishing data connection to 10.0.0.196:60505.
2023-01-09 17:00:52.530 DEBUG Ftp(1)[1] Proxy: Connecting to 10.0.0.196:60505 (no proxy).
2023-01-09 17:00:52.531 DEBUG Ftp(1)[1] Proxy: Connection established.
2023-01-09 17:00:52.535 DEBUG Ftp(1)[1] Info: Established data connection from 10.0.0.196:64571.
2023-01-09 17:00:52.535 INFO Ftp(1)[1] Command: MLSD
2023-01-09 17:00:52.536 INFO Ftp(1)[1] Response: 150 Starting data transfer.
2023-01-09 17:00:52.537 DEBUG Ftp(1)[1] Info: Data transfer started.
2023-01-09 17:00:52.537 INFO Ftp(1)[1] Response: 226 Operation successful
Q#D?G?+c?*9?Py?~??mEq?E+???e‼??(+W?F▼?G??t??_?X?♥????]&_?8????▲?♦uP?&u???¶♣Ow?S?h▲??E♂c??}I??↑j?L???♥?Y?ZM??1↑??w0h?♠8?‼?Y??G?w(?DCp??◄g?o???m?# ??r????i?⌂P????☼O?rf?|g?∟?☻??f??e#?<????▲??Av?G?Z?4♀???K)?.??C%☺???A?? ???B}y*?II/%►4"*???~?Y/H???|a??☺??↑Sh♀??????????∟U6?z?]@▼b*↓Y?!?.I♥?⌂"??o????& ??
2023-01-09 17:00:52.539 DEBUG Ftp(1)[1] Info: Item: x??? ?J5?.⌂?????C?♀M? ?▬???????V?e???????IW???n?b?↑???Nz▼_?{?:?↨?3n?8?iL?dG???5?_?i?t?g?M▬?;▲???a???C?I?Y8??∟?c?♠iT??????n???\????#?;f\Pf#?▬|?k◄?Fdb¶V?2???l???P?],♥?Df∟?▲§o?n▬▼S??~??e?☻?H?ZS??????lop???N??"▼v?e¶6?P??9?r????9?2?????U|p?p????;?►0♦?vvjXx▲?♫☺?L?E???‼??‼????F???*??*?l"↑(?6?{g|6E??♦7?an?+?h??5^{v|∟♦?Y???M???dgX?M↔E??K?s?<o?vTv?,G?'♀?V??♠?????X♦??E?F?Y?kr?4u9uRv??.?↓?~???=??⌂☻j??+§►??3r?&?9g¶????↔8j?U9??8EF??Y?☻☼??►↓P#?X?B???_¶1?iD6??<???L?↕♠t?D?G??g!↔p&>???7??x{3 ↓/?↑?!LU☻??|?▬‼????g???R??►?↔A????♦?F?!?ix?6??\??98aR♂~q??0pm??▬ ?M??@??:♣&??}??????"e???⌂?.n?i]?M??H?☺r????↔?$?
fE~♂H?????7?B???1??H??%?X;??G Ftp(1)[1] Info: Item: ?9??'?V?~m??t?9??H|?,?~?%?|3→§♀??r{?]k??↕?X???↓??
♦ ?N?|??fFI????V?{?@?6.|u(???M???2?????↕?§?>►?M↨<!??l??]↑??Bl;?"??+☼)?vT1Dc??‼?TM7????V?9?i/??x??↑?hO?m♫/r-??o?&☻?j??P"??↕►h1,%Gl??~u??N$?♣4%fSJ§?{▬?y??H?%???tO?%i??q?'vF?M?H?#?±?(P?5~?#<.C??E(U???b[?&????"?<d?_??????[??N?7?Dn?U??+?)♫????Q♣??♣?Y6u♂???,??????¶?p??N~@?i◄?p?Z,?♀?IM?WW}????????)2??S&◄6?<R??v?☻??☺W⌂?mJZ?Q,??♂?:♥???S??m▲?♣??Z??d}i????§???=Kz?n~????6??2♣?e???∟►↑??E????????Sba?☻?→☻??▲|?◄???f?u??AWy??>?|"????A☺S??s'?+>??L?☻b?►????e;s☻?Y4S?↔???↨▲Q

So please do open a FileZilla ticket for this – it looks like something very wrong is going on at the server indeed!
My guess is that it has something to do with “ABOR” command – apparently, although it does stop the current transfer (before all data has been transmitted), part of the remaining data remains in some buffer and is later sent via data connection belonging to a subsequent command.

[Fabio Alemagna]

Hi,

Thanks for the detailed report. The issue has been confirmed and fixed. Next nightly builds and releases will contain the fix.