new ldap users inconsistently able to auth on existing servers

[Johnny Tan]

I recently setup sssd (sssd-1.2.1-39.el5) in our environment. We have
an LDAP server running openldap-servers-2.3.43-12.el5_5.2.x86_64.

It seems that certain users can't authenticate to certain servers. All
servers have identical sssd.conf, nsswitch.conf, and system-auth-ac
files (pushed by puppet). I haven't yet found a pattern as to which
users and which servers, as it seems to be random.

I've included a couple config files.

== sssd.conf begin ==
[sssd]
config_file_version = 2
reconnection_retries = 3
sbus_timeout = 30
services = nss, pam
domains = LDAP

[nss]
filter_groups = root
filter_users = root
reconnection_retries = 3

[pam]
reconnection_retries = 3

[domain/LDAP]
id_provider = ldap
auth_provider = ldap
ldap_schema = rfc2307
ldap_uri = ldap://xxxxxxxxxxx/
ldap_search_base = dc=renttherunway,dc=com
ldap_id_use_start_tls = true
ldap_tls_reqcert = never
cache_credentials = true
enumerate = true
== sssd.conf end ==


== system-auth-ac begin ==
#%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 >= 500 quiet
auth        sufficient    pam_sss.so use_first_pass
auth        required      pam_deny.so

account     required      pam_unix.so broken_shadow
account     sufficient    pam_succeed_if.so uid < 500 quiet
account     [default=bad success=ok user_unknown=ignore] pam_sss.so
account     required      pam_permit.so

password    requisite     pam_cracklib.so try_first_pass retry=3
password    sufficient    pam_unix.so md5 shadow nullok try_first_pass
use_authtok
password    sufficient    pam_sss.so use_authtok
password    required      pam_deny.so

session     optional      pam_mkhomedir.so
session     optional      pam_keyinit.so revoke
session     required      pam_limits.so
session     [success=1 default=ignore] pam_succeed_if.so service in
crond quiet use_uid
session     sufficient    pam_sss.so
session     required      pam_unix.so
== system-auth-ac end ==


On the same server, debug level set to 5, here's an example of a
successful ssh attempt:

== successful-auth sssd_pam.log begin ==
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [accept_priv_fd_handler] (4):
Client connected to privileged pipe!
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [sss_cmd_get_version] (5):
Received client version [3].
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [sss_cmd_get_version] (5):
Offered version [3].
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_cmd_authenticate] (4):
entering pam_cmd_authenticate
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): command:
PAM_AUTHENTICATE
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): domain: (null)
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): user: jt
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): service: sshd
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): tty: ssh
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): ruser: (null)
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): rhost:
204.145.76.74
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): authtok type: 1
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): authtok size: 8
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): newauthtok type: 0
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): newauthtok size: 0
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): priv: 1
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): cli_pid: 6524
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [sss_dp_send_acct_req_create]
(4): Sending request for [LDAP][3][1][name=jt]
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [sss_dp_get_reply] (4): Got
reply (0, 0, Success) from Data Provider
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_dp_send_req] (4): Sending
request with the following data:
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): command:
PAM_AUTHENTICATE
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): domain: LDAP
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): user: jt
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): service: sshd
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): tty: ssh
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): ruser: (null)
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): rhost:
204.145.76.74
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): authtok type: 1
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): authtok size: 8
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): newauthtok type: 0
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): newauthtok size: 0
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): priv: 1
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): cli_pid: 6524
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_dom_forwarder] (4):
pam_dp_send_req returned 0
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_dp_process_reply] (4):
received: [0][LDAP]
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_reply] (4): pam_reply get called.
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_reply] (4): pam_reply get called.
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_reply] (4): blen: 21
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_cmd_acct_mgmt] (4):
entering pam_cmd_acct_mgmt
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): command:
PAM_ACCT_MGMT
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): domain: (null)
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): user: jt
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): service: sshd
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): tty: ssh
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): ruser: (null)
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): rhost:
204.145.76.74
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): authtok type: 0
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): authtok size: 0
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): newauthtok type: 0
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): newauthtok size: 0
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): priv: 1
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): cli_pid: 6524
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_dp_send_req] (4): Sending
request with the following data:
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): command:
PAM_ACCT_MGMT
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): domain: LDAP
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): user: jt
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): service: sshd
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): tty: ssh
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): ruser: (null)
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): rhost:
204.145.76.74
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): authtok type: 0
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): authtok size: 0
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): newauthtok type: 0
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): newauthtok size: 0
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): priv: 1
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): cli_pid: 6524
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_dom_forwarder] (4):
pam_dp_send_req returned 0
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_dp_process_reply] (4):
received: [0][LDAP]
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_reply] (4): pam_reply get called.
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_reply] (4): blen: 21
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_cmd_setcred] (4): entering
pam_cmd_setcred
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): command:
PAM_SETCRED
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): domain: (null)
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): user: jt
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): service: sshd
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): tty: ssh
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): ruser: (null)
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): rhost:
204.145.76.74
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): authtok type: 0
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): authtok size: 0
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): newauthtok type: 0
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): newauthtok size: 0
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): priv: 1
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): cli_pid: 6524
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [sss_dp_send_acct_req_create]
(4): Sending request for [LDAP][3][1][name=jt]
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [sss_dp_get_reply] (4): Got
reply (0, 0, Success) from Data Provider
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_dp_send_req] (4): Sending
request with the following data:
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): command:
PAM_SETCRED
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): domain: LDAP
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): user: jt
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): service: sshd
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): tty: ssh
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): ruser: (null)
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): rhost:
204.145.76.74
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): authtok type: 0
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): authtok size: 0
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): newauthtok type: 0
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): newauthtok size: 0
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): priv: 1
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): cli_pid: 6524
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_dom_forwarder] (4):
pam_dp_send_req returned 0
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_dp_process_reply] (4):
received: [0][LDAP]
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_reply] (4): pam_reply get called.
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_reply] (4): blen: 21
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_cmd_open_session] (4):
entering pam_cmd_open_session
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): command:
PAM_OPEN_SESSION
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): domain: (null)
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): user: jt
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): service: sshd
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): tty: ssh
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): ruser: (null)
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): rhost:
204.145.76.74
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): authtok type: 0
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): authtok size: 0
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): newauthtok type: 0
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): newauthtok size: 0
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): priv: 1
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): cli_pid: 6524
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_dp_send_req] (4): Sending
request with the following data:
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): command:
PAM_OPEN_SESSION
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): domain: LDAP
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): user: jt
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): service: sshd
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): tty: ssh
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): ruser: (null)
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): rhost:
204.145.76.74
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): authtok type: 0
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): authtok size: 0
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): newauthtok type: 0
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): newauthtok size: 0
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): priv: 1
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): cli_pid: 6524
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_dom_forwarder] (4):
pam_dp_send_req returned 0
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_dp_process_reply] (4):
received: [0][LDAP]
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_reply] (4): pam_reply get called.
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_reply] (4): blen: 21
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [accept_fd_handler] (4): Client
connected!
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [sss_cmd_get_version] (5):
Received client version [3].
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [sss_cmd_get_version] (5):
Offered version [3].
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_cmd_setcred] (4): entering
pam_cmd_setcred
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): command:
PAM_SETCRED
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): domain: (null)
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): user: jt
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): service: sshd
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): tty: ssh
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): ruser: (null)
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): rhost:
204.145.76.74
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): authtok type: 0
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): authtok size: 0
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): newauthtok type: 0
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): newauthtok size: 0
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): priv: 0
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): cli_pid: 6526
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [sss_dp_send_acct_req_create]
(4): Sending request for [LDAP][3][1][name=jt]
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [sss_dp_get_reply] (4): Got
reply (0, 0, Success) from Data Provider
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_dp_send_req] (4): Sending
request with the following data:
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): command:
PAM_SETCRED
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): domain: LDAP
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): user: jt
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): service: sshd
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): tty: ssh
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): ruser: (null)
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): rhost:
204.145.76.74
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): authtok type: 0
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): authtok size: 0
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): newauthtok type: 0
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): newauthtok size: 0
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): priv: 0
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_print_data] (4): cli_pid: 6526
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_dom_forwarder] (4):
pam_dp_send_req returned 0
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_dp_process_reply] (4):
received: [0][LDAP]
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_reply] (4): pam_reply get called.
(Fri Jun 17 21:05:49 2011) [sssd[pam]] [pam_reply] (4): blen: 21
==

And same server, different user, just a couple minutes later (but this
user 'iambot' can ssh/auth to other identically-configured servers):

== failed-auth sssd_pam.log begin ==
(Fri Jun 17 21:07:25 2011) [sssd[pam]] [accept_priv_fd_handler] (4):
Client connected to privileged pipe!
(Fri Jun 17 21:07:25 2011) [sssd[pam]] [sss_cmd_get_version] (5):
Received client version [3].
(Fri Jun 17 21:07:25 2011) [sssd[pam]] [sss_cmd_get_version] (5):
Offered version [3].
(Fri Jun 17 21:07:25 2011) [sssd[pam]] [pam_cmd_authenticate] (4):
entering pam_cmd_authenticate
(Fri Jun 17 21:07:25 2011) [sssd[pam]] [pam_print_data] (4): command:
PAM_AUTHENTICATE
(Fri Jun 17 21:07:25 2011) [sssd[pam]] [pam_print_data] (4): domain: (null)
(Fri Jun 17 21:07:25 2011) [sssd[pam]] [pam_print_data] (4): user: iambot
(Fri Jun 17 21:07:25 2011) [sssd[pam]] [pam_print_data] (4): service: sshd
(Fri Jun 17 21:07:25 2011) [sssd[pam]] [pam_print_data] (4): tty: ssh
(Fri Jun 17 21:07:25 2011) [sssd[pam]] [pam_print_data] (4): ruser: (null)
(Fri Jun 17 21:07:25 2011) [sssd[pam]] [pam_print_data] (4): rhost:
204.145.76.74
(Fri Jun 17 21:07:25 2011) [sssd[pam]] [pam_print_data] (4): authtok type: 1
(Fri Jun 17 21:07:25 2011) [sssd[pam]] [pam_print_data] (4): authtok size: 16
(Fri Jun 17 21:07:25 2011) [sssd[pam]] [pam_print_data] (4): newauthtok type: 0
(Fri Jun 17 21:07:25 2011) [sssd[pam]] [pam_print_data] (4): newauthtok size: 0
(Fri Jun 17 21:07:25 2011) [sssd[pam]] [pam_print_data] (4): priv: 1
(Fri Jun 17 21:07:25 2011) [sssd[pam]] [pam_print_data] (4): cli_pid: 6564
(Fri Jun 17 21:07:25 2011) [sssd[pam]] [sss_dp_send_acct_req_create]
(4): Sending request for [LDAP][3][1][name=iambot]
(Fri Jun 17 21:07:25 2011) [sssd[pam]] [sss_dp_get_reply] (4): Got
reply (1, 14, Init Groups Failed) from Data Provider
(Fri Jun 17 21:07:25 2011) [sssd[pam]] [pam_check_user_dp_callback]
(2): Unable to get information from Data Provider
Error: 1, 14, Init Groups Failed
(Fri Jun 17 21:07:25 2011) [sssd[pam]] [pam_dp_send_req] (4): Sending
request with the following data:
(Fri Jun 17 21:07:25 2011) [sssd[pam]] [pam_print_data] (4): command:
PAM_AUTHENTICATE
(Fri Jun 17 21:07:25 2011) [sssd[pam]] [pam_print_data] (4): domain: LDAP
(Fri Jun 17 21:07:25 2011) [sssd[pam]] [pam_print_data] (4): user: iambot
(Fri Jun 17 21:07:25 2011) [sssd[pam]] [pam_print_data] (4): service: sshd
(Fri Jun 17 21:07:25 2011) [sssd[pam]] [pam_print_data] (4): tty: ssh
(Fri Jun 17 21:07:25 2011) [sssd[pam]] [pam_print_data] (4): ruser: (null)
(Fri Jun 17 21:07:25 2011) [sssd[pam]] [pam_print_data] (4): rhost:
204.145.76.74
(Fri Jun 17 21:07:25 2011) [sssd[pam]] [pam_print_data] (4): authtok type: 1
(Fri Jun 17 21:07:25 2011) [sssd[pam]] [pam_print_data] (4): authtok size: 16
(Fri Jun 17 21:07:25 2011) [sssd[pam]] [pam_print_data] (4): newauthtok type: 0
(Fri Jun 17 21:07:25 2011) [sssd[pam]] [pam_print_data] (4): newauthtok size: 0
(Fri Jun 17 21:07:25 2011) [sssd[pam]] [pam_print_data] (4): priv: 1
(Fri Jun 17 21:07:25 2011) [sssd[pam]] [pam_print_data] (4): cli_pid: 6564
(Fri Jun 17 21:07:25 2011) [sssd[pam]] [pam_dom_forwarder] (4):
pam_dp_send_req returned 0
(Fri Jun 17 21:07:25 2011) [sssd[pam]] [pam_dp_process_reply] (4):
received: [9][LDAP]
(Fri Jun 17 21:07:25 2011) [sssd[pam]] [pam_reply] (4): pam_reply get called.
(Fri Jun 17 21:07:25 2011) [sssd[pam]]
[sysdb_cache_auth_get_attrs_done] (4): Cached credentials not
available.
(Fri Jun 17 21:07:25 2011) [sssd[pam]] [pam_reply] (4): pam_reply get called.
(Fri Jun 17 21:07:25 2011) [sssd[pam]] [pam_reply] (4): blen: 21
== failed-auth end ==


My own hypothesis is that the successful auth is using cached
credentials (since jt has logged in previously), but the failed one is
from a user that has not successfully logged into the server. But if
I'm correct, what I don't get is why sssd cannot pull information from
the LDAP provider. It's online and serving out requests, and the
failed user on this machine has successfully logged in for the first
time on a couple other servers in the same timeframe.

Thoughts?
johnny