It's an issue we started to see randomly in upstream PRCI tests about 2 months ago, see https://pagure.io/freeipa/issue/8748.
On pki side the ticket https://github.com/dogtagpki/pki/issues/3472 was opened.

Seen on fedora32, fedora33, and more and more frequently in azure pipelines that are using a fedora32 container.
Endi, the logs now collect /etc/pki/pki-tomcat/server.xml and /etc/pki/pki-tomcat/ca/CS.cfg. Do you see other files that could help troubleshoot and that we should also collect?

flo

On Tue, May 4, 2021 at 6:23 AM Alexander Bokovoy via FreeIPA-devel <freeipa-devel@lists.fedorahosted.org> wrote:
On ma, 03 touko 2021, Endi Dewata via FreeIPA-devel wrote:
>On Mon, May 3, 2021 at 4:54 PM Rob Crittenden <rcritten@redhat.com> wrote:
>
>> Endi Dewata wrote:
>> > 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)?
>>
>> It doesn't look like Azure captures the versions of installed packages
>> but CS.cfg says cms.product.version=10.10.5
>>
>> rob
>>
>
>There has been no PKI updates for almost 2 months:
>https://koji.fedoraproject.org/koji/buildinfo?buildID=1722678
>so I doubt this was caused by PKI.
>
>I see new Tomcat and OpenJDK updates:
>https://koji.fedoraproject.org/koji/buildinfo?buildID=1739112
>https://koji.fedoraproject.org/koji/buildinfo?buildID=1738932
>You might want to try downgrading them. I don't see
>any issues in PKI CI though.

Azure tests run on Fedora 32. Here are the logs for preparing that environment:
https://dev.azure.com/freeipa/dd9bf4ec-d636-4558-8f6e-ee17af87f33b/_apis/build/builds/8758/logs/58

2021-04-30T19:02:27.9424285Z  java-1.8.0-openjdk-headless       x86_64  1:1.8.0.292.b10-0.fc32                     updates        33 M
2021-04-30T19:02:27.9715663Z  tomcat                            noarch  1:9.0.39-2.fc32                            updates        90 k
2021-04-30T19:02:27.9716706Z  tomcat-el-3.0-api                 noarch  1:9.0.39-2.fc32                            updates       106 k
2021-04-30T19:02:27.9717743Z  tomcat-jsp-2.3-api                noarch  1:9.0.39-2.fc32                            updates        63 k
2021-04-30T19:02:27.9718797Z  tomcat-lib                        noarch  1:9.0.39-2.fc32                            updates       5.3 M
2021-04-30T19:02:27.9719823Z  tomcat-servlet-4.0-api            noarch  1:9.0.39-2.fc32                            updates       280 k
2021-04-30T19:02:27.9720851Z  tomcatjss                         noarch  7.6.1-1.fc32                               updates        38 k

and

2021-04-30T19:02:27.9575285Z  pki-acme                          noarch  10.10.5-5.fc32                             updates       985 k
2021-04-30T19:02:27.9576151Z  pki-base                          noarch  10.10.5-5.fc32                             updates       260 k
2021-04-30T19:02:27.9577006Z  pki-base-java                     noarch  10.10.5-5.fc32                             updates       660 k
2021-04-30T19:02:27.9577842Z  pki-ca                            noarch  10.10.5-5.fc32                             updates       1.0 M
2021-04-30T19:02:27.9578697Z  pki-kra                           noarch  10.10.5-5.fc32                             updates       193 k
2021-04-30T19:02:27.9579535Z  pki-server                        noarch  10.10.5-5.fc32                             updates       2.9 M
2021-04-30T19:02:27.9580836Z  pki-symkey                        x86_64  10.10.5-5.fc32                             updates        51 k
2021-04-30T19:02:27.9581832Z  pki-tools                         x86_64  10.10.5-5.fc32                             updates       741 k

This was run with OpenJDK from https://bodhi.fedoraproject.org/updates/FEDORA-2021-f71b592e07.

Latest OpenJDK update is https://bodhi.fedoraproject.org/updates/FEDORA-2021-b88e86b753 but it only went to stable this weekend.

Sadly, we don't run OpenQA FreeIPA tests against F32 anymore but Rawhide
runs with the latest OpenJDK 11.0.11 update are passing just fine
(search for 'domain_controller'):

https://openqa.fedoraproject.org/tests/overview.html?distri=fedora&version=Rawhide&build=Fedora-Rawhide-20210502.n.0&groupid=1


Since Azure tests are using standard Fedora updates, we cannot really
'downgrade'.



>--
>Endi S. Dewata
>
>>
>> > --
>> > Endi S. Dewata
>> >
>> > On Mon, May 3, 2021 at 3:45 PM Rob Crittenden <rcritten@redhat.com
>> > <mailto: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
>> >     <http://sun.nio.ch
>> >.ServerSocketChannelImpl.bind(ServerSocketChannelImpl.java:222)
>> >     Apr 30 19:32:35 master1.ipa.test server[3589]:         at
>> >     sun.nio.ch
>> >     <http://sun.nio.ch
>> >.ServerSocketAdaptor.bind(ServerSocketAdaptor.java:85)
>> >     Apr 30 19:32:35 master1.ipa.test server[3589]:         at
>> >     org.apache.tomcat.util.net
>> >     <http://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
>> >     <http://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
>> >     <http://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
>> >     <http://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
>> >
>> >
>> >
>>
>>




--
/ Alexander Bokovoy
Sr. Principal Software Engineer
Security / Identity Management Engineering
Red Hat Limited, Finland
_______________________________________________
FreeIPA-devel mailing list -- freeipa-devel@lists.fedorahosted.org
To unsubscribe send an email to freeipa-devel-leave@lists.fedorahosted.org
Fedora Code of Conduct: https://docs.fedoraproject.org/en-US/project/code-of-conduct/
List Guidelines: https://fedoraproject.org/wiki/Mailing_list_guidelines
List Archives: https://lists.fedorahosted.org/archives/list/freeipa-devel@lists.fedorahosted.org
Do not reply to spam on the list, report it: https://pagure.io/fedora-infrastructure