Bug 1841925

Summary: ipa-server: FIPS mode installation failure ("Can't contact LDAP server")
Product: Red Hat Enterprise Linux 8 Reporter: Robbie Harwood <rharwood>
Component: 389-ds-baseAssignee: mreynolds
Status: CLOSED NOTABUG QA Contact: RHDS QE <ds-qe-bugs>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: ---CC: cheimes, lkrispen, mreynolds, rcritten, spichugi, tbordaz, tscherf, vashirov
Target Milestone: rc   
Target Release: 8.0   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2020-06-03 18:07:55 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Attachments:
Description Flags
ipaserver-install.log (8.3.0) none

Description Robbie Harwood 2020-05-29 20:24:16 UTC
With both RHEL-8.2 and the latest RHEL-8.3 nightlies, I don't seem to be able to get IPA installed.

ipaserver-install.log is attached, but here's logs from dirsrv:

[root@ipa dirsrv]# journalctl -xu dirsrv@FIPS-COM
-- Logs begin at Fri 2020-05-29 19:22:58 UTC, end at Fri 2020-05-29 20:21:20 UTC. --
May 29 19:30:26 ipa.fips.com systemd[1]: Starting 389 Directory Server FIPS-COM....
-- Subject: Unit dirsrv has begun start-up
-- Defined-By: systemd
-- Support: https://access.redhat.com/support
-- 
-- Unit dirsrv has begun starting up.
May 29 19:30:26 ipa.fips.com ns-slapd[7359]: [29/May/2020:19:30:26.626828097 +0000] - INFO - slapd_system_isFIPS - system in FIPS mode
May 29 19:30:26 ipa.fips.com ns-slapd[7359]: [29/May/2020:19:30:26.641212622 +0000] - INFO - slapd_system_isFIPS - system in FIPS mode
May 29 19:30:26 ipa.fips.com ns-slapd[7359]: [29/May/2020:19:30:26.741556013 +0000] - INFO - main - 389-Directory/1.4.3.8 B2020.132.2142 starting up
May 29 19:30:26 ipa.fips.com ns-slapd[7359]: [29/May/2020:19:30:26.746684192 +0000] - INFO - main - Setting the maximum file descriptor limit to: 262144
May 29 19:30:26 ipa.fips.com ns-slapd[7359]: [29/May/2020:19:30:26.752000445 +0000] - ERR - PBKDF2_SHA256 - Unable to retrieve slot from NSS.
May 29 19:30:26 ipa.fips.com ns-slapd[7359]: [29/May/2020:19:30:26.757397247 +0000] - ERR - PBKDF2_SHA256 - Could not generate pbkdf2_sha256_hash!
May 29 19:30:26 ipa.fips.com ns-slapd[7359]: [29/May/2020:19:30:26.759837725 +0000] - ERR - PBKDF2_SHA256 - Unable to retrieve slot from NSS.
May 29 19:30:26 ipa.fips.com ns-slapd[7359]: [29/May/2020:19:30:26.765247054 +0000] - ERR - PBKDF2_SHA256 - Could not generate pbkdf2_sha256_hash!
May 29 19:30:26 ipa.fips.com ns-slapd[7359]: [29/May/2020:19:30:26.767690870 +0000] - ERR - PBKDF2_SHA256 - Unable to retrieve slot from NSS.
May 29 19:30:26 ipa.fips.com ns-slapd[7359]: [29/May/2020:19:30:26.770080595 +0000] - ERR - PBKDF2_SHA256 - Could not generate pbkdf2_sha256_hash!
May 29 19:30:26 ipa.fips.com ns-slapd[7359]: [29/May/2020:19:30:26.775370506 +0000] - ERR - PBKDF2_SHA256 - Unable to retrieve slot from NSS.
May 29 19:30:26 ipa.fips.com ns-slapd[7359]: [29/May/2020:19:30:26.778260796 +0000] - ERR - PBKDF2_SHA256 - Could not generate pbkdf2_sha256_hash!
May 29 19:30:26 ipa.fips.com ns-slapd[7359]: [29/May/2020:19:30:26.781011218 +0000] - ERR - PBKDF2_SHA256 - Unable to retrieve slot from NSS.
May 29 19:30:26 ipa.fips.com ns-slapd[7359]: [29/May/2020:19:30:26.786123278 +0000] - ERR - PBKDF2_SHA256 - Could not generate pbkdf2_sha256_hash!
May 29 19:30:26 ipa.fips.com ns-slapd[7359]: [29/May/2020:19:30:26.789245928 +0000] - ERR - PBKDF2_SHA256 - Unable to retrieve slot from NSS.
May 29 19:30:26 ipa.fips.com ns-slapd[7359]: [29/May/2020:19:30:26.791801681 +0000] - ERR - PBKDF2_SHA256 - Could not generate pbkdf2_sha256_hash!
May 29 19:30:26 ipa.fips.com ns-slapd[7359]: [29/May/2020:19:30:26.796949960 +0000] - ERR - PBKDF2_SHA256 - Unable to retrieve slot from NSS.
May 29 19:30:26 ipa.fips.com ns-slapd[7359]: [29/May/2020:19:30:26.799865474 +0000] - ERR - PBKDF2_SHA256 - Could not generate pbkdf2_sha256_hash!
May 29 19:30:26 ipa.fips.com ns-slapd[7359]: [29/May/2020:19:30:26.811816664 +0000] - ERR - PBKDF2_SHA256 - Unable to retrieve slot from NSS.
May 29 19:30:26 ipa.fips.com ns-slapd[7359]: [29/May/2020:19:30:26.815074666 +0000] - ERR - PBKDF2_SHA256 - Could not generate pbkdf2_sha256_hash!
May 29 19:30:26 ipa.fips.com ns-slapd[7359]: [29/May/2020:19:30:26.817775851 +0000] - INFO - PBKDF2_SHA256 - Based on CPU performance, chose 6000 rounds
May 29 19:30:26 ipa.fips.com ns-slapd[7359]: [29/May/2020:19:30:26.822520053 +0000] - WARN - spal_meminfo_get - cgroups v1 or v2 unable to be read - may not be on this platform ...
May 29 19:30:26 ipa.fips.com ns-slapd[7359]: [29/May/2020:19:30:26.826036309 +0000] - INFO - bdb_config_upgrade_dse_info - create config entry from old config
May 29 19:30:26 ipa.fips.com ns-slapd[7359]: [29/May/2020:19:30:26.831226957 +0000] - WARN - spal_meminfo_get - cgroups v1 or v2 unable to be read - may not be on this platform ...
May 29 19:30:26 ipa.fips.com ns-slapd[7359]: [29/May/2020:19:30:26.837728501 +0000] - NOTICE - ldbm_back_start - found 1861564k physical memory
May 29 19:30:26 ipa.fips.com ns-slapd[7359]: [29/May/2020:19:30:26.839831286 +0000] - NOTICE - ldbm_back_start - found 1331720k available
May 29 19:30:26 ipa.fips.com ns-slapd[7359]: [29/May/2020:19:30:26.842032414 +0000] - NOTICE - ldbm_back_start - cache autosizing: db cache: 46539k
May 29 19:30:26 ipa.fips.com ns-slapd[7359]: [29/May/2020:19:30:26.844634434 +0000] - WARN - spal_meminfo_get - cgroups v1 or v2 unable to be read - may not be on this platform ...
May 29 19:30:26 ipa.fips.com ns-slapd[7359]: [29/May/2020:19:30:26.847236715 +0000] - NOTICE - ldbm_back_start - total cache size: 38124830 B;
May 29 19:30:26 ipa.fips.com ns-slapd[7359]: [29/May/2020:19:30:26.849681195 +0000] - WARN - spal_meminfo_get - cgroups v1 or v2 unable to be read - may not be on this platform ...
May 29 19:30:26 ipa.fips.com ns-slapd[7359]: [29/May/2020:19:30:26.969006228 +0000] - INFO - slapd_daemon - slapd started.  Listening on All Interfaces port 389 for LDAP requests
May 29 19:30:26 ipa.fips.com systemd[1]: Started 389 Directory Server FIPS-COM..
-- Subject: Unit dirsrv has finished start-up
-- Defined-By: systemd
-- Support: https://access.redhat.com/support
-- 
-- Unit dirsrv has finished starting up.
-- 
-- The start-up result is done.
[root@ipa dirsrv]# 

Logs above and attached are from nightly:

[root@ipa dirsrv]# rpm -qv ipa-server 389-ds-base nss openssl
ipa-server-4.8.6-1.module+el8.3.0+6429+acaee14b.x86_64
389-ds-base-1.4.3.8-2.module+el8.3.0+6591+ebfc9766.x86_64
nss-3.44.0-15.el8.x86_64
openssl-1.1.1g-5.el8.x86_64
[root@ipa dirsrv]# fips-mode-setup --check
FIPS mode is enabled.
[root@ipa dirsrv]#

Comment 1 Rob Crittenden 2020-05-30 01:43:37 UTC
I don't know if it would be useful to log the NSS error code in this case or not. 389 is searching for the "best" slot that provides the mechanisms CKM_SHA256_HMAC and CKM_PKCS5_PBKD2 (and this particular code hasn't changed in 3 years).

According to modutil the only difference in the mechanism list between FIPS and non-FIPS is non-FIPS has ECC.

The FIPS mechanisms list is:

RSA:DH:RC2:RC4:DES:AES:CAMELLIA:SEED:SHA1:SHA256:SHA512:MD5:MD2:SSL:TLS

Comment 2 Christian Heimes 2020-05-30 09:20:26 UTC
This might be a duplicate ore reappearance of https://bugzilla.redhat.com/show_bug.cgi?id=1656418

Comment 3 Christian Heimes 2020-05-30 09:21:50 UTC
Robbie, I don't see any attachments. Could you please attach ipaserver-install.log?

Comment 4 Christian Heimes 2020-05-30 09:51:11 UTC
Installation works for me in 8.3 nightly compose (RHEL-8.3.0-20200526.n.1) in 1minutetip (1minutetip --fips --flavor ci.m1.medium.rng 1MT-RHEL-8.3.0-20200526.n.1).

# fips-mode-setup --check
FIPS mode is enabled.
# rpm -qv ipa-server 389-ds-base nss openssl
ipa-server-4.8.6-1.module+el8.3.0+6429+acaee14b.x86_64
389-ds-base-1.4.3.8-2.module+el8.3.0+6591+ebfc9766.x86_64
nss-3.44.0-15.el8.x86_64
openssl-1.1.1g-3.el8.x86_64

My test installation has openssl-1.1.1g-3 instead of openssl-1.1.1g-5 and uses a fake FIPS mode (user-space behaves like FIPS mode, Kernel is in standard mode).

389-DS log:

[30/May/2020:05:47:41.838601571 -0400] - ERR - PBKDF2_SHA256 - Unable to extract hash output.
[30/May/2020:05:47:41.840335864 -0400] - ERR - PBKDF2_SHA256 - Could not generate pbkdf2_sha256_hash!
[30/May/2020:05:47:41.953889328 -0400] - ERR - PBKDF2_SHA256 - Unable to extract hash output.
[30/May/2020:05:47:41.954569758 -0400] - ERR - PBKDF2_SHA256 - Could not generate pbkdf2_sha256_hash!
[30/May/2020:05:47:42.060831106 -0400] - ERR - PBKDF2_SHA256 - Unable to extract hash output.
[30/May/2020:05:47:42.061525839 -0400] - ERR - PBKDF2_SHA256 - Could not generate pbkdf2_sha256_hash!
[30/May/2020:05:47:42.166559085 -0400] - ERR - PBKDF2_SHA256 - Unable to extract hash output.
[30/May/2020:05:47:42.167509433 -0400] - ERR - PBKDF2_SHA256 - Could not generate pbkdf2_sha256_hash!
[30/May/2020:05:47:42.274974145 -0400] - ERR - PBKDF2_SHA256 - Unable to extract hash output.
[30/May/2020:05:47:42.275570890 -0400] - ERR - PBKDF2_SHA256 - Could not generate pbkdf2_sha256_hash!
[30/May/2020:05:47:42.389873016 -0400] - ERR - PBKDF2_SHA256 - Unable to extract hash output.
[30/May/2020:05:47:42.390570641 -0400] - ERR - PBKDF2_SHA256 - Could not generate pbkdf2_sha256_hash!
[30/May/2020:05:47:42.498283153 -0400] - ERR - PBKDF2_SHA256 - Unable to extract hash output.
[30/May/2020:05:47:42.499016833 -0400] - ERR - PBKDF2_SHA256 - Could not generate pbkdf2_sha256_hash!
[30/May/2020:05:47:42.612415059 -0400] - ERR - PBKDF2_SHA256 - Unable to extract hash output.
[30/May/2020:05:47:42.613234147 -0400] - ERR - PBKDF2_SHA256 - Could not generate pbkdf2_sha256_hash!
[30/May/2020:05:47:42.613727024 -0400] - INFO - PBKDF2_SHA256 - Based on CPU performance, chose 2048 rounds
[30/May/2020:05:47:42.617387007 -0400] - WARN - spal_meminfo_get - cgroups v1 or v2 unable to be read - may not be on this platform ...
[30/May/2020:05:47:42.619623189 -0400] - INFO - ldbm_instance_config_cachememsize_set - force a minimal value 512000
[30/May/2020:05:47:42.620430312 -0400] - WARN - spal_meminfo_get - cgroups v1 or v2 unable to be read - may not be on this platform ...
[30/May/2020:05:47:42.621080825 -0400] - WARN - spal_meminfo_get - cgroups v1 or v2 unable to be read - may not be on this platform ...
[30/May/2020:05:47:42.621867922 -0400] - WARN - spal_meminfo_get - cgroups v1 or v2 unable to be read - may not be on this platform ...
[30/May/2020:05:47:42.623141040 -0400] - WARN - spal_meminfo_get - cgroups v1 or v2 unable to be read - may not be on this platform ...
[30/May/2020:05:47:42.623884364 -0400] - WARN - spal_meminfo_get - cgroups v1 or v2 unable to be read - may not be on this platform ...
[30/May/2020:05:47:42.624516341 -0400] - WARN - spal_meminfo_get - cgroups v1 or v2 unable to be read - may not be on this platform ...
[30/May/2020:05:47:42.632015621 -0400] - INFO - ldbm_instance_config_cachememsize_set - force a minimal value 512000
[30/May/2020:05:47:42.632844524 -0400] - WARN - spal_meminfo_get - cgroups v1 or v2 unable to be read - may not be on this platform ...
[30/May/2020:05:47:42.633480980 -0400] - WARN - spal_meminfo_get - cgroups v1 or v2 unable to be read - may not be on this platform ...
[30/May/2020:05:47:42.634148978 -0400] - WARN - spal_meminfo_get - cgroups v1 or v2 unable to be read - may not be on this platform ...
[30/May/2020:05:47:42.635277459 -0400] - WARN - spal_meminfo_get - cgroups v1 or v2 unable to be read - may not be on this platform ...
[30/May/2020:05:47:42.635979150 -0400] - WARN - spal_meminfo_get - cgroups v1 or v2 unable to be read - may not be on this platform ...
[30/May/2020:05:47:42.637117724 -0400] - WARN - spal_meminfo_get - cgroups v1 or v2 unable to be read - may not be on this platform ...
[30/May/2020:05:47:42.643287501 -0400] - INFO - ldbm_instance_config_cachememsize_set - force a minimal value 512000
[30/May/2020:05:47:42.644013640 -0400] - WARN - spal_meminfo_get - cgroups v1 or v2 unable to be read - may not be on this platform ...
[30/May/2020:05:47:42.644624631 -0400] - WARN - spal_meminfo_get - cgroups v1 or v2 unable to be read - may not be on this platform ...
[30/May/2020:05:47:42.645384278 -0400] - WARN - spal_meminfo_get - cgroups v1 or v2 unable to be read - may not be on this platform ...
[30/May/2020:05:47:42.646901962 -0400] - WARN - spal_meminfo_get - cgroups v1 or v2 unable to be read - may not be on this platform ...
[30/May/2020:05:47:42.647497723 -0400] - WARN - spal_meminfo_get - cgroups v1 or v2 unable to be read - may not be on this platform ...
[30/May/2020:05:47:42.648074336 -0400] - WARN - spal_meminfo_get - cgroups v1 or v2 unable to be read - may not be on this platform ...
[30/May/2020:05:47:42.652656212 -0400] - WARN - spal_meminfo_get - cgroups v1 or v2 unable to be read - may not be on this platform ...
[30/May/2020:05:47:42.653234829 -0400] - WARN - spal_meminfo_get - cgroups v1 or v2 unable to be read - may not be on this platform ...
[30/May/2020:05:47:42.653593782 -0400] - NOTICE - ldbm_back_start - found 3827844k physical memory
[30/May/2020:05:47:42.653916986 -0400] - NOTICE - ldbm_back_start - found 2087268k available
[30/May/2020:05:47:42.654274811 -0400] - NOTICE - ldbm_back_start - cache autosizing: db cache: 95696k
[30/May/2020:05:47:42.654627165 -0400] - NOTICE - ldbm_back_start - cache autosizing: userRoot entry cache (3 total): 131072k
[30/May/2020:05:47:42.655162363 -0400] - WARN - spal_meminfo_get - cgroups v1 or v2 unable to be read - may not be on this platform ...
[30/May/2020:05:47:42.655557778 -0400] - NOTICE - ldbm_back_start - cache autosizing: userRoot dn cache (3 total): 65536k
[30/May/2020:05:47:42.656018406 -0400] - WARN - spal_meminfo_get - cgroups v1 or v2 unable to be read - may not be on this platform ...
[30/May/2020:05:47:42.656459995 -0400] - NOTICE - ldbm_back_start - cache autosizing: ipaca entry cache (3 total): 131072k
[30/May/2020:05:47:42.656997628 -0400] - WARN - spal_meminfo_get - cgroups v1 or v2 unable to be read - may not be on this platform ...
[30/May/2020:05:47:42.657354563 -0400] - NOTICE - ldbm_back_start - cache autosizing: ipaca dn cache (3 total): 65536k
[30/May/2020:05:47:42.657868819 -0400] - WARN - spal_meminfo_get - cgroups v1 or v2 unable to be read - may not be on this platform ...
[30/May/2020:05:47:42.658232037 -0400] - NOTICE - ldbm_back_start - cache autosizing: changelog entry cache (3 total): 131072k
[30/May/2020:05:47:42.658753071 -0400] - WARN - spal_meminfo_get - cgroups v1 or v2 unable to be read - may not be on this platform ...
[30/May/2020:05:47:42.659146629 -0400] - NOTICE - ldbm_back_start - cache autosizing: changelog dn cache (3 total): 65536k
[30/May/2020:05:47:42.659554308 -0400] - WARN - spal_meminfo_get - cgroups v1 or v2 unable to be read - may not be on this platform ...
[30/May/2020:05:47:42.659904600 -0400] - NOTICE - ldbm_back_start - total cache size: 682374020 B; 
[30/May/2020:05:47:42.661091783 -0400] - WARN - spal_meminfo_get - cgroups v1 or v2 unable to be read - may not be on this platform ...
[30/May/2020:05:47:42.664184612 -0400] - ERR - attrcrypt_unwrap_key - Failed to unwrap key for cipher AES
[30/May/2020:05:47:42.664646466 -0400] - ERR - attrcrypt_cipher_init - Symmetric key failed to unwrap with the private key; Cert might have been renewed since the key is wrapped.  To recover the encrypted contents, keep the wrapped symmetric key value.
[30/May/2020:05:47:42.665430798 -0400] - ERR - attrcrypt_unwrap_key - Failed to unwrap key for cipher 3DES
[30/May/2020:05:47:42.665945789 -0400] - ERR - attrcrypt_cipher_init - Symmetric key failed to unwrap with the private key; Cert might have been renewed since the key is wrapped.  To recover the encrypted contents, keep the wrapped symmetric key value.
[30/May/2020:05:47:42.666335191 -0400] - ERR - attrcrypt_init - All prepared ciphers are not available. Please disable attribute encryption.
[30/May/2020:05:47:42.668655844 -0400] - ERR - attrcrypt_unwrap_key - Failed to unwrap key for cipher AES
[30/May/2020:05:47:42.669093034 -0400] - ERR - attrcrypt_cipher_init - Symmetric key failed to unwrap with the private key; Cert might have been renewed since the key is wrapped.  To recover the encrypted contents, keep the wrapped symmetric key value.
[30/May/2020:05:47:42.669847423 -0400] - ERR - attrcrypt_unwrap_key - Failed to unwrap key for cipher 3DES
[30/May/2020:05:47:42.670229657 -0400] - ERR - attrcrypt_cipher_init - Symmetric key failed to unwrap with the private key; Cert might have been renewed since the key is wrapped.  To recover the encrypted contents, keep the wrapped symmetric key value.
[30/May/2020:05:47:42.670588954 -0400] - ERR - attrcrypt_init - All prepared ciphers are not available. Please disable attribute encryption.

Comment 5 Robbie Harwood 2020-05-30 15:59:28 UTC
Created attachment 1693700 [details]
ipaserver-install.log (8.3.0)

My bad, please find attached.

Comment 6 Rob Crittenden 2020-06-01 18:55:05 UTC
Based on where it failed in the ipa-server-install log it looks to me like it's failing in the initial 389-ds setup itself using lib389.

Re-assigning to 389-ds for analysis.

Comment 7 mreynolds 2020-06-01 19:04:09 UTC
This is a known issue, FIPS mode and PBKDF2 do not work together yet.  DS uses PBKDF2 by default, so that storage scheme needs to be changed before running in FIPS mode.

So this is a duplicate of:  https://bugzilla.redhat.com/show_bug.cgi?id=1779685

Comment 11 Robbie Harwood 2020-06-03 17:42:23 UTC
At Christian's suggestion, I reran the install with the hostname ipa.fips.test (instead of ipa.fips.com) and it seems to have worked.  (The dirsrv errors are still present, but I guess they don't actually break anything?)

Comment 12 Christian Heimes 2020-06-03 18:07:55 UTC
The hostname ipa.fips.com resolves to an external IP address, not a local address. This caused the installation to fail.

The PBKDF2 warnings are already tracked at #1779685.