On Tue, Sep 27, 2011 at 03:56:57PM +0200, Ondrej Valousek wrote:
> Hi List,
>
> I experience sometimes sssd reports certain users as not existing -
> symptoms in log are the following:
That's because at the time the request came, the SSSD back end was
marked as "offline" and the user was not cached.
Yes, as you suspect, here is your problem: "ldap_result gave -1, something bad
happend"
However, I don't know the reason why that is.
> (Tue Sep 27 15:30:17 2011) [sssd[nss]] [accept_fd_handler] (4): Client
> connected!
> (Tue Sep 27 15:30:17 2011) [sssd[nss]] [sss_cmd_get_version] (5):
> Received client version [1].
> (Tue Sep 27 15:30:17 2011) [sssd[nss]] [sss_cmd_get_version] (5):
> Offered version [1].
> (Tue Sep 27 15:30:17 2011) [sssd[nss]] [nss_cmd_getpwnam] (4):
> Requesting info for [paulr] from [<ALL>]
> (Tue Sep 27 15:30:17 2011) [sssd[nss]] [nss_cmd_getpwnam_search] (4):
> Requesting info for [paulr@default]
> (Tue Sep 27 15:30:17 2011) [sssd[nss]] [sss_dp_send_acct_req_create]
> (4): Sending request for [default][4097][1][name=paulr]
> (Tue Sep 27 15:30:17 2011) [sssd[nss]] [sss_dp_get_reply] (4): Got
> reply (1, 11, Fast reply - offline) from Data Provider
>
> In this case sssd reports no such a user 'paulr'.
> Also, the connection to the ldap server (AD, Windows Server 2008)
> seems to be quite unreliable:
> (Tue Sep 27 14:26:40 2011) [sssd[be[default]]] [child_sig_handler]
> (4): child [20098] finished successfully.
> (Tue Sep 27 14:26:40 2011) [sssd[be[default]]] [fo_set_port_status]
> (4): Marking port 389 of server 'dcpra1.dublin.ad.s3group.com' as
> 'working' (Tue Sep 27 14:26:40 2011) [sssd[be[default]]]
> [set_server_common_status] (4): Marking server
> 'dcpra1.dublin.ad.s3group.com' as 'working' (Tue Sep 27 14:41:51
> 2011) [sssd[be[default]]] [sdap_process_result] (4): ldap_result gave
> -1, something bad happend!
> (Tue Sep 27 14:43:50 2011) [sssd[be[default]]] [be_get_account_info]
> (4): Got request for [4099][1][name=postfix]
> (Tue Sep 27 14:43:50 2011) [sssd[be[default]]]
> [fo_resolve_service_send] (4): Trying to resolve service 'LDAP'
> (Tue Sep 27 14:43:50 2011) [sssd[be[default]]]
> [be_resolve_server_done] (4): Found address for server
>
dcpra1.dublin.ad.s3group.com:
> [192.168.60.203]
> (Tue Sep 27 14:43:50 2011) [sssd[be[default]]]
> [fo_resolve_service_send] (4): Trying to resolve service 'KERBEROS'
> (Tue Sep 27 14:43:50 2011) [sssd[be[default]]] [fo_set_port_status]
> (4): Marking port 389 of server 'dcpra1.dublin.ad.s3group.com' as
> 'not working' (Tue Sep 27 14:43:50 2011) [sssd[be[default]]]
> [fo_resolve_service_send] (4): Trying to resolve service 'LDAP'
> (Tue Sep 27 14:43:50 2011) [sssd[be[default]]]
> [fo_resolve_service_send] (1): No available servers for service
> 'LDAP'
> (Tue Sep 27 14:43:50 2011) [sssd[be[default]]]
> [sdap_id_op_connect_done] (1): Failed to connect, going offline (5
> [Input/output error]) (Tue Sep 27 14:43:50 2011) [sssd[be[default]]]
> [be_run_offline_cb] (3): Going offline. Running callbacks.
> (Tue Sep 27 14:43:50 2011) [sssd[be[default]]] [acctinfo_callback]
> (4): Request processed. Returned 1,11,Offline
> (Tue Sep 27 14:43:50 2011) [sssd[be[default]]]
> [remove_krb5_info_files] (5): Could not remove
> [/var/lib/sss/pubconf/kpasswdinfo.DUBLIN.AD.S3GROUP.COM], [2][No such
> file or directory]
> (Tue Sep 27 14:43:50 2011) [sssd[be[default]]]
> [remove_krb5_info_files] (5): Could not remove
> [/var/lib/sss/pubconf/kdcinfo.DUBLIN.AD.S3GROUP.COM], [2][No such file
> or directory]
> (Tue Sep 27 14:43:50 2011) [sssd[be[default]]]
> [remove_krb5_info_files] (5): Could not remove
> [/var/lib/sss/pubconf/kpasswdinfo.DUBLIN.AD.S3GROUP.COM], [2][No such
> file or directory]
> (Tue Sep 27 15:30:17 2011) [sssd[be[default]]] [be_get_account_info]
> (4): Got request for [4097][1][name=paulr]
> (Tue Sep 27 15:30:17 2011) [sssd[be[default]]] [be_get_account_info]
> (4): Request processed. Returned 1,11,Fast reply - offline
> (Tue Sep 27 15:30:17 2011) [sssd[be[default]]]
> [fo_resolve_service_send] (4): Trying to resolve service 'LDAP'
> (Tue Sep 27 15:30:17 2011) [sssd[be[default]]] [get_port_status] (4):
> Reseting the status of port 389 for server
> 'dcpra1.dublin.ad.s3group.com' (Tue Sep 27 15:30:17 2011)
> [sssd[be[default]]] [be_resolve_server_done] (4): Found address for
> server
dcpra1.dublin.ad.s3group.com:
> [192.168.60.203]
> (Tue Sep 27 15:30:17 2011) [sssd[be[default]]]
> [fo_resolve_service_send] (4): Trying to resolve service 'KERBEROS'
> (Tue Sep 27 15:30:17 2011) [sssd[be[default]]]
> [be_resolve_server_done] (4): Found address for server
>
dcpra1.dublin.ad.s3group.com:
> [192.168.60.203]
> (Tue Sep 27 15:30:18 2011) [sssd[be[default]]] [sasl_bind_send] (4):
> Executing sasl bind mech: GSSAPI, user: draco$(a)DUBLIN.AD.S3GROUP.COM
> (Tue Sep 27 15:30:18 2011) [sssd[be[default]]] [child_sig_handler]
> (4): child [20584] finished successfully.
> (Tue Sep 27 15:30:18 2011) [sssd[be[default]]] [fo_set_port_status]
> (4): Marking port 389 of server 'dcpra1.dublin.ad.s3group.com' as
> 'working' (Tue Sep 27 15:30:18 2011) [sssd[be[default]]]
> [set_server_common_status] (4): Marking server
> 'dcpra1.dublin.ad.s3group.com' as 'working' (Tue Sep 27 15:38:40
> 2011) [sssd[be[default]]] [be_get_account_info] (4): Got request for
> [4098][1][idnumber=203]
> (Tue Sep 27 15:38:40 2011) [sssd[be[default]]]
> [sysdb_attrs_primary_name] (1): Could not determine primary name:
> [22][Invalid argument] (Tue Sep 27 15:38:40 2011) [sssd[be[default]]]
> [sdap_save_user] (1): Failed to save the user - entry has no name
> attribute
> (Tue Sep 27 15:38:40 2011) [sssd[be[default]]] [sdap_save_user] (2):
> Failed to save user [Unknown]
>
> Is there any help to this? The client is a RHEL-6 machine.
> Thanks,
What debug_level do you run with? Cau you raise it to 9 so that we see
more info?
_______________________________________________
sssd-devel mailing list
sssd-devel(a)lists.fedorahosted.org
https://fedorahosted.org/mailman/listinfo/sssd-devel
--
Thank you
Jan Zeleny
Red Hat Software Engineer
Brno, Czech Republic