mscdex/ssh2

Version 1.x.x got socket error: read ECONNRESET

Closed this issue · 4 comments

I got this error when trying to establish a SFTP connection with version 1.0.0 or 1.1.0.
But if I downgrade to v0.8.9, it works.

Expected Behavior

Can establish a SFTP connection with the latest version

Current Behavior

Got socket error

Possible Solution

Downgrade to v0.8.9

Steps to Reproduce

  1. Install ssh2@latest or ssh2@"1.0.0"
  2. Establish a SFTP connection

Context (Environment)

  • Node.js: v14.14.0
  • OS: Ubuntu 20.04

Detailed Description

Here is the code:

conn
    .on('ready', () => {
      console.log('Client :: ready');
      conn.sftp((err, sftp) => {
        if (err) throw err;
        sftp.readdir('foo', (err, list) => {
          if (err) throw err;
          console.dir(list);
          conn.end();
        });
      });
    })
    .connect({
      host: 'abc.xyz',
      port: 22,
      username: 'foo',
      privateKey: PRIVATE_KEY,
      debug: console.log,
    });

Here is the log:

Custom crypto binding available
Client: Trying abc.xyz on port 22 ...
Local ident: 'SSH-2.0-ssh2js1.1.0'
Socket connected
Socket error: read ECONNRESET
2021-06-06T03:14:50.738Z Error: read ECONNRESET
    at TCP.onStreamRead (internal/stream_base_commons.js:209:20)
    at TCP.callbackTrampoline (internal/async_hooks.js:129:14) {
  errno: -104,
  code: 'ECONNRESET',
  syscall: 'read',
  level: 'client-socket'
}
Socket closed
2021-06-06T03:14:50.747Z Error: Connection lost before handshake
    at makeError (.../node_modules/ssh2/lib/protocol/utils.js:142:15)
    at .../node_modules/ssh2/lib/client.js:673:13
    at Socket.<anonymous> (.../node_modules/ssh2/lib/client.js:734:7)
    at Socket.emit (events.js:315:20)
    at TCP.<anonymous> (net.js:673:12)
    at TCP.callbackTrampoline (internal/async_hooks.js:129:14) {
  level: 'protocol',
  fatal: true
}

Are you using the same node version when switching versions?

Also, what is the server ident (this should show at the beginning of the debug output with v0.8.9)?

Yes, I'm using the same node version when switching versions.
Here is the log with v0.8.9:

DEBUG: Local ident: 'SSH-2.0-ssh2js0.4.10'
DEBUG: Client: Trying abc.xyz on port 22 ...
DEBUG: Client: Connected
DEBUG: Parser: IN_INIT
DEBUG: Parser: IN_GREETING
DEBUG: Parser: IN_HEADER
DEBUG: Remote ident: 'SSH-2.0-IP*Works! SSH Daemon 2016'
DEBUG: Outgoing: Writing KEXINIT
DEBUG: Parser: IN_PACKETBEFORE (expecting 8)
DEBUG: Parser: IN_PACKET
DEBUG: Parser: pktLen:572,padLen:9,remainLen:568
DEBUG: Parser: IN_PACKETDATA
DEBUG: Parser: IN_PACKETDATAAFTER, packet: KEXINIT
DEBUG: Comparing KEXINITs ...
DEBUG: (local) KEX algorithms: curve25519-sha256@libssh.org,curve25519-sha256,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,diffie-hellman-group14-sha256,diffie-hellman-group16-sha512,diffie-hellman-group18-sha512,diffie-hellman-group14-sha1
DEBUG: (remote) KEX algorithms: diffie-hellman-group-exchange-sha256,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521
DEBUG: KEX algorithm: ecdh-sha2-nistp256
DEBUG: (local) Host key formats: ssh-ed25519,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521,ssh-rsa
DEBUG: (remote) Host key formats: ssh-rsa,x509v3-sign-rsa
DEBUG: Host key format: ssh-rsa
DEBUG: (local) Client->Server ciphers: aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm,aes128-gcm@openssh.com,aes256-gcm,aes256-gcm@openssh.com
DEBUG: (remote) Client->Server ciphers: chacha20-poly1305@openssh.com,aes256-gcm@openssh.com,aes128-gcm@openssh.com,aes256-ctr,aes192-ctr,aes128-ctr,aes256-cbc,aes192-cbc,aes128-cbc
DEBUG: Client->Server Cipher: aes128-ctr
DEBUG: (local) Server->Client ciphers: aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm,aes128-gcm@openssh.com,aes256-gcm,aes256-gcm@openssh.com
DEBUG: (remote) Server->Client ciphers: chacha20-poly1305@openssh.com,aes256-gcm@openssh.com,aes128-gcm@openssh.com,aes256-ctr,aes192-ctr,aes128-ctr,aes256-cbc,aes192-cbc,aes128-cbc
DEBUG: Server->Client Cipher: aes128-ctr
DEBUG: (local) Client->Server HMAC algorithms: hmac-sha2-256,hmac-sha2-512,hmac-sha1
DEBUG: (remote) Client->Server HMAC algorithms: hmac-sha2-256,hmac-sha2-512,hmac-ripemd160
DEBUG: Client->Server HMAC algorithm: hmac-sha2-256
DEBUG: (local) Server->Client HMAC algorithms: hmac-sha2-256,hmac-sha2-512,hmac-sha1
DEBUG: (remote) Server->Client HMAC algorithms: hmac-sha2-256,hmac-sha2-512,hmac-ripemd160
DEBUG: Server->Client HMAC algorithm: hmac-sha2-256
DEBUG: (local) Client->Server compression algorithms: none,zlib@openssh.com,zlib
DEBUG: (remote) Client->Server compression algorithms: none,zlib
DEBUG: Client->Server compression algorithm: none
DEBUG: (local) Server->Client compression algorithms: none,zlib@openssh.com,zlib
DEBUG: (remote) Server->Client compression algorithms: none,zlib
DEBUG: Server->Client compression algorithm: none
DEBUG: Outgoing: Writing KEXECDH_INIT
DEBUG: Parser: IN_PACKETBEFORE (expecting 8)
DEBUG: Parser: IN_PACKET
DEBUG: Parser: pktLen:636,padLen:7,remainLen:632
DEBUG: Parser: IN_PACKETDATA
DEBUG: Parser: IN_PACKETDATAAFTER, packet: KEXECDH_REPLY
DEBUG: Checking host key format
DEBUG: Checking signature format
DEBUG: Verifying host fingerprint
DEBUG: Host accepted by default (no verification)
DEBUG: Verifying signature
DEBUG: Outgoing: Writing NEWKEYS
DEBUG: Parser: IN_PACKETBEFORE (expecting 8)
DEBUG: Parser: IN_PACKET
DEBUG: Parser: pktLen:12,padLen:10,remainLen:8
DEBUG: Parser: IN_PACKETDATA
DEBUG: Parser: IN_PACKETDATAAFTER, packet: NEWKEYS
DEBUG: Outgoing: Writing SERVICE_REQUEST (ssh-userauth)
DEBUG: Parser: IN_PACKETBEFORE (expecting 16)
DEBUG: Parser: IN_PACKET
DEBUG: Parser: Decrypting
DEBUG: Parser: pktLen:28,padLen:10,remainLen:16
DEBUG: Parser: IN_PACKETDATA
DEBUG: Parser: Decrypting
DEBUG: Parser: HMAC size:32
DEBUG: Parser: IN_PACKETDATAVERIFY
DEBUG: Parser: Verifying MAC
DEBUG: Parser: IN_PACKETDATAVERIFY (Valid HMAC)
DEBUG: Parser: IN_PACKETDATAAFTER, packet: SERVICE_ACCEPT
DEBUG: Outgoing: Writing USERAUTH_REQUEST (none)
DEBUG: Parser: IN_PACKETBEFORE (expecting 16)
DEBUG: Parser: IN_PACKET
DEBUG: Parser: Decrypting
DEBUG: Parser: pktLen:28,padLen:12,remainLen:16
DEBUG: Parser: IN_PACKETDATA
DEBUG: Parser: Decrypting
DEBUG: Parser: HMAC size:32
DEBUG: Parser: IN_PACKETDATAVERIFY
DEBUG: Parser: Verifying MAC
DEBUG: Parser: IN_PACKETDATAVERIFY (Valid HMAC)
DEBUG: Parser: IN_PACKETDATAAFTER, packet: USERAUTH_FAILURE
DEBUG: Client: none auth failed
DEBUG: Outgoing: Writing USERAUTH_REQUEST (publickey -- check)
DEBUG: Parser: IN_PACKETBEFORE (expecting 16)
DEBUG: Parser: IN_PACKET
DEBUG: Parser: Decrypting
DEBUG: Parser: pktLen:428,padLen:4,remainLen:416
DEBUG: Parser: IN_PACKETDATA
DEBUG: Parser: Decrypting
DEBUG: Parser: HMAC size:32
DEBUG: Parser: IN_PACKETDATAVERIFY
DEBUG: Parser: Verifying MAC
DEBUG: Parser: IN_PACKETDATAVERIFY (Valid HMAC)
DEBUG: Parser: IN_PACKETDATAAFTER, packet: USERAUTH_PK_OK
DEBUG: Outgoing: Writing USERAUTH_REQUEST (publickey)
DEBUG: Parser: IN_PACKETBEFORE (expecting 16)
DEBUG: Parser: IN_PACKET
DEBUG: Parser: Decrypting
DEBUG: Parser: pktLen:12,padLen:10,remainLen:0
DEBUG: Parser: IN_PACKETDATA
DEBUG: Parser: HMAC size:32
DEBUG: Parser: IN_PACKETDATAVERIFY
DEBUG: Parser: Verifying MAC
DEBUG: Parser: IN_PACKETDATAVERIFY (Valid HMAC)
DEBUG: Parser: IN_PACKETDATAAFTER, packet: USERAUTH_SUCCESS
Client :: ready
DEBUG: Outgoing: Writing CHANNEL_OPEN (0, session)
DEBUG: Parser: IN_PACKETBEFORE (expecting 16)
DEBUG: Parser: IN_PACKET
DEBUG: Parser: Decrypting
DEBUG: Parser: pktLen:28,padLen:10,remainLen:16
DEBUG: Parser: IN_PACKETDATA
DEBUG: Parser: Decrypting
DEBUG: Parser: HMAC size:32
DEBUG: Parser: IN_PACKETDATAVERIFY
DEBUG: Parser: Verifying MAC
DEBUG: Parser: IN_PACKETDATAVERIFY (Valid HMAC)
DEBUG: Parser: IN_PACKETDATAAFTER, packet: CHANNEL_OPEN_CONFIRMATION
DEBUG: Outgoing: Writing CHANNEL_REQUEST (0, subsystem: sftp)
DEBUG: Parser: IN_PACKETBEFORE (expecting 16)
DEBUG: Parser: IN_PACKET
DEBUG: Parser: Decrypting
DEBUG: Parser: pktLen:12,padLen:6,remainLen:0
DEBUG: Parser: IN_PACKETDATA
DEBUG: Parser: HMAC size:32
DEBUG: Parser: IN_PACKETDATAVERIFY
DEBUG: Parser: Verifying MAC
DEBUG: Parser: IN_PACKETDATAVERIFY (Valid HMAC)
DEBUG: Parser: IN_PACKETDATAAFTER, packet: CHANNEL_SUCCESS (0)
DEBUG: Parser: IN_PACKETBEFORE (expecting 16)
DEBUG: Outgoing: Writing CHANNEL_DATA (0)
DEBUG: Parser: IN_PACKET
DEBUG: Parser: Decrypting
DEBUG: Parser: pktLen:28,padLen:9,remainLen:16
DEBUG: Parser: IN_PACKETDATA
DEBUG: Parser: Decrypting
DEBUG: Parser: HMAC size:32
DEBUG: Parser: IN_PACKETDATAVERIFY
DEBUG: Parser: Verifying MAC
DEBUG: Parser: IN_PACKETDATAVERIFY (Valid HMAC)
DEBUG: Parser: IN_PACKETDATAAFTER, packet: CHANNEL_DATA (0)
DEBUG[SFTP]: Outgoing: Writing OPENDIR
DEBUG: Outgoing: Writing CHANNEL_DATA (0)
DEBUG: Parser: IN_PACKETBEFORE (expecting 16)
DEBUG: Parser: IN_PACKET
DEBUG: Parser: Decrypting
DEBUG: Parser: pktLen:28,padLen:4,remainLen:16
DEBUG: Parser: IN_PACKETDATA
DEBUG: Parser: Decrypting
DEBUG: Parser: HMAC size:32
DEBUG: Parser: IN_PACKETDATAVERIFY
DEBUG: Parser: Verifying MAC
DEBUG: Parser: IN_PACKETDATAVERIFY (Valid HMAC)
DEBUG: Parser: IN_PACKETDATAAFTER, packet: CHANNEL_DATA (0)
DEBUG[SFTP]: Parser: Response: HANDLE
DEBUG[SFTP]: Outgoing: Writing READDIR
DEBUG: Outgoing: Writing CHANNEL_DATA (0)
DEBUG: Parser: IN_PACKETBEFORE (expecting 16)
DEBUG: Parser: IN_PACKET
DEBUG: Parser: Decrypting
DEBUG: Parser: pktLen:60,padLen:9,remainLen:48
DEBUG: Parser: IN_PACKETDATA
DEBUG: Parser: Decrypting
DEBUG: Parser: HMAC size:32
DEBUG: Parser: IN_PACKETDATAVERIFY
DEBUG: Parser: Verifying MAC
DEBUG: Parser: IN_PACKETDATAVERIFY (Valid HMAC)
DEBUG: Parser: IN_PACKETDATAAFTER, packet: CHANNEL_DATA (0)
DEBUG[SFTP]: Parser: Response: STATUS
DEBUG[SFTP]: Outgoing: Writing CLOSE
DEBUG: Outgoing: Writing CHANNEL_DATA (0)
DEBUG: Parser: IN_PACKETBEFORE (expecting 16)
DEBUG: Parser: IN_PACKET
DEBUG: Parser: Decrypting
DEBUG: Parser: pktLen:44,padLen:11,remainLen:32
DEBUG: Parser: IN_PACKETDATA
DEBUG: Parser: Decrypting
DEBUG: Parser: HMAC size:32
DEBUG: Parser: IN_PACKETDATAVERIFY
DEBUG: Parser: Verifying MAC
DEBUG: Parser: IN_PACKETDATAVERIFY (Valid HMAC)
DEBUG: Parser: IN_PACKETDATAAFTER, packet: CHANNEL_DATA (0)
DEBUG[SFTP]: Parser: Response: STATUS
[]
DEBUG: Outgoing: Writing DISCONNECT (BY_APPLICATION)
DEBUG: Outgoing: Writing CHANNEL_CLOSE (0)

Unfortunately I only have access to OpenSSH servers, which all work fine for me.

I wonder if there is a remote server implementation bug here. Can you try this patch on top of master?:

diff --git a/lib/protocol/Protocol.js b/lib/protocol/Protocol.js
index b4d1ee0..c4ac214 100644
--- a/lib/protocol/Protocol.js
+++ b/lib/protocol/Protocol.js
@@ -254,8 +254,7 @@ class Protocol {
       );
       if (greeting)
         this._onWrite(greeting);
-      this._onWrite(this._identRaw);
-      this._onWrite(CRLF);
+      this._onWrite(Buffer.concat([this._identRaw, CRLF]);
     });
   }
   _destruct(reason) {

Yes, it works 👍
Here is the patch: https://github.com/FunctorGuys/ssh2

Custom crypto binding available
Client: Trying abc.xyz on port 22 ...
Local ident: 'SSH-2.0-ssh2js1.1.0'
2021-06-06T04:54:27.680Z Connected to mongo server.
Socket connected
Remote ident: 'SSH-2.0-IP*Works! SSH Daemon 2016'
Outbound: Sending KEXINIT
Debugger attached.
Inbound: Handshake in progress
Handshake: (local) KEX method: curve25519-sha256@libssh.org,curve25519-sha256,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,diffie-hellman-group14-sha256,diffie-hellman-group15-sha512,diffie-hellman-group16-sha512,diffie-hellman-group17-sha512,diffie-hellman-group18-sha512
Handshake: (remote) KEX method: diffie-hellman-group-exchange-sha256,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521
Handshake: KEX algorithm: ecdh-sha2-nistp256
Handshake: (local) Host key format: ssh-ed25519,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521,rsa-sha2-512,rsa-sha2-256,ssh-rsa
Handshake: (remote) Host key format: ssh-rsa,x509v3-sign-rsa
Handshake: Host key format: ssh-rsa
Handshake: (local) C->S cipher: aes128-gcm,aes128-gcm@openssh.com,aes256-gcm,aes256-gcm@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,chacha20-poly1305@openssh.com
Handshake: (remote) C->S cipher: chacha20-poly1305@openssh.com,aes256-gcm@openssh.com,aes128-gcm@openssh.com,aes256-ctr,aes192-ctr,aes128-ctr,aes256-cbc,aes192-cbc,aes128-cbc
Handshake: C->S Cipher: aes128-gcm@openssh.com
Handshake: (local) S->C cipher: aes128-gcm,aes128-gcm@openssh.com,aes256-gcm,aes256-gcm@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,chacha20-poly1305@openssh.com
Handshake: (remote) S->C cipher: chacha20-poly1305@openssh.com,aes256-gcm@openssh.com,aes128-gcm@openssh.com,aes256-ctr,aes192-ctr,aes128-ctr,aes256-cbc,aes192-cbc,aes128-cbc
Handshake: S->C cipher: aes128-gcm@openssh.com
Handshake: (local) C->S MAC: hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-sha1-etm@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1
Handshake: (remote) C->S MAC: hmac-sha2-256,hmac-sha2-512,hmac-ripemd160
Handshake: C->S MAC: <implicit>
Handshake: (local) S->C MAC: hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-sha1-etm@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1
Handshake: (remote) S->C MAC: hmac-sha2-256,hmac-sha2-512,hmac-ripemd160
Handshake: S->C MAC: <implicit>
Handshake: (local) C->S compression: none,zlib@openssh.com,zlib
Handshake: (remote) C->S compression: none,zlib
Handshake: C->S compression: none
Handshake: (local) S->C compression: none,zlib@openssh.com,zlib
Handshake: (remote) S->C compression: none,zlib
Handshake: S->C compression: none
Outbound: Sending KEXECDH_INIT
Received DH Reply
Host accepted by default (no verification)
Host accepted (verified)
Inbound: NEWKEYS
Verifying signature ...
Verified signature
Outbound: Sending NEWKEYS
Handshake completed
Outbound: Sending SERVICE_REQUEST (ssh-userauth)
Inbound: Received SERVICE_ACCEPT (ssh-userauth)
Outbound: Sending USERAUTH_REQUEST (none)
Inbound: Received USERAUTH_FAILURE (publickey)
Client: none auth failed
Outbound: Sending USERAUTH_REQUEST (publickey -- check)
Inbound: Received USERAUTH_PK_OK
Outbound: Sending USERAUTH_REQUEST (publickey)
Inbound: Received USERAUTH_SUCCESS
Client :: ready
Outbound: Sending CHANNEL_OPEN (r:0, session)
Inbound: CHANNEL_OPEN_CONFIRMATION (r:0, s:0)
Outbound: Sending CHANNEL_REQUEST (r:0, subsystem: sftp)
Inbound: CHANNEL_SUCCESS (r:0)
Outbound: Sending CHANNEL_DATA (r:0, 9)
Inbound: CHANNEL_DATA (r:0, 9)
SFTP: Inbound: Received VERSION (v3)
Outbound: Sending CHANNEL_DATA (r:0, 16)
SFTP: Outbound: Buffered OPENDIR
Inbound: CHANNEL_DATA (r:0, 14)
SFTP: Inbound: Received HANDLE (id:0)
Outbound: Sending CHANNEL_DATA (r:0, 14)
SFTP: Outbound: Buffered READDIR
Inbound: CHANNEL_DATA (r:0, 41)
SFTP: Inbound: Received STATUS (id:1, 1, "End of file reached.")
Outbound: Sending CHANNEL_DATA (r:0, 14)
SFTP: Outbound: Buffered CLOSE
Inbound: CHANNEL_DATA (r:0, 23)
SFTP: Inbound: Received STATUS (id:2, 0, "OK")
[]
Outbound: Sending DISCONNECT (11)
Socket ended
Socket closed