Robert Moulton wrote on 8/12/16 12:14 PM:
Jakub Hrozek wrote on 8/12/16 12:59 AM:
> On Thu, Aug 11, 2016 at 03:08:35PM -0700, Robert Moulton wrote:
>> On a CentOS 6 system we recently implemented sssd auth against an AD
>> domain
>> (Samba 4 AD, specifically). The system messages log often shows
>> flurries of
>> these GSSAPI errors:
>>
>> sssd[be[notarealdomain.com]]: GSSAPI Error: Invalid token was supplied
>> (Token header is malformed or corrupt)
Scanning system logs, I noticed that along with thes GSSAPI error
messages, an error of this form occasionally shows up:
sssd_be: encoded packet size too big (-1344597784 > 16777215)
Unlike the GSSAPI errors which tend to repeat for extended length of
time, this one is typically just logged a single time per "incident",
and evidently immediately preceding (or at least coinciding with) the
GSSAPI errors.
>> I'm sorry, I've never seen this error. But what you can do is to kinit
>> with the keytab using KRB5_TRACE=/dev/stderr and then search the AD
>> DC/Samba DC with -Y GSSAPI (again prepending KRB5_TRACE=/dev/stderr) and
>> see if more helpful errors appear.
>
> Thanks for the suggestion Jakub. I tried that. A preauth error was
> reported, along with a response-size error, but no corresponding sssd
> messages showed up in the system log. Are those errors or anything else
> in the output possibly meaningful in this case? The output:
>
> $ KRB5_TRACE=/dev/stderr kinit
> [14527] 1471027291.50378: Getting initial credentials for
> rmoulton(a)NOTAREALDOMAIN.COM
> [14527] 1471027291.58578: Sending request (222 bytes) to
NOTAREALDOMAIN.COM
> [14527] 1471027291.58857: Sending initial UDP request to dgram
> 10.95.160.78:88
> [14527] 1471027291.66763: Received answer from dgram 10.95.160.78:88
> [14527] 1471027291.66834: Response was from master KDC
> [14527] 1471027291.66865: Received error from KDC:
> -1765328359/Additional pre-authentication required
> [14527] 1471027291.66915: Processing preauth types: 16, 15, 2, 11, 19
> [14527] 1471027291.66933: Selected etype info: etype rc4-hmac, salt
> "(null)", params ""
> [14527] 1471027291.66945: Selected etype info: etype rc4-hmac, salt
> "(null)", params ""
> Password for rmoulton(a)NOTAREALDOMAIN.COM:
> [14527] 1471027295.243102: AS key obtained for encrypted timestamp:
> rc4-hmac/60BE
> [14527] 1471027295.243177: Encrypted timestamp (for 1471027295.243112):
> plain 301AA011180F32303136303831323138343133355AA105020303B5A8,
> encrypted
>
E7B719EF8E1A52A5A81C6FF11CB6298FD2F8560A54DD6AE9E25B324541A1F6E4B310EE5EFA20A91C15BA15EB2D71D15BA0E48E9C
>
> [14527] 1471027295.243204: Preauth module encrypted_timestamp (2)
> (flags=1) returned: 0/Success
> [14527] 1471027295.243212: Produced preauth for next request: 2
> [14527] 1471027295.243239: Sending request (298 bytes) to
>
NOTAREALDOMAIN.COM
> [14527] 1471027295.243339: Sending initial UDP request to dgram
> 10.95.160.78:88
> [14527] 1471027295.270030: Received answer from dgram 10.95.160.78:88
> [14527] 1471027295.270104: Response was from master KDC
> [14527] 1471027295.270127: Received error from KDC: -1765328332/Response
> too big for UDP, retry with TCP
> [14527] 1471027295.270136: Request or response is too big for UDP;
> retrying with TCP
> [14527] 1471027295.270142: Sending request (298 bytes) to
>
NOTAREALDOMAIN.COM (tcp only)
> [14527] 1471027295.270204: Initiating TCP connection to stream
> 10.95.160.78:88
> [14527] 1471027295.270573: Sending TCP request to stream 10.95.160.78:88
> [14527] 1471027295.293462: Received answer from stream 10.95.160.78:88
> [14527] 1471027295.293562: Response was from master KDC
> [14527] 1471027295.293598: Salt derived from principal:
> NOTAREALDOMAIN.COMrmoulton
> [14527] 1471027295.293615: AS key determined by preauth: rc4-hmac/60BE
> [14527] 1471027295.293667: Decrypted AS reply; session key is:
> rc4-hmac/319D
> [14527] 1471027295.293673: FAST negotiation: unavailable
> [14527] 1471027295.293716: Initializing FILE:/tmp/krb5cc_1331_LQ9X0S
> with default princ rmoulton(a)NOTAREALDOMAIN.COM
> [14527] 1471027295.294014: Removing rmoulton(a)NOTAREALDOMAIN.COM ->
> krbtgt/NOTAREALDOMAIN.COM(a)NOTAREALDOMAIN.COM from
> FILE:/tmp/krb5cc_1331_LQ9X0S
> [14527] 1471027295.294029: Storing rmoulton(a)NOTAREALDOMAIN.COM ->
> krbtgt/NOTAREALDOMAIN.COM(a)NOTAREALDOMAIN.COM in
> FILE:/tmp/krb5cc_1331_LQ9X0S
>
> bash-4.1$ KRB5_TRACE=/dev/stderr ldapsearch -H ldap://porter -Y GSSAPI
> -b dc=notarealdomain,dc=com cn=rmoulton
> SASL/GSSAPI authentication started
> [16471] 1471027634.101272: ccselect module realm chose cache
> FILE:/tmp/krb5cc_1331_LQ9X0S with client principal
> rmoulton(a)NOTAREALDOMAIN.COM for server principal
> ldap/porter.notarealdomain.com(a)NOTAREALDOMAIN.COM
> [16471] 1471027634.101357: Retrieving rmoulton(a)NOTAREALDOMAIN.COM ->
> krb5_ccache_conf_data/proxy_impersonator@X-CACHECONF: from
> FILE:/tmp/krb5cc_1331_LQ9X0S with result: -1765328243/Matching
> credential not found
> [16471] 1471027634.101386: Getting credentials
> rmoulton(a)NOTAREALDOMAIN.COM ->
> ldap/porter.notarealdomain.com(a)NOTAREALDOMAIN.COM using ccache
> FILE:/tmp/krb5cc_1331_LQ9X0S
> [16471] 1471027634.101439: Retrieving rmoulton(a)NOTAREALDOMAIN.COM ->
> ldap/porter.notarealdomain.com(a)NOTAREALDOMAIN.COM from
> FILE:/tmp/krb5cc_1331_LQ9X0S with result: -1765328243/Matching
> credential not found
> [16471] 1471027634.101477: Retrieving rmoulton(a)NOTAREALDOMAIN.COM ->
> krbtgt/NOTAREALDOMAIN.COM(a)NOTAREALDOMAIN.COM from
> FILE:/tmp/krb5cc_1331_LQ9X0S with result: 0/Success
> [16471] 1471027634.101487: Found cached TGT for service realm:
> rmoulton(a)NOTAREALDOMAIN.COM -> krbtgt/NOTAREALDOMAIN.COM(a)NOTAREALDOMAIN.COM
> [16471] 1471027634.101496: Requesting tickets for
> ldap/porter.notarealdomain.com(a)NOTAREALDOMAIN.COM, referrals on
> [16471] 1471027634.101543: Generated subkey for TGS request: rc4-hmac/BA52
> [16471] 1471027634.101555: etypes requested in TGS request: aes256-cts,
> aes128-cts, des3-cbc-sha1, rc4-hmac
> [16471] 1471027634.101747: Sending request (1705 bytes) to
>
NOTAREALDOMAIN.COM
> [16471] 1471027634.102072: Initiating TCP connection to stream
> 10.95.160.78:88
> [16471] 1471027634.102417: Sending TCP request to stream 10.95.160.78:88
> [16471] 1471027634.119567: Received answer from stream 10.95.160.78:88
> [16471] 1471027634.119663: Response was from master KDC
> [16471] 1471027634.119726: TGS reply is for rmoulton(a)NOTAREALDOMAIN.COM
> -> ldap/porter.notarealdomain.com(a)NOTAREALDOMAIN.COM with session key
> rc4-hmac/6537
> [16471] 1471027634.119772: TGS request result: 0/Success
> [16471] 1471027634.119778: Received creds for desired service
> ldap/porter.notarealdomain.com(a)NOTAREALDOMAIN.COM
> [16471] 1471027634.119785: Removing rmoulton(a)NOTAREALDOMAIN.COM ->
> ldap/porter.notarealdomain.com(a)NOTAREALDOMAIN.COM from
> FILE:/tmp/krb5cc_1331_LQ9X0S
> [16471] 1471027634.119791: Storing rmoulton(a)NOTAREALDOMAIN.COM ->
> ldap/porter.notarealdomain.com(a)NOTAREALDOMAIN.COM in
> FILE:/tmp/krb5cc_1331_LQ9X0S
> [16471] 1471027634.119921: Creating authenticator for
> rmoulton(a)NOTAREALDOMAIN.COM ->
> ldap/porter.notarealdomain.com(a)NOTAREALDOMAIN.COM, seqnum 706553382,
> subkey rc4-hmac/57FE, session key rc4-hmac/6537
> [16471] 1471027634.119930: Negotiating for enctypes in authenticator:
> aes256-cts, aes128-cts, des3-cbc-sha1, rc4-hmac
> [16471] 1471027634.123899: ccselect module realm chose cache
> FILE:/tmp/krb5cc_1331_LQ9X0S with client principal
> rmoulton(a)NOTAREALDOMAIN.COM for server principal
> ldap/porter.notarealdomain.com(a)NOTAREALDOMAIN.COM
> [16471] 1471027634.123961: Retrieving rmoulton(a)NOTAREALDOMAIN.COM ->
> krb5_ccache_conf_data/proxy_impersonator@X-CACHECONF: from
> FILE:/tmp/krb5cc_1331_LQ9X0S with result: -1765328243/Matching
> credential not found
> [16471] 1471027634.124034: Read AP-REP, time 1471027638.119937, subkey
> aes256-cts/02E0, seqnum 255305194
> SASL username: rmoulton(a)NOTAREALDOMAIN.COM
> SASL SSF: 56
> SASL data security layer installed.
> # extended LDIF
> #
> # LDAPv3
> # base <dc=notarealdomain,dc=com> with scope subtree
> # filter: cn=rmoulton
> # requesting: ALL
> #
>
> # rmoulton, Users,
notarealdomain.com
> dn: CN=rmoulton,CN=Users,DC=notarealdomain,DC=com
> objectClass: top
> objectClass: posixAccount
> objectClass: person
> objectClass: organizationalPerson
> objectClass: user
> cn: rmoulton
> sn: Moulton
>
> < remaining output snipped >
>
>>>
>>> Any idea what might be wrong? Troubleshooting tips? (We don't have much
>>> experience with sssd, admittedly.)
>>>
>>> When the flurries happen, system load increases markedly, and we suspect
>>> that a recent system crash was related.
>>>
>>> Our sssd.conf:
>>>
>>> ----------
>>> [sssd]
>>> services = nss, pam
>>> config_file_version = 2
>>> domains =
notarealdomain.com
>>> [nss]
>>> [pam]
>>> [
domain/notarealdomain.com]
>>> id_provider = ad
>>> access_provider = ad
>>> ldap_id_mapping=false
>>> krb5_keytab=/etc/krb5.sssd.keytab
>>> ----------
>>>
>>> thanks in advance,
>>> -r
>>> _______________________________________________
>>> sssd-users mailing list
>>> sssd-users(a)lists.fedorahosted.org
>>>
https://lists.fedorahosted.org/admin/lists/sssd-users@lists.fedorahosted.org
>>>
>> _______________________________________________
>> sssd-users mailing list
>> sssd-users(a)lists.fedorahosted.org
>>
https://lists.fedorahosted.org/admin/lists/sssd-users@lists.fedorahosted.org
>>
>>