openwrt / openwrt

This repository is a mirror of https://git.openwrt.org/openwrt/openwrt.git It is for reference only and is not active for check-ins. We will continue to accept Pull Requests here. They will be merged via staging trees then into openwrt.git.
Other
19.54k stars 10.21k forks source link

FS#3199 - Outbound SSH failure with dropbear from lantiq (BT HH5a). #8027

Open openwrt-bot opened 4 years ago

openwrt-bot commented 4 years ago

dwmw2:

About 4 times out of 5 I cannot establish an outbound SSH connection with dropbear.

ssh zeniv.linux.org.uk

ssh: Connection to root@zeniv.linux.org.uk:22 exited: Bad buf_getbyte

Precisely the same binary running on my wndr3800 works OK.

openwrt-bot commented 4 years ago

dwmw2:

sshd debug from a failing connection:

Connection from 2001:8b0:10b:1::1234 port 43720 on 2001:8b0:10b:1:21e:67ff:fecb:7a92 port 2222 rdomain "" debug1: Local version string SSH-2.0-OpenSSH_8.3 debug1: Remote protocol version 2.0, remote software version dropbear debug1: no match: dropbear debug2: fd 3 setting O_NONBLOCK debug3: ssh_sandbox_init: preparing seccomp filter sandbox debug2: Network child is on pid 4139069 debug3: preauth child monitor started debug1: SELinux support enabled [preauth] debug1: ssh_selinux_change_context: setting context from 'unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023' to 'unconfined_u:unconfined_r:sshd_net_t:s0-s0:c0.c1023' [preauth] debug3: ssh_selinux_change_context: setcon unconfined_u:unconfined_r:sshd_net_t:s0-s0:c0.c1023 from unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 failed with Invalid argument [preauth] debug3: privsep user:group 74:484 [preauth] debug1: permanently_set_uid: 74/484 [preauth] debug3: ssh_sandbox_child: setting PR_SET_NO_NEW_PRIVS [preauth] debug3: ssh_sandbox_child: attaching seccomp filter program [preauth] debug1: list_hostkey_types: rsa-sha2-512,rsa-sha2-256,ssh-rsa,ecdsa-sha2-nistp256,ssh-ed25519 [preauth] debug3: send packet: type 20 [preauth] debug1: SSH2_MSG_KEXINIT sent [preauth] debug3: receive packet: type 20 [preauth] debug1: SSH2_MSG_KEXINIT received [preauth] debug2: local server KEXINIT proposal [preauth] debug2: KEX algorithms: curve25519-sha256,curve25519-sha256@libssh.org,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,diffie-hellman-group16-sha512,diffie-hellman-group18-sha512,diffie-hellman-group14-sha256 [preauth] debug2: host key algorithms: rsa-sha2-512,rsa-sha2-256,ssh-rsa,ecdsa-sha2-nistp256,ssh-ed25519 [preauth] debug2: ciphers ctos: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com [preauth] debug2: ciphers stoc: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com [preauth] debug2: MACs ctos: umac-64-etm@openssh.com,umac-128-etm@openssh.com,hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-sha1-etm@openssh.com,umac-64@openssh.com,umac-128@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1 [preauth] debug2: MACs stoc: umac-64-etm@openssh.com,umac-128-etm@openssh.com,hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-sha1-etm@openssh.com,umac-64@openssh.com,umac-128@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1 [preauth] debug2: compression ctos: none,zlib@openssh.com [preauth] debug2: compression stoc: none,zlib@openssh.com [preauth] debug2: languages ctos: [preauth] debug2: languages stoc: [preauth] debug2: first_kex_follows 0 [preauth] debug2: reserved 0 [preauth] debug2: peer client KEXINIT proposal [preauth] debug2: KEX algorithms: curve25519-sha256,curve25519-sha256@libssh.org,diffie-hellman-group14-sha256,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1,kexguess2@matt.ucc.asn.au [preauth] debug2: host key algorithms: ssh-rsa [preauth] debug2: ciphers ctos: aes128-ctr,aes256-ctr [preauth] debug2: ciphers stoc: aes128-ctr,aes256-ctr [preauth] debug2: MACs ctos: hmac-sha1,hmac-sha2-256 [preauth] debug2: MACs stoc: hmac-sha1,hmac-sha2-256 [preauth] debug2: compression ctos: none [preauth] debug2: compression stoc: none [preauth] debug2: languages ctos: [preauth] debug2: languages stoc: [preauth] debug2: first_kex_follows 1 [preauth] debug2: reserved 0 [preauth] debug1: kex: algorithm: curve25519-sha256 [preauth] debug1: kex: host key algorithm: ssh-rsa [preauth] debug1: kex: client->server cipher: aes128-ctr MAC: hmac-sha1 compression: none [preauth] debug1: kex: server->client cipher: aes128-ctr MAC: hmac-sha1 compression: none [preauth] debug1: kex: curve25519-sha256 need=20 dh_need=20 [preauth] debug3: mm_request_send entering: type 120 [preauth] debug3: mm_request_receive_expect entering: type 121 [preauth] debug3: mm_request_receive entering [preauth] debug3: mm_request_receive entering debug3: monitor_read: checking request 120 debug3: mm_request_send entering: type 121 debug1: kex: curve25519-sha256 need=20 dh_need=20 [preauth] debug3: mm_request_send entering: type 120 [preauth] debug3: mm_request_receive entering debug3: monitor_read: checking request 120 debug3: mm_request_send entering: type 121 debug3: mm_request_receive_expect entering: type 121 [preauth] debug3: mm_request_receive entering [preauth] debug2: proposal mismatch: my rsa-sha2-512 peer ssh-rsa [preauth] debug1: expecting SSH2_MSG_KEX_ECDH_INIT [preauth] debug3: receive packet: type 30 [preauth] debug2: skipped packet (type 30) [preauth] debug3: receive packet: type 30 [preauth] debug3: mm_sshkey_sign entering [preauth] debug3: mm_request_send entering: type 6 [preauth] debug3: mm_sshkey_sign: waiting for MONITOR_ANS_SIGN [preauth] debug3: mm_request_receive_expect entering: type 7 [preauth] debug3: mm_request_receive entering [preauth] debug3: mm_request_receive entering debug3: monitor_read: checking request 6 debug3: mm_answer_sign debug3: mm_answer_sign: KEX signature 0x561f6b4ce8a0(271) debug3: mm_request_send entering: type 7 debug2: monitor_read: 6 used once, disabling now debug3: send packet: type 31 [preauth] debug3: send packet: type 21 [preauth] debug2: set_newkeys: mode 1 [preauth] debug1: rekey out after 4294967296 blocks [preauth] debug1: SSH2_MSG_NEWKEYS sent [preauth] debug1: expecting SSH2_MSG_NEWKEYS [preauth] debug3: receive packet: type 21 [preauth] debug1: SSH2_MSG_NEWKEYS received [preauth] debug2: set_newkeys: mode 0 [preauth] debug1: rekey in after 4294967296 blocks [preauth] debug1: KEX done [preauth] debug3: receive packet: type 5 [preauth] debug3: send packet: type 6 [preauth] debug3: receive packet: type 50 [preauth] debug1: userauth-request for user root service ssh-connection method none [preauth] debug1: attempt 0 failures 0 [preauth] debug3: mm_getpwnamallow entering [preauth] debug3: mm_request_send entering: type 8 [preauth] debug3: mm_getpwnamallow: waiting for MONITOR_ANS_PWNAM [preauth] debug3: mm_request_receive_expect entering: type 9 [preauth] debug3: mm_request_receive entering [preauth] debug3: mm_request_receive entering debug3: monitor_read: checking request 8 debug3: mm_answer_pwnamallow debug2: parse_server_config_depth: config reprocess config len 711 debug3: mm_answer_pwnamallow: sending MONITOR_ANS_PWNAM: 1 debug3: mm_request_send entering: type 9 debug2: monitor_read: 8 used once, disabling now debug2: input_userauth_request: setting up authctxt for root [preauth] debug3: mm_start_pam entering [preauth] debug3: mm_request_send entering: type 100 [preauth] debug3: mm_inform_authserv entering [preauth] debug3: mm_request_send entering: type 4 [preauth] debug3: mm_inform_authrole entering [preauth] debug3: mm_request_send entering: type 80 [preauth] debug2: input_userauth_request: try method none [preauth] debug3: user_specific_delay: user specific delay 0.000ms [preauth] debug3: ensure_minimum_time_since: elapsed 2.292ms, delaying 2.993ms (requested 5.285ms) [preauth] debug3: mm_request_receive entering debug3: monitor_read: checking request 100 debug1: PAM: initializing for "root" debug1: PAM: setting PAM_RHOST to "2001:8b0:10b:1::1234" debug1: PAM: setting PAM_TTY to "ssh" debug2: monitor_read: 100 used once, disabling now debug3: userauth_finish: failure partial=0 next methods="publickey,gssapi-keyex,gssapi-with-mic,password" [preauth] debug3: send packet: type 51 [preauth] debug3: mm_request_receive entering debug3: monitor_read: checking request 4 debug3: mm_answer_authserv: service=ssh-connection, style= debug2: monitor_read: 4 used once, disabling now debug3: mm_request_receive entering debug3: monitor_read: checking request 80 debug3: mm_answer_authrole: role= debug2: monitor_read: 80 used once, disabling now debug3: mm_request_send entering: type 122 [preauth] debug3: mm_request_receive_expect entering: type 123 [preauth] debug3: mm_request_receive entering [preauth] debug3: mm_request_receive entering debug3: monitor_read: checking request 122 debug3: mm_request_send entering: type 123 Connection closed by authenticating user root 2001:8b0:10b:1::1234 port 43720 [preauth] debug1: do_cleanup [preauth] debug3: PAM: sshpam_thread_cleanup entering [preauth] debug3: mm_request_send entering: type 124 [preauth] debug3: mm_request_receive entering debug3: monitor_read: checking request 124 debug1: monitor_read_log: child log fd closed debug3: mm_request_receive entering debug1: do_cleanup debug1: PAM: cleanup debug3: PAM: sshpam_thread_cleanup entering debug1: Killing privsep child 4139069

openwrt-bot commented 4 years ago

dwmw2:

ssh debug from a working connection:

Connection from 2001:8b0:10b:1::1234 port 43718 on 2001:8b0:10b:1:21e:67ff:fecb:7a92 port 2222 rdomain "" debug1: Local version string SSH-2.0-OpenSSH_8.3 debug1: Remote protocol version 2.0, remote software version dropbear debug1: no match: dropbear debug2: fd 3 setting O_NONBLOCK debug3: ssh_sandbox_init: preparing seccomp filter sandbox debug2: Network child is on pid 4139017 debug3: preauth child monitor started debug1: SELinux support enabled [preauth] debug1: ssh_selinux_change_context: setting context from 'unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023' to 'unconfined_u:unconfined_r:sshd_net_t:s0-s0:c0.c1023' [preauth] debug3: ssh_selinux_change_context: setcon unconfined_u:unconfined_r:sshd_net_t:s0-s0:c0.c1023 from unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 failed with Invalid argument [preauth] debug3: privsep user:group 74:484 [preauth] debug1: permanently_set_uid: 74/484 [preauth] debug3: ssh_sandbox_child: setting PR_SET_NO_NEW_PRIVS [preauth] debug3: ssh_sandbox_child: attaching seccomp filter program [preauth] debug1: list_hostkey_types: rsa-sha2-512,rsa-sha2-256,ssh-rsa,ecdsa-sha2-nistp256,ssh-ed25519 [preauth] debug3: send packet: type 20 [preauth] debug1: SSH2_MSG_KEXINIT sent [preauth] debug3: receive packet: type 20 [preauth] debug1: SSH2_MSG_KEXINIT received [preauth] debug2: local server KEXINIT proposal [preauth] debug2: KEX algorithms: curve25519-sha256,curve25519-sha256@libssh.org,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,diffie-hellman-group16-sha512,diffie-hellman-group18-sha512,diffie-hellman-group14-sha256 [preauth] debug2: host key algorithms: rsa-sha2-512,rsa-sha2-256,ssh-rsa,ecdsa-sha2-nistp256,ssh-ed25519 [preauth] debug2: ciphers ctos: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com [preauth] debug2: ciphers stoc: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com [preauth] debug2: MACs ctos: umac-64-etm@openssh.com,umac-128-etm@openssh.com,hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-sha1-etm@openssh.com,umac-64@openssh.com,umac-128@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1 [preauth] debug2: MACs stoc: umac-64-etm@openssh.com,umac-128-etm@openssh.com,hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-sha1-etm@openssh.com,umac-64@openssh.com,umac-128@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1 [preauth] debug2: compression ctos: none,zlib@openssh.com [preauth] debug2: compression stoc: none,zlib@openssh.com [preauth] debug2: languages ctos: [preauth] debug2: languages stoc: [preauth] debug2: first_kex_follows 0 [preauth] debug2: reserved 0 [preauth] debug2: peer client KEXINIT proposal [preauth] debug2: KEX algorithms: curve25519-sha256,curve25519-sha256@libssh.org,diffie-hellman-group14-sha256,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1,kexguess2@matt.ucc.asn.au [preauth] debug2: host key algorithms: ssh-rsa [preauth] debug2: ciphers ctos: aes128-ctr,aes256-ctr [preauth] debug2: ciphers stoc: aes128-ctr,aes256-ctr [preauth] debug2: MACs ctos: hmac-sha1,hmac-sha2-256 [preauth] debug2: MACs stoc: hmac-sha1,hmac-sha2-256 [preauth] debug2: compression ctos: none [preauth] debug2: compression stoc: none [preauth] debug2: languages ctos: [preauth] debug2: languages stoc: [preauth] debug2: first_kex_follows 1 [preauth] debug2: reserved 0 [preauth] debug1: kex: algorithm: curve25519-sha256 [preauth] debug1: kex: host key algorithm: ssh-rsa [preauth] debug1: kex: client->server cipher: aes128-ctr MAC: hmac-sha1 compression: none [preauth] debug1: kex: server->client cipher: aes128-ctr MAC: hmac-sha1 compression: none [preauth] debug1: kex: curve25519-sha256 need=20 dh_need=20 [preauth] debug3: mm_request_send entering: type 120 [preauth] debug3: mm_request_receive_expect entering: type 121 [preauth] debug3: mm_request_receive entering [preauth] debug3: mm_request_receive entering debug3: monitor_read: checking request 120 debug3: mm_request_send entering: type 121 debug1: kex: curve25519-sha256 need=20 dh_need=20 [preauth] debug3: mm_request_send entering: type 120 [preauth] debug3: mm_request_receive_expect entering: type 121 [preauth] debug3: mm_request_receive entering [preauth] debug3: mm_request_receive entering debug3: monitor_read: checking request 120 debug3: mm_request_send entering: type 121 debug2: proposal mismatch: my rsa-sha2-512 peer ssh-rsa [preauth] debug1: expecting SSH2_MSG_KEX_ECDH_INIT [preauth] debug3: receive packet: type 30 [preauth] debug2: skipped packet (type 30) [preauth] debug3: receive packet: type 30 [preauth] debug3: mm_sshkey_sign entering [preauth] debug3: mm_request_send entering: type 6 [preauth] debug3: mm_sshkey_sign: waiting for MONITOR_ANS_SIGN [preauth] debug3: mm_request_receive_expect entering: type 7 [preauth] debug3: mm_request_receive entering [preauth] debug3: mm_request_receive entering debug3: monitor_read: checking request 6 debug3: mm_answer_sign debug3: mm_answer_sign: KEX signature 0x5641d84a3ba0(271) debug3: mm_request_send entering: type 7 debug2: monitor_read: 6 used once, disabling now debug3: send packet: type 31 [preauth] debug3: send packet: type 21 [preauth] debug2: set_newkeys: mode 1 [preauth] debug1: rekey out after 4294967296 blocks [preauth] debug1: SSH2_MSG_NEWKEYS sent [preauth] debug1: expecting SSH2_MSG_NEWKEYS [preauth] debug3: receive packet: type 21 [preauth] debug1: SSH2_MSG_NEWKEYS received [preauth] debug2: set_newkeys: mode 0 [preauth] debug1: rekey in after 4294967296 blocks [preauth] debug1: KEX done [preauth] debug3: receive packet: type 5 [preauth] debug3: send packet: type 6 [preauth] debug3: receive packet: type 50 [preauth] debug1: userauth-request for user root service ssh-connection method none [preauth] debug1: attempt 0 failures 0 [preauth] debug3: mm_getpwnamallow entering [preauth] debug3: mm_request_send entering: type 8 [preauth] debug3: mm_getpwnamallow: waiting for MONITOR_ANS_PWNAM [preauth] debug3: mm_request_receive_expect entering: type 9 [preauth] debug3: mm_request_receive entering [preauth] debug3: mm_request_receive entering debug3: monitor_read: checking request 8 debug3: mm_answer_pwnamallow debug2: parse_server_config_depth: config reprocess config len 711 debug3: mm_answer_pwnamallow: sending MONITOR_ANS_PWNAM: 1 debug3: mm_request_send entering: type 9 debug2: monitor_read: 8 used once, disabling now debug2: input_userauth_request: setting up authctxt for root [preauth] debug3: mm_start_pam entering [preauth] debug3: mm_request_send entering: type 100 [preauth] debug3: mm_inform_authserv entering [preauth] debug3: mm_request_send entering: type 4 [preauth] debug3: mm_inform_authrole entering [preauth] debug3: mm_request_send entering: type 80 [preauth] debug2: input_userauth_request: try method none [preauth] debug3: user_specific_delay: user specific delay 0.000ms [preauth] debug3: ensure_minimum_time_since: elapsed 1.783ms, delaying 3.502ms (requested 5.285ms) [preauth] debug3: mm_request_receive entering debug3: monitor_read: checking request 100 debug1: PAM: initializing for "root" debug1: PAM: setting PAM_RHOST to "2001:8b0:10b:1::1234" debug1: PAM: setting PAM_TTY to "ssh" debug2: monitor_read: 100 used once, disabling now debug3: userauth_finish: failure partial=0 next methods="publickey,gssapi-keyex,gssapi-with-mic,password" [preauth] debug3: send packet: type 51 [preauth] debug3: mm_request_receive entering debug3: monitor_read: checking request 4 debug3: mm_answer_authserv: service=ssh-connection, style= debug2: monitor_read: 4 used once, disabling now debug3: mm_request_receive entering debug3: monitor_read: checking request 80 debug3: mm_answer_authrole: role= debug2: monitor_read: 80 used once, disabling now

... at this point, the client asks for password ...

debug3: receive packet: type 50 [preauth] debug1: userauth-request for user root service ssh-connection method password [preauth] debug1: attempt 1 failures 0 [preauth] debug2: input_userauth_request: try method password [preauth] debug3: mm_auth_password entering [preauth] debug3: mm_request_send entering: type 12 [preauth] debug3: mm_auth_password: waiting for MONITOR_ANS_AUTHPASSWORD [preauth] debug3: mm_request_receive_expect entering: type 13 [preauth] debug3: mm_request_receive entering [preauth] debug3: mm_request_receive entering debug3: monitor_read: checking request 12 debug3: PAM: sshpam_passwd_conv called with 1 messages debug1: PAM: password authentication accepted for root debug3: mm_answer_authpassword: sending result 1 debug3: mm_request_send entering: type 13 debug3: mm_request_receive_expect entering: type 102 debug3: mm_request_receive entering debug1: do_pam_account: called debug2: do_pam_account: auth information in SSH_AUTH_INFO_0 debug3: PAM: do_pam_account pam_acct_mgmt = 0 (Success) debug3: mm_request_send entering: type 103 Accepted password for root from 2001:8b0:10b:1::1234 port 43718 ssh2

openwrt-bot commented 4 years ago

dwmw2:

This is dropbear 2019.78 on OpenWrt 19.07. I don't recall it happening in 18.06.