Hello,
We are currently experiencing strange behavior on FreeIPA system related to PKINIT OpenSSL error when trying to log in through FreeIPA web gui. This started happening as we upgraded our second replica with "dnf ugprade". Freeipa packages in themself haven't been updated.
Our setup is basically as follows.
ipa.tre-1.web1.fi
ipa.tku-2.web1.fi <-- the one not working.
GUI throws an error "Login failed due to an unknown reason"
httpd error log has the following line after error:
[Fri Feb 25 19:32:50.776457 2022] [wsgi:error] [pid 17977:tid 18319] [remote 10.20.11.2:49472] ipapython.ipautil.CalledProcessError: CalledProcessError(Command ['/usr/bin/kinit', '-n', '-c', '/run/ipa/ccaches/armor_17977', '-X', 'X509_anchors=FILE:/var/kerberos/krb5kdc/kdc.crt', '-X', 'X509_anchors=FILE:/var/lib/ipa-client/pki/kdc-ca-bundle.pem'] returned non-zero exit status 1: 'kinit: Cannot read password while getting initial credentials\\n')
Now if I try to run
" KRB5_TRACE=/dev/stdout /usr/bin/kinit -n -c /var/run/ipa/ccaches/armor_15581 -X X509_anchors=FILE:/var/kerberos/krb5kdc/kdc.crt -X X509_anchors=FILE:/var/lib/ipa-client/pki/kdc-ca-bundle.pem"
I get the following output
[19260] 1645812760.557398: Getting initial credentials for WELLKNOWN/ANONYMOUS(a)IPA.WEB1.FI
[19260] 1645812760.557400: Sending unauthenticated request
[19260] 1645812760.557401: Sending request (186 bytes) to IPA.WEB1.FI
[19260] 1645812760.557402: Initiating TCP connection to stream 10.20.13.5:88
[19260] 1645812760.557403: Sending TCP request to stream 10.20.13.5:88
[19260] 1645812760.557404: Received answer (538 bytes) from stream 10.20.13.5:88
[19260] 1645812760.557405: Terminating TCP connection to stream 10.20.13.5:88
[19260] 1645812760.557406: Response was from primary KDC
[19260] 1645812760.557407: Received error from KDC: -1765328359/Additional pre-authentication required
[19260] 1645812760.557410: Preauthenticating using KDC method data
[19260] 1645812760.557411: 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)
[19260] 1645812760.557412: Selected etype info: etype aes256-cts, salt "IPA.WEB1.FIWELLKNOWNANONYMOUS", params ""
[19260] 1645812760.557413: Received cookie: MIT1\x00\x00\x00\x01\x8f\xcb\x99\x9c~\xed!^Qj\xa3\x0a\x82~\xe94\x04\x0ck[j=\x08\xd2\x97j'K2\x8f\xa0\xf6\xc3\x89Z@\x8b]\xc3K\xc2h\xfa\xaek\x11\x91y\xc9\xf0\xadG\x13\x9a\xb2\xb6\x1c\x12\xbfr\x0a'Z\xfe\x12\x81\x1a>2\x8c\x1a\xf2\x96\xdc]&qH\x08\x1f\x0d\xc0a{\xe8\xff\xbbF\x9c\x86`\xd6G\xc4*5\xccL\xc1m\xc0\xa7b\x8b]od\xfa*\xd4.bmB\x9d\x92\xb7\xf9($\xa4D\xea\xcd\xc6\xe3p\xac$\xf4
[19260] 1645812760.557414: Preauth module pkinit (147) (info) returned: 0/Success
[19260] 1645812760.557415: PKINIT client received freshness token from KDC
[19260] 1645812760.557416: Preauth module pkinit (150) (info) returned: 0/Success
[19260] 1645812760.557417: PKINIT loading CA certs and CRLs from FILE
[19260] 1645812760.557418: PKINIT loading CA certs and CRLs from FILE
[19260] 1645812760.557419: PKINIT loading CA certs and CRLs from FILE
[19260] 1645812760.557420: PKINIT client computed kdc-req-body checksum 9/B79768B0DAD630709ABFE35C1E2B6FDAB714913D
[19260] 1645812760.557422: PKINIT client making DH request
[19260] 1645812760.557423: Preauth module pkinit (16) (real) returned: 0/Success
[19260] 1645812760.557424: Produced preauth for next request: PA-FX-COOKIE (133), PA-PK-AS-REQ (16)
[19260] 1645812760.557425: Sending request (1674 bytes) to IPA.WEB1.FI
[19260] 1645812760.557426: Initiating TCP connection to stream 10.20.13.5:88
[19260] 1645812760.557427: Sending TCP request to stream 10.20.13.5:88
[19260] 1645812760.557428: Received answer (2619 bytes) from stream 10.20.13.5:88
[19260] 1645812760.557429: Terminating TCP connection to stream 10.20.13.5:88
[19260] 1645812760.557430: Response was from primary KDC
[19260] 1645812760.557431: Processing preauth types: PA-PK-AS-REP (17), PA-PKINIT-KX (147)
[19260] 1645812760.557432: Preauth module pkinit (147) (info) returned: 0/Success
[19260] 1645812760.557433: PKINIT OpenSSL error: Failed to verify CMS message
[19260] 1645812760.557434: PKINIT OpenSSL error: error:1700006B:CMS routines::content type not enveloped data
[19260] 1645812760.557435: PKINIT OpenSSL error: error:03000098:digital envelope routines::invalid digest
[19260] 1645812760.557436: PKINIT client could not verify DH reply
[19260] 1645812760.557437: Preauth module pkinit (17) (real) returned: -1765328320/Failed to verify CMS message: content type not enveloped data
[19260] 1645812760.557438: Produced preauth for next request: (empty)
[19260] 1645812760.557439: Getting AS key, salt "IPA.WEB1.FIWELLKNOWNANONYMOUS", params ""
Password for WELLKNOWN/ANONYMOUS(a)IPA.WEB1.FI:
[19260] 1645812776.928337: AS key obtained from gak_fct: aes256-cts/3840
kinit: Password incorrect while getting initial credentials
But this only happens on the "dc2" one.
If I would run this on the "dc1" it would work just fine.
I have tried running
ipa-pkinit-manage disable
ipa-pkinit-manage enable
to regen the cert but it didn't help. Any suggestions / pointers at why the OpenSSL error on the tku-2 is showing up.