1

Our customer has a FileZilla FTP Server running on a Windows box and I'm using FileZilla Client to test the connection. The connection works from my office, and from all of our Azure servers except one.

I've set the debug option in FileZilla Client and below are both the successful and failed connections. Why does the connection succeed on 1 server but fail on another?

Both of our servers connecting to customers FTP are in Azure, both are VM's running the same OS

Successful

Status: Disconnected from server
Trace:  CRealControlSocket::DoClose(66)
Trace:  CControlSocket::DoClose(66)
Trace:  CFtpControlSocket::ResetOperation(66)
Trace:  CControlSocket::ResetOperation(66)
Trace:  CFileZillaEnginePrivate::ResetOperation(66)
Trace:  CRealControlSocket::DoClose(66)
Trace:  CControlSocket::DoClose(66)
Trace:  CControlSocket::DoClose(66)
Trace:  CFileZillaEnginePrivate::ResetOperation(0)
Trace:  CControlSocket::SendNextCommand()
Trace:  CFtpLogonOpData::Send() in state 0
Status: Resolving address of *SERVER DNS*
Status: Connecting to *SERVER IP*:2121...
Status: Connection established, waiting for welcome message...
Trace:  CFtpControlSocket::OnReceive()
Response:   220 PPW FTP Server
Trace:  CFtpLogonOpData::ParseResponse() in state 1
Trace:  CControlSocket::SendNextCommand()
Trace:  CFtpLogonOpData::Send() in state 2
Command:    AUTH TLS
Trace:  CFtpControlSocket::OnReceive()
Response:   502 Explicit TLS authentication not allowed
Trace:  CFtpLogonOpData::ParseResponse() in state 2
Trace:  CControlSocket::SendNextCommand()
Trace:  CFtpLogonOpData::Send() in state 3
Command:    AUTH SSL
Trace:  CFtpControlSocket::OnReceive()
Response:   502 Explicit TLS authentication not allowed
Trace:  CFtpLogonOpData::ParseResponse() in state 3
Status: Insecure server, it does not support FTP over TLS.
Trace:  CControlSocket::SendNextCommand()
Trace:  CFtpLogonOpData::Send() in state 5
Command:    USER printiq
Trace:  CFtpControlSocket::OnReceive()
Response:   331 Password required for printiq
Trace:  CFtpLogonOpData::ParseResponse() in state 5
Trace:  CControlSocket::SendNextCommand()
Trace:  CFtpLogonOpData::Send() in state 5
Command:    PASS ********
Trace:  CFtpControlSocket::OnReceive()
Response:   230 Logged on
Trace:  CFtpLogonOpData::ParseResponse() in state 5
Status: Logged in
Trace:  Measured latency of 46 ms
Trace:  CFtpControlSocket::ResetOperation(0)
Trace:  CControlSocket::ResetOperation(0)
Trace:  CFileZillaEnginePrivate::ResetOperation(0)
Status: Retrieving directory listing...
Trace:  CControlSocket::SendNextCommand()
Trace:  CFtpListOpData::ListSend() in state 0
Trace:  CFtpChangeDirOpData::Send() in state 0
Trace:  CFtpChangeDirOpData::Send() in state 1
Command:    PWD
Trace:  CFtpControlSocket::OnReceive()
Response:   257 "/" is current directory.
Trace:  CFtpChangeDirOpData::ParseResponse() in state 1
Trace:  CFtpControlSocket::ResetOperation(0)
Trace:  CControlSocket::ResetOperation(0)
Trace:  CControlSocket::ParseSubcommandResult(0)
Trace:  CFtpListOpData::SubcommandResult() in state 1
Trace:  CControlSocket::SendNextCommand()
Trace:  CFtpListOpData::ListSend() in state 2
Trace:  CFtpControlSocket::ResetOperation(0)
Trace:  CControlSocket::ResetOperation(0)
Status: Directory listing of "/" successful
Trace:  CFileZillaEnginePrivate::ResetOperation(0)

Failed

Status: Disconnected from server
Trace:  CRealControlSocket::DoClose(66)
Trace:  CControlSocket::DoClose(66)
Trace:  CFtpControlSocket::ResetOperation(66)
Trace:  CControlSocket::ResetOperation(66)
Trace:  CFileZillaEnginePrivate::ResetOperation(66)
Trace:  CRealControlSocket::DoClose(66)
Trace:  CControlSocket::DoClose(66)
Trace:  CControlSocket::DoClose(66)
Trace:  CFileZillaEnginePrivate::ResetOperation(0)
Trace:  CControlSocket::SendNextCommand()
Trace:  CFtpLogonOpData::Send() in state 0
Status: Resolving address of *SERVER DNS*
Status: Connecting to **SERVER IP**:2121...
Status: Connection established, waiting for welcome message...
Trace:  CFtpControlSocket::OnReceive()
Response:   220 PPW FTP Server
Trace:  CFtpLogonOpData::ParseResponse() in state 1
Trace:  CControlSocket::SendNextCommand()
Trace:  CFtpLogonOpData::Send() in state 2
Command:    AUTH TLS
Trace:  CFtpControlSocket::OnReceive()
Response:   502 Explicit TLS authentication not allowed
Trace:  CFtpLogonOpData::ParseResponse() in state 2
Trace:  CControlSocket::SendNextCommand()
Trace:  CFtpLogonOpData::Send() in state 3
Command:    AUTH SSL
Trace:  CFtpControlSocket::OnReceive()
Response:   502 Explicit TLS authentication not allowed
Trace:  CFtpLogonOpData::ParseResponse() in state 3
Status: Insecure server, it does not support FTP over TLS.
Trace:  CControlSocket::SendNextCommand()
Trace:  CFtpLogonOpData::Send() in state 5
Command:    USER printiq
Trace:  CFtpControlSocket::OnReceive()
Response:   331 Password required for printiq
Trace:  CFtpLogonOpData::ParseResponse() in state 5
Trace:  CControlSocket::SendNextCommand()
Trace:  CFtpLogonOpData::Send() in state 5
Command:    PASS ********
Trace:  CFtpControlSocket::OnReceive()
Response:   230 Logged on
Trace:  CFtpLogonOpData::ParseResponse() in state 5
Status: Logged in
Trace:  Measured latency of 38 ms
Trace:  CFtpControlSocket::ResetOperation(0)
Trace:  CControlSocket::ResetOperation(0)
Trace:  CFileZillaEnginePrivate::ResetOperation(0)
Status: Retrieving directory listing...
Trace:  CControlSocket::SendNextCommand()
Trace:  CFtpListOpData::ListSend() in state 0
Trace:  CFtpChangeDirOpData::Send() in state 0
Trace:  CFtpChangeDirOpData::Send() in state 1
Command:    PWD
Trace:  CFtpControlSocket::OnReceive()
Response:   257 "/" is current directory.
Trace:  CFtpChangeDirOpData::ParseResponse() in state 1
Trace:  CFtpControlSocket::ResetOperation(0)
Trace:  CControlSocket::ResetOperation(0)
Trace:  CControlSocket::ParseSubcommandResult(0)
Trace:  CFtpListOpData::SubcommandResult() in state 1
Trace:  CControlSocket::SendNextCommand()
Trace:  CFtpListOpData::ListSend() in state 2
Trace:  CFtpRawTransferOpData::Send() in state 1
Command:    TYPE I
Trace:  CFtpControlSocket::OnReceive()
Response:   200 Type set to I
Trace:  CFtpRawTransferOpData::ParseResponse() in state 1
Trace:  CControlSocket::SendNextCommand()
Trace:  CFtpRawTransferOpData::Send() in state 2
Command:    PASV
Trace:  CFtpControlSocket::OnReceive()
Response:   227 Entering Passive Mode (*SERVER IP*,234,225)
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 10.0.0.4
Command:    MLSD
Trace:  CFtpControlSocket::OnReceive()
Response:   425 Can't open data connection for transfer of "/"
Trace:  CFtpRawTransferOpData::ParseResponse() in state 4
Trace:  CFtpControlSocket::ResetOperation(2)
Trace:  CControlSocket::ResetOperation(2)
Trace:  CControlSocket::ParseSubcommandResult(2)
Trace:  CFtpListOpData::SubcommandResult() in state 3
Trace:  CFtpControlSocket::ResetOperation(2)
Trace:  CControlSocket::ResetOperation(2)
Error:  Failed to retrieve directory listing
Trace:  CFileZillaEnginePrivate::ResetOperation(2)
Paul
  • 3,037
  • 6
  • 27
  • 40
Zeb Rawnsley
  • 145
  • 1
  • 2
  • 8
  • Note: on both servers I freshly installed FileZilla Client before running this connection test, no config changes were made except for setting debug output – Zeb Rawnsley Nov 18 '17 at 23:08

2 Answers2

3

This is usually a problem with the active/passive mode of FTP.

Most server/client FTP scenarios work in passive mode and you can see in the log that your client has switched to PASV mode.

To give a little background, when you connect to an FTP server there is a control connection, and a data connection established. FTP commands are sent and responses are received over the control connection. The actual data, like a file listing or directory listing is sent over the data connection.

In FTP active mode, your client initiates the control connection to the server, and the server initiates the data connection to the client. In modern IT networks, this doesn’t work very well because most clients sit behind a NAT’d network and it would require port forwarding.

As a work around, passive mode causes the client to initiate both the control connection and the data connection. The data connection occurs over a random port designated by the server.

In your scenario, it appears you have successfully created the control connection and logged in. But as soon as you try to do a directory listing over the data connection it fails.

Therefore, a firewall between the client and the server is blocking the connection that the client is trying to initiate to the server. Being that other clients can connect OK, it is probably not on the server side, but it very well could be if it is blocking certain IPs or ports that are related to the connection from the client.

PASV mode is the typical mode to use and the most reliable unless both the server and client have a public IP address, or some other network modifications on the client side have been made to accommodate the random FTP data connections.

Appleoddity
  • 3,488
  • 2
  • 13
  • 33
  • Thanks for this, it explains a lot for me. I ended up configuring a proxy on our web server to route FTP requests through our office as a test, and the connection is successful. I can only think that this means there is a security rule on the customer's network that is blocking our webserver. – Zeb Rawnsley Nov 19 '17 at 21:44
2

The reason is, your sucessfull client don't use the passive command PASV

Command:    PASV
Trace:  CFtpControlSocket::OnReceive()
Response:   227 Entering Passive Mode (*SERVER IP*,234,225)

the server told you, that he opened the port 60385 on SERVER IP, (is the firewall open?)

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 10.0.0.4

your client cant reach your server on port 60385 with source 10.0.0.4

FaxMax
  • 165
  • 1
  • 2
  • 12