Ask a Question

Server closes FtpSSL connection after some time

0 votes
by (130 points)
edited

I am using the Ftp and Sftp components of the rebex total pack, all works mostly fine but when I start transfering a lot of files (>5000) with putfile over a FTP SSL Connection the server closes the Connection after some time.

Regardless of wether I use one or two threads for the transfer or even if I use the GUI thread always the same exception is thrown after some time. I can continue the transfer if I close and reopen the connection with the same exception after some time.

Is it possible that there is some "keep alive" logic missing and if not how can I handle the exception without parsing the exception message string - the state of the Ftp Client when the exception occures is not "disconnected" but "reading".

Would that be the right handling for this kind of connection closing to check the Ftp client state for reading? Or is it possible to Monitor the TLS state?

with many thanks in advance, Uwe

from the logfile:

2013-02-26 22:47:02.324 INFO Ftp(5)[10] Command: STOR testdatei.1469
2013-02-26 22:47:02.347 INFO Ftp(6)[11] Command: STOR testdatei.147
2013-02-26 22:47:02.361 INFO Ftp(5)[10] Response: 150 Opening BINARY mode data connection for testdatei.1469
2013-02-26 22:47:02.361 DEBUG Ftp(5)[10] Info: Upgrading data connection to TLS/SSL.
2013-02-26 22:47:02.362 DEBUG Ftp(5)[10] TLS: Data connection: Asking the server to resume session ID: 
 0000 |0D-37-C2-B6-E4-37-98-DF FF-9F-11-D6-C8-43-BE-2D| .7...7.......C.-
 0010 |ED-86-51-FC-3D-F7-61-9A E4-43-AA-79-BF-62-F3-B9| ..Q.=.a..C.y.b..
2013-02-26 22:47:02.362 INFO Ftp(5)[10] TLS: Data connection: State StateChange:Negotiating
2013-02-26 22:47:02.362 DEBUG Ftp(5)[10] TLS: Data connection: HandshakeMessage:ClientHello was sent.
2013-02-26 22:47:02.382 INFO Ftp(6)[11] Response: 150 Opening BINARY mode data connection for testdatei.147
2013-02-26 22:47:02.383 DEBUG Ftp(6)[11] Info: Upgrading data connection to TLS/SSL.
2013-02-26 22:47:02.384 DEBUG Ftp(6)[11] TLS: Data connection: Asking the server to resume session ID: 
 0000 |08-59-CD-22-0D-06-57-97 43-7D-1E-80-98-01-73-68| .Y."..W.C}....sh
 0010 |FA-5D-BF-8E-BE-A0-98-7B A0-E5-49-4C-08-E6-D7-C3| .].....{..IL....
2013-02-26 22:47:02.384 INFO Ftp(6)[11] TLS: Data connection: State StateChange:Negotiating
2013-02-26 22:47:02.384 DEBUG Ftp(6)[11] TLS: Data connection: HandshakeMessage:ClientHello was sent.
2013-02-26 22:47:02.399 DEBUG Ftp(5)[10] TLS: Data connection: HandshakeMessage:ServerHello was received.
2013-02-26 22:47:02.399 INFO Ftp(5)[10] TLS: Data connection: Info Info:ResumingCachedSession
2013-02-26 22:47:02.400 DEBUG Ftp(5)[10] TLS: Data connection: CipherSpec:ChangeCipherSpec was received.
2013-02-26 22:47:02.400 DEBUG Ftp(5)[10] TLS: Data connection: HandshakeMessage:Finished was received.
2013-02-26 22:47:02.400 DEBUG Ftp(5)[10] TLS: Data connection: CipherSpec:ChangeCipherSpec was sent.
2013-02-26 22:47:02.401 DEBUG Ftp(5)[10] TLS: Data connection: HandshakeMessage:Finished was sent.
2013-02-26 22:47:02.401 INFO Ftp(5)[10] TLS: Data connection: State StateChange:Secured
2013-02-26 22:47:02.401 INFO Ftp(5)[10] TLS: Data connection: Connection secured using cipher: TLS 1.0, RSA with ephemeral Diffie-Hellman, 128bit AES in CBC mode, SHA1
2013-02-26 22:47:02.401 DEBUG Ftp(5)[10] TLS: Data connection: Session ID: 
 0000 |0D-37-C2-B6-E4-37-98-DF FF-9F-11-D6-C8-43-BE-2D| .7...7.......C.-
 0010 |ED-86-51-FC-3D-F7-61-9A E4-43-AA-79-BF-62-F3-B9| ..Q.=.a..C.y.b..
2013-02-26 22:47:02.401 DEBUG Ftp(5)[10] Info: Data connection upgraded to TLS/SSL.
2013-02-26 22:47:02.402 DEBUG Ftp(5)[10] Info: Closing uploading data connection.
2013-02-26 22:47:02.402 DEBUG Ftp(5)[10] TLS: Data connection: Closing TLS socket.
2013-02-26 22:47:02.402 INFO Ftp(5)[10] TLS: Data connection: Alert Alert:Alert was sent.
2013-02-26 22:47:02.402 INFO Ftp(5)[10] TLS: Data connection: State StateChange:Closed
2013-02-26 22:47:02.402 DEBUG Ftp(5)[10] Info: Waiting for data transfer ending message.
2013-02-26 22:47:02.420 DEBUG Ftp(6)[11] TLS: Data connection: HandshakeMessage:ServerHello was received.
2013-02-26 22:47:02.420 INFO Ftp(6)[11] TLS: Data connection: Info Info:ResumingCachedSession
2013-02-26 22:47:02.420 DEBUG Ftp(6)[11] TLS: Data connection: CipherSpec:ChangeCipherSpec was received.
2013-02-26 22:47:02.420 DEBUG Ftp(6)[11] TLS: Data connection: HandshakeMessage:Finished was received.
2013-02-26 22:47:02.421 DEBUG Ftp(6)[11] TLS: Data connection: CipherSpec:ChangeCipherSpec was sent.
2013-02-26 22:47:02.421 DEBUG Ftp(6)[11] TLS: Data connection: HandshakeMessage:Finished was sent.
2013-02-26 22:47:02.421 INFO Ftp(6)[11] TLS: Data connection: State StateChange:Secured
2013-02-26 22:47:02.421 INFO Ftp(6)[11] TLS: Data connection: Connection secured using cipher: TLS 1.0, RSA with ephemeral Diffie-Hellman, 128bit AES in CBC mode, SHA1
2013-02-26 22:47:02.421 DEBUG Ftp(6)[11] TLS: Data connection: Session ID: 
 0000 |08-59-CD-22-0D-06-57-97 43-7D-1E-80-98-01-73-68| .Y."..W.C}....sh
 0010 |FA-5D-BF-8E-BE-A0-98-7B A0-E5-49-4C-08-E6-D7-C3| .].....{..IL....
2013-02-26 22:47:02.421 DEBUG Ftp(6)[11] Info: Data connection upgraded to TLS/SSL.
2013-02-26 22:47:02.422 DEBUG Ftp(6)[11] Info: Closing uploading data connection.
2013-02-26 22:47:02.422 DEBUG Ftp(6)[11] TLS: Data connection: Closing TLS socket.
2013-02-26 22:47:02.422 INFO Ftp(6)[11] TLS: Data connection: Alert Alert:Alert was sent.
2013-02-26 22:47:02.422 INFO Ftp(6)[11] TLS: Data connection: State StateChange:Closed
2013-02-26 22:47:02.422 DEBUG Ftp(6)[11] Info: Waiting for data transfer ending message.
2013-02-26 22:47:02.449 INFO Ftp(5)[10] Response: 226 Transfer complete
2013-02-26 22:47:02.449 DEBUG Ftp(5)[10] Info: Data transfer ended.
2013-02-26 22:47:02.449 DEBUG Ftp(5)[10] Info: Transfer ended successfully.
2013-02-26 22:47:02.449 DEBUG Ftp(5)[10] Info: Data connection closed.
2013-02-26 22:47:02.449 DEBUG Ftp(5)[10] Info: Starting data transfer.
2013-02-26 22:47:02.450 INFO Ftp(5)[10] Command: PASV
2013-02-26 22:47:02.473 INFO Ftp(6)[11] Response: 226 Transfer complete
2013-02-26 22:47:02.473 DEBUG Ftp(6)[11] Info: Data transfer ended.
2013-02-26 22:47:02.473 DEBUG Ftp(6)[11] Info: Transfer ended successfully.
2013-02-26 22:47:02.474 DEBUG Ftp(6)[11] Info: Data connection closed.
2013-02-26 22:47:02.474 DEBUG Ftp(6)[11] Info: Starting data transfer.
2013-02-26 22:47:02.474 INFO Ftp(6)[11] Command: PASV
2013-02-26 22:47:02.484 INFO Ftp(5)[10] Response: 227 Entering Passive Mode (80,237,132,78,195,175).
2013-02-26 22:47:02.485 DEBUG Ftp(5)[10] Info: Establishing data connection to 80.237.132.78:50095.
2013-02-26 22:47:02.564 INFO Ftp(5)[10] Command: STOR testdatei.1470
2013-02-26 22:47:02.564 DEBUG Ftp(6)[11] TLS: TLS socket error, 0 bytes of data were received.
2013-02-26 22:47:02.595 INFO Ftp(5)[10] Response: 150 Opening BINARY mode data connection for testdatei.1470
2013-02-26 22:47:02.596 DEBUG Ftp(5)[10] Info: Upgrading data connection to TLS/SSL.
2013-02-26 22:47:02.596 DEBUG Ftp(6)[11] TLS: TLS socket was closed: System.Net.Sockets.SocketException (0x80004005): Eine vorhandene Verbindung wurde vom Remotehost geschlossen
   bei System.Net.Sockets.Socket.Receive(Byte[] buffer, Int32 offset, Int32 size, SocketFlags socketFlags)
   bei Rebex.Net.ProxySocket.Receive(Byte[] buffer, Int32 offset, Int32 size, SocketFlags socketFlags)
   bei gbMKS.1UaphuZ.1oSQZR(Int32 , Boolean )
   bei gbMKS.1UaphuZ.JZ4YLZ()
   bei gbMKS.1UaphuZ.1rsOcLZ()
2013-02-26 22:47:02.597 DEBUG Ftp(5)[10] TLS: Data connection: Asking the server to resume session ID: 
 0000 |0D-37-C2-B6-E4-37-98-DF FF-9F-11-D6-C8-43-BE-2D| .7...7.......C.-
 0010 |ED-86-51-FC-3D-F7-61-9A E4-43-AA-79-BF-62-F3-B9| ..Q.=.a..C.y.b..
2013-02-26 22:47:02.597 INFO Ftp(5)[10] TLS: Data connection: State StateChange:Negotiating
2013-02-26 22:47:02.597 DEBUG Ftp(5)[10] TLS: Data connection: HandshakeMessage:ClientHello was sent.
2013-02-26 22:47:02.598 INFO Ftp(6)[11] TLS: Info Info:UnexpectedException
2013-02-
Applies to: Rebex FTP/SSL
by (58.9k points)
edited

From the log it looks as though the data connection simply "died". You could try the Flush method as suggested below. It could help to switch the Ftp.State from Reading back to Ready and then you could go on with file uploads. Please give it a try and let us know whether it helped to solve the issue:

        Ftp ftp = new Ftp();
        // connect & login
        string fileName = "fileName";

        try
        {
            ftp.PutFile(fileName, fileName);
        }
        catch (TlsException ex)
        {
            if (ftp.State != FtpState.Reading)
                throw ex;

            // try to get back data connection
            ftp.Flush(10000);

            if (ftp.State != FtpState.Ready)
                throw ex;

            ftp.PutFile(fileName, fileName);
        }

        ftp.Disconnect();
by (130 points)
edited

Hello Tomáš,

thanks for your quick answer but in my tests Ftp.flush never recovered the connection and always throws a new FtpException.

The only solution for me is to reconnect to the server. This disconnection problem occurs with every SSL Server I tried and always! The only difference is the time after which the connection is closed as Tom Henrichs also mentioned.

Therefore I come round to Tom's opinion that this is a problem with the FtpClient component and perhaps it is only a time out problem that you can fix easily - or?

with best regards for your help, Uwe

2 Answers

0 votes
by (140 points)
edited

I'm having the same issue, which is fairly easy to recreate:

  1. Install FileZilla Server
  2. Run the following code:
Ftp ftp = new Ftp();
ftp.Connect("localhost", SslMode.Explicit);
ftp.Login("user", "password");
int i = 0;
while (true)
{
    Console.WriteLine(++i);
    ftp.PutFile("thefile.txt", "thefiles.txt");
}

The loop throws the exception Uwe mentioned after a few hundred iterations.

by (58.9k points)
edited

Thank you for reporting the problem - we were able to replicate it. It looks as though FileZilla Server is imposing some restriction on number of files transmitted - the server closes the connection every 334th file upload.

You can use this workaround:

        Ftp ftp = new Ftp();
        ftp.Connect("localhost", SslMode.Explicit);
        ftp.Login("user", "pass");

        try
        {
            ftp.PutFile(@"c:\temp\file.txt", "file.txt");
        }
        catch (TlsException ex1)
        {
            if (ftp.State != FtpState.Reading)
                throw ex1;

            try
            {
                ftp.Flush(0);
            }
            catch (FtpException ex2)
            {
                if (ex2.Status != FtpExceptionStatus.ConnetionClosed)
                    throw ex2;

                if (!ftp.GetConnectionState().Connected)
                // reconnect, login and continue
                {
                    ftp.Connect("localhost", SslMode.Explicit);
                    ftp.Login("user", "pass");
                }
            }
            ftp.PutFile(@"c:\temp\file.txt", "file.txt");
        }

        ftp.Disconnect();
by (58.9k points)
edited

Thank you, please have a look at the answer below.

by (140 points)
edited

That's more or less what I do right now. But the problem is not limited to Filezilla, it occurs with each ftps-Server I tried (although the number of files transferrable differs from server to server):

  • hosteurope.de (German ISP)
  • QNAP NAS FTP Server (proftpd)
  • Mac OSX Server
  • Debian running proftpd

I can live with the reconnection workaround right now. But I'd really appreciate, if your developement team could look into the matter.

by (58.9k points)
edited

Hello Tom, sorry we will not add automatic reconnection support into Rebex FTP/SSL component - the reason is that we do not want to save usernames, passwords, or even private keys, etc within the FTP/SSL nor other Rebex components. Sorry!

by (148k points)
edited

However, we will still look into the issue for sure!

+1 vote
by (58.9k points)
edited

Hello Uwe, in some cases the Ftp.Flush() might really recover the data connection, so that's why we included it here.

Clearly, we see your point - it is really possible that a majority of servers will disconnect a client, if it simply sends too many requests - this is a form of server defense.

Most clients handle this situation by reconnecting and this is recommended solution for programmers using Rebex FTP/SSL component. It is not caused by a timeout, it is simply caused by the server disconnecting the client.

However, due to our good practice of not saving or storing our clients' usernames, passwords, etc anywhere in Rebex components we cannot add automatic reconnection support into FTP /SSL component. Sorry.

EDIT:

In fact we have tested FileZilla Server with FileZilla client and the server behaves in the same way - i.e. it disconnects the client after a few hundred uploads. FileZilla client handles this also by reconnecting and uploading the file again.

Do you know any Ftp client that is able to transfer thousends of files without being disconnected by one of the servers you reported?

by (130 points)
edited

Hello Tomáš,

you are right - I don't know a ftp client which is not disconnected from the server: I didn't got into detail how filezilla handles the situation and I never wanted to go into detail of the ftp/ssl socket protocol level :-)

I am living fine with reconnecting to the server.

best wishes, Uwe

...