3 nightly tests using pki's nightly copr repo failed in ipa-replica-install, see PR #421, PR#623: - test_replication_layouts_TestLineTopologyWithCA: report, logs - test_replication_layouts_TestLineTopologyWithCAKRA: report, logs - test_replica_promotion.py::TestHiddenReplicaPromotion::test_replica_from_hidden: report, logs - test_replica_promotion.py::TestHiddenReplicaKRA: report, logs
test_replication_layouts_TestLineTopologyWithCA
test_replication_layouts_TestLineTopologyWithCAKRA
test_replica_promotion.py::TestHiddenReplicaPromotion::test_replica_from_hidden
test_replica_promotion.py::TestHiddenReplicaKRA
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)
Companion issue against dogtag: https://pagure.io/dogtagpki/issue/3213
Metadata Update from @frenaud: - Issue tagged with: tracker
The issue also happens on the master branch without the pki copr repo, see PR #552[testing_master_latest] with report
Fixed with pki 10.10.5. Green runs: - testing_master_previous: PR 780 - testing_master_latest: PR 779 - testing_master_pki: PR 777
Metadata Update from @frenaud: - Issue close_status updated to: fixed - Issue status updated to: Closed (was: Open)
Login to comment on this ticket.