Mailing List Archive

I've been scratching my head about this one for a few days
now and can't make sense of it.

We have a user who always wants to auth via publickey. Most
of the time, that happens. What is shown below is debugging
info for one of the rare times that the user was asked for
a PAM password due to publickey failing and the stack falling
through.

The server, beijing, is running OpenSSH 4.3p2 and is a
RHELv5 box.

The client is either (both fail in the same way) Sun SSH
from Solaris 9 fully patched or OpenSSH 5.1p1 from
Ubuntu 8.10

Can anyone make any sense of why this is happening? The debug
info leaves a LOT to be desired :(

-rw-r--r-- 1 jimbo air 795 Feb 28 23:14
/home/jimbo/.ssh/authorized_keys

Apr 9 13:40:24 beijing sshd[9505]: debug1: userauth-request for user
jimbo service ssh-connection method none
Apr 9 13:40:24 beijing sshd[9505]: debug1: attempt 0 failures 0
Apr 9 13:40:24 beijing sshd[9504]: debug2: monitor_read: 7 used once,
disabling now
Apr 9 13:40:24 beijing sshd[9505]: debug2: input_userauth_request:
setting up authctxt for jimbo
Apr 9 13:40:24 beijing sshd[9505]: debug2: input_userauth_request: try
method none
Apr 9 13:40:24 beijing sshd[9504]: debug1: PAM: initializing for "jimbo"
Apr 9 13:40:24 beijing sshd[9505]: debug1: userauth-request for user
jimbo service ssh-connection method publickey
Apr 9 13:40:24 beijing sshd[9505]: debug1: attempt 1 failures 1
Apr 9 13:40:24 beijing sshd[9505]: debug2: input_userauth_request: try
method publickey
Apr 9 13:40:24 beijing sshd[9505]: debug1: test whether pkalg/pkblob
are acceptable
Apr 9 13:40:24 beijing sshd[9504]: debug1: PAM: setting PAM_RHOST to
"ssh-client.our.org"
Apr 9 13:40:24 beijing sshd[9504]: debug1: PAM: setting PAM_TTY to "ssh"
Apr 9 13:40:24 beijing sshd[9504]: debug2: monitor_read: 46 used once,
disabling now
Apr 9 13:40:24 beijing sshd[9504]: debug2: monitor_read: 3 used once,
disabling now
Apr 9 13:40:24 beijing sshd[9504]: debug2: monitor_read: 4 used once,
disabling now
Apr 9 13:40:24 beijing sshd[9504]: debug1: temporarily_use_uid:
14946/67 (e=0/0)
Apr 9 13:40:24 beijing sshd[9504]: debug1: trying public key file
/home/jimbo/.ssh/authorized_keys
Apr 9 13:40:24 beijing sshd[9504]: debug1: restore_uid: 0/0
Apr 9 13:40:24 beijing sshd[9504]: debug1: temporarily_use_uid:
14946/67 (e=0/0)
Apr 9 13:40:24 beijing sshd[9504]: debug1: trying public key file
/home/jimbo/.ssh/authorized_keys2
Apr 9 13:40:24 beijing sshd[9504]: debug1: restore_uid: 0/0
Apr 9 13:40:24 beijing sshd[9504]: Failed publickey for jimbo from
XXX.YY.51.5 port 50928 ssh2
Apr 9 13:40:24 beijing sshd[9505]: debug2: userauth_pubkey:
authenticated 0 pkalg ssh-rsa
Apr 9 13:40:24 beijing sshd[9505]: debug1: userauth-request for user
jimbo service ssh-connection method keyboard-interactive
Apr 9 13:40:24 beijing sshd[9505]: debug1: attempt 2 failures 2
Apr 9 13:40:24 beijing sshd[9505]: debug2: input_userauth_request: try
method keyboard-interactive
Apr 9 13:40:24 beijing sshd[9505]: debug1: keyboard-interactive devs
Apr 9 13:40:25 beijing sshd[9505]: debug1: auth2_challenge: user=jimbo
devs=
Apr 9 13:40:25 beijing sshd[9505]: debug1: kbdint_alloc: devices 'pam'
Apr 9 13:40:25 beijing sshd[9505]: debug2: auth2_challenge_start:
devices pam
Apr 9 13:40:25 beijing sshd[9505]: debug2: kbdint_next_device: devices
<empty>
Apr 9 13:40:25 beijing sshd[9505]: debug1: auth2_challenge_start:
trying authentication method 'pam'
Apr 9 13:40:25 beijing sshd[9505]: Postponed keyboard-interactive for
jimbo from XXX.YY.51.5 port 50928 ssh2
Apr 9 13:40:27 beijing sshd[9504]: debug2: PAM: sshpam_respond
entering, 1 responses
Apr 9 13:40:27 beijing sshd[9509]: debug1: do_pam_account: called
Apr 9 13:40:27 beijing sshd[9504]: debug1: PAM: num PAM env strings 1
Apr 9 13:40:27 beijing sshd[9505]: Postponed keyboard-interactive/pam
for jimbo from XXX.YY.51.5 port 50928 ssh2
Apr 9 13:40:27 beijing sshd[9504]: debug2: PAM: sshpam_respond
entering, 0 responses
Apr 9 13:40:27 beijing sshd[9504]: debug2: monitor_read: 55 used once,
disabling now
Apr 9 13:40:27 beijing sshd[9504]: debug1: do_pam_account: called
Apr 9 13:40:27 beijing sshd[9504]: Accepted keyboard-interactive/pam
for jimbo from XXX.YY.51.5 port 50928 ssh2
Apr 9 13:40:27 beijing sshd[9504]: debug1: monitor_child_preauth: jimbo
has been authenticated by privileged process
Apr 9 13:40:27 beijing sshd[9504]: debug2: mac_init: found hmac-md5
Apr 9 13:40:27 beijing sshd[9504]: debug2: mac_init: found hmac-md5
Apr 9 13:40:27 beijing sshd[9504]: debug1: PAM: establishing credentials
Apr 9 13:40:27 beijing sshd[9504]: debug2: User child is on pid 9512
Apr 9 13:40:27 beijing sshd[9512]: debug1: PAM: reinitializing credentials
Apr 9 13:40:27 beijing sshd[9512]: debug1: permanently_set_uid: 14946/67
Apr 9 13:40:27 beijing sshd[9512]: debug2: set_newkeys: mode 0
Apr 9 13:40:27 beijing sshd[9512]: debug2: set_newkeys: mode 1
Apr 9 13:40:27 beijing sshd[9512]: debug1: Entering interactive session
for SSH2.