Catastrophic failure
by Marin BERNARD
Hi,
My NPO uses FreeIPA internally on a couple of Oracle Linux 8 instances. I know this is a Fedora ML, but since OL8 is derivated from EL8 (as CentOS is), I think it may not make any difference anyway.
The FreeIPA instance was deployed 6-8 months ago, with the LDAP, CA DNS roles enabled on both nodes. DNSSEC was never enabled. An AD trust was created with the AD domain.
It worked flawlessly until the latest batch of updates which upgraded both systems to OL 8.5 + FreeIPA 4.9.6-6.0.1. An IPA upgrade was automatically started to migrate from version 4.9.2-4.0.2 to 4.9.6-6.0.1, but it failed in different ways on both systems, leaving them in unusable states. Of course, no backup to restore.
**Node #02** (ros-ass-ipa-02) upgraded first. The failure happened at IPA CA DNS update, because the named-pkcs11 service could not be restarted. Here are the last lines from the log:
2021-11-17T05:59:11Z DEBUG stderr=
2021-11-17T05:59:11Z DEBUG Loading StateFile from '/var/lib/ipa/sysrestore/sysrestore.state'
2021-11-17T05:59:11Z INFO dnssec-validation yes
2021-11-17T05:59:11Z INFO [Add missing CA DNS records]
2021-11-17T05:59:11Z DEBUG Loading StateFile from '/var/lib/ipa/sysupgrade/sysupgrade.state'
2021-11-17T05:59:11Z INFO IPA CA DNS records already processed
2021-11-17T05:59:11Z DEBUG Loading StateFile from '/var/lib/ipa/sysupgrade/sysupgrade.state'
2021-11-17T05:59:11Z DEBUG Loading StateFile from '/var/lib/ipa/sysrestore/sysrestore.state'
2021-11-17T05:59:11Z DEBUG Loading StateFile from '/var/lib/ipa/sysrestore/sysrestore.state'
2021-11-17T05:59:11Z DEBUG Loading StateFile from '/var/lib/ipa/sysrestore/sysrestore.state'
2021-11-17T05:59:11Z DEBUG Loading StateFile from '/var/lib/ipa/sysrestore/sysrestore.state'
2021-11-17T05:59:11Z DEBUG Loading StateFile from '/var/lib/ipa/sysupgrade/sysupgrade.state'
2021-11-17T05:59:11Z DEBUG Loading StateFile from '/var/lib/ipa/sysupgrade/sysupgrade.state'
2021-11-17T05:59:11Z DEBUG Loading StateFile from '/var/lib/ipa/sysupgrade/sysupgrade.state'
2021-11-17T05:59:11Z DEBUG Loading StateFile from '/var/lib/ipa/sysupgrade/sysupgrade.state'
2021-11-17T05:59:11Z DEBUG Loading StateFile from '/var/lib/ipa/sysupgrade/sysupgrade.state'
2021-11-17T05:59:11Z DEBUG Loading StateFile from '/var/lib/ipa/sysupgrade/sysupgrade.state'
2021-11-17T05:59:11Z DEBUG Loading StateFile from '/var/lib/ipa/sysupgrade/sysupgrade.state'
2021-11-17T05:59:11Z DEBUG Loading StateFile from '/var/lib/ipa/sysupgrade/sysupgrade.state'
2021-11-17T05:59:11Z DEBUG Loading StateFile from '/var/lib/ipa/sysupgrade/sysupgrade.state'
2021-11-17T05:59:11Z DEBUG Loading StateFile from '/var/lib/ipa/sysupgrade/sysupgrade.state'
2021-11-17T05:59:11Z DEBUG Loading StateFile from '/var/lib/ipa/sysupgrade/sysupgrade.state'
2021-11-17T05:59:11Z DEBUG Starting external process
2021-11-17T05:59:11Z DEBUG args=['/bin/systemctl', 'is-active', 'named-pkcs11.service']
2021-11-17T05:59:11Z DEBUG Process finished, return code=3
2021-11-17T05:59:11Z DEBUG stdout=failed
2021-11-17T05:59:11Z DEBUG stderr=
2021-11-17T05:59:11Z DEBUG Starting external process
2021-11-17T05:59:11Z DEBUG args=['/bin/systemctl', 'start', 'named-pkcs11.service']
2021-11-17T05:59:12Z DEBUG Process finished, return code=1
2021-11-17T05:59:12Z DEBUG stdout=
2021-11-17T05:59:12Z DEBUG stderr=Job for named-pkcs11.service failed because the control process exited with error code.
See "systemctl status named-pkcs11.service" and "journalctl -xe" for details.
2021-11-17T05:59:12Z ERROR IPA server upgrade failed: Inspect /var/log/ipaupgrade.log and run command ipa-server-upgrade manually.
2021-11-17T05:59:12Z DEBUG File "/usr/lib/python3.6/site-packages/ipapython/admintool.py", line 180, in execute
return_value = self.run()
File "/usr/lib/python3.6/site-packages/ipaserver/install/ipa_server_upgrade.py", line 54, in run
server.upgrade()
File "/usr/lib/python3.6/site-packages/ipaserver/install/server/upgrade.py", line 1961, in upgrade
upgrade_configuration()
File "/usr/lib/python3.6/site-packages/ipaserver/install/server/upgrade.py", line 1791, in upgrade_configuration
upgrade_bind(fstore)
File "/usr/lib/python3.6/site-packages/ipaserver/install/server/upgrade.py", line 1453, in upgrade_bind
bind.start()
File "/usr/lib/python3.6/site-packages/ipaserver/install/service.py", line 524, in start
self.service.start(instance_name, capture_output=capture_output, wait=wait)
File "/usr/lib/python3.6/site-packages/ipaplatform/base/services.py", line 311, in start
skip_output=not capture_output)
File "/usr/lib/python3.6/site-packages/ipapython/ipautil.py", line 599, in run
p.returncode, arg_string, output_log, error_log
2021-11-17T05:59:12Z DEBUG The ipa-server-upgrade command failed, exception: CalledProcessError: CalledProcessError(Command ['/bin/systemctl', 'start', 'named-pkcs11.service'] returned non-zero exit status 1: 'Job for named-pkcs11.service failed because the control process exited with error code.\nSee "systemctl status named-pkcs11.service" and "journalctl -xe" for details.\n')
2021-11-17T05:59:12Z ERROR Unexpected error - see /var/log/ipaupgrade.log for details:
CalledProcessError: CalledProcessError(Command ['/bin/systemctl', 'start', 'named-pkcs11.service'] returned non-zero exit status 1: 'Job for named-pkcs11.service failed because the control process exited with error code.\nSee "systemctl status named-pkcs11.service" and "journalctl -xe" for details.\n')
2021-11-17T05:59:12Z ERROR The ipa-server-upgrade command failed. See /var/log/ipaupgrade.log for more information
**Node #01** (ros-ass-ipa-01) upgraded an hour after, and failed at step 5/9 when the directory server could not be restarted after disabling Schema compat. Here are the last log entries:
2021-11-17T06:45:38Z DEBUG stderr=
2021-11-17T06:45:38Z DEBUG Starting external process
2021-11-17T06:45:38Z DEBUG args=['/bin/systemctl', 'start', 'dirsrv(a)IPA-PEP06-FR.service']
2021-11-17T06:45:38Z DEBUG step duration: dirsrv __enable_ds_global_write_lock 0.09 sec
2021-11-17T06:45:38Z DEBUG [4/9]: disabling Schema Compat
2021-11-17T06:45:38Z DEBUG step duration: dirsrv __disable_schema_compat 0.14 sec
2021-11-17T06:45:38Z DEBUG [5/9]: starting directory server
2021-11-17T06:45:38Z DEBUG Starting external process
2021-11-17T06:45:38Z DEBUG args=['/bin/systemctl', 'start', 'dirsrv(a)IPA-PEP06-FR.service']
2021-11-17T06:45:38Z DEBUG Process finished, return code=1
2021-11-17T06:45:38Z DEBUG stdout=
2021-11-17T06:45:38Z DEBUG stderr=Job for dirsrv(a)IPA-PEP06-FR.service failed because the control process exited with error code.
See "systemctl status dirsrv(a)IPA-PEP06-FR.service" and "journalctl -xe" for details.
2021-11-17T06:45:38Z ERROR IPA server upgrade failed: Inspect /var/log/ipaupgrade.log and run command ipa-server-upgrade manually.
2021-11-17T06:45:38Z DEBUG Process finished, return code=1
2021-11-17T06:45:38Z DEBUG stdout=
2021-11-17T06:45:38Z DEBUG stderr=Job for dirsrv(a)IPA-PEP06-FR.service failed because the control process exited with error code.
See "systemctl status dirsrv(a)IPA-PEP06-FR.service" and "journalctl -xe" for details.
2021-11-17T06:45:38Z DEBUG File "/usr/lib/python3.6/site-packages/ipapython/admintool.py", line 180, in execute
return_value = self.run()
File "/usr/lib/python3.6/site-packages/ipaserver/install/ipa_server_upgrade.py", line 54, in run
server.upgrade()
File "/usr/lib/python3.6/site-packages/ipaserver/install/server/upgrade.py", line 1961, in upgrade
upgrade_configuration()
File "/usr/lib/python3.6/site-packages/ipaserver/install/server/upgrade.py", line 1584, in upgrade_configuration
ds.start(ds.serverid)
File "/usr/lib/python3.6/site-packages/ipaserver/install/dsinstance.py", line 652, in start
instance_name, capture_output=capture_output, wait=wait
File "/usr/lib/python3.6/site-packages/ipaserver/install/service.py", line 524, in start
self.service.start(instance_name, capture_output=capture_output, wait=wait)
File "/usr/lib/python3.6/site-packages/ipaplatform/redhat/services.py", line 138, in start
instance_name, capture_output=capture_output, wait=wait)
File "/usr/lib/python3.6/site-packages/ipaplatform/base/services.py", line 311, in start
skip_output=not capture_output)
File "/usr/lib/python3.6/site-packages/ipapython/ipautil.py", line 599, in run
p.returncode, arg_string, output_log, error_log
2021-11-17T06:45:38Z DEBUG The ipa-server-upgrade command failed, exception: CalledProcessError: CalledProcessError(Command ['/bin/systemctl', 'start', 'dirsrv(a)IPA-PEP06-FR.service'] returned non-zero exit status 1: 'Job for dirsrv(a)IPA-PEP06-FR.service failed because the control process exited with error code.\nSee "systemctl status dirsrv(a)IPA-PEP06-FR.service" and "journalctl -xe" for details.\n')
2021-11-17T06:45:38Z ERROR Unexpected error - see /var/log/ipaupgrade.log for details:
CalledProcessError: CalledProcessError(Command ['/bin/systemctl', 'start', 'dirsrv(a)IPA-PEP06-FR.service'] returned non-zero exit status 1: 'Job for dirsrv(a)IPA-PEP06-FR.service failed because the control process exited with error code.\nSee "systemctl status dirsrv(a)IPA-PEP06-FR.service" and "journalctl -xe" for details.\n')
2021-11-17T06:45:38Z ERROR The ipa-server-upgrade command failed. See /var/log/ipaupgrade.log for more information
2021-11-17T06:45:38Z DEBUG Traceback (most recent call last):
File "/usr/lib/python3.6/site-packages/ipaserver/install/service.py", line 635, in start_creation
run_step(full_msg, method)
File "/usr/lib/python3.6/site-packages/ipaserver/install/service.py", line 621, in run_step
method()
File "/usr/lib/python3.6/site-packages/ipaserver/install/upgradeinstance.py", line 104, in __start
srv.start(self.serverid, ldapi=True)
File "/usr/lib/python3.6/site-packages/ipaplatform/redhat/services.py", line 138, in start
instance_name, capture_output=capture_output, wait=wait)
File "/usr/lib/python3.6/site-packages/ipaplatform/base/services.py", line 311, in start
skip_output=not capture_output)
File "/usr/lib/python3.6/site-packages/ipapython/ipautil.py", line 599, in run
p.returncode, arg_string, output_log, error_log
ipapython.ipautil.CalledProcessError: CalledProcessError(Command ['/bin/systemctl', 'start', 'dirsrv(a)IPA-PEP06-FR.service'] returned non-zero exit status 1: 'Job for dirsrv(a)IPA-PEP06-FR.service failed because the control process exited with error code.\nSee "systemctl status dirsrv(a)IPA-PEP06-FR.service" and "journalctl -xe" for details.\n')
2021-11-17T06:45:38Z DEBUG [error] CalledProcessError: CalledProcessError(Command ['/bin/systemctl', 'start', 'dirsrv(a)IPA-PEP06-FR.service'] returned non-zero exit status 1: 'Job for dirsrv(a)IPA-PEP06-FR.service failed because the control process exited with error code.\nSee "systemctl status dirsrv(a)IPA-PEP06-FR.service" and "journalctl -xe" for details.\n')
2021-11-17T06:45:38Z DEBUG [cleanup]: stopping directory server
2021-11-17T06:45:38Z DEBUG Starting external process
2021-11-17T06:45:38Z DEBUG args=['/bin/systemctl', 'stop', 'dirsrv(a)IPA-PEP06-FR.service']
2021-11-17T06:45:38Z DEBUG Process finished, return code=0
2021-11-17T06:45:38Z DEBUG stdout=
2021-11-17T06:45:38Z DEBUG stderr=
2021-11-17T06:45:38Z DEBUG Stop of dirsrv(a)IPA-PEP06-FR.service complete
2021-11-17T06:45:38Z DEBUG step duration: dirsrv __stop_instance 0.02 sec
2021-11-17T06:45:38Z DEBUG [cleanup]: restoring configuration
2021-11-17T06:45:38Z DEBUG Loading StateFile from '/var/lib/ipa/sysrestore/sysrestore.state'
2021-11-17T06:45:38Z DEBUG Loading StateFile from '/var/lib/ipa/sysrestore/sysrestore.state'
2021-11-17T06:45:38Z DEBUG Loading StateFile from '/var/lib/ipa/sysrestore/sysrestore.state'
2021-11-17T06:45:38Z DEBUG Loading StateFile from '/var/lib/ipa/sysrestore/sysrestore.state'
2021-11-17T06:45:38Z DEBUG Loading StateFile from '/var/lib/ipa/sysrestore/sysrestore.state'
2021-11-17T06:45:38Z DEBUG Loading StateFile from '/var/lib/ipa/sysrestore/sysrestore.state'
2021-11-17T06:45:38Z DEBUG Loading StateFile from '/var/lib/ipa/sysrestore/sysrestore.state'
2021-11-17T06:45:38Z DEBUG Loading StateFile from '/var/lib/ipa/sysrestore/sysrestore.state'
2021-11-17T06:45:38Z DEBUG Loading StateFile from '/var/lib/ipa/sysrestore/sysrestore.state'
2021-11-17T06:45:38Z DEBUG step duration: dirsrv __restore_config 0.09 sec
2021-11-17T06:45:38Z ERROR IPA server upgrade failed: Inspect /var/log/ipaupgrade.log and run command ipa-server-upgrade manually.
2021-11-17T06:45:38Z DEBUG File "/usr/lib/python3.6/site-packages/ipapython/admintool.py", line 180, in execute
return_value = self.run()
File "/usr/lib/python3.6/site-packages/ipaserver/install/ipa_server_upgrade.py", line 54, in run
server.upgrade()
File "/usr/lib/python3.6/site-packages/ipaserver/install/server/upgrade.py", line 1946, in upgrade
data_upgrade.create_instance()
File "/usr/lib/python3.6/site-packages/ipaserver/install/upgradeinstance.py", line 134, in create_instance
runtime=90)
File "/usr/lib/python3.6/site-packages/ipaserver/install/service.py", line 635, in start_creation
run_step(full_msg, method)
File "/usr/lib/python3.6/site-packages/ipaserver/install/service.py", line 621, in run_step
method()
File "/usr/lib/python3.6/site-packages/ipaserver/install/upgradeinstance.py", line 104, in __start
srv.start(self.serverid, ldapi=True)
File "/usr/lib/python3.6/site-packages/ipaplatform/redhat/services.py", line 138, in start
instance_name, capture_output=capture_output, wait=wait)
File "/usr/lib/python3.6/site-packages/ipaplatform/base/services.py", line 311, in start
skip_output=not capture_output)
File "/usr/lib/python3.6/site-packages/ipapython/ipautil.py", line 599, in run
p.returncode, arg_string, output_log, error_log
2021-11-17T06:45:38Z DEBUG The ipa-server-upgrade command failed, exception: CalledProcessError: CalledProcessError(Command ['/bin/systemctl', 'start', 'dirsrv(a)IPA-PEP06-FR.service'] returned non-zero exit status 1: 'Job for dirsrv(a)IPA-PEP06-FR.service failed because the control process exited with error code.\nSee "systemctl status dirsrv(a)IPA-PEP06-FR.service" and "journalctl -xe" for details.\n')
2021-11-17T06:45:38Z ERROR Unexpected error - see /var/log/ipaupgrade.log for details:
CalledProcessError: CalledProcessError(Command ['/bin/systemctl', 'start', 'dirsrv(a)IPA-PEP06-FR.service'] returned non-zero exit status 1: 'Job for dirsrv(a)IPA-PEP06-FR.service failed because the control process exited with error code.\nSee "systemctl status dirsrv(a)IPA-PEP06-FR.service" and "journalctl -xe" for details.\n')
2021-11-17T06:45:38Z ERROR The ipa-server-upgrade command failed. See /var/log/ipaupgrade.log for more information
On both nodes, several IPA services such as named-pkcs11, ipa-custodia, krb5kdc and kdamin are now disabled in systemd. Of course, they were enabled before the update, since both nodes were serving DNS and kerberos requests. I can re-enable and start most of those services without an error except:
- dirsv@PEP06-IPA-FR, which seems OK on node #02 (ros-ass-ipa-02), but refuses to start on node #01 (ros-ass-ipa-01):
nov. 17 09:17:17 ros-ass-ipa-01.core.ass.ros.ipa.pep06.fr systemd[1]: Starting 389 Directory Server IPA-PEP06-FR....
nov. 17 09:17:17 ros-ass-ipa-01.core.ass.ros.ipa.pep06.fr ns-slapd[5880]: [17/Nov/2021:09:17:17.220419556 +0100] - WARN - str2entry_dupcheckEntry (%s), ignoring invalid line "%s"...
nov. 17 09:17:17 ros-ass-ipa-01.core.ass.ros.ipa.pep06.fr ns-slapd[5880]: - [17/Nov/2021:09:17:17.572658255 +0100] - NOTICE - config_set_port - Non-Secure Port Disabled
nov. 17 09:17:17 ros-ass-ipa-01.core.ass.ros.ipa.pep06.fr ns-slapd[5880]: [17/Nov/2021:09:17:17.637702405 +0100] - WARN - str2entry_dupcheckEntry (%s), ignoring invalid line "%s"...
nov. 17 09:17:17 ros-ass-ipa-01.core.ass.ros.ipa.pep06.fr ns-slapd[5880]: - [17/Nov/2021:09:17:17.641830897 +0100] - ERR - slapi_entry_schema_check_ext - Entry "cn=SHA,cn=Password Storage Schemes,cn=plugins,cn=config" required attribute "objectclass" missing
nov. 17 09:17:17 ros-ass-ipa-01.core.ass.ros.ipa.pep06.fr ns-slapd[5880]: [17/Nov/2021:09:17:17.644760642 +0100] - ERR - init_dse_file - Could not load config file [dse.ldif]
nov. 17 09:17:17 ros-ass-ipa-01.core.ass.ros.ipa.pep06.fr ns-slapd[5880]: [17/Nov/2021:09:17:17.647669444 +0100] - ERR - setup_internal_backends - Please edit the file to correct the reported problems and then restart the server.
nov. 17 09:17:17 ros-ass-ipa-01.core.ass.ros.ipa.pep06.fr systemd[1]: dirsrv(a)IPA-PEP06-FR.service: Main process exited, code=exited, status=1/FAILURE
nov. 17 09:17:17 ros-ass-ipa-01.core.ass.ros.ipa.pep06.fr systemd[1]: dirsrv(a)IPA-PEP06-FR.service: Failed with result 'exit-code'.
nov. 17 09:17:17 ros-ass-ipa-01.core.ass.ros.ipa.pep06.fr systemd[1]: Failed to start 389 Directory Server IPA-PEP06-FR..
- named-pkcs11, which throws an "initializing DST: PKCS#11 initialization failed" error, on both nodes:
nov. 17 09:30:05 ros-ass-ipa-01.core.ass.ros.ipa.pep06.fr named-pkcs11[5910]: running as: named-pkcs11 -u named -c /etc/named.conf
nov. 17 09:30:05 ros-ass-ipa-01.core.ass.ros.ipa.pep06.fr named-pkcs11[5910]: compiled by GCC 8.5.0 20210514 (Red Hat 8.5.0-3.0.1)
nov. 17 09:30:05 ros-ass-ipa-01.core.ass.ros.ipa.pep06.fr named-pkcs11[5910]: compiled with libxml2 version: 2.9.7
nov. 17 09:30:05 ros-ass-ipa-01.core.ass.ros.ipa.pep06.fr named-pkcs11[5910]: linked to libxml2 version: 20907
nov. 17 09:30:05 ros-ass-ipa-01.core.ass.ros.ipa.pep06.fr named-pkcs11[5910]: compiled with libjson-c version: 0.13.1
nov. 17 09:30:05 ros-ass-ipa-01.core.ass.ros.ipa.pep06.fr named-pkcs11[5910]: linked to libjson-c version: 0.13.1
nov. 17 09:30:05 ros-ass-ipa-01.core.ass.ros.ipa.pep06.fr named-pkcs11[5910]: compiled with zlib version: 1.2.11
nov. 17 09:30:05 ros-ass-ipa-01.core.ass.ros.ipa.pep06.fr named-pkcs11[5910]: linked to zlib version: 1.2.11
nov. 17 09:30:05 ros-ass-ipa-01.core.ass.ros.ipa.pep06.fr named-pkcs11[5910]: threads support is enabled
nov. 17 09:30:05 ros-ass-ipa-01.core.ass.ros.ipa.pep06.fr named-pkcs11[5910]: ----------------------------------------------------
nov. 17 09:30:05 ros-ass-ipa-01.core.ass.ros.ipa.pep06.fr named-pkcs11[5910]: BIND 9 is maintained by Internet Systems Consortium,
nov. 17 09:30:05 ros-ass-ipa-01.core.ass.ros.ipa.pep06.fr named-pkcs11[5910]: Inc. (ISC), a non-profit 501(c)(3) public-benefit
nov. 17 09:30:05 ros-ass-ipa-01.core.ass.ros.ipa.pep06.fr named-pkcs11[5910]: corporation. Support and training for BIND 9 are
nov. 17 09:30:05 ros-ass-ipa-01.core.ass.ros.ipa.pep06.fr named-pkcs11[5910]: available at https://www.isc.org/support
nov. 17 09:30:05 ros-ass-ipa-01.core.ass.ros.ipa.pep06.fr named-pkcs11[5910]: ----------------------------------------------------
nov. 17 09:30:05 ros-ass-ipa-01.core.ass.ros.ipa.pep06.fr named-pkcs11[5910]: adjusted limit on open files from 262144 to 1048576
nov. 17 09:30:05 ros-ass-ipa-01.core.ass.ros.ipa.pep06.fr named-pkcs11[5910]: found 4 CPUs, using 4 worker threads
nov. 17 09:30:05 ros-ass-ipa-01.core.ass.ros.ipa.pep06.fr named-pkcs11[5910]: using 3 UDP listeners per interface
nov. 17 09:30:05 ros-ass-ipa-01.core.ass.ros.ipa.pep06.fr named-pkcs11[5910]: using up to 21000 sockets
nov. 17 09:30:05 ros-ass-ipa-01.core.ass.ros.ipa.pep06.fr named-pkcs11[5910]: initializing DST: PKCS#11 initialization failed
nov. 17 09:30:05 ros-ass-ipa-01.core.ass.ros.ipa.pep06.fr named-pkcs11[5910]: exiting (due to fatal error)
nov. 17 09:30:05 ros-ass-ipa-01.core.ass.ros.ipa.pep06.fr systemd[1]: named-pkcs11.service: Control process exited, code=exited status=1
nov. 17 09:30:05 ros-ass-ipa-01.core.ass.ros.ipa.pep06.fr systemd[1]: named-pkcs11.service: Failed with result 'exit-code'.
nov. 17 09:30:05 ros-ass-ipa-01.core.ass.ros.ipa.pep06.fr systemd[1]: Failed to start Berkeley Internet Name Domain (DNS) with native PKCS#11.
I could not find much info about the BIND error. It is usually related to HSM configuration errors, but I couldn't find what's wrong:
[root@ros-ass-ipa-01 ~]# grep SOFTHSM2_CONF /etc/sysconfig/named
SOFTHSM2_CONF=/etc/ipa/dnssec/softhsm2.conf
[root@ros-ass-ipa-01 ~]# SOFTHSM2_CONF=/etc/ipa/dnssec/softhsm2.conf softhsm2-util --show-slots
Available slots:
Slot 1594851657
Slot info:
Description: SoftHSM slot ID 0x5f0f8149
Manufacturer ID: SoftHSM project
Hardware version: 2.6
Firmware version: 2.6
Token present: yes
Token info:
Manufacturer ID: SoftHSM project
Model: SoftHSM v2
Hardware version: 2.6
Firmware version: 2.6
Serial number: 4a9fc4075f0f8149
Initialized: yes
User PIN init.: yes
Label: ipaDNSSEC
Slot 1
Slot info:
Description: SoftHSM slot ID 0x1
Manufacturer ID: SoftHSM project
Hardware version: 2.6
Firmware version: 2.6
Token present: yes
Token info:
Manufacturer ID: SoftHSM project
Model: SoftHSM v2
Hardware version: 2.6
Firmware version: 2.6
Serial number:
Initialized: no
User PIN init.: no
Label:
I tried re-running the IPA upgrade manually, and it failed on both nodes at the exact same step as during the automatic upgrade. While node #02 seems mostly OK (dirsrv and KDC are running, kinit does work; only named-pkcs11 is down), node #01 was more damaged as the directory server does not even start anymore.
Full upgrade logs:
- Node #01 (ros-ass-ipa-01): https://gist.github.com/marinbernard-pep06/548c4aea3006e18b5f86cda6f935f2c5
- Node #02 (ros-ass-ipa-02): https://gist.github.com/marinbernard-pep06/7e5a76712cc4b23101f1fab39315f870
I would be **very** grateful to anyone sharing insight about this situation.
Thank you!
2 years, 5 months
389ds on latest CentOS 8 Steam - broken update ?! - undefined symbol
by lejeczek
Hi guys.
I've just gotten some rpm updates and now 'dirsrv' fails with:
> $ journalctl -lf -o cat -u dirsrv(a)PRIV-MINE.service
dirsrv(a)PRIV-MINE.service: Failed with result 'exit-code'.
Failed to start 389 Directory Server PRIV-MINE..
Starting 389 Directory Server PRIV-MINE....
[17/Nov/2021:11:09:00.635419084 +0000] - ERR -
symload_report_error - Netscape Portable Runtime error
-5975: /usr/lib64/dirsrv/plugins/libpwdstorage-plugin.so:
undefined symbol: gost_yescrypt_pwd_storage_scheme_init
[17/Nov/2021:11:09:00.658674244 +0000] - ERR -
symload_report_error - Could not load symbol
"gost_yescrypt_pwd_storage_scheme_init" from
"libpwdstorage-plugin" for plugin GOST_YESCRYPT
[17/Nov/2021:11:09:00.662676168 +0000] - ERR -
slapd_bootstrap_config - The plugin entry
[cn=GOST_YESCRYPT,cn=Password Storage
Schemes,cn=plugins,cn=config] in the configfile
/etc/dirsrv/slapd-PRIV-MINE/dse.ldif was invalid. Failed to
load plugin's init function.
[17/Nov/2021:11:09:00.676121018 +0000] - EMERG - main - The
configuration files in directory /etc/dirsrv/slapd-PRIV-MINE
could not be read or were not found. Please refer to the
error log or output for more information.
dirsrv(a)PRIV-MINE.service: Main process exited, code=exited,
status=1/FAILURE
dirsrv(a)PRIV-MINE.service: Failed with result 'exit-code'.
affected RPMs:
389-ds-base-1.4.3.23-10.module_el8.5.0+946+51aba098.x86_64
Tue 16 Nov 2021 22:20:36 GMT
389-ds-base-libs-1.4.3.23-10.module_el8.5.0+946+51aba098.x86_64
Tue 16 Nov 2021 22:20:35 GMT
simple:
-> $ dnf downgrade 389-ds-base*
seems like a "fix"
L.
2 years, 5 months
Read only service user to run "ipa dnszone-find --all" and "ipa dnsrecord-find $zone"
by Kathy Zhu
Hi List,
I'd like to set up a read only service user to backup my DNS zone data into
text file daily. However, I checked outputs from "ipa permission-find" and
all of the attributes for user setting, none including permission to DNS
records. Did I miss something here?
Thanks!
Kathy. pa permission-find --bindtype=all | grep "Permission name"`,
2 years, 5 months
non-enrolled out-of-realm cert request - Insufficient write privilege to the userCertificate
by lejeczek
Hi guys.
I am thinking perhaps these things IPA does not allow, certs
for hosts in "outside" domain which IPA serves?
I do simple
-> $ ipa-getcert request -f
/etc/pki/tls/certs/datastor.outside.crt -k
/etc/pki/tls/private/datastor.outside.key
--dns=DNSNAME=datastor.outside -K
host/datastor.outside(a)PRIVATE.LOT
...
Request ID '20211115180241':
status: CA_REJECTED
ca-error: Server at
https://c8kubermaster1.private.lot/ipa/json denied our
request, giving up: 2100 (Insufficient access: Insufficient
'write' privilege to the 'userCertificate' attribute of
entry
'fqdn=datastor.outside,cn=computers,cn=accounts,dc=private,dc=lot'.).
stuck: yes
Or am I doing something silly there?
This is for a host/service.
many thanks, L.
2 years, 5 months
KRA: problems renewing 'storageCert cert-pki-kra'
by Jochen Kellner
Hi,
I'm working to get the KRA subsystem in shape again. It has been broken
due to failed system replication (which is since fixed). There might be
lurking further problems - let's see what we can find out.
I'm working through ipa-healthcheck - currently on the CA renewal
master. The (last) error I'm having there is the following:
[
{
"source": "ipahealthcheck.ipa.certs",
"check": "IPADogtagCertsMatchCheck",
"result": "ERROR",
"uuid": "70f767e8-19de-4426-94e0-6c7704a72895",
"when": "20211114152924Z",
"duration": "2.801277",
"kw": {
"key": "storageCert cert-pki-kra",
"nickname": "storageCert cert-pki-kra",
"dbdir": "/etc/pki/pki-tomcat/alias",
"msg": "{nickname} certificate in NSS DB {dbdir} does not match entry in LDAP"
}
}
]
[That certificate will expire in dezember.]
And that's due to an error I made when trying to fix KRA. This is an
excerpt from "getcert list":
Request ID '20210210143948':
status: MONITORING
ca-error: Server at "http://freeipa1.example.org:8080/ca/ee/ca/profileSubmit" replied: Policy Set Not Found
stuck: no
key pair storage: type=NSSDB,location='/etc/pki/pki-tomcat/alias',nickname='storageCert cert-pki-kra',token='NSS Certificate DB',pin s
et
certificate: type=NSSDB,location='/etc/pki/pki-tomcat/alias',nickname='storageCert cert-pki-kra',token='NSS Certificate DB'
CA: dogtag-ipa-ca-renew-agent
issuer: CN=Certificate Authority,O=EXAMPLE.ORG
subject: CN=KRA Storage Certificate,O=IPA.EXAMPLE.ORG
issued: 2020-12-31 21:08:29 CET
expires: 2022-12-21 21:08:29 CET
key usage: digitalSignature,nonRepudiation,keyEncipherment,dataEncipherment
eku: id-kp-clientAuth
profile: caStorageCert
pre-save command: /usr/libexec/ipa/certmonger/stop_pkicad
post-save command: /usr/libexec/ipa/certmonger/renew_ca_cert "storageCert cert-pki-kra"
track: yes
auto-renew: yes
That's the error - I copied the request from a temporary install but
failed to fix the subject (did not remove "IPA.")
subject: CN=KRA Storage Certificate,O=IPA.EXAMPLE.ORG
I tried to resubmit the certificate request with:
getcert resubmit -i 20210210143948 -N "CN=KRA Storage Certificate,O=EXAMPLE.ORG"
Here's the redacted log:
Nov 14 15:09:57 freeipa1 certmonger[209808]: 2021-11-14 15:09:57 [209808] Setting "CERTMONGER_REQ_SUBJECT" to "CN=KRA Storage Certificate,O=EXAMPLE.ORG" for child.
Nov 14 15:09:57 freeipa1 certmonger[209808]: 2021-11-14 15:09:57 [209808] Setting "CERTMONGER_OPERATION" to "SUBMIT" for child.
Nov 14 15:09:57 freeipa1 certmonger[209808]: 2021-11-14 15:09:57 [209808] Setting "CERTMONGER_CSR" to "-----BEGIN NEW CERTIFICATE REQUEST-----
<redacted>
Nov 14 15:09:57 freeipa1 certmonger[209808]: -----END NEW CERTIFICATE REQUEST-----
Nov 14 15:09:57 freeipa1 certmonger[209808]: " for child.
Nov 14 15:09:57 freeipa1 certmonger[209808]: 2021-11-14 15:09:57 [209808] Setting "CERTMONGER_SPKAC" to "<redacted>" for child.
Nov 14 15:09:57 freeipa1 certmonger[209808]: 2021-11-14 15:09:57 [209808] Setting "CERTMONGER_SPKI" to "<redacted>" for child.
Nov 14 15:09:57 freeipa1 certmonger[209808]: 2021-11-14 15:09:57 [209808] Setting "CERTMONGER_LOCAL_CA_DIR" to "/var/lib/certmonger/local" for child.
Nov 14 15:09:57 freeipa1 certmonger[209808]: 2021-11-14 15:09:57 [209808] Setting "CERTMONGER_KEY_TYPE" to "RSA" for child.
Nov 14 15:09:57 freeipa1 certmonger[209808]: 2021-11-14 15:09:57 [209808] Setting "CERTMONGER_CA_NICKNAME" to "dogtag-ipa-ca-renew-agent" for child.
Nov 14 15:09:57 freeipa1 certmonger[209808]: 2021-11-14 15:09:57 [209808] Setting "CERTMONGER_CA_PROFILE" to "caStorageCert" for child.
Nov 14 15:09:57 freeipa1 certmonger[209808]: 2021-11-14 15:09:57 [209808] Setting "CERTMONGER_CERTIFICATE" to "-----BEGIN CERTIFICATE-----
<redacted>
Nov 14 15:09:57 freeipa1 certmonger[209808]: -----END CERTIFICATE-----
Nov 14 15:09:57 freeipa1 certmonger[209808]: " for child.
Nov 14 15:09:57 freeipa1 certmonger[209808]: 2021-11-14 15:09:57 [209808] Redirecting stdin to /dev/null, leaving stdout and stderr open for child "/usr/libexec/certmonger/dogtag-ipa-ca-renew-agent-submit".
Nov 14 15:09:57 freeipa1 certmonger[209808]: 2021-11-14 15:09:57 [209808] Running enrollment helper "/usr/libexec/certmonger/dogtag-ipa-ca-renew-agent-submit".
Nov 14 15:09:58 freeipa1 certmonger[209234]: 2021-11-14 15:09:58 [209234] Certificate submission still ongoing.
Nov 14 15:09:58 freeipa1 certmonger[209234]: 2021-11-14 15:09:58 [209234] Certificate submission attempt complete.
Nov 14 15:09:58 freeipa1 certmonger[209234]: 2021-11-14 15:09:58 [209234] Child status = 2.
Nov 14 15:09:58 freeipa1 certmonger[209234]: 2021-11-14 15:09:58 [209234] Child output:
Nov 14 15:09:58 freeipa1 certmonger[209234]: "Server at "http://freeipa1.example.org:8080/ca/ee/ca/profileSubmit" replied: Policy Set Not Found
Nov 14 15:09:58 freeipa1 certmonger[209234]: "
Nov 14 15:09:58 freeipa1 certmonger[209234]: 2021-11-14 15:09:58 [209234] Server at "http://freeipa1.example.org:8080/ca/ee/ca/profileSubmit" replied: Policy Set Not Found
Nov 14 15:09:58 freeipa1 certmonger[209234]: 2021-11-14 15:09:58 [209234] Certificate not (yet?) issued.
I think the request uses the correct Profile here:
Nov 14 15:09:57 freeipa1 certmonger[209808]: 2021-11-14 15:09:57 [209808] Setting "CERTMONGER_CA_PROFILE" to "caStorageCert" for child.
The CA has the profile in the filesystem:
pki/pki-tomcat/ca/CS.cfg:1145:profile.caStorageCert.config=/var/lib/pki/pki-tomcat/ca/profiles/ca/caStorageCert.cfg
The file has not been modified and is the same as on my temporary installation.
That's from the ca error log:
2021-11-14 15:09:58 [http-nio-8080-exec-15] INFO: EnrollProfile: Creating ernrollment request 139960063
2021-11-14 15:09:58 [http-nio-8080-exec-15] SEVERE: CertProcessor: no profile policy set found
2021-11-14 15:09:58 [http-nio-8080-exec-15] SEVERE: ProfileSubmitServlet: error in processing request: Policy Set Not Found
Policy Set Not Found
at com.netscape.cms.servlet.cert.CertProcessor.populateRequests(CertProcessor.java:376)
at com.netscape.cms.servlet.cert.EnrollmentProcessor.processEnrollment(EnrollmentProcessor.java:189)
at com.netscape.cms.servlet.cert.EnrollmentProcessor.processEnrollment(EnrollmentProcessor.java:97)
at com.netscape.cms.servlet.profile.ProfileSubmitServlet.processEnrollment(ProfileSubmitServlet.java:279)
at com.netscape.cms.servlet.profile.ProfileSubmitServlet.process(ProfileSubmitServlet.java:132)
at com.netscape.cms.servlet.base.CMSServlet.service(CMSServlet.java:501)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:764)
at jdk.internal.reflect.GeneratedMethodAccessor56.invoke(Unknown Source)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:566)
at org.apache.catalina.security.SecurityUtil.lambda$execute$0(SecurityUtil.java:280)
at java.base/java.security.AccessController.doPrivileged(Native Method)
at java.base/javax.security.auth.Subject.doAsPrivileged(Subject.java:550)
at org.apache.catalina.security.SecurityUtil.execute(SecurityUtil.java:311)
at org.apache.catalina.security.SecurityUtil.doAsPrivilege(SecurityUtil.java:170)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:221)
at org.apache.catalina.core.ApplicationFilterChain.lambda$doFilter$0(ApplicationFilterChain.java:145)
at java.base/java.security.AccessController.doPrivileged(Native Method)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:143)
at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53)
at jdk.internal.reflect.GeneratedMethodAccessor55.invoke(Unknown Source)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:566)
at org.apache.catalina.security.SecurityUtil.lambda$execute$0(SecurityUtil.java:280)
at java.base/java.security.AccessController.doPrivileged(Native Method)
at java.base/javax.security.auth.Subject.doAsPrivileged(Subject.java:550)
at org.apache.catalina.security.SecurityUtil.execute(SecurityUtil.java:311)
at org.apache.catalina.security.SecurityUtil.doAsPrivilege(SecurityUtil.java:253)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:187)
at org.apache.catalina.core.ApplicationFilterChain.lambda$doFilter$0(ApplicationFilterChain.java:145)
at java.base/java.security.AccessController.doPrivileged(Native Method)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:143)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:197)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:97)
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:540)
at com.netscape.cms.tomcat.ExternalAuthenticationValve.invoke(ExternalAuthenticationValve.java:83)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:135)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92)
at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:687)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:78)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:357)
at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:382)
at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65)
at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:895)
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1722)
at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
at org.apache.tomcat.util.threads.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1191)
at org.apache.tomcat.util.threads.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:659)
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.base/java.lang.Thread.run(Thread.java:829)
I found dogtag bug https://github.com/dogtagpki/pki/issues/2872 , but I
don't see how we can work around the error from the IPA side.
Any idea how I can get the certificate renewed?
Jochen
--
This space is intentionally left blank.
2 years, 5 months
klist Valid and expiry dates problem 01/01/70 10:00:00
by Tony Delov
I seem to have an intermittent problem.
When I ssh into it my server,( using sssd and registered to a freeipa server). I often get dates starting at 1970! I seem to be able to login without any issue.
I suspect this may be that our AD server has multiple realms. Strangely enough, our AD has no "MYEDU.EDU" realm but has got an "AD.MYEDU.EDU", which is what I see when it works normally.
I've logged the output of 'sssd -i -d 9 ' plenty of times, but I'm not sure what to even start looking for, nothing obvious is noticeable at the moment.
I've noticed the same problem on Redhat 7, 8 and Ubuntu 18.04. Ubuntu 20.04 has not shown this issue and just works. The dates from klist on Ubuntu 20.04 look OK.
They all have the same krb5.conf and sssd.conf.
How would I debug this?
What sort of things should I be looking at?
@ipa-testp01 ~]$ klist
Ticket cache: KCM:500876:97839
Default principal: tony(a)MYEDU.EDU
Valid starting Expires Service principal
01/01/70 10:00:00 01/01/70 10:00:00 krbtgt/MYEDU.EDU(a)MYEDU.EDU
2 years, 5 months
Error starting FreeIPA service after update
by Pascal Pascher
Just updated:
2021-11-14T16:37:18+0100 DEBUG ---> Package 389-ds-base.x86_64 1.4.3.23-7.module_el8.5.0+889+90e0384f will be upgraded
2021-11-14T16:37:18+0100 DEBUG ---> Package 389-ds-base.x86_64 1.4.3.23-10.module_el8.5.0+946+51aba098 will be an upgrade
After a restart I see the following in my log:
Nov 14 17:21:14 ipa01 systemd[1]: Starting 389 Directory Server IPA-MYDOMAIN-COM....
Nov 14 17:21:14 ipa01 ns-slapd[2040]: [14/Nov/2021:17:21:14.506510437 +0100] - ERR - symload_report_error - Netscape Portable Runtime error -5975: /usr/lib64/dirsrv/plugins/libpwdstorage-plugin.so: undefined symbol: gost_yescrypt_pwd_storage_scheme_init
Nov 14 17:21:14 ipa01 ns-slapd[2040]: [14/Nov/2021:17:21:14.508430711 +0100] - ERR - symload_report_error - Could not load symbol "gost_yescrypt_pwd_storage_scheme_init" from "libpwdstorage-plugin" for plugin GOST_YESCRYPT
Nov 14 17:21:14 ipa01 ns-slapd[2040]: [14/Nov/2021:17:21:14.509110542 +0100] - ERR - slapd_bootstrap_config - The plugin entry [cn=GOST_YESCRYPT,cn=Password Storage Schemes,cn=plugins,cn=config] in the configfile /etc/dirsrv/slapd-IPA-MYDOMAIN-COM/dse.ldif was invalid. Failed to load plugin's init function.
Nov 14 17:21:14 ipa01 ns-slapd[2040]: [14/Nov/2021:17:21:14.509762642 +0100] - EMERG - main - The configuration files in directory /etc/dirsrv/slapd-IPA-MYDOMAIN-COM could not be read or were not found. Please refer to the error log or output for more information.
Nov 14 17:21:14 ipa01 systemd[1]: dirsrv(a)IPA-MYDOMAIN-COM.service: Main process exited, code=exited, status=1/FAILURE
Nov 14 17:21:14 ipa01 systemd[1]: dirsrv(a)IPA-MYDOMAIN-COM.service: Failed with result 'exit-code'.
Nov 14 17:21:14 ipa01 systemd[1]: Failed to start 389 Directory Server IPA-MYDOMAIN-COM..
After removing GOST_YESCRYPT section from the dse.ldif the server starts up again.
2 years, 5 months
Can I allow sudo to users on only specified hosts by FreeIPA?
by Rikimaru Honjo
Hi All,
Can I allow sudo to users on only specified hosts by FreeIPA?
I know that users can use sudo on all nodes if I create "sudo" group and
add users to the group by FreeIPA. But I don't wish it.
In my understand, sudo rule's porpose is different from the above one.
Best Regards,
2 years, 5 months
Academic 'dependency' research / freeipa
by Harry G. Coin
I think freeipa represents something of a research opportunity.
Among all the 'functional subsystem packages' out there, freeipa is the
'tallest pyramid with the widest base' I'm aware of. By that I mean it
has the largest number of dependencies which themselves are also
subsystems (over against libraries with little more than libc/kernel
dependencies); and that in order to be considered 'up and useful' all of
the subsystems contribute to the necessary 'running properly'
condition. In fact many of the subsystems freeipa relies upon are
themselves reliant on what you might call 'functional subsystems'.
You might argue a 'distro' or a GUI environment would be better, but
that's more like a collection of shorter pyramids where the 'breakage'
of one doesn't materially impact the others.
A hypothesis worth getting actual metrics on would be how often it would
appear 'freeipa breaks upon install' and 'freeipa breaks upon upgrade'
when installed via a stream-style release, over against 'vm' or 'docker'
releases, and that over against 'lts/rhel/centos' vs fedora.
Over the coming decades, a question needs resolving-- how high a 'brick
wall' is possible and sustainable (where each 'brick' is a dependency)
and what can be done to make 'higher walls' more reliable? Because each
subsystem represents thousands of hours of focused labor, and that
packaged and made available to other developers faced with either
re-creating the function or using the subsystem.
Presently we're faced with the smallest changes in a dependency
corrupting a database upon 'upgrade', or some seeming trifle breaking
the ui, etc.
I suppose it would lead to a 'so, then, with that, now what?' question
-- and that would be really interesting as well.
So, there's a Monday morning idea.
Harry Coin
2 years, 5 months
Trust between FreeIPA servers
by FreeIPA Question
Hi all,
I was wondering if it would be possible to create a trust relation between two FreeIPA servers. I've read a lot about a trust relation between FreeIPA and Microsoft AD, however I'd like to set up a trust between FreeIPA and FreeIPA.
The use case I'm trying to cover: I'm maintaining multiple environments at different clients and I'd like to be able to log in with my credentials in systems of clients while separating users at the client. Ideally I'd set up a FreeIPA for mycomany.com and make a trust with a FreeIPA for myclient.com. The users at mycompany.com should be able to log in on systems that are enrolled on myclient.com. The users of the client are stored in the IPA server of myclient.com.
Thanks in advance for your help!
2 years, 5 months
