Issue #8230: The process of installation brokes at creating directory server instance - freeipa

freeipa

#8230 The process of installation brokes at creating directory server instance

Closed: invalid Mar 17, 2020 by totkapf. Opened Mar 16, 2020 by totkapf.

Issue
I run into error when executing script ipa-server-install --setup-dns at step of creating directory server instance.

Steps to Reproduce

1.Instal new instance of VM CentOS 8
2.Install ipa-server and ipa-server-dns
3.execute script ipa-server-install --setup-dns

Actual behavior

The following operations may take some minutes to complete.
Please wait until the prompt is returned.

Disabled p11-kit-proxy
Synchronizing time
No SRV records of NTP servers found and no NTP server or pool address was provided.
Using default chrony configuration.
Attempting to sync time with chronyc.
Time synchronization was successful.
Configuring directory server (dirsrv). Estimated time: 30 seconds
[1/44]: creating directory server instance
[error] SERVER_DOWN: {'desc': "Can't contact LDAP server", 'errno': 107, 'info': 'Transport endpoint is not connected'}
{'desc': "Can't contact LDAP server", 'errno': 107, 'info': 'Transport endpoint is not connected'}
The ipa-server-install command failed. See /var/log/ipaserver-install.log for more information

Log output:
2020-03-16T14:32:56Z DEBUG Starting external process
2020-03-16T14:32:56Z DEBUG args=['/bin/systemctl', 'is-active', 'ntpd.service']
2020-03-16T14:32:56Z DEBUG Process finished, return code=3
2020-03-16T14:32:56Z DEBUG stdout=inactive

2020-03-16T14:32:56Z DEBUG stderr=
2020-03-16T14:32:56Z DEBUG Search DNS for SRV record of _ntp._udp.None
2020-03-16T14:33:01Z DEBUG DNS record not found: NoAnswer
2020-03-16T14:33:01Z INFO Synchronizing time
2020-03-16T14:33:01Z WARNING No SRV records of NTP servers found and no NTP server or pool address was provided.
2020-03-16T14:33:01Z DEBUG Starting external process
2020-03-16T14:33:01Z DEBUG args=['/bin/systemctl', 'enable', 'chronyd.service']
2020-03-16T14:33:01Z DEBUG Process finished, return code=0
2020-03-16T14:33:01Z DEBUG stdout=
2020-03-16T14:33:01Z DEBUG stderr=
2020-03-16T14:33:01Z DEBUG Starting external process
2020-03-16T14:33:01Z DEBUG args=['/bin/systemctl', 'restart', 'chronyd.service']
2020-03-16T14:33:01Z DEBUG Process finished, return code=0
2020-03-16T14:33:01Z DEBUG stdout=
2020-03-16T14:33:01Z DEBUG stderr=
2020-03-16T14:33:01Z DEBUG Starting external process
2020-03-16T14:33:01Z DEBUG args=['/bin/systemctl', 'is-active', 'chronyd.service']
2020-03-16T14:33:01Z DEBUG Process finished, return code=0
2020-03-16T14:33:01Z DEBUG stdout=active

2020-03-16T14:33:01Z DEBUG stderr=
2020-03-16T14:33:01Z DEBUG Restart of chronyd.service complete
2020-03-16T14:33:01Z INFO Attempting to sync time with chronyc.
2020-03-16T14:33:01Z DEBUG Starting external process
2020-03-16T14:33:01Z DEBUG args=['/usr/bin/chronyc', 'waitsync', '3', '-d']
2020-03-16T14:33:11Z DEBUG Process finished, return code=0
2020-03-16T14:33:11Z DEBUG stdout=try: 1, refid: 00000000, correction: 0.000000000, skew: 0.000
try: 2, refid: B9D155DE, correction: 0.000003624, skew: 6.921

2020-03-16T14:33:11Z DEBUG stderr=
2020-03-16T14:33:11Z INFO Time synchronization was successful.
2020-03-16T14:33:11Z DEBUG Loading StateFile from '/var/lib/ipa/sysrestore/sysrestore.state'
2020-03-16T14:33:11Z DEBUG Configuring directory server (dirsrv). Estimated time: 30 seconds
2020-03-16T14:33:11Z DEBUG [1/44]: creating directory server instance
2020-03-16T14:33:11Z DEBUG Loading StateFile from '/var/lib/ipa/sysrestore/sysrestore.state'
2020-03-16T14:33:11Z DEBUG Saving StateFile to '/var/lib/ipa/sysrestore/sysrestore.state'
2020-03-16T14:33:11Z DEBUG Running setup with verbose
2020-03-16T14:33:13Z DEBUG START: Starting installation...
2020-03-16T14:33:13Z DEBUG READY: Preparing installation for INTEGRANW-LOCAL...
2020-03-16T14:33:13Z DEBUG PASSED: using config settings 999999999
2020-03-16T14:33:13Z DEBUG PASSED: user / group checking
2020-03-16T14:33:13Z DEBUG PASSED: prefix checking
2020-03-16T14:33:13Z DEBUG list instance not found in /etc/dirsrv/slapd-INTEGRANW-LOCAL/dse.ldif: INTEGRANW-LOCAL

2020-03-16T14:33:13Z DEBUG PASSED: instance checking
2020-03-16T14:33:13Z DEBUG INFO: temp root password set to ELfcqxu09VJP4RPEgdqVq7nFcIZq7.QIGq92Oyvkcu.n2j6KI5nj9f9zQmH2gISyZ
2020-03-16T14:33:13Z DEBUG PASSED: root user checking
2020-03-16T14:33:13Z DEBUG PASSED: network avaliability checking
2020-03-16T14:33:13Z DEBUG READY: Beginning installation for INTEGRANW-LOCAL...
2020-03-16T14:33:13Z DEBUG ACTION: Creating dse.ldif
2020-03-16T14:33:13Z DEBUG ACTION: creating /var/lib/dirsrv/slapd-INTEGRANW-LOCAL/bak
2020-03-16T14:33:13Z DEBUG ACTION: creating /etc/dirsrv/slapd-INTEGRANW-LOCAL
2020-03-16T14:33:13Z DEBUG ACTION: creating /var/lib/dirsrv/slapd-INTEGRANW-LOCAL/db
2020-03-16T14:33:13Z DEBUG ACTION: creating /var/lib/dirsrv/slapd-INTEGRANW-LOCAL/ldif
2020-03-16T14:33:13Z DEBUG ACTION: creating /var/lock/dirsrv/slapd-INTEGRANW-LOCAL
2020-03-16T14:33:13Z DEBUG ACTION: creating /var/log/dirsrv/slapd-INTEGRANW-LOCAL
2020-03-16T14:33:13Z DEBUG ACTION: creating /var/run/dirsrv
2020-03-16T14:33:13Z DEBUG CMD: systemctl enable dirsrv@INTEGRANW-LOCAL ; STDOUT: ; STDERR: Created symlink /etc/systemd/system/multi-user.target.wants/dirsrv@INTEGRANW-LOCAL.service → /usr/lib/systemd/system/dirsrv@.service.

2020-03-16T14:33:13Z DEBUG ACTION: Creating certificate database is /etc/dirsrv/slapd-INTEGRANW-LOCAL
2020-03-16T14:33:13Z DEBUG Allocate with None
2020-03-16T14:33:13Z DEBUG Allocate with freeipa.integranw.ru:389
2020-03-16T14:33:13Z DEBUG Allocate with freeipa.integranw.ru:389
2020-03-16T14:33:13Z DEBUG nss cmd: /usr/bin/certutil -N -d /etc/dirsrv/slapd-INTEGRANW-LOCAL -f /etc/dirsrv/slapd-INTEGRANW-LOCAL/pwdfile.txt
2020-03-16T14:33:14Z DEBUG nss output:
2020-03-16T14:33:14Z DEBUG nss cmd: /usr/bin/certutil -N -d /etc/dirsrv/ssca/ -f /etc/dirsrv/ssca//pwdfile.txt
2020-03-16T14:33:15Z DEBUG nss output:
2020-03-16T14:33:16Z DEBUG nss cmd: /usr/bin/certutil -S -n Self-Signed-CA -s CN=ssca.389ds.example.com,O=testing,L=389ds,ST=Queensland,C=AU -x -g 4096 -t CT,, -v 24 --keyUsage certSigning -d /etc/dirsrv/ssca/ -z /etc/dirsrv/ssca//noise.txt -f /etc/dirsrv/ssca//pwdfile.txt
2020-03-16T14:33:19Z DEBUG nss output:

Generating key. This may take a few moments...

2020-03-16T14:33:19Z DEBUG nss cmd: /usr/bin/certutil -L -n Self-Signed-CA -d /etc/dirsrv/ssca/ -a
2020-03-16T14:33:19Z DEBUG nss cmd: /usr/bin/c_rehash /etc/dirsrv/ssca/
2020-03-16T14:33:19Z DEBUG CSR subject -> CN=freeipa.integranw.ru,givenName=f8410b28-8d79-443f-92c5-540af4362dfe,O=testing,L=389ds,ST=Queensland,C=AU
2020-03-16T14:33:19Z DEBUG CSR alt_names -> ['freeipa.integranw.ru']
2020-03-16T14:33:20Z DEBUG nss cmd: /usr/bin/certutil -R --keyUsage digitalSignature,nonRepudiation,keyEncipherment,dataEncipherment --nsCertType sslClient,sslServer --extKeyUsage clientAuth,serverAuth -s CN=freeipa.integranw.ru,givenName=f8410b28-8d79-443f-92c5-540af4362dfe,O=testing,L=389ds,ST=Queensland,C=AU -8 freeipa.integranw.ru -g 4096 -d /etc/dirsrv/slapd-INTEGRANW-LOCAL -z /etc/dirsrv/slapd-INTEGRANW-LOCAL/noise.txt -f /etc/dirsrv/slapd-INTEGRANW-LOCAL/pwdfile.txt -a -o /etc/dirsrv/slapd-INTEGRANW-LOCAL/Server-Cert.csr
2020-03-16T14:33:22Z DEBUG nss cmd: /usr/bin/certutil -C -d /etc/dirsrv/ssca/ -f /etc/dirsrv/ssca//pwdfile.txt -v 24 -a -i /etc/dirsrv/slapd-INTEGRANW-LOCAL/Server-Cert.csr -o /etc/dirsrv/slapd-INTEGRANW-LOCAL/Server-Cert.crt -c Self-Signed-CA
2020-03-16T14:33:22Z DEBUG nss cmd: /usr/bin/c_rehash /etc/dirsrv/slapd-INTEGRANW-LOCAL
2020-03-16T14:33:22Z DEBUG nss cmd: /usr/bin/certutil -A -n Self-Signed-CA -t CT,, -a -i /etc/dirsrv/slapd-INTEGRANW-LOCAL/ca.crt -d /etc/dirsrv/slapd-INTEGRANW-LOCAL -f /etc/dirsrv/slapd-INTEGRANW-LOCAL/pwdfile.txt
2020-03-16T14:33:23Z DEBUG nss cmd: /usr/bin/certutil -A -n Server-Cert -t ,, -a -i /etc/dirsrv/slapd-INTEGRANW-LOCAL/Server-Cert.crt -d /etc/dirsrv/slapd-INTEGRANW-LOCAL -f /etc/dirsrv/slapd-INTEGRANW-LOCAL/pwdfile.txt
2020-03-16T14:33:24Z DEBUG nss cmd: /usr/bin/certutil -V -d /etc/dirsrv/slapd-INTEGRANW-LOCAL -n Server-Cert -u YCV
2020-03-16T14:33:24Z DEBUG port 636 already in [389, 636, 3268, 3269, 7389], skipping port relabel
2020-03-16T14:33:24Z DEBUG port 389 already in [389, 636, 3268, 3269, 7389], skipping port relabel
2020-03-16T14:33:24Z DEBUG systemd status -> True
2020-03-16T14:33:24Z DEBUG systemd status -> True
2020-03-16T14:33:27Z DEBUG open(): Connecting to uri ldap://freeipa.integranw.ru:389/
2020-03-16T14:33:27Z DEBUG Using dirsrv ca certificate /etc/dirsrv/slapd-INTEGRANW-LOCAL
2020-03-16T14:33:27Z DEBUG Using external ca certificate /etc/dirsrv/slapd-INTEGRANW-LOCAL
2020-03-16T14:33:27Z DEBUG Using external ca certificate /etc/dirsrv/slapd-INTEGRANW-LOCAL
2020-03-16T14:33:27Z DEBUG Using certificate policy 1
2020-03-16T14:33:27Z DEBUG ldap.OPT_X_TLS_REQUIRE_CERT = 1
2020-03-16T14:33:28Z DEBUG Cannot connect to 'ldap://freeipa.integranw.ru:389/'
2020-03-16T14:33:28Z DEBUG Traceback (most recent call last):
File "/usr/lib/python3.6/site-packages/ipaserver/install/service.py", line 603, in start_creation
run_step(full_msg, method)
File "/usr/lib/python3.6/site-packages/ipaserver/install/service.py", line 589, in run_step
method()
File "/usr/lib/python3.6/site-packages/ipaserver/install/dsinstance.py", line 559, in create_instance
sds.create_from_args(general, slapd, backends, None)
File "/usr/lib/python3.6/site-packages/lib389/instance/setup.py", line 655, in create_from_args
self._install_ds(general, slapd, backends)
File "/usr/lib/python3.6/site-packages/lib389/instance/setup.py", line 869, in _install_ds
ds_instance.start(timeout=60)
File "/usr/lib/python3.6/site-packages/lib389/__init.py", line 1173, in start
self.open()
File "/usr/lib/python3.6/site-packages/lib389/init.py", line 1076, in open
raise e
File "/usr/lib/python3.6/site-packages/lib389/init.py", line 1072, in open
self.simple_bind_s(ensure_str(self.binddn), self.bindpw, escapehatch='i am sure')
File "/usr/lib/python3.6/site-packages/lib389/init.py", line 180, in inner
return f(args, kwargs)
File "/usr/lib64/python3.6/site-packages/ldap/ldapobject.py", line 443, in simple_bind_s
msgid = self.simple_bind(who,cred,serverctrls,clientctrls)
File "/usr/lib/python3.6/site-packages/lib389/init.py", line 180, in inner
return f(args, kwargs)
File "/usr/lib64/python3.6/site-packages/ldap/ldapobject.py", line 437, in simple_bind
return self._ldap_call(self._l.simple_bind,who,cred,RequestControlTuples(serverctrls),RequestControlTuples(clientctrls))
File "/usr/lib/python3.6/site-packages/lib389/init.py", line 180, in inner
return f(*args, kwargs)
File "/usr/lib64/python3.6/site-packages/ldap/ldapobject.py", line 329, in _ldap_call
reraise(exc_type, exc_value, exc_traceback)
File "/usr/lib64/python3.6/site-packages/ldap/compat.py", line 44, in reraise
raise exc_value
File "/usr/lib64/python3.6/site-packages/ldap/ldapobject.py", line 313, in _ldap_call
result = func(args,kwargs)
ldap.SERVER_DOWN: {'desc': "Can't contact LDAP server", 'errno': 107, 'info': 'Transport endpoint is not connected'}
2020-03-16T14:33:28Z DEBUG [error] SERVER_DOWN: {'desc': "Can't contact LDAP server", 'errno': 107, 'info': 'Transport endpoint is not connected'}
2020-03-16T14:33:28Z DEBUG File "/usr/lib/python3.6/site-packages/ipapython/admintool.py", line 179, in execute
return_value = self.run()
File "/usr/lib/python3.6/site-packages/ipapython/install/cli.py", line 340, in run
return cfgr.run()
File "/usr/lib/python3.6/site-packages/ipapython/install/core.py", line 360, in run
return self.execute()
File "/usr/lib/python3.6/site-packages/ipapython/install/core.py", line 386, in execute
for rval in self._executor():
File "/usr/lib/python3.6/site-packages/ipapython/install/core.py", line 431, in __runner
exc_handler(exc_info)
File "/usr/lib/python3.6/site-packages/ipapython/install/core.py", line 460, in _handle_execute_exception
self._handle_exception(exc_info)
File "/usr/lib/python3.6/site-packages/ipapython/install/core.py", line 450, in _handle_exception
six.reraise(exc_info)
File "/usr/lib/python3.6/site-packages/six.py", line 693, in reraise
raise value
File "/usr/lib/python3.6/site-packages/ipapython/install/core.py", line 421, in runner
step()
File "/usr/lib/python3.6/site-packages/ipapython/install/core.py", line 418, in
step = lambda: next(self.__gen)
File "/usr/lib/python3.6/site-packages/ipapython/install/util.py", line 81, in run_generator_with_yield_from
six.reraise(exc_info)
File "/usr/lib/python3.6/site-packages/six.py", line 693, in reraise
raise value
File "/usr/lib/python3.6/site-packages/ipapython/install/util.py", line 59, in run_generator_with_yield_from
value = gen.send(prev_value)
File "/usr/lib/python3.6/site-packages/ipapython/install/core.py", line 655, in _configure
next(executor)
File "/usr/lib/python3.6/site-packages/ipapython/install/core.py", line 431, in __runner
exc_handler(exc_info)
File "/usr/lib/python3.6/site-packages/ipapython/install/core.py", line 460, in _handle_execute_exception
self._handle_exception(exc_info)
File "/usr/lib/python3.6/site-packages/ipapython/install/core.py", line 518, in _handle_exception
self.__parent._handle_exception(exc_info)
File "/usr/lib/python3.6/site-packages/ipapython/install/core.py", line 450, in _handle_exception
six.reraise(exc_info)
File "/usr/lib/python3.6/site-packages/six.py", line 693, in reraise
raise value
File "/usr/lib/python3.6/site-packages/ipapython/install/core.py", line 421, in __runner
step()
File "/usr/lib/python3.6/site-packages/ipapython/install/core.py", line 418, in
step = lambda: next(self.__gen)
File "/usr/lib/python3.6/site-packages/ipapython/install/util.py", line 81, in run_generator_with_yield_from
six.reraise(exc_info)
File "/usr/lib/python3.6/site-packages/six.py", line 693, in reraise
raise value
File "/usr/lib/python3.6/site-packages/ipapython/install/util.py", line 59, in run_generator_with_yield_from
value = gen.send(prev_value)
File "/usr/lib/python3.6/site-packages/ipapython/install/common.py", line 65, in _install
for unused in self._installer(self.parent):
File "/usr/lib/python3.6/site-packages/ipaserver/install/server/init.py", line 557, in main
master_install(self)
File "/usr/lib/python3.6/site-packages/ipaserver/install/server/install.py", line 255, in decorated
func(installer)
File "/usr/lib/python3.6/site-packages/ipaserver/install/server/install.py", line 828, in install
setup_pkinit=not options.no_pkinit)
File "/usr/lib/python3.6/site-packages/ipaserver/install/dsinstance.py", line 317, in create_instance
self.start_creation(runtime=30)
File "/usr/lib/python3.6/site-packages/ipaserver/install/service.py", line 603, in start_creation
run_step(full_msg, method)
File "/usr/lib/python3.6/site-packages/ipaserver/install/service.py", line 589, in run_step
method()
File "/usr/lib/python3.6/site-packages/ipaserver/install/dsinstance.py", line 559, in create_instance
sds.create_from_args(general, slapd, backends, None)
File "/usr/lib/python3.6/site-packages/lib389/instance/setup.py", line 655, in create_from_args
self._install_ds(general, slapd, backends)
File "/usr/lib/python3.6/site-packages/lib389/instance/setup.py", line 869, in _install_ds
ds_instance.start(timeout=60)
File "/usr/lib/python3.6/site-packages/lib389/__init.py", line 1173, in start
self.open()
File "/usr/lib/python3.6/site-packages/lib389/init.py", line 1076, in open
raise e
File "/usr/lib/python3.6/site-packages/lib389/init.py", line 1072, in open
self.simple_bind_s(ensure_str(self.binddn), self.bindpw, escapehatch='i am sure')
File "/usr/lib/python3.6/site-packages/lib389/init.py", line 180, in inner
return f(args, kwargs)
File "/usr/lib64/python3.6/site-packages/ldap/ldapobject.py", line 443, in simple_bind_s
msgid = self.simple_bind(who,cred,serverctrls,clientctrls)
File "/usr/lib/python3.6/site-packages/lib389/init.py", line 180, in inner
return f(*args, kwargs)
File "/usr/lib64/python3.6/site-packages/ldap/ldapobject.py", line 437, in simple_bind
return self._ldap_call(self._l.simple_bind,who,cred,RequestControlTuples(serverctrls),RequestControlTuples(clientctrls))
File "/usr/lib/python3.6/site-packages/lib389/__init.py", line 180, in inner
return f(args, kwargs)
File "/usr/lib64/python3.6/site-packages/ldap/ldapobject.py", line 329, in _ldap_call
reraise(exc_type, exc_value, exc_traceback)
File "/usr/lib64/python3.6/site-packages/ldap/compat.py", line 44, in reraise
raise exc_value
File "/usr/lib64/python3.6/site-packages/ldap/ldapobject.py", line 313, in _ldap_call
result = func(args,**kwargs)

2020-03-16T14:33:28Z DEBUG The ipa-server-install command failed, exception: SERVER_DOWN: {'desc': "Can't contact LDAP server", 'errno': 107, 'info': 'Transport endpoint is not connected'}
2020-03-16T14:33:28Z ERROR {'desc': "Can't contact LDAP server", 'errno': 107, 'info': 'Transport endpoint is not connected'}
2020-03-16T14:33:28Z ERROR The ipa-server-install command failed. See /var/log/ipaserver-install.log for more information

Expected behavior

(what do you expect to happen)

Version/Release/Distribution

rpm -q freeipa-server freeipa-client ipa-server ipa-client 389-ds-base pki-ca krb5-server
package freeipa-server is not installed
package freeipa-client is not installed
ipa-server-4.8.0-13.module_el8.1.0+265+e1e65be4.x86_64
ipa-client-4.8.0-13.module_el8.1.0+265+e1e65be4.x86_64
389-ds-base-1.4.2.7-1.module_el8+7440+226525ca.x86_64
pki-ca-10.7.3-1.module_el8.1.0+238+005506d1.noarch
krb5-server-1.17-9.el8.x86_64

frenaud commented Mar 16, 2020

Hi @totkapf ,
I am not able to reproduce the issue. I installed the packages and the server with

$ dnf module enable idm:DL1/dns
$ dnf module install idm:DL1/dns
$ ipa-server-install --domain ipa.test --realm IPA.TEST --seutp-dns --auto-forwarder --auto-reverse -a Secret123 -p Secret123 -U

which worked perfectly. My version of 389 is different from yours, though:

$ rpm -q freeipa-server freeipa-client ipa-server ipa-client 389-ds-base pki-ca krb5-server
package freeipa-server is not installed
package freeipa-client is not installed
ipa-server-4.8.0-13.module_el8.1.0+265+e1e65be4.x86_64
ipa-client-4.8.0-13.module_el8.1.0+265+e1e65be4.x86_64
389-ds-base-1.4.1.3-7.module_el8.1.0+234+96aec258.x86_64
pki-ca-10.7.3-1.module_el8.1.0+238+005506d1.noarch
krb5-server-1.17-9.el8.x86_64

Where did you get 389-ds-base-1.4.2.7-1.module_el8+7440+226525ca.x86_64?

totkapf commented Mar 17, 2020

Hello frenaud,
Well my procedure was.
$ dnf module enable idm:DL1
$ dnf distro-sync
$ dnf install ipa-server ipa-server-dns
The only missed package was ipa-healthcheck.

Next I was try to do the whole procedure again and installation was done.

Metadata Update from @totkapf:
- Issue close_status updated to: invalid
- Issue status updated to: Closed (was: Open)

Mar 17, 2020

Metadata

Assignee

None

Tags

None

Blocking

None

Depending on

None

Priority

None

on_review

None

rhbz

None

freeipa

#8230 The process of installation brokes at creating directory server instance Closed: invalid Mar 17, 2020 by totkapf. Opened Mar 16, 2020 by totkapf.

Steps to Reproduce

Actual behavior

Expected behavior

Version/Release/Distribution

Metadata

#8230 The process of installation brokes at creating directory server instance

Closed: invalid Mar 17, 2020 by totkapf. Opened Mar 16, 2020 by totkapf.