FluentFTP
FluentFTP copied to clipboard
robinrodricks
Uploading error when connecting through SOCKS4 / SOCKS4a / SOCKS5 proxy
FTP OS: Windows
FTP Server: Reproduced on XLight and EFT
Computer OS: Windows
FluentFTP Version: 38.0.0
Every time I upload 8 megs or (bigger) file through SOCKS4, SOCKS4a or even SOCKS5 (which exists in the library for the long time) it is uploaded incomplete and with different file size each time. When I upload without proxy, everything is OK.
Logs :
# Connect()
Status: Connecting to ***:1080
Response: 220 Xlight FTP Server 3.8 ready...
Status: Detected FTP server: XLight
Command: USER ***
Response: 331 Password required for nuser
Command: PASS ***
Response: 230 Login OK
Command: FEAT
Response: 211-Features supported
Response: REST STREAM
Response: EPRT
Response: EPSV
Response: SIZE
Response: MDTM
Response: MFMT
Response: AUTH
Response: PBSZ
Response: PROT
Response: MLST type*;size*;modify*;
Response: MLSD
Response: 211 End
Status: Text encoding: System.Text.ASCIIEncoding
Command: SYST
Response: 215 UNIX Type: L8
Status: Listing parser set to: Machine
# Upload("test.mdf", Overwrite, False)
# FileExists("test.mdf")
Command: PWD
Response: 257 "/"
Command: SIZE /test.mdf
Response: 213 7954432
# DeleteFile("test.mdf")
Command: DELE test.mdf
Response: 250 Deleted file "test.mdf".
# OpenWrite("test.mdf", Binary)
# GetFileSize("test.mdf")
Command: SIZE test.mdf
Response: 550 Can't find file "test.mdf".
Command: TYPE I
Response: 200 Type set to I.
# OpenPassiveDataStream(AutoPassive, "STOR test.mdf", 0)
Command: EPSV
Response: 229 Entering Passive Mode (|||50030|)
Status: Connecting to ***:1080
Command: STOR test.mdf
Response: 150 Opening BINARY mode data connection for test.mdf.
Status: Disposing FtpSocketStream...
Response: 226 Transfer complete (26707.252 KB/s).
Command: QUIT
Response: 221 Good-Bye
Status: Disposing FtpSocketStream...
Since you contributed SOCKS4x support into the library you would be the best person to debug this.
My company's support team told me that the library is doing very frequent requests to the FTP and it causes proxy/firewall to cut the connection probably that's the reason. Here, is the explanation of this:
https://kb.globalscape.com/Knowledgebase/10142/FTP-Status-and-Error-Codes#:~:text=For%20example%2C%20if%20you%20get,if%20that%20solves%20the%20problem
Also, they provided EFT Server log for my request:
2022-12-09 12:54:46 216.64.152.29 - store_pass [6429801]sent /PROD/3718/user_account.xml - 426 20445750 - - 21
2022-12-09 12:55:18 216.64.152.29 - store_pass [6430152]size /PROD/3718/user_account.xml - 213 - - - 21
2022-12-09 12:55:18 216.64.152.29 - store_pass [6430152]retr /PROD/3718/user_account.xml - 150 - - - 21
2022-12-09 12:57:31 216.64.152.29 - store_pass [6430152]sent /PROD/3718/user_account.xml - 426 28833750 - - 21
2022-12-09 12:57:32 216.64.152.29 - store_pass [6430541]size /PROD/3718/user_account.xml - 213 - - - 21
2022-12-09 12:57:32 216.64.152.29 - store_pass [6430541]retr /PROD/3718/user_account.xml - 150 - - - 21
2022-12-09 12:58:43 216.64.152.29 - store_pass [6430541]sent /PROD/3718/user_account.xml - 426 14416875 - - 21
2022-12-09 12:58:44 216.64.152.29 - store_pass [6430765]size /PROD/3718/user_account.xml - 213 - - - 21
2022-12-09 12:58:44 216.64.152.29 - store_pass [6430765]retr /PROD/3718/user_account.xml - 150 - - - 21
2022-12-09 13:04:44 216.64.152.29 - store_pass [6430765]sent /PROD/3718/user_account.xml - 426 81520875 - - 21
2022-12-09 13:04:44 216.64.152.29 - store_pass [6432002]size /PROD/3718/user_account.xml - 213 - - - 21
2022-12-09 13:04:44 216.64.152.29 - store_pass [6432002]retr /PROD/3718/user_account.xml - 150 - - - 21
2022-12-09 13:05:56 216.64.152.29 - store_pass [6432002]sent /PROD/3718/user_account.xml - 426 13892625 - - 21
2022-12-09 13:05:57 216.64.152.29 - store_pass [6432233]size /PROD/3718/user_account.xml - 213 - - - 21
2022-12-09 13:05:57 216.64.152.29 - store_pass [6432233]retr /PROD/3718/user_account.xml - 150 - - - 21
2022-12-09 13:08:20 216.64.152.29 - store_pass [6432233]sent /PROD/3718/user_account.xml - 426 30406500 - - 21
This is how FTP works isn't it? I'm not sure what you are asking.... If you want data to be transferred in bigger chunks, enable chunks - See https://github.com/robinrodricks/FluentFTP/wiki/File-Transfer#settings
I see from your link:
You should consider using the "NOOP" feature of FluentFTP to make sure that a long running transfer does not timeout.
I am not saying that is the cause of your problem - but please try this first.
You say: 8 megs or (bigger), but works fine without proxy. Someone is dropping the connection, but for what reason. You are not using the latest version of FluentFTP, which would produce more information in the verbose log.
Please try some more, perhaps we can find a reason.
Secondly, the log you posted, ending in 226 Transfer complete, is not congruent to your ...426 sequence in the EFT server log.
I can surmise what is happening in the EFT log, but I need to see the whole FluentFTP log that corresponds to that.
First of all, thank you for your answer and suggestion what to try, because I really stuck. EFT is this FTP Server: https://www.globalscape.com/eft
In the proxy log, what I see is the sequence:
213 - 150 - 426
again and again, for the same file or for many files?
213 is maybe from the SIZE command,
150 is maybe from Opening BINARY mode data connection for test.mdf.
426 is the abort but I cannot see that in the FluentFTP log you posted.
Also, the FluentFTP Version you are using is much too old. Please do a single 8MB transfer and post the complete verbose log using the newest version.
First of all, sorry for delay. We are having electricity problems in Ukraine from time to time.
Here is the log for the most recent version of FluentFTP uploading 16 MB file to XLight FTP Server through the SOCKS proxy:
# Connect(False)
Status: FluentFTP 44.0.1.0
Status: Connecting to IP #1= ***:1080
Status: Waiting for a response
Response: 220 Xlight FTP Server 3.8 ready... [738537.497d]
Status: Detected FTP server: XLight
Command: USER ***
Status: Waiting for response to: USER ***
Response: 331 Password required for *** [392ms]
Command: PASS ***
Status: Waiting for response to: PASS ***
Response: 230 Login OK [240ms]
Command: FEAT
Status: Waiting for response to: FEAT
Response: 211-Features supported
Response: REST STREAM
Response: EPRT
Response: EPSV
Response: SIZE
Response: MDTM
Response: MFMT
Response: AUTH
Response: PBSZ
Response: PROT
Response: MLST type*;size*;modify*;
Response: MLSD
Response: 211 End [103ms]
Status: Text encoding: System.Text.ASCIIEncoding
Command: SYST
Status: Waiting for response to: SYST
Response: 215 UNIX Type: L8 [93ms]
Status: Listing parser set to: Machine
Command: PWD
Status: Waiting for response to: PWD
Response: 257 "/" [97ms]
XLight
REST, EPSV, SIZE, MDTM, MFMT, MLSD,
# UploadStream("dblp.7z", Overwrite, False)
# FileExists("dblp.7z")
Command: SIZE /dblp.7z
Status: Waiting for response to: SIZE /dblp.7z
Response: 550 Can't find file "dblp.7z". [88ms]
# OpenWrite("dblp.7z", Binary)
Command: TYPE I
Status: Waiting for response to: TYPE I
Response: 200 Type set to I. [99ms]
# OpenDataStream("STOR dblp.7z", 0)
# OpenPassiveDataStream(AutoPassive, "STOR dblp.7z", 0)
Command: EPSV
Status: Waiting for response to: EPSV
Response: 229 Entering Passive Mode (|||1047|) [101ms]
Status: Connecting to IP #1= ***:1080
Command: STOR dblp.7z
Status: Waiting for response to: STOR dblp.7z
Response: 150 Opening BINARY mode data connection for dblp.7z. [103ms]
Status: Uploaded 17601706 bytes
Status: Closing/Disposing FtpSocketStream(data connection)
Status: Waiting for response to: *UPLOAD*
Response: 226 Transfer complete (28393.215 KB/s). [3.441s]
# FileExists(" dblp.7z")
Command: SIZE / dblp.7z
Status: Waiting for response to: SIZE / dblp.7z
Response: 550 Wrong file type, file is directory [100ms]
Command: MDTM / dblp.7z
Status: Waiting for response to: MDTM / dblp.7z
Response: 213 20230118115557 [100ms]
True
# GetNameListing(null)
# OpenDataStream("NLST /", 0)
# OpenPassiveDataStream(AutoPassive, "NLST /", 0)
Command: EPSV
Status: Waiting for response to: EPSV
Response: 229 Entering Passive Mode (|||1048|) [100ms]
Status: Connecting to IP #1= ***:1080
Command: NLST /
Status: Waiting for response to: NLST /
Response: 150 Opening ASCII mode data connection for NLIST (9 bytes). [99ms]
+---------------------------------------+
Listing: ?????Odblp.7z
Status: Closing/Disposing FtpSocketStream(data connection)
# CloseDataStream()
Status: Waiting for a response
Response: 226 Transfer complete (1.800 KB/s). [106ms]
+---------------------------------------+
Status: Closing/Disposing FtpSocketStream(data connection)
13
# GetNameListing(null)
# OpenDataStream("NLST /", 0)
# OpenPassiveDataStream(AutoPassive, "NLST /", 0)
Command: EPSV
Status: Waiting for response to: EPSV
Response: 229 Entering Passive Mode (|||1049|) [93ms]
Status: Connecting to IP #1= ***:1080
Command: NLST /
Status: Waiting for response to: NLST /
Response: 150 Opening ASCII mode data connection for NLIST (9 bytes). [99ms]
+---------------------------------------+
Listing: ?????Odblp.7z
Status: Closing/Disposing FtpSocketStream(data connection)
# CloseDataStream()
Status: Waiting for a response
Response: 226 Transfer complete (0.200 KB/s). [101ms]
+---------------------------------------+
Status: Closing/Disposing FtpSocketStream(data connection)
False
Command: QUIT
Status: Waiting for response to: QUIT
Response: 221 Good-Bye [43ms]
Status: Closing/Disposing FtpSocketStream(control connection)
# Dispose()
Status: Disposing FtpClient object...
Status: Closing/Disposing FtpSocketStream(control connection)
This here looks strange:
# FileExists(" dblp.7z")
Command: SIZE / dblp.7z
Status: Waiting for response to: SIZE / dblp.7z
Response: 550 Wrong file type, file is directory [100ms]
Command: MDTM / dblp.7z
Status: Waiting for response to: MDTM / dblp.7z
Response: 213 20230118115557 [100ms]
True
SIZE / dblp.7z is definitely strange syntax, how does this happen, what does your source code look like?
using System;
using System.IO;
using System.Linq;
using System.Net;
using FluentFTP;
using FluentFTP.Logging;
using FluentFTP.Proxy.SyncProxy;
namespace FtpTest
{
internal static class Program
{
const string phost = "127.0.0.1";
const int pport = 1080;
const string fhost = "192.168.186.137";
const int fport = 21;
const string flogin = "nuser";
const string fpassword = "123456";
const string fileName = "dblp.7z";
const string ufname = @"c:\users\firelizard\desktop\dblp.7z";
private static void TestFluentFTPUpload()
{
try
{
var ftpClient = new FtpClientSocks4Proxy(new FtpProxyProfile
{
ProxyCredentials = null,
ProxyHost = phost,
ProxyPort = pport
})
{
Credentials = new NetworkCredential(flogin, fpassword),
Host = fhost,
Port = fport
};
ftpClient.Connect();
Console.ForegroundColor = ConsoleColor.Green;
Console.WriteLine(ftpClient.ServerType + "\n");
foreach (var ftpClientCapability in ftpClient.Capabilities)
{
Console.Write(ftpClientCapability + ", ");
}
Console.WriteLine("\n");
FileStream fs = new FileStream(ufname, FileMode.Open);
ftpClient.UploadStream(fs, fileName);
fs.Close();
Console.WriteLine(ftpClient.FileExists("\0\0\0\0\0\0" + fileName));
Console.WriteLine(ftpClient.GetNameListing()[0].Length);
Console.WriteLine(ftpClient.GetNameListing().Select(x => x.Trim().Replace("\0", "")).Contains(fileName));
ftpClient.Disconnect();
}
catch (Exception exc)
{
Console.ForegroundColor = ConsoleColor.Red;
Console.WriteLine(exc.GetExceptionMessages());
}
}
public static void Main(string[] args)
{
TestFluentFTPUpload();
}
}
}
I suppose "\0\0\0\0\0\0" + fileName that explains the strange output. I suppose you have strange filenames :-)
It looks to me like the file transfer you just posted worked fine, it was not one of the ones that failed. Status: Uploaded 17601706 bytes. Looks good right?
17 601 706 is about 16MB. Hmmm, are you saying that on the server, the file is not complete?
Thank you for your response Filename is dblp.7z, but library adds 6 '\0' to it. It says Status: Uploaded 17601706 bytes but actual size is much less (could be 8 or 10 MB approximately)
Ok. I understand.
I just now realized the connection to the PROXY! There is always a 6 byte header to be removed..... somewhere there must still be a bug in the "dissection" of stuff that is received from the proxy. That needs to be debugged (it is problem #1, funny name being received with 6 zeros in front???, the number "six" is definitely a big clue to the problem and looks very fishy).
problem #2 would then be: Uploaded looks good, means we sent all the data, but actual size on the server is much smaller.
Could be, 6 bytes are being "swallowed" on each transfer chunk sent? Could that be? Chunks would be maybe MSS like 1400 bytes, then 6 bytes would be about 0.5% bytes missing?
@robinrodricks says you wrote the proxy stuff, can you think about it too?
We are having electricity problems in Ukraine from time to time
Take your time. I am on your side.
Sorry no idea much. 99% of the proxy stuff was purely user contributions. I only acted as steward.
I was referring to @fire-lizard - fighting for his country in the Ukraine. Trouble is, I don't have any access to proxies for testing.
Hi and thank you for remembering me @FanDjango I am OK, but I changed job which means I lost access to the corporate Microsoft ISA Server 2006 they had and could not reproduce issue with my local install of MS ISA (on VMWARE). Tested with 3proxy too (SOCKS4, SOCKS4a and SOCKS5 modes) and everything working fine.
and everything working fine
Ooof. We'll put this on a back burner then. I doubt the problem has just dissappeared. But I would close this and we will remember the topic in case it ever comes up. The issue title is sufficient for anyone researching proxy related problems to find this.
Happy to hear you have a job and not a foxhole :-) - stay safe bro