Error "Secure connection was closed by the remote connection end"

Question

Error "Secure connection was closed by the remote connection end"

asked Aug 9, 2013 by jonataspc (160 points)
edited Aug 20, 2013

Hi,

I am facing the described error. I have already tried to increase the timeout but no success. It happens exactly 5 minutes after the last message. Although it is trial, i will buy soon.

How can I fix it?

LOG:

http://pastebin.com/9hAVHkHS

Welcome to Rebex FTP!
09:56:39.702 Info Info: Connecting to XXXXXX:21 using Ftp 4.0.4959.0 (trial version).
09:56:39.702 Info Info: Using proxy none.
09:56:39.780 Info Response: 220 
09:56:39.796 Info Command: AUTH TLS
09:56:39.811 Info Response: 234 AUTH command ok. Expecting TLS Negotiation.
09:56:39.842 Info TLS: State StateChange:Negotiating
09:56:41.374 Info TLS: Performing client certificate authentication.
09:56:41.592 Info TLS: State StateChange:Secured
09:56:41.592 Info TLS: Connection secured using cipher: TLS 1.0, RSA, 128bit AES in CBC mode, SHA1
09:56:41.608 Info Command: USER USR
09:56:41.624 Info Response: 331 Password required for USR.
09:56:41.624 Info Command: PASS **********
09:56:41.671 Info Response: 230 User logged in.
09:56:41.671 Info Command: FEAT
09:56:41.686 Info Response: 211-Extended features supported:
09:56:41.842 Info Response:  LANG EN*
09:56:41.842 Info Response:  UTF8
09:56:41.842 Info Response:  AUTH TLS;TLS-C;SSL;TLS-P;
09:56:41.842 Info Response:  PBSZ
09:56:41.842 Info Response:  PROT C;P;
09:56:41.842 Info Response:  CCC
09:56:41.842 Info Response:  HOST
09:56:41.842 Info Response:  SIZE
09:56:41.858 Info Response:  MDTM
09:56:41.858 Info Response:  REST STREAM
09:56:41.858 Info Response: 211 END
09:56:41.858 Info Command: OPTS UTF8 ON
09:56:41.874 Info Response: 200 OPTS UTF8 command successful - UTF8 encoding now ON.
09:56:41.889 Info Command: PBSZ 0
09:56:41.921 Info Response: 200 PBSZ command successful.
09:56:41.921 Info Command: PROT P
09:56:41.936 Info Response: 200 PROT command successful.
09:56:41.936 Info Command: TYPE A
09:56:41.952 Info Response: 200 Type set to A.
09:56:41.967 Info Command: PASV
09:56:41.983 Info Response: 227 Entering Passive Mode (200,185,17,156,19,171).
09:56:41.999 Info Command: LIST
09:56:42.030 Info Response: 125 Data connection already open; Transfer starting.
09:56:42.030 Info TLS: Data connection: State StateChange:Negotiating
09:56:42.452 Info TLS: Data connection: Performing client certificate authentication.
09:56:42.686 Info TLS: Data connection: State StateChange:Secured
09:56:42.686 Info TLS: Data connection: Connection secured using cipher: TLS 1.0, RSA, 128bit AES in CBC mode, SHA1
09:56:42.686 Info Response: 226 Transfer complete.
09:56:42.717 Info TLS: Data connection: Alert Alert:Alert was received.
09:56:42.717 Info TLS: Data connection: Alert Alert:Alert was sent.
09:56:42.717 Info TLS: Data connection: State StateChange:Closed
09:56:42.749 Info Command: PWD
09:56:42.764 Info Response: 257 "/" is current directory.
09:56:45.217 Info Command: CWD CARGA
09:56:45.233 Info Response: 250 CWD command successful.
09:56:45.233 Info Command: PASV
09:56:45.264 Info Response: 227 Entering Passive Mode (200,185,17,156,19,178).
09:56:45.264 Info Command: LIST
09:56:45.311 Info Response: 125 Data connection already open; Transfer starting.
09:56:45.311 Info TLS: Data connection: State StateChange:Negotiating
09:56:45.358 Info TLS: Data connection: Info Info:ResumingCachedSession
09:56:45.358 Info TLS: Data connection: State StateChange:Secured
09:56:45.358 Info TLS: Data connection: Connection secured using cipher: TLS 1.0, RSA, 128bit AES in CBC mode, SHA1
09:56:45.592 Info TLS: Data connection: Alert Alert:Alert was received.
09:56:45.592 Info TLS: Data connection: Alert Alert:Alert was sent.
09:56:45.592 Info TLS: Data connection: State StateChange:Closed
09:56:45.608 Info Response: 226 Transfer complete.
09:56:45.608 Info Command: PWD
09:56:45.624 Info Response: 257 "/CARGA" is current directory.
09:56:49.546 Info Batch: Calling Download(string = 'filename.txt', string = 'C:\', TraversalMode = 'Recursive', TransferMethod = 'Copy', ActionOnExistingFiles = 'ThrowException').
09:56:49.592 Info Command: PWD
09:56:49.608 Info Response: 257 "/CARGA" is current directory.
09:56:49.608 Info Command: TYPE I
09:56:49.639 Info Response: 200 Type set to I.
09:56:49.639 Info Command: MDTM .
09:56:49.671 Info Response: 550 The specified path is invalid. 
09:56:49.671 Info Command: SIZE .
09:56:49.686 Info Response: 550 Access is denied. 
09:56:49.686 Info Command: MDTM filename.txt
09:56:49.717 Info Response: 213 20130809083928
09:56:49.717 Info Command: SIZE filename.txt
09:56:49.749 Info Response: 213 228584328
09:56:51.280 Info Command: PASV
09:56:51.296 Info Response: 227 Entering Passive Mode (200,185,17,156,19,141).
09:56:51.311 Info Command: RETR filename.txt
09:56:51.327 Info Response: 150 Opening BINARY mode data connection.
09:56:51.327 Info TLS: Data connection: State StateChange:Negotiating
09:56:51.467 Info TLS: Data connection: Info Info:ResumingCachedSession
09:56:51.467 Info TLS: Data connection: State StateChange:Secured
09:56:51.467 Info TLS: Data connection: Connection secured using cipher: TLS 1.0, RSA, 128bit AES in CBC mode, SHA1
10:01:51.389 Info TLS: Data connection: Alert Alert:Alert was sent.
10:01:51.389 Info TLS: Data connection: State StateChange:Closed
10:01:51.405 Error Info: Error while reading data: Rebex.Net.TlsException: Secure connection was closed by the remote connection end. ---> System.Net.Sockets.SocketException: An existing connection was forcibly closed by the remote host
   at System.Net.Sockets.Socket.Receive(Byte[] buffer, Int32 offset, Int32 size, SocketFlags socketFlags)
   at Rebex.Net.ProxySocket.Receive(Byte[] buffer, Int32 offset, Int32 size, SocketFlags socketFlags)
   at Rebex.Net.CZ.DD(Int32 A, Boolean B)
   at Rebex.Net.CZ.ED()
   at Rebex.Net.CZ.GD()
   --- End of inner exception stack trace ---
   at Rebex.Net.CZ.GD()
   at Rebex.Net.TlsSocket.Poll(Int32 microSeconds, SocketSelectMode mode)
   at Rebex.Net.QJ.TC(Byte[] A, Int32 B, Int32 C)
   at Rebex.Net.QJ.Read(Byte[] buffer, Int32 offset, Int32 count)
10:01:51.405 Error Info: Rebex.Net.TlsException: Secure connection was closed by the remote connection end. ---> System.Net.Sockets.SocketException: An existing connection was forcibly closed by the remote host
   at System.Net.Sockets.Socket.Receive(Byte[] buffer, Int32 offset, Int32 size, SocketFlags socketFlags)
   at Rebex.Net.ProxySocket.Receive(Byte[] buffer, Int32 offset, Int32 size, SocketFlags socketFlags)
   at Rebex.Net.CZ.DD(Int32 A, Boolean B)
   at Rebex.Net.CZ.ED()
   at Rebex.Net.CZ.GD()
   --- End of inner exception stack trace ---
   at Rebex.Net.CZ.GD()
   at Rebex.Net.TlsSocket.Poll(Int32 microSeconds, SocketSelectMode mode)
   at Rebex.Net.QJ.TC(Byte[] A, Int32 B, Int32 C)
   at Rebex.Net.QJ.Read(Byte[] buffer, Int32 offset, Int32 count)
   at Rebex.Net.XI.Read(Byte[] buffer, Int32 offset, Int32 count)
   at Rebex.Net.Ftp.VM(String A, Boolean B, Stream C, Int64 D, String E, WG H)
10:01:51.405 Error Info: Rebex.Net.TlsException: Secure connection was closed by the remote connection end. ---> System.Net.Sockets.SocketException: An existing connection was forcibly closed by the remote host
   at System.Net.Sockets.Socket.Receive(Byte[] buffer, Int32 offset, Int32 size, SocketFlags socketFlags)
   at Rebex.Net.ProxySocket.Receive(Byte[] buffer, Int32 offset, Int32 size, SocketFlags socketFlags)
   at Rebex.Net.CZ.DD(Int32 A, Boolean B)
   at Rebex.Net.CZ.ED()
   at Rebex.Net.CZ.GD()
   --- End of inner exception stack trace ---
   at Rebex.Net.CZ.GD()
   at Rebex.Net.TlsSocket.Poll(Int32 microSeconds, SocketSelectMode mode)
   at Rebex.Net.QJ.TC(Byte[] A, Int32 B, Int32 C)
   at Rebex.Net.QJ.Read(Byte[] buffer, Int32 offset, Int32 count)
   at Rebex.Net.XI.Read(Byte[] buffer, Int32 offset, Int32 count)
   at Rebex.Net.Ftp.VM(String A, Boolean B, Stream C, Int64 D, String E, WG H)
   at Rebex.Net.Ftp.EN(String A, String B, Int64 C, Int64 D, WG E)
   at Rebex.Net.BJ.EC(QG A, Q

3 Answers

Lukas Pokorny · Answer 1 · 2013-08-09T14:41:21+0000

The stack trace reveals that the actual socket that was closed was the control socket (connection to port 21), not the data socket (initialized for each data transfer), although it's not at all apparent from the error message (we will fix that).

It looks like the control connection was suddenly closed immediately after a secure data connection has been established, which doesn't look like a coincidence - the timing matches perfectly.

The most likely cause for this is a server-side error that was triggered by the client trying to download a file (or establishing the data connection) and caused the FTP session to be closed suddenly. Do you have access to the server and its log? It is possible the cause of the error is logged there.

Also, I'm not sure I properly understood the remark that "it happens exactly 5 minutes after the last message". Which last message? Was there a similar error 5 minutes before, or something else?

Oh, and one more tip - we encountered a similar issue in the past that was caused by a bug in the server that caused it to fail when the client tried resuming a TLS/SSL session for a data connection. In this case, the log shows that one resume was actually successful, but please give it a try anyway - simply set Ftp object's Settings.SslReuseSessions to false. If there is no difference, at least we could rule this option out as a possible cause.

jonataspc · Answer 2 · 2013-08-09T16:17:09+0000

Thanks for the reply. I am testing it through the sample project "FtpWinFormClientClassic_VB".

The weird is that I can download the same file in another FTP client (Ipswitch WS_FTP 12) without errors.

The error occurs exactly 5 min after the "Info Tls" command. All times i have tried it happed exactly after 5 min. 09:56:51.467 Info TLS: Data connection: Connection secured using cipher: TLS 1.0, RSA, 128bit AES in CBC mode, SHA1 10:01:51.389 Info TLS: Data connection: Alert Alert:Alert was sent

I have tried set the "Timeout","AbortTimeout" and "Settings.SslReuseSessions = False" but still no success. And i don't have access to the server...

Other details: I am using the following properties: Passive mode Use large buffers Security: Explicit TLS or SSL Client certificate (file.pfx)

Is there a command such "ping" that I could execute to avoid the error? It seems the server closes the connection because inactivity.

Please help me, I need to solve this problem in a big project. Any hint?

Lukas Pokorny · Answer 3 · 2013-08-12T11:18:24+0000

Oh, sorry, I completely overlooked the 5 minute gap! The timing was too exact...

There is actually a "ping" command and it can be enabled using Settings.KeepAliveDuringTransfer option:

_ftp.Settings.KeepAliveDuringTransfer = True

Try a one-minute interval:

_ftp.Settings.KeepAliveDuringTransferInterval = 60

If this doesn't help, please post a new communication log.

Error "Secure connection was closed by the remote connection end"

Please log in or register to add a comment.

Please log in or register to answer this question.

3 Answers

Please log in or register to add a comment.

Please log in or register to add a comment.

Please log in or register to add a comment.

Categories

Error "Secure connection was closed by the remote connection end"

Please log in or register to add a comment.

Please log in or register to answer this question.

3 Answers

Please log in or register to add a comment.

Please log in or register to add a comment.

Please log in or register to add a comment.

Related questions

Categories