Bug 2164348
| Summary: | Better catch of the IPA web UI event "IPA Error 4301:CertificateOperationError", and IPA httpd error CertificateOperationError | |||
|---|---|---|---|---|
| Product: | Red Hat Enterprise Linux 8 | Reporter: | Chris Kelley <ckelley> | |
| Component: | ipa | Assignee: | Rob Crittenden <rcritten> | |
| Status: | CLOSED ERRATA | QA Contact: | Mohammad Rizwan <myusuf> | |
| Severity: | medium | Docs Contact: | ||
| Priority: | urgent | |||
| Version: | 8.3 | CC: | ademir.ladeira, amayberr, arajendr, bugzilla-pkiqe, cilmar, ckelley, frenaud, ftrivino, gkaihoro, msauton, myusuf, negativo17, rcritten, rjeffman, sumenon, tscherf | |
| Target Milestone: | beta | Keywords: | Triaged | |
| Target Release: | --- | |||
| Hardware: | All | |||
| OS: | Unspecified | |||
| Whiteboard: | ||||
| Fixed In Version: | ipa-4.9.12-2.module+el8.9.0+18921+013c0de2 | Doc Type: | No Doc Update | |
| Doc Text: | Story Points: | --- | ||
| Clone Of: | 1959057 | |||
| : | 2192625 (view as bug list) | Environment: | ||
| Last Closed: | 2023-11-14 15:32:50 UTC | Type: | Bug | |
| Regression: | --- | Mount Type: | --- | |
| Documentation: | --- | CRM: | ||
| Verified Versions: | Category: | --- | ||
| oVirt Team: | --- | RHEL 7.3 requirements from Atomic Host: | ||
| Cloudforms Team: | --- | Target Upstream Version: | ||
| Embargoed: | ||||
| Bug Depends On: | 1959057 | |||
| Bug Blocks: | 2164347, 2192625 | |||
flo do you remember how you reproduced this? (In reply to Rob Crittenden from comment #3) > flo do you remember how you reproduced this? Yes, I defined a sizelimit for uid=pkidbuser. The trick is to pick something big enough that allows pki to start (pkidbuser is performing searches for the certificate profiles for instance, and there are ~90 entries, so I picked nsSizeLimit= 100). # ldapmodify -D cn=directory\ manager -w Secret123 dn: uid=pkidbuser,ou=people,o=ipaca changetype: modify add: nssizelimit nssizelimit: 100 # ipactl restart (restart pki is needed to re-establish a new connection between pki and 389ds and take into account the new sizelimit for uid=pkidbuser) # ipa cert-find (if there are < 100 certificates, should succeed) Create enough certificates to reach the limit # ipa cert-find ipa: ERROR: Certificate operation cannot be completed: Unable to communicate with CMS (500) The logs in /var/log/pki/pki-tomcat/ca/debug.$DATE.log show all the certs returned up to 100 and then the failure: 2023-04-25 06:51:31 [ajp-nio-0:0:0:0:0:0:0:1-8009-exec-1] INFO: Searching for certificates 2023-04-25 06:51:31 [ajp-nio-0:0:0:0:0:0:0:1-8009-exec-1] INFO: PKIService: Request class: CertSearchRequest 2023-04-25 06:51:31 [ajp-nio-0:0:0:0:0:0:0:1-8009-exec-1] INFO: PKIService: Request format: application/xml 2023-04-25 06:51:31 [ajp-nio-0:0:0:0:0:0:0:1-8009-exec-1] INFO: PKIService: XML request: <?xml version='1.0' encoding='UTF-8'?> <CertSearchRequest><serialNumberRangeInUse>true</serialNumberRangeInUse><subjectInUse>false</subjectInUse><matchExactly>false</matchExactly><revokedByInUse>false</revokedByInUse><revokedOnInUse>false</revokedOnInUse><revocationReasonInUse>false</revocationReasonInUse><issuedByInUse>false</issuedByInUse><issuedOnInUse>false</issuedOnInUse><validNotBeforeInUse>false</validNotBeforeInUse><validNotAfterInUse>false</validNotAfterInUse><validityLengthInUse>false</validityLengthInUse><certTypeInUse>false</certTypeInUse></CertSearchRequest> 2023-04-25 06:51:31 [ajp-nio-0:0:0:0:0:0:0:1-8009-exec-1] INFO: Search filter: (certstatus=*) 2023-04-25 06:51:31 [ajp-nio-0:0:0:0:0:0:0:1-8009-exec-1] INFO: DBVirtualList: Searching ou=certificateRepository, ou=ca,o=ipaca 2023-04-25 06:51:31 [ajp-nio-0:0:0:0:0:0:0:1-8009-exec-1] INFO: DBVirtualList: filter: (certStatus=*) 2023-04-25 06:51:31 [ajp-nio-0:0:0:0:0:0:0:1-8009-exec-1] INFO: DBVirtualList: dn: cn=101,ou=certificateRepository,ou=ca,o=ipaca 2023-04-25 06:51:31 [ajp-nio-0:0:0:0:0:0:0:1-8009-exec-1] INFO: Search results: 101 2023-04-25 06:51:31 [ajp-nio-0:0:0:0:0:0:0:1-8009-exec-1] INFO: DBVirtualList: Searching ou=certificateRepository, ou=ca,o=ipaca 2023-04-25 06:51:31 [ajp-nio-0:0:0:0:0:0:0:1-8009-exec-1] INFO: DBVirtualList: filter: (certStatus=*) 2023-04-25 06:51:31 [ajp-nio-0:0:0:0:0:0:0:1-8009-exec-1] INFO: DBVirtualList: dn: cn=1,ou=certificateRepository,ou=ca,o=ipaca ... 2023-04-25 06:51:31 [ajp-nio-0:0:0:0:0:0:0:1-8009-exec-1] INFO: DBVirtualList: dn: cn=100,ou=certificateRepository,ou=ca,o=ipaca 2023-04-25 06:51:31 [ajp-nio-0:0:0:0:0:0:0:1-8009-exec-1] SEVERE: Operation Error - class netscape.ldap.LDAPException cannot be cast to class netscape.ldap.LDAPEntry (netscape.ldap.LDAPException and netscape.ldap.LDAPEntry are in unnamed module of loader java.net.URLClassLoader @5e8c92f4) java.lang.ClassCastException: class netscape.ldap.LDAPException cannot be cast to class netscape.ldap.LDAPEntry (netscape.ldap.LDAPException and netscape.ldap.LDAPEntry are in unnamed module of loader java.net.URLClassLoader @5e8c92f4) The new message will be (proposed): ipa: ERROR: Certificate operation cannot be completed: Unable to search for certificates (500) We get no indication of the reason for the search failure. I suppose this is message is better in that it doesn't imply that the CA is not available at all. Fixed upstream master: https://pagure.io/freeipa/c/9e80616401fe878f4db9dcd5b6188c0b2039db53 Fixed upstream ipa-4-9: https://pagure.io/freeipa/c/b9b268e5ed497400b3525b0eec95e2ae4f039526 Fixed upstream ipa-4-10: https://pagure.io/freeipa/c/81a6b9ad2d42fecdd94e17fa7c888bbdea2daf3c version: ipa-server-4.9.12-2.module+el8.9.0+18921+013c0de2.x86_64 Steps: https://bugzilla.redhat.com/show_bug.cgi?id=2164348#c4 Actual result: when number of cert > nssizelimit [root@master ~]# ldapmodify -D cn=Directory\ Manager -w Secret123 dn: uid=pkidbuser,ou=people,o=ipaca changetype: modify add: nssizelimit nssizelimit: 100 modifying entry "uid=pkidbuser,ou=people,o=ipaca" ^C [root@master ~]# ipactl restart Restarting Directory Service Restarting krb5kdc Service Restarting kadmin Service Restarting named Service Restarting httpd Service Restarting ipa-custodia Service Restarting pki-tomcatd Service Restarting ipa-otpd Service Restarting ipa-dnskeysyncd Service ipa: INFO: The ipactl command was successful [root@master ~]# ipa cert-find ipa: ERROR: Certificate operation cannot be completed: Unable to search for certificates (500) [root@master ~]# [root@master ~]# when number of cert < nssizelimit: [root@master ~]# ldapmodify -D cn=Directory\ Manager -w Secret123 dn: uid=pkidbuser,ou=people,o=ipaca changetype: modify replace: nssizelimit nssizelimit: 200 modifying entry "uid=pkidbuser,ou=people,o=ipaca" ^C [root@master ~]# [root@master ~]# ipactl restart Restarting Directory Service Restarting krb5kdc Service Restarting kadmin Service Restarting named Service Restarting httpd Service Restarting ipa-custodia Service Restarting pki-tomcatd Service Restarting ipa-otpd Service Restarting ipa-dnskeysyncd Service ipa: INFO: The ipactl command was successful [root@master ~]# [root@master ~]# [root@master ~]# ipa cert-find ------------------------ 100 certificates matched ------------------------ [..] Issuing CA: ipa Subject: CN=tuser90,O=TESTRELM.TEST Issuer: CN=Certificate Authority,O=TESTRELM.TEST Not Before: Thu Jun 08 07:13:13 2023 UTC Not After: Sun Jun 08 07:13:13 2025 UTC Serial number: 100 Serial number (hex): 0x64 Status: VALID Revoked: False ------------------------------ Number of entries returned 100 ------------------------------ [root@master ~]# 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 (idm:client and idm:DL1 bug fix and enhancement update), 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-2023:6977 |
When a user is doing ipa cert-find, the operation triggers a search in PKI (through an HTTP POST ca/rest/certs/search?size=2147483647). PKI performs a LDAP search with VLV that can return err=4 (sizelimit exceeded) but does not properly handle this case. When LDAP returns err=4, PKI tries to decode the result as a LDAPEntry even though it received a netscape.ldap.LDAPException. This triggers the following error in ca/debug logs: 2023-02-02 11:34:30 [ajp-nio-0:0:0:0:0:0:0:1-8009-exec-7] SEVERE: Operation Error - netscape.ldap.LDAPException cannot be cast to netscape.ldap.LDAPEntry java.lang.ClassCastException: netscape.ldap.LDAPException cannot be cast to netscape.ldap.LDAPEntry at com.netscape.cmscore.dbs.DBVirtualList.getEntries(DBVirtualList.java:482) at com.netscape.cmscore.dbs.DBVirtualList.getPage(DBVirtualList.java:617) at com.netscape.cmscore.dbs.DBVirtualList.getPage(DBVirtualList.java:609) at com.netscape.cmscore.dbs.DBVirtualList.getElementAt(DBVirtualList.java:763) at com.netscape.cmscore.dbs.CertRecordList.getCertRecord(CertRecordList.java:142) at org.dogtagpki.server.ca.rest.CertService.searchCerts(CertService.java:503) The data returned to the POST operation (=received by IPA) is then the following: status, _, data = dogtag.https_request(...) status = 500 data = b'<?xml version="1.0" encoding="UTF-8" standalone="yes"?><PKIException><Attributes/><ClassName>com.netscape.certsrv.base.PKIException</ClassName><Code>500</Code><Message>Unable to search for certificates: java.lang.ClassCastException: netscape.ldap.LDAPException cannot be cast to netscape.ldap.LDAPEntry</Message></PKIException>' IPA checks the status and if != 200 raises an Exception with the information from the status only: if status != 200: self.raise_certificate_operation_error('find', detail=status) IPA could parse the output from the data field and include this information in the exception, and call instead self.raise_certificate_operation_error('find',err_msg=<to be filled>, detail=status). The err_msg would then be logged instead of "Unable to communicate with CMS" which is not specific enough. But IMO PKI should fix the Exception on its side and return a clean error message, that could be easily understood by the user.