Hi,
It looks like you're running in from inetd and the TRACE output is
ending up getting sent over the network socket. The length 1414676803 is
'TRAC' converted to ascii.
I guess dropbear is running with "-E", or what is the configuration?
That won't work, you'll need to log to syslog instead (the default) when
using inetd.
I can't think of any known issues in 2016.74 causing messages like that
- if you keep seeing it could you send me the logs/pcap off-list,
without -v.
Cheers,
Matt
On 2017-10-11 11:25 am, Hariharasubramanian Ramasubramanian wrote:
I was observing occasional connection disconnect during session setup
with dropber version 2016.74.
I compiled dropbear (version 2016.74) with DEBUG_TRACE flag on (in
debug.h) to help me debug these session setup errors.
However when I run dropbear with the -v switch, client fails to
connect, _everytime_.
The client (9.41.166.131) is OpenSSH_5.8p2 running on RHEL 6.4.
The server (9.3.21.44) is dropbear_2016.74
1) Is this a known issue in dropbear_2016.74 ?
2) Also please suggest how I can debug ssh session setup failures with
dropbear server ?
----------------------------------------------------------------------------------------------------------------------------
The output of ssh -vvv root@9.3.21.44 is as follows:
-bash-4.1$ ssh -vvv root@9.3.21.44
OpenSSH_5.8p2, OpenSSL 1.0.0g 18 Jan 2012
debug1: Reading configuration data /etc/ssh/ssh_config
debug1: Applying options for *
debug2: ssh_connect: needpriv 0
debug1: Connecting to 9.3.21.44 [9.3.21.44] port 22.
debug1: Connection established.
debug1: identity file
/afs/awd.austin.ibm.com/usr/u2/hramasub/.ssh/id_rsa type -1
debug1: identity file
/afs/awd.austin.ibm.com/usr/u2/hramasub/.ssh/id_rsa-cert type -1
debug1: identity file
/afs/awd.austin.ibm.com/usr/u2/hramasub/.ssh/id_dsa type -1
debug1: identity file
/afs/awd.austin.ibm.com/usr/u2/hramasub/.ssh/id_dsa-cert type -1
debug1: identity file
/afs/awd.austin.ibm.com/usr/u2/hramasub/.ssh/id_ecdsa type -1
debug1: identity file
/afs/awd.austin.ibm.com/usr/u2/hramasub/.ssh/id_ecdsa-cert type -1
debug1: ssh_exchange_identification: [1522] Oct 09 11:35:43 Failed
loading /var/lib/dropbear/dropbear_rsa_host_key
debug1: ssh_exchange_identification: TRACE (1522) 0.000000: leave
loadhostkey
debug1: ssh_exchange_identification: TRACE (1522) 0.001107: enter
buf_get_rsa_priv_key
debug1: ssh_exchange_identification: TRACE (1522) 0.001398: enter
buf_get_rsa_pub_key
debug1: ssh_exchange_identification: TRACE (1522) 0.002371: leave
buf_get_rsa_pub_key: success
debug1: ssh_exchange_identification: TRACE (1522) 0.003364: leave
buf_get_rsa_priv_key
debug1: ssh_exchange_identification: TRACE (1522) 0.003685: leave
loadhostkey
debug1: ssh_exchange_identification: [1522] Oct 09 11:35:43 Failed
loading /etc/dropbear/dropbear_dss_host_key
debug1: ssh_exchange_identification: TRACE (1522) 0.009414: leave
loadhostkey
debug1: ssh_exchange_identification: [1522] Oct 09 11:35:43 Failed
loading /etc/dropbear/dropbear_ecdsa_host_key
debug1: ssh_exchange_identification: TRACE (1522) 0.014786: leave
loadhostkey
debug1: ssh_exchange_identification: TRACE (1522) 0.014964: Disabling
key type 1
debug1: ssh_exchange_identification: TRACE (1522) 0.015427: Disabling
key type 2
debug1: ssh_exchange_identification: TRACE (1522) 0.016107: Disabling
key type 3
debug1: ssh_exchange_identification: TRACE (1522) 0.016541: Disabling
key type 4
debug1: ssh_exchange_identification: [1522] Oct 09 11:35:43 Child
connection from ::ffff:9.41.166.131:49818
debug1: ssh_exchange_identification: TRACE (1522) 0.030210: enter
session_init
debug1: ssh_exchange_identification: TRACE (1522) 0.030381:
setnonblocking: 0
debug1: ssh_exchange_identification: TRACE (1522) 0.031095: leave
setnonblocking
debug1: ssh_exchange_identification: TRACE (1522) 0.031521:
setnonblocking: 0
debug1: ssh_exchange_identification: TRACE (1522) 0.031948: leave
setnonblocking
debug1: ssh_exchange_identification: TRACE (1522) 0.032572:
update_channel_prio
debug1: ssh_exchange_identification: TRACE (1522) 0.033036:
update_channel_prio: not any
debug1: ssh_exchange_identification: TRACE (1522) 0.033453: Dropbear
priority transitioning 10 -> 11
debug1: ssh_exchange_identification: TRACE (1522) 0.034171:
setnonblocking: 4
debug1: ssh_exchange_identification: TRACE (1522) 0.034642: leave
setnonblocking
debug1: ssh_exchange_identification: TRACE (1522) 0.035068:
setnonblocking: 5
debug1: ssh_exchange_identification: TRACE (1522) 0.035746: leave
setnonblocking
debug1: ssh_exchange_identification: TRACE (1522) 0.036801: leave
session_init
debug1: ssh_exchange_identification: TRACE (1522) 0.037927:
kexinitialise()
debug1: ssh_exchange_identification: TRACE (1522) 0.038795:
DATAALLOWED=0
debug1: ssh_exchange_identification: TRACE (1522) 0.039085: -> KEXINIT
debug1: ssh_exchange_identification: TRACE (1522) 0.039748: enter
set_connect_fds
debug1: ssh_exchange_identification: TRACE (1522) 0.040495:
maybe_empty_reply_queue - no data allowed
debug1: ssh_exchange_identification: TRACE (1522) 0.040959: enter
handle_connect_fds
debug1: ssh_exchange_identification: TRACE (1522) 0.041604: leave
handle_connect_fds - end iter
debug1: Remote protocol version 2.0, remote software version
dropbear_2016.74
debug1: no match: dropbear_2016.74
debug1: Enabling compatibility mode for protocol 2.0
debug1: Local version string SSH-2.0-OpenSSH_5.8
debug2: fd 3 setting O_NONBLOCK
debug3: load_hostkeys: loading entries for host "9.3.21.44" from file
"/afs/awd.austin.ibm.com/usr/u2/hramasub/.ssh/known_hosts"
debug3: load_hostkeys: found key type RSA in file
/afs/awd.austin.ibm.com/usr/u2/hramasub/.ssh/known_hosts:6
debug3: load_hostkeys: loaded 1 keys
debug3: order_hostkeyalgs: prefer hostkeyalgs:
ssh-rsa-cert-...@openssh.com,ssh-rsa-cert-...@openssh.com,ssh-rsa
debug1: SSH2_MSG_KEXINIT sent
debug1: SSH2_MSG_KEXINIT received
debug2: kex_parse_kexinit:
ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,diffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1
debug2: kex_parse_kexinit:
ssh-rsa-cert-...@openssh.com,ssh-rsa-cert-...@openssh.com,ssh-rsa,ecdsa-sha2-nistp256-cert-...@openssh.com,ecdsa-sha2-nistp384-cert-...@openssh.com,ecdsa-sha2-nistp521-cert-...@openssh.com,ssh-dss-cert-...@openssh.com,ssh-dss-cert-...@openssh.com,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521,ssh-dss
debug2: kex_parse_kexinit:
aes128-ctr,aes192-ctr,aes256-ctr,arcfour256,arcfour128,aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,aes192-cbc,aes256-cbc,arcfour,rijndael-...@lysator.liu.se
debug2: kex_parse_kexinit:
aes128-ctr,aes192-ctr,aes256-ctr,arcfour256,arcfour128,aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,aes192-cbc,aes256-cbc,arcfour,rijndael-...@lysator.liu.se
debug2: kex_parse_kexinit:
hmac-md5,hmac-sha1,umac...@openssh.com,hmac-ripemd160,hmac-ripemd...@openssh.com,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit:
hmac-md5,hmac-sha1,umac...@openssh.com,hmac-ripemd160,hmac-ripemd...@openssh.com,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: none,z...@openssh.com,zlib
debug2: kex_parse_kexinit: none,z...@openssh.com,zlib
debug2: kex_parse_kexinit:
debug2: kex_parse_kexinit:
debug2: kex_parse_kexinit: first_kex_follows 0
debug2: kex_parse_kexinit: reserved 0
debug2: kex_parse_kexinit:
curve25519-sha...@libssh.org,ecdh-sha2-nistp521,ecdh-sha2-nistp384,ecdh-sha2-nistp256,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1,kexgue...@matt.ucc.asn.au
debug2: kex_parse_kexinit: ssh-rsa
debug2: kex_parse_kexinit:
aes128-ctr,aes256-ctr,aes128-cbc,aes256-cbc,twofish256-cbc,twofish-cbc,twofish128-cbc,3des-ctr,3des-cbc
debug2: kex_parse_kexinit:
aes128-ctr,aes256-ctr,aes128-cbc,aes256-cbc,twofish256-cbc,twofish-cbc,twofish128-cbc,3des-ctr,3des-cbc
debug2: kex_parse_kexinit:
hmac-sha1-96,hmac-sha1,hmac-sha2-256,hmac-sha2-512,hmac-md5
debug2: kex_parse_kexinit:
hmac-sha1-96,hmac-sha1,hmac-sha2-256,hmac-sha2-512,hmac-md5
debug2: kex_parse_kexinit: z...@openssh.com,none
debug2: kex_parse_kexinit: z...@openssh.com,none
debug2: kex_parse_kexinit:
debug2: kex_parse_kexinit:
debug2: kex_parse_kexinit: first_kex_follows 0
debug2: kex_parse_kexinit: reserved 0
debug2: mac_setup: found hmac-md5
debug1: kex: server->client aes128-ctr hmac-md5 none
debug2: mac_setup: found hmac-md5
debug1: kex: client->server aes128-ctr hmac-md5 none
debug1: sending SSH2_MSG_KEX_ECDH_INIT
debug1: expecting SSH2_MSG_KEX_ECDH_REPLY
Bad packet length 1414676803.
Disconnecting: Packet corrupt
----------------------------------------------------------------------------------------------------------------------------
tcpdump of the session setup sequence is attached.
thanks in advance,
Hariharasubramanian R.
Power Firmware Development
IBM India Systems & Technology Lab, Bangalore, India
Phone: +91 80 4025 5075
