[Freeipa-users] AD users cannot log in: PAM permission denied
Guertin, David S.
guertin at middlebury.edu
Wed Mar 18 18:28:28 UTC 2015
I've almost got AD integration going, except for the minor detail that no one can log in. When an AD user tries to SSH in to the IPA server, /var/log/secure shows:
------------------------------------------
Mar 18 13:59:08 genet sshd[21335]: pam_unix(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=tundra.middlebury.edu user=MIDD\guertin-s
Mar 18 13:59:09 genet sshd[21335]: pam_sss(sshd:auth): authentication success; logname= uid=0 euid=0 tty=ssh ruser= rhost=tundra.middlebury.edu user=MIDD\guertin-s
Mar 18 13:59:10 genet sshd[21335]: pam_sss(sshd:account): Access denied for user MIDD\guertin-s: 6 (Permission denied)
Mar 18 13:59:10 genet sshd[21335]: Failed password for MIDD\\guertin-s from 140.233.6.66 port 59707 ssh2
Mar 18 13:59:10 genet sshd[21335]: fatal: Access denied for user MIDD\\\\guertin-s by PAM account configuration [preauth]
------------------------------------------
So pam_sss is responding with "permission denied". /etc/pam.d/password-auth contains:
------------------------------------------
#%PAM-1.0
# This file is auto-generated.
# User changes will be destroyed the next time authconfig is run.
auth required pam_env.so
auth sufficient pam_unix.so nullok try_first_pass
auth requisite pam_succeed_if.so uid >= 1000 quiet_success
auth sufficient pam_sss.so use_first_pass
auth required pam_deny.so
account required pam_unix.so
account sufficient pam_localuser.so
account sufficient pam_succeed_if.so uid < 1000 quiet
account [default=bad success=ok user_unknown=ignore] pam_sss.so
account required pam_permit.so
password requisite pam_pwquality.so try_first_pass local_users_only retry=3 authtok_type=
password sufficient pam_unix.so sha512 shadow nullok try_first_pass use_authtok
password sufficient pam_sss.so use_authtok
password required pam_deny.so
session optional pam_keyinit.so revoke
session required pam_limits.so
-session optional pam_systemd.so
session optional pam_oddjob_mkhomedir.so umask=0077
session [success=1 default=ignore] pam_succeed_if.so service in crond quiet use_uid
session required pam_unix.so
session optional pam_sss.so
------------------------------------------
And with debug_level = 10, /var/log/sssd/sssd_pam.log shows:
------------------------------------------
(Wed Mar 18 13:59:08 2015) [sssd[pam]] [pam_cmd_authenticate] (0x0100): entering pam_cmd_authenticate
(Wed Mar 18 13:59:08 2015) [sssd[pam]] [sss_parse_name_for_domains] (0x0200): name 'MIDD\guertin-s' matched expression for domain 'middlebury.edu', user is guertin-s
(Wed Mar 18 13:59:08 2015) [sssd[pam]] [pam_print_data] (0x0100): command: PAM_AUTHENTICATE
(Wed Mar 18 13:59:08 2015) [sssd[pam]] [pam_print_data] (0x0100): domain: middlebury.edu
(Wed Mar 18 13:59:08 2015) [sssd[pam]] [pam_print_data] (0x0100): user: guertin-s
(Wed Mar 18 13:59:08 2015) [sssd[pam]] [pam_print_data] (0x0100): service: sshd
(Wed Mar 18 13:59:08 2015) [sssd[pam]] [pam_print_data] (0x0100): tty: ssh
(Wed Mar 18 13:59:08 2015) [sssd[pam]] [pam_print_data] (0x0100): ruser: not set
(Wed Mar 18 13:59:08 2015) [sssd[pam]] [pam_print_data] (0x0100): rhost: tundra.middlebury.edu
(Wed Mar 18 13:59:08 2015) [sssd[pam]] [pam_print_data] (0x0100): authtok type: 1
(Wed Mar 18 13:59:08 2015) [sssd[pam]] [pam_print_data] (0x0100): newauthtok type: 0
(Wed Mar 18 13:59:08 2015) [sssd[pam]] [pam_print_data] (0x0100): priv: 1
(Wed Mar 18 13:59:08 2015) [sssd[pam]] [pam_print_data] (0x0100): cli_pid: 21335
(Wed Mar 18 13:59:08 2015) [sssd[pam]] [pam_print_data] (0x0100): logon name: MIDD\guertin-s
(Wed Mar 18 13:59:08 2015) [sssd[pam]] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/USER/middlebury.edu/guertin-s]
(Wed Mar 18 13:59:08 2015) [sssd[pam]] [sss_dp_issue_request] (0x0400): Issuing request for [0x7fc92c76bed0:3:guertin-s at middlebury.edu]
(Wed Mar 18 13:59:08 2015) [sssd[pam]] [sss_dp_get_account_msg] (0x0400): Creating request for [middlebury.edu][3][1][name=guertin-s]
(Wed Mar 18 13:59:08 2015) [sssd[pam]] [sbus_add_timeout] (0x2000): 0x7fc92e921240
(Wed Mar 18 13:59:08 2015) [sssd[pam]] [sss_dp_internal_get_send] (0x0400): Entering request [0x7fc92c76bed0:3:guertin-s at middlebury.edu]
(Wed Mar 18 13:59:08 2015) [sssd[pam]] [sbus_remove_timeout] (0x2000): 0x7fc92e921240
(Wed Mar 18 13:59:08 2015) [sssd[pam]] [sbus_dispatch] (0x4000): dbus conn: 0x7fc92e920450
(Wed Mar 18 13:59:08 2015) [sssd[pam]] [sbus_dispatch] (0x4000): Dispatching.
(Wed Mar 18 13:59:08 2015) [sssd[pam]] [sss_dp_get_reply] (0x1000): Got reply from Data Provider - DP error code: 0 errno: 0 error message: Success
(Wed Mar 18 13:59:08 2015) [sssd[pam]] [pam_check_user_search] (0x0100): Requesting info for [guertin-s at middlebury.edu]
(Wed Mar 18 13:59:08 2015) [sssd[pam]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7fc92e924ac0
(Wed Mar 18 13:59:08 2015) [sssd[pam]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7fc92e924bf0
(Wed Mar 18 13:59:08 2015) [sssd[pam]] [ldb] (0x4000): Running timer event 0x7fc92e924ac0 "ltdb_callback"
(Wed Mar 18 13:59:08 2015) [sssd[pam]] [ldb] (0x4000): Destroying timer event 0x7fc92e924bf0 "ltdb_timeout"
(Wed Mar 18 13:59:08 2015) [sssd[pam]] [ldb] (0x4000): Ending timer event 0x7fc92e924ac0 "ltdb_callback"
(Wed Mar 18 13:59:08 2015) [sssd[pam]] [pam_check_user_search] (0x0400): Returning info for user [guertin-s at middlebury.edu]
(Wed Mar 18 13:59:08 2015) [sssd[pam]] [pd_set_primary_name] (0x0400): User's primary name is guertin-s at middlebury.edu
(Wed Mar 18 13:59:08 2015) [sssd[pam]] [pam_initgr_cache_set] (0x2000): [guertin-s at middlebury.edu] added to PAM initgroup cache
(Wed Mar 18 13:59:08 2015) [sssd[pam]] [pam_dp_send_req] (0x0100): Sending request with the following data:
(Wed Mar 18 13:59:08 2015) [sssd[pam]] [pam_print_data] (0x0100): command: PAM_AUTHENTICATE
(Wed Mar 18 13:59:08 2015) [sssd[pam]] [pam_print_data] (0x0100): domain: middlebury.edu
(Wed Mar 18 13:59:08 2015) [sssd[pam]] [pam_print_data] (0x0100): user: guertin-s at middlebury.edu
(Wed Mar 18 13:59:08 2015) [sssd[pam]] [pam_print_data] (0x0100): service: sshd
(Wed Mar 18 13:59:08 2015) [sssd[pam]] [pam_print_data] (0x0100): tty: ssh
(Wed Mar 18 13:59:08 2015) [sssd[pam]] [pam_print_data] (0x0100): ruser: not set
(Wed Mar 18 13:59:08 2015) [sssd[pam]] [pam_print_data] (0x0100): rhost: tundra.middlebury.edu
(Wed Mar 18 13:59:08 2015) [sssd[pam]] [pam_print_data] (0x0100): authtok type: 1
(Wed Mar 18 13:59:08 2015) [sssd[pam]] [pam_print_data] (0x0100): newauthtok type: 0
(Wed Mar 18 13:59:08 2015) [sssd[pam]] [pam_print_data] (0x0100): priv: 1
(Wed Mar 18 13:59:08 2015) [sssd[pam]] [pam_print_data] (0x0100): cli_pid: 21335
(Wed Mar 18 13:59:08 2015) [sssd[pam]] [pam_print_data] (0x0100): logon name: MIDD\guertin-s
(Wed Mar 18 13:59:08 2015) [sssd[pam]] [sbus_add_timeout] (0x2000): 0x7fc92e928530
(Wed Mar 18 13:59:08 2015) [sssd[pam]] [pam_dom_forwarder] (0x0100): pam_dp_send_req returned 0
(Wed Mar 18 13:59:08 2015) [sssd[pam]] [sss_dp_req_destructor] (0x0400): Deleting request: [0x7fc92c76bed0:3:guertin-s at middlebury.edu]
(Wed Mar 18 13:59:09 2015) [sssd[pam]] [sbus_remove_timeout] (0x2000): 0x7fc92e928530
(Wed Mar 18 13:59:09 2015) [sssd[pam]] [sbus_dispatch] (0x4000): dbus conn: 0x7fc92e920450
(Wed Mar 18 13:59:09 2015) [sssd[pam]] [sbus_dispatch] (0x4000): Dispatching.
(Wed Mar 18 13:59:09 2015) [sssd[pam]] [pam_dp_process_reply] (0x0100): received: [0][middlebury.edu]
(Wed Mar 18 13:59:09 2015) [sssd[pam]] [pam_reply] (0x0200): pam_reply called with result [0].
(Wed Mar 18 13:59:09 2015) [sssd[pam]] [ldb] (0x4000): start ldb transaction (nesting: 0)
(Wed Mar 18 13:59:09 2015) [sssd[pam]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7fc92e9281b0
(Wed Mar 18 13:59:09 2015) [sssd[pam]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7fc92e928270
(Wed Mar 18 13:59:09 2015) [sssd[pam]] [ldb] (0x4000): Running timer event 0x7fc92e9281b0 "ltdb_callback"
(Wed Mar 18 13:59:09 2015) [sssd[pam]] [ldb] (0x4000): Destroying timer event 0x7fc92e928270 "ltdb_timeout"
(Wed Mar 18 13:59:09 2015) [sssd[pam]] [ldb] (0x4000): Ending timer event 0x7fc92e9281b0 "ltdb_callback"
(Wed Mar 18 13:59:09 2015) [sssd[pam]] [ldb] (0x4000): commit ldb transaction (nesting: 0)
(Wed Mar 18 13:59:09 2015) [sssd[pam]] [pam_reply] (0x0200): pam_reply called with result [0].
(Wed Mar 18 13:59:09 2015) [sssd[pam]] [pam_reply] (0x0200): blen: 79
(Wed Mar 18 13:59:09 2015) [sssd[pam]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x7fc92e931f40][19]
(Wed Mar 18 13:59:09 2015) [sssd[pam]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x7fc92e931f40][19]
(Wed Mar 18 13:59:09 2015) [sssd[pam]] [pam_cmd_acct_mgmt] (0x0100): entering pam_cmd_acct_mgmt
(Wed Mar 18 13:59:09 2015) [sssd[pam]] [sss_parse_name_for_domains] (0x0200): name 'MIDD\guertin-s' matched expression for domain 'middlebury.edu', user is guertin-s
(Wed Mar 18 13:59:09 2015) [sssd[pam]] [pam_print_data] (0x0100): command: PAM_ACCT_MGMT
(Wed Mar 18 13:59:09 2015) [sssd[pam]] [pam_print_data] (0x0100): domain: middlebury.edu
(Wed Mar 18 13:59:09 2015) [sssd[pam]] [pam_print_data] (0x0100): user: guertin-s
(Wed Mar 18 13:59:09 2015) [sssd[pam]] [pam_print_data] (0x0100): service: sshd
(Wed Mar 18 13:59:09 2015) [sssd[pam]] [pam_print_data] (0x0100): tty: ssh
(Wed Mar 18 13:59:09 2015) [sssd[pam]] [pam_print_data] (0x0100): ruser: not set
(Wed Mar 18 13:59:09 2015) [sssd[pam]] [pam_print_data] (0x0100): rhost: tundra.middlebury.edu
(Wed Mar 18 13:59:09 2015) [sssd[pam]] [pam_print_data] (0x0100): authtok type: 0
(Wed Mar 18 13:59:09 2015) [sssd[pam]] [pam_print_data] (0x0100): newauthtok type: 0
(Wed Mar 18 13:59:09 2015) [sssd[pam]] [pam_print_data] (0x0100): priv: 1
(Wed Mar 18 13:59:09 2015) [sssd[pam]] [pam_print_data] (0x0100): cli_pid: 21335
(Wed Mar 18 13:59:09 2015) [sssd[pam]] [pam_print_data] (0x0100): logon name: MIDD\guertin-s
(Wed Mar 18 13:59:09 2015) [sssd[pam]] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/USER/middlebury.edu/guertin-s]
(Wed Mar 18 13:59:09 2015) [sssd[pam]] [sss_dp_issue_request] (0x0400): Issuing request for [0x7fc92c76bed0:3:guertin-s at middlebury.edu]
(Wed Mar 18 13:59:09 2015) [sssd[pam]] [sss_dp_get_account_msg] (0x0400): Creating request for [middlebury.edu][3][1][name=guertin-s]
(Wed Mar 18 13:59:09 2015) [sssd[pam]] [sbus_add_timeout] (0x2000): 0x7fc92e929bc0
(Wed Mar 18 13:59:09 2015) [sssd[pam]] [sss_dp_internal_get_send] (0x0400): Entering request [0x7fc92c76bed0:3:guertin-s at middlebury.edu]
(Wed Mar 18 13:59:10 2015) [sssd[pam]] [sbus_remove_timeout] (0x2000): 0x7fc92e929bc0
(Wed Mar 18 13:59:10 2015) [sssd[pam]] [sbus_dispatch] (0x4000): dbus conn: 0x7fc92e920450
(Wed Mar 18 13:59:10 2015) [sssd[pam]] [sbus_dispatch] (0x4000): Dispatching.
(Wed Mar 18 13:59:10 2015) [sssd[pam]] [sss_dp_get_reply] (0x1000): Got reply from Data Provider - DP error code: 0 errno: 0 error message: Success
(Wed Mar 18 13:59:10 2015) [sssd[pam]] [pam_check_user_search] (0x0100): Requesting info for [guertin-s at middlebury.edu]
(Wed Mar 18 13:59:10 2015) [sssd[pam]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x7fc92e9249e0
(Wed Mar 18 13:59:10 2015) [sssd[pam]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x7fc92e924b10
(Wed Mar 18 13:59:10 2015) [sssd[pam]] [ldb] (0x4000): Running timer event 0x7fc92e9249e0 "ltdb_callback"
(Wed Mar 18 13:59:10 2015) [sssd[pam]] [ldb] (0x4000): Destroying timer event 0x7fc92e924b10 "ltdb_timeout"
(Wed Mar 18 13:59:10 2015) [sssd[pam]] [ldb] (0x4000): Ending timer event 0x7fc92e9249e0 "ltdb_callback"
(Wed Mar 18 13:59:10 2015) [sssd[pam]] [pam_check_user_search] (0x0400): Returning info for user [guertin-s at middlebury.edu]
(Wed Mar 18 13:59:10 2015) [sssd[pam]] [pd_set_primary_name] (0x0400): User's primary name is guertin-s at middlebury.edu
(Wed Mar 18 13:59:10 2015) [sssd[pam]] [pam_initgr_cache_set] (0x2000): [guertin-s at middlebury.edu] added to PAM initgroup cache
(Wed Mar 18 13:59:10 2015) [sssd[pam]] [pam_dp_send_req] (0x0100): Sending request with the following data:
(Wed Mar 18 13:59:10 2015) [sssd[pam]] [pam_print_data] (0x0100): command: PAM_ACCT_MGMT
(Wed Mar 18 13:59:10 2015) [sssd[pam]] [pam_print_data] (0x0100): domain: middlebury.edu
(Wed Mar 18 13:59:10 2015) [sssd[pam]] [pam_print_data] (0x0100): user: guertin-s at middlebury.edu
(Wed Mar 18 13:59:10 2015) [sssd[pam]] [pam_print_data] (0x0100): service: sshd
(Wed Mar 18 13:59:10 2015) [sssd[pam]] [pam_print_data] (0x0100): tty: ssh
(Wed Mar 18 13:59:10 2015) [sssd[pam]] [pam_print_data] (0x0100): ruser: not set
(Wed Mar 18 13:59:10 2015) [sssd[pam]] [pam_print_data] (0x0100): rhost: tundra.middlebury.edu
(Wed Mar 18 13:59:10 2015) [sssd[pam]] [pam_print_data] (0x0100): authtok type: 0
(Wed Mar 18 13:59:10 2015) [sssd[pam]] [pam_print_data] (0x0100): newauthtok type: 0
(Wed Mar 18 13:59:10 2015) [sssd[pam]] [pam_print_data] (0x0100): priv: 1
(Wed Mar 18 13:59:10 2015) [sssd[pam]] [pam_print_data] (0x0100): cli_pid: 21335
(Wed Mar 18 13:59:10 2015) [sssd[pam]] [pam_print_data] (0x0100): logon name: MIDD\guertin-s
(Wed Mar 18 13:59:10 2015) [sssd[pam]] [sbus_add_timeout] (0x2000): 0x7fc92e936050
(Wed Mar 18 13:59:10 2015) [sssd[pam]] [pam_dom_forwarder] (0x0100): pam_dp_send_req returned 0
(Wed Mar 18 13:59:10 2015) [sssd[pam]] [sss_dp_req_destructor] (0x0400): Deleting request: [0x7fc92c76bed0:3:guertin-s at middlebury.edu]
(Wed Mar 18 13:59:10 2015) [sssd[pam]] [sbus_remove_timeout] (0x2000): 0x7fc92e936050
(Wed Mar 18 13:59:10 2015) [sssd[pam]] [sbus_dispatch] (0x4000): dbus conn: 0x7fc92e920450
(Wed Mar 18 13:59:10 2015) [sssd[pam]] [sbus_dispatch] (0x4000): Dispatching.
(Wed Mar 18 13:59:10 2015) [sssd[pam]] [pam_dp_process_reply] (0x0100): received: [6][middlebury.edu]
(Wed Mar 18 13:59:10 2015) [sssd[pam]] [pam_reply] (0x0200): pam_reply called with result [6].
(Wed Mar 18 13:59:10 2015) [sssd[pam]] [pam_reply] (0x0200): blen: 31
(Wed Mar 18 13:59:10 2015) [sssd[pam]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x7fc92e931f40][19]
(Wed Mar 18 13:59:10 2015) [sssd[pam]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x7fc92e931f40][19]
(Wed Mar 18 13:59:10 2015) [sssd[pam]] [client_recv] (0x0200): Client disconnected!
(Wed Mar 18 13:59:10 2015) [sssd[pam]] [client_destructor] (0x2000): Terminated client [0x7fc92e931f40][19]
------------------------------------------
Everything looks normal here to me, until "[pam_dp_process_reply] (0x0100): received: [6]", after which the client disconnects. Can someone help with PAM configuration to get this to work?
As described in the documentation, my ad_users group contains the group ad_users_external, which contains the AD group rhidm_users:
# ipa group-show ad_users
Group name: ad_users
Description: AD users
GID: 1447200005
Member groups: ad_users_external
# ipa group-show ad_users_external
Group name: ad_users_external
Description: AD users external map
Member of groups: ad_users
External member: rhidm_users at middlebury.edu?
David Guertin
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://listman.redhat.com/archives/freeipa-users/attachments/20150318/03e8abad/attachment.htm>
More information about the Freeipa-users
mailing list