IPA 4.5 replica installation failing - Unable to acquire replica: error: permission denied

[Michael Stathers]

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(a)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(a)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(a)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(a)CORP.VWSRV.NET
,c
 n=services,cn=accounts,dc=corp,dc=vwsrv,dc=net
member: krbprincipalname=ldap/corp-idm02.aws.vwsrv.net(a)CORP.VWSRV.NET
,cn=servi
 ces,cn=accounts,dc=corp,dc=vwsrv,dc=net
member: krbprincipalname=ldap/corp-idm03.aws.vwsrv.net(a)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

[Michael Stathers]

I managed to get past this. Even though I had updated the appropriate
FreeIPA packages at the time, I hadn't updated all system packages.
Updating all packages resulted in the intended result. Not a definitive fix
sorry, but "try updating everything" is the best I can suggest for others
in this situation.

--
Michael