Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

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

Open
openwrt-bot opened this issue Jun 22, 2020 · 3 comments
Open
Labels

Comments

@openwrt-bot
Copy link

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
Copy link
Author

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
Copy link
Author

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
Copy link
Author

dwmw2:

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

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

1 participant