Attachment 3582 Details for Bug 3406 – sshd_debug3_log_key_auth_failed.txt

sshd_debug3_log_key_auth_failed.txt

sshd_debug3_log_key_auth_failed.txt (text/plain), 23.12 KB, created by qji on 2022-03-15 21:44:52 AEDT

(hide)

Description:

Filename:

MIME Type:

Creator: qji

Created: 2022-03-15 21:44:52 AEDT

Size: 23.12 KB

patch

obsolete

>Mar 15 10:34:58 myserver sshd[4661]: debug3: fd 5 is not O_NONBLOCK
>Mar 15 10:34:58 myserver sshd[4661]: debug1: Forked child 4669.
>Mar 15 10:34:58 myserver sshd[4661]: debug3: send_rexec_state: entering fd = 8 config len 3345
>Mar 15 10:34:58 myserver sshd[4661]: debug3: ssh_msg_send: type 0
>Mar 15 10:34:58 myserver sshd[4661]: debug3: send_rexec_state: done
>Mar 15 10:34:58 myserver sshd[4669]: debug3: oom_adjust_restore
>Mar 15 10:34:58 myserver sshd[4669]: debug1: Set /proc/self/oom_score_adj to 0
>Mar 15 10:34:58 myserver sshd[4669]: debug1: rexec start in 5 out 5 newsock 5 pipe 7 sock 8
>Mar 15 10:34:58 myserver sshd[4669]: debug1: inetd sockets after dupping: 4, 4
>Mar 15 10:34:58 myserver sshd[4669]: Connection from 10.1.2.25 port 37306 on 10.1.1.172 port 22 rdomain ""
>Mar 15 10:34:58 myserver sshd[4669]: debug1: Local version string SSH-2.0-OpenSSH_8.9p1 Ubuntu-3
>Mar 15 10:34:58 myserver sshd[4669]: debug1: Remote protocol version 2.0, remote software version OpenSSH_8.9p1 Ubuntu-3
>Mar 15 10:34:58 myserver sshd[4669]: debug1: compat_banner: match: OpenSSH_8.9p1 Ubuntu-3 pat OpenSSH* compat 0x04000000
>Mar 15 10:34:58 myserver sshd[4669]: debug2: fd 4 setting O_NONBLOCK
>Mar 15 10:34:58 myserver sshd[4669]: debug3: ssh_sandbox_init: preparing seccomp filter sandbox
>Mar 15 10:34:58 myserver sshd[4669]: debug2: Network child is on pid 4670
>Mar 15 10:34:58 myserver sshd[4669]: debug3: preauth child monitor started
>Mar 15 10:34:58 myserver sshd[4669]: debug3: privsep user:group 106:65534 [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug1: permanently_set_uid: 106/65534 [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: ssh_sandbox_child: setting PR_SET_NO_NEW_PRIVS [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: ssh_sandbox_child: attaching seccomp filter program [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: append_hostkey_type: ssh-rsa key not permitted by HostkeyAlgorithms [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug1: list_hostkey_types: rsa-sha2-512,rsa-sha2-256,ecdsa-sha2-nistp256,ssh-ed25519 [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: mm_request_send: entering, type 42 [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: mm_request_receive_expect: entering, type 43 [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: mm_request_receive: entering [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: mm_request_receive: entering
>Mar 15 10:34:58 myserver sshd[4669]: debug3: monitor_read: checking request 42
>Mar 15 10:34:58 myserver sshd[4669]: debug3: mm_request_send: entering, type 43
>Mar 15 10:34:58 myserver sshd[4669]: debug3: send packet: type 20 [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug1: SSH2_MSG_KEXINIT sent [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: receive packet: type 20 [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug1: SSH2_MSG_KEXINIT received [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug2: local server KEXINIT proposal [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug2: KEX algorithms: gss-group14-sha256-toWM5Slw5Ew8Mqkay+al2g==,gss-group16-sha512-toWM5Slw5Ew8Mqkay+al2g==,gss-nistp256-sha256-toWM5Slw5Ew8Mqkay+al2g==,gss-curve25519-sha256-toWM5Slw5Ew8Mqkay+al2g==,gss-group14-sha1-toWM5Slw5Ew8Mqkay+al2g==,gss-gex-sha1-toWM5Slw5Ew8Mqkay+al2g==,curve25519-sha256,curve25519-sha256@libssh.org,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,sntrup761x25519-sha512@openssh.com,diffie-hellman-group-exchange-sha256,diffie-hellman-group16-sha512,diffie-hel
>Mar 15 10:34:58 myserver sshd[4669]: debug2: host key algorithms: rsa-sha2-512,rsa-sha2-256,ecdsa-sha2-nistp256,ssh-ed25519 [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug2: ciphers ctos: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug2: ciphers stoc: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: 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]
>Mar 15 10:34:58 myserver sshd[4669]: 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]
>Mar 15 10:34:58 myserver sshd[4669]: debug2: compression ctos: none,zlib@openssh.com [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug2: compression stoc: none,zlib@openssh.com [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug2: languages ctos:  [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug2: languages stoc:  [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug2: first_kex_follows 0  [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug2: reserved 0  [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug2: peer client KEXINIT proposal [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug2: KEX algorithms: gss-group14-sha256-toWM5Slw5Ew8Mqkay+al2g==,gss-group16-sha512-toWM5Slw5Ew8Mqkay+al2g==,gss-nistp256-sha256-toWM5Slw5Ew8Mqkay+al2g==,gss-curve25519-sha256-toWM5Slw5Ew8Mqkay+al2g==,gss-group14-sha1-toWM5Slw5Ew8Mqkay+al2g==,gss-gex-sha1-toWM5Slw5Ew8Mqkay+al2g==,gss-group14-sha256-eipGX3TCiQSrx573bT1o1Q==,gss-group16-sha512-eipGX3TCiQSrx573bT1o1Q==,gss-nistp256-sha256-eipGX3TCiQSrx573bT1o1Q==,gss-curve25519-sha256-eipGX3TCiQSrx573bT1o1Q==,gss-group14-sha1-eipGX3TCiQSrx573bT1
>Mar 15 10:34:58 myserver sshd[4669]: debug2: host key algorithms: ssh-ed25519-cert-v01@openssh.com,ecdsa-sha2-nistp256-cert-v01@openssh.com,ecdsa-sha2-nistp384-cert-v01@openssh.com,ecdsa-sha2-nistp521-cert-v01@openssh.com,sk-ssh-ed25519-cert-v01@openssh.com,sk-ecdsa-sha2-nistp256-cert-v01@openssh.com,rsa-sha2-512-cert-v01@openssh.com,rsa-sha2-256-cert-v01@openssh.com,ssh-ed25519,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521,sk-ssh-ed25519@openssh.com,sk-ecdsa-sha2-nistp256@openssh.com,rsa-sha2-512,rsa-sha2-256,null [p
>Mar 15 10:34:58 myserver sshd[4669]: debug2: ciphers ctos: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug2: ciphers stoc: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: 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]
>Mar 15 10:34:58 myserver sshd[4669]: 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]
>Mar 15 10:34:58 myserver sshd[4669]: debug2: compression ctos: none,zlib@openssh.com,zlib [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug2: compression stoc: none,zlib@openssh.com,zlib [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug2: languages ctos:  [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug2: languages stoc:  [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug2: first_kex_follows 0  [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug2: reserved 0  [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug1: kex: algorithm: gss-group14-sha256-toWM5Slw5Ew8Mqkay+al2g== [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug1: kex: host key algorithm: ssh-ed25519 [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug1: kex: client->server cipher: chacha20-poly1305@openssh.com MAC: <implicit> compression: none [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug1: kex: server->client cipher: chacha20-poly1305@openssh.com MAC: <implicit> compression: none [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug2: kexgss_server: Identifying gss-group14-sha256-toWM5Slw5Ew8Mqkay+al2g== [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug2: kexgss_server: Acquiring credentials [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: mm_request_send: entering, type 42 [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: mm_request_receive_expect: entering, type 43 [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: mm_request_receive: entering [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: mm_request_receive: entering
>Mar 15 10:34:58 myserver sshd[4669]: debug3: monitor_read: checking request 42
>Mar 15 10:34:58 myserver sshd[4669]: debug3: mm_request_send: entering, type 43
>Mar 15 10:34:58 myserver sshd[4669]: debug1: Wait SSH2_MSG_KEXGSS_INIT [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: receive packet: type 30 [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug2: bits set: 1006/2048 [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug2: bits set: 989/2048 [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: mm_request_send: entering, type 44 [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: mm_request_receive_expect: entering, type 45 [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: mm_request_receive: entering [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: mm_request_receive: entering
>Mar 15 10:34:58 myserver sshd[4669]: debug3: monitor_read: checking request 44
>Mar 15 10:34:58 myserver sshd[4669]: debug1: Received some client credentials
>Mar 15 10:34:58 myserver sshd[4669]: debug3: mm_request_send: entering, type 45
>Mar 15 10:34:58 myserver sshd[4669]: debug3: mm_request_send: entering, type 150 [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: mm_request_receive_expect: entering, type 151 [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: mm_request_receive: entering [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: mm_request_receive: entering
>Mar 15 10:34:58 myserver sshd[4669]: debug3: monitor_read: checking request 150
>Mar 15 10:34:58 myserver sshd[4669]: debug3: mm_request_send: entering, type 151
>Mar 15 10:34:58 myserver sshd[4669]: debug2: monitor_read: 150 used once, disabling now
>Mar 15 10:34:58 myserver sshd[4669]: debug3: send packet: type 32 [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: send packet: type 21 [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug2: ssh_set_newkeys: mode 1 [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug1: rekey out after 134217728 blocks [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug1: SSH2_MSG_NEWKEYS sent [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug1: Sending SSH2_MSG_EXT_INFO [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: send packet: type 7 [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug1: expecting SSH2_MSG_NEWKEYS [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: receive packet: type 21 [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug1: SSH2_MSG_NEWKEYS received [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug2: ssh_set_newkeys: mode 0 [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug1: rekey in after 134217728 blocks [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug1: KEX done [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: receive packet: type 5 [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: send packet: type 6 [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: receive packet: type 50 [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug1: userauth-request for user localadmin service ssh-connection method none [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug1: attempt 0 failures 0 [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: mm_getpwnamallow: entering [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: mm_request_send: entering, type 8 [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: mm_getpwnamallow: waiting for MONITOR_ANS_PWNAM [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: mm_request_receive_expect: entering, type 9 [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: mm_request_receive: entering [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: mm_request_receive: entering
>Mar 15 10:34:58 myserver sshd[4669]: debug3: monitor_read: checking request 8
>Mar 15 10:34:58 myserver sshd[4669]: debug3: mm_answer_pwnamallow: entering
>Mar 15 10:34:58 myserver sshd[4669]: debug2: parse_server_config_depth: config reprocess config len 3345
>Mar 15 10:34:58 myserver sshd[4669]: debug2: parse_server_config_depth: config  len 0
>Mar 15 10:34:58 myserver sshd[4669]: debug3: mm_answer_pwnamallow: sending MONITOR_ANS_PWNAM: 1
>Mar 15 10:34:58 myserver sshd[4669]: debug3: mm_request_send: entering, type 9
>Mar 15 10:34:58 myserver sshd[4669]: debug2: monitor_read: 8 used once, disabling now
>Mar 15 10:34:58 myserver sshd[4669]: debug2: input_userauth_request: setting up authctxt for localadmin [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: mm_start_pam entering [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: mm_request_send: entering, type 100 [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: mm_inform_authserv: entering [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: mm_request_send: entering, type 4 [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug2: input_userauth_request: try method none [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: mm_request_receive: entering
>Mar 15 10:34:58 myserver sshd[4669]: debug3: monitor_read: checking request 100
>Mar 15 10:34:58 myserver sshd[4669]: debug1: PAM: initializing for "localadmin"
>Mar 15 10:34:58 myserver sshd[4669]: debug1: PAM: setting PAM_RHOST to "10.1.2.25"
>Mar 15 10:34:58 myserver sshd[4669]: debug1: PAM: setting PAM_TTY to "ssh"
>Mar 15 10:34:58 myserver sshd[4669]: debug2: monitor_read: 100 used once, disabling now
>Mar 15 10:34:58 myserver sshd[4669]: debug3: user_specific_delay: user specific delay 0.000ms [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: ensure_minimum_time_since: elapsed 1.287ms, delaying 5.611ms (requested 6.898ms) [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: mm_request_receive: entering
>Mar 15 10:34:58 myserver sshd[4669]: debug3: monitor_read: checking request 4
>Mar 15 10:34:58 myserver sshd[4669]: debug3: mm_answer_authserv: service=ssh-connection, style=, role=
>Mar 15 10:34:58 myserver sshd[4669]: debug2: monitor_read: 4 used once, disabling now
>Mar 15 10:34:58 myserver sshd[4669]: debug3: userauth_finish: failure partial=0 next methods="publickey,gssapi-with-mic,password" [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: send packet: type 51 [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: receive packet: type 50 [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug1: userauth-request for user localadmin service ssh-connection method gssapi-with-mic [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug1: attempt 1 failures 0 [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug2: input_userauth_request: try method gssapi-with-mic [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: mm_request_send: entering, type 42 [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: mm_request_receive_expect: entering, type 43 [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: mm_request_receive: entering [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: mm_request_receive: entering
>Mar 15 10:34:58 myserver sshd[4669]: debug3: monitor_read: checking request 42
>Mar 15 10:34:58 myserver sshd[4669]: debug3: mm_request_send: entering, type 43
>Mar 15 10:34:58 myserver sshd[4669]: debug3: send packet: type 60 [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: user_specific_delay: user specific delay 0.000ms [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: ensure_minimum_time_since: elapsed 1.131ms, delaying 5.767ms (requested 6.898ms) [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: Postponed gssapi-with-mic for localadmin from 10.1.2.25 port 37306 ssh2 [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: receive packet: type 61 [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: mm_request_send: entering, type 44 [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: mm_request_receive_expect: entering, type 45 [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: mm_request_receive: entering [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: mm_request_receive: entering
>Mar 15 10:34:58 myserver sshd[4669]: debug3: monitor_read: checking request 44
>Mar 15 10:34:58 myserver sshd[4669]: debug1: Received some client credentials
>Mar 15 10:34:58 myserver sshd[4669]: debug3: mm_request_send: entering, type 45
>Mar 15 10:34:58 myserver sshd[4669]: debug3: send packet: type 61 [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: receive packet: type 66 [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: mm_request_send: entering, type 48 [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: mm_request_receive_expect: entering, type 49 [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: mm_request_receive: entering [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: mm_request_receive: entering
>Mar 15 10:34:58 myserver sshd[4669]: debug3: monitor_read: checking request 48
>Mar 15 10:34:58 myserver sshd[4669]: debug3: mm_request_send: entering, type 49
>Mar 15 10:34:58 myserver sshd[4669]: debug2: monitor_read: 48 used once, disabling now
>Mar 15 10:34:58 myserver sshd[4669]: debug3: mm_request_send: entering, type 46 [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: mm_request_receive_expect: entering, type 47 [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: mm_request_receive: entering [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: mm_request_receive: entering
>Mar 15 10:34:58 myserver sshd[4669]: debug3: monitor_read: checking request 46
>Mar 15 10:34:58 myserver sshd[4669]: debug3: mm_answer_gss_userok: sending result 0
>Mar 15 10:34:58 myserver sshd[4669]: debug3: mm_request_send: entering, type 47
>Mar 15 10:34:58 myserver sshd[4669]: debug2: monitor_read: 46 used once, disabling now
>Mar 15 10:34:58 myserver sshd[4669]: Failed gssapi-with-mic for localadmin from 10.1.2.25 port 37306 ssh2
>Mar 15 10:34:58 myserver sshd[4669]: debug3: mm_ssh_gssapi_userok: user not authenticated [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: userauth_finish: failure partial=0 next methods="publickey,gssapi-with-mic,password" [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: send packet: type 51 [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: receive packet: type 50 [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug1: userauth-request for user localadmin service ssh-connection method gssapi-with-mic [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug1: attempt 2 failures 1 [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug2: input_userauth_request: try method gssapi-with-mic [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: user_specific_delay: user specific delay 0.000ms [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: ensure_minimum_time_since: elapsed 0.122ms, delaying 6.775ms (requested 6.898ms) [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: userauth_finish: failure partial=0 next methods="publickey,gssapi-with-mic,password" [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: send packet: type 51 [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: receive packet: type 50 [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug1: userauth-request for user localadmin service ssh-connection method publickey [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug1: attempt 3 failures 1 [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug2: input_userauth_request: try method publickey [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug2: userauth_pubkey: valid user localadmin querying public key rsa-sha2-512 AAAAB3NzaC1yc2EAAAADAQABAAABgQDAkY9VqR/woS5GEsj9Fnc1YknP9OfDWiBDaselR4HoXcmlw0ruF57bDiOS6gcumg6LpRPKFPrB3MLHmSifTE5yPqgQL+zywLDyoM1xs/V4/eRrPs5PKnNyzaKs8e2V8wxv6ikoXAjcTjl2/8EKbEwON+LZ6lnkPVgwKmXvI9xvCh3IxA55hVdZxeic/8J/DWQXdVnOyOZGQ1kCmHPKhc1PLMLBhAqB8uCxMMr03MzOqSjXV/AHiWXI+1pNrtKFXMPLpF55k7eyJ+yQpmXvZnGZhvwPn8omXi78eKXb7perSXDOn4DmaMCzLE2rPU6kpFqL8zDmtn2Np4ASB0PeMoPnIsWuuTmCSu8Y9Y+tqMReOVm3t+Gq6sh+h9U0wpUpHpl2UELR
>Mar 15 10:34:58 myserver sshd[4669]: debug1: userauth_pubkey: publickey test pkalg rsa-sha2-512 pkblob RSA SHA256:h7gKt52JatIQiyV4z+fiSABkg4Rp9jjgUPFK1bK02Y0 [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: mm_key_allowed: entering [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: mm_request_send: entering, type 22 [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: mm_key_allowed: waiting for MONITOR_ANS_KEYALLOWED [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: mm_request_receive_expect: entering, type 23 [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: mm_request_receive: entering [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: mm_request_receive: entering
>Mar 15 10:34:58 myserver sshd[4669]: debug3: monitor_read: checking request 22
>Mar 15 10:34:58 myserver sshd[4669]: debug3: mm_answer_keyallowed: entering
>Mar 15 10:34:58 myserver sshd[4669]: debug1: temporarily_use_uid: 1000/1000 (e=0/0)
>Mar 15 10:34:58 myserver sshd[4669]: debug1: trying public key file /home/localadmin/.ssh/authorized_keys
>Mar 15 10:34:58 myserver sshd[4669]: debug1: fd 10 clearing O_NONBLOCK
>Mar 15 10:34:58 myserver sshd[4669]: debug1: /home/localadmin/.ssh/authorized_keys:1: matching key found: RSA SHA256:h7gKt52JatIQiyV4z+fiSABkg4Rp9jjgUPFK1bK02Y0
>Mar 15 10:34:58 myserver sshd[4669]: debug1: /home/localadmin/.ssh/authorized_keys:1: key options: agent-forwarding port-forwarding pty user-rc x11-forwarding
>Mar 15 10:34:58 myserver sshd[4669]: Accepted key RSA SHA256:h7gKt52JatIQiyV4z+fiSABkg4Rp9jjgUPFK1bK02Y0 found at /home/localadmin/.ssh/authorized_keys:1
>Mar 15 10:34:58 myserver sshd[4669]: debug2: check_authkeys_file: /home/localadmin/.ssh/authorized_keys: processed 1/1 lines
>Mar 15 10:34:58 myserver sshd[4669]: debug1: restore_uid: 0/0
>Mar 15 10:34:58 myserver sshd[4669]: debug3: mm_answer_keyallowed: publickey authentication test: RSA key is allowed
>Mar 15 10:34:58 myserver sshd[4669]: debug3: mm_request_send: entering, type 23
>Mar 15 10:34:58 myserver sshd[4669]: debug3: send packet: type 60 [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug2: userauth_pubkey: authenticated 0 pkalg rsa-sha2-512 [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: user_specific_delay: user specific delay 0.000ms [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: ensure_minimum_time_since: elapsed 6.138ms, delaying 0.760ms (requested 6.898ms) [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: Postponed publickey for localadmin from 10.1.2.25 port 37306 ssh2 [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: Connection closed by authenticating user localadmin 10.1.2.25 port 37306 [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug1: do_cleanup [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug3: PAM: sshpam_thread_cleanup entering [preauth]
>Mar 15 10:34:58 myserver sshd[4669]: debug1: monitor_read_log: child log fd closed
>Mar 15 10:34:58 myserver sshd[4669]: debug3: mm_request_receive: entering
>Mar 15 10:34:58 myserver sshd[4669]: debug1: do_cleanup
>Mar 15 10:34:58 myserver sshd[4669]: debug1: PAM: cleanup
>Mar 15 10:34:58 myserver sshd[4669]: debug3: PAM: sshpam_thread_cleanup entering
>Mar 15 10:34:58 myserver sshd[4669]: debug1: Killing privsep child 4670
>Mar 15 10:34:58 myserver sshd[4669]: debug1: audit_event: unhandled event 12
>

Actions: View

Attachments on bug 3406: 3582 | 3583