#7003 anonymous PKINIT fails after upgrading from 4.4.4-2 to 4.5.x development version
Closed: duplicate Opened by mbabinsk.

When upgrading FreeIPA server between 4.4 and 4.5.x version built from git and enabling PKINIT, the user can not receive anonymous TGT using PKINIT due to failure in DH exchange between client library and KDC (see the full trace below). Interestingly, password authentication (and thus also the WebUI login) works correctly so it seems that the client PKINIT anchors are misconfigured somehow.

Steps to reproduce:

1.) Install FreeIPA server 4.4.4-2 or earlier

2.) upgrade to RPMs built from current 4.5 branch (e.g. freeipa-server-4.5.1.dev201706070816+git6206ac8-0.fc25.x86_64)

3.) enable PKINIT by running ipa-pkinit-manage enable

4.) kinit -n

Expected results:

You receive a TGT for WELLKNOWN/ANONYMOUS principal

Actual results:

You get kinit: Preauthentication failed while getting initial credentials error. Tracing the Kerberos library shows the following:

# KRB5_TRACE=/dev/stderr kinit -n
[10658] 1496831215.179809: Resolving unique ccache of type KEYRING
[10658] 1496831215.179971: Getting initial credentials for WELLKNOWN/ANONYMOUS@IPA.TEST
[10658] 1496831215.181784: Sending request (180 bytes) to IPA.TEST
[10658] 1496831215.182214: Initiating TCP connection to stream 192.168.122.100:88
[10658] 1496831215.182432: Sending TCP request to stream 192.168.122.100:88
[10658] 1496831215.184000: Received answer (329 bytes) from stream 192.168.122.100:88
[10658] 1496831215.184080: Terminating TCP connection to stream 192.168.122.100:88
[10658] 1496831215.184225: Response was from master KDC
[10658] 1496831215.184394: Received error from KDC: -1765328359/Additional pre-authentication required
[10658] 1496831215.184494: Processing preauth types: 16, 15, 14, 136, 19, 147, 2, 133
[10658] 1496831215.184596: Selected etype info: etype aes256-cts, salt "IPA.TESTWELLKNOWNANONYMOUS", params ""
[10658] 1496831215.184666: Received cookie: MIT
[10658] 1496831215.184752: Preauth module pkinit (147) (info) returned: 0/Success
[10658] 1496831215.185030: PKINIT client computed kdc-req-body checksum 9/318127877C86F092BF7457747E3059CE8A49F481
[10658] 1496831215.185111: PKINIT client making DH request
[10658] 1496831215.205760: Preauth module pkinit (16) (real) returned: 0/Success
[10658] 1496831215.205918: Produced preauth for next request: 133, 16
[10658] 1496831215.206039: Sending request (1367 bytes) to IPA.TEST
[10658] 1496831215.206189: Initiating TCP connection to stream 192.168.122.100:88
[10658] 1496831215.206348: Sending TCP request to stream 192.168.122.100:88
[10658] 1496831215.233142: Received answer (1588 bytes) from stream 192.168.122.100:88
[10658] 1496831215.233153: Terminating TCP connection to stream 192.168.122.100:88
[10658] 1496831215.233202: Response was from master KDC
[10658] 1496831215.233223: Processing preauth types: 17, 19, 147
[10658] 1496831215.233234: Selected etype info: etype aes256-cts, salt "IPA.TESTWELLKNOWNANONYMOUS", params ""
[10658] 1496831215.233247: Preauth module pkinit (147) (info) returned: 0/Success
[10658] 1496831215.233284: PKINIT client could not verify DH reply
[10658] 1496831215.233289: Preauth module pkinit (17) (real) returned: -1765328360/Preauthentication failed
kinit: Preauthentication failed while getting initial credentials

Are you sure your client configuration trusts the same CA certificate chain that KDC uses for PKINIT?

When we set up PKINIT with local self-signed certificate, we do not expect it will be trusted by any client other than IPA framework running on the same machine. The framework code actually adds pkinit_anchors to point to the same certificates used by KDC.

This is the case of proper PKINIT with KDC certificates issued by IPA CA. In this case IPA CA certificate should be appended to client anchors/pkinit_pool but apparently this is not the case in this upgrade path.

I am hitting this even with ipa-server-4.5.0-16.el7.x86_64 server without any upgrade.

Steps to reproduce:

  1. install CA-less master without pkinit
  2. generate KDC cert signed by different CA
  3. issue "ipa-cacert-manage install" to add the CA
  4. ipa-certupdate
  5. ipa-server-certinstall --kdc ./pkinit-server.p12 --pin XXX
  6. kinit -n
[root@master ~]# KRB5_TRACE=/dev/stdout kinit -n
[12984] 1496992862.778766: Getting initial credentials for WELLKNOWN/ANONYMOUS@TESTRELM.TEST
[12984] 1496992862.781603: Sending request (190 bytes) to TESTRELM.TEST
[12984] 1496992862.781775: Initiating TCP connection to stream 192.168.222.10:88
[12984] 1496992862.782014: Sending TCP request to stream 192.168.222.10:88
[12984] 1496992862.785226: Received answer (344 bytes) from stream 192.168.222.10:88
[12984] 1496992862.785236: Terminating TCP connection to stream 192.168.222.10:88
[12984] 1496992862.785312: Response was from master KDC
[12984] 1496992862.785355: Received error from KDC: -1765328359/Additional pre-authentication required
[12984] 1496992862.785401: Processing preauth types: 16, 15, 14, 136, 19, 147, 2, 133
[12984] 1496992862.785414: Selected etype info: etype aes256-cts, salt "TESTRELM.TESTWELLKNOWNANONYMOUS", params ""
[12984] 1496992862.785418: Received cookie: MIT
[12984] 1496992862.785448: Preauth module pkinit (147) (info) returned: 0/Success
[12984] 1496992862.785860: PKINIT client computed kdc-req-body checksum 9/146F1085B92F98D4745FD5EFB4DA2FE1EE3E0E65
[12984] 1496992862.785867: PKINIT client making DH request
[12984] 1496992862.811974: Preauth module pkinit (16) (real) returned: 0/Success
[12984] 1496992862.811990: Produced preauth for next request: 133, 16
[12984] 1496992862.812012: Sending request (1453 bytes) to TESTRELM.TEST
[12984] 1496992862.812087: Initiating TCP connection to stream 192.168.222.10:88
[12984] 1496992862.812143: Sending TCP request to stream 192.168.222.10:88
[12984] 1496992862.826079: Received answer (1622 bytes) from stream 192.168.222.10:88
[12984] 1496992862.826093: Terminating TCP connection to stream 192.168.222.10:88
[12984] 1496992862.826143: Response was from master KDC
[12984] 1496992862.826169: Processing preauth types: 17, 19, 147
[12984] 1496992862.826176: Selected etype info: etype aes256-cts, salt "TESTRELM.TESTWELLKNOWNANONYMOUS", params ""
[12984] 1496992862.826191: Preauth module pkinit (147) (info) returned: 0/Success
[12984] 1496992862.826302: PKINIT client could not verify DH reply
[12984] 1496992862.826328: Preauth module pkinit (17) (real) returned: -1765328360/Preauthentication failed
kinit: Preauthentication failed while getting initial credentials

Attaching krb5kdc logs.

krb5kdc.log

Tried again after krb5kdc service restart and "kinit -n" works. Just to be sure tried to set up another environment:

ipa-server-4.5.0-16.el7.x86_64
selinux-policy-3.13.1-160.el7.noarch

[root@master2 ~]# ipa-server-certinstall --kdc ./pkinit-server.p12 --pin Secret123
Directory Manager password: 
The ipa-server-certinstall command was successful
[root@master2 ~]# 
[root@master2 ~]# 
[root@master2 ~]# 
[root@master2 ~]# kinit -n
kinit: Preauthentication failed while getting initial credentials
[root@master2 ~]# 
[root@master2 ~]# systemctl restart krb5kdc.service
[root@master2 ~]# 
[root@master2 ~]# kinit -n
[root@master2 ~]# 
[root@master2 ~]# klist
Ticket cache: KEYRING:persistent:0:0
Default principal: WELLKNOWN/ANONYMOUS@WELLKNOWN:ANONYMOUS
Valid starting       Expires              Service principal
06/09/2017 05:13:30  06/10/2017 05:13:30  krbtgt/TESTRELM.TEST@TESTRELM.TEST
[root@master2 ~]# 
[root@master2 ~]# getenforce
Enforcing
[root@master2 ~]# ausearch -m avc
<no matches>

In krb5kdc.log got this error right at the begin:

otp: Loaded
Jun 09 05:10:09 master2 krb5kdc[5168](Error): preauth pkinit failed to initialize: No realms configured correctly for pkinit support
Jun 09 05:10:09 master2 krb5kdc[5168](info): setting up network...
krb5kdc: setsockopt(7,IPV6_V6ONLY,1) worked
krb5kdc: setsockopt(9,IPV6_V6ONLY,1) worked
Jun 09 05:10:09 master2 krb5kdc[5168](info): set up 4 sockets
Jun 09 05:10:09 master2 krb5kdc[5169](info): creating 2 worker processes
Jun 09 05:10:09 master2 krb5kdc[5169](info): closing down fd 9

Then it goes:

un 09 05:10:09 master2 krb5kdc[5170](info): commencing operation
Jun 09 05:10:09 master2 krb5kdc[5171](info): commencing operation
Jun 09 05:10:20 master2 krb5kdc[5171](info): AS_REQ (8 etypes {18 17 16 23 25 26 20 19}) 192.168.222.11: NEEDED_PREAUTH: host/master2.testrelm.test@TESTRELM.TEST for krbtgt/TESTRELM.TEST@TESTRELM.TEST, Additional pre-authentication required
Jun 09 05:10:20 master2 krb5kdc[5171](info): closing down fd 11
Jun 09 05:10:20 master2 krb5kdc[5171](Error): No default authorization data types available, no authorization data will be added.
Jun 09 05:10:20 master2 krb5kdc[5171](info): AS_REQ (8 etypes {18 17 16 23 25 26 20 19}) 192.168.222.11: ISSUE: authtime 1496999420, etypes {rep=18 tkt=18 ses=18}, host/master2.testrelm.test@TESTRELM.TEST for krbtgt/TESTRELM.TEST@TESTRELM.TEST
Jun 09 05:10:20 master2 krb5kdc[5171](info): closing down fd 11
Jun 09 05:10:20 master2 krb5kdc[5170](Error): No default authorization data types available, no authorization data will be added.
Jun 09 05:10:20 master2 krb5kdc[5170](info): TGS_REQ (8 etypes {18 17 20 19 16 23 25 26}) 192.168.222.11: ISSUE: authtime 1496999420, etypes {rep=18 tkt=18 ses=18}, host/master2.testrelm.test@TESTRELM.TEST for ldap/master2.testrelm.test@TESTRELM.TEST

It turned out that the issue reported on ipa-server-4.5.0-16.el7.x86_64 was caused by not implemented restart of krb5kdc service. So for the moment the restart is indeed needed. Ticket #7016 deals with this.

Closing given that #7016 deals with it.

Metadata Update from @pvoborni:
- Issue close_status updated to: duplicate
- Issue status updated to: Closed (was: Open)

Metadata