During execution of DNSSEC test I received following error:
[ipa.ipatests.test_integration.host.Host.replica2.cmd19] [3/23]: setting up initial replication [ipa.ipatests.test_integration.host.Host.replica2.cmd19] Starting replication, please wait until this has completed. Update in progress, 4 seconds elapsedost.replica2.cmd19] [ipa.ipatests.test_integration.host.Host.replica2.cmd19] Update succeeded [ipa.ipatests.test_integration.host.Host.replica2.cmd19] [ipa.ipatests.test_integration.host.Host.replica2.cmd19] [4/23]: creating installation admin user [ipa.ipatests.test_integration.host.Host.replica2.cmd19] [5/23]: setting up certificate server [ipa.ipatests.test_integration.host.Host.replica2.cmd19] ipa.ipaserver.install.cainstance.CAInstance: CRITICAL Failed to configure CA instance: Command '/usr/sbin/pkispawn -s CA -f /tmp/tmpVSfVqa' returned non-zero exit status 1 [ipa.ipatests.test_integration.host.Host.replica2.cmd19] ipa.ipaserver.install.cainstance.CAInstance: CRITICAL See the installation logs and the following files/directories for more information: [ipa.ipatests.test_integration.host.Host.replica2.cmd19] ipa.ipaserver.install.cainstance.CAInstance: CRITICAL /var/log/pki/pki-tomcat [ipa.ipatests.test_integration.host.Host.replica2.cmd19] [error] RuntimeError: CA configuration failed. [ipa.ipatests.test_integration.host.Host.replica2.cmd19] ipa.ipapython.install.cli.install_tool(Replica): ERROR CA configuration failed. [ipa.ipatests.test_integration.host.Host.replica2.cmd19] ipa.ipapython.install.cli.install_tool(Replica): ERROR The ipa-replica-install command failed. See /var/log/ipareplica-install.log for more information [ipa.ipatests.test_integration.host.Host.replica2.cmd19] Your system may be partly configured. [ipa.ipatests.test_integration.host.Host.replica2.cmd19] Run /usr/sbin/ipa-server-install --uninstall to clean up. [ipa.ipatests.test_integration.host.Host.replica2.cmd19] [ipa.ipatests.test_integration.host.Host.replica2.cmd19] Exit code: 1
All servers have CA installed.
pkispwan log:
2016-01-06 16:01:26 pkispawn : INFO ....... constructing PKI configuration data. 2016-01-06 16:01:26 pkispawn : INFO ....... configuring PKI configuration data. 2016-01-06 16:01:30 pkispawn : ERROR ....... Exception from Java Configuration Servlet: 500 Server Error: Internal Server Error for url: https://replica2.ipa.test:8443/ca/rest/installer/configure 2016-01-06 16:01:30 pkispawn : ERROR ....... ParseError: not well-formed (invalid token): line 1, column 0: {"Attributes":{"Attribute":[]},"ClassName":"com.netscape.certsrv.base.PKIException","Code":500,"Message":"Failed to obtain installation token from security domain: com.netscape.certsrv.base.UnauthorizedException: Access denied."} 2016-01-06 16:01:30 pkispawn : DEBUG ....... Error Type: ParseError 2016-01-06 16:01:30 pkispawn : DEBUG ....... Error Message: not well-formed (invalid token): line 1, column 0 2016-01-06 16:01:30 pkispawn : DEBUG ....... File "/usr/sbin/pkispawn", line 597, in main rv = instance.spawn(deployer) File "/usr/lib/python2.7/site-packages/pki/server/deployment/scriptlets/configuration.py", line 116, in spawn json.dumps(data, cls=pki.encoder.CustomTypeEncoder)) File "/usr/lib/python2.7/site-packages/pki/server/deployment/pkihelper.py", line 3872, in configure_pki_data root = ET.fromstring(e.response.text) File "/usr/lib64/python2.7/xml/etree/ElementTree.py", line 1300, in XML parser.feed(text) File "/usr/lib64/python2.7/xml/etree/ElementTree.py", line 1642, in feed self._raiseerror(v) File "/usr/lib64/python2.7/xml/etree/ElementTree.py", line 1506, in _raiseerror raise err
I was able to reproduce it again with different test, it is not reproducible always.
More details:
2016-01-14 17:32:23 pkispawn : DEBUG ........... No connection - server may still be down 2016-01-14 17:32:23 pkispawn : DEBUG ........... No connection - exception thrown: HTTPSConnectionPool(host='replica3.ipa.test', port=8443): Max retries exceeded with url: /ca/admin/ca/getStatus (Caused by NewConnectionError('<requests.packages.urllib3.connection.VerifiedHTTPSConnection object at 0x7fd18bc9ac90>: Failed to establish a new connection: [Errno 111] Connection refused',)) 2016-01-14 17:32:24 pkispawn : DEBUG ........... No connection - server may still be down 2016-01-14 17:32:24 pkispawn : DEBUG ........... No connection - exception thrown: HTTPSConnectionPool(host='replica3.ipa.test', port=8443): Max retries exceeded with url: /ca/admin/ca/getStatus (Caused by NewConnectionError('<requests.packages.urllib3.connection.VerifiedHTTPSConnection object at 0x7fd18bc9ac50>: Failed to establish a new connection: [Errno 111] Connection refused',)) 2016-01-14 17:32:32 pkispawn : DEBUG ........... <?xml version="1.0" encoding="UTF-8" standalone="no"?><XMLResponse><State>0</State><Type>CA</Type><Status>running</Status><Version>10.2.6-13.fc23</Version></XMLResponse> 2016-01-14 17:32:33 pkispawn : INFO ....... constructing PKI configuration data. 2016-01-14 17:32:33 pkispawn : INFO ....... configuring PKI configuration data. 2016-01-14 17:32:37 pkispawn : ERROR ....... Exception from Java Configuration Servlet: 500 Server Error: Internal Server Error for url: https://replica3.ipa.test:8443/ca/rest/installer/configure 2016-01-14 17:32:37 pkispawn : ERROR ....... ParseError: not well-formed (invalid token): line 1, column 0: {"Attributes":{"Attribute":[]},"ClassName":"com.netscape.certsrv.base.PKIException","Code":500,"Message":"Failed to obtain installation token from security domain: com.netscape.certsrv.base.UnauthorizedException: Access denied."} 2016-01-14 17:32:37 pkispawn : DEBUG ....... Error Type: ParseError 2016-01-14 17:32:37 pkispawn : DEBUG ....... Error Message: not well-formed (invalid token): line 1, column 0 2016-01-14 17:32:37 pkispawn : DEBUG ....... File "/usr/sbin/pkispawn", line 597, in main rv = instance.spawn(deployer) File "/usr/lib/python2.7/site-packages/pki/server/deployment/scriptlets/configuration.py", line 116, in spawn json.dumps(data, cls=pki.encoder.CustomTypeEncoder)) File "/usr/lib/python2.7/site-packages/pki/server/deployment/pkihelper.py", line 3872, in configure_pki_data root = ET.fromstring(e.response.text) File "/usr/lib64/python2.7/xml/etree/ElementTree.py", line 1300, in XML parser.feed(text) File "/usr/lib64/python2.7/xml/etree/ElementTree.py", line 1642, in feed self._raiseerror(v) File "/usr/lib64/python2.7/xml/etree/ElementTree.py", line 1506, in _raiseerror raise err
is it still an issue?
I haven't been able to reproduce it for long time, but I'm still keeping eye on tests.
I was able to reproduce it again, but now with different error.
2016-03-11 11:41:04 pkispawn : INFO ....... executing 'systemctl start pki-tomcatd@pki-tomcat.service' 2016-03-11 11:41:04 pkispawn : DEBUG ........... No connection - server may still be down 2016-03-11 11:41:04 pkispawn : DEBUG ........... No connection - exception thrown: HTTPSConnectionPool(host='replica2.ipa.test', port=8443): Max retries exceeded with url: /ca/admin/ca/getStatus (Caused by NewConnectionError('<requests.packages.urllib3.connection.VerifiedHTTPSConnection object at 0x7f472d307650>: Failed to establish a new connection: [Errno 111] Connection refused',)) 2016-03-11 11:41:05 pkispawn : DEBUG ........... No connection - server may still be down 2016-03-11 11:41:05 pkispawn : DEBUG ........... No connection - exception thrown: HTTPSConnectionPool(host='replica2.ipa.test', port=8443): Max retries exceeded with url: /ca/admin/ca/getStatus (Caused by NewConnectionError('<requests.packages.urllib3.connection.VerifiedHTTPSConnection object at 0x7f472d307610>: Failed to establish a new connection: [Errno 111] Connection refused',)) 2016-03-11 11:41:12 pkispawn : DEBUG ........... <?xml version="1.0" encoding="UTF-8" standalone="no"?><XMLResponse><State>0</State><Type>CA</Type><Status>running</Status><Version>10.2.6-15.fc23</Version></XMLResponse> 2016-03-11 11:41:13 pkispawn : INFO ....... constructing PKI configuration data. 2016-03-11 11:41:13 pkispawn : INFO ....... configuring PKI configuration data. 2016-03-11 11:41:57 pkispawn : ERROR ....... Exception from Java Configuration Servlet: 500 Server Error: Internal Server Error for url: https://replica2.ipa.test:8443/ca/rest/installer/configure 2016-03-11 11:41:57 pkispawn : ERROR ....... ParseError: not well-formed (invalid token): line 1, column 0: {"Attributes":{"Attribute":[]},"ClassName":"com.netscape.certsrv.base.PKIException","Code":500,"Message":"Error in populating database: java.io.IOException: Failed to setup the replication for cloning."} 2016-03-11 11:41:57 pkispawn : DEBUG ....... Error Type: ParseError 2016-03-11 11:41:57 pkispawn : DEBUG ....... Error Message: not well-formed (invalid token): line 1, column 0 2016-03-11 11:41:57 pkispawn : DEBUG ....... File "/usr/sbin/pkispawn", line 597, in main rv = instance.spawn(deployer) File "/usr/lib/python2.7/site-packages/pki/server/deployment/scriptlets/configuration.py", line 246, in spawn json.dumps(data, cls=pki.encoder.CustomTypeEncoder)) File "/usr/lib/python2.7/site-packages/pki/server/deployment/pkihelper.py", line 3863, in configure_pki_data root = ET.fromstring(e.response.text) File "/usr/lib64/python2.7/xml/etree/ElementTree.py", line 1300, in XML parser.feed(text) File "/usr/lib64/python2.7/xml/etree/ElementTree.py", line 1642, in feed self._raiseerror(v) File "/usr/lib64/python2.7/xml/etree/ElementTree.py", line 1506, in _raiseerror raise err
dogtag version: pki-ca-10.2.6-15.fc23.noarch
DS error log
[11/Mar/2016:11:41:20 +0000] ipa-topology-plugin - ipa_topo_be_state_change - backend ipaca is coming online; checking domain level and init shared topology [11/Mar/2016:11:41:20 +0000] - Skipping CoS Definition cn=Password Policy,cn=accounts,dc=ipa,dc=test--no CoS Templates found, which should be added before the CoS Definition. [11/Mar/2016:11:41:55 +0000] ipa-topology-plugin - ipa_topo_be_state_changebackend ipaca is going offline; inactivate plugin [11/Mar/2016:11:41:55 +0000] NSMMReplicationPlugin - multimaster_be_state_change: replica o=ipaca is going offline; disabling replication [11/Mar/2016:11:41:56 +0000] NSMMReplicationPlugin - agmt="cn=cloneAgreement1-replica2.ipa.test-pki-tomcat" (master:389): The remote replica has a different database generation ID than the local database. You may have to reinitialize the remote replica, or the local replica. [11/Mar/2016:11:41:56 +0000] - Skipping CoS Definition cn=Password Policy,cn=accounts,dc=ipa,dc=test--no CoS Templates found, which should be added before the CoS Definition. [11/Mar/2016:11:41:56 +0000] - WARNING: Import is running with nsslapd-db-private-import-mem on; No other process is allowed to access the database
CA debug log
[11/Mar/2016:11:41:55][http-bio-8443-exec-3]: ConfigurationUtils: setupReplication: replicadn=cn=replica,cn="o=ipaca",cn=mapping tree,cn=config [11/Mar/2016:11:41:55][http-bio-8443-exec-3]: createReplicationManager: containing ou already exists [11/Mar/2016:11:41:55][http-bio-8443-exec-3]: createReplicationManager: Successfully created Replication Manager [11/Mar/2016:11:41:55][http-bio-8443-exec-3]: createReplicationManager: Successfully created Replication Manager [11/Mar/2016:11:41:55][http-bio-8443-exec-3]: getInstanceDir: DN for storing nsslapd-directory: cn=config,cn=ldbm database,cn=plugins,cn=config [11/Mar/2016:11:41:55][http-bio-8443-exec-3]: getInstanceDir: attribute name: nsslapd-directory [11/Mar/2016:11:41:55][http-bio-8443-exec-3]: getInstanceDir: instanceDir=/var/lib/dirsrv/slapd-IPA-TEST/db [11/Mar/2016:11:41:55][http-bio-8443-exec-3]: createChangeLog: Changelog entry has already used [11/Mar/2016:11:41:55][http-bio-8443-exec-3]: getInstanceDir: DN for storing nsslapd-directory: cn=config,cn=ldbm database,cn=plugins,cn=config [11/Mar/2016:11:41:55][http-bio-8443-exec-3]: getInstanceDir: attribute name: nsslapd-directory [11/Mar/2016:11:41:55][http-bio-8443-exec-3]: getInstanceDir: instanceDir=/var/lib/dirsrv/slapd-IPA-TEST/db [11/Mar/2016:11:41:55][http-bio-8443-exec-3]: createChangeLog: Changelog entry has already used [11/Mar/2016:11:41:55][http-bio-8443-exec-3]: enableReplication: replicadn: cn=replica,cn="o=ipaca",cn=mapping tree,cn=config [11/Mar/2016:11:41:55][http-bio-8443-exec-3]: enableReplication: Successfully create cn=replica,cn="o=ipaca",cn=mapping tree,cn=config entry. [11/Mar/2016:11:41:55][http-bio-8443-exec-3]: enableReplication: replicadn: cn=replica,cn="o=ipaca",cn=mapping tree,cn=config [11/Mar/2016:11:41:55][http-bio-8443-exec-3]: enableReplication: Successfully create cn=replica,cn="o=ipaca",cn=mapping tree,cn=config entry. [11/Mar/2016:11:41:55][http-bio-8443-exec-3]: setupReplication: Finished enabling replication [11/Mar/2016:11:41:55][http-bio-8443-exec-3]: createReplicationAgreement: dn: cn=masterAgreement1-replica2.ipa.test-pki-tomcat,cn=replica,cn="o=ipaca",cn=mapping tree,cn=config [11/Mar/2016:11:41:55][http-bio-8443-exec-3]: About to set description attr to masterAgreement1-replica2.ipa.test-pki-tomcat [11/Mar/2016:11:41:55][http-bio-8443-exec-3]: createReplicationAgreement: Successfully create replication agreement masterAgreement1-replica2.ipa.test-pki-tomcat [11/Mar/2016:11:41:55][http-bio-8443-exec-3]: createReplicationAgreement: dn: cn=cloneAgreement1-replica2.ipa.test-pki-tomcat,cn=replica,cn="o=ipaca",cn=mapping tree,cn=config [11/Mar/2016:11:41:55][http-bio-8443-exec-3]: About to set description attr to cloneAgreement1-replica2.ipa.test-pki-tomcat [11/Mar/2016:11:41:55][http-bio-8443-exec-3]: createReplicationAgreement: Successfully create replication agreement cloneAgreement1-replica2.ipa.test-pki-tomcat [11/Mar/2016:11:41:55][http-bio-8443-exec-3]: initializeConsumer: initializeConsumer dn: cn=masterAgreement1-replica2.ipa.test-pki-tomcat,cn=replica,cn="o=ipaca",cn=mapping tree,cn=config [11/Mar/2016:11:41:55][http-bio-8443-exec-3]: initializeConsumer: initializeConsumer host: master.ipa.test port: 636 [11/Mar/2016:11:41:55][http-bio-8443-exec-3]: initializeConsumer: Successfully initialized consumer [11/Mar/2016:11:41:55][http-bio-8443-exec-3]: replicationDone: dn: cn=masterAgreement1-replica2.ipa.test-pki-tomcat,cn=replica,cn="o=ipaca",cn=mapping tree,cn=config [11/Mar/2016:11:41:55][http-bio-8443-exec-3]: setupReplication: Waiting for replication to complete [11/Mar/2016:11:41:56][http-bio-8443-exec-3]: replicationDone: dn: cn=masterAgreement1-replica2.ipa.test-pki-tomcat,cn=replica,cn="o=ipaca",cn=mapping tree,cn=config [11/Mar/2016:11:41:56][http-bio-8443-exec-3]: setupReplication: Waiting for replication to complete [11/Mar/2016:11:41:57][http-bio-8443-exec-3]: replicationDone: dn: cn=masterAgreement1-replica2.ipa.test-pki-tomcat,cn=replica,cn="o=ipaca",cn=mapping tree,cn=config [11/Mar/2016:11:41:57][http-bio-8443-exec-3]: replicationStatus: dn: cn=masterAgreement1-replica2.ipa.test-pki-tomcat,cn=replica,cn="o=ipaca",cn=mapping tree,cn=config [11/Mar/2016:11:41:57][http-bio-8443-exec-3]: setupReplication: consumer initialization failed. -11 connection error: Unknown connection error (-11) - Total update aborted [11/Mar/2016:11:41:57][http-bio-8443-exec-3]: setupReplication: java.io.IOException: consumer initialization failed. -11 connection error: Unknown connection error (-11) - Total update aborted [11/Mar/2016:11:41:57][http-bio-8443-exec-3]: Error in populating database: java.io.IOException: Failed to setup the replication for cloning. [11/Mar/2016:11:46:02][Finalizer]: Destroying LdapBoundConnFactory(ConfigurationUtils) [11/Mar/2016:11:46:02][Finalizer]: Cannot reset factory: connections not all returned [11/Mar/2016:11:46:02][Finalizer]: Destroying LdapBoundConnFactory(ConfigurationUtils) [11/Mar/2016:11:46:02][Finalizer]: Cannot reset factory: connections not all returned
Metadata Update from @mbasti: - Issue assigned to someone - Issue set to the milestone: FreeIPA 4.5 backlog
Login to comment on this ticket.