UNOFFICIAL
Hi Jakub,
No problem about the late reply, I understand being snowed under :)
I'm fairly sure that the details entered for tests in the previous email were correct,
but I have run some additional tests to validate and something strange is definitely going
on here.
The inconsistency of the results can be shown by:
1. Check Kerberos ticket (after being renewed)
kinit firstname.lastname
klist
Ticket cache: FILE:/tmp/krb5cc_0
Default principal: firstname.lastname(a)DOMAIN.SUBDOMAIN.COM
Valid starting Expires Service principal
04/13/16 09:15:17 04/13/16 19:16:42 krbtgt/DOMAIN.SUBDOMAIN.COM(a)DOMAIN.SUBDOMAIN.COM
renew until 04/20/16 09:15:17
04/13/16 09:16:56 04/13/16 19:16:42 ldap/computername.domain.subdomain.com@
renew until 04/20/16 09:15:17
04/13/16 09:16:56 04/13/16 19:16:42
ldap/computername.domain.subdomain.com(a)DOMAIN.SUBDOMAIN.COM
renew until 04/20/16 09:15:17
klist -ke
Keytab name: FILE:/etc/krb5.keytab
KVNO Principal
---- --------------------------------------------------------------------------
2 host/computername.domain.subdomain.com(a)DOMAIN.SUBDOMAIN.COM (des-cbc-crc)
2 host/computername.domain.subdomain.com(a)DOMAIN.SUBDOMAIN.COM (des-cbc-md5)
2 host/computername.domain.subdomain.com(a)DOMAIN.SUBDOMAIN.COM
(aes128-cts-hmac-sha1-96)
2 host/computername.domain.subdomain.com(a)DOMAIN.SUBDOMAIN.COM
(aes256-cts-hmac-sha1-96)
2 host/computername.domain.subdomain.com(a)DOMAIN.SUBDOMAIN.COM (arcfour-hmac)
2 host/computername(a)DOMAIN.SUBDOMAIN.COM (des-cbc-crc)
2 host/computername(a)DOMAIN.SUBDOMAIN.COM (des-cbc-md5)
2 host/computername(a)DOMAIN.SUBDOMAIN.COM (aes128-cts-hmac-sha1-96)
2 host/computername(a)DOMAIN.SUBDOMAIN.COM (aes256-cts-hmac-sha1-96)
2 host/computername(a)DOMAIN.SUBDOMAIN.COM (arcfour-hmac)
2 COMPUTERNAME$(a)DOMAIN.SUBDOMAIN.COM (des-cbc-crc)
2 COMPUTERNAME$(a)DOMAIN.SUBDOMAIN.COM (des-cbc-md5)
2 COMPUTERNAME$(a)DOMAIN.SUBDOMAIN.COM (aes128-cts-hmac-sha1-96)
2 COMPUTERNAME$(a)DOMAIN.SUBDOMAIN.COM (aes256-cts-hmac-sha1-96)
2 COMPUTERNAME$(a)DOMAIN.SUBDOMAIN.COM (arcfour-hmac)
2. Run an ldapsearch to confirm connectivity
/usr/bin/ldapsearch -H
ldap://domaincontrollerA0101.domain.subdomain.com -Y GSSAPI -N -b
"dc=domain,dc=subdomain,dc=com"
"(&(objectClass=user)(sAMAccountName=firstname.lastname))"
SASL/GSSAPI authentication started
SASL username: firstname.lastname(a)DOMAIN.SUBDOMAIN.COM
SASL SSF: 56
SASL data security layer installed.
# extended LDIF
#
# LDAPv3
# base <dc=domain,dc=subdomain,dc=com> with scope subtree # filter:
(&(objectClass=user)(sAMAccountName=firstname.lastname))
# requesting: ALL
#
# Firstname.Lastname, Privileged, Users, CompanyName,
DOMAIN.SUBDOMAIN.COM
dn:
CN=Firstname.Lastname,OU=Privileged,OU=Users,OU=CompanyName,DC=DOMAIN,DC=SUBDOMAIN,DC=COM
objectClass: top
objectClass: person
objectClass: organizationalPerson
objectClass: user
cn: Firstname.Lastname
sn: Lastname
description: <foo>
givenName: Firstname
distinguishedName:
CN=Firstname.Lastname,OU=Privileged,OU=Users,OU=CompanyName,DC=DOMAIN,DC=SUBDOMAIN,DC=COM
instanceType: 4
whenCreated: 20150623222214.0Z
whenChanged: 20160411045338.0Z
displayName: Firstname Lastname
uSNCreated: 22286092
memberOf: CN=<Group1>,OU=<OU1>,OU=Groups,OU=CP,DC=DOMAIN,DC=SUBDOMAIN,DC=COM
memberOf: CN=<Group2>,OU=Privileged Roles,OU=Role
Groups,OU=Groups,OU=CompanyName,DC=DOMAIN,DC=SUBDOMAIN,DC=COM
uSNChanged: 70577727
name: Firstname.Lastname
objectGUID:: 7ETyl9SLLECRcLMwU8B7Bw==
userAccountControl: 512
badPwdCount: 0
codePage: 0
countryCode: 0
badPasswordTime: 131048186499453019
lastLogoff: 0
lastLogon: 131048282599611200
pwdLastSet: 131017840136140126
primaryGroupID: 513
objectSid:: AQUAAAAAAAUVAAAAvu+cFd6oI02tmKt08AoAAA==
adminCount: 1
accountExpires: 131112504000000000
logonCount: 1427
sAMAccountName: Firstname.Lastname
sAMAccountType: 805306368
userPrincipalName: Firstname.Lastname(a)DOMAIN.SUBDOMAIN.COM
lockoutTime: 0
objectCategory: CN=Person,CN=Schema,CN=Configuration,DC=SUBDOMAIN,DC=COM
dSCorePropagationData: 20150623225235.0Z
dSCorePropagationData: 16010101000000.0Z
lastLogonTimestamp: 131048240186138155
msTSExpireDate: 20160104050554.0Z
msTSLicenseVersion: 393218
msTSManagingLS: 00184-30000-00001-AT061
msTSLicenseVersion2: 7
msTSLicenseVersion3: C50-6.02-S
# search reference
ref:
ldap://DomainDnsZones.DOMAIN.SUBDOMAIN.COM/DC=DomainDnsZones,DC=DOMAIN,DC...
# search result
search: 4
result: 0 Success
# numResponses: 3
# numEntries: 1
# numReferences: 1
3. Stop SSSD
4. Clear cache (sss_cache -E; rm /var/lib/sss/db/*) 5. Set SSSD domain & nss log
levels to 3 6. Start SSSD 7. Query my user account (id firstname.lastname) 8. Query my
user account again, immediately after previous results returned (id firstname.lastname) 9.
Stop SSSD 10. Gather logs
The results from steps 7 & 8 differ, with the step 7 producing correct results, but
step 8 (and each query thereafter) providing incorrect results.
See an example here:
Step 7:
uid=202800(firstname.lastname) gid=200513(domain users) groups=200513(domain
users),200512(domain
admins),201549(<GROUP>),202710(<GROUP>),201226(<GROUP>),202712(<GROUP>),201172(<GROUP>),202682(<GROUP>),202717(<GROUP>),200572(<GROUP>),204611(<GROUP>),201120(<GROUP>),201156(<GROUP>),201228(<GROUP>),201123(<GROUP>),201207(<GROUP>),202703(<GROUP>),201210(<GROUP>),202686(<GROUP>),201103(<GROUP>),201113(<GROUP>),201223(<GROUP>),201230(<GROUP>),204612(<GROUP>),201126(<GROUP>),201112(<GROUP>),202684(<GROUP>),202714(<GROUP>)
Step 8:
uid=202800(firstname.lastname) gid=200513(domain users) groups=200513(domain users)
I then repeated steps 2-7, except with log levels set to 9 and everything worked correctly
- multiple queries from step 7 onwards all succeeded (I ran at least 5, then logged in via
SSH a couple of times).
I then repeated steps 2-7, with log levels set back to 3 and the problem recurs except the
first result (and all results thereafter) were incorrect.
I repeated sequence 4-9 until I could capture one correct and one incorrect query
sequentially at log level 9 (attached).
Very inconsistent behaviour, but failing more often than succeeding!
This environment has 4 Domain controllers for the domain (in 2 remote datacentres), and 8
for the parent domain (4 locally, and the other 4 in 2 remote datacentres).
Please let me know if you need any additional information for this one!
Regards,
Adam
-----Original Message-----
From: Jakub Hrozek [mailto:jhrozek@redhat.com]
Sent: Tuesday, 12 April 2016 18:20
To: sssd-users(a)lists.fedorahosted.org
Subject: [SSSD-users] Re: Inconsistent SSSD function [SEC=UNOFFICIAL]
Sorry for the late reply, I had some urgent packaging work on my plate lately..
OK, I see some failures, but I'm not sure if it's "expected" failures
(ie a mistyped password) or some unexpected one.
In the logs, one is at this point in the domain log:
(Fri Apr 8 09:36:35 2016) [sssd[be[domain.subdomain.com]]] [check_wait_queue] (0x1000):
Wait queue for user [Firstname.Lastname] is empty.
(Fri Apr 8 09:36:35 2016) [sssd[be[domain.subdomain.com]]] [be_pam_handler_callback]
(0x0100): Backend returned: (0, 17, <NULL>) [Success] (Fri Apr 8 09:36:35 2016)
[sssd[be[domain.subdomain.com]]] [be_pam_handler_callback] (0x0100): Sending result
[
17][domain.subdomain.com] (Fri Apr 8 09:36:35 2016) [sssd[be[domain.subdomain.com]]]
[be_pam_handler_callback] (0x0100): Sent result [
17][domain.subdomain.com]
The corresponding krb5_child.log entry is:
(Fri Apr 8 09:36:35 2016) [[sssd[krb5_child[17431]]]] [get_and_save_tgt] (0x0400):
Attempting kinit for realm [
domain.subdomain.com] (Fri Apr 8 09:36:35 2016)
[[sssd[krb5_child[17431]]]] [sss_child_krb5_trace_cb] (0x4000): [17431] 1460072195.572481:
Getting initial credentials for
Firstname.Lastname\@domain.subdomain.com(a)domain.subdomain.com
(Fri Apr 8 09:36:35 2016) [[sssd[krb5_child[17431]]]] [sss_child_krb5_trace_cb] (0x4000):
[17431] 1460072195.572640: Sending request (268 bytes) to
domain.subdomain.com (Fri Apr 8
09:36:35 2016) [[sssd[krb5_child[17431]]]] [sss_child_krb5_trace_cb] (0x4000): [17431]
1460072195.577302: Sending initial UDP request to dgram 10.221.74.11:88 (Fri Apr 8
09:36:35 2016) [[sssd[krb5_child[17431]]]] [sss_child_krb5_trace_cb] (0x4000): [17431]
1460072195.583749: Received answer from dgram 10.221.74.11:88 (Fri Apr 8 09:36:35 2016)
[[sssd[krb5_child[17431]]]] [sss_child_krb5_trace_cb] (0x4000): [17431] 1460072195.586942:
Response was from master KDC (Fri Apr 8 09:36:35 2016) [[sssd[krb5_child[17431]]]]
[sss_child_krb5_trace_cb] (0x4000): [17431] 1460072195.587015: Received error from KDC:
-1765328359/Additional pre-authentication required (Fri Apr 8 09:36:35 2016)
[[sssd[krb5_child[17431]]]] [sss_child_krb5_trace_cb] (0x4000): [17431] 1460072195.587091:
Processing preauth types: 16, 15, 19, 2 (Fri Apr 8 09:36:35 2016)
[[sssd[krb5_child[17431]]]] [sss_child_krb5_trace_cb] (0x4000): [17431] 1460072195.587148:
Selected etype info: etype aes256-cts, salt
"domain.subdomain.comFirstname.Lastname", params ""
(Fri Apr 8 09:36:35 2016) [[sssd[krb5_child[17431]]]] [sss_child_krb5_trace_cb] (0x4000):
[17431] 1460072195.595249: AS key obtained for encrypted timestamp: aes256-cts/3F75 (Fri
Apr 8 09:36:35 2016) [[sssd[krb5_child[17431]]]] [sss_child_krb5_trace_cb] (0x4000):
[17431] 1460072195.595342: Encrypted timestamp (for 1460072195.595307): plain
301AA011180F32303136303430373233333633355A
A105020309156B, encrypted
CD8D6091D7AAFBD97B420B58CB3AECA637D42FD03AA8F715BCF4257CBE0C8FCC66DD96041263B421DE4E4024513C7263B1D3D91BF4D1FA18
(Fri Apr 8 09:36:35 2016) [[sssd[krb5_child[17431]]]] [sss_child_krb5_trace_cb] (0x4000):
[17431] 1460072195.595397: Preauth module encrypted_timestamp (2) (flags=1) returned:
0/Success (Fri Apr 8 09:36:35 2016) [[sssd[krb5_child[17431]]]] [sss_child_krb5_trace_cb]
(0x4000): [17431] 1460072195.595457: Produced preauth for next request: 2 (Fri Apr 8
09:36:35 2016) [[sssd[krb5_child[17431]]]] [sss_child_krb5_trace_cb] (0x4000): [17431]
1460072195.595517: Sending request (346 bytes) to
domain.subdomain.com (Fri Apr 8
09:36:35 2016) [[sssd[krb5_child[17431]]]] [sss_child_krb5_trace_cb] (0x4000): [17431]
1460072195.598683: Sending initial UDP request to dgram 10.221.74.11:88 (Fri Apr 8
09:36:35 2016) [[sssd[krb5_child[17431]]]] [sss_child_krb5_trace_cb] (0x4000): [17431]
1460072195.615505: Received answer from dgram 10.221.74.11:88 (Fri Apr 8 09:36:35 2016)
[[sssd[krb5_child[17431]]]] [sss_child_krb5_trace_cb] (0x4000): [17431] 1460072195.619074:
Response was from master KDC (Fri Apr 8 09:36:35 2016) [[sssd[krb5_child[17431]]]]
[sss_child_krb5_trace_cb] (0x4000): [17431] 1460072195.619139: Received error from KDC:
-1765328360/Preauthentication failed (Fri Apr 8 09:36:35 2016)
[[sssd[krb5_child[17431]]]] [sss_child_krb5_trace_cb] (0x4000): [17431] 1460072195.619205:
Preauth tryagain input types: 16, 15, 19, 2 (Fri Apr 8 09:36:35 2016)
[[sssd[krb5_child[17431]]]] [get_and_save_tgt] (0x0020): 1000:
[-1765328360][Preauthentication failed] (Fri Apr 8 09:36:35 2016)
[[sssd[krb5_child[17431]]]] [map_krb5_error] (0x0020): 1069:
[-1765328360][Preauthentication failed] (Fri Apr 8 09:36:35 2016)
[[sssd[krb5_child[17431]]]] [k5c_send_data] (0x0200): Received error code 1432158215
As far as I know, libkrb5 reports "preauthentication failed" in case of a wrong
password. Can you please check if that could be the case? Also, is SSSD talking to the
right DC and not some other?
If there is another login failure I should look at, please point me to the right
timestamp, but in the logs, I only see these "Preauthentication failed"
messages.
_______________________________________________
sssd-users mailing list
sssd-users(a)lists.fedorahosted.org
https://lists.fedorahosted.org/admin/lists/sssd-users@lists.fedorahosted.org