dogtagpki

#3213 FreeIPA nightly tests failure when installing a CA replica (pki nightly)
Closed: migrated by dmoluguw. Opened by frenaud.

Closed: migrated
Reopen Issue

2 nightly tests using pki's nightly copr repo failed in ipa-replica-install, see PR #421:
- test_replication_layouts_TestLineTopologyWithCA: report, logs
- test_replication_layouts_TestLineTopologyWithCAKRA: report, logs

The replica installation fails in the pkispawn step with the following message:

Installation failed: Command failed: pki -d /etc/pki/pki-tomcat/alias -f /etc/pki/pki-tomcat/password.conf -U https://replica0.ipa.test:443 ca-range-request request --session 3460448776536667421 --output-format json --debug
Please check pkispawn logs in /var/log/pki/pki-ca-spawn.20200921215144.log

and we also see the following in the logs:

INFO: Requesting request range
INFO: HTTP request: POST /ca/admin/ca/updateNumberRange HTTP/1.1
INFO:   Content-Type: application/x-www-form-urlencoded
INFO:   Content-Length: 57
INFO:   Host: replica0.ipa.test:443
INFO:   Connection: Keep-Alive
INFO:   User-Agent: Apache-HttpClient/4.5.10 (Java/1.8.0_265)
INFO: HTTP response: HTTP/1.1 200 200
INFO:   Date: Mon, 21 Sep 2020 21:52:20 GMT
INFO:   Server: Apache/2.4.46 (Fedora) OpenSSL/1.1.1g mod_wsgi/4.6.8 Python/3.8 mod_auth_gssapi/1.6.1
INFO:   Content-Type: application/xml
INFO:   Content-Length: 174
INFO:   Keep-Alive: timeout=30, max=99
INFO:   Connection: Keep-Alive
FINE: Response: <?xml version="1.0" encoding="UTF-8" standalone="no"?><XMLResponse><Status>1</Status><Error>Error: Unable to update number range: Zero length BigInteger</Error></XMLResponse>
FINE: Status: 1
java.io.IOException: Error: Unable to update number range: Zero length BigInteger
    at com.netscape.certsrv.client.SubsystemClient.requestRange(SubsystemClient.java:133)
    at com.netscape.cmstools.range.RangeRequestCLI.execute(RangeRequestCLI.java:62)
    at org.dogtagpki.cli.CommandCLI.execute(CommandCLI.java:57)
    at org.dogtagpki.cli.CLI.execute(CLI.java:352)
    at org.dogtagpki.cli.CLI.execute(CLI.java:352)
    at com.netscape.cmstools.cli.SubsystemCLI.execute(SubsystemCLI.java:76)
    at org.dogtagpki.cli.CLI.execute(CLI.java:352)
    at com.netscape.cmstools.cli.MainCLI.execute(MainCLI.java:688)
    at com.netscape.cmstools.cli.MainCLI.main(MainCLI.java:724)
ERROR: CalledProcessError: Command '['pki', '-d', '/etc/pki/pki-tomcat/alias', '-f', '/etc/pki/pki-tomcat/password.conf', '-U', 'https://replica0.ipa.test:443', 'ca-range-request', 'request', '--session', '3460448776536667421', '--output-format', 'json', '--debug']' returned non-zero exit status 255.
  File "/usr/lib/python3.8/site-packages/pki/server/pkispawn.py", line 575, in main
    scriptlet.spawn(deployer)
  File "/usr/lib/python3.8/site-packages/pki/server/deployment/scriptlets/configuration.py", line 821, in spawn
    subsystem.update_ranges(master_url, deployer.install_token)
  File "/usr/lib/python3.8/site-packages/pki/server/subsystem.py", line 991, in update_ranges
    request_range = self.request_range(master_url, 'request', install_token)
  File "/usr/lib/python3.8/site-packages/pki/server/subsystem.py", line 983, in request_range
    output = subprocess.check_output(cmd)
  File "/usr/lib64/python3.8/subprocess.py", line 411, in check_output
    return run(*popenargs, stdout=PIPE, timeout=timeout, check=True,
  File "/usr/lib64/python3.8/subprocess.py", line 512, in run
    raise CalledProcessError(retcode, process.args,

The same error can be seen in the server used as source for the CA replication in /var/log/pki/pki-tomcat/ca/debug.2020-09-21.log.gz :

2020-09-21 21:52:21 [ajp-nio-127.0.0.1-8009-exec-5] INFO: UpdateNumberRange: Type: request
2020-09-21 21:52:21 [ajp-nio-127.0.0.1-8009-exec-5] INFO: UpdateNumberRange: Getting request repository
2020-09-21 21:52:21 [ajp-nio-127.0.0.1-8009-exec-5] INFO: UpdateNumberRange: dbs.endRequestNumber: 10000000
2020-09-21 21:52:21 [ajp-nio-127.0.0.1-8009-exec-5] INFO: UpdateNumberRange: dbs.requestCloneTransferNumber: 10000
2020-09-21 21:52:21 [ajp-nio-127.0.0.1-8009-exec-5] INFO: UpdateNumberRange: Begin number: 9990001
2020-09-21 21:52:21 [ajp-nio-127.0.0.1-8009-exec-5] INFO: Configured transfer size: 10000
2020-09-21 21:52:21 [ajp-nio-127.0.0.1-8009-exec-5] INFO: UpdateNumberRange: Current range: 9990003..10000000
2020-09-21 21:52:21 [ajp-nio-127.0.0.1-8009-exec-5] INFO: UpdateNumberRange: Size: 9998
2020-09-21 21:52:21 [ajp-nio-127.0.0.1-8009-exec-5] SEVERE: UpdateNumberRange: Unable to update number range: Zero length BigInteger
java.lang.NumberFormatException: Zero length BigInteger
    at java.math.BigInteger.<init>(BigInteger.java:420)
    at com.netscape.cms.servlet.csadmin.UpdateNumberRange.process(UpdateNumberRange.java:225)
    at com.netscape.cms.servlet.base.CMSServlet.service(CMSServlet.java:494)
    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 com.netscape.cms.tomcat.ExternalAuthenticationValve.invoke(ExternalAuthenticationValve.java:82)
    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)

Installed packages (full list here):
- pki-server-10.10.0-0.1.alpha1.20200921191621UTC.14caa1fe.fc32.noarch
- tomcat-9.0.36-1.fc32.noarch
- tomcatjss-7.5.0-1.20200917180556UTC.18249585.fc32.noarch
- jss-4.8.0-0.1.20200918204253UTC.6c40ee99.fc32.x86_64

Companion issue logged against FreeIPA: https://pagure.io/freeipa/issue/8509

Dogtag PKI is moving from Pagure issues to GitHub issues. This means that existing or new
issues will be reported and tracked through Dogtag PKI's GitHub Issue tracker.

This issue has been cloned to GitHub and is available here:
https://github.com/dogtagpki/pki/issues/3330

If you want to receive further updates on the issue, please navigate to the
GitHub issue and click on Subscribe button.

Thank you for understanding, and we apologize for any inconvenience.

Metadata Update from @dmoluguw:
- Issue close_status updated to: migrated
- Issue status updated to: Closed (was: Open)
Metadata
None
None
None
None
None
None
None
None
None
None
None
None
None
None
Static archive. pagure.io was sunset in 2026; this is a read-only snapshot.
Red Hat Logo

Fedora is sponsored by Red Hat. Learn more about the relationship between Red Hat and Fedora »

© Red Hat, Inc. and others.