2.9: RSAAuthentication problems

[Phil Pennock]

I'm using an OpenBSD 2.9 snapshot on i386.  "ssh -V" reveals
OpenSSH_2.9, yada yada.

I generated a keypair using ssh-keygen and accepting defaults.  I copied
the public key to another box, stuck it in ~/.ssh/authorized_keys with
host restriction and then tried to use it.  Failed.  Removed the host
restriction, still failed.  Just get asked for password.

So I cut out the extra box.  As root, on the 2.9 box, I ran
# sshd -ddd -p24 2>&1 | tee ssh-server
and then as myself, under script, I showed the presence of a key in the
agent, and then tried to ssh with "-v -v -v -p 24" to localhost.

Still fails to use the keys.  debug2 shows "userauth_pubkey_agent: no
keys at all" whilst "ssh-add -l" obviously disagrees.  The attempts to
access the private keys directly (debug1, "try privkey") are silent for
the key which exists, ~/.ssh/identity -- but if I move that to id_rsa,
then ssh is silent about id_rsa and reports trying the "identity" file.

Rest of this message is the output from script (details of key from
"ssh-add -l" are censored), followed by the server output.

Hrm, given how the server output was generated, I'm also curious to know
why there were carriage-returns at the end of lines.

Help please?  Am I missing something really obvious?

-----------------------------< cut here >-------------------------------
% ssh-add -l
1024 <fingerprint was here> <comment was here> (RSA1)
% ssh -v -v -v -p 24 localhost
OpenSSH_2.9, SSH protocols 1.5/2.0, OpenSSL 0x0090600f
debug1: Reading configuration data /etc/ssh_config
debug1: Rhosts Authentication disabled, originating port will not be trusted.
debug1: restore_uid
debug1: ssh_connect: getuid 1000 geteuid 0 anon 1
debug1: Connecting to localhost [127.0.0.1] port 24.
debug1: temporarily_use_uid: 1000/500 (e=0)
debug1: restore_uid
debug1: temporarily_use_uid: 1000/500 (e=0)
debug1: restore_uid
debug1: Connection established.
debug1: read PEM private key done: type DSA
debug1: read PEM private key done: type RSA
debug1: identity file /home/phil/.ssh/identity type 0
debug1: identity file /home/phil/.ssh/id_rsa type -1
debug1: identity file /home/phil/.ssh/id_dsa type -1
debug1: Remote protocol version 1.99, remote software version OpenSSH_2.9
debug1: match: OpenSSH_2.9 pat ^OpenSSH
Enabling compatibility mode for protocol 2.0
debug1: Local version string SSH-2.0-OpenSSH_2.9
debug1: SSH2_MSG_KEXINIT sent
debug1: SSH2_MSG_KEXINIT received
debug2: kex_parse_kexinit: diffie-hellman-group-exchange-sha1,diffie-hellman-group1-sha1
debug2: kex_parse_kexinit: ssh-rsa,ssh-dss
debug2: kex_parse_kexinit: aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour,aes192-cbc,aes256-cbc,rijndael128-cbc,rijndael192-cbc,rijndael256-cbc,rijndael-cbc at lysator.liu.se
debug2: kex_parse_kexinit: aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour,aes192-cbc,aes256-cbc,rijndael128-cbc,rijndael192-cbc,rijndael256-cbc,rijndael-cbc at lysator.liu.se
debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,hmac-ripemd160,hmac-ripemd160 at openssh.com,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,hmac-ripemd160,hmac-ripemd160 at openssh.com,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: none
debug2: kex_parse_kexinit: none
debug2: kex_parse_kexinit: 
debug2: kex_parse_kexinit: 
debug2: kex_parse_kexinit: first_kex_follows 0 
debug2: kex_parse_kexinit: reserved 0 
debug2: kex_parse_kexinit: diffie-hellman-group-exchange-sha1,diffie-hellman-group1-sha1
debug2: kex_parse_kexinit: ssh-rsa,ssh-dss
debug2: kex_parse_kexinit: aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour,aes192-cbc,aes256-cbc,rijndael128-cbc,rijndael192-cbc,rijndael256-cbc,rijndael-cbc at lysator.liu.se
debug2: kex_parse_kexinit: aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour,aes192-cbc,aes256-cbc,rijndael128-cbc,rijndael192-cbc,rijndael256-cbc,rijndael-cbc at lysator.liu.se
debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,hmac-ripemd160,hmac-ripemd160 at openssh.com,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,hmac-ripemd160,hmac-ripemd160 at openssh.com,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: none,zlib
debug2: kex_parse_kexinit: none,zlib
debug2: kex_parse_kexinit: 
debug2: kex_parse_kexinit: 
debug2: kex_parse_kexinit: first_kex_follows 0 
debug2: kex_parse_kexinit: reserved 0 
debug2: mac_init: found hmac-md5
debug1: kex: server->client aes128-cbc hmac-md5 none
debug2: mac_init: found hmac-md5
debug1: kex: client->server aes128-cbc hmac-md5 none
debug1: SSH2_MSG_KEX_DH_GEX_REQUEST sent
debug1: expecting SSH2_MSG_KEX_DH_GEX_GROUP
debug1: dh_gen_key: priv key bits set: 134/256
debug1: bits set: 991/2049
debug1: SSH2_MSG_KEX_DH_GEX_INIT sent
debug1: expecting SSH2_MSG_KEX_DH_GEX_REPLY
debug1: Forcing accepting of host key for loopback/localhost.
debug1: bits set: 997/2049
debug1: ssh_rsa_verify: signature correct
debug1: kex_derive_keys
debug1: newkeys: mode 1
debug1: SSH2_MSG_NEWKEYS sent
debug1: waiting for SSH2_MSG_NEWKEYS
debug1: newkeys: mode 0
debug1: SSH2_MSG_NEWKEYS received
debug1: done: ssh_kex2.
debug1: send SSH2_MSG_SERVICE_REQUEST
debug1: service_accept: ssh-userauth
debug1: got SSH2_MSG_SERVICE_ACCEPT
debug1: authentications that can continue: publickey,password,keyboard-interactive
debug3: start over, passed a different list publickey,password,keyboard-interactive
debug3: preferred publickey,password,keyboard-interactive
debug3: authmethod_lookup publickey
debug3: remaining preferred: password,keyboard-interactive
debug3: authmethod_is_enabled publickey
debug1: next auth method to try is publickey
debug2: userauth_pubkey_agent: no keys at all
debug2: userauth_pubkey_agent: no more keys
debug2: userauth_pubkey_agent: no message sent
debug1: try privkey: /home/phil/.ssh/id_rsa
debug3: no such identity: /home/phil/.ssh/id_rsa
debug1: try privkey: /home/phil/.ssh/id_dsa
debug3: no such identity: /home/phil/.ssh/id_dsa
debug2: we did not send a packet, disable method
debug3: authmethod_lookup password
debug3: remaining preferred: keyboard-interactive
debug3: authmethod_is_enabled password
debug1: next auth method to try is password
phil at localhost's password: 
debug2: packet_inject_ignore: current 49
debug2: packet_inject_ignore: block 16 have 4 nb 4 mini 1 need 4
debug2: we sent a password packet, wait for reply
debug1: authentications that can continue: publickey,password,keyboard-interactive
Permission denied, please try again.
phil at localhost's password: 
debug2: packet_inject_ignore: current 49
debug2: packet_inject_ignore: block 16 have 4 nb 4 mini 1 need 4
debug2: we sent a password packet, wait for reply
debug1: authentications that can continue: publickey,password,keyboard-interactive
Permission denied, please try again.
phil at localhost's password: 
debug2: packet_inject_ignore: current 49
debug2: packet_inject_ignore: block 16 have 4 nb 4 mini 1 need 4
debug2: we sent a password packet, wait for reply
debug1: authentications that can continue: publickey,password,keyboard-interactive
debug2: we did not send a packet, disable method
debug3: authmethod_lookup keyboard-interactive
debug3: remaining preferred: 
debug3: authmethod_is_enabled keyboard-interactive
debug1: next auth method to try is keyboard-interactive
debug2: userauth_kbdint
debug2: we sent a keyboard-interactive packet, wait for reply
debug1: authentications that can continue: publickey,password,keyboard-interactive
debug2: userauth_kbdint
debug2: we sent a keyboard-interactive packet, wait for reply
debug1: authentications that can continue: publickey,password,keyboard-interactive
debug2: userauth_kbdint
debug2: we sent a keyboard-interactive packet, wait for reply
debug1: authentications that can continue: publickey,password,keyboard-interactive
debug2: we did not send a packet, disable method
debug1: no more auth methods to try
Permission denied (publickey,password,keyboard-interactive).
debug1: Calling cleanup 0x21218(0x0)
-----------------------------< cut here >-------------------------------
debug1: sshd version OpenSSH_2.9
debug1: private host key: #0 type 0 RSA1
debug3: No RSA1 key file /etc/ssh_host_rsa_key.
debug1: read PEM private key done: type RSA
debug1: private host key: #1 type 1 RSA
debug3: No RSA1 key file /etc/ssh_host_dsa_key.
debug1: read PEM private key done: type DSA
debug1: private host key: #2 type 2 DSA
debug1: Bind to port 24 on ::.
Server listening on :: port 24.
debug1: Bind to port 24 on 0.0.0.0.
Server listening on 0.0.0.0 port 24.
Generating 768 bit RSA key.
RSA key generation complete.
debug1: Server will not fork when running in debugging mode.
Connection from 127.0.0.1 port 43936
debug1: Client protocol version 2.0; client software version OpenSSH_2.9
debug1: match: OpenSSH_2.9 pat ^OpenSSH
Enabling compatibility mode for protocol 2.0
debug1: Local version string SSH-1.99-OpenSSH_2.9
debug1: Rhosts Authentication disabled, originating port not trusted.
debug1: list_hostkey_types: ssh-rsa,ssh-dss
debug1: SSH2_MSG_KEXINIT sent
debug1: SSH2_MSG_KEXINIT received
debug2: kex_parse_kexinit: diffie-hellman-group-exchange-sha1,diffie-hellman-group1-sha1
debug2: kex_parse_kexinit: ssh-rsa,ssh-dss
debug2: kex_parse_kexinit: aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour,aes192-cbc,aes256-cbc,rijndael128-cbc,rijndael192-cbc,rijndael256-cbc,rijndael-cbc at lysator.liu.se
debug2: kex_parse_kexinit: aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour,aes192-cbc,aes256-cbc,rijndael128-cbc,rijndael192-cbc,rijndael256-cbc,rijndael-cbc at lysator.liu.se
debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,hmac-ripemd160,hmac-ripemd160 at openssh.com,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,hmac-ripemd160,hmac-ripemd160 at openssh.com,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: none,zlib
debug2: kex_parse_kexinit: none,zlib
debug2: kex_parse_kexinit: 
debug2: kex_parse_kexinit: 
debug2: kex_parse_kexinit: first_kex_follows 0 
debug2: kex_parse_kexinit: reserved 0 
debug2: kex_parse_kexinit: diffie-hellman-group-exchange-sha1,diffie-hellman-group1-sha1
debug2: kex_parse_kexinit: ssh-rsa,ssh-dss
debug2: kex_parse_kexinit: aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour,aes192-cbc,aes256-cbc,rijndael128-cbc,rijndael192-cbc,rijndael256-cbc,rijndael-cbc at lysator.liu.se
debug2: kex_parse_kexinit: aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour,aes192-cbc,aes256-cbc,rijndael128-cbc,rijndael192-cbc,rijndael256-cbc,rijndael-cbc at lysator.liu.se
debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,hmac-ripemd160,hmac-ripemd160 at openssh.com,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: hmac-md5,hmac-sha1,hmac-ripemd160,hmac-ripemd160 at openssh.com,hmac-sha1-96,hmac-md5-96
debug2: kex_parse_kexinit: none
debug2: kex_parse_kexinit: none
debug2: kex_parse_kexinit: 
debug2: kex_parse_kexinit: 
debug2: kex_parse_kexinit: first_kex_follows 0 
debug2: kex_parse_kexinit: reserved 0 
debug2: mac_init: found hmac-md5
debug1: kex: client->server aes128-cbc hmac-md5 none
debug2: mac_init: found hmac-md5
debug1: kex: server->client aes128-cbc hmac-md5 none
debug1: SSH2_MSG_KEX_DH_GEX_REQUEST received
debug1: SSH2_MSG_KEX_DH_GEX_GROUP sent
debug1: dh_gen_key: priv key bits set: 118/256
debug1: bits set: 997/2049
debug1: expecting SSH2_MSG_KEX_DH_GEX_INIT
debug1: bits set: 991/2049
debug2: ssh_rsa_sign: done
debug1: SSH2_MSG_KEX_DH_GEX_REPLY sent
debug1: kex_derive_keys
debug1: newkeys: mode 1
debug1: SSH2_MSG_NEWKEYS sent
debug1: waiting for SSH2_MSG_NEWKEYS
debug1: newkeys: mode 0
debug1: SSH2_MSG_NEWKEYS received
debug1: KEX done
debug1: userauth-request for user phil service ssh-connection method none
debug1: attempt 0 failures 0
debug2: input_userauth_request: setting up authctxt for phil
debug2: input_userauth_request: try method none
Failed none for phil from 127.0.0.1 port 43936 ssh2
debug1: userauth-request for user phil service ssh-connection method password
debug1: attempt 1 failures 1
debug2: input_userauth_request: try method password
Failed password for phil from 127.0.0.1 port 43936 ssh2
debug1: userauth-request for user phil service ssh-connection method password
debug1: attempt 2 failures 2
debug2: input_userauth_request: try method password
Failed password for phil from 127.0.0.1 port 43936 ssh2
debug1: userauth-request for user phil service ssh-connection method password
debug1: attempt 3 failures 3
debug2: input_userauth_request: try method password
Failed password for phil from 127.0.0.1 port 43936 ssh2
debug1: userauth-request for user phil service ssh-connection method keyboard-interactive
debug1: attempt 4 failures 4
debug2: input_userauth_request: try method keyboard-interactive
debug1: keyboard-interactive language  devs 
Failed keyboard-interactive for phil from 127.0.0.1 port 43936 ssh2
debug1: userauth-request for user phil service ssh-connection method keyboard-interactive
debug1: attempt 5 failures 5
debug2: input_userauth_request: try method keyboard-interactive
debug1: keyboard-interactive language  devs 
Failed keyboard-interactive for phil from 127.0.0.1 port 43936 ssh2
debug1: userauth-request for user phil service ssh-connection method keyboard-interactive
debug1: attempt 6 failures 6
debug2: input_userauth_request: try method keyboard-interactive
debug1: keyboard-interactive language  devs 
Failed keyboard-interactive for phil from 127.0.0.1 port 43936 ssh2
Connection closed by 127.0.0.1
debug1: Calling cleanup 0x250d8(0x0)