Page 1 of 1

Transfers stalling when using pure-ftpd

Posted: 2019-07-24 20:39
by xeon
Hello,

I've noticed when stopping a transfer and trying to start another right after will result in FIleZilla Client stalling for 20 seconds (or whatever timeout is set), before resuming the transfer, or even starting a completely new transfer.

I've also been able to get FileZilla Client to permanently stall all transfers from the same server if the timeout isn't allowed to happen. Attempting to start a new transfer or resume will result in the same "Waiting for replies to skip before sending next command..." every single time if you remove the file from the queue before the timeout happens.

This odd thing is, I've only been able to reproduce this on servers running pure-ftpd. I'm not able to reproduce this behavior with vsftpd.

Here's a log of me starting a transfer, then stopping it and trying to resume.

16:31:36 Status: Connecting to 23.18.7.10:21...
16:31:36 Status: Connection established, waiting for welcome message...
16:31:36 Response: 220-Welcome to Pure-FTPd.
16:31:36 Response: 220-Local time is now 20:31. Server port: 21.
16:31:36 Response: 220-This is a private system - No anonymous login
16:31:36 Response: 220 You will be disconnected after 5 minutes of inactivity.
16:31:36 Command: AUTH TLS
16:31:36 Response: 234 AUTH TLS OK.
16:31:36 Status: Initializing TLS...
16:31:36 Status: Verifying certificate...
16:31:36 Status: TLS connection established.
16:31:36 Command: USER test
16:31:36 Response: 331 User test OK. Password required
16:31:36 Command: PASS ***************************************************************
16:31:36 Response: 230 OK. Current restricted directory is /
16:31:36 Command: SYST
16:31:36 Response: 215 UNIX Type: L8
16:31:36 Command: FEAT
16:31:37 Response: 211-Extensions supported:
16:31:37 Response: UTF8
16:31:37 Response: EPRT
16:31:37 Response: IDLE
16:31:37 Response: MDTM
16:31:37 Response: SIZE
16:31:37 Response: MFMT
16:31:37 Response: REST STREAM
16:31:37 Response: MLST type*;size*;sizd*;modify*;UNIX.mode*;UNIX.uid*;UNIX.gid*;unique*;
16:31:37 Response: MLSD
16:31:37 Response: PRET
16:31:37 Response: AUTH TLS
16:31:37 Response: PBSZ
16:31:37 Response: PROT
16:31:37 Response: TVFS
16:31:37 Response: ESTA
16:31:37 Response: PASV
16:31:37 Response: EPSV
16:31:37 Response: SPSV
16:31:37 Response: ESTP
16:31:37 Response: 211 End.
16:31:37 Command: OPTS UTF8 ON
16:31:37 Response: 504 Unknown command
16:31:37 Command: PBSZ 0
16:31:37 Response: 200 PBSZ=0
16:31:37 Command: PROT P
16:31:37 Response: 200 Data protection level set to "private"
16:31:37 Status: Logged in
16:31:37 Status: Retrieving directory listing...
16:31:37 Command: PWD
16:31:37 Response: 257 "/" is your current location
16:31:37 Command: TYPE I
16:31:37 Response: 200 TYPE is now 8-bit binary
16:31:37 Command: PASV
16:31:37 Response: 227 Entering Passive Mode (23,18,7,10,171,215)
16:31:37 Command: MLSD
16:31:37 Response: 150 Accepted data connection
16:31:37 Response: 226 6 matches total
16:31:38 Status: Directory listing of "/" successful
16:31:38 Status: Retrieving directory listing of "/Miscellany"...
16:31:38 Command: CWD Miscellany
16:31:38 Response: 250 OK. Current directory is /Miscellany
16:31:38 Command: PWD
16:31:38 Response: 257 "/Miscellany" is your current location
16:31:38 Command: PASV
16:31:38 Response: 227 Entering Passive Mode (23,18,7,10,221,85)
16:31:38 Command: MLSD
16:31:39 Response: 150 Accepted data connection
16:31:39 Response: 226 79 matches total
16:31:39 Status: Directory listing of "/Miscellany" successful
16:31:40 Status: Connecting to 23.18.7.10:21...
16:31:40 Status: Connection established, waiting for welcome message...
16:31:40 Response: 220-Welcome to Pure-FTPd.
16:31:40 Response: 220-Local time is now 20:31. Server port: 21.
16:31:40 Response: 220-This is a private system - No anonymous login
16:31:40 Response: 220 You will be disconnected after 5 minutes of inactivity.
16:31:40 Command: AUTH TLS
16:31:40 Response: 234 AUTH TLS OK.
16:31:40 Status: Initializing TLS...
16:31:41 Status: Verifying certificate...
16:31:41 Status: TLS connection established.
16:31:41 Command: USER test
16:31:41 Response: 331 User test OK. Password required
16:31:41 Command: PASS ***************************************************************
16:31:41 Response: 230 OK. Current restricted directory is /
16:31:41 Command: OPTS UTF8 ON
16:31:41 Response: 504 Unknown command
16:31:41 Command: PBSZ 0
16:31:41 Response: 200 PBSZ=0
16:31:41 Command: PROT P
16:31:41 Response: 200 Data protection level set to "private"
16:31:41 Status: Logged in
16:31:41 Status: Starting download of /Miscellany/testfile.bin
16:31:41 Command: CWD /Miscellany
16:31:41 Response: 250 OK. Current directory is /Miscellany
16:31:41 Command: PWD
16:31:41 Response: 257 "/Miscellany" is your current location
16:31:41 Command: TYPE I
16:31:41 Response: 200 TYPE is now 8-bit binary
16:31:41 Command: PASV
16:31:41 Response: 227 Entering Passive Mode (23,18,7,10,96,175)
16:31:41 Command: RETR testfile.bin
16:31:41 Response: 150-Accepted data connection
16:31:41 Response: 150 303557.4 kbytes to download
16:31:46 Error: File transfer aborted by user after transferring 944.0 KB in 4 seconds
16:31:46 Response: 150 4.611 seconds (measured here), 222.06 Kbytes per second
16:31:48 Status: Waiting for replies to skip before sending next command...
16:32:08 Error: Connection timed out after 20 seconds of inactivity
16:32:08 Error: File transfer failed
16:32:08 Status: Disconnected from server
16:32:08 Status: Connecting to 23.18.7.10:21...
16:32:09 Status: Connection established, waiting for welcome message...
16:32:09 Response: 220-Welcome to Pure-FTPd.
16:32:09 Response: 220-Local time is now 20:32. Server port: 21.
16:32:09 Response: 220-This is a private system - No anonymous login
16:32:09 Response: 220 You will be disconnected after 5 minutes of inactivity.
16:32:09 Command: AUTH TLS
16:32:09 Response: 234 AUTH TLS OK.
16:32:09 Status: Initializing TLS...
16:32:09 Status: Verifying certificate...
16:32:09 Status: TLS connection established.
16:32:09 Command: USER test
16:32:09 Response: 331 User test OK. Password required
16:32:09 Command: PASS ***************************************************************
16:32:09 Response: 230 OK. Current restricted directory is /
16:32:09 Command: OPTS UTF8 ON
16:32:09 Response: 504 Unknown command
16:32:09 Command: PBSZ 0
16:32:09 Response: 200 PBSZ=0
16:32:09 Command: PROT P
16:32:09 Response: 200 Data protection level set to "private"
16:32:09 Status: Logged in
16:32:09 Status: Starting download of /Miscellany/testfile.bin
16:32:09 Command: CWD /Miscellany
16:32:09 Response: 250 OK. Current directory is /Miscellany
16:32:09 Command: TYPE I
16:32:09 Response: 200 TYPE is now 8-bit binary
16:32:09 Command: PASV
16:32:09 Response: 227 Entering Passive Mode (23,18,7,10,112,156)
16:32:09 Command: REST 966656
16:32:09 Response: 350 Restarting at 966656
16:32:09 Command: RETR testfile.bin
16:32:10 Response: 150-Accepted data connection
16:32:10 Response: 150 302613.4 kbytes to download
16:32:23 Response: 226-File successfully transferred
16:32:23 Response: 226 13.733 seconds (measured here), 21.52 Mbytes per second
16:32:24 Status: File transfer successful, transferred 295.6 MB in 14 seconds

Re: Transfers stalling when using pure-ftpd

Posted: 2019-07-24 21:01
by xeon
Just wanted to add that this might be a bug with pure-ftpd, as I can also reproduce this behavior with other FTP clients, such as lftp.

Re: Transfers stalling when using pure-ftpd

Posted: 2019-07-25 06:51
by botg
16:31:41 Command: RETR testfile.bin
16:31:41 Response: 150-Accepted data connection
16:31:41 Response: 150 303557.4 kbytes to download
16:31:46 Error: File transfer aborted by user after transferring 944.0 KB in 4 seconds
16:31:46 Response: 150 4.611 seconds (measured here), 222.06 Kbytes per second
Yes, this is a bug in the used server software. 1yz replies are only a preliminary reply, they must be followed by a 2yz, 3yz, 4yz or 5yz reply.
This is also a second bug, a server may send at most one preliminary reply to a single command, here it sends two.

Re: Transfers stalling when using pure-ftpd

Posted: 2019-09-16 14:01
by kermito
Sure it's a serverbug, but this patch enables PRET Support

copy this into a file in filezilla source dir an run patch -p1 < 'YOURFILENAME'

Code: Select all

Index: filezilla/src/engine/ftp/ftpcontrolsocket.cpp
===================================================================
--- filezilla/src/engine/ftp/ftpcontrolsocket.cpp	(revision 8672)
+++ filezilla/src/engine/ftp/ftpcontrolsocket.cpp	(working copy)
@@ -742,7 +742,10 @@
 	if ((pData->pOldData->binary && m_lastTypeBinary == 1) ||
 		(!pData->pOldData->binary && m_lastTypeBinary == 0))
 	{
-		pData->opState = rawtransfer_port_pasv;
+      if (pData->bPasv && CServerCapabilities::GetCapability(currentServer_, pret_command) == yes)
+         pData->opState = rawtransfer_pret;
+      else
+         pData->opState = rawtransfer_port_pasv;
 	}
 	else {
 		pData->opState = rawtransfer_type;
Index: filezilla/src/engine/ftp/logon.cpp
===================================================================
--- filezilla/src/engine/ftp/logon.cpp  (revision 8672)
+++ filezilla/src/engine/ftp/logon.cpp  (working copy)
@@ -778,6 +778,9 @@
 	else if (HasFeature(up, L"CLNT")) {
 		CServerCapabilities::SetCapability(currentServer_, clnt_command, yes);
 	}
+	else if (HasFeature(up, L"PRET")) {
+		CServerCapabilities::SetCapability(currentServer_, pret_command, yes);
+	}
 	else if (HasFeature(up, L"MLSD")) {
 		std::wstring facts;
 		// FEAT output for MLST overrides MLSD
Index: src/engine/ftp/rawtransfer.cpp
===================================================================
--- filezilla/src/engine/ftp/rawtransfer.cpp	(revision 8672)
+++ filezilla/src/engine/ftp/rawtransfer.cpp	(working copy)
@@ -24,10 +23,23 @@
 			error = true;
 		}
 		else {
-			opState = rawtransfer_port_pasv;
+			if (bPasv && CServerCapabilities::GetCapability(currentServer_, pret_command) == yes) 
+				opState = rawtransfer_pret;
+			else
+				opState = rawtransfer_port_pasv;
 			controlSocket_.m_lastTypeBinary = pOldData->binary ? 1 : 0;
 		}
 		break;
+	case rawtransfer_pret:
+		if (code != 2 && code != 3)
+		{
+			error = true;
+		}
+		else
+		{
+			opState = rawtransfer_port_pasv;
+		}
+		break;
 	case rawtransfer_port_pasv:
 		if (code != 2 && code != 3) {
 			if (!engine_.GetOptions().GetOptionVal(OPTION_ALLOW_TRANSFERMODEFALLBACK)) {
@@ -189,6 +201,9 @@
 		}
 		measureRTT = true;
 		break;
+	case rawtransfer_pret:
+		cmd = L"PRET " + cmd_;
+		break;
 	case rawtransfer_port_pasv:
 		if (bPasv) {
 			cmd = GetPassiveCommand();
Index: filezilla/src/engine/ftp/rawtransfer.h
===================================================================
--- filezilla/src/engine/ftp/rawtransfer.h	(revision 8672)
+++ filezilla/src/engine/ftp/rawtransfer.h	(working copy)
@@ -13,7 +13,8 @@
 	rawtransfer_waitfinish,
 	rawtransfer_waittransferpre,
 	rawtransfer_waittransfer,
-	rawtransfer_waitsocket
+	rawtransfer_waitsocket,
+	rawtransfer_pret
 };
 
 class CFtpRawTransferOpData final : public COpData, public CFtpOpData
Index: filezilla/src/engine/servercapabilities.h
===================================================================
--- filezilla/src/engine/servercapabilities.h	(revision 8672)
+++ filezilla/src/engine/servercapabilities.h	(working copy)
@@ -41,7 +41,8 @@
 	timezone_offset,
 
 	auth_tls_command,
-	auth_ssl_command
+	auth_ssl_command,
+	pret_command
 };
 
 class CCapabilities final

Re: Transfers stalling when using pure-ftpd

Posted: 2019-09-16 22:35
by botg
Please don't post content unrelated to the topic.