Bug 1655808 - com.netscape.cms.tomcat.PKIListener missing from /etc/pki/pki-tomcat/server.xml after F27 -> F29 FreeIPA server upgrade, breaks FreeIPA
Summary: com.netscape.cms.tomcat.PKIListener missing from /etc/pki/pki-tomcat/server.x...
Keywords:
Status: CLOSED CURRENTRELEASE
Alias: None
Product: Fedora
Classification: Fedora
Component: pki-core
Version: 29
Hardware: x86_64
OS: Linux
unspecified
high
Target Milestone: ---
Assignee: Matthew Harmsen
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2018-12-04 00:46 UTC by Adam Williamson
Modified: 2019-11-13 22:55 UTC (History)
8 users (show)

Fixed In Version: pki-core-10.7.0-1.fc29
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2019-10-31 19:49:47 UTC


Attachments (Terms of Use)

Description Adam Williamson 2018-12-04 00:46:35 UTC
I upgraded my own FreeIPA server from Fedora 27 to Fedora 29 today. On reboot, ipa.service was failed, and the logs indicated the FreeIPA upgrade process was not completing successfully due to inability to access the CA.

Poking around a bit I found some errors in the dogtag logs, a NoSuchProviderException during service startup:

Dec 03 14:52:59 id.happyassassin.net server[7656]: SEVERE: Failed to load keystore type [pkcs11] with path [/var/lib/.keystore] due to [no such provider: Mozilla-JSS]
Dec 03 14:52:59 id.happyassassin.net server[7656]: java.security.NoSuchProviderException: no such provider: Mozilla-JSS
Dec 03 14:52:59 id.happyassassin.net server[7656]:         at sun.security.jca.GetInstance.getService(GetInstance.java:83)
Dec 03 14:52:59 id.happyassassin.net server[7656]:         at sun.security.jca.GetInstance.getInstance(GetInstance.java:206)
Dec 03 14:52:59 id.happyassassin.net server[7656]:         at java.security.Security.getImpl(Security.java:731)
Dec 03 14:52:59 id.happyassassin.net server[7656]:         at java.security.KeyStore.getInstance(KeyStore.java:896)
Dec 03 14:52:59 id.happyassassin.net server[7656]:         at org.apache.tomcat.util.net.SSLUtilBase.getStore(SSLUtilBase.java:127)
Dec 03 14:52:59 id.happyassassin.net server[7656]:         at org.apache.tomcat.util.net.SSLHostConfigCertificate.getCertificateKeystore(SSLHostConfigCertificate.java:204)
Dec 03 14:52:59 id.happyassassin.net server[7656]:         at org.apache.tomcat.util.net.jsse.JSSEUtil.getKeyManagers(JSSEUtil.java:184)
Dec 03 14:52:59 id.happyassassin.net server[7656]:         at org.apache.tomcat.util.net.AbstractJsseEndpoint.createSSLContext(AbstractJsseEndpoint.java:112)
Dec 03 14:52:59 id.happyassassin.net server[7656]:         at org.apache.tomcat.util.net.AbstractJsseEndpoint.initialiseSsl(AbstractJsseEndpoint.java:85)
Dec 03 14:52:59 id.happyassassin.net server[7656]:         at org.apache.tomcat.util.net.NioEndpoint.bind(NioEndpoint.java:216)
Dec 03 14:52:59 id.happyassassin.net server[7656]:         at org.apache.tomcat.util.net.AbstractEndpoint.init(AbstractEndpoint.java:1043)
Dec 03 14:52:59 id.happyassassin.net server[7656]:         at org.apache.coyote.AbstractProtocol.init(AbstractProtocol.java:540)
Dec 03 14:52:59 id.happyassassin.net server[7656]:         at org.apache.coyote.http11.AbstractHttp11Protocol.init(AbstractHttp11Protocol.java:74)
Dec 03 14:52:59 id.happyassassin.net server[7656]:         at org.apache.catalina.connector.Connector.initInternal(Connector.java:932)
Dec 03 14:52:59 id.happyassassin.net server[7656]:         at org.apache.catalina.util.LifecycleBase.init(LifecycleBase.java:136)
Dec 03 14:52:59 id.happyassassin.net server[7656]:         at org.apache.catalina.core.StandardService.initInternal(StandardService.java:530)
Dec 03 14:52:59 id.happyassassin.net server[7656]:         at org.apache.catalina.util.LifecycleBase.init(LifecycleBase.java:136)
Dec 03 14:52:59 id.happyassassin.net server[7656]:         at org.apache.catalina.core.StandardServer.initInternal(StandardServer.java:852)
Dec 03 14:52:59 id.happyassassin.net server[7656]:         at org.apache.catalina.util.LifecycleBase.init(LifecycleBase.java:136)
Dec 03 14:52:59 id.happyassassin.net server[7656]:         at org.apache.catalina.startup.Catalina.load(Catalina.java:633)
Dec 03 14:52:59 id.happyassassin.net server[7656]:         at org.apache.catalina.startup.Catalina.load(Catalina.java:656)
Dec 03 14:52:59 id.happyassassin.net server[7656]:         at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
Dec 03 14:52:59 id.happyassassin.net server[7656]:         at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
Dec 03 14:52:59 id.happyassassin.net server[7656]:         at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
Dec 03 14:52:59 id.happyassassin.net server[7656]:         at java.lang.reflect.Method.invoke(Method.java:498)
Dec 03 14:52:59 id.happyassassin.net server[7656]:         at org.apache.catalina.startup.Bootstrap.load(Bootstrap.java:306)
Dec 03 14:52:59 id.happyassassin.net server[7656]:         at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:491)
Dec 03 14:52:59 id.happyassassin.net server[7656]: Dec 03, 2018 2:52:59 PM org.apache.catalina.util.LifecycleBase handleSubClassException
Dec 03 14:52:59 id.happyassassin.net server[7656]: SEVERE: Failed to initialize component [Connector[org.dogtagpki.tomcat.Http11NioProtocol-8443]]
Dec 03 14:52:59 id.happyassassin.net server[7656]: org.apache.catalina.LifecycleException: Protocol handler initialization failed
Dec 03 14:52:59 id.happyassassin.net server[7656]:         at org.apache.catalina.connector.Connector.initInternal(Connector.java:935)
Dec 03 14:52:59 id.happyassassin.net server[7656]:         at org.apache.catalina.util.LifecycleBase.init(LifecycleBase.java:136)
Dec 03 14:52:59 id.happyassassin.net server[7656]:         at org.apache.catalina.core.StandardService.initInternal(StandardService.java:530)
Dec 03 14:52:59 id.happyassassin.net server[7656]:         at org.apache.catalina.util.LifecycleBase.init(LifecycleBase.java:136)
Dec 03 14:52:59 id.happyassassin.net server[7656]:         at org.apache.catalina.core.StandardServer.initInternal(StandardServer.java:852)
Dec 03 14:52:59 id.happyassassin.net server[7656]:         at org.apache.catalina.util.LifecycleBase.init(LifecycleBase.java:136)
Dec 03 14:52:59 id.happyassassin.net server[7656]:         at org.apache.catalina.startup.Catalina.load(Catalina.java:633)
Dec 03 14:52:59 id.happyassassin.net server[7656]:         at org.apache.catalina.startup.Catalina.load(Catalina.java:656)
Dec 03 14:52:59 id.happyassassin.net server[7656]:         at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
Dec 03 14:52:59 id.happyassassin.net server[7656]:         at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
Dec 03 14:52:59 id.happyassassin.net server[7656]:         at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
Dec 03 14:52:59 id.happyassassin.net server[7656]:         at java.lang.reflect.Method.invoke(Method.java:498)
Dec 03 14:52:59 id.happyassassin.net server[7656]:         at org.apache.catalina.startup.Bootstrap.load(Bootstrap.java:306)
Dec 03 14:52:59 id.happyassassin.net server[7656]:         at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:491)
Dec 03 14:52:59 id.happyassassin.net server[7656]: Caused by: java.lang.IllegalArgumentException: Failed to load keystore type [pkcs11] with path [/var/lib/.keystore] due to [no such provider: Mozilla-JSS]
Dec 03 14:52:59 id.happyassassin.net server[7656]:         at org.apache.tomcat.util.net.AbstractJsseEndpoint.createSSLContext(AbstractJsseEndpoint.java:114)
Dec 03 14:52:59 id.happyassassin.net server[7656]:         at org.apache.tomcat.util.net.AbstractJsseEndpoint.initialiseSsl(AbstractJsseEndpoint.java:85)
Dec 03 14:52:59 id.happyassassin.net server[7656]:         at org.apache.tomcat.util.net.NioEndpoint.bind(NioEndpoint.java:216)
Dec 03 14:52:59 id.happyassassin.net server[7656]:         at org.apache.tomcat.util.net.AbstractEndpoint.init(AbstractEndpoint.java:1043)
Dec 03 14:52:59 id.happyassassin.net server[7656]:         at org.apache.coyote.AbstractProtocol.init(AbstractProtocol.java:540)
Dec 03 14:52:59 id.happyassassin.net server[7656]:         at org.apache.coyote.http11.AbstractHttp11Protocol.init(AbstractHttp11Protocol.java:74)
Dec 03 14:52:59 id.happyassassin.net server[7656]:         at org.apache.catalina.connector.Connector.initInternal(Connector.java:932)
Dec 03 14:52:59 id.happyassassin.net server[7656]:         ... 13 more
Dec 03 14:52:59 id.happyassassin.net server[7656]: Caused by: java.io.IOException: Failed to load keystore type [pkcs11] with path [/var/lib/.keystore] due to [no such provider: Mozilla-JSS]
Dec 03 14:52:59 id.happyassassin.net server[7656]:         at org.apache.tomcat.util.net.SSLUtilBase.getStore(SSLUtilBase.java:150)
Dec 03 14:52:59 id.happyassassin.net server[7656]:         at org.apache.tomcat.util.net.SSLHostConfigCertificate.getCertificateKeystore(SSLHostConfigCertificate.java:204)
Dec 03 14:52:59 id.happyassassin.net server[7656]:         at org.apache.tomcat.util.net.jsse.JSSEUtil.getKeyManagers(JSSEUtil.java:184)
Dec 03 14:52:59 id.happyassassin.net server[7656]:         at org.apache.tomcat.util.net.AbstractJsseEndpoint.createSSLContext(AbstractJsseEndpoint.java:112)
Dec 03 14:52:59 id.happyassassin.net server[7656]:         ... 19 more

cipherboy (ascheel) came up with the solution. This line needed to be added to /etc/pki/pki-tomcat/server.xml:

    <Listener className="com.netscape.cms.tomcat.PKIListener"/>

along with the other listeners. The upgrade process did not do this. Once I added that line and restarted tomcat, it started without the exception, and I could then restart ipa.service successfully - it ran the FreeIPA upgrade process successfully this time, and my server came up working.

Comment 1 jonnyfahrenheit 2019-01-08 15:54:26 UTC
   Hi Adam, I'm getting exactly this error as well, although I'm upgrading from fedora 27 to 28. I tried using the "Listener" line but no matter where I place it, the service fails to start the connector on port 8443.

   Can you post details on where this line needs to sit in the server.xml please?

   Thanks in advance...

Comment 2 Dinesh Prasanth 2019-01-08 16:22:25 UTC
@jonny,

You need to add it to:

<Server port="8005" shutdown="SHUTDOWN">
   <Listener className="org.apache.catalina.startup.VersionLoggerListener"/>
   ...
   <Listener className="org.apache.catalina.core.JreMemoryLeakPreventionListener"/>
   <Listener className="org.apache.catalina.mbeans.GlobalResourcesLifecycleListener"/>
   <Listener className="org.apache.catalina.core.ThreadLocalLeakPreventionListener"/>
   <Listener className="com.netscape.cms.tomcat.PKIListener"/>
   ...
</Server>

Hope this helps.

Comment 3 jonnyfahrenheit 2019-01-09 12:43:06 UTC
   Hi Dinesh, thank you for the prompt reply...I rolled back the server and went through the OS upgrade again from 27 to 28. This time, after the new fedora 28 OS booted up, I checked the pki-tomcatd@pki-tomcat.service and the Mozilla-JSS was present. I put the listener line in and restarted the service. This time I got further and received a new error which I will include with preceding startup entries:-

09-Jan-2019 11:07:08.367 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server version:        Apache Tomcat/8.5.32
09-Jan-2019 11:07:08.371 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server built:          Aug 1 2018 01:30:11 UTC
09-Jan-2019 11:07:08.373 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server number:         8.5.32.0
09-Jan-2019 11:07:08.375 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log OS Name:               Linux
09-Jan-2019 11:07:08.378 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log OS Version:            4.19.13-200.fc28.x86_64
09-Jan-2019 11:07:08.382 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Architecture:          amd64
09-Jan-2019 11:07:08.384 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Java Home:             /usr/lib/jvm/java-1.8.0-openjdk-1.8.0.191.b12-11.fc28.x86_64/jre
09-Jan-2019 11:07:08.389 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log JVM Version:           1.8.0_191-b12
09-Jan-2019 11:07:08.390 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log JVM Vendor:            Oracle Corporation
09-Jan-2019 11:07:08.392 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log CATALINA_BASE:         /var/lib/pki/pki-tomcat
09-Jan-2019 11:07:08.394 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log CATALINA_HOME:         /usr/share/tomcat
09-Jan-2019 11:07:08.396 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -DRESTEASY_LIB=/usr/share/java/resteasy
09-Jan-2019 11:07:08.397 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcatalina.base=/var/lib/pki/pki-tomcat
09-Jan-2019 11:07:08.405 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcatalina.home=/usr/share/tomcat
09-Jan-2019 11:07:08.410 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.endorsed.dirs=
09-Jan-2019 11:07:08.414 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.io.tmpdir=/var/lib/pki/pki-tomcat/temp
09-Jan-2019 11:07:08.419 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.util.logging.config.file=/var/lib/pki/pki-tomcat/conf/logging.properties
09-Jan-2019 11:07:08.422 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager
09-Jan-2019 11:07:08.427 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.security.manager
09-Jan-2019 11:07:08.430 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.security.policy==/var/lib/pki/pki-tomcat/conf/catalina.policy
09-Jan-2019 11:07:08.688 INFO [main] com.netscape.cms.tomcat.PKIListener.lifecycleEvent PKIListener: org.apache.catalina.core.StandardServer [before_init]
09-Jan-2019 11:07:08.711 INFO [main] com.netscape.cms.tomcat.PKIListener.lifecycleEvent PKIListener: Initializing TomcatJSS
09-Jan-2019 11:07:08.828 INFO [main] org.apache.tomcat.util.net.jss.TomcatJSS.init TomcatJSS: initialization
09-Jan-2019 11:07:08.840 INFO [main] org.mozilla.jss.CryptoManager.<clinit> CryptoManager: loading JSS library
09-Jan-2019 11:07:08.849 INFO [main] org.mozilla.jss.CryptoManager.<clinit> CryptoManager: loaded JSS library from /usr/lib64/jss/libjss4.so
09-Jan-2019 11:07:08.854 INFO [main] org.mozilla.jss.CryptoManager.initialize CryptoManager: initializing NSS database at /var/lib/pki/pki-tomcat/alias
09-Jan-2019 11:07:08.983 INFO [main] org.apache.tomcat.util.net.jss.TomcatJSS.configureOCSP configuring OCSP
09-Jan-2019 11:07:09.129 WARNING [main] org.apache.tomcat.util.net.jss.TomcatJSS.setSSLCiphers Unable to set SSL cipher preference: org.mozilla.jss.ssl.SSLSocketException: Failed to enable cipher 0xc02d
: (-12266) An unknown SSL cipher suite has been requested.
09-Jan-2019 11:07:09.132 WARNING [main] org.apache.tomcat.util.net.jss.TomcatJSS.setSSLCiphers SSL ECC cipher "TLS_ECDH_ECDSA_WITH_AES_128_GCM_SHA256" unsupported by NSS. This is probably O.K. unless ECC support has been installed.
09-Jan-2019 11:07:09.136 WARNING [main] org.apache.tomcat.util.net.jss.TomcatJSS.setSSLCiphers Unable to set SSL cipher preference: org.mozilla.jss.ssl.SSLSocketException: Failed to enable cipher 0xc031
: (-12266) An unknown SSL cipher suite has been requested.
09-Jan-2019 11:07:09.138 WARNING [main] org.apache.tomcat.util.net.jss.TomcatJSS.setSSLCiphers SSL ECC cipher "TLS_ECDH_RSA_WITH_AES_128_GCM_SHA256" unsupported by NSS. This is probably O.K. unless ECC support has been installed.
09-Jan-2019 11:07:09.140 INFO [main] org.apache.tomcat.util.net.jss.TomcatJSS.init TomcatJSS: initialization complete
09-Jan-2019 11:07:09.352 INFO [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["http-nio-8080"]
09-Jan-2019 11:07:09.410 INFO [main] org.apache.tomcat.util.net.NioSelectorPool.getSharedSelector Using a shared selector for servlet write/read
09-Jan-2019 11:07:09.495 INFO [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["https-jsse-nio-8443"]
09-Jan-2019 11:07:10.217 INFO [main] org.apache.tomcat.util.net.NioSelectorPool.getSharedSelector Using a shared selector for servlet write/read
09-Jan-2019 11:07:10.221 INFO [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["ajp-nio-127.0.0.1-8009"]
09-Jan-2019 11:07:10.236 INFO [main] org.apache.tomcat.util.net.NioSelectorPool.getSharedSelector Using a shared selector for servlet write/read
09-Jan-2019 11:07:10.242 INFO [main] com.netscape.cms.tomcat.PKIListener.lifecycleEvent PKIListener: org.apache.catalina.core.StandardServer [after_init]
09-Jan-2019 11:07:10.243 INFO [main] org.apache.catalina.startup.Catalina.load Initialization processed in 3851 ms
09-Jan-2019 11:07:10.244 INFO [main] com.netscape.cms.tomcat.PKIListener.lifecycleEvent PKIListener: org.apache.catalina.core.StandardServer [before_start]
09-Jan-2019 11:07:10.286 INFO [main] com.netscape.cms.tomcat.PKIListener.lifecycleEvent PKIListener: org.apache.catalina.core.StandardServer [configure_start]
09-Jan-2019 11:07:10.371 INFO [main] com.netscape.cms.tomcat.PKIListener.lifecycleEvent PKIListener: org.apache.catalina.core.StandardServer [start]
09-Jan-2019 11:07:10.381 INFO [main] org.apache.catalina.core.StandardService.startInternal Starting service [Catalina]
09-Jan-2019 11:07:10.386 INFO [main] org.apache.catalina.core.StandardEngine.startInternal Starting Servlet Engine: Apache Tomcat/8.5.32
09-Jan-2019 11:07:10.441 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDescriptor Deploying configuration descriptor [/etc/pki/pki-tomcat/Catalina/localhost/pki.xml]
09-Jan-2019 11:07:18.433 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDescriptor Deployment of configuration descriptor [/etc/pki/pki-tomcat/Catalina/localhost/pki.xml] has finished in [7,992] ms
09-Jan-2019 11:07:18.436 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDescriptor Deploying configuration descriptor [/etc/pki/pki-tomcat/Catalina/localhost/ca.xml]
09-Jan-2019 11:07:18.471 INFO [localhost-startStop-1] com.netscape.cms.tomcat.AbstractPKIAuthenticator.<init> PKIAuthenticator: Creating SSLAuthenticatorWithFallback
09-Jan-2019 11:07:25.562 INFO [localhost-startStop-1] org.apache.jasper.servlet.TldScanner.scanJars 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.
09-Jan-2019 11:07:25.810 SEVERE [localhost-startStop-1] com.netscape.cms.servlet.base.CMSStartServlet.init Unable to create CMS engine: com.netscape.cmscore.apps.CMSEngine
 java.lang.InstantiationException: com.netscape.cmscore.apps.CMSEngine
        at java.lang.Class.newInstance(Class.java:427)
        at com.netscape.cms.servlet.base.CMSStartServlet.init(CMSStartServlet.java:138)
        at javax.servlet.GenericServlet.init(GenericServlet.java:158)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:498)
        at org.apache.catalina.security.SecurityUtil$1.run(SecurityUtil.java:282)
        at org.apache.catalina.security.SecurityUtil$1.run(SecurityUtil.java:279)
        at java.security.AccessController.doPrivileged(Native Method)
        at javax.security.auth.Subject.doAsPrivileged(Subject.java:549)
        at org.apache.catalina.security.SecurityUtil.execute(SecurityUtil.java:314)
        at org.apache.catalina.security.SecurityUtil.doAsPrivilege(SecurityUtil.java:170)
        at org.apache.catalina.security.SecurityUtil.doAsPrivilege(SecurityUtil.java:123)
        at org.apache.catalina.core.StandardWrapper.initServlet(StandardWrapper.java:1132)
        at org.apache.catalina.core.StandardWrapper.loadServlet(StandardWrapper.java:1091)
        at org.apache.catalina.core.StandardWrapper.load(StandardWrapper.java:983)
        at org.apache.catalina.core.StandardContext.loadOnStartup(StandardContext.java:4978)
        at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5290)
        at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:150)
        at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:754)
        at org.apache.catalina.core.ContainerBase.access$000(ContainerBase.java:129)
        at org.apache.catalina.core.ContainerBase$PrivilegedAddChild.run(ContainerBase.java:150)
        at org.apache.catalina.core.ContainerBase$PrivilegedAddChild.run(ContainerBase.java:140)
        at java.security.AccessController.doPrivileged(Native Method)
        at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:728)
        at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:734)
        at org.apache.catalina.startup.HostConfig.deployDescriptor(HostConfig.java:629)
        at org.apache.catalina.startup.HostConfig$DeployDescriptor.run(HostConfig.java:1839)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
        at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.NoSuchMethodException: com.netscape.cmscore.apps.CMSEngine.<init>()
        at java.lang.Class.getConstructor0(Class.java:3082)
        at java.lang.Class.newInstance(Class.java:412)
        ... 33 more

09-Jan-2019 11:07:25.867 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDescriptor Deployment of configuration descriptor [/etc/pki/pki-tomcat/Catalina/localhost/ca.xml] has finished in [7,427] ms
09-Jan-2019 11:07:25.878 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDescriptor Deploying configuration descriptor [/etc/pki/pki-tomcat/Catalina/localhost/ROOT.xml]
09-Jan-2019 11:07:30.547 INFO [localhost-startStop-1] org.apache.jasper.servlet.TldScanner.scanJars 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.
09-Jan-2019 11:07:30.566 INFO [localhost-startStop-1] org.apache.catalina.startup.HostConfig.deployDescriptor Deployment of configuration descriptor [/etc/pki/pki-tomcat/Catalina/localhost/ROOT.xml] has finished in [4,688] ms
09-Jan-2019 11:07:30.578 INFO [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["http-nio-8080"]
09-Jan-2019 11:07:30.713 INFO [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["https-jsse-nio-8443"]
09-Jan-2019 11:07:30.836 INFO [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["ajp-nio-127.0.0.1-8009"]
09-Jan-2019 11:07:30.886 INFO [main] com.netscape.cms.tomcat.PKIListener.lifecycleEvent PKIListener: org.apache.catalina.core.StandardServer [after_start]
09-Jan-2019 11:07:30.899 INFO [main] com.netscape.cms.tomcat.PKIListener.verifySubsystems PKIListener: Subsystem CA is running.
09-Jan-2019 11:07:30.906 INFO [main] org.apache.catalina.startup.Catalina.start Server startup in 20661 ms
09-Jan-2019 11:07:40.591 WARNING [ContainerBackgroundProcessor[StandardEngine[Catalina]]] org.apache.catalina.core.ContainerBase.backgroundProcess Exception processing realm [com.netscape.cms.tomcat.ProxyRealm@61344244] background process
 javax.ws.rs.ServiceUnavailableException: Subsystem unavailable
        at com.netscape.cms.tomcat.ProxyRealm.backgroundProcess(ProxyRealm.java:142)
        at org.apache.catalina.core.ContainerBase.backgroundProcess(ContainerBase.java:1152)
        at org.apache.catalina.core.StandardContext.backgroundProcess(StandardContext.java:5648)
        at org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.processChildren(ContainerBase.java:1390)
        at org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.processChildren(ContainerBase.java:1394)
        at org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.processChildren(ContainerBase.java:1394)
        at org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.run(ContainerBase.java:1362)
        at java.lang.Thread.run(Thread.java:748)



   The last section of the log starting at "09-Jan-2019 11:07:40.591" repeats every 10 seconds after that.

   At this point I tried issuing "ipa-server-upgrade" but of course that fails to contact the CA and the following url gives a "HTTP Status 500 – Internal Server Error":-

http://ipa.mydomain.org:8080/ca/admin/ca/getStatus

   Obviously, "ipa.mydomain.org is not the hostname for the server but used as an example...

   Sorry for the long post.

Jonny

Comment 4 Adam Williamson 2019-02-09 16:50:28 UTC
mharmsen: is there any plan to fix this for future upgrades or are we just supposed to document this or what?

Comment 5 jonnyfahrenheit 2019-03-25 12:10:03 UTC
   Hi there, is there an update to this issue yet? I'm now using an unsupported version of fedora (27) and I am desperate to upgrade.

   Thanks in advance for your time...

Jonny

Comment 6 Adam Williamson 2019-03-25 15:19:31 UTC
Jonny: sorry, I didn't notice your follow-up comment before. That looks like a different issue to this one, but I don't know how to fix it, sorry (I am no Java expert). Perhaps someone else on this bug could help you, or maybe ask in #freeipa on Freenode IRC?

Comment 7 Endi Sukma Dewata 2019-03-27 15:34:02 UTC
Adam, I installed a new IPA server on F27 and it already has com.netscape.cms.tomcat.PKIListener. Did you upgrade your server from an older Fedora?

Jonny, the stack trace indicates a problem creating CMSEngine object. The constructor for this class indeed changed between PKI 10.5 and 10.6:
* https://github.com/dogtagpki/pki/blob/DOGTAG_10_5_BRANCH/base/server/cmscore/src/com/netscape/cmscore/apps/CMSEngine.java#L299
* https://github.com/dogtagpki/pki/blob/DOGTAG_10_6_BRANCH/base/server/cmscore/src/com/netscape/cmscore/apps/CMSEngine.java#L221

If the upgrade worked correctly you shouldn't see this problem. Could you check to make sure you don't have a mix of PKI 10.5 and 10.6 RPM packages? Regardless, I think this is a different issue. Feel free to open a separate ticket.

Comment 8 Adam Williamson 2019-03-27 16:05:06 UTC
Endi: yes. It started out as approximately Fedora 19 or something. This is why I find a lot of bugs like this.

Comment 9 Endi Sukma Dewata 2019-04-23 19:02:16 UTC
This is fixed in master (PKI 10.7):
https://github.com/dogtagpki/pki/commit/dd974891a22ecbbdffd91df9d75044e09e60ca71

It may need to be cherry-picked into PKI 10.6 branch and released into Fedora 28+.

Comment 10 jonnyfahrenheit 2019-06-19 13:07:30 UTC
   Hi Endi, after the dnf system-upgrade, I checked the versions of pki and there was only the new 10.6 rpms installed. How should I proceed at this point?

Jonny

Comment 11 Endi Sukma Dewata 2019-06-19 13:48:51 UTC
Hi Jonny, the PKI 10.7 was released in F29 and F30:
* https://bodhi.fedoraproject.org/updates/FEDORA-2019-40e2ad6d2c
* https://bodhi.fedoraproject.org/updates/FEDORA-2019-1337735a42

As mentioned in comment #7, the CMSEngine issue seems to be an environment issue. Make sure all PKI packages installed are all in the same version.

Comment 12 jonnyfahrenheit 2019-06-19 16:08:24 UTC
   Thanks for the response Endi, I tried going from fc27 to 29 this time. PKI tomcat complains about a missing jar file:tomcat-pki-3.1-api.jar and fails. rpms installed for pki tomcat are all 10.7 this time.

   I guess I need to open a new ticket but need to ask for guidance on this issue as I have put quite a bit of time into this problem already. Can I even open a ticket for upgrade to fc28 now? Or would I need to try resolving through  upgrade from 27 to 29.

Jonny

Comment 13 jonnyfahrenheit 2019-06-19 16:22:47 UTC
   Sorry Endi, that jar filename was tomcat-servlet-3.1-api.jar

Jonny

Comment 14 Endi Sukma Dewata 2019-06-19 16:35:15 UTC
Jonny, could you post the command that you executed and the actual error message?
Could you also show which pki/tomcat/jss/tomcatjss packages are installed?

I'm not sure you can open an F28 ticket, but for sure we can't release an official
F28 build anymore. I'd suggest you try upgrading directly to F29, and if it fails
with an error unrelated to the missing PKIListener please open a new ticket with
the above information included. Thanks!

Comment 15 Ben Cotton 2019-10-31 19:06:50 UTC
This message is a reminder that Fedora 29 is nearing its end of life.
Fedora will stop maintaining and issuing updates for Fedora 29 on 2019-11-26.
It is Fedora's policy to close all bug reports from releases that are no longer
maintained. At that time this bug will be closed as EOL if it remains open with a
Fedora 'version' of '29'.

Package Maintainer: If you wish for this bug to remain open because you
plan to fix it in a currently maintained version, simply change the 'version' 
to a later Fedora version.

Thank you for reporting this issue and we are sorry that we were not 
able to fix it before Fedora 29 is end of life. If you would still like 
to see this bug fixed and are able to reproduce it against a later version 
of Fedora, you are encouraged  change the 'version' to a later Fedora 
version prior this bug is closed as described in the policy above.

Although we aim to fix as many bugs as possible during every release's 
lifetime, sometimes those efforts are overtaken by events. Often a 
more recent Fedora release includes newer upstream software that fixes 
bugs or makes them obsolete.


Note You need to log in before you can comment on or make changes to this bug.