AsyncFtpClient - The operation has timed out about fluentftp

[mattiaslundborg]

Hi!

I managed to get a log from an UploadStream call:

UploadStream("8721056381685/8721056381685.xml", NoCheck, False)

OpenWrite("8721056381685/8721056381685.xml", Binary, −1, False)
Command:  TYPE I
Status:   Waiting for response to: TYPE I
Response: 200 TYPE is now 8-bit binary [24ms]

OpenDataStreamAsync("STOR 8721056381685/8721056381685.xml", 0)

OpenPassiveDataStreamAsync(PASV, "STOR 8721056381685/8721056381685.xml", 0)
Command:  PASV
Status:   Waiting for response to: PASV
Response: 227 Entering Passive Mode (178,237,44,159,131,201) [24ms]
Status:   Connecting to IP #1= ***:33737
Command:  STOR 8721056381685/8721056381685.xml
Status:   Waiting for response to: STOR 8721056381685/8721056381685.xml
Response: 150 Accepted data connection [25ms]
Warning:  SSL Buffering disabled because of .NET 5.0 and later
Status:   FTPS authentication successful, lib = .NET SslStream, cipher suite = Tls12 (Aes256, TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384, DiffieHellman, 0) [57ms]
Status:   Uploaded 3566 bytes
Status:   Disposing(async) FtpSocketStream(data connection of AsyncFtpClient)
Status:   Waiting for response to: STOR 8721056381685/8721056381685.xml
Status:   Error encountered uploading file

[FanDjango]

Disregard the post about GetListing.
I can see one in the second log of yours

[FanDjango]

I put a lot of Azure labels on this, even if they are not necessarily on target. Helps others find Azure related stuff.

[mattiaslundborg]

Hi again. I created a new Console app with simple code to just delete an existing folder:

And this works totally fine. I have to start digging to try to find why it doesn't work in my real project.

[FanDjango]

Unless you post a verbose log of the sequence of events, I am afraid there is not much one could do for you here. I just used an ASYNC client on V50.0.1 with .NET 6 a few moments ago, it worked.

And I am not sure that this is really what you mean to say: "I'm connecting to the AsyncFtpClient".

Put yourself in my shoes: I must deduce from your prose, that the AutoConnect must have worked, for example, but more than that I know nothing, not the FEAT reply of the server (or must I google that for IIS or test it quickly myself).

My crystal ball is at the cleaners right now, so even that doesn't help.

Post a log, OK?

[FanDjango]

OK, I see. Try a GetListing first... because it uses the data connection with different code

[mattiaslundborg]

And here is a log from DeleteDirectory:

DeleteDirectory("8721056381685")

GetListing("/8721056381685", Auto)
Command:  TYPE I
Status:   Waiting for response to: TYPE I
Response: 200 TYPE is now 8-bit binary [27ms]

OpenDataStreamAsync("MLSD /8721056381685", 0)

OpenPassiveDataStreamAsync(PASV, "MLSD /8721056381685", 0)
Command:  PASV
Status:   Waiting for response to: PASV
Response: 227 Entering Passive Mode (178,237,44,159,118,178) [24ms]
Status:   Connecting to IP #1= ***:30386
Command:  MLSD /8721056381685
Status:   Waiting for response to: MLSD /8721056381685
Response: 150 Accepted data connection [24ms]
Warning:  SSL Buffering disabled because of .NET 5.0 and later
Status:   FTPS authentication successful, lib = .NET SslStream, cipher suite = Tls12 (Aes256, TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384, DiffieHellman, 0) [61ms]
+---------------------------------------+
-----------------------------------------
Status:   Disposing(async) FtpSocketStream(data connection of AsyncFtpClient)

CloseDataStream()
Status:   Waiting for response to: MLSD /8721056381685

[FanDjango]

I need to see a download attempt, can you?

[mattiaslundborg]

# DownloadFile("/Users/myuser/Desktop/8721056381685.wav", "8721056381685/8721056381685.wav", Resume, None)

# OpenRead("8721056381685/8721056381685.wav", Binary, 0, 0, False)

# GetFileSize("8721056381685/8721056381685.wav", −1)
Command:  SIZE 8721056381685/8721056381685.wav
Status:   Waiting for response to: SIZE 8721056381685/8721056381685.wav
Response: 213 42538710 [24ms]
Command:  TYPE I
Status:   Waiting for response to: TYPE I
Response: 200 TYPE is now 8-bit binary [24ms]

# OpenDataStreamAsync("RETR 8721056381685/8721056381685.wav", 0)

# OpenPassiveDataStreamAsync(PASV, "RETR 8721056381685/8721056381685.wav", 0)
Command:  PASV
Status:   Waiting for response to: PASV
Response: 227 Entering Passive Mode (178,237,44,159,151,161) [24ms]
Status:   Connecting to IP #1= ***:38817
Command:  RETR 8721056381685/8721056381685.wav
Status:   Waiting for response to: RETR 8721056381685/8721056381685.wav
Response: 150-Accepted data connection
Response: 150 41541.7 kbytes to download [24ms]
Warning:  SSL Buffering disabled because of .NET 5.0 and later
Status:   FTPS authentication successful, lib = .NET SslStream, cipher suite = Tls12 (Aes256, TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384, DiffieHellman, 0) [61ms]
Status:   Downloaded 0 bytes
Status:   Disposing(async) FtpSocketStream(data connection of AsyncFtpClient)
Status:   Waiting for response to: RETR 8721056381685/8721056381685.wav
Status:   Error encountered downloading file

[FanDjango]

Thanks for that last log, it looks very bad now.

In your original post:

Note - it works perfectly fine with the sync FtpClient, but i need the AsyncFtpClient to send in my cancellationToken.

Then you edited:

Note - I can connect to the FTP successfully but can't do anything after that. I also tried using the FtpClient, but getting the same issue there.

I suppose that SYNC and ASYNC have the same problem, right???

I will write more in the next post...

[mattiaslundborg]

Correct, it worked in the beginning for me when i started using SYNC. Then i changed the code to ASYNC and i started to get the operation timeout problem. Then i changed back to SYNC to test that again - but then i got the same operation timeout problem again. That was why i edited my first comment.

[FanDjango]

Ok. That is very strange behaviour. Are you in a corporate environment with strict firewalls, stateful firewalls etc. or is the server one that you could even restart, or see its loges?

[FanDjango]

It seems that the PASV command gives an IP and PORT to connect to, which succeeds. Then the SSL negotiation, which means some data going back and forth on that connection, succeeds. And then, it seems, the connection drops. Even the control connection becomes dead.

[mattiaslundborg]

I agree, feels strange. No corporate, just me at home. Running an Azure SQL database created in Docker Desktop in my local environment.

[FanDjango]

MLSD - no data received
RETR - no data received
STOR - able to write 3566 bytes to the network, it probably gets stored in a buffer somewhere but does not reach the server.

Aahh! AZURE. In Docker. That's a big gotcha. I have some suggestions.

[FanDjango]

You would need first to verify functionality using a manual FTP client of your choosing, such as WinSCP or FileZilla accessing that server - the AZURE SQL database running in the docker container. Did I get that right?

See if that works, first.

[FanDjango]

I mean, I am not an AZURE knowleagable person - so tell me: Exactly where are you running the client code? And exactly where is the server located?

[mattiaslundborg]

I'm using the app 'Commander One' to access to the FTP manually, it's exactly like FileZilla. I'm able to access it if that is what you meant?

I have a Blazor WASM app, with both client and server project. Server is located in a Docker Container with the image:
"mcr.microsoft.com/azure-sql-edge"

[FanDjango]

Commander One running on the same physical machine as Blazor WASM app? Docker Container also on that physical machine?

[mattiaslundborg]

Well it's all localhost/development environment so everything is from my computer, correct!

I can manually download/upload files to the FTP using Commander One program, but i can't do it using FluentFTP in my c# code

Note: i can also access the FTP using FileZilla

[mattiaslundborg]

I tried restarting my docker container - didn't help

[FanDjango]

With this kind of configuration, if this is all on your machine, I would

1. Install Wireshark and take a trace of the download attempt. I would study that trace and probably know more after that.
2. Perhaps use FluentFTP.GnuTLS instead of the standard .NET SslStream, it produces more log information, but not as good as using wireshark.
3. I would try to see the server logs, very much a hassle if it inside the container.

but i can't do it using FluentFTP in my c# code

Trouble is, that code is also running (as opposed to FileZilla etc.) in a sort of different environment (Blazor? Yuck...) so the comparison is not totally exact.

[FanDjango]

Try an excerpt of your ftp code in a c# console app, first, maybe

[FanDjango]

Is there any chance, even if only once for testing, to try without encryption? Allow this in the server? Let's see if there is a difference.

[FanDjango]

it worked in the beginning for me when i started using SYNC. Then i changed the code to ASYNC and i started to get the operation timeout problem. Then i changed back to SYNC to test that again - but then i got the same operation timeout problem again

I have debugging experience and this is also something you need to worry about: Until you can get it to work again like in the beginning with SYNC, something is still very fishy

A persistent disk full on the server side after a few tests, now nothing works any more?

[FanDjango]

Listen: This kind of problem (with Azure, Docker and other "strange" environments) has plagued us for a long time already. If there is any kind of things I can modify in FluentFTP, not in the Nuget but in special GitHub branches/repos to help diagnose, I am available. I really wonder what makes the connection simply stop , especially as the Ssl Handshake needs at least certain number of transactions on the data connection to succeed.

1. Try unencrypted, if you can. SslStream is slightly finnicky concerning the connection
2. Try FluentFTP.GnuTLS instead of SslStream, it is much more robust.
3. Send me a Wireshark, it is my swiss knife
4. In the end, you might not succeed - many others have tried.

[FanDjango]

Especially two Wireshark traces: 1. The console App which works 2. The fail in the Blazor App
And then to compare those two.... :-)