"TransportException: Broken transport; encountered EOF" connecting to a new third party SFTP

[vdeconinck]

Hi,

A third party was using FTP and is switching to SFTP.
I can connect to their new server using plain sftp command-line (on Ubuntu) but cannot connect to it using sshj. All I'm getting is a "Broken transport; encountered EOF" error.

Here is a minimal code exhibiting the issue. Note that I tried disabling server validation to rule out security issues, to no avail:

import java.io.IOException;
import java.security.PublicKey;
import java.util.List;

import net.schmizz.sshj.SSHClient;
import net.schmizz.sshj.sftp.SFTPClient;
import net.schmizz.sshj.sftp.RemoteResourceInfo;
import net.schmizz.sshj.transport.verification.HostKeyVerifier;

public class SFTPExample {

    public static void main(String[] args) {
        if (args.length < 4) {
            System.err.println("Usage: SFTPExample host login password remoteDir");
            System.exit(-1);
        }
        String host = args[0];
        String username = args[1];
        String password = args[2];
        String remoteDir = args[3];

        SSHClient sshClient = new SSHClient();

        try {
            // Disable host key verification
            sshClient.addHostKeyVerifier(new HostKeyVerifier() {
                public boolean verify(String hostname, int port, PublicKey publicKey) {
                    return true;
                }

                public List<String> findExistingAlgorithms(String hostname, int port) {
                    return null;
                }
            });

            // Connect to the remote SFTP server
            sshClient.connect(host);
            sshClient.authPassword(username, password);

            // Open an SFTP session
            SFTPClient sftpClient = sshClient.newSFTPClient();

            // List files in the remote directory
            List<RemoteResourceInfo> fileList = sftpClient.ls(remoteDir);

            // Print the list of files
            System.out.println("Listing files in: " + remoteDir);
            for (RemoteResourceInfo file : fileList) {
                System.out.println(file.getName());
            }

            // Close the SFTP client
            sftpClient.close();

        } catch (IOException e) {
            e.printStackTrace();
        } finally {
            try {
                // Close the SSH client
                if (sshClient.isConnected()) {
                    sshClient.disconnect();
                }
            } catch (IOException e) {
                e.printStackTrace();
            }
        }
    }
}

The log is:

[main] INFO net.schmizz.sshj.transport.random.JCERandom - Creating new SecureRandom.
[main] INFO net.schmizz.sshj.transport.TransportImpl - Client identity string: SSH-2.0-SSHJ_0.39.0
[main] INFO net.schmizz.sshj.transport.TransportImpl - Server identity string: SSH-2.0-mod_sftp
[sshj-Reader-/54.185.84.253:22-1727803034330] ERROR net.schmizz.sshj.transport.TransportImpl - Dying because - Broken transport; encountered EOF
net.schmizz.sshj.transport.TransportException: Broken transport; encountered EOF
        at net.schmizz.sshj.transport.Reader.run(Reader.java:58)
[sshj-Reader-/54.185.84.253:22-1727803034330] INFO net.schmizz.sshj.transport.TransportImpl - Disconnected - UNKNOWN
[main] ERROR net.schmizz.concurrent.Promise - <<service accept>> woke to: net.schmizz.sshj.transport.TransportException: Broken transport; encountered EOF
net.schmizz.sshj.transport.TransportException: Broken transport; encountered EOF
        at net.schmizz.sshj.transport.Reader.run(Reader.java:58)

When increasing the trace level, here is the part where it fails:

...
[sshj-Reader-/54.185.84.253:22-1727802635949] DEBUG net.schmizz.concurrent.Promise - Clearing <<kexinit sent>>
[sshj-Reader-/54.185.84.253:22-1727802635949] DEBUG net.schmizz.concurrent.Promise - Setting <<kex done>> to `SOME`
[main] DEBUG net.schmizz.sshj.SSHClient - Key exchange took 0.386 seconds
[main] DEBUG net.schmizz.concurrent.Promise - Clearing <<service accept>>
[main] DEBUG net.schmizz.sshj.transport.TransportImpl - Sending SSH_MSG_SERVICE_REQUEST for ssh-userauth
[main] TRACE net.schmizz.sshj.transport.Encoder - Encoding packet #3: 05 00 00 00 0c 73 73 68 2d 75 73 65 72 61 75 74 68
[main] DEBUG net.schmizz.concurrent.Promise - Awaiting <<service accept>>
[sshj-Reader-/54.185.84.253:22-1727802635949] ERROR net.schmizz.sshj.transport.TransportImpl - Dying because - Broken transport; encountered EOF
net.schmizz.sshj.transport.TransportException: Broken transport; encountered EOF
        at net.schmizz.sshj.transport.Reader.run(Reader.java:58)
...

Note: I'm using sshj-0.39.0, bcprov-jdk18on-1.78.1 and eddsa-0.3.0.jar

Any idea what could cause the issue and how to solve it ?
Am I doing something wrong :-) ?

KR, Vincent

[jakub-nezasa]

Hi, we have encountered the same problem.

We are connecting to a new SFTP third party endpoint. We need to upgrade sshj library due to other dependency and we are now encountering the same problem. Below I attach trace logs to help with debugging. When using com.hierynomus:sshj:0.39.0:

[info] net.schmizz.sshj.transport.random.JCERandom - Creating new SecureRandom. [info] net.schmizz.sshj.transport.random.JCERandom - Creating new SecureRandom. [debug] net.schmizz.sshj.transport.random.JCERandom - Random creation took 0 ms [debug] net.schmizz.sshj.transport.random.JCERandom - Random creation took 0 ms [debug] net.schmizz.sshj.DefaultConfig - Available Ciphers [[email protected], aes128-cbc, aes128-ctr, aes192-cbc, aes192-ctr, aes256-cbc, aes256-ctr, [email protected], [email protected], blowfish-cbc, blowfish-ctr, cast128-cbc, cast128-ctr, idea-cbc, idea-ctr, serpent128-cbc, serpent128-ctr, serpent192-cbc, serpent192-ctr, serpent256-cbc, serpent256-ctr, 3des-cbc, 3des-ctr, twofish128-cbc, twofish128-ctr, twofish192-cbc, twofish192-ctr, twofish256-cbc, twofish256-ctr, twofish-cbc, arcfour, arcfour128, arcfour256] [debug] net.schmizz.sshj.DefaultConfig - Available Ciphers [[email protected], aes128-cbc, aes128-ctr, aes192-cbc, aes192-ctr, aes256-cbc, aes256-ctr, [email protected], [email protected], blowfish-cbc, blowfish-ctr, cast128-cbc, cast128-ctr, idea-cbc, idea-ctr, serpent128-cbc, serpent128-ctr, serpent192-cbc, serpent192-ctr, serpent256-cbc, serpent256-ctr, 3des-cbc, 3des-ctr, twofish128-cbc, twofish128-ctr, twofish192-cbc, twofish192-ctr, twofish256-cbc, twofish256-ctr, twofish-cbc, arcfour, arcfour128, arcfour256] [info] net.schmizz.sshj.transport.TransportImpl - Client identity string: SSH-2.0-SSHJ_0.39.0 [info] net.schmizz.sshj.transport.TransportImpl - Client identity string: SSH-2.0-SSHJ_0.39.0 [info] net.schmizz.sshj.transport.TransportImpl - Server identity string: SSH-2.0-mod_sftp [info] net.schmizz.sshj.transport.TransportImpl - Server identity string: SSH-2.0-mod_sftp [debug] net.schmizz.sshj.transport.KeyExchanger - Initiating key exchange [debug] net.schmizz.sshj.transport.KeyExchanger - Initiating key exchange [debug] net.schmizz.concurrent.Promise - Clearing <<kex done>> [debug] net.schmizz.concurrent.Promise - Clearing <<kex done>> [debug] net.schmizz.sshj.transport.KeyExchanger - Sending SSH_MSG_KEXINIT [debug] net.schmizz.sshj.transport.KeyExchanger - Sending SSH_MSG_KEXINIT [trace] net.schmizz.sshj.transport.Decoder - Received packet #0: 14 71 ef [truncated] [trace] net.schmizz.sshj.transport.Decoder - Received packet #0: 14 71 ef [truncated] [trace] net.schmizz.sshj.transport.TransportImpl - Received packet KEXINIT [trace] net.schmizz.sshj.transport.TransportImpl - Received packet KEXINIT [debug] net.schmizz.sshj.transport.KeyExchanger - Received SSH_MSG_KEXINIT [debug] net.schmizz.sshj.transport.KeyExchanger - Received SSH_MSG_KEXINIT [debug] net.schmizz.concurrent.Promise - Awaiting <<kexinit sent>> [debug] net.schmizz.concurrent.Promise - Awaiting <<kexinit sent>> [trace] net.schmizz.sshj.transport.Encoder - Encoding packet #0: 14 c6 [truncated] [debug] net.schmizz.concurrent.Promise - Setting <<kexinit sent>> to SOME[debug] net.schmizz.concurrent.Promise - Setting <<kexinit sent>> toSOME[debug] net.schmizz.concurrent.Promise - Awaiting <<kex done>> [debug] net.schmizz.concurrent.Promise - Awaiting <<kex done>> [debug] net.schmizz.sshj.transport.KeyExchanger - Negotiated algorithms: [ kex=curve25519-sha256; sig=ecdsa-sha2-nistp256; c2sCipher=aes128-cbc; s2cCipher=aes128-cbc; c2sMAC=hmac-sha1; s2cMAC=hmac-sha1; c2sComp=none; s2cComp=none; ] [debug] net.schmizz.sshj.transport.KeyExchanger - Negotiated algorithms: [ kex=curve25519-sha256; sig=ecdsa-sha2-nistp256; c2sCipher=aes128-cbc; s2cCipher=aes128-cbc; c2sMAC=hmac-sha1; s2cMAC=hmac-sha1; c2sComp=none; s2cComp=none; ] [debug] n.schmizz.sshj.transport.kex.Curve25519SHA256 - Sending SSH_MSG_KEXDH_INIT [debug] n.schmizz.sshj.transport.kex.Curve25519SHA256 - Sending SSH_MSG_KEXDH_INIT [trace] net.schmizz.sshj.transport.Encoder - Encoding packet #1: 1e 00 00 [truncated] [trace] net.schmizz.sshj.transport.Encoder - Encoding packet #1: 1e 00 00 [truncated] [trace] net.schmizz.sshj.transport.Decoder - Received packet #1: 1f 00 00 [truncated] [trace] net.schmizz.sshj.transport.TransportImpl - Received packet KEXDH_31 [trace] net.schmizz.sshj.transport.TransportImpl - Received packet KEXDH_31 [debug] net.schmizz.sshj.transport.KeyExchanger - Received kex followup data [debug] net.schmizz.sshj.transport.KeyExchanger - Received kex followup data [debug] n.schmizz.sshj.transport.kex.Curve25519SHA256 - Received SSH_MSG_KEXDH_REPLY [debug] n.schmizz.sshj.transport.kex.Curve25519SHA256 - Received SSH_MSG_KEXDH_REPLY [debug] n.schmizz.sshj.common.ECDSAVariationsAdapter - Key algo: ecdsa-sha2-nistp256, Key curve: nistp256, Key Len: 65, 0x04: 4 x: [-127, -90, -61, -99, -42, -14, -106, 69, -124, 100, -3, -84, -73, 87, -21, 9, -6, -13, -122, -38, 58, 28, 40, -12, -49, 68, 93, 121, 94, -102, 7, 101] y: [125, 79, 110, -74, 43, 48, -103, 89, -13, 60, -17, 14, -113, -89, -28, 125, -82, 12, -18, -14, -49, -35, -75, -86, 70, -12, 24, 114, -122, 23, 13, 5] [debug] n.schmizz.sshj.common.ECDSAVariationsAdapter - Key algo: ecdsa-sha2-nistp256, Key curve: nistp256, Key Len: 65, 0x04: 4 x: [-127, -90, -61, -99, -42, -14, -106, 69, -124, 100, -3, -84, -73, 87, -21, 9, -6, -13, -122, -38, 58, 28, 40, -12, -49, 68, 93, 121, 94, -102, 7, 101] y: [125, 79, 110, -74, 43, 48, -103, 89, -13, 60, -17, 14, -113, -89, -28, 125, -82, 12, -18, -14, -49, -35, -75, -86, 70, -12, 24, 114, -122, 23, 13, 5] [debug] net.schmizz.sshj.transport.KeyExchanger - Trying to verify host key with net.schmizz.sshj.transport.verification.PromiscuousVerifier@19ca0780 [debug] net.schmizz.sshj.transport.KeyExchanger - Trying to verify host key with net.schmizz.sshj.transport.verification.PromiscuousVerifier@19ca0780 [debug] net.schmizz.sshj.transport.KeyExchanger - Sending SSH_MSG_NEWKEYS [debug] net.schmizz.sshj.transport.KeyExchanger - Sending SSH_MSG_NEWKEYS [trace] net.schmizz.sshj.transport.Encoder - Encoding packet #2: 15 [trace] net.schmizz.sshj.transport.Encoder - Encoding packet #2: 15 [trace] net.schmizz.sshj.transport.Decoder - Received packet #2: 15 [trace] net.schmizz.sshj.transport.Decoder - Received packet #2: 15 [trace] net.schmizz.sshj.transport.TransportImpl - Received packet NEWKEYS [trace] net.schmizz.sshj.transport.TransportImpl - Received packet NEWKEYS [debug] net.schmizz.sshj.transport.KeyExchanger - Received SSH_MSG_NEWKEYS [debug] net.schmizz.sshj.transport.KeyExchanger - Received SSH_MSG_NEWKEYS [debug] net.schmizz.concurrent.Promise - Clearing <<kexinit sent>> [debug] net.schmizz.concurrent.Promise - Clearing <<kexinit sent>> [debug] net.schmizz.concurrent.Promise - Setting <<kex done>> toSOME[debug] net.schmizz.concurrent.Promise - Setting <<kex done>> toSOME [debug] net.schmizz.sshj.SSHClient - Key exchange took 0.225 seconds [debug] net.schmizz.sshj.SSHClient - Key exchange took 0.225 seconds [debug] net.schmizz.concurrent.Promise - Clearing <<service accept>> [debug] net.schmizz.concurrent.Promise - Clearing <<service accept>> [debug] net.schmizz.sshj.transport.TransportImpl - Sending SSH_MSG_SERVICE_REQUEST for ssh-userauth [debug] net.schmizz.sshj.transport.TransportImpl - Sending SSH_MSG_SERVICE_REQUEST for ssh-userauth [trace] net.schmizz.sshj.transport.Encoder - Encoding packet #3: 05 00 00 00 0c 73 73 68 2d 75 73 65 72 61 75 74 68 [trace] net.schmizz.sshj.transport.Encoder - Encoding packet #3: 05 00 00 00 0c 73 73 68 2d 75 73 65 72 61 75 74 68 [debug] net.schmizz.concurrent.Promise - Awaiting <<service accept>> [debug] net.schmizz.concurrent.Promise - Awaiting <<service accept>> [error] net.schmizz.sshj.transport.TransportImpl - Dying because - Broken transport; encountered EOF net.schmizz.sshj.transport.TransportException: Broken transport; encountered EOF at net.schmizz.sshj.transport.Reader.run(Reader.java:58)

However, with the old version of

[debug] net.schmizz.sshj.common.SecurityUtils - Trying to register BouncyCastle as a JCE provider [debug] net.schmizz.sshj.common.SecurityUtils - Trying to register BouncyCastle as a JCE provider [info] net.schmizz.sshj.common.SecurityUtils - BouncyCastle registration succeeded [info] net.schmizz.sshj.common.SecurityUtils - BouncyCastle registration succeeded [info] net.schmizz.sshj.transport.TransportImpl - Client identity string: SSH-2.0-SSHJ_0_8_1_SNAPSHOT [info] net.schmizz.sshj.transport.TransportImpl - Client identity string: SSH-2.0-SSHJ_0_8_1_SNAPSHOT [info] net.schmizz.sshj.transport.TransportImpl - Server identity string: SSH-2.0-mod_sftp [info] net.schmizz.sshj.transport.TransportImpl - Server identity string: SSH-2.0-mod_sftp [debug] net.schmizz.concurrent.Promise - Setting <<kex done>> to null[debug] net.schmizz.concurrent.Promise - Setting <<kex done>> tonull[debug] net.schmizz.sshj.transport.KeyExchanger - Sending SSH_MSG_KEXINIT [debug] net.schmizz.sshj.transport.KeyExchanger - Sending SSH_MSG_KEXINIT [trace] net.schmizz.sshj.transport.Decoder - Received packet #0: 14 0f dc [truncated] [trace] net.schmizz.sshj.transport.Decoder - Received packet #0: 14 0f dc [truncated] [trace] net.schmizz.sshj.transport.TransportImpl - Received packet KEXINIT [trace] net.schmizz.sshj.transport.TransportImpl - Received packet KEXINIT [debug] net.schmizz.sshj.transport.KeyExchanger - Received SSH_MSG_KEXINIT [debug] net.schmizz.sshj.transport.KeyExchanger - Received SSH_MSG_KEXINIT [trace] net.schmizz.sshj.transport.Encoder - Encoding packet #-1: 14 84 [truncated] [trace] net.schmizz.sshj.transport.Encoder - Encoding packet #-1: 14 84 [truncated] [debug] net.schmizz.concurrent.Promise - Awaiting <<kexinit sent>> [debug] net.schmizz.concurrent.Promise - Awaiting <<kexinit sent>> [debug] net.schmizz.concurrent.Promise - Setting <<kexinit sent>> toSOME[debug] net.schmizz.concurrent.Promise - Setting <<kexinit sent>> toSOME[debug] net.schmizz.concurrent.Promise - Awaiting <<kex done>> [debug] net.schmizz.concurrent.Promise - Awaiting <<kex done>> [debug] net.schmizz.sshj.transport.KeyExchanger - Negotiated algorithms: [ kex=diffie-hellman-group14-sha1; sig=ssh-rsa; c2sCipher=aes128-ctr; s2cCipher=aes128-ctr; c2sMAC=hmac-sha1; s2cMAC=hmac-sha1; c2sComp=none; s2cComp=none ] [debug] net.schmizz.sshj.transport.KeyExchanger - Negotiated algorithms: [ kex=diffie-hellman-group14-sha1; sig=ssh-rsa; c2sCipher=aes128-ctr; s2cCipher=aes128-ctr; c2sMAC=hmac-sha1; s2cMAC=hmac-sha1; c2sComp=none; s2cComp=none ] [debug] net.schmizz.sshj.transport.kex.DHG14 - Sending SSH_MSG_KEXDH_INIT [debug] net.schmizz.sshj.transport.kex.DHG14 - Sending SSH_MSG_KEXDH_INIT [trace] net.schmizz.sshj.transport.Encoder - Encoding packet #0: 1e 00 00 [truncated] [trace] net.schmizz.sshj.transport.Encoder - Encoding packet #0: 1e 00 00 [truncated] [trace] net.schmizz.sshj.transport.Decoder - Received packet #1: 1f 00 00 [truncated] [trace] net.schmizz.sshj.transport.Decoder - Received packet #1: 1f 00 00 [truncated] [trace] net.schmizz.sshj.transport.TransportImpl - Received packet KEXDH_31 [trace] net.schmizz.sshj.transport.TransportImpl - Received packet KEXDH_31 [debug] net.schmizz.sshj.transport.KeyExchanger - Received kex followup data [debug] net.schmizz.sshj.transport.KeyExchanger - Received kex followup data [debug] net.schmizz.sshj.transport.kex.DHG14 - Received SSH_MSG_KEXDH_REPLY [debug] net.schmizz.sshj.transport.kex.DHG14 - Received SSH_MSG_KEXDH_REPLY [debug] net.schmizz.sshj.transport.KeyExchanger - Trying to verify host key with net.schmizz.sshj.transport.verification.PromiscuousVerifier@a9afd90 [debug] net.schmizz.sshj.transport.KeyExchanger - Trying to verify host key with net.schmizz.sshj.transport.verification.PromiscuousVerifier@a9afd90 [debug] net.schmizz.sshj.transport.KeyExchanger - Sending SSH_MSG_NEWKEYS [debug] net.schmizz.sshj.transport.KeyExchanger - Sending SSH_MSG_NEWKEYS [trace] net.schmizz.sshj.transport.Encoder - Encoding packet #1: 15 [trace] net.schmizz.sshj.transport.Encoder - Encoding packet #1: 15 [trace] net.schmizz.sshj.transport.Decoder - Received packet #2: 15 [trace] net.schmizz.sshj.transport.Decoder - Received packet #2: 15 [trace] net.schmizz.sshj.transport.TransportImpl - Received packet NEWKEYS [trace] net.schmizz.sshj.transport.TransportImpl - Received packet NEWKEYS [debug] net.schmizz.sshj.transport.KeyExchanger - Received SSH_MSG_NEWKEYS [debug] net.schmizz.sshj.transport.KeyExchanger - Received SSH_MSG_NEWKEYS [debug] net.schmizz.concurrent.Promise - Setting <<kexinit sent>> tonull[debug] net.schmizz.concurrent.Promise - Setting <<kexinit sent>> tonull[debug] net.schmizz.concurrent.Promise - Setting <<kex done>> toSOME[debug] net.schmizz.concurrent.Promise - Setting <<kex done>> toSOME[debug] net.schmizz.sshj.SSHClient - Key exchange took 0.13 seconds [debug] net.schmizz.sshj.SSHClient - Key exchange took 0.13 seconds [debug] net.schmizz.concurrent.Promise - Setting <<service accept>> tonull[debug] net.schmizz.concurrent.Promise - Setting <<service accept>> tonull [debug] net.schmizz.sshj.transport.TransportImpl - Sending SSH_MSG_SERVICE_REQUEST for ssh-userauth [debug] net.schmizz.sshj.transport.TransportImpl - Sending SSH_MSG_SERVICE_REQUEST for ssh-userauth [trace] net.schmizz.sshj.transport.Encoder - Encoding packet #2: 05 00 00 [truncated] [trace] net.schmizz.sshj.transport.Encoder - Encoding packet #2: 05 00 00 [truncated] [debug] net.schmizz.concurrent.Promise - Awaiting <<service accept>> [debug] net.schmizz.concurrent.Promise - Awaiting <<service accept>> [trace] net.schmizz.sshj.transport.Decoder - Received packet #3: 06 00 00 [truncated] [trace] net.schmizz.sshj.transport.Decoder - Received packet #3: 06 00 00 [truncated] [trace] net.schmizz.sshj.transport.TransportImpl - Received packet SERVICE_ACCEPT [trace] net.schmizz.sshj.transport.TransportImpl - Received packet SERVICE_ACCEPT

There is not so much difference in the logs produced by those two versions, so it should be easy to pinpoint the problem. How can we fix the issue?