Forum » Support and Bug Reports »

Post a reply

Before posting, please read how to report bug or request support effectively.

Bug reports without an attached log file are usually useless.

Options
Add an Attachment

If you do not want to add an Attachment to your Post, please leave the Fields blank.

(maximum 10 MB; please compress large files; only common media, archive, text and programming file formats are allowed)

Options

Topic review

martin

Thanks for your feedback.
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 :)
Guest

BTW, WinSCP is great :-)
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)
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.
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.
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 :)
martin

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?
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.
Guest

In comparison, FileZilla TLS transfer log
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.
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.
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.
martin

Re: Deadlock during TLS to Android

Please post session log file on Debug 1 level showing both transfer and non-transfer.
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.

Documentation

Support

Associations

Follow Us