Call for testing: OpenSSH 8.0

Adam Eijdenberg adam.eijdenberg at digital.gov.au
Wed Apr 3 09:29:31 AEDT 2019 

> From: Damien Miller <djm at mindrot.org>
> Thanks for testing - are you able to see if there's anything in
> the server logs?

Hi Damien,

I've been able to reproduce being unable to successfully connect to
EC2 instances launched with either Amazon Linux 2 AMI (HVM) or Amazon
Linux AMI 2018.03.0 (HVM) images (which are the first two options you
see when launching an instance via their "Launch instance..." wizard).

Both appear to use OpenSSH 7.4.

I've included both client and server logs below. Older versions of the
ssh client connect just fine. For these logs, the server contained no
custom configuration (other than setting the LogLevel to DEBUG3), so
this should be reproducible by anyone with an AWS account.

Hope that helps.

Cheers, Adam

Client:

$ ./ssh ec2-user at server.ip.in.cloud -vvv
OpenSSH_7.9p1-snap20190402, OpenSSL 1.1.0g  2 Nov 2017
debug1: Reading configuration data /home/username/.ssh/config
debug2: resolve_canonicalize: hostname server.ip.in.cloud is address
debug2: ssh_connect_direct
debug1: Connecting to server.ip.in.cloud [server.ip.in.cloud] port 22.
debug1: Connection established.
debug1: identity file /home/username/.ssh/id_rsa type 0
debug1: identity file /home/username/.ssh/id_rsa-cert type -1
debug1: identity file /home/username/.ssh/id_dsa type -1
debug1: identity file /home/username/.ssh/id_dsa-cert type -1
debug1: identity file /home/username/.ssh/id_ecdsa type -1
debug1: identity file /home/username/.ssh/id_ecdsa-cert type -1
debug1: identity file /home/username/.ssh/id_ed25519 type -1
debug1: identity file /home/username/.ssh/id_ed25519-cert type -1
debug1: identity file /home/username/.ssh/id_xmss type -1
debug1: identity file /home/username/.ssh/id_xmss-cert type -1
debug1: Local version string SSH-2.0-OpenSSH_7.9
debug1: Remote protocol version 2.0, remote software version OpenSSH_7.4
debug1: match: OpenSSH_7.4 pat
OpenSSH_7.0*,OpenSSH_7.1*,OpenSSH_7.2*,OpenSSH_7.3*,OpenSSH_7.4*,OpenSSH_7.5*,OpenSSH_7.6*,OpenSSH_7.7*
compat 0x04000002
debug2: fd 3 setting O_NONBLOCK
debug1: Authenticating to server.ip.in.cloud:22 as 'ec2-user'
debug3: hostkeys_foreach: reading file "/home/username/.ssh/known_hosts"
debug3: record_hostkey: found key type ECDSA in file
/home/username/.ssh/known_hosts:13
debug3: load_hostkeys: loaded 1 keys from server.ip.in.cloud
debug3: order_hostkeyalgs: prefer hostkeyalgs:
ecdsa-sha2-nistp256-cert-v01 at openssh.com,ecdsa-sha2-nistp384-cert-v01 at openssh.com,ecdsa-sha2-nistp521-cert-v01 at openssh.com,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521
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-sha256,curve25519-sha256 at 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,diffie-hellman-group14-sha1,ext-info-c
debug2: host key algorithms:
ecdsa-sha2-nistp256-cert-v01 at openssh.com,ecdsa-sha2-nistp384-cert-v01 at openssh.com,ecdsa-sha2-nistp521-cert-v01 at openssh.com,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521,ssh-ed25519-cert-v01 at openssh.com,rsa-sha2-512-cert-v01 at openssh.com,rsa-sha2-256-cert-v01 at openssh.com,ssh-rsa-cert-v01 at openssh.com,ssh-ed25519,rsa-sha2-512,rsa-sha2-256,ssh-rsa
debug2: ciphers ctos:
chacha20-poly1305 at openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm at openssh.com,aes256-gcm at openssh.com
debug2: ciphers stoc:
chacha20-poly1305 at openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm at openssh.com,aes256-gcm at openssh.com
debug2: MACs ctos:
umac-64-etm at openssh.com,umac-128-etm at openssh.com,hmac-sha2-256-etm at openssh.com,hmac-sha2-512-etm at openssh.com,hmac-sha1-etm at openssh.com,umac-64 at openssh.com,umac-128 at openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1
debug2: MACs stoc:
umac-64-etm at openssh.com,umac-128-etm at openssh.com,hmac-sha2-256-etm at openssh.com,hmac-sha2-512-etm at openssh.com,hmac-sha1-etm at openssh.com,umac-64 at openssh.com,umac-128 at openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1
debug2: compression ctos: none,zlib at openssh.com,zlib
debug2: compression stoc: none,zlib at 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:
curve25519-sha256,curve25519-sha256 at 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-group-exchange-sha1,diffie-hellman-group14-sha256,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1
debug2: host key algorithms:
ssh-rsa,rsa-sha2-512,rsa-sha2-256,ecdsa-sha2-nistp256,ssh-ed25519
debug2: ciphers ctos:
chacha20-poly1305 at openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm at openssh.com,aes256-gcm at openssh.com,aes128-cbc,aes192-cbc,aes256-cbc,blowfish-cbc,cast128-cbc,3des-cbc
debug2: ciphers stoc:
chacha20-poly1305 at openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm at openssh.com,aes256-gcm at openssh.com,aes128-cbc,aes192-cbc,aes256-cbc,blowfish-cbc,cast128-cbc,3des-cbc
debug2: MACs ctos:
umac-64-etm at openssh.com,umac-128-etm at openssh.com,hmac-sha2-256-etm at openssh.com,hmac-sha2-512-etm at openssh.com,hmac-sha1-etm at openssh.com,umac-64 at openssh.com,umac-128 at openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1
debug2: MACs stoc:
umac-64-etm at openssh.com,umac-128-etm at openssh.com,hmac-sha2-256-etm at openssh.com,hmac-sha2-512-etm at openssh.com,hmac-sha1-etm at openssh.com,umac-64 at openssh.com,umac-128 at openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1
debug2: compression ctos: none,zlib at openssh.com
debug2: compression stoc: none,zlib at openssh.com
debug2: languages ctos:
debug2: languages stoc:
debug2: first_kex_follows 0
debug2: reserved 0
debug1: kex: algorithm: curve25519-sha256
debug1: kex: host key algorithm: ecdsa-sha2-nistp256
debug1: kex: server->client cipher: chacha20-poly1305 at openssh.com MAC:
<implicit> compression: none
debug1: kex: client->server cipher: chacha20-poly1305 at openssh.com MAC:
<implicit> compression: none
debug3: send packet: type 30
debug1: expecting SSH2_MSG_KEX_ECDH_REPLY
debug3: receive packet: type 31
debug1: Server host key: ecdsa-sha2-nistp256
SHA256:v57cBLmh7Ypw6bZIWO/wb9+UqN95LOce2IiQdFmY6o8
debug3: hostkeys_foreach: reading file "/home/username/.ssh/known_hosts"
debug3: record_hostkey: found key type ECDSA in file
/home/username/.ssh/known_hosts:13
debug3: load_hostkeys: loaded 1 keys from server.ip.in.cloud
debug1: Host 'server.ip.in.cloud' is known and matches the ECDSA host key.
debug1: Found key in /home/username/.ssh/known_hosts:13
debug3: send packet: type 21
debug2: set_newkeys: mode 1
debug1: rekey out after 134217728 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 in after 134217728 blocks
debug1: Will attempt key: /home/username/.ssh/id_rsa RSA
SHA256:wrong.key.sig agent
debug1: Will attempt key: (stdin) RSA SHA256:our.key.sig agent
debug1: Will attempt key: /home/username/.ssh/id_dsa
debug1: Will attempt key: /home/username/.ssh/id_ecdsa
debug1: Will attempt key: /home/username/.ssh/id_ed25519
debug1: Will attempt key: /home/username/.ssh/id_xmss
debug2: pubkey_prepare: done
debug3: send packet: type 5
debug3: receive packet: type 7
debug1: SSH2_MSG_EXT_INFO received
debug1: kex_input_ext_info: server-sig-algs=<rsa-sha2-256,rsa-sha2-512>
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
debug3: start over, passed a different list publickey
debug3: preferred 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: Offering public key: /home/username/.ssh/id_rsa RSA
SHA256:wrong.key.sig agent
debug3: send packet: type 50
debug2: we sent a publickey packet, wait for reply
debug3: receive packet: type 51
debug1: Authentications that can continue: publickey
debug1: Offering public key: (stdin) RSA SHA256:our.key.sig agent
debug3: send packet: type 50
debug2: we sent a publickey packet, wait for reply
debug3: receive packet: type 60
debug1: Server accepts key: (stdin) RSA SHA256:our.key.sig agent
debug3: sign_and_send_pubkey: RSA SHA256:our.key.sig
debug3: sign_and_send_pubkey: signing using rsa-sha2-512
debug3: send packet: type 50
debug3: receive packet: type 52
debug1: Authentication succeeded (publickey).
Authenticated to server.ip.in.cloud ([server.ip.in.cloud]:22).
debug1: channel 0: new [client-session]
debug3: ssh_session2_open: channel_new: 0
debug2: channel 0: send open
debug3: send packet: type 90
debug1: Requesting no-more-sessions at openssh.com
debug3: send packet: type 80
debug1: Entering interactive session.
debug1: pledge: network
debug3: receive packet: type 80
debug1: client_input_global_request: rtype hostkeys-00 at openssh.com want_reply 0
debug3: receive packet: type 91
debug2: channel_input_open_confirmation: channel 0: callback start
debug2: fd 3 setting TCP_NODELAY
debug3: ssh_packet_set_tos: set IP_TOS 0x48
debug2: client_session2_setup: id 0
debug2: channel 0: request pty-req confirm 1
debug3: send packet: type 98
debug2: channel 0: request shell confirm 1
debug3: send packet: type 98
debug2: channel_input_open_confirmation: channel 0: callback done
debug2: channel 0: open confirm rwindow 0 rmax 32768
debug3: send packet: type 1
client_loop: Broken pipe
<client terminates>

Server:

Apr  2 22:05:56 ip-an-ip sshd[2773]: Received signal 15; terminating.
Apr  2 22:05:56 ip-an-ip sshd[3006]: debug3: oom_adjust_setup
Apr  2 22:05:56 ip-an-ip sshd[3006]: debug1: Set
/proc/self/oom_score_adj from 0 to -1000
Apr  2 22:05:56 ip-an-ip sshd[3006]: debug2: fd 3 setting O_NONBLOCK
Apr  2 22:05:56 ip-an-ip sshd[3006]: debug1: Bind to port 22 on 0.0.0.0.
Apr  2 22:05:56 ip-an-ip sshd[3006]: Server listening on 0.0.0.0 port 22.
Apr  2 22:05:56 ip-an-ip sshd[3006]: debug2: fd 4 setting O_NONBLOCK
Apr  2 22:05:56 ip-an-ip sshd[3006]: debug3: sock_set_v6only: set
socket 4 IPV6_V6ONLY
Apr  2 22:05:56 ip-an-ip sshd[3006]: debug1: Bind to port 22 on ::.
Apr  2 22:05:56 ip-an-ip sshd[3006]: Server listening on :: port 22.
Apr  2 22:06:11 ip-an-ip sshd[3006]: debug3: fd 5 is not O_NONBLOCK
Apr  2 22:06:11 ip-an-ip sshd[3006]: debug1: Forked child 3009.
Apr  2 22:06:11 ip-an-ip sshd[3006]: debug3: send_rexec_state:
entering fd = 8 config len 743
Apr  2 22:06:11 ip-an-ip sshd[3006]: debug3: ssh_msg_send: type 0
Apr  2 22:06:11 ip-an-ip sshd[3006]: debug3: send_rexec_state: done
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: oom_adjust_restore
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug1: Set /proc/self/oom_score_adj to 0
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug1: rexec start in 5 out 5
newsock 5 pipe 7 sock 8
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug1: inetd sockets after dupping: 3, 3
Apr  2 22:06:11 ip-an-ip sshd[3009]: Connection from source.ip port
62367 on 172.31.15.213 port 22
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug1: Client protocol version
2.0; client software version OpenSSH_7.9
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug1: match: OpenSSH_7.9 pat
OpenSSH* compat 0x04000000
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug1: Local version string
SSH-2.0-OpenSSH_7.4
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug1: Enabling compatibility
mode for protocol 2.0
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug2: fd 3 setting O_NONBLOCK
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: ssh_sandbox_init:
preparing rlimit sandbox
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug2: Network child is on pid 3010
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: preauth child monitor started
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug1: SELinux support disabled [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: privsep user:group 74:74 [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug1: permanently_set_uid:
74/74 [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug1: list_hostkey_types:
ssh-rsa,rsa-sha2-512,rsa-sha2-256,ecdsa-sha2-nistp256,ssh-ed25519
[preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: send packet: type 20 [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug1: SSH2_MSG_KEXINIT sent [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: receive packet: type 20 [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug1: SSH2_MSG_KEXINIT received [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug2: local server KEXINIT
proposal [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug2: KEX algorithms:
curve25519-sha256,curve25519-sha256 at 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-group-exchange-sha1,diffie-hellman-group14-sha256,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1
[preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug2: host key algorithms:
ssh-rsa,rsa-sha2-512,rsa-sha2-256,ecdsa-sha2-nistp256,ssh-ed25519
[preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug2: ciphers ctos:
chacha20-poly1305 at openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm at openssh.com,aes256-gcm at openssh.com,aes128-cbc,aes192-cbc,aes256-cbc,blowfish-cbc,cast128-cbc,3des-cbc
[preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug2: ciphers stoc:
chacha20-poly1305 at openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm at openssh.com,aes256-gcm at openssh.com,aes128-cbc,aes192-cbc,aes256-cbc,blowfish-cbc,cast128-cbc,3des-cbc
[preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug2: MACs ctos:
umac-64-etm at openssh.com,umac-128-etm at openssh.com,hmac-sha2-256-etm at openssh.com,hmac-sha2-512-etm at openssh.com,hmac-sha1-etm at openssh.com,umac-64 at openssh.com,umac-128 at openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1
[preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug2: MACs stoc:
umac-64-etm at openssh.com,umac-128-etm at openssh.com,hmac-sha2-256-etm at openssh.com,hmac-sha2-512-etm at openssh.com,hmac-sha1-etm at openssh.com,umac-64 at openssh.com,umac-128 at openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1
[preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug2: compression ctos:
none,zlib at openssh.com [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug2: compression stoc:
none,zlib at openssh.com [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug2: languages ctos:  [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug2: languages stoc:  [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug2: first_kex_follows 0  [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug2: reserved 0  [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug2: peer client KEXINIT
proposal [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug2: KEX algorithms:
curve25519-sha256,curve25519-sha256 at 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,diffie-hellman-group14-sha1,ext-info-c
[preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug2: host key algorithms:
ecdsa-sha2-nistp256-cert-v01 at openssh.com,ecdsa-sha2-nistp384-cert-v01 at openssh.com,ecdsa-sha2-nistp521-cert-v01 at openssh.com,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521,ssh-ed25519-cert-v01 at openssh.com,rsa-sha2-512-cert-v01 at openssh.com,rsa-sha2-256-cert-v01 at openssh.com,ssh-rsa-cert-v01 at openssh.com,ssh-ed25519,rsa-sha2-512,rsa-sha2-256,ssh-rsa
[preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug2: ciphers ctos:
chacha20-poly1305 at openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm at openssh.com,aes256-gcm at openssh.com
[preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug2: ciphers stoc:
chacha20-poly1305 at openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm at openssh.com,aes256-gcm at openssh.com
[preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug2: MACs ctos:
umac-64-etm at openssh.com,umac-128-etm at openssh.com,hmac-sha2-256-etm at openssh.com,hmac-sha2-512-etm at openssh.com,hmac-sha1-etm at openssh.com,umac-64 at openssh.com,umac-128 at openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1
[preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug2: MACs stoc:
umac-64-etm at openssh.com,umac-128-etm at openssh.com,hmac-sha2-256-etm at openssh.com,hmac-sha2-512-etm at openssh.com,hmac-sha1-etm at openssh.com,umac-64 at openssh.com,umac-128 at openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1
[preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug2: compression ctos:
none,zlib at openssh.com,zlib [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug2: compression stoc:
none,zlib at openssh.com,zlib [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug2: languages ctos:  [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug2: languages stoc:  [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug2: first_kex_follows 0  [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug2: reserved 0  [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug1: kex: algorithm:
curve25519-sha256 [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug1: kex: host key algorithm:
ecdsa-sha2-nistp256 [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug1: kex: client->server
cipher: chacha20-poly1305 at openssh.com MAC: <implicit> compression:
none [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug1: kex: server->client
cipher: chacha20-poly1305 at openssh.com MAC: <implicit> compression:
none [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug1: kex: curve25519-sha256
need=64 dh_need=64 [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: mm_request_send entering:
type 120 [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: mm_request_receive entering
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: monitor_read: checking request 120
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: mm_request_send entering: type 121
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: mm_request_receive_expect
entering: type 121 [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: mm_request_receive
entering [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug1: kex: curve25519-sha256
need=64 dh_need=64 [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: mm_request_send entering:
type 120 [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: mm_request_receive entering
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: monitor_read: checking request 120
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: mm_request_send entering: type 121
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: mm_request_receive_expect
entering: type 121 [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: mm_request_receive
entering [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug1: expecting
SSH2_MSG_KEX_ECDH_INIT [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: receive packet: type 30 [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: mm_key_sign entering [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: mm_request_send entering:
type 6 [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: mm_request_receive entering
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: monitor_read: checking request 6
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: mm_answer_sign
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: mm_answer_sign: hostkey
proof signature 0x55c067c39140(100)
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: mm_request_send entering: type 7
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug2: monitor_read: 6 used
once, disabling now
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: mm_key_sign: waiting for
MONITOR_ANS_SIGN [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: mm_request_receive_expect
entering: type 7 [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: mm_request_receive
entering [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: send packet: type 31 [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: send packet: type 21 [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug2: set_newkeys: mode 1 [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug1: rekey after 134217728
blocks [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug1: SSH2_MSG_NEWKEYS sent [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug1: expecting
SSH2_MSG_NEWKEYS [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: send packet: type 7 [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: receive packet: type 21 [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug1: SSH2_MSG_NEWKEYS received [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug2: set_newkeys: mode 0 [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug1: rekey after 134217728
blocks [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug1: KEX done [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: receive packet: type 5 [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: send packet: type 6 [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: receive packet: type 50 [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug1: userauth-request for user
ec2-user service ssh-connection method none [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug1: attempt 0 failures 0 [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: mm_getpwnamallow entering [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: mm_request_send entering:
type 8 [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: mm_request_receive entering
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: monitor_read: checking request 8
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: mm_answer_pwnamallow
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: Trying to reverse map
address source.ip.
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug2: parse_server_config:
config reprocess config len 743
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: mm_answer_pwnamallow:
sending MONITOR_ANS_PWNAM: 1
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: mm_request_send entering: type 9
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug2: monitor_read: 8 used
once, disabling now
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: mm_getpwnamallow: waiting
for MONITOR_ANS_PWNAM [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: mm_request_receive_expect
entering: type 9 [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: mm_request_receive
entering [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug2: input_userauth_request:
setting up authctxt for ec2-user [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: mm_start_pam entering [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: mm_request_send entering:
type 100 [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: mm_request_receive entering
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: monitor_read: checking request 100
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug1: PAM: initializing for "ec2-user"
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug1: PAM: setting PAM_RHOST to
"host.on.other.side"
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug1: PAM: setting PAM_TTY to "ssh"
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug2: monitor_read: 100 used
once, disabling now
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: mm_inform_authserv
entering [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: mm_request_send entering:
type 4 [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: mm_inform_authrole
entering [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: mm_request_send entering:
type 80 [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug2: input_userauth_request:
try method none [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: userauth_finish: failure
partial=0 next methods="publickey" [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: send packet: type 51 [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: mm_request_receive entering
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: monitor_read: checking request 4
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: mm_answer_authserv:
service=ssh-connection, style=
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug2: monitor_read: 4 used
once, disabling now
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: mm_request_receive entering
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: monitor_read: checking request 80
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: mm_answer_authrole: role=
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug2: monitor_read: 80 used
once, disabling now
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: receive packet: type 50 [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug1: userauth-request for user
ec2-user service ssh-connection method publickey [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug1: attempt 1 failures 0 [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug2: input_userauth_request:
try method publickey [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug1: userauth_pubkey: test
whether pkalg/pkblob are acceptable for RSA SHA256:wrong.key.sig
[preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: mm_key_allowed entering [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: mm_request_send entering:
type 22 [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: mm_key_allowed: waiting
for MONITOR_ANS_KEYALLOWED [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: mm_request_receive_expect
entering: type 23 [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: mm_request_receive
entering [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: mm_request_receive entering
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: monitor_read: checking request 22
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: mm_answer_keyallowed entering
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: mm_answer_keyallowed:
key_from_blob: 0x55c067c466f0
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug1: temporarily_use_uid:
500/500 (e=0/0)
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug1: trying public key file
/home/ec2-user/.ssh/authorized_keys
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug1: fd 4 clearing O_NONBLOCK
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug2: key not found
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug1: restore_uid: 0/0
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: mm_answer_keyallowed: key
0x55c067c466f0 is not allowed
Apr  2 22:06:11 ip-an-ip sshd[3009]: Failed publickey for ec2-user
from source.ip port 62367 ssh2: RSA SHA256:wrong.key.sig
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: mm_request_send entering: type 23
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug2: userauth_pubkey:
authenticated 0 pkalg rsa-sha2-512 [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: userauth_finish: failure
partial=0 next methods="publickey" [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: send packet: type 51 [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: receive packet: type 50 [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug1: userauth-request for user
ec2-user service ssh-connection method publickey [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug1: attempt 2 failures 1 [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug2: input_userauth_request:
try method publickey [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug1: userauth_pubkey: test
whether pkalg/pkblob are acceptable for RSA SHA256:our.key.sig
[preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: mm_key_allowed entering [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: mm_request_send entering:
type 22 [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: mm_key_allowed: waiting
for MONITOR_ANS_KEYALLOWED [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: mm_request_receive_expect
entering: type 23 [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: mm_request_receive
entering [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: mm_request_receive entering
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: monitor_read: checking request 22
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: mm_answer_keyallowed entering
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: mm_answer_keyallowed:
key_from_blob: 0x55c067c39330
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug1: temporarily_use_uid:
500/500 (e=0/0)
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug1: trying public key file
/home/ec2-user/.ssh/authorized_keys
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug1: fd 4 clearing O_NONBLOCK
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug1: matching key found: file
/home/ec2-user/.ssh/authorized_keys, line 1 RSA SHA256:our.key.sig
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug1: restore_uid: 0/0
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: mm_answer_keyallowed: key
0x55c067c39330 is allowed
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: mm_request_send entering: type 23
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: send packet: type 60 [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug2: userauth_pubkey:
authenticated 0 pkalg rsa-sha2-512 [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: Postponed publickey for ec2-user
from source.ip port 62367 ssh2 [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: receive packet: type 50 [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug1: userauth-request for user
ec2-user service ssh-connection method publickey [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug1: attempt 3 failures 1 [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug2: input_userauth_request:
try method publickey [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: userauth_pubkey: have
signature for RSA SHA256:our.key.sig [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: mm_key_allowed entering [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: mm_request_send entering:
type 22 [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: mm_key_allowed: waiting
for MONITOR_ANS_KEYALLOWED [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: mm_request_receive_expect
entering: type 23 [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: mm_request_receive
entering [preauth]
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: mm_request_receive entering
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: monitor_read: checking request 22
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: mm_answer_keyallowed entering
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug3: mm_answer_keyallowed:
key_from_blob: 0x55c067c465f0
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug1: temporarily_use_uid:
500/500 (e=0/0)
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug1: trying public key file
/home/ec2-user/.ssh/authorized_keys
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug1: fd 4 clearing O_NONBLOCK
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug1: matching key found: file
/home/ec2-user/.ssh/authorized_keys, line 1 RSA SHA256:our.key.sig
Apr  2 22:06:11 ip-an-ip sshd[3009]: debug1: restore_uid: 0/0
Apr  2 22:06:11 ip-an-ip sshd[3011]: debug1: PAM: establishing credentials
Apr  2 22:06:11 ip-an-ip sshd[3011]: debug1: permanently_set_uid: 500/500
Apr  2 22:06:11 ip-an-ip sshd[3011]: debug3: monitor_apply_keystate:
packet_set_state
Apr  2 22:06:11 ip-an-ip sshd[3011]: debug2: set_newkeys: mode 0
Apr  2 22:06:11 ip-an-ip sshd[3011]: debug1: rekey after 134217728 blocks
Apr  2 22:06:11 ip-an-ip sshd[3011]: debug2: set_newkeys: mode 1
Apr  2 22:06:11 ip-an-ip sshd[3011]: debug1: rekey after 134217728 blocks
Apr  2 22:06:11 ip-an-ip sshd[3011]: debug1: ssh_packet_set_postauth: called
Apr  2 22:06:11 ip-an-ip sshd[3011]: debug3: ssh_packet_set_state: done
Apr  2 22:06:11 ip-an-ip sshd[3011]: debug3: notify_hostkeys: key 0:
ssh-rsa SHA256:HR2Tce3f0NZNVJmhSiO+NYOH9CkdctNWlNpZx8ddJts
Apr  2 22:06:11 ip-an-ip sshd[3011]: debug3: notify_hostkeys: key 1:
ecdsa-sha2-nistp256 SHA256:v57cBLmh7Ypw6bZIWO/wb9+UqN95LOce2IiQdFmY6o8
Apr  2 22:06:11 ip-an-ip sshd[3011]: debug3: notify_hostkeys: key 2:
ssh-ed25519 SHA256:RfsVz1u9CcJlkgZg3ybqTA//lEb8x+Pi4xIyM2xKDfA
Apr  2 22:06:11 ip-an-ip sshd[3011]: debug3: notify_hostkeys: sent 3 hostkeys
Apr  2 22:06:11 ip-an-ip sshd[3011]: debug3: send packet: type 80
Apr  2 22:06:11 ip-an-ip sshd[3011]: debug1: Entering interactive
session for SSH2.
Apr  2 22:06:11 ip-an-ip sshd[3011]: debug2: fd 4 setting O_NONBLOCK
Apr  2 22:06:11 ip-an-ip sshd[3011]: debug2: fd 6 setting O_NONBLOCK
Apr  2 22:06:11 ip-an-ip sshd[3011]: debug1: server_init_dispatch
Apr  2 22:06:11 ip-an-ip sshd[3011]: debug3: receive packet: type 90
Apr  2 22:06:11 ip-an-ip sshd[3011]: debug1:
server_input_channel_open: ctype session rchan 0 win 1048576 max 16384
Apr  2 22:06:11 ip-an-ip sshd[3011]: debug1: input_session_request
Apr  2 22:06:11 ip-an-ip sshd[3011]: debug1: channel 0: new [server-session]
Apr  2 22:06:11 ip-an-ip sshd[3011]: debug2: session_new: allocate
(allocated 0 max 10)
Apr  2 22:06:11 ip-an-ip sshd[3011]: debug3: session_unused: session id 0 unused
Apr  2 22:06:11 ip-an-ip sshd[3011]: debug1: session_new: session 0
Apr  2 22:06:11 ip-an-ip sshd[3011]: debug1: session_open: channel 0
Apr  2 22:06:11 ip-an-ip sshd[3011]: debug1: session_open: session 0:
link with channel 0
Apr  2 22:06:11 ip-an-ip sshd[3011]: debug1:
server_input_channel_open: confirm session
Apr  2 22:06:11 ip-an-ip sshd[3011]: debug3: send packet: type 91
Apr  2 22:06:11 ip-an-ip sshd[3011]: debug3: receive packet: type 80
Apr  2 22:06:11 ip-an-ip sshd[3011]: debug1:
server_input_global_request: rtype no-more-sessions at openssh.com
want_reply 0
<no more output from server>

More information about the openssh-unix-dev mailing list