Session Resumption Failing on Back to Back Connections

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

Moderator: Project members

Post Reply
Message
Author
jlcox5
500 Command not understood
Posts: 4
Joined: 2019-05-06 22:49
First name: Jonathan
Last name: Cox

Session Resumption Failing on Back to Back Connections

#1 Post by jlcox5 » 2019-05-06 23:35

Hi There,

I'm working with a company that has written some software for embedded systems that, among other things, serves as an FTP client. We have a scenario where back to back connections to a FileZilla Server fail when connecting to the data channel the second time.

Essentially, our procedure is:
- Connect to the FTPS server, do some things
- Close the connection
- Reconnect
- Attempt to do more things, and fail with an error 450 on the data connection

Here are the associated logs:
FileZilla Server 0.9.60 beta
Copyright 2001-2016 by Tim Kosse (tim.kosse@filezilla-project.org)
https://filezilla-project.org/
Connecting to server localhost:14147...
Connected, waiting for authentication
Logged on
You appear to be behind a NAT router. Please configure the passive mode settings and forward a range of ports in your router.
(000048)5/6/2019 16:30:53 PM - (not logged in) (10.1.1.124)> Connected on port 990, sending welcome message...
(000048)5/6/2019 16:30:53 PM - (not logged in) (10.1.1.124)> 220-FileZilla Server 0.9.60 beta
(000048)5/6/2019 16:30:53 PM - (not logged in) (10.1.1.124)> 220-written by Tim Kosse (tim.kosse@filezilla-project.org)
(000048)5/6/2019 16:30:53 PM - (not logged in) (10.1.1.124)> 220 Please visit https://filezilla-project.org/
(000048)5/6/2019 16:30:54 PM - (not logged in) (10.1.1.124)> TLS connection established
(000048)5/6/2019 16:30:54 PM - (not logged in) (10.1.1.124)> PBSZ 0
(000048)5/6/2019 16:30:54 PM - (not logged in) (10.1.1.124)> 200 PBSZ=0
(000048)5/6/2019 16:30:54 PM - (not logged in) (10.1.1.124)> PROT P
(000048)5/6/2019 16:30:54 PM - (not logged in) (10.1.1.124)> 200 Protection level set to P
(000048)5/6/2019 16:30:54 PM - (not logged in) (10.1.1.124)> USER RLTest
(000048)5/6/2019 16:30:54 PM - (not logged in) (10.1.1.124)> 331 Password required for rltest
(000048)5/6/2019 16:30:54 PM - (not logged in) (10.1.1.124)> PASS ****
(000048)5/6/2019 16:30:54 PM - rltest (10.1.1.124)> 230 Logged on
(000048)5/6/2019 16:30:54 PM - rltest (10.1.1.124)> TYPE A
(000048)5/6/2019 16:30:54 PM - rltest (10.1.1.124)> 200 Type set to A
(000048)5/6/2019 16:30:54 PM - rltest (10.1.1.124)> PORT 10,1,1,124,100,234
(000048)5/6/2019 16:30:54 PM - rltest (10.1.1.124)> 200 Port command successful
(000048)5/6/2019 16:30:54 PM - rltest (10.1.1.124)> STOR FOOBARLONG.TXT
(000048)5/6/2019 16:30:54 PM - rltest (10.1.1.124)> 150 Opening data channel for file upload to server of "/FOOBARLONG.TXT"
(000048)5/6/2019 16:30:54 PM - rltest (10.1.1.124)> TLS connection for data connection established
(000048)5/6/2019 16:31:01 PM - rltest (10.1.1.124)> QUIT
(000048)5/6/2019 16:31:01 PM - rltest (10.1.1.124)> disconnected.
(000049)5/6/2019 16:31:05 PM - (not logged in) (10.1.1.124)> Connected on port 990, sending welcome message...
(000049)5/6/2019 16:31:05 PM - (not logged in) (10.1.1.124)> 220-FileZilla Server 0.9.60 beta
(000049)5/6/2019 16:31:05 PM - (not logged in) (10.1.1.124)> 220-written by Tim Kosse (tim.kosse@filezilla-project.org)
(000049)5/6/2019 16:31:05 PM - (not logged in) (10.1.1.124)> 220 Please visit https://filezilla-project.org/
(000049)5/6/2019 16:31:05 PM - (not logged in) (10.1.1.124)> TLS connection established
(000049)5/6/2019 16:31:05 PM - (not logged in) (10.1.1.124)> PBSZ 0
(000049)5/6/2019 16:31:05 PM - (not logged in) (10.1.1.124)> 200 PBSZ=0
(000049)5/6/2019 16:31:05 PM - (not logged in) (10.1.1.124)> PROT P
(000049)5/6/2019 16:31:05 PM - (not logged in) (10.1.1.124)> 200 Protection level set to P
(000049)5/6/2019 16:31:05 PM - (not logged in) (10.1.1.124)> USER RLTest
(000049)5/6/2019 16:31:05 PM - (not logged in) (10.1.1.124)> 331 Password required for rltest
(000049)5/6/2019 16:31:05 PM - (not logged in) (10.1.1.124)> PASS ****
(000049)5/6/2019 16:31:05 PM - rltest (10.1.1.124)> 230 Logged on
(000049)5/6/2019 16:31:05 PM - rltest (10.1.1.124)> TYPE A
(000049)5/6/2019 16:31:05 PM - rltest (10.1.1.124)> 200 Type set to A
(000049)5/6/2019 16:31:05 PM - rltest (10.1.1.124)> PORT 10,1,1,124,100,235
(000049)5/6/2019 16:31:05 PM - rltest (10.1.1.124)> 200 Port command successful
(000049)5/6/2019 16:31:05 PM - rltest (10.1.1.124)> STOR FOOBARLONG.TXT
(000049)5/6/2019 16:31:05 PM - rltest (10.1.1.124)> 150 Opening data channel for file upload to server of "/FOOBARLONG.TXT"
(000049)5/6/2019 16:31:06 PM - rltest (10.1.1.124)> 450 TLS session of data connection has not resumed or the session does not match the control connection
(000049)5/6/2019 16:31:08 PM - rltest (10.1.1.124)> QUIT
(000049)5/6/2019 16:31:08 PM - rltest (10.1.1.124)> 221 Goodbye
(000049)5/6/2019 16:31:08 PM - rltest (10.1.1.124)> disconnected.
We have found a way to get around this by clearing our stored sessions before new connections, but I wanted to reach out and see if this was the expected behavior. We've spent some time debugging things on our side, and the session seems to be stored and maintained properly. Any thoughts or insights would be appreciated. Thank you!

Kind Regards,
Jon

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

Re: Session Resumption Failing on Back to Back Connections

#2 Post by botg » 2019-05-07 07:02

Make sure you are trying to resume the session of the currently active control connection, not the session of a past control connection.

Past sessions intentionally cannot be used, it would not be secure.

jlcox5
500 Command not understood
Posts: 4
Joined: 2019-05-06 22:49
First name: Jonathan
Last name: Cox

Re: Session Resumption Failing on Back to Back Connections

#3 Post by jlcox5 » 2019-05-07 17:00

That is exactly what is happening, and explains why clearing out the session cache after the first connection closes resolves the issue. Thank you very much for the response!

Kind Regards,
Jon

jlcox5
500 Command not understood
Posts: 4
Joined: 2019-05-06 22:49
First name: Jonathan
Last name: Cox

Re: Session Resumption Failing on Back to Back Connections

#4 Post by jlcox5 » 2019-05-07 17:55

One quick follow up: The active control session on the second connection resumes the previous connection from the first, and that looks like it's successful. It only fails on the data connection. It seems that if the sessions were not intended to be used between connections, it would likely fail during the initial connection. Is that correct, or am I misunderstanding something? Thank you again!

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

Re: Session Resumption Failing on Back to Back Connections

#5 Post by botg » 2019-05-07 18:06

You are merely attempting resumption on the second control connection, the session isn't actually resumed.

jlcox5
500 Command not understood
Posts: 4
Joined: 2019-05-06 22:49
First name: Jonathan
Last name: Cox

Re: Session Resumption Failing on Back to Back Connections

#6 Post by jlcox5 » 2019-05-07 18:18

Ahhh, okay, thank you for the clarification, that makes much more sense.

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

Re: Session Resumption Failing on Back to Back Connections

#7 Post by botg » 2019-05-07 20:08

There's an old post of mine highlighting what can happen if session resumption isn't correctly handled: viewtopic.php?p=137191#p137191

Post Reply