Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Upload within Parallel.ForEach() #1533

Open
chrisfranklynandrews opened this issue Apr 4, 2024 · 11 comments
Open

Upload within Parallel.ForEach() #1533

chrisfranklynandrews opened this issue Apr 4, 2024 · 11 comments

Comments

@chrisfranklynandrews
Copy link

FTP Server OS: Windows

FTP Server Type: FileZilla

Client Computer OS: Windows

FluentFTP Version: 49.0.2

Framework: .NET 8 and/or .NET Frankwork 4.8

I generally love FluentFTP. However, when used within a Parallel.ForEach() loop, the server allows the first file upload. Then responds with.

FTP Session 133 hidden developmenttesting [Error] TLS session of data connection not resumed.
FTP Session 133 hidden developmenttesting [Response] 425 Unable to build data connection: TLS session of data connection not resumed.

Each iteration of the loop is getting their own FtpClient. So is it not safe to use inside threads like this?

Here's a simplified version that reproduces this:

Loop:

image

Method:

image

Logs :

Hello, World!

# Connect(False)

# Connect(False)
Status:   FluentFTP 49.0.2.0(.NET 6.0)
Status:   FluentFTP 49.0.2.0(.NET 6.0)
Status:   Connecting to IP #1= ***:21
Status:   Connecting to IP #1= ***:21
Status:   Waiting for a response
Status:   Waiting for a response
Response: 220-FileZilla Server 1.7.3
Response: 220-Please visit https://filezilla-project.org/
Response: 220-FileZilla Server 1.7.3
Response: 220-Please visit https://filezilla-project.org/
Status:   Detected FTP server: FileZilla
Status:   Detected FTP server: FileZilla
Command:  AUTH TLS
Command:  AUTH TLS
Status:   Waiting for response to: AUTH TLS
Status:   Waiting for response to: AUTH TLS
Response: 234 Using authentication type TLS. [22ms]
Response: 234 Using authentication type TLS. [28ms]
Warning:  SSL Buffering disabled because of .NET 5.0 and later, NOOPs requested
Warning:  SSL Buffering disabled because of .NET 5.0 and later, NOOPs requested
Status:   FTPS authentication successful, lib = .NET SslStream, cipher suite = Tls12 (Aes256, TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384, 44550, 255) [169ms]
Status:   FTPS authentication successful, lib = .NET SslStream, cipher suite = Tls12 (Aes256, TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384, 44550, 255) [169ms]
Command:  USER ***
Command:  USER ***
Status:   Waiting for response to: USER ***
Status:   Waiting for response to: USER ***
Response: 331 Please, specify the password. [17ms]
Command:  PASS ***
Status:   Waiting for response to: PASS ***
Response: 331 Please, specify the password. [139ms]
Command:  PASS ***
Status:   Waiting for response to: PASS ***
Response: 230 Login successful. [204ms]
Response: 230 Login successful. [326ms]
Command:  PBSZ 0
Command:  PBSZ 0
Status:   Waiting for response to: PBSZ 0
Status:   Waiting for response to: PBSZ 0
Response: 200 PBSZ=0 [48ms]
Response: 200 PBSZ=0 [49ms]
Command:  PROT P
Command:  PROT P
Status:   Waiting for response to: PROT P
Status:   Waiting for response to: PROT P
Response: 200 Protection level set to P [18ms]
Response: 200 Protection level set to P [18ms]
Command:  FEAT
Command:  FEAT
Status:   Waiting for response to: FEAT
Status:   Waiting for response to: FEAT
Response: 211-Features:
Response: MDTM
Response: REST STREAM
Response: SIZE
Response: MLST type*;size*;modify*;perm*;
Response: MLSD
Response: AUTH SSL
Response: AUTH TLS
Response: PROT
Response: PBSZ
Response: UTF8
Response: TVFS
Response: EPSV
Response: EPRT
Response: MFMT
Response: 211 End [17ms]
Response: 211-Features:
Response: MDTM
Response: REST STREAM
Response: SIZE
Response: MLST type*;size*;modify*;perm*;
Response: MLSD
Response: AUTH SSL
Response: AUTH TLS
Response: PROT
Response: PBSZ
Response: UTF8
Response: TVFS
Response: EPSV
Response: EPRT
Response: MFMT
Response: 211 End [17ms]
Status:   Text encoding: System.Text.UTF8Encoding+UTF8EncodingSealed
Status:   Text encoding: System.Text.UTF8Encoding+UTF8EncodingSealed
Command:  OPTS UTF8 ON
Command:  OPTS UTF8 ON
Status:   Waiting for response to: OPTS UTF8 ON
Status:   Waiting for response to: OPTS UTF8 ON
Response: 202 UTF8 mode is always enabled. No need to send this command [65ms]
Response: 202 UTF8 mode is always enabled. No need to send this command [65ms]
Command:  SYST
Command:  SYST
Status:   Waiting for response to: SYST
Status:   Waiting for response to: SYST
Response: 215 UNIX emulated by FileZilla. [19ms]
Response: 215 UNIX emulated by FileZilla. [19ms]
Status:   Active ServerHandler is: FileZilla
Status:   Active ServerHandler is: FileZilla
Status:   Listing parser set to: Machine
Status:   Listing parser set to: Machine
Command:  PWD
Command:  PWD
Status:   Waiting for response to: PWD
Status:   Waiting for response to: PWD
Response: 257 "/" is current directory. [19ms]
Response: 257 "/" is current directory. [19ms]

# UploadBytes("/chris/PingFtp.TestFile1.txt", Overwrite, False)

# UploadBytes("/chris/PingFtp.TestFile2.txt", Overwrite, False)

# FileExists("/chris/PingFtp.TestFile1.txt")

# FileExists("/chris/PingFtp.TestFile2.txt")
Command:  SIZE /chris/PingFtp.TestFile1.txt
Command:  SIZE /chris/PingFtp.TestFile2.txt
Status:   Waiting for response to: SIZE /chris/PingFtp.TestFile1.txt
Status:   Waiting for response to: SIZE /chris/PingFtp.TestFile2.txt
Response: 550 Couldn't open the file or directory [60ms]
Response: 550 Couldn't open the file or directory [60ms]

# OpenWrite("/chris/PingFtp.TestFile1.txt", Binary, -1, False)

# OpenWrite("/chris/PingFtp.TestFile2.txt", Binary, -1, False)
Command:  TYPE I
Command:  TYPE I
Status:   Waiting for response to: TYPE I
Status:   Waiting for response to: TYPE I
Response: 200 Type set to I [17ms]
Response: 200 Type set to I [17ms]

# OpenDataStream("STOR /chris/PingFtp.TestFile1.txt", 0)

# OpenDataStream("STOR /chris/PingFtp.TestFile2.txt", 0)

# OpenPassiveDataStream(PASV, "STOR /chris/PingFtp.TestFile1.txt", 0)

# OpenPassiveDataStream(PASV, "STOR /chris/PingFtp.TestFile2.txt", 0)
Command:  PASV
Command:  PASV
Status:   Waiting for response to: PASV
Status:   Waiting for response to: PASV
Response: 227 Entering Passive Mode (172,31,36,108,195,128) [18ms]
Response: 227 Entering Passive Mode (172,31,36,108,195,103) [18ms]
Status:   PASV advertised a non-routable IPAD. Using original connect dnsname/IPAD
Status:   PASV advertised a non-routable IPAD. Using original connect dnsname/IPAD
Status:   Connecting to IP #1= ***:50023
Status:   Connecting to IP #1= ***:50048
Command:  STOR /chris/PingFtp.TestFile1.txt
Status:   Waiting for response to: STOR /chris/PingFtp.TestFile1.txt
Command:  STOR /chris/PingFtp.TestFile2.txt
Status:   Waiting for response to: STOR /chris/PingFtp.TestFile2.txt
Response: 150 Starting data transfer. [41ms]
Warning:  SSL Buffering disabled because of .NET 5.0 and later, NOOPs requested
Response: 150 Starting data transfer. [43ms]
Warning:  SSL Buffering disabled because of .NET 5.0 and later, NOOPs requested
Status:   FTPS authentication successful, lib = .NET SslStream, cipher suite = Tls12 (Aes256, TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384, 44550, 255) [26ms]
Status:   Uploaded 4 bytes
Status:   Closing/Disposing FtpSocketStream(data connection)
Status:   Waiting for response to: STOR /chris/PingFtp.TestFile1.txt
Response: 226 Operation successful [99ms]
Status:   FTPS authentication successful, lib = .NET SslStream, cipher suite = Tls12 (Aes256, TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384, 44550, 255) [112ms]
Status:   Uploaded 4 bytes
Status:   Closing/Disposing FtpSocketStream(data connection)
Status:   Waiting for response to: STOR /chris/PingFtp.TestFile2.txt
Response: 425 Unable to build data connection: TLS session of data connection not resumed. [161ms]


@FanDjango
Copy link
Collaborator

I generally love reports about TLS Session Resume failures, however:

A "real" session resume problem normally does not even allow the first file transfer to work. So, this log is really really interesting.

But, please look at all the closed issues marked with the "Session Resume" tab and you will note that this looks somewhat fishy. Is access to the FileZilla (set to debug level) log a viable option, can you post it?

Normally, using TLS 1.2, session resume can work, but not always. Strange to see it working and then not working here (at the same time).

On the other hand, multithreading FTP operations with each on having its own FtpClient is perfectly acceptable.

A number of things come to mind:

  1. Some kind of problem with FluentFTP thread safety. Very low probability currently, recently been extensively tested when a previous issue of this kind was worked on. *1)

  2. Some kind of problem with the underlying SslStream.SChannel thread safety. Same as 1. in my humble opinion, but to prove the problem might lie here, you could do the same test by using FluentFTL.GnuTLS instead. Thread Safety intensively tested with that only recently.

  3. FileZilla - different versions had differing behaviour for Session Resume. You might want to install or use a different version as a test, or you might test that code of yours on a different server location altogether in order to narrrow things down. Perhaps FileZilla (and not FluentFTP), or even GnuTLS (which is used by FileZilla) is somehow mixing up TLS session data between parallel session from the same client.

*1) I have a parallel up- and download test program I run regularly, it does 50 operation simultaneously (albeit agains a proFTPd server). No problems.

Since you can reproduce this and you have supplied the code, I can try the same here (also against a FileZilla) and that will also give us another angle to analyze this.

@chrisfranklynandrews
Copy link
Author

Thanks for your response. I was hoping for a "You're doing it wrong" answers, so I'm willing to try anything.

  1. I'll go an look at the log level on the server (it's not my server, but I know a man...)

  2. I can look at using FluentFTL.GnuTLS to rule things out. But I won't be able to use anything LGPL in our solution sadly.

  3. I'll try it locally too, see if it reproduces here.

Thanks again.

@chrisfranklynandrews
Copy link
Author

Attached Server Log (from my local FileZilla server 1.8.1)

zillaserverlog.txt

@FanDjango
Copy link
Collaborator

Good, so you can run this on your own server. Later I will do some testing also and we will see where that gets us. Pity about GnuTLS, what is the actual things preventing use?

@FanDjango
Copy link
Collaborator

OK, I have been playing around with parallel uploads.

I get the exact same symptoms as you with FileZilla, but I would not necessarily say it is FileZilla's fault (it can be very strict and sometimes ornery, but all accords to the RFCs instead of "strange" custom behaviour).

Here are my results:

Encryption OFF:
FileZilla 1.8.1 and proFTPd: Parallel uploads ok.

Encryption: Explicit SslStream
proFTPd: Parallel uploads ok.
FileZilla 1.8.1: Exact same failure as yours.

Encryption: Explicit FluentFTP.GnuTLS
proFTPd: Parallel uploads ok.
FileZilla 1.8.1: Parallel uploads ok.

Conclusion: .NET SslStream Session Resume is requested by FileZilla. The way SslStream TLS1.2 implements Session Resume is not correct. FileZilla(GnuTLS) rejects this. proFTPd seemingly does not request Session Resume for TLS1.2 and thus it works. To use TLS1.3, you would need at least Win11 and .NET6+ (there are rumours of a late WIN10, but YMMV), or use FluentFTP.GnuTLS.

The first upload, or sequential uploads work, because in those cases the session data used for the Session Resume is unique and not (incorrectly) shared between the sessions, I can only surmise.

And now go figure :-) - like trying to see at what level this is happening: Running two separate executables at the same time, for example, I have never tested that.

@chrisfranklynandrews
Copy link
Author

Thanks for checking out my scenario. Very much appreciated. I've got signoff to try FluentFTP.GnuTLS now, and I've tried. With limited success.

Once again, with no threads/parallelism it works fine. However, there seems to be issues with concurrency.

The issues seems to be inside GetCachedHostAddresses

image

Sometimes it outright refuses to do it saying "Operations that change non-concurrent collections must have exclusive access. A concurrent update was performed on this collection and corrupted its state. The collection's state is no longer correct."

Other times it simply says that a key already exists with that hostname.

Are the settings in your tests the same as those in the repository here for the test? In case I'm missing out something that magically makes this work. I've looked through the issues and there were historically settings for concurrency, but they don't seem to be there now.

Thanks!

@FanDjango
Copy link
Collaborator

FanDjango commented Apr 5, 2024

The issues seems to be inside GetCachedHostAddresses
Sometimes it outright refuses to do it saying "Operations that change non-concurrent collections must have exclusive access. A concurrent update was performed on this collection and corrupted its state. The collection's state is no longer correct."

Other times it simply says that a key already exists with

First of all, this error is a totally different one from the one you initially reported. I wonder how you got that to happen, given that the Status.CachedHostIpads is local to the ftpClient object.

I looked at your code and I don't see anything obvious, here is mine:

			Random r = new Random();

			await Task.WhenAll(Enumerable.Repeat(1, 5).Select(async _ => {

				using (var client = new AsyncFtpClient("host", "****", "********")) {
					client.Config.EncryptionMode = FtpEncryptionMode.Explicit;
					client.Config.DataConnectionType = FtpDataConnectionType.PASV;
					client.Config.DownloadDataType = FtpDataType.Binary;
					client.Config.ValidateAnyCertificate = true;

					client.Config.Navigate = FtpNavigate.SemiAuto;

					//client.Config.SslSessionLength = 0;

					client.LegacyLogger = FTPLogEvent;

					//client.Config.CustomStream = typeof(GnuTlsStream);
					//client.Config.CustomStreamConfig = new GnuConfig() {
					//	//SecuritySuite = GnuSuite.Normal,
					//	//SecurityOptions = new List<GnuOption> {
					//	//		new GnuOption(GnuOperator.Include, GnuCommand.Protocol_All),
					//	//		new GnuOption(GnuOperator.Exclude, GnuCommand.Protocol_Tls10),
					//	//		new GnuOption(GnuOperator.Exclude, GnuCommand.Protocol_Tls11),
					//	//	},
					//	//SecurityProfile = GnuProfile.None,
					//	//AdvancedOptions = new List<GnuAdvanced> {
					//	//		GnuAdvanced.NoExtensions,
					//	//	},
					//	SetALPNControlConnection = string.Empty,
					//	SetALPNDataConnection = string.Empty,
					//	//LoadLibraryDllNamePrefix = "D:\\temp\\",
					//	LogLevel = 0,
					//	LogMessages = GnuMessage.All,
					//};

					await client.Connect();

					await client.UploadFile("D:\\testdir\\t.t", "\\home\\****\\t" + r.Next() + ".cs", FtpRemoteExists.Overwrite, true);

					await client.Disconnect();
				}
			}
			));

@FanDjango
Copy link
Collaborator

This runs 5 parallel uploads of one local file to different names on the server and with or without GnuTLS depending on uncommenting the config statements. It is .NET 6 on my side at the moment and I have not tested any others.

@FanDjango
Copy link
Collaborator

Meanwhile you ponder that, I do have a few tricks up my sleeve to dig deeper into your original reported problem, which I can reproduce - namely to place a lock around SslStream initial authorization. Will do this later on...

@FanDjango
Copy link
Collaborator

One more thing:

The issues seems to be inside GetCachedHostAddresses

This is outside any SslStream concurrency issues - and comon code for non-encrypted - you should always also check your code with a non-encrypted connection (if at all possible) as a cross-check.

@chrisfranklynandrews
Copy link
Author

Cheers for the update. Yes, it is a new issue, it came about when trying FluentFTP.GnuTLS as suggested. Apologies for muddling up a issue tracking system with a support line :)

I will try the things suggested but I have to travel now and will not be back until next week. So I'm not deliberately being rude if you don't hear back from me soon. Thanks.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

2 participants