OpenSSH public key problem with Solaris 10 and LDAP users?

[Alexander Skwar]

David Leonard <d at adaptive-enterprises.com.au> wrote:

> Alexander Skwar wrote:
>> I've got a problem logging in to a Sparc Solaris 10 machine
> 
>> 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?
>>   
> 
> Hi, Alexander
> See this post for information on enabling debug output from the pam
> stack on Solaris:
> http://mail.opensolaris.org/pipermail/ug-bosug/2006-July/000746.html

Hm. I get the following (starting from when I get the login prompt
after "telnet  host", ending after I entered username+password and then
^D):

,----[ PAM Debug Log Messages ]
| Aug 14 14:03:32 winds05 login[3155]: [ID 397050 auth.debug] PAM[3155]: pam_start(telnet,,26a84:29430) - debug = 1
| Aug 14 14:03:32 winds05 login[3155]: [ID 360225 auth.debug] PAM[3155]: pam_set_item(29430:service)
| Aug 14 14:03:32 winds05 login[3155]: [ID 360225 auth.debug] PAM[3155]: pam_set_item(29430:user)
| Aug 14 14:03:32 winds05 login[3155]: [ID 360225 auth.debug] PAM[3155]: pam_set_item(29430:conv)
| Aug 14 14:03:32 winds05 login[3155]: [ID 360225 auth.debug] PAM[3155]: pam_set_item(29430:tty)
| Aug 14 14:03:32 winds05 login[3155]: [ID 360225 auth.debug] PAM[3155]: pam_set_item(29430:rhost)
| Aug 14 14:03:32 winds05 login: [ID 360225 auth.debug] PAM[3155]: pam_set_item(29430:user_prompt)
| Aug 14 14:03:32 winds05 login: [ID 304686 auth.debug] PAM[3155]: pam_authenticate(29430, 0)
| Aug 14 14:03:32 winds05 login: [ID 387781 auth.debug] PAM[3155]: load_modules(29430, pam_sm_authenticate)=/usr/lib/security/pam_authtok_get.so.1
| Aug 14 14:03:32 winds05 login: [ID 278207 auth.debug] PAM[3155]: load_function: successful load of pam_sm_authenticate
| Aug 14 14:03:32 winds05 login: [ID 387781 auth.debug] PAM[3155]: load_modules(29430, pam_sm_authenticate)=/usr/lib/security/pam_dhkeys.so.1
| Aug 14 14:03:32 winds05 login: [ID 278207 auth.debug] PAM[3155]: load_function: successful load of pam_sm_authenticate
| Aug 14 14:03:32 winds05 login: [ID 387781 auth.debug] PAM[3155]: load_modules(29430, pam_sm_authenticate)=/usr/lib/security/pam_unix_auth.so.1
| Aug 14 14:03:32 winds05 login: [ID 278207 auth.debug] PAM[3155]: load_function: successful load of pam_sm_authenticate
| Aug 14 14:03:32 winds05 login: [ID 744822 auth.debug] PAM[3155]: pam_get_user(29430, 61746500, NULL)
| 
| ==> ./remote/winds06/local4/debug <==
| Aug 14 14:01:14 winds06 slapd[24115]: [ID 925615 local4.debug] <= bdb_equality_candidates: (ipHostNumber) index_param failed (18)
| Aug 14 14:01:14 winds06 slapd[24115]: [ID 580335 local4.debug] conn=968 op=0 ENTRY dn="cn=winnb000353.win.ch.da.rtr,ou=hosts,ou=race,o=Example"
| Aug 14 14:01:14 winds06 slapd[24115]: [ID 368799 local4.debug] get_filter: conn 969 unknown attribute type=nisdomain (17)
| Aug 14 14:01:14 winds06 slapd[24115]: [ID 368799 local4.debug] get_filter: conn 970 unknown attribute type=nisdomain (17)
| Aug 14 14:01:14 winds06 slapd[24115]: [ID 368799 local4.debug] get_filter: conn 971 unknown attribute type=nisdomain (17)
| 
| ==> ./remote/10.0.1.25/auth/debug <==
| Aug 14 14:03:36 winds05 login: [ID 360225 auth.debug] PAM[3155]: pam_set_item(29430:user)
| 
| ==> ./remote/winds06/local4/debug <==
| Aug 14 14:01:15 winds06 slapd[24115]: [ID 925615 local4.debug] <= bdb_equality_candidates: (uid) index_param failed (18)
| Aug 14 14:01:15 winds06 slapd[24115]: [ID 580335 local4.debug] conn=972 op=0 ENTRY dn="uid=testme,ou=people,ou=race,o=Example"
| 
| ==> ./remote/10.0.1.25/auth/debug <==
| Aug 14 14:03:40 winds05 login: [ID 360225 auth.debug] PAM[3155]: pam_set_item(29430:authtok)
| Aug 14 14:03:40 winds05 login: [ID 360225 auth.debug] PAM[3155]: pam_set_item(29430:authtok)
| Aug 14 14:03:40 winds05 login: [ID 993814 auth.debug] PAM[3155]: pam_authenticate(29430, 0): error Authentication failed
| Aug 14 14:03:40 winds05 login: [ID 360225 auth.debug] PAM[3155]: pam_set_item(29430:authtok)
| 
| ==> ./remote/winds06/local4/debug <==
| Aug 14 14:01:20 winds06 slapd[24115]: [ID 925615 local4.debug] <= bdb_equality_candidates: (uid) index_param failed (18)
| Aug 14 14:01:20 winds06 slapd[24115]: [ID 580335 local4.debug] conn=973 op=0 ENTRY dn="uid=testme,ou=people,ou=race,o=Example"
| Aug 14 14:01:20 winds06 slapd[24115]: [ID 925615 local4.debug] <= bdb_equality_candidates: (uid) index_param failed (18)
| Aug 14 14:01:20 winds06 slapd[24115]: [ID 580335 local4.debug] conn=974 op=0 ENTRY dn="uid=testme,ou=people,ou=race,o=Example"
| Aug 14 14:01:20 winds06 slapd[24115]: [ID 925615 local4.debug] <= bdb_equality_candidates: (uid) index_param failed (18)
| Aug 14 14:01:20 winds06 slapd[24115]: [ID 580335 local4.debug] conn=975 op=0 ENTRY dn="uid=testme,ou=people,ou=race,o=Example"
| Aug 14 14:01:20 winds06 slapd[24115]: [ID 925615 local4.debug] <= bdb_equality_candidates: (uid) index_param failed (18)
| Aug 14 14:01:20 winds06 slapd[24115]: [ID 580335 local4.debug] conn=976 op=0 ENTRY dn="uid=testme,ou=people,ou=race,o=Example"
| 
| ==> ./remote/10.0.1.25/auth/debug <==
| Aug 14 14:03:44 winds05 login: [ID 360225 auth.debug] PAM[3155]: pam_set_item(29430:user)
| Aug 14 14:03:44 winds05 login: [ID 360225 auth.debug] PAM[3155]: pam_set_item(29430:ruser)
| Aug 14 14:03:44 winds05 login: [ID 360225 auth.debug] PAM[3155]: pam_set_item(29430:user_prompt)
| Aug 14 14:03:44 winds05 login: [ID 304686 auth.debug] PAM[3155]: pam_authenticate(29430, 0)
| Aug 14 14:03:44 winds05 login: [ID 387781 auth.debug] PAM[3155]: load_modules(29430, pam_sm_authenticate)=/usr/lib/security/pam_authtok_get.so.1
| Aug 14 14:03:44 winds05 login: [ID 744822 auth.debug] PAM[3155]: pam_get_user(29430, ff0000, NULL)
| Aug 14 14:03:46 winds05 login: [ID 503841 auth.debug] PAM[3155]: pam_end(29430): status = General PAM failure 
| Aug 14 14:03:46 winds05 telnetd[3153]: [ID 397042 auth.debug] PAM[3153]: pam_start(telnet,.telnet,0:28fe0) - debug = 1
| Aug 14 14:03:46 winds05 telnetd[3153]: [ID 735918 auth.debug] PAM[3153]: pam_set_item(28fe0:service)
| Aug 14 14:03:46 winds05 telnetd[3153]: [ID 735918 auth.debug] PAM[3153]: pam_set_item(28fe0:user)
| Aug 14 14:03:46 winds05 telnetd[3153]: [ID 735918 auth.debug] PAM[3153]: pam_set_item(28fe0:conv)
| Aug 14 14:03:46 winds05 telnetd[3153]: [ID 735918 auth.debug] PAM[3153]: pam_set_item(28fe0:tty)
| Aug 14 14:03:46 winds05 telnetd[3153]: [ID 735918 auth.debug] PAM[3153]: pam_set_item(28fe0:rhost)
| Aug 14 14:03:46 winds05 telnetd[3153]: [ID 304685 auth.debug] PAM[3153]: pam_close_session(28fe0, 0)
| Aug 14 14:03:46 winds05 telnetd[3153]: [ID 258799 auth.debug] PAM[3153]: load_modules(28fe0, pam_sm_close_session)=/usr/lib/security/pam_unix_session.so.1
| Aug 14 14:03:46 winds05 telnetd[3153]: [ID 213716 auth.debug] PAM[3153]: load_function: successful load of pam_sm_close_session
| Aug 14 14:03:46 winds05 telnetd[3153]: [ID 893552 auth.debug] PAM[3153]: pam_end(28fe0): status = Success
`----

Doesn't tell me much... I saw

Aug 14 14:03:40 winds05 login: [ID 993814 auth.debug] PAM[3155]: pam_authenticate(29430, 0): error Authentication failed

But why?

Anyway. Seems to be a PAM issue, not (much) related to OpenSSH.

Thanks a lot for the (not yet, but nonetheless *G*) helpful hint on how
to enable PAM debugging!

Best regards,

Alexander Skwar