Hi everybody,

While preparing the replica files on the latest IPA master I've noticed the following error messages in the dirsrv error log:


[19/Jun/2015:15:26:10 +0200] NSMMReplicationPlugin - agmt="cn=masterAgreement1-vm-244.idm.lab.eng.brq.redhat.com-pki-tomcat" (vm-244:389): Replication bind with SIMPLE auth failed: LDAP error -1 (Can't contact LDAP server) () [19/Jun/2015:15:26:10 +0200] - Entry "uid=admin,ou=people,o=ipaca" -- attribute "krbExtraData" not allowed [19/Jun/2015:15:26:13 +0200] slapi_ldap_bind - Error: could not send startTLS request: error -1 (Can't contact LDAP server) errno 0 (Success)

Though the stdout of the replica preparation reports success, when I later use the resulting gpg file to actually setup a replica the setup process fails with the following output:

Configuring Kerberos KDC (krb5kdc). Estimated time: 30 seconds
  [1/8]: adding sasl mappings to the directory
  [2/8]: configuring KDC
  [3/8]: creating a keytab for the directory
  [4/8]: creating a keytab for the machine
  [5/8]: adding the password extension to the directory
  [6/8]: enable GSSAPI for replication
[error] RuntimeError: One of the ldap service principals is missing. Replication agreement cannot be converted. Replication error message: Unable to acquire replicaLDAP error: No such object
Your system may be partly configured.
Run /usr/sbin/ipa-server-install --uninstall to clean up.

ipa.ipapython.install.cli.install_tool(Replica): ERROR One of the ldap service principals is missing. Replication agreement cannot be converted. Replication error message: Unable to acquire replicaLDAP error: No such object

The corresponding part of the ipareplica-install.log is attached

I've encountered this already twice. The strangest part is that I prepared 3 replicas simultaneously: 2 of them installed successfully and one - failed. All three replicas were launched from the same vm-template

--
Oleg Fayans
Quality Engineer
FreeIPA team
RedHat.

2015-06-19T13:01:36Z INFO Setting agreement cn=meTovm-069.idm.lab.eng.brq.redhat.com,cn=replica,cn=dc\=idm\,dc\=lab\,dc\=eng\,dc\=brq\,dc\=redhat\,dc\=com,cn=mapping tree,cn=config schedule to 2358-2359 0 to force synch
2015-06-19T13:01:37Z INFO Deleting schedule 2358-2359 0 from agreement cn=meTovm-069.idm.lab.eng.brq.redhat.com,cn=replica,cn=dc\=idm\,dc\=lab\,dc\=eng\,dc\=brq\,dc\=redhat\,dc\=com,cn=mapping tree,cn=config
2015-06-19T13:01:38Z INFO Replication Update in progress: FALSE: status: 32 Unable to acquire replicaLDAP error: No such object: start: 0: end: 0
2015-06-19T13:01:38Z INFO Getting ldap service principals for conversion: (krbprincipalname=ldap/vm-244.idm.lab.eng.brq.redhat....@idm.lab.eng.brq.redhat.com) and (krbprincipalname=ldap/vm-069.idm.lab.eng.brq.redhat....@idm.lab.eng.brq.redhat.com)
2015-06-19T13:01:38Z DEBUG Unable to find entry for (krbprincipalname=ldap/vm-244.idm.lab.eng.brq.redhat....@idm.lab.eng.brq.redhat.com) on vm-069.idm.lab.eng.brq.redhat.com:636
2015-06-19T13:01:38Z INFO Setting agreement cn=meTovm-069.idm.lab.eng.brq.redhat.com,cn=replica,cn=dc\=idm\,dc\=lab\,dc\=eng\,dc\=brq\,dc\=redhat\,dc\=com,cn=mapping tree,cn=config schedule to 2358-2359 0 to force synch
2015-06-19T13:01:39Z INFO Deleting schedule 2358-2359 0 from agreement cn=meTovm-069.idm.lab.eng.brq.redhat.com,cn=replica,cn=dc\=idm\,dc\=lab\,dc\=eng\,dc\=brq\,dc\=redhat\,dc\=com,cn=mapping tree,cn=config
2015-06-19T13:01:40Z INFO Replication Update in progress: FALSE: status: 32 Unable to acquire replicaLDAP error: No such object: start: 0: end: 0
2015-06-19T13:01:40Z INFO Getting ldap service principals for conversion: (krbprincipalname=ldap/vm-244.idm.lab.eng.brq.redhat....@idm.lab.eng.brq.redhat.com) and (krbprincipalname=ldap/vm-069.idm.lab.eng.brq.redhat....@idm.lab.eng.brq.redhat.com)
2015-06-19T13:01:40Z DEBUG Unable to find entry for (krbprincipalname=ldap/vm-244.idm.lab.eng.brq.redhat....@idm.lab.eng.brq.redhat.com) on vm-069.idm.lab.eng.brq.redhat.com:636
2015-06-19T13:01:40Z INFO Setting agreement cn=meTovm-069.idm.lab.eng.brq.redhat.com,cn=replica,cn=dc\=idm\,dc\=lab\,dc\=eng\,dc\=brq\,dc\=redhat\,dc\=com,cn=mapping tree,cn=config schedule to 2358-2359 0 to force synch
2015-06-19T13:01:41Z INFO Deleting schedule 2358-2359 0 from agreement cn=meTovm-069.idm.lab.eng.brq.redhat.com,cn=replica,cn=dc\=idm\,dc\=lab\,dc\=eng\,dc\=brq\,dc\=redhat\,dc\=com,cn=mapping tree,cn=config
2015-06-19T13:01:42Z INFO Replication Update in progress: FALSE: status: 32 Unable to acquire replicaLDAP error: No such object: start: 0: end: 0
2015-06-19T13:01:42Z INFO Getting ldap service principals for conversion: (krbprincipalname=ldap/vm-244.idm.lab.eng.brq.redhat....@idm.lab.eng.brq.redhat.com) and (krbprincipalname=ldap/vm-069.idm.lab.eng.brq.redhat....@idm.lab.eng.brq.redhat.com)
2015-06-19T13:01:42Z DEBUG Unable to find entry for (krbprincipalname=ldap/vm-244.idm.lab.eng.brq.redhat....@idm.lab.eng.brq.redhat.com) on vm-069.idm.lab.eng.brq.redhat.com:636
2015-06-19T13:01:42Z INFO Setting agreement cn=meTovm-069.idm.lab.eng.brq.redhat.com,cn=replica,cn=dc\=idm\,dc\=lab\,dc\=eng\,dc\=brq\,dc\=redhat\,dc\=com,cn=mapping tree,cn=config schedule to 2358-2359 0 to force synch
2015-06-19T13:01:43Z INFO Deleting schedule 2358-2359 0 from agreement cn=meTovm-069.idm.lab.eng.brq.redhat.com,cn=replica,cn=dc\=idm\,dc\=lab\,dc\=eng\,dc\=brq\,dc\=redhat\,dc\=com,cn=mapping tree,cn=config
2015-06-19T13:01:44Z INFO Replication Update in progress: FALSE: status: 32 Unable to acquire replicaLDAP error: No such object: start: 0: end: 0
2015-06-19T13:01:44Z INFO Getting ldap service principals for conversion: (krbprincipalname=ldap/vm-244.idm.lab.eng.brq.redhat....@idm.lab.eng.brq.redhat.com) and (krbprincipalname=ldap/vm-069.idm.lab.eng.brq.redhat....@idm.lab.eng.brq.redhat.com)
2015-06-19T13:01:44Z DEBUG Unable to find entry for (krbprincipalname=ldap/vm-244.idm.lab.eng.brq.redhat....@idm.lab.eng.brq.redhat.com) on vm-069.idm.lab.eng.brq.redhat.com:636
2015-06-19T13:01:44Z INFO Setting agreement cn=meTovm-069.idm.lab.eng.brq.redhat.com,cn=replica,cn=dc\=idm\,dc\=lab\,dc\=eng\,dc\=brq\,dc\=redhat\,dc\=com,cn=mapping tree,cn=config schedule to 2358-2359 0 to force synch
2015-06-19T13:01:46Z INFO Deleting schedule 2358-2359 0 from agreement cn=meTovm-069.idm.lab.eng.brq.redhat.com,cn=replica,cn=dc\=idm\,dc\=lab\,dc\=eng\,dc\=brq\,dc\=redhat\,dc\=com,cn=mapping tree,cn=config
2015-06-19T13:01:47Z INFO Replication Update in progress: FALSE: status: 32 Unable to acquire replicaLDAP error: No such object: start: 0: end: 0
2015-06-19T13:01:47Z INFO Getting ldap service principals for conversion: (krbprincipalname=ldap/vm-244.idm.lab.eng.brq.redhat....@idm.lab.eng.brq.redhat.com) and (krbprincipalname=ldap/vm-069.idm.lab.eng.brq.redhat....@idm.lab.eng.brq.redhat.com)
2015-06-19T13:01:47Z DEBUG Unable to find entry for (krbprincipalname=ldap/vm-244.idm.lab.eng.brq.redhat....@idm.lab.eng.brq.redhat.com) on vm-069.idm.lab.eng.brq.redhat.com:636
2015-06-19T13:01:47Z INFO Setting agreement cn=meTovm-069.idm.lab.eng.brq.redhat.com,cn=replica,cn=dc\=idm\,dc\=lab\,dc\=eng\,dc\=brq\,dc\=redhat\,dc\=com,cn=mapping tree,cn=config schedule to 2358-2359 0 to force synch
2015-06-19T13:01:48Z INFO Deleting schedule 2358-2359 0 from agreement cn=meTovm-069.idm.lab.eng.brq.redhat.com,cn=replica,cn=dc\=idm\,dc\=lab\,dc\=eng\,dc\=brq\,dc\=redhat\,dc\=com,cn=mapping tree,cn=config
2015-06-19T13:01:49Z INFO Replication Update in progress: FALSE: status: 32 Unable to acquire replicaLDAP error: No such object: start: 0: end: 0
2015-06-19T13:01:49Z INFO Getting ldap service principals for conversion: (krbprincipalname=ldap/vm-244.idm.lab.eng.brq.redhat....@idm.lab.eng.brq.redhat.com) and (krbprincipalname=ldap/vm-069.idm.lab.eng.brq.redhat....@idm.lab.eng.brq.redhat.com)
2015-06-19T13:01:50Z DEBUG Unable to find entry for (krbprincipalname=ldap/vm-244.idm.lab.eng.brq.redhat....@idm.lab.eng.brq.redhat.com) on vm-069.idm.lab.eng.brq.redhat.com:636
2015-06-19T13:01:50Z INFO Setting agreement cn=meTovm-069.idm.lab.eng.brq.redhat.com,cn=replica,cn=dc\=idm\,dc\=lab\,dc\=eng\,dc\=brq\,dc\=redhat\,dc\=com,cn=mapping tree,cn=config schedule to 2358-2359 0 to force synch
2015-06-19T13:01:51Z INFO Deleting schedule 2358-2359 0 from agreement cn=meTovm-069.idm.lab.eng.brq.redhat.com,cn=replica,cn=dc\=idm\,dc\=lab\,dc\=eng\,dc\=brq\,dc\=redhat\,dc\=com,cn=mapping tree,cn=config
2015-06-19T13:01:52Z INFO Replication Update in progress: FALSE: status: 32 Unable to acquire replicaLDAP error: No such object: start: 0: end: 0
2015-06-19T13:01:52Z INFO Getting ldap service principals for conversion: (krbprincipalname=ldap/vm-244.idm.lab.eng.brq.redhat....@idm.lab.eng.brq.redhat.com) and (krbprincipalname=ldap/vm-069.idm.lab.eng.brq.redhat....@idm.lab.eng.brq.redhat.com)
2015-06-19T13:01:52Z DEBUG Unable to find entry for (krbprincipalname=ldap/vm-244.idm.lab.eng.brq.redhat....@idm.lab.eng.brq.redhat.com) on vm-069.idm.lab.eng.brq.redhat.com:636
2015-06-19T13:01:52Z INFO Setting agreement cn=meTovm-069.idm.lab.eng.brq.redhat.com,cn=replica,cn=dc\=idm\,dc\=lab\,dc\=eng\,dc\=brq\,dc\=redhat\,dc\=com,cn=mapping tree,cn=config schedule to 2358-2359 0 to force synch
2015-06-19T13:01:53Z INFO Deleting schedule 2358-2359 0 from agreement cn=meTovm-069.idm.lab.eng.brq.redhat.com,cn=replica,cn=dc\=idm\,dc\=lab\,dc\=eng\,dc\=brq\,dc\=redhat\,dc\=com,cn=mapping tree,cn=config
2015-06-19T13:01:54Z INFO Replication Update in progress: FALSE: status: 32 Unable to acquire replicaLDAP error: No such object: start: 0: end: 0
2015-06-19T13:01:54Z INFO Getting ldap service principals for conversion: (krbprincipalname=ldap/vm-244.idm.lab.eng.brq.redhat....@idm.lab.eng.brq.redhat.com) and (krbprincipalname=ldap/vm-069.idm.lab.eng.brq.redhat....@idm.lab.eng.brq.redhat.com)
2015-06-19T13:01:54Z DEBUG Unable to find entry for (krbprincipalname=ldap/vm-244.idm.lab.eng.brq.redhat....@idm.lab.eng.brq.redhat.com) on vm-069.idm.lab.eng.brq.redhat.com:636
2015-06-19T13:01:54Z INFO Setting agreement cn=meTovm-069.idm.lab.eng.brq.redhat.com,cn=replica,cn=dc\=idm\,dc\=lab\,dc\=eng\,dc\=brq\,dc\=redhat\,dc\=com,cn=mapping tree,cn=config schedule to 2358-2359 0 to force synch
2015-06-19T13:01:55Z INFO Deleting schedule 2358-2359 0 from agreement cn=meTovm-069.idm.lab.eng.brq.redhat.com,cn=replica,cn=dc\=idm\,dc\=lab\,dc\=eng\,dc\=brq\,dc\=redhat\,dc\=com,cn=mapping tree,cn=config
2015-06-19T13:01:56Z INFO Replication Update in progress: FALSE: status: 32 Unable to acquire replicaLDAP error: No such object: start: 0: end: 0
2015-06-19T13:01:56Z DEBUG Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/ipaserver/install/service.py", line 389, in start_creation
    run_step(full_msg, method)
  File "/usr/lib/python2.7/site-packages/ipaserver/install/service.py", line 379, in run_step
    method()
  File "/usr/lib/python2.7/site-packages/ipaserver/install/krbinstance.py", line 438, in __convert_to_gssapi_replication
    r_bindpw=self.dm_password)
  File "/usr/lib/python2.7/site-packages/ipaserver/install/replication.py", line 1104, in convert_to_gssapi_replication
    self.gssapi_update_agreements(self.conn, r_conn)
  File "/usr/lib/python2.7/site-packages/ipaserver/install/replication.py", line 797, in gssapi_update_agreements
    self.setup_krb_princs_as_replica_binddns(a, b)
  File "/usr/lib/python2.7/site-packages/ipaserver/install/replication.py", line 767, in setup_krb_princs_as_replica_binddns
    (a_dn, b_dn) = self.get_replica_principal_dns(a, b, retries=100)
  File "/usr/lib/python2.7/site-packages/ipaserver/install/replication.py", line 751, in get_replica_principal_dns
    raise RuntimeError(error)
RuntimeError: One of the ldap service principals is missing. Replication agreement cannot be converted.
Replication error message: Unable to acquire replicaLDAP error: No such object

2015-06-19T13:01:56Z DEBUG   [error] RuntimeError: One of the ldap service principals is missing. Replication agreement cannot be converted.
Replication error message: Unable to acquire replicaLDAP error: No such object
2015-06-19T13:01:56Z DEBUG   File "/usr/lib/python2.7/site-packages/ipapython/admintool.py", line 171, in execute
    return_value = self.run()
  File "/usr/lib/python2.7/site-packages/ipapython/install/cli.py", line 308, in run
    cfgr.run()
  File "/usr/lib/python2.7/site-packages/ipapython/install/core.py", line 280, in run
    self.execute()
  File "/usr/lib/python2.7/site-packages/ipapython/install/core.py", line 302, in execute
    for nothing in self._executor():
  File "/usr/lib/python2.7/site-packages/ipapython/install/core.py", line 342, in __runner
    self._handle_exception(exc_info)
  File "/usr/lib/python2.7/site-packages/ipapython/install/core.py", line 364, in _handle_exception
    util.raise_exc_info(exc_info)
  File "/usr/lib/python2.7/site-packages/ipapython/install/core.py", line 332, in __runner
    step()
  File "/usr/lib/python2.7/site-packages/ipapython/install/util.py", line 87, in run_generator_with_yield_from
    raise_exc_info(exc_info)
  File "/usr/lib/python2.7/site-packages/ipapython/install/util.py", line 65, in run_generator_with_yield_from
    value = gen.send(prev_value)
  File "/usr/lib/python2.7/site-packages/ipapython/install/core.py", line 523, in _configure
    executor.next()
  File "/usr/lib/python2.7/site-packages/ipapython/install/core.py", line 342, in __runner
    self._handle_exception(exc_info)
  File "/usr/lib/python2.7/site-packages/ipapython/install/core.py", line 420, in _handle_exception
    self.__parent._handle_exception(exc_info)
  File "/usr/lib/python2.7/site-packages/ipapython/install/core.py", line 364, in _handle_exception
    util.raise_exc_info(exc_info)
  File "/usr/lib/python2.7/site-packages/ipapython/install/core.py", line 417, in _handle_exception
    super(ComponentBase, self)._handle_exception(exc_info)
  File "/usr/lib/python2.7/site-packages/ipapython/install/core.py", line 364, in _handle_exception
    util.raise_exc_info(exc_info)
  File "/usr/lib/python2.7/site-packages/ipapython/install/core.py", line 332, in __runner
    step()
  File "/usr/lib/python2.7/site-packages/ipapython/install/util.py", line 87, in run_generator_with_yield_from
    raise_exc_info(exc_info)
  File "/usr/lib/python2.7/site-packages/ipapython/install/util.py", line 65, in run_generator_with_yield_from
    value = gen.send(prev_value)
  File "/usr/lib/python2.7/site-packages/ipapython/install/common.py", line 63, in _install
    for nothing in self._installer(self.parent):
  File "/usr/lib/python2.7/site-packages/ipaserver/install/server/replicainstall.py", line 869, in main
    install(self)
  File "/usr/lib/python2.7/site-packages/ipaserver/install/server/replicainstall.py", line 295, in decorated
    func(installer)
  File "/usr/lib/python2.7/site-packages/ipaserver/install/server/replicainstall.py", line 576, in install
    krb = install_krb(config, setup_pkinit=not options.no_pkinit)
  File "/usr/lib/python2.7/site-packages/ipaserver/install/server/replicainstall.py", line 93, in install_krb
    setup_pkinit, pkcs12_info)
  File "/usr/lib/python2.7/site-packages/ipaserver/install/krbinstance.py", line 214, in create_replica
    self.start_creation(runtime=30)
  File "/usr/lib/python2.7/site-packages/ipaserver/install/service.py", line 389, in start_creation
    run_step(full_msg, method)
  File "/usr/lib/python2.7/site-packages/ipaserver/install/service.py", line 379, in run_step
    method()
  File "/usr/lib/python2.7/site-packages/ipaserver/install/krbinstance.py", line 438, in __convert_to_gssapi_replication
    r_bindpw=self.dm_password)
  File "/usr/lib/python2.7/site-packages/ipaserver/install/replication.py", line 1104, in convert_to_gssapi_replication
    self.gssapi_update_agreements(self.conn, r_conn)
  File "/usr/lib/python2.7/site-packages/ipaserver/install/replication.py", line 797, in gssapi_update_agreements
    self.setup_krb_princs_as_replica_binddns(a, b)
  File "/usr/lib/python2.7/site-packages/ipaserver/install/replication.py", line 767, in setup_krb_princs_as_replica_binddns
    (a_dn, b_dn) = self.get_replica_principal_dns(a, b, retries=100)
  File "/usr/lib/python2.7/site-packages/ipaserver/install/replication.py", line 751, in get_replica_principal_dns
    raise RuntimeError(error)

2015-06-19T13:01:56Z DEBUG The ipa-replica-install command failed, exception: RuntimeError: One of the ldap service principals is missing. Replication agreement cannot be converted.
Replication error message: Unable to acquire replicaLDAP error: No such object
2015-06-19T13:01:56Z ERROR One of the ldap service principals is missing. Replication agreement cannot be converted.
Replication error message: Unable to acquire replicaLDAP error: No such object
-- 
Manage your subscription for the Freeipa-devel mailing list:
https://www.redhat.com/mailman/listinfo/freeipa-devel
Contribute to FreeIPA: http://www.freeipa.org/page/Contribute/Code

Reply via email to