Could not read from transfer socket: ECONNABORTED

[tzlp6m]

FileZilla Client Version 3.1.0 Build Date 2008-07-23
OS - Windows XP Version 2002 Service Pack 2

Odd thing is the problem I am reporting worked fine with an older version of the FileZilla Version 3 Client. I just upgraded to the current build today and then encountered the error. Here are the details:

Using a predefine site Manager profile, I connected to a private z/OS (IBM Mainframe) host using secured FTP (TLS). By private host, I mean no public access for logins, my company maintains high security - no outside access (sorry). Hopefully the log will be useful. I imagine that you have very few clients that access MVS/z/OS hosts so it is probably a low priority in the scheme of things.

As one can see in the log, the TLS authentication worked fine. The error is encountered when the client receives back the directory listing of the default host directory. The directory list does come back to the client and looks correct in the log. The log then shows "Trace: GnuTLS error -9: A TLS packet with unexpected length was received." then the "Could not read from transfer socket: ECONNABORTED" message.

Here is the complete log:

08:59:08 Status: Resolving address of plp311.sys.eds.com
08:59:08 Status: Connecting to 128.212.110.33:21...
08:59:08 Status: Connection established, waiting for welcome message...
08:59:08 Trace: CFtpControlSocket::OnReceive()
08:59:08 Response: 220-NETIFTP1 IBM FTP CS V1R7 at PLIPC3E.SYS.EDS.COM, 13:59:08 on 2008-07-24.
08:59:08 Trace: CFtpControlSocket::OnReceive()
08:59:08 Response: 220 Connection will close if idle for more than 5 minutes.
08:59:08 Trace: CFtpControlSocket::SendNextCommand()
08:59:08 Command: AUTH TLS
08:59:09 Trace: CFtpControlSocket::OnReceive()
08:59:09 Response: 234 Security environment established - ready for negotiation
08:59:09 Status: Initializing TLS...
08:59:09 Trace: CTlsSocket::Handshake()
08:59:09 Trace: CTlsSocket::OnRead()
08:59:09 Trace: CTlsSocket::Handshake()
08:59:09 Trace: CTlsSocket::OnSend()
08:59:09 Trace: CTlsSocket::OnRead()
08:59:09 Trace: CTlsSocket::Handshake()
08:59:09 Trace: CTlsSocket::OnRead()
08:59:09 Trace: CTlsSocket::Handshake()
08:59:09 Trace: Handshake successful
08:59:09 Trace: Cipher: 3DES-CBC, MAC: SHA1
08:59:09 Status: Verifying certificate...
08:59:09 Trace: CFtpControlSocket::SendNextCommand()
08:59:09 Command: USER tzlp6m
08:59:09 Status: TLS/SSL connection established.
08:59:09 Trace: CTlsSocket::OnRead()
08:59:09 Trace: CFtpControlSocket::OnReceive()
08:59:09 Response: 331 Send password please.
08:59:09 Trace: CFtpControlSocket::SendNextCommand()
08:59:09 Command: PASS
08:59:09 Trace: CTlsSocket::OnRead()
08:59:09 Trace: CFtpControlSocket::OnReceive()
08:59:09 Response: 230 TZLP6M is logged on. Working directory is "TZLP6M.".
08:59:09 Trace: CFtpControlSocket::SendNextCommand()
08:59:09 Command: SYST
08:59:09 Trace: CTlsSocket::OnRead()
08:59:09 Trace: CFtpControlSocket::OnReceive()
08:59:09 Response: 215 MVS is the operating system of this server. FTP Server is running on z/OS.
08:59:09 Trace: CFtpControlSocket::SendNextCommand()
08:59:09 Command: FEAT
08:59:09 Trace: CTlsSocket::OnRead()
08:59:09 Trace: CFtpControlSocket::OnReceive()
08:59:09 Response: 211- Extensions supported
08:59:09 Trace: CTlsSocket::OnRead()
08:59:09 Trace: CFtpControlSocket::OnReceive()
08:59:09 Response: MDTM
08:59:09 Response: AUTH TLS
08:59:09 Response: PBSZ
08:59:09 Response: PROT
08:59:09 Response: 211 End
08:59:09 Trace: CFtpControlSocket::SendNextCommand()
08:59:09 Command: PBSZ 0
08:59:09 Trace: CTlsSocket::OnRead()
08:59:09 Trace: CFtpControlSocket::OnReceive()
08:59:09 Response: 200 Protection buffer size accepted
08:59:09 Trace: CFtpControlSocket::SendNextCommand()
08:59:09 Command: PROT P
08:59:09 Trace: CTlsSocket::OnRead()
08:59:09 Trace: CFtpControlSocket::OnReceive()
08:59:09 Response: 200 Data connection protection set to private
08:59:09 Status: Connected
08:59:09 Trace: CFtpControlSocket::ResetOperation(0)
08:59:09 Trace: CControlSocket::ResetOperation(0)
08:59:09 Status: Retrieving directory listing...
08:59:09 Trace: CFtpControlSocket::SendNextCommand()
08:59:09 Trace: CFtpControlSocket::ChangeDirSend()
08:59:09 Command: CWD 'tzlp6m.hamlb.wipQA'
08:59:09 Trace: CTlsSocket::OnRead()
08:59:09 Trace: CFtpControlSocket::OnReceive()
08:59:09 Response: 250 The working directory "TZLP6M.HAMLB.WIPQA" is a partitioned data set
08:59:09 Trace: CFtpControlSocket::SendNextCommand()
08:59:09 Trace: CFtpControlSocket::ChangeDirSend()
08:59:09 Command: PWD
08:59:09 Trace: CTlsSocket::OnRead()
08:59:09 Trace: CFtpControlSocket::OnReceive()
08:59:09 Response: 257 "'TZLP6M.HAMLB.WIPQA'" partitioned data set is working directory.
08:59:09 Trace: CFtpControlSocket::ResetOperation(0)
08:59:09 Trace: CControlSocket::ResetOperation(0)
08:59:09 Trace: CFtpControlSocket::ParseSubcommandResult(0)
08:59:09 Trace: CFtpControlSocket::ListSubcommandResult()
08:59:09 Trace: state = 1
08:59:09 Trace: CFtpControlSocket::SendNextCommand()
08:59:09 Trace: CFtpControlSocket::TransferSend()
08:59:09 Trace: state = 1
08:59:09 Command: TYPE I
08:59:09 Trace: CTlsSocket::OnRead()
08:59:09 Trace: CFtpControlSocket::OnReceive()
08:59:09 Response: 200 Representation type is Image
08:59:09 Trace: CFtpControlSocket::TransferParseResponse()
08:59:09 Trace: code = 2
08:59:09 Trace: state = 1
08:59:09 Trace: CFtpControlSocket::SendNextCommand()
08:59:10 Trace: CFtpControlSocket::TransferSend()
08:59:10 Trace: state = 2
08:59:10 Command: PASV
08:59:10 Trace: CTlsSocket::OnRead()
08:59:10 Trace: CFtpControlSocket::OnReceive()
08:59:10 Response: 227 Entering Passive Mode (128,212,110,33,6,63)
08:59:10 Trace: CFtpControlSocket::TransferParseResponse()
08:59:10 Trace: code = 2
08:59:10 Trace: state = 2
08:59:10 Trace: CFtpControlSocket::SendNextCommand()
08:59:10 Trace: CFtpControlSocket::TransferSend()
08:59:10 Trace: state = 4
08:59:10 Command: LIST
08:59:10 Trace: CTransferSocket::OnConnect
08:59:10 Trace: CTlsSocket::Handshake()
08:59:10 Trace: Skipping socket event 4, id mismatch.
08:59:10 Trace: CTlsSocket::OnSend()
08:59:10 Trace: CTlsSocket::OnRead()
08:59:10 Trace: CFtpControlSocket::OnReceive()
08:59:10 Response: 125 List started OK
08:59:10 Trace: CFtpControlSocket::TransferParseResponse()
08:59:10 Trace: code = 1
08:59:10 Trace: state = 4
08:59:10 Trace: CFtpControlSocket::SendNextCommand()
08:59:10 Trace: CFtpControlSocket::TransferSend()
08:59:10 Trace: state = 5
08:59:10 Trace: CTlsSocket::OnRead()
08:59:10 Trace: CTlsSocket::Handshake()
08:59:10 Trace: CTlsSocket::OnRead()
08:59:10 Trace: CTlsSocket::Handshake()
08:59:10 Trace: CTlsSocket::OnRead()
08:59:10 Trace: CTlsSocket::Handshake()
08:59:10 Trace: Handshake successful
08:59:10 Trace: Cipher: 3DES-CBC, MAC: SHA1
08:59:10 Trace: CTransferSocket::OnConnect
08:59:10 Trace: CTransferSocket::OnReceive(), m_transferMode=0
08:59:10 Listing: Name VV.MM Created Changed Size Init Mod Id
08:59:10 Listing: ALPHA 01.03 2007/10/04 2007/10/04 14:24 3 1 0 TZLP6M
08:59:10 Listing: H99PD100 01.02 2008/04/14 2008/04/14 15:43 11803 11803 0 TZLP6M
08:59:10 Listing: H99SD100 01.01 2008/04/14 2008/04/14 15:05 10657 10657 0 TZLP6M
08:59:10 Listing: LOG 01.00 2008/04/14 2008/04/14 10:06 8 8 0 TZLP6M
08:59:10 Listing: MSSTRZ50 01.02 2008/02/25 2008/02/25 09:27 400 351 0 TZLP6M
08:59:10 Trace: GnuTLS error -9: A TLS packet with unexpected length was received.
08:59:10 Error: Could not read from transfer socket: ECONNABORTED - Connection aborted
08:59:10 Trace: CTransferSocket::TransferEnd(3)
08:59:10 Trace: Skipping socket event 4, no socket or id mismatch.
08:59:10 Trace: Skipping socket event 5, no socket or id mismatch.
08:59:10 Trace: CFtpControlSocket::TransferEnd()
08:59:10 Trace: CTlsSocket::OnRead()
08:59:10 Trace: CFtpControlSocket::OnReceive()
08:59:10 Response: 250 List completed successfully.
08:59:10 Trace: CFtpControlSocket::TransferParseResponse()
08:59:10 Trace: code = 2
08:59:10 Trace: state = 7
08:59:10 Trace: CFtpControlSocket::ResetOperation(2)
08:59:10 Trace: CControlSocket::ResetOperation(2)
08:59:10 Trace: CFtpControlSocket::ParseSubcommandResult(2)
08:59:10 Trace: CFtpControlSocket::ListSubcommandResult()
08:59:10 Trace: state = 2
08:59:10 Trace: CFtpControlSocket::ResetOperation(2)
08:59:10 Trace: CControlSocket::ResetOperation(2)
08:59:10 Error: Failed to retrieve directory listing

[Tim Kosse]

Your server is broken. It does not perform the required TLS shutdown. Previous versions of FileZilla did not detect this faulty server behavior.