0 votes
by (1.2k points)

Connecting through FTP with SSL, our customer gets the following error message:

450 Transfer aborted. Link to file server lost

Here is the full log.

I'm rather clueless. Google did not show me any meaningful results.

Do you have any idea what could be the issue here?

Applies to: Rebex FTP/SSL

1 Answer

+1 vote
by (144k points)
  • We have not seen this error yet. However, it actually comes from the FTP server, so it would be useful to check out corresponding entries in the server's log files, to see why it reported this error to the FTP client.

  • It looks like you use TLS 1.3 already. This is still a new protocol, and interoperability issues are still being sorted out, both by Rebex and other vendors. To determine whether this issue has anything to do with TLS 1.3, it might be useful to temporarily switch to TLS 1.2 to see whether this makes this issue disappear.

  • Additionally, it might be useful to try using the latest version of Rebex FTP/SSL, 2020 R3, with many improvements in the TLS 1.3 core.

by (1.2k points)
Thanks a lot, Lukas, will do so.
by (1.9k points)
I had same error : ASUSTOR Ftp Server & QNAP FTP Server
After abort transfer, server response to the previous request command.
The same problem appears whether Abort succeeds or fails with Timeout.

2020-09-29 13:41:36.291 INFO FileLogWriter(1)[13] Info: Assembly: Rebex.Common 2020 R3 for .NET 4.0-4.8
2020-09-29 13:41:36.296 INFO FileLogWriter(1)[13] Info: Platform: Windows 10.0.18363 64-bit; CLR: 4.0.30319.42000
2020-09-29 13:41:36.359 INFO RaiFtp(1)[13] Info: Assembly: Rebex.Ftp 2020 R3 for .NET 4.0-4.8
2020-09-29 13:41:36.359 INFO RaiFtp(1)[13] Info: Platform: Windows 10.0.18363 64-bit; CLR: 4.0.30319.42000
2020-09-29 13:41:36.361 INFO RaiFtp(1)[13] Info: Using proxy none.
2020-09-29 13:41:36.435 DEBUG RaiFtp(1)[13] Info: Connection succeeded.
2020-09-29 13:41:36.470 INFO RaiFtp(1)[13] Response: 220 ProFTPD 1.3.4a Server (ProFTPD) [::ffff:192.168.200.44]
2020-09-29 13:41:36.508 INFO RaiFtp(1)[13] Command: AUTH TLS
2020-09-29 13:41:36.511 INFO RaiFtp(1)[13] Response: 234 AUTH TLS successful
2020-09-29 13:41:36.516 DEBUG RaiFtp(1)[13] Info: Upgrading control connection to TLS/SSL.
2020-09-29 13:41:36.874 DEBUG RaiFtp(1)[13] TLS: Using TLS 1.3 core.
2020-09-29 13:41:38.426 DEBUG RaiFtp(1)[13] TLS: Generating key shares.
2020-09-29 13:41:38.756 DEBUG RaiFtp(1)[13] TLS: Key shares generated (secp256r1, secp384r1, secp521r1, x25519).
2020-09-29 13:41:39.979 DEBUG RaiFtp(1)[14] TLS: Using modern transport layer.
2020-09-29 13:41:40.012 DEBUG RaiFtp(1)[14] TLS: HandshakeMessage:ClientHello was sent.
2020-09-29 13:41:40.375 DEBUG RaiFtp(1)[15] TLS: HandshakeMessage:ServerHello was received.
2020-09-29 13:41:41.878 INFO RaiFtp(1)[13] TLS: Preferred TLS version: TLS 1.3, server is asking for TLS 1.2.
2020-09-29 13:41:41.927 INFO RaiFtp(1)[13] TLS: Warning: SSL 3.0 has been deprecated. According to RFC 7568, it must no longer be used.
2020-09-29 13:41:41.947 DEBUG RaiFtp(1)[13] TLS: Enabled cipher suites: 0x0C1FFFFFFFF4F666.
2020-09-29 13:41:41.947 DEBUG RaiFtp(1)[13] TLS: Applicable cipher suites: 0x0C1FFFFFFFF4F666.
2020-09-29 13:41:41.991 DEBUG RaiFtp(1)[13] TLS: HandshakeMessage:ClientHello was sent.
2020-09-29 13:41:42.118 DEBUG RaiFtp(1)[13] TLS: HandshakeMessage:ServerHello was received.
2020-09-29 13:41:42.123 INFO RaiFtp(1)[13] TLS: Negotiating TLS 1.2, RSA with ephemeral Diffie-Hellman, AES with 256-bit key in GCM mode, AEAD.
2020-09-29 13:41:42.130 DEBUG RaiFtp(1)[13] TLS: The server supports secure renegotiation.
2020-09-29 13:41:42.156 DEBUG RaiFtp(1)[19] TLS: HandshakeMessage:Certificate was received.
2020-09-29 13:41:42.284 DEBUG RaiFtp(1)[18] TLS: HandshakeMessage:ServerKeyExchange was received.
2020-09-29 13:41:42.284 DEBUG RaiFtp(1)[18] TLS: HandshakeMessage:ServerHelloDone was received.
2020-09-29 13:41:42.299 DEBUG RaiFtp(1)[18] TLS: Verifying server certificate ('E=support@asustor.com, CN=Support, OU=NAS, O=Asustor, L=Taipei, S=Taiwan, C=TW').
2020-09-29 13:41:42.306 DEBUG RaiFtp(1)[18] TLS: Certificate verification result: Accept
2020-09-29 13:41:42.317 DEBUG RaiFtp(1)[18] TLS: Verifying server key exchange signature.
2020-09-29 13:41:42.457 DEBUG RaiFtp(1)[18] TLS: Received ephemeral Diffie-Hellman prime.
2020-09-29 13:41:42.913 DEBUG RaiFtp(1)[18] TLS: Ephemeral Diffie-Hellman prime size is 1024 bits (minimum allowed size is 1024 bits).
2020-09-29 13:41:42.950 DEBUG RaiFtp(1)[18] TLS: HandshakeMessage:ClientKeyExchange was sent.
2020-09-29 13:41:43.046 DEBUG RaiFtp(1)[18] TLS: CipherSpec:ChangeCipherSpec was sent.
2020-09-29 13:41:43.053 DEBUG RaiFtp(1)[18] TLS: HandshakeMessage:Finished was sent.
2020-09-29 13:41:43.150 DEBUG RaiFtp(1)[24] TLS: CipherSpec:ChangeCipherSpec was received.
2020-09-29 13:41:43.158 DEBUG RaiFtp(1)[24] TLS: HandshakeMessage:Finished was received.
2020-09-29 13:41:43.171 INFO RaiFtp(1)[24] TLS: Connection secured using cipher: TLS 1.2, RSA with ephemeral Diffie-Hellman, AES with 256-bit key in GCM mode, AEAD.

....


2020-09-29 13:41:50.715 DEBUG RaiFtp(2)[42] Info: Data transfer started.
2020-09-29 13:41:50.761 INFO RaiFtp(2)[42] Info: Aborting operation.
2020-09-29 13:41:50.789 DEBUG RaiFtp(2)[42] Info: Aborting downloading data connection.
2020-09-29 13:41:50.794 INFO RaiFtp(2)[42] Info: Aborting download.
2020-09-29 13:41:50.801 INFO RaiFtp(2)[42] Command: ABOR
2020-09-29 13:41:56.805 INFO RaiFtp(2)[42] Info: Timing out because of an abort method.
2020-09-29 13:41:56.833 DEBUG RaiFtp(2)[42] Info: Abort failed or ignored.
2020-09-29 13:41:56.833 DEBUG RaiFtp(2)[42] Info: Unable to abort, closing data connection instead.
2020-09-29 13:41:56.833 DEBUG RaiFtp(2)[42] TLS: Data connection: Closing TLS socket.
2020-09-29 13:41:56.833 DEBUG RaiFtp(2)[42] TLS: Data connection: Alert:CloseNotify was sent.
2020-09-29 13:41:56.839 INFO RaiFtp(2)[42] Response: 226 Abort successful
2020-09-29 13:41:56.839 INFO RaiFtp(2)[42] Response: 426 Transfer aborted. Data connection closed
2020-09-29 13:41:56.928 ERROR RaiFtp(2)[42] Info: Rebex.Net.FtpException: The operation was aborted.
   위치: Rebex.Net.Ftp.sswbh(String p0, Boolean p1, Stream p2, Int64 p3, String p4, gcays p5)
2020-09-29 13:41:56.948 INFO RaiFtp(2)[42] Command: CWD /Home/Test
2020-09-29 13:41:56.948 INFO RaiFtp(2)[42] Response: 450 Transfer aborted. Link to file server lost
2020-09-29 13:41:56.968 ERROR RaiFtp(2)[42] Info: Rebex.Net.FtpException: Transfer aborted. Link to file server lost (450).
   위치: Rebex.Net.Ftp.dwzoq(Int32 p0, Boolean p1)
   위치: Rebex.Net.Ftp.qdils(String p0, gcays p1)
2020-09-29 13:41:56.984 INFO RaiFtp(2)[42] Command: CWD /Home/Test
2020-09-29 13:41:56.984 INFO RaiFtp(2)[42] Response: 250 CWD command successful
2020-09-29 13:41:56.984 DEBUG RaiFtp(2)[42] Info: Starting data transfer.
2020-09-29 13:41:56.985 INFO RaiFtp(2)[42] Command: PASV
2020-09-29 13:41:56.991 INFO RaiFtp(2)[42] Response: 250 CWD command successful
2020-09-29 13:41:57.007 DEBUG RaiFtp(2)[42] Info: Error while starting data transfer: Rebex.Net.FtpException: Unable to parse server response to PASV command.
   위치: rabtx.itxfc.izbwl(EndPoint p0, String p1, String p2)
   위치: Rebex.Net.Ftp.ptdlv()
   위치: Rebex.Net.Ftp.qqgif(String p0, Boolean p1, qzkpn p2, gcays p3, Int64 p4, FtpTransferState p5)
2020-09-29 13:41:57.007 DEBUG RaiFtp(2)[42] Info: Error while initializing data connection.
2020-09-29 13:41:57.024 ERROR RaiFtp(2)[42] Info: Rebex.Net.FtpException: Unable to parse server response to PASV command.
   위치: rabtx.itxfc.izbwl(EndPoint p0, String p1, String p2)
   위치: Rebex.Net.Ftp.ptdlv()
   위치: Rebex.Net.Ftp.qqgif(String p0, Boolean p1, qzkpn p2, gcays p3, Int64 p4, FtpTransferState p5)
   위치: Rebex.Net.Ftp.sswbh(String p0, Boolean p1, Stream p2, Int64 p3, String p4, gcays p5)
2020-09-29 13:41:57.036 ERROR RaiFtp(2)[42] Info: Rebex.Net.FtpException: Unable to parse server response to PASV command.
   위치: rabtx.itxfc.izbwl(EndPoint p0, String p1, String p2)
   위치: Rebex.Net.Ftp.ptdlv()
   위치: Rebex.Net.Ftp.qqgif(String p0, Boolean p1, qzkpn p2, gcays p3, Int64 p4, FtpTransferState p5)
   위치: Rebex.Net.Ftp.sswbh(String p0, Boolean p1, Stream p2, Int64 p3, String p4, gcays p5)
by (144k points)
The error is the same, but the issue seems to be different. It looks like a server-side issue, because the server responded with 3 separate responses to 2 commands (the transfer command and ABOR command). To work around the issue, call Ftp.Flush method after aborting a transfer with this server. Alternatively, if the server is under your control, consider upgrading it. ProFTPD 1.3.4a is already more than 8 years old.
by (1.9k points)
Thanks you very much.
by (1.2k points)
3 and a half years later, we still get this error, as soon as TLS 1.3 is activated.

Here is a recent log:
https://pastebin.com/AAxTAh9L

The error does _not_ occur if only TLS 1.2 is active.

Ist there any chance to not get this error even if TLS 1.3 is active?
by (144k points)
Thanks for confirming that this only occurs when TLS 1.3 is in use. Until now, we did not actually know. And because no other customers reported anything similar, we had no way to investigate this until now. Moreover, the response by Lanopk seems to suggest this might not be related to TLS 1.3 at all.

We'll now review the data channel closure logic in Rebex FTP with TLS 1.3, and we don't find any possible causes, we will enhance the logging a bit to find out more. We are unable to reproduce this issue with any of the TLS 1.3-capable FTP servers in our test lab, so we will need your help to determine the cause.

Also, if possible, check out corresponding entries in the server's log files - that might provide some clues as well.
by (1.2k points)
Thanks, Lukas.

The server is at a big German hosting company, https://www.hosteurope.de, and the issue was reported by several customers of us.

So currently I do not have a own webspace at Host Europe.

If you do think this might help, I could purchase some hosting package for a few months and give you FTP access to try your tests against this server.

I strongly assume that Host Europe will _not_ give us access to their FTP server log files at all.
by (1.9k points)
edited by
hello.

I hope my case helps you.

For reference, some servers may respond too late for uploads.
So, if the client closes the data channel before the server cleans the upload data, you may be getting a 450 error. (especially IIS)

So after uploading to ftp stream, after doing ftpstream.Flush()
Execute the code below:

using (var ftpStream = ftp.GetUploadStream(filename))
{
  // todo upload
  ftpStream.Flush();
}

for (int r = 0; r < 30; r++)
{
if (ftp.State == FtpState.Ready)
{
break;
}
Thread.Sleep(10);
DEBUGLOG($"UPLOAD FTP STATE : {ftp.State}");
}

Or, after flushing, it might be a good idea to give it some time.
by (144k points)
Don't purchase a hosting package yet - we'll first try some tweaks. If that doesn't lead anywhere, purchasing the package might be a good option, and I'm sure we can give you a discount as a compensation for your next renewal.

For now, try enabling these options before connecting to the server:

ftp.Settings.PauseBeforeUploadClose = true;
ftp.Settings.EnableBrokenShutdownWorkaround = true;

In case these don't have any effect on the issue, please send us a new communication log (at the same verbosity as the last one).
by (1.2k points)
Just set these two properties to "true" and tried again with active TLS 1.3.

And it really works now, without any error messages. Don't know whether this is any slower now, but at least it works.

Thanks a million times for your help, Lukas!
by (144k points)
Great, thanks for testing! Try removing the PauseBeforeUploadClose option now (or set it to false). I guess that the other option is what's important. It should rather be called something like "Enable very strict TLS 1.3 closure alert handling", and I think we should make it the default in future version. Thanks for bringing this to our attention!
by (1.2k points)
Thanks again. Setting only the "EnableBrokenShutdownWorkaround" to "true" works just great with TLS 1.3.
...