calderonth commented on issue #650:
URL: https://github.com/apache/mina-sshd/issues/650#issuecomment-2749086056
Here the full debug log.
Could it be that it's because it's using the `CachingPublicKeyAuthenticator`?
We clearly see in the logs that at least the auth seems to succeed once but
then it explodes after that.
```
==> /var/tmp/gerrit-site/logs/error_log <==
[2025-03-24T14:36:28.694-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-6] DEBUG
org.apache.sshd.common.io.nio2.Nio2Acceptor : setOption(SO_REUSEADDR)[true]
from property=Property[socket-reuseaddr](Boolean]
[2025-03-24T14:36:28.695-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-6] DEBUG
org.apache.sshd.common.io.nio2.Nio2Session : Creating IoSession on
/192.168.0.1:29418 from /192.168.0.1:35308 via /0.0.0.0:29418
[2025-03-24T14:36:28.695-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-6] DEBUG
org.apache.sshd.common.session.helpers.SessionTimeoutListener :
sessionCreated(ServerSessionImpl[null@/192.168.0.1:35308]) tracking
[2025-03-24T14:36:28.695-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-6] DEBUG
org.apache.sshd.server.session.ServerSessionImpl :
sendIdentification(ServerSessionImpl[null@/192.168.0.1:35308]):
SSH-2.0-GerritCodeReview_3.11.1-45-g13f11a459a-dirty
(APACHE-SSHD-2.15.1-SNAPSHOT)
[2025-03-24T14:36:28.695-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-6] DEBUG
org.apache.sshd.common.io.nio2.Nio2Session :
writeBuffer(Nio2Session[local=/192.168.0.1:29418, remote=/192.168.0.1:35308])
writing 84 bytes
[2025-03-24T14:36:28.698-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-7] DEBUG
org.apache.sshd.server.session.ServerSessionImpl :
doReadIdentification(ServerSessionImpl[null@/192.168.0.1:35308])
line='SSH-2.0-OpenSSH_8.4p1 Debian-5+deb11u3'
[2025-03-24T14:36:28.711-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-7] DEBUG
org.apache.sshd.server.session.ServerSessionImpl :
readIdentification(ServerSessionImpl[null@/192.168.0.1:35308]) client version
string: SSH-2.0-OpenSSH_8.4p1 Debian-5+deb11u3
[2025-03-24T14:36:28.712-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-7] DEBUG
org.apache.sshd.server.session.ServerSessionImpl :
sendKexInit(ServerSessionImpl[null@/192.168.0.1:35308]) Send SSH_MSG_KEXINIT
[2025-03-24T14:36:28.712-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-7] DEBUG
org.apache.sshd.server.session.ServerSessionImpl :
encode(ServerSessionImpl[null@/192.168.0.1:35308]) packet #0 sending
command=20[SSH_MSG_KEXINIT] len=1049
[2025-03-24T14:36:28.712-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-7] DEBUG
org.apache.sshd.common.io.nio2.Nio2Session :
writeBuffer(Nio2Session[local=/192.168.0.1:29418, remote=/192.168.0.1:35308])
writing 1064 bytes
[2025-03-24T14:36:28.712-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-7] DEBUG
org.apache.sshd.server.session.ServerSessionImpl :
doHandleMessage(ServerSessionImpl[null@/192.168.0.1:35308]) process #0
SSH_MSG_KEXINIT
[2025-03-24T14:36:28.712-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-7] DEBUG
org.apache.sshd.server.session.ServerSessionImpl :
handleKexInit(ServerSessionImpl[null@/192.168.0.1:35308]) SSH_MSG_KEXINIT
[2025-03-24T14:36:28.713-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-7] DEBUG
org.apache.sshd.server.session.ServerSessionImpl :
negotiate(ServerSessionImpl[null@/192.168.0.1:35308]) strict KEX=true
client=true server=true
[2025-03-24T14:36:28.713-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-7] DEBUG
org.apache.sshd.server.session.ServerSessionImpl :
negotiate(ServerSessionImpl[null@/192.168.0.1:35308]) ignore missing value for
KEX option=C2SLANG
[2025-03-24T14:36:28.713-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-7] DEBUG
org.apache.sshd.server.session.ServerSessionImpl :
negotiate(ServerSessionImpl[null@/192.168.0.1:35308]) ignore missing value for
KEX option=S2CLANG
[2025-03-24T14:36:28.713-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-7] DEBUG
org.apache.sshd.server.session.ServerSessionImpl :
setNegotiationResult(ServerSessionImpl[null@/192.168.0.1:35308]) Kex: kex
algorithms = curve25519-sha256
[2025-03-24T14:36:28.713-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-7] DEBUG
org.apache.sshd.server.session.ServerSessionImpl :
setNegotiationResult(ServerSessionImpl[null@/192.168.0.1:35308]) Kex: server
host key algorithms = ecdsa-sha2-nistp256
[2025-03-24T14:36:28.713-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-7] DEBUG
org.apache.sshd.server.session.ServerSessionImpl :
setNegotiationResult(ServerSessionImpl[null@/192.168.0.1:35308]) Kex:
encryption algorithms (client to server) = chacha20-poly1...@openssh.com
[2025-03-24T14:36:28.713-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-7] DEBUG
org.apache.sshd.server.session.ServerSessionImpl :
setNegotiationResult(ServerSessionImpl[null@/192.168.0.1:35308]) Kex:
encryption algorithms (server to client) = chacha20-poly1...@openssh.com
[2025-03-24T14:36:28.713-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-7] DEBUG
org.apache.sshd.server.session.ServerSessionImpl :
setNegotiationResult(ServerSessionImpl[null@/192.168.0.1:35308]) Kex: mac
algorithms (client to server) = aead
[2025-03-24T14:36:28.713-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-7] DEBUG
org.apache.sshd.server.session.ServerSessionImpl :
setNegotiationResult(ServerSessionImpl[null@/192.168.0.1:35308]) Kex: mac
algorithms (server to client) = aead
[2025-03-24T14:36:28.713-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-7] DEBUG
org.apache.sshd.server.session.ServerSessionImpl :
setNegotiationResult(ServerSessionImpl[null@/192.168.0.1:35308]) Kex:
compression algorithms (client to server) = none
[2025-03-24T14:36:28.713-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-7] DEBUG
org.apache.sshd.server.session.ServerSessionImpl :
setNegotiationResult(ServerSessionImpl[null@/192.168.0.1:35308]) Kex:
compression algorithms (server to client) = none
[2025-03-24T14:36:28.714-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-8] DEBUG
org.apache.sshd.server.session.ServerSessionImpl :
doHandleMessage(ServerSessionImpl[null@/192.168.0.1:35308]) process #1 30
[2025-03-24T14:36:28.714-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-8] DEBUG
org.apache.sshd.server.kex.DHGServer :
next(DHGServer[curve25519-sha256])[ServerSessionImpl[null@/192.168.0.1:35308]]
process command=SSH_MSG_KEXDH_INIT
[2025-03-24T14:36:28.716-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-8] DEBUG
org.apache.sshd.server.kex.DHGServer :
next(DHGServer[curve25519-sha256])[ServerSessionImpl[null@/192.168.0.1:35308]]
Send SSH_MSG_KEXDH_REPLY
[2025-03-24T14:36:28.716-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-8] DEBUG
org.apache.sshd.server.session.ServerSessionImpl :
encode(ServerSessionImpl[null@/192.168.0.1:35308]) packet #1 sending
command=31[31] len=249
[2025-03-24T14:36:28.716-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-8] DEBUG
org.apache.sshd.common.io.nio2.Nio2Session :
writeBuffer(Nio2Session[local=/192.168.0.1:29418, remote=/192.168.0.1:35308])
writing 264 bytes
[2025-03-24T14:36:28.716-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-8] DEBUG
org.apache.sshd.server.session.ServerSessionImpl :
handleKexMessage(ServerSessionImpl[null@/192.168.0.1:35308])[curve25519-sha256]
KEX processing complete after cmd=30
[2025-03-24T14:36:28.716-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-8] DEBUG
org.apache.sshd.server.session.ServerSessionImpl :
sendNewKeys(ServerSessionImpl[null@/192.168.0.1:35308]) Send SSH_MSG_NEWKEYS
[2025-03-24T14:36:28.716-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-8] DEBUG
org.apache.sshd.server.session.ServerSessionImpl :
prepareNewKeys(ServerSessionImpl[null@/192.168.0.1:35308]) session
ID=a0:70:39:8f:39:1f:38:54:3c:fd:1f:4d:b2:e5:f4:29:09:90:67:a9:3b:1c:30:2c:3b:b0:16:12:d5:eb:b4:12
[2025-03-24T14:36:28.716-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-8] DEBUG
org.apache.sshd.server.session.ServerSessionImpl :
encode(ServerSessionImpl[null@/192.168.0.1:35308]) packet #2 sending
command=21[SSH_MSG_NEWKEYS] len=1
[2025-03-24T14:36:28.716-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-8] DEBUG
org.apache.sshd.common.io.nio2.Nio2Session :
writeBuffer(Nio2Session[local=/192.168.0.1:29418, remote=/192.168.0.1:35308])
writing 16 bytes
[2025-03-24T14:36:28.717-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-8] DEBUG
org.apache.sshd.server.session.ServerSessionImpl :
setOutputEncoding(ServerSessionImpl[null@/192.168.0.1:35308]): strict KEX
resets output message sequence number from 3 to 0
[2025-03-24T14:36:28.717-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-8] DEBUG
org.apache.sshd.server.session.ServerSessionImpl :
setOutputEncoding(ServerSessionImpl[null@/192.168.0.1:35308]): cipher
chacha20-poly1305; mac null; compression none[Deflater/-1]; blocks limit
134217728
[2025-03-24T14:36:28.717-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-8] DEBUG
org.apache.sshd.common.kex.extension.DefaultServerKexExtensionHandler :
collectExtensions(ServerSessionImpl[null@/192.168.0.1:35308])[NEWKEYS]:
extension info server-sig-algs:
ecdsa-sha2-nistp256-cert-...@openssh.com,ecdsa-sha2-nistp384-cert-...@openssh.com,ecdsa-sha2-nistp521-cert-...@openssh.com,ssh-ed25519-cert-...@openssh.com,rsa-sha2-512-cert-...@openssh.com,rsa-sha2-256-cert-...@openssh.com,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521,ssh-ed25519,sk-ecdsa-sha2-nistp...@openssh.com,sk-ssh-ed25...@openssh.com,rsa-sha2-512,rsa-sha2-256,ssh-rsa
[2025-03-24T14:36:28.717-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-8] DEBUG
org.apache.sshd.common.kex.extension.DefaultServerKexExtensionHandler :
sendKexExtensions(ServerSessionImpl[null@/192.168.0.1:35308])[NEWKEYS]: sending
SSH_MSG_EXT_INFO with 1 info records
[2025-03-24T14:36:28.717-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-8] DEBUG
org.apache.sshd.server.session.ServerSessionImpl :
encode(ServerSessionImpl[null@/192.168.0.1:35308]) packet #0 sending
command=7[7] len=419
[2025-03-24T14:36:28.717-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-8] DEBUG
org.apache.sshd.common.io.nio2.Nio2Session :
writeBuffer(Nio2Session[local=/192.168.0.1:29418, remote=/192.168.0.1:35308])
writing 452 bytes
[2025-03-24T14:36:28.717-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-8] DEBUG
org.apache.sshd.server.session.ServerSessionImpl :
handleNewKeys(ServerSessionImpl[null@/192.168.0.1:35308]) No pending packets to
flush at end of KEX
[2025-03-24T14:36:28.721-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-9] DEBUG
org.apache.sshd.server.session.ServerSessionImpl :
doHandleMessage(ServerSessionImpl[null@/192.168.0.1:35308]) process #2
SSH_MSG_NEWKEYS
[2025-03-24T14:36:28.722-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-9] DEBUG
org.apache.sshd.server.session.ServerSessionImpl :
handleNewKeys(ServerSessionImpl[null@/192.168.0.1:35308]) SSH_MSG_NEWKEYS
command=SSH_MSG_NEWKEYS
[2025-03-24T14:36:28.722-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-9] DEBUG
org.apache.sshd.server.session.ServerSessionImpl :
setInputEncoding(ServerSessionImpl[null@/192.168.0.1:35308]): strict KEX resets
input message sequence number from 3 to 0
[2025-03-24T14:36:28.722-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-9] DEBUG
org.apache.sshd.server.session.ServerSessionImpl :
setInputEncoding(ServerSessionImpl[null@/192.168.0.1:35308]): cipher
chacha20-poly1305; mac null; compression none[Inflater/-1]; blocks limit
134217728
[2025-03-24T14:36:28.884-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-10] DEBUG
org.apache.sshd.server.session.ServerSessionImpl :
doHandleMessage(ServerSessionImpl[null@/192.168.0.1:35308]) process #0
SSH_MSG_SERVICE_REQUEST
[2025-03-24T14:36:28.884-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-10] DEBUG
org.apache.sshd.server.session.ServerSessionImpl :
handleServiceRequest(ServerSessionImpl[null@/192.168.0.1:35308])
SSH_MSG_SERVICE_REQUEST 'ssh-userauth'
[2025-03-24T14:36:28.885-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-10] DEBUG
org.apache.sshd.server.session.ServerUserAuthService :
ServerUserAuthService(ServerSessionImpl[null@/192.168.0.1:35308]) authorized
authentication methods: publickey
[2025-03-24T14:36:28.885-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-10] DEBUG
org.apache.sshd.server.session.ServerSessionImpl :
handleServiceRequest(ServerSessionImpl[null@/192.168.0.1:35308]) Accepted
service ssh-userauth
[2025-03-24T14:36:28.885-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-10] DEBUG
org.apache.sshd.server.session.ServerSessionImpl :
encode(ServerSessionImpl[null@/192.168.0.1:35308]) packet #1 sending
command=6[SSH_MSG_SERVICE_ACCEPT] len=17
[2025-03-24T14:36:28.885-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-10] DEBUG
org.apache.sshd.common.io.nio2.Nio2Session :
writeBuffer(Nio2Session[local=/192.168.0.1:29418, remote=/192.168.0.1:35308])
writing 52 bytes
[2025-03-24T14:36:28.886-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-10] DEBUG
org.apache.sshd.server.session.ServerSessionImpl :
doHandleMessage(ServerSessionImpl[null@/192.168.0.1:35308]) process #1
SSH_MSG_USERAUTH_REQUEST
[2025-03-24T14:36:28.886-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-10] DEBUG
org.apache.sshd.server.session.ServerUserAuthService :
handleUserAuthRequestMessage(ServerSessionImpl[null@/192.168.0.1:35308])
Received SSH_MSG_USERAUTH_REQUEST user=tcalderon, service=ssh-connection,
method=none
[2025-03-24T14:36:28.886-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-10] DEBUG
org.apache.sshd.server.session.ServerUserAuthService :
handleUserAuthRequestMessage(ServerSessionImpl[null@/192.168.0.1:35308])
Authenticating user 'tcalderon' with service 'ssh-connection' and method 'none'
(attempt 0 / 6)
[2025-03-24T14:36:28.886-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-10] DEBUG
org.apache.sshd.server.session.ServerUserAuthService :
handleUserAuthRequestMessage(ServerSessionImpl[null@/192.168.0.1:35308]) no
authentication factory for method=none
[2025-03-24T14:36:28.886-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-10] DEBUG
org.apache.sshd.server.session.ServerUserAuthService :
handleAuthenticationFailure(null@ServerSessionImpl[null@/192.168.0.1:35308])
SSH_MSG_USERAUTH_REQUEST
[2025-03-24T14:36:28.886-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-10] DEBUG
org.apache.sshd.server.session.ServerUserAuthService :
handleAuthenticationFailure(null@ServerSessionImpl[null@/192.168.0.1:35308])
remaining methods: publickey
[2025-03-24T14:36:28.886-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-10] DEBUG
org.apache.sshd.server.session.ServerSessionImpl :
encode(ServerSessionImpl[null@/192.168.0.1:35308]) packet #2 sending
command=51[SSH_MSG_USERAUTH_FAILURE] len=15
[2025-03-24T14:36:28.886-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-10] DEBUG
org.apache.sshd.common.io.nio2.Nio2Session :
writeBuffer(Nio2Session[local=/192.168.0.1:29418, remote=/192.168.0.1:35308])
writing 44 bytes
[2025-03-24T14:36:28.887-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-11] DEBUG
org.apache.sshd.server.session.ServerSessionImpl :
doHandleMessage(ServerSessionImpl[null@/192.168.0.1:35308]) process #2
SSH_MSG_USERAUTH_REQUEST
[2025-03-24T14:36:28.887-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-11] DEBUG
org.apache.sshd.server.session.ServerUserAuthService :
handleUserAuthRequestMessage(ServerSessionImpl[null@/192.168.0.1:35308])
Received SSH_MSG_USERAUTH_REQUEST user=tcalderon, service=ssh-connection,
method=publickey
[2025-03-24T14:36:28.887-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-11] DEBUG
org.apache.sshd.server.session.ServerUserAuthService :
handleUserAuthRequestMessage(ServerSessionImpl[null@/192.168.0.1:35308])
Authenticating user 'tcalderon' with service 'ssh-connection' and method
'publickey' (attempt 1 / 6)
[2025-03-24T14:36:28.889-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-11] DEBUG
org.apache.sshd.server.auth.pubkey.UserAuthPublicKey :
doAuth(tcalderon@ServerSessionImpl[null@/192.168.0.1:35308]) verify key
type=ecdsa-sha2-nistp256-cert-...@openssh.com,
factories=ecdsa-sha2-nistp256-cert-...@openssh.com,ecdsa-sha2-nistp384-cert-...@openssh.com,ecdsa-sha2-nistp521-cert-...@openssh.com,ssh-ed25519-cert-...@openssh.com,rsa-sha2-512-cert-...@openssh.com,rsa-sha2-256-cert-...@openssh.com,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521,ssh-ed25519,sk-ecdsa-sha2-nistp...@openssh.com,sk-ssh-ed25...@openssh.com,rsa-sha2-512,rsa-sha2-256,ssh-rsa,
fingerprint=SHA256:2fqpKRZHyXP0F6yCRGpSEJhqfmJSPmxYoy5XGs/czTw
[2025-03-24T14:36:28.889-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-11] ERROR
com.google.gerrit.sshd.DatabasePubKeyAuth : Will check enableSSHUserCerts config
[2025-03-24T14:36:28.889-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-11] ERROR
com.google.gerrit.sshd.DatabasePubKeyAuth : Starting checkSSHUserCerts
[2025-03-24T14:36:28.890-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-11] DEBUG
org.apache.sshd.server.auth.pubkey.AuthorizedKeyEntriesPublickeyAuthenticator :
authenticate(tcalderon)[ServerSessionImpl[null@/192.168.0.1:35308]] match found
[2025-03-24T14:36:28.890-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-11] ERROR
com.google.gerrit.sshd.DatabasePubKeyAuth : SSH user cert auth successfull
[2025-03-24T14:36:28.894-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-11] ERROR
com.google.gerrit.sshd.DatabasePubKeyAuth : Returning a success
[2025-03-24T14:36:28.895-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-11] DEBUG
org.apache.sshd.server.auth.pubkey.UserAuthPublicKey :
doAuth(tcalderon@ServerSessionImpl[null@/192.168.0.1:35308]) key
type=ecdsa-sha2-nistp256-cert-...@openssh.com,
fingerprint=SHA256:2fqpKRZHyXP0F6yCRGpSEJhqfmJSPmxYoy5XGs/czTw - authentication
result: true
[2025-03-24T14:36:28.895-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-11] DEBUG
org.apache.sshd.server.auth.pubkey.UserAuthPublicKey :
doAuth(tcalderon@ServerSessionImpl[null@/192.168.0.1:35308]) send
SSH_MSG_USERAUTH_PK_OK for key type=ecdsa-sha2-nistp256-cert-...@openssh.com,
fingerprint=SHA256:2fqpKRZHyXP0F6yCRGpSEJhqfmJSPmxYoy5XGs/czTw
[2025-03-24T14:36:28.895-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-11] DEBUG
org.apache.sshd.server.session.ServerSessionImpl :
encode(ServerSessionImpl[null@/192.168.0.1:35308]) packet #3 sending
command=60[60] len=673
==> /var/tmp/gerrit-site/logs/sshd_log <==
[2025-03-24T14:36:28.894-04:00] a70b867f
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-11] tcalderon a/1000001 LOGIN
FROM 192.168.0.1
==> /var/tmp/gerrit-site/logs/error_log <==
[2025-03-24T14:36:28.895-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-11] DEBUG
org.apache.sshd.common.io.nio2.Nio2Session :
writeBuffer(Nio2Session[local=/192.168.0.1:29418, remote=/192.168.0.1:35308])
writing 708 bytes
[2025-03-24T14:36:28.895-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-11] DEBUG
org.apache.sshd.server.session.ServerUserAuthService :
handleAuthenticationInProgress(tcalderon@ServerSessionImpl[null@/192.168.0.1:35308])
SSH_MSG_USERAUTH_REQUEST
[2025-03-24T14:36:28.979-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-12] DEBUG
org.apache.sshd.server.session.ServerSessionImpl :
doHandleMessage(ServerSessionImpl[null@/192.168.0.1:35308]) process #3
SSH_MSG_USERAUTH_REQUEST
[2025-03-24T14:36:28.979-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-12] DEBUG
org.apache.sshd.server.session.ServerUserAuthService :
handleUserAuthRequestMessage(ServerSessionImpl[null@/192.168.0.1:35308])
Received SSH_MSG_USERAUTH_REQUEST user=tcalderon, service=ssh-connection,
method=publickey
[2025-03-24T14:36:28.979-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-12] DEBUG
org.apache.sshd.server.session.ServerUserAuthService :
handleUserAuthRequestMessage(ServerSessionImpl[null@/192.168.0.1:35308])
Authenticating user 'tcalderon' with service 'ssh-connection' and method
'publickey' (attempt 2 / 6)
[2025-03-24T14:36:28.981-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-12] DEBUG
org.apache.sshd.server.auth.pubkey.UserAuthPublicKey :
doAuth(tcalderon@ServerSessionImpl[null@/192.168.0.1:35308]) verify key
type=ecdsa-sha2-nistp256-cert-...@openssh.com,
factories=ecdsa-sha2-nistp256-cert-...@openssh.com,ecdsa-sha2-nistp384-cert-...@openssh.com,ecdsa-sha2-nistp521-cert-...@openssh.com,ssh-ed25519-cert-...@openssh.com,rsa-sha2-512-cert-...@openssh.com,rsa-sha2-256-cert-...@openssh.com,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521,ssh-ed25519,sk-ecdsa-sha2-nistp...@openssh.com,sk-ssh-ed25...@openssh.com,rsa-sha2-512,rsa-sha2-256,ssh-rsa,
fingerprint=SHA256:2fqpKRZHyXP0F6yCRGpSEJhqfmJSPmxYoy5XGs/czTw
[2025-03-24T14:36:28.981-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-12] WARN
org.apache.sshd.server.session.ServerUserAuthService :
handleUserAuthRequestMessage(ServerSessionImpl[null@/192.168.0.1:35308]) Failed
(IllegalStateException) to authenticate using factory method=publickey: null
java.lang.IllegalStateException
at
com.google.common.base.Preconditions.checkState(Preconditions.java:496)
at
com.google.gerrit.sshd.DatabasePubKeyAuth.authenticate(DatabasePubKeyAuth.java:147)
at
org.apache.sshd.server.auth.pubkey.CachingPublicKeyAuthenticator.authenticate(CachingPublicKeyAuthenticator.java:59)
at
org.apache.sshd.server.auth.pubkey.UserAuthPublicKey.doAuth(UserAuthPublicKey.java:148)
at
org.apache.sshd.server.auth.AbstractUserAuth.auth(AbstractUserAuth.java:70)
at
org.apache.sshd.server.session.ServerUserAuthService.handleUserAuthRequestMessage(ServerUserAuthService.java:331)
at
org.apache.sshd.server.session.ServerUserAuthService.process(ServerUserAuthService.java:163)
at
org.apache.sshd.common.session.helpers.CurrentService.process(CurrentService.java:109)
at
org.apache.sshd.common.session.helpers.AbstractSession.doHandleMessage(AbstractSession.java:634)
at
org.apache.sshd.common.session.helpers.AbstractSession.lambda$handleMessage$0(AbstractSession.java:555)
at
org.apache.sshd.common.util.threads.ThreadUtils.runAsInternal(ThreadUtils.java:68)
at
org.apache.sshd.common.session.helpers.AbstractSession.handleMessage(AbstractSession.java:554)
at
org.apache.sshd.common.session.helpers.AbstractSession.decode(AbstractSession.java:1738)
at
org.apache.sshd.common.session.helpers.AbstractSession.messageReceived(AbstractSession.java:515)
at
org.apache.sshd.common.session.helpers.AbstractSessionIoHandler.messageReceived(AbstractSessionIoHandler.java:76)
at
org.apache.sshd.common.io.nio2.Nio2Session.handleReadCycleCompletion(Nio2Session.java:409)
at
org.apache.sshd.common.io.nio2.Nio2Session$1.onCompleted(Nio2Session.java:382)
at
org.apache.sshd.common.io.nio2.Nio2Session$1.onCompleted(Nio2Session.java:377)
at
org.apache.sshd.common.io.nio2.Nio2CompletionHandler.lambda$completed$0(Nio2CompletionHandler.java:38)
at
java.base/java.security.AccessController.doPrivileged(AccessController.java:319)
at
org.apache.sshd.common.io.nio2.Nio2CompletionHandler.completed(Nio2CompletionHandler.java:37)
at java.base/sun.nio.ch.Invoker.invokeUnchecked(Invoker.java:125)
at java.base/sun.nio.ch.Invoker$1.run(Invoker.java:217)
at
java.base/sun.nio.ch.AsynchronousChannelGroupImpl$1.run(AsynchronousChannelGroupImpl.java:113)
at
java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144)
at
java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
at java.base/java.lang.Thread.run(Thread.java:1570)
[2025-03-24T14:36:28.981-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-12] DEBUG
org.apache.sshd.server.session.ServerUserAuthService :
handleAuthenticationFailure(tcalderon@ServerSessionImpl[null@/192.168.0.1:35308])
SSH_MSG_USERAUTH_REQUEST
[2025-03-24T14:36:28.981-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-12] DEBUG
org.apache.sshd.server.session.ServerUserAuthService :
handleAuthenticationFailure(tcalderon@ServerSessionImpl[null@/192.168.0.1:35308])
remaining methods: publickey
[2025-03-24T14:36:28.982-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-12] DEBUG
org.apache.sshd.server.session.ServerSessionImpl :
encode(ServerSessionImpl[null@/192.168.0.1:35308]) packet #4 sending
command=51[SSH_MSG_USERAUTH_FAILURE] len=15
[2025-03-24T14:36:28.982-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-12] DEBUG
org.apache.sshd.common.io.nio2.Nio2Session :
writeBuffer(Nio2Session[local=/192.168.0.1:29418, remote=/192.168.0.1:35308])
writing 44 bytes
[2025-03-24T14:36:28.982-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-13] DEBUG
org.apache.sshd.server.session.ServerSessionImpl :
doHandleMessage(ServerSessionImpl[null@/192.168.0.1:35308]) process #4
SSH_MSG_USERAUTH_REQUEST
[2025-03-24T14:36:28.983-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-13] DEBUG
org.apache.sshd.server.session.ServerUserAuthService :
handleUserAuthRequestMessage(ServerSessionImpl[null@/192.168.0.1:35308])
Received SSH_MSG_USERAUTH_REQUEST user=tcalderon, service=ssh-connection,
method=publickey
[2025-03-24T14:36:28.983-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-13] DEBUG
org.apache.sshd.server.session.ServerUserAuthService :
handleUserAuthRequestMessage(ServerSessionImpl[null@/192.168.0.1:35308])
Authenticating user 'tcalderon' with service 'ssh-connection' and method
'publickey' (attempt 3 / 6)
[2025-03-24T14:36:28.983-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-13] DEBUG
org.apache.sshd.server.auth.pubkey.UserAuthPublicKey :
doAuth(tcalderon@ServerSessionImpl[null@/192.168.0.1:35308]) verify key
type=ssh-ed25519,
factories=ecdsa-sha2-nistp256-cert-...@openssh.com,ecdsa-sha2-nistp384-cert-...@openssh.com,ecdsa-sha2-nistp521-cert-...@openssh.com,ssh-ed25519-cert-...@openssh.com,rsa-sha2-512-cert-...@openssh.com,rsa-sha2-256-cert-...@openssh.com,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521,ssh-ed25519,sk-ecdsa-sha2-nistp...@openssh.com,sk-ssh-ed25...@openssh.com,rsa-sha2-512,rsa-sha2-256,ssh-rsa,
fingerprint=SHA256:fXraQLcglzp4M1DPnC/CqvaDHkmFAbCLj0L3QWfm12U
[2025-03-24T14:36:28.983-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-13] WARN
org.apache.sshd.server.session.ServerUserAuthService :
handleUserAuthRequestMessage(ServerSessionImpl[null@/192.168.0.1:35308]) Failed
(IllegalStateException) to authenticate using factory method=publickey: null
java.lang.IllegalStateException
at
com.google.common.base.Preconditions.checkState(Preconditions.java:496)
at
com.google.gerrit.sshd.DatabasePubKeyAuth.authenticate(DatabasePubKeyAuth.java:147)
at
org.apache.sshd.server.auth.pubkey.CachingPublicKeyAuthenticator.authenticate(CachingPublicKeyAuthenticator.java:59)
at
org.apache.sshd.server.auth.pubkey.UserAuthPublicKey.doAuth(UserAuthPublicKey.java:148)
at
org.apache.sshd.server.auth.AbstractUserAuth.auth(AbstractUserAuth.java:70)
at
org.apache.sshd.server.session.ServerUserAuthService.handleUserAuthRequestMessage(ServerUserAuthService.java:331)
at
org.apache.sshd.server.session.ServerUserAuthService.process(ServerUserAuthService.java:163)
at
org.apache.sshd.common.session.helpers.CurrentService.process(CurrentService.java:109)
at
org.apache.sshd.common.session.helpers.AbstractSession.doHandleMessage(AbstractSession.java:634)
at
org.apache.sshd.common.session.helpers.AbstractSession.lambda$handleMessage$0(AbstractSession.java:555)
at
org.apache.sshd.common.util.threads.ThreadUtils.runAsInternal(ThreadUtils.java:68)
at
org.apache.sshd.common.session.helpers.AbstractSession.handleMessage(AbstractSession.java:554)
at
org.apache.sshd.common.session.helpers.AbstractSession.decode(AbstractSession.java:1738)
at
org.apache.sshd.common.session.helpers.AbstractSession.messageReceived(AbstractSession.java:515)
at
org.apache.sshd.common.session.helpers.AbstractSessionIoHandler.messageReceived(AbstractSessionIoHandler.java:76)
at
org.apache.sshd.common.io.nio2.Nio2Session.handleReadCycleCompletion(Nio2Session.java:409)
at
org.apache.sshd.common.io.nio2.Nio2Session$1.onCompleted(Nio2Session.java:382)
at
org.apache.sshd.common.io.nio2.Nio2Session$1.onCompleted(Nio2Session.java:377)
at
org.apache.sshd.common.io.nio2.Nio2CompletionHandler.lambda$completed$0(Nio2CompletionHandler.java:38)
at
java.base/java.security.AccessController.doPrivileged(AccessController.java:319)
at
org.apache.sshd.common.io.nio2.Nio2CompletionHandler.completed(Nio2CompletionHandler.java:37)
at java.base/sun.nio.ch.Invoker.invokeUnchecked(Invoker.java:125)
at java.base/sun.nio.ch.Invoker$1.run(Invoker.java:217)
at
java.base/sun.nio.ch.AsynchronousChannelGroupImpl$1.run(AsynchronousChannelGroupImpl.java:113)
at
java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144)
at
java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
at java.base/java.lang.Thread.run(Thread.java:1570)
[2025-03-24T14:36:28.984-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-13] DEBUG
org.apache.sshd.server.session.ServerUserAuthService :
handleAuthenticationFailure(tcalderon@ServerSessionImpl[null@/192.168.0.1:35308])
SSH_MSG_USERAUTH_REQUEST
[2025-03-24T14:36:28.984-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-13] DEBUG
org.apache.sshd.server.session.ServerUserAuthService :
handleAuthenticationFailure(tcalderon@ServerSessionImpl[null@/192.168.0.1:35308])
remaining methods: publickey
[2025-03-24T14:36:28.984-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-13] DEBUG
org.apache.sshd.server.session.ServerSessionImpl :
encode(ServerSessionImpl[null@/192.168.0.1:35308]) packet #5 sending
command=51[SSH_MSG_USERAUTH_FAILURE] len=15
[2025-03-24T14:36:28.984-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-13] DEBUG
org.apache.sshd.common.io.nio2.Nio2Session :
writeBuffer(Nio2Session[local=/192.168.0.1:29418, remote=/192.168.0.1:35308])
writing 44 bytes
[2025-03-24T14:36:28.986-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-14] DEBUG
org.apache.sshd.common.io.nio2.Nio2Session :
handleReadCycleCompletion(Nio2Session[local=/192.168.0.1:29418,
remote=/192.168.0.1:35308]) Socket has been disconnected (result=-1), closing
IoSession now
[2025-03-24T14:36:28.986-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-14] DEBUG
org.apache.sshd.common.io.nio2.Nio2Session :
close(Nio2Session[local=/192.168.0.1:29418, remote=/192.168.0.1:35308]) Closing
immediately
[2025-03-24T14:36:28.986-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-14] DEBUG
org.apache.sshd.common.io.nio2.Nio2Session :
doCloseImmediately(Nio2Session[local=/192.168.0.1:29418,
remote=/192.168.0.1:35308]) closing
socket=sun.nio.ch.UnixAsynchronousSocketChannelImpl[connected
local=/192.168.0.1:29418 remote=/192.168.0.1:35308]
[2025-03-24T14:36:28.986-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-14] DEBUG
org.apache.sshd.common.io.nio2.Nio2Session :
doCloseImmediately(Nio2Session[local=/192.168.0.1:29418,
remote=/192.168.0.1:35308])
socket=sun.nio.ch.UnixAsynchronousSocketChannelImpl[closed] closed
[2025-03-24T14:36:28.986-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-14] DEBUG
org.apache.sshd.common.io.nio2.Nio2Acceptor : unmapSession(id=119):
Nio2Session[local=/192.168.0.1:29418, remote=/192.168.0.1:35308]
[2025-03-24T14:36:28.986-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-14] DEBUG
org.apache.sshd.server.session.ServerSessionImpl :
close(ServerSessionImpl[null@/192.168.0.1:35308]) Closing immediately
[2025-03-24T14:36:28.987-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-14] DEBUG
org.apache.sshd.common.session.helpers.SessionTimeoutListener :
sessionClosed(ServerSessionImpl[null@/192.168.0.1:35308]) un-tracked
[2025-03-24T14:36:28.987-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-14] DEBUG
org.apache.sshd.server.session.ServerUserAuthService :
close(org.apache.sshd.server.session.ServerUserAuthService@15c4f946) Closing
immediately
[2025-03-24T14:36:28.987-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-14] DEBUG
org.apache.sshd.server.session.ServerUserAuthService :
close(org.apache.sshd.server.session.ServerUserAuthService@15c4f946)[Immediately]
closed
[2025-03-24T14:36:28.987-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-14] DEBUG
org.apache.sshd.common.io.nio2.Nio2Session :
close(Nio2Session[local=/192.168.0.1:29418,
remote=/192.168.0.1:35308])[Immediately] state already Closed
[2025-03-24T14:36:28.987-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-14] DEBUG
org.apache.sshd.common.util.closeable.SequentialCloseable :
doClose(org.apache.sshd.common.util.closeable.SequentialCloseable$1@623dc76b)
signal close complete immediately=true
[2025-03-24T14:36:28.988-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-14] DEBUG
org.apache.sshd.server.session.ServerSessionImpl :
close(ServerSessionImpl[null@/192.168.0.1:35308])[Immediately] closed
[2025-03-24T14:36:28.988-04:00]
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-14] DEBUG
org.apache.sshd.common.io.nio2.Nio2Session :
close(Nio2Session[local=/192.168.0.1:29418,
remote=/192.168.0.1:35308])[Immediately] closed
==> /var/tmp/gerrit-site/logs/sshd_log <==
[2025-03-24T14:36:28.987-04:00] a70b867f
[sshd-SshDaemon[687313e1](port=22)-nio2-thread-14] tcalderon a/1000001 LOGOUT
```
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: dev-unsubscr...@mina.apache.org
For queries about this service, please contact Infrastructure at:
us...@infra.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscr...@mina.apache.org
For additional commands, e-mail: dev-h...@mina.apache.org
