Hi, this is the part of troubleshooting expired certificates (it's in another
post). I can't successfully renew certs after going back in time and I believe
the reason is that CA is not starting. Some of posts and Bugzilla bugs suggest
using PKI basic authentication, that I try without success, so I'd like to see
if I do something wrong.
ipa-server is 4.4.0 and pki-server is 10.3.3
[1] "internaldb" added to /etc/pki/pki-tomcat/password.conf hence it reads:
internal=264530051944
replicationdb=-1979518752
internaldb=directory-manager-password
[2] Edited /etc/pki/pki-tomcat/ca/CS.cfg so diff is:
61c61
< authz.instance.DirAclAuthz.ldap.ldapauth.authtype=BasicAuth
---
> authz.instance.DirAclAuthz.ldap.ldapauth.authtype=SslClientAuth
63,64c63,64
< authz.instance.DirAclAuthz.ldap.ldapconn.port=389
< authz.instance.DirAclAuthz.ldap.ldapconn.secureConn=false
---
> authz.instance.DirAclAuthz.ldap.ldapconn.port=636
> authz.instance.DirAclAuthz.ldap.ldapconn.secureConn=true
784,786c784,785
< internaldb.ldapauth.authtype=BasicAuth
< internaldb.ldapauth.bindDN=cn=Directory Manager
< internaldb.ldapauth.bindPWPrompt=internaldb
---
> internaldb.ldapauth.authtype=SslClientAuth
> internaldb.ldapauth.bindDN=uid=pkidbuser,ou=people,o=ipaca
791c790
< internaldb.ldapconn.port=389
---
> internaldb.ldapconn.port=636
793c792
< internaldb.ldapconn.secureConn=false
---
> internaldb.ldapconn.secureConn=true
[3] Restart pki-tomcatd@pki-tomcat.service
Please let me know if you need some additional logs, these are the ones I
believe can help and are relevant.
[4] /var/log/pki/pki-tomcat/catalina.2018-11-06.log
WARNING: Problem with JAR file [/usr/share/pki/server/common/lib/symkey.jar],
exists: [false], canRead: [false]
Nov 06, 2018 3:54:35 PM org.apache.catalina.startup.SetAllPropertiesRule begin
WARNING: [SetAllPropertiesRule]{Server/Service/Connector} Setting property
'enableOCSP' to 'false' did not find a matching property.
Nov 06, 2018 3:54:35 PM org.apache.catalina.startup.SetAllPropertiesRule begin
WARNING: [SetAllPropertiesRule]{Server/Service/Connector} Setting property
'ocspResponderURL' to 'http://ca-ldap04.internal.com:9080/ca/ocsp' did not find
a matching property.
Nov 06, 2018 3:54:35 PM org.apache.catalina.startup.SetAllPropertiesRule begin
WARNING: [SetAllPropertiesRule]{Server/Service/Connector} Setting property
'ocspResponderCertNickname' to 'ocspSigningCert cert-pki-ca' did not find a
matching property.
Nov 06, 2018 3:54:35 PM org.apache.catalina.startup.SetAllPropertiesRule begin
WARNING: [SetAllPropertiesRule]{Server/Service/Connector} Setting property
'ocspCacheSize' to '1000' did not find a matching property.
Nov 06, 2018 3:54:35 PM org.apache.catalina.startup.SetAllPropertiesRule begin
WARNING: [SetAllPropertiesRule]{Server/Service/Connector} Setting property
'ocspMinCacheEntryDuration' to '60' did not find a matching property.
Nov 06, 2018 3:54:35 PM org.apache.catalina.startup.SetAllPropertiesRule begin
WARNING: [SetAllPropertiesRule]{Server/Service/Connector} Setting property
'ocspMaxCacheEntryDuration' to '120' did not find a matching property.
Nov 06, 2018 3:54:35 PM org.apache.catalina.startup.SetAllPropertiesRule begin
WARNING: [SetAllPropertiesRule]{Server/Service/Connector} Setting property
'ocspTimeout' to '10' did not find a matching property.
Nov 06, 2018 3:54:35 PM org.apache.catalina.startup.SetAllPropertiesRule begin
WARNING: [SetAllPropertiesRule]{Server/Service/Connector} Setting property
'strictCiphers' to 'true' did not find a matching property.
Nov 06, 2018 3:54:35 PM org.apache.catalina.startup.SetAllPropertiesRule begin
WARNING: [SetAllPropertiesRule]{Server/Service/Connector} Setting property
'sslOptions' to 'ssl2=false,ssl3=false,tls=true' did not find a matching
property.
... shortened INFO messages ...
Nov 06, 2018 3:55:13 PM org.apache.catalina.loader.WebappClassLoaderBase
clearReferencesThreads
SEVERE: The web application [/ca] appears to have started a thread named
[LDAPConnThread-9 ldap://ca-ldap04.internal.com:389] but has failed to stop it.
This is very likely to create a memory leak.
Nov 06, 2018 3:55:13 PM org.apache.catalina.loader.WebappClassLoaderBase
clearReferencesThreads
SEVERE: The web application [/ca] appears to have started a thread named
[profileChangeMonitor] but has failed to stop it. This is very likely to create
a memory leak.
[5] /var/log/pki/pki-tomcat/ca/debug
[06/Nov/2018:15:55:28][ContainerBackgroundProcessor[StandardEngine[Catalina]]]:
CMSEngine.shutdown()
[06/Nov/2018:15:55:28][ContainerBackgroundProcessor[StandardEngine[Catalina]]]:
Destroying LdapBoundConnFactory(CrossCertPairSubsystem)
[06/Nov/2018:15:55:28][ContainerBackgroundProcessor[StandardEngine[Catalina]]]:
Destroying RollingLogFile(/var/lib/pki/pki-tomcat/logs/ca/selftests.log)
[06/Nov/2018:15:55:28][ContainerBackgroundProcessor[StandardEngine[Catalina]]]:
Destroying LogFile(/var/lib/pki/pki-tomcat/logs/ca/selftests.log)
[06/Nov/2018:15:55:28][ContainerBackgroundProcessor[StandardEngine[Catalina]]]:
SignedAuditEventFactory: create() message created for
eventType=AUDIT_LOG_SHUTDOWN
[06/Nov/2018:15:55:28][ContainerBackgroundProcessor[StandardEngine[Catalina]]]:
In LdapBoundConnFactory::getConn()
[06/Nov/2018:15:55:28][ContainerBackgroundProcessor[StandardEngine[Catalina]]]:
masterConn is null.
[06/Nov/2018:15:55:28][ContainerBackgroundProcessor[StandardEngine[Catalina]]]:
makeConnection: errorIfDown true
[06/Nov/2018:15:55:28][ContainerBackgroundProcessor[StandardEngine[Catalina]]]:
Established LDAP connection using basic authentication to host
ca-ldap04.internal.com port 389 as cn=Directory Manager
[06/Nov/2018:15:55:28][ContainerBackgroundProcessor[StandardEngine[Catalina]]]:
increasing minimum connections by 3
[06/Nov/2018:15:55:28][ContainerBackgroundProcessor[StandardEngine[Catalina]]]:
new total available connections 3
[06/Nov/2018:15:55:28][ContainerBackgroundProcessor[StandardEngine[Catalina]]]:
new number of connections 3
[06/Nov/2018:15:55:28][ContainerBackgroundProcessor[StandardEngine[Catalina]]]:
getConn: conn is connected true
[06/Nov/2018:15:55:28][ContainerBackgroundProcessor[StandardEngine[Catalina]]]:
getConn: mNumConns now 2
[06/Nov/2018:15:55:28][ContainerBackgroundProcessor[StandardEngine[Catalina]]]:
returnConn: mNumConns now 3
[06/Nov/2018:15:55:28][ContainerBackgroundProcessor[StandardEngine[Catalina]]]:
Shuting down publishing.
[06/Nov/2018:15:55:28][ContainerBackgroundProcessor[StandardEngine[Catalina]]]:
Destroying LdapBoundConnFactory(CertificateAuthority)
[06/Nov/2018:15:55:28][ContainerBackgroundProcessor[StandardEngine[Catalina]]]:
Cannot reset factory: connections not all returned
[06/Nov/2018:15:55:28][ContainerBackgroundProcessor[StandardEngine[Catalina]]]:
CertificateAuthority.shutdown: failed to reset dbFactory: Cannot reset LDAP
connection factory because some connections are still outstanding.
[6] /var/log/messages
Nov 6 15:54:34 ca-ldap04 server: INFO: Pausing ProtocolHandler
["http-bio-8080"]
Nov 6 15:54:34 ca-ldap04 systemd: Starting PKI Tomcat Server pki-tomcat...
Nov 6 15:54:34 ca-ldap04 systemd: Started PKI Tomcat Server pki-tomcat.
Nov 6 15:54:34 ca-ldap04 server: Java virtual machine used:
/usr/lib/jvm/jre-1.8.0-openjdk/bin/java
Nov 6 15:54:34 ca-ldap04 server: classpath used:
/usr/share/tomcat/bin/bootstrap.jar:/usr/share/tomcat/bin/tomcat-juli.jar:/usr/share/java/commons-daemon.jar
Nov 6 15:54:34 ca-ldap04 server: main class used:
org.apache.catalina.startup.Bootstrap
Nov 6 15:54:34 ca-ldap04 server: flags used:
-DRESTEASY_LIB=/usr/share/java/resteasy-base
-Djava.library.path=/usr/lib64/nuxwdog-jni
Nov 6 15:54:34 ca-ldap04 server: options used:
-Dcatalina.base=/var/lib/pki/pki-tomcat -Dcatalina.home=/usr/share/tomcat
-Djava.endorsed.dirs= -Djava.io.tmpdir=/var/lib/pki/pki-tomcat/temp
-Djava.util.logging.config.file=/var/lib/pki/pki-tomcat/conf/logging.properties
-Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager
-Djava.security.manager
-Djava.security.policy==/var/lib/pki/pki-tomcat/conf/catalina.policy
Nov 6 15:54:34 ca-ldap04 server: arguments used: start
Nov 6 15:54:35 ca-ldap04 server: Nov 06, 2018 3:54:35 PM
org.apache.catalina.startup.ClassLoaderFactory validateFile
Nov 6 15:54:35 ca-ldap04 server: WARNING: Problem with JAR file
[/usr/share/pki/server/common/lib/symkey.jar], exists: [false], canRead: [false]
Nov 6 15:54:35 ca-ldap04 server: Nov 06, 2018 3:54:35 PM
org.apache.catalina.startup.SetAllPropertiesRule begin
Nov 6 15:54:35 ca-ldap04 server: WARNING:
[SetAllPropertiesRule]{Server/Service/Connector} Setting property 'enableOCSP'
to 'false' did not find a matching property.
Nov 6 15:54:35 ca-ldap04 server: Nov 06, 2018 3:54:35 PM
org.apache.catalina.startup.SetAllPropertiesRule begin
Nov 6 15:54:35 ca-ldap04 server: WARNING:
[SetAllPropertiesRule]{Server/Service/Connector} Setting property
'ocspResponderURL' to 'http://ca-ldap04.internal.com:9080/ca/ocsp' did not find
a matching property.
Nov 6 15:54:35 ca-ldap04 server: Nov 06, 2018 3:54:35 PM
org.apache.catalina.startup.SetAllPropertiesRule begin
Nov 6 15:54:35 ca-ldap04 server: WARNING:
[SetAllPropertiesRule]{Server/Service/Connector} Setting property
'ocspResponderCertNickname' to 'ocspSigningCert cert-pki-ca' did not find a
matching property.
Nov 6 15:54:35 ca-ldap04 server: Nov 06, 2018 3:54:35 PM
org.apache.catalina.startup.SetAllPropertiesRule begin
Nov 6 15:54:35 ca-ldap04 server: WARNING:
[SetAllPropertiesRule]{Server/Service/Connector} Setting property
'ocspCacheSize' to '1000' did not find a matching property.
Nov 6 15:54:35 ca-ldap04 server: Nov 06, 2018 3:54:35 PM
org.apache.catalina.startup.SetAllPropertiesRule begin
Nov 6 15:54:35 ca-ldap04 server: WARNING:
[SetAllPropertiesRule]{Server/Service/Connector} Setting property
'ocspMinCacheEntryDuration' to '60' did not find a matching property.
Nov 6 15:54:35 ca-ldap04 server: Nov 06, 2018 3:54:35 PM
org.apache.catalina.startup.SetAllPropertiesRule begin
Nov 6 15:54:35 ca-ldap04 server: WARNING:
[SetAllPropertiesRule]{Server/Service/Connector} Setting property
'ocspMaxCacheEntryDuration' to '120' did not find a matching property.
Nov 6 15:54:35 ca-ldap04 server: Nov 06, 2018 3:54:35 PM
org.apache.catalina.startup.SetAllPropertiesRule begin
Nov 6 15:54:35 ca-ldap04 server: WARNING:
[SetAllPropertiesRule]{Server/Service/Connector} Setting property 'ocspTimeout'
to '10' did not find a matching property.
Nov 6 15:54:35 ca-ldap04 server: Nov 06, 2018 3:54:35 PM
org.apache.catalina.startup.SetAllPropertiesRule begin
Nov 6 15:54:35 ca-ldap04 server: WARNING:
[SetAllPropertiesRule]{Server/Service/Connector} Setting property
'strictCiphers' to 'true' did not find a matching property.
Nov 6 15:54:35 ca-ldap04 server: Nov 06, 2018 3:54:35 PM
org.apache.catalina.startup.SetAllPropertiesRule begin
Nov 6 15:54:35 ca-ldap04 server: WARNING:
[SetAllPropertiesRule]{Server/Service/Connector} Setting property 'sslOptions'
to 'ssl2=false,ssl3=false,tls=true' did not find a matching property.
Nov 6 15:54:35 ca-ldap04 server: Nov 06, 2018 3:54:35 PM
org.apache.catalina.startup.SetAllPropertiesRule begin
Nov 6 15:54:35 ca-ldap04 server: WARNING:
[SetAllPropertiesRule]{Server/Service/Connector} Setting property 'ssl2Ciphers'
to '-
SSL2_RC4_128_WITH_MD5,-SSL2_RC4_128_EXPORT40_WITH_MD5,-SSL2_RC2_128_CBC_WITH_MD5,-SSL2_RC2_128_CBC_EXPORT40_WITH_MD5,-SSL2_DES_64_CBC_WITH_MD5,-
SSL2_DES_192_EDE3_CBC_WITH_MD5' did not find a matching property.
Nov 6 15:54:35 ca-ldap04 server: Nov 06, 2018 3:54:35 PM
org.apache.catalina.startup.SetAllPropertiesRule begin
...
Nov 6 15:54:58 ca-ldap04 server: Nov 06, 2018 3:54:58 PM
org.apache.catalina.startup.HostConfig deployDescriptor
Nov 6 15:54:58 ca-ldap04 server: INFO: Deploying configuration descriptor
/etc/pki/pki-tomcat/Catalina/localhost/ca.xml
Nov 6 15:54:58 ca-ldap04 server: SSLAuthenticatorWithFallback: Creating SSL
authenticator with fallback
Nov 6 15:54:58 ca-ldap04 server: SSLAuthenticatorWithFallback: Setting
container
Nov 6 15:55:00 ca-ldap04 server: Nov 06, 2018 3:55:00 PM
org.apache.catalina.startup.TldConfig execute
Nov 6 15:55:00 ca-ldap04 server: INFO: At least one JAR was scanned for TLDs
yet contained no TLDs. Enable debug logging for this logger for a complete list
of JARs that were scanned but no TLDs were found in them. Skipping unneeded
JARs during scanning can improve startup time and JSP compilation time.
Nov 6 15:55:00 ca-ldap04 server: SSLAuthenticatorWithFallback: Initializing
authenticators
Nov 6 15:55:00 ca-ldap04 server: SSLAuthenticatorWithFallback: Starting
authenticators
Nov 6 15:55:00 ca-ldap04 server: CMSEngine.initializePasswordStore() begins
Nov 6 15:55:00 ca-ldap04 server: CMSEngine.initializePasswordStore():
tag=internaldb
Nov 6 15:55:01 ca-ldap04 server: testLDAPConnection connecting to
ca-ldap04.internal.com:389
Nov 6 15:55:01 ca-ldap04 server: CMSEngine.initializePasswordStore():
tag=replicationdb
Nov 6 15:55:01 ca-ldap04 server: testLDAPConnection connecting to
ca-ldap04.internal.com:389
Nov 6 15:55:01 ca-ldap04 server: testLDAPConnection: The specified user
cn=Replication Manager
masterAgreement1-ca-ldap04.internal.com-pki-tomcat,cn=config does not exist
Nov 6 15:55:02 ca-ldap04 server: CMSEngine: init(): password test execution
failed for replicationdbwith NO_SUCH_USER. This may not be a latest instance.
Ignoring ..
Nov 6 15:55:03 ca-ldap04 server: SelfTestSubsystem: Disabling "ca" subsystem
due to selftest failure.
Nov 6 15:55:03 ca-ldap04 server: -----------------------
Nov 6 15:55:03 ca-ldap04 server: Disabled "ca" subsystem
Nov 6 15:55:03 ca-ldap04 server: -----------------------
Nov 6 15:55:03 ca-ldap04 server: Subsystem ID: ca
Nov 6 15:55:03 ca-ldap04 server: Instance ID: pki-tomcat
Nov 6 15:55:03 ca-ldap04 server: Enabled: False
Nov 6 15:55:03 ca-ldap04 server: Invalid class name repositorytop
Nov 6 15:55:03 ca-ldap04 server: Invalid class name repositorytop
..
Nov 6 15:55:03 ca-ldap04 server: Nov 06, 2018 3:55:03 PM
org.apache.catalina.startup.HostConfig deployDescriptor
Nov 6 15:55:03 ca-ldap04 server: INFO: Deployment of configuration descriptor
/etc/pki/pki-tomcat/Catalina/localhost/ca.xml has finished in4,815 ms
Nov 6 15:55:13 ca-ldap04 server: Nov 06, 2018 3:55:13 PM
org.apache.catalina.startup.HostConfig undeploy
Nov 6 15:55:13 ca-ldap04 server: INFO: Undeploying context [/ca]
Nov 6 15:55:13 ca-ldap04 server: SSLAuthenticatorWithFallback: Stopping
authenticators
Nov 6 15:55:13 ca-ldap04 server: Nov 06, 2018 3:55:13 PM
org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
Nov 6 15:55:13 ca-ldap04 server: SEVERE: The web application [/ca] appears to
have started a thread named [LDAPConnThread-3
ldap://ca-ldap04.internal.com:389] but has failed to stop it. This is very
likely to create a memory leak.
Nov 6 15:55:13 ca-ldap04 server: Nov 06, 2018 3:55:13 PM
org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
Nov 6 15:55:13 ca-ldap04 server: SEVERE: The web application [/ca] appears to
have started a thread named [LDAPConnThread-7 ldap://ca-dap04.internal.com:389]
but has failed to stop it. This is very likely to create a memory leak.
Nov 6 15:55:13 ca-ldap04 server: Nov 06, 2018 3:55:13 PM
org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
Nov 6 15:55:13 ca-ldap04 server: SEVERE: The web application [/ca] appears to
have started a thread named [authorityMonitor] but has failed to stop it. This
is very likely to create a memory leak.
Nov 6 15:55:13 ca-ldap04 server: Nov 06, 2018 3:55:13 PM
org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
Nov 6 15:55:13 ca-ldap04 server: SEVERE: The web application [/ca] appears to
have started a thread named [LDAPConnThread-9
ldap://ca-ldap04.internal.com:389] but has failed to stop it. This is very
likely to create a memory leak.
Nov 6 15:55:13 ca-ldap04 server: Nov 06, 2018 3:55:13 PM
org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
Nov 6 15:55:13 ca-ldap04 server: SEVERE: The web application [/ca] appears to
have started a thread named [profileChangeMonitor] but has failed to stop it.
This is very likely to create a memory leak.
Nov 6 15:55:13 ca-ldap04 server: SSLAuthenticatorWithFallback: Setting
container
Nov 6 15:55:13 ca-ldap04 server: Nov 06, 2018 3:55:13 PM
org.apache.catalina.startup.HostConfig deployDescriptor
Nov 6 15:55:13 ca-ldap04 server: INFO: Deploying configuration descriptor
/etc/pki/pki-tomcat/Catalina/localhost/ca.xml
Nov 6 15:55:13 ca-ldap04 server: SSLAuthenticatorWithFallback: Creating SSL
authenticator with fallback
Nov 6 15:55:13 ca-ldap04 server: SSLAuthenticatorWithFallback: Setting
container
Nov 6 15:55:14 ca-ldap04 server: Nov 06, 2018 3:55:14 PM
org.apache.catalina.startup.TldConfig execute
Nov 6 15:55:14 ca-ldap04 server: INFO: At least one JAR was scanned for TLDs
yet contained no TLDs. Enable debug logging for this logger for a complete list
of JARs that were scanned but no TLDs were found in them. Skipping unneeded
JARs during scanning can improve startup time and JSP compilation time.
Nov 6 15:55:14 ca-ldap04 server: SSLAuthenticatorWithFallback: Initializing
authenticators
Nov 6 15:55:15 ca-ldap04 server: SSLAuthenticatorWithFallback: Starting
authenticators
Nov 6 15:55:15 ca-ldap04 server: CMSEngine.initializePasswordStore() begins
Nov 6 15:55:15 ca-ldap04 server: CMSEngine.initializePasswordStore():
tag=internaldb
Nov 6 15:55:15 ca-ldap04 server: testLDAPConnection connecting to
ca-ldap04.internal.com:389
Nov 6 15:55:15 ca-ldap04 server: CMSEngine.initializePasswordStore():
tag=replicationdb
Nov 6 15:55:15 ca-ldap04 server: testLDAPConnection connecting to
ca-ldap04.internal.com:389
Nov 6 15:55:15 ca-ldap04 server: testLDAPConnection: The specified user
cn=Replication Manager
masterAgreement1-ca-ldap04.internal.com-pki-tomcat,cn=config does not exist
_______________________________________________
FreeIPA-users mailing list -- freeipa-users@lists.fedorahosted.org
To unsubscribe send an email to freeipa-users-le...@lists.fedorahosted.org
Fedora Code of Conduct: https://getfedora.org/code-of-conduct.html
List Guidelines: https://fedoraproject.org/wiki/Mailing_list_guidelines
List Archives:
https://lists.fedorahosted.org/archives/list/freeipa-users@lists.fedorahosted.org
