#5581 Replica install with CA failed on 3rd server
Opened 8 years ago by mbasti. Modified 7 years ago

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

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

7 years ago

Login to comment on this ticket.

Metadata