Comments (17)
jay
commented on June 7, 2024
2
#6149 sounds similar and my conclusion there was basically for each connection we need a separate optional state to do a proper SSL shutdown if the user specifies it or it's required because the server does not send the final message like for ftps data conn
see also https://curl.se/docs/knownbugs.html#FTPS_upload_data_loss_with_TLS_1
from curl.
blach
commented on June 7, 2024
This is the verbose output of the failing FTP upload command that eventually times out and results in a 0 byte file on the server:
* Connected to <redacted>.kasserver.com (85.13.<redacted>) port 21
< 220 FTP on <redacted>.kasserver.com ready
> AUTH SSL
< 234 AUTH SSL successful
} [5 bytes data]
* TLSv1.3 (OUT), TLS handshake, Client hello (1):
} [512 bytes data]
* TLSv1.3 (IN), TLS handshake, Server hello (2):
{ [88 bytes data]
* TLSv1.3 (OUT), TLS change cipher, Change cipher spec (1):
} [1 bytes data]
* TLSv1.3 (OUT), TLS handshake, Client hello (1):
} [512 bytes data]
* TLSv1.3 (IN), TLS handshake, Server hello (2):
{ [155 bytes data]
* TLSv1.3 (IN), TLS handshake, Encrypted Extensions (8):
{ [10 bytes data]
* TLSv1.3 (IN), TLS handshake, Certificate (11):
{ [4590 bytes data]
* TLSv1.3 (IN), TLS handshake, CERT verify (15):
{ [264 bytes data]
* TLSv1.3 (IN), TLS handshake, Finished (20):
{ [52 bytes data]
* TLSv1.3 (OUT), TLS handshake, Finished (20):
} [52 bytes data]
* SSL connection using TLSv1.3 / TLS_AES_256_GCM_SHA384 / secp256r1 / RSASSA-PSS
* Server certificate:
* subject: CN=*.kasserver.com
* start date: Dec 18 00:00:00 2023 GMT
* expire date: Jan 17 23:59:59 2025 GMT
* subjectAltName: host "<redacted>.kasserver.com" matched cert's "*.kasserver.com"
* issuer: C=GB; ST=Greater Manchester; L=Salford; O=Sectigo Limited; CN=Sectigo RSA Domain Validation Secure Server CA
* SSL certificate verify ok.
* Certificate level 0: Public key type RSA (2048/112 Bits/secBits), signed using sha256WithRSAEncryption
* Certificate level 1: Public key type RSA (2048/112 Bits/secBits), signed using sha384WithRSAEncryption
* Certificate level 2: Public key type RSA (4096/152 Bits/secBits), signed using sha384WithRSAEncryption
} [5 bytes data]
> USER <redacted>
{ [5 bytes data]
* TLSv1.3 (IN), TLS handshake, Newsession Ticket (4):
{ [57 bytes data]
* TLSv1.3 (IN), TLS handshake, Newsession Ticket (4):
{ [57 bytes data]
* old SSL session ID is stale, removing
{ [5 bytes data]
< 331 Password required for <redacted>
} [5 bytes data]
> PASS <redacted>
{ [5 bytes data]
< 230 User <redacted> logged in
} [5 bytes data]
> PBSZ 0
{ [5 bytes data]
< 200 PBSZ 0 successful
} [5 bytes data]
> PROT P
{ [5 bytes data]
< 200 Protection set to Private
} [5 bytes data]
> PWD
{ [5 bytes data]
< 257 "/" is the current directory
* Entry path is '/'
} [5 bytes data]
> CWD test
* ftp_perform ends with SECONDARY: 0
{ [5 bytes data]
< 250 CWD command successful
} [5 bytes data]
> EPSV
* Connect data stream passively
{ [5 bytes data]
< 229 Entering Extended Passive Mode (|||50218|)
* Connecting to 85.13.<redacted> (85.13.<redacted>) port 50218
* Trying 85.13.<redacted>:50218...
* Connected 2nd connection to 85.13.<redacted> port 50218
* SSL reusing session ID
} [5 bytes data]
* TLSv1.3 (OUT), TLS handshake, Client hello (1):
} [512 bytes data]
> TYPE I
{ [5 bytes data]
< 200 Type set to I
} [5 bytes data]
> STOR test.html
{ [5 bytes data]
< 150 Opening BINARY mode data connection for test.html
{ [5 bytes data]
* TLSv1.3 (IN), TLS handshake, Server hello (2):
{ [88 bytes data]
* TLSv1.3 (OUT), TLS change cipher, Change cipher spec (1):
} [1 bytes data]
* TLSv1.3 (OUT), TLS handshake, Client hello (1):
} [512 bytes data]
* TLSv1.3 (IN), TLS handshake, Server hello (2):
{ [161 bytes data]
* TLSv1.3 (IN), TLS handshake, Encrypted Extensions (8):
{ [10 bytes data]
* TLSv1.3 (IN), TLS handshake, Finished (20):
{ [52 bytes data]
* TLSv1.3 (OUT), TLS handshake, Finished (20):
} [52 bytes data]
* SSL connection using TLSv1.3 / TLS_AES_256_GCM_SHA384 / secp256r1 / UNDEF
* Server certificate:
* subject: CN=*.kasserver.com
* start date: Dec 18 00:00:00 2023 GMT
* expire date: Jan 17 23:59:59 2025 GMT
* subjectAltName: host "<redacted>.kasserver.com" matched cert's "*.kasserver.com"
* issuer: C=GB; ST=Greater Manchester; L=Salford; O=Sectigo Limited; CN=Sectigo RSA Domain Validation Secure Server CA
* SSL certificate verify ok.
} [5 bytes data]
* upload completely sent off: 18815 bytes
* Remembering we are in dir "test/"
} [5 bytes data]
* TLSv1.3 (OUT), TLS alert, close notify (256):
} [2 bytes data]
* FTP response timeout
* control connection looks dead
* Closing connection
} [5 bytes data]
* TLSv1.3 (OUT), TLS alert, close notify (256):
} [2 bytes data]
from curl.
blach
commented on June 7, 2024
The problem might be related to #6149
This issue was actually discovered when using libcurl to upload a file >18KB using FTP with explicit auth SSL to that server.
With libcurl and curl_easy_perform I get the error "Transferred a partial file".
from curl.
blach
commented on June 7, 2024
I just set up a brand new vsftpd server on a Debian 12 machine that is publicly accessible.
I created a new RSA 4096 key and enabled SSL for the FTP server.
Now uploading a file larger than a certain size results in a 0 byte file on the server and the curl command times out.
Can I privately share the commands to reproduce this issue with you?
The problem is that the command only works once, then vsftp seems to keep accessing the file, so when the command is issued a second time, it shows a different behavior. That's why I wouldn't want to post this publicly.
from curl.
blach
commented on June 7, 2024
The redacted commands to reproduce this after setting up the vsftpd server with SSL are:
To create a local file with a size of 18 kB:
head --bytes 18432 /dev/zero > test-curl.txt
Upload the file:
curl --ssl-reqd --insecure ftp://<ip-address>/ -u <redacted> --upload-file test-curl.txt --verbose
The upload starts, times out, and results in a 0 byte "test-curl.txt" file on the server.
Uploading the same file to the same server with FileZilla using TLS 1.3 works without problems.
from curl.
blach
commented on June 7, 2024
I also asked the support team at all-inkl.com what FTP server software they are using. They answered that they are using ProFTPD from the original Ubuntu repository.
So it looks like this is an issue with both vsftpd and ProFTPD servers when using TLS 1.3.
from curl.
blach
commented on June 7, 2024
Can you reproduce this issue? Is there anything I can do to help?
from curl.
bagder
commented on June 7, 2024
@icing there's no upload among the new ftp tests yet is there?
from curl.
icing
commented on June 7, 2024
Added --upload-file tests in #13734. I see no problems with a local vsftpd with or without --ssl-reqd. TLSv1.3 is being used. I tested on my macOS machine using my own vsftpd build (homebrew one is not linked with openssl). Let's see what the CI jobs on other platforms say on the PR.
@blach could you add -v --trace-config ids,time,tcp,read and tell use what gets logged?
from curl.
icing
commented on June 7, 2024
Another thing to test with you vsftpd is if the setting require_ssl_reuse=NO makes any difference.
from curl.
blach
commented on June 7, 2024
I just added require_ssl_reuse=NO to /etc/vsftpd.conf, restarted the vsftpd service and ran the upload command again.
I see no difference in behavior. It still results in a 0 byte file on the server and a timeout of the upload.
from curl.
blach
commented on June 7, 2024
@blach could you add
-v --trace-config ids,time,tcp,readand tell use what gets logged?
Here is the log:
> curl --ssl-reqd --insecure ftp://<ipaddress>/ -u demo:<redacted> --upload-file test-curl.txt -v --trace-config ids,time,tcp,read
13:25:34.785068 [0-0] * Trying <ipaddress>:21...
13:25:34.785332 [0-0] * [TCP] cf_socket_open() -> 0, fd=6
13:25:34.785477 [0-0] * [TCP] local address 192.168.2.169 port 50977...
13:25:34.785502 [0-0] * [TCP] adjust_pollset, !connected, POLLOUT fd=6
13:25:34.785524 [0-0] * [TCP] adjust_pollset, !connected, POLLOUT fd=6
13:25:34.785548 [0-0] * [TCP] not connected yet
13:25:34.785569 [0-0] * [TCP] adjust_pollset, !connected, POLLOUT fd=6
13:25:34.785590 [0-0] * [TCP] adjust_pollset, !connected, POLLOUT fd=6
13:25:34.803875 [0-0] * [TCP] connected
13:25:34.803908 [0-0] * Connected to <ipaddress> (<ipaddress>) port 21
13:25:34.824553 [0-0] * [TCP] nw_in_read(len=900, fd=6) -> 20, err=0
13:25:34.824587 [0-0] * [TCP] recv(len=900) -> 20, err=0
13:25:34.824612 [0-0] < 220 (vsFTPd 3.0.3)
13:25:34.824711 [0-0] * [TCP] send(len=10) -> 10, err=0
13:25:34.824736 [0-0] > AUTH SSL
13:25:34.839978 [0-0] * [TCP] nw_in_read(len=900, fd=6) -> 31, err=0
13:25:34.840011 [0-0] * [TCP] recv(len=900) -> 31, err=0
13:25:34.840038 [0-0] < 234 Proceed with negotiation.
13:25:34.843937 [0-0] } [5 bytes data]
13:25:34.843979 [0-0] * TLSv1.3 (OUT), TLS handshake, Client hello (1):
13:25:34.844003 [0-0] } [512 bytes data]
13:25:34.844072 [0-0] * [TCP] send(len=517) -> 517, err=0
13:25:34.844104 [0-0] * [TCP] nw_in_read(len=5, fd=6) -> -1, err=81
13:25:34.844127 [0-0] * [TCP] recv(len=5) -> -1, err=81
13:25:34.862637 [0-0] * [TCP] nw_in_read(len=5, fd=6) -> 5, err=0
13:25:34.862674 [0-0] * [TCP] recv(len=5) -> 5, err=0
13:25:34.862700 [0-0] { [5 bytes data]
13:25:34.862748 [0-0] * [TCP] nw_in_read(len=88, fd=6) -> 88, err=0
13:25:34.862775 [0-0] * [TCP] recv(len=88) -> 88, err=0
13:25:34.862807 [0-0] * TLSv1.3 (IN), TLS handshake, Server hello (2):
13:25:34.862833 [0-0] { [88 bytes data]
13:25:34.862903 [0-0] * TLSv1.3 (OUT), TLS change cipher, Change cipher spec (1):
13:25:34.862930 [0-0] } [1 bytes data]
13:25:34.863129 [0-0] * TLSv1.3 (OUT), TLS handshake, Client hello (1):
13:25:34.863159 [0-0] } [512 bytes data]
13:25:34.863257 [0-0] * [TCP] send(len=523) -> 523, err=0
13:25:34.863290 [0-0] * [TCP] nw_in_read(len=5, fd=6) -> 5, err=0
13:25:34.863317 [0-0] * [TCP] recv(len=5) -> 5, err=0
13:25:34.863344 [0-0] { [5 bytes data]
13:25:34.863387 [0-0] * [TCP] nw_in_read(len=1, fd=6) -> 1, err=0
13:25:34.863415 [0-0] * [TCP] recv(len=1) -> 1, err=0
13:25:34.863443 [0-0] * [TCP] nw_in_read(len=5, fd=6) -> -1, err=81
13:25:34.863469 [0-0] * [TCP] recv(len=5) -> -1, err=81
13:25:34.899315 [0-0] * [TCP] nw_in_read(len=5, fd=6) -> 5, err=0
13:25:34.899364 [0-0] * [TCP] recv(len=5) -> 5, err=0
13:25:34.899391 [0-0] { [5 bytes data]
13:25:34.899435 [0-0] * [TCP] nw_in_read(len=155, fd=6) -> 155, err=0
13:25:34.899461 [0-0] * [TCP] recv(len=155) -> 155, err=0
13:25:34.899495 [0-0] * TLSv1.3 (IN), TLS handshake, Server hello (2):
13:25:34.899521 [0-0] { [155 bytes data]
13:25:34.899996 [0-0] * [TCP] nw_in_read(len=5, fd=6) -> 5, err=0
13:25:34.900025 [0-0] * [TCP] recv(len=5) -> 5, err=0
13:25:34.900050 [0-0] { [5 bytes data]
13:25:34.900098 [0-0] * [TCP] nw_in_read(len=23, fd=6) -> 23, err=0
13:25:34.900124 [0-0] * [TCP] recv(len=23) -> 23, err=0
13:25:34.900157 [0-0] { [1 bytes data]
13:25:34.900200 [0-0] * TLSv1.3 (IN), TLS handshake, Encrypted Extensions (8):
13:25:34.900226 [0-0] { [6 bytes data]
13:25:34.900273 [0-0] * [TCP] nw_in_read(len=5, fd=6) -> 5, err=0
13:25:34.900299 [0-0] * [TCP] recv(len=5) -> 5, err=0
13:25:34.900326 [0-0] { [5 bytes data]
13:25:34.900368 [0-0] * [TCP] nw_in_read(len=62, fd=6) -> 62, err=0
13:25:34.900395 [0-0] * [TCP] recv(len=62) -> 62, err=0
13:25:34.900423 [0-0] { [1 bytes data]
13:25:34.900464 [0-0] * TLSv1.3 (IN), TLS handshake, Request CERT (13):
13:25:34.900490 [0-0] { [45 bytes data]
13:25:34.900544 [0-0] * [TCP] nw_in_read(len=5, fd=6) -> 5, err=0
13:25:34.900570 [0-0] * [TCP] recv(len=5) -> 5, err=0
13:25:34.900596 [0-0] { [5 bytes data]
13:25:34.900637 [0-0] * [TCP] nw_in_read(len=1411, fd=6) -> 1411, err=0
13:25:34.900662 [0-0] * [TCP] recv(len=1411) -> 1411, err=0
13:25:34.900695 [0-0] { [1 bytes data]
13:25:34.900740 [0-0] * TLSv1.3 (IN), TLS handshake, Certificate (11):
13:25:34.900767 [0-0] { [1394 bytes data]
13:25:34.902005 [0-0] * [TCP] nw_in_read(len=5, fd=6) -> 5, err=0
13:25:34.902037 [0-0] * [TCP] recv(len=5) -> 5, err=0
13:25:34.902064 [0-0] { [5 bytes data]
13:25:34.902112 [0-0] * [TCP] nw_in_read(len=537, fd=6) -> 537, err=0
13:25:34.902139 [0-0] * [TCP] recv(len=537) -> 537, err=0
13:25:34.902170 [0-0] { [1 bytes data]
13:25:34.902213 [0-0] * TLSv1.3 (IN), TLS handshake, CERT verify (15):
13:25:34.902240 [0-0] { [520 bytes data]
13:25:34.902488 [0-0] * [TCP] nw_in_read(len=5, fd=6) -> 5, err=0
13:25:34.902516 [0-0] * [TCP] recv(len=5) -> 5, err=0
13:25:34.902542 [0-0] { [5 bytes data]
13:25:34.902589 [0-0] * [TCP] nw_in_read(len=69, fd=6) -> 69, err=0
13:25:34.902615 [0-0] * [TCP] recv(len=69) -> 69, err=0
13:25:34.902643 [0-0] { [1 bytes data]
13:25:34.902693 [0-0] * TLSv1.3 (IN), TLS handshake, Finished (20):
13:25:34.902719 [0-0] { [52 bytes data]
13:25:34.902830 [0-0] * TLSv1.3 (OUT), TLS handshake, Certificate (11):
13:25:34.902857 [0-0] } [8 bytes data]
13:25:34.902905 [0-0] * TLSv1.3 (OUT), TLS handshake, Finished (20):
13:25:34.902932 [0-0] } [52 bytes data]
13:25:34.903088 [0-0] * [TCP] send(len=104) -> 104, err=0
13:25:34.903149 [0-0] * SSL connection using TLSv1.3 / TLS_AES_256_GCM_SHA384 / secp256r1 / RSASSA-PSS
13:25:34.903180 [0-0] * Server certificate:
13:25:34.903212 [0-0] * subject: C=DE; ST=Some-State; L=Test; O=Test
13:25:34.903242 [0-0] * start date: May 8 16:40:22 2024 GMT
13:25:34.903271 [0-0] * expire date: May 6 16:40:22 2034 GMT
13:25:34.903300 [0-0] * issuer: C=DE; ST=Some-State; L=Test; O=Test
13:25:34.903328 [0-0] * SSL certificate verify result: self-signed certificate (18), continuing anyway.
13:25:34.903359 [0-0] * Certificate level 0: Public key type RSA (4096/152 Bits/secBits), signed using sha256WithRSAEncryption
13:25:34.903408 [0-0] } [5 bytes data]
13:25:34.903473 [0-0] * [TCP] send(len=33) -> 33, err=0
13:25:34.903499 [0-0] > USER demo
13:25:34.917653 [0-0] * [TCP] nw_in_read(len=5, fd=6) -> 5, err=0
13:25:34.917688 [0-0] * [TCP] recv(len=5) -> 5, err=0
13:25:34.917715 [0-0] { [5 bytes data]
13:25:34.917758 [0-0] * [TCP] nw_in_read(len=250, fd=6) -> 250, err=0
13:25:34.917785 [0-0] * [TCP] recv(len=250) -> 250, err=0
13:25:34.917815 [0-0] { [1 bytes data]
13:25:34.917862 [0-0] * TLSv1.3 (IN), TLS handshake, Newsession Ticket (4):
13:25:34.917889 [0-0] { [233 bytes data]
13:25:34.917954 [0-0] * [TCP] nw_in_read(len=5, fd=6) -> 5, err=0
13:25:34.917980 [0-0] * [TCP] recv(len=5) -> 5, err=0
13:25:34.918006 [0-0] { [5 bytes data]
13:25:34.918046 [0-0] * [TCP] nw_in_read(len=250, fd=6) -> 250, err=0
13:25:34.918073 [0-0] * [TCP] recv(len=250) -> 250, err=0
13:25:34.918101 [0-0] { [1 bytes data]
13:25:34.918145 [0-0] * TLSv1.3 (IN), TLS handshake, Newsession Ticket (4):
13:25:34.918171 [0-0] { [233 bytes data]
13:25:34.918220 [0-0] * old SSL session ID is stale, removing
13:25:34.918252 [0-0] * [TCP] nw_in_read(len=5, fd=6) -> 5, err=0
13:25:34.918279 [0-0] * [TCP] recv(len=5) -> 5, err=0
13:25:34.918306 [0-0] { [5 bytes data]
13:25:34.918348 [0-0] * [TCP] nw_in_read(len=51, fd=6) -> 51, err=0
13:25:34.918374 [0-0] * [TCP] recv(len=51) -> 51, err=0
13:25:34.918401 [0-0] { [1 bytes data]
13:25:34.918444 [0-0] < 331 Please specify the password.
13:25:34.918480 [0-0] } [5 bytes data]
13:25:34.918563 [0-0] * [TCP] send(len=33) -> 33, err=0
13:25:34.918592 [0-0] > PASS <redacted>
13:25:34.987728 [0-0] * [TCP] nw_in_read(len=5, fd=6) -> 5, err=0
13:25:34.987807 [0-0] * [TCP] recv(len=5) -> 5, err=0
13:25:34.987845 [0-0] { [5 bytes data]
13:25:34.987911 [0-0] * [TCP] nw_in_read(len=40, fd=6) -> 40, err=0
13:25:34.987948 [0-0] * [TCP] recv(len=40) -> 40, err=0
13:25:34.988021 [0-0] { [1 bytes data]
13:25:34.988161 [0-0] < 230 Login successful.
13:25:34.988590 [0-0] } [5 bytes data]
13:25:34.988737 [0-0] * [TCP] send(len=30) -> 30, err=0
13:25:34.988844 [0-0] > PBSZ 0
13:25:35.002428 [0-0] * [TCP] nw_in_read(len=5, fd=6) -> 5, err=0
13:25:35.002519 [0-0] * [TCP] recv(len=5) -> 5, err=0
13:25:35.002556 [0-0] { [5 bytes data]
13:25:35.002620 [0-0] * [TCP] nw_in_read(len=37, fd=6) -> 37, err=0
13:25:35.002656 [0-0] * [TCP] recv(len=37) -> 37, err=0
13:25:35.002707 [0-0] { [1 bytes data]
13:25:35.002764 [0-0] < 200 PBSZ set to 0.
13:25:35.002813 [0-0] } [5 bytes data]
13:25:35.002927 [0-0] * [TCP] send(len=30) -> 30, err=0
13:25:35.002964 [0-0] > PROT P
13:25:35.020002 [0-0] * [TCP] nw_in_read(len=5, fd=6) -> 5, err=0
13:25:35.020069 [0-0] * [TCP] recv(len=5) -> 5, err=0
13:25:35.020106 [0-0] { [5 bytes data]
13:25:35.020166 [0-0] * [TCP] nw_in_read(len=40, fd=6) -> 40, err=0
13:25:35.020202 [0-0] * [TCP] recv(len=40) -> 40, err=0
13:25:35.020249 [0-0] { [1 bytes data]
13:25:35.020307 [0-0] < 200 PROT now Private.
13:25:35.020355 [0-0] } [5 bytes data]
13:25:35.020470 [0-0] * [TCP] send(len=27) -> 27, err=0
13:25:35.020572 [0-0] > PWD
13:25:35.034769 [0-0] * [TCP] nw_in_read(len=5, fd=6) -> 5, err=0
13:25:35.034812 [0-0] * [TCP] recv(len=5) -> 5, err=0
13:25:35.034843 [0-0] { [5 bytes data]
13:25:35.034896 [0-0] * [TCP] nw_in_read(len=60, fd=6) -> 60, err=0
13:25:35.034928 [0-0] * [TCP] recv(len=60) -> 60, err=0
13:25:35.034964 [0-0] { [1 bytes data]
13:25:35.035013 [0-0] < 257 "/home/demo" is the current directory
13:25:35.035048 [0-0] * Entry path is '/home/demo'
13:25:35.035082 [0-0] * Request has same path as previous transfer
13:25:35.035120 [0-0] } [5 bytes data]
13:25:35.035210 [0-0] * [TCP] send(len=28) -> 28, err=0
13:25:35.035242 [0-0] > EPSV
13:25:35.035272 [0-0] * Connect data stream passively
13:25:35.035307 [0-0] * ftp_perform ends with SECONDARY: 0
13:25:35.050290 [0-0] * [TCP] nw_in_read(len=5, fd=6) -> 5, err=0
13:25:35.050336 [0-0] * [TCP] recv(len=5) -> 5, err=0
13:25:35.050376 [0-0] { [5 bytes data]
13:25:35.050443 [0-0] * [TCP] nw_in_read(len=65, fd=6) -> 65, err=0
13:25:35.050481 [0-0] * [TCP] recv(len=65) -> 65, err=0
13:25:35.050526 [0-0] { [1 bytes data]
13:25:35.050587 [0-0] < 229 Entering Extended Passive Mode (|||57503|)
13:25:35.051398 [0-0] * Connecting to <ipaddress> (<ipaddress>) port 57503
13:25:35.051499 [0-0] * Trying <ipaddress>:57503...
13:25:35.051564 [0-0] * [TCP-1] cf_socket_open() -> 0, fd=7
13:25:35.051730 [0-0] * [TCP-1] local address 192.168.2.169 port 50978...
13:25:35.051775 [0-0] * [TCP-1] adjust_pollset, !connected, POLLOUT fd=7
13:25:35.051816 [0-0] * [TCP-1] adjust_pollset, !connected, POLLOUT fd=7
13:25:35.051862 [0-0] * [TCP-1] not connected yet
13:25:35.051901 [0-0] * [TCP-1] adjust_pollset, !connected, POLLOUT fd=7
13:25:35.051940 [0-0] * [TCP-1] adjust_pollset, !connected, POLLOUT fd=7
13:25:35.068188 [0-0] * [TCP-1] connected
13:25:35.068283 [0-0] * Connected 2nd connection to <ipaddress> port 57503
13:25:35.071746 [0-0] * SSL reusing session ID
13:25:35.072515 [0-0] } [5 bytes data]
13:25:35.072579 [0-0] * TLSv1.3 (OUT), TLS handshake, Client hello (1):
13:25:35.072617 [0-0] } [565 bytes data]
13:25:35.073082 [0-0] * [TCP-1] send(len=570) -> 570, err=0
13:25:35.073140 [0-0] * [TCP-1] nw_in_read(len=5, fd=7) -> -1, err=81
13:25:35.073176 [0-0] * [TCP-1] recv(len=5) -> -1, err=81
13:25:35.073256 [0-0] } [5 bytes data]
13:25:35.073356 [0-0] * [TCP] send(len=30) -> 30, err=0
13:25:35.073393 [0-0] > TYPE I
13:25:35.087859 [0-0] * [TCP-1] nw_in_read(len=5, fd=7) -> -1, err=81
13:25:35.087945 [0-0] * [TCP-1] recv(len=5) -> -1, err=81
13:25:35.088041 [0-0] * [TCP] nw_in_read(len=5, fd=6) -> 5, err=0
13:25:35.088089 [0-0] * [TCP] recv(len=5) -> 5, err=0
13:25:35.088139 [0-0] { [5 bytes data]
13:25:35.088221 [0-0] * [TCP] nw_in_read(len=48, fd=6) -> 48, err=0
13:25:35.088327 [0-0] * [TCP] recv(len=48) -> 48, err=0
13:25:35.088406 [0-0] { [1 bytes data]
13:25:35.088478 [0-0] < 200 Switching to Binary mode.
13:25:35.088561 [0-0] } [5 bytes data]
13:25:35.089104 [0-0] * [TCP] send(len=42) -> 42, err=0
13:25:35.089153 [0-0] > STOR test-curl.txt
13:25:35.103656 [0-0] * [TCP-1] nw_in_read(len=5, fd=7) -> 5, err=0
13:25:35.103718 [0-0] * [TCP-1] recv(len=5) -> 5, err=0
13:25:35.103755 [0-0] { [5 bytes data]
13:25:35.103816 [0-0] * [TCP-1] nw_in_read(len=88, fd=7) -> 88, err=0
13:25:35.103853 [0-0] * [TCP-1] recv(len=88) -> 88, err=0
13:25:35.103902 [0-0] * TLSv1.3 (IN), TLS handshake, Server hello (2):
13:25:35.103937 [0-0] { [88 bytes data]
13:25:35.104218 [0-0] * TLSv1.3 (OUT), TLS change cipher, Change cipher spec (1):
13:25:35.104257 [0-0] } [1 bytes data]
13:25:35.104995 [0-0] * TLSv1.3 (OUT), TLS handshake, Client hello (1):
13:25:35.105102 [0-0] } [598 bytes data]
13:25:35.105233 [0-0] * [TCP-1] send(len=609) -> 609, err=0
13:25:35.105276 [0-0] * [TCP-1] nw_in_read(len=5, fd=7) -> 5, err=0
13:25:35.105313 [0-0] * [TCP-1] recv(len=5) -> 5, err=0
13:25:35.105350 [0-0] { [5 bytes data]
13:25:35.105408 [0-0] * [TCP-1] nw_in_read(len=1, fd=7) -> 1, err=0
13:25:35.105462 [0-0] * [TCP-1] recv(len=1) -> 1, err=0
13:25:35.105500 [0-0] * [TCP-1] nw_in_read(len=5, fd=7) -> -1, err=81
13:25:35.105535 [0-0] * [TCP-1] recv(len=5) -> -1, err=81
13:25:35.105586 [0-0] * [TCP] nw_in_read(len=5, fd=6) -> 5, err=0
13:25:35.105621 [0-0] * [TCP] recv(len=5) -> 5, err=0
13:25:35.105655 [0-0] { [5 bytes data]
13:25:35.105740 [0-0] * [TCP] nw_in_read(len=39, fd=6) -> 39, err=0
13:25:35.105776 [0-0] * [TCP] recv(len=39) -> 39, err=0
13:25:35.105842 [0-0] { [1 bytes data]
13:25:35.105897 [0-0] < 150 Ok to send data.
13:25:35.120733 [0-0] * [TCP-1] nw_in_read(len=5, fd=7) -> 5, err=0
13:25:35.120810 [0-0] * [TCP-1] recv(len=5) -> 5, err=0
13:25:35.120847 [0-0] { [5 bytes data]
13:25:35.120902 [0-0] * [TCP-1] nw_in_read(len=161, fd=7) -> 161, err=0
13:25:35.120933 [0-0] * [TCP-1] recv(len=161) -> 161, err=0
13:25:35.120989 [0-0] * TLSv1.3 (IN), TLS handshake, Server hello (2):
13:25:35.121018 [0-0] { [161 bytes data]
13:25:35.122061 [0-0] * [TCP-1] nw_in_read(len=5, fd=7) -> 5, err=0
13:25:35.122109 [0-0] * [TCP-1] recv(len=5) -> 5, err=0
13:25:35.122138 [0-0] { [5 bytes data]
13:25:35.122189 [0-0] * [TCP-1] nw_in_read(len=23, fd=7) -> 23, err=0
13:25:35.122218 [0-0] * [TCP-1] recv(len=23) -> 23, err=0
13:25:35.122262 [0-0] { [1 bytes data]
13:25:35.122308 [0-0] * TLSv1.3 (IN), TLS handshake, Encrypted Extensions (8):
13:25:35.122337 [0-0] { [6 bytes data]
13:25:35.122390 [0-0] * [TCP-1] nw_in_read(len=5, fd=7) -> 5, err=0
13:25:35.122419 [0-0] * [TCP-1] recv(len=5) -> 5, err=0
13:25:35.122447 [0-0] { [5 bytes data]
13:25:35.122496 [0-0] * [TCP-1] nw_in_read(len=69, fd=7) -> 69, err=0
13:25:35.122525 [0-0] * [TCP-1] recv(len=69) -> 69, err=0
13:25:35.122558 [0-0] { [1 bytes data]
13:25:35.122614 [0-0] * TLSv1.3 (IN), TLS handshake, Finished (20):
13:25:35.122643 [0-0] { [52 bytes data]
13:25:35.122775 [0-0] * TLSv1.3 (OUT), TLS handshake, Finished (20):
13:25:35.122804 [0-0] } [52 bytes data]
13:25:35.122987 [0-0] * [TCP-1] send(len=74) -> 74, err=0
13:25:35.123386 [0-0] * SSL connection using TLSv1.3 / TLS_AES_256_GCM_SHA384 / secp256r1 / UNDEF
13:25:35.123421 [0-0] * Server certificate:
13:25:35.123590 [0-0] * subject: C=DE; ST=Some-State; L=Test; O=Test
13:25:35.123631 [0-0] * start date: May 8 16:40:22 2024 GMT
13:25:35.123661 [0-0] * expire date: May 6 16:40:22 2034 GMT
13:25:35.123695 [0-0] * issuer: C=DE; ST=Some-State; L=Test; O=Test
13:25:35.123730 [0-0] * SSL certificate verify result: self-signed certificate (18), continuing anyway.
13:25:35.123778 [0-0] * Certificate level 0: Public key type RSA (4096/152 Bits/secBits), signed using sha256WithRSAEncryption
13:25:35.125499 [0-0] } [5 bytes data]
13:25:35.125728 [0-0] * [TCP-1] send(len=16406) -> 16406, err=0
13:25:35.125776 [0-0] } [5 bytes data]
13:25:35.125844 [0-0] * [TCP-1] send(len=2070) -> 2070, err=0
13:25:35.125882 [0-0] } [18432 bytes data]
13:25:35.125949 [0-0] * upload completely sent off: 18432 bytes
13:25:35.125995 [0-0] * Remembering we are in dir ""
13:25:35.126044 [0-0] * [TCP-1] nw_in_read(len=5, fd=7) -> -1, err=81
13:25:35.126084 [0-0] * [TCP-1] recv(len=5) -> -1, err=81
13:25:35.126128 [0-0] } [5 bytes data]
13:25:35.126194 [0-0] * [TCP-1] send(len=24) -> 24, err=0
13:25:35.126235 [0-0] * TLSv1.3 (OUT), TLS alert, close notify (256):
13:25:35.126273 [0-0] } [2 bytes data]
13:25:35.126334 [0-0] * [TCP-1] nw_in_read(len=5, fd=7) -> -1, err=81
13:25:35.126372 [0-0] * [TCP-1] recv(len=5) -> -1, err=81
13:25:35.126463 [0-0] * [TCP-1] cf_socket_close(7)
13:25:35.126517 [0-0] * [TCP-1] destroy
13:25:35.126563 [0-0] * [TCP] nw_in_read(len=5, fd=6) -> -1, err=81
13:25:35.126601 [0-0] * [TCP] recv(len=5) -> -1, err=81
100 18432 0 0 100 18432 0 305 0:01:00 0:01:00 --:--:-- 013:26:35.132407 [0-0] * FTP response timeout
13:26:35.132514 [0-0] * control connection looks dead
100 18432 0 0 100 18432 0 305 0:01:00 0:01:00 --:--:-- 0
13:26:35.132831 [0-0] * Closing connection
13:26:35.132977 [0-0] * [TCP] nw_in_read(len=5, fd=6) -> -1, err=81
13:26:35.133041 [0-0] * [TCP] recv(len=5) -> -1, err=81
13:26:35.133133 [0-0] } [5 bytes data]
13:26:35.133487 [0-0] * [TCP] send(len=24) -> 24, err=0
13:26:35.133561 [0-0] * TLSv1.3 (OUT), TLS alert, close notify (256):
13:26:35.133622 [0-0] } [2 bytes data]
13:26:35.133735 [0-0] * [TCP] nw_in_read(len=5, fd=6) -> -1, err=81
13:26:35.133800 [0-0] * [TCP] recv(len=5) -> -1, err=81
13:26:35.134044 [0-0] * [TCP] cf_socket_close(6)
13:26:35.134316 [0-0] * [TCP] destroy
curl: (28) FTP response timeout
from curl.
blach
commented on June 7, 2024
Some additional details:
I just tried running the curl command on the server that runs the vsftpd server.
The server runs Debian 12.5 Bookworm which comes with curl 7.88.1.
Curl 7.88.1 on the Debian server also resulted in a timeout and a 0 byte file.
Then I installed curl 8.7.1 from bookworm backports.
This version uploads the file to the vsftpd server running on the same server successfully!
So, curl 8.7.1 from Homebrew on my Mac shows the error while curl 8.7.1 on Debian does not show the error.
On my Mac:
curl 8.7.1 (aarch64-apple-darwin23.4.0) libcurl/8.7.1 (SecureTransport) OpenSSL/3.3.0 zlib/1.2.12 brotli/1.1.0 zstd/1.5.6 libidn2/2.3.7 libssh2/1.11.0 nghttp2/1.61.0 librtmp/2.3 OpenLDAP/2.6.7
Release-Date: 2024-03-27
Protocols: dict file ftp ftps gopher gophers http https imap imaps ipfs ipns ldap ldaps mqtt pop3 pop3s rtmp rtsp scp sftp smb smbs smtp smtps telnet tftp
Features: alt-svc AsynchDNS brotli GSS-API HSTS HTTP2 HTTPS-proxy IDN IPv6 Kerberos Largefile libz MultiSSL NTLM SPNEGO SSL threadsafe TLS-SRP UnixSockets zstd
On the Debian server:
curl 8.7.1 (x86_64-pc-linux-gnu) libcurl/8.7.1 OpenSSL/3.0.11 zlib/1.2.13 brotli/1.0.9 zstd/1.5.4 libidn2/2.3.3 libpsl/0.21.2 libssh2/1.10.0 nghttp2/1.52.0 librtmp/2.3 OpenLDAP/2.5.13
Release-Date: 2024-03-27, security patched: 8.7.1-5~bpo12+1
Protocols: dict file ftp ftps gopher gophers http https imap imaps ipfs ipns ldap ldaps mqtt pop3 pop3s rtmp rtsp scp sftp smb smbs smtp smtps telnet tftp
Features: alt-svc AsynchDNS brotli GSS-API HSTS HTTP2 HTTPS-proxy IDN IPv6 Kerberos Largefile libz NTLM PSL SPNEGO SSL threadsafe TLS-SRP UnixSockets zstd
from curl.
blach
commented on June 7, 2024
Could this be an aarch64 vs x86_64 architecture issue?
from curl.
icing
commented on June 7, 2024
@blach I suspect more a timing issue. TLS has this concept of close notify messages at the end of a connection from both sides. That can make life tricky.
When ending the transfer, curl is sending close notify, checks if there is something from the server and then closes the socket. When the delay between curl and the server is large enough, the server might get an error sending his part of the TLS shutdown. Ideally, curl would be more gracefully here and wait a considerable time for the server to properly deliver his shutdown before closing the socket.
If you enable the following on your vsftp setup, we might see in the server log what it complains about:
xferlog_enable=YES
debug_ssl=YES
xferlog_std_format=NO
You can set vsftpd_log_file=path_to_my_log_file if you want it in another location. Default should be /var/log/vsftpd.log.
from curl.
blach
commented on June 7, 2024
Thanks, I added those configuration options and see this in the log file:
Tue May 21 12:45:14 2024 [pid 254883] CONNECT: Client "::ffff:217.82.60.116"
Tue May 21 12:45:14 2024 [pid 254883] DEBUG: Client "::ffff:217.82.60.116", "SSL version: TLSv1.3, SSL cipher: TLS_AES_256_GCM_SHA384, not reused, no cert"
Tue May 21 12:45:14 2024 [pid 254882] [demo] OK LOGIN: Client "::ffff:217.82.60.116"
Tue May 21 12:45:14 2024 [pid 254883] [demo] DEBUG: Client "::ffff:217.82.60.116", "SSL version: TLSv1.3, SSL cipher: TLS_AES_256_GCM_SHA384, reused, no cert"
Tue May 21 12:50:14 2024 [pid 254883] [demo] DEBUG: Client "::ffff:217.82.60.116", "DATA connection terminated without SSL shutdown. Buggy client! Integrity of upload cannot be asserted."
Tue May 21 12:50:14 2024 [pid 254883] [demo] DEBUG: Client "::ffff:217.82.60.116", "SSL shutdown state is: NONE"
Tue May 21 12:50:14 2024 [pid 254883] [demo] DEBUG: Client "::ffff:217.82.60.116", "SSL shutdown state is: NONE"
Tue May 21 12:50:14 2024 [pid 254883] [demo] DEBUG: Client "::ffff:217.82.60.116", "SSL ret: 18446744073709551615, SSL error: error:0A000126:SSL routines::unexpected eof while reading, errno: 32"
Tue May 21 12:50:14 2024 [pid 254884] [demo] FAIL UPLOAD: Client "::ffff:217.82.60.116", "/home/demo/test-curl.txt", 0.00Kbyte/sec
from curl.
blach
commented on June 7, 2024
When I run the command successfully on the server itself, I get this instead:
Tue May 21 12:57:37 2024 [pid 254977] CONNECT: Client "::ffff:xx.xxx.xxx.xxx"
Tue May 21 12:57:37 2024 [pid 254977] DEBUG: Client "::ffff:xx.xxx.xxx.xxx", "SSL version: TLSv1.3, SSL cipher: TLS_AES_256_GCM_SHA384, not reused, no cert"
Tue May 21 12:57:37 2024 [pid 254976] [demo] OK LOGIN: Client "::ffff:xx.xxx.xxx.xxx"
Tue May 21 12:57:37 2024 [pid 254977] [demo] DEBUG: Client "::ffff:xx.xxx.xxx.xxx", "SSL version: TLSv1.3, SSL cipher: TLS_AES_256_GCM_SHA384, reused, no cert"
Tue May 21 12:57:37 2024 [pid 254977] [demo] DEBUG: Client "::ffff:xx.xxx.xxx.xxx", "SSL shutdown state is: SSL_RECEIVED_SHUTDOWN"
Tue May 21 12:57:37 2024 [pid 254977] [demo] DEBUG: Client "::ffff:xx.xxx.xxx.xxx", "SSL shutdown state is: 3"
Tue May 21 12:57:37 2024 [pid 254978] [demo] OK UPLOAD: Client "::ffff:xx.xxx.xxx.xxx", "/home/demo/test-curl.txt", 18432 bytes, 817.96Kbyte/sec
So it's indeed a problem with the SSL shutdown not working correctly when uploading from my Mac.
from curl.
Related Issues (20)
- aws-sigv4 does not work with URLs containing "=" and other special characters HOT 3
- curl_multi_socket_action crashes occasionally HOT 4
- Download progress callback can be significantly delayed HOT 2
- Document that CURLOPT_SSL_VERIFYHOST applies to SSH HOT 1
- 8.8.0: Test 1553 (IMAP cleanup before a connection was created) appears flaky on some Gentoo systems HOT 9
- configure : Failed to find size of size_t HOT 8
- Regression: In 8.8.0, HTTP3 with QuicTLS errors out with "QUIC needs at least TLS version 1.3" with CURLOPT_SSLVERSION set as documented
- manpage paragraph incorrect indentation HOT 4
- Calling `curl_global_init` after `curl_global_cleanup` failed HOT 2
- IPV6 curl sftp known_host key validation failure HOT 6
- ECH: SIGSEGV when use HTTP/3 HOT 21
- CURL 7.20.0 Form Data: When using curl_formadd to create a multipart request, the boundary delimiter is missing in the generated data. HOT 1
- Android has a broken CLOCK_MONOTONIC_RAW HOT 9
- WebSocket Failure Doesnt Clear socket. HOT 8
- No failure when the header file can't be written HOT 3
- Crash when using CURL_LOCK_DATA_CONNECT in Curl_conn_close at cfilters.c:165 HOT 3
- v8.8.0 - problem with `--write-out`: error 43 - A libcurl function was given a bad argument HOT 14
- Wrong time units of TCP keepalive options on DragonFlyBSD 5.8+
- random OOM errors HOT 10
- "--ciphers" may not properly set "--tls13-ciphers" HOT 3
Recommend Projects
-
React
A declarative, efficient, and flexible JavaScript library for building user interfaces.
-
Vue.js
🖖 Vue.js is a progressive, incrementally-adoptable JavaScript framework for building UI on the web.
-
Typescript
TypeScript is a superset of JavaScript that compiles to clean JavaScript output.
-
TensorFlow
An Open Source Machine Learning Framework for Everyone
-
Django
The Web framework for perfectionists with deadlines.
-
Laravel
A PHP framework for web artisans
-
D3
Bring data to life with SVG, Canvas and HTML. 📊📈🎉
-
Recommend Topics
-
javascript
JavaScript (JS) is a lightweight interpreted programming language with first-class functions.
-
web
Some thing interesting about web. New door for the world.
-
server
A server is a program made to process requests and deliver data to clients.
-
Machine learning
Machine learning is a way of modeling and interpreting data that allows a piece of software to respond intelligently.
-
Visualization
Some thing interesting about visualization, use data art
-
Game
Some thing interesting about game, make everyone happy.
Recommend Org
-
Facebook
We are working to build community through open source technology. NB: members must have two-factor auth.
-
Microsoft
Open source projects and samples from Microsoft.
-
Google
Google ❤️ Open Source for everyone.
-
Alibaba
Alibaba Open Source for everyone
-
D3
Data-Driven Documents codes.
-
Tencent
China tencent open source team.
from curl.