botg wrote: ↑2018-11-19 18:55
No, the error isn't client-side.
Try to check the server log to find out why it closes the connection.
No help unfortunately...
Code: Select all
Nov 19 11:14:00 fserver pure-ftpd: (?@192.168.1.3) [INFO] New connection from 192.168.1.3
Nov 19 11:14:00 fserver pure-ftpd: (?@192.168.1.3) [DEBUG] 220---------- Welcome to Pure-FTPd [privsep] [TLS] ----------
Nov 19 11:14:00 fserver pure-ftpd: (?@192.168.1.3) [DEBUG] 220-You are user number 2 of 50 allowed.
Nov 19 11:14:00 fserver pure-ftpd: (?@192.168.1.3) [DEBUG] 220-Local time is now 11:14. Server port: 21.
Nov 19 11:14:00 fserver pure-ftpd: (?@192.168.1.3) [DEBUG] 220-This is a private system - No anonymous login
Nov 19 11:14:00 fserver pure-ftpd: (?@192.168.1.3) [DEBUG] 220-IPv6 connections are also welcome on this server.
Nov 19 11:14:00 fserver pure-ftpd: (?@192.168.1.3) [DEBUG] 220 You will be disconnected after 15 minutes of inactivity.
Nov 19 11:14:00 fserver pure-ftpd: (?@192.168.1.3) [DEBUG] Command [auth] [TLS]
Nov 19 11:14:00 fserver pure-ftpd: (?@192.168.1.3) [DEBUG] 234 AUTH TLS OK.
Nov 19 11:14:00 fserver pure-ftpd: (?@192.168.1.3) [INFO] TLS: Enabled TLSv1.2 with ECDHE-RSA-AES256-GCM-SHA384, 256 secret bits cipher
Nov 19 11:14:00 fserver pure-ftpd: (?@192.168.1.3) [DEBUG] Command [user] [administrator]
Nov 19 11:14:00 fserver pure-ftpd: (?@192.168.1.3) [DEBUG] 331 User administrator OK. Password required
Nov 19 11:14:00 fserver pure-ftpd: (?@192.168.1.3) [DEBUG] Command [pass] [<*>]
Nov 19 11:14:00 fserver pure-ftpd: (?@192.168.1.3) [INFO] administrator is now logged in
Nov 19 11:14:00 fserver pure-ftpd: (administrator@192.168.1.3) [DEBUG] 230 OK. Current directory is /
Nov 19 11:14:00 fserver pure-ftpd: (administrator@192.168.1.3) [DEBUG] Command [opts] [UTF8 ON]
Nov 19 11:14:00 fserver pure-ftpd: (administrator@192.168.1.3) [DEBUG] 200 OK, UTF-8 enabled
Nov 19 11:14:00 fserver pure-ftpd: (administrator@192.168.1.3) [DEBUG] Command [pbsz] [0]
Nov 19 11:14:00 fserver pure-ftpd: (administrator@192.168.1.3) [DEBUG] 200 PBSZ=0
Nov 19 11:14:00 fserver pure-ftpd: (administrator@192.168.1.3) [DEBUG] Command [prot] [P]
Nov 19 11:14:00 fserver pure-ftpd: (administrator@192.168.1.3) [DEBUG] 200 Data protection level set to "private"
Nov 19 11:14:00 fserver pure-ftpd: (administrator@192.168.1.3) [DEBUG] Command [pwd] []
Nov 19 11:14:00 fserver pure-ftpd: (administrator@192.168.1.3) [DEBUG] 257 "/" is your current location
Nov 19 11:14:00 fserver pure-ftpd: (administrator@192.168.1.3) [DEBUG] Command [type] [I]
Nov 19 11:14:00 fserver pure-ftpd: (administrator@192.168.1.3) [DEBUG] 200 TYPE is now 8-bit binary
Nov 19 11:14:00 fserver pure-ftpd: (administrator@192.168.1.3) [DEBUG] Command [pasv] []
Nov 19 11:14:00 fserver pure-ftpd: (administrator@192.168.1.3) [DEBUG] 227 Entering Passive Mode (75,85,178,33,73,167)
Nov 19 11:14:00 fserver pure-ftpd: (administrator@192.168.1.3) [DEBUG] Command [mlsd] []
The interesting thing, though, is that if I tell pure-ftpd to respond to PASV with my local IP, everything works.The log for that connection attempt also has:
Code: Select all
Nov 19 11:22:21 fserver pure-ftpd: (administrator@192.168.1.3) [DEBUG] 150 Accepted data connection
Nov 19 11:22:21 fserver pure-ftpd: (administrator@192.168.1.3) [INFO] TLS: Enabled TLSv1.2 with ECDHE-RSA-AES256-GCM-SHA384, 256 secret bits cipher
Nov 19 11:22:21 fserver pure-ftpd: (administrator@192.168.1.3) [DEBUG] 226-Options: -a -l
Nov 19 11:22:21 fserver pure-ftpd: (administrator@192.168.1.3) [DEBUG] 226 59 matches total
So it seems that for some reason using the external IP, the data connection isn't being made.
The filezilla log for that is:
Code: Select all
Trace: CControlSocket::SendNextCommand()
Trace: CFtpLogonOpData::Send() in state 0
Status: Resolving address of iamnub.com
Status: Connecting to 192.168.1.2:21...
Status: Connection established, waiting for welcome message...
Trace: CFtpControlSocket::OnReceive()
Response: 220---------- Welcome to Pure-FTPd [privsep] [TLS] ----------
Response: 220-You are user number 1 of 50 allowed.
Response: 220-Local time is now 11:29. Server port: 21.
Response: 220-This is a private system - No anonymous login
Response: 220-IPv6 connections are also welcome on this server.
Response: 220 You will be disconnected after 15 minutes of inactivity.
Trace: CFtpLogonOpData::ParseResponse() in state 1
Trace: CControlSocket::SendNextCommand()
Trace: CFtpLogonOpData::Send() in state 2
Command: AUTH TLS
Trace: CFtpControlSocket::OnReceive()
Response: 234 AUTH TLS OK.
Trace: CFtpLogonOpData::ParseResponse() in state 2
Status: Initializing TLS...
Trace: CTlsSocketImpl::Handshake()
Trace: CTlsSocketImpl::ContinueHandshake()
Trace: TLS handshake: About to send CLIENT HELLO
Trace: TLS handshake: Sent CLIENT HELLO
Trace: CTlsSocketImpl::OnSend()
Trace: CTlsSocketImpl::OnRead()
Trace: CTlsSocketImpl::ContinueHandshake()
Trace: CTlsSocketImpl::OnRead()
Trace: CTlsSocketImpl::ContinueHandshake()
Trace: TLS handshake: Received SERVER HELLO
Trace: TLS handshake: Processed SERVER HELLO
Trace: CTlsSocketImpl::OnRead()
Trace: CTlsSocketImpl::ContinueHandshake()
Trace: TLS handshake: Received CERTIFICATE
Trace: TLS handshake: Processed CERTIFICATE
Trace: TLS handshake: Received SERVER KEY EXCHANGE
Trace: TLS handshake: Processed SERVER KEY EXCHANGE
Trace: TLS handshake: Received SERVER HELLO DONE
Trace: TLS handshake: Processed SERVER HELLO DONE
Trace: TLS handshake: About to send CLIENT KEY EXCHANGE
Trace: TLS handshake: Sent CLIENT KEY EXCHANGE
Trace: TLS handshake: About to send FINISHED
Trace: TLS handshake: Sent FINISHED
Trace: CTlsSocketImpl::OnRead()
Trace: CTlsSocketImpl::ContinueHandshake()
Trace: TLS handshake: Received NEW SESSION TICKET
Trace: TLS handshake: Processed NEW SESSION TICKET
Trace: TLS handshake: Received FINISHED
Trace: TLS handshake: Processed FINISHED
Trace: TLS Handshake successful
Trace: Protocol: TLS1.2, Key exchange: ECDHE-RSA, Cipher: AES-256-GCM, MAC: AEAD
Status: Verifying certificate...
Status: TLS connection established.
Trace: CControlSocket::SendNextCommand()
Trace: CFtpLogonOpData::Send() in state 5
Command: USER administrator
Trace: CTlsSocketImpl::OnRead()
Trace: CFtpControlSocket::OnReceive()
Response: 331 User administrator OK. Password required
Trace: CFtpLogonOpData::ParseResponse() in state 5
Trace: CControlSocket::SendNextCommand()
Trace: CFtpLogonOpData::Send() in state 5
Command: PASS **********
Trace: CTlsSocketImpl::OnRead()
Trace: CFtpControlSocket::OnReceive()
Response: 230 OK. Current directory is /
Trace: CFtpLogonOpData::ParseResponse() in state 5
Trace: CControlSocket::SendNextCommand()
Trace: CFtpLogonOpData::Send() in state 9
Command: OPTS UTF8 ON
Trace: CTlsSocketImpl::OnRead()
Trace: CFtpControlSocket::OnReceive()
Response: 200 OK, UTF-8 enabled
Trace: CFtpLogonOpData::ParseResponse() in state 9
Trace: CControlSocket::SendNextCommand()
Trace: CFtpLogonOpData::Send() in state 10
Command: PBSZ 0
Trace: CTlsSocketImpl::OnRead()
Trace: CFtpControlSocket::OnReceive()
Response: 200 PBSZ=0
Trace: CFtpLogonOpData::ParseResponse() in state 10
Trace: CControlSocket::SendNextCommand()
Trace: CFtpLogonOpData::Send() in state 11
Command: PROT P
Trace: CTlsSocketImpl::OnRead()
Trace: CFtpControlSocket::OnReceive()
Response: 200 Data protection level set to "private"
Trace: CFtpLogonOpData::ParseResponse() in state 11
Status: Logged in
Trace: Measured latency of 3 ms
Trace: CFtpControlSocket::ResetOperation(0)
Trace: CControlSocket::ResetOperation(0)
Trace: CFtpLogonOpData::Reset(0) in state 14
Trace: CFileZillaEnginePrivate::ResetOperation(0)
Status: Retrieving directory listing...
Trace: CControlSocket::SendNextCommand()
Trace: CFtpListOpData::Send() in state 0
Trace: CFtpChangeDirOpData::Send() in state 0
Trace: CFtpChangeDirOpData::Send() in state 1
Command: PWD
Trace: CTlsSocketImpl::OnRead()
Trace: CFtpControlSocket::OnReceive()
Response: 257 "/" is your current location
Trace: CFtpChangeDirOpData::ParseResponse() in state 1
Trace: CFtpControlSocket::ResetOperation(0)
Trace: CControlSocket::ResetOperation(0)
Trace: CFtpChangeDirOpData::Reset(0) in state 1
Trace: CFtpListOpData::SubcommandResult(0) in state 1
Trace: CControlSocket::SendNextCommand()
Trace: CFtpListOpData::Send() in state 2
Trace: CFtpControlSocket::ResetOperation(0)
Trace: CControlSocket::ResetOperation(0)
Trace: CFtpListOpData::Reset(0) in state 2
Status: Directory listing of "/" successful
Trace: CFileZillaEnginePrivate::ResetOperation(0)
Trace: CControlSocket::SendNextCommand()
Trace: CFtpLogonOpData::Send() in state 0
Status: Resolving address of iamnub.com
Status: Connecting to 192.168.1.2:21...
Status: Connection established, waiting for welcome message...
Trace: CFtpControlSocket::OnReceive()
Response: 220---------- Welcome to Pure-FTPd [privsep] [TLS] ----------
Response: 220-You are user number 2 of 50 allowed.
Response: 220-Local time is now 11:30. Server port: 21.
Response: 220-This is a private system - No anonymous login
Response: 220-IPv6 connections are also welcome on this server.
Response: 220 You will be disconnected after 15 minutes of inactivity.
Trace: CFtpLogonOpData::ParseResponse() in state 1
Trace: CControlSocket::SendNextCommand()
Trace: CFtpLogonOpData::Send() in state 2
Command: AUTH TLS
Trace: CFtpControlSocket::OnReceive()
Response: 234 AUTH TLS OK.
Trace: CFtpLogonOpData::ParseResponse() in state 2
Status: Initializing TLS...
Trace: CTlsSocketImpl::Handshake()
Trace: CTlsSocketImpl::ContinueHandshake()
Trace: TLS handshake: About to send CLIENT HELLO
Trace: TLS handshake: Sent CLIENT HELLO
Trace: CTlsSocketImpl::OnSend()
Trace: CTlsSocketImpl::OnRead()
Trace: CTlsSocketImpl::ContinueHandshake()
Trace: CTlsSocketImpl::OnRead()
Trace: CTlsSocketImpl::ContinueHandshake()
Trace: TLS handshake: Received SERVER HELLO
Trace: TLS handshake: Processed SERVER HELLO
Trace: CTlsSocketImpl::OnRead()
Trace: CTlsSocketImpl::ContinueHandshake()
Trace: TLS handshake: Received CERTIFICATE
Trace: TLS handshake: Processed CERTIFICATE
Trace: TLS handshake: Received SERVER KEY EXCHANGE
Trace: TLS handshake: Processed SERVER KEY EXCHANGE
Trace: TLS handshake: Received SERVER HELLO DONE
Trace: TLS handshake: Processed SERVER HELLO DONE
Trace: TLS handshake: About to send CLIENT KEY EXCHANGE
Trace: TLS handshake: Sent CLIENT KEY EXCHANGE
Trace: TLS handshake: About to send FINISHED
Trace: TLS handshake: Sent FINISHED
Trace: CTlsSocketImpl::OnRead()
Trace: CTlsSocketImpl::ContinueHandshake()
Trace: TLS handshake: Received NEW SESSION TICKET
Trace: TLS handshake: Processed NEW SESSION TICKET
Trace: TLS handshake: Received FINISHED
Trace: TLS handshake: Processed FINISHED
Trace: TLS Handshake successful
Trace: Protocol: TLS1.2, Key exchange: ECDHE-RSA, Cipher: AES-256-GCM, MAC: AEAD
Status: Verifying certificate...
Status: TLS connection established.
Trace: CControlSocket::SendNextCommand()
Trace: CFtpLogonOpData::Send() in state 5
Command: USER administrator
Trace: CTlsSocketImpl::OnRead()
Trace: CFtpControlSocket::OnReceive()
Response: 331 User administrator OK. Password required
Trace: CFtpLogonOpData::ParseResponse() in state 5
Trace: CControlSocket::SendNextCommand()
Trace: CFtpLogonOpData::Send() in state 5
Command: PASS **********
Trace: CTlsSocketImpl::OnRead()
Trace: CFtpControlSocket::OnReceive()
Response: 230 OK. Current directory is /
Trace: CFtpLogonOpData::ParseResponse() in state 5
Trace: CControlSocket::SendNextCommand()
Trace: CFtpLogonOpData::Send() in state 9
Command: OPTS UTF8 ON
Trace: CTlsSocketImpl::OnRead()
Trace: CFtpControlSocket::OnReceive()
Response: 200 OK, UTF-8 enabled
Trace: CFtpLogonOpData::ParseResponse() in state 9
Trace: CControlSocket::SendNextCommand()
Trace: CFtpLogonOpData::Send() in state 10
Command: PBSZ 0
Trace: CTlsSocketImpl::OnRead()
Trace: CFtpControlSocket::OnReceive()
Response: 200 PBSZ=0
Trace: CFtpLogonOpData::ParseResponse() in state 10
Trace: CControlSocket::SendNextCommand()
Trace: CFtpLogonOpData::Send() in state 11
Command: PROT P
Trace: CTlsSocketImpl::OnRead()
Trace: CFtpControlSocket::OnReceive()
Response: 200 Data protection level set to "private"
Trace: CFtpLogonOpData::ParseResponse() in state 11
Status: Logged in
Trace: Measured latency of 3 ms
Trace: CFtpControlSocket::ResetOperation(0)
Trace: CControlSocket::ResetOperation(0)
Trace: CFtpLogonOpData::Reset(0) in state 14
Trace: CFileZillaEnginePrivate::ResetOperation(0)
Trace: CFtpControlSocket::FileTransfer()
Trace: CControlSocket::SendNextCommand()
Trace: CFtpFileTransferOpData::Send() in state 0
Status: Starting download of /robots.txt
Trace: CFtpChangeDirOpData::Send() in state 0
Trace: CFtpChangeDirOpData::Send() in state 2
Command: CWD /
Trace: CTlsSocketImpl::OnRead()
Trace: CFtpControlSocket::OnReceive()
Response: 250 OK. Current directory is /
Trace: CFtpChangeDirOpData::ParseResponse() in state 2
Trace: CControlSocket::SendNextCommand()
Trace: CFtpChangeDirOpData::Send() in state 3
Command: PWD
Trace: CTlsSocketImpl::OnRead()
Trace: CFtpControlSocket::OnReceive()
Response: 257 "/" is your current location
Trace: CFtpChangeDirOpData::ParseResponse() in state 3
Trace: CFtpControlSocket::ResetOperation(0)
Trace: CControlSocket::ResetOperation(0)
Trace: CFtpChangeDirOpData::Reset(0) in state 3
Trace: CFtpFileTransferOpData::SubcommandResult(0) in state 1
Trace: CControlSocket::CheckOverwriteFile()
Trace: CControlSocket::SendNextCommand()
Trace: CFtpFileTransferOpData::Send() in state 5
Trace: CFtpRawTransferOpData::Send() in state 1
Command: TYPE A
Trace: CTlsSocketImpl::OnRead()
Trace: CFtpControlSocket::OnReceive()
Response: 200 TYPE is now ASCII
Trace: CFtpRawTransferOpData::ParseResponse() in state 1
Trace: CControlSocket::SendNextCommand()
Trace: CFtpRawTransferOpData::Send() in state 2
Command: PASV
Trace: CTlsSocketImpl::OnRead()
Trace: CFtpControlSocket::OnReceive()
Response: 227 Entering Passive Mode (192,168,1,2,43,222)
Trace: CFtpRawTransferOpData::ParseResponse() in state 2
Trace: CControlSocket::SendNextCommand()
Trace: CFtpRawTransferOpData::Send() in state 4
Trace: Binding data connection source IP to control connection source IP 192.168.1.3
Command: RETR robots.txt
Trace: CTransferSocket::OnConnect
Trace: CTlsSocketImpl::Handshake()
Trace: Trying to resume existing TLS session.
Trace: CTlsSocketImpl::ContinueHandshake()
Trace: TLS handshake: About to send CLIENT HELLO
Trace: TLS handshake: Sent CLIENT HELLO
Trace: CTlsSocketImpl::OnSend()
Trace: CTlsSocketImpl::OnSend()
Trace: CTlsSocketImpl::OnRead()
Trace: CTlsSocketImpl::ContinueHandshake()
Trace: CTlsSocketImpl::OnRead()
Trace: CFtpControlSocket::OnReceive()
Response: 150 Accepted data connection
Trace: CFtpRawTransferOpData::ParseResponse() in state 4
Trace: CControlSocket::SendNextCommand()
Trace: CFtpRawTransferOpData::Send() in state 5
Trace: CTlsSocketImpl::OnRead()
Trace: CTlsSocketImpl::ContinueHandshake()
Trace: TLS handshake: Received SERVER HELLO
Trace: TLS handshake: Processed SERVER HELLO
Trace: TLS handshake: Received FINISHED
Trace: TLS handshake: Processed FINISHED
Trace: TLS handshake: About to send FINISHED
Trace: TLS handshake: Sent FINISHED
Trace: TLS Handshake successful
Trace: TLS Session resumed
Trace: Protocol: TLS1.2, Key exchange: ECDHE-RSA, Cipher: AES-256-GCM, MAC: AEAD
Trace: CTlsSocketImpl::OnRead()
Trace: CTransferSocket::OnConnect
Trace: CTransferSocket::OnReceive(), m_transferMode=2
Trace: CTransferSocket::TransferEnd(1)
Trace: CFtpControlSocket::OnReceive()
Response: 226-File successfully transferred
Response: 226 0.000 seconds (measured here), 202.55 Kbytes per second
Trace: CFtpRawTransferOpData::ParseResponse() in state 5
Trace: CControlSocket::SendNextCommand()
Trace: CFtpRawTransferOpData::Send() in state 8
Trace: CFtpControlSocket::TransferEnd()
Trace: CFtpControlSocket::ResetOperation(0)
Trace: CControlSocket::ResetOperation(0)
Trace: CFtpRawTransferOpData::Reset(0) in state 8
Trace: CFtpFileTransferOpData::SubcommandResult(0) in state 7
Trace: CFtpControlSocket::ResetOperation(0)
Trace: CControlSocket::ResetOperation(0)
Trace: CFtpFileTransferOpData::Reset(0) in state 7
Status: File transfer successful, transferred 27 bytes in 1 second
Trace: CFileZillaEnginePrivate::ResetOperation(0)
Trace: CFileZillaEnginePrivate::ResetOperation(0)
I notice two things: first, when I'm connecting just using local IP's the PASV command isn't being sent until I download a file. Second, during this connection, the data connection says
Binding data connection source IP to control connection source IP 192.168.1.3.
What does filezilla use as the data connection source IP when the PASV response is external? My original logs seem to indicate that the data connection isn't binding any source IP so maybe that's the problem? Is it not even attempting the connection?