Unable to authenticate with kinit or FreeIPA web GUI after upgrading from Fedora 37 to Fedora 38

[Martin Gignac]

Hi,

I'm currently running 3 Fedora 37 VMs (freeipa01, freeipa02 and freeipa03), running FreeIPA in a cluster. I decided today to upgrade the freeipa03 VM to Fedora 38. After the upgrade, I am no longer able to successfully login to the FreeIPA web GUI on this VM using my account credentials, nor am I able to 'kinit' successfully on the VM either with this account. Using the same account on the other two Fedora 37 VMs still works, so I would like to resolve this issue before upgrading the rest of the cluster. Note that the 'admin' account still works on freeipa03, though, both in the GUI and using 'kinit'. It also seems that pure LDAP authentication is unaffected (i.e. I can log in successfully with my account using the OpenLDAP client).

Suspecting that the problem might be Kerberos-specific, I followed the instructions on this page (https://www.freeipa.org/page/Troubleshooting/Kerberos) and ran (user and domain names changed to protect the innocent):

--------------
[root@freeipa03 log]# KRB5_TRACE=/dev/stdout kinit buddy
[1542] 1695160597.889222: Matching [e-mail] in collection with result: 0/Success
[1542] 1695160597.889223: Getting initial credentials for [e-mail]
[1542] 1695160597.889225: Sending unauthenticated request
[1542] 1695160597.889226: Sending request (170 bytes) to EXAMPLE.COM
[1542] 1695160597.889227: Initiating TCP connection to stream 192.168.40.133:88
[1542] 1695160597.889228: Sending TCP request to stream 192.168.40.133:88
[1542] 1695160597.889229: Received answer (519 bytes) from stream 192.168.40.133:88
[1542] 1695160597.889230: Terminating TCP connection to stream 192.168.40.133:88
[1542] 1695160597.889231: Response was from primary KDC
[1542] 1695160597.889232: Received error from KDC: -1765328359/Additional pre-authentication required
[1542] 1695160597.889235: Preauthenticating using KDC method data
[1542] 1695160597.889236: 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)
[1542] 1695160597.889237: Selected etype info: etype aes256-cts, salt "a&591&^W'=$!B6#6", params ""
[1542] 1695160597.889238: Received cookie: MIT1\x00\x00\x00\x01Q\xa3RO\xea\xa6\xc4Z\xa4\xd6_w\xacA\x05\x97J\xaf\x12\x1c*\xab\xa0vkGq\x88\xfa\xb3\x98\xb3v\xc02\xe2>\xebZ%g\x9e'7\xac\x97\xb5\x18w\x11e\x870**\xddvQs\xcd\x81\x95\x90\xd5\x0b\xd5\x9f\x11%\x88\xfb\xc7*l\xea\xceV\xc0%\xca{\x14\xe7\xbf\xbf\x9a\xef\x93\xa1\xe4v\x13\xe8C\xd9B\xceay\xe4U\x1e\x1b\x01V\xf9\xc45\x84\x1a\x99W\x18j\xed\xf1V\xc9\x08\xa98\x91\x14\xb1\x95L\xf4\xe2\xef\xc9\xff\xe2\xe95\xcb\xdf\xaa\xe4\x1e\xc7,G
[1542] 1695160597.889239: PKINIT client has no configured identity; giving up
[1542] 1695160597.889240: Preauth module pkinit (147) (info) returned: 0/Success
[1542] 1695160597.889241: PKINIT client received freshness token from KDC
[1542] 1695160597.889242: Preauth module pkinit (150) (info) returned: 0/Success
[1542] 1695160597.889243: PKINIT client has no configured identity; giving up
[1542] 1695160597.889244: Preauth module pkinit (16) (real) returned: 22/Invalid argument
[1542] 1695160597.889245: SPAKE challenge received with group 1, pubkey E03357913D632FED4908863B7F43145F9A64BBE14921DA6C9FBD7C1C21F60E14
Password for [e-mail]: 
[1542] 1695160600.810901: SPAKE key generated with pubkey 75C14A0B07690CDCB14EE2580FD53E19BF28D7AC548CC276CE35A6EBE971E46C
[1542] 1695160600.810902: SPAKE algorithm result: 53671BE2D5C567F80864741EF0C69555C3817303DEDA9A5F28E9823001438226
[1542] 1695160600.810903: SPAKE final transcript hash: 9C2818F938FDF8F916F7100C4A5426FCAE4FCE53A34BFDF82BF1F6BA55296513
[1542] 1695160600.810904: Sending SPAKE response
[1542] 1695160600.810905: Preauth module spake (151) (real) returned: 0/Success
[1542] 1695160600.810906: Produced preauth for next request: PA-FX-COOKIE (133), PA-SPAKE (151)
[1542] 1695160600.810907: Sending request (441 bytes) to EXAMPLE.COM
[1542] 1695160600.810908: Initiating TCP connection to stream 192.168.40.133:88
[1542] 1695160600.810909: Sending TCP request to stream 192.168.40.133:88
[1542] 1695160600.810910: Received answer (143 bytes) from stream 192.168.40.133:88
[1542] 1695160600.810911: Terminating TCP connection to stream 192.168.40.133:88
[1542] 1695160600.810912: Response was from primary KDC
[1542] 1695160600.810913: Received error from KDC: -1765328324/Generic error (see e-text)
kinit: Generic error (see e-text) while getting initial credentials
--------------

Something I see different between the working Kerberos authentication on freeipa01 and freeipa02 and the non-working one on freeipa03 is the presence of this line in '/var/log/krb5kdc.log' on freeipa03:

--------------
Sep 19 18:09:07 freeipa03.infra.example.com krb5kdc[888](info): AS_REQ (6 etypes {aes256-cts-hmac-sha1-96(18), aes256-cts-hmac-sha384-192(20), camellia256-cts-cmac(26), aes128-cts-hmac-sha256-128(19), aes128-cts-hmac-sha1-96(17), camellia128-cts-cmac(25)}) 192.168.40.133: HANDLE_AUTHDATA: [e-mail] for krbtgt/[e-mail], No such file or directory
--------------

On Fedora 38, I am running FreeIPA 4.10.2, whereas on Fedora 37 I am running 4.10.1.

I found this RedHat article (https://access.redhat.com/solutions/7015184 "Cannot authenticate using Kerberos after upgrading Red Hat Identity Management") which describes the problem as: "After updating ipa-server to 4.10.1-3 or newer, domain users cannot login anymore with Kerberos" with the exact same 'kinit <user>' error I obtained, and the same error line in '/var/log/krb5kdc.log'.

The article then suggests running the following:

--------------
$ kinit admin
$ ipa config-mod --enable-sid --add-sids

Check if a SID has been generated for the user:

$ ipa user-show <user> --all | grep ipantsecurityidentifier
ipantsecurityidentifier: S-1-5-21-198193297-2287641477-1368658080-1001
--------------

So, I ran 'ipa config-mod --enable-sid --add-sids', but even after running this command 'ipa user-show buddy --all | grep ipantsecurityidentifier' still shows up empty.

Since this seems to be the exact same problem I have, but it doesn't seem to fix my particular situation, is there anything else I need to do and/or check?

Thank you,
-Martin

[Rob Crittenden]

Martin Gignac via FreeIPA-users wrote:
> Hi,
>
> I'm currently running 3 Fedora 37 VMs (freeipa01, freeipa02 and freeipa03), running FreeIPA in a cluster. I decided today to upgrade the freeipa03 VM to Fedora 38. After the upgrade, I am no longer able to successfully login to the FreeIPA web GUI on this VM using my account credentials, nor am I able to 'kinit' successfully on the VM either with this account. Using the same account on the other two Fedora 37 VMs still works, so I would like to resolve this issue before upgrading the rest of the cluster. Note that the 'admin' account still works on freeipa03, though, both in the GUI and using 'kinit'. It also seems that pure LDAP authentication is unaffected (i.e. I can log in successfully with my account using the OpenLDAP client).
>
> Suspecting that the problem might be Kerberos-specific, I followed the instructions on this page (https://www.freeipa.org/page/Troubleshooting/Kerberos) and ran (user and domain names changed to protect the innocent):
>
> [root@freeipa03 log]# KRB5_TRACE=/dev/stdout kinit buddy
> [1542] 1695160597.889222: Matching [e-mail] in collection with result: 0/Success
> [1542] 1695160597.889223: Getting initial credentials for [e-mail]
> [1542] 1695160597.889225: Sending unauthenticated request
> [1542] 1695160597.889226: Sending request (170 bytes) to EXAMPLE.COM
> [1542] 1695160597.889227: Initiating TCP connection to stream 192.168.40.133:88
> [1542] 1695160597.889228: Sending TCP request to stream 192.168.40.133:88
> [1542] 1695160597.889229: Received answer (519 bytes) from stream 192.168.40.133:88
> [1542] 1695160597.889230: Terminating TCP connection to stream 192.168.40.133:88
> [1542] 1695160597.889231: Response was from primary KDC
> [1542] 1695160597.889232: Received error from KDC: -1765328359/Additional pre-authentication required
> [1542] 1695160597.889235: Preauthenticating using KDC method data
> [1542] 1695160597.889236: 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)
> [1542] 1695160597.889237: Selected etype info: etype aes256-cts, salt "a&591&^W'=$!B6#6", params ""
> [1542] 1695160597.889238: Received cookie: MIT1\x00\x00\x00\x01Q\xa3RO\xea\xa6\xc4Z\xa4\xd6_w\xacA\x05\x97J\xaf\x12\x1c*\xab\xa0vkGq\x88\xfa\xb3\x98\xb3v\xc02\xe2>\xebZ%g\x9e'7\xac\x97\xb5\x18w\x11e\x870**\xddvQs\xcd\x81\x95\x90\xd5\x0b\xd5\x9f\x11%\x88\xfb\xc7*l\xea\xceV\xc0%\xca{\x14\xe7\xbf\xbf\x9a\xef\x93\xa1\xe4v\x13\xe8C\xd9B\xceay\xe4U\x1e\x1b\x01V\xf9\xc45\x84\x1a\x99W\x18j\xed\xf1V\xc9\x08\xa98\x91\x14\xb1\x95L\xf4\xe2\xef\xc9\xff\xe2\xe95\xcb\xdf\xaa\xe4\x1e\xc7,G
> [1542] 1695160597.889239: PKINIT client has no configured identity; giving up
> [1542] 1695160597.889240: Preauth module pkinit (147) (info) returned: 0/Success
> [1542] 1695160597.889241: PKINIT client received freshness token from KDC
> [1542] 1695160597.889242: Preauth module pkinit (150) (info) returned: 0/Success
> [1542] 1695160597.889243: PKINIT client has no configured identity; giving up
> [1542] 1695160597.889244: Preauth module pkinit (16) (real) returned: 22/Invalid argument
> [1542] 1695160597.889245: SPAKE challenge received with group 1, pubkey E03357913D632FED4908863B7F43145F9A64BBE14921DA6C9FBD7C1C21F60E14
> Password for [e-mail]: 
> [1542] 1695160600.810901: SPAKE key generated with pubkey 75C14A0B07690CDCB14EE2580FD53E19BF28D7AC548CC276CE35A6EBE971E46C
> [1542] 1695160600.810902: SPAKE algorithm result: 53671BE2D5C567F80864741EF0C69555C3817303DEDA9A5F28E9823001438226
> [1542] 1695160600.810903: SPAKE final transcript hash: 9C2818F938FDF8F916F7100C4A5426FCAE4FCE53A34BFDF82BF1F6BA55296513
> [1542] 1695160600.810904: Sending SPAKE response
> [1542] 1695160600.810905: Preauth module spake (151) (real) returned: 0/Success
> [1542] 1695160600.810906: Produced preauth for next request: PA-FX-COOKIE (133), PA-SPAKE (151)
> [1542] 1695160600.810907: Sending request (441 bytes) to EXAMPLE.COM
> [1542] 1695160600.810908: Initiating TCP connection to stream 192.168.40.133:88
> [1542] 1695160600.810909: Sending TCP request to stream 192.168.40.133:88
> [1542] 1695160600.810910: Received answer (143 bytes) from stream 192.168.40.133:88
> [1542] 1695160600.810911: Terminating TCP connection to stream 192.168.40.133:88
> [1542] 1695160600.810912: Response was from primary KDC
> [1542] 1695160600.810913: Received error from KDC: -1765328324/Generic error (see e-text)
> kinit: Generic error (see e-text) while getting initial credentials
>
> Something I see different between the working Kerberos authentication on freeipa01 and freeipa02 and the non-working one on freeipa03 is the presence of this line in '/var/log/krb5kdc.log' on freeipa03:
> Sep 19 18:09:07 freeipa03.infra.example.com krb5kdc[888](info): AS_REQ (6 etypes {aes256-cts-hmac-sha1-96(18), aes256-cts-hmac-sha384-192(20), camellia256-cts-cmac(26), aes128-cts-hmac-sha256-128(19), aes128-cts-hmac-sha1-96(17), camellia128-cts-cmac(25)}) 192.168.40.133: HANDLE_AUTHDATA: [e-mail] for krbtgt/[e-mail], No such file or directory
>
> On Fedora 38, I am running FreeIPA 4.10.2, whereas on Fedora 37 I am running 4.10.1.
>
> I found this RedHat article (https://access.redhat.com/solutions/7015184 "Cannot authenticate using Kerberos after upgrading Red Hat Identity Management") which describes the problem as: "After updating ipa-server to 4.10.1-3 or newer, domain users cannot login anymore with Kerberos" with the exact same 'kinit <user>' error I obtained, and the same error line in '/var/log/krb5kdc.log'.
>
> The article then suggests running the following:
>
> $ kinit admin
> $ ipa config-mod --enable-sid --add-sids
>
> Check if a SID has been generated for the user:
>
> $ ipa user-show <user> --all | grep ipantsecurityidentifier
> ipantsecurityidentifier: S-1-5-21-198193297-2287641477-1368658080-1001
>
> So, I ran 'ipa config-mod --enable-sid --add-sids', but even after running this command 'ipa user-show buddy --all | grep ipantsecurityidentifier' still shows up empty.
>
> Since this seems to be the exact same problem I have, but it doesn't seem to fix my particular situation, is there anything else I need to do and/or check?

Check /var/log/dirsrv/slapd-REALM/errors. If a user is found not in a
valid range the SID generator will quit.

rob

[Martin Gignac]

Hi Rob,

Inside the '/var/log/dirsrv/slapd-EXAMPLE-COM' directory, the only file that gets updated after performing an unsuccessful 'kinit' is the file 'access'. The files 'errors' and 'security' haven't been updated for at least three hours. So either it's not the error you referenced, or that error is not logged in that file on my machine.

Thanks,
-Martin

[Martin Gignac]

Rob, I googled a bit more, and I think I misunderstood what you meant. You're right, when running 'ipa config-mod --enable-sid --add-sids', I *do* get an error in '/var/log/dirsrv/slapd-EXAMPLE-COM/errors', I do see the following:

[19/Sep/2023:21:33:28.535278863 -0400] - ERR - sidgen_task_thread - [file ipa_sidgen_task.c, line 194]: Sidgen task starts ...
[19/Sep/2023:21:33:28.598913824 -0400] - ERR - find_sid_for_ldap_entry - [file ipa_sidgen_common.c, line 521]: Cannot convert Posix ID [1409438538] into an unused SID.
[19/Sep/2023:21:33:28.600673160 -0400] - ERR - do_work - [file ipa_sidgen_task.c, line 154]: Cannot add SID to existing entry.
[19/Sep/2023:21:33:28.604385987 -0400] - ERR - sidgen_task_thread - [file ipa_sidgen_task.c, line 199]: Sidgen task finished [32].

I'll try to figure out how to correct this.

Thanks.

[Martin Gignac]

Adding a range that matches UIDs and GIDs that were not within the existing range fixed the 'Cannot convert Posix ID [1409438538] into an unused SID' error and allowed me to run 'ipa config-mod --enable-sid --add-sids' successfully. I can now use 'kinit' and log in to the web GUI successfully.

Thanks Rob.