Hi,

The stack trace says that the AJP port (8009) is
already in use. The ports are part of Tomcat (i.e.
app server) initialization, not CA (i.e. web app)
initialization, that's why the error appears in
systemd journal instead of CA debug log. Which
PKI version are you using (I can't see the logs)?

--
Endi S. Dewata

On Mon, May 3, 2021 at 3:45 PM Rob Crittenden <rcritten@redhat.com> wrote:
Looks a lot of IPA PRs have been failing the last few days due to one or
more tests in Azure failing. I cherry-picked a few and they all look
like CA startup failures during server installation, replication
creation, ipa-ca-install, etc.

In the one test I did a deeper dive into the CA debug log the start up
looks quite benign with no errors reported and it finishes up at 19:33:27

The IPA installer kicked off the restart at 19:32:11 and gave up at
19:35:23.

The journal logs a suspect (why this isn't in the CA debug log I don't
know):

Apr 30 19:32:35 master1.ipa.test server[3589]: SEVERE: Failed to
initialize component [Connector[AJP/1.3-8009]]
Apr 30 19:32:35 master1.ipa.test server[3589]:
org.apache.catalina.LifecycleException: Protocol handler initialization
failed
Apr 30 19:32:35 master1.ipa.test server[3589]:         at
org.apache.catalina.connector.Connector.initInternal(Connector.java:1042)
Apr 30 19:32:35 master1.ipa.test server[3589]:         at
org.apache.catalina.util.LifecycleBase.init(LifecycleBase.java:136)
Apr 30 19:32:35 master1.ipa.test server[3589]:         at
org.apache.catalina.core.StandardService.initInternal(StandardService.java:533)
Apr 30 19:32:35 master1.ipa.test server[3589]:         at
org.apache.catalina.util.LifecycleBase.init(LifecycleBase.java:136)
Apr 30 19:32:35 master1.ipa.test server[3589]:         at
org.apache.catalina.core.StandardServer.initInternal(StandardServer.java:1057)
Apr 30 19:32:35 master1.ipa.test server[3589]:         at
org.apache.catalina.util.LifecycleBase.init(LifecycleBase.java:136)
Apr 30 19:32:35 master1.ipa.test server[3589]:         at
org.apache.catalina.startup.Catalina.load(Catalina.java:724)
Apr 30 19:32:35 master1.ipa.test server[3589]:         at
org.apache.catalina.startup.Catalina.load(Catalina.java:746)
Apr 30 19:32:35 master1.ipa.test server[3589]:         at
sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
Apr 30 19:32:35 master1.ipa.test server[3589]:         at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
Apr 30 19:32:35 master1.ipa.test server[3589]:         at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
Apr 30 19:32:35 master1.ipa.test server[3589]:         at
java.lang.reflect.Method.invoke(Method.java:498)
Apr 30 19:32:35 master1.ipa.test server[3589]:         at
org.apache.catalina.startup.Bootstrap.load(Bootstrap.java:302)
Apr 30 19:32:35 master1.ipa.test server[3589]:         at
org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:472)
Apr 30 19:32:35 master1.ipa.test server[3589]: Caused by:
java.net.BindException: Address already in use
Apr 30 19:32:35 master1.ipa.test server[3589]:         at
sun.nio.ch.Net.bind0(Native Method)
Apr 30 19:32:35 master1.ipa.test server[3589]:         at
sun.nio.ch.Net.bind(Net.java:461)
Apr 30 19:32:35 master1.ipa.test server[3589]:         at
sun.nio.ch.Net.bind(Net.java:453)
Apr 30 19:32:35 master1.ipa.test server[3589]:         at
sun.nio.ch.ServerSocketChannelImpl.bind(ServerSocketChannelImpl.java:222)
Apr 30 19:32:35 master1.ipa.test server[3589]:         at
sun.nio.ch.ServerSocketAdaptor.bind(ServerSocketAdaptor.java:85)
Apr 30 19:32:35 master1.ipa.test server[3589]:         at
org.apache.tomcat.util.net.NioEndpoint.initServerSocket(NioEndpoint.java:228)
Apr 30 19:32:35 master1.ipa.test server[3589]:         at
org.apache.tomcat.util.net.NioEndpoint.bind(NioEndpoint.java:211)
Apr 30 19:32:35 master1.ipa.test server[3589]:         at
org.apache.tomcat.util.net.AbstractEndpoint.bindWithCleanup(AbstractEndpoint.java:1141)
Apr 30 19:32:35 master1.ipa.test server[3589]:         at
org.apache.tomcat.util.net.AbstractEndpoint.init(AbstractEndpoint.java:1154)
Apr 30 19:32:35 master1.ipa.test server[3589]:         at
org.apache.coyote.AbstractProtocol.init(AbstractProtocol.java:581)
Apr 30 19:32:35 master1.ipa.test server[3589]:         at
org.apache.catalina.connector.Connector.initInternal(Connector.java:1039)
Apr 30 19:32:35 master1.ipa.test server[3589]:         ... 13 more

and the journal is full of the expected HTTP connect issues trying to
verify that the CA is fully up.

The full logs are available at
https://dev.azure.com/freeipa/freeipa/_build/results?buildId=8758&view=artifacts&pathAsName=false&type=publishedArtifacts

Right click the three-dot thinger at the end of
logs-GATING-sudo_1_to_5_8758-1-1-3-Linux-X86 and select Download artifacts.

rob