[
https://issues.apache.org/jira/browse/SSHD-941?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16932574#comment-16932574
]
Goldstein Lyor commented on SSHD-941:
-------------------------------------
The only explanation that comes to mind in view of the log is some slightly
unorthodox behavior where the server does not wait for the KEX to complete and
starts sending some "pre-emptive" packets:
{noformat}
2019-09-12 20:42:30.564Z [collector-55326-2] DEBUG
o.a.s.c.session.ClientSessionImpl:1110 -
writePacket(ClientSessionImpl[admin@/10.10.20.25:22])[SSH_MSG_USERAUTH_REQUEST]
Start flagging packets as pending until key exchange is done
{noformat}
This is something we have not encountered (at least I have not) and while the
code should handle this correctly, I am not so sure it does cover all such
possible flows. It may be the case that the server sent some "pre-emptive"
packet and wait for a response while the client is still waiting for the KEX
phase to end.
I'll look at the successful log you added and see if I can figure out what the
server is sending.
> mina ssh client times out connecting with IOS 15.2
> --------------------------------------------------
>
> Key: SSHD-941
> URL: https://issues.apache.org/jira/browse/SSHD-941
> Project: MINA SSHD
> Issue Type: Bug
> Affects Versions: 2.0.0
> Reporter: Yuefeng
> Priority: Major
>
> Other device is Cisco IOS 15.2 -
> IOS-15#show version
> Cisco IOS Software, Linux Software (I86BI_LINUXL2-ADVENTERPRISEK9-M), Version
> 15.2(CML_NIGHTLY_20180510)FLO_DSGS7, EARLY DEPLOYMENT DEVELOPMENT BUILD,
> synced to V152_6_0_81_E
>
> apache.sshd always times out connecting to this device -
>
> {code:java}
> 2019-09-12 20:42:30.559Z [sshd-SshClient[4ae0d26a]-nio2-thread-15] DEBUG
> o.a.s.c.session.ClientSessionImpl:68 - Client session created:
> Nio2Session[local=/10.10.20.1:41950, remote=/10.10.20.25:22]
> 2019-09-12 20:42:30.559Z [sshd-SshClient[4ae0d26a]-nio2-thread-15] DEBUG
> o.a.s.c.s.ClientUserAuthService:101 -
> ClientUserAuthService(ClientSessionImpl[null@/10.10.20.25:22]) client
> methods: [publickey, keyboard-interactive, password]
> 2019-09-12 20:42:30.559Z [sshd-SshClient[4ae0d26a]-nio2-thread-15] DEBUG
> o.a.s.c.session.ClientSessionImpl:1569 -
> sendIdentification(ClientSessionImpl[null@/10.10.20.25:22]):
> SSH-2.0-SSHD-CORE-2.0.0
> 2019-09-12 20:42:30.560Z [sshd-SshClient[4ae0d26a]-nio2-thread-15] DEBUG
> o.a.s.c.session.ClientSessionImpl:1716 -
> sendKexInit(ClientSessionImpl[null@/10.10.20.25:22]) Send SSH_MSG_KEXINIT
> 2019-09-12 20:42:30.560Z [collector-55326-2] DEBUG
> o.a.s.c.s.ClientUserAuthService:150 -
> auth(ClientSessionImpl[admin@/10.10.20.25:22])[ssh-connection] send
> SSH_MSG_USERAUTH_REQUEST for 'none'
> 2019-09-12 20:42:30.564Z [collector-55326-2] DEBUG
> o.a.s.c.session.ClientSessionImpl:1110 -
> writePacket(ClientSessionImpl[admin@/10.10.20.25:22])[SSH_MSG_USERAUTH_REQUEST]
> Start flagging packets as pending until key exchange is done
> 2019-09-12 20:42:30.612Z [sshd-SshClient[4ae0d26a]-nio2-thread-9] DEBUG
> o.a.s.c.session.ClientSessionImpl:1653 -
> doReadIdentification(ClientSessionImpl[admin@/10.10.20.25:22])
> line='SSH-2.0-Cisco-1.25'
> 2019-09-12 20:42:30.612Z [sshd-SshClient[4ae0d26a]-nio2-thread-9] DEBUG
> o.a.s.c.session.ClientSessionImpl:375 -
> readIdentification(ClientSessionImpl[admin@/10.10.20.25:22]) Server version
> string: SSH-2.0-Cisco-1.25
> 2019-09-12 20:42:50.565Z [collector-55326-2] WARN
> c.forwardnetworks.client.web.a.b.e:181 - SSH auth failed:
> DefaultAuthFuture[ssh-connection]: Failed to get operation result within
> specified timeout: 20000
> org.apache.sshd.common.SshException: DefaultAuthFuture[ssh-connection]:
> Failed to get operation result within specified timeout: 20000
> {code}
>
> ssh on linux has no problem connecting -
> {code:java}
> root@eve-ng:/opt/fwd/logs# ssh -vvvv admin@10.10.20.25
> OpenSSH_7.2p2 Ubuntu-4ubuntu2.8, OpenSSL 1.0.2g 1 Mar 2016
> debug1: Reading configuration data /etc/ssh/ssh_config
> debug1: /etc/ssh/ssh_config line 19: Applying options for *
> debug2: resolving "10.10.20.25" port 22
> debug2: ssh_connect_direct: needpriv 0
> debug1: Connecting to 10.10.20.25 [10.10.20.25] port 22.
> debug1: Connection established.
> debug1: permanently_set_uid: 0/0
> debug1: key_load_public: No such file or directory
> debug1: identity file /root/.ssh/id_rsa type -1
> debug1: key_load_public: No such file or directory
> debug1: identity file /root/.ssh/id_rsa-cert type -1
> debug1: key_load_public: No such file or directory
> debug1: identity file /root/.ssh/id_dsa type -1
> debug1: key_load_public: No such file or directory
> debug1: identity file /root/.ssh/id_dsa-cert type -1
> debug1: key_load_public: No such file or directory
> debug1: identity file /root/.ssh/id_ecdsa type -1
> debug1: key_load_public: No such file or directory
> debug1: identity file /root/.ssh/id_ecdsa-cert type -1
> debug1: key_load_public: No such file or directory
> debug1: identity file /root/.ssh/id_ed25519 type -1
> debug1: key_load_public: No such file or directory
> debug1: identity file /root/.ssh/id_ed25519-cert type -1
> debug1: Enabling compatibility mode for protocol 2.0
> debug1: Local version string SSH-2.0-OpenSSH_7.2p2 Ubuntu-4ubuntu2.8
> debug1: Remote protocol version 2.0, remote software version Cisco-1.25
> debug1: match: Cisco-1.25 pat Cisco-1.* compat 0x60000000
> debug2: fd 3 setting O_NONBLOCK
> debug1: Authenticating to 10.10.20.25:22 as 'admin'
> debug3: hostkeys_foreach: reading file "/root/.ssh/known_hosts"
> debug3: record_hostkey: found key type RSA in file /root/.ssh/known_hosts:9
> debug3: load_hostkeys: loaded 1 keys from 10.10.20.25
> debug3: order_hostkeyalgs: prefer hostkeyalgs:
> ssh-rsa-cert-...@openssh.com,rsa-sha2-512,rsa-sha2-256,ssh-rsa
> debug3: send packet: type 20
> debug1: SSH2_MSG_KEXINIT sent
> debug3: receive packet: type 20
> debug1: SSH2_MSG_KEXINIT received
> debug2: local client KEXINIT proposal
> debug2: KEX algorithms:
> curve25519-sha...@libssh.org,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,diffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha1,ext-info-c
> debug2: host key algorithms:
> ssh-rsa-cert-...@openssh.com,rsa-sha2-512,rsa-sha2-256,ssh-rsa,ecdsa-sha2-nistp256-cert-...@openssh.com,ecdsa-sha2-nistp384-cert-...@openssh.com,ecdsa-sha2-nistp521-cert-...@openssh.com,ssh-ed25519-cert-...@openssh.com,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521,ssh-ed25519
> debug2: ciphers ctos:
> chacha20-poly1...@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-...@openssh.com,aes256-...@openssh.com,aes128-cbc,aes192-cbc,aes256-cbc,3des-cbc
> debug2: ciphers stoc:
> chacha20-poly1...@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-...@openssh.com,aes256-...@openssh.com,aes128-cbc,aes192-cbc,aes256-cbc,3des-cbc
> debug2: MACs ctos:
> umac-64-...@openssh.com,umac-128-...@openssh.com,hmac-sha2-256-...@openssh.com,hmac-sha2-512-...@openssh.com,hmac-sha1-...@openssh.com,umac...@openssh.com,umac-...@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1
> debug2: MACs stoc:
> umac-64-...@openssh.com,umac-128-...@openssh.com,hmac-sha2-256-...@openssh.com,hmac-sha2-512-...@openssh.com,hmac-sha1-...@openssh.com,umac...@openssh.com,umac-...@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1
> debug2: compression ctos: none,z...@openssh.com,zlib
> debug2: compression stoc: none,z...@openssh.com,zlib
> debug2: languages ctos:
> debug2: languages stoc:
> debug2: first_kex_follows 0
> debug2: reserved 0
> debug2: peer server KEXINIT proposal
> debug2: KEX algorithms:
> diffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1
> debug2: host key algorithms: ssh-rsa
> debug2: ciphers ctos: aes128-ctr,aes192-ctr,aes256-ctr
> debug2: ciphers stoc: aes128-ctr,aes192-ctr,aes256-ctr
> debug2: MACs ctos: hmac-sha1,hmac-sha1-96
> debug2: MACs stoc: hmac-sha1,hmac-sha1-96
> debug2: compression ctos: none
> debug2: compression stoc: none
> debug2: languages ctos:
> debug2: languages stoc:
> debug2: first_kex_follows 0
> debug2: reserved 0
> debug1: kex: algorithm: diffie-hellman-group-exchange-sha1
> debug1: kex: host key algorithm: ssh-rsa
> debug1: kex: server->client cipher: aes128-ctr MAC: hmac-sha1 compression:
> none
> debug1: kex: client->server cipher: aes128-ctr MAC: hmac-sha1 compression:
> none
> debug3: send packet: type 34
> debug1: SSH2_MSG_KEX_DH_GEX_REQUEST(2048<4096<8192) sent
> debug3: receive packet: type 31
> debug1: got SSH2_MSG_KEX_DH_GEX_GROUP
> debug2: bits set: 2030/4096
> debug3: send packet: type 32
> debug1: SSH2_MSG_KEX_DH_GEX_INIT sent
> debug3: receive packet: type 33
> debug1: got SSH2_MSG_KEX_DH_GEX_REPLY
> debug1: Server host key: ssh-rsa
> SHA256:qb8x7Bb8Q3x5rtAC/s/zTeHyOGpwyLolpvIYcFIfrhk
> debug3: hostkeys_foreach: reading file "/root/.ssh/known_hosts"
> debug3: record_hostkey: found key type RSA in file /root/.ssh/known_hosts:9
> debug3: load_hostkeys: loaded 1 keys from 10.10.20.25
> debug1: Host '10.10.20.25' is known and matches the RSA host key.
> debug1: Found key in /root/.ssh/known_hosts:9
> debug2: bits set: 2098/4096
> debug3: send packet: type 21
> debug2: set_newkeys: mode 1
> debug1: rekey after 4294967296 blocks
> debug1: SSH2_MSG_NEWKEYS sent
> debug1: expecting SSH2_MSG_NEWKEYS
> debug3: receive packet: type 21
> debug1: SSH2_MSG_NEWKEYS received
> debug2: set_newkeys: mode 0
> debug1: rekey after 4294967296 blocks
> debug2: key: /root/.ssh/id_rsa ((nil))
> debug2: key: /root/.ssh/id_dsa ((nil))
> debug2: key: /root/.ssh/id_ecdsa ((nil))
> debug2: key: /root/.ssh/id_ed25519 ((nil))
> debug3: send packet: type 5
> debug3: receive packet: type 6
> debug2: service_accept: ssh-userauth
> debug1: SSH2_MSG_SERVICE_ACCEPT received
> debug3: send packet: type 50
> debug3: receive packet: type 51
> debug1: Authentications that can continue:
> publickey,keyboard-interactive,password
> debug3: start over, passed a different list
> publickey,keyboard-interactive,password
> debug3: preferred
> gssapi-keyex,gssapi-with-mic,publickey,keyboard-interactive,password
> debug3: authmethod_lookup publickey
> debug3: remaining preferred: keyboard-interactive,password
> debug3: authmethod_is_enabled publickey
> debug1: Next authentication method: publickey
> debug1: Trying private key: /root/.ssh/id_rsa
> debug3: no such identity: /root/.ssh/id_rsa: No such file or directory
> debug1: Trying private key: /root/.ssh/id_dsa
> debug3: no such identity: /root/.ssh/id_dsa: No such file or directory
> debug1: Trying private key: /root/.ssh/id_ecdsa
> debug3: no such identity: /root/.ssh/id_ecdsa: No such file or directory
> debug1: Trying private key: /root/.ssh/id_ed25519
> debug3: no such identity: /root/.ssh/id_ed25519: No such file or directory
> debug2: we did not send a packet, disable method
> debug3: authmethod_lookup keyboard-interactive
> debug3: remaining preferred: password
> debug3: authmethod_is_enabled keyboard-interactive
> debug1: Next authentication method: keyboard-interactive
> debug2: userauth_kbdint
> debug3: send packet: type 50
> debug2: we sent a keyboard-interactive packet, wait for reply
> debug3: receive packet: type 60
> debug2: input_userauth_info_req
> debug2: input_userauth_info_req: num_prompts 1
> Password:
> {code}
>
>
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscr...@mina.apache.org
For additional commands, e-mail: dev-h...@mina.apache.org
