Search code examples
javaproxyftpftpsapache-commons-net

FTPS data connection with TLS/SSL via proxy fails with log entry "Replacing PASV mode reply address <PROXY_IP> with <FTPS_IP>"


I have an issue while connecting to a FTPS server with TLS/SSL Implicit encryption via PROXY.

I am following the custom Apache FTPS Client (commons-net-3.8.0) solution provided from Java FTPS client through HTTP proxy

My server connection is working, but unable to list or file transfer, getting below error:

425 Can't open data connection for transfer of "<REMOVED_FOR_SECURITY>"

Data connection / File transfer is working fine from Windows WinSCP and Linux LFTP.

WinSCP Log:

2022-02-06 16:25:04.874 --------------------------------------------------------------------------
2022-02-06 16:25:04.876 WinSCP Version 5.15.5 (Build 9925) (OS 10.0.19042 - Windows 10 Enterprise)
2022-02-06 16:25:04.877 Configuration: C:\Users\<LOGIN_SER>\AppData\Roaming\WinSCP.ini
2022-02-06 16:25:04.879 Log level: Normal
2022-02-06 16:25:04.879 Local account: HBEU\<LOGIN_SER>
2022-02-06 16:25:04.879 Working directory: C:\Program Files\WinSCP-5.15.5
2022-02-06 16:25:04.879 Process ID: 16452
2022-02-06 16:25:04.883 Command-line: C:\Program Files\WinSCP-5.15.5\WinSCP.exe
2022-02-06 16:25:04.885 Time zone: Current: GMT+3 (Arab Standard Time), No DST
2022-02-06 16:25:04.885 Login time: Sunday, February 6, 2022 4:25:04 PM
2022-02-06 16:25:04.885 --------------------------------------------------------------------------
2022-02-06 16:25:04.885 Session name: FTPS TEST (Site)
2022-02-06 16:25:04.885 Host name: <FTPS_HOST_NAME> (Port: <FTPS_PORT>)
2022-02-06 16:25:04.885 User name: <FTPS_USER_NAME> (Password: No, Key file: No, Passphrase: No)
2022-02-06 16:25:04.885 Transfer Protocol: FTP
2022-02-06 16:25:04.885 Ping type: Dummy, Ping interval: 30 sec; Timeout: 15 sec
2022-02-06 16:25:04.885 Disable Nagle: No
2022-02-06 16:25:04.885 Proxy: HTTP
2022-02-06 16:25:04.885 HostName: <PROXY_HOST_NAME> (Port: <PROXY_PORT>); Username: ; Passwd: No
2022-02-06 16:25:04.885 Send buffer: 262144
2022-02-06 16:25:04.885 UTF: Auto
2022-02-06 16:25:04.885 FTPS: Implicit TLS/SSL [Client certificate: No]
2022-02-06 16:25:04.885 FTP: Passive: Yes [Force IP: Auto]; MLSD: Auto [List all: Auto]; HOST: Auto
2022-02-06 16:25:04.885 Session reuse: Yes
2022-02-06 16:25:04.885 TLS/SSL versions: TLSv1.0-TLSv1.2
2022-02-06 16:25:04.885 Local directory: <LOCAL_DIRECTORY>, Remote directory: <REMOTE_DIRECTORY>, Update: Yes, Cache: Yes
2022-02-06 16:25:04.885 Cache directory changes: Yes, Permanent: Yes
2022-02-06 16:25:04.885 Recycle bin: Delete to: No, Overwritten to: No, Bin path: 
2022-02-06 16:25:04.885 Timezone offset: 0h 0m
2022-02-06 16:25:04.885 --------------------------------------------------------------------------
2022-02-06 16:25:04.953 Connecting to <FTPS_HOST_NAME>:<FTPS_PORT> ...
2022-02-06 16:25:04.953 HTTP proxy command: CONNECT <FTPS_HOST_NAME>:<FTPS_PORT HTTP/1.1
2022-02-06 16:25:04.953 Host: <FTPS_HOST_NAME>:<FTPS_PORT>
2022-02-06 16:25:04.989 Connection with proxy established, performing handshake...
2022-02-06 16:25:04.989 HTTP proxy response: HTTP/1.1 200 Connection established
2022-02-06 16:25:04.989 HTTP proxy headers: 
2022-02-06 16:25:04.989 Connected with <FTPS_HOST_NAME>:<FTPS_PORT>, negotiating TLS connection...
2022-02-06 16:25:05.038 Verifying certificate for "" with fingerprint <REMOVED_FOR_SECURITY> and 20 failures
2022-02-06 16:25:05.038 Certificate common name "*.<FTPS_DOMAIN_NAME>" matches hostname
2022-02-06 16:25:05.138 Certificate verified against Windows certificate store
2022-02-06 16:25:05.138 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
2022-02-06 16:25:05.191 TLS connection established. Waiting for welcome message...
2022-02-06 16:25:05.191 220 SIJIL FTP
2022-02-06 16:25:05.191 USER <FTPS_USER_NAME>
2022-02-06 16:25:05.191 331 Password required for <FTPS_USER_NAME>
2022-02-06 16:25:06.977 PASS *************
2022-02-06 16:25:07.013 230 Logged on
2022-02-06 16:25:07.013 SYST
2022-02-06 16:25:07.049 215 UNIX emulated by FileZilla
2022-02-06 16:25:07.049 FEAT
2022-02-06 16:25:07.085 211-Features:
2022-02-06 16:25:07.085  MDTM
2022-02-06 16:25:07.086  REST STREAM
2022-02-06 16:25:07.086  SIZE
2022-02-06 16:25:07.086  MLST type*;size*;modify*;
2022-02-06 16:25:07.086  MLSD
2022-02-06 16:25:07.086  AUTH SSL
2022-02-06 16:25:07.086  AUTH TLS
2022-02-06 16:25:07.086  PROT
2022-02-06 16:25:07.088  PBSZ
2022-02-06 16:25:07.088  UTF8
2022-02-06 16:25:07.088  CLNT
2022-02-06 16:25:07.088  MFMT
2022-02-06 16:25:07.088  EPSV
2022-02-06 16:25:07.088  EPRT
2022-02-06 16:25:07.088 211 End
2022-02-06 16:25:07.088 CLNT WinSCP-release-5.15.5
2022-02-06 16:25:07.122 200 Don't care
2022-02-06 16:25:07.123 OPTS UTF8 ON
2022-02-06 16:25:07.159 202 UTF8 mode is always enabled. No need to send this command.
2022-02-06 16:25:07.160 PBSZ 0
2022-02-06 16:25:07.198 200 PBSZ=0
2022-02-06 16:25:07.199 PROT P
2022-02-06 16:25:07.235 200 Protection level set to P
2022-02-06 16:25:07.248 Connected
2022-02-06 16:25:07.248 --------------------------------------------------------------------------
2022-02-06 16:25:07.248 Using FTP protocol.
2022-02-06 16:25:07.250 Doing startup conversation with host.
2022-02-06 16:25:07.264 PWD
2022-02-06 16:25:07.303 257 "/" is current directory.
2022-02-06 16:25:07.303 Changing directory to "<REMOTE_DIRECTORY>".
2022-02-06 16:25:07.303 CWD <REMOTE_DIRECTORY>
2022-02-06 16:25:07.340 250 CWD successful. "<REMOTE_DIRECTORY>" is current directory.
2022-02-06 16:25:07.340 Getting current directory name.
2022-02-06 16:25:07.341 PWD
2022-02-06 16:25:07.384 257 "<REMOTE_DIRECTORY>" is current directory.
2022-02-06 16:25:07.458 Retrieving directory listing...
2022-02-06 16:25:07.458 TYPE A
2022-02-06 16:25:07.493 200 Type set to A
2022-02-06 16:25:07.493 PASV
2022-02-06 16:25:07.530 227 Entering Passive Mode (<REMOVED_FOR_SECURITY>)
2022-02-06 16:25:07.530 Error retrieving server address, cannot test if address is routable
2022-02-06 16:25:07.530 MLSD
2022-02-06 16:25:07.530 Connecting to <PROXY_IP>:<PROXY_DYNAMIC_PORT> ...
2022-02-06 16:25:07.534 HTTP proxy command: CONNECT <PROXY_IP>:<PROXY_DYNAMIC_PORT> HTTP/1.1
2022-02-06 16:25:07.534 Host: <PROXY_IP>:<PROXY_DYNAMIC_PORT>
2022-02-06 16:25:07.534 Connection with proxy established, performing handshake...
2022-02-06 16:25:07.586 HTTP proxy response: HTTP/1.1 200 Connection established
2022-02-06 16:25:07.587 HTTP proxy headers: 
2022-02-06 16:25:07.608 Session ID reused
2022-02-06 16:25:07.610 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
2022-02-06 16:25:07.610 TLS connection established
2022-02-06 16:25:07.619 150 Opening data channel for directory listing of "<REMOTE_DIRECTORY>"
2022-02-06 16:25:07.620 226 Successfully transferred "<REMOTE_DIRECTORY>"
2022-02-06 16:25:07.630 Data connection closed
2022-02-06 16:25:07.631 type=file;modify=20220203072851;size=21; test.txt
2022-02-06 16:25:07.631 type=file;modify=20220203072851;size=21; test_1.txt
2022-02-06 16:25:07.631 Directory listing successful
2022-02-06 16:25:07.632 ..;D;0;1899-12-30T03:00:00.000Z;0;"" [0];"" [0];---------;0
2022-02-06 16:25:07.632 test.txt;-;21;2022-02-03T07:28:51.000Z;3;"" [0];"" [0];---------;0
2022-02-06 16:25:07.632 test_1.txt;-;21;2022-02-03T07:28:51.000Z;3;"" [0];"" [0];---------;0
2022-02-06 16:25:07.659 Startup conversation with host finished.

Apache Log:

220 SIJIL FTP
USER *******
331 Password required for <FTPS_USER_NAME>
PASS *******
230 Logged on
PBSZ 0
200 PBSZ=0
PROT P
200 Protection level set to P
PWD
257 "/" is current directory.
/
CWD <REMOTE_DIRECTORY>
250 CWD successful. "<REMOTE_DIRECTORY>" is current directory.
PWD
257 "<REMOTE_DIRECTORY>" is current directory.
<REMOTE_DIRECTORY>
PASV
227 Entering Passive Mode (<REMOVED_FOR_SECURITY>)
[Replacing PASV mode reply address <PROXY_IP> with <FTPS_IP>]
MLSD
425 Can't open data connection for transfer of "<REMOTE_DIRECTORY>"
List size: 0
QUIT
221 Goodbye

Solution

  • I do not know your network/proxy setup, so I cannot really explain the behaviour of FTPClient. Your server seems to return IP address of the proxy in the PASV response. The default NAT resolver of FTPClient decides that the address is wrong (is it a local network host address?) and choses to use original FTP server's address instead.

    While WinSCP does not do that and connects to the IP that the server returned.

    To avoid the NAT resolver from messing with the address, use FTPClient.setPassiveNatWorkaround (though that's deprecated):

    ftpClient.setPassiveNatWorkaround(false);
    

    or equivalent FTPClient.setPassiveNatWorkaroundStrategy:

    ftpClient.setPassiveNatWorkaroundStrategy(null);