Hello,
i've got a little Problem with ipa-replica install
After the following command: ipa-replica-install --setup-ca --setup-dns
--forwarder=9.9.9.9
--skip-conncheck
the replica install interrupt with the following comment:
Starting replication, please wait until this has completed.
Update in progress, 14 seconds elapsed
[ldap://ipaserver1.linuxtest.gonicus.de:389] reports: Update failed! Status: [Error (-1) -
LDAP
error: Can't contact LDAP server - no response received]
I have tested the IPA Replica with Fedora 30 and Rawhide, the error is the same.
Here comes the last entries of the /var/log/ipareplica-install.log, i think this may
help.
[root@ipaserver2 ~]# tail -n +1846 /var/log/ipareplica-install.log
2019-07-17T10:51:15Z DEBUG stderr=ldap_initialize(
ldapi://%2Fvar%2Frun%2Fslapd-LINUXTEST-GONICUS-DE.socket/??base )
SASL/EXTERNAL authentication started
SASL username: gidNumber=0+uidNumber=0,cn=peercred,cn=external,cn=auth
SASL SSF: 0
2019-07-17T10:51:15Z DEBUG step duration: dirsrv __enable_sasl_mapping_fallback 0.02 sec
2019-07-17T10:51:15Z DEBUG [25/41]: restarting directory server
2019-07-17T10:51:15Z DEBUG Destroyed connection context.ldap2_140587719084688
2019-07-17T10:51:15Z DEBUG Starting external process
2019-07-17T10:51:15Z DEBUG args=['/bin/systemctl', '--system',
'daemon-reload']
2019-07-17T10:51:15Z DEBUG Process finished, return code=0
2019-07-17T10:51:15Z DEBUG stdout=
2019-07-17T10:51:15Z DEBUG stderr=
2019-07-17T10:51:15Z DEBUG Starting external process
2019-07-17T10:51:15Z DEBUG args=['/bin/systemctl', 'restart',
'dirsrv(a)LINUXTEST-GONICUS-DE.service']
2019-07-17T10:51:18Z DEBUG Process finished, return code=0
2019-07-17T10:51:18Z DEBUG stdout=
2019-07-17T10:51:18Z DEBUG stderr=
2019-07-17T10:51:18Z DEBUG Starting external process
2019-07-17T10:51:18Z DEBUG args=['/bin/systemctl', 'is-active',
'dirsrv(a)LINUXTEST-GONICUS-DE.service']
2019-07-17T10:51:18Z DEBUG Process finished, return code=0
2019-07-17T10:51:18Z DEBUG stdout=active
2019-07-17T10:51:18Z DEBUG stderr=
2019-07-17T10:51:18Z DEBUG wait_for_open_ports: localhost [389] timeout 120
2019-07-17T10:51:18Z DEBUG waiting for port: 389
2019-07-17T10:51:18Z DEBUG SUCCESS: port: 389
2019-07-17T10:51:18Z DEBUG Restart of dirsrv(a)LINUXTEST-GONICUS-DE.service complete
2019-07-17T10:51:18Z DEBUG Starting external process
2019-07-17T10:51:18Z DEBUG args=['/bin/systemctl', 'is-active',
'dirsrv(a)LINUXTEST-GONICUS-DE.service']
2019-07-17T10:51:18Z DEBUG Process finished, return code=0
2019-07-17T10:51:18Z DEBUG stdout=active
2019-07-17T10:51:18Z DEBUG stderr=
2019-07-17T10:51:18Z DEBUG Created connection context.ldap2_140587719084688
2019-07-17T10:51:18Z DEBUG step duration: dirsrv __restart_instance 3.15 sec
2019-07-17T10:51:18Z DEBUG [26/41]: creating DS keytab
2019-07-17T10:51:18Z DEBUG raw:
service_add('ldap/ipaserver2.linuxtest.gonicus.de(a)LINUXTEST.GONICUS.DE',
force=True, version='2.233')
2019-07-17T10:51:18Z DEBUG
service_add(ipapython.kerberos.Principal('ldap/ipaserver2.linuxtest.gonicus.de(a)LINUXTEST.GONICUS.DE'),
force=True, skip_host_check=False, all=False, raw=False, version='2.233',
no_members=False)
2019-07-17T10:51:18Z DEBUG raw: host_show('ipaserver2.linuxtest.gonicus.de',
version='2.233')
2019-07-17T10:51:18Z DEBUG host_show('ipaserver2.linuxtest.gonicus.de',
rights=False, all=False,
raw=False, version='2.233', no_members=False)
2019-07-17T10:51:18Z DEBUG Backing up system configuration file
'/etc/dirsrv/ds.keytab'
2019-07-17T10:51:18Z DEBUG -> Not backing up - '/etc/dirsrv/ds.keytab'
doesn't exist
2019-07-17T10:51:18Z DEBUG Starting external process
2019-07-17T10:51:18Z DEBUG args=['/usr/sbin/ipa-getkeytab', '-k',
'/etc/dirsrv/ds.keytab', '-p',
'ldap/ipaserver2.linuxtest.gonicus.de(a)LINUXTEST.GONICUS.DE', '-H',
'ldaps://ipaserver1.linuxtest.gonicus.de']
2019-07-17T10:51:18Z DEBUG Process finished, return code=0
2019-07-17T10:51:18Z DEBUG stdout=
2019-07-17T10:51:18Z DEBUG stderr=Keytab successfully retrieved and stored in:
/etc/dirsrv/ds.keytab
2019-07-17T10:51:18Z DEBUG step duration: dirsrv request_service_keytab 0.08 sec
2019-07-17T10:51:18Z DEBUG [27/41]: ignore time skew for initial replication
2019-07-17T10:51:18Z DEBUG Starting external process
2019-07-17T10:51:18Z DEBUG args=['/usr/bin/ldapmodify', '-v',
'-f', '/tmp/tmpijxp8wcg', '-H',
'ldapi://%2Fvar%2Frun%2Fslapd-LINUXTEST-GONICUS-DE.socket', '-Y',
'EXTERNAL']
2019-07-17T10:51:18Z DEBUG Process finished, return code=0
2019-07-17T10:51:18Z DEBUG stdout=replace nsslapd-ignore-time-skew:
on
modifying entry "cn=config"
modify complete
2019-07-17T10:51:18Z DEBUG stderr=ldap_initialize(
ldapi://%2Fvar%2Frun%2Fslapd-LINUXTEST-GONICUS-DE.socket/??base )
SASL/EXTERNAL authentication started
SASL username: gidNumber=0+uidNumber=0,cn=peercred,cn=external,cn=auth
SASL SSF: 0
2019-07-17T10:51:18Z DEBUG step duration: dirsrv __replica_ignore_initial_time_skew 0.04
sec
2019-07-17T10:51:18Z DEBUG [28/41]: setting up initial replication
2019-07-17T10:51:18Z DEBUG retrieving schema for SchemaCache
url=ldapi://%2Fvar%2Frun%2Fslapd-LINUXTEST-GONICUS-DE.socket
conn=<ldap.ldapobject.SimpleLDAPObject
object at 0x7fdd1e59a690>
2019-07-17T10:51:19Z DEBUG Destroyed connection context.ldap2_140587719084688
2019-07-17T10:51:19Z DEBUG Starting external process
2019-07-17T10:51:19Z DEBUG args=['/bin/systemctl', '--system',
'daemon-reload']
2019-07-17T10:51:19Z DEBUG Process finished, return code=0
2019-07-17T10:51:19Z DEBUG stdout=
2019-07-17T10:51:19Z DEBUG stderr=
2019-07-17T10:51:19Z DEBUG Starting external process
2019-07-17T10:51:19Z DEBUG args=['/bin/systemctl', 'restart',
'dirsrv(a)LINUXTEST-GONICUS-DE.service']
2019-07-17T10:51:22Z DEBUG Process finished, return code=0
2019-07-17T10:51:22Z DEBUG stdout=
2019-07-17T10:51:22Z DEBUG stderr=
2019-07-17T10:51:22Z DEBUG Restart of dirsrv(a)LINUXTEST-GONICUS-DE.service complete
2019-07-17T10:51:22Z DEBUG Created connection context.ldap2_140587719084688
2019-07-17T10:51:22Z DEBUG Fetching nsDS5ReplicaId from master [attempt 1/5]
2019-07-17T10:51:22Z DEBUG retrieving schema for SchemaCache
url=ldap://ipaserver1.linuxtest.gonicus.de:389 conn=<ldap.ldapobject.SimpleLDAPObject
object at
0x7fdd1e3f5710>
2019-07-17T10:51:22Z DEBUG Successfully updated nsDS5ReplicaId.
2019-07-17T10:51:22Z DEBUG Add or update replica config
cn=replica,cn=dc\=linuxtest\,dc\=gonicus\,dc\=de,cn=mapping tree,cn=config
2019-07-17T10:51:22Z DEBUG Added replica config
cn=replica,cn=dc\=linuxtest\,dc\=gonicus\,dc\=de,cn=mapping tree,cn=config
2019-07-17T10:51:22Z DEBUG Fetching nsDS5ReplicaId from master [attempt 1/5]
2019-07-17T10:51:22Z DEBUG Successfully updated nsDS5ReplicaId.
2019-07-17T10:51:22Z DEBUG Add or update replica config
cn=replica,cn=dc\=linuxtest\,dc\=gonicus\,dc\=de,cn=mapping tree,cn=config
2019-07-17T10:51:22Z DEBUG Added replica config
cn=replica,cn=dc\=linuxtest\,dc\=gonicus\,dc\=de,cn=mapping tree,cn=config
2019-07-17T10:51:22Z DEBUG Waiting for replication
(ldap://ipaserver1.linuxtest.gonicus.de:389)
cn=meToipaserver2.linuxtest.gonicus.de,cn=replica,cn=dc\=linuxtest\,dc\=gonicus\,dc\=de,cn=mapping
tree,cn=config (objectclass=*)
2019-07-17T10:51:22Z DEBUG Entry found
[LDAPEntry(ipapython.dn.DN('cn=meToipaserver2.linuxtest.gonicus.de,cn=replica,cn=dc\=linuxtest\,dc\=gonicus\,dc\=de,cn=mapping
tree,cn=config'), {'objectClass': [b'nsds5replicationagreement',
b'top'], 'cn':
[b'meToipaserver2.linuxtest.gonicus.de'], 'nsDS5ReplicaHost':
[b'ipaserver2.linuxtest.gonicus.de'],
'nsDS5ReplicaPort': [b'389'], 'nsds5replicaTimeout':
[b'120'], 'nsDS5ReplicaRoot':
[b'dc=linuxtest,dc=gonicus,dc=de'], 'description': [b'me to
ipaserver2.linuxtest.gonicus.de'],
'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 (-1) Problem connecting to replica - LDAP error: Can't contact LDAP
server (connection
error)"], 'nsds5replicaLastUpdateStatusJSON': [b'{"state":
"red", "ldap_rc": "-1", "ldap_rc_text":
"Can\'t contact LDAP server", "repl_rc": "16",
"repl_rc_text": "connection error", "date":
"2019-07-17T10:51:22Z", "message": "Error (-1) Problem connecting
to replica - LDAP error: Can\'t
contact LDAP server (connection error)"}'],
'nsds5replicaUpdateInProgress': [b'FALSE'],
'nsds5replicaLastInitStart': [b'19700101000000Z'],
'nsds5replicaLastInitEnd': [b'19700101000000Z']})]
2019-07-17T10:51:22Z DEBUG Waiting for replication
(ldapi://%2Fvar%2Frun%2Fslapd-LINUXTEST-GONICUS-DE.socket)
cn=meToipaserver1.linuxtest.gonicus.de,cn=replica,cn=dc\=linuxtest\,dc\=gonicus\,dc\=de,cn=mapping
tree,cn=config (objectclass=*)
2019-07-17T10:51:22Z DEBUG Entry found
[LDAPEntry(ipapython.dn.DN('cn=meToipaserver1.linuxtest.gonicus.de,cn=replica,cn=dc\=linuxtest\,dc\=gonicus\,dc\=de,cn=mapping
tree,cn=config'), {'objectClass': [b'nsds5replicationagreement',
b'top'], 'cn':
[b'meToipaserver1.linuxtest.gonicus.de'], 'nsDS5ReplicaHost':
[b'ipaserver1.linuxtest.gonicus.de'],
'nsDS5ReplicaPort': [b'389'], 'nsds5replicaTimeout':
[b'120'], 'nsDS5ReplicaRoot':
[b'dc=linuxtest,dc=gonicus,dc=de'], 'description': [b'me to
ipaserver1.linuxtest.gonicus.de'],
'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": "2019-07-17T10:51:22Z", "message":
"Error (0) No replication sessions started since server startup"}'],
'nsds5replicaUpdateInProgress':
[b'FALSE'], 'nsds5replicaLastInitStart': [b'19700101000000Z'],
'nsds5replicaLastInitEnd':
[b'19700101000000Z']})]
2019-07-17T10:51:38Z DEBUG Traceback (most recent call last):
File "/usr/lib/python3.7/site-packages/ipaserver/install/service.py", line
603, in start_creation
run_step(full_msg, method)
File "/usr/lib/python3.7/site-packages/ipaserver/install/service.py", line
589, in run_step
method()
File "/usr/lib/python3.7/site-packages/ipaserver/install/dsinstance.py", line
427, in __setup_replica
cacert=self.ca_file
File "/usr/lib/python3.7/site-packages/ipaserver/install/replication.py", line
1860, in
setup_promote_replication
raise RuntimeError("Failed to start replication")
RuntimeError: Failed to start replication
2019-07-17T10:51:38Z DEBUG [error] RuntimeError: Failed to start replication
2019-07-17T10:51:38Z DEBUG Destroyed connection context.ldap2_140587706624720
2019-07-17T10:51:38Z DEBUG Backing up system configuration file
'/etc/ipa/default.conf'
2019-07-17T10:51:38Z DEBUG Saving Index File to
'/var/lib/ipa/sysrestore/sysrestore.index'
2019-07-17T10:51:38Z DEBUG Writing configuration file /etc/ipa/default.conf
2019-07-17T10:51:38Z DEBUG [global]
basedn = dc=linuxtest,dc=gonicus,dc=de
host = ipaserver2.linuxtest.gonicus.de
realm = LINUXTEST.GONICUS.DE
domain = linuxtest.gonicus.de
xmlrpc_uri =
https://ipaserver2.linuxtest.gonicus.de/ipa/xml
ldap_uri = ldapi://%2Fvar%2Frun%2Fslapd-LINUXTEST-GONICUS-DE.socket
mode = production
enable_ra = True
ra_plugin = dogtag
dogtag_version = 10
2019-07-17T10:51:38Z DEBUG File
"/usr/lib/python3.7/site-packages/ipapython/admintool.py", line
179, in execute
return_value = self.run()
File "/usr/lib/python3.7/site-packages/ipapython/install/cli.py", line 340, in
run
return cfgr.run()
File "/usr/lib/python3.7/site-packages/ipapython/install/core.py", line 360,
in run
return self.execute()
File "/usr/lib/python3.7/site-packages/ipapython/install/core.py", line 386,
in execute
for rval in self._executor():
File "/usr/lib/python3.7/site-packages/ipapython/install/core.py", line 431,
in __runner
exc_handler(exc_info)
File "/usr/lib/python3.7/site-packages/ipapython/install/core.py", line 460,
in
_handle_execute_exception
self._handle_exception(exc_info)
File "/usr/lib/python3.7/site-packages/ipapython/install/core.py", line 450,
in _handle_exception
six.reraise(*exc_info)
File "/usr/lib/python3.7/site-packages/six.py", line 693, in reraise
raise value
File "/usr/lib/python3.7/site-packages/ipapython/install/core.py", line 421,
in __runner
step()
File "/usr/lib/python3.7/site-packages/ipapython/install/core.py", line 418,
in <lambda>
step = lambda: next(self.__gen)
File "/usr/lib/python3.7/site-packages/ipapython/install/util.py", line 81,
in
run_generator_with_yield_from
six.reraise(*exc_info)
File "/usr/lib/python3.7/site-packages/six.py", line 693, in reraise
raise value
File "/usr/lib/python3.7/site-packages/ipapython/install/util.py", line 59,
in
run_generator_with_yield_from
value = gen.send(prev_value)
File "/usr/lib/python3.7/site-packages/ipapython/install/core.py", line 655,
in _configure
next(executor)
File "/usr/lib/python3.7/site-packages/ipapython/install/core.py", line 431,
in __runner
exc_handler(exc_info)
File "/usr/lib/python3.7/site-packages/ipapython/install/core.py", line 460,
in
_handle_execute_exception
self._handle_exception(exc_info)
File "/usr/lib/python3.7/site-packages/ipapython/install/core.py", line 518,
in _handle_exception
self.__parent._handle_exception(exc_info)
File "/usr/lib/python3.7/site-packages/ipapython/install/core.py", line 450,
in _handle_exception
six.reraise(*exc_info)
File "/usr/lib/python3.7/site-packages/six.py", line 693, in reraise
raise value
File "/usr/lib/python3.7/site-packages/ipapython/install/core.py", line 515,
in _handle_exception
super(ComponentBase, self)._handle_exception(exc_info)
File "/usr/lib/python3.7/site-packages/ipapython/install/core.py", line 450,
in _handle_exception
six.reraise(*exc_info)
File "/usr/lib/python3.7/site-packages/six.py", line 693, in reraise
raise value
File "/usr/lib/python3.7/site-packages/ipapython/install/core.py", line 421,
in __runner
step()
File "/usr/lib/python3.7/site-packages/ipapython/install/core.py", line 418,
in <lambda>
step = lambda: next(self.__gen)
File "/usr/lib/python3.7/site-packages/ipapython/install/util.py", line 81,
in
run_generator_with_yield_from
six.reraise(*exc_info)
File "/usr/lib/python3.7/site-packages/six.py", line 693, in reraise
raise value
File "/usr/lib/python3.7/site-packages/ipapython/install/util.py", line 59,
in
run_generator_with_yield_from
value = gen.send(prev_value)
File "/usr/lib/python3.7/site-packages/ipapython/install/common.py", line 65,
in _install
for unused in self._installer(self.parent):
File "/usr/lib/python3.7/site-packages/ipaserver/install/server/__init__.py",
line 590, in main
replica_install(self)
File
"/usr/lib/python3.7/site-packages/ipaserver/install/server/replicainstall.py",
line 402, in
decorated
func(installer)
File
"/usr/lib/python3.7/site-packages/ipaserver/install/server/replicainstall.py",
line 1207, in
install
fstore=fstore)
File
"/usr/lib/python3.7/site-packages/ipaserver/install/server/replicainstall.py",
line 112, in
install_replica_ds
setup_pkinit=not options.no_pkinit,
File "/usr/lib/python3.7/site-packages/ipaserver/install/dsinstance.py", line
391, in create_replica
self.start_creation(runtime=30)
File "/usr/lib/python3.7/site-packages/ipaserver/install/service.py", line
603, in start_creation
run_step(full_msg, method)
File "/usr/lib/python3.7/site-packages/ipaserver/install/service.py", line
589, in run_step
method()
File "/usr/lib/python3.7/site-packages/ipaserver/install/dsinstance.py", line
427, in __setup_replica
cacert=self.ca_file
File "/usr/lib/python3.7/site-packages/ipaserver/install/replication.py", line
1860, in
setup_promote_replication
raise RuntimeError("Failed to start replication")
2019-07-17T10:51:38Z DEBUG The ipa-replica-install command failed, exception:
RuntimeError: Failed
to start replication
2019-07-17T10:51:38Z ERROR Failed to start replication
2019-07-17T10:51:38Z ERROR The ipa-replica-install command failed. See
/var/log/ipareplica-install.log for more information
For me it is interesting to see that the Replica does not work with Fedora 30 and Rawhide,
always
the same error.
And no, firewalld is masked and not in use.
Have somebody any ideas for me?
Regards
Dirk