sssd-users November 2012

sssd-users@lists.fedorahosted.org

14 participants
16 discussions

ldap_sasl_mech EXTERNAL and SSL client authc
by Michael Ströder 18 Mar '15

18 Mar '15

HI! Is it possible to use SASL/EXTERNAL when connecting to a LDAP server with StartTLS or LDAPS using client certs? In a project they have certs in all systems anyway (because of using puppet) and I'd like to let the sssd instances on all the systems authenticate to the LDAP server to restrict visibility of LDAP entries by ACL. I'd like to avoid having to set/configure passwords for each system's sssd. Ciao, Michael.

5 22

RFC: dropping upstream support of RHEL5 starting with 1.10
by Jakub Hrozek 01 May '13

01 May '13

Hi, many new features rely on library APIs and features that are only available in recent versions of SSSD dependencies. As a result, the code often needs #ifdefs and special branches in order to at least compile or run on RHEL5. So far we've been doing nightly builds also for RHEL5 and fixing issues as we were finding them. But recently we are considering dropping support for RHEL5 -- it is causing some engineering effort and at the same time the audience is probably very limited. If you are running super-stable enterprise distribution, chances are you are not all that interested in the latest and possibly very unstable SSSD version. The proposal would be to keep building and supporting the 1.9.x branch for RHEL5 and switch to using RHEL6 as the oldest supported release starting from the 1.10 upstream version. Of course we would still accept patches from any potential contributors. Any objections against the plan?

3 5

A test repository with SSSD 1.9 for RHEL-6.3
by Jakub Hrozek 21 Dec '12

21 Dec '12

Hi, even though RHEL-6.4 is still brewing, I think there might be some interest in trying out the 1.9.x series of the SSSD on RHEL-6.3. So I went ahead and built the SSSD 1.9.2 in a RHEL-6.3 buildroot: http://repos.fedorapeople.org/repos/jhrozek/sssd/epel-6/ The NVR of these test packages will be lower than those in 6.4 to keep the upgrade path clean. The only missing functionality is the PAC responder, which means this SSSD version won't be able to work with an AD domain that is in a trust relationship with an IPA 3.x domain. I had to disable the PAC responder as it requires Kerberos 1.10. Because some new functionality required tweaking the SELinux policy, you will encounter AVC denials when the new fast cache is accessed. That said, my quick smoke testing went fine and we will be glad to hear test results or bug reports. Using the repository comes with a warning - this is NOT an official Red Hat supported repository. The packages have NOT gone through formal QA. If it breaks your RHEL-6.3 installation, you get to keep the pieces. This is the repo configuration I used: -------------------------- [sssd-1.9-RHEL6.3] name=SSSD 1.9.x built for latest stable RHEL baseurl=http://repos.fedorapeople.org/repos/jhrozek/sssd/epel-6/$basearch/ enabled=1 skip_if_unavailable=1 gpgcheck=0 [sssd-1.9-RHEL6.3-source] name=SSSD 1.9.x built for latest stable RHEL - Source baseurl=http://repos.fedorapeople.org/repos/jhrozek/sssd/epel-6/SRPMS enabled=0 skip_if_unavailable=1 gpgcheck=0 -------------------------- Happy testing!

5 15

problems sssd-1.9.2
by Longina Przybyszewska 30 Nov '12

30 Nov '12

Hi, I try sssd-1.9.2 on Ubuntu-Quantal with ad-provider. So far I can login to the desktop with AD identity; Login hangs a bit because of unknown group; What is the best practice to resolve the group (set up PrimaryGroupId, run idmap????) The option 'default_shell = /bin/bash' in sssd.conf doesn't seem to have effect. I would expect it being visible In users info: getent passwd imadatestuser imadatestuser:*:332410389:332400513:IMADAtest Testesen:/home/imadatestuser: In pam.d/common-session I added entry for case of nonexistent homedir reference, and shell - so ADuser can login. There is a lot of messages in sssd_nat.c.sdu.dk - for searching principal info for lightdm in AD - Is it correct? Shouldn't be sssd awared that lightdm is a local service? ..................... Tue Nov 13 10:29:29 2012) [sssd[be[nat.c.sdu.dk]]] [sbus_message_handler] (0x4000): Received SBUS method [pamHandler] (Tue Nov 13 10:29:30 2012) [sssd[be[nat.c.sdu.dk]]] [be_pam_handler] (0x0100): Got request with the following data (Tue Nov 13 10:29:30 2012) [sssd[be[nat.c.sdu.dk]]] [pam_print_data] (0x0100): command: PAM_OPEN_SESSION (Tue Nov 13 10:29:30 2012) [sssd[be[nat.c.sdu.dk]]] [pam_print_data] (0x0100): domain: nat.c.sdu.dk (Tue Nov 13 10:29:30 2012) [sssd[be[nat.c.sdu.dk]]] [pam_print_data] (0x0100): user: imadatestuser (Tue Nov 13 10:29:30 2012) [sssd[be[nat.c.sdu.dk]]] [pam_print_data] (0x0100): service: lightdm ^^^^^^^^ (Tue Nov 13 10:29:30 2012) [sssd[be[nat.c.sdu.dk]]] [pam_print_data] (0x0100): tty: :0 (Tue Nov 13 10:29:30 2012) [sssd[be[nat.c.sdu.dk]]] [pam_print_data] (0x0100): ruser: (Tue Nov 13 10:29:30 2012) [sssd[be[nat.c.sdu.dk]]] [pam_print_data] (0x0100): rhost: (Tue Nov 13 10:29:30 2012) [sssd[be[nat.c.sdu.dk]]] [pam_print_data] (0x0100): authtok type: 0 (Tue Nov 13 10:29:30 2012) [sssd[be[nat.c.sdu.dk]]] [pam_print_data] (0x0100): authtok size: 0 (Tue Nov 13 10:29:30 2012) [sssd[be[nat.c.sdu.dk]]] [pam_print_data] (0x0100): newauthtok type: 0 (Tue Nov 13 10:29:30 2012) [sssd[be[nat.c.sdu.dk]]] [pam_print_data] (0x0100): newauthtok size: 0 (Tue Nov 13 10:29:30 2012) [sssd[be[nat.c.sdu.dk]]] [pam_print_data] (0x0100): priv: 1 (Tue Nov 13 10:29:30 2012) [sssd[be[nat.c.sdu.dk]]] [pam_print_data] (0x0100): cli_pid: 2564 (Tue Nov 13 10:29:30 2012) [sssd[be[nat.c.sdu.dk]]] [be_pam_handler] (0x0100): Sending result [0][nat.c.sdu.dk] (Tue Nov 13 10:29:30 2012) [sssd[be[nat.c.sdu.dk]]] [sbus_dispatch] (0x4000): dbus conn: 7063D0 (Tue Nov 13 10:29:30 2012) [sssd[be[nat.c.sdu.dk]]] [sbus_dispatch] (0x4000): Dispatching. (Tue Nov 13 10:29:30 2012) [sssd[be[nat.c.sdu.dk]]] [sbus_message_handler] (0x4000): Received SBUS method [getDomains] (Tue Nov 13 10:29:30 2012) [sssd[be[nat.c.sdu.dk]]] [be_get_subdomains] (0x2000): Undefined backend target. (Tue Nov 13 10:29:30 2012) [sssd[be[nat.c.sdu.dk]]] [sbus_dispatch] (0x4000): dbus conn: 7063D0 (Tue Nov 13 10:29:30 2012) [sssd[be[nat.c.sdu.dk]]] [sbus_dispatch] (0x4000): Dispatching. (Tue Nov 13 10:29:30 2012) [sssd[be[nat.c.sdu.dk]]] [sbus_message_handler] (0x4000): Received SBUS method [getAccountInfo] (Tue Nov 13 10:29:30 2012) [sssd[be[nat.c.sdu.dk]]] [be_get_account_info] (0x0100): Got request for [4099][1][name=lightdm] (Tue Nov 13 10:29:30 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_id_op_connect_step] (0x4000): reusing cached connection (Tue Nov 13 10:29:30 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_initgr_send] (0x4000): Retrieving info for initgroups call (Tue Nov 13 10:29:30 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_initgr_next_base] (0x0400): Searching for users with base [ou=ADUsers,dc=nat,dc=c,dc=sdu,dc=dk] (Tue Nov 13 10:29:30 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(sAMAccountName=lightdm)(objectclass=person))][ou=ADUsers,dc=nat,dc=c,dc=sdu,dc=dk].^ ^^^^^^^^^^^^^^ (Tue Nov 13 10:29:30 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectClass] (Tue Nov 13 10:29:30 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [sAMAccountName] (Tue Nov 13 10:29:30 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [unixUserPassword] (Tue Nov 13 10:29:30 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uidNumber] (Tue Nov 13 10:29:30 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gidNumber] (Tue Nov 13 10:29:30 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gecos] (Tue Nov 13 10:29:30 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [unixHomeDirectory] (Tue Nov 13 10:29:30 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [loginShell] (Tue Nov 13 10:29:30 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userPrincipalName] (Tue Nov 13 10:29:30 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [name] (Tue Nov 13 10:29:30 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [memberOf] (Tue Nov 13 10:29:30 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectGUID] (Tue Nov 13 10:29:30 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectSID] (Tue Nov 13 10:29:30 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [primaryGroupID] (Tue Nov 13 10:29:30 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [whenChanged] (Tue Nov 13 10:29:30 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uSNChanged] (Tue Nov 13 10:29:30 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [accountExpires] (Tue Nov 13 10:29:30 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userAccountControl] (Tue Nov 13 10:29:30 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 13 (Tue Nov 13 10:29:30 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_process_result] (0x2000): Trace: sh[0x6e8e00], connected[1], ops[0x76c190], ldap[0x713300] (Tue Nov 13 10:29:30 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT] (Tue Nov 13 10:29:30 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set (Tue Nov 13 10:29:30 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_initgr_user] (0x4000): Receiving info for the user (Tue Nov 13 10:29:30 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_id_op_done] (0x4000): releasing operation connection (Tue Nov 13 10:29:30 2012) [sssd[be[nat.c.sdu.dk]]] [ldb] (0x4000): tevent: Added timed event "ltdb_callback": 0x7555e0 (Tue Nov 13 10:29:30 2012) [sssd[be[nat.c.sdu.dk]]] [ldb] (0x4000): tevent: Destroying timer event 0x6f8740 "ltdb_timeout" (Tue Nov 13 10:29:30 2012) [sssd[be[nat.c.sdu.dk]]] [ldb] (0x4000): tevent: Ending timer event 0x6f4c60 "ltdb_callback" (Tue Nov 13 10:29:30 2012) [sssd[be[nat.c.sdu.dk]]] [sysdb_search_groups] (0x2000): No such entry (Tue Nov 13 10:29:30 2012) [sssd[be[nat.c.sdu.dk]]] [sysdb_delete_user] (0x0400): Error: 2 (No such file or directory) (Tue Nov 13 10:29:30 2012) [sssd[be[nat.c.sdu.dk]]] [acctinfo_callback] (0x0100): Request processed. Returned 0,0,Success (Tue Nov 13 10:29:30 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_process_result] (0x2000): Trace: sh[0x6e8e00], connected[1], ops[(nil)], ldap[0x713300] (Tue Nov 13 10:29:30 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_process_result] (0x2000): Trace: ldap_result found nothing! (Tue Nov 13 10:29:30 2012) [sssd[be[nat.c.sdu.dk]]] [sbus_dispatch] (0x4000): dbus conn: 707F80 (Tue Nov 13 10:29:30 2012) [sssd[be[nat.c.sdu.dk]]] [sbus_dispatch] (0x4000): Dispatching. (Tue Nov 13 10:29:30 2012) [sssd[be[nat.c.sdu.dk]]] [sbus_message_handler] (0x4000): Received SBUS method [getAccountInfo] (Tue Nov 13 10:29:30 2012) [sssd[be[nat.c.sdu.dk]]] [be_get_account_info] (0x0100): Got request for [3][1][name=lightdm] ^^^^^^^^ (Tue Nov 13 10:29:30 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_id_op_connect_step] (0x4000): reusing cached connection (Tue Nov 13 10:29:30 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_initgr_send] (0x4000): Retrieving info for initgroups call (Tue Nov 13 10:29:30 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_initgr_next_base] (0x0400): Searching for users with base [ou=ADUsers,dc=nat,dc=c,dc=sdu,dc=dk] (Tue Nov 13 10:29:30 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(sAMAccountName=lightdm)(objectclass=person))][ou=ADUsers,dc=nat,dc=c,dc=sdu,dc=dk]. ...... I can also see a lot of messages: ... (Tue Nov 13 13:10:33 2012) [sssd[be[nat.c.sdu.dk]]] [sbus_message_handler] (0x4000): Received SBUS method [getDomains] (Tue Nov 13 13:10:33 2012) [sssd[be[nat.c.sdu.dk]]] [be_get_subdomains] (0x2000): Undefined backend target. (Tue Nov 13 13:10:33 2012) [sssd[be[nat.c.sdu.dk]]] [sbus_dispatch] (0x4000): dbus conn: EA75B0 (Tue Nov 13 13:10:33 2012) [sssd[be[nat.c.sdu.dk]]] [sbus_dispatch] (0x4000): Dispatching. (Tue Nov 13 13:10:33 2012) [sssd[be[nat.c.sdu.dk]]] [sbus_message_handler] (0x4000): Received SBUS method [getDomains] (Tue Nov 13 13:10:33 2012) [sssd[be[nat.c.sdu.dk]]] [be_get_subdomains] (0x2000): Undefined backend target. ... Do I miss specific parameter in sssd.conf? Thanks in advance longina

5 11

Howto to accept users with uidnumber or gidnumber equal to 0 ?
by Christian Claveleira 30 Nov '12

30 Nov '12

Hi, I'm trying to setup sssd (sssd-1.8.0-32) on CentOS release 6.3. We have some users whose uidnumber or gidnumber is equal to 0 in our LDAP. I set min_id to 0 in the domain section but these users are filtered out : (Thu Nov 29 17:23:02 2012) [sssd[be[LDAP]]] [sdap_save_user] (0x0040): User [root-rdm] filtered out! (id out of range) (Thu Nov 29 17:23:02 2012) [sssd[be[LDAP]]] [sdap_save_user] (0x0040): Failed to save user [root-rdm] (Thu Nov 29 17:23:02 2012) [sssd[be[LDAP]]] [sdap_save_users] (0x0040): Failed to store user 0. Ignoring. Am I missing something ? -- CC

4 4

Password expiration with public-key authentication
by Iain Morgan 29 Nov '12

29 Nov '12

Hello, I recently began experimenting with sssd (1.8.0) and have run into an issue with its support for password expiration. Specifically, the case where sssd is configured to use LDAP and the user authenticates via SSH public-key. If a user connects via ssh to a host which is using sssd and authenticates via a public-key, the only way to enforce password expiration appears to be to set ldap_pwd_policy=shadow. However, sssd will not attempt to change the password when the policy is thus set. I know that there are those who would argue that password expiration should not be enforced when public-key authentication is used, but that is an organizational policy decision. The expectation for the environment which I deal with is that password expiration should be enforced, and work, regardless of the method used for authentication. Is there some trick that I have overlooked or is this simply a design limitation? If the shadow map were exposed, pam_unix.so could be used to detect password expiration and pam_sss.so (with ldap_pwd_policy=none) could be used to change the password, but that is not currently the case. Thanks, -- Iain Morgan

5 7

Re: [SSSD-users] [Freeipa-users] Problem with password reset on ubuntu 12.04 (lightdm)
by Marc Grimme 21 Nov '12

21 Nov '12

Hello sssd list. My problem is that a with sssd configured ubuntu 12.04 client cannot change a password that has to be set a new for IPA. As I've learned from the IPA list there are indications that sssd might be the problem in this case. With logging=10 in sssd.conf I see the following logs by sssd: When a user password expires the users are requested to change their password (in the login screen). They'll type their old password and then repeat it as part of the change process. Nevertheless - although the password matches - they are not issued to input their new password but get the error message that this action could not be performed (Password change failed. Server message..). The sssd logs show the following. (Mon Nov 19 10:33:18 2012) [sssd[be[gallien.atix]]] [sbus_dispatch] (0x4000): dbus conn: 8C8E50 (Mon Nov 19 10:33:18 2012) [sssd[be[gallien.atix]]] [sbus_dispatch] (0x4000): Dispatching. (Mon Nov 19 10:33:18 2012) [sssd[be[gallien.atix]]] [sbus_message_handler] (0x4000): Received SBUS method [ping] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sbus_dispatch] (0x4000): dbus conn: 8ED0A0 (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sbus_dispatch] (0x4000): Dispatching. (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sbus_message_handler] (0x4000): Received SBUS method [getAccountInfo] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [be_get_account_info] (0x0100): Got request for [3][1][name=tuser] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_id_op_connect_step] (0x4000): reusing cached connection (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_get_initgr_send] (0x4000): Retrieving info for initgroups call (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_get_initgr_next_base] (0x0400): Searching for users with base [cn=accounts,dc=cl,dc=atix] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(uid=tuser)(objectclass=posixAccount))][cn=accounts,dc=cl,dc=atix]. (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectClass] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uid] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userPassword] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uidNumber] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gidNumber] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gecos] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [homeDirectory] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [loginShell] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [krbPrincipalName] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [cn] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [memberOf] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [nsUniqueId] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [modifyTimestamp] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [entryUSN] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowLastChange] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowMin] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowMax] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowWarning] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowInactive] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowExpire] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowFlag] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [krbLastPwdChange] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [krbPasswordExpiration] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [pwdAttribute] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [authorizedService] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [accountExpires] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userAccountControl] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [nsAccountLock] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [host] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [loginDisabled] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [loginExpirationTime] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [loginAllowedTimeMap] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [ipaSshPubKey] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 8 (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_process_result] (0x2000): Trace: sh[0x997840], connected[1], ops[0x9a7480], ldap[0x9a48d0] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_ENTRY] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_parse_entry] (0x4000): OriginalDN: [uid=tuser,cn=users,cn=accounts,dc=cl,dc=atix]. (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_process_result] (0x2000): Trace: sh[0x997840], connected[1], ops[0x9a7480], ldap[0x9a48d0] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_get_initgr_user] (0x4000): Receiving info for the user (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): start ldb transaction (nesting: 0) (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_get_initgr_user] (0x4000): Storing the user (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_save_user] (0x4000): Save user (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_attrs_add_ldap_attr] (0x2000): Adding original DN [uid=tuser,cn=users,cn=accounts,dc=cl,dc=atix] to attributes of [tuser]. (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_save_user] (0x1000): Original memberOf is not available for [tuser]. (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_attrs_add_ldap_attr] (0x2000): Adding original mod-Timestamp [20121119092148Z] to attributes of [tuser]. (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_save_user] (0x1000): Adding user principal [tuser(a)CL.ATIX] to attributes of [tuser]. (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowLastChange is not available for [tuser]. (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowMin is not available for [tuser]. (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowMax is not available for [tuser]. (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowWarning is not available for [tuser]. (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowInactive is not available for [tuser]. (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowExpire is not available for [tuser]. (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowFlag is not available for [tuser]. (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_attrs_add_ldap_attr] (0x2000): Adding krbLastPwdChange [20121119091442Z] to attributes of [tuser]. (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_attrs_add_ldap_attr] (0x2000): Adding krbPasswordExpiration [20121119091442Z] to attributes of [tuser]. (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_attrs_add_ldap_attr] (0x2000): pwdAttribute is not available for [tuser]. (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_attrs_add_ldap_attr] (0x2000): authorizedService is not available for [tuser]. (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_attrs_add_ldap_attr] (0x2000): adAccountExpires is not available for [tuser]. (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_attrs_add_ldap_attr] (0x2000): adUserAccountControl is not available for [tuser]. (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_attrs_add_ldap_attr] (0x2000): nsAccountLock is not available for [tuser]. (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_attrs_add_ldap_attr] (0x2000): authorizedHost is not available for [tuser]. (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_attrs_add_ldap_attr] (0x2000): ndsLoginDisabled is not available for [tuser]. (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_attrs_add_ldap_attr] (0x2000): ndsLoginExpirationTime is not available for [tuser]. (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_attrs_add_ldap_attr] (0x2000): ndsLoginAllowedTimeMap is not available for [tuser]. (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_attrs_add_ldap_attr] (0x2000): sshPublicKey is not available for [tuser]. (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_save_user] (0x0400): Storing info for user tuser (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): start ldb transaction (nesting: 1) (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_callback": 0x99b6e0 (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_timeout": 0x99b800 (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Destroying timer event 0x99b800 "ltdb_timeout" (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Ending timer event 0x99b6e0 "ltdb_callback" (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): start ldb transaction (nesting: 2) (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_callback": 0x99b6e0 (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_timeout": 0x9a8300 (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Destroying timer event 0x9a8300 "ltdb_timeout" (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Ending timer event 0x99b6e0 "ltdb_callback" (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): commit ldb transaction (nesting: 2) (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): start ldb transaction (nesting: 2) (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sysdb_remove_attrs] (0x2000): Removing attribute [userPassword] from [tuser] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): start ldb transaction (nesting: 3) (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_callback": 0x9a8300 (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_timeout": 0x99b800 (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Destroying timer event 0x99b800 "ltdb_timeout" (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Ending timer event 0x9a8300 "ltdb_callback" (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3) (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sysdb_remove_attrs] (0x2000): Removing attribute [shadowLastChange] from [tuser] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): start ldb transaction (nesting: 3) (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_callback": 0x99b6e0 (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_timeout": 0x99b800 (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Destroying timer event 0x99b800 "ltdb_timeout" (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Ending timer event 0x99b6e0 "ltdb_callback" (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3) (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sysdb_remove_attrs] (0x2000): Removing attribute [shadowMin] from [tuser] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): start ldb transaction (nesting: 3) (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_callback": 0x9a8300 (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_timeout": 0x99b800 (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Destroying timer event 0x99b800 "ltdb_timeout" (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Ending timer event 0x9a8300 "ltdb_callback" (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3) (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sysdb_remove_attrs] (0x2000): Removing attribute [shadowMax] from [tuser] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): start ldb transaction (nesting: 3) (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_callback": 0x99b6e0 (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_timeout": 0x99b800 (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Destroying timer event 0x99b800 "ltdb_timeout" (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Ending timer event 0x99b6e0 "ltdb_callback" (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3) (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sysdb_remove_attrs] (0x2000): Removing attribute [shadowWarning] from [tuser] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): start ldb transaction (nesting: 3) (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_callback": 0x9a8300 (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_timeout": 0x99b800 (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Destroying timer event 0x99b800 "ltdb_timeout" (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Ending timer event 0x9a8300 "ltdb_callback" (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3) (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sysdb_remove_attrs] (0x2000): Removing attribute [shadowInactive] from [tuser] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): start ldb transaction (nesting: 3) (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_callback": 0x99b6e0 (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_timeout": 0x99b800 (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Destroying timer event 0x99b800 "ltdb_timeout" (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Ending timer event 0x99b6e0 "ltdb_callback" (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3) (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sysdb_remove_attrs] (0x2000): Removing attribute [shadowExpire] from [tuser] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): start ldb transaction (nesting: 3) (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_callback": 0x9a8300 (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_timeout": 0x99b800 (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Destroying timer event 0x99b800 "ltdb_timeout" (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Ending timer event 0x9a8300 "ltdb_callback" (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3) (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sysdb_remove_attrs] (0x2000): Removing attribute [shadowFlag] from [tuser] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): start ldb transaction (nesting: 3) (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_callback": 0x99b6e0 (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_timeout": 0x99b800 (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Destroying timer event 0x99b800 "ltdb_timeout" (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Ending timer event 0x99b6e0 "ltdb_callback" (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3) (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sysdb_remove_attrs] (0x2000): Removing attribute [pwdAttribute] from [tuser] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): start ldb transaction (nesting: 3) (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_callback": 0x9a8300 (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_timeout": 0x99b800 (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Destroying timer event 0x99b800 "ltdb_timeout" (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Ending timer event 0x9a8300 "ltdb_callback" (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3) (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sysdb_remove_attrs] (0x2000): Removing attribute [authorizedService] from [tuser] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): start ldb transaction (nesting: 3) (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_callback": 0x99b6e0 (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_timeout": 0x99b800 (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Destroying timer event 0x99b800 "ltdb_timeout" (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Ending timer event 0x99b6e0 "ltdb_callback" (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3) (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sysdb_remove_attrs] (0x2000): Removing attribute [adAccountExpires] from [tuser] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): start ldb transaction (nesting: 3) (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_callback": 0x9a8300 (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_timeout": 0x99b800 (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Destroying timer event 0x99b800 "ltdb_timeout" (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Ending timer event 0x9a8300 "ltdb_callback" (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3) (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sysdb_remove_attrs] (0x2000): Removing attribute [adUserAccountControl] from [tuser] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): start ldb transaction (nesting: 3) (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_callback": 0x99b6e0 (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_timeout": 0x99b800 (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Destroying timer event 0x99b800 "ltdb_timeout" (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Ending timer event 0x99b6e0 "ltdb_callback" (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3) (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sysdb_remove_attrs] (0x2000): Removing attribute [nsAccountLock] from [tuser] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): start ldb transaction (nesting: 3) (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_callback": 0x9a8300 (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_timeout": 0x99b800 (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Destroying timer event 0x99b800 "ltdb_timeout" (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Ending timer event 0x9a8300 "ltdb_callback" (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3) (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sysdb_remove_attrs] (0x2000): Removing attribute [authorizedHost] from [tuser] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): start ldb transaction (nesting: 3) (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_callback": 0x99b6e0 (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_timeout": 0x99b800 (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Destroying timer event 0x99b800 "ltdb_timeout" (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Ending timer event 0x99b6e0 "ltdb_callback" (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3) (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sysdb_remove_attrs] (0x2000): Removing attribute [ndsLoginDisabled] from [tuser] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): start ldb transaction (nesting: 3) (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_callback": 0x9a8300 (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_timeout": 0x99b800 (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Destroying timer event 0x99b800 "ltdb_timeout" (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Ending timer event 0x9a8300 "ltdb_callback" (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3) (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sysdb_remove_attrs] (0x2000): Removing attribute [ndsLoginExpirationTime] from [tuser] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): start ldb transaction (nesting: 3) (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_callback": 0x99b6e0 (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_timeout": 0x99b800 (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Destroying timer event 0x99b800 "ltdb_timeout" (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Ending timer event 0x99b6e0 "ltdb_callback" (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3) (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sysdb_remove_attrs] (0x2000): Removing attribute [ndsLoginAllowedTimeMap] from [tuser] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): start ldb transaction (nesting: 3) (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_callback": 0x9a8300 (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_timeout": 0x99b800 (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Destroying timer event 0x99b800 "ltdb_timeout" (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Ending timer event 0x9a8300 "ltdb_callback" (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3) (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sysdb_remove_attrs] (0x2000): Removing attribute [sshPublicKey] from [tuser] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): start ldb transaction (nesting: 3) (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_callback": 0x99b6e0 (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_timeout": 0x99b800 (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Destroying timer event 0x99b800 "ltdb_timeout" (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Ending timer event 0x99b6e0 "ltdb_callback" (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3) (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): commit ldb transaction (nesting: 2) (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): commit ldb transaction (nesting: 1) (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_get_initgr_user] (0x4000): Commit change (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): commit ldb transaction (nesting: 0) (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_callback": 0x9d8720 (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_timeout": 0x9d8840 (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Destroying timer event 0x9d8840 "ltdb_timeout" (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Ending timer event 0x9d8720 "ltdb_callback" (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_get_initgr_user] (0x4000): Process user's groups (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_initgr_nested_send] (0x0100): User entry lacks original memberof ? (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_get_initgr_done] (0x4000): Initgroups done (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_id_op_connect_step] (0x4000): reusing cached connection (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_id_op_destroy] (0x4000): releasing operation connection (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_id_op_done] (0x4000): releasing operation connection (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [acctinfo_callback] (0x0100): Request processed. Returned 0,0,Success (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_process_result] (0x2000): Trace: sh[0x997840], connected[1], ops[(nil)], ldap[0x9a48d0] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sdap_process_result] (0x2000): Trace: ldap_result found nothing! (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sbus_dispatch] (0x4000): dbus conn: 8ED0A0 (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sbus_dispatch] (0x4000): Dispatching. (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sbus_message_handler] (0x4000): Received SBUS method [pamHandler] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [be_pam_handler] (0x0100): Got request with the following data (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [pam_print_data] (0x0100): command: PAM_AUTHENTICATE (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [pam_print_data] (0x0100): domain: gallien.atix (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [pam_print_data] (0x0100): user: tuser (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [pam_print_data] (0x0100): service: lightdm (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [pam_print_data] (0x0100): tty: :0 (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [pam_print_data] (0x0100): ruser: (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [pam_print_data] (0x0100): rhost: (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [pam_print_data] (0x0100): authtok type: 1 (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [pam_print_data] (0x0100): authtok size: 7 (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [pam_print_data] (0x0100): newauthtok type: 0 (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [pam_print_data] (0x0100): newauthtok size: 0 (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [pam_print_data] (0x0100): priv: 1 (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [pam_print_data] (0x0100): cli_pid: 19892 (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_callback": 0x9d0710 (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_timeout": 0x9b6400 (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Destroying timer event 0x9b6400 "ltdb_timeout" (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Ending timer event 0x9d0710 "ltdb_callback" (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [krb5_auth_send] (0x0100): No ccache file for user [tuser] found. (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [krb5_auth_send] (0x4000): Ccache_file is [not set] and is not active and TGT is not valid. (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'IPA' (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [get_server_status] (0x1000): Status of server 'axinfra02-1.cl.atix' is 'working' (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [get_port_status] (0x1000): Port status of port 0 for server 'axinfra02-1.cl.atix' is 'working' (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 10 seconds (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [get_server_status] (0x1000): Status of server 'axinfra02-1.cl.atix' is 'working' (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [be_resolve_server_done] (0x1000): Saving the first resolved server (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [be_resolve_server_done] (0x0200): Found address for server axinfra02-1.cl.atix: [192.168.3.4] TTL 1200 (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [ipa_resolve_callback] (0x0400): Constructed uri 'ldap://axinfra02-1.cl.atix' (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [krb5_find_ccache_step] (0x4000): Recreating ccache file. (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [child_handler_setup] (0x2000): Setting up signal handler up for pid [19941] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [child_handler_setup] (0x2000): Signal handler set up for pid [19941] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [write_pipe_handler] (0x0400): All data has been sent! ==> /var/log/sssd/krb5_child.log <== (Mon Nov 19 10:33:27 2012) [[sssd[krb5_child[19941]]]] [main] (0x0400): krb5_child started. (Mon Nov 19 10:33:27 2012) [[sssd[krb5_child[19941]]]] [krb5_child_setup] (0x1000): Cannot read [SSSD_KRB5_RENEWABLE_LIFETIME] from environment. (Mon Nov 19 10:33:27 2012) [[sssd[krb5_child[19941]]]] [krb5_child_setup] (0x1000): Cannot read [SSSD_KRB5_LIFETIME] from environment. (Mon Nov 19 10:33:27 2012) [[sssd[krb5_child[19941]]]] [krb5_child_setup] (0x4000): Not using FAST. (Mon Nov 19 10:33:27 2012) [[sssd[krb5_child[19941]]]] [get_and_save_tgt] (0x0020): 660: [-1765328361][Password has expired] (Mon Nov 19 10:33:27 2012) [[sssd[krb5_child[19941]]]] [tgt_req_child] (0x0020): 919: [-1765328361][Password has expired] ==> /var/log/sssd/sssd_gallien.atix.log <== (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [read_pipe_handler] (0x0400): EOF received, client finished (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [krb5_child_done] (0x4000): child response [12][1][21]. (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [be_pam_handler_callback] (0x0100): Backend returned: (0, 12, <NULL>) [Success] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [be_pam_handler_callback] (0x0100): Sending result [12][gallien.atix] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [be_pam_handler_callback] (0x0100): Sent result [12][gallien.atix] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sbus_dispatch] (0x4000): dbus conn: 8ED0A0 (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sbus_dispatch] (0x4000): Dispatching. (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sbus_message_handler] (0x4000): Received SBUS method [pamHandler] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [be_pam_handler] (0x0100): Got request with the following data (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [pam_print_data] (0x0100): command: PAM_ACCT_MGMT (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [pam_print_data] (0x0100): domain: gallien.atix (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [pam_print_data] (0x0100): user: tuser (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [pam_print_data] (0x0100): service: lightdm (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [pam_print_data] (0x0100): tty: :0 (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [pam_print_data] (0x0100): ruser: (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [pam_print_data] (0x0100): rhost: (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [pam_print_data] (0x0100): authtok type: 0 (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [pam_print_data] (0x0100): authtok size: 0 (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [pam_print_data] (0x0100): newauthtok type: 0 (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [pam_print_data] (0x0100): newauthtok size: 0 (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [pam_print_data] (0x0100): priv: 1 (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [pam_print_data] (0x0100): cli_pid: 19892 (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [be_target_access_permit] (0x4000): be_target_access_permit called, returning PAM_SUCCESS. (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [be_pam_handler_callback] (0x0100): Backend returned: (0, 0, <NULL>) [Success] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [be_pam_handler_callback] (0x0100): Sending result [0][gallien.atix] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [be_pam_handler_callback] (0x0100): Sent result [0][gallien.atix] (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [child_sig_handler] (0x1000): Waiting for child [19941]. (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [child_sig_handler] (0x0100): child [19941] finished successfully. (Mon Nov 19 10:33:27 2012) [sssd[be[gallien.atix]]] [sss_child_handler] (0x2000): waitpid failed [10]: No child processes (Mon Nov 19 10:33:28 2012) [sssd[be[gallien.atix]]] [sbus_dispatch] (0x4000): dbus conn: 8C8E50 (Mon Nov 19 10:33:28 2012) [sssd[be[gallien.atix]]] [sbus_dispatch] (0x4000): Dispatching. (Mon Nov 19 10:33:28 2012) [sssd[be[gallien.atix]]] [sbus_message_handler] (0x4000): Received SBUS method [ping] (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sbus_dispatch] (0x4000): dbus conn: 8ED0A0 (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sbus_dispatch] (0x4000): Dispatching. (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sbus_message_handler] (0x4000): Received SBUS method [getAccountInfo] (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [be_get_account_info] (0x0100): Got request for [3][1][name=tuser] (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_id_op_connect_step] (0x4000): reusing cached connection (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_get_initgr_send] (0x4000): Retrieving info for initgroups call (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_get_initgr_next_base] (0x0400): Searching for users with base [cn=accounts,dc=cl,dc=atix] (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(uid=tuser)(objectclass=posixAccount))][cn=accounts,dc=cl,dc=atix]. (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [objectClass] (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uid] (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userPassword] (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [uidNumber] (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gidNumber] (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [gecos] (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [homeDirectory] (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [loginShell] (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [krbPrincipalName] (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [cn] (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [memberOf] (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [nsUniqueId] (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [modifyTimestamp] (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [entryUSN] (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowLastChange] (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowMin] (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowMax] (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowWarning] (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowInactive] (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowExpire] (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [shadowFlag] (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [krbLastPwdChange] (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [krbPasswordExpiration] (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [pwdAttribute] (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [authorizedService] (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [accountExpires] (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [userAccountControl] (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [nsAccountLock] (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [host] (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [loginDisabled] (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [loginExpirationTime] (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [loginAllowedTimeMap] (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [ipaSshPubKey] (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_step] (0x2000): ldap_search_ext called, msgid = 9 (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_process_result] (0x2000): Trace: sh[0x997840], connected[1], ops[0x9a7480], ldap[0x9a48d0] (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_ENTRY] (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_parse_entry] (0x4000): OriginalDN: [uid=tuser,cn=users,cn=accounts,dc=cl,dc=atix]. (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_process_result] (0x2000): Trace: sh[0x997840], connected[1], ops[0x9a7480], ldap[0x9a48d0] (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_process_message] (0x4000): Message type: [LDAP_RES_SEARCH_RESULT] (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_get_generic_ext_done] (0x0400): Search result: Success(0), no errmsg set (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_get_initgr_user] (0x4000): Receiving info for the user (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): start ldb transaction (nesting: 0) (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_get_initgr_user] (0x4000): Storing the user (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_save_user] (0x4000): Save user (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_attrs_add_ldap_attr] (0x2000): Adding original DN [uid=tuser,cn=users,cn=accounts,dc=cl,dc=atix] to attributes of [tuser]. (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_save_user] (0x1000): Original memberOf is not available for [tuser]. (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_attrs_add_ldap_attr] (0x2000): Adding original mod-Timestamp [20121119093326Z] to attributes of [tuser]. (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_save_user] (0x1000): Adding user principal [tuser(a)CL.ATIX] to attributes of [tuser]. (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowLastChange is not available for [tuser]. (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowMin is not available for [tuser]. (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowMax is not available for [tuser]. (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowWarning is not available for [tuser]. (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowInactive is not available for [tuser]. (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowExpire is not available for [tuser]. (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_attrs_add_ldap_attr] (0x2000): shadowFlag is not available for [tuser]. (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_attrs_add_ldap_attr] (0x2000): Adding krbLastPwdChange [20121119091442Z] to attributes of [tuser]. (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_attrs_add_ldap_attr] (0x2000): Adding krbPasswordExpiration [20121119091442Z] to attributes of [tuser]. (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_attrs_add_ldap_attr] (0x2000): pwdAttribute is not available for [tuser]. (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_attrs_add_ldap_attr] (0x2000): authorizedService is not available for [tuser]. (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_attrs_add_ldap_attr] (0x2000): adAccountExpires is not available for [tuser]. (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_attrs_add_ldap_attr] (0x2000): adUserAccountControl is not available for [tuser]. (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_attrs_add_ldap_attr] (0x2000): nsAccountLock is not available for [tuser]. (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_attrs_add_ldap_attr] (0x2000): authorizedHost is not available for [tuser]. (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_attrs_add_ldap_attr] (0x2000): ndsLoginDisabled is not available for [tuser]. (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_attrs_add_ldap_attr] (0x2000): ndsLoginExpirationTime is not available for [tuser]. (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_attrs_add_ldap_attr] (0x2000): ndsLoginAllowedTimeMap is not available for [tuser]. (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_attrs_add_ldap_attr] (0x2000): sshPublicKey is not available for [tuser]. (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_save_user] (0x0400): Storing info for user tuser (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): start ldb transaction (nesting: 1) (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_callback": 0x9b6300 (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_timeout": 0x9d48d0 (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Destroying timer event 0x9d48d0 "ltdb_timeout" (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Ending timer event 0x9b6300 "ltdb_callback" (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): start ldb transaction (nesting: 2) (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_callback": 0x9d0600 (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_timeout": 0x9d0720 (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Destroying timer event 0x9d0720 "ltdb_timeout" (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Ending timer event 0x9d0600 "ltdb_callback" (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): commit ldb transaction (nesting: 2) (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): start ldb transaction (nesting: 2) (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sysdb_remove_attrs] (0x2000): Removing attribute [userPassword] from [tuser] (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): start ldb transaction (nesting: 3) (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_callback": 0x9d08b0 (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_timeout": 0xa319d0 (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Destroying timer event 0xa319d0 "ltdb_timeout" (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Ending timer event 0x9d08b0 "ltdb_callback" (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3) (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sysdb_remove_attrs] (0x2000): Removing attribute [shadowLastChange] from [tuser] (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): start ldb transaction (nesting: 3) (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_callback": 0x9d08b0 (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_timeout": 0x9d0720 (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Destroying timer event 0x9d0720 "ltdb_timeout" (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Ending timer event 0x9d08b0 "ltdb_callback" (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3) (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sysdb_remove_attrs] (0x2000): Removing attribute [shadowMin] from [tuser] (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): start ldb transaction (nesting: 3) (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_callback": 0x9d0720 (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_timeout": 0x9d08b0 (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Destroying timer event 0x9d08b0 "ltdb_timeout" (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Ending timer event 0x9d0720 "ltdb_callback" (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3) (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sysdb_remove_attrs] (0x2000): Removing attribute [shadowMax] from [tuser] (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): start ldb transaction (nesting: 3) (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_callback": 0x9d08b0 (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_timeout": 0x9d0720 (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Destroying timer event 0x9d0720 "ltdb_timeout" (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Ending timer event 0x9d08b0 "ltdb_callback" (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3) (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sysdb_remove_attrs] (0x2000): Removing attribute [shadowWarning] from [tuser] (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): start ldb transaction (nesting: 3) (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_callback": 0x9d0720 (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_timeout": 0x9d08b0 (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Destroying timer event 0x9d08b0 "ltdb_timeout" (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Ending timer event 0x9d0720 "ltdb_callback" (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3) (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sysdb_remove_attrs] (0x2000): Removing attribute [shadowInactive] from [tuser] (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): start ldb transaction (nesting: 3) (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_callback": 0x9d08b0 (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_timeout": 0x9d0720 (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Destroying timer event 0x9d0720 "ltdb_timeout" (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Ending timer event 0x9d08b0 "ltdb_callback" (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3) (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sysdb_remove_attrs] (0x2000): Removing attribute [shadowExpire] from [tuser] (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): start ldb transaction (nesting: 3) (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_callback": 0x9d0720 (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_timeout": 0x9d08b0 (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Destroying timer event 0x9d08b0 "ltdb_timeout" (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Ending timer event 0x9d0720 "ltdb_callback" (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3) (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sysdb_remove_attrs] (0x2000): Removing attribute [shadowFlag] from [tuser] (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): start ldb transaction (nesting: 3) (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_callback": 0x9d08b0 (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_timeout": 0x9d0720 (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Destroying timer event 0x9d0720 "ltdb_timeout" (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Ending timer event 0x9d08b0 "ltdb_callback" (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3) (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sysdb_remove_attrs] (0x2000): Removing attribute [pwdAttribute] from [tuser] (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): start ldb transaction (nesting: 3) (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_callback": 0x9d0720 (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_timeout": 0x9d08b0 (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Destroying timer event 0x9d08b0 "ltdb_timeout" (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Ending timer event 0x9d0720 "ltdb_callback" (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3) (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sysdb_remove_attrs] (0x2000): Removing attribute [authorizedService] from [tuser] (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): start ldb transaction (nesting: 3) (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_callback": 0x9d08b0 (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_timeout": 0x9d0720 (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Destroying timer event 0x9d0720 "ltdb_timeout" (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Ending timer event 0x9d08b0 "ltdb_callback" (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3) (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sysdb_remove_attrs] (0x2000): Removing attribute [adAccountExpires] from [tuser] (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): start ldb transaction (nesting: 3) (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_callback": 0x9d0720 (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_timeout": 0x9d08b0 (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Destroying timer event 0x9d08b0 "ltdb_timeout" (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Ending timer event 0x9d0720 "ltdb_callback" (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3) (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sysdb_remove_attrs] (0x2000): Removing attribute [adUserAccountControl] from [tuser] (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): start ldb transaction (nesting: 3) (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_callback": 0x9d08b0 (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_timeout": 0x9d0720 (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Destroying timer event 0x9d0720 "ltdb_timeout" (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Ending timer event 0x9d08b0 "ltdb_callback" (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3) (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sysdb_remove_attrs] (0x2000): Removing attribute [nsAccountLock] from [tuser] (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): start ldb transaction (nesting: 3) (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_callback": 0x9d0720 (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_timeout": 0x9d08b0 (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Destroying timer event 0x9d08b0 "ltdb_timeout" (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Ending timer event 0x9d0720 "ltdb_callback" (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3) (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sysdb_remove_attrs] (0x2000): Removing attribute [authorizedHost] from [tuser] (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): start ldb transaction (nesting: 3) (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_callback": 0x9d08b0 (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_timeout": 0x9d0720 (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Destroying timer event 0x9d0720 "ltdb_timeout" (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Ending timer event 0x9d08b0 "ltdb_callback" (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3) (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sysdb_remove_attrs] (0x2000): Removing attribute [ndsLoginDisabled] from [tuser] (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): start ldb transaction (nesting: 3) (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_callback": 0x9d0720 (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_timeout": 0x9d08b0 (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Destroying timer event 0x9d08b0 "ltdb_timeout" (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Ending timer event 0x9d0720 "ltdb_callback" (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3) (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sysdb_remove_attrs] (0x2000): Removing attribute [ndsLoginExpirationTime] from [tuser] (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): start ldb transaction (nesting: 3) (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_callback": 0x9d08b0 (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_timeout": 0x9d0720 (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Destroying timer event 0x9d0720 "ltdb_timeout" (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Ending timer event 0x9d08b0 "ltdb_callback" (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3) (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sysdb_remove_attrs] (0x2000): Removing attribute [ndsLoginAllowedTimeMap] from [tuser] (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): start ldb transaction (nesting: 3) (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_callback": 0x9d0720 (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_timeout": 0x9d08b0 (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Destroying timer event 0x9d08b0 "ltdb_timeout" (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Ending timer event 0x9d0720 "ltdb_callback" (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3) (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sysdb_remove_attrs] (0x2000): Removing attribute [sshPublicKey] from [tuser] (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): start ldb transaction (nesting: 3) (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_callback": 0x9d08b0 (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_timeout": 0x9d0720 (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Destroying timer event 0x9d0720 "ltdb_timeout" (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Ending timer event 0x9d08b0 "ltdb_callback" (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): cancel ldb transaction (nesting: 3) (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): commit ldb transaction (nesting: 2) (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): commit ldb transaction (nesting: 1) (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_get_initgr_user] (0x4000): Commit change (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): commit ldb transaction (nesting: 0) (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_callback": 0x99b840 (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_timeout": 0x99b960 (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Destroying timer event 0x99b960 "ltdb_timeout" (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Ending timer event 0x99b840 "ltdb_callback" (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_get_initgr_user] (0x4000): Process user's groups (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_initgr_nested_send] (0x0100): User entry lacks original memberof ? (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_get_initgr_done] (0x4000): Initgroups done (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_id_op_connect_step] (0x4000): reusing cached connection (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_id_op_destroy] (0x4000): releasing operation connection (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_id_op_done] (0x4000): releasing operation connection (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [acctinfo_callback] (0x0100): Request processed. Returned 0,0,Success (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_process_result] (0x2000): Trace: sh[0x997840], connected[1], ops[(nil)], ldap[0x9a48d0] (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sdap_process_result] (0x2000): Trace: ldap_result found nothing! (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sbus_dispatch] (0x4000): dbus conn: 8ED0A0 (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sbus_dispatch] (0x4000): Dispatching. (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [sbus_message_handler] (0x4000): Received SBUS method [pamHandler] (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [be_pam_handler] (0x0100): Got request with the following data (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [pam_print_data] (0x0100): command: PAM_CHAUTHTOK_PRELIM (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [pam_print_data] (0x0100): domain: gallien.atix (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [pam_print_data] (0x0100): user: tuser (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [pam_print_data] (0x0100): service: lightdm (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [pam_print_data] (0x0100): tty: :0 (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [pam_print_data] (0x0100): ruser: (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [pam_print_data] (0x0100): rhost: (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [pam_print_data] (0x0100): authtok type: 1 (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [pam_print_data] (0x0100): authtok size: 7 (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [pam_print_data] (0x0100): newauthtok type: 0 (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [pam_print_data] (0x0100): newauthtok size: 0 (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [pam_print_data] (0x0100): priv: 1 (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [pam_print_data] (0x0100): cli_pid: 19892 (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_callback": 0x9cfdf0 (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_timeout": 0x9d8b50 (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Destroying timer event 0x9d8b50 "ltdb_timeout" (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Ending timer event 0x9cfdf0 "ltdb_callback" (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [krb5_auth_send] (0x0100): No ccache file for user [tuser] found. (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [krb5_auth_send] (0x4000): Ccache_file is [not set] and is not active and TGT is not valid. (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'IPA' (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [get_server_status] (0x1000): Status of server 'axinfra02-1.cl.atix' is 'working' (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [get_port_status] (0x1000): Port status of port 0 for server 'axinfra02-1.cl.atix' is 'working' (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 10 seconds (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [get_server_status] (0x1000): Status of server 'axinfra02-1.cl.atix' is 'working' (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [be_resolve_server_done] (0x1000): Saving the first resolved server (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [be_resolve_server_done] (0x0200): Found address for server axinfra02-1.cl.atix: [192.168.3.4] TTL 1200 (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [krb5_find_ccache_step] (0x4000): Recreating ccache file. (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [child_handler_setup] (0x2000): Setting up signal handler up for pid [19942] (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [child_handler_setup] (0x2000): Signal handler set up for pid [19942] (Mon Nov 19 10:33:32 2012) [sssd[be[gallien.atix]]] [write_pipe_handler] (0x0400): All data has been sent! ==> /var/log/sssd/krb5_child.log <== (Mon Nov 19 10:33:32 2012) [[sssd[krb5_child[19942]]]] [main] (0x0400): krb5_child started. (Mon Nov 19 10:33:32 2012) [[sssd[krb5_child[19942]]]] [krb5_child_setup] (0x1000): Cannot read [SSSD_KRB5_RENEWABLE_LIFETIME] from environment. (Mon Nov 19 10:33:32 2012) [[sssd[krb5_child[19942]]]] [krb5_child_setup] (0x1000): Cannot read [SSSD_KRB5_LIFETIME] from environment. (Mon Nov 19 10:33:32 2012) [[sssd[krb5_child[19942]]]] [krb5_child_setup] (0x4000): Not using FAST. (Mon Nov 19 10:33:33 2012) [[sssd[krb5_child[19942]]]] [changepw_child] (0x4000): Initial authentication for change password operation successfull. ==> /var/log/sssd/sssd_gallien.atix.log <== (Mon Nov 19 10:33:33 2012) [sssd[be[gallien.atix]]] [read_pipe_handler] (0x0400): EOF received, client finished (Mon Nov 19 10:33:33 2012) [sssd[be[gallien.atix]]] [be_pam_handler_callback] (0x0100): Backend returned: (0, 0, <NULL>) [Success] (Mon Nov 19 10:33:33 2012) [sssd[be[gallien.atix]]] [be_pam_handler_callback] (0x0100): Sending result [0][gallien.atix] (Mon Nov 19 10:33:33 2012) [sssd[be[gallien.atix]]] [be_pam_handler_callback] (0x0100): Sent result [0][gallien.atix] (Mon Nov 19 10:33:33 2012) [sssd[be[gallien.atix]]] [sbus_dispatch] (0x4000): dbus conn: 8ED0A0 (Mon Nov 19 10:33:33 2012) [sssd[be[gallien.atix]]] [sbus_dispatch] (0x4000): Dispatching. (Mon Nov 19 10:33:33 2012) [sssd[be[gallien.atix]]] [sbus_message_handler] (0x4000): Received SBUS method [pamHandler] (Mon Nov 19 10:33:33 2012) [sssd[be[gallien.atix]]] [be_pam_handler] (0x0100): Got request with the following data (Mon Nov 19 10:33:33 2012) [sssd[be[gallien.atix]]] [pam_print_data] (0x0100): command: PAM_CHAUTHTOK (Mon Nov 19 10:33:33 2012) [sssd[be[gallien.atix]]] [pam_print_data] (0x0100): domain: gallien.atix (Mon Nov 19 10:33:33 2012) [sssd[be[gallien.atix]]] [pam_print_data] (0x0100): user: tuser (Mon Nov 19 10:33:33 2012) [sssd[be[gallien.atix]]] [pam_print_data] (0x0100): service: lightdm (Mon Nov 19 10:33:33 2012) [sssd[be[gallien.atix]]] [pam_print_data] (0x0100): tty: :0 (Mon Nov 19 10:33:33 2012) [sssd[be[gallien.atix]]] [pam_print_data] (0x0100): ruser: (Mon Nov 19 10:33:33 2012) [sssd[be[gallien.atix]]] [pam_print_data] (0x0100): rhost: (Mon Nov 19 10:33:33 2012) [sssd[be[gallien.atix]]] [pam_print_data] (0x0100): authtok type: 1 (Mon Nov 19 10:33:33 2012) [sssd[be[gallien.atix]]] [pam_print_data] (0x0100): authtok size: 7 (Mon Nov 19 10:33:33 2012) [sssd[be[gallien.atix]]] [pam_print_data] (0x0100): newauthtok type: 1 (Mon Nov 19 10:33:33 2012) [sssd[be[gallien.atix]]] [pam_print_data] (0x0100): newauthtok size: 0 (Mon Nov 19 10:33:33 2012) [sssd[be[gallien.atix]]] [pam_print_data] (0x0100): priv: 1 (Mon Nov 19 10:33:33 2012) [sssd[be[gallien.atix]]] [pam_print_data] (0x0100): cli_pid: 19892 (Mon Nov 19 10:33:33 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_callback": 0x9d8720 (Mon Nov 19 10:33:33 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Added timed event "ltdb_timeout": 0x9d9090 (Mon Nov 19 10:33:33 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Destroying timer event 0x9d9090 "ltdb_timeout" (Mon Nov 19 10:33:33 2012) [sssd[be[gallien.atix]]] [ldb] (0x4000): tevent: Ending timer event 0x9d8720 "ltdb_callback" (Mon Nov 19 10:33:33 2012) [sssd[be[gallien.atix]]] [krb5_auth_send] (0x0100): No ccache file for user [tuser] found. (Mon Nov 19 10:33:33 2012) [sssd[be[gallien.atix]]] [krb5_auth_send] (0x4000): Ccache_file is [not set] and is not active and TGT is not valid. (Mon Nov 19 10:33:33 2012) [sssd[be[gallien.atix]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'IPA' (Mon Nov 19 10:33:33 2012) [sssd[be[gallien.atix]]] [get_server_status] (0x1000): Status of server 'axinfra02-1.cl.atix' is 'working' (Mon Nov 19 10:33:33 2012) [sssd[be[gallien.atix]]] [get_port_status] (0x1000): Port status of port 0 for server 'axinfra02-1.cl.atix' is 'working' (Mon Nov 19 10:33:33 2012) [sssd[be[gallien.atix]]] [fo_resolve_service_activate_timeout] (0x2000): Resolve timeout set to 10 seconds (Mon Nov 19 10:33:33 2012) [sssd[be[gallien.atix]]] [get_server_status] (0x1000): Status of server 'axinfra02-1.cl.atix' is 'working' (Mon Nov 19 10:33:33 2012) [sssd[be[gallien.atix]]] [be_resolve_server_done] (0x1000): Saving the first resolved server (Mon Nov 19 10:33:33 2012) [sssd[be[gallien.atix]]] [be_resolve_server_done] (0x0200): Found address for server axinfra02-1.cl.atix: [192.168.3.4] TTL 1200 (Mon Nov 19 10:33:33 2012) [sssd[be[gallien.atix]]] [krb5_find_ccache_step] (0x4000): Recreating ccache file. (Mon Nov 19 10:33:33 2012) [sssd[be[gallien.atix]]] [child_handler_setup] (0x2000): Setting up signal handler up for pid [19943] (Mon Nov 19 10:33:33 2012) [sssd[be[gallien.atix]]] [child_handler_setup] (0x2000): Signal handler set up for pid [19943] (Mon Nov 19 10:33:33 2012) [sssd[be[gallien.atix]]] [write_pipe_handler] (0x0400): All data has been sent! (Mon Nov 19 10:33:33 2012) [sssd[be[gallien.atix]]] [child_sig_handler] (0x1000): Waiting for child [19943]. (Mon Nov 19 10:33:33 2012) [sssd[be[gallien.atix]]] [child_sig_handler] (0x0020): waitpid did not found a child with changed status. (Mon Nov 19 10:33:33 2012) [sssd[be[gallien.atix]]] [child_sig_handler] (0x1000): Waiting for child [19942]. (Mon Nov 19 10:33:33 2012) [sssd[be[gallien.atix]]] [child_sig_handler] (0x0100): child [19942] finished successfully. ==> /var/log/sssd/krb5_child.log <== (Mon Nov 19 10:33:33 2012) [[sssd[krb5_child[19943]]]] [main] (0x0400): krb5_child started. (Mon Nov 19 10:33:33 2012) [[sssd[krb5_child[19943]]]] [krb5_child_setup] (0x1000): Cannot read [SSSD_KRB5_RENEWABLE_LIFETIME] from environment. (Mon Nov 19 10:33:33 2012) [[sssd[krb5_child[19943]]]] [krb5_child_setup] (0x1000): Cannot read [SSSD_KRB5_LIFETIME] from environment. (Mon Nov 19 10:33:33 2012) [[sssd[krb5_child[19943]]]] [krb5_child_setup] (0x4000): Not using FAST. (Mon Nov 19 10:33:33 2012) [[sssd[krb5_child[19943]]]] [changepw_child] (0x0020): krb5_change_password failed [2][Server error]. (Mon Nov 19 10:33:33 2012) [[sssd[krb5_child[19943]]]] [changepw_child] (0x0020): krb5_change_password failed [2][Password not changed.]. ==> /var/log/sssd/sssd_gallien.atix.log <== (Mon Nov 19 10:33:33 2012) [sssd[be[gallien.atix]]] [read_pipe_handler] (0x0400): EOF received, client finished (Mon Nov 19 10:33:33 2012) [sssd[be[gallien.atix]]] [krb5_child_done] (0x4000): child response [20][1][27]. (Mon Nov 19 10:33:33 2012) [sssd[be[gallien.atix]]] [krb5_child_done] (0x4000): child response [20][6][29]. (Mon Nov 19 10:33:33 2012) [sssd[be[gallien.atix]]] [be_pam_handler_callback] (0x0100): Backend returned: (0, 20, <NULL>) [Success] (Mon Nov 19 10:33:33 2012) [sssd[be[gallien.atix]]] [be_pam_handler_callback] (0x0100): Sending result [20][gallien.atix] (Mon Nov 19 10:33:33 2012) [sssd[be[gallien.atix]]] [be_pam_handler_callback] (0x0100): Sent result [20][gallien.atix] (Mon Nov 19 10:33:33 2012) [sssd[be[gallien.atix]]] [child_sig_handler] (0x1000): Waiting for child [19943]. (Mon Nov 19 10:33:33 2012) [sssd[be[gallien.atix]]] [child_sig_handler] (0x0100): child [19943] finished successfully. (Mon Nov 19 10:33:33 2012) [sssd[be[gallien.atix]]] [sss_child_handler] (0x2000): waitpid failed [10]: No child processes (Mon Nov 19 10:33:38 2012) [sssd[be[gallien.atix]]] [sbus_dispatch] (0x4000): dbus conn: 8C8E50 (Mon Nov 19 10:33:38 2012) [sssd[be[gallien.atix]]] [sbus_dispatch] (0x4000): Dispatching. (Mon Nov 19 10:33:38 2012) [sssd[be[gallien.atix]]] [sbus_message_handler] (0x4000): Received SBUS method [ping] (Mon Nov 19 10:33:48 2012) [sssd[be[gallien.atix]]] [sbus_dispatch] (0x4000): dbus conn: 8C8E50 (Mon Nov 19 10:33:48 2012) [sssd[be[gallien.atix]]] [sbus_dispatch] (0x4000): Dispatching. (Mon Nov 19 10:33:48 2012) [sssd[be[gallien.atix]]] [sbus_message_handler] (0x4000): Received SBUS method [ping] (Mon Nov 19 10:33:58 2012) [sssd[be[gallien.atix]]] [sbus_dispatch] (0x4000): dbus conn: 8C8E50 (Mon Nov 19 10:33:58 2012) [sssd[be[gallien.atix]]] [sbus_dispatch] (0x4000): Dispatching. (Mon Nov 19 10:33:58 2012) [sssd[be[gallien.atix]]] [sbus_message_handler] (0x4000): Received SBUS method [ping] (Mon Nov 19 10:34:08 2012) [sssd[be[gallien.atix]]] [sbus_dispatch] (0x4000): dbus conn: 8C8E50 (Mon Nov 19 10:34:08 2012) [sssd[be[gallien.atix]]] [sbus_dispatch] (0x4000): Dispatching. (Mon Nov 19 10:34:08 2012) [sssd[be[gallien.atix]]] [sbus_message_handler] (0x4000): Received SBUS method [ping] (Mon Nov 19 10:34:18 2012) [sssd[be[gallien.atix]]] [sbus_dispatch] (0x4000): dbus conn: 8C8E50 (Mon Nov 19 10:34:18 2012) [sssd[be[gallien.atix]]] [sbus_dispatch] (0x4000): Dispatching. (Mon Nov 19 10:34:18 2012) [sssd[be[gallien.atix]]] [sbus_message_handler] (0x4000): Received SBUS method [ping] (Mon Nov 19 10:34:28 2012) [sssd[be[gallien.atix]]] [sbus_dispatch] (0x4000): dbus conn: 8C8E50 (Mon Nov 19 10:34:28 2012) [sssd[be[gallien.atix]]] [sbus_dispatch] (0x4000): Dispatching. (Mon Nov 19 10:34:28 2012) [sssd[be[gallien.atix]]] [sbus_message_handler] (0x4000): Received SBUS method [ping] Any ideas? If you need more information or have a special trace let me know. Regards Marc. Am 19.11.2012 18:12, schrieb Dmitri Pal: > On 11/19/2012 11:31 AM, Marc Grimme wrote: >> This is what the kerberos (kadmin.log) shows on the relevant IPA server. >> Nov 19 17:29:54 axinfra02-1.cl.atix kadmind[18851](Error): password >> quality module empty rejected password for tuser(a)CL.ATIX: Empty >> passwords are not allowed >> Nov 19 17:29:54 axinfra02-1.cl.atix kadmind[18851](Notice): chpw request >> from 192.168.3.231 for tuser(a)CL.ATIX: Password is too short >> >> I could only enter the old password the new one was never queried. >> Any idea? > Please cross post to the sssd-users. It seems that the server receives > an empty password. I do not know if one can enable a trace that would > show what password is actually sent. > You might need to have a special build of SSSD to see what SSSD is > actually sending. > Anyways ask on SSSD list, you might get some good hints. > > Thanks > Dmitri > >> Thanks >> Marc. >> >> Am 19.11.2012 16:57, schrieb Dmitri Pal: >>> On 11/19/2012 04:37 AM, Marc Grimme wrote: >>>> (Mon Nov 19 10:33:33 2012) [[sssd[krb5_child[19943]]]] >>>> [krb5_child_setup] (0x4000): Not using FAST. >>>> (Mon Nov 19 10:33:33 2012) [[sssd[krb5_child[19943]]]] [changepw_child] >>>> (0x0020): krb5_change_password failed [2][Server error]. >>>> (Mon Nov 19 10:33:33 2012) [[sssd[krb5_child[19943]]]] [changepw_child] >>>> (0x0020): krb5_change_password failed [2][Password not changed.]. >>> Have you looked at the server Kerberos log? >>> Do you see an attempt there? >>> If not there might be a problem accessing kadmin process on the server. >>> Might be a firewall issue then. >>> But let us start with the server side. >>> >>> > -- Marc Grimme Tel: +49 (0)89 452 35 38-140 Fax: +49 (0)89 452 35 38-290 E-Mail: grimme(a)atix.de ATIX Informationstechnologie und Consulting AG | Einsteinstrasse 10 | 85716 Unterschleissheim | www.atix.de | www.comoonics.org Registergericht: Amtsgericht Muenchen, Registernummer: HRB 168930, USt.-Id.: DE209485962 | Vorstand: Marc Grimme, Mark Hlawatschek, Thomas Merz (Vors.) | Vorsitzender des Aufsichtsrats: Dr. Martin Buss

4 4

sss_cache is not working for automount maps
by Ondrej Valousek 13 Nov '12

13 Nov '12

Hi List, Is sss_cache (as of version 1.9.2) supposed to work for automount maps (i.e. -a & -A parameters)? It seems to me that it is not working - maps are not reloaded (tcpdump port ldap says nothing) Just asking first before submitting a bug report :) Thanks, Ondrej

2 1

Re: [SSSD-users] startup problem/port 0 not working-almost resolved
by Longina Przybyszewska 12 Nov '12

12 Nov '12

Hi, I get it working; I made configuration for ldap/krb5 providers, get it work, than exchanged all providers => ad . Best Longina -----Original Message----- From: sssd-users-bounces(a)lists.fedorahosted.org [mailto:sssd-users-bounces@lists.fedorahosted.org] On Behalf Of Longina Przybyszewska Sent: 12. november 2012 11:06 To: 'End-user discussions about the System Security Services Daemon' Subject: Re: [SSSD-users] startup problem/port 0 not working Hi Jakub, How can I get more debugging level as you suggested? I got my packages Could my problem be related to DNS- resolution configuration? Old resolv.conf seems to be changed in Ubuntu Quantal - there is only reference to loopback. But I have no problems with resolving names on that machine. alongina@victoria:~$ cat /etc/resolv.conf # Dynamic resolv.conf(5) file for glibc resolver(3) generated by resolvconf(8) # DO NOT EDIT THIS FILE BY HAND -- YOUR CHANGES WILL BE OVERWRITTEN nameserver 127.0.1.1 regards Longina -----Original Message----- From: sssd-users-bounces(a)lists.fedorahosted.org [mailto:sssd-users-bounces@lists.fedorahosted.org] On Behalf Of Jakub Hrozek Sent: 9. november 2012 12:48 To: sssd-users(a)lists.fedorahosted.org Subject: Re: [SSSD-users] startup problem/port 0 not working On Fri, Nov 09, 2012 at 11:15:25AM +0000, Longina Przybyszewska wrote: > It is "ad_hostname=VICTORIA$(a)NAT.C.SDU.DK" - this is my mail editor > starting with capital letter after "." ;( > > I joined domain (again, again..) from scratch. > > ad_hostname = VICTORIA$NAT.C.SDU.DK > > I have the following principal names bound to computer > victoria.nat.sdu.dk root@victoria:/var/log/sssd# ldapsearch -E pr=1000/noprompt -H ldap://nat.c.sdu.dk -Y GSSAPI -b 'ou=Linux computers,ou=ADResources,dc=nat,dc=c,dc=sdu,dc=dk' '(&(objectClass=computer)(name=victoria))' > .... > # VICTORIA, Linux computers, ADResources, nat.c.sdu.dk > dn: CN=VICTORIA,OU=Linux > computers,OU=ADResources,DC=nat,DC=c,DC=sdu,DC=dk > objectClass: top > objectClass: person > objectClass: organizationalPerson > objectClass: user > objectClass: computer > cn: VICTORIA > distinguishedName: CN=VICTORIA,OU=Linux > computers,OU=ADResources,DC=nat,DC=c,D > C=sdu,DC=dk > ... > name: VICTORIA > ... > sAMAccountName: VICTORIA$ > sAMAccountType: 805306369 > dNSHostName: victoria.nat.c.sdu.dk > userPrincipalName: victoria.nat.sdu.dk(a)NAT.C.SDU.DK > servicePrincipalName: host/victoria.nat.c.sdu.dk > > ... > I can kinit as admin aduser. > I can kinit as principal VICTORIA$ and VICTORIA$NAT.C.SDU.DK OK, then the keytab seems fine. > > I can as local root get info on computer 'victoria' and ad user 'imadatestuser': > > ldapsearch -E pr=1000/noprompt -H ldap://nat.c.sdu.dk -Y GSSAPI -b 'ou=Linux computers,ou=ADResources,dc=nat,dc=c,dc=sdu,dc=dk' '(&(objectClass=computer)(name=victoria))' > root@victoria:/var/log/sssd# ldapsearch -E pr=1000/noprompt -H ldap://nat.c.sdu.dk -Y GSSAPI -b 'ou=ADusers,dc=nat,dc=c,dc=sdu,dc=dk' '(&(objectClass=person)(sAMAccountName=imadatestuser))' > > I can kinit imadatestuser > > BUT login as imadatestuser and ' getent passwd imadatestuser' doesn't work - still the same error on "port 0" > What is "port 0" ??? For server that "aggregate" LDAP and Kerberos such as AD or IPA, we don't want to be talking to a different box in the same domain on LDAP port and different box on Kerberos port. So instead of using 389 for LDAP and 88 for Kerberos separately, we use kind of a hack of using port 0 in the fail over code only to force the SSSD to talk to a single AD/IPA server for both LDAP and Kerberos. Internally, when establishing the network connection, we use the real ports of 389 and 88 of course. > > Ldap_child.log > (Fri Nov 9 11:50:07 2012) [[sssd[ldap_child[4438]]]] [unpack_buffer] > (0x1000): total buffer size: 37 (Fri Nov 9 11:50:07 2012) > [[sssd[ldap_child[4438]]]] [unpack_buffer] (0x1000): realm_str size: > 12 (Fri Nov 9 11:50:07 2012) [[sssd[ldap_child[4438]]]] > [unpack_buffer] (0x1000): got realm_str: NAT.C.SDU.DK (Fri Nov 9 > 11:50:07 2012) [[sssd[ldap_child[4438]]]] [unpack_buffer] (0x1000): > princ_str size: 9 (Fri Nov 9 11:50:07 2012) > [[sssd[ldap_child[4438]]]] [unpack_buffer] (0x1000): got princ_str: > VICTORIA$ (Fri Nov 9 11:50:07 2012) [[sssd[ldap_child[4438]]]] > [unpack_buffer] (0x1000): keytab_name size: 0 (Fri Nov 9 11:50:07 > 2012) [[sssd[ldap_child[4438]]]] [unpack_buffer] (0x1000): lifetime: > 86400 (Fri Nov 9 11:50:07 2012) [[sssd[ldap_child[4438]]]] > [ldap_child_get_tgt_sync] (0x0100): Principal name is: > [VICTORIA$(a)NAT.C.SDU.DK] (Fri Nov 9 11:50:07 2012) > [[sssd[ldap_child[4438]]]] [ldap_child_get_tgt_sync] (0x0100): Using > keytab [default] (Fri Nov 9 11:50:07 2012) [[sssd[ldap_child[4438]]]] > [pack_buffer] (0x1000): result [0] krberr [0] msgsize [40] msg > [FILE:/var/lib/sss/db/ccache_NAT.C.SDU.DK] > (Fri Nov 9 11:51:39 2012) [[sssd[ldap_child[4441]]]] [unpack_buffer] > (0x1000): total buffer size: 37 (Fri Nov 9 11:51:39 2012) > [[sssd[ldap_child[4441]]]] [unpack_buffer] (0x1000): realm_str size: > 12 (Fri Nov 9 11:51:39 2012) [[sssd[ldap_child[4441]]]] > [unpack_buffer] (0x1000): got realm_str: NAT.C.SDU.DK (Fri Nov 9 > 11:51:39 2012) [[sssd[ldap_child[4441]]]] [unpack_buffer] (0x1000): > princ_str size: 9 (Fri Nov 9 11:51:39 2012) > [[sssd[ldap_child[4441]]]] [unpack_buffer] (0x1000): got princ_str: > VICTORIA$ (Fri Nov 9 11:51:39 2012) [[sssd[ldap_child[4441]]]] > [unpack_buffer] (0x1000): keytab_name size: 0 (Fri Nov 9 11:51:39 > 2012) [[sssd[ldap_child[4441]]]] [unpack_buffer] (0x1000): lifetime: > 86400 (Fri Nov 9 11:51:39 2012) [[sssd[ldap_child[4441]]]] > [ldap_child_get_tgt_sync] (0x0100): Principal name is: > [VICTORIA$(a)NAT.C.SDU.DK] (Fri Nov 9 11:51:39 2012) > [[sssd[ldap_child[4441]]]] [ldap_child_get_tgt_sync] (0x0100): Using > keytab [default] (Fri Nov 9 11:51:39 2012) [[sssd[ldap_child[4441]]]] > [pack_buffer] (0x1000): result [0] krberr [0] msgsize [40] msg > [FILE:/var/lib/sss/db/ccache_NAT.C.SDU.DK] > ...... > > Sssd_nat.c.sdu.dk.log > ..... > Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] > [be_get_account_info] (0x0100): Got request for > [4097][1][name=imadatestuser] (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [be_get_account_info] (0x0100): Request processed. Returned 1,11,Fast reply - offline (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'AD' > (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [get_server_status] (0x1000): Status of server 'nat.c.sdu.dk' is 'name resolved' > (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [get_port_status] (0x1000): Port status of port 0 for server 'nat.c.sdu.dk' is 'not working' > (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [get_port_status] (0x0100): Reseting the status of port 0 for server 'nat.c.sdu.dk' > (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [get_server_status] (0x1000): Status of server 'nat.c.sdu.dk' is 'name resolved' > (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] > [be_resolve_server_process] (0x1000): Saving the first resolved server > (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [be_resolve_server_process] (0x0200): Found address for server nat.c.sdu.dk: [10.144.5.17] TTL 271 (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [ad_resolve_callback] (0x0100): Constructed uri 'ldap://nat.c.sdu.dk' > (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_ldap_connect_callback_add] (0x1000): New LDAP connection to [ldap://nat.c.sdu.dk:389/??base] with fd [22]. > (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] > [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [*] (Fri Nov > 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] > (0x1000): Requesting attrs: [altServer] (Fri Nov 9 12:07:00 2012) > [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): > Requesting attrs: [namingContexts] (Fri Nov 9 12:07:00 2012) > [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): > Requesting attrs: [supportedControl] (Fri Nov 9 12:07:00 2012) > [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): > Requesting attrs: [supportedExtension] (Fri Nov 9 12:07:00 2012) > [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): > Requesting attrs: [supportedFeatures] (Fri Nov 9 12:07:00 2012) > [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): > Requesting attrs: [supportedLDAPVersion] (Fri Nov 9 12:07:00 2012) > [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedSASLMechanisms] (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [domainControllerFunctionality] (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [defaultNamingContext] (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [lastUSN] (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [highestCommittedUSN] (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_server_opts_from_rootdse] (0x0100): Setting AD compatibility level to [4] (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_kinit_next_kdc] (0x1000): Resolving next KDC for service AD (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'AD' > (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [get_server_status] (0x1000): Status of server 'nat.c.sdu.dk' is 'name resolved' > (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [get_server_status] (0x1000): Status of server 'nat.c.sdu.dk' is 'name resolved' > (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] > [be_resolve_server_process] (0x1000): Saving the first resolved server > (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [be_resolve_server_process] (0x0200): Found address for server nat.c.sdu.dk: [10.144.5.17] TTL 271 (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_kinit_kdc_resolved] (0x1000): KDC resolved, attempting to get TGT... > (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] > [create_tgt_req_send_buffer] (0x1000): buffer size: 37 (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [child_sig_handler] (0x1000): Waiting for child [4471]. > (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [child_sig_handler] (0x0100): child [4471] finished successfully. > (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sasl_bind_send] > (0x0100): Executing sasl bind mech: gssapi, user: VICTORIA$ (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [fo_set_port_status] (0x0100): Marking port 0 of server 'nat.c.sdu.dk' as 'not working' > (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'AD' > (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [get_server_status] (0x1000): Status of server 'nat.c.sdu.dk' is 'name resolved' > (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [get_port_status] (0x1000): Port status of port 0 for server 'nat.c.sdu.dk' is 'not working' > (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] > [be_resolve_server_done] (0x1000): Server resolution failed: 5 (Fri > Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] > [remove_krb5_info_files] (0x0200): Could not remove > [/var/lib/sss/pubconf/kpasswdinfo.NAT.C.SDU.DK], [2][No such file or > directory] > Hm, I still don't see the failure, what debug level are you using? Can you bump it up to 10, please? _______________________________________________ sssd-users mailing list sssd-users(a)lists.fedorahosted.org https://lists.fedorahosted.org/mailman/listinfo/sssd-users _______________________________________________ sssd-users mailing list sssd-users(a)lists.fedorahosted.org https://lists.fedorahosted.org/mailman/listinfo/sssd-users

1 0

Re: [SSSD-users] startup problem/port 0 not working
by Longina Przybyszewska 12 Nov '12

12 Nov '12

It is "ad_hostname=VICTORIA$(a)NAT.C.SDU.DK" - this is my mail editor starting with capital letter after "." ;( I joined domain (again, again..) from scratch. ad_hostname = VICTORIA$NAT.C.SDU.DK I have the following principal names bound to computer victoria.nat.sdu.dk root@victoria:/var/log/sssd# ldapsearch -E pr=1000/noprompt -H ldap://nat.c.sdu.dk -Y GSSAPI -b 'ou=Linux computers,ou=ADResources,dc=nat,dc=c,dc=sdu,dc=dk' '(&(objectClass=computer)(name=victoria))' .... # VICTORIA, Linux computers, ADResources, nat.c.sdu.dk dn: CN=VICTORIA,OU=Linux computers,OU=ADResources,DC=nat,DC=c,DC=sdu,DC=dk objectClass: top objectClass: person objectClass: organizationalPerson objectClass: user objectClass: computer cn: VICTORIA distinguishedName: CN=VICTORIA,OU=Linux computers,OU=ADResources,DC=nat,DC=c,D C=sdu,DC=dk ... name: VICTORIA ... sAMAccountName: VICTORIA$ sAMAccountType: 805306369 dNSHostName: victoria.nat.c.sdu.dk userPrincipalName: victoria.nat.sdu.dk(a)NAT.C.SDU.DK servicePrincipalName: host/victoria.nat.c.sdu.dk ... I can kinit as admin aduser. I can kinit as principal VICTORIA$ and VICTORIA$NAT.C.SDU.DK I can as local root get info on computer 'victoria' and ad user 'imadatestuser': ldapsearch -E pr=1000/noprompt -H ldap://nat.c.sdu.dk -Y GSSAPI -b 'ou=Linux computers,ou=ADResources,dc=nat,dc=c,dc=sdu,dc=dk' '(&(objectClass=computer)(name=victoria))' root@victoria:/var/log/sssd# ldapsearch -E pr=1000/noprompt -H ldap://nat.c.sdu.dk -Y GSSAPI -b 'ou=ADusers,dc=nat,dc=c,dc=sdu,dc=dk' '(&(objectClass=person)(sAMAccountName=imadatestuser))' I can kinit imadatestuser BUT login as imadatestuser and ' getent passwd imadatestuser' doesn't work - still the same error on "port 0" What is "port 0" ??? Ldap_child.log (Fri Nov 9 11:50:07 2012) [[sssd[ldap_child[4438]]]] [unpack_buffer] (0x1000): total buffer size: 37 (Fri Nov 9 11:50:07 2012) [[sssd[ldap_child[4438]]]] [unpack_buffer] (0x1000): realm_str size: 12 (Fri Nov 9 11:50:07 2012) [[sssd[ldap_child[4438]]]] [unpack_buffer] (0x1000): got realm_str: NAT.C.SDU.DK (Fri Nov 9 11:50:07 2012) [[sssd[ldap_child[4438]]]] [unpack_buffer] (0x1000): princ_str size: 9 (Fri Nov 9 11:50:07 2012) [[sssd[ldap_child[4438]]]] [unpack_buffer] (0x1000): got princ_str: VICTORIA$ (Fri Nov 9 11:50:07 2012) [[sssd[ldap_child[4438]]]] [unpack_buffer] (0x1000): keytab_name size: 0 (Fri Nov 9 11:50:07 2012) [[sssd[ldap_child[4438]]]] [unpack_buffer] (0x1000): lifetime: 86400 (Fri Nov 9 11:50:07 2012) [[sssd[ldap_child[4438]]]] [ldap_child_get_tgt_sync] (0x0100): Principal name is: [VICTORIA$(a)NAT.C.SDU.DK] (Fri Nov 9 11:50:07 2012) [[sssd[ldap_child[4438]]]] [ldap_child_get_tgt_sync] (0x0100): Using keytab [default] (Fri Nov 9 11:50:07 2012) [[sssd[ldap_child[4438]]]] [pack_buffer] (0x1000): result [0] krberr [0] msgsize [40] msg [FILE:/var/lib/sss/db/ccache_NAT.C.SDU.DK] (Fri Nov 9 11:51:39 2012) [[sssd[ldap_child[4441]]]] [unpack_buffer] (0x1000): total buffer size: 37 (Fri Nov 9 11:51:39 2012) [[sssd[ldap_child[4441]]]] [unpack_buffer] (0x1000): realm_str size: 12 (Fri Nov 9 11:51:39 2012) [[sssd[ldap_child[4441]]]] [unpack_buffer] (0x1000): got realm_str: NAT.C.SDU.DK (Fri Nov 9 11:51:39 2012) [[sssd[ldap_child[4441]]]] [unpack_buffer] (0x1000): princ_str size: 9 (Fri Nov 9 11:51:39 2012) [[sssd[ldap_child[4441]]]] [unpack_buffer] (0x1000): got princ_str: VICTORIA$ (Fri Nov 9 11:51:39 2012) [[sssd[ldap_child[4441]]]] [unpack_buffer] (0x1000): keytab_name size: 0 (Fri Nov 9 11:51:39 2012) [[sssd[ldap_child[4441]]]] [unpack_buffer] (0x1000): lifetime: 86400 (Fri Nov 9 11:51:39 2012) [[sssd[ldap_child[4441]]]] [ldap_child_get_tgt_sync] (0x0100): Principal name is: [VICTORIA$(a)NAT.C.SDU.DK] (Fri Nov 9 11:51:39 2012) [[sssd[ldap_child[4441]]]] [ldap_child_get_tgt_sync] (0x0100): Using keytab [default] (Fri Nov 9 11:51:39 2012) [[sssd[ldap_child[4441]]]] [pack_buffer] (0x1000): result [0] krberr [0] msgsize [40] msg [FILE:/var/lib/sss/db/ccache_NAT.C.SDU.DK] ...... Sssd_nat.c.sdu.dk.log ..... Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [be_get_account_info] (0x0100): Got request for [4097][1][name=imadatestuser] (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [be_get_account_info] (0x0100): Request processed. Returned 1,11,Fast reply - offline (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'AD' (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [get_server_status] (0x1000): Status of server 'nat.c.sdu.dk' is 'name resolved' (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [get_port_status] (0x1000): Port status of port 0 for server 'nat.c.sdu.dk' is 'not working' (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [get_port_status] (0x0100): Reseting the status of port 0 for server 'nat.c.sdu.dk' (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [get_server_status] (0x1000): Status of server 'nat.c.sdu.dk' is 'name resolved' (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [be_resolve_server_process] (0x1000): Saving the first resolved server (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [be_resolve_server_process] (0x0200): Found address for server nat.c.sdu.dk: [10.144.5.17] TTL 271 (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [ad_resolve_callback] (0x0100): Constructed uri 'ldap://nat.c.sdu.dk' (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_ldap_connect_callback_add] (0x1000): New LDAP connection to [ldap://nat.c.sdu.dk:389/??base] with fd [22]. (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [*] (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [altServer] (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [namingContexts] (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedControl] (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedExtension] (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedFeatures] (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedLDAPVersion] (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [supportedSASLMechanisms] (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [domainControllerFunctionality] (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [defaultNamingContext] (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [lastUSN] (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_generic_ext_step] (0x1000): Requesting attrs: [highestCommittedUSN] (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_get_server_opts_from_rootdse] (0x0100): Setting AD compatibility level to [4] (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_kinit_next_kdc] (0x1000): Resolving next KDC for service AD (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'AD' (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [get_server_status] (0x1000): Status of server 'nat.c.sdu.dk' is 'name resolved' (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [get_server_status] (0x1000): Status of server 'nat.c.sdu.dk' is 'name resolved' (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [be_resolve_server_process] (0x1000): Saving the first resolved server (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [be_resolve_server_process] (0x0200): Found address for server nat.c.sdu.dk: [10.144.5.17] TTL 271 (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sdap_kinit_kdc_resolved] (0x1000): KDC resolved, attempting to get TGT... (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [create_tgt_req_send_buffer] (0x1000): buffer size: 37 (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [child_sig_handler] (0x1000): Waiting for child [4471]. (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [child_sig_handler] (0x0100): child [4471] finished successfully. (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [sasl_bind_send] (0x0100): Executing sasl bind mech: gssapi, user: VICTORIA$ (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [fo_set_port_status] (0x0100): Marking port 0 of server 'nat.c.sdu.dk' as 'not working' (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'AD' (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [get_server_status] (0x1000): Status of server 'nat.c.sdu.dk' is 'name resolved' (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [get_port_status] (0x1000): Port status of port 0 for server 'nat.c.sdu.dk' is 'not working' (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [be_resolve_server_done] (0x1000): Server resolution failed: 5 (Fri Nov 9 12:07:00 2012) [sssd[be[nat.c.sdu.dk]]] [remove_krb5_info_files] (0x0200): Could not remove [/var/lib/sss/pubconf/kpasswdinfo.NAT.C.SDU.DK], [2][No such file or directory] Longina -----Original Message----- From: sssd-users-bounces(a)lists.fedorahosted.org [mailto:sssd-users-bounces@lists.fedorahosted.org] On Behalf Of Jakub Hrozek Sent: 8. november 2012 18:41 To: sssd-users(a)lists.fedorahosted.org Subject: Re: [SSSD-users] startup problem/port status 0 On Thu, Nov 08, 2012 at 03:38:47PM +0000, Longina Przybyszewska wrote: > In /etc/sssd/sssd.conf > > ...... > Ad_hostname = VICTORIA$(a)NAT.C.SDU.DK > ...... It should be "ad_hostname" (note the capital A) and it's only useful for specifying the machine hostname in case the output of hostname command wouldn't reflect the real host name.. Does it work if you set: ad_hostname = VICTORIA$ krb5_realm = NAT.C.SDU.DK (VICTORIA$(a)NAT.C.SDU.DK was the one that worked for you, right?) If it doesn't, can you raise debugging in the domain section, restart the sssd, try again and look for lines that mention "ldap_child" ? You would see the principal used there. > IT is obviously confusing about principal names... > > Longina > > > > > > > -----Original Message----- > From: sssd-users-bounces(a)lists.fedorahosted.org > [mailto:sssd-users-bounces@lists.fedorahosted.org] On Behalf Of Jakub > Hrozek > Sent: 8. november 2012 10:54 > To: sssd-users(a)lists.fedorahosted.org > Subject: Re: [SSSD-users] startup problem/port status 0 > > On Tue, Nov 06, 2012 at 02:16:26PM +0000, Longina Przybyszewska wrote: > > Hi again, > > Thanks a lot for guiding me so far :) > > > > I have got sssd-1.9.2 package from Timo, Ubuntu sssd package maintainer for Ubuntu Quantal. > > > > SSSD is configured against AD as auth/id - provider > > > > sssd.conf > > > > [sssd] > > debug_level = 0x1310 > > config_file_version = 2 > > services = nss, pam > > domains = nat.c.sdu.dk > > > > [nss] > > filter_groups = root > > filter_users = root > > > > [pam] > > > > [domain/nat.c.sdu.dk] > > > > debug_level = 0x1310 > > > > enumerate = False > > min_id = 1000 > > max_id = 20000 > > > > auth_provider = ad > > id_provider = ad > > access_provider = ad > > chpass_provider = ad > > > > ad_server = nat.c.sdu.dk > > ad_hostname = testina4$.nat.c.sdu.dk ad_domain = nat.c.sdu.dk > > > > > > From log: > > (Tue Nov 6 13:42:35 2012) [sssd[be[nat.c.sdu.dk]]] > > [be_resolve_server_process] (0x1000): Saving the first resolved > > server (Tue Nov 6 13:42:35 2012) [sssd[be[nat.c.sdu.dk]]] > > [be_resolve_server_process] (0x0200): Found address for server > > nat.c.sdu.dk: [10.144.5.18] TTL 455 (Tue Nov 6 13:42:35 2012) [sssd[be[nat.c.sdu.dk]]] [sasl_bind_send] (0x0100): Executing sasl bind mech: gssapi, user: testina4$ (Tue Nov 6 13:42:35 2012) [sssd[be[nat.c.sdu.dk]]] [fo_set_port_status] (0x0100): Marking port 0 of server 'nat.c.sdu.dk' as 'not working (Tue Nov 6 13:42:35 2012) [sssd[be[nat.c.sdu.dk]]] [fo_resolve_service_send] (0x0100): Trying to resolve service 'AD' > > (Tue Nov 6 13:42:35 2012) [sssd[be[nat.c.sdu.dk]]] [get_server_status] (0x1000): Status of server 'nat.c.sdu.dk' is 'name resolved' > > (Tue Nov 6 13:42:35 2012) [sssd[be[nat.c.sdu.dk]]] [get_port_status] (0x1000): Port status of port 0 for server 'nat.c.sdu.dk' is 'not working' > > (Tue Nov 6 13:42:35 2012) [sssd[be[nat.c.sdu.dk]]] > > [be_resolve_server_done] (0x1000): Server resolution failed: 5 (Tue > > Nov 6 13:42:35 2012) [sssd[be[nat.c.sdu.dk]]] [acctinfo_callback] > > (0x0100): Request processed. Returned 1,11,Offline (Tue Nov 6 > > 13:42:35 2012) [sssd[be[nat.c.sdu.dk]]] [remove_krb5_info_files] > > (0x0200): Could not remove > > [/var/lib/sss/pubconf/kpasswdinfo.NAT.C.SDU.DK], [2][No such file or > > directory > > > > There is not all the information in the log, raising the debug_level might provide more info, but I think the problem is in the kinit. > > Can you kinit as the principal specified in the ad_hostname and then ldapsearch the directory? > > Are you sure about the principal in ad_hostname? I think it is typically HOST$@DOMAIN, your principal doesn't contain the at-sign. > _______________________________________________ > sssd-users mailing list > sssd-users(a)lists.fedorahosted.org > https://lists.fedorahosted.org/mailman/listinfo/sssd-users > _______________________________________________ > sssd-users mailing list > sssd-users(a)lists.fedorahosted.org > https://lists.fedorahosted.org/mailman/listinfo/sssd-users _______________________________________________ sssd-users mailing list sssd-users(a)lists.fedorahosted.org https://lists.fedorahosted.org/mailman/listinfo/sssd-users

3 7

2024

2023

2022

2021

2020

2019

2018

2017

2016

2015

2014

2013

2012

sssd-users November 2012