Attachment 1970874 Details for Bug 2214399 – KRB5_TRACE log of a successful lookup [mildly redacted]

KRB5_TRACE log of a successful lookup [mildly redacted]

krb5-success-log.txt (text/plain), 15.08 KB, created by Ian Collier on 2023-06-14 16:42:40 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Ian Collier

Created: 2023-06-14 16:42:40 UTC

Size: 15.08 KB

patch

obsolete

>[292391] 1686755514.828414: TXT record _kerberos.ipaserver2. not found
>[292391] 1686755514.828415: TXT record _kerberos.mydomain. found: MYREALM
>[292391] 1686755514.828416: ccselect module realm chose cache MEMORY:_autofstkt with client principal host/myhost@MYREALM for server principal ldap/ipaserver2@MYREALM
>[292391] 1686755514.828417: Storing config in MEMORY:_autofstkt for : refresh_time: 1686755544
>[292391] 1686755514.828418: Storing host/myhost@MYREALM -> krb5_ccache_conf_data/refresh_time@X-CACHECONF: in MEMORY:_autofstkt
>[292391] 1686755514.828419: Getting initial credentials for host/myhost@MYREALM
>[292391] 1686755514.828420: Couldn't lookup etypes in keytab: 2/Key table file '/var/kerberos/krb5/user/0/client.keytab' not found
>[292391] 1686755514.828422: Sending unauthenticated request
>[292391] 1686755514.828423: Sending request (222 bytes) to MYREALM
>[292391] 1686755514.828424: Sending initial UDP request to dgram ipaserver1:88
>[292391] 1686755514.828425: Received answer (532 bytes) from dgram ipaserver1:88
>[292391] 1686755514.828426: Response was from primary KDC
>[292391] 1686755514.828427: Received error from KDC: -1765328359/Additional pre-authentication required
>[292391] 1686755514.828430: Preauthenticating using KDC method data
>[292391] 1686755514.828431: Processing preauth types: PA-PK-AS-REQ (16), PA-FX-FAST (136), PA-ETYPE-INFO2 (19), PA-PKINIT-KX (147), PA-SPAKE (151), PA-ENC-TIMESTAMP (2), PA_AS_FRESHNESS (150), PA-FX-COOKIE (133)
>[292391] 1686755514.828432: Selected etype info: etype aes256-cts, salt "lKh51H1tY9P[CO^S", params ""
>[292391] 1686755514.828433: Received cookie: MIT1...
>[292391] 1686755514.828434: PKINIT client has no configured identity; giving up
>[292391] 1686755514.828435: Preauth module pkinit (147) (info) returned: 0/Success
>[292391] 1686755514.828436: PKINIT client received freshness token from KDC
>[292391] 1686755514.828437: Preauth module pkinit (150) (info) returned: 0/Success
>[292391] 1686755514.828438: PKINIT client has no configured identity; giving up
>[292391] 1686755514.828439: Preauth module pkinit (16) (real) returned: 22/Invalid argument
>[292391] 1686755514.828440: SPAKE challenge received with group 1, pubkey HEXDIGITS
>[292391] 1686755514.828441: Retrieving host/myhost@MYREALM from FILE:/var/kerberos/krb5/user/0/client.keytab (vno 0, enctype aes256-cts) with result: 2/Key table file '/var/kerberos/krb5/user/0/client.keytab' not found
>[292391] 1686755514.828442: Preauth module spake (151) (real) returned: 2/Key table file '/var/kerberos/krb5/user/0/client.keytab' not found
>[292391] 1686755514.828443: Retrieving host/myhost@MYREALM from FILE:/var/kerberos/krb5/user/0/client.keytab (vno 0, enctype aes256-cts) with result: 2/Key table file '/var/kerberos/krb5/user/0/client.keytab' not found
>[292391] 1686755514.828444: Preauth module encrypted_timestamp (2) (real) returned: 2/Key table file '/var/kerberos/krb5/user/0/client.keytab' not found
>[292391] 1686755514.828445: Getting credentials host/myhost@MYREALM -> ldap/ipaserver2@ using ccache MEMORY:_autofstkt
>[292391] 1686755514.828446: Retrieving host/myhost@MYREALM -> krb5_ccache_conf_data/start_realm@X-CACHECONF: from MEMORY:_autofstkt with result: -1765328243/Matching credential not found
>[292391] 1686755514.828447: Retrieving host/myhost@MYREALM -> ldap/ipaserver2@ from MEMORY:_autofstkt with result: -1765328243/Matching credential not found
>[292391] 1686755514.828448: Retrying host/myhost@MYREALM -> ldap/ipaserver2@MYREALM with result: -1765328243/Matching credential not found
>[292391] 1686755514.828449: Retrieving host/myhost@MYREALM -> krbtgt/MYREALM@MYREALM from MEMORY:_autofstkt with result: 0/Success
>[292391] 1686755514.828460: TXT record _kerberos.ipaserver1. not found
>[292391] 1686755514.828461: TXT record _kerberos.mydomain. found: MYREALM
>[292391] 1686755514.828462: ccselect module realm chose cache MEMORY:_autofstkt with client principal host/myhost@MYREALM for server principal ldap/ipaserver1@MYREALM
>[292391] 1686755514.828463: Storing config in MEMORY:_autofstkt for : refresh_time: 1686755544
>[292391] 1686755514.828464: Storing host/myhost@MYREALM -> krb5_ccache_conf_data/refresh_time@X-CACHECONF: in MEMORY:_autofstkt
>[292391] 1686755514.828465: Getting initial credentials for host/myhost@MYREALM
>[292391] 1686755514.828466: Couldn't lookup etypes in keytab: 2/Key table file '/var/kerberos/krb5/user/0/client.keytab' not found
>[292391] 1686755514.828468: Sending unauthenticated request
>[292391] 1686755514.828469: Sending request (222 bytes) to MYREALM
>[292391] 1686755514.828470: Sending initial UDP request to dgram ipaserver1:88
>[292391] 1686755514.828471: Received answer (532 bytes) from dgram ipaserver1:88
>[292391] 1686755514.828472: Response was from primary KDC
>[292391] 1686755514.828473: Received error from KDC: -1765328359/Additional pre-authentication required
>[292391] 1686755514.828476: Preauthenticating using KDC method data
>[292391] 1686755514.828477: Processing preauth types: PA-PK-AS-REQ (16), PA-FX-FAST (136), PA-ETYPE-INFO2 (19), PA-PKINIT-KX (147), PA-SPAKE (151), PA-ENC-TIMESTAMP (2), PA_AS_FRESHNESS (150), PA-FX-COOKIE (133)
>[292391] 1686755514.828478: Selected etype info: etype aes256-cts, salt "lKh51H1tY9P[CO^S", params ""
>[292391] 1686755514.828479: Received cookie: MIT1...
>[292391] 1686755514.828480: PKINIT client has no configured identity; giving up
>[292391] 1686755514.828481: Preauth module pkinit (147) (info) returned: 0/Success
>[292391] 1686755514.828482: PKINIT client received freshness token from KDC
>[292391] 1686755514.828483: Preauth module pkinit (150) (info) returned: 0/Success
>[292391] 1686755514.828484: PKINIT client has no configured identity; giving up
>[292391] 1686755514.828485: Preauth module pkinit (16) (real) returned: 22/Invalid argument
>[292391] 1686755514.828486: SPAKE challenge received with group 1, pubkey HEXDIGITS
>[292391] 1686755514.828487: Retrieving host/myhost@MYREALM from FILE:/var/kerberos/krb5/user/0/client.keytab (vno 0, enctype aes256-cts) with result: 2/Key table file '/var/kerberos/krb5/user/0/client.keytab' not found
>[292391] 1686755514.828488: Preauth module spake (151) (real) returned: 2/Key table file '/var/kerberos/krb5/user/0/client.keytab' not found
>[292391] 1686755514.828489: Retrieving host/myhost@MYREALM from FILE:/var/kerberos/krb5/user/0/client.keytab (vno 0, enctype aes256-cts) with result: 2/Key table file '/var/kerberos/krb5/user/0/client.keytab' not found
>[292391] 1686755514.828490: Preauth module encrypted_timestamp (2) (real) returned: 2/Key table file '/var/kerberos/krb5/user/0/client.keytab' not found
>[292391] 1686755514.828491: Getting credentials host/myhost@MYREALM -> ldap/ipaserver1@ using ccache MEMORY:_autofstkt
>[292391] 1686755514.828492: Retrieving host/myhost@MYREALM -> krb5_ccache_conf_data/start_realm@X-CACHECONF: from MEMORY:_autofstkt with result: -1765328243/Matching credential not found
>[292391] 1686755514.828493: Retrieving host/myhost@MYREALM -> ldap/ipaserver1@ from MEMORY:_autofstkt with result: -1765328243/Matching credential not found
>[292391] 1686755514.828494: Retrying host/myhost@MYREALM -> ldap/ipaserver1@MYREALM with result: -1765328243/Matching credential not found
>[292391] 1686755514.828495: Retrieving host/myhost@MYREALM -> krbtgt/MYREALM@MYREALM from MEMORY:_autofstkt with result: 0/Success
>[292391] 1686755514.828501: Getting initial credentials for host/myhost@MYREALM
>[292391] 1686755514.828502: Setting initial creds service to krbtgt/MYREALM@MYREALM
>[292391] 1686755514.828503: Found entries for host/myhost@MYREALM in keytab: aes256-cts, aes128-cts
>[292391] 1686755514.828505: Sending unauthenticated request
>[292391] 1686755514.828506: Sending request (222 bytes) to MYREALM
>[292391] 1686755514.828507: Sending initial UDP request to dgram ipaserver1:88
>[292391] 1686755514.828508: Received answer (532 bytes) from dgram ipaserver1:88
>[292391] 1686755514.828509: Response was from primary KDC
>[292391] 1686755514.828510: Received error from KDC: -1765328359/Additional pre-authentication required
>[292391] 1686755514.828513: Preauthenticating using KDC method data
>[292391] 1686755514.828514: Processing preauth types: PA-PK-AS-REQ (16), PA-FX-FAST (136), PA-ETYPE-INFO2 (19), PA-PKINIT-KX (147), PA-SPAKE (151), PA-ENC-TIMESTAMP (2), PA_AS_FRESHNESS (150), PA-FX-COOKIE (133)
>[292391] 1686755514.828515: Selected etype info: etype aes256-cts, salt "lKh51H1tY9P[CO^S", params ""
>[292391] 1686755514.828516: Received cookie: MIT1...
>[292391] 1686755514.828517: PKINIT client has no configured identity; giving up
>[292391] 1686755514.828518: Preauth module pkinit (147) (info) returned: 0/Success
>[292391] 1686755514.828519: PKINIT client received freshness token from KDC
>[292391] 1686755514.828520: Preauth module pkinit (150) (info) returned: 0/Success
>[292391] 1686755514.828521: PKINIT client has no configured identity; giving up
>[292391] 1686755514.828522: Preauth module pkinit (16) (real) returned: 22/Invalid argument
>[292391] 1686755514.828523: SPAKE challenge received with group 1, pubkey HEXDIGITS
>[292391] 1686755514.828524: Retrieving host/myhost@MYREALM from FILE:/etc/krb5.keytab (vno 0, enctype aes256-cts) with result: 0/Success
>[292391] 1686755514.828525: SPAKE key generated with pubkey HEXDIGITS
>[292391] 1686755514.828526: SPAKE algorithm result: HEXDIGITS
>[292391] 1686755514.828527: SPAKE final transcript hash: HEXDIGITS
>[292391] 1686755514.828528: Sending SPAKE response
>[292391] 1686755514.828529: Preauth module spake (151) (real) returned: 0/Success
>[292391] 1686755514.828530: Produced preauth for next request: PA-FX-COOKIE (133), PA-SPAKE (151)
>[292391] 1686755514.828531: Sending request (481 bytes) to MYREALM
>[292391] 1686755514.828532: Sending initial UDP request to dgram ipaserver1:88
>[292391] 1686755514.828533: Received answer (885 bytes) from dgram ipaserver1:88
>[292391] 1686755514.828534: Response was from primary KDC
>[292391] 1686755514.828535: AS key determined by preauth: aes256-cts/E9C3
>[292391] 1686755514.828536: Decrypted AS reply; session key is: aes256-cts/5A8D
>[292391] 1686755514.828537: FAST negotiation: available
>[292391] 1686755514.828538: Storing host/myhost@MYREALM -> krbtgt/MYREALM@MYREALM in MEMORY:_autofstkt
>[292391] 1686755514.828545: TXT record _kerberos.ipaserver1. not found
>[292391] 1686755514.828546: TXT record _kerberos.mydomain. found: MYREALM
>[292391] 1686755514.828547: ccselect module realm chose cache MEMORY:_autofstkt with client principal host/myhost@MYREALM for server principal ldap/ipaserver1@MYREALM
>[292391] 1686755514.828548: Storing config in MEMORY:_autofstkt for : refresh_time: 1686755544
>[292391] 1686755514.828549: Storing host/myhost@MYREALM -> krb5_ccache_conf_data/refresh_time@X-CACHECONF: in MEMORY:_autofstkt
>[292391] 1686755514.828550: Getting initial credentials for host/myhost@MYREALM
>[292391] 1686755514.828551: Couldn't lookup etypes in keytab: 2/Key table file '/var/kerberos/krb5/user/0/client.keytab' not found
>[292391] 1686755514.828553: Sending unauthenticated request
>[292391] 1686755514.828554: Sending request (222 bytes) to MYREALM
>[292391] 1686755514.828555: Sending initial UDP request to dgram ipaserver1:88
>[292391] 1686755514.828556: Received answer (532 bytes) from dgram ipaserver1:88
>[292391] 1686755514.828557: Response was from primary KDC
>[292391] 1686755514.828558: Received error from KDC: -1765328359/Additional pre-authentication required
>[292391] 1686755514.828561: Preauthenticating using KDC method data
>[292391] 1686755514.828562: Processing preauth types: PA-PK-AS-REQ (16), PA-FX-FAST (136), PA-ETYPE-INFO2 (19), PA-PKINIT-KX (147), PA-SPAKE (151), PA-ENC-TIMESTAMP (2), PA_AS_FRESHNESS (150), PA-FX-COOKIE (133)
>[292391] 1686755514.828563: Selected etype info: etype aes256-cts, salt "lKh51H1tY9P[CO^S", params ""
>[292391] 1686755514.828564: Received cookie: MIT1...
>[292391] 1686755514.828565: PKINIT client has no configured identity; giving up
>[292391] 1686755514.828566: Preauth module pkinit (147) (info) returned: 0/Success
>[292391] 1686755514.828567: PKINIT client received freshness token from KDC
>[292391] 1686755514.828568: Preauth module pkinit (150) (info) returned: 0/Success
>[292391] 1686755514.828569: PKINIT client has no configured identity; giving up
>[292391] 1686755514.828570: Preauth module pkinit (16) (real) returned: 22/Invalid argument
>[292391] 1686755514.828571: SPAKE challenge received with group 1, pubkey HEXDIGITS
>[292391] 1686755514.828572: Retrieving host/myhost@MYREALM from FILE:/var/kerberos/krb5/user/0/client.keytab (vno 0, enctype aes256-cts) with result: 2/Key table file '/var/kerberos/krb5/user/0/client.keytab' not found
>[292391] 1686755514.828573: Preauth module spake (151) (real) returned: 2/Key table file '/var/kerberos/krb5/user/0/client.keytab' not found
>[292391] 1686755514.828574: Retrieving host/myhost@MYREALM from FILE:/var/kerberos/krb5/user/0/client.keytab (vno 0, enctype aes256-cts) with result: 2/Key table file '/var/kerberos/krb5/user/0/client.keytab' not found
>[292391] 1686755514.828575: Preauth module encrypted_timestamp (2) (real) returned: 2/Key table file '/var/kerberos/krb5/user/0/client.keytab' not found
>[292391] 1686755514.828576: Getting credentials host/myhost@MYREALM -> ldap/ipaserver1@ using ccache MEMORY:_autofstkt
>[292391] 1686755514.828577: Retrieving host/myhost@MYREALM -> krb5_ccache_conf_data/start_realm@X-CACHECONF: from MEMORY:_autofstkt with result: -1765328243/Matching credential not found
>[292391] 1686755514.828578: Retrieving host/myhost@MYREALM -> ldap/ipaserver1@ from MEMORY:_autofstkt with result: -1765328243/Matching credential not found
>[292391] 1686755514.828579: Retrying host/myhost@MYREALM -> ldap/ipaserver1@MYREALM with result: -1765328243/Matching credential not found
>[292391] 1686755514.828580: Retrieving host/myhost@MYREALM -> krbtgt/MYREALM@MYREALM from MEMORY:_autofstkt with result: 0/Success
>[292391] 1686755514.828581: Starting with TGT for client realm: host/myhost@MYREALM -> krbtgt/MYREALM@MYREALM
>[292391] 1686755514.828582: Requesting tickets for ldap/ipaserver1@MYREALM, referrals on
>[292391] 1686755514.828583: Generated subkey for TGS request: aes256-cts/E43F
>[292391] 1686755514.828584: etypes requested in TGS request: aes256-cts, aes256-sha2, camellia256-cts, aes128-sha2, aes128-cts, camellia128-cts
>[292391] 1686755514.828586: Encoding request body and padata into FAST request
>[292391] 1686755514.828587: Sending request (1132 bytes) to MYREALM
>[292391] 1686755514.828588: Sending initial UDP request to dgram ipaserver1:88
>[292391] 1686755514.828589: Received answer (1086 bytes) from dgram ipaserver1:88
>[292391] 1686755514.828590: Response was from primary KDC
>[292391] 1686755514.828591: Decoding FAST response
>[292391] 1686755514.828592: FAST reply key: aes256-cts/2B3F
>[292391] 1686755514.828593: TGS reply is for host/myhost@MYREALM -> ldap/ipaserver1@MYREALM with session key aes256-cts/2B56
>[292391] 1686755514.828594: TGS request result: 0/Success
>[292391] 1686755514.828595: Received creds for desired service ldap/ipaserver1@MYREALM
>[292391] 1686755514.828596: Storing host/myhost@MYREALM -> ldap/ipaserver1@ in MEMORY:_autofstkt
>[292391] 1686755514.828598: Creating authenticator for host/myhost@MYREALM -> ldap/ipaserver1@, seqnum 552967253, subkey aes256-cts/5735, session key aes256-cts/2B56
>[292391] 1686755514.828607: Read AP-REP, time 1686755514.828599, subkey aes256-cts/7F0A, seqnum 373240526

Actions: View

Attachments on bug 2214399: 1970873 | 1970874 | 1973430