SSSD - user id mapping - sssd-users - Fedora Mailing-Lists

Thursday, 26 January 2017

 Hi Everyone,

I am running into a problem with usernames disappearing (and being replaced by their
uids). The prompt in the terminal also changes to "i have no
name!@<HOST>"

Jakub suggested that it could be that the getgr* is failing for some reason

Here is the timestamp for when the error happens:

I have no name!@perf-imglab08:~$ date
Wed Jan 18 17:22:19 EST 2017
I have no name!@perf-imglab08:~$ getent group 1234
I have no name!@perf-imglab08:~$ date
Wed Jan 18 17:22:36 EST 2017

and here are my sssd logs:

sssd.log

(Wed Jan 18 17:22:13 2017) [sssd] [service_send_ping] (0x2000): Pinging concordia.ca
(Wed Jan 18 17:22:13 2017) [sssd] [sbus_add_timeout] (0x2000): 0x146a570
(Wed Jan 18 17:22:13 2017) [sssd] [service_send_ping] (0x2000): Pinging nss
(Wed Jan 18 17:22:13 2017) [sssd] [sbus_add_timeout] (0x2000): 0x1473220
(Wed Jan 18 17:22:13 2017) [sssd] [service_send_ping] (0x2000): Pinging pam
(Wed Jan 18 17:22:13 2017) [sssd] [sbus_add_timeout] (0x2000): 0x146a4e0
(Wed Jan 18 17:22:13 2017) [sssd] [service_send_ping] (0x2000): Pinging ssh
(Wed Jan 18 17:22:13 2017) [sssd] [sbus_add_timeout] (0x2000): 0x1478db0
(Wed Jan 18 17:22:13 2017) [sssd] [service_send_ping] (0x2000): Pinging autofs
(Wed Jan 18 17:22:13 2017) [sssd] [sbus_add_timeout] (0x2000): 0x146a4a0
(Wed Jan 18 17:22:13 2017) [sssd] [sbus_remove_timeout] (0x2000): 0x1473220
(Wed Jan 18 17:22:13 2017) [sssd] [sbus_dispatch] (0x4000): dbus conn: 0x146e7c0
(Wed Jan 18 17:22:13 2017) [sssd] [sbus_dispatch] (0x4000): Dispatching.
(Wed Jan 18 17:22:13 2017) [sssd] [ping_check] (0x2000): Service nss replied to ping
(Wed Jan 18 17:22:13 2017) [sssd] [sbus_remove_timeout] (0x2000): 0x146a570
(Wed Jan 18 17:22:13 2017) [sssd] [sbus_dispatch] (0x4000): dbus conn: 0x1468c00
(Wed Jan 18 17:22:13 2017) [sssd] [sbus_dispatch] (0x4000): Dispatching.
(Wed Jan 18 17:22:13 2017) [sssd] [ping_check] (0x2000): Service concordia.ca replied to
ping
(Wed Jan 18 17:22:13 2017) [sssd] [sbus_remove_timeout] (0x2000): 0x146a4e0
(Wed Jan 18 17:22:13 2017) [sssd] [sbus_dispatch] (0x4000): dbus conn: 0x1474870
(Wed Jan 18 17:22:13 2017) [sssd] [sbus_dispatch] (0x4000): Dispatching.
(Wed Jan 18 17:22:13 2017) [sssd] [ping_check] (0x2000): Service pam replied to ping
(Wed Jan 18 17:22:13 2017) [sssd] [sbus_remove_timeout] (0x2000): 0x1478db0
(Wed Jan 18 17:22:13 2017) [sssd] [sbus_dispatch] (0x4000): dbus conn: 0x14700f0
(Wed Jan 18 17:22:13 2017) [sssd] [sbus_dispatch] (0x4000): Dispatching.
(Wed Jan 18 17:22:13 2017) [sssd] [ping_check] (0x2000): Service ssh replied to ping
(Wed Jan 18 17:22:13 2017) [sssd] [sbus_remove_timeout] (0x2000): 0x146a4a0
(Wed Jan 18 17:22:13 2017) [sssd] [sbus_dispatch] (0x4000): dbus conn: 0x1471e30
(Wed Jan 18 17:22:13 2017) [sssd] [sbus_dispatch] (0x4000): Dispatching.
(Wed Jan 18 17:22:13 2017) [sssd] [ping_check] (0x2000): Service autofs replied to ping
(Wed Jan 18 17:22:23 2017) [sssd] [service_send_ping] (0x2000): Pinging concordia.ca
(Wed Jan 18 17:22:23 2017) [sssd] [sbus_add_timeout] (0x2000): 0x146a4a0
(Wed Jan 18 17:22:23 2017) [sssd] [service_send_ping] (0x2000): Pinging nss
(Wed Jan 18 17:22:23 2017) [sssd] [sbus_add_timeout] (0x2000): 0x1478db0
(Wed Jan 18 17:22:23 2017) [sssd] [service_send_ping] (0x2000): Pinging pam
(Wed Jan 18 17:22:23 2017) [sssd] [sbus_add_timeout] (0x2000): 0x146a4e0
(Wed Jan 18 17:22:23 2017) [sssd] [service_send_ping] (0x2000): Pinging ssh
(Wed Jan 18 17:22:23 2017) [sssd] [sbus_add_timeout] (0x2000): 0x146a570
(Wed Jan 18 17:22:23 2017) [sssd] [service_send_ping] (0x2000): Pinging autofs
(Wed Jan 18 17:22:23 2017) [sssd] [sbus_add_timeout] (0x2000): 0x1473220
(Wed Jan 18 17:22:23 2017) [sssd] [sbus_remove_timeout] (0x2000): 0x1478db0
(Wed Jan 18 17:22:23 2017) [sssd] [sbus_dispatch] (0x4000): dbus conn: 0x146e7c0
(Wed Jan 18 17:22:23 2017) [sssd] [sbus_dispatch] (0x4000): Dispatching.
(Wed Jan 18 17:22:23 2017) [sssd] [ping_check] (0x2000): Service nss replied to ping
(Wed Jan 18 17:22:23 2017) [sssd] [sbus_remove_timeout] (0x2000): 0x146a4e0
(Wed Jan 18 17:22:23 2017) [sssd] [sbus_dispatch] (0x4000): dbus conn: 0x1474870
(Wed Jan 18 17:22:23 2017) [sssd] [sbus_dispatch] (0x4000): Dispatching.
(Wed Jan 18 17:22:23 2017) [sssd] [ping_check] (0x2000): Service pam replied to ping
(Wed Jan 18 17:22:23 2017) [sssd] [sbus_remove_timeout] (0x2000): 0x146a570
(Wed Jan 18 17:22:23 2017) [sssd] [sbus_dispatch] (0x4000): dbus conn: 0x14700f0
(Wed Jan 18 17:22:23 2017) [sssd] [sbus_dispatch] (0x4000): Dispatching.
(Wed Jan 18 17:22:23 2017) [sssd] [ping_check] (0x2000): Service ssh replied to ping
(Wed Jan 18 17:22:23 2017) [sssd] [sbus_remove_timeout] (0x2000): 0x146a4a0
(Wed Jan 18 17:22:23 2017) [sssd] [sbus_dispatch] (0x4000): dbus conn: 0x1468c00
(Wed Jan 18 17:22:23 2017) [sssd] [sbus_dispatch] (0x4000): Dispatching.
(Wed Jan 18 17:22:23 2017) [sssd] [ping_check] (0x2000): Service concordia.ca replied to
ping
(Wed Jan 18 17:22:23 2017) [sssd] [sbus_remove_timeout] (0x2000): 0x1473220
(Wed Jan 18 17:22:23 2017) [sssd] [sbus_dispatch] (0x4000): dbus conn: 0x1471e30
(Wed Jan 18 17:22:23 2017) [sssd] [sbus_dispatch] (0x4000): Dispatching.
(Wed Jan 18 17:22:23 2017) [sssd] [ping_check] (0x2000): Service autofs replied to ping
(Wed Jan 18 17:22:33 2017) [sssd] [service_send_ping] (0x2000): Pinging concordia.ca
(Wed Jan 18 17:22:33 2017) [sssd] [sbus_add_timeout] (0x2000): 0x1473220
(Wed Jan 18 17:22:33 2017) [sssd] [service_send_ping] (0x2000): Pinging nss
(Wed Jan 18 17:22:33 2017) [sssd] [sbus_add_timeout] (0x2000): 0x146a4a0
(Wed Jan 18 17:22:33 2017) [sssd] [service_send_ping] (0x2000): Pinging pam
(Wed Jan 18 17:22:33 2017) [sssd] [sbus_add_timeout] (0x2000): 0x146a570
(Wed Jan 18 17:22:33 2017) [sssd] [service_send_ping] (0x2000): Pinging ssh
(Wed Jan 18 17:22:33 2017) [sssd] [sbus_add_timeout] (0x2000): 0x146a4e0
(Wed Jan 18 17:22:33 2017) [sssd] [service_send_ping] (0x2000): Pinging autofs
(Wed Jan 18 17:22:33 2017) [sssd] [sbus_add_timeout] (0x2000): 0x1478db0
(Wed Jan 18 17:22:33 2017) [sssd] [sbus_remove_timeout] (0x2000): 0x146a4a0
(Wed Jan 18 17:22:33 2017) [sssd] [sbus_dispatch] (0x4000): dbus conn: 0x146e7c0
(Wed Jan 18 17:22:33 2017) [sssd] [sbus_dispatch] (0x4000): Dispatching.
(Wed Jan 18 17:22:33 2017) [sssd] [ping_check] (0x2000): Service nss replied to ping
(Wed Jan 18 17:22:33 2017) [sssd] [sbus_remove_timeout] (0x2000): 0x146a570
(Wed Jan 18 17:22:33 2017) [sssd] [sbus_dispatch] (0x4000): dbus conn: 0x1474870
(Wed Jan 18 17:22:33 2017) [sssd] [sbus_dispatch] (0x4000): Dispatching.
(Wed Jan 18 17:22:33 2017) [sssd] [ping_check] (0x2000): Service pam replied to ping
(Wed Jan 18 17:22:33 2017) [sssd] [sbus_remove_timeout] (0x2000): 0x1473220
(Wed Jan 18 17:22:33 2017) [sssd] [sbus_dispatch] (0x4000): dbus conn: 0x1468c00
(Wed Jan 18 17:22:33 2017) [sssd] [sbus_dispatch] (0x4000): Dispatching.
(Wed Jan 18 17:22:33 2017) [sssd] [ping_check] (0x2000): Service concordia.ca replied to
ping
(Wed Jan 18 17:22:33 2017) [sssd] [sbus_remove_timeout] (0x2000): 0x146a4e0
(Wed Jan 18 17:22:33 2017) [sssd] [sbus_dispatch] (0x4000): dbus conn: 0x14700f0
(Wed Jan 18 17:22:33 2017) [sssd] [sbus_dispatch] (0x4000): Dispatching.
(Wed Jan 18 17:22:33 2017) [sssd] [ping_check] (0x2000): Service ssh replied to ping
(Wed Jan 18 17:22:33 2017) [sssd] [sbus_remove_timeout] (0x2000): 0x1478db0
(Wed Jan 18 17:22:33 2017) [sssd] [sbus_dispatch] (0x4000): dbus conn: 0x1471e30
(Wed Jan 18 17:22:33 2017) [sssd] [sbus_dispatch] (0x4000): Dispatching.
(Wed Jan 18 17:22:33 2017) [sssd] [ping_check] (0x2000): Service autofs replied to ping
(Wed Jan 18 17:22:43 2017) [sssd] [service_send_ping] (0x2000): Pinging concordia.ca
(Wed Jan 18 17:22:43 2017) [sssd] [sbus_add_timeout] (0x2000): 0x1478db0
(Wed Jan 18 17:22:43 2017) [sssd] [service_send_ping] (0x2000): Pinging nss
(Wed Jan 18 17:22:43 2017) [sssd] [sbus_add_timeout] (0x2000): 0x146a4e0
(Wed Jan 18 17:22:43 2017) [sssd] [service_send_ping] (0x2000): Pinging pam
(Wed Jan 18 17:22:43 2017) [sssd] [sbus_add_timeout] (0x2000): 0x1473220
(Wed Jan 18 17:22:43 2017) [sssd] [service_send_ping] (0x2000): Pinging ssh
(Wed Jan 18 17:22:43 2017) [sssd] [sbus_add_timeout] (0x2000): 0x146a570
(Wed Jan 18 17:22:43 2017) [sssd] [service_send_ping] (0x2000): Pinging autofs
(Wed Jan 18 17:22:43 2017) [sssd] [sbus_add_timeout] (0x2000): 0x146a4a0
(Wed Jan 18 17:22:43 2017) [sssd] [sbus_remove_timeout] (0x2000): 0x146a4e0
(Wed Jan 18 17:22:43 2017) [sssd] [sbus_dispatch] (0x4000): dbus conn: 0x146e7c0
(Wed Jan 18 17:22:43 2017) [sssd] [sbus_dispatch] (0x4000): Dispatching.
(Wed Jan 18 17:22:43 2017) [sssd] [ping_check] (0x2000): Service nss replied to ping
(Wed Jan 18 17:22:43 2017) [sssd] [sbus_remove_timeout] (0x2000): 0x1473220
(Wed Jan 18 17:22:43 2017) [sssd] [sbus_dispatch] (0x4000): dbus conn: 0x1474870
(Wed Jan 18 17:22:43 2017) [sssd] [sbus_dispatch] (0x4000): Dispatching.
(Wed Jan 18 17:22:43 2017) [sssd] [ping_check] (0x2000): Service pam replied to ping
(Wed Jan 18 17:22:43 2017) [sssd] [sbus_remove_timeout] (0x2000): 0x1478db0
(Wed Jan 18 17:22:43 2017) [sssd] [sbus_dispatch] (0x4000): dbus conn: 0x1468c00
(Wed Jan 18 17:22:43 2017) [sssd] [sbus_dispatch] (0x4000): Dispatching.
(Wed Jan 18 17:22:43 2017) [sssd] [ping_check] (0x2000): Service concordia.ca replied to
ping
(Wed Jan 18 17:22:43 2017) [sssd] [sbus_remove_timeout] (0x2000): 0x146a570
(Wed Jan 18 17:22:43 2017) [sssd] [sbus_dispatch] (0x4000): dbus conn: 0x14700f0
(Wed Jan 18 17:22:43 2017) [sssd] [sbus_dispatch] (0x4000): Dispatching.
(Wed Jan 18 17:22:43 2017) [sssd] [ping_check] (0x2000): Service ssh replied to ping
(Wed Jan 18 17:22:43 2017) [sssd] [sbus_remove_timeout] (0x2000): 0x146a4a0
(Wed Jan 18 17:22:43 2017) [sssd] [sbus_dispatch] (0x4000): dbus conn: 0x1471e30
(Wed Jan 18 17:22:43 2017) [sssd] [sbus_dispatch] (0x4000): Dispatching.
(Wed Jan 18 17:22:43 2017) [sssd] [ping_check] (0x2000): Service autofs replied to ping

sssd_concordia.ca.log

(Wed Jan 18 17:22:13 2017) [sssd[be[concordia.ca]]] [sbus_dispatch] (0x4000): dbus conn:
0xaa5740
(Wed Jan 18 17:22:13 2017) [sssd[be[concordia.ca]]] [sbus_dispatch] (0x4000):
Dispatching.
(Wed Jan 18 17:22:13 2017) [sssd[be[concordia.ca]]] [sbus_message_handler] (0x2000):
Received SBUS method org.freedesktop.sssd.service.ping on path
/org/freedesktop/sssd/service
(Wed Jan 18 17:22:13 2017) [sssd[be[concordia.ca]]] [sbus_get_sender_id_send] (0x2000):
Not a sysbus message, quit
(Wed Jan 18 17:22:23 2017) [sssd[be[concordia.ca]]] [sbus_dispatch] (0x4000): dbus conn:
0xaa5740
(Wed Jan 18 17:22:23 2017) [sssd[be[concordia.ca]]] [sbus_dispatch] (0x4000):
Dispatching.
(Wed Jan 18 17:22:23 2017) [sssd[be[concordia.ca]]] [sbus_message_handler] (0x2000):
Received SBUS method org.freedesktop.sssd.service.ping on path
/org/freedesktop/sssd/service
(Wed Jan 18 17:22:23 2017) [sssd[be[concordia.ca]]] [sbus_get_sender_id_send] (0x2000):
Not a sysbus message, quit
(Wed Jan 18 17:22:33 2017) [sssd[be[concordia.ca]]] [sbus_dispatch] (0x4000): dbus conn:
0xaa5740
(Wed Jan 18 17:22:33 2017) [sssd[be[concordia.ca]]] [sbus_dispatch] (0x4000):
Dispatching.
(Wed Jan 18 17:22:33 2017) [sssd[be[concordia.ca]]] [sbus_message_handler] (0x2000):
Received SBUS method org.freedesktop.sssd.service.ping on path
/org/freedesktop/sssd/service
(Wed Jan 18 17:22:33 2017) [sssd[be[concordia.ca]]] [sbus_get_sender_id_send] (0x2000):
Not a sysbus message, quit
(Wed Jan 18 17:22:33 2017) [sssd[be[concordia.ca]]] [sbus_dispatch] (0x4000): dbus conn:
0xaeeb80
(Wed Jan 18 17:22:33 2017) [sssd[be[concordia.ca]]] [sbus_dispatch] (0x4000):
Dispatching.
(Wed Jan 18 17:22:33 2017) [sssd[be[concordia.ca]]] [sbus_message_handler] (0x2000):
Received SBUS method org.freedesktop.sssd.dataprovider.getAccountInfo on path
/org/freedesktop/sssd/dataprovider
(Wed Jan 18 17:22:33 2017) [sssd[be[concordia.ca]]] [sbus_get_sender_id_send] (0x2000):
Not a sysbus message, quit
(Wed Jan 18 17:22:33 2017) [sssd[be[concordia.ca]]] [be_get_account_info] (0x0200): Got
request for [0x1002][FAST BE_REQ_GROUP][1][idnumber=1234]
(Wed Jan 18 17:22:33 2017) [sssd[be[concordia.ca]]] [be_get_account_info] (0x0100):
Request processed. Returned 1,11,Fast reply - offline
(Wed Jan 18 17:22:33 2017) [sssd[be[concordia.ca]]] [be_req_set_domain] (0x0400): Changing
request domain from [concordia.ca] to [concordia.ca]
(Wed Jan 18 17:22:33 2017) [sssd[be[concordia.ca]]] [sbus_dispatch] (0x4000): dbus conn:
0xaeeb80
(Wed Jan 18 17:22:33 2017) [sssd[be[concordia.ca]]] [sbus_dispatch] (0x4000):
Dispatching.
(Wed Jan 18 17:22:33 2017) [sssd[be[concordia.ca]]] [sbus_message_handler] (0x2000):
Received SBUS method org.freedesktop.sssd.dataprovider.getAccountInfo on path
/org/freedesktop/sssd/dataprovider
(Wed Jan 18 17:22:33 2017) [sssd[be[concordia.ca]]] [sbus_get_sender_id_send] (0x2000):
Not a sysbus message, quit
(Wed Jan 18 17:22:33 2017) [sssd[be[concordia.ca]]] [be_get_account_info] (0x0200): Got
request for [0x1002][FAST BE_REQ_GROUP][1][idnumber=1234]
(Wed Jan 18 17:22:33 2017) [sssd[be[concordia.ca]]] [be_get_account_info] (0x0100):
Request processed. Returned 1,11,Fast reply - offline
(Wed Jan 18 17:22:33 2017) [sssd[be[concordia.ca]]] [be_req_set_domain] (0x0400): Changing
request domain from [concordia.ca] to [forestroot.concordia.montreal.qc.ca]
(Wed Jan 18 17:22:43 2017) [sssd[be[concordia.ca]]] [sbus_dispatch] (0x4000): dbus conn:
0xaa5740
(Wed Jan 18 17:22:43 2017) [sssd[be[concordia.ca]]] [sbus_dispatch] (0x4000):
Dispatching.
(Wed Jan 18 17:22:43 2017) [sssd[be[concordia.ca]]] [sbus_message_handler] (0x2000):
Received SBUS method org.freedesktop.sssd.service.ping on path
/org/freedesktop/sssd/service
(Wed Jan 18 17:22:43 2017) [sssd[be[concordia.ca]]] [sbus_get_sender_id_send] (0x2000):
Not a sysbus message, quit

ldap_child.log

(Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [main] (0x0400): ldap_child
started.
(Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [main] (0x2000): context
initialized
(Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [unpack_buffer] (0x1000): total
buffer size: 50
(Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [unpack_buffer] (0x1000): realm_str
size: 12
(Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [unpack_buffer] (0x1000): got
realm_str: CONCORDIA.CA
(Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [unpack_buffer] (0x1000): princ_str
size: 14
(Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [unpack_buffer] (0x1000): got
princ_str: PERF-IMGLAB08$
(Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [unpack_buffer] (0x1000):
keytab_name size: 0
(Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [unpack_buffer] (0x1000): lifetime:
86400
(Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [unpack_buffer] (0x0200): Will run
as [0][0].
(Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [privileged_krb5_setup] (0x2000):
Kerberos context initialized
(Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [main] (0x2000): Kerberos context
initialized
(Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [become_user] (0x0200): Trying to
become user [0][0].
(Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [become_user] (0x0200): Already
user [0].
(Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [main] (0x2000): Running as
[0][0].
(Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [main] (0x2000): getting TGT sync
(Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [ldap_child_get_tgt_sync] (0x2000):
got realm_name: [CONCORDIA.CA]
(Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [ldap_child_get_tgt_sync] (0x0100):
Principal name is: [PERF-IMGLAB08$(a)CONCORDIA.CA]
(Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [ldap_child_get_tgt_sync] (0x0100):
Using keytab [MEMORY:/etc/krb5.keytab]
(Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000):
[25844] 1484778122.728189: Getting initial credentials for PERF-IMGLAB08$(a)CONCORDIA.CA
(Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000):
[25844] 1484778122.728262: Looked up etypes in keytab: des-cbc-crc, des, des-cbc-crc,
rc4-hmac, aes128-cts, aes256-cts
(Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000):
[25844] 1484778122.728291: Sending request (195 bytes) to CONCORDIA.CA
(Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000):
[25844] 1484778122.728317: Resolving hostname Int-con-dc-1.concordia.ca
(Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000):
[25844] 1484778122.729762: Sending initial UDP request to dgram 132.205.123.21:88
(Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000):
[25844] 1484778122.731123: Received answer (210 bytes) from dgram 132.205.123.21:88
(Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000):
[25844] 1484778122.734046: Response was not from master KDC
(Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000):
[25844] 1484778122.734082: Received error from KDC: -1765328359/Additional
pre-authentication required
(Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000):
[25844] 1484778122.734104: Processing preauth types: 16, 15, 19, 2
(Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000):
[25844] 1484778122.734112: Selected etype info: etype aes256-cts, salt
"CONCORDIA.CAhostperf-imglab08.concordia.ca", params ""
(Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000):
[25844] 1484778122.734127: Retrieving PERF-IMGLAB08$(a)CONCORDIA.CA from
MEMORY:/etc/krb5.keytab (vno 0, enctype aes256-cts) with result: 0/Success
(Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000):
[25844] 1484778122.734137: AS key obtained for encrypted timestamp: aes256-cts/FC36
(Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000):
[25844] 1484778122.734161: Encrypted timestamp (for 1484778122.795789): plain
301AA011180F32303137303131383232323230325AA10502030C248D, encrypted
77571640DED5412F7668B68A1684793B574BFD047B5D9F7CC62D4197B088FB59018B3BB6E748E651507780452E6B4E8CC31F67FF4A31EEBD
(Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000):
[25844] 1484778122.734168: Preauth module encrypted_timestamp (2) (real) returned:
0/Success
(Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000):
[25844] 1484778122.734173: Produced preauth for next request: 2
(Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000):
[25844] 1484778122.734189: Sending request (275 bytes) to CONCORDIA.CA
(Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000):
[25844] 1484778122.734196: Resolving hostname Int-con-dc-1.concordia.ca
(Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000):
[25844] 1484778122.735879: Sending initial UDP request to dgram 132.205.123.21:88
(Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000):
[25844] 1484778122.737712: Received answer (96 bytes) from dgram 132.205.123.21:88
(Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000):
[25844] 1484778122.739940: Response was not from master KDC
(Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000):
[25844] 1484778122.739968: Received error from KDC: -1765328332/Response too big for UDP,
retry with TCP
(Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000):
[25844] 1484778122.739978: Request or response is too big for UDP; retrying with TCP
(Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000):
[25844] 1484778122.739986: Sending request (275 bytes) to CONCORDIA.CA (tcp only)
(Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000):
[25844] 1484778122.739996: Resolving hostname Int-con-dc-1.concordia.ca
(Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000):
[25844] 1484778122.741680: Initiating TCP connection to stream 132.205.123.21:88
(Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000):
[25844] 1484778122.742475: Sending TCP request to stream 132.205.123.21:88
(Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000):
[25844] 1484778122.744227: Received answer (1508 bytes) from stream 132.205.123.21:88
(Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000):
[25844] 1484778122.744240: Terminating TCP connection to stream 132.205.123.21:88
(Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000):
[25844] 1484778122.745376: Response was not from master KDC
(Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000):
[25844] 1484778122.745404: Processing preauth types: 19
(Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000):
[25844] 1484778122.745412: Selected etype info: etype aes256-cts, salt
"CONCORDIA.CAhostperf-imglab08.concordia.ca", params ""
(Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000):
[25844] 1484778122.745419: Produced preauth for next request: (empty)
(Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000):
[25844] 1484778122.745425: AS key determined by preauth: aes256-cts/FC36
(Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000):
[25844] 1484778122.745450: Decrypted AS reply; session key is: aes256-cts/7A2A
(Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000):
[25844] 1484778122.745455: FAST negotiation: unavailable
(Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [ldap_child_get_tgt_sync] (0x2000):
credentials initialized
(Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [ldap_child_get_tgt_sync] (0x2000):
keytab ccname: [FILE:/var/lib/sss/db/ccache_CONCORDIA.CA_OaPYPl]
(Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000):
[25844] 1484778122.745483: Initializing FILE:/var/lib/sss/db/ccache_CONCORDIA.CA_OaPYPl
with default princ PERF-IMGLAB08$(a)CONCORDIA.CA
(Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [sss_child_krb5_trace_cb] (0x4000):
[25844] 1484778122.745537: Storing PERF-IMGLAB08$(a)CONCORDIA.CA ->
krbtgt/CONCORDIA.CA(a)CONCORDIA.CA in FILE:/var/lib/sss/db/ccache_CONCORDIA.CA_OaPYPl
(Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [ldap_child_get_tgt_sync] (0x2000):
credentials stored
(Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [ldap_child_get_tgt_sync] (0x2000):
Got KDC time offset
(Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [ldap_child_get_tgt_sync] (0x2000):
Renaming [/var/lib/sss/db/ccache_CONCORDIA.CA_OaPYPl] to
[/var/lib/sss/db/ccache_CONCORDIA.CA]
(Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [unique_filename_destructor]
(0x2000): Unlinking [/var/lib/sss/db/ccache_CONCORDIA.CA_OaPYPl]
(Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [unlink_dbg] (0x2000): File already
removed: [/var/lib/sss/db/ccache_CONCORDIA.CA_OaPYPl]
(Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [prepare_response] (0x0400):
Building response for result [0]
(Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [pack_buffer] (0x2000): response
size: 60
(Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [pack_buffer] (0x1000): result [0]
krberr [0] msgsize [40] msg [FILE:/var/lib/sss/db/ccache_CONCORDIA.CA]
(Wed Jan 18 17:22:02 2017) [[sssd[ldap_child[25844]]]] [main] (0x0400): ldap_child
completed successfully
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [main] (0x0400): ldap_child
started.
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [main] (0x2000): context
initialized
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [unpack_buffer] (0x1000): total
buffer size: 50
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [unpack_buffer] (0x1000): realm_str
size: 12
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [unpack_buffer] (0x1000): got
realm_str: CONCORDIA.CA
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [unpack_buffer] (0x1000): princ_str
size: 14
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [unpack_buffer] (0x1000): got
princ_str: PERF-IMGLAB08$
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [unpack_buffer] (0x1000):
keytab_name size: 0
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [unpack_buffer] (0x1000): lifetime:
86400
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [unpack_buffer] (0x0200): Will run
as [0][0].
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [privileged_krb5_setup] (0x2000):
Kerberos context initialized
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [main] (0x2000): Kerberos context
initialized
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [become_user] (0x0200): Trying to
become user [0][0].
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [become_user] (0x0200): Already
user [0].
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [main] (0x2000): Running as
[0][0].
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [main] (0x2000): getting TGT sync
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [ldap_child_get_tgt_sync] (0x2000):
got realm_name: [CONCORDIA.CA]
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [ldap_child_get_tgt_sync] (0x0100):
Principal name is: [PERF-IMGLAB08$(a)CONCORDIA.CA]
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [ldap_child_get_tgt_sync] (0x0100):
Using keytab [MEMORY:/etc/krb5.keytab]
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000):
[25873] 1484778188.791179: Getting initial credentials for PERF-IMGLAB08$(a)CONCORDIA.CA
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000):
[25873] 1484778188.791382: Looked up etypes in keytab: des-cbc-crc, des, des-cbc-crc,
rc4-hmac, aes128-cts, aes256-cts
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000):
[25873] 1484778188.791490: Sending request (195 bytes) to CONCORDIA.CA
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000):
[25873] 1484778188.791569: Resolving hostname Int-con-dc-1.concordia.ca
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000):
[25873] 1484778188.793862: Sending initial UDP request to dgram 132.205.123.21:88
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000):
[25873] 1484778188.795622: Received answer (210 bytes) from dgram 132.205.123.21:88
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000):
[25873] 1484778188.798139: Response was not from master KDC
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000):
[25873] 1484778188.798175: Received error from KDC: -1765328359/Additional
pre-authentication required
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000):
[25873] 1484778188.798194: Processing preauth types: 16, 15, 19, 2
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000):
[25873] 1484778188.798201: Selected etype info: etype aes256-cts, salt
"CONCORDIA.CAhostperf-imglab08.concordia.ca", params ""
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000):
[25873] 1484778188.798214: Retrieving PERF-IMGLAB08$(a)CONCORDIA.CA from
MEMORY:/etc/krb5.keytab (vno 0, enctype aes256-cts) with result: 0/Success
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000):
[25873] 1484778188.798226: AS key obtained for encrypted timestamp: aes256-cts/FC36
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000):
[25873] 1484778188.798251: Encrypted timestamp (for 1484778188.864327): plain
301AA011180F32303137303131383232323330385AA10502030D3047, encrypted
D1207C76AB678F2BBC0336F2F2EE373DF28682250D27A98B1249180CF5319FC7199D6018C0A44399945C235ECF9B295704D6EAEC3F5FF5FD
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000):
[25873] 1484778188.798259: Preauth module encrypted_timestamp (2) (real) returned:
0/Success
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000):
[25873] 1484778188.798264: Produced preauth for next request: 2
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000):
[25873] 1484778188.798278: Sending request (275 bytes) to CONCORDIA.CA
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000):
[25873] 1484778188.798286: Resolving hostname Int-con-dc-1.concordia.ca
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000):
[25873] 1484778188.799446: Sending initial UDP request to dgram 132.205.123.21:88
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000):
[25873] 1484778188.801292: Received answer (96 bytes) from dgram 132.205.123.21:88
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000):
[25873] 1484778188.803814: Response was not from master KDC
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000):
[25873] 1484778188.803836: Received error from KDC: -1765328332/Response too big for UDP,
retry with TCP
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000):
[25873] 1484778188.803844: Request or response is too big for UDP; retrying with TCP
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000):
[25873] 1484778188.803850: Sending request (275 bytes) to CONCORDIA.CA (tcp only)
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000):
[25873] 1484778188.803858: Resolving hostname Int-con-dc-1.concordia.ca
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000):
[25873] 1484778188.805392: Initiating TCP connection to stream 132.205.123.21:88
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000):
[25873] 1484778188.806522: Sending TCP request to stream 132.205.123.21:88
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000):
[25873] 1484778188.808296: Received answer (1508 bytes) from stream 132.205.123.21:88
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000):
[25873] 1484778188.808314: Terminating TCP connection to stream 132.205.123.21:88
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000):
[25873] 1484778188.809712: Response was not from master KDC
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000):
[25873] 1484778188.809737: Processing preauth types: 19
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000):
[25873] 1484778188.809747: Selected etype info: etype aes256-cts, salt
"CONCORDIA.CAhostperf-imglab08.concordia.ca", params ""
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000):
[25873] 1484778188.809755: Produced preauth for next request: (empty)
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000):
[25873] 1484778188.809763: AS key determined by preauth: aes256-cts/FC36
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000):
[25873] 1484778188.809790: Decrypted AS reply; session key is: aes256-cts/A0EB
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000):
[25873] 1484778188.809796: FAST negotiation: unavailable
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [ldap_child_get_tgt_sync] (0x2000):
credentials initialized
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [ldap_child_get_tgt_sync] (0x2000):
keytab ccname: [FILE:/var/lib/sss/db/ccache_CONCORDIA.CA_btC2E5]
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000):
[25873] 1484778188.809829: Initializing FILE:/var/lib/sss/db/ccache_CONCORDIA.CA_btC2E5
with default princ PERF-IMGLAB08$(a)CONCORDIA.CA
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [sss_child_krb5_trace_cb] (0x4000):
[25873] 1484778188.809880: Storing PERF-IMGLAB08$(a)CONCORDIA.CA ->
krbtgt/CONCORDIA.CA(a)CONCORDIA.CA in FILE:/var/lib/sss/db/ccache_CONCORDIA.CA_btC2E5
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [ldap_child_get_tgt_sync] (0x2000):
credentials stored
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [ldap_child_get_tgt_sync] (0x2000):
Got KDC time offset
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [ldap_child_get_tgt_sync] (0x2000):
Renaming [/var/lib/sss/db/ccache_CONCORDIA.CA_btC2E5] to
[/var/lib/sss/db/ccache_CONCORDIA.CA]
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [unique_filename_destructor]
(0x2000): Unlinking [/var/lib/sss/db/ccache_CONCORDIA.CA_btC2E5]
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [unlink_dbg] (0x2000): File already
removed: [/var/lib/sss/db/ccache_CONCORDIA.CA_btC2E5]
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [prepare_response] (0x0400):
Building response for result [0]
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [pack_buffer] (0x2000): response
size: 60
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [pack_buffer] (0x1000): result [0]
krberr [0] msgsize [40] msg [FILE:/var/lib/sss/db/ccache_CONCORDIA.CA]
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25873]]]] [main] (0x0400): ldap_child
completed successfully
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [main] (0x0400): ldap_child
started.
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [main] (0x2000): context
initialized
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [unpack_buffer] (0x1000): total
buffer size: 50
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [unpack_buffer] (0x1000): realm_str
size: 12
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [unpack_buffer] (0x1000): got
realm_str: CONCORDIA.CA
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [unpack_buffer] (0x1000): princ_str
size: 14
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [unpack_buffer] (0x1000): got
princ_str: PERF-IMGLAB08$
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [unpack_buffer] (0x1000):
keytab_name size: 0
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [unpack_buffer] (0x1000): lifetime:
86400
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [unpack_buffer] (0x0200): Will run
as [0][0].
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [privileged_krb5_setup] (0x2000):
Kerberos context initialized
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [main] (0x2000): Kerberos context
initialized
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [become_user] (0x0200): Trying to
become user [0][0].
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [become_user] (0x0200): Already
user [0].
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [main] (0x2000): Running as
[0][0].
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [main] (0x2000): getting TGT sync
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [ldap_child_get_tgt_sync] (0x2000):
got realm_name: [CONCORDIA.CA]
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [ldap_child_get_tgt_sync] (0x0100):
Principal name is: [PERF-IMGLAB08$(a)CONCORDIA.CA]
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [ldap_child_get_tgt_sync] (0x0100):
Using keytab [MEMORY:/etc/krb5.keytab]
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000):
[25874] 1484778188.911434: Getting initial credentials for PERF-IMGLAB08$(a)CONCORDIA.CA
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000):
[25874] 1484778188.911637: Looked up etypes in keytab: des-cbc-crc, des, des-cbc-crc,
rc4-hmac, aes128-cts, aes256-cts
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000):
[25874] 1484778188.911713: Sending request (195 bytes) to CONCORDIA.CA
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000):
[25874] 1484778188.911787: Resolving hostname Int-con-dc-1.concordia.ca
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000):
[25874] 1484778188.914393: Sending initial UDP request to dgram 132.205.123.21:88
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000):
[25874] 1484778188.915860: Received answer (210 bytes) from dgram 132.205.123.21:88
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000):
[25874] 1484778188.918866: Response was not from master KDC
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000):
[25874] 1484778188.918976: Received error from KDC: -1765328359/Additional
pre-authentication required
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000):
[25874] 1484778188.919054: Processing preauth types: 16, 15, 19, 2
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000):
[25874] 1484778188.919087: Selected etype info: etype aes256-cts, salt
"CONCORDIA.CAhostperf-imglab08.concordia.ca", params ""
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000):
[25874] 1484778188.919141: Retrieving PERF-IMGLAB08$(a)CONCORDIA.CA from
MEMORY:/etc/krb5.keytab (vno 0, enctype aes256-cts) with result: 0/Success
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000):
[25874] 1484778188.919180: AS key obtained for encrypted timestamp: aes256-cts/FC36
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000):
[25874] 1484778188.919280: Encrypted timestamp (for 1484778188.973670): plain
301AA011180F32303137303131383232323330385AA10502030EDB66, encrypted
D33317E3C9292ABF582F8D1E389DF6A3B5FFABFC7E0420B45A45B610EFD80E1D9C19CE9AAE0D7959B44E0773747AC7B0DCB56C9DFBF97DA3
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000):
[25874] 1484778188.919315: Preauth module encrypted_timestamp (2) (real) returned:
0/Success
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000):
[25874] 1484778188.919337: Produced preauth for next request: 2
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000):
[25874] 1484778188.919431: Sending request (275 bytes) to CONCORDIA.CA
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000):
[25874] 1484778188.919472: Resolving hostname Int-con-dc-1.concordia.ca
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000):
[25874] 1484778188.921847: Sending initial UDP request to dgram 132.205.123.21:88
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000):
[25874] 1484778188.924168: Received answer (96 bytes) from dgram 132.205.123.21:88
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000):
[25874] 1484778188.927183: Response was not from master KDC
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000):
[25874] 1484778188.927216: Received error from KDC: -1765328332/Response too big for UDP,
retry with TCP
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000):
[25874] 1484778188.927222: Request or response is too big for UDP; retrying with TCP
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000):
[25874] 1484778188.927227: Sending request (275 bytes) to CONCORDIA.CA (tcp only)
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000):
[25874] 1484778188.927234: Resolving hostname Int-con-dc-1.concordia.ca
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000):
[25874] 1484778188.928427: Initiating TCP connection to stream 132.205.123.21:88
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000):
[25874] 1484778188.929201: Sending TCP request to stream 132.205.123.21:88
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000):
[25874] 1484778188.931067: Received answer (1508 bytes) from stream 132.205.123.21:88
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000):
[25874] 1484778188.931080: Terminating TCP connection to stream 132.205.123.21:88
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000):
[25874] 1484778188.932326: Response was not from master KDC
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000):
[25874] 1484778188.932365: Processing preauth types: 19
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000):
[25874] 1484778188.932374: Selected etype info: etype aes256-cts, salt
"CONCORDIA.CAhostperf-imglab08.concordia.ca", params ""
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000):
[25874] 1484778188.932380: Produced preauth for next request: (empty)
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000):
[25874] 1484778188.932387: AS key determined by preauth: aes256-cts/FC36
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000):
[25874] 1484778188.932409: Decrypted AS reply; session key is: aes256-cts/C509
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000):
[25874] 1484778188.932415: FAST negotiation: unavailable
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [ldap_child_get_tgt_sync] (0x2000):
credentials initialized
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [ldap_child_get_tgt_sync] (0x2000):
keytab ccname: [FILE:/var/lib/sss/db/ccache_CONCORDIA.CA_BHwy1c]
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000):
[25874] 1484778188.932442: Initializing FILE:/var/lib/sss/db/ccache_CONCORDIA.CA_BHwy1c
with default princ PERF-IMGLAB08$(a)CONCORDIA.CA
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [sss_child_krb5_trace_cb] (0x4000):
[25874] 1484778188.932486: Storing PERF-IMGLAB08$(a)CONCORDIA.CA ->
krbtgt/CONCORDIA.CA(a)CONCORDIA.CA in FILE:/var/lib/sss/db/ccache_CONCORDIA.CA_BHwy1c
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [ldap_child_get_tgt_sync] (0x2000):
credentials stored
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [ldap_child_get_tgt_sync] (0x2000):
Got KDC time offset
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [ldap_child_get_tgt_sync] (0x2000):
Renaming [/var/lib/sss/db/ccache_CONCORDIA.CA_BHwy1c] to
[/var/lib/sss/db/ccache_CONCORDIA.CA]
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [unique_filename_destructor]
(0x2000): Unlinking [/var/lib/sss/db/ccache_CONCORDIA.CA_BHwy1c]
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [unlink_dbg] (0x2000): File already
removed: [/var/lib/sss/db/ccache_CONCORDIA.CA_BHwy1c]
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [prepare_response] (0x0400):
Building response for result [0]
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [pack_buffer] (0x2000): response
size: 60
(Wed Jan 18 17:23:08 2017) [[sssd[ldap_child[25874]]]] [pack_buffer] (0x1000): result [0]
krberr [0] msgsize [40] msg [FILE:/var/lib/sss/db/ccache_CONCORDIA.CA]

Any help would be greatly appreciated, I've been trying to solve this problem over the
last 2 weeks to no success.

Thanks!
Thomas

2024

2023

2022

2021

2020

2019

2018

2017

2016

2015

2014

2013

2012

SSSD - user id mapping