[Freeipa-users] Re: freshly installed FreeIPA server dies

On Thu, 2020-07-09 at 06:13 +0000, Tony Brian Albers via FreeIPA-users wrote: > Hi guys, > > This is a new install, software used is: > ipa-server.x86_64 4.8.4-7.module+el8.2.0+6046+aaa49f96 > 389-ds-base.x86_64 1.4.2.4-8.module+el8.2.0+5959+cfcaedbd > > I followed the install instructions in the documentation, and > everything went fine. I haven't added any users or groups yet. > > I have a master and a replica. The master dies, but the replica seems > totally happy. > > I restarted the master yesterday at 13:25. However, after a short > time > running, the log files in /var/log/pki/pki-tomcat/ca/debug.. starts > filling up with java SocketExceptions like these: > > 2020-07-08 13:57:49 [profileChangeMonitor] SEVERE: Profile change > monitor: Caught exception: netscape.ldap.LDAPException: Server or > network error (81) > netscape.ldap.LDAPException: Server or network error (81) > at netscape.ldap.LDAPConnThread.networkError(Unknown Source) > at netscape.ldap.LDAPConnThread.run(Unknown Source) > at java.lang.Thread.run(Thread.java:748) > > 2020-07-08 13:57:49 [AuthorityMonitor] WARNING: AuthorityMonitor: > Failed to execute LDAP search for lightweight CAs: > netscape.ldap.LDAPException: Server or network error (81) > netscape.ldap.LDAPException: Server or network error (81) > at netscape.ldap.LDAPConnThread.networkError(Unknown Source) > at netscape.ldap.LDAPConnThread.run(Unknown Source) > at java.lang.Thread.run(Thread.java:748) > > 2020-07-08 13:57:49 [profileChangeMonitor] SEVERE: Unable to create > socket: java.net.SocketException: Network is unreachable (connect > failed) > java.net.SocketException: Network is unreachable (connect failed) > ... > > So it's pretty obvious that the LDAP server is not working properly. > > In /var/log/dirsrv/slapd-YAK2-NET/errors I see: > > 389-Directory/1.4.2.4 B2020.121.2358 > fipa001.yak2.net:636 (/etc/dirsrv/slapd-YAK2-NET) > > [08/Jul/2020:13:25:36.982866396 +0200] - INFO - slapd_extract_cert - > CA > CERT NAME: YAK2.NET IPA CA > [08/Jul/2020:13:25:37.002136210 +0200] - WARN - Security > Initialization > - SSL alert: Sending pin request to SVRCore. You may need to run > systemd-tty-ask-password-agent to provide the password. > [08/Jul/2020:13:25:37.030257707 +0200] - INFO - slapd_extract_cert - > SERVER CERT NAME: Server-Cert > [08/Jul/2020:13:25:37.049921505 +0200] - INFO - Security > Initialization > - SSL info: Enabling default cipher set. > [08/Jul/2020:13:25:37.074564197 +0200] - INFO - Security > Initialization > - SSL info: Configured NSS Ciphers > [08/Jul/2020:13:25:37.091262372 +0200] - INFO - Security > Initialization > - SSL info: TLS_AES_128_GCM_SHA256: enabled > ... > All ciphers enabled > ... > [08/Jul/2020:13:25:37.601009917 +0200] - INFO - Security > Initialization > - slapd_ssl_init2 - Configured SSL version range: min: TLS1.0, ma > x: TLS1.2 > [08/Jul/2020:13:25:37.616336615 +0200] - INFO - Security > Initialization > - slapd_ssl_init2 - NSS adjusted SSL version range: min: TLS1.2, > max: TLS1.2 > ... > [08/Jul/2020:13:25:38.547791102 +0200] - NOTICE - bdb_start - > Detected > Disorderly Shutdown last time Directory Server was running, > recovering > database. > [08/Jul/2020:13:25:38.792474100 +0200] - ERR - attrcrypt_unwrap_key - > Failed to unwrap key for cipher AES > [08/Jul/2020:13:25:38.817182778 +0200] - 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. > [08/Jul/2020:13:25:38.852524974 +0200] - ERR - attrcrypt_unwrap_key - > Failed to unwrap key for cipher 3DES > [08/Jul/2020:13:25:38.871423186 +0200] - 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. > [08/Jul/2020:13:25:38.880537833 +0200] - ERR - attrcrypt_init - All > prepared ciphers are not available. Please disable attribute > encryption. > [08/Jul/2020:13:25:38.891681971 +0200] - ERR - attrcrypt_unwrap_key - > Failed to unwrap key for cipher AES > [08/Jul/2020:13:25:38.916694998 +0200] - 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. > [08/Jul/2020:13:25:38.925787580 +0200] - ERR - attrcrypt_unwrap_key - > Failed to unwrap key for cipher 3DES > [08/Jul/2020:13:25:38.934688993 +0200] - 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. > [08/Jul/2020:13:25:38.943696327 +0200] - ERR - attrcrypt_init - All > prepared ciphers are not available. Please disable attribute > encryption. Right, so I tried doing what it says here: https://access.redhat.com/solutions/461893 Basically remove all entries starting with: dn: cn=AES,cn=encrypted attribute keys,cn=NetscapeRoot,cn=ldbm database,cn=plugins,cn=config In /etc/dirsrv/sladp-instance/dse.ldif And then I rebooted. But when it came back up, pki-tomcat was still acting up and systemd quickly set it to "failed". However, doing a 'systemctl restart pki-tomcatd(a)pki-tomcat.service' seemed to make it run. And soon I saw this in the dirsrv errors log: [09/Jul/2020:08:50:45.683765835 +0200] - INFO - NSMMReplicationPlugin - bind_and_check_pwp - agmt="cn=meTofipa002.yak2.net" (fipa002:389): Replication bind with GSSAPI auth resumed Seems that the communication with the replica is now ok. Now pki-tomcat on the master has been running for 4 hours without any errors. So this looks good. But after a reboot, it's back, pki-tomcat debug-log: 2020-07-09 13:23:33 [main] SEVERE: Unable to create socket: java.net.SocketException: Network is unreachable (connect failed) java.net.SocketException: Network is unreachable (connect failed) And again, restarting pki-tomcatd(a)pki-tomcat.service seems to fix it, so it's like pki-tomcat tries to start before the LDAP server is ready and then it just goes fubar. Any good ideas anyone?