OpenSSH public key problem with Solaris 10 and LDAP users?

Alexander Skwar listen at alexander.skwar.name
Tue Aug 14 18:54:18 EST 2007


Hello.

I've got a problem logging in to a Sparc Solaris 10 machine with 
public key authentication. I searched, and found a similar problem
report at <http://thread.gmane.org/gmane.network.openssh.devel/12694>.
For that guy, the problem had to do with LDAP.

My user accounts are also stored in LDAP, an OpenLDAP server, to be
exact. That server runs on the same machine as the machine I'm trying
to login to. I'm using the Sun pam_ldap stuff.

Strange thing is, that I *am* able to login to this machine with
pubkey authentication as /some/ users. But it does not work for /all/
the users; also not for (test) accounts I just created.

What did I do? In LDAP, I added a test account:

version: 1

# LDIF Export for: uid=testme,ou=People,ou=RACE,o=cmp
# Generated by phpLDAPadmin ( http://phpldapadmin.sourceforge.net/ ) on August 14, 2007 10:43 am
# Server: RACE LDAP Server (winds06)
# Search Scope: base
# Search Filter: (objectClass=*)
# Total Entries: 1

dn: uid=testme,ou=People,ou=RACE,o=cmp
cn: Test User
gidNumber: 10
homeDirectory: /tmp/testme
sn: User
uid: testme
uidNumber: 12345
loginShell: /opt/csw/bin/bash
objectClass: inetLocalMailRecipient
objectClass: inetOrgPerson
objectClass: organizationalPerson
objectClass: person
objectClass: posixAccount
objectClass: shadowAccount
objectClass: top
objectClass: hostObject
userPassword: {CRYPT}YN5cP0Ms6G.C2
roomNumber: tesetme at cmp.ch
mail: testme at cmp.com
mailRoutingAddress: testme at rieter.ch
mailHost: mail1.cmp.com
shadowLastChange: 13503
gecos: Test Me User,testme at cmp.ch
host: winds06
host: winds06.win.ch.da.rtr
host: winnb000488.win.ch.da.rtr
host: winnb000488
givenName: Test

(I don't care that you now might now the password.)

Next I "mkdir /tmp/testme && chown 12345:10 /tmp/testme". After
that, I'm able to ssh into that account using the password.
Fine. On my Gentoo Linux "client" (I'm sitting in front of it
and use it to do everything), I then ran:

ssh-copy-id testme at winds06

It prompted me for the password and then copied the public key
to the remote host:

root at winds06 $ ls -laR ~testme
/tmp/testme:
total 48
drwxr-xr-x   3 testme   staff        178 Aug 14 10:01 .
drwxrwxrwt  18 root     sys         2469 Aug 14 10:30 ..
drwx------   2 testme   staff        189 Aug 14 10:01 .ssh

/tmp/testme/.ssh:
total 48
drwx------   2 testme   staff        189 Aug 14 10:01 .
drwxr-xr-x   3 testme   staff        178 Aug 14 10:01 ..
-rw-------   1 testme   staff        406 Aug 14 10:01 authorized_keys

root at winds06 $ cat /tmp/testme/.ssh/authorized_keys 
ssh-rsa AAAAB3NzaC1yc2EAAAABIwAAAQEAz3yb3Ey6eoDCViXpPNgNQ6gtB92tmEdzvn6R9rHDolPxA3iCOqtkGnMlOAhcg8E5NuGRWeJZueN8E3VpicJsY6xTGl8j8i9+PaCeraNCjJzwrEPXzeeTSKWNnS/uwO8j8NEGec6ZuYI2s4YmCzKGlG8xRS2D6fZalgbcjn4/ZkMGZiYeKm1RSY9Kg0pfLXnXu8u9kQczhKSFYEjvLi+IEhirnAcGPKTYAbNmvnWK8xvtNM+Gp3MQqmqfNC38XUXdah1fYZJaCH3i0slT/8bu3KxjT7UigE4NJ3AguByNfag6s4nglR8EVb0eqeVxdRWaSJrbeoXeZkuRfYM1d/DmnQ== /home/askwar/.ssh/id_rsa

Looks fine, doesn't it? I'm also able to login to other
accounts using this exact key.

Well, but watch this :(

root at winds06 $ /opt/csw/sbin/sshd -p 9991 -Dddd
debug2: load_server_config: filename /opt/csw/etc/sshd_config
debug2: load_server_config: done config len = 198
debug2: parse_server_config: config /opt/csw/etc/sshd_config len 198
debug3: /opt/csw/etc/sshd_config:15 setting Protocol 2
debug3: /opt/csw/etc/sshd_config:79 setting UsePAM yes
debug3: /opt/csw/etc/sshd_config:84 setting X11Forwarding yes
debug3: /opt/csw/etc/sshd_config:88 setting PrintMotd no
debug3: /opt/csw/etc/sshd_config:105 setting Subsystem sftp     /opt/csw/libexec/sftp-server
debug1: sshd version OpenSSH_4.5p1
debug3: Not a RSA1 key file /opt/csw/etc/ssh_host_rsa_key.
debug1: read PEM private key done: type RSA
debug1: private host key: #0 type 1 RSA
debug3: Not a RSA1 key file /opt/csw/etc/ssh_host_dsa_key.
debug1: read PEM private key done: type DSA
debug1: private host key: #1 type 2 DSA
debug1: rexec_argv[0]='/opt/csw/sbin/sshd'
debug1: rexec_argv[1]='-p'
debug1: rexec_argv[2]='9991'
debug1: rexec_argv[3]='-Dddd'
debug2: fd 4 setting O_NONBLOCK
debug1: Bind to port 9991 on ::.
Server listening on :: port 9991.
debug2: fd 5 setting O_NONBLOCK
debug1: Bind to port 9991 on 0.0.0.0.
Server listening on 0.0.0.0 port 9991.
debug1: fd 6 clearing O_NONBLOCK
debug1: Server will not fork when running in debugging mode.
debug3: send_rexec_state: entering fd = 11 config len 198
debug3: ssh_msg_send: type 0
debug3: send_rexec_state: done
debug1: rexec start in 6 out 6 newsock 6 pipe -1 sock 11
debug1: inetd sockets after dupping: 4, 4
Connection from 10.0.3.115 port 57348
debug1: Client protocol version 2.0; client software version OpenSSH_4.6p1-hpn12v17
debug1: match: OpenSSH_4.6p1-hpn12v17 pat OpenSSH*
debug1: Enabling compatibility mode for protocol 2.0
debug1: Local version string SSH-2.0-OpenSSH_4.5
debug2: fd 4 setting O_NONBLOCK
debug2: Network child is on pid 17491
debug3: preauth child monitor started
debug3: mm_request_receive entering
debug3: privsep user:group 113:1
debug1: permanently_set_uid: 113/1
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-sha256,diffie-hellman-group-exchange-sha1,diffie-hellman-group14-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,arcfour128,arcfour256,arcfour,aes192-cbc,aes256-cbc,rijndael-cbc at lysator.liu.se,aes128-ctr,aes192-ctr,aes256-ctr
debug2: kex_parse_kexinit: aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour128,arcfour256,arcfour,aes192-cbc,aes256-cbc,rijndael-cbc at lysator.liu.se,aes128-ctr,aes192-ctr,aes256-ctr
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 at openssh.com
debug2: kex_parse_kexinit: none,zlib at openssh.com
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-sha256,diffie-hellman-group-exchange-sha1,diffie-hellman-group14-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,arcfour128,arcfour256,arcfour,aes192-cbc,aes256-cbc,rijndael-cbc at lysator.liu.se,aes128-ctr,aes192-ctr,aes256-ctr
debug2: kex_parse_kexinit: aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour128,arcfour256,arcfour,aes192-cbc,aes256-cbc,rijndael-cbc at lysator.liu.se,aes128-ctr,aes192-ctr,aes256-ctr
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: zlib at openssh.com,zlib,none
debug2: kex_parse_kexinit: zlib at openssh.com,zlib,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 zlib at openssh.com
debug2: mac_init: found hmac-md5
debug1: kex: server->client aes128-cbc hmac-md5 zlib at openssh.com
debug1: SSH2_MSG_KEX_DH_GEX_REQUEST received
debug3: mm_request_send entering: type 0
debug3: mm_choose_dh: waiting for MONITOR_ANS_MODULI
debug3: mm_request_receive_expect entering: type 1
debug3: mm_request_receive entering
debug3: monitor_read: checking request 0
debug3: mm_answer_moduli: got parameters: 1024 1024 8192
debug3: mm_request_send entering: type 1
debug2: monitor_read: 0 used once, disabling now
debug3: mm_request_receive entering
debug3: mm_choose_dh: remaining 0
debug1: SSH2_MSG_KEX_DH_GEX_GROUP sent
debug2: dh_gen_key: priv key bits set: 135/256
debug2: bits set: 504/1024
debug1: expecting SSH2_MSG_KEX_DH_GEX_INIT
debug2: bits set: 501/1024
debug3: mm_key_sign entering
debug3: mm_request_send entering: type 4
debug3: mm_key_sign: waiting for MONITOR_ANS_SIGN
debug3: mm_request_receive_expect entering: type 5
debug3: mm_request_receive entering
debug3: monitor_read: checking request 4
debug3: mm_answer_sign
debug3: mm_answer_sign: signature a0f28(143)
debug3: mm_request_send entering: type 5
debug2: monitor_read: 4 used once, disabling now
debug3: mm_request_receive entering
debug1: SSH2_MSG_KEX_DH_GEX_REPLY sent
debug2: kex_derive_keys
debug2: set_newkeys: mode 1
debug1: SSH2_MSG_NEWKEYS sent
debug1: expecting SSH2_MSG_NEWKEYS
debug2: set_newkeys: mode 0
debug1: SSH2_MSG_NEWKEYS received
debug1: KEX done
debug1: userauth-request for user testme service ssh-connection method none
debug1: attempt 0 failures 0
debug3: mm_getpwnamallow entering
debug3: mm_request_send entering: type 6
debug3: mm_getpwnamallow: waiting for MONITOR_ANS_PWNAM
debug3: mm_request_receive_expect entering: type 7
debug3: mm_request_receive entering
debug3: monitor_read: checking request 6
debug3: mm_answer_pwnamallow
debug3: Trying to reverse map address 10.0.3.115.
debug2: parse_server_config: config reprocess config len 198
debug3: mm_answer_pwnamallow: sending MONITOR_ANS_PWNAM: 1
debug3: mm_request_send entering: type 7
debug2: monitor_read: 6 used once, disabling now
debug3: mm_request_receive entering
debug2: input_userauth_request: setting up authctxt for testme
debug3: mm_start_pam entering
debug3: mm_request_send entering: type 47
debug3: mm_inform_authserv entering
debug3: mm_request_send entering: type 3
debug2: input_userauth_request: try method none
debug3: mm_auth_password entering
debug3: mm_request_send entering: type 10
debug3: mm_auth_password: waiting for MONITOR_ANS_AUTHPASSWORD
debug3: mm_request_receive_expect entering: type 11
debug3: mm_request_receive entering
debug3: monitor_read: checking request 47
debug1: PAM: initializing for "testme"
debug1: PAM: setting PAM_RHOST to "winnb000488.win.ch.da.rtr"
debug1: PAM: setting PAM_TTY to "ssh"
debug2: monitor_read: 47 used once, disabling now
debug3: mm_request_receive entering
debug3: monitor_read: checking request 3
debug3: mm_answer_authserv: service=ssh-connection, style=
debug2: monitor_read: 3 used once, disabling now
debug3: mm_request_receive entering
debug3: monitor_read: checking request 10
debug3: mm_answer_authpassword: sending result 0
debug3: mm_request_send entering: type 11
Failed none for testme from 10.0.3.115 port 57348 ssh2
debug3: mm_request_receive entering
debug3: mm_auth_password: user not authenticated
debug1: userauth-request for user testme service ssh-connection method publickey
debug1: attempt 1 failures 1
debug2: input_userauth_request: try method publickey
debug1: test whether pkalg/pkblob are acceptable
debug3: mm_key_allowed entering
debug3: mm_request_send entering: type 20
debug3: mm_key_allowed: waiting for MONITOR_ANS_KEYALLOWED
debug3: mm_request_receive_expect entering: type 21
debug3: mm_request_receive entering
debug3: monitor_read: checking request 20
debug3: mm_answer_keyallowed entering
debug3: mm_answer_keyallowed: key_from_blob: 99468
debug1: temporarily_use_uid: 12345/10 (e=0/0)
debug1: trying public key file /tmp/testme/.ssh/authorized_keys
debug3: secure_filename: checking '/tmp/testme/.ssh'
debug3: secure_filename: checking '/tmp/testme'
debug3: secure_filename: terminating check at '/tmp/testme'
debug1: matching key found: file /tmp/testme/.ssh/authorized_keys, line 1
Found matching RSA key: 42:1b:5b:46:12:a2:78:4d:7c:fc:b8:5a:a5:49:b9:e1
debug1: restore_uid: 0/0
debug3: mm_answer_keyallowed: key 99468 is allowed
debug3: mm_request_send entering: type 21
debug3: mm_request_receive entering
debug2: userauth_pubkey: authenticated 0 pkalg ssh-rsa
Postponed publickey for testme from 10.0.3.115 port 57348 ssh2
debug1: userauth-request for user testme service ssh-connection method publickey
debug1: attempt 2 failures 1
debug2: input_userauth_request: try method publickey
debug3: mm_key_allowed entering
debug3: mm_request_send entering: type 20
debug3: mm_key_allowed: waiting for MONITOR_ANS_KEYALLOWED
debug3: mm_request_receive_expect entering: type 21
debug3: mm_request_receive entering
debug3: monitor_read: checking request 20
debug3: mm_answer_keyallowed entering
debug3: mm_answer_keyallowed: key_from_blob: 996a8
debug1: temporarily_use_uid: 12345/10 (e=0/0)
debug1: trying public key file /tmp/testme/.ssh/authorized_keys
debug3: secure_filename: checking '/tmp/testme/.ssh'
debug3: secure_filename: checking '/tmp/testme'
debug3: secure_filename: terminating check at '/tmp/testme'
debug1: matching key found: file /tmp/testme/.ssh/authorized_keys, line 1
Found matching RSA key: 42:1b:5b:46:12:a2:78:4d:7c:fc:b8:5a:a5:49:b9:e1
debug1: restore_uid: 0/0
debug3: mm_answer_keyallowed: key 996a8 is allowed
debug3: mm_request_send entering: type 21
debug3: mm_key_verify entering
debug3: mm_request_send entering: type 22
debug3: mm_key_verify: waiting for MONITOR_ANS_KEYVERIFY
debug3: mm_request_receive_expect entering: type 23
debug3: mm_request_receive entering
debug3: mm_request_receive entering
debug3: monitor_read: checking request 22
debug1: ssh_rsa_verify: signature correct
debug3: mm_answer_keyverify: key 99468 signature verified
debug3: mm_request_send entering: type 23
debug2: userauth_pubkey: authenticated 1 pkalg ssh-rsa
debug3: mm_do_pam_account entering
debug3: mm_request_send entering: type 48
debug3: mm_request_receive_expect entering: type 49
debug3: mm_request_receive entering
debug3: mm_request_receive_expect entering: type 48
debug3: mm_request_receive entering
debug1: do_pam_account: called
debug3: PAM: do_pam_account pam_acct_mgmt = 9 (Authentication failed)
debug3: mm_request_send entering: type 49
debug3: mm_do_pam_account returning 0
Access denied for user testme by PAM account configuration
debug1: do_cleanup
Failed publickey for testme from 10.0.3.115 port 57348 ssh2
debug3: mm_request_receive entering
debug1: do_cleanup

I guess the most important lines are these:

debug3: PAM: do_pam_account pam_acct_mgmt = 9 (Authentication failed)
[...]
Access denied for user testme by PAM account configuration

Why is PAM denying access?

root at winds06 $ grep -v \# /etc/pam.conf
login   auth requisite        pam_authtok_get.so.1
login   auth required         pam_dhkeys.so.1
login   auth required         pam_unix_cred.so.1
login   auth required         pam_dial_auth.so.1
login   auth binding          pam_unix_auth.so.1 server_policy
login   auth required         pam_ldap.so.1
rlogin  auth sufficient       pam_rhosts_auth.so.1
rlogin  auth requisite        pam_authtok_get.so.1
rlogin  auth required         pam_dhkeys.so.1
rlogin  auth required         pam_unix_cred.so.1
rlogin  auth binding          pam_unix_auth.so.1 server_policy
rlogin  auth required         pam_ldap.so.1
rsh     auth sufficient       pam_rhosts_auth.so.1
rsh     auth required         pam_unix_cred.so.1
rsh     auth binding          pam_unix_auth.so.1 server_policy
rsh     auth required         pam_ldap.so.1
ppp     auth requisite        pam_authtok_get.so.1
ppp     auth required         pam_dhkeys.so.1
ppp     auth required         pam_dial_auth.so.1
ppp     auth binding          pam_unix_auth.so.1 server_policy
ppp     auth required         pam_ldap.so.1
other   auth requisite        pam_authtok_get.so.1
other   auth required         pam_dhkeys.so.1
other   auth required         pam_unix_cred.so.1
other   auth binding          pam_unix_auth.so.1 server_policy
other   auth required         pam_ldap.so.1
passwd  auth binding          pam_passwd_auth.so.1 server_policy
passwd  auth required         pam_ldap.so.1
cron    account required      pam_unix_account.so.1
other   account requisite     pam_roles.so.1
other   account binding       pam_unix_account.so.1 server_policy
other   account required      pam_ldap.so.1
other   session required      pam_unix_session.so.1
other   password required     pam_dhkeys.so.1
other   password requisite    pam_authtok_get.so.1
other   password requisite    pam_authtok_check.so.1
other   password required     pam_authtok_store.so.1 server_policy

What I absolutely don't get, is why PAM denies access to this
user with pubkey auth. To create the user in LDAP, I copied an 
existing and working entry and then modified stuff like uidNumber,
uid, userPassword etc.

Versions:

Server: OpenSSH_4.5p1, OpenSSL 0.9.8e 23 Feb 2007, Sparc Solaris 10
Client: OpenSSH_4.6p1-hpn12v17, OpenSSL 0.9.8e 23 Feb 2007, x86 Gentoo Linux

Thanks a lot for any hints,

Alexander Skwar



More information about the openssh-unix-dev mailing list