FTPc 1.55

Here’s a status log for a plain attempt that worked:

Resolving host name: dragonfruit.active-ns.com
Connecting
Connection established
   220---------- Welcome to Pure-FTPd [privsep] [TLS] ----------
   220-You are user number 1 of 50 allowed.
   220-Local time is now 13:34. Server port: 21.
   220-This is a private system - No anonymous login
   220-IPv6 connections are also welcome on this server.
   220 You will be disconnected after 15 minutes of inactivity.
USER [my_user_name]
   331 User [my_user_name] OK. Password required
PASS
   230 OK. Current restricted directory is /
PWD
   257 "/" is your current location
CWD [my_path]
   550 Can't change directory to [my_path]: No such file or directory
PORT 192,168,16,69,192,13
   200 PORT command successful
LIST
   150 Connecting to port 49165
   226-Options: -a -l 
   226 11 matches total
PWD
   257 "/" is your current location

Here’s a status log for a secure attempt:

Resolving host name: dragonfruit.active-ns.com
Connecting
Connection established
   220---------- Welcome to Pure-FTPd [privsep] [TLS] ----------
   220-You are user number 2 of 50 allowed.
   220-Local time is now 15:48. Server port: 21.
   220-This is a private system - No anonymous login
   220-IPv6 connections are also welcome on this server.
   220 You will be disconnected after 15 minutes of inactivity.
AUTH TLS
   234 AUTH TLS OK.
Secure connection established
USER [my_user_name]
   331 User [my_user_name] OK. Password required
PASS
   230 OK. Current restricted directory is /
PBSZ 0
   200 PBSZ=0
PROT P
   200 Data protection level set to "private"
PWD
   257 "/" is your current location
CWD [my_path]
   550 Can't change directory to [my_path]: No such file or directory
PASV
   227 Entering Passive Mode (84,18,207,61,143,84)
Secure connection established
LIST
   150 Accepted data connection

[my_path] concealed just in case it shouldn’t be made public. [my_user_name] replaced because textile…

So, did the secure attempt succeed or fail? FTPc reported “Not con” and “Connection failed”, yet the status log says “Secure connection established” and “150 Accepted data connection”.

It’s the same problem as another report I have.

In ftp you have 2 connections – one for commands/replies and one for data. The log shows what is sent and received over the command socket – which is encrypted after the AUTH TLS line. At the PASV command a data socket is created but that just sits in a loop waiting for data on your site.

If you try the test site I posted earlier you will find that it works. So the problem is why do some sites have no problems creating the secure data socket and other sites do. It’s not a problem I encountered with Rcomps ssl module but AcornSSL works differently.

I was hoping some update to AcornSSL would fix things.

So, exactly what does “150 Accepted data connection” mean? Have the sockets at both ends negotiated and made an encrypted connection? Which end is waiting, and can something be prodded to cause data to flow?

Naive questions all.

When Filezilla connects to my site, everything goes the same as with FTPC until the PWD command, after which Filezilla says "Directory listing of “/” successful" and its detailed log stops there. FTPc issues the PASV command (AFAICT it ignores the Passive control on the GUI) and the site responds with 227 Entering Passive Mode (84,18,207,61,143,84), which is its own IP address. (I’m guessing that the other two numbers must correspond to a port number?)

I don’t suppose that MLSD would work where LIST doesn’t? RFC 3659 says that MLSD lists the current directory if no object is named.

FTPc is waiting

It means the remote end has accepted the data connection. ‘Secure connection established’ means the ssl session has been created after the socket is connected. However with AcornSSL – unlike Rcomp SSL – a secure connection isn’t confirmed until data is transferred. I’ve also found AcornSSL a bit flakey but it seems odd that the control connection works ok.

Re. my 550 errors: apparently I don’t need to specify a path. Logging in as me logs me into the correct path.

LIST uses the same process as sending or receiving files ie they all need a separate data socket so if LIST fails I’d expect the others to fail too.

OK, what exactly causes FTPc to report “Not con” and “Connection failed”?

However with AcornSSL – unlike Rcomp SSL – a secure connection isn’t confirmed until data is transferred

Ah – you specifically mean transferred from the AcornSSL end to the server?

If yes, I can see that that would be difficult to prod.

It’s complicated by the fact that AcornSSL uses ENOTCONN to signify that the SSL connection is in progress.

I don’t have a problem site to test so if you’d like to send my your details I can make further tests but I’ve done this before and seen nothing.

you specifically mean transferred from the AcornSSL end to the server?

No. The problem is receiving on the data socket. FTPc is polling recv (non blocking) and no data is arriving.

I’ve only used AcornSSL in an app that sends data before it receives any. In the case of the send, it treats ENOTCONN as “in progress” and retries the send (XAcornSSL_Write) until either it succeeds or there is another error. Error &813F27 is an SSL “in progress” error treated the same way.

On receive (in my case, of the reply), ENOTCONN is treated as no data and therefore retried infinitely. SSL error &813F26 is treated the same way.

But I don’t know what happens if the first data are sent to the AcornSSL socket.

When FTPc reports “Not con” and “Connection failed”, what does it do from then on? Does it continue to poll the data socket for incoming data, or has it given up at that point?

On your site the ssl_recv function returns ENOTCONN until the secure connection is made then returns a length of 0 indicating the socket has been closed at the remote end. After the data socket returns a length of 0 the control socket, which has been waiting for a reply while data is transferred over the data socket, also returns a length of 0 which means the remote end also closed the control socket which is where I output “connection failed”

The output from the test site I posted is exactly the same except the first reply after a series of ENOTCONNs is the length of the data transferred. That is followed by a length of 0 indicating the remote end has closed the data connection. In this case the remote end does not close the control connection – which is normal – so you don’t get the “Connection failed” message.

Interesting. My app seems to treat a length of 0 the same as EWOULDBLOCK, though the considerations around using the socket are perhaps not the same as FTPc.

My app seems to treat a length of 0 the same as EWOULDBLOCK

If the socket is a SOCK_STREAM socket a return value of 0 when receiving means that the other end has shut down. You get EWOULDBLOCK when the socket would normally block ie when no data has been received.

I managed to get Pure-ftpd – which is the server used on your site – working on raspian and it shows the same problem. Unfortunately I can’t find a way to get useful debugging out of it. What little I’ve found doesn’t indicate any problems at the server end.

Here is a ftpc wireshark screenshot showing what happens when FTPc tries to connect with TLS – I can’t see that it gets us anywhere. Line 39/40 is the data socket opening and lines 56/57 is the server closing both control and data sockets. It just looks to me that that a security conversation occurs on the data socket then the server just decides to close everything down.

Maybe it makes more sense to someone else.

I wish I knew TCP and IP at that level.

I couldn’t resist writing a test FTPS client to see if I could have any more luck than you, but no. With it I can get a directory listing from the MS test FTP server, but not from my web site.

I’m going to join the Pure-FTPd mailing list. Maybe that will give us more help.

I did look at what FileZilla was doing. It turns out that it uses TLSv1.3 – as opposed to TLSv1.2 for AcornSSL – and has a different ‘conversation’.

Hmm. mbedtls only supports TLS up to 1.2. But does that explain what we’re seeing?

Who knows but it shows that you are not comparing apples to apples regarding FileZilla connecting and ftpc connecting.

Am I correct in believing that, in FTP, you have to open, use and close a data connection for each command that uses data? If so, does it matter whether the data connection is opened before or after the relevant command?

My test app opens a data socket, then upgrades it to secure by XAcornSSL_CreateSession. If I wait after the socket open, I receive a 150 response, then everything sits there waiting for each other. Once I allow it to go from there to CreateSession, the server promptly closes both control and data connections.

Bulk transfers are via a separate data connection. This connection is specified in the reply to the PASV command, is opened by the client after PASV and closed by the sender as closing indicates EOF. The 150 response is an acknowledgement of the connection and the transfer can begin. It is not a command complete response. That is sent after the transfer has finished – success would be a 2xx response.

If you look at the wireshark jpg above, line 38 will be the PASV response (commands/responses are garbled as they are encrypted), the data port is opened (line 39,40,41) and ssl_createsession is called, LIST is sent (line 42), you get the 150 response (line 43). Lines 44-55 are the secure handshake. These occur while polling ssl_recv. I did want to have the secure connection established before sending LIST but AcornSSL doesn’t work like that – you have to call recv or send. After that both sockets close as you found with your test program.

Things we know.

1) The secure connection works – the control socket is encrypted and works fine.
2) The server has accepted the socket and is transferring data over it in the handshake phase.
3) There’s no problem with a different server. So my misgivings about the handshake happening after the LIST response, when I would have expected the server to be trying to send data, appear unfounded.

I joined the Pure-FTPd mailing list and posted the symptoms just now. The support people have raised a ticket. We’ll see what happens.