FTP passive mode not passive? :: Support Forum

MarisB
Joined:: 2019-07-18
Posts:: 19

FTP passive mode not passive?

2019-08-19 10:31

Hello,

I am trying to do some operations in FTP server, upload, download, delete directory... and suddenly got error / or state when directory is not deleted. I mean some operations are going through successfully, file gets uploaded, then downloaded, but then nothing works.

Looking into log file reveals, that WinScp are using PORT command, that supposed to happen only in Active mode? After first tries, WinScp swiches to passive mode again, until it stops trying...

Here is a fragments from the log:

. 2019-08-19 11:47:47.372 --------------------------------------------------------------------------
. 2019-08-19 11:47:47.372 WinSCP Version 5.15.2 (Build 9590) (OS 10.0.18362 - Windows 10 Enterprise)
. 2019-08-19 11:47:47.372 Configuration: nul
. 2019-08-19 11:47:47.372 Log level: Debug 2
.....
.....
.....
.....
. 2019-08-19 11:47:47.374 Transfer Protocol: FTP
. 2019-08-19 11:47:47.374 Ping type: Dummy, Ping interval: 30 sec; Timeout: 3600 sec
. 2019-08-19 11:47:47.374 Disable Nagle: No
. 2019-08-19 11:47:47.374 Proxy: None
. 2019-08-19 11:47:47.374 Send buffer: 262144
. 2019-08-19 11:47:47.374 UTF: Auto
. 2019-08-19 11:47:47.374 FTPS: Implicit TLS/SSL [Client certificate: No]
. 2019-08-19 11:47:47.374 FTP: Passive: Yes [Force IP: Auto]; MLSD: Auto [List all: Auto]; HOST: Auto
. 2019-08-19 11:47:47.374 Session reuse: Yes
. 2019-08-19 11:47:47.374 TLS/SSL versions: TLSv1.0-TLSv1.2
. 2019-08-19 11:47:47.374 Local directory: default, Remote directory: home, Update: Yes, Cache: Yes
. 2019-08-19 11:47:47.374 Cache directory changes: Yes, Permanent: Yes
. 2019-08-19 11:47:47.374 Recycle bin: Delete to: No, Overwritten to: No, Bin path: 
. 2019-08-19 11:47:47.374 Timezone offset: 0h 0m
....
....
....
....
....
. 2019-08-19 11:47:48.633 Certificate common name "EC2AMAZ-OBTD71K" does not match hostname
. 2019-08-19 11:47:48.633 Certificate subject alternative name "EC2AMAZ-OBTD71K" does not match hostname
. 2019-08-19 11:47:48.633 Certificate for "" matches configured fingerprint
. 2019-08-19 11:47:48.633 Using TLSv1.2, cipher TLSv1/SSLv3: ECDHE-RSA-AES256-GCM-SHA384, 2048 bit RSA, ECDHE-RSA-AES256-GCM-SHA384 TLSv1.2 Kx=ECDH     Au=RSA  Enc=AESGCM(256) Mac=AEAD
. 2019-08-19 11:47:48.633 TLS connection established. Waiting for welcome message...
< 2019-08-19 11:47:48.633 220 Microsoft FTP Service
> 2019-08-19 11:47:48.633 USER user
< 2019-08-19 11:47:48.749 331 Password required
> 2019-08-19 11:47:48.749 PASS *************************
< 2019-08-19 11:47:48.867 230 User logged in.
> 2019-08-19 11:47:48.867 SYST
. 2019-08-19 11:47:48.984 The server is probably running Windows, assuming that directory listing timestamps are affected by DST.
< 2019-08-19 11:47:48.984 215 Windows_NT
> 2019-08-19 11:47:48.984 FEAT
< 2019-08-19 11:47:49.100 211-Extended features supported:
< 2019-08-19 11:47:49.100  LANG EN*
< 2019-08-19 11:47:49.100  UTF8
< 2019-08-19 11:47:49.100  AUTH TLS;TLS-C;SSL;TLS-P;
< 2019-08-19 11:47:49.100  PBSZ
< 2019-08-19 11:47:49.100  PROT C;P;
< 2019-08-19 11:47:49.100  CCC
< 2019-08-19 11:47:49.100  HOST
< 2019-08-19 11:47:49.100  SIZE
< 2019-08-19 11:47:49.100  MDTM
< 2019-08-19 11:47:49.100  REST STREAM
< 2019-08-19 11:47:49.100 211 END
> 2019-08-19 11:47:49.100 OPTS UTF8 ON
< 2019-08-19 11:47:49.217 200 OPTS UTF8 command successful - UTF8 encoding now ON.
> 2019-08-19 11:47:49.217 PBSZ 0
< 2019-08-19 11:47:49.335 200 PBSZ command successful.
> 2019-08-19 11:47:49.335 PROT P
< 2019-08-19 11:47:49.451 200 PROT command successful.
. 2019-08-19 11:47:49.451 Connected
. 2019-08-19 11:47:49.451 Got reply 1 to the command 1
. 2019-08-19 11:47:49.451 --------------------------------------------------------------------------
. 2019-08-19 11:47:49.451 Using FTP protocol.
. 2019-08-19 11:47:49.451 Doing startup conversation with host.
> 2019-08-19 11:47:49.499 PWD
< 2019-08-19 11:47:49.614 257 "/" is current directory.
. 2019-08-19 11:47:49.614 Got reply 1 to the command 16
. 2019-08-19 11:47:49.614 Getting current directory name.
. 2019-08-19 11:47:49.614 Startup conversation with host finished.
...
...
...
...
...
. 2019-08-19 11:47:50.116 Binary transfer mode selected.
. 2019-08-19 11:47:50.117 Starting upload of c:\zzzzzzzzzzzzzzzzzzzzzz
> 2019-08-19 11:47:50.117 CWD /the test directory
< 2019-08-19 11:47:50.234 250 CWD command successful.
> 2019-08-19 11:47:50.234 PWD
< 2019-08-19 11:47:50.350 257 "/xxxxxxxxxxx" is current directory.
> 2019-08-19 11:47:50.350 TYPE I
< 2019-08-19 11:47:50.466 200 Type set to I.
> 2019-08-19 11:47:50.466 PORT 192,168,1,150,19,93
< 2019-08-19 11:47:50.583 501 Server cannot accept argument.
> 2019-08-19 11:47:50.583 PASV
< 2019-08-19 11:47:50.699 227 Entering Passive Mode (XXX,XXX,XXX,69,19,228).
> 2019-08-19 11:47:50.699 STOR zzzzzzzzzzzzzzzzz.txt
. 2019-08-19 11:47:50.699 Connecting to XXX.XXX.XXX.69:5092 ...
. 2019-08-19 11:47:50.812 Data connection opened
< 2019-08-19 11:47:50.816 150 Opening BINARY mode data connection.
. 2019-08-19 11:47:50.816 Data connection opened
...
...
...
...
...
< 2019-08-19 11:47:53.869 250 DELE command successful.
. 2019-08-19 11:47:53.869 Got reply 1 to the command 32
. 2019-08-19 11:47:53.896 Copying finished: Transferred: 74, Elapsed: 0:00:01, CPS: 169/s
. 2019-08-19 11:47:53.896 Session upkeep
> 2019-08-19 11:47:54.256 Script: ls -- "/"
> 2019-08-19 11:47:54.257 Script: Parameter: /
. 2019-08-19 11:47:54.257 Retrieving directory listing...
> 2019-08-19 11:47:54.257 CWD /
< 2019-08-19 11:47:54.373 250 CWD command successful.
> 2019-08-19 11:47:54.373 PWD
< 2019-08-19 11:47:54.489 257 "/" is current directory.
> 2019-08-19 11:47:54.489 TYPE A
< 2019-08-19 11:47:54.605 200 Type set to A.
> 2019-08-19 11:47:54.605 PORT 192,168,1,150,19,98
< 2019-08-19 11:47:54.722 501 Server cannot accept argument.
. 2019-08-19 11:47:54.722 Could not retrieve directory listing
. 2019-08-19 11:47:54.722 Got reply 4 to the command 2
. 2019-08-19 11:47:54.722 LIST with -a failed, will try pure LIST
. 2019-08-19 11:47:54.722 Retrieving directory listing...
> 2019-08-19 11:47:54.723 TYPE A
< 2019-08-19 11:47:54.838 200 Type set to A.
> 2019-08-19 11:47:54.838 PORT 192,168,1,150,19,99
< 2019-08-19 11:47:54.958 501 Server cannot accept argument.
. 2019-08-19 11:47:54.958 Could not retrieve directory listing
. 2019-08-19 11:47:54.958 Got reply 4 to the command 2
. 2019-08-19 11:47:54.958 Asking user:
. 2019-08-19 11:47:54.958 Error listing directory '/'. ("Could not retrieve directory listing","Server cannot accept argument.")
< 2019-08-19 11:47:54.958 Script: Error listing directory '/'.
< 2019-08-19 11:47:54.958 Script: Could not retrieve directory listing

< 2019-08-19 11:47:54.958 Server cannot accept argument.
. 2019-08-19 11:47:55.100 Script: Failed
. 2019-08-19 11:47:55.100 Session upkeep
> 2019-08-19 11:47:55.200 Script: exit
. 2019-08-19 11:47:55.201 Session upkeep
. 2019-08-19 11:47:55.201 Script: Exit code: 1
. 2019-08-19 11:47:55.201 Script: Max roundtrip: 500
. 2019-08-19 11:47:55.201 Got reply 1004 to the command 2
. 2019-08-19 11:47:55.203 Disconnected from server

Reply with quote

MarisB

2019-08-19 10:41

Update: it seems, that I have lost Passive flag, and the log file is from Active mode... So the question now is: It seems that there is a fallback from Active mode to Passive based on error response? On local IP?

Reply with quote

martin◆ Site Admin
Joined:: 2002-12-10
Posts:: 41,468
Location:: Prague, Czechia

Re: FTP passive mode not passive?

2019-08-20

Can you attach a complete log file?

Reply with quote

MarisB

2019-08-20 10:09

Not in public forum. I can send as a private message or email, but I do not see how...

Reply with quote

martin◆ Site Admin

2019-08-23

You can flag the attachment as private.

Reply with quote

MarisB
Joined:: 2019-07-18
Posts:: 19

2019-08-23 08:49

The question is, why it is entering Passive mode here:

> 2019-08-19 11:47:50.350 TYPE I
< 2019-08-19 11:47:50.466 200 Type set to I.
> 2019-08-19 11:47:50.466 PORT 192,168,111,222,19,93
< 2019-08-19 11:47:50.583 501 Server cannot accept argument.
> 2019-08-19 11:47:50.583 PASV
< 2019-08-19 11:47:50.699 227 Entering Passive Mode (211,211,211,211,19,228).

And if this is some kind of fallback, can it be disabled?

Full log in private attachment.

full-log.zip (4.58 KB, Private file)

Reply with quote

martin◆ Site Admin
Joined:: 2002-12-10
Posts:: 41,468
Location:: Prague, Czechia

2019-08-27

Yes, WinSCP falls back to the passive mode, because the server rejected the active mode.
The server probably rejected the active mode, because WinSCP is sending internal IP address.
You can set external IP address using Interface\ExternalIpAddress raw configuration settings:
https://winscp.net/eng/docs/rawconfig

Though why do you insist on using the active mode?

Reply with quote

MarisB
Joined:: 2019-07-18
Posts:: 19

2019-08-27 10:41

Thanks for the reply! I already figured out, that if using FTP Active mode with improper configuration (local IP address in this case), it is falling back to Passive mode.

The question was, is this intentional - designed behavior? Because I couldn't find this in documentation. And if this is by design, then is it possible to disable this fallback from active to passive mode?

Not that I need this feature, but I got stuck on this writing some test cases, where I started wondering, why SessionOptions.FtpMode does not have any effect... and then I looked into log file, and found something like a fallback, that does not work in every case though.

To summarize -- everything is working as expected, except it would be nice if documentation mentioned this, for example, here: https://winscp.net/eng/docs/library_sessionoptions
at FtpMode property.

Reply with quote

martin◆ Site Admin

2019-08-30

OK, I will improve the documentation.

Reply with quote

FTP passive mode not passive?

FTP passive mode not passive?

Re: FTP passive mode not passive?

Documentation

Support

Associations

Follow Us