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/bui...
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&versi...
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 toone or
more tests in Azure failing. I cherry-picked a few and they alllook
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 thestart
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 upat
19:35:23. The journal logs a suspect (why this isn't in the CA debug log Idon'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 handlerinitialization
failed Apr 30 19:32:35 master1.ipa.test server[3589]: atorg.apache.catalina.connector.Connector.initInternal(Connector.java:1042)
Apr 30 19:32:35 master1.ipa.test server[3589]: atorg.apache.catalina.util.LifecycleBase.init(LifecycleBase.java:136)
Apr 30 19:32:35 master1.ipa.test server[3589]: atorg.apache.catalina.core.StandardService.initInternal(StandardService.java:533)
Apr 30 19:32:35 master1.ipa.test server[3589]: atorg.apache.catalina.util.LifecycleBase.init(LifecycleBase.java:136)
Apr 30 19:32:35 master1.ipa.test server[3589]: atorg.apache.catalina.core.StandardServer.initInternal(StandardServer.java:1057)
Apr 30 19:32:35 master1.ipa.test server[3589]: atorg.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]: atsun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
Apr 30 19:32:35 master1.ipa.test server[3589]: atsun.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 issuestrying to
verify that the CA is fully up. The full logs are available athttps://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-- / 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.fedorahoste... Do not reply to spam on the list, report it: https://pagure.io/fedora-infrastructure