Red Hat Bugzilla – Bug 1452763
ipa certmaprule change not reflected in krb5kdc workers
Last modified: 2017-08-01 05:51:24 EDT
Description of problem: While testing Smart Cards on an IPA client with PKINIT enabled in IPA, I noticed intermittent failures. The certificate maps properly to the user but, the KDC on IPA would sometimes seem to try to match to the previous rule. Version-Release number of selected component (if applicable): krb5-server-1.15.1-8.el7.x86_64 How reproducible: unknown. Steps to Reproduce: 1. IPA Server installed with PKINIT support 2. IPA Client setup with Smart Card 3. Cert generated on IPA server and added to card 4. created one certmaprule and tested client 5. deleted rule and added new rule 6. tested authentication which should use the new rule Actual results: authentication would fail at times. work others. Expected results: always work. Additional info: FYI, rules used when I saw the error: ipa certmaprule-add ipaadcs12r2_defaultrule --maprule='(|(userCertificate;binary={cert!bin})(altSecurityIdentities=X509:<I>{issuer_dn!ad_x500}<S>{subject_dn!ad_x500}))' --matchrule='<ISSUER>CN=Certificate Authority,O=TESTRELM.TEST' --domain=ipaadcs12r2.test --domain=testrelm.test ipa certmaprule-del ipaadcs12r2_ipacertrule ipa certmaprule-add testrealm_defaultrule --maprule='(|(userCertificate;binary={cert!bin})(ipacertmapdata=X509:<I>{issuer_dn!nss_x500}<S>{subject_dn!nss_x500}))' --matchrule='<ISSUER>CN=Certificate Authority,O=TESTRELM.TEST' --domain=testrelm.test This rule change seems to have happened between when the kdc workers loaded the rule. [Wed May 17 17:06:43.623274 2017] [:error] [pid 8318] ipa: INFO: [jsonserver_session] admin@TESTRELM.TEST: certmaprule_add/1(u'ipaadcs12r2_defaultrule', ipacertmapmaprule=u'(|(userCertificate;binary={cert!bin})(altSecurityIdentities=X509:<I>{issuer_dn!ad_x500}<S>{subject_dn!ad_x500}))', ipacertmapmatchrule=u'<ISSUER>CN=Certificate Authority,O=TESTRELM.TEST', associateddomain=(<DNS name ipaadcs12r2.test>, <DNS name testrelm.test>), version=u'2.224'): SUCCESS [Thu May 18 14:43:51.148965 2017] [:error] [pid 8319] ipa: INFO: [jsonserver_session] admin@TESTRELM.TEST: certmaprule_del/1([u'ipaadcs12r2_defaultrule'], version=u'2.224'): SUCCESS [Thu May 18 14:44:30.060976 2017] [:error] [pid 8318] ipa: INFO: [jsonserver_session] admin@TESTRELM.TEST: certmaprule_add/1(u'testrealm_defaultrule', ipacertmapmaprule=u'(|(userCertificate;binary={cert!bin})(ipacertmapdata=X509:<I>{issuer_dn!nss_x500}<S>{subject_dn!nss_x500}))', ipacertmapmatchrule=u'<ISSUER>CN=Certificate Authority,O=TESTRELM.TEST', associateddomain=(<DNS name testrelm.test>,), version=u'2.224'): SUCCESS ######## Example krb5kdc.log entries showing failure and success May 18 17:26:08 auto-hv-02-guest08.testrelm.test krb5kdc[8259](info): Got cert filter [(|(userCertificate;binary=\30\82\04\0d... May 18 17:26:08 auto-hv-02-guest08.testrelm.test krb5kdc[8259](info): No matching entry found May 18 17:41:02 auto-hv-02-guest08.testrelm.test krb5kdc[8260](info): Got cert filter [(|(userCertificate;binary=\30\82\04\0d... May 18 17:41:02 auto-hv-02-guest08.testrelm.test krb5kdc[8260](info): AS_REQ (8 etypes {18 17 20 19 16 23 25 26}) <CLIENT_IP>: ISSUE: authtime 1495143662, etypes {rep=18 tkt=18 ses=18}, demosc1@TESTRELM.TEST for krbtgt/TESTRELM.TEST@TESTRELM.TEST
This seems like an IPA bug, since you're saying an IPA command isn't working right? I'm not set up to test smartcard stuff, in any case, so if it's something krb5's doing wrong please give me more information on what to look at.
It is an issue in the IPA certauth plugin. The certificate mapping rules are store during the initialization of the pkinit module in the ipadb_context. Since this context is not shared between different workers and the pkinit module is not initialized at startup but at first use it might be possible that different workers will use different mapping rules pkinit in not initialized at the same time and if the rules where changed between the two initializations. To solve this the certificate mapping rules can be updated on a more regular basis like it is done e.g. in ipadb_reinit_mspac() to update the data about trusted domains.
Upstream ticket: https://pagure.io/freeipa/issue/6963
Fixed upstream master: https://pagure.io/freeipa/c/e8aed2524846f1cff3d09d676675f3b426178f60 ipa-4-5: https://pagure.io/freeipa/c/d59694a93c3a734915d4ac05bb4e02a40f9cb08a
Ok, first I'll show a reproducer: # User has whole cert and not certmapdata. Will keep this constant so kinit will go from passing to failing but, we're looking for the logs more than anything here. [root@auto-hv-02-guest08 ~]# systemctl restart krb5kdc [root@dhcp129-184 ~]# ipa certmaprule-add testrelm_certificate \ > --maprule='(userCertificate;binary={cert!bin})' \ > --matchrule='<ISSUER>CN=Certificate Authority,O=TESTRELM.TEST' -------------------------------------------------------------- Added Certificate Identity Mapping Rule "testrelm_certificate" -------------------------------------------------------------- Rule name: testrelm_certificate Mapping rule: (userCertificate;binary={cert!bin}) Matching rule: <ISSUER>CN=Certificate Authority,O=TESTRELM.TEST Enabled: TRUE [root@dhcp129-184 ~]# kinit -X X509_user_identity=PKCS11:module_name=/usr/lib64/opensc-pkcs11.so demosc1 demosc1 (OpenSC Card) PIN: # IN /var/log/krb5kdc.log on MASTER: Jun 07 12:53:46 auto-hv-02-guest08.testrelm.test krb5kdc[27694](info): Got cert filter [(userCertificate;binary=\30\82\04\0d... 2017-06-07 10:53:46 MDT [root@dhcp129-184 ~]# kdestroy -A ; echo Secret123|kinit admin Password for admin@TESTRELM.TEST: 2017-06-07 10:53:53 MDT [root@dhcp129-184 ~]# ipa certmaprule-del testrelm_certificate ---------------------------------------------------------------- Deleted Certificate Identity Mapping Rule "testrelm_certificate" ---------------------------------------------------------------- 2017-06-07 10:53:57 MDT [root@dhcp129-184 ~]# ipa certmaprule-add testrelm_certmapdata \ > --maprule='(ipacertmapdata=X509:<I>{issuer_dn!nss_x500}<S>{subject_dn!nss_x500})' \ > --matchrule='<ISSUER>CN=Certificate Authority,O=TESTRELM.TEST' -------------------------------------------------------------- Added Certificate Identity Mapping Rule "testrelm_certmapdata" -------------------------------------------------------------- Rule name: testrelm_certmapdata Mapping rule: (ipacertmapdata=X509:<I>{issuer_dn!nss_x500}<S>{subject_dn!nss_x500}) Matching rule: <ISSUER>CN=Certificate Authority,O=TESTRELM.TEST Enabled: TRUE 2017-06-07 10:54:01 MDT [root@dhcp129-184 ~]# kinit -X X509_user_identity=PKCS11:module_name=/usr/lib64/opensc-pkcs11.so demosc1 demosc1 (OpenSC Card) PIN: # IN /var/log/krb5kdc.log on MASTER we can see it uses the same worker with the old filter: Jun 07 12:54:08 auto-hv-02-guest08.testrelm.test krb5kdc[27694](info): Got cert filter [(userCertificate;binary=\30\82\04... 2017-06-07 10:54:08 MDT [root@dhcp129-184 ~]# kinit -X X509_user_identity=PKCS11:module_name=/usr/lib64/opensc-pkcs11.so demosc1 demosc1 (OpenSC Card) PIN: kinit: Certificate mismatch while getting initial credentials ^^^ FAILS as EXPECTED because we do not have certmapdata defined for the user...only whole cert. # IN /var/log/krb5kdc.log on MASTER we can see it used a new worker and pulled the new filter with certmapdata instead of whole cert: Jun 07 12:54:26 auto-hv-02-guest08.testrelm.test krb5kdc[27695](info): Got cert filter [(ipacertmapdata=X509:<I>O=TESTRELM.TEST,CN=Certificate Authority<S>O=TESTRELM.TEST,CN=demosc1)] If I were to switch again that worker would continue using that filter for a while. With the new fix this same failure should occur in this short amount of time but, if I wait 5 minutes, it should timeout and pick up the new rule. This is what I will test for the verification to follow.
Verified. Version :: ipa-server-4.5.0-15.el7.x86_64 Results :: [root@auto-hv-02-guest08 ~]# systemctl restart krb5kdc [root@dhcp129-184 ~]# ipa certmaprule-add testrelm_certificate \ > --maprule='(userCertificate;binary={cert!bin})' \ > --matchrule='<ISSUER>CN=Certificate Authority,O=TESTRELM.TEST' -------------------------------------------------------------- Added Certificate Identity Mapping Rule "testrelm_certificate" -------------------------------------------------------------- Rule name: testrelm_certificate Mapping rule: (userCertificate;binary={cert!bin}) Matching rule: <ISSUER>CN=Certificate Authority,O=TESTRELM.TEST Enabled: TRUE 2017-06-07 11:11:40 MDT [root@dhcp129-184 ~]# kinit -X X509_user_identity=PKCS11:module_name=/usr/lib64/opensc-pkcs11.so demosc1 demosc1 (OpenSC Card) PIN: 2017-06-07 11:11:52 MDT # IN /var/log/krb5kdc.log: Jun 07 13:11:52 auto-hv-02-guest08.testrelm.test krb5kdc[6839](info): Got cert filter [(userCertificate;binary=\30\82\04 # ^^^ got cert filter as expected [root@dhcp129-184 ~]# kdestroy -A ; echo Secret123|kinit admin Password for admin@TESTRELM.TEST: 2017-06-07 11:12:03 MDT [root@dhcp129-184 ~]# ipa certmaprule-del testrelm_certificate ---------------------------------------------------------------- Deleted Certificate Identity Mapping Rule "testrelm_certificate" ---------------------------------------------------------------- 2017-06-07 11:12:06 MDT [root@dhcp129-184 ~]# ipa certmaprule-add testrelm_certmapdata \ > --maprule='(ipacertmapdata=X509:<I>{issuer_dn!nss_x500}<S>{subject_dn!nss_x500})' \ > --matchrule='<ISSUER>CN=Certificate Authority,O=TESTRELM.TEST' -------------------------------------------------------------- Added Certificate Identity Mapping Rule "testrelm_certmapdata" -------------------------------------------------------------- Rule name: testrelm_certmapdata Mapping rule: (ipacertmapdata=X509:<I>{issuer_dn!nss_x500}<S>{subject_dn!nss_x500}) Matching rule: <ISSUER>CN=Certificate Authority,O=TESTRELM.TEST Enabled: TRUE 2017-06-07 11:12:11 MDT [root@dhcp129-184 ~]# kinit -X X509_user_identity=PKCS11:module_name=/usr/lib64/opensc-pkcs11.so demosc1 demosc1 (OpenSC Card) PIN: 2017-06-07 11:12:17 MDT # IN /var/log/krb5kdc.log Jun 07 13:12:17 auto-hv-02-guest08.testrelm.test krb5kdc[6839](info): Got cert filter [(userCertificate;binary=\30\82\04 # ^^ got worker 1 again so need to retry kinit [root@dhcp129-184 ~]# kinit -X X509_user_identity=PKCS11:module_name=/usr/lib64/opensc-pkcs11.so demosc1 demosc1 (OpenSC Card) PIN: kinit: Certificate mismatch while getting initial credentials 2017-06-07 11:12:24 MDT # IN /var/log/krb5kdc.log: Jun 07 13:12:24 auto-hv-02-guest08.testrelm.test krb5kdc[6840](info): Got cert filter [(ipacertmapdata=X509:<I>O=TESTRELM.TEST,CN=Certificate Authority<S>O=TESTRELM.TEST,CN=demosc1)] # ^^ worker2 gets the new filter as expected which is why the second kinit failed. ### Now we change the rule again and will watch for worker2 results to see if it changes (should not at first) [root@dhcp129-184 ~]# kdestroy -A ; echo Secret123|kinit admin Password for admin@TESTRELM.TEST: 2017-06-07 11:12:38 MDT [root@dhcp129-184 ~]# ipa certmaprule-del testrelm_certmapdata ---------------------------------------------------------------- Deleted Certificate Identity Mapping Rule "testrelm_certmapdata" ---------------------------------------------------------------- 2017-06-07 11:12:42 MDT [root@dhcp129-184 ~]# ipa certmaprule-add testrelm_certificate \ > --maprule='(userCertificate;binary={cert!bin})' \ > --matchrule='<ISSUER>CN=Certificate Authority,O=TESTRELM.TEST' -------------------------------------------------------------- Added Certificate Identity Mapping Rule "testrelm_certificate" -------------------------------------------------------------- Rule name: testrelm_certificate Mapping rule: (userCertificate;binary={cert!bin}) Matching rule: <ISSUER>CN=Certificate Authority,O=TESTRELM.TEST Enabled: TRUE 2017-06-07 11:12:47 MDT [root@dhcp129-184 ~]# kinit -X X509_user_identity=PKCS11:module_name=/usr/lib64/opensc-pkcs11.so demosc1 demosc1 (OpenSC Card) PIN: 2017-06-07 11:12:55 MDT # IN /var/log/krb5kdc.log: Jun 07 13:12:55 auto-hv-02-guest08.testrelm.test krb5kdc[6839](info): Got cert filter [(userCertificate;binary=\30\82\04 # ^^ used worker1 so we have to try again [root@dhcp129-184 ~]# kinit -X X509_user_identity=PKCS11:module_name=/usr/lib64/opensc-pkcs11.so demosc1 demosc1 (OpenSC Card) PIN: kinit: Certificate mismatch while getting initial credentials 2017-06-07 11:13:02 MDT # IN /var/log/krb5kdc.log Jun 07 13:13:02 auto-hv-02-guest08.testrelm.test krb5kdc[6840](info): Got cert filter [(ipacertmapdata=X509:<I>O=TESTRELM.TEST,CN=Certificate Authority<S>O=TESTRELM.TEST,CN=demosc1)] # ^^ Used worker2 with old certmapdata filter instead of new cert one... # now will wait 5 minutes to see if this updates [root@dhcp129-184 ~]# sleep 300 2017-06-07 11:18:16 MDT [root@dhcp129-184 ~]# kinit -X X509_user_identity=PKCS11:module_name=/usr/lib64/opensc-pkcs11.so demosc1 demosc1 (OpenSC Card) PIN: 2017-06-07 11:18:30 MDT # IN /var/log/krb5kdc.log Jun 07 13:18:30 auto-hv-02-guest08.testrelm.test krb5kdc[6840](info): Got cert filter [(userCertificate;binary=\30\82\04 # ^^ and we see that worker2 has the new cert rule instead of the old certmapdata one.
Since the problem described in this bug report should be resolved in a recent advisory, it has been closed with a resolution of ERRATA. For information on the advisory, and where to find the updated files, follow the link below. If the solution does not work for you, open a new bug report. https://access.redhat.com/errata/RHBA-2017:2304