Problem
We assume that we were able to established a successful FTPS base session between a client and server. The client started a new data session to download a large file from the server or is uploading a file using the passive mode.
What happens to a file transfer if the control session is terminated by the client.
Troubleshooting
To verify the scenario we are going to setup a simple test scenario like in Does IPv4 based FTPS server supports EPSV FTP protocol extension blog [1].
As the curl client by default is not closing the control connections (what is a correct behavior that we will discuss at the end of this blog) we are going to use an active method to close an established tcp session described here How to forcibly kill an established TCP connection in Linux [2].
Test #1: client download a large file
Client logs
Logs when the control connection is being closed and reseted
root@clinet:~# netstat -tulpan | grep curl
tcp 0 0 5.79.21.166:45707 5.79.17.48:8000 ESTABLISHED 5546/curl
tcp 64210 0 5.79.21.166:43796 5.79.17.48:8011 ESTABLISHED 5546/curl
root@clinet:~# ./killcx.pl 5.79.17.48:8011
killcx v1.0.3 - (c)2009-2011 Jerome Bruandet - http://killcx.sourceforge.net/
[PARENT] checking connection with [5.79.17.48:8011]
[PARENT] found connection with [5.79.21.166:43796] (ESTABLISHED)
[PARENT] forking child
[CHILD] interface not defined, will use [eth0]
[CHILD] setting up filter to sniff ACK on [eth0] for 5 seconds
[CHILD] hooked ACK from [5.79.21.166:43796]
[CHILD] found AckNum [1229126485] and SeqNum [3095306962]
[CHILD] sending spoofed RST to [5.79.21.166:43796] with SeqNum [1229126485]
[CHILD] sending RST to remote host as well with SeqNum [3095306962]
[CHILD] all done, sending USR1 signal to parent [5781] and exiting
[PARENT] received child signal, checking results...
=> success : connection has been closed !
These are the client logs from the start of downloading until the control session is closed.
root@client:~# curl -v --limit-rate 10K -o file.txt -u rado:pass -k --ftp-ssl ftp://5.79.17.48:8000/c2900-universalk9-mz.SPA.152-1.T.bin
* About to connect() to 5.79.17.48 port 8000 (#0)
* Trying 5.79.17.48... % Total % Received % Xferd Average Speed Time Time Time Current
Dload Upload Total Spent Left Speed
0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:-- 0connected
< 220-FileZilla Server version 0.9.41 beta
< 220-written by Tim Kosse (Tim.Kosse@gmx.de)
< 220 Please visit http://sourceforge.net/projects/filezilla/
> AUTH SSL
< 234 Using authentication type SSL
* successfully set certificate verify locations:
* CAfile: none
CApath: /etc/ssl/certs
* SSLv3, TLS handshake, Client hello (1):
} [data not shown]
* SSLv3, TLS handshake, Server hello (2):
{ [data not shown]
* SSLv3, TLS handshake, CERT (11):
{ [data not shown]
* SSLv3, TLS handshake, Server finished (14):
{ [data not shown]
* SSLv3, TLS handshake, Client key exchange (16):
} [data not shown]
* SSLv3, TLS change cipher, Client hello (1):
} [data not shown]
* SSLv3, TLS handshake, Finished (20):
} [data not shown]
* SSLv3, TLS change cipher, Client hello (1):
{ [data not shown]
* SSLv3, TLS handshake, Finished (20):
{ [data not shown]
* SSL connection using AES256-SHA
* Server certificate:
* subject: CN=www; C=11; ST=aaa; L=bbb; O=ddd; OU=aaa; emailAddress=a@a.com
* start date: 2012-11-08 00:13:54 GMT
* expire date: 2013-11-08 00:13:54 GMT
* common name: www (does not match '5.79.17.48')
* issuer: CN=www; C=11; ST=aaa; L=bbb; O=ddd; OU=aaa; emailAddress=a@a.com
* SSL certificate verify result: self signed certificate (18), continuing anyway.
> USER rado
< 331 Password required for rado
> PASS pass
< 230 Logged on
> PBSZ 0
< 200 PBSZ=0
> PROT P
< 200 Protection level set to P
> PWD
< 257 "/" is current directory.
* Entry path is '/'
> EPSV
* Connect data stream passively
< 229 Entering Extended Passive Mode (|||8011|)
* Trying 5.79.17.48... connected
* Connecting to 5.79.17.48 (5.79.17.48) port 8011
> TYPE I
< 200 Type set to I
> SIZE c2900-universalk9-mz.SPA.152-1.T.bin
< 213 77200652
> RETR c2900-universalk9-mz.SPA.152-1.T.bin
< 150 Connection accepted
* Doing the SSL/TLS handshake on the data stream
* successfully set certificate verify locations:
* CAfile: none
CApath: /etc/ssl/certs
* SSL re-using session ID
* SSLv3, TLS handshake, Client hello (1):
} [data not shown]
* SSLv3, TLS handshake, Server hello (2):
{ [data not shown]
* SSLv3, TLS change cipher, Client hello (1):
{ [data not shown]
* SSLv3, TLS handshake, Finished (20):
{ [data not shown]
* SSLv3, TLS change cipher, Client hello (1):
} [data not shown]
* SSLv3, TLS handshake, Finished (20):
} [data not shown]
* SSL connection using AES256-SHA
* Server certificate:
* subject: CN=www; C=11; ST=aaa; L=bbb; O=ddd; OU=aaa; emailAddress=a@a.com
* start date: 2012-11-08 00:13:54 GMT
* expire date: 2013-11-08 00:13:54 GMT
* common name: www (does not match '5.79.17.48')
* issuer: CN=www; C=11; ST=aaa; L=bbb; O=ddd; OU=aaa; emailAddress=a@a.com
* SSL certificate verify result: self signed certificate (18), continuing anyway.
* Maxdownload = -1
* Getting file with size: 77200652
{ [data not shown]
0 73.6M 0 616k 0 0 10095 0 2:07:27 0:01:02 2:06:25 9753* SSL read: error:00000000:lib(0):func(0):reason(0), errno 104
0 73.6M 0 620k 0 0 10160 0 2:06:38 0:01:02 2:05:36 11170
* Closing connection #0
* SSLv3, TLS alert, Client hello (1):
} [data not shown]
curl: (56) SSL read: error:00000000:lib(0):func(0):reason(0), errno 104
Server logs
As the file download started this is logged on the server.
After the client control connections is terminated the server logs '426 Connection closed' tranfer aborted' log message.
After about 3-5 seconds after the connections clears from the server logs.
Test #2: client upload a large file
Client logs
The client logs when control channel is terminated.
root@client:~# netstat -tulpan | grep curl
tcp 0 0 5.79.21.166:43489 5.79.17.48:8016 ESTABLISHED 13177/curl
tcp 0 0 5.79.21.166:45717 5.79.17.48:8000 ESTABLISHED 13177/curl
root@client:~# ./killcx.pl 5.79.17.48:8016
killcx v1.0.3 - (c)2009-2011 Jerome Bruandet - http://killcx.sourceforge.net/
[PARENT] checking connection with [5.79.17.48:8016]
[PARENT] found connection with [5.79.21.166:43489] (ESTABLISHED)
[PARENT] forking child
[CHILD] interface not defined, will use [eth0]
[CHILD] setting up filter to sniff ACK on [eth0] for 5 seconds
[PARENT] sending spoofed SYN to [5.79.21.166:43489] with bogus SeqNum
[CHILD] hooked ACK from [5.79.21.166:43489]
[CHILD] found AckNum [781536832] and SeqNum [2094006657]
[CHILD] sending spoofed RST to [5.79.21.166:43489] with SeqNum [781536832]
[CHILD] sending RST to remote host as well with SeqNum [2094006657]
[CHILD] all done, sending USR1 signal to parent [13547] and exiting
[PARENT] received child signal, checking results...
=> success : connection has been closed !
Curl logs when the upload starts and the control channel is terminated.
root@client:~# curl -v --limit-rate 10K -T file.txt -u rado:pass -k --ftp-ssl ftp://5.79.17.48:8000/
* About to connect() to 5.79.17.48 port 8000 (#0)
* Trying 5.79.17.48... % Total % Received % Xferd Average Speed Time Time Time Current
Dload Upload Total Spent Left Speed
0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:-- 0connected
< 220-FileZilla Server version 0.9.41 beta
< 220-written by Tim Kosse (Tim.Kosse@gmx.de)
< 220 Please visit http://sourceforge.net/projects/filezilla/
> AUTH SSL
0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:-- 0< 234 Using authentication type SSL
* successfully set certificate verify locations:
* CAfile: none
CApath: /etc/ssl/certs
* SSLv3, TLS handshake, Client hello (1):
} [data not shown]
* SSLv3, TLS handshake, Server hello (2):
{ [data not shown]
* SSLv3, TLS handshake, CERT (11):
{ [data not shown]
* SSLv3, TLS handshake, Server finished (14):
{ [data not shown]
* SSLv3, TLS handshake, Client key exchange (16):
} [data not shown]
* SSLv3, TLS change cipher, Client hello (1):
} [data not shown]
* SSLv3, TLS handshake, Finished (20):
} [data not shown]
* SSLv3, TLS change cipher, Client hello (1):
{ [data not shown]
* SSLv3, TLS handshake, Finished (20):
{ [data not shown]
* SSL connection using AES256-SHA
* Server certificate:
* subject: CN=www; C=11; ST=aaa; L=bbb; O=ddd; OU=aaa; emailAddress=a@a.com
* start date: 2012-11-08 00:13:54 GMT
* expire date: 2013-11-08 00:13:54 GMT
* common name: www (does not match '5.79.17.48')
* issuer: CN=www; C=11; ST=aaa; L=bbb; O=ddd; OU=aaa; emailAddress=a@a.com
* SSL certificate verify result: self signed certificate (18), continuing anyway.
> USER rado
< 331 Password required for rado
> PASS pass
< 230 Logged on
> PBSZ 0
< 200 PBSZ=0
> PROT P
< 200 Protection level set to P
> PWD
< 257 "/" is current directory.
* Entry path is '/'
> EPSV
* Connect data stream passively
< 229 Entering Extended Passive Mode (|||8016|)
* Trying 5.79.17.48... connected
* Connecting to 5.79.17.48 (5.79.17.48) port 8016
> TYPE I
< 200 Type set to I
> STOR file.txt
< 150 Connection accepted
* Doing the SSL/TLS handshake on the data stream
* successfully set certificate verify locations:
* CAfile: none
CApath: /etc/ssl/certs
* SSL re-using session ID
* SSLv3, TLS handshake, Client hello (1):
} [data not shown]
* SSLv3, TLS handshake, Server hello (2):
{ [data not shown]
* SSLv3, TLS change cipher, Client hello (1):
{ [data not shown]
* SSLv3, TLS handshake, Finished (20):
{ [data not shown]
* SSLv3, TLS change cipher, Client hello (1):
} [data not shown]
* SSLv3, TLS handshake, Finished (20):
} [data not shown]
* SSL connection using AES256-SHA
* Server certificate:
* subject: CN=www; C=11; ST=aaa; L=bbb; O=ddd; OU=aaa; emailAddress=a@a.com
* start date: 2012-11-08 00:13:54 GMT
* expire date: 2013-11-08 00:13:54 GMT
* common name: www (does not match '5.79.17.48')
* issuer: CN=www; C=11; ST=aaa; L=bbb; O=ddd; OU=aaa; emailAddress=a@a.com
* SSL certificate verify result: self signed certificate (18), continuing anyway.
} [data not shown]
0 73.6M 0 0 0 688k 0 10122 2:07:07 0:01:09 2:05:58 9814* SSL_write() returned SYSCALL, errno = 10422:51:35
0 73.6M 0 0 0 688k 0 10122 2:07:07 0:01:09 2:05:58 8177
* Closing connection #0
* SSLv3, TLS alert, Client hello (1):
} [data not shown]
curl: (55) SSL_write() returned SYSCALL, errno = 104
Server logs
When the upload starts and 1-3 seconds after the control channel is closed.
Results discussion
We can see that every time the client closes the TCP session used to host the control channel bad things happen to the upload or download process.
This is expected behavior and is documented in the relevant RFC documents:
http://tools.ietf.org/html/rfc4217
7. Data Connection Behaviour
http://tools.ietf.org/html/rfc959
3.2. ESTABLISHING DATA CONNECTIONS
The server MUST close the data connection under the following conditions:
1. The server has completed sending data in a transfer mode
that requires a close to indicate EOF.
2. The server receives an ABORT command from the user.
3. The port specification is changed by a command from the
user.
4. The control connection is closed legally or otherwise.
5. An irrecoverable error condition occurs.
References
Posts
