Note: This is a public test instance of Red Hat Bugzilla. The data contained within is a snapshot of the live data so any changes you make will not be reflected in the production Bugzilla. Email is disabled so feel free to test any aspect of the site that you want. File any problems you find or give feedback at bugzilla.redhat.com.
Bug 1869009 - Running ipa-replica-install fails with Failed to start replication
Summary: Running ipa-replica-install fails with Failed to start replication
Keywords:
Status: CLOSED DUPLICATE of bug 1868482
Alias: None
Product: Fedora
Classification: Fedora
Component: freeipa
Version: 32
Hardware: Unspecified
OS: Unspecified
unspecified
unspecified
Target Milestone: ---
Assignee: IPA Maintainers
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2020-08-15 09:08 UTC by Jan Pazdziora
Modified: 2020-08-16 19:27 UTC (History)
11 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2020-08-16 19:27:11 UTC
Type: Bug
Embargoed:

Attachments (Terms of Use)

Description Jan Pazdziora 2020-08-15 09:08:40 UTC 
Description of problem:

Running ipa-replica-install fails with

[ldap://master.example.test:389] reports: Update failed! Status: [Error (-2) - LDAP error: Local error - no response received]
  [error] RuntimeError: Failed to start replication
Failed to start replication

Version-Release number of selected component (if applicable):

freeipa-server-4.8.7-1.fc32

How reproducible:

Deterministic.

Steps to Reproduce:
1. On $MASTER machine, setup the FreeIPA master:
   ipa-server-install -U -r EXAMPLE.TEST -n example.test -p Secret123 -a Secret123
2. On the replica machine, try to setup the FreeIPA replica:
   ipa-replica-install -U --principal admin --setup-ca --no-ntp --domain=example.test --server=$MASTER --admin-password=Secret123

Actual results:

  [22/41]: configure new location for managed entries
  [23/41]: configure dirsrv ccache and keytab
  [24/41]: enabling SASL mapping fallback
  [25/41]: restarting directory server
  [26/41]: creating DS keytab
  [27/41]: ignore time skew for initial replication
  [28/41]: setting up initial replication
Starting replication, please wait until this has completed.

Update in progress, 1 seconds elapsed
Update in progress, 2 seconds elapsed
Update in progress, 3 seconds elapsed
Update in progress, 4 seconds elapsed
Update in progress, 5 seconds elapsed
Update in progress, 6 seconds elapsed
Update in progress, 7 seconds elapsed
Update in progress, 8 seconds elapsed
Update in progress, 9 seconds elapsed
Update in progress, 10 seconds elapsed
Update in progress, 11 seconds elapsed
Update in progress, 12 seconds elapsed
Update in progress, 13 seconds elapsed
Update in progress, 14 seconds elapsed
Update in progress, 15 seconds elapsed
[ldap://master.example.test:389] reports: Update failed! Status: [Error (-2) - LDAP error: Local error - no response received]

  [error] RuntimeError: Failed to start replication
Failed to start replication
The ipa-replica-install command failed. See /var/log/ipareplica-install.log for more information
Your system may be partly configured.
Run /usr/sbin/ipa-server-install --uninstall to clean up.

Expected results:

  [22/41]: configure new location for managed entries
  [23/41]: configure dirsrv ccache and keytab
  [24/41]: enabling SASL mapping fallback
  [25/41]: restarting directory server
  [26/41]: creating DS keytab
  [27/41]: ignore time skew for initial replication
  [28/41]: setting up initial replication
Starting replication, please wait until this has completed.

Update in progress, 1 seconds elapsed
Update in progress, 2 seconds elapsed
Update in progress, 3 seconds elapsed
Update in progress, 4 seconds elapsed
Update in progress, 5 seconds elapsed
Update in progress, 6 seconds elapsed
Update in progress, 7 seconds elapsed
Update succeeded

  [29/41]: prevent time skew after initial replication
  [30/41]: adding sasl mappings to the directory
  [31/41]: updating schema
[...]
  [8/10]: stopping directory server
  [9/10]: restoring configuration
  [10/10]: starting directory server
Done.
Finalize replication settings
Restarting the KDC
The ipa-replica-install command was successful

Additional info:

The /var/log/ipareplica-install.log ends with:

2020-08-15T08:33:16Z DEBUG   [26/41]: creating DS keytab
2020-08-15T08:33:16Z DEBUG raw: service_add('ldap/replica.example.test', force=True, version='2.239')
2020-08-15T08:33:16Z DEBUG service_add(ipapython.kerberos.Principal('ldap/replica.example.test'), force=True, skip_host_check=False, all=False, raw=False, version='2.239', no_members=False)
2020-08-15T08:33:16Z DEBUG raw: host_show('replica.example.test', version='2.239')
2020-08-15T08:33:16Z DEBUG host_show('replica.example.test', rights=False, all=False, raw=False, version='2.239', no_members=False)
2020-08-15T08:33:16Z DEBUG Backing up system configuration file '/etc/dirsrv/ds.keytab'
2020-08-15T08:33:16Z DEBUG   -> Not backing up - '/etc/dirsrv/ds.keytab' doesn't exist
2020-08-15T08:33:16Z DEBUG Starting external process
2020-08-15T08:33:16Z DEBUG args=['/usr/sbin/ipa-getkeytab', '-k', '/etc/dirsrv/ds.keytab', '-p', 'ldap/replica.example.test', '-H', 'ldaps://master.example.test']
2020-08-15T08:33:16Z DEBUG Process finished, return code=0
2020-08-15T08:33:16Z DEBUG stdout=
2020-08-15T08:33:16Z DEBUG stderr=Keytab successfully retrieved and stored in: /etc/dirsrv/ds.keytab

2020-08-15T08:33:16Z DEBUG step duration: dirsrv request_service_keytab 0.17 sec
2020-08-15T08:33:16Z DEBUG   [27/41]: ignore time skew for initial replication
2020-08-15T08:33:16Z DEBUG Starting external process
2020-08-15T08:33:16Z DEBUG args=['/usr/bin/ldapmodify', '-v', '-f', '/tmp/tmp_lxln0fa', '-H', 'ldapi://%2Frun%2Fslapd-EXAMPLE-TEST.socket', '-Y', 'EXTERNAL']
2020-08-15T08:33:16Z DEBUG Process finished, return code=0
2020-08-15T08:33:16Z DEBUG stdout=replace nsslapd-ignore-time-skew:
	on
modifying entry "cn=config"
modify complete


2020-08-15T08:33:16Z DEBUG stderr=ldap_initialize( ldapi://%2Frun%2Fslapd-EXAMPLE-TEST.socket/??base )
SASL/EXTERNAL authentication started
SASL username: gidNumber=0+uidNumber=0,cn=peercred,cn=external,cn=auth
SASL SSF: 0

2020-08-15T08:33:16Z DEBUG step duration: dirsrv __replica_ignore_initial_time_skew 0.04 sec
2020-08-15T08:33:16Z DEBUG   [28/41]: setting up initial replication
2020-08-15T08:33:16Z DEBUG retrieving schema for SchemaCache url=ldapi://%2Frun%2Fslapd-EXAMPLE-TEST.socket conn=<ldap.ldapobject.SimpleLDAPObject object at 0x7fb8e0470a60>
2020-08-15T08:33:16Z DEBUG Destroyed connection context.ldap2_140432053615152
2020-08-15T08:33:16Z DEBUG Starting external process
2020-08-15T08:33:16Z DEBUG args=['/bin/systemctl', '--system', 'daemon-reload']
2020-08-15T08:33:17Z DEBUG Process finished, return code=0
2020-08-15T08:33:17Z DEBUG stdout=
2020-08-15T08:33:17Z DEBUG stderr=
2020-08-15T08:33:17Z DEBUG Starting external process
2020-08-15T08:33:17Z DEBUG args=['/bin/systemctl', 'restart', 'dirsrv']
2020-08-15T08:33:22Z DEBUG Process finished, return code=0
2020-08-15T08:33:22Z DEBUG stdout=
2020-08-15T08:33:22Z DEBUG stderr=
2020-08-15T08:33:22Z DEBUG Restart of dirsrv complete
2020-08-15T08:33:22Z DEBUG Created connection context.ldap2_140432053615152
2020-08-15T08:33:23Z DEBUG Fetching nsDS5ReplicaId from master [attempt 1/5]
2020-08-15T08:33:23Z DEBUG retrieving schema for SchemaCache url=ldap://master.example.test:389 conn=<ldap.ldapobject.SimpleLDAPObject object at 0x7fb8e029ac10>
2020-08-15T08:33:23Z DEBUG Successfully updated nsDS5ReplicaId.
2020-08-15T08:33:23Z DEBUG Add or update replica config cn=replica,cn=dc\=example\,dc\=test,cn=mapping tree,cn=config
2020-08-15T08:33:23Z DEBUG Added replica config cn=replica,cn=dc\=example\,dc\=test,cn=mapping tree,cn=config
2020-08-15T08:33:23Z DEBUG Fetching nsDS5ReplicaId from master [attempt 1/5]
2020-08-15T08:33:23Z DEBUG Successfully updated nsDS5ReplicaId.
2020-08-15T08:33:23Z DEBUG Add or update replica config cn=replica,cn=dc\=example\,dc\=test,cn=mapping tree,cn=config
2020-08-15T08:33:23Z DEBUG Added replica config cn=replica,cn=dc\=example\,dc\=test,cn=mapping tree,cn=config
2020-08-15T08:33:23Z DEBUG Waiting up to 300 seconds for replication (ldap://master.example.test:389) cn=meToreplica.example.test,cn=replica,cn=dc\=example\,dc\=test,cn=mapping tree,cn=config (objectclass=*)
2020-08-15T08:33:23Z DEBUG Entry found [LDAPEntry(ipapython.dn.DN('cn=meToreplica.example.test,cn=replica,cn=dc\=example\,dc\=test,cn=mapping tree,cn=config'), {'objectClass': [b'nsds5replicationagreement', b'top'], 'cn': [b'meToreplica.example.test'], 'nsDS5ReplicaHost': [b'replica.example.test'], 'nsDS5ReplicaPort': [b'389'], 'nsds5replicaTimeout': [b'120'], 'nsDS5ReplicaRoot': [b'dc=example,dc=test'], 'description': [b'me to replica.example.test'], 'nsDS5ReplicatedAttributeList': [b'(objectclass=*) $ EXCLUDE memberof idnssoaserial entryusn krblastsuccessfulauth krblastfailedauth krbloginfailedcount'], 'nsDS5ReplicaTransportInfo': [b'LDAP'], 'nsDS5ReplicaBindMethod': [b'SASL/GSSAPI'], 'nsds5ReplicaStripAttrs': [b'modifiersName modifyTimestamp internalModifiersName internalModifyTimestamp'], 'nsDS5ReplicatedAttributeListTotal': [b'(objectclass=*) $ EXCLUDE entryusn krblastsuccessfulauth krblastfailedauth krbloginfailedcount'], 'nsds5replicareapactive': [b'0'], 'nsds5replicaLastUpdateStart': [b'19700101000000Z'], 'nsds5replicaLastUpdateEnd': [b'19700101000000Z'], 'nsds5replicaChangesSentSinceStartup': [b''], 'nsds5replicaLastUpdateStatus': [b'Error (-2) Problem connecting to replica - LDAP error: Local error (connection error)'], 'nsds5replicaLastUpdateStatusJSON': [b'{"state": "red", "ldap_rc": "-2", "ldap_rc_text": "Local error", "repl_rc": "16", "repl_rc_text": "connection error", "date": "2020-08-15T08:33:23Z", "message": "Error (-2) Problem connecting to replica - LDAP error: Local error (connection error)"}'], 'nsds5replicaUpdateInProgress': [b'FALSE'], 'nsds5replicaLastInitStart': [b'19700101000000Z'], 'nsds5replicaLastInitEnd': [b'19700101000000Z']})]
2020-08-15T08:33:23Z DEBUG Waiting up to 300 seconds for replication (ldapi://%2Frun%2Fslapd-EXAMPLE-TEST.socket) cn=meTomaster.example.test,cn=replica,cn=dc\=example\,dc\=test,cn=mapping tree,cn=config (objectclass=*)
2020-08-15T08:33:23Z DEBUG Entry found [LDAPEntry(ipapython.dn.DN('cn=meTomaster.example.test,cn=replica,cn=dc\=example\,dc\=test,cn=mapping tree,cn=config'), {'objectClass': [b'nsds5replicationagreement', b'top'], 'cn': [b'meTomaster.example.test'], 'nsDS5ReplicaHost': [b'master.example.test'], 'nsDS5ReplicaPort': [b'389'], 'nsds5replicaTimeout': [b'120'], 'nsDS5ReplicaRoot': [b'dc=example,dc=test'], 'description': [b'me to master.example.test'], 'nsDS5ReplicatedAttributeList': [b'(objectclass=*) $ EXCLUDE memberof idnssoaserial entryusn krblastsuccessfulauth krblastfailedauth krbloginfailedcount'], 'nsDS5ReplicaTransportInfo': [b'LDAP'], 'nsDS5ReplicaBindMethod': [b'SASL/GSSAPI'], 'nsds5ReplicaStripAttrs': [b'modifiersName modifyTimestamp internalModifiersName internalModifyTimestamp'], 'nsDS5ReplicatedAttributeListTotal': [b'(objectclass=*) $ EXCLUDE entryusn krblastsuccessfulauth krblastfailedauth krbloginfailedcount'], 'nsds5replicareapactive': [b'0'], 'nsds5replicaLastUpdateStart': [b'19700101000000Z'], 'nsds5replicaLastUpdateEnd': [b'19700101000000Z'], 'nsds5replicaChangesSentSinceStartup': [b''], 'nsds5replicaLastUpdateStatus': [b'Error (0) No replication sessions started since server startup'], 'nsds5replicaLastUpdateStatusJSON': [b'{"state": "green", "ldap_rc": "0", "ldap_rc_text": "success", "repl_rc": "0", "repl_rc_text": "replica acquired", "date": "2020-08-15T08:33:23Z", "message": "Error (0) No replication sessions started since server startup"}'], 'nsds5replicaUpdateInProgress': [b'FALSE'], 'nsds5replicaLastInitStart': [b'19700101000000Z'], 'nsds5replicaLastInitEnd': [b'19700101000000Z']})]
2020-08-15T08:33:39Z DEBUG Traceback (most recent call last):
  File "/usr/lib/python3.8/site-packages/ipaserver/install/service.py", line 603, in start_creation
    run_step(full_msg, method)
  File "/usr/lib/python3.8/site-packages/ipaserver/install/service.py", line 589, in run_step
    method()
  File "/usr/lib/python3.8/site-packages/ipaserver/install/dsinstance.py", line 423, in __setup_replica
    repl.setup_promote_replication(
  File "/usr/lib/python3.8/site-packages/ipaserver/install/replication.py", line 1862, in setup_promote_replication
    raise RuntimeError("Failed to start replication")
RuntimeError: Failed to start replication

2020-08-15T08:33:39Z DEBUG   [error] RuntimeError: Failed to start replication
2020-08-15T08:33:39Z DEBUG Destroyed connection context.ldap2_140432043233776
2020-08-15T08:33:39Z DEBUG Backing up system configuration file '/etc/ipa/default.conf'
2020-08-15T08:33:39Z DEBUG Saving Index File to '/var/lib/ipa/sysrestore/sysrestore.index'
2020-08-15T08:33:39Z DEBUG Writing configuration file /etc/ipa/default.conf
2020-08-15T08:33:39Z DEBUG [global]
basedn = dc=example,dc=test
host = replica.example.test
realm = EXAMPLE.TEST
domain = example.test
xmlrpc_uri = https://replica.example.test/ipa/xml
ldap_uri = ldapi://%2Frun%2Fslapd-EXAMPLE-TEST.socket
mode = production
enable_ra = True
ra_plugin = dogtag
dogtag_version = 10



2020-08-15T08:33:39Z DEBUG   File "/usr/lib/python3.8/site-packages/ipapython/admintool.py", line 179, in execute
    return_value = self.run()
  File "/usr/lib/python3.8/site-packages/ipapython/install/cli.py", line 340, in run
    return cfgr.run()
  File "/usr/lib/python3.8/site-packages/ipapython/install/core.py", line 360, in run
    return self.execute()
  File "/usr/lib/python3.8/site-packages/ipapython/install/core.py", line 386, in execute
    for rval in self._executor():
  File "/usr/lib/python3.8/site-packages/ipapython/install/core.py", line 431, in __runner
    exc_handler(exc_info)
  File "/usr/lib/python3.8/site-packages/ipapython/install/core.py", line 460, in _handle_execute_exception
    self._handle_exception(exc_info)
  File "/usr/lib/python3.8/site-packages/ipapython/install/core.py", line 450, in _handle_exception
    six.reraise(*exc_info)
  File "/usr/lib/python3.8/site-packages/six.py", line 703, in reraise
    raise value
  File "/usr/lib/python3.8/site-packages/ipapython/install/core.py", line 421, in __runner
    step()
  File "/usr/lib/python3.8/site-packages/ipapython/install/core.py", line 418, in <lambda>
    step = lambda: next(self.__gen)
  File "/usr/lib/python3.8/site-packages/ipapython/install/util.py", line 81, in run_generator_with_yield_from
    six.reraise(*exc_info)
  File "/usr/lib/python3.8/site-packages/six.py", line 703, in reraise
    raise value
  File "/usr/lib/python3.8/site-packages/ipapython/install/util.py", line 59, in run_generator_with_yield_from
    value = gen.send(prev_value)
  File "/usr/lib/python3.8/site-packages/ipapython/install/core.py", line 655, in _configure
    next(executor)
  File "/usr/lib/python3.8/site-packages/ipapython/install/core.py", line 431, in __runner
    exc_handler(exc_info)
  File "/usr/lib/python3.8/site-packages/ipapython/install/core.py", line 460, in _handle_execute_exception
    self._handle_exception(exc_info)
  File "/usr/lib/python3.8/site-packages/ipapython/install/core.py", line 518, in _handle_exception
    self.__parent._handle_exception(exc_info)
  File "/usr/lib/python3.8/site-packages/ipapython/install/core.py", line 450, in _handle_exception
    six.reraise(*exc_info)
  File "/usr/lib/python3.8/site-packages/six.py", line 703, in reraise
    raise value
  File "/usr/lib/python3.8/site-packages/ipapython/install/core.py", line 515, in _handle_exception
    super(ComponentBase, self)._handle_exception(exc_info)
  File "/usr/lib/python3.8/site-packages/ipapython/install/core.py", line 450, in _handle_exception
    six.reraise(*exc_info)
  File "/usr/lib/python3.8/site-packages/six.py", line 703, in reraise
    raise value
  File "/usr/lib/python3.8/site-packages/ipapython/install/core.py", line 421, in __runner
    step()
  File "/usr/lib/python3.8/site-packages/ipapython/install/core.py", line 418, in <lambda>
    step = lambda: next(self.__gen)
  File "/usr/lib/python3.8/site-packages/ipapython/install/util.py", line 81, in run_generator_with_yield_from
    six.reraise(*exc_info)
  File "/usr/lib/python3.8/site-packages/six.py", line 703, in reraise
    raise value
  File "/usr/lib/python3.8/site-packages/ipapython/install/util.py", line 59, in run_generator_with_yield_from
    value = gen.send(prev_value)
  File "/usr/lib/python3.8/site-packages/ipapython/install/common.py", line 65, in _install
    for unused in self._installer(self.parent):
  File "/usr/lib/python3.8/site-packages/ipaserver/install/server/__init__.py", line 602, in main
    replica_install(self)
  File "/usr/lib/python3.8/site-packages/ipaserver/install/server/replicainstall.py", line 402, in decorated
    func(installer)
  File "/usr/lib/python3.8/site-packages/ipaserver/install/server/replicainstall.py", line 1240, in install
    ds = install_replica_ds(config, options, ca_enabled,
  File "/usr/lib/python3.8/site-packages/ipaserver/install/server/replicainstall.py", line 100, in install_replica_ds
    ds.create_replica(
  File "/usr/lib/python3.8/site-packages/ipaserver/install/dsinstance.py", line 391, in create_replica
    self.start_creation(runtime=30)
  File "/usr/lib/python3.8/site-packages/ipaserver/install/service.py", line 603, in start_creation
    run_step(full_msg, method)
  File "/usr/lib/python3.8/site-packages/ipaserver/install/service.py", line 589, in run_step
    method()
  File "/usr/lib/python3.8/site-packages/ipaserver/install/dsinstance.py", line 423, in __setup_replica
    repl.setup_promote_replication(
  File "/usr/lib/python3.8/site-packages/ipaserver/install/replication.py", line 1862, in setup_promote_replication
    raise RuntimeError("Failed to start replication")

2020-08-15T08:33:39Z DEBUG The ipa-replica-install command failed, exception: RuntimeError: Failed to start replication
2020-08-15T08:33:39Z ERROR Failed to start replication
2020-08-15T08:33:39Z ERROR The ipa-replica-install command failed. See /var/log/ipareplica-install.log for more information
Comment 2 Jan Pazdziora 2020-08-15 09:10:44 UTC 
This was first shown in FreeIPA container CI:
https://travis-ci.org/github/freeipa/freeipa-container/builds/717852685

But the problem is present outside of containers as well.
Comment 3 Rob Crittenden 2020-08-15 14:35:41 UTC 
This is almost certainly a duplicate of https://bugzilla.redhat.com/show_bug.cgi?id=1868482

https://bodhi.fedoraproject.org/updates/FEDORA-2020-d10a284af3 was pushed to stable recently but I don't know if it's hit the repos yet. Can you re-test with this updated package?
Comment 4 Jan Pazdziora 2020-08-16 19:27:11 UTC 
Thanks for the pointer, Rob. I confirm that with krb5-libs-1.18.2-20.fc32, ipa-replica-install passes.

*** This bug has been marked as a duplicate of bug 1868482 ***
Note You need to log in before you can comment on or make changes to this bug.