GnuTLS error -9: TLS packet with unexpected length

Need help with FileZilla Client? Something does not work as expected? In this forum you may find an answer.

Moderator: Project members

Message
Author
juancarletto
500 Syntax error
Posts: 12
Joined: 2012-01-03 18:40
First name: Juan-Carlos
Last name: Amengual

GnuTLS error -9: TLS packet with unexpected length

#1 Post by juancarletto » 2012-01-04 12:43

Okay, let's go... I know from threads http://forum.filezilla-project.org/view ... f=2&t=7465 and http://forum.filezilla-project.org/view ... f=2&t=7688 that this is considered as a server fault. I have my own opinion regarding this issue but I won't make any comment at this respect. I would only like to solve this problem.

The server, which I administer, runs proftpd 1.3.4a. It is a Debian (testing) system with packages proftpd-basic, proftpd-doc and gadmin-proftpd installed.

The client is Filezilla 3.5.2 (in latest Kubuntu, but the same error happens in Windows). With Filezilla client 3.0.11 everything is OK (no errors).

As far as I know, proftpd 1.3.4a had solved the SSL/TLS closure notification problem. Am I right?

My proftpd.conf <IfModule mod_tls.c> section configuration:

TLSEngine on
TLSRequired on
TLSVerifyClient off
TLSProtocol SSLv23
TLSLog /var/log/proftpd_tls.log
TLSRSACertificateFile /etc/gadmin-proftpd/certs/cert.pem
TLSRSACertificateKeyFile /etc/gadmin-proftpd/certs/key.pem
TLSCACertificateFile /etc/gadmin-proftpd/certs/cacert.pem
TLSRenegotiate none
# TLSOptions NoSessionReuseRequired (I have to enable this option in order to get filezilla 3.0.11 working)

and this is the complete trace (mode debug on) with FileZilla 3.5.2 (sorry, some phrases in spanish, thought I think I have translated the important stuff):

Could you please shed a light on me :-)? Maybe Is something regarding the configuration of proftpd or Filezilla? Or is this a bug on proftpd? (I want to know for issuing the corresponding Debian bug report). Thanks a lot in advance!
Estado: Resolviendo la dirección de xxx.xxx.xxx.xx
Estado: Conectando a xxx.xxx.xxx.xxx:21...
Estado: Conexión establecida, esperando el mensaje de bienvenida...
Traza: CFtpControlSocket::OnReceive()
Respuesta: 220 El FTP de teseo
Traza: CFtpControlSocket::SendNextCommand()
Comando: AUTH TLS
Traza: CFtpControlSocket::OnReceive()
Respuesta: 234 AUTH TLS successful
Estado: Inicializando TLS...
Traza: CTlsSocket::Handshake()
Traza: CTlsSocket::ContinueHandshake()
Traza: CTlsSocket::OnSend()
Traza: CTlsSocket::OnRead()
Traza: CTlsSocket::ContinueHandshake()
Traza: CTlsSocket::OnRead()
Traza: CTlsSocket::ContinueHandshake()
Traza: CTlsSocket::OnRead()
Traza: CTlsSocket::ContinueHandshake()
Traza: Handshake successful
Traza: Cipher: AES-256-CBC, MAC: SHA1
Estado: Verificando certificado...
Traza: CFtpControlSocket::SendNextCommand()
Comando: USER XXXXXX
Estado: Conexión TLS/SSL establecida.
Traza: CTlsSocket::OnRead()
Traza: CFtpControlSocket::OnReceive()
Respuesta: 331 Password required for XXXXXX
Traza: CFtpControlSocket::SendNextCommand()
Comando: PASS ******************
Traza: CTlsSocket::OnRead()
Traza: CFtpControlSocket::OnReceive()
Respuesta: 230 User XXXXXX logged in
Traza: CFtpControlSocket::SendNextCommand()
Comando: SYST
Traza: CTlsSocket::OnRead()
Traza: CFtpControlSocket::OnReceive()
Respuesta: 215 UNIX Type: L8
Traza: CFtpControlSocket::SendNextCommand()
Comando: FEAT
Traza: CTlsSocket::OnRead()
Traza: CFtpControlSocket::OnReceive()
Respuesta: 211-Features:
Respuesta: MDTM
Respuesta: MFMT
Respuesta: TVFS
Respuesta: AUTH TLS
Respuesta: UTF8
Respuesta: MFF modify;UNIX.group;UNIX.mode;
Respuesta: MLST modify*;perm*;size*;type*;unique*;UNIX.group*;UNIX.mode*;UNIX.owner*;
Respuesta: PBSZ
Respuesta: PROT
Respuesta: SITE MKDIR
Respuesta: SITE RMDIR
Respuesta: SITE UTIME
Respuesta: SITE SYMLINK
Respuesta: REST STREAM
Respuesta: LANG es-ES.UTF-8*
Respuesta: SITE COPY
Respuesta: SIZE
Traza: CTlsSocket::OnRead()
Traza: CFtpControlSocket::OnReceive()
Respuesta: 211 End
Traza: CFtpControlSocket::SendNextCommand()
Comando: OPTS UTF8 ON
Traza: CTlsSocket::OnRead()
Traza: CFtpControlSocket::OnReceive()
Respuesta: 200 UTF8 set to on
Traza: CFtpControlSocket::SendNextCommand()
Comando: PBSZ 0
Traza: CTlsSocket::OnRead()
Traza: CFtpControlSocket::OnReceive()
Respuesta: 200 PBSZ 0 successful
Traza: CFtpControlSocket::SendNextCommand()
Comando: PROT P
Traza: CTlsSocket::OnRead()
Traza: CFtpControlSocket::OnReceive()
Respuesta: 200 Protection set to Private
Estado: Conectado
Traza: CFtpControlSocket::ResetOperation(0)
Traza: CControlSocket::ResetOperation(0)
Traza: CFileZillaEnginePrivate::ResetOperation(0)
Estado: Recuperando el listado del directorio... (Recovering directory listing...)
Traza: CFtpControlSocket::SendNextCommand()
Traza: CFtpControlSocket::ChangeDirSend()
Comando: PWD
Traza: CTlsSocket::OnRead()
Traza: CFtpControlSocket::OnReceive()
Respuesta: 257 "/" is the current directory
Traza: CFtpControlSocket::ResetOperation(0)
Traza: CControlSocket::ResetOperation(0)
Traza: CFtpControlSocket::ParseSubcommandResult(0)
Traza: CFtpControlSocket::ListSubcommandResult()
Traza: state = 1
Traza: CFtpControlSocket::SendNextCommand()
Traza: CFtpControlSocket::TransferSend()
Traza: state = 1
Comando: TYPE I
Traza: CTlsSocket::OnRead()
Traza: CFtpControlSocket::OnReceive()
Respuesta: 200 Type set to I
Traza: CFtpControlSocket::TransferParseResponse()
Traza: code = 2
Traza: state = 1
Traza: CFtpControlSocket::SendNextCommand()
Traza: CFtpControlSocket::TransferSend()
Traza: state = 2
Comando: PASV
Traza: CTlsSocket::OnRead()
Traza: CFtpControlSocket::OnReceive()
Respuesta: 227 Entering Passive Mode (xxx,xxx,xxx,xxx,xxx,x).
Traza: CFtpControlSocket::TransferParseResponse()
Traza: code = 2
Traza: state = 2
Traza: CFtpControlSocket::SendNextCommand()
Traza: CFtpControlSocket::TransferSend()
Traza: state = 4
Comando: MLSD
Traza: CTransferSocket::OnConnect
Traza: CTlsSocket::Handshake()
Traza: CTlsSocket::ContinueHandshake()
Traza: CTlsSocket::OnSend()
Traza: CTlsSocket::OnSend()
Traza: CTlsSocket::OnRead()
Traza: CTlsSocket::Failure(-9, 103)
Error: GnuTLS error -9: Se recibió un paquete TLS con longitud inesperada
Estado: El servidor no respondió adecuadamente, cierre de conexión TLS
Traza: CRealControlSocket::OnClose(103)
Error: Desconectado del servidor: ECONNABORTED - Connection aborted
Traza: CControlSocket::DoClose(64)
Traza: CFtpControlSocket::ResetOperation(66)
Traza: CControlSocket::ResetOperation(66)
Traza: CFtpControlSocket::ResetOperation(66)
Traza: CControlSocket::ResetOperation(66)
Error: Error al recuperar el listado del directorio
Traza: CFileZillaEnginePrivate::ResetOperation(66)
Traza: CFileZillaEnginePrivate::ResetOperation(0)

User avatar
botg
Site Admin
Posts: 35508
Joined: 2004-02-23 20:49
First name: Tim
Last name: Kosse

Re: GnuTLS error -9: TLS packet with unexpected length

#2 Post by botg » 2012-01-04 21:56

Can you please describe your network architecture a bit, where both the client and the server are located?

juancarletto
500 Syntax error
Posts: 12
Joined: 2012-01-03 18:40
First name: Juan-Carlos
Last name: Amengual

Re: GnuTLS error -9: TLS packet with unexpected length

#3 Post by juancarletto » 2012-01-05 11:08

First of all, I would like to thank you for your quick answer.

The server is located at the public side of University (where I work) network. The server is protected by a firewall where, among others, port 21 is open. There are also a range of ports (60000-65534) open for passive ftp connections. Clients can be anywhere :-) I am testing FTP connections with my laptop (now at my house :-) running latest kubuntu and using filezilla 3.5.2 linux client. I want to test connections for a user that really don't exist in the server (/bin/false as shell). The home directory for this user is really a subdirectory in my account and is chroot protected (jail). Proftpd is the one I know and serves perfectly to my purposes. Everything went OK till filezilla version was updated. Below is the log with Filezilla 3.0.11.1 linux client (everything OK). Please, could you tell me if the problem is related to proftpd? I really thought the bug with the closing TLS dialog was solved in 1.3.4a. Thanks a lot, your kind attention is greatly appreciated.
Estado: Resolviendo la dirección IP de XXX.XXX.XXX.XXX
Traza: ControlSocket.cpp(1056): CRealControlSocket::ContinueConnect(0x127d430) m_pEngine=0x1987550 caller=0x12d0d00
Estado: Conectando a XXXXXXXX:21...
Estado: Conexión establecida, esperando el mensaje de bienvenida...
Traza: CFtpControlSocket::OnReceive()
Respuesta: 220 El FTP de teseo
Traza: CFtpControlSocket::SendNextCommand()
Comando: AUTH TLS
Traza: CFtpControlSocket::OnReceive()
Respuesta: 234 AUTH TLS successful
Estado: Inicializando TLS...
Traza: CTlsSocket::Handshake()
Traza: CFtpControlSocket::SendNextCommand()
Comando: USER XXXXXX
Traza: CTlsSocket::OnRead()
Traza: CTlsSocket::Handshake()
Traza: CTlsSocket::OnRead()
Traza: CTlsSocket::Handshake()
Traza: CTlsSocket::OnRead()
Traza: CTlsSocket::Handshake()
Traza: CTlsSocket::OnRead()
Traza: CTlsSocket::Handshake()
Traza: CTlsSocket::OnRead()
Traza: CTlsSocket::Handshake()
Traza: CTlsSocket::OnRead()
Traza: CTlsSocket::Handshake()
Traza: CTlsSocket::OnRead()
Traza: CTlsSocket::Handshake()
Traza: CTlsSocket::OnRead()
Traza: CTlsSocket::Handshake()
Traza: CTlsSocket::OnRead()
Traza: CTlsSocket::Handshake()
Traza: CTlsSocket::OnRead()
Traza: CTlsSocket::Handshake()
Traza: CTlsSocket::OnRead()
Traza: CTlsSocket::Handshake()
Traza: CTlsSocket::OnRead()
Traza: CTlsSocket::Handshake()
Traza: CTlsSocket::OnRead()
Traza: CTlsSocket::Handshake()
Traza: Handshake successful
Traza: Cipher: AES-128-CBC, MAC: SHA1
Estado: Verificando certificado...
Estado: Conexión TLS/SSL establecida.
Traza: CFtpControlSocket::OnReceive()
Traza: CFtpControlSocket::OnReceive()
Traza: CTlsSocket::OnRead()
Traza: CFtpControlSocket::OnReceive()
Traza: CTlsSocket::OnRead()
Traza: CFtpControlSocket::OnReceive()
Respuesta: 331 Password required for XXXXXX
Traza: CFtpControlSocket::SendNextCommand()
Comando: PASS **********************
Traza: CFtpControlSocket::OnReceive()
Traza: CTlsSocket::OnRead()
Traza: CFtpControlSocket::OnReceive()
Traza: CTlsSocket::OnRead()
Traza: CFtpControlSocket::OnReceive()
Respuesta: 230 User XXXXXX logged in
Traza: CFtpControlSocket::SendNextCommand()
Comando: SYST
Traza: CFtpControlSocket::OnReceive()
Traza: CTlsSocket::OnRead()
Traza: CFtpControlSocket::OnReceive()
Traza: CTlsSocket::OnRead()
Traza: CFtpControlSocket::OnReceive()
Respuesta: 215 UNIX Type: L8
Traza: CFtpControlSocket::SendNextCommand()
Comando: FEAT
Traza: CFtpControlSocket::OnReceive()
Traza: CTlsSocket::OnRead()
Traza: CFtpControlSocket::OnReceive()
Traza: CTlsSocket::OnRead()
Traza: CFtpControlSocket::OnReceive()
Respuesta: 211-Features:
Respuesta: MDTM
Respuesta: MFMT
Respuesta: TVFS
Respuesta: AUTH TLS
Respuesta: UTF8
Respuesta: MFF modify;UNIX.group;UNIX.mode;
Respuesta: MLST modify*;perm*;size*;type*;unique*;UNIX.group*;UNIX.mode*;UNIX.owner*;
Respuesta: PBSZ
Respuesta: PROT
Respuesta: SITE MKDIR
Respuesta: SITE RMDIR
Respuesta: SITE UTIME
Respuesta: SITE SYMLINK
Respuesta: REST STREAM
Respuesta: LANG es-ES.UTF-8*
Respuesta: SITE COPY
Respuesta: SIZE
Traza: CFtpControlSocket::OnReceive()
Traza: CTlsSocket::OnRead()
Traza: CFtpControlSocket::OnReceive()
Traza: CTlsSocket::OnRead()
Traza: CFtpControlSocket::OnReceive()
Respuesta: 211 End
Traza: CFtpControlSocket::SendNextCommand()
Comando: OPTS UTF8 ON
Traza: CFtpControlSocket::OnReceive()
Traza: CTlsSocket::OnRead()
Traza: CFtpControlSocket::OnReceive()
Traza: CTlsSocket::OnRead()
Traza: CFtpControlSocket::OnReceive()
Respuesta: 200 UTF8 set to on
Traza: CFtpControlSocket::SendNextCommand()
Comando: PBSZ 0
Traza: CFtpControlSocket::OnReceive()
Traza: CTlsSocket::OnRead()
Traza: CFtpControlSocket::OnReceive()
Traza: CTlsSocket::OnRead()
Traza: CFtpControlSocket::OnReceive()
Respuesta: 200 PBSZ 0 successful
Traza: CFtpControlSocket::SendNextCommand()
Comando: PROT P
Traza: CFtpControlSocket::OnReceive()
Traza: CTlsSocket::OnRead()
Traza: CFtpControlSocket::OnReceive()
Traza: CTlsSocket::OnRead()
Traza: CFtpControlSocket::OnReceive()
Respuesta: 200 Protection set to Private
Estado: Conectado
Traza: CFtpControlSocket::ResetOperation(0)
Traza: CControlSocket::ResetOperation(0)
Estado: Recuperando el listado del directorio...
Traza: CFtpControlSocket::SendNextCommand()
Traza: CFtpControlSocket::ChangeDirSend()
Comando: PWD
Traza: CFtpControlSocket::OnReceive()
Traza: CTlsSocket::OnRead()
Traza: CFtpControlSocket::OnReceive()
Traza: CTlsSocket::OnRead()
Traza: CFtpControlSocket::OnReceive()
Respuesta: 257 "/" is the current directory
Traza: CFtpControlSocket::ResetOperation(0)
Traza: CControlSocket::ResetOperation(0)
Traza: CFtpControlSocket::ParseSubcommandResult(0)
Traza: CFtpControlSocket::ListSubcommandResult()
Traza: state = 1
Traza: CFtpControlSocket::SendNextCommand()
Traza: CFtpControlSocket::TransferSend()
Traza: state = 1
Comando: TYPE I
Traza: CFtpControlSocket::OnReceive()
Traza: CTlsSocket::OnRead()
Traza: CFtpControlSocket::OnReceive()
Traza: CTlsSocket::OnRead()
Traza: CFtpControlSocket::OnReceive()
Respuesta: 200 Type set to I
Traza: CFtpControlSocket::TransferParseResponse()
Traza: code = 2
Traza: state = 1
Traza: CFtpControlSocket::SendNextCommand()
Traza: CFtpControlSocket::TransferSend()
Traza: state = 2
Comando: PASV
Traza: CFtpControlSocket::OnReceive()
Traza: CTlsSocket::OnRead()
Traza: CFtpControlSocket::OnReceive()
Traza: CTlsSocket::OnRead()
Traza: CFtpControlSocket::OnReceive()
Respuesta: 227 Entering Passive Mode (XXXXXXXXXXXXXXXXXXXX).
Traza: CFtpControlSocket::TransferParseResponse()
Traza: code = 2
Traza: state = 2
Traza: CFtpControlSocket::SendNextCommand()
Traza: CFtpControlSocket::TransferSend()
Traza: state = 4
Comando: LIST
Traza: CFtpControlSocket::OnReceive()
Traza: CTransferSocket::OnConnect
Traza: CTlsSocket::Handshake()
Traza: CTlsSocket::OnRead()
Traza: CFtpControlSocket::OnReceive()
Traza: CTlsSocket::OnRead()
Traza: CFtpControlSocket::OnReceive()
Respuesta: 150 Opening BINARY mode data connection for file list
Traza: CFtpControlSocket::TransferParseResponse()
Traza: code = 1
Traza: state = 4
Traza: CFtpControlSocket::SendNextCommand()
Traza: CFtpControlSocket::TransferSend()
Traza: state = 5
Traza: CFtpControlSocket::OnReceive()
Traza: CTlsSocket::OnRead()
Traza: CTlsSocket::Handshake()
Traza: CTlsSocket::OnRead()
Traza: CTlsSocket::Handshake()
Traza: CTlsSocket::OnRead()
Traza: CTlsSocket::Handshake()
Traza: CTlsSocket::OnRead()
Traza: CTlsSocket::Handshake()
Traza: CTlsSocket::OnRead()
Traza: CTlsSocket::Handshake()
Traza: CTlsSocket::OnRead()
Traza: CTlsSocket::Handshake()
Traza: CTlsSocket::OnRead()
Traza: CTlsSocket::Handshake()
Traza: CTlsSocket::OnRead()
Traza: CTlsSocket::Handshake()
Traza: CTlsSocket::OnRead()
Traza: CTlsSocket::Handshake()
Traza: CTlsSocket::OnRead()
Traza: CTlsSocket::Handshake()
Traza: CTlsSocket::OnRead()
Traza: CTlsSocket::Handshake()
Traza: CTlsSocket::OnRead()
Traza: CTlsSocket::Handshake()
Traza: Handshake successful
Traza: Cipher: AES-128-CBC, MAC: SHA1
Traza: CTransferSocket::OnConnect
Traza: CTransferSocket::OnReceive(), m_transferMode=0
Traza: CTransferSocket::OnConnect
Traza: CTlsSocket::OnRead()
Traza: CTransferSocket::OnReceive(), m_transferMode=0
Traza: CTlsSocket::OnRead()
Traza: CTransferSocket::OnReceive(), m_transferMode=0
Traza: CTransferSocket::OnReceive(), m_transferMode=0
Traza: CTlsSocket::OnRead()
Traza: CTransferSocket::OnReceive(), m_transferMode=0
Traza: CTlsSocket::OnRead()
Traza: CTransferSocket::OnReceive(), m_transferMode=0
Traza: CTransferSocket::TransferEnd(1)
Traza: CFtpControlSocket::TransferEnd()
Traza: CTlsSocket::OnRead()
Traza: CFtpControlSocket::OnReceive()
Traza: CTlsSocket::OnRead()
Traza: CFtpControlSocket::OnReceive()
Respuesta: 226 Transfer complete
Traza: CFtpControlSocket::TransferParseResponse()
Traza: code = 2
Traza: state = 7
Traza: CFtpControlSocket::ResetOperation(0)
Traza: CControlSocket::ResetOperation(0)
Traza: CFtpControlSocket::ParseSubcommandResult(0)
Traza: CFtpControlSocket::ListSubcommandResult()
Traza: state = 2
Traza: CFtpControlSocket::ResetOperation(0)
Traza: CControlSocket::ResetOperation(0)
Estado: Directorio listado correctamente
Traza: CFtpControlSocket::OnReceive()
Estado: Recuperando el listado del directorio...
Traza: CFtpControlSocket::SendNextCommand()
Traza: CFtpControlSocket::ChangeDirSend()
Comando: CWD Curso11-12
Traza: CFtpControlSocket::OnReceive()
Traza: CTlsSocket::OnRead()
Traza: CFtpControlSocket::OnReceive()
Traza: CTlsSocket::OnRead()
Traza: CFtpControlSocket::OnReceive()
Respuesta: 250-Please upload first!
Traza: CFtpControlSocket::OnReceive()
Traza: CTlsSocket::OnRead()
Traza: CFtpControlSocket::OnReceive()
Traza: CTlsSocket::OnRead()
Traza: CFtpControlSocket::OnReceive()
Respuesta: 250 CWD command successful
Traza: CFtpControlSocket::SendNextCommand()
Traza: CFtpControlSocket::ChangeDirSend()
Comando: PWD
Traza: CFtpControlSocket::OnReceive()
Traza: CTlsSocket::OnRead()
Traza: CFtpControlSocket::OnReceive()
Traza: CTlsSocket::OnRead()
Traza: CFtpControlSocket::OnReceive()
Respuesta: 257 "/Curso11-12" is the current directory
Traza: CFtpControlSocket::ResetOperation(0)
Traza: CControlSocket::ResetOperation(0)
Traza: CFtpControlSocket::ParseSubcommandResult(0)
Traza: CFtpControlSocket::ListSubcommandResult()
Traza: state = 1
Traza: CFtpControlSocket::SendNextCommand()
Traza: CFtpControlSocket::TransferSend()
Traza: state = 2
Comando: PASV
Traza: CFtpControlSocket::OnReceive()
Traza: CTlsSocket::OnRead()
Traza: CFtpControlSocket::OnReceive()
Traza: CTlsSocket::OnRead()
Traza: CFtpControlSocket::OnReceive()
Respuesta: 227 Entering Passive Mode (XXXXXXXXXXXXXX).
Traza: CFtpControlSocket::TransferParseResponse()
Traza: code = 2
Traza: state = 2
Traza: CFtpControlSocket::SendNextCommand()
Traza: CFtpControlSocket::TransferSend()
Traza: state = 4
Comando: LIST
Traza: CFtpControlSocket::OnReceive()
Traza: CTransferSocket::OnConnect
Traza: CTlsSocket::Handshake()
Traza: CTlsSocket::OnRead()
Traza: CFtpControlSocket::OnReceive()
Traza: CTlsSocket::OnRead()
Traza: CTlsSocket::OnRead()
Traza: CTlsSocket::Handshake()
Traza: CFtpControlSocket::OnReceive()
Respuesta: 150 Opening BINARY mode data connection for file list
Traza: CFtpControlSocket::TransferParseResponse()
Traza: code = 1
Traza: state = 4
Traza: CFtpControlSocket::SendNextCommand()
Traza: CFtpControlSocket::TransferSend()
Traza: state = 5
Traza: CFtpControlSocket::OnReceive()
Traza: CTlsSocket::OnRead()
Traza: CTlsSocket::Handshake()
Traza: CTlsSocket::OnRead()
Traza: CTlsSocket::Handshake()
Traza: CTlsSocket::OnRead()
Traza: CTlsSocket::Handshake()
Traza: CTlsSocket::OnRead()
Traza: CTlsSocket::Handshake()
Traza: CTlsSocket::OnRead()
Traza: CTlsSocket::Handshake()
Traza: CTlsSocket::OnRead()
Traza: CTlsSocket::Handshake()
Traza: CTlsSocket::OnRead()
Traza: CTlsSocket::Handshake()
Traza: CTlsSocket::OnRead()
Traza: CTlsSocket::Handshake()
Traza: CTlsSocket::OnRead()
Traza: CTlsSocket::Handshake()
Traza: CTlsSocket::OnRead()
Traza: CTlsSocket::Handshake()
Traza: CTlsSocket::OnRead()
Traza: CTlsSocket::Handshake()
Traza: Handshake successful
Traza: Cipher: AES-128-CBC, MAC: SHA1
Traza: CTransferSocket::OnConnect
Traza: CTransferSocket::OnReceive(), m_transferMode=0
Traza: CTransferSocket::OnConnect
Traza: CTlsSocket::OnRead()
Traza: CTransferSocket::OnReceive(), m_transferMode=0
Traza: CTlsSocket::OnRead()
Traza: CTransferSocket::OnReceive(), m_transferMode=0
Traza: CTransferSocket::OnReceive(), m_transferMode=0
Traza: CTlsSocket::OnRead()
Traza: CTransferSocket::OnReceive(), m_transferMode=0
Traza: CTlsSocket::OnRead()
Traza: CTransferSocket::OnReceive(), m_transferMode=0
Traza: CTransferSocket::TransferEnd(1)
Traza: CFtpControlSocket::TransferEnd()
Traza: CTlsSocket::OnRead()
Traza: CFtpControlSocket::OnReceive()
Traza: CTlsSocket::OnRead()
Traza: CFtpControlSocket::OnReceive()
Respuesta: 226 Transfer complete
Traza: CFtpControlSocket::TransferParseResponse()
Traza: code = 2
Traza: state = 7
Traza: CFtpControlSocket::ResetOperation(0)
Traza: CControlSocket::ResetOperation(0)
Traza: CFtpControlSocket::ParseSubcommandResult(0)
Traza: CFtpControlSocket::ListSubcommandResult()
Traza: state = 2
Traza: CFtpControlSocket::SendNextCommand()
Traza: CFtpControlSocket::ListSend()
Traza: state = 3
Estado: Calculando compensación de la zona horaria del servidor...
Comando: MDTM AUDIT-EI1002_10-11.odt
Traza: CFtpControlSocket::OnReceive()
Traza: CTlsSocket::OnRead()
Traza: CFtpControlSocket::OnReceive()
Traza: CTlsSocket::OnRead()
Traza: CFtpControlSocket::OnReceive()
Respuesta: 213 20111214144851
Traza: CFtpControlSocket::ListParseResponse()
Estado: Compensaciones de zona horaria: Servidor: 3600 segundos. Local: 3600 segundos. Diferencia: 0 segundos.
Traza: CFtpControlSocket::ResetOperation(0)
Traza: CControlSocket::ResetOperation(0)
Estado: Directorio listado correctamente
Traza: CFtpControlSocket::OnReceive()
Traza: CTlsSocket::OnRead()
Traza: CFtpControlSocket::OnReceive()
Traza: CTlsSocket::OnRead()
Traza: CFtpControlSocket::OnReceive()
Traza: CTlsSocket::OnRead()
Traza: CFtpControlSocket::OnReceive()

User avatar
boco
Contributor
Posts: 26913
Joined: 2006-05-01 03:28
Location: Germany

Re: GnuTLS error -9: TLS packet with unexpected length

#4 Post by boco » 2012-01-05 11:23

I really thought the bug with the closing TLS dialog was solved in 1.3.4a.
According to ProFTPd changelog, the problem was fixed in 1.3.2c. Note that distro packages may be versioned differently.
No support requests over PM! You will NOT get any reply!!!
FTP connection problems? Please read Network Configuration.
FileZilla connection test: https://filezilla-project.org/conntest.php
FileZilla Pro support: https://customerforum.fileZilla-project.org

juancarletto
500 Syntax error
Posts: 12
Joined: 2012-01-03 18:40
First name: Juan-Carlos
Last name: Amengual

Re: GnuTLS error -9: TLS packet with unexpected length

#5 Post by juancarletto » 2012-01-05 15:12

So, it is the closing TLS dialog problem, isn't it? If so, I will submit the corresponding bug report in Debian. By the way, I don't understand why the version of debian packages would be different from that of the official proftpd site. Latest stable version in http://www.proftpd.org/ is 1.3.4a and this is the version of Debian packages in testing (1.3.4a-1). I think that changes in version numbering will be misleading in this case and I don't think Debian package maintainers would change this. It makes no sense! Thanks a lot for your help! If you can confirm that this is the problem between filezilla client and proftpd server I will proceed with the bug report.

User avatar
boco
Contributor
Posts: 26913
Joined: 2006-05-01 03:28
Location: Germany

Re: GnuTLS error -9: TLS packet with unexpected length

#6 Post by boco » 2012-01-05 20:09

Wait, I wrote they MAY be different. Sometimes Distro-repositories contain custom-made packages with patches and backports applied. So having a lower version of a package doesn't necessarily mean it contains the problem. The opposite case (newer version with missing fix) is also possible, though very unlikely.
No support requests over PM! You will NOT get any reply!!!
FTP connection problems? Please read Network Configuration.
FileZilla connection test: https://filezilla-project.org/conntest.php
FileZilla Pro support: https://customerforum.fileZilla-project.org

User avatar
botg
Site Admin
Posts: 35508
Joined: 2004-02-23 20:49
First name: Tim
Last name: Kosse

Re: GnuTLS error -9: TLS packet with unexpected length

#7 Post by botg » 2012-01-05 22:57

Is there anything in the server logs?

juancarletto
500 Syntax error
Posts: 12
Joined: 2012-01-03 18:40
First name: Juan-Carlos
Last name: Amengual

Re: GnuTLS error -9: TLS packet with unexpected length

#8 Post by juancarletto » 2012-01-06 13:44

In proftpd_tls.log:
  • ene 05 11:45:48 mod_tls/2.4.3[14369]: TLS/TLS-C requested, starting TLS handshake
    ene 05 11:45:50 mod_tls/2.4.3[14369]: client supports secure renegotiations
    ene 05 11:45:50 mod_tls/2.4.3[14369]: TLSv1/SSLv3 connection accepted, using cipher DHE-RSA-AES256-SHA (256 bits)
    ene 05 11:45:53 mod_tls/2.4.3[14369]: Protection set to Private
and no more... The above happens when using Filezilla client 3.5.2 (it seems that "someone" is waiting for something to happen).
  • ene 05 11:47:06 mod_tls/2.4.3[14375]: TLS/TLS-C requested, starting TLS handshake
    ene 05 11:47:07 mod_tls/2.4.3[14375]: TLSv1/SSLv3 connection accepted, using cipher DHE-RSA-AES128-SHA (128 bits)
    ene 05 11:47:11 mod_tls/2.4.3[14375]: Protection set to Private
    ene 05 11:47:13 mod_tls/2.4.3[14375]: starting TLS negotiation on data connection
    ene 05 11:47:14 mod_tls/2.4.3[14375]: TLSv1/SSLv3 renegotiation accepted, using cipher DHE-RSA-AES128-SHA (128 bits)
    ene 05 11:47:14 mod_tls/2.4.3[14375]: client did not reuse SSL session, rejecting data connection (see the NoSessionReuseRequired TLSOptions parameter)
    ene 05 11:47:14 mod_tls/2.4.3[14375]: unable to open data connection: TLS negotiation failed
The above happens when using Filezila 3.0.11.1 and not enabling "TLSOptions NoSessionReuseRequired" in proftpd configuration.
  • ene 05 11:49:00 mod_tls/2.4.3[14491]: TLS/TLS-C requested, starting TLS handshake
    ene 05 11:49:01 mod_tls/2.4.3[14491]: TLSv1/SSLv3 connection accepted, using cipher DHE-RSA-AES128-SHA (128 bits)
    ene 05 11:49:06 mod_tls/2.4.3[14491]: Protection set to Private
    ene 05 11:49:07 mod_tls/2.4.3[14491]: starting TLS negotiation on data connection
    ene 05 11:49:10 mod_tls/2.4.3[14491]: TLSv1/SSLv3 renegotiation accepted, using cipher DHE-RSA-AES128-SHA (128 bits)
    ene 05 11:49:10 mod_tls/2.4.3[14491]: TLSv1/SSLv3 data connection accepted, using cipher DHE-RSA-AES128-SHA (128 bits)
    ene 05 11:49:26 mod_tls/2.4.3[14491]: starting TLS negotiation on data connection
    ene 05 11:49:26 mod_tls/2.4.3[14491]: TLSv1/SSLv3 renegotiation accepted, using cipher DHE-RSA-AES128-SHA (128 bits)
And the above happens when using Filezila 3.0.11.1 and "TLSOptions NoSessionReuseRequired" is enabled in proftpd configuration. As you can see, in this last case everything went OK.

Nothing relevant in proftpd regular logs: just successful or unsuccessful logins and transfers registered.

Finally, all I have to say is just thank you both of you for the kind help you are offering me. Thanks a lot! If you can confirm that the problem is in the TLS dialog I will issue the Debian bug report and hope for a fast solution. Thanks, again.

juancarletto
500 Syntax error
Posts: 12
Joined: 2012-01-03 18:40
First name: Juan-Carlos
Last name: Amengual

Re: GnuTLS error -9: TLS packet with unexpected length

#9 Post by juancarletto » 2012-01-10 14:01

Please, could you confirm that the problem is related with the closure of the TLS dialog as described in http://forum.filezilla-project.org/view ... f=2&t=7688? I need your confirmation for issuing the proper corresponding Debian bug report against proftpd package. Thanks a lot in advance!

User avatar
botg
Site Admin
Posts: 35508
Joined: 2004-02-23 20:49
First name: Tim
Last name: Kosse

Re: GnuTLS error -9: TLS packet with unexpected length

#10 Post by botg » 2012-01-10 23:10

Seems unrelated.

Can you please try FileZilla 3.5.3?

juancarletto
500 Syntax error
Posts: 12
Joined: 2012-01-03 18:40
First name: Juan-Carlos
Last name: Amengual

Re: GnuTLS error -9: TLS packet with unexpected length

#11 Post by juancarletto » 2012-01-13 16:10

Unrelated? :(

I've tried Filezilla 3.5.3 (linux client). Same happens...
Estado: Resolviendo la dirección de XXXXXXXXX
Estado: Conectando a XXXXXXXXXXXXXX:21...
Estado: Conexión establecida, esperando el mensaje de bienvenida...
Traza: CFtpControlSocket::OnReceive()
Respuesta: 220 El FTP de teseo
Traza: CFtpControlSocket::SendNextCommand()
Comando: AUTH TLS
Traza: CFtpControlSocket::OnReceive()
Respuesta: 234 AUTH TLS successful
Estado: Inicializando TLS...
Traza: CTlsSocket::Handshake()
Traza: CTlsSocket::ContinueHandshake()
Traza: CTlsSocket::OnSend()
Traza: CTlsSocket::OnRead()
Traza: CTlsSocket::ContinueHandshake()
Traza: CTlsSocket::OnRead()
Traza: CTlsSocket::ContinueHandshake()
Traza: TLS Handshake successful
Traza: Cipher: AES-128-CBC, MAC: SHA1
Estado: Verificando certificado...
Traza: CFtpControlSocket::SendNextCommand()
Comando: USER XXXXXX
Estado: Conexión TLS/SSL establecida.
Traza: CTlsSocket::OnRead()
Traza: CFtpControlSocket::OnReceive()
Respuesta: 331 Password required for XXXXXX
Traza: CFtpControlSocket::SendNextCommand()
Comando: PASS *************************************
Traza: CTlsSocket::OnRead()
Traza: CFtpControlSocket::OnReceive()
Respuesta: 230 User XXXXXX logged in
Traza: CFtpControlSocket::SendNextCommand()
Comando: SYST
Traza: CTlsSocket::OnRead()
Traza: CFtpControlSocket::OnReceive()
Respuesta: 215 UNIX Type: L8
Traza: CFtpControlSocket::SendNextCommand()
Comando: FEAT
Traza: CTlsSocket::OnRead()
Traza: CFtpControlSocket::OnReceive()
Respuesta: 211-Features:
Respuesta: MDTM
Respuesta: MFMT
Respuesta: TVFS
Respuesta: AUTH TLS
Respuesta: UTF8
Respuesta: MFF modify;UNIX.group;UNIX.mode;
Respuesta: MLST modify*;perm*;size*;type*;unique*;UNIX.group*;UNIX.mode*;UNIX.owner*;
Respuesta: PBSZ
Respuesta: PROT
Respuesta: SITE MKDIR
Respuesta: SITE RMDIR
Respuesta: SITE UTIME
Respuesta: SITE SYMLINK
Respuesta: REST STREAM
Respuesta: LANG es-ES.UTF-8*
Respuesta: SITE COPY
Respuesta: SIZE
Respuesta: 211 End
Traza: CFtpControlSocket::SendNextCommand()
Comando: OPTS UTF8 ON
Traza: CTlsSocket::OnRead()
Traza: CFtpControlSocket::OnReceive()
Respuesta: 200 UTF8 set to on
Traza: CFtpControlSocket::SendNextCommand()
Comando: PBSZ 0
Traza: CTlsSocket::OnRead()
Traza: CFtpControlSocket::OnReceive()
Respuesta: 200 PBSZ 0 successful
Traza: CFtpControlSocket::SendNextCommand()
Comando: PROT P
Traza: CTlsSocket::OnRead()
Traza: CFtpControlSocket::OnReceive()
Respuesta: 200 Protection set to Private
Estado: Conectado
Traza: CFtpControlSocket::ResetOperation(0)
Traza: CControlSocket::ResetOperation(0)
Traza: CFileZillaEnginePrivate::ResetOperation(0)
Estado: Recuperando el listado del directorio...
Traza: CFtpControlSocket::SendNextCommand()
Traza: CFtpControlSocket::ChangeDirSend()
Comando: PWD
Traza: CTlsSocket::OnRead()
Traza: CFtpControlSocket::OnReceive()
Respuesta: 257 "/" is the current directory
Traza: CFtpControlSocket::ResetOperation(0)
Traza: CControlSocket::ResetOperation(0)
Traza: CFtpControlSocket::ParseSubcommandResult(0)
Traza: CFtpControlSocket::ListSubcommandResult()
Traza: state = 1
Traza: CFtpControlSocket::SendNextCommand()
Traza: CFtpControlSocket::TransferSend()
Traza: state = 1
Comando: TYPE I
Traza: CTlsSocket::OnRead()
Traza: CFtpControlSocket::OnReceive()
Respuesta: 200 Type set to I
Traza: CFtpControlSocket::TransferParseResponse()
Traza: code = 2
Traza: state = 1
Traza: CFtpControlSocket::SendNextCommand()
Traza: CFtpControlSocket::TransferSend()
Traza: state = 2
Comando: PASV
Traza: CTlsSocket::OnRead()
Traza: CFtpControlSocket::OnReceive()
Respuesta: 227 Entering Passive Mode (150,128,97,70,237,178).
Traza: CFtpControlSocket::TransferParseResponse()
Traza: code = 2
Traza: state = 2
Traza: CFtpControlSocket::SendNextCommand()
Traza: CFtpControlSocket::TransferSend()
Traza: state = 4
Comando: MLSD
Traza: CTransferSocket::OnConnect
Traza: CTlsSocket::Handshake()
Traza: Trying to resume existing TLS session.
Traza: CTlsSocket::ContinueHandshake()
Traza: CTlsSocket::Failure(-53, 103)
Error: GnuTLS error -53: Error en la función push.
Traza: CTransferSocket::TransferEnd(3)
Traza: CFtpControlSocket::TransferEnd()
Traza: CTlsSocket::OnRead()
Traza: CTlsSocket::Failure(-9, 103)
Error: GnuTLS error -9: Se recibió un paquete TLS con longitud inesperada
Estado: El servidor no respondió adecuadamente, cierre de conexión TLS
Traza: CRealControlSocket::OnClose(103)
Error: Desconectado del servidor: ECONNABORTED - Connection aborted
Traza: CControlSocket::DoClose(64)
Traza: CFtpControlSocket::ResetOperation(66)
Traza: CControlSocket::ResetOperation(66)
Traza: CFtpControlSocket::ResetOperation(66)
Traza: CControlSocket::ResetOperation(66)
Error: Error al recuperar el listado del directorio
Traza: CFileZillaEnginePrivate::ResetOperation(66)
As you can see connection (i.e login) is produced. The error happens when retrieving directory listings.

Messages in proftpd_tls.log are the same as with Filezilla client 3.5.2:
ene 13 16:59:38 mod_tls/2.4.3[22678]: TLS/TLS-C requested, starting TLS handshake
ene 13 16:59:38 mod_tls/2.4.3[22678]: client supports secure renegotiations
ene 13 16:59:38 mod_tls/2.4.3[22678]: TLSv1/SSLv3 connection accepted, using cipher DHE-RSA-AES128-SHA (128 bits)
ene 13 16:59:40 mod_tls/2.4.3[22678]: Protection set to Private
It seems that the TLS dialog is not properly conveyed. Please, could you give me some hint? Your time and efforts are greatly appreciated. Thanks a lot!

juancarletto
500 Syntax error
Posts: 12
Joined: 2012-01-03 18:40
First name: Juan-Carlos
Last name: Amengual

Re: GnuTLS error -9: TLS packet with unexpected length

#12 Post by juancarletto » 2012-01-13 16:24

Well, in fact there is something new:
Error: GnuTLS error -53: Error en la función push.

which is translated as:

Error: GnuTLS error -53: Error in the push function
Same happens in the windows version of Filezilla 3.5.3 client. Any hint? Thanks a lot!

User avatar
boco
Contributor
Posts: 26913
Joined: 2006-05-01 03:28
Location: Germany

Re: GnuTLS error -9: TLS packet with unexpected length

#13 Post by boco » 2012-01-13 21:08

That latest error usually means that something blocks the port/transfer, like a firewall. So it looks like something between server and client is interfering.
No support requests over PM! You will NOT get any reply!!!
FTP connection problems? Please read Network Configuration.
FileZilla connection test: https://filezilla-project.org/conntest.php
FileZilla Pro support: https://customerforum.fileZilla-project.org

juancarletto
500 Syntax error
Posts: 12
Joined: 2012-01-03 18:40
First name: Juan-Carlos
Last name: Amengual

Re: GnuTLS error -9: TLS packet with unexpected length

#14 Post by juancarletto » 2012-01-16 16:47

Nope :( I have tried connection with the firewall stopped and the results were the same (using filezilla linux clients 3.5.2 and 3.5.3).

So, I've tried with another client, ftp-ssl linux client in this case. In fact, I have restarted the firewall in the server and... ¡everything went OK! I could connect, list directories, perform a get and a put command. ¡Everything fine! The logs in the server (proftpd_tls.log):
ene 16 17:33:43 mod_tls/2.4.3[518]: SSL/TLS-P requested, starting TLS handshake
ene 16 17:33:43 mod_tls/2.4.3[518]: client supports secure renegotiations
ene 16 17:33:43 mod_tls/2.4.3[518]: TLSv1/SSLv3 connection accepted, using cipher DHE-RSA-AES256-SHA (256 bits)
ene 16 17:33:54 mod_tls/2.4.3[518]: starting TLS negotiation on data connection
ene 16 17:33:54 mod_tls/2.4.3[518]: TLSv1/SSLv3 renegotiation accepted, using cipher DHE-RSA-AES256-SHA (256 bits)
ene 16 17:33:54 mod_tls/2.4.3[518]: client reused SSL session for data connection
ene 16 17:33:54 mod_tls/2.4.3[518]: TLSv1/SSLv3 data connection accepted, using cipher DHE-RSA-AES256-SHA (256 bits)
ene 16 17:34:13 mod_tls/2.4.3[518]: starting TLS negotiation on data connection
ene 16 17:34:13 mod_tls/2.4.3[518]: TLSv1/SSLv3 renegotiation accepted, using cipher DHE-RSA-AES256-SHA (256 bits)
ene 16 17:34:13 mod_tls/2.4.3[518]: client reused SSL session for data connection
ene 16 17:34:21 mod_tls/2.4.3[518]: starting TLS negotiation on data connection
ene 16 17:34:21 mod_tls/2.4.3[518]: TLSv1/SSLv3 renegotiation accepted, using cipher DHE-RSA-AES256-SHA (256 bits)
ene 16 17:34:21 mod_tls/2.4.3[518]: client reused SSL session for data connection
ene 16 17:34:44 mod_tls/2.4.3[518]: starting TLS negotiation on data connection
ene 16 17:34:44 mod_tls/2.4.3[518]: TLSv1/SSLv3 renegotiation accepted, using cipher DHE-RSA-AES256-SHA (256 bits)
ene 16 17:34:44 mod_tls/2.4.3[518]: client reused SSL session for data connection
ene 16 17:34:53 mod_tls/2.4.3[518]: starting TLS negotiation on data connection
ene 16 17:34:53 mod_tls/2.4.3[518]: TLSv1/SSLv3 renegotiation accepted, using cipher DHE-RSA-AES256-SHA (256 bits)
ene 16 17:34:53 mod_tls/2.4.3[518]: client reused SSL session for data connection
ene 16 17:35:32 mod_tls/2.4.3[518]: starting TLS negotiation on data connection
ene 16 17:35:32 mod_tls/2.4.3[518]: TLSv1/SSLv3 renegotiation accepted, using cipher DHE-RSA-AES256-SHA (256 bits)
ene 16 17:35:32 mod_tls/2.4.3[518]: client reused SSL session for data connection
So? Filezilla bug? Now it seems that to me. Please, let me know because the users of the FTP server will use a graphical client (not so "skilled" as to manage a console client :) ) and I have always thought of Filezilla for these purposes. Thanks a lot!!!

User avatar
Spot
500 Command not understood
Posts: 4
Joined: 2008-06-25 08:22
First name: Rene
Last name: van Stipriaan

Re: GnuTLS error -9: TLS packet with unexpected length

#15 Post by Spot » 2012-01-18 09:55

I have ran into the same problem.

In my case it's FileZilla Client talking to FileZilla Server.

The problem does not occur when I use FileZilla client version 3.1.2.

When I use FileZilla client version 3.5.3 I get the same error. (GnuTLS error -9: A TLS packet with unexpected length was received.)

I only get the error when accessing a specific directory and not with any of my other directories on the same server.

If you want detailed (server/client) logs let me know and I will provide them.

Post Reply