> On 20 Sep 2018, at 06:47, Alexander Bokovoy <aboko...@redhat.com> wrote:
> 
> On ke, 19 syys 2018, Björn Persson wrote:
>> Alexander Bokovoy wrote:
>>> Can you provide output from
>>> 
>>> export KRB5_TRACE=/dev/stderr
>>> klist -A
>>> kinit
>>> fedpkg build
>>> 
>>> ?
>> 
>> The log is attached. I tried it twice as Tony Nelson suggested. The
>> first attempt failed as usual, but the second attempt was successful.
>> 
>> Björn Persson
> 
>> [beorn@tag gnat-srpm-macros]$ export KRB5_TRACE=/dev/stderr
>> [beorn@tag gnat-srpm-macros]$ klist -A
>> Ticket cache: KCM:1000
>> Default principal: rombobe...@fedoraproject.org
>> 
>> Valid starting       Expires              Service principal
>> 2018-09-17 05:24:43  2018-09-18 05:24:35  
>> krbtgt/fedoraproject....@fedoraproject.org
>>      renew until 2018-09-24 05:24:35
>> 2018-09-17 05:27:25  2018-09-18 05:24:35  
>> HTTP/koji.fedoraproject....@fedoraproject.org
>>      renew until 2018-09-24 05:24:35
>> [beorn@tag gnat-srpm-macros]$ kinit rombobe...@fedoraproject.org
>> [14092] 1537389788.507256: Getting initial credentials for 
>> rombobe...@fedoraproject.org
>> [14092] 1537389788.507258: Sending request (207 bytes) to FEDORAPROJECT.ORG
>> [14092] 1537389788.507259: Resolving hostname id.fedoraproject.org
>> [14092] 1537389788.507260: TLS certificate name matched 
>> "id.fedoraproject.org"
>> [14092] 1537389789.71948: Sending HTTPS request to https 152.19.134.142:443
>> [14092] 1537389789.71949: Received answer (322 bytes) from https 
>> 152.19.134.142:443
>> [14092] 1537389789.71950: Terminating TCP connection to https 
>> 152.19.134.142:443
>> [14092] 1537389794.417687: Response was not from master KDC
>> [14092] 1537389794.417688: Received error from KDC: -1765328359/Additional 
>> pre-authentication required
>> [14092] 1537389794.417691: Processing preauth types: 16, 15, 14, 136, 19, 
>> 147, 2, 133
>> [14092] 1537389794.417692: Selected etype info: etype aes256-cts, salt 
>> "3'Ds5@-0:LIC'DI@", params ""
>> [14092] 1537389794.417693: Received cookie: MIT
>> Password for rombobe...@fedoraproject.org:
>> [14092] 1537389816.394788: AS key obtained for encrypted timestamp: 
>> aes256-cts/3ECA
>> [14092] 1537389816.394790: Encrypted timestamp (for 1537389811.329323): 
>> plain 301AA011180F32303138303931393230343333315AA105020305066B, encrypted 
>> 9D4E22D8C8E839FD08FDEF5513D8B3ECA58449937FAA393FC840524E9FBB4C5AAD7AAF5747A5F9B36B608199BB2A62A85BAED55317B1BA18
>> [14092] 1537389816.394791: Preauth module encrypted_timestamp (2) (real) 
>> returned: 0/Success
>> [14092] 1537389816.394792: Produced preauth for next request: 133, 2
>> [14092] 1537389816.394793: Sending request (302 bytes) to FEDORAPROJECT.ORG
>> [14092] 1537389816.394794: Resolving hostname id.fedoraproject.org
>> [14092] 1537389816.394795: TLS certificate name matched 
>> "id.fedoraproject.org"
>> [14092] 1537389817.98943: Sending HTTPS request to https 140.211.169.196:443
>> [14092] 1537389817.98944: Received answer (795 bytes) from https 
>> 140.211.169.196:443
>> [14092] 1537389817.98945: Terminating TCP connection to https 
>> 140.211.169.196:443
>> [14092] 1537389822.391083: Response was not from master KDC
>> [14092] 1537389822.391084: Processing preauth types: 19
>> [14092] 1537389822.391085: Selected etype info: etype aes256-cts, salt 
>> "3'Ds5@-0:LIC'DI@", params ""
>> [14092] 1537389822.391086: Produced preauth for next request: (empty)
>> [14092] 1537389822.391087: AS key determined by preauth: aes256-cts/3ECA
>> [14092] 1537389822.391088: Decrypted AS reply; session key is: 
>> aes256-cts/A5E2
>> [14092] 1537389822.391089: FAST negotiation: available
>> [14092] 1537389822.391090: Initializing KCM:1000 with default princ 
>> rombobe...@fedoraproject.org
>> [beorn@tag gnat-srpm-macros]$ echo $?
>> 141
> So there is something wrong happening right after starting to save the cred 
> into KCM credentials
> cache.
> 
> Jakub (in CC:), do you see any reason for this?

Not without logs. Please file a bug so that we can take a look.

It would be nice to:
 - edit /etc/sssd/sssd.conf
 - add:
   [kcm]
   debug_level = 10
 - systemctl restart sssd # to regenerate the configuration
 - systemctl restart sssd-kcm # restart the KCM deamon
- attach the logs at /var/log/sssd/*

> 
>> [beorn@tag gnat-srpm-macros]$ fedpkg build
>> [14333] 1537389921.736427: ccselect module realm chose cache KCM:1000 with 
>> client principal rombobe...@fedoraproject.org for server principal 
>> HTTP/koji.fedoraproject....@fedoraproject.org
>> [14333] 1537389921.736428: Getting credentials rombobe...@fedoraproject.org 
>> -> HTTP/koji.fedoraproject....@fedoraproject.org using ccache KCM:1000
>> [14333] 1537389921.736429: Retrieving rombobe...@fedoraproject.org -> 
>> HTTP/koji.fedoraproject....@fedoraproject.org from KCM:1000 with result: 
>> -1765328243/Matching credential not found
>> [14333] 1537389921.736430: Retrieving rombobe...@fedoraproject.org -> 
>> krbtgt/fedoraproject....@fedoraproject.org from KCM:1000 with result: 
>> 0/Success
>> [14333] 1537389921.736436: ccselect module realm chose cache KCM:1000 with 
>> client principal rombobe...@fedoraproject.org for server principal 
>> HTTP/koji.fedoraproject....@fedoraproject.org
>> [14333] 1537389921.736437: Getting credentials rombobe...@fedoraproject.org 
>> -> HTTP/koji.fedoraproject....@fedoraproject.org using ccache KCM:1000
>> [14333] 1537389921.736438: Retrieving rombobe...@fedoraproject.org -> 
>> HTTP/koji.fedoraproject....@fedoraproject.org from KCM:1000 with result: 
>> -1765328243/Matching credential not found
>> [14333] 1537389921.736439: Retrieving rombobe...@fedoraproject.org -> 
>> krbtgt/fedoraproject....@fedoraproject.org from KCM:1000 with result: 
>> 0/Success
>> [14333] 1537389921.736443: Getting credentials rombobe...@fedoraproject.org 
>> -> host/koji.fedoraproject....@fedoraproject.org using ccache KCM:1000
>> [14333] 1537389921.736444: Retrieving rombobe...@fedoraproject.org -> 
>> host/koji.fedoraproject....@fedoraproject.org from KCM:1000 with result: 
>> -1765328243/Matching credential not found
>> [14333] 1537389921.736445: Retrieving rombobe...@fedoraproject.org -> 
>> krbtgt/fedoraproject....@fedoraproject.org from KCM:1000 with result: 
>> 0/Success
>> Kerberos authentication fails: (-1765328352, 'Ticket expired')
>> Could not execute build: Could not login to 
>> https://koji.fedoraproject.org/kojihub
>> [beorn@tag gnat-srpm-macros]$ kinit rombobe...@fedoraproject.org
>> [14577] 1537390046.602684: Getting initial credentials for 
>> rombobe...@fedoraproject.org
>> [14577] 1537390046.602686: Sending request (207 bytes) to FEDORAPROJECT.ORG
>> [14577] 1537390046.602687: Resolving hostname id.fedoraproject.org
>> [14577] 1537390047.260926: TLS certificate name matched 
>> "id.fedoraproject.org"
>> [14577] 1537390047.260927: Sending HTTPS request to https 140.211.169.206:443
>> [14577] 1537390047.260928: Received answer (322 bytes) from https 
>> 140.211.169.206:443
>> [14577] 1537390047.260929: Terminating TCP connection to https 
>> 140.211.169.206:443
>> [14577] 1537390052.749341: Response was not from master KDC
>> [14577] 1537390052.749342: Received error from KDC: -1765328359/Additional 
>> pre-authentication required
>> [14577] 1537390052.749345: Processing preauth types: 16, 15, 14, 136, 19, 
>> 147, 2, 133
>> [14577] 1537390052.749346: Selected etype info: etype aes256-cts, salt 
>> "3'Ds5@-0:LIC'DI@", params ""
>> [14577] 1537390052.749347: Received cookie: MIT
>> Password for rombobe...@fedoraproject.org:
>> [14577] 1537390055.226653: AS key obtained for encrypted timestamp: 
>> aes256-cts/3ECA
>> [14577] 1537390055.226655: Encrypted timestamp (for 1537390050.175343): 
>> plain 301AA011180F32303138303931393230343733305AA105020302ACEF, encrypted 
>> 5C227C17080085735129429BE0AAE712824F9593C3B7A6EA2E21DCE153E59AD09557698A93DA5355F405E27CDCCACD2404EAA9F89D352C78
>> [14577] 1537390055.226656: Preauth module encrypted_timestamp (2) (real) 
>> returned: 0/Success
>> [14577] 1537390055.226657: Produced preauth for next request: 133, 2
>> [14577] 1537390055.226658: Sending request (302 bytes) to FEDORAPROJECT.ORG
>> [14577] 1537390055.226659: Resolving hostname id.fedoraproject.org
>> [14577] 1537390055.226660: TLS certificate name matched 
>> "id.fedoraproject.org"
>> [14577] 1537390055.226661: Sending HTTPS request to https 185.141.165.254:443
>> [14577] 1537390055.226662: Received answer (795 bytes) from https 
>> 185.141.165.254:443
>> [14577] 1537390055.226663: Terminating TCP connection to https 
>> 185.141.165.254:443
>> [14577] 1537390060.960472: Response was not from master KDC
>> [14577] 1537390060.960473: Processing preauth types: 19
>> [14577] 1537390060.960474: Selected etype info: etype aes256-cts, salt 
>> "3'Ds5@-0:LIC'DI@", params ""
>> [14577] 1537390060.960475: Produced preauth for next request: (empty)
>> [14577] 1537390060.960476: AS key determined by preauth: aes256-cts/3ECA
>> [14577] 1537390060.960477: Decrypted AS reply; session key is: 
>> aes256-cts/17FB
>> [14577] 1537390060.960478: FAST negotiation: available
>> [14577] 1537390060.960479: Initializing KCM:1000 with default princ 
>> rombobe...@fedoraproject.org
>> [14577] 1537390061.48793: Storing rombobe...@fedoraproject.org -> 
>> krbtgt/fedoraproject....@fedoraproject.org in KCM:1000
>> [14577] 1537390061.48794: Storing config in KCM:1000 for 
>> krbtgt/fedoraproject....@fedoraproject.org: fast_avail: yes
>> [14577] 1537390061.48795: Storing rombobe...@fedoraproject.org -> 
>> krb5_ccache_conf_data/fast_avail/krbtgt\/FEDORAPROJECT.ORG\@FEDORAPROJECT.ORG@X-CACHECONF:
>>  in KCM:1000
>> [14577] 1537390061.48796: Storing config in KCM:1000 for 
>> krbtgt/fedoraproject....@fedoraproject.org: pa_type: 2
>> [14577] 1537390061.48797: Storing rombobe...@fedoraproject.org -> 
>> krb5_ccache_conf_data/pa_type/krbtgt\/FEDORAPROJECT.ORG\@FEDORAPROJECT.ORG@X-CACHECONF:
>>  in KCM:1000
>> [beorn@tag gnat-srpm-macros]$ echo $?
>> 0
>> [beorn@tag gnat-srpm-macros]$ fedpkg build
>> [14673] 1537390098.518916: ccselect module realm chose cache KCM:1000 with 
>> client principal rombobe...@fedoraproject.org for server principal 
>> HTTP/koji.fedoraproject....@fedoraproject.org
>> [14673] 1537390098.518917: Getting credentials rombobe...@fedoraproject.org 
>> -> HTTP/koji.fedoraproject....@fedoraproject.org using ccache KCM:1000
>> [14673] 1537390098.518918: Retrieving rombobe...@fedoraproject.org -> 
>> HTTP/koji.fedoraproject....@fedoraproject.org from KCM:1000 with result: 
>> -1765328243/Matching credential not found
>> [14673] 1537390098.518919: Retrieving rombobe...@fedoraproject.org -> 
>> krbtgt/fedoraproject....@fedoraproject.org from KCM:1000 with result: 
>> 0/Success
>> [14673] 1537390098.518920: Starting with TGT for client realm: 
>> rombobe...@fedoraproject.org -> krbtgt/fedoraproject....@fedoraproject.org
>> [14673] 1537390098.518921: Requesting tickets for 
>> HTTP/koji.fedoraproject....@fedoraproject.org, referrals on
>> [14673] 1537390098.518922: Generated subkey for TGS request: aes256-cts/5A88
>> [14673] 1537390098.518923: etypes requested in TGS request: aes256-cts, 
>> aes128-cts, aes256-sha2, aes128-sha2, des3-cbc-sha1, rc4-hmac, 
>> camellia128-cts, camellia256-cts
>> [14673] 1537390098.518925: Encoding request body and padata into FAST request
>> [14673] 1537390098.518926: Sending request (1012 bytes) to FEDORAPROJECT.ORG
>> [14673] 1537390098.518927: Resolving hostname id.fedoraproject.org
>> [14673] 1537390099.70951: TLS certificate name matched "id.fedoraproject.org"
>> [14673] 1537390099.70952: Sending HTTPS request to https 140.211.169.196:443
>> [14673] 1537390099.70953: Received answer (975 bytes) from https 
>> 140.211.169.196:443
>> [14673] 1537390099.70954: Terminating TCP connection to https 
>> 140.211.169.196:443
>> [14673] 1537390104.638599: Response was not from master KDC
>> [14673] 1537390104.638600: Decoding FAST response
>> [14673] 1537390104.638601: FAST reply key: aes256-cts/7D56
>> [14673] 1537390104.638602: TGS reply is for rombobe...@fedoraproject.org -> 
>> HTTP/koji.fedoraproject....@fedoraproject.org with session key 
>> aes256-cts/ABBE
>> [14673] 1537390104.638603: TGS request result: 0/Success
>> [14673] 1537390104.638604: Received creds for desired service 
>> HTTP/koji.fedoraproject....@fedoraproject.org
>> [14673] 1537390104.638605: Storing rombobe...@fedoraproject.org -> 
>> HTTP/koji.fedoraproject....@fedoraproject.org in KCM:1000
>> [14673] 1537390104.638607: Creating authenticator for 
>> rombobe...@fedoraproject.org -> 
>> HTTP/koji.fedoraproject....@fedoraproject.org, seqnum 981922983, subkey 
>> aes256-cts/E0B2, session key aes256-cts/ABBE
>> [14673] 1537390104.638612: Read AP-REP, time 1537390104.638608, subkey 
>> aes256-cts/6E40, seqnum 114415586
>> Building gnat-srpm-macros-4-4.fc30 for rawhide
>> Created task: 29768338
>> Task info: https://koji.fedoraproject.org/koji/taskinfo?taskID=29768338
>> Watching tasks (this may be safely interrupted)...
>> 29768338 build (rawhide, 
>> /rpms/gnat-srpm-macros.git:07c0eb592eed960636c297ad9205edf537d9d789): open 
>> (buildvm-28.phx2.fedoraproject.org)
>> 29768339 buildSRPMFromSCM 
>> (/rpms/gnat-srpm-macros.git:07c0eb592eed960636c297ad9205edf537d9d789): closed
>> 29768340 buildArch (gnat-srpm-macros-4-4.fc30.src.rpm, noarch): open 
>> (buildvm-ppc64le-15.ppc.fedoraproject.org)
>> 29768340 buildArch (gnat-srpm-macros-4-4.fc30.src.rpm, noarch): open 
>> (buildvm-ppc64le-15.ppc.fedoraproject.org) -> closed
>> 0 free  1 open  2 done  0 failed
>> 29768338 build (rawhide, 
>> /rpms/gnat-srpm-macros.git:07c0eb592eed960636c297ad9205edf537d9d789): open 
>> (buildvm-28.phx2.fedoraproject.org) -> closed
>> 0 free  0 open  3 done  0 failed
>> 29768342 tagBuild (noarch): closed
>> 
>> 29768338 build (rawhide, 
>> /rpms/gnat-srpm-macros.git:07c0eb592eed960636c297ad9205edf537d9d789) 
>> completed successfully
> 
> 
> 
> 
>> _______________________________________________
>> devel mailing list -- devel@lists.fedoraproject.org
>> To unsubscribe send an email to devel-le...@lists.fedoraproject.org
>> Fedora Code of Conduct: https://getfedora.org/code-of-conduct.html
>> List Guidelines: https://fedoraproject.org/wiki/Mailing_list_guidelines
>> List Archives: 
>> https://lists.fedoraproject.org/archives/list/devel@lists.fedoraproject.org
> 
> 
> -- 
> / Alexander Bokovoy
> Sr. Principal Software Engineer
> Security / Identity Management Engineering
> Red Hat Limited, Finland
_______________________________________________
devel mailing list -- devel@lists.fedoraproject.org
To unsubscribe send an email to devel-le...@lists.fedoraproject.org
Fedora Code of Conduct: https://getfedora.org/code-of-conduct.html
List Guidelines: https://fedoraproject.org/wiki/Mailing_list_guidelines
List Archives: 
https://lists.fedoraproject.org/archives/list/devel@lists.fedoraproject.org

Reply via email to