Deadlock during TLS to Android

Advertisement

Guest

Deadlock during TLS to Android

This is what happens in the WinSCP log on data connection for non-transfers:
  • Data connection opened
  • Trying reuse main TLS session ID
Compare that to what happens during a transfer:
  • Data connection opened
  • Now forever stuck in an idle loop or TLS handshake code throws a timeout
The 1st line is in TransferSocket.cpp. The socket source code on Android shows stuck waiting as well. So it's a deadlock where both sides are waiting forever :)

When that 1st line is entered, there's a note that transfers have a special difference over non-transfers. Hence, only transfers are seeing a problem here.

TLSv1.2 and TLSv1.3 see this happen (did not try testing lower).

FileZilla works great but it does have a highly different TransferSocket.cpp today.

Android Conscrypt and BoringSSL deal with the sockets, TLS, and the client. So the handshake is done by those and WinSCP.

Reply with quote

Advertisement

Guest

Thanks for looking further into this :)

Hopefully the files show up.

I do seem to be seeing something a bit different today now after getting those logs. Although, its still failing during the handshake, but not with the same failure stack trace in the server side logs.
  • Winscp_transfer.log (24.85 KB, Private file)
  • Winscp_non_transfer.log (42.24 KB, Private file)

Reply with quote

Guest

Probably just me after looking at too many logs... the timeout is still happening 30 seconds later at SocketInputStream on the server side when its handshake timeout strikes.

Reply with quote

Guest

Something else happened here... rofl. An automatic script I use ran and tried some transfer in the non-transfer log. That was bad timing and I didn't notice until now.

That transfer is on non-TLS plain unencrypted connection. So, I guess now you can see TLS verses plain too lol.

Sorry about that.

Reply with quote

Advertisement

Guest

Built Conscrypt and BoringSSL from latest source and confirmed in use for server side. Made no difference.

Probably may see if I can do something simple from that source code anyway to get things working here regardless for multiple reasons.

Reply with quote

martin
Site Admin
martin avatar

Re: Deadlock during TLS to Android

Both logs contain a file transfer(s).
The Winscp_non_transfer.log contains a successful foreground transfers. While the Winscp_transfer.log contains a failed background transfer. Is that foreground/background the significant difference? Or am I missing something?

Reply with quote

Guest

Yes, you missed my post above. The transfer in the non_transfer log was an automatic script on unencrypted connection that was accidental.

Winscp_transfer.log is the one with the problem anyway. What are your thoughts on that one? Do you see a deadlock in that one from WinSCP that I'm seeing in server side or anything that can be fixed on the WinSCP side in your opinion?

Thanks :)

Reply with quote

Advertisement

Guest

Just an alternate way of showing where I'm seeing a problem with transfers only:

FTP TLS RFC...
https://www.rfc-editor.org/rfc/rfc4217#section-12.6
12.7. A Firewall-Friendly Data Transfer with Protection

Client Server
control data data control
====================================================================

PASV --------------------------------------------------------> (OKAY)
socket() (OKAY)
bind() (OKAY
<------------------------------------------ 227 (w,x,y,z,a,b) (OKAY)
socket() (OKAY)
STOR file ---------------------------------------------------> (OKAY)
connect() ----------> accept() (WinSCP fails to handshake here and there's nothing else to do pre handshake)
<-------------------------------------------------------- 150 (Never reaches here)
TLSneg() <---------> TLSneg()
TLSwrite() ---------> TLSread()
TLSshutdown() -------> TLSshutdown()
close() ---------> close()
<-------------------------------------------------------- 226
So, it doesn't look like server side can do anything else.

Reply with quote

Guest

It almost feels like WinSCP is getting into here where it talks about waiting for 1xx response which would be incorrect for TLS but this is a guess: https://github.com/winscp/winscp/blob/6.3.3/source/filezilla/TransferSocket.cpp#L387

Still, anyway it's here: https://github.com/winscp/winscp/blob/6.3.3/source/filezilla/TransferSocket.cpp#L385

then...

But the next log entry should be a few lines down right here: https://github.com/winscp/winscp/blob/6.3.3/source/filezilla/TransferSocket.cpp#L414C28-L414C45

then should be a short bit more to be the same as a non-transfer...
https://github.com/winscp/winscp/blob/6.3.3/source/filezilla/AsyncSslSocketLayer.cpp#L847

Something is not happening in there. The whole train stops.

Reply with quote

Guest

Just got it working! It is indeed going on wrong order and getting trapped at incorrectly waiting 1xx as below. Correct order for this situation I have in post above. The actual thing is that it can go before or after depending on the situation as per the RFC and currently WinSCP only accepts it before and not after here.

So there's some issue with WinSCP's use of waiting during transfers: https://github.com/winscp/winscp/blob/6.3.3/source/filezilla/TransferSocket.cpp#L387

The wrong order here works:
Client Server
control data data control
====================================================================

PASV --------------------------------------------------------> (OKAY)
socket() (OKAY)
bind() (OKAY
<------------------------------------------ 227 (w,x,y,z,a,b) (OKAY)
socket() (OKAY)
STOR file ---------------------------------------------------> (OKAY)
<-------------------------------------------------------- 150 (WRONG HERE BUT GETS EVERYTHING WORKING)
connect() ----------> accept() (FINALLY OKAY)
TLSneg() <---------> TLSneg() (OKAY)
TLSwrite() ---------> TLSread() (OKAY)
TLSshutdown() -------> TLSshutdown() (OKAY)
close() ---------> close() (OKAY)
<-------------------------------------------------------- 226 (OKAY)

Reply with quote

Advertisement

Guest

Ahhhh... That does work.

Didn't expect that. Couldn't find it anywhere before and happened to today while looking into things elsewhere.

Thank you :)

Reply with quote

Advertisement

You can post new topics in this forum