lavv17 / lftp

sophisticated command line file transfer program (ftp, http, sftp, fish, torrent)
http://lftp.yar.ru
GNU General Public License v3.0
1.08k stars 159 forks source link

lftp 4.9.2 doesn't recover from failed (421) PASV command #632

Open rmallinsAtViavi opened 3 years ago

rmallinsAtViavi commented 3 years ago

We use lftp 4.6.0 on 64 bit linux in our product to fetch files from a "filezilla" ftp server running on windows, and have recently noticed an issue in how lftp handles an infrequent - but occasionally expected - error condition from the ftp server. We've subsequently reproduced this issue in lftp 4.9.2, which is the latest released version, and from my limited understanding of the lftp code it appears that the issue is still present in the very latest commit (d67fc14d085 as of now).

The lftp man page says that:

Every operation in lftp is reliable, that is any non-fatal error is handled properly and the operation is repeated.

but I don't believe the current code correctly handles non-fatal errors returned by a server in response to the PASV command.

What is:

This log comes from lftp stdout/stderr with "debug" enabled in the lftp conf file: echo debug >>/etc/lftp.conf

From a log of our system when the problem presents itself:

2021-05-06T10:00:42+0000 ---> PASV 
2021-05-06T10:00:42+0000 <--- 227 Entering Passive Mode (10,120,4,85,220,193) 
2021-05-06T10:00:42+0000 ---- Connecting data socket to (10.120.4.85) port 56513 
2021-05-06T10:00:42+0000 ---- Data connection established 
2021-05-06T10:00:42+0000 ---> RETR R730-oran-du.txt 
2021-05-06T10:00:42+0000 <--- 150 Opening data channel for file download from server of "/cpupools/R730-oran-du.txt" 
2021-05-06T10:00:42+0000 ---- Got EOF on data connection 
2021-05-06T10:00:42+0000 ---- Closing data socket 
2021-05-06T10:00:42+0000 <--- 226 Successfully transferred "/cpupools/R730-oran-du.txt" 
2021-05-06T10:00:42+0000 ---> PASV 
2021-05-06T10:00:42+0000 <--- 421 Could not create socket. 
2021-05-06T10:00:42+0000 ---> RETR R730-oran-fhm.txt 
2021-05-06T10:00:42+0000 <--- 503 Bad sequence of commands. 
2021-05-06T10:00:42+0000 ---- Closing data socket 
2021-05-06T10:00:42+0000 ---- Closing control socket 
2021-05-06T10:00:42+0000 mirror: Access failed: 503 Bad sequence of commands. (R730-oran-fhm.txt) 

It can be seen that the normal sequence of events is for lftp to send the PASV command, receive an <ip>,<ports> spec in response then set up a data socket. It then tries to retrieve the file in question.

In the failure mode the filezilla server (which has been unable to open a port for the transfer in this case) returns a 421 error, which lftp appears to ignore, and sends the RETR command regardless, though no data connection has been set up for the transfer to go over.

The server then (correctly IMO), reports that it has been sent a bad sequence of commands.

What should be

I believe lftp should retry the PASV command after a suitable small delay.

Workarounds

For us this problem is caused by our ftp server (Filezilla on windows) very occasionally attempting to open ports that are already in use and failing: https://forum.filezilla-project.org/viewtopic.php?t=49773. The error message filezilla correctly reports in this event appears to expose this lftp bug. We are working around it by restricting the range of ports filezilla attempts to use to high ones that aren't being used by other processes.