Hello, I'm having an issue setting up a new replica. When running the following on the replica:

ipa-replica-install --mkhomedir replica-info-corp-idm03.aws.vwsrv.net.gpg

it stops at "[27/40]: setting up initial replication" with "RuntimeError: Failed to start replication"

From the /var/log/ipareplica-install.log

2018-03-16T18:05:13Z DEBUG   [27/40]: setting up initial replication
2018-03-16T18:05:13Z DEBUG retrieving schema for SchemaCache url=ldapi://%2fvar%2frun%2fslapd-CORP-VWSRV-NET.socket conn=<ldap.ldapobject.SimpleLDAPObject instance at 0x8d9a908>
2018-03-16T18:05:13Z DEBUG Destroyed connection context.ldap2_73919120
2018-03-16T18:05:13Z DEBUG Starting external process
2018-03-16T18:05:13Z DEBUG args=/bin/systemctl --system daemon-reload
2018-03-16T18:05:13Z DEBUG Process finished, return code=0
2018-03-16T18:05:13Z DEBUG stdout=
2018-03-16T18:05:13Z DEBUG stderr=
2018-03-16T18:05:13Z DEBUG Starting external process
2018-03-16T18:05:13Z DEBUG args=/bin/systemctl restart dirsrv@CORP-VWSRV-NET.service
2018-03-16T18:05:14Z DEBUG Process finished, return code=0
2018-03-16T18:05:14Z DEBUG stdout=
2018-03-16T18:05:14Z DEBUG stderr=
2018-03-16T18:05:14Z DEBUG Created connection context.ldap2_73919120
2018-03-16T18:05:14Z DEBUG Fetching nsDS5ReplicaId from master [attempt 1/5]
2018-03-16T18:05:14Z DEBUG retrieving schema for SchemaCache url=ldap://corp-idm02.aws.vwsrv.net:389 conn=<ldap.ldapobject.SimpleLDAPObject instance at 0x92e5fc8>
2018-03-16T18:05:14Z DEBUG Successfully updated nsDS5ReplicaId.
2018-03-16T18:05:30Z DEBUG Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/ipaserver/install/service.py", line 504, in start_creation
    run_step(full_msg, method)
  File "/usr/lib/python2.7/site-packages/ipaserver/install/service.py", line 494, in run_step
    method()
  File "/usr/lib/python2.7/site-packages/ipaserver/install/dsinstance.py", line 439, in __setup_replica
    cacert=self.ca_file)
  File "/usr/lib/python2.7/site-packages/ipaserver/install/replication.py", line 1666, in setup_promote_replication
    raise RuntimeError("Failed to start replication")
RuntimeError: Failed to start replication

2018-03-16T18:05:30Z DEBUG   [error] RuntimeError: Failed to start replication
2018-03-16T18:05:30Z DEBUG Destroyed connection context.ldap2_107462864
2018-03-16T18:05:30Z DEBUG   File "/usr/lib/python2.7/site-packages/ipapython/admintool.py", line 172, in execute
    return_value = self.run()
  File "/usr/lib/python2.7/site-packages/ipapython/install/cli.py", line 333, in run
    cfgr.run()
  File "/usr/lib/python2.7/site-packages/ipapython/install/core.py", line 368, in run
    self.execute()
  File "/usr/lib/python2.7/site-packages/ipapython/install/core.py", line 392, in execute
    for _nothing in self._executor():
  File "/usr/lib/python2.7/site-packages/ipapython/install/core.py", line 434, in __runner
    exc_handler(exc_info)
  File "/usr/lib/python2.7/site-packages/ipapython/install/core.py", line 463, in _handle_execute_exception
    self._handle_exception(exc_info)
  File "/usr/lib/python2.7/site-packages/ipapython/install/core.py", line 453, in _handle_exception
    six.reraise(*exc_info)
  File "/usr/lib/python2.7/site-packages/ipapython/install/core.py", line 424, in __runner
    step()
  File "/usr/lib/python2.7/site-packages/ipapython/install/core.py", line 421, in <lambda>
    step = lambda: next(self.__gen)
  File "/usr/lib/python2.7/site-packages/ipapython/install/util.py", line 81, in run_generator_with_yield_from
    six.reraise(*exc_info)
  File "/usr/lib/python2.7/site-packages/ipapython/install/util.py", line 59, in run_generator_with_yield_from
    value = gen.send(prev_value)
  File "/usr/lib/python2.7/site-packages/ipapython/install/core.py", line 658, in _configure
    next(executor)
  File "/usr/lib/python2.7/site-packages/ipapython/install/core.py", line 434, in __runner
    exc_handler(exc_info)
  File "/usr/lib/python2.7/site-packages/ipapython/install/core.py", line 463, in _handle_execute_exception
    self._handle_exception(exc_info)
  File "/usr/lib/python2.7/site-packages/ipapython/install/core.py", line 521, in _handle_exception
    self.__parent._handle_exception(exc_info)
  File "/usr/lib/python2.7/site-packages/ipapython/install/core.py", line 453, in _handle_exception
    six.reraise(*exc_info)
  File "/usr/lib/python2.7/site-packages/ipapython/install/core.py", line 518, in _handle_exception
    super(ComponentBase, self)._handle_exception(exc_info)
  File "/usr/lib/python2.7/site-packages/ipapython/install/core.py", line 453, in _handle_exception
    six.reraise(*exc_info)
  File "/usr/lib/python2.7/site-packages/ipapython/install/core.py", line 424, in __runner
    step()
  File "/usr/lib/python2.7/site-packages/ipapython/install/core.py", line 421, in <lambda>
    step = lambda: next(self.__gen)
  File "/usr/lib/python2.7/site-packages/ipapython/install/util.py", line 81, in run_generator_with_yield_from
    six.reraise(*exc_info)
  File "/usr/lib/python2.7/site-packages/ipapython/install/util.py", line 59, 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/__init__.py", line 617, in main
    replica_install(self)
  File "/usr/lib/python2.7/site-packages/ipaserver/install/server/replicainstall.py", line 386, in decorated
    func(installer)
  File "/usr/lib/python2.7/site-packages/ipaserver/install/server/replicainstall.py", line 1405, in install
    pkcs12_info=dirsrv_pkcs12_info)
  File "/usr/lib/python2.7/site-packages/ipaserver/install/server/replicainstall.py", line 107, in install_replica_ds
    setup_pkinit=not options.no_pkinit,
  File "/usr/lib/python2.7/site-packages/ipaserver/install/dsinstance.py", line 404, in create_replica
    self.start_creation(runtime=30)
  File "/usr/lib/python2.7/site-packages/ipaserver/install/service.py", line 504, in start_creation
    run_step(full_msg, method)
  File "/usr/lib/python2.7/site-packages/ipaserver/install/service.py", line 494, in run_step
    method()
  File "/usr/lib/python2.7/site-packages/ipaserver/install/dsinstance.py", line 439, in __setup_replica
    cacert=self.ca_file)
  File "/usr/lib/python2.7/site-packages/ipaserver/install/replication.py", line 1666, in setup_promote_replication
    raise RuntimeError("Failed to start replication")

2018-03-16T18:05:30Z DEBUG The ipa-replica-install command failed, exception: RuntimeError: Failed to start replication
2018-03-16T18:05:30Z ERROR Failed to start replication
2018-03-16T18:05:30Z ERROR The ipa-replica-install command failed. See /var/log/ipareplica-install.log for more information

In the dirsrv error log on the replica:

[16/Mar/2018:14:06:00.376045567 -0400] - ERR - NSMMReplicationPlugin - acquire_replica - agmt="cn=meTocorp-idm02.aws.vwsrv.net" (corp-idm02:389): Unable to acquire replica: permission denied. The bind dn "" does not have permission to supply replication updates to the replica. Will retry later.

In the dirsrv error log on the master:

[16/Mar/2018:14:06:00.345021912 -0400] - ERR - NSMMReplicationPlugin - multimaster_extop_StartNSDS50ReplicationRequest - conn=895 op=9 replica="dc=corp,dc=vwsrv,dc=net": Unable to acquire replica: error: permission denied

This issue does seem similar to a previous issue posted to this list, although this person was at a different stage during the replica install (maybe it changed in this version) - https://www.redhat.com/archives/freeipa-users/2016-November/msg00237.html


I ran some ldapsearch queries as well to try to get more information (as suggested in that thread).

On the replica:
# ldapsearch -LLL -D "cn=directory manager" -W -b "cn=config" 'cn=replica' nsds5replicabinddngroup nsds5replicabinddngroupcheckinterval nsDS5ReplicaBindDN
Enter LDAP Password:
dn: cn=replica,cn=dc\3Dcorp\2Cdc\3Dvwsrv\2Cdc\3Dnet,cn=mapping tree,cn=config
nsds5replicabinddngroup: cn=replication managers,cn=sysaccounts,cn=etc,dc=corp
 ,dc=vwsrv,dc=net
nsds5replicabinddngroupcheckinterval: 60
nsDS5ReplicaBindDN: cn=replication manager,cn=config
nsDS5ReplicaBindDN: cn=ldap/corp-idm02.aws.vwsrv.net@CORP.VWSRV.NET,cn=config

On the master:
# ldapsearch -LLL -D "cn=directory manager" -W -b "cn=config" 'cn=replica' nsds5replicabinddngroup nsds5replicabinddngroupcheckinterval nsDS5ReplicaBindDN
Enter LDAP Password:
dn: cn=replica,cn=dc\3Dcorp\2Cdc\3Dvwsrv\2Cdc\3Dnet,cn=mapping tree,cn=config
nsds5replicabinddngroup: cn=replication managers,cn=sysaccounts,cn=etc,dc=corp
 ,dc=vwsrv,dc=net
nsds5replicabinddngroupcheckinterval: 60
nsDS5ReplicaBindDN: cn=replication manager,cn=config
nsDS5ReplicaBindDN: cn=ldap/corp-idm03.aws.vwsrv.net@CORP.VWSRV.NET,cn=config   <-- I added this entry manually.

On the replica (interesting that it doesn't have this cn, maybe it isn't setup yet by the replica instal):

# ldapsearch -D "cn=directory manager" -W -b "cn=replication managers,cn=sysaccounts,cn=etc,dc=corp,dc=vwsrv,dc=net"
Enter LDAP Password:
# extended LDIF
#
# LDAPv3
# base <cn=replication managers,cn=sysaccounts,cn=etc,dc=corp,dc=vwsrv,dc=net> with scope subtree
# filter: (objectclass=*)
# requesting: ALL
#

# search result
search: 2
result: 32 No such object
matchedDN: dc=corp,dc=vwsrv,dc=net

# numResponses: 1

On the master:

# ldapsearch -D "cn=directory manager" -W -b "cn=replication managers,cn=sysaccounts,cn=etc,dc=corp,dc=vwsrv,dc=net"
Enter LDAP Password:
# extended LDIF
#
# LDAPv3
# base <cn=replication managers,cn=sysaccounts,cn=etc,dc=corp,dc=vwsrv,dc=net> with scope subtree
# filter: (objectclass=*)
# requesting: ALL
#

# replication managers, sysaccounts, etc, corp.vwsrv.net
dn: cn=replication managers,cn=sysaccounts,cn=etc,dc=corp,dc=vwsrv,dc=net
cn: replication managers
member: krbprincipalname=ldap/dal10-corp-idm01.corp.vwsrv.net@CORP.VWSRV.NET,c
 n=services,cn=accounts,dc=corp,dc=vwsrv,dc=net
member: krbprincipalname=ldap/corp-idm02.aws.vwsrv.net@CORP.VWSRV.NET,cn=servi
 ces,cn=accounts,dc=corp,dc=vwsrv,dc=net
member: krbprincipalname=ldap/corp-idm03.aws.vwsrv.net@CORP.VWSRV.NET,cn=servi
 ces,cn=accounts,dc=corp,dc=vwsrv,dc=net
objectClass: top
objectClass: groupofnames

# search result
search: 2
result: 0 Success

# numResponses: 2
# numEntries: 1


The logs seem lacking in this case, "permission denied" isn't super helpful. Does anybody have any ideas about this one? Thanks!

--
Michael