search

mscdex / ssh2

SSH2 client and server modules written in pure JavaScript for node.js
MIT License
5.51k stars 664 forks source link

The client doesn't recognize authentication fail #841

Closed Kurtas closed 4 years ago

Kurtas commented 4 years ago

Hi,

I found a problem with SSH connection to HP Aruba Switch 2920 where I don't get error event when an authentication fails, but it works for other switches, for example, I get error event with error All configured authentication methods failed for Cisco IOS.

Do you have any idea?

BTW: I using v8.0.5

See below logs from both devices

Debug log from HP ArubaSw 2920

Connecting to 192.168.102.18
[Thu Oct 24 2019 16:45:18 GMT+0200 (CEST)] DEBUG: Local ident: 'SSH-2.0-ssh2js0.4.6'
[Thu Oct 24 2019 16:45:18 GMT+0200 (CEST)] DEBUG: Client: Trying 192.168.102.18 on port 22 ...
[Thu Oct 24 2019 16:45:18 GMT+0200 (CEST)] DEBUG: Client: Connected
[Thu Oct 24 2019 16:45:18 GMT+0200 (CEST)] DEBUG: Parser: IN_INIT
[Thu Oct 24 2019 16:45:18 GMT+0200 (CEST)] DEBUG: Parser: IN_GREETING
[Thu Oct 24 2019 16:45:18 GMT+0200 (CEST)] DEBUG: Parser: IN_HEADER
[Thu Oct 24 2019 16:45:18 GMT+0200 (CEST)] DEBUG: Remote ident: 'SSH-2.0-Mocana SSH 6.3'
[Thu Oct 24 2019 16:45:18 GMT+0200 (CEST)] DEBUG: Outgoing: Writing KEXINIT
[Thu Oct 24 2019 16:45:18 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETBEFORE (expecting 8)
[Thu Oct 24 2019 16:45:18 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKET
[Thu Oct 24 2019 16:45:18 GMT+0200 (CEST)] DEBUG: Parser: pktLen:404,padLen:9,remainLen:400
[Thu Oct 24 2019 16:45:18 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETDATA
[Thu Oct 24 2019 16:45:18 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETDATAAFTER, packet: KEXINIT
[Thu Oct 24 2019 16:45:18 GMT+0200 (CEST)] DEBUG: Comparing KEXINITs ...
[Thu Oct 24 2019 16:45:18 GMT+0200 (CEST)] DEBUG: (local) KEX algorithms: ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,diffie-hellman-group14-sha1,diffie-hellman-group-exchange-sha1,diffie-hellman-group1-sha1
[Thu Oct 24 2019 16:45:18 GMT+0200 (CEST)] DEBUG: (remote) KEX algorithms: diffie-hellman-group14-sha1
[Thu Oct 24 2019 16:45:18 GMT+0200 (CEST)] DEBUG: KEX algorithm: diffie-hellman-group14-sha1
[Thu Oct 24 2019 16:45:18 GMT+0200 (CEST)] DEBUG: (local) Host key formats: ssh-rsa,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521,ssh-dss
[Thu Oct 24 2019 16:45:18 GMT+0200 (CEST)] DEBUG: (remote) Host key formats: ssh-rsa
[Thu Oct 24 2019 16:45:18 GMT+0200 (CEST)] DEBUG: Host key format: ssh-rsa
[Thu Oct 24 2019 16:45:18 GMT+0200 (CEST)] DEBUG: (local) Client->Server ciphers: aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm,aes128-gcm@openssh.com,aes256-gcm,aes256-gcm@openssh.com,aes256-cbc,aes192-cbc,aes128-cbc,blowfish-cbc,3des-cbc,arcfour256,arcfour128,cast128-cbc,arcfour
[Thu Oct 24 2019 16:45:18 GMT+0200 (CEST)] DEBUG: (remote) Client->Server ciphers: aes256-ctr,aes256-cbc,rijndael-cbc@lysator.liu.se,aes192-ctr,aes192-cbc,aes128-ctr,aes128-cbc,3des-cbc
[Thu Oct 24 2019 16:45:18 GMT+0200 (CEST)] DEBUG: Client->Server Cipher: aes128-ctr
[Thu Oct 24 2019 16:45:18 GMT+0200 (CEST)] DEBUG: (local) Server->Client ciphers: aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm,aes128-gcm@openssh.com,aes256-gcm,aes256-gcm@openssh.com,aes256-cbc,aes192-cbc,aes128-cbc,blowfish-cbc,3des-cbc,arcfour256,arcfour128,cast128-cbc,arcfour
[Thu Oct 24 2019 16:45:18 GMT+0200 (CEST)] DEBUG: (remote) Server->Client ciphers: aes256-ctr,aes256-cbc,rijndael-cbc@lysator.liu.se,aes192-ctr,aes192-cbc,aes128-ctr,aes128-cbc,3des-cbc
[Thu Oct 24 2019 16:45:18 GMT+0200 (CEST)] DEBUG: Server->Client Cipher: aes128-ctr
[Thu Oct 24 2019 16:45:18 GMT+0200 (CEST)] DEBUG: (local) Client->Server HMAC algorithms: hmac-sha2-256,hmac-sha2-512,hmac-sha1,hmac-md5,hmac-sha2-256-96,hmac-sha2-512-96,hmac-ripemd160,hmac-sha1-96,hmac-md5-96
[Thu Oct 24 2019 16:45:18 GMT+0200 (CEST)] DEBUG: (remote) Client->Server HMAC algorithms: hmac-sha1-96,hmac-md5,hmac-sha1,hmac-md5-96
[Thu Oct 24 2019 16:45:18 GMT+0200 (CEST)] DEBUG: Client->Server HMAC algorithm: hmac-sha1
[Thu Oct 24 2019 16:45:18 GMT+0200 (CEST)] DEBUG: (local) Server->Client HMAC algorithms: hmac-sha2-256,hmac-sha2-512,hmac-sha1,hmac-md5,hmac-sha2-256-96,hmac-sha2-512-96,hmac-ripemd160,hmac-sha1-96,hmac-md5-96
[Thu Oct 24 2019 16:45:18 GMT+0200 (CEST)] DEBUG: (remote) Server->Client HMAC algorithms: hmac-sha1-96,hmac-md5,hmac-sha1,hmac-md5-96
[Thu Oct 24 2019 16:45:18 GMT+0200 (CEST)] DEBUG: Server->Client HMAC algorithm: hmac-sha1
[Thu Oct 24 2019 16:45:18 GMT+0200 (CEST)] DEBUG: (local) Client->Server compression algorithms: none,zlib@openssh.com,zlib
[Thu Oct 24 2019 16:45:18 GMT+0200 (CEST)] DEBUG: (remote) Client->Server compression algorithms: none
[Thu Oct 24 2019 16:45:18 GMT+0200 (CEST)] DEBUG: Client->Server compression algorithm: none
[Thu Oct 24 2019 16:45:18 GMT+0200 (CEST)] DEBUG: (local) Server->Client compression algorithms: none,zlib@openssh.com,zlib
[Thu Oct 24 2019 16:45:18 GMT+0200 (CEST)] DEBUG: (remote) Server->Client compression algorithms: none
[Thu Oct 24 2019 16:45:18 GMT+0200 (CEST)] DEBUG: Server->Client compression algorithm: none
[Thu Oct 24 2019 16:45:18 GMT+0200 (CEST)] DEBUG: Outgoing: Writing KEXDH_INIT
[Thu Oct 24 2019 16:45:18 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETBEFORE (expecting 8)
[Thu Oct 24 2019 16:45:19 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKET
[Thu Oct 24 2019 16:45:19 GMT+0200 (CEST)] DEBUG: Parser: pktLen:828,padLen:7,remainLen:824
[Thu Oct 24 2019 16:45:19 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETDATA
[Thu Oct 24 2019 16:45:19 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETDATAAFTER, packet: KEXDH_REPLY
[Thu Oct 24 2019 16:45:19 GMT+0200 (CEST)] DEBUG: Checking host key format
[Thu Oct 24 2019 16:45:19 GMT+0200 (CEST)] DEBUG: Checking signature format
[Thu Oct 24 2019 16:45:19 GMT+0200 (CEST)] DEBUG: Verifying host fingerprint
[Thu Oct 24 2019 16:45:19 GMT+0200 (CEST)] DEBUG: Host accepted by default (no verification)
[Thu Oct 24 2019 16:45:19 GMT+0200 (CEST)] DEBUG: Verifying signature
[Thu Oct 24 2019 16:45:19 GMT+0200 (CEST)] DEBUG: Outgoing: Writing NEWKEYS
[Thu Oct 24 2019 16:45:19 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETBEFORE (expecting 8)
[Thu Oct 24 2019 16:45:19 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKET
[Thu Oct 24 2019 16:45:19 GMT+0200 (CEST)] DEBUG: Parser: pktLen:12,padLen:10,remainLen:8
[Thu Oct 24 2019 16:45:19 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETDATA
[Thu Oct 24 2019 16:45:19 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETDATAAFTER, packet: NEWKEYS
[Thu Oct 24 2019 16:45:19 GMT+0200 (CEST)] DEBUG: Outgoing: Writing SERVICE_REQUEST (ssh-userauth)
[Thu Oct 24 2019 16:45:19 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETBEFORE (expecting 16)
[Thu Oct 24 2019 16:45:19 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKET
[Thu Oct 24 2019 16:45:19 GMT+0200 (CEST)] DEBUG: Parser: Decrypting
[Thu Oct 24 2019 16:45:19 GMT+0200 (CEST)] DEBUG: Parser: pktLen:28,padLen:10,remainLen:16
[Thu Oct 24 2019 16:45:19 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETDATA
[Thu Oct 24 2019 16:45:19 GMT+0200 (CEST)] DEBUG: Parser: Decrypting
[Thu Oct 24 2019 16:45:19 GMT+0200 (CEST)] DEBUG: Parser: HMAC size:20
[Thu Oct 24 2019 16:45:19 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETDATAVERIFY
[Thu Oct 24 2019 16:45:19 GMT+0200 (CEST)] DEBUG: Parser: Verifying MAC
[Thu Oct 24 2019 16:45:19 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETDATAVERIFY (Valid HMAC)
[Thu Oct 24 2019 16:45:19 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETDATAAFTER, packet: SERVICE_ACCEPT
[Thu Oct 24 2019 16:45:19 GMT+0200 (CEST)] DEBUG: Outgoing: Writing USERAUTH_REQUEST (none)
[Thu Oct 24 2019 16:45:19 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETBEFORE (expecting 16)
[Thu Oct 24 2019 16:45:19 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKET
[Thu Oct 24 2019 16:45:19 GMT+0200 (CEST)] DEBUG: Parser: Decrypting
[Thu Oct 24 2019 16:45:19 GMT+0200 (CEST)] DEBUG: Parser: pktLen:716,padLen:9,remainLen:704
[Thu Oct 24 2019 16:45:19 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETDATA
[Thu Oct 24 2019 16:45:19 GMT+0200 (CEST)] DEBUG: Parser: Decrypting
[Thu Oct 24 2019 16:45:19 GMT+0200 (CEST)] DEBUG: Parser: HMAC size:20
[Thu Oct 24 2019 16:45:19 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETDATAVERIFY
[Thu Oct 24 2019 16:45:19 GMT+0200 (CEST)] DEBUG: Parser: Verifying MAC
[Thu Oct 24 2019 16:45:19 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETDATAVERIFY (Valid HMAC)
[Thu Oct 24 2019 16:45:19 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETDATAAFTER, packet: USERAUTH_BANNER
[Thu Oct 24 2019 16:45:19 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETBEFORE (expecting 16)
[Thu Oct 24 2019 16:45:19 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKET
[Thu Oct 24 2019 16:45:19 GMT+0200 (CEST)] DEBUG: Parser: Decrypting
[Thu Oct 24 2019 16:45:19 GMT+0200 (CEST)] DEBUG: Parser: pktLen:44,padLen:8,remainLen:32
[Thu Oct 24 2019 16:45:19 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETDATA
[Thu Oct 24 2019 16:45:19 GMT+0200 (CEST)] DEBUG: Parser: Decrypting
[Thu Oct 24 2019 16:45:19 GMT+0200 (CEST)] DEBUG: Parser: HMAC size:20
[Thu Oct 24 2019 16:45:19 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETDATAVERIFY
[Thu Oct 24 2019 16:45:19 GMT+0200 (CEST)] DEBUG: Parser: Verifying MAC
[Thu Oct 24 2019 16:45:19 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETDATAVERIFY (Valid HMAC)
[Thu Oct 24 2019 16:45:19 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETDATAAFTER, packet: USERAUTH_FAILURE
[Thu Oct 24 2019 16:45:19 GMT+0200 (CEST)] DEBUG: Client: none auth failed
[Thu Oct 24 2019 16:45:19 GMT+0200 (CEST)] DEBUG: Outgoing: Writing USERAUTH_REQUEST (password)
[Thu Oct 24 2019 16:45:19 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETBEFORE (expecting 16)
[Thu Oct 24 2019 16:45:20 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKET
[Thu Oct 24 2019 16:45:20 GMT+0200 (CEST)] DEBUG: Parser: Decrypting
[Thu Oct 24 2019 16:45:20 GMT+0200 (CEST)] DEBUG: Parser: pktLen:44,padLen:8,remainLen:32
[Thu Oct 24 2019 16:45:20 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETDATA
[Thu Oct 24 2019 16:45:20 GMT+0200 (CEST)] DEBUG: Parser: Decrypting
[Thu Oct 24 2019 16:45:20 GMT+0200 (CEST)] DEBUG: Parser: HMAC size:20
[Thu Oct 24 2019 16:45:20 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETDATAVERIFY
[Thu Oct 24 2019 16:45:20 GMT+0200 (CEST)] DEBUG: Parser: Verifying MAC
[Thu Oct 24 2019 16:45:20 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETDATAVERIFY (Valid HMAC)
[Thu Oct 24 2019 16:45:20 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETDATAAFTER, packet: USERAUTH_FAILURE
[Thu Oct 24 2019 16:45:20 GMT+0200 (CEST)] DEBUG: Client: password auth failed
[Thu Oct 24 2019 16:45:20 GMT+0200 (CEST)] DEBUG: Outgoing: Writing USERAUTH_REQUEST (keyboard-interactive)
[Thu Oct 24 2019 16:45:20 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETBEFORE (expecting 16)
[Thu Oct 24 2019 16:45:20 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKET
[Thu Oct 24 2019 16:45:20 GMT+0200 (CEST)] DEBUG: Parser: Decrypting
[Thu Oct 24 2019 16:45:20 GMT+0200 (CEST)] DEBUG: Parser: pktLen:76,padLen:19,remainLen:64
[Thu Oct 24 2019 16:45:20 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETDATA
[Thu Oct 24 2019 16:45:20 GMT+0200 (CEST)] DEBUG: Parser: Decrypting
[Thu Oct 24 2019 16:45:20 GMT+0200 (CEST)] DEBUG: Parser: HMAC size:20
[Thu Oct 24 2019 16:45:20 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETDATAVERIFY
[Thu Oct 24 2019 16:45:20 GMT+0200 (CEST)] DEBUG: Parser: Verifying MAC
[Thu Oct 24 2019 16:45:20 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETDATAVERIFY (Valid HMAC)
[Thu Oct 24 2019 16:45:20 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETDATAAFTER, packet: USERAUTH_INFO_REQUEST
[Thu Oct 24 2019 16:45:20 GMT+0200 (CEST)] DEBUG: Outgoing: Writing USERAUTH_INFO_RESPONSE
[Thu Oct 24 2019 16:45:20 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETBEFORE (expecting 16)
[Thu Oct 24 2019 16:45:27 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKET
[Thu Oct 24 2019 16:45:27 GMT+0200 (CEST)] DEBUG: Parser: Decrypting
[Thu Oct 24 2019 16:45:27 GMT+0200 (CEST)] DEBUG: Parser: pktLen:76,padLen:19,remainLen:64
[Thu Oct 24 2019 16:45:27 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETDATA
[Thu Oct 24 2019 16:45:27 GMT+0200 (CEST)] DEBUG: Parser: Decrypting
[Thu Oct 24 2019 16:45:27 GMT+0200 (CEST)] DEBUG: Parser: HMAC size:20
[Thu Oct 24 2019 16:45:27 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETDATAVERIFY
[Thu Oct 24 2019 16:45:27 GMT+0200 (CEST)] DEBUG: Parser: Verifying MAC
[Thu Oct 24 2019 16:45:27 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETDATAVERIFY (Valid HMAC)
[Thu Oct 24 2019 16:45:27 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETDATAAFTER, packet: USERAUTH_INFO_REQUEST
[Thu Oct 24 2019 16:45:27 GMT+0200 (CEST)] DEBUG: Outgoing: Writing USERAUTH_INFO_RESPONSE
[Thu Oct 24 2019 16:45:27 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETBEFORE (expecting 16)
[Thu Oct 24 2019 16:45:32 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKET
[Thu Oct 24 2019 16:45:32 GMT+0200 (CEST)] DEBUG: Parser: Decrypting
[Thu Oct 24 2019 16:45:32 GMT+0200 (CEST)] DEBUG: Parser: pktLen:60,padLen:11,remainLen:48
[Thu Oct 24 2019 16:45:32 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETDATA
[Thu Oct 24 2019 16:45:32 GMT+0200 (CEST)] DEBUG: Parser: Decrypting
[Thu Oct 24 2019 16:45:32 GMT+0200 (CEST)] DEBUG: Parser: HMAC size:20
[Thu Oct 24 2019 16:45:32 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETDATAVERIFY
[Thu Oct 24 2019 16:45:32 GMT+0200 (CEST)] DEBUG: Parser: Verifying MAC
[Thu Oct 24 2019 16:45:32 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETDATAVERIFY (Valid HMAC)
[Thu Oct 24 2019 16:45:32 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETDATAAFTER, packet: DISCONNECT (BY_APPLICATION)

Debug log for CISCO IOS

Connecting to 10.47.119.135
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: Local ident: 'SSH-2.0-ssh2js0.4.6'
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: Client: Trying 10.47.119.135 on port 22 ...
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: Client: Connected
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: Parser: IN_INIT
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: Parser: IN_GREETING
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: Parser: IN_HEADER
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: Remote ident: 'SSH-2.0-Cisco-1.25'
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: Outgoing: Writing KEXINIT
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETBEFORE (expecting 8)
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKET
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: Parser: pktLen:284,padLen:9,remainLen:280
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETDATA
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETDATAAFTER, packet: KEXINIT
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: Comparing KEXINITs ...
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: (local) KEX algorithms: ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: (remote) KEX algorithms: diffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: KEX algorithm: diffie-hellman-group14-sha1
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: (local) Host key formats: ssh-rsa,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521,ssh-dss
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: (remote) Host key formats: ssh-rsa
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: Host key format: ssh-rsa
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: (local) Client->Server ciphers: aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm,aes128-gcm@openssh.com,aes256-gcm,aes256-gcm@openssh.com,aes256-cbc,aes192-cbc,aes128-cbc,blowfish-cbc,3des-cbc,arcfour256,arcfour128,cast128-cbc,arcfour
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: (remote) Client->Server ciphers: aes128-ctr,aes192-ctr,aes256-ctr
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: Client->Server Cipher: aes128-ctr
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: (local) Server->Client ciphers: aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm,aes128-gcm@openssh.com,aes256-gcm,aes256-gcm@openssh.com,aes256-cbc,aes192-cbc,aes128-cbc,blowfish-cbc,3des-cbc,arcfour256,arcfour128,cast128-cbc,arcfour
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: (remote) Server->Client ciphers: aes128-ctr,aes192-ctr,aes256-ctr
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: Server->Client Cipher: aes128-ctr
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: (local) Client->Server HMAC algorithms: hmac-sha2-256,hmac-sha2-512,hmac-sha1,hmac-md5,hmac-sha2-256-96,hmac-sha2-512-96,hmac-ripemd160,hmac-sha1-96,hmac-md5-96
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: (remote) Client->Server HMAC algorithms: hmac-sha1,hmac-sha1-96
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: Client->Server HMAC algorithm: hmac-sha1
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: (local) Server->Client HMAC algorithms: hmac-sha2-256,hmac-sha2-512,hmac-sha1,hmac-md5,hmac-sha2-256-96,hmac-sha2-512-96,hmac-ripemd160,hmac-sha1-96,hmac-md5-96
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: (remote) Server->Client HMAC algorithms: hmac-sha1,hmac-sha1-96
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: Server->Client HMAC algorithm: hmac-sha1
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: (local) Client->Server compression algorithms: none,zlib@openssh.com,zlib
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: (remote) Client->Server compression algorithms: none
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: Client->Server compression algorithm: none
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: (local) Server->Client compression algorithms: none,zlib@openssh.com,zlib
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: (remote) Server->Client compression algorithms: none
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: Server->Client compression algorithm: none
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: Outgoing: Writing KEXDH_INIT
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETBEFORE (expecting 8)
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKET
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: Parser: pktLen:1340,padLen:7,remainLen:1336
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETDATA
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETDATAAFTER, packet: KEXDH_REPLY
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: Checking host key format
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: Checking signature format
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: Verifying host fingerprint
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: Host accepted by default (no verification)
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: Verifying signature
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: Outgoing: Writing NEWKEYS
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETBEFORE (expecting 8)
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKET
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: Parser: pktLen:12,padLen:10,remainLen:8
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETDATA
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETDATAAFTER, packet: NEWKEYS
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: Outgoing: Writing SERVICE_REQUEST (ssh-userauth)
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETBEFORE (expecting 16)
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKET
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: Parser: Decrypting
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: Parser: pktLen:28,padLen:10,remainLen:16
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETDATA
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: Parser: Decrypting
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: Parser: HMAC size:20
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETDATAVERIFY
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: Parser: Verifying MAC
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETDATAVERIFY (Valid HMAC)
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETDATAAFTER, packet: SERVICE_ACCEPT
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: Outgoing: Writing USERAUTH_REQUEST (none)
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETBEFORE (expecting 16)
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKET
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: Parser: Decrypting
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: Parser: pktLen:60,padLen:14,remainLen:48
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETDATA
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: Parser: Decrypting
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: Parser: HMAC size:20
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETDATAVERIFY
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: Parser: Verifying MAC
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETDATAVERIFY (Valid HMAC)
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETDATAAFTER, packet: USERAUTH_FAILURE
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: Client: none auth failed
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: Outgoing: Writing USERAUTH_REQUEST (password)
[Thu Oct 24 2019 16:40:26 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETBEFORE (expecting 16)
[Thu Oct 24 2019 16:40:29 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKET
[Thu Oct 24 2019 16:40:29 GMT+0200 (CEST)] DEBUG: Parser: Decrypting
[Thu Oct 24 2019 16:40:29 GMT+0200 (CEST)] DEBUG: Parser: pktLen:60,padLen:14,remainLen:48
[Thu Oct 24 2019 16:40:29 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETDATA
[Thu Oct 24 2019 16:40:29 GMT+0200 (CEST)] DEBUG: Parser: Decrypting
[Thu Oct 24 2019 16:40:29 GMT+0200 (CEST)] DEBUG: Parser: HMAC size:20
[Thu Oct 24 2019 16:40:29 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETDATAVERIFY
[Thu Oct 24 2019 16:40:29 GMT+0200 (CEST)] DEBUG: Parser: Verifying MAC
[Thu Oct 24 2019 16:40:29 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETDATAVERIFY (Valid HMAC)
[Thu Oct 24 2019 16:40:29 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETDATAAFTER, packet: USERAUTH_FAILURE
[Thu Oct 24 2019 16:40:29 GMT+0200 (CEST)] DEBUG: Client: password auth failed
[Thu Oct 24 2019 16:40:29 GMT+0200 (CEST)] DEBUG: Outgoing: Writing USERAUTH_REQUEST (keyboard-interactive)
[Thu Oct 24 2019 16:40:29 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETBEFORE (expecting 16)
[Thu Oct 24 2019 16:40:29 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKET
[Thu Oct 24 2019 16:40:29 GMT+0200 (CEST)] DEBUG: Parser: Decrypting
[Thu Oct 24 2019 16:40:29 GMT+0200 (CEST)] DEBUG: Parser: pktLen:44,padLen:11,remainLen:32
[Thu Oct 24 2019 16:40:29 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETDATA
[Thu Oct 24 2019 16:40:29 GMT+0200 (CEST)] DEBUG: Parser: Decrypting
[Thu Oct 24 2019 16:40:29 GMT+0200 (CEST)] DEBUG: Parser: HMAC size:20
[Thu Oct 24 2019 16:40:29 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETDATAVERIFY
[Thu Oct 24 2019 16:40:29 GMT+0200 (CEST)] DEBUG: Parser: Verifying MAC
[Thu Oct 24 2019 16:40:29 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETDATAVERIFY (Valid HMAC)
[Thu Oct 24 2019 16:40:29 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETDATAAFTER, packet: USERAUTH_INFO_REQUEST
[Thu Oct 24 2019 16:40:29 GMT+0200 (CEST)] DEBUG: Outgoing: Writing USERAUTH_INFO_RESPONSE
[Thu Oct 24 2019 16:40:29 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETBEFORE (expecting 16)
[Thu Oct 24 2019 16:40:31 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKET
[Thu Oct 24 2019 16:40:31 GMT+0200 (CEST)] DEBUG: Parser: Decrypting
[Thu Oct 24 2019 16:40:31 GMT+0200 (CEST)] DEBUG: Parser: pktLen:60,padLen:14,remainLen:48
[Thu Oct 24 2019 16:40:31 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETDATA
[Thu Oct 24 2019 16:40:31 GMT+0200 (CEST)] DEBUG: Parser: Decrypting
[Thu Oct 24 2019 16:40:31 GMT+0200 (CEST)] DEBUG: Parser: HMAC size:20
[Thu Oct 24 2019 16:40:31 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETDATAVERIFY
[Thu Oct 24 2019 16:40:31 GMT+0200 (CEST)] DEBUG: Parser: Verifying MAC
[Thu Oct 24 2019 16:40:31 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETDATAVERIFY (Valid HMAC)
[Thu Oct 24 2019 16:40:31 GMT+0200 (CEST)] DEBUG: Parser: IN_PACKETDATAAFTER, packet: USERAUTH_FAILURE
[Thu Oct 24 2019 16:40:31 GMT+0200 (CEST)] DEBUG: Client: keyboard-interactive auth failed
error event { Error: All configured authentication methods failed
    at doNextAuth (/home/script/node_modules/ssh2/lib/client.js:413:17)
    at tryNextAuth (/home/script/node_modules/ssh2/lib/client.js:484:5)
    at SSH2Stream.onUSERAUTH_FAILURE (/home/script/node_modules/ssh2/lib/client.js:597:5)
    at emitTwo (events.js:126:13)
    at SSH2Stream.emit (events.js:214:7)
    at parsePacket (/home/script/node_modules/ssh2-streams/lib/ssh.js:3772:10)
    at SSH2Stream._transform (/home/script/node_modules/ssh2-streams/lib/ssh.js:694:13)
    at SSH2Stream.Transform._read (_stream_transform.js:186:10)
    at SSH2Stream._read (/home/script/node_modules/ssh2-streams/lib/ssh.js:253:15)
    at SSH2Stream.Transform._write (_stream_transform.js:174:12)
    at doWrite (_stream_writable.js:396:12)
    at writeOrBuffer (_stream_writable.js:382:5)
    at SSH2Stream.Writable.write (_stream_writable.js:290:11)
    at Socket.ondata (_stream_readable.js:639:20)
    at emitOne (events.js:116:13)
    at Socket.emit (events.js:211:7) level: 'client-authentication' }
mscdex commented 4 years ago

The reason is that the server is disconnecting before sending a response. This is a known issue.

Kurtas commented 4 years ago

Hi mscdex,

thanks for a quick answer! So there isn't a way how to fix it? For example in both logs is line DEBUG: Client: password auth failed you can't emit an event in this case?

mscdex commented 4 years ago

The workaround is to listen for the 'close' event on the connection object.

For example in both logs is line DEBUG: Client: password auth failed you can't emit an event in this case?

No, because as you can see in the debug log, there are other authentication methods being tried after that. As I said, this (no 'error' on abrupt disconnect) is a known issue.

Kurtas commented 4 years ago

Thank you @mscdex for your time & support. Thanks of your hint that there is a next authentication method, I'm explored debug log again and I found a solution.

The solution if someone was looking for it in the future:

I noticed that I'm sending a response in "keyboard-interactive" event, if I sent the wrong password then I get again same password prompt and in this case I will emit "error" manually event and I'm able to try next credentials.