Search code examples
javaftpftpsapache-commons-net

Fail to get remote data (passive mode, TLS implicit, client certificate + login/pwd authentication)


I try to connect with a FTP server with apache-commons-net-3.7.2 (implicit TLS, double factor authentication with client cert + login/password).

I can authenticate myself, enter in passive mode, but the client doesn't succeed in connecting to the server in order to get data by the data socket.

I can connect myself, on the same computer, with WinSCP (same settings), I have activated WinSCP logs to see protocol details, and I have adjusted my source code with the same options. I can verify that my protocol is OK with a ProtocolCommandListener.

WinSCP logs are below

Connect and browse root directory
Chiffrement : Chiffrement SSL/TLS implicite
Version min TLS/SSL : TLS 1.0
Version max TLS/SSL : TLS 1.2
Réutiliser l'ID de session TLS/SL pour le connexions de données activé
(reuse ssl session id for data connexions activated)

I use the same certificate as for my Java (PFX format with WinSCP, JCEKS for Java, which is Java 8)

. 2021-01-07 15:36:03.031 --------------------------------------------------------------------------
. 2021-01-07 15:36:03.032 WinSCP Version 5.17.9 (Compilation 10905) (OS 10.0.19041 - Windows 10 Enterprise)
. 2021-01-07 15:36:03.032 Configuration: HKCU\Software\Martin Prikryl\WinSCP 2\
. 2021-01-07 15:36:03.032 Log level: Normal
. 2021-01-07 15:36:03.032 Local account: FANLESS\damie
. 2021-01-07 15:36:03.032 Working directory: C:\Users\damie\Desktop
. 2021-01-07 15:36:03.032 Process ID: 22344
. 2021-01-07 15:36:03.033 Command-line: "C:\Program Files (x86)\WinSCP\WinSCP.exe" "xxxxxx" /Desktop /UploadIfAny /log="d:\temp\debugftp.log" /loglevel=0
. 2021-01-07 15:36:03.033 Time zone: Current: GMT+1, Standard: GMT+1 (Paris, Madrid), DST: GMT+2 (Paris, Madrid (heure d’été)), DST Start: 28/03/2021, DST End: 31/10/2021
. 2021-01-07 15:36:03.033 Login time: jeudi 7 janvier 2021 15:36:03
. 2021-01-07 15:36:03.033 --------------------------------------------------------------------------
. 2021-01-07 15:36:03.033 Session name: XXX@XXX (Site)
. 2021-01-07 15:36:03.034 Host name: XXX (Port: 999)
. 2021-01-07 15:36:03.034 User name: XXX (Password: Yes, Key file: No, Passphrase: No)
. 2021-01-07 15:36:03.034 Transfer Protocol: FTP
. 2021-01-07 15:36:03.034 Ping type: Dummy, Ping interval: 30 sec; Timeout: 15 sec
. 2021-01-07 15:36:03.034 Disable Nagle: No
. 2021-01-07 15:36:03.034 Proxy: None
. 2021-01-07 15:36:03.034 Send buffer: 262144
. 2021-01-07 15:36:03.034 UTF: Auto
. 2021-01-07 15:36:03.034 FTPS: Implicit TLS/SSL [Client certificate: Yes]
. 2021-01-07 15:36:03.034 FTP: Passive: Yes [Force IP: Auto]; MLSD: Auto [List all: Auto]; HOST: Auto
. 2021-01-07 15:36:03.034 Session reuse: Yes
. 2021-01-07 15:36:03.034 TLS/SSL versions: TLSv1.0-TLSv1.2
. 2021-01-07 15:36:03.034 Local directory: D:\Local\Documents, Remote directory: /, Update: Yes, Cache: Yes
. 2021-01-07 15:36:03.034 Cache directory changes: Yes, Permanent: Yes
. 2021-01-07 15:36:03.034 Recycle bin: Delete to: No, Overwritten to: No, Bin path: 
. 2021-01-07 15:36:03.034 Timezone offset: 0h 0m
. 2021-01-07 15:36:03.034 --------------------------------------------------------------------------
. 2021-01-07 15:36:03.381 Connexion à XXX:999...
. 2021-01-07 15:36:03.382 Connecté à XXX:999, négociation de la connexion SSL...
. 2021-01-07 15:36:03.382 Server asks for authentication with a client certificate.
. 2021-01-07 15:36:03.382 Verifying certificate for "RESEAU GDS" with fingerprint 58:12:03:0e:b3:dd:cc:d9:c4:a1:ce:a0:4a:d8:83:77:46:0b:9e:4c and 20 failures
. 2021-01-07 15:36:03.382 Certificate common name "XXX" matches hostname
. 2021-01-07 15:36:03.463 Certificate verified against Windows certificate store
. 2021-01-07 15:36:03.463 Using TLSv1.2, cipher TLSv1.2: AES256-GCM-SHA384, 2048 bit RSA, AES256-GCM-SHA384       TLSv1.2 Kx=RSA      Au=RSA  Enc=AESGCM(256) Mac=AEAD
. 2021-01-07 15:36:03.479 Connexion SSL établie. En attente du message de bienvenue...
< 2021-01-07 15:36:03.479 220 w2003-ftp X2 WS_FTP Server 7.7(73371983)
> 2021-01-07 15:36:03.479 USER XXX
< 2021-01-07 15:36:03.483 331 Enter password
> 2021-01-07 15:36:03.483 PASS ********************
< 2021-01-07 15:36:03.533 230-User logged in
< 2021-01-07 15:36:03.533  Bonjour Serveur FTP de ReseauGDS
< 2021-01-07 15:36:03.533 230 User logged in
> 2021-01-07 15:36:03.533 SYST
< 2021-01-07 15:36:03.548 215 UNIX
> 2021-01-07 15:36:03.548 FEAT
< 2021-01-07 15:36:03.567 211-Extensions supported
< 2021-01-07 15:36:03.567     SIZE
< 2021-01-07 15:36:03.567     XMD5
< 2021-01-07 15:36:03.567     XSHA1
< 2021-01-07 15:36:03.567     XSHA256
< 2021-01-07 15:36:03.567     XSHA512
< 2021-01-07 15:36:03.567     XQUOTA
< 2021-01-07 15:36:03.567     LANG EN, ES, FR, GE
< 2021-01-07 15:36:03.567     MDTM
< 2021-01-07 15:36:03.567     MLST size*;type*;perm*;create*;modify*;
< 2021-01-07 15:36:03.567     REST STREAM
< 2021-01-07 15:36:03.567     TVFS
< 2021-01-07 15:36:03.567     UTF8
< 2021-01-07 15:36:03.568     AUTH SSL;TLS-P;
< 2021-01-07 15:36:03.568     PBSZ
< 2021-01-07 15:36:03.568     PROT C;P;
< 2021-01-07 15:36:03.568 211 end
> 2021-01-07 15:36:03.568 OPTS UTF8 ON
< 2021-01-07 15:36:03.584 200 Command OPTS succeed
> 2021-01-07 15:36:03.584 PBSZ 0
< 2021-01-07 15:36:03.598 200 PBSZ=0
> 2021-01-07 15:36:03.598 PROT P
< 2021-01-07 15:36:03.615 200 PRIVATE data channel protection level set
. 2021-01-07 15:36:03.664 Connecté
. 2021-01-07 15:36:03.664 --------------------------------------------------------------------------
. 2021-01-07 15:36:03.664 Using FTP protocol.
. 2021-01-07 15:36:03.664 Doing startup conversation with host.
> 2021-01-07 15:36:03.679 PWD
< 2021-01-07 15:36:03.694 257 "/" is current directory
. 2021-01-07 15:36:03.694 Changing directory to "/".
> 2021-01-07 15:36:03.695 CWD /
< 2021-01-07 15:36:03.723 250 Command CWD succeed
. 2021-01-07 15:36:03.723 Getting current directory name.
> 2021-01-07 15:36:03.723 PWD
< 2021-01-07 15:36:03.740 257 "/" is current directory
. 2021-01-07 15:36:03.787 Listage du répertoire en cours...
> 2021-01-07 15:36:03.787 TYPE A
< 2021-01-07 15:36:03.802 200 Transfer mode set to ASCII
> 2021-01-07 15:36:03.802 PASV
< 2021-01-07 15:36:03.817 227 Entering Passive Mode (192,168,4,122,235,142).
. 2021-01-07 15:36:03.817 Server sent passive reply with unroutable address 192.168.4.122, using host address instead.
> 2021-01-07 15:36:03.817 MLSD
. 2021-01-07 15:36:03.817 Connexion à 83.XXX.XXX.XXX:60302...
< 2021-01-07 15:36:03.845 150 Transferring directory
. 2021-01-07 15:36:03.846 Session ID reused
. 2021-01-07 15:36:03.847 Using TLSv1.2, cipher TLSv1.2: AES256-GCM-SHA384, 2048 bit RSA, AES256-GCM-SHA384       TLSv1.2 Kx=RSA      Au=RSA  Enc=AESGCM(256) Mac=AEAD
. 2021-01-07 15:36:03.847 Connexion SSL établie
< 2021-01-07 15:36:03.869 226 Transfer completed
. 2021-01-07 15:36:03.869 Data connection closed
. 2021-01-07 15:36:03.869 size=0;type=cdir;create=20200623122630;modify=20201020142437; .
. 2021-01-07 15:36:03.869 size=0;type=pdir;create=20160308132406;modify=20200812101755; ..
. 2021-01-07 15:36:03.869 size=0;type=dir;create=20201020141336;modify=20201208104858; Mensuel
. 2021-01-07 15:36:03.869 size=0;type=dir;create=20201020141315;modify=20210107105026; Quotidien
. 2021-01-07 15:36:03.869 Listage du répertoire réussi
. 2021-01-07 15:36:03.870 ..;D;0;1899-12-30T01:00:00.000Z;0;"" [0];"" [0];---------;0
. 2021-01-07 15:36:03.870 Mensuel;D;0;2020-12-08T10:48:58.000Z;3;"" [0];"" [0];---------;0
. 2021-01-07 15:36:03.870 Quotidien;D;0;2021-01-07T10:50:26.000Z;3;"" [0];"" [0];---------;0
. 2021-01-07 15:36:03.893 Startup conversation with host finished.

Java code extract below. You can see that I use a ProtocolCommandListener in order to output the protocol details

    public static void main(String[] args) throws SocketException, IOException, GeneralSecurityException {

        String hostname = args[0];
        int port = Integer.parseInt(args[1]);
        String login = args[2];
        String pwd = args[3];
        
        System.setProperty("jdk.tls.useExtendedMasterSecret", "false");     

        //CompliantFTPSClient client = new CompliantFTPSClient("TLS", true);
        FTPSClient client = new FTPSClient("TLS", true);
        
        File clientCertStore = new File(
                "path to store");
        KeyManager keyManager = KeyManagerUtils.createClientKeyManager("JCEKS", clientCertStore, "",
                "alias", "");
        client.setKeyManager(keyManager);

        client.connect(hostname, port);
        int reply = client.getReplyCode();

        if (!FTPReply.isPositiveCompletion(reply)) {
            client.disconnect();
            System.err.println("FTP server refused connection.");
            System.exit(1);
        } else {
            if (client.login(login, pwd)) {

                client.addProtocolCommandListener(new PrintCommandListener(new PrintWriter(System.err), true));
                client.sendCommand("OPTS", "UTF8 ON");
                client.sendCommand("PBSZ", "0");
                client.sendCommand("PROT", "P");

                client.enterLocalPassiveMode();

                System.out.println("Current directory : "+client.printWorkingDirectory());

                System.out.println(client.listHelp());

                FTPFile[] remoteFiles = client.mlistDir();

                reply = client.getReplyCode();
                System.out.println("fichiers : "+reply);
                System.out.println("nombre : "+remoteFiles.length);

                System.out.println("LOGOUT");
                client.logout();
            } else {
                System.out.println("echec login");
            }
        }
    }
}

Java detailed logs below (system.err and System.out):

janv. 07, 2021 8:31:50 PM sun.security.ssl.SSLLogger log
AVERTISSEMENT: Signature algorithm, ed25519, is not supported by the underlying providers
janv. 07, 2021 8:31:50 PM sun.security.ssl.SSLLogger log
AVERTISSEMENT: Signature algorithm, ed448, is not supported by the underlying providers
janv. 07, 2021 8:31:50 PM sun.security.ssl.SSLLogger log
INFOS: No available application protocols
janv. 07, 2021 8:31:50 PM sun.security.ssl.SSLLogger log
AVERTISSEMENT: Ignore impact of unsupported extension: renegotiation_info
OPTS UTF8 ON
200 Command OPTS succeed
PBSZ 0
200 PBSZ=0
PROT P
200 PRIVATE data channel protection level set
PWD
257 "/" is current directory
Current directory : /
HELP
214-The following commands are implemented
    ABOR  ACCT  ALLO* APPE  CDUP  CWD   DELE  FEAT+ HELP
    HOST+ LANG+ LIST  MDTM+ MLST+ MKD   MODE  NLST  NOOP
    OPTS+ PASS  PASV  PORT  PWD   QUIT  REIN  REST  RETR
    RMD   RNFR  RNTO  SITE  SIZE  SMNT  STAT  STOR  STOU
    STRU* SYST  TYPE  USER  XCUP  XCRC  XCWD  XMD5  XMKD
    XPWD  XRMD  XSIGN XSHA1 XSHA256 XSHA512 XQUOTA
214 Help complete

214-The following commands are implemented
    ABOR  ACCT  ALLO* APPE  CDUP  CWD   DELE  FEAT+ HELP
    HOST+ LANG+ LIST  MDTM+ MLST+ MKD   MODE  NLST  NOOP
    OPTS+ PASS  PASV  PORT  PWD   QUIT  REIN  REST  RETR
    RMD   RNFR  RNTO  SITE  SIZE  SMNT  STAT  STOR  STOU
    STRU* SYST  TYPE  USER  XCUP  XCRC  XCWD  XMD5  XMKD
    XPWD  XRMD  XSIGN XSHA1 XSHA256 XSHA512 XQUOTA
214 Help complete
PASV
227 Entering Passive Mode (192,168,4,122,236,242).
[Replacing PASV mode reply address 192.168.4.122 with 83.206.162.234]
MLSD
150 Transferring directory

The MLSD command never replies.

Perhaps the problem is with ssl session id reuse? It seems that this is a known issue with apache-commons-net, cf https://www.javaer101.com/en/article/970693.html

I asked the FTP admin if this is activated on his side. He said "yes", this is a ""ipswitch ftp server". We planned a debug session on Monday the 11th.

I also tried the workaround that Martin Prikryl indicated to me, subclassing FTPSClient and overloading the prepareDataSocket method, but it doesn't work. The socket passed to the method is not a SSLSocket, so nothings happens (first test).

The code:

public class CompliantFTPSClient extends FTPSClient {

    public CompliantFTPSClient(String protocol, boolean isImplicit) {
        super(protocol, isImplicit);
    }

    @Override
    protected void _prepareDataSocket_(Socket socket) throws IOException {
        if (socket instanceof SSLSocket) {
            // Control socket is SSL
            final SSLSession session = ((SSLSocket) _socket_).getSession();
            if (session.isValid()) {
                final SSLSessionContext context = session.getSessionContext();
                context.setSessionCacheSize(0);
                try {
                    final Field sessionHostPortCache = context.getClass().getDeclaredField("sessionHostPortCache");
                    sessionHostPortCache.setAccessible(true);
                    final Object cache = sessionHostPortCache.get(context);
                    final Method method = cache.getClass().getDeclaredMethod("put", Object.class, Object.class);
                    method.setAccessible(true);
                    method.invoke(cache, String
                            .format("%s:%s", socket.getInetAddress().getHostName(), String.valueOf(socket.getPort()))
                            .toLowerCase(Locale.ROOT), session);
                    method.invoke(cache, String
                            .format("%s:%s", socket.getInetAddress().getHostAddress(), String.valueOf(socket.getPort()))
                            .toLowerCase(Locale.ROOT), session);
                } catch (NoSuchFieldException e) {
                    System.err.println("WARN : No field sessionHostPortCache in SSLSessionContext");
                    e.printStackTrace(System.err);
                } catch (Exception e) {
                    System.err.println("WARN : " + e.getMessage());
                }
            } else {
                System.err.println(String.format("SSL session %s for socket %s is not rejoinable", session, socket));
            }
        }
    }
}

What I'm trying to do: Just recursively browse directory on server, list files, and download some files, the kind of things that usually I can do in a few minutes in SFTP or SCP. But in FTPS with this API, this is just painful.


Solution

  • You have mismatch in data connection encryption by sending PROT P command to the server.

    As you only send the command to the server using the FTP.sendCommand, the command affects the server only. But not the client (Apache Common FTPClient). So when starting the data connection, the server waits for TLS/SSL exchange, but the client does not respond, as it is only expecting plain data. That's why the connection hangs.

    You have to call FTPClient.execPROT("P"). It internally calls FTP.sendCommand("PROT", "P"), but it also enables the encryption on the client side.


    Similarly you should use FTPSClient.execPBSZ instead of sending raw PBSZ 0. Though currently, the FTPSClient.execPBSZ does not do anything on top of calling FTP.sendCommand("PBSZ", ...) (apart from checking results).


    WinSCP also reuses the session ID. If that is required by your server, see:
    How to connect to FTPS server with data connection using same TLS session?