Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

libcurl with SChannel hangs/times-out after FTPS transfer completes #7068

Closed
JDepooter opened this issue May 14, 2021 · 2 comments
Closed

libcurl with SChannel hangs/times-out after FTPS transfer completes #7068

JDepooter opened this issue May 14, 2021 · 2 comments

Comments

@JDepooter
Copy link
Contributor

@JDepooter JDepooter commented May 14, 2021

I did this

./curld --verbose --ssl --insecure --user xxxx:xxxx --output out.txt ftp://dev-tls-test:33333/12317_bytes.txt

The download actually works fine, the file is fully downloaded quite quickly. However, once the file is downloaded, the curl command line tool appears wait until it detects that the control connection is disconnected. In our application which uses libcurl, there is a hang until the configured timeout length is reached.

% Total % Received % Xferd Average Speed Time Time Time Current
Dload Upload Total Spent Left Speed
100 12317 100 12317 0 0 33 0 0:10:06 0:10:00 0:00:06 0
curl: (28) control connection looks dead

I have only reproduced this issue when libcurl is built with the SChannel TLS backend. When built with the OpenSSL backend, the curl command terminates as soon as the download is complete.

This server is not publicly accessible. However, it is just a stock Ubuntu 18.04 machine running vsftpd on port 33333.

$ vsftpd -version
vsftpd: version 3.0.3

The server is using more-or-less the default config, except for the port number. It is using the default "snakeoil" certificates, hence the --insecure flag on the curl command line. I've generated the target file using this command:

$ perl -e "print '0' x 12317" > 12317_bytes.txt

The file size does not seem to be relevant, this particular size just matches the size of the file used in our customer's issue. I have reproduced this timeout with various file sizes.

Examining the verbose output, I see the following log, starting from when the data transfer begins:

< 150 Opening BINARY mode data connection for 12317_bytes.txt (12317 bytes).
Maxdownload = -1
Getting file with size: 12317
Doing the SSL/TLS handshake on the data stream
schannel: SSL/TLS connection with dev-tls-test port 33333 (step 1/3)
schannel: re-using existing credential handle
schannel: incremented credential handle refcount = 3
schannel: sending initial handshake data: sending 350 bytes...
schannel: sent initial handshake data: sent 350 bytes
schannel: SSL/TLS connection with dev-tls-test port 33333 (step 2/3)
schannel: failed to receive handshake, need more data
schannel: SSL/TLS connection with dev-tls-test port 33333 (step 2/3)
schannel: encrypted data got 109
schannel: encrypted data buffer: offset 109 length 4096
schannel: sending next handshake data: sending 51 bytes...
schannel: SSL/TLS handshake complete
schannel: SSL/TLS connection with dev-tls-test port 33333 (step 3/3)
FTP 0x13bed3732c8 (line 468) state change from RETR to STOP
STATE: DOING_MORE => DID handle 0x13bed355f60; line 2133 (connection #0)
STATE: DID => PERFORMING handle 0x13bed355f60; line 2158 (connection #0)
schannel: client wants to read 12317 bytes
schannel: encdata_buffer resized 13341
schannel: encrypted data buffer: offset 0 length 13341
schannel: encrypted data got 1360
schannel: encrypted data buffer: offset 1360 length 13341
schannel: failed to decrypt data, need more data
schannel: schannel_recv cleanup
schannel: client wants to read 12317 bytes
schannel: encrypted data buffer: offset 1360 length 13341
schannel: encrypted data got 4080
schannel: encrypted data buffer: offset 5440 length 13341
schannel: failed to decrypt data, need more data
schannel: schannel_recv cleanup
schannel: client wants to read 12317 bytes
schannel: encrypted data buffer: offset 5440 length 13341
schannel: encrypted data got 2720
schannel: encrypted data buffer: offset 8160 length 13341
schannel: failed to decrypt data, need more data
schannel: schannel_recv cleanup
schannel: client wants to read 12317 bytes
schannel: encrypted data buffer: offset 8160 length 13341
schannel: encrypted data got 2720
schannel: encrypted data buffer: offset 10880 length 13341
schannel: failed to decrypt data, need more data
schannel: schannel_recv cleanup
schannel: client wants to read 12317 bytes
schannel: encrypted data buffer: offset 10880 length 13341
schannel: encrypted data got 1497
schannel: encrypted data buffer: offset 12377 length 13341
schannel: decrypted data length: 12317
schannel: decrypted data added: 12317
schannel: decrypted cached: offset 12317 length 12317
schannel: encrypted data length: 31
schannel: encrypted cached: offset 31 length 13341
schannel: encrypted data buffer: offset 31 length 13341
schannel: decrypted data buffer: offset 12317 length 12317
schannel: schannel_recv cleanup
schannel: decrypted data returned 12317
schannel: decrypted data buffer: offset 0 length 12317
{ [12317 bytes data]
100 12317 100 12317 0 0 414 0 0:00:29 0:00:29 --:--:-- 0

It seems that once the download is compete (decrypted buffer has 12317 bytes...), there are an additional 31 bytes in the encrypted buffer. I believe this is the TLS close_notify alert. Wireshark shows a 31 byte "encrypted alert" (typically this is the close_notify) arriving in the same packet as the final bytes of the file transfer. I think that libcurl is not aware that the close_notify has been sent, and therefore waits for it on the file transfer socket until a timeout is reached.

Although I only experienced this issue with SChannel, I feel like this is at least superficially similar to the problem in #6149, in which TLS messages on the file transfer connection are not processed correctly.

I have a proposed fix for this issue; I will open a pull request shortly.

I expected the following

The file is downloaded and curl terminates once the download is finished.

curl/libcurl version

curl built with the SChannel backend:

$ ./curld --version
curl 7.77.0-DEV (x86_64-pc-win32) libcurl/7.77.0-DEV Schannel
Release-Date: [unreleased]
Protocols: dict file ftp ftps gopher gophers http https imap imaps ldap ldaps mqtt pop3 pop3s rtsp smb smbs smtp smtps telnet tftp
Features: AsynchDNS Debug HSTS IPv6 Kerberos Largefile NTLM SPNEGO SSL SSPI Unicode UnixSockets alt-svc

operating system

Windows 10

@jay
Copy link
Member

@jay jay commented May 15, 2021

I wonder if #5284 is related

@JDepooter
Copy link
Contributor Author

@JDepooter JDepooter commented May 15, 2021

#5284 does seem very similar. Not sure why that didn't show up in my search for ftps issues. Regardless, the server linked in that issue appears to not be running any more, so I have not been able to see if my pull request fixes that issue.

@bagder bagder closed this in 77444b8 May 18, 2021
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Linked pull requests

Successfully merging a pull request may close this issue.

None yet
2 participants