#8978 Freeipa server does not start after yum update and IPA upgrade
Closed: invalid 2 years ago by jeremytourville. Opened 2 years ago by jeremytourville.

Request for enhancement

As <persona, e.g. admin> , I want <what?> so that <why?>.

Issue

Centos 8.2 was updated to 8.4 After that I ran:

ipa-server-upgrade

Steps to Reproduce

1.upgrade from version '4.8.4 to '4.9.2
2.
3.

Actual behavior

IPA server does not start after a successful upgrade. named-pkcs11 service will not start

Expected behavior

IPA server should run

Version/Release/Distribution

$ rpm -q freeipa-server freeipa-client ipa-server ipa-client 389-ds-base pki-ca krb5-server
ipa-server-4.9.2-4.module_el8.4.0+846+96522ed7.x86_64
ipa-client-4.9.2-4.module_el8.4.0+846+96522ed7.x86_64
389-ds-base-1.4.3.16-19.module_el8.4.0+884+e9b25896.x86_64
pki-ca-10.10.5-3.module_el8.4.0+816+beb6e9a3.noarch
krb5-server-1.18.2-8.el8.x86_64

cat /etc/redhat-release

CentOS Linux release 8.4.2105

Additional info:

Initially the directory server would not start but that issue is now fixed. IPACTL start -f reports that only named is having issues though I also see evidence that ipa-dnskeysyncd.service is having issues.

systemctl status named-pkcs11

● named-pkcs11.service - Berkeley Internet Name Domain (DNS) with native PKCS#11
Loaded: loaded (/usr/lib/systemd/system/named-pkcs11.service; disabled; vendor preset: disabled)
Active: failed (Result: exit-code) since Sat 2021-09-04 07:49:09 CDT; 44min ago
Process: 3139 ExecStart=/usr/sbin/named-pkcs11 -u named -c ${NAMEDCONF} $OPTIONS (code=exited, status=1/FAILURE)
Process: 3136 ExecStartPre=/bin/bash -c if [ ! "$DISABLE_ZONE_CHECKING" == "yes" ]; then /usr/sbin/named-checkconf -z "$NAMEDCONF"; else ec>

Sep 04 07:49:09 utility.idm.nac-issa.org named-pkcs11[3140]: ----------------------------------------------------
Sep 04 07:49:09 utility.idm.nac-issa.org named-pkcs11[3140]: adjusted limit on open files from 262144 to 1048576
Sep 04 07:49:09 utility.idm.nac-issa.org named-pkcs11[3140]: found 4 CPUs, using 4 worker threads
Sep 04 07:49:09 utility.idm.nac-issa.org named-pkcs11[3140]: using 3 UDP listeners per interface
Sep 04 07:49:09 utility.idm.nac-issa.org named-pkcs11[3140]: using up to 21000 sockets
Sep 04 07:49:09 utility.idm.nac-issa.org named-pkcs11[3140]: initializing DST: PKCS#11 initialization failed
Sep 04 07:49:09 utility.idm.nac-issa.org named-pkcs11[3140]: exiting (due to fatal error)
Sep 04 07:49:09 utility.idm.nac-issa.org systemd[1]: named-pkcs11.service: Control process exited, code=exited status=1
Sep 04 07:49:09 utility.idm.nac-issa.org systemd[1]: named-pkcs11.service: Failed with result 'exit-code'.
Sep 04 07:49:09 utility.idm.nac-issa.org systemd[1]: Failed to start Berkeley Internet Name Domain (DNS) with native PKCS#11.

[root@utility log]# journalctl -xe
Sep 04 08:33:45 utility.idm.nac-issa.org ipa-dnskeysyncd[3778]: ipa-dnskeysync-replica: DEBUG Kerberos principal: ipa-dnskeysyncd/utility.>
Sep 04 08:33:45 utility.idm.nac-issa.org ipa-dnskeysyncd[3778]: ipalib.install.kinit: DEBUG Initializing principal ipa-dnskeysyncd/utility>
Sep 04 08:33:45 utility.idm.nac-issa.org ipa-dnskeysyncd[3778]: ipalib.install.kinit: DEBUG using ccache /tmp/ipa-dnskeysync-replica.ccache
Sep 04 08:33:45 utility.idm.nac-issa.org ipa-dnskeysyncd[3778]: ipalib.install.kinit: DEBUG Attempt 1/5: success
Sep 04 08:33:45 utility.idm.nac-issa.org ipa-dnskeysyncd[3778]: ipa-dnskeysync-replica: DEBUG Got TGT
Sep 04 08:33:45 utility.idm.nac-issa.org ipa-dnskeysyncd[3778]: Traceback (most recent call last):
Sep 04 08:33:45 utility.idm.nac-issa.org ipa-dnskeysyncd[3778]: File "/usr/libexec/ipa/ipa-dnskeysync-replica", line 177, in <module>
Sep 04 08:33:45 utility.idm.nac-issa.org ipa-dnskeysyncd[3778]: f.read()
Sep 04 08:33:45 utility.idm.nac-issa.org ipa-dnskeysyncd[3778]: File "/usr/lib/python3.6/site-packages/ipaserver/dnssec/localhsm.py", line >
Sep 04 08:33:45 utility.idm.nac-issa.org ipa-dnskeysyncd[3778]: self.p11 = _ipap11helper.P11_Helper(label, pin, library)
Sep 04 08:33:45 utility.idm.nac-issa.org ipa-dnskeysyncd[3778]: File "/usr/lib/python3.6/site-packages/ipaserver/p11helper.py", line 868, i>
Sep 04 08:33:45 utility.idm.nac-issa.org ipa-dnskeysyncd[3778]: raise Error("No slot for label {} found".format(self.token_label))
Sep 04 08:33:45 utility.idm.nac-issa.org ipa-dnskeysyncd[3778]: ipaserver.p11helper.Error: No slot for label ipaDNSSEC found
Sep 04 08:33:45 utility.idm.nac-issa.org ipa-dnskeysyncd[3778]: Exception ignored in: <bound method LocalHSM.__del__ of <ipaserver.dnssec.loc>
Sep 04 08:33:45 utility.idm.nac-issa.org ipa-dnskeysyncd[3778]: Traceback (most recent call last):
Sep 04 08:33:45 utility.idm.nac-issa.org ipa-dnskeysyncd[3778]: File "/usr/lib/python3.6/site-packages/ipaserver/dnssec/localhsm.py", line >
Sep 04 08:33:45 utility.idm.nac-issa.org ipa-dnskeysyncd[3778]: self.p11.finalize()
Sep 04 08:33:45 utility.idm.nac-issa.org ipa-dnskeysyncd[3778]: AttributeError: 'LocalHSM' object has no attribute 'p11'
Sep 04 08:33:45 utility.idm.nac-issa.org ipa-dnskeysyncd[3778]: Traceback (most recent call last):
Sep 04 08:33:45 utility.idm.nac-issa.org ipa-dnskeysyncd[3778]: File "/usr/libexec/ipa/ipa-dnskeysyncd", line 113, in <module>
Sep 04 08:33:45 utility.idm.nac-issa.org ipa-dnskeysyncd[3778]: while ldap_connection.syncrepl_poll(all=1, msgid=ldap_search):
Sep 04 08:33:45 utility.idm.nac-issa.org ipa-dnskeysyncd[3778]: File "/usr/lib64/python3.6/site-packages/ldap/syncrepl.py", line 465, in sy>
Sep 04 08:33:45 utility.idm.nac-issa.org ipa-dnskeysyncd[3778]: self.syncrepl_refreshdone()
Sep 04 08:33:45 utility.idm.nac-issa.org ipa-dnskeysyncd[3778]: File "/usr/lib/python3.6/site-packages/ipaserver/dnssec/keysyncer.py", line>
Sep 04 08:33:45 utility.idm.nac-issa.org ipa-dnskeysyncd[3778]: self.hsm_replica_sync()
Sep 04 08:33:45 utility.idm.nac-issa.org ipa-dnskeysyncd[3778]: File "/usr/lib/python3.6/site-packages/ipaserver/dnssec/keysyncer.py", line>
Sep 04 08:33:45 utility.idm.nac-issa.org ipa-dnskeysyncd[3778]: ipautil.run([paths.IPA_DNSKEYSYNCD_REPLICA])
Sep 04 08:33:45 utility.idm.nac-issa.org ipa-dnskeysyncd[3778]: File "/usr/lib/python3.6/site-packages/ipapython/ipautil.py", line 599, in >
Sep 04 08:33:45 utility.idm.nac-issa.org ipa-dnskeysyncd[3778]: p.returncode, arg_string, output_log, error_log
Sep 04 08:33:45 utility.idm.nac-issa.org ipa-dnskeysyncd[3778]: ipapython.ipautil.CalledProcessError: CalledProcessError(Command ['/usr/libex>
Sep 04 08:33:45 utility.idm.nac-issa.org systemd[1]: ipa-dnskeysyncd.service: Main process exited, code=exited, status=1/FAILURE
Sep 04 08:33:45 utility.idm.nac-issa.org systemd[1]: ipa-dnskeysyncd.service: Failed with result 'exit-code'.
-- Subject: Unit failed
-- Defined-By: systemd
-- Support: https://access.redhat.com/support
--
-- The unit ipa-dnskeysyncd.service has entered the 'failed' state with result 'exit-code'.

I have followed the guide - https://docs.pagure.org/bind-dyndb-ldap/BIND9/NamedCannotStart.html

  1. /var/log/messages is not present on my system and
    /var/named/data/named.run contains no data during the time period when I attempted to start the named-pkcs11.service

  2. hostname is set to FQDN and hosts entry is correct

  3. This item was tested but the keys match

  4. a log file was examined after running

export KRB5_KTNAME=/etc/named.keytab; named -gu named -4 -d99

04-Sep-2021 07:34:18.941 bind to LDAP server successful

5 All zones appear to be loaded (AFAIK)

export KRB5_KTNAME=/etc/named.keytab; named -gu named -m record -4

04-Sep-2021 07:38:43.473 all zones loaded
04-Sep-2021 07:38:43.473 running
04-Sep-2021 07:38:43.474 LDAP configuration for instance 'ipa' synchronized
04-Sep-2021 07:38:43.478 LDAP data for instance 'ipa' are being synchronized, please ignore message 'all zones loaded'
04-Sep-2021 07:38:43.503 forward zone 'ad.nac-issa.org': loaded
04-Sep-2021 07:38:43.523 zone 50.30.172.in-addr.arpa/IN: loaded serial 1630759123
04-Sep-2021 07:38:43.524 zone 51.30.172.in-addr.arpa/IN: loaded serial 1630759123
04-Sep-2021 07:38:43.524 zone idm.nac-issa.org/IN: loaded serial 1630759123
04-Sep-2021 07:38:43.524 3 master zones from LDAP instance 'ipa' loaded (3 zones defined, 0 inactive, 0 failed to load)

Log file locations: https://access.redhat.com/documentation/en-US/Red_Hat_Enterprise_Linux/7/html/Linux_Domain_Identity_Authentication_and_Policy_Guide/config-files-logs.html
Troubleshooting guide: https://www.freeipa.org/page/Troubleshooting


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

2 years ago

Login to comment on this ticket.

Metadata