search

pki-bot / pki-issues-final

0 stars 0 forks source link

FreeIPA nightly test failure (pki nightly) in a call to certbot register #2763

Open pki-bot opened 4 years ago

pki-bot commented 4 years ago

This issue was migrated from Pagure Issue #3214. Originally filed by frenaud (@flo-renaud) on 2020-09-29 12:45:46:

The nightly tests for FreeIPA fail in an ACME test when calling certbot register. See PR #439 that is using the copr repo @pki/master: pki-fedora/test_acme: report and logs.

Issue also logged on FreeIPA side as 8520

It looks like the schema for acme objects hcryptomilk't been loaded to the directory server:

/var/log/pki/pki-tomcat/acme/debug.log.gz contains:

020-09-28 13:23:41 [ajp-nio-127.0.0.1-8009-exec-2] INFO: Creating directory
2020-09-28 13:23:41 [ajp-nio-127.0.0.1-8009-exec-2] INFO: Directory:
{"newNonce":"https://ipa-ca.ipa.test/acme/new-nonce","newAccount":"https://ipa-ca.ipa.test/acme/new-account","newOrder":"https://ipa-ca.ipa.test/acme/new-order","revokeCert":"https://ipa-ca.ipa.test/acme/revoke-cert","meta":{"termsOfService":"https://www.dogtagpki.org/wiki/PKI_ACME_Responder","website":"https://www.dogtagpki.org","caaIdentities":["dogtagpki.org"],"externalAccountRequired":false}}
2020-09-28 13:23:45 [ajp-nio-127.0.0.1-8009-exec-3] INFO: Creating directory
2020-09-28 13:23:45 [ajp-nio-127.0.0.1-8009-exec-3] INFO: Directory:
{"newNonce":"https://ipa-ca.ipa.test/acme/new-nonce","newAccount":"https://ipa-ca.ipa.test/acme/new-account","newOrder":"https://ipa-ca.ipa.test/acme/new-order","revokeCert":"https://ipa-ca.ipa.test/acme/revoke-cert","meta":{"termsOfService":"https://www.dogtagpki.org/wiki/PKI_ACME_Responder","website":"https://www.dogtagpki.org","caaIdentities":["dogtagpki.org"],"externalAccountRequired":false}}
2020-09-28 13:23:45 [ajp-nio-127.0.0.1-8009-exec-4] INFO: Creating nonce
2020-09-28 13:23:45 [ajp-nio-127.0.0.1-8009-exec-4] INFO: LDAP: add acmeNonceId=0W5yUo_i4VHuP7mp2xusBQ,ou=nonces,ou=acme,o=ipaca
2020-09-28 13:23:46 [ajp-nio-127.0.0.1-8009-exec-4] SEVERE: Servlet.service() for servlet [ACME] in context with path [/acme] threw exception
org.jboss.resteasy.spi.UnhandledException: java.lang.Exception: LDAP add failed: netscape.ldap.LDAPException: error result (65); unknown object class "acmeNonce"

    at org.jboss.resteasy.core.ExceptionHandler.handleApplicationException(ExceptionHandler.java:78)
    at org.jboss.resteasy.core.ExceptionHandler.handleException(ExceptionHandler.java:222)
    at org.jboss.resteasy.core.SynchronousDispatcher.writeException(SynchronousDispatcher.java:179)
    at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:422)
    at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:213)
    at org.jboss.resteasy.plugins.server.servlet.ServletContainerDispatcher.service(ServletContainerDispatcher.java:228)
    at org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(HttpServletDispatcher.java:56)
    at org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(HttpServletDispatcher.java:51)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:741)
    at sun.reflect.GeneratedMethodAccessor42.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at org.apache.catalina.security.SecurityUtil$1.run(SecurityUtil.java:282)
    at org.apache.catalina.security.SecurityUtil$1.run(SecurityUtil.java:279)
    at java.security.AccessController.doPrivileged(Native Method)
    at javax.security.auth.Subject.doAsPrivileged(Subject.java:549)
    at org.apache.catalina.security.SecurityUtil.execute(SecurityUtil.java:314)
    at org.apache.catalina.security.SecurityUtil.doAsPrivilege(SecurityUtil.java:170)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:225)
    at org.apache.catalina.core.ApplicationFilterChain.access$000(ApplicationFilterChain.java:47)
    at org.apache.catalina.core.ApplicationFilterChain$1.run(ApplicationFilterChain.java:149)
    at org.apache.catalina.core.ApplicationFilterChain$1.run(ApplicationFilterChain.java:145)
    at java.security.AccessController.doPrivileged(Native Method)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:144)
    at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53)
    at sun.reflect.GeneratedMethodAccessor41.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at org.apache.catalina.security.SecurityUtil$1.run(SecurityUtil.java:282)
    at org.apache.catalina.security.SecurityUtil$1.run(SecurityUtil.java:279)
    at java.security.AccessController.doPrivileged(Native Method)
    at javax.security.auth.Subject.doAsPrivileged(Subject.java:549)
    at org.apache.catalina.security.SecurityUtil.execute(SecurityUtil.java:314)
    at org.apache.catalina.security.SecurityUtil.doAsPrivilege(SecurityUtil.java:253)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:191)
    at org.apache.catalina.core.ApplicationFilterChain.access$000(ApplicationFilterChain.java:47)
    at org.apache.catalina.core.ApplicationFilterChain$1.run(ApplicationFilterChain.java:149)
    at org.apache.catalina.core.ApplicationFilterChain$1.run(ApplicationFilterChain.java:145)
    at java.security.AccessController.doPrivileged(Native Method)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:144)
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:202)
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96)
    at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:541)
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:139)
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92)
    at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:690)
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:74)
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:343)
    at org.apache.coyote.ajp.AjpProcessor.service(AjpProcessor.java:431)
    at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65)
    at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:868)
    at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1590)
    at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
    at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.Exception: LDAP add failed: netscape.ldap.LDAPException: error result (65); unknown object class "acmeNonce"

    at org.dogtagpki.acme.database.LDAPDatabase.ldapAdd(LDAPDatabase.java:906)
    at org.dogtagpki.acme.database.LDAPDatabase.addNonce(LDAPDatabase.java:259)
    at org.dogtagpki.acme.server.ACMEEngine.createNonce(ACMEEngine.java:514)
    at org.dogtagpki.acme.server.ACMENewNonceService.createNonce(ACMENewNonceService.java:52)
    at org.dogtagpki.acme.server.ACMENewNonceService.headNewNonce(ACMENewNonceService.java:35)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:140)
    at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTarget(ResourceMethodInvoker.java:295)
    at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:249)
    at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:236)
    at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:406)
    ... 53 more
Caused by: netscape.ldap.LDAPException: error result (65); unknown object class "acmeNonce"

    at netscape.ldap.LDAPConnection.checkMsg(Unknown Source)
    at netscape.ldap.LDAPConnection.add(Unknown Source)
    at netscape.ldap.LDAPConnection.add(Unknown Source)
    at netscape.ldap.LDAPConnection.add(Unknown Source)
    at org.dogtagpki.acme.database.LDAPDatabase.ldapAdd(LDAPDatabase.java:904)

Note that the nightly tests using pki 10.9.4-1.fc32.noarch don't have the failure. The issue is consistently reproduced with pki-server-10.10.0-0.1.alpha1.20200925212028UTC.040b5657.fc32.noarch

pki-bot commented 4 years ago

Comment from edewata (@edewata) at 2020-09-29 12:53:02

Did IPA import the ACME schema as documented here? https://github.com/dogtagpki/pki/blob/master/docs/installation/acme/Configuring_ACME_Database.md

The acmeNonce is defined in this file: https://github.com/dogtagpki/pki/blob/master/base/acme/database/ds/schema.ldif#L62-L64

pki-bot commented 4 years ago

Comment from edewata (@edewata) at 2020-09-29 12:53:03

Metadata Update from @edewata: