Hi, Can you help me with a problem I struggle quite a time, that appeared after upgrade to sssd-13.4 (Ubuntu Xenial): User can not login; Home directory (nfs) secured with Kerberos, is mounted, with proper idmapping, but user is refused to login to the desktop (lightdm). Ssh login is possible, but permission denied to access the home directory.
This is setup with: .. id_provider=ad use_fully_qualified_names = true ldap_id_mapping = false .. In the krb5_child.log I can see suspicious sequence about "krb5_cc_cache_match failed";
Output from the log: -- Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [sss_child_krb5_trace_cb] (0x4000): [3331] 1477404875.933479: Sending request (8186 bytes) to A DM.C.DOMAIN (tcp only)
(Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [sss_child_krb5_trace_cb] (0x4000): [3331] 1477404875.934588: Resolving hostname host0a.adm. c.domain.
(Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [sss_child_krb5_trace_cb] (0x4000): [3331] 1477404875.936998: Initiating TCP connection to stre am 10.144.5.5:88
(Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [sss_child_krb5_trace_cb] (0x4000): [3331] 1477404875.938147: Sending TCP request to stream 10. 144.5.5:88
(Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [sss_child_krb5_trace_cb] (0x4000): [3331] 1477404875.946674: Received answer (8380 bytes) from stream 10.144.5.5:88
(Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [sss_child_krb5_trace_cb] (0x4000): [3331] 1477404875.946720: Terminating TCP connection to str eam 10.144.5.5:88
(Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [sss_child_krb5_trace_cb] (0x4000): [3331] 1477404875.948199: Response was not from master KDC
(Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [sss_child_krb5_trace_cb] (0x4000): [3331] 1477404875.948264: Decoding FAST response
(Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [sss_child_krb5_trace_cb] (0x4000): [3331] 1477404875.948342: FAST reply key: rc4-hmac/12E4
(Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [sss_child_krb5_trace_cb] (0x4000): [3331] 1477404875.948366: TGS reply is for user@NAT.C.SD U.DK -> host/lnx-adm557.a.c.domain@A.C.DOMAIN with session key aes256-cts/31E4
(Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [sss_child_krb5_trace_cb] (0x4000): [3331] 1477404875.948401: TGS request result: 0/Success
(Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [sss_child_krb5_trace_cb] (0x4000): [3331] 1477404875.948407: Received creds for desired servic e host/lnx-adm557.a.c.domain@A.C.DOMAIN
(Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [sss_child_krb5_trace_cb] (0x4000): [3331] 1477404875.948416: Storing user@N.C.DOMAIN -> h ost/lnx-adm557.a.c.domain@A.C.DOMAIN in MEMORY:gNruZJ9
(Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [sss_child_krb5_trace_cb] (0x4000): [3331] 1477404875.948440: Creating authenticator for user@N.C.DOMAIN -> host/lnx-adm557.a.c.domain@A.C.DOMAIN, seqnum 0, subkey (null), session key aes256-cts/31E4 (Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [sss_child_krb5_trace_cb] (0x4000): [3331] 1477404875.948500: Retrieving host/lnx-adm557.a.c.domain@A.C.DOMAIN from MEMORY:/etc/krb5.keytab (vno 6, enctype aes256-cts) with result: 0/Success
(Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [sss_child_krb5_trace_cb] (0x4000): [3331] 1477404875.948585: Decrypted AP-REQ with specified server principal host/lnx-adm557.a.c.domain@A.C.DOMAIN: aes256-cts/DDBF
(Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [sss_child_krb5_trace_cb] (0x4000): [3331] 1477404875.948594: AP-REQ ticket: user@N.C.DOMAIN -> host/lnx-adm557.a.c.domain@A.C.DOMAIN, session key aes256-cts/31E4 (Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [sss_child_krb5_trace_cb] (0x4000): [3331] 1477404875.948813: Negotiated enctype based on authenticator: aes256-cts
(Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [sss_child_krb5_trace_cb] (0x4000): [3331] 1477404875.948828: Initializing MEMORY:rd_req2 with default princ user@N.C.DOMAIN
(Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [sss_child_krb5_trace_cb] (0x4000): [3331] 1477404875.948837: Storing user@N.C.DOMAIN -> host/lnx-adm557.a.c.domain@A.C.DOMAIN in MEMORY:rd_req2
(Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [sss_child_krb5_trace_cb] (0x4000): [3331] 1477404875.948849: Destroying ccache MEMORY:gNruZJ9
(Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [validate_tgt] (0x0400): TGT verified using key for [host/lnx-adm557.a.c.domain@A.C.DOMAIN]. (Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [sss_child_krb5_trace_cb] (0x4000): [3331] 1477404875.948876: Retrieving user@N.C.DOMAIN -> host/lnx-adm557.a.c.domain@A.C.DOMAIN from MEMORY:rd_req2 with result: 0/Success
(Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [sss_child_krb5_trace_cb] (0x4000): [3331] 1477404875.948967: Retrieving LNX-ADM557$@A.C.DOMAIN from MEMORY:/etc/krb5.keytab (vno 6, enctype aes256-cts) with result: 0/Success
(Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [sss_send_pac] (0x0040): sss_pac_make_request failed [-1][2]. (Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [validate_tgt] (0x0040): sss_send_pac failed, group membership for user with principal [user@N.C.DOMAIN@A.C.DOMAIN] might not be correct. (Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [sss_child_krb5_trace_cb] (0x4000): [3331] 1477404875.949031: Destroying ccache MEMORY:rd_req2
(Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [sss_get_ccache_name_for_principal] (0x4000): Location: [FILE:/tmp/krb5cc_10002_XXXXXX] (Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [sss_get_ccache_name_for_principal] (0x2000): krb5_cc_cache_match failed: [-1765328243][Can't find client principal user@N.C.DOMAIN in cache collection] (Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [create_ccache] (0x4000): Initializing ccache of type [FILE] (Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [create_ccache] (0x4000): returning: 0 (Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [switch_creds] (0x0200): Switch user to [10002][30000000]. (Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [switch_creds] (0x0200): Already user [10002]. (Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [k5c_send_data] (0x0200): Received error code 0 (Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [pack_response_packet] (0x2000): response packet size: [138] (Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [k5c_send_data] (0x4000): Response sent. (Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [main] (0x0400): krb5_child completed successfully
-- ls -l /tmp/krb5cc_10002_gIeneD -rw------- 1 user@n.c.domain lnx-primary@a.c.domain 16482 Oct 25 16:14 /tmp/krb5cc_10002_gIeneD
klist -c /tmp/krb5cc_10002_gIeneD Ticket cache: FILE:/tmp/krb5cc_10002_gIeneD Default principal: user@N.C.DOMAIN
Valid starting Expires Service principal 10/25/2016 16:14:35 10/26/2016 02:14:35 krbtgt/N.C.DOMAIN@N.C.DOMAIN renew until 10/26/2016 02:14:35 10/25/2016 16:14:36 10/26/2016 02:14:35 krbtgt/C.SDU.DK@N.C.DOMAIN renew until 10/26/2016 02:14:35 10/25/2016 16:14:36 10/26/2016 02:14:35 nfs/adm-lnx-nfs0a.a.c.domain@ renew until 10/26/2016 02:14:35 10/25/2016 16:14:36 10/26/2016 02:14:35 nfs/adm-lnx-nfs0a.a.c.domain@A.C.DOMAIN
renew until 10/26/2016 02:14:35
Best, Longina
Hi again, I still hang on that problem. Client and server are configured in AD trust realm environment. Client and server are joind to a.c.domain; User is from n.c.domain.
During login sequence NFS-share (sec=krb5) homedir is mounted with right nfsidmapping . User can't login because of access denied to the homedir.
If I change mount parameter to sec=sys, user can successfully login.
Machine's and user's credentials *are* valid ;
== Ticket cache: FILE:/tmp/krb5cc_332405654_B4r6Sy Default principal: longina@N.C.DOMAIN
Valid starting Expires Service principal 11/09/2016 15:00:43 11/10/2016 01:00:43 krbtgt/N.C.DOMAIN@N.C.DOMAIN renew until 11/10/2016 01:00:43 11/09/2016 15:00:45 11/10/2016 01:00:43 krbtgt/C.SDU.DK@N.C.DOMAIN renew until 11/10/2016 01:00:43 11/09/2016 15:00:45 11/10/2016 01:00:43 nfs/adm-lptest.a.c.domain@ renew until 11/10/2016 01:00:43 11/09/2016 15:00:45 11/10/2016 01:00:43 nfs/adm-lptest.a.c.domain@A.C.DOMAIN renew until 11/10/2016 01:00:43 == Kerberos sequence for login ends with (krb5_child.log) :
==[sss_get_ccache_name_for_principal] (0x2000): krb5_cc_cache_match failed: [-1765328243][Can't find client principal longina@N.C.DOMAIN in cache collection]=
The krb5_child.log is attached. Any ideas for solving this problem?
Best, Longina
Fra: Longina Przybyszewska [mailto:longina@sdu.dk] Sendt: 26. oktober 2016 11:36 Til: End-user discussions about the System Security Services Daemon (sssd-users@lists.fedorahosted.org) Emne: [SSSD-users] sssd-13.4 can't login
Hi, Can you help me with a problem I struggle quite a time, that appeared after upgrade to sssd-13.4 (Ubuntu Xenial): User can not login; Home directory (nfs) secured with Kerberos, is mounted, with proper idmapping, but user is refused to login to the desktop (lightdm). Ssh login is possible, but permission denied to access the home directory.
This is setup with: .. id_provider=ad use_fully_qualified_names = true ldap_id_mapping = false .. In the krb5_child.log I can see suspicious sequence about "krb5_cc_cache_match failed";
Output from the log: --
Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [sss_child_krb5_trace_cb] (0x4000): [3331] 1477404875.933479: Sending request (8186 bytes) to A DM.C.DOMAIN (tcp only)
(Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [sss_child_krb5_trace_cb] (0x4000): [3331] 1477404875.934588: Resolving hostname host0a.adm. c.domain.
(Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [sss_child_krb5_trace_cb] (0x4000): [3331] 1477404875.936998: Initiating TCP connection to stre am 10.144.5.5:88
(Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [sss_child_krb5_trace_cb] (0x4000): [3331] 1477404875.938147: Sending TCP request to stream 10. 144.5.5:88
(Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [sss_child_krb5_trace_cb] (0x4000): [3331] 1477404875.946674: Received answer (8380 bytes) from stream 10.144.5.5:88
(Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [sss_child_krb5_trace_cb] (0x4000): [3331] 1477404875.946720: Terminating TCP connection to str eam 10.144.5.5:88
(Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [sss_child_krb5_trace_cb] (0x4000): [3331] 1477404875.948199: Response was not from master KDC
(Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [sss_child_krb5_trace_cb] (0x4000): [3331] 1477404875.948264: Decoding FAST response
(Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [sss_child_krb5_trace_cb] (0x4000): [3331] 1477404875.948342: FAST reply key: rc4-hmac/12E4
(Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [sss_child_krb5_trace_cb] (0x4000): [3331] 1477404875.948366: TGS reply is for user@NAT.C.SDmailto:user@NAT.C.SD U.DK -> host/lnx-adm557.a.c.domain@A.C.DOMAINmailto:host/lnx-adm557.a.c.domain@A.C.DOMAIN with session key aes256-cts/31E4
(Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [sss_child_krb5_trace_cb] (0x4000): [3331] 1477404875.948401: TGS request result: 0/Success
(Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [sss_child_krb5_trace_cb] (0x4000): [3331] 1477404875.948407: Received creds for desired servic e host/lnx-adm557.a.c.domain@A.C.DOMAINmailto:host/lnx-adm557.a.c.domain@A.C.DOMAIN
(Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [sss_child_krb5_trace_cb] (0x4000): [3331] 1477404875.948416: Storing user@N.C.DOMAINmailto:user@N.C.DOMAIN -> h ost/lnx-adm557.a.c.domain@A.C.DOMAINmailto:ost/lnx-adm557.a.c.domain@A.C.DOMAIN in MEMORY:gNruZJ9
(Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [sss_child_krb5_trace_cb] (0x4000): [3331] 1477404875.948440: Creating authenticator for user@N.C.DOMAINmailto:user@N.C.DOMAIN -> host/lnx-adm557.a.c.domain@A.C.DOMAINmailto:host/lnx-adm557.a.c.domain@A.C.DOMAIN, seqnum 0, subkey (null), session key aes256-cts/31E4 (Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [sss_child_krb5_trace_cb] (0x4000): [3331] 1477404875.948500: Retrieving host/lnx-adm557.a.c.domain@A.C.DOMAINmailto:host/lnx-adm557.a.c.domain@A.C.DOMAIN from MEMORY:/etc/krb5.keytab (vno 6, enctype aes256-cts) with result: 0/Success
(Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [sss_child_krb5_trace_cb] (0x4000): [3331] 1477404875.948585: Decrypted AP-REQ with specified server principal host/lnx-adm557.a.c.domain@A.C.DOMAINmailto:host/lnx-adm557.a.c.domain@A.C.DOMAIN: aes256-cts/DDBF
(Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [sss_child_krb5_trace_cb] (0x4000): [3331] 1477404875.948594: AP-REQ ticket: user@N.C.DOMAINmailto:user@N.C.DOMAIN -> host/lnx-adm557.a.c.domain@A.C.DOMAINmailto:host/lnx-adm557.a.c.domain@A.C.DOMAIN, session key aes256-cts/31E4 (Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [sss_child_krb5_trace_cb] (0x4000): [3331] 1477404875.948813: Negotiated enctype based on authenticator: aes256-cts
(Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [sss_child_krb5_trace_cb] (0x4000): [3331] 1477404875.948828: Initializing MEMORY:rd_req2 with default princ user@N.C.DOMAINmailto:user@N.C.DOMAIN
(Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [sss_child_krb5_trace_cb] (0x4000): [3331] 1477404875.948837: Storing user@N.C.DOMAINmailto:user@N.C.DOMAIN -> host/lnx-adm557.a.c.domain@A.C.DOMAINmailto:host/lnx-adm557.a.c.domain@A.C.DOMAIN in MEMORY:rd_req2
(Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [sss_child_krb5_trace_cb] (0x4000): [3331] 1477404875.948849: Destroying ccache MEMORY:gNruZJ9
(Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [validate_tgt] (0x0400): TGT verified using key for [host/lnx-adm557.a.c.domain@A.C.DOMAIN]. (Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [sss_child_krb5_trace_cb] (0x4000): [3331] 1477404875.948876: Retrieving user@N.C.DOMAINmailto:user@N.C.DOMAIN -> host/lnx-adm557.a.c.domain@A.C.DOMAINmailto:host/lnx-adm557.a.c.domain@A.C.DOMAIN from MEMORY:rd_req2 with result: 0/Success
(Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [sss_child_krb5_trace_cb] (0x4000): [3331] 1477404875.948967: Retrieving LNX-ADM557$@A.C.DOMAINmailto:LNX-ADM557$@A.C.DOMAIN from MEMORY:/etc/krb5.keytab (vno 6, enctype aes256-cts) with result: 0/Success
(Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [sss_send_pac] (0x0040): sss_pac_make_request failed [-1][2]. (Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [validate_tgt] (0x0040): sss_send_pac failed, group membership for user with principal [user@N.C.DOMAIN@A.C.DOMAIN] might not be correct. (Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [sss_child_krb5_trace_cb] (0x4000): [3331] 1477404875.949031: Destroying ccache MEMORY:rd_req2
(Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [sss_get_ccache_name_for_principal] (0x4000): Location: [FILE:/tmp/krb5cc_10002_XXXXXX] (Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [sss_get_ccache_name_for_principal] (0x2000): krb5_cc_cache_match failed: [-1765328243][Can't find client principal user@N.C.DOMAINmailto:user@N.C.DOMAIN in cache collection] (Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [create_ccache] (0x4000): Initializing ccache of type [FILE] (Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [create_ccache] (0x4000): returning: 0 (Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [switch_creds] (0x0200): Switch user to [10002][30000000]. (Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [switch_creds] (0x0200): Already user [10002]. (Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [k5c_send_data] (0x0200): Received error code 0 (Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [pack_response_packet] (0x2000): response packet size: [138] (Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [k5c_send_data] (0x4000): Response sent. (Tue Oct 25 16:14:35 2016) [[sssd[krb5_child[3331]]]] [main] (0x0400): krb5_child completed successfully
-- ls -l /tmp/krb5cc_10002_gIeneD -rw------- 1 user@n.c.domainmailto:user@n.c.domain lnx-primary@a.c.domainmailto:lnx-primary@a.c.domain 16482 Oct 25 16:14 /tmp/krb5cc_10002_gIeneD
klist -c /tmp/krb5cc_10002_gIeneD Ticket cache: FILE:/tmp/krb5cc_10002_gIeneD Default principal: user@N.C.DOMAINmailto:user@N.C.DOMAIN
Valid starting Expires Service principal 10/25/2016 16:14:35 10/26/2016 02:14:35 krbtgt/N.C.DOMAIN@N.C.DOMAINmailto:krbtgt/N.C.DOMAIN@N.C.DOMAIN renew until 10/26/2016 02:14:35 10/25/2016 16:14:36 10/26/2016 02:14:35 krbtgt/C.SDU.DK@N.C.DOMAINmailto:krbtgt/C.SDU.DK@N.C.DOMAIN renew until 10/26/2016 02:14:35 10/25/2016 16:14:36 10/26/2016 02:14:35 nfs/adm-lnx-nfs0a.a.c.domain@ renew until 10/26/2016 02:14:35 10/25/2016 16:14:36 10/26/2016 02:14:35 nfs/adm-lnx-nfs0a.a.c.domain@A.C.DOMAINmailto:nfs/adm-lnx-nfs0a.a.c.domain@A.C.DOMAIN
renew until 10/26/2016 02:14:35
Best, Longina
On Wed, Nov 09, 2016 at 02:45:56PM +0000, Longina Przybyszewska wrote:
Hi again, I still hang on that problem. Client and server are configured in AD trust realm environment. Client and server are joind to a.c.domain; User is from n.c.domain.
During login sequence NFS-share (sec=krb5) homedir is mounted with right nfsidmapping . User can't login because of access denied to the homedir.
If I change mount parameter to sec=sys, user can successfully login.
Machine's and user's credentials *are* valid ;
== Ticket cache: FILE:/tmp/krb5cc_332405654_B4r6Sy Default principal: longina@N.C.DOMAIN
Valid starting Expires Service principal 11/09/2016 15:00:43 11/10/2016 01:00:43 krbtgt/N.C.DOMAIN@N.C.DOMAIN renew until 11/10/2016 01:00:43 11/09/2016 15:00:45 11/10/2016 01:00:43 krbtgt/C.SDU.DK@N.C.DOMAIN renew until 11/10/2016 01:00:43 11/09/2016 15:00:45 11/10/2016 01:00:43 nfs/adm-lptest.a.c.domain@ renew until 11/10/2016 01:00:43 11/09/2016 15:00:45 11/10/2016 01:00:43 nfs/adm-lptest.a.c.domain@A.C.DOMAIN renew until 11/10/2016 01:00:43 == Kerberos sequence for login ends with (krb5_child.log) :
==[sss_get_ccache_name_for_principal] (0x2000): krb5_cc_cache_match failed: [-1765328243][Can't find client principal longina@N.C.DOMAIN in cache collection]=
You can ignore this, since you are using the FILE: ccache which is doesn't support collections, this error is harmless.
It looks like the krb5_child itself finished fine, according to:
(Wed Nov 9 15:00:44 2016) [[sssd[krb5_child[1563]]]] [k5c_send_data] (0x0200): Received error code 0 (Wed Nov 9 15:00:44 2016) [[sssd[krb5_child[1563]]]] [pack_response_packet] (0x2000): response packet size: [142] (Wed Nov 9 15:00:44 2016) [[sssd[krb5_child[1563]]]] [k5c_send_data] (0x4000): Response sent. (Wed Nov 9 15:00:44 2016) [[sssd[krb5_child[1563]]]] [main] (0x0400): krb5_child completed successfully
So I would suggest to look into the domain logs as well. Chances are some other part (maybe the access control later?) is failing.
Thank you for the response. The problems with login started after upgrades -this is Ubuntu Xenial . In the meantime I debugged PAM. I will look now in domain log
I attach sssd.conf and the sequence for 'longina' login from sssd-pam.log Could it be that the problem is generated by lightdm / PAM? It seems that there is something wrong in the very last step of the login sequence.
cat common-session |grep -v ^#
session [default=1] pam_permit.so session requisite pam_deny.so session required pam_permit.so session optional pam_umask.so session required pam_unix.so session optional pam_sss.so session optional pam_mount.so session optional pam_systemd.so
cat lightdm |grep -v ^#
auth requisite pam_nologin.so auth sufficient pam_succeed_if.so user ingroup nopasswdlogin @include common-auth auth optional pam_gnome_keyring.so auth optional pam_kwallet.so auth optional pam_kwallet5.so @include common-account session [success=ok ignore=ignore module_unknown=ignore default=bad] pam_selinux.so close session required pam_limits.so @include common-session session [success=ok ignore=ignore module_unknown=ignore default=bad] pam_selinux.so open session optional pam_gnome_keyring.so auto_start session optional pam_kwallet.so auto_start session optional pam_kwallet5.so auto_start session required pam_env.so readenv=1 session required pam_env.so readenv=1 user_readenv=1 envfile=/etc/default/locale @include common-password
Best, Longina
-----Oprindelig meddelelse----- Fra: Jakub Hrozek [mailto:jhrozek@redhat.com] Sendt: 17. november 2016 09:25 Til: sssd-users@lists.fedorahosted.org Emne: [SSSD-users] Re: sssd-13.4 can't login
On Wed, Nov 09, 2016 at 02:45:56PM +0000, Longina Przybyszewska wrote:
Hi again, I still hang on that problem. Client and server are configured in AD trust realm environment. Client and server are joind to a.c.domain; User is from n.c.domain.
During login sequence NFS-share (sec=krb5) homedir is mounted with
right nfsidmapping .
User can't login because of access denied to the homedir.
If I change mount parameter to sec=sys, user can successfully login.
Machine's and user's credentials *are* valid ;
== Ticket cache: FILE:/tmp/krb5cc_332405654_B4r6Sy Default principal: longina@N.C.DOMAIN
Valid starting Expires Service principal 11/09/2016 15:00:43 11/10/2016 01:00:43
krbtgt/N.C.DOMAIN@N.C.DOMAIN
renew until 11/10/2016 01:00:4311/09/2016 15:00:45 11/10/2016 01:00:43 krbtgt/C.SDU.DK@N.C.DOMAIN renew until 11/10/2016 01:00:43 11/09/2016 15:00:45 11/10/2016 01:00:43 nfs/adm-lptest.a.c.domain@ renew until 11/10/2016 01:00:43 11/09/2016 15:00:45 11/10/2016 01:00:43 nfs/adm-
lptest.a.c.domain@A.C.DOMAIN
renew until 11/10/2016 01:00:43== Kerberos sequence for login ends with (krb5_child.log) :
==[sss_get_ccache_name_for_principal] (0x2000): krb5_cc_cache_match
failed: [-1765328243][Can't find client principal longina@N.C.DOMAIN in cache collection]=
You can ignore this, since you are using the FILE: ccache which is doesn't support collections, this error is harmless.
It looks like the krb5_child itself finished fine, according to:
(Wed Nov 9 15:00:44 2016) [[sssd[krb5_child[1563]]]] [k5c_send_data]
(0x0200): Received error code 0
(Wed Nov 9 15:00:44 2016) [[sssd[krb5_child[1563]]]]
[pack_response_packet] (0x2000): response packet size: [142]
(Wed Nov 9 15:00:44 2016) [[sssd[krb5_child[1563]]]] [k5c_send_data]
(0x4000): Response sent.
(Wed Nov 9 15:00:44 2016) [[sssd[krb5_child[1563]]]] [main] (0x0400):
krb5_child completed successfully
So I would suggest to look into the domain logs as well. Chances are some other part (maybe the access control later?) is failing. _______________________________________________ sssd-users mailing list -- sssd-users@lists.fedorahosted.org To unsubscribe send an email to sssd-users-leave@lists.fedorahosted.org
On (21/11/16 09:01), Longina Przybyszewska wrote:
Thank you for the response. The problems with login started after upgrades -this is Ubuntu Xenial . In the meantime I debugged PAM. I will look now in domain log
I attach sssd.conf and the sequence for 'longina' login from sssd-pam.log Could it be that the problem is generated by lightdm / PAM? It seems that there is something wrong in the very last step of the login sequence.
cat common-session |grep -v ^#
session [default=1] pam_permit.so session requisite pam_deny.so session required pam_permit.so session optional pam_umask.so session required pam_unix.so session optional pam_sss.so session optional pam_mount.so session optional pam_systemd.so
cat lightdm |grep -v ^#
auth requisite pam_nologin.so auth sufficient pam_succeed_if.so user ingroup nopasswdlogin @include common-auth auth optional pam_gnome_keyring.so auth optional pam_kwallet.so auth optional pam_kwallet5.so @include common-account session [success=ok ignore=ignore module_unknown=ignore default=bad] pam_selinux.so close session required pam_limits.so @include common-session session [success=ok ignore=ignore module_unknown=ignore default=bad] pam_selinux.so open session optional pam_gnome_keyring.so auto_start session optional pam_kwallet.so auto_start session optional pam_kwallet5.so auto_start session required pam_env.so readenv=1 session required pam_env.so readenv=1 user_readenv=1 envfile=/etc/default/locale @include common-password
Best, Longina
-----Oprindelig meddelelse----- Fra: Jakub Hrozek [mailto:jhrozek@redhat.com] Sendt: 17. november 2016 09:25 Til: sssd-users@lists.fedorahosted.org Emne: [SSSD-users] Re: sssd-13.4 can't login
On Wed, Nov 09, 2016 at 02:45:56PM +0000, Longina Przybyszewska wrote:
Hi again, I still hang on that problem. Client and server are configured in AD trust realm environment. Client and server are joind to a.c.domain; User is from n.c.domain.
During login sequence NFS-share (sec=krb5) homedir is mounted with
right nfsidmapping .
User can't login because of access denied to the homedir.
If I change mount parameter to sec=sys, user can successfully login.
Machine's and user's credentials *are* valid ;
== Ticket cache: FILE:/tmp/krb5cc_332405654_B4r6Sy Default principal: longina@N.C.DOMAIN
Valid starting Expires Service principal 11/09/2016 15:00:43 11/10/2016 01:00:43
krbtgt/N.C.DOMAIN@N.C.DOMAIN
renew until 11/10/2016 01:00:4311/09/2016 15:00:45 11/10/2016 01:00:43 krbtgt/C.SDU.DK@N.C.DOMAIN renew until 11/10/2016 01:00:43 11/09/2016 15:00:45 11/10/2016 01:00:43 nfs/adm-lptest.a.c.domain@ renew until 11/10/2016 01:00:43 11/09/2016 15:00:45 11/10/2016 01:00:43 nfs/adm-
lptest.a.c.domain@A.C.DOMAIN
renew until 11/10/2016 01:00:43== Kerberos sequence for login ends with (krb5_child.log) :
==[sss_get_ccache_name_for_principal] (0x2000): krb5_cc_cache_match
failed: [-1765328243][Can't find client principal longina@N.C.DOMAIN in cache collection]=
You can ignore this, since you are using the FILE: ccache which is doesn't support collections, this error is harmless.
It looks like the krb5_child itself finished fine, according to:
(Wed Nov 9 15:00:44 2016) [[sssd[krb5_child[1563]]]] [k5c_send_data]
(0x0200): Received error code 0
(Wed Nov 9 15:00:44 2016) [[sssd[krb5_child[1563]]]]
[pack_response_packet] (0x2000): response packet size: [142]
(Wed Nov 9 15:00:44 2016) [[sssd[krb5_child[1563]]]] [k5c_send_data]
(0x4000): Response sent.
(Wed Nov 9 15:00:44 2016) [[sssd[krb5_child[1563]]]] [main] (0x0400):
krb5_child completed successfully
So I would suggest to look into the domain logs as well. Chances are some other part (maybe the access control later?) is failing. _______________________________________________ sssd-users mailing list -- sssd-users@lists.fedorahosted.org To unsubscribe send an email to sssd-users-leave@lists.fedorahosted.org
(Thu Nov 17 11:30:05 2016) [sssd[pam]] [pam_cmd_acct_mgmt] (0x0100): entering pam_cmd_acct_mgmt (Thu Nov 17 11:30:05 2016) [sssd[pam]] [sss_parse_name_for_domains] (0x0200): name 'longina@n.c.domain' matched expression for domain 'n.c.domain', user is longina (Thu Nov 17 11:30:05 2016) [sssd[pam]] [pam_print_data] (0x0100): command: SSS_PAM_ACCT_MGMT (Thu Nov 17 11:30:05 2016) [sssd[pam]] [pam_print_data] (0x0100): domain: n.c.domain (Thu Nov 17 11:30:05 2016) [sssd[pam]] [pam_print_data] (0x0100): user: longina (Thu Nov 17 11:30:05 2016) [sssd[pam]] [pam_print_data] (0x0100): service: su (Thu Nov 17 11:30:05 2016) [sssd[pam]] [pam_print_data] (0x0100): tty: /dev/pts/19 (Thu Nov 17 11:30:05 2016) [sssd[pam]] [pam_print_data] (0x0100): ruser: root (Thu Nov 17 11:30:05 2016) [sssd[pam]] [pam_print_data] (0x0100): rhost: not set (Thu Nov 17 11:30:05 2016) [sssd[pam]] [pam_print_data] (0x0100): authtok type: 0 (Thu Nov 17 11:30:05 2016) [sssd[pam]] [pam_print_data] (0x0100): newauthtok type: 0 (Thu Nov 17 11:30:05 2016) [sssd[pam]] [pam_print_data] (0x0100): priv: 1 (Thu Nov 17 11:30:05 2016) [sssd[pam]] [pam_print_data] (0x0100): cli_pid: 6611 (Thu Nov 17 11:30:05 2016) [sssd[pam]] [pam_print_data] (0x0100): logon name: longina@n.c.domain (Thu Nov 17 11:30:05 2016) [sssd[pam]] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/USER/n.c.domain/longina] (Thu Nov 17 11:30:05 2016) [sssd[pam]] [pam_initgr_check_timeout] (0x4000): User [longina@n.c.domain] not found in PAM cache. (Thu Nov 17 11:30:05 2016) [sssd[pam]] [sss_dp_issue_request] (0x0400): Issuing request for [0x410090:3:longina@n.c.domain] (Thu Nov 17 11:30:05 2016) [sssd[pam]] [sss_dp_get_account_msg] (0x0400): Creating request for [n.c.domain][0x3][BE_REQ_INITGROUPS][1][name=longina] (Thu Nov 17 11:30:05 2016) [sssd[pam]] [sbus_add_timeout] (0x2000): 0x1fcbd80 (Thu Nov 17 11:30:05 2016) [sssd[pam]] [sss_dp_internal_get_send] (0x0400): Entering request [0x410090:3:longina@n.c.domain] (Thu Nov 17 11:30:05 2016) [sssd[pam]] [sbus_remove_timeout] (0x2000): 0x1fcbd80 (Thu Nov 17 11:30:05 2016) [sssd[pam]] [sbus_dispatch] (0x4000): dbus conn: 0x1fcc1e0 (Thu Nov 17 11:30:05 2016) [sssd[pam]] [sbus_dispatch] (0x4000): Dispatching. (Thu Nov 17 11:30:05 2016) [sssd[pam]] [sss_dp_get_reply] (0x1000): Got reply from Data Provider - DP error code: 0 errno: 0 error message: Success (Thu Nov 17 11:30:05 2016) [sssd[pam]] [pam_check_user_search] (0x0100): Requesting info for [longina@n.c.domain] (Thu Nov 17 11:30:05 2016) [sssd[pam]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x1fd4570
(Thu Nov 17 11:30:05 2016) [sssd[pam]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x1fd4630
(Thu Nov 17 11:30:05 2016) [sssd[pam]] [ldb] (0x4000): Running timer event 0x1fd4570 "ltdb_callback"
(Thu Nov 17 11:30:05 2016) [sssd[pam]] [ldb] (0x4000): Destroying timer event 0x1fd4630 "ltdb_timeout"
(Thu Nov 17 11:30:05 2016) [sssd[pam]] [ldb] (0x4000): Ending timer event 0x1fd4570 "ltdb_callback"
(Thu Nov 17 11:30:05 2016) [sssd[pam]] [pam_check_user_search] (0x0400): Returning info for user [longina@n.c.domain] (Thu Nov 17 11:30:05 2016) [sssd[pam]] [pd_set_primary_name] (0x0400): User's primary name is longina@n.c.domain (Thu Nov 17 11:30:05 2016) [sssd[pam]] [pam_initgr_cache_set] (0x2000): [longina@n.c.domain] added to PAM initgroup cache (Thu Nov 17 11:30:05 2016) [sssd[pam]] [pam_dp_send_req] (0x0100): Sending request with the following data: (Thu Nov 17 11:30:05 2016) [sssd[pam]] [pam_print_data] (0x0100): command: SSS_PAM_ACCT_MGMT (Thu Nov 17 11:30:05 2016) [sssd[pam]] [pam_print_data] (0x0100): domain: n.c.domain (Thu Nov 17 11:30:05 2016) [sssd[pam]] [pam_print_data] (0x0100): user: longina@n.c.domain (Thu Nov 17 11:30:05 2016) [sssd[pam]] [pam_print_data] (0x0100): service: su (Thu Nov 17 11:30:05 2016) [sssd[pam]] [pam_print_data] (0x0100): tty: /dev/pts/19 (Thu Nov 17 11:30:05 2016) [sssd[pam]] [pam_print_data] (0x0100): ruser: root (Thu Nov 17 11:30:05 2016) [sssd[pam]] [pam_print_data] (0x0100): rhost: not set (Thu Nov 17 11:30:05 2016) [sssd[pam]] [pam_print_data] (0x0100): authtok type: 0 (Thu Nov 17 11:30:05 2016) [sssd[pam]] [pam_print_data] (0x0100): newauthtok type: 0 (Thu Nov 17 11:30:05 2016) [sssd[pam]] [pam_print_data] (0x0100): priv: 1 (Thu Nov 17 11:30:05 2016) [sssd[pam]] [pam_print_data] (0x0100): cli_pid: 6611 (Thu Nov 17 11:30:05 2016) [sssd[pam]] [pam_print_data] (0x0100): logon name: longina@n.c.domain (Thu Nov 17 11:30:05 2016) [sssd[pam]] [sbus_add_timeout] (0x2000): 0x1fcd6d0 (Thu Nov 17 11:30:05 2016) [sssd[pam]] [pam_dom_forwarder] (0x0100): pam_dp_send_req returned 0 (Thu Nov 17 11:30:05 2016) [sssd[pam]] [sss_dp_req_destructor] (0x0400): Deleting request: [0x410090:3:longina@n.c.domain] (Thu Nov 17 11:30:06 2016) [sssd[pam]] [sbus_remove_timeout] (0x2000): 0x1fcd6d0 (Thu Nov 17 11:30:06 2016) [sssd[pam]] [sbus_dispatch] (0x4000): dbus conn: 0x1fcc1e0 (Thu Nov 17 11:30:06 2016) [sssd[pam]] [sbus_dispatch] (0x4000): Dispatching. (Thu Nov 17 11:30:06 2016) [sssd[pam]] [pam_dp_process_reply] (0x0200): received: [0 (Success)][n.c.domain] (Thu Nov 17 11:30:06 2016) [sssd[pam]] [pam_reply] (0x0200): pam_reply called with result [0]: Success. (Thu Nov 17 11:30:06 2016) [sssd[pam]] [pam_reply] (0x0200): blen: 29 (Thu Nov 17 11:30:06 2016) [sssd[pam]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x1fd3fc0][19] (Thu Nov 17 11:30:06 2016) [sssd[pam]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x1fd3fc0][19] (Thu Nov 17 11:30:06 2016) [sssd[pam]] [pam_cmd_open_session] (0x0100): entering pam_cmd_open_session (Thu Nov 17 11:30:06 2016) [sssd[pam]] [sss_parse_name_for_domains] (0x0200): name 'longina@n.c.domain' matched expression for domain 'n.c.domain', user is longina (Thu Nov 17 11:30:06 2016) [sssd[pam]] [pam_print_data] (0x0100): command: SSS_PAM_OPEN_SESSION (Thu Nov 17 11:30:06 2016) [sssd[pam]] [pam_print_data] (0x0100): domain: n.c.domain (Thu Nov 17 11:30:06 2016) [sssd[pam]] [pam_print_data] (0x0100): user: longina (Thu Nov 17 11:30:06 2016) [sssd[pam]] [pam_print_data] (0x0100): service: su (Thu Nov 17 11:30:06 2016) [sssd[pam]] [pam_print_data] (0x0100): tty: /dev/pts/19 (Thu Nov 17 11:30:06 2016) [sssd[pam]] [pam_print_data] (0x0100): ruser: root (Thu Nov 17 11:30:06 2016) [sssd[pam]] [pam_print_data] (0x0100): rhost: not set (Thu Nov 17 11:30:06 2016) [sssd[pam]] [pam_print_data] (0x0100): authtok type: 0 (Thu Nov 17 11:30:06 2016) [sssd[pam]] [pam_print_data] (0x0100): newauthtok type: 0 (Thu Nov 17 11:30:06 2016) [sssd[pam]] [pam_print_data] (0x0100): priv: 1 (Thu Nov 17 11:30:06 2016) [sssd[pam]] [pam_print_data] (0x0100): cli_pid: 6611 (Thu Nov 17 11:30:06 2016) [sssd[pam]] [pam_print_data] (0x0100): logon name: longina@n.c.domain (Thu Nov 17 11:30:06 2016) [sssd[pam]] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/USER/n.c.domain/longina] (Thu Nov 17 11:30:06 2016) [sssd[pam]] [pam_initgr_check_timeout] (0x2000): User [longina@n.c.domain] found in PAM cache. (Thu Nov 17 11:30:06 2016) [sssd[pam]] [pam_check_user_search] (0x0100): Requesting info for [longina@n.c.domain] (Thu Nov 17 11:30:06 2016) [sssd[pam]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x1fd07d0
(Thu Nov 17 11:30:06 2016) [sssd[pam]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x1fd0890
(Thu Nov 17 11:30:06 2016) [sssd[pam]] [ldb] (0x4000): Running timer event 0x1fd07d0 "ltdb_callback"
(Thu Nov 17 11:30:06 2016) [sssd[pam]] [ldb] (0x4000): Destroying timer event 0x1fd0890 "ltdb_timeout"
(Thu Nov 17 11:30:06 2016) [sssd[pam]] [ldb] (0x4000): Ending timer event 0x1fd07d0 "ltdb_callback"
(Thu Nov 17 11:30:06 2016) [sssd[pam]] [pam_check_user_search] (0x0400): Returning info for user [longina@n.c.domain] (Thu Nov 17 11:30:06 2016) [sssd[pam]] [pd_set_primary_name] (0x0400): User's primary name is longina@n.c.domain (Thu Nov 17 11:30:06 2016) [sssd[pam]] [pam_dp_send_req] (0x0100): Sending request with the following data: (Thu Nov 17 11:30:06 2016) [sssd[pam]] [pam_print_data] (0x0100): command: SSS_PAM_OPEN_SESSION (Thu Nov 17 11:30:06 2016) [sssd[pam]] [pam_print_data] (0x0100): domain: n.c.domain (Thu Nov 17 11:30:06 2016) [sssd[pam]] [pam_print_data] (0x0100): user: longina@n.c.domain (Thu Nov 17 11:30:06 2016) [sssd[pam]] [pam_print_data] (0x0100): service: su (Thu Nov 17 11:30:06 2016) [sssd[pam]] [pam_print_data] (0x0100): tty: /dev/pts/19 (Thu Nov 17 11:30:06 2016) [sssd[pam]] [pam_print_data] (0x0100): ruser: root (Thu Nov 17 11:30:06 2016) [sssd[pam]] [pam_print_data] (0x0100): rhost: not set (Thu Nov 17 11:30:06 2016) [sssd[pam]] [pam_print_data] (0x0100): authtok type: 0 (Thu Nov 17 11:30:06 2016) [sssd[pam]] [pam_print_data] (0x0100): newauthtok type: 0 (Thu Nov 17 11:30:06 2016) [sssd[pam]] [pam_print_data] (0x0100): priv: 1 (Thu Nov 17 11:30:06 2016) [sssd[pam]] [pam_print_data] (0x0100): cli_pid: 6611 (Thu Nov 17 11:30:06 2016) [sssd[pam]] [pam_print_data] (0x0100): logon name: longina@n.c.domain (Thu Nov 17 11:30:06 2016) [sssd[pam]] [sbus_add_timeout] (0x2000): 0x1fcd640 (Thu Nov 17 11:30:06 2016) [sssd[pam]] [pam_dom_forwarder] (0x0100): pam_dp_send_req returned 0 (Thu Nov 17 11:30:06 2016) [sssd[pam]] [sbus_remove_timeout] (0x2000): 0x1fcd640 (Thu Nov 17 11:30:06 2016) [sssd[pam]] [sbus_dispatch] (0x4000): dbus conn: 0x1fcc1e0 (Thu Nov 17 11:30:06 2016) [sssd[pam]] [sbus_dispatch] (0x4000): Dispatching. (Thu Nov 17 11:30:06 2016) [sssd[pam]] [pam_dp_process_reply] (0x0200): received: [0 (Success)][n.c.domain] (Thu Nov 17 11:30:06 2016) [sssd[pam]] [pam_reply] (0x0200): pam_reply called with result [0]: Success. (Thu Nov 17 11:30:06 2016) [sssd[pam]] [pam_reply] (0x0200): blen: 29 (Thu Nov 17 11:30:06 2016) [sssd[pam]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x1fd3fc0][19] (Thu Nov 17 11:30:10 2016) [sssd[pam]] [pam_initgr_cache_remove] (0x2000): [longina@n.c.domain] removed from PAM initgroup cache (Thu Nov 17 11:30:12 2016) [sssd[pam]] [sbus_dispatch] (0x4000): dbus conn: 0x1fcfa30 (Thu Nov 17 11:30:12 2016) [sssd[pam]] [sbus_dispatch] (0x4000): Dispatching. (Thu Nov 17 11:30:12 2016) [sssd[pam]] [sbus_message_handler] (0x2000): Received SBUS method org.freedesktop.sssd.service.ping on path /org/freedesktop/sssd/service (Thu Nov 17 11:30:12 2016) [sssd[pam]] [sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit (Thu Nov 17 11:30:22 2016) [sssd[pam]] [sbus_dispatch] (0x4000): dbus conn: 0x1fcfa30 (Thu Nov 17 11:30:22 2016) [sssd[pam]] [sbus_dispatch] (0x4000): Dispatching. (Thu Nov 17 11:30:22 2016) [sssd[pam]] [sbus_message_handler] (0x2000): Received SBUS method org.freedesktop.sssd.service.ping on path /org/freedesktop/sssd/service (Thu Nov 17 11:30:22 2016) [sssd[pam]] [sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit (Thu Nov 17 11:30:32 2016) [sssd[pam]] [sbus_dispatch] (0x4000): dbus conn: 0x1fcfa30 (Thu Nov 17 11:30:32 2016) [sssd[pam]] [sbus_dispatch] (0x4000): Dispatching. (Thu Nov 17 11:30:32 2016) [sssd[pam]] [sbus_message_handler] (0x2000): Received SBUS method org.freedesktop.sssd.service.ping on path /org/freedesktop/sssd/service (Thu Nov 17 11:30:32 2016) [sssd[pam]] [sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit (Thu Nov 17 11:30:42 2016) [sssd[pam]] [sbus_dispatch] (0x4000): dbus conn: 0x1fcfa30 (Thu Nov 17 11:30:42 2016) [sssd[pam]] [sbus_dispatch] (0x4000): Dispatching. (Thu Nov 17 11:30:42 2016) [sssd[pam]] [sbus_message_handler] (0x2000): Received SBUS method org.freedesktop.sssd.service.ping on path /org/freedesktop/sssd/service (Thu Nov 17 11:30:42 2016) [sssd[pam]] [sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit (Thu Nov 17 11:30:52 2016) [sssd[pam]] [sbus_dispatch] (0x4000): dbus conn: 0x1fcfa30 (Thu Nov 17 11:30:52 2016) [sssd[pam]] [sbus_dispatch] (0x4000): Dispatching. (Thu Nov 17 11:30:52 2016) [sssd[pam]] [sbus_message_handler] (0x2000): Received SBUS method org.freedesktop.sssd.service.ping on path /org/freedesktop/sssd/service (Thu Nov 17 11:30:52 2016) [sssd[pam]] [sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit (Thu Nov 17 11:30:53 2016) [sssd[pam]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x1fd3fc0][19] (Thu Nov 17 11:30:53 2016) [sssd[pam]] [pam_cmd_close_session] (0x0100): entering pam_cmd_close_session (Thu Nov 17 11:30:53 2016) [sssd[pam]] [sss_parse_name_for_domains] (0x0200): name 'longina@n.c.domain' matched expression for domain 'n.c.domain', user is longina (Thu Nov 17 11:30:53 2016) [sssd[pam]] [pam_print_data] (0x0100): command: SSS_PAM_CLOSE_SESSION (Thu Nov 17 11:30:53 2016) [sssd[pam]] [pam_print_data] (0x0100): domain: n.c.domain (Thu Nov 17 11:30:53 2016) [sssd[pam]] [pam_print_data] (0x0100): user: longina (Thu Nov 17 11:30:53 2016) [sssd[pam]] [pam_print_data] (0x0100): service: su (Thu Nov 17 11:30:53 2016) [sssd[pam]] [pam_print_data] (0x0100): tty: /dev/pts/19 (Thu Nov 17 11:30:53 2016) [sssd[pam]] [pam_print_data] (0x0100): ruser: root (Thu Nov 17 11:30:53 2016) [sssd[pam]] [pam_print_data] (0x0100): rhost: not set (Thu Nov 17 11:30:53 2016) [sssd[pam]] [pam_print_data] (0x0100): authtok type: 0 (Thu Nov 17 11:30:53 2016) [sssd[pam]] [pam_print_data] (0x0100): newauthtok type: 0 (Thu Nov 17 11:30:53 2016) [sssd[pam]] [pam_print_data] (0x0100): priv: 1 (Thu Nov 17 11:30:53 2016) [sssd[pam]] [pam_print_data] (0x0100): cli_pid: 6611 (Thu Nov 17 11:30:53 2016) [sssd[pam]] [pam_print_data] (0x0100): logon name: longina@n.c.domain (Thu Nov 17 11:30:53 2016) [sssd[pam]] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/USER/n.c.domain/longina] (Thu Nov 17 11:30:53 2016) [sssd[pam]] [pam_initgr_check_timeout] (0x4000): User [longina@n.c.domain] not found in PAM cache. (Thu Nov 17 11:30:53 2016) [sssd[pam]] [sss_dp_issue_request] (0x0400): Issuing request for [0x410090:3:longina@n.c.domain] (Thu Nov 17 11:30:53 2016) [sssd[pam]] [sss_dp_get_account_msg] (0x0400): Creating request for [n.c.domain][0x3][BE_REQ_INITGROUPS][1][name=longina] (Thu Nov 17 11:30:53 2016) [sssd[pam]] [sbus_add_timeout] (0x2000): 0x1fcd6d0 (Thu Nov 17 11:30:53 2016) [sssd[pam]] [sss_dp_internal_get_send] (0x0400): Entering request [0x410090:3:longina@n.c.domain] (Thu Nov 17 11:30:53 2016) [sssd[pam]] [sbus_remove_timeout] (0x2000): 0x1fcd6d0 (Thu Nov 17 11:30:53 2016) [sssd[pam]] [sbus_dispatch] (0x4000): dbus conn: 0x1fcc1e0 (Thu Nov 17 11:30:53 2016) [sssd[pam]] [sbus_dispatch] (0x4000): Dispatching. (Thu Nov 17 11:30:53 2016) [sssd[pam]] [sss_dp_get_reply] (0x1000): Got reply from Data Provider - DP error code: 0 errno: 0 error message: Success (Thu Nov 17 11:30:53 2016) [sssd[pam]] [pam_check_user_search] (0x0100): Requesting info for [longina@n.c.domain] (Thu Nov 17 11:30:53 2016) [sssd[pam]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x1fd07d0
(Thu Nov 17 11:30:53 2016) [sssd[pam]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x1fd0890
(Thu Nov 17 11:30:53 2016) [sssd[pam]] [ldb] (0x4000): Running timer event 0x1fd07d0 "ltdb_callback" (Thu Nov 17 11:30:53 2016) [sssd[pam]] [ldb] (0x4000): Destroying timer event 0x1fd0890 "ltdb_timeout"
(Thu Nov 17 11:30:53 2016) [sssd[pam]] [ldb] (0x4000): Ending timer event 0x1fd07d0 "ltdb_callback"
(Thu Nov 17 11:30:53 2016) [sssd[pam]] [pam_check_user_search] (0x0400): Returning info for user [longina@n.c.domain] (Thu Nov 17 11:30:53 2016) [sssd[pam]] [pd_set_primary_name] (0x0400): User's primary name is longina@n.c.domain (Thu Nov 17 11:30:53 2016) [sssd[pam]] [pam_initgr_cache_set] (0x2000): [longina@n.c.domain] added to PAM initgroup cache (Thu Nov 17 11:30:53 2016) [sssd[pam]] [pam_dp_send_req] (0x0100): Sending request with the following data: (Thu Nov 17 11:30:53 2016) [sssd[pam]] [pam_print_data] (0x0100): command: SSS_PAM_CLOSE_SESSION (Thu Nov 17 11:30:53 2016) [sssd[pam]] [pam_print_data] (0x0100): domain: n.c.domain (Thu Nov 17 11:30:53 2016) [sssd[pam]] [pam_print_data] (0x0100): user: longina@n.c.domain (Thu Nov 17 11:30:53 2016) [sssd[pam]] [pam_print_data] (0x0100): service: su (Thu Nov 17 11:30:53 2016) [sssd[pam]] [pam_print_data] (0x0100): tty: /dev/pts/19 (Thu Nov 17 11:30:53 2016) [sssd[pam]] [pam_print_data] (0x0100): ruser: root (Thu Nov 17 11:30:53 2016) [sssd[pam]] [pam_print_data] (0x0100): rhost: not set (Thu Nov 17 11:30:53 2016) [sssd[pam]] [pam_print_data] (0x0100): authtok type: 0 (Thu Nov 17 11:30:53 2016) [sssd[pam]] [pam_print_data] (0x0100): newauthtok type: 0 (Thu Nov 17 11:30:53 2016) [sssd[pam]] [pam_print_data] (0x0100): priv: 1 (Thu Nov 17 11:30:53 2016) [sssd[pam]] [pam_print_data] (0x0100): cli_pid: 6611 (Thu Nov 17 11:30:53 2016) [sssd[pam]] [pam_print_data] (0x0100): logon name: longina@n.c.domain (Thu Nov 17 11:30:53 2016) [sssd[pam]] [sbus_add_timeout] (0x2000): 0x1fcbd80 (Thu Nov 17 11:30:53 2016) [sssd[pam]] [pam_dom_forwarder] (0x0100): pam_dp_send_req returned 0 (Thu Nov 17 11:30:53 2016) [sssd[pam]] [sss_dp_req_destructor] (0x0400): Deleting request: [0x410090:3:longina@n.c.domain] (Thu Nov 17 11:30:53 2016) [sssd[pam]] [sbus_remove_timeout] (0x2000): 0x1fcbd80 (Thu Nov 17 11:30:53 2016) [sssd[pam]] [sbus_dispatch] (0x4000): dbus conn: 0x1fcc1e0 (Thu Nov 17 11:30:53 2016) [sssd[pam]] [sbus_dispatch] (0x4000): Dispatching. (Thu Nov 17 11:30:53 2016) [sssd[pam]] [pam_dp_process_reply] (0x0200): received: [0 (Success)][n.c.domain] (Thu Nov 17 11:30:53 2016) [sssd[pam]] [pam_reply] (0x0200): pam_reply called with result [0]: Success. (Thu Nov 17 11:30:53 2016) [sssd[pam]] [pam_reply] (0x0200): blen: 29 (Thu Nov 17 11:30:53 2016) [sssd[pam]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x1fd3fc0][19] (Thu Nov 17 11:30:53 2016) [sssd[pam]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x1fd3fc0][19] (Thu Nov 17 11:30:53 2016) [sssd[pam]] [client_recv] (0x0200): Client disconnected! (Thu Nov 17 11:30:53 2016) [sssd[pam]] [client_destructor] (0x2000): Terminated client [0x1fd3fc0][19] (Thu Nov 17 11:30:58 2016) [sssd[pam]] [pam_initgr_cache_remove] (0x2000): [longina@n.c.domain] removed from PAM initgroup cache (Thu Nov 17 11:30:59 2016) [sssd[pam]] [get_client_cred] (0x4000): Client creds: euid[0] egid[0] pid[1717]. (Thu Nov 17 11:30:59 2016) [sssd[pam]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x1fd3fc0][19] (Thu Nov 17 11:30:59 2016) [sssd[pam]] [accept_fd_handler] (0x0400): Client connected to privileged pipe! (Thu Nov 17 11:30:59 2016) [sssd[pam]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x1fd3fc0][19] (Thu Nov 17 11:30:59 2016) [sssd[pam]] [sss_cmd_get_version] (0x0200): Received client version [3]. (Thu Nov 17 11:30:59 2016) [sssd[pam]] [sss_cmd_get_version] (0x0200): Offered version [3]. (Thu Nov 17 11:30:59 2016) [sssd[pam]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x1fd3fc0][19] (Thu Nov 17 11:30:59 2016) [sssd[pam]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x1fd3fc0][19] (Thu Nov 17 11:30:59 2016) [sssd[pam]] [pam_cmd_close_session] (0x0100): entering pam_cmd_close_session (Thu Nov 17 11:30:59 2016) [sssd[pam]] [sss_parse_name_for_domains] (0x0200): name 'alongina' matched without domain, user is alongina (Thu Nov 17 11:30:59 2016) [sssd[pam]] [pam_print_data] (0x0100): command: SSS_PAM_CLOSE_SESSION (Thu Nov 17 11:30:59 2016) [sssd[pam]] [pam_print_data] (0x0100): domain: not set (Thu Nov 17 11:30:59 2016) [sssd[pam]] [pam_print_data] (0x0100): user: alongina (Thu Nov 17 11:30:59 2016) [sssd[pam]] [pam_print_data] (0x0100): service: lightdm (Thu Nov 17 11:30:59 2016) [sssd[pam]] [pam_print_data] (0x0100): tty: :0 (Thu Nov 17 11:30:59 2016) [sssd[pam]] [pam_print_data] (0x0100): ruser: not set (Thu Nov 17 11:30:59 2016) [sssd[pam]] [pam_print_data] (0x0100): rhost: not set (Thu Nov 17 11:30:59 2016) [sssd[pam]] [pam_print_data] (0x0100): authtok type: 0 (Thu Nov 17 11:30:59 2016) [sssd[pam]] [pam_print_data] (0x0100): newauthtok type: 0 (Thu Nov 17 11:30:59 2016) [sssd[pam]] [pam_print_data] (0x0100): priv: 1 (Thu Nov 17 11:30:59 2016) [sssd[pam]] [pam_print_data] (0x0100): cli_pid: 1717 (Thu Nov 17 11:30:59 2016) [sssd[pam]] [pam_print_data] (0x0100): logon name: alongina (Thu Nov 17 11:30:59 2016) [sssd[pam]] [pam_reply] (0x0200): pam_reply called with result [10]: User not known to the underlying authentication module. (Thu Nov 17 11:30:59 2016) [sssd[pam]] [pam_reply] (0x0200): blen: 8
Is it a typo? because the user "alongina" was not recognized as a sssd user. Therefore there is a pam error "User not known to the underlying authentication module"
Different user was used in previous pam actions "longina@n.c.domain"
(Thu Nov 17 11:30:59 2016) [sssd[pam]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x1fd3fc0][19] (Thu Nov 17 11:30:59 2016) [sssd[pam]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x1fd3fc0][19] (Thu Nov 17 11:30:59 2016) [sssd[pam]] [client_recv] (0x0200): Client disconnected! (Thu Nov 17 11:30:59 2016) [sssd[pam]] [client_destructor] (0x2000): Terminated client [0x1fd3fc0][19] (Thu Nov 17 11:31:00 2016) [sssd[pam]] [get_client_cred] (0x4000): Client creds: euid[0] egid[0] pid[6669]. (Thu Nov 17 11:31:00 2016) [sssd[pam]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x1fd3fc0][19] (Thu Nov 17 11:31:00 2016) [sssd[pam]] [accept_fd_handler] (0x0400): Client connected to privileged pipe! (Thu Nov 17 11:31:00 2016) [sssd[pam]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x1fd3fc0][19] (Thu Nov 17 11:31:00 2016) [sssd[pam]] [sss_cmd_get_version] (0x0200): Received client version [3]. (Thu Nov 17 11:31:00 2016) [sssd[pam]] [sss_cmd_get_version] (0x0200): Offered version [3]. (Thu Nov 17 11:31:00 2016) [sssd[pam]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x1fd3fc0][19] (Thu Nov 17 11:31:00 2016) [sssd[pam]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x1fd3fc0][19] (Thu Nov 17 11:31:00 2016) [sssd[pam]] [pam_cmd_open_session] (0x0100): entering pam_cmd_open_session (Thu Nov 17 11:31:00 2016) [sssd[pam]] [sss_parse_name_for_domains] (0x0200): name 'lightdm' matched without domain, user is lightdm (Thu Nov 17 11:31:00 2016) [sssd[pam]] [pam_print_data] (0x0100): command: SSS_PAM_OPEN_SESSION (Thu Nov 17 11:31:00 2016) [sssd[pam]] [pam_print_data] (0x0100): domain: not set (Thu Nov 17 11:31:00 2016) [sssd[pam]] [pam_print_data] (0x0100): user: lightdm (Thu Nov 17 11:31:00 2016) [sssd[pam]] [pam_print_data] (0x0100): service: lightdm-greeter (Thu Nov 17 11:31:00 2016) [sssd[pam]] [pam_print_data] (0x0100): tty: :0 (Thu Nov 17 11:31:00 2016) [sssd[pam]] [pam_print_data] (0x0100): ruser: not set (Thu Nov 17 11:31:00 2016) [sssd[pam]] [pam_print_data] (0x0100): rhost: not set (Thu Nov 17 11:31:00 2016) [sssd[pam]] [pam_print_data] (0x0100): authtok type: 0 (Thu Nov 17 11:31:00 2016) [sssd[pam]] [pam_print_data] (0x0100): newauthtok type: 0 (Thu Nov 17 11:31:00 2016) [sssd[pam]] [pam_print_data] (0x0100): priv: 1 (Thu Nov 17 11:31:00 2016) [sssd[pam]] [pam_print_data] (0x0100): cli_pid: 6669 (Thu Nov 17 11:31:00 2016) [sssd[pam]] [pam_print_data] (0x0100): logon name: lightdm (Thu Nov 17 11:31:00 2016) [sssd[pam]] [pam_reply] (0x0200): pam_reply called with result [10]: User not known to the underlying authentication module.
I think it is expected user lightdm is not handled by sssd. So I am not sure wheter it could cause a problem. The only problem could be caused by gpo and that service "lightdm-greeter" is not allowed by default.
LS
No, it is not a typo, 'alongina' is my local account - sorry , I should cut it off from the log ;(
Domain user is longina@n.c.domain
I use following option to turn off gpo : .... ad_gpo_access_control = permissive pam_public_domains = all selinux_provider = none ....
Is it not enough?
Best Longina
-----Oprindelig meddelelse----- Fra: Lukas Slebodnik [mailto:lslebodn@redhat.com] Sendt: 21. november 2016 10:11 Til: End-user discussions about the System Security Services Daemon Emne: [SSSD-users] Re: sssd-13.4 can't login
On (21/11/16 09:01), Longina Przybyszewska wrote:
Thank you for the response. The problems with login started after upgrades -this is Ubuntu Xenial . In the meantime I debugged PAM. I will look now in domain log
I attach sssd.conf and the sequence for 'longina' login from sssd-pam.log Could it be that the problem is generated by lightdm / PAM? It seems that there is something wrong in the very last step of the login
sequence.
cat common-session |grep -v ^#
session [default=1] pam_permit.so session requisite pam_deny.so session required pam_permit.so session optional pam_umask.so session required pam_unix.so session optional pam_sss.so session optional pam_mount.so session optional pam_systemd.so
cat lightdm |grep -v ^#
auth requisite pam_nologin.so auth sufficient pam_succeed_if.so user ingroup nopasswdlogin @include common-auth auth optional pam_gnome_keyring.so auth optional pam_kwallet.so auth optional pam_kwallet5.so @include common-account session [success=ok ignore=ignore module_unknown=ignore default=bad]
pam_selinux.so close
session required pam_limits.so @include common-session session [success=ok ignore=ignore module_unknown=ignore default=bad]
pam_selinux.so open
session optional pam_gnome_keyring.so auto_start session optional pam_kwallet.so auto_start session optional pam_kwallet5.so auto_start session required pam_env.so readenv=1 session required pam_env.so readenv=1 user_readenv=1
envfile=/etc/default/locale
@include common-password
Best, Longina
-----Oprindelig meddelelse----- Fra: Jakub Hrozek [mailto:jhrozek@redhat.com] Sendt: 17. november 2016 09:25 Til: sssd-users@lists.fedorahosted.org Emne: [SSSD-users] Re: sssd-13.4 can't login
On Wed, Nov 09, 2016 at 02:45:56PM +0000, Longina Przybyszewska
wrote:
Hi again, I still hang on that problem. Client and server are configured in AD trust realm environment. Client and server are joind to a.c.domain; User is from n.c.domain.
During login sequence NFS-share (sec=krb5) homedir is mounted with
right nfsidmapping .
User can't login because of access denied to the homedir.
If I change mount parameter to sec=sys, user can successfully login.
Machine's and user's credentials *are* valid ;
== Ticket cache: FILE:/tmp/krb5cc_332405654_B4r6Sy Default principal: longina@N.C.DOMAIN
Valid starting Expires Service principal 11/09/2016 15:00:43 11/10/2016 01:00:43
krbtgt/N.C.DOMAIN@N.C.DOMAIN
renew until 11/10/2016 01:00:4311/09/2016 15:00:45 11/10/2016 01:00:43
krbtgt/C.SDU.DK@N.C.DOMAIN
renew until 11/10/2016 01:00:4311/09/2016 15:00:45 11/10/2016 01:00:43 nfs/adm-lptest.a.c.domain@ renew until 11/10/2016 01:00:43 11/09/2016 15:00:45 11/10/2016 01:00:43 nfs/adm-
lptest.a.c.domain@A.C.DOMAIN
renew until 11/10/2016 01:00:43 == Kerberos sequence forlogin ends with (krb5_child.log) :
==[sss_get_ccache_name_for_principal] (0x2000):
krb5_cc_cache_match
failed: [-1765328243][Can't find client principal longina@N.C.DOMAIN in cache collection]=
You can ignore this, since you are using the FILE: ccache which is doesn't support collections, this error is harmless.
It looks like the krb5_child itself finished fine, according to:
(Wed Nov 9 15:00:44 2016) [[sssd[krb5_child[1563]]]] [k5c_send_data]
(0x0200): Received error code 0
(Wed Nov 9 15:00:44 2016) [[sssd[krb5_child[1563]]]]
[pack_response_packet] (0x2000): response packet size: [142]
(Wed Nov 9 15:00:44 2016) [[sssd[krb5_child[1563]]]] [k5c_send_data]
(0x4000): Response sent.
(Wed Nov 9 15:00:44 2016) [[sssd[krb5_child[1563]]]] [main] (0x0400):
krb5_child completed successfully
So I would suggest to look into the domain logs as well. Chances are some other part (maybe the access control later?) is failing. _______________________________________________ sssd-users mailing list -- sssd-users@lists.fedorahosted.org To unsubscribe send an email to sssd-users-leave@lists.fedorahosted.org
(Thu Nov 17 11:30:05 2016) [sssd[pam]] [pam_cmd_acct_mgmt] (0x0100): entering pam_cmd_acct_mgmt (Thu Nov 17 11:30:05 2016) [sssd[pam]] [sss_parse_name_for_domains] (0x0200): name 'longina@n.c.domain' matched expression for domain 'n.c.domain', user is longina (Thu Nov 17 11:30:05 2016) [sssd[pam]] [pam_print_data] (0x0100): command: SSS_PAM_ACCT_MGMT (Thu Nov 17 11:30:05 2016) [sssd[pam]] [pam_print_data] (0x0100): domain: n.c.domain (Thu Nov 17 11:30:05 2016) [sssd[pam]] [pam_print_data] (0x0100): user: longina (Thu Nov 17 11:30:05 2016) [sssd[pam]] [pam_print_data] (0x0100): service: su (Thu Nov 17 11:30:05 2016) [sssd[pam]] [pam_print_data] (0x0100): tty: /dev/pts/19 (Thu Nov 17 11:30:05 2016) [sssd[pam]] [pam_print_data] (0x0100): ruser: root (Thu Nov 17 11:30:05 2016) [sssd[pam]] [pam_print_data] (0x0100): rhost: not set (Thu Nov 17 11:30:05 2016) [sssd[pam]] [pam_print_data] (0x0100): authtok type: 0 (Thu Nov 17 11:30:05 2016) [sssd[pam]] [pam_print_data] (0x0100): newauthtok type: 0 (Thu Nov 17 11:30:05 2016) [sssd[pam]] [pam_print_data] (0x0100): priv: 1
(Thu Nov 17 11:30:05 2016) [sssd[pam]] [pam_print_data] (0x0100): cli_pid: 6611 (Thu Nov 17 11:30:05 2016) [sssd[pam]] [pam_print_data] (0x0100): logon name: longina@n.c.domain (Thu Nov 17 11:30:05 2016) [sssd[pam]] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/USER/n.c.domain/longina] (Thu Nov 17 11:30:05 2016) [sssd[pam]] [pam_initgr_check_timeout] (0x4000): User [longina@n.c.domain] not found in PAM cache.
(Thu Nov 17 11:30:05 2016) [sssd[pam]] [sss_dp_issue_request] (0x0400): Issuing request for [0x410090:3:longina@n.c.domain] (Thu Nov 17 11:30:05 2016) [sssd[pam]] [sss_dp_get_account_msg] (0x0400): Creating request for [n.c.domain][0x3][BE_REQ_INITGROUPS][1][name=longina] (Thu Nov 17 11:30:05 2016) [sssd[pam]] [sbus_add_timeout] (0x2000): 0x1fcbd80 (Thu Nov 17 11:30:05 2016) [sssd[pam]] [sss_dp_internal_get_send] (0x0400): Entering request [0x410090:3:longina@n.c.domain] (Thu Nov 17 11:30:05 2016) [sssd[pam]] [sbus_remove_timeout] (0x2000): 0x1fcbd80 (Thu Nov 17 11:30:05 2016)
[sssd[pam]] [sbus_dispatch] (0x4000): dbus conn: 0x1fcc1e0 (Thu Nov 17 11:30:05 2016) [sssd[pam]] [sbus_dispatch] (0x4000): Dispatching.
(Thu Nov 17 11:30:05 2016) [sssd[pam]] [sss_dp_get_reply] (0x1000): Got reply from Data Provider - DP error code: 0 errno: 0 error message: Success (Thu Nov 17 11:30:05 2016) [sssd[pam]] [pam_check_user_search] (0x0100): Requesting info for [longina@n.c.domain] (Thu Nov 17 11:30:05 2016) [sssd[pam]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x1fd4570
(Thu Nov 17 11:30:05 2016) [sssd[pam]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x1fd4630
(Thu Nov 17 11:30:05 2016) [sssd[pam]] [ldb] (0x4000): Running timer event
0x1fd4570 "ltdb_callback"
(Thu Nov 17 11:30:05 2016) [sssd[pam]] [ldb] (0x4000): Destroying timer
event 0x1fd4630 "ltdb_timeout"
(Thu Nov 17 11:30:05 2016) [sssd[pam]] [ldb] (0x4000): Ending timer event
0x1fd4570 "ltdb_callback"
(Thu Nov 17 11:30:05 2016) [sssd[pam]] [pam_check_user_search] (0x0400): Returning info for user [longina@n.c.domain] (Thu Nov 17 11:30:05 2016) [sssd[pam]] [pd_set_primary_name] (0x0400): User's primary name is longina@n.c.domain (Thu Nov 17 11:30:05 2016)
[sssd[pam]] [pam_initgr_cache_set] (0x2000): [longina@n.c.domain] added to PAM initgroup cache (Thu Nov 17 11:30:05 2016) [sssd[pam]] [pam_dp_send_req] (0x0100): Sending request with the following data:
(Thu Nov 17 11:30:05 2016) [sssd[pam]] [pam_print_data] (0x0100): command: SSS_PAM_ACCT_MGMT (Thu Nov 17 11:30:05 2016) [sssd[pam]] [pam_print_data] (0x0100): domain: n.c.domain (Thu Nov 17 11:30:05 2016) [sssd[pam]] [pam_print_data] (0x0100): user: longina@n.c.domain (Thu Nov 17 11:30:05 2016) [sssd[pam]] [pam_print_data] (0x0100): service: su (Thu Nov 17 11:30:05 2016) [sssd[pam]] [pam_print_data] (0x0100): tty: /dev/pts/19 (Thu Nov 17 11:30:05 2016) [sssd[pam]] [pam_print_data] (0x0100): ruser: root (Thu Nov 17 11:30:05 2016) [sssd[pam]] [pam_print_data] (0x0100): rhost: not set (Thu Nov 17 11:30:05 2016) [sssd[pam]] [pam_print_data] (0x0100): authtok type: 0 (Thu Nov 17 11:30:05 2016) [sssd[pam]] [pam_print_data] (0x0100): newauthtok type: 0 (Thu Nov 17 11:30:05 2016) [sssd[pam]] [pam_print_data] (0x0100): priv: 1 (Thu Nov 17 11:30:05 2016) [sssd[pam]] [pam_print_data] (0x0100): cli_pid: 6611 (Thu Nov 17 11:30:05 2016) [sssd[pam]] [pam_print_data] (0x0100): logon name: longina@n.c.domain (Thu Nov 17 11:30:05 2016) [sssd[pam]] [sbus_add_timeout] (0x2000): 0x1fcd6d0 (Thu Nov 17 11:30:05 2016) [sssd[pam]] [pam_dom_forwarder] (0x0100): pam_dp_send_req returned
0 (Thu Nov 17 11:30:05 2016) [sssd[pam]] [sss_dp_req_destructor] (0x0400): Deleting request: [0x410090:3:longina@n.c.domain] (Thu Nov 17 11:30:06 2016) [sssd[pam]] [sbus_remove_timeout] (0x2000): 0x1fcd6d0 (Thu Nov 17 11:30:06 2016) [sssd[pam]] [sbus_dispatch] (0x4000): dbus conn: 0x1fcc1e0 (Thu Nov 17 11:30:06 2016) [sssd[pam]] [sbus_dispatch] (0x4000): Dispatching.
(Thu Nov 17 11:30:06 2016) [sssd[pam]] [pam_dp_process_reply] (0x0200): received: [0 (Success)][n.c.domain] (Thu Nov 17 11:30:06 2016) [sssd[pam]]
[pam_reply] (0x0200): pam_reply called with result [0]: Success.
(Thu Nov 17 11:30:06 2016) [sssd[pam]] [pam_reply] (0x0200): blen: 29 (Thu Nov 17 11:30:06 2016) [sssd[pam]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x1fd3fc0][19] (Thu Nov 17 11:30:06 2016) [sssd[pam]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x1fd3fc0][19] (Thu Nov 17 11:30:06 2016) [sssd[pam]] [pam_cmd_open_session] (0x0100): entering pam_cmd_open_session
(Thu Nov
17 11:30:06 2016) [sssd[pam]] [sss_parse_name_for_domains] (0x0200): name 'longina@n.c.domain' matched expression for domain 'n.c.domain', user is longina (Thu Nov 17 11:30:06 2016) [sssd[pam]] [pam_print_data] (0x0100): command: SSS_PAM_OPEN_SESSION (Thu Nov 17 11:30:06 2016) [sssd[pam]] [pam_print_data] (0x0100): domain: n.c.domain (Thu Nov 17 11:30:06 2016) [sssd[pam]] [pam_print_data] (0x0100): user: longina (Thu Nov 17 11:30:06 2016) [sssd[pam]] [pam_print_data] (0x0100): service: su (Thu Nov 17 11:30:06 2016) [sssd[pam]] [pam_print_data] (0x0100): tty: /dev/pts/19 (Thu Nov 17 11:30:06 2016) [sssd[pam]] [pam_print_data] (0x0100): ruser: root (Thu Nov 17 11:30:06 2016) [sssd[pam]] [pam_print_data] (0x0100): rhost: not set (Thu Nov 17 11:30:06 2016) [sssd[pam]] [pam_print_data] (0x0100): authtok type: 0 (Thu Nov 17 11:30:06 2016) [sssd[pam]] [pam_print_data] (0x0100):
newauthtok type: 0 (Thu Nov 17 11:30:06 2016) [sssd[pam]] [pam_print_data] (0x0100): priv: 1 (Thu Nov 17 11:30:06 2016) [sssd[pam]] [pam_print_data] (0x0100): cli_pid: 6611 (Thu Nov 17 11:30:06 2016) [sssd[pam]] [pam_print_data] (0x0100): logon name: longina@n.c.domain (Thu Nov 17 11:30:06 2016) [sssd[pam]] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/USER/n.c.domain/longina] (Thu Nov 17 11:30:06 2016) [sssd[pam]] [pam_initgr_check_timeout] (0x2000): User [longina@n.c.domain] found in PAM cache.
(Thu Nov 17 11:30:06 2016) [sssd[pam]] [pam_check_user_search] (0x0100): Requesting info for [longina@n.c.domain] (Thu Nov 17 11:30:06 2016) [sssd[pam]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x1fd07d0
(Thu Nov 17 11:30:06 2016) [sssd[pam]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x1fd0890
(Thu Nov 17 11:30:06 2016) [sssd[pam]] [ldb] (0x4000): Running timer event
0x1fd07d0 "ltdb_callback"
(Thu Nov 17 11:30:06 2016) [sssd[pam]] [ldb] (0x4000): Destroying timer
event 0x1fd0890 "ltdb_timeout"
(Thu Nov 17 11:30:06 2016) [sssd[pam]] [ldb] (0x4000): Ending timer event
0x1fd07d0 "ltdb_callback"
(Thu Nov 17 11:30:06 2016) [sssd[pam]] [pam_check_user_search] (0x0400): Returning info for user [longina@n.c.domain] (Thu Nov 17 11:30:06 2016) [sssd[pam]] [pd_set_primary_name] (0x0400): User's
primary name is longina@n.c.domain (Thu Nov 17 11:30:06 2016) [sssd[pam]] [pam_dp_send_req] (0x0100): Sending request with the following data:
(Thu Nov 17 11:30:06 2016) [sssd[pam]] [pam_print_data] (0x0100): command: SSS_PAM_OPEN_SESSION (Thu Nov 17 11:30:06 2016)
[sssd[pam]]
[pam_print_data] (0x0100): domain: n.c.domain (Thu Nov 17 11:30:06 2016) [sssd[pam]] [pam_print_data] (0x0100): user: longina@n.c.domain (Thu Nov 17 11:30:06 2016) [sssd[pam]] [pam_print_data] (0x0100): service: su (Thu Nov 17 11:30:06 2016) [sssd[pam]] [pam_print_data] (0x0100): tty: /dev/pts/19 (Thu Nov 17 11:30:06 2016) [sssd[pam]] [pam_print_data] (0x0100): ruser: root (Thu Nov 17 11:30:06 2016) [sssd[pam]] [pam_print_data] (0x0100): rhost: not set (Thu Nov 17 11:30:06 2016) [sssd[pam]] [pam_print_data] (0x0100): authtok type: 0 (Thu Nov 17 11:30:06 2016) [sssd[pam]] [pam_print_data] (0x0100): newauthtok type: 0 (Thu Nov 17 11:30:06 2016) [sssd[pam]] [pam_print_data] (0x0100): priv: 1 (Thu Nov 17 11:30:06 2016) [sssd[pam]] [pam_print_data] (0x0100): cli_pid: 6611 (Thu Nov 17 11:30:06 2016) [sssd[pam]] [pam_print_data] (0x0100): logon name: longina@n.c.domain (Thu Nov 17 11:30:06 2016) [sssd[pam]] [sbus_add_timeout] (0x2000): 0x1fcd640 (Thu Nov 17 11:30:06 2016)
[sssd[pam]] [pam_dom_forwarder] (0x0100): pam_dp_send_req returned 0 (Thu Nov 17 11:30:06 2016) [sssd[pam]] [sbus_remove_timeout] (0x2000): 0x1fcd640 (Thu Nov 17 11:30:06 2016) [sssd[pam]] [sbus_dispatch] (0x4000): dbus conn: 0x1fcc1e0 (Thu Nov 17 11:30:06 2016) [sssd[pam]] [sbus_dispatch] (0x4000): Dispatching.
(Thu Nov 17 11:30:06 2016) [sssd[pam]] [pam_dp_process_reply] (0x0200): received: [0 (Success)][n.c.domain] (Thu Nov 17 11:30:06 2016) [sssd[pam]]
[pam_reply] (0x0200): pam_reply called with result [0]: Success.
(Thu Nov 17 11:30:06 2016) [sssd[pam]] [pam_reply] (0x0200): blen: 29 (Thu Nov 17 11:30:06 2016) [sssd[pam]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x1fd3fc0][19] (Thu Nov 17 11:30:10 2016) [sssd[pam]] [pam_initgr_cache_remove] (0x2000): [longina@n.c.domain] removed from PAM initgroup cache (Thu Nov 17 11:30:12 2016) [sssd[pam]]
[sbus_dispatch] (0x4000): dbus conn: 0x1fcfa30 (Thu Nov 17 11:30:12 2016) [sssd[pam]] [sbus_dispatch] (0x4000): Dispatching.
(Thu Nov 17 11:30:12 2016) [sssd[pam]] [sbus_message_handler] (0x2000): Received SBUS method org.freedesktop.sssd.service.ping on path /org/freedesktop/sssd/service (Thu Nov 17 11:30:12 2016) [sssd[pam]] [sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit (Thu Nov
17 11:30:22 2016) [sssd[pam]] [sbus_dispatch] (0x4000): dbus conn: 0x1fcfa30 (Thu Nov 17 11:30:22 2016) [sssd[pam]] [sbus_dispatch] (0x4000): Dispatching.
(Thu Nov 17 11:30:22 2016) [sssd[pam]] [sbus_message_handler] (0x2000): Received SBUS method org.freedesktop.sssd.service.ping on path /org/freedesktop/sssd/service (Thu Nov 17 11:30:22 2016) [sssd[pam]] [sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit (Thu Nov
17 11:30:32 2016) [sssd[pam]] [sbus_dispatch] (0x4000): dbus conn: 0x1fcfa30 (Thu Nov 17 11:30:32 2016) [sssd[pam]] [sbus_dispatch] (0x4000): Dispatching.
(Thu Nov 17 11:30:32 2016) [sssd[pam]] [sbus_message_handler] (0x2000): Received SBUS method org.freedesktop.sssd.service.ping on path /org/freedesktop/sssd/service (Thu Nov 17 11:30:32 2016) [sssd[pam]] [sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit (Thu Nov
17 11:30:42 2016) [sssd[pam]] [sbus_dispatch] (0x4000): dbus conn: 0x1fcfa30 (Thu Nov 17 11:30:42 2016) [sssd[pam]] [sbus_dispatch] (0x4000): Dispatching.
(Thu Nov 17 11:30:42 2016) [sssd[pam]] [sbus_message_handler] (0x2000): Received SBUS method org.freedesktop.sssd.service.ping on path /org/freedesktop/sssd/service (Thu Nov 17 11:30:42 2016) [sssd[pam]] [sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit (Thu Nov
17 11:30:52 2016) [sssd[pam]] [sbus_dispatch] (0x4000): dbus conn: 0x1fcfa30 (Thu Nov 17 11:30:52 2016) [sssd[pam]] [sbus_dispatch] (0x4000): Dispatching.
(Thu Nov 17 11:30:52 2016) [sssd[pam]] [sbus_message_handler] (0x2000): Received SBUS method org.freedesktop.sssd.service.ping on path /org/freedesktop/sssd/service (Thu Nov 17 11:30:52 2016) [sssd[pam]] [sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit (Thu Nov 17 11:30:53 2016) [sssd[pam]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x1fd3fc0][19] (Thu Nov 17 11:30:53 2016) [sssd[pam]] [pam_cmd_close_session] (0x0100): entering pam_cmd_close_session (Thu Nov 17 11:30:53 2016) [sssd[pam]] [sss_parse_name_for_domains] (0x0200): name 'longina@n.c.domain' matched expression for domain 'n.c.domain', user is longina (Thu Nov 17 11:30:53 2016) [sssd[pam]] [pam_print_data] (0x0100): command: SSS_PAM_CLOSE_SESSION (Thu Nov 17 11:30:53 2016) [sssd[pam]] [pam_print_data] (0x0100): domain: n.c.domain (Thu Nov 17 11:30:53 2016) [sssd[pam]] [pam_print_data] (0x0100): user: longina (Thu Nov 17 11:30:53 2016) [sssd[pam]] [pam_print_data] (0x0100): service: su (Thu Nov 17 11:30:53 2016) [sssd[pam]] [pam_print_data] (0x0100): tty: /dev/pts/19 (Thu Nov 17 11:30:53 2016) [sssd[pam]] [pam_print_data] (0x0100): ruser: root (Thu Nov 17 11:30:53 2016) [sssd[pam]] [pam_print_data] (0x0100): rhost: not set (Thu Nov 17 11:30:53 2016)
[sssd[pam]] [pam_print_data] (0x0100): authtok type: 0 (Thu Nov 17 11:30:53 2016) [sssd[pam]] [pam_print_data] (0x0100): newauthtok type: 0 (Thu Nov 17 11:30:53 2016) [sssd[pam]] [pam_print_data] (0x0100): priv: 1 (Thu Nov 17 11:30:53 2016) [sssd[pam]] [pam_print_data] (0x0100): cli_pid: 6611 (Thu Nov 17 11:30:53 2016) [sssd[pam]] [pam_print_data] (0x0100): logon name: longina@n.c.domain (Thu Nov 17 11:30:53 2016) [sssd[pam]] [sss_ncache_check_str] (0x2000): Checking negative cache for [NCE/USER/n.c.domain/longina] (Thu Nov 17 11:30:53 2016) [sssd[pam]] [pam_initgr_check_timeout] (0x4000): User [longina@n.c.domain] not found in PAM cache.
(Thu Nov 17 11:30:53 2016) [sssd[pam]] [sss_dp_issue_request] (0x0400): Issuing request for [0x410090:3:longina@n.c.domain] (Thu Nov 17 11:30:53 2016) [sssd[pam]] [sss_dp_get_account_msg] (0x0400): Creating request for [n.c.domain][0x3][BE_REQ_INITGROUPS][1][name=longina] (Thu Nov 17 11:30:53 2016) [sssd[pam]] [sbus_add_timeout] (0x2000): 0x1fcd6d0 (Thu Nov 17 11:30:53 2016) [sssd[pam]] [sss_dp_internal_get_send] (0x0400): Entering request [0x410090:3:longina@n.c.domain] (Thu Nov 17 11:30:53 2016) [sssd[pam]] [sbus_remove_timeout] (0x2000): 0x1fcd6d0 (Thu Nov 17 11:30:53 2016)
[sssd[pam]] [sbus_dispatch] (0x4000): dbus conn: 0x1fcc1e0 (Thu Nov 17 11:30:53 2016) [sssd[pam]] [sbus_dispatch] (0x4000): Dispatching.
(Thu Nov 17 11:30:53 2016) [sssd[pam]] [sss_dp_get_reply] (0x1000): Got reply from Data Provider - DP error code: 0 errno: 0 error message: Success (Thu Nov 17 11:30:53 2016) [sssd[pam]] [pam_check_user_search] (0x0100): Requesting info for [longina@n.c.domain] (Thu Nov 17 11:30:53 2016) [sssd[pam]] [ldb] (0x4000): Added timed event "ltdb_callback": 0x1fd07d0
(Thu Nov 17 11:30:53 2016) [sssd[pam]] [ldb] (0x4000): Added timed event "ltdb_timeout": 0x1fd0890
(Thu Nov 17 11:30:53 2016) [sssd[pam]] [ldb] (0x4000): Running timer event
0x1fd07d0 "ltdb_callback"
(Thu Nov 17 11:30:53 2016) [sssd[pam]] [ldb] (0x4000): Destroying timer
event 0x1fd0890 "ltdb_timeout"
(Thu Nov 17 11:30:53 2016) [sssd[pam]] [ldb] (0x4000): Ending timer event
0x1fd07d0 "ltdb_callback"
(Thu Nov 17 11:30:53 2016) [sssd[pam]] [pam_check_user_search] (0x0400): Returning info for user [longina@n.c.domain] (Thu Nov 17 11:30:53 2016) [sssd[pam]] [pd_set_primary_name] (0x0400): User's primary name is longina@n.c.domain (Thu Nov 17 11:30:53 2016)
[sssd[pam]] [pam_initgr_cache_set] (0x2000): [longina@n.c.domain] added to PAM initgroup cache (Thu Nov 17 11:30:53 2016) [sssd[pam]] [pam_dp_send_req] (0x0100): Sending request with the following data:
(Thu Nov 17 11:30:53 2016) [sssd[pam]] [pam_print_data] (0x0100): command: SSS_PAM_CLOSE_SESSION (Thu Nov 17 11:30:53 2016)
[sssd[pam]]
[pam_print_data] (0x0100): domain: n.c.domain (Thu Nov 17 11:30:53 2016) [sssd[pam]] [pam_print_data] (0x0100): user: longina@n.c.domain (Thu Nov 17 11:30:53 2016) [sssd[pam]] [pam_print_data] (0x0100): service: su (Thu Nov 17 11:30:53 2016) [sssd[pam]] [pam_print_data] (0x0100): tty: /dev/pts/19 (Thu Nov 17 11:30:53 2016) [sssd[pam]] [pam_print_data] (0x0100): ruser: root (Thu Nov 17 11:30:53 2016) [sssd[pam]] [pam_print_data] (0x0100): rhost: not set (Thu Nov 17 11:30:53 2016) [sssd[pam]] [pam_print_data] (0x0100): authtok type: 0 (Thu Nov 17 11:30:53 2016) [sssd[pam]] [pam_print_data] (0x0100): newauthtok type: 0 (Thu Nov 17 11:30:53 2016) [sssd[pam]] [pam_print_data] (0x0100): priv: 1 (Thu Nov 17 11:30:53 2016) [sssd[pam]] [pam_print_data] (0x0100): cli_pid: 6611 (Thu Nov 17 11:30:53 2016) [sssd[pam]] [pam_print_data] (0x0100): logon name: longina@n.c.domain (Thu Nov 17 11:30:53 2016) [sssd[pam]] [sbus_add_timeout] (0x2000): 0x1fcbd80 (Thu Nov 17 11:30:53 2016) [sssd[pam]] [pam_dom_forwarder] (0x0100): pam_dp_send_req returned
0 (Thu Nov 17 11:30:53 2016) [sssd[pam]] [sss_dp_req_destructor] (0x0400): Deleting request: [0x410090:3:longina@n.c.domain] (Thu Nov 17 11:30:53 2016) [sssd[pam]] [sbus_remove_timeout] (0x2000): 0x1fcbd80 (Thu Nov 17 11:30:53 2016) [sssd[pam]] [sbus_dispatch] (0x4000): dbus conn: 0x1fcc1e0 (Thu Nov 17 11:30:53 2016) [sssd[pam]] [sbus_dispatch] (0x4000): Dispatching.
(Thu Nov 17 11:30:53 2016) [sssd[pam]] [pam_dp_process_reply] (0x0200): received: [0 (Success)][n.c.domain] (Thu Nov 17 11:30:53 2016) [sssd[pam]]
[pam_reply] (0x0200): pam_reply called with result [0]: Success.
(Thu Nov 17 11:30:53 2016) [sssd[pam]] [pam_reply] (0x0200): blen: 29 (Thu Nov 17 11:30:53 2016) [sssd[pam]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x1fd3fc0][19] (Thu Nov 17 11:30:53 2016) [sssd[pam]] [reset_idle_timer] (0x4000): Idle timer re-set for client
[0x1fd3fc0][19] (Thu Nov 17 11:30:53 2016) [sssd[pam]] [client_recv] (0x0200): Client disconnected!
(Thu Nov 17 11:30:53 2016) [sssd[pam]] [client_destructor] (0x2000): Terminated client [0x1fd3fc0][19] (Thu Nov 17 11:30:58 2016) [sssd[pam]] [pam_initgr_cache_remove] (0x2000): [longina@n.c.domain]
removed from PAM initgroup cache (Thu Nov 17 11:30:59 2016) [sssd[pam]] [get_client_cred] (0x4000): Client creds: euid[0] egid[0] pid[1717].
(Thu Nov 17 11:30:59 2016) [sssd[pam]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x1fd3fc0][19] (Thu Nov 17 11:30:59 2016)
[sssd[pam]] [accept_fd_handler] (0x0400): Client connected to privileged pipe!
(Thu Nov 17 11:30:59 2016) [sssd[pam]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x1fd3fc0][19] (Thu Nov 17 11:30:59 2016)
[sssd[pam]] [sss_cmd_get_version] (0x0200): Received client version [3].
(Thu Nov 17 11:30:59 2016) [sssd[pam]] [sss_cmd_get_version] (0x0200):
Offered version [3].
(Thu Nov 17 11:30:59 2016) [sssd[pam]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x1fd3fc0][19] (Thu Nov 17 11:30:59 2016) [sssd[pam]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x1fd3fc0][19] (Thu Nov 17 11:30:59 2016) [sssd[pam]] [pam_cmd_close_session] (0x0100): entering pam_cmd_close_session
(Thu
Nov 17 11:30:59 2016) [sssd[pam]] [sss_parse_name_for_domains] (0x0200): name 'alongina' matched without domain, user is alongina (Thu Nov 17 11:30:59 2016) [sssd[pam]] [pam_print_data] (0x0100): command: SSS_PAM_CLOSE_SESSION (Thu Nov 17 11:30:59 2016) [sssd[pam]] [pam_print_data] (0x0100): domain: not set (Thu Nov 17 11:30:59 2016) [sssd[pam]] [pam_print_data] (0x0100): user: alongina (Thu Nov 17 11:30:59 2016) [sssd[pam]] [pam_print_data] (0x0100): service: lightdm (Thu Nov 17 11:30:59 2016) [sssd[pam]] [pam_print_data] (0x0100): tty: :0 (Thu Nov 17 11:30:59 2016) [sssd[pam]] [pam_print_data] (0x0100): ruser: not set (Thu Nov 17 11:30:59 2016) [sssd[pam]] [pam_print_data] (0x0100): rhost: not set (Thu Nov 17 11:30:59 2016) [sssd[pam]] [pam_print_data] (0x0100): authtok type: 0 (Thu Nov 17 11:30:59 2016)
[sssd[pam]] [pam_print_data] (0x0100): newauthtok type: 0 (Thu Nov 17 11:30:59 2016) [sssd[pam]] [pam_print_data] (0x0100): priv: 1 (Thu Nov 17 11:30:59 2016) [sssd[pam]] [pam_print_data] (0x0100): cli_pid: 1717 (Thu Nov 17 11:30:59 2016) [sssd[pam]] [pam_print_data] (0x0100): logon name: alongina (Thu Nov 17 11:30:59 2016) [sssd[pam]] [pam_reply] (0x0200): pam_reply called with result [10]: User not known to the underlying authentication module.
(Thu Nov 17 11:30:59 2016) [sssd[pam]] [pam_reply] (0x0200): blen: 8
Is it a typo? because the user "alongina" was not recognized as a sssd user. Therefore there is a pam error "User not known to the underlying authentication module"
Different user was used in previous pam actions "longina@n.c.domain"
(Thu Nov 17 11:30:59 2016) [sssd[pam]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x1fd3fc0][19] (Thu Nov 17 11:30:59 2016) [sssd[pam]] [reset_idle_timer] (0x4000): Idle timer re-set for client
[0x1fd3fc0][19] (Thu Nov 17 11:30:59 2016) [sssd[pam]] [client_recv] (0x0200): Client disconnected!
(Thu Nov 17 11:30:59 2016) [sssd[pam]] [client_destructor] (0x2000): Terminated client [0x1fd3fc0][19] (Thu Nov 17 11:31:00 2016) [sssd[pam]]
[get_client_cred] (0x4000): Client creds: euid[0] egid[0] pid[6669].
(Thu Nov 17 11:31:00 2016) [sssd[pam]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x1fd3fc0][19] (Thu Nov 17 11:31:00 2016)
[sssd[pam]] [accept_fd_handler] (0x0400): Client connected to privileged pipe!
(Thu Nov 17 11:31:00 2016) [sssd[pam]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x1fd3fc0][19] (Thu Nov 17 11:31:00 2016)
[sssd[pam]] [sss_cmd_get_version] (0x0200): Received client version [3].
(Thu Nov 17 11:31:00 2016) [sssd[pam]] [sss_cmd_get_version] (0x0200):
Offered version [3].
(Thu Nov 17 11:31:00 2016) [sssd[pam]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x1fd3fc0][19] (Thu Nov 17 11:31:00 2016) [sssd[pam]] [reset_idle_timer] (0x4000): Idle timer re-set for client [0x1fd3fc0][19] (Thu Nov 17 11:31:00 2016) [sssd[pam]] [pam_cmd_open_session] (0x0100): entering pam_cmd_open_session
(Thu Nov
17 11:31:00 2016) [sssd[pam]] [sss_parse_name_for_domains] (0x0200): name 'lightdm' matched without domain, user is lightdm (Thu Nov 17 11:31:00 2016) [sssd[pam]] [pam_print_data] (0x0100): command: SSS_PAM_OPEN_SESSION (Thu Nov 17 11:31:00 2016) [sssd[pam]] [pam_print_data] (0x0100): domain: not set (Thu Nov 17 11:31:00 2016) [sssd[pam]] [pam_print_data] (0x0100): user: lightdm (Thu Nov 17 11:31:00 2016) [sssd[pam]] [pam_print_data] (0x0100): service: lightdm-greeter (Thu Nov 17 11:31:00 2016) [sssd[pam]] [pam_print_data] (0x0100): tty: :0 (Thu Nov 17 11:31:00 2016) [sssd[pam]] [pam_print_data] (0x0100): ruser: not set (Thu Nov 17 11:31:00 2016) [sssd[pam]] [pam_print_data] (0x0100): rhost: not set (Thu Nov 17 11:31:00 2016) [sssd[pam]] [pam_print_data] (0x0100): authtok type: 0 (Thu
Nov 17 11:31:00 2016) [sssd[pam]] [pam_print_data] (0x0100): newauthtok type: 0 (Thu Nov 17 11:31:00 2016) [sssd[pam]] [pam_print_data] (0x0100): priv: 1 (Thu Nov 17 11:31:00 2016) [sssd[pam]] [pam_print_data] (0x0100): cli_pid: 6669 (Thu Nov 17 11:31:00 2016) [sssd[pam]] [pam_print_data] (0x0100): logon name: lightdm (Thu Nov 17 11:31:00 2016) [sssd[pam]] [pam_reply] (0x0200): pam_reply called with result [10]: User not known to the underlying authentication module. I think it is expected user lightdm is not handled by sssd. So I am not sure wheter it could cause a problem. The only problem could be caused by gpo and that service "lightdm-greeter" is not allowed by default.
LS _______________________________________________ sssd-users mailing list -- sssd-users@lists.fedorahosted.org To unsubscribe send an email to sssd-users-leave@lists.fedorahosted.org
On (21/11/16 11:38), Longina Przybyszewska wrote:
No, it is not a typo, 'alongina' is my local account - sorry , I should cut it off from the log ;(
Domain user is longina@n.c.domain
As I wrote in previous mail. I cannot see any problem in logs with authentication for this user.
I use following option to turn off gpo : .... ad_gpo_access_control = permissive
That shoudl be enough.
pam_public_domains = all
This option does not have any effect unless you changed pam stack configuration and you use "domains=" together with pam_sss.so
selinux_provider = none
ad doesnot have selinux_provider. So this line didn't change anything.
....
Is it not enough?
LS
Hi again, Sorry for delay ; I checked domain log - the long version of the log attached.
Here is the short extract from the log - with focus on PAM;
I am suspicious , that PAM commands end with "logon_name = not set" whatever that means; As I wrote before, the login session is partially done - homedir is nfs+krb share and is mounted With proper nfsidmapping. I login with fqn longina@n.c.domain
Best, Longina
---
(Wed Nov 30 16:25:16 2016) [sssd[be[a.c.domain]]] [ad_gpo_access_check] (0x0400): POLICY DECISION: (Wed Nov 30 16:25:16 2016) [sssd[be[a.c.domain]]] [ad_gpo_access_check] (0x0400): access_granted = 1 (Wed Nov 30 16:25:16 2016) [sssd[be[a.c.domain]]] [ad_gpo_access_check] (0x0400): access_denied = 0 (Wed Nov 30 16:25:16 2016) [sssd[be[a.c.domain]]] [ad_gpo_access_done] (0x0400): GPO-based access control successful.
.....
(Wed Nov 30 16:24:56 2016) [sssd[be[a.c.domain]]] [pam_print_data] (0x0100): command: SSS_PAM_AUTHENTICATE (Wed Nov 30 16:24:56 2016) [sssd[be[a.c.domain]]] [pam_print_data] (0x0100): domain: n.c.domain (Wed Nov 30 16:24:56 2016) [sssd[be[a.c.domain]]] [pam_print_data] (0x0100): user: longina@n.c.domain (Wed Nov 30 16:24:56 2016) [sssd[be[a.c.domain]]] [pam_print_data] (0x0100): service: lightdm (Wed Nov 30 16:24:56 2016) [sssd[be[a.c.domain]]] [pam_print_data] (0x0100): tty: :0 (Wed Nov 30 16:24:56 2016) [sssd[be[a.c.domain]]] [pam_print_data] (0x0100): ruser: (Wed Nov 30 16:24:56 2016) [sssd[be[a.c.domain]]] [pam_print_data] (0x0100): rhost: (Wed Nov 30 16:24:56 2016) [sssd[be[a.c.domain]]] [pam_print_data] (0x0100): authtok type: 1 (Wed Nov 30 16:24:56 2016) [sssd[be[a.c.domain]]] [pam_print_data] (0x0100): newauthtok type: 0 (Wed Nov 30 16:24:56 2016) [sssd[be[a.c.domain]]] [pam_print_data] (0x0100): priv: 1 (Wed Nov 30 16:24:56 2016) [sssd[be[a.c.domain]]] [pam_print_data] (0x0100): cli_pid: 1164 (Wed Nov 30 16:24:56 2016) [sssd[be[a.c.domain]]] [pam_print_data] (0x0100): logon name: not set (Wed Nov 30 16:24:56 2016) [sssd[be[a.c.domain]]] [krb5_auth_queue_send] (0x1000): Wait queue of user [longina@n.c.domain] is empty, running request [0x2290660] immediately. (Wed Nov 30 16:24:56 2016) [sssd[be[a.c.domain]]] [krb5_setup] (0x4000): No mapping for: longina@n.c.domain
...... (Wed Nov 30 16:24:57 2016) [sssd[be[a.c.domain]]] [pam_print_data] (0x0100): command: SSS_PAM_ACCT_MGMT (Wed Nov 30 16:24:57 2016) [sssd[be[a.c.domain]]] [pam_print_data] (0x0100): domain: n.c.domain (Wed Nov 30 16:24:57 2016) [sssd[be[a.c.domain]]] [pam_print_data] (0x0100): user: longina@n.c.domain (Wed Nov 30 16:24:57 2016) [sssd[be[a.c.domain]]] [pam_print_data] (0x0100): service: lightdm (Wed Nov 30 16:24:57 2016) [sssd[be[a.c.domain]]] [pam_print_data] (0x0100): tty: :0 (Wed Nov 30 16:24:57 2016) [sssd[be[a.c.domain]]] [pam_print_data] (0x0100): ruser: (Wed Nov 30 16:24:57 2016) [sssd[be[a.c.domain]]] [pam_print_data] (0x0100): rhost: (Wed Nov 30 16:24:57 2016) [sssd[be[a.c.domain]]] [pam_print_data] (0x0100): authtok type: 0 (Wed Nov 30 16:24:57 2016) [sssd[be[a.c.domain]]] [pam_print_data] (0x0100): newauthtok type: 0 (Wed Nov 30 16:24:57 2016) [sssd[be[a.c.domain]]] [pam_print_data] (0x0100): priv: 1 (Wed Nov 30 16:24:57 2016) [sssd[be[a.c.domain]]] [pam_print_data] (0x0100): cli_pid: 1164 (Wed Nov 30 16:24:57 2016) [sssd[be[a.c.domain]]] [pam_print_data] (0x0100): logon name: not set (Wed Nov 30 16:24:57 2016) [sssd[be[a.c.domain]]] [sdap_access_send] (0x0400): Performing access check for user [longina@n.c.domain]
...... (Wed Nov 30 16:24:59 2016) [sssd[be[a.c.domain]]] [pam_print_data] (0x0100): command: SSS_PAM_SETCRED (Wed Nov 30 16:24:59 2016) [sssd[be[a.c.domain]]] [pam_print_data] (0x0100): domain: n.c.domain (Wed Nov 30 16:24:59 2016) [sssd[be[a.c.domain]]] [pam_print_data] (0x0100): user: longina@n.c.domain (Wed Nov 30 16:24:59 2016) [sssd[be[a.c.domain]]] [pam_print_data] (0x0100): service: lightdm (Wed Nov 30 16:24:59 2016) [sssd[be[a.c.domain]]] [pam_print_data] (0x0100): tty: :0 (Wed Nov 30 16:24:59 2016) [sssd[be[a.c.domain]]] [pam_print_data] (0x0100): ruser: (Wed Nov 30 16:24:59 2016) [sssd[be[a.c.domain]]] [pam_print_data] (0x0100): rhost: (Wed Nov 30 16:24:59 2016) [sssd[be[a.c.domain]]] [pam_print_data] (0x0100): authtok type: 0 (Wed Nov 30 16:24:59 2016) [sssd[be[a.c.domain]]] [pam_print_data] (0x0100): newauthtok type: 0 (Wed Nov 30 16:24:59 2016) [sssd[be[a.c.domain]]] [pam_print_data] (0x0100): priv: 1 (Wed Nov 30 16:24:59 2016) [sssd[be[a.c.domain]]] [pam_print_data] (0x0100): cli_pid: 1164 (Wed Nov 30 16:24:59 2016) [sssd[be[a.c.domain]]] [pam_print_data] (0x0100): logon name: not set (Wed Nov 30 16:24:59 2016) [sssd[be[a.c.domain]]] [be_pam_handler] (0x0100): Sending result [0][n.c.domain] (Wed Nov 30 16:24:59 2016) [sssd[be[a.c.domain]]] [sbus_dispatch] (0x4000): dbus conn: 0x21d6360 (Wed Nov 30 16:24:59 2016) [sssd[be[a.c.domain]]] [sbus_dispatch] (0x4000): Dispatching. (Wed Nov 30 16:24:59 2016) [sssd[be[a.c.domain]]] [sbus_message_handler] (0x2000): Received SBUS method org.freedesktop.sssd.dataprovider.pamHandler on path /org/freedesktop/sssd/dataprovider (Wed Nov 30 16:24:59 2016) [sssd[be[a.c.domain]]] [sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit (Wed Nov 30 16:24:59 2016) [sssd[be[a.c.domain]]] [be_req_set_domain] (0x0400): Changing request domain from [a.c.domain] to [n.c.domain] (Wed Nov 30 16:24:59 2016) [sssd[be[a.c.domain]]] [be_pam_handler] (0x0100): Got request with the following data (Wed Nov 30 16:24:59 2016) [sssd[be[a.c.domain]]] [pam_print_data] (0x0100): command: SSS_PAM_OPEN_SESSION (Wed Nov 30 16:24:59 2016) [sssd[be[a.c.domain]]] [pam_print_data] (0x0100): domain: n.c.domain (Wed Nov 30 16:24:59 2016) [sssd[be[a.c.domain]]] [pam_print_data] (0x0100): user: longina@n.c.domain (Wed Nov 30 16:24:59 2016) [sssd[be[a.c.domain]]] [pam_print_data] (0x0100): service: lightdm (Wed Nov 30 16:24:59 2016) [sssd[be[a.c.domain]]] [pam_print_data] (0x0100): tty: :0 (Wed Nov 30 16:24:59 2016) [sssd[be[a.c.domain]]] [pam_print_data] (0x0100): ruser: (Wed Nov 30 16:24:59 2016) [sssd[be[a.c.domain]]] [pam_print_data] (0x0100): rhost: (Wed Nov 30 16:24:59 2016) [sssd[be[a.c.domain]]] [pam_print_data] (0x0100): authtok type: 0 (Wed Nov 30 16:24:59 2016) [sssd[be[a.c.domain]]] [pam_print_data] (0x0100): newauthtok type: 0 (Wed Nov 30 16:24:59 2016) [sssd[be[a.c.domain]]] [pam_print_data] (0x0100): priv: 1 (Wed Nov 30 16:24:59 2016) [sssd[be[a.c.domain]]] [pam_print_data] (0x0100): cli_pid: 1164 (Wed Nov 30 16:24:59 2016) [sssd[be[a.c.domain]]] [pam_print_data] (0x0100): logon name: not set (Wed Nov 30 16:24:59 2016) [sssd[be[a.c.domain]]] [be_pam_handler] (0x0100): Sending result [0][n.c.domain] (Wed Nov 30 16:24:59 2016) [sssd[be[a.c.domain]]] [sbus_dispatch] (0x4000): dbus conn: 0x21d6360 (Wed Nov 30 16:24:59 2016) [sssd[be[a.c.domain]]] [sbus_dispatch] (0x4000): Dispatching. (Wed Nov 30 16:24:59 2016) [sssd[be[a.c.domain]]] [sbus_message_handler] (0x2000): Received SBUS method org.freedesktop.sssd.dataprovider.pamHandler on path /org/freedesktop/sssd/dataprovider (Wed Nov 30 16:24:59 2016) [sssd[be[a.c.domain]]] [sbus_get_sender_id_send] (0x2000): Not a sysbus message, quit
-----Oprindelig meddelelse----- Fra: Jakub Hrozek [mailto:jhrozek@redhat.com] Sendt: 17. november 2016 09:25 Til: sssd-users@lists.fedorahosted.org Emne: [SSSD-users] Re: sssd-13.4 can't login
On Wed, Nov 09, 2016 at 02:45:56PM +0000, Longina Przybyszewska wrote:
Hi again, I still hang on that problem. Client and server are configured in AD trust realm environment. Client and server are joind to a.c.domain; User is from n.c.domain.
During login sequence NFS-share (sec=krb5) homedir is mounted with
right nfsidmapping .
User can't login because of access denied to the homedir.
If I change mount parameter to sec=sys, user can successfully login.
Machine's and user's credentials *are* valid ;
== Ticket cache: FILE:/tmp/krb5cc_332405654_B4r6Sy Default principal: longina@N.C.DOMAIN
Valid starting Expires Service principal 11/09/2016 15:00:43 11/10/2016 01:00:43
krbtgt/N.C.DOMAIN@N.C.DOMAIN
renew until 11/10/2016 01:00:4311/09/2016 15:00:45 11/10/2016 01:00:43 krbtgt/C.SDU.DK@N.C.DOMAIN renew until 11/10/2016 01:00:43 11/09/2016 15:00:45 11/10/2016 01:00:43 nfs/adm-lptest.a.c.domain@ renew until 11/10/2016 01:00:43 11/09/2016 15:00:45 11/10/2016 01:00:43 nfs/adm-
lptest.a.c.domain@A.C.DOMAIN
renew until 11/10/2016 01:00:43 == Kerberos sequence for loginends with (krb5_child.log) :
==[sss_get_ccache_name_for_principal] (0x2000): krb5_cc_cache_match failed: [-1765328243][Can't find client principal longina@N.C.DOMAIN in cache collection]=
You can ignore this, since you are using the FILE: ccache which is doesn't support collections, this error is harmless.
It looks like the krb5_child itself finished fine, according to:
(Wed Nov 9 15:00:44 2016) [[sssd[krb5_child[1563]]]] [k5c_send_data] (0x0200): Received error code 0 (Wed Nov 9 15:00:44 2016) [[sssd[krb5_child[1563]]]] [pack_response_packet] (0x2000): response
packet size: [142] (Wed Nov 9 15:00:44 2016) [[sssd[krb5_child[1563]]]] [k5c_send_data] (0x4000): Response sent.
(Wed Nov 9 15:00:44 2016) [[sssd[krb5_child[1563]]]] [main] (0x0400): krb5_child completed successfully
So I would suggest to look into the domain logs as well. Chances are some other part (maybe the access control later?) is failing. _______________________________________________ sssd-users mailing list -- sssd-users@lists.fedorahosted.org To unsubscribe send an email to sssd-users-leave@lists.fedorahosted.org
sssd-users@lists.fedorahosted.org
-
Jakub Hrozek -
Longina Przybyszewska -
Lukas Slebodnik