3 May
2021
3 May
'21
4:44 p.m.
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=a...
>
> 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
>
>