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
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 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
-- 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
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.
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 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 startup
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 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]: at org.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]: at org.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]: 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]: 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 issues trying 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
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
The mentioned Java traceback is there even for OK cases.
Unfortunately, I don't know the exact reason right now. It may be related to the region of Azure hosting and for example, countermeasures for mining through GH Actions(performance downgrade). I run exactly the same CI on my account without failures: https://dev.azure.com/slev0538/slev_/_build/results?buildId=101&view=res... https://dev.azure.com/slev0538/slev_/_build/results?buildId=100&view=res...
Workaround: if test env's memory limit(sum of limits) doesn't exceed provided by Azure VM(7Gb+4Gb swap), then tests are OK:
https://github.com/freeipa/freeipa/pull/5656/commits/3f0308c275fc07a1cec87f3...
https://dev.azure.com/freeipa/freeipa/_build/results?buildId=8780&view=r...
Hi all,
Stanislav, thanks for your investigation. Could you do a separate PR with the commit azure: Re-group test envs https://github.com/freeipa/freeipa/pull/5656/commits/3f0308c275fc07a1cec87f39e9f4bdefb7ffc011 (it would unblock our other PRs without waiting for your PR 5656 https://github.com/freeipa/freeipa/pull/5656 to be reviewed)?
On my side I investigated the "java.net.BindException: Address already in use" exception and I suspect it's related to the way we setup /etc/hosts on the machines. Since commit 1906afb https://github.com/dogtagpki/pki/commit/1906afbeb3c8b7140601be7f9bee2f7fef5b0a5e, pki defines 2 AJP connectors, one using localhost4 and the other localhost6 but our /etc/hosts defines only localhost. I created a PR to check if the exception goes away with a proper /etc/hosts configuration (PR 5749 https://github.com/freeipa/freeipa/pull/5749). So the action plan would be: 1. fix azure pipelines with Stanislav's PR 2. fix the "Address already in use" with my PR 3. make the same modification to /etc/hosts in freeipa-pr-ci https://github.com/flo-renaud/freeipa-pr-ci/commit/78e949ccc0194c7c4cea64a917a6edba786ddd4a, so that the tests running in PRCI also have localhost4 and localhost6 defined
How does it sound? flo
On Tue, May 4, 2021 at 8:38 PM Stanislav Levin via FreeIPA-devel < freeipa-devel@lists.fedorahosted.org> wrote:
The mentioned Java traceback is there even for OK cases.
Unfortunately, I don't know the exact reason right now. It may be related to the region of Azure hosting and for example, countermeasures for mining through GH Actions(performance downgrade). I run exactly the same CI on my account without failures:
https://dev.azure.com/slev0538/slev_/_build/results?buildId=101&view=res...
https://dev.azure.com/slev0538/slev_/_build/results?buildId=100&view=res...
Workaround: if test env's memory limit(sum of limits) doesn't exceed provided by Azure VM(7Gb+4Gb swap), then tests are OK:
https://github.com/freeipa/freeipa/pull/5656/commits/3f0308c275fc07a1cec87f3...
https://dev.azure.com/freeipa/freeipa/_build/results?buildId=8780&view=r...
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
On ke, 05 touko 2021, Florence Renaud wrote:
Hi all,
Stanislav, thanks for your investigation. Could you do a separate PR with the commit azure: Re-group test envs https://github.com/freeipa/freeipa/pull/5656/commits/3f0308c275fc07a1cec87f39e9f4bdefb7ffc011 (it would unblock our other PRs without waiting for your PR 5656 https://github.com/freeipa/freeipa/pull/5656 to be reviewed)?
On my side I investigated the "java.net.BindException: Address already in use" exception and I suspect it's related to the way we setup /etc/hosts on the machines. Since commit 1906afb https://github.com/dogtagpki/pki/commit/1906afbeb3c8b7140601be7f9bee2f7fef5b0a5e, pki defines 2 AJP connectors, one using localhost4 and the other localhost6 but our /etc/hosts defines only localhost. I created a PR to check if the exception goes away with a proper /etc/hosts configuration (PR 5749 https://github.com/freeipa/freeipa/pull/5749). So the action plan would be:
- fix azure pipelines with Stanislav's PR
- fix the "Address already in use" with my PR
- make the same modification to /etc/hosts in freeipa-pr-ci
https://github.com/flo-renaud/freeipa-pr-ci/commit/78e949ccc0194c7c4cea64a917a6edba786ddd4a, so that the tests running in PRCI also have localhost4 and localhost6 defined
How does it sound?
I would prefer if we simply redefine
pki_ajp_host_ipv4=localhost4 pki_ajp_host_ipv6=localhost6
in IPA CA configuration template to be 127.0.0.1 and ::1
As shown in https://github.com/freeipa/freeipa-container/issues/385#issuecomment-8175707..., this solves the problem for freeipa-container and should really be a default on our side.
flo
On Tue, May 4, 2021 at 8:38 PM Stanislav Levin via FreeIPA-devel < freeipa-devel@lists.fedorahosted.org> wrote:
The mentioned Java traceback is there even for OK cases.
Unfortunately, I don't know the exact reason right now. It may be related to the region of Azure hosting and for example, countermeasures for mining through GH Actions(performance downgrade). I run exactly the same CI on my account without failures:
https://dev.azure.com/slev0538/slev_/_build/results?buildId=101&view=res...
https://dev.azure.com/slev0538/slev_/_build/results?buildId=100&view=res...
Workaround: if test env's memory limit(sum of limits) doesn't exceed provided by Azure VM(7Gb+4Gb swap), then tests are OK:
https://github.com/freeipa/freeipa/pull/5656/commits/3f0308c275fc07a1cec87f3...
https://dev.azure.com/freeipa/freeipa/_build/results?buildId=8780&view=r...
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
05.05.2021 19:55, Florence Renaud пишет:
Hi all,
Stanislav, thanks for your investigation. Could you do a separate PR with the commit azure: Re-group test envs https://github.com/freeipa/freeipa/pull/5656/commits/3f0308c275fc07a1cec87f39e9f4bdefb7ffc011 (it would unblock our other PRs without waiting for your PR 5656 https://github.com/freeipa/freeipa/pull/5656 to be reviewed)?
On Wed, May 5, 2021 at 8:06 PM Alexander Bokovoy abokovoy@redhat.com wrote:
On ke, 05 touko 2021, Florence Renaud wrote:
Hi all,
Stanislav, thanks for your investigation. Could you do a separate PR with the commit azure: Re-group test envs <
https://github.com/freeipa/freeipa/pull/5656/commits/3f0308c275fc07a1cec87f3...
(it would unblock our other PRs without waiting for your PR 5656 https://github.com/freeipa/freeipa/pull/5656 to be reviewed)?
On my side I investigated the "java.net.BindException: Address already in use" exception and I suspect it's related to the way we setup /etc/hosts
on
the machines. Since commit 1906afb <
https://github.com/dogtagpki/pki/commit/1906afbeb3c8b7140601be7f9bee2f7fef5b...
, pki defines 2 AJP connectors, one using localhost4 and the other
localhost6
but our /etc/hosts defines only localhost. I created a PR to check if the exception goes away with a proper /etc/hosts configuration (PR 5749 https://github.com/freeipa/freeipa/pull/5749). So the action plan would be:
- fix azure pipelines with Stanislav's PR
- fix the "Address already in use" with my PR
- make the same modification to /etc/hosts in freeipa-pr-ci
<
https://github.com/flo-renaud/freeipa-pr-ci/commit/78e949ccc0194c7c4cea64a91...
, so that the tests running in PRCI also have localhost4 and localhost6 defined
How does it sound?
I would prefer if we simply redefine
pki_ajp_host_ipv4=localhost4 pki_ajp_host_ipv6=localhost6
in IPA CA configuration template to be 127.0.0.1 and ::1
As shown in
https://github.com/freeipa/freeipa-container/issues/385#issuecomment-8175707... , this solves the problem for freeipa-container and should really be a default on our side.
Ok, thanks for the suggestion, I updated my PR with the proposal.
flo
flo
On Tue, May 4, 2021 at 8:38 PM Stanislav Levin via FreeIPA-devel < freeipa-devel@lists.fedorahosted.org> wrote:
The mentioned Java traceback is there even for OK cases.
Unfortunately, I don't know the exact reason right now. It may be related to the region of Azure hosting and for example, countermeasures for mining through GH Actions(performance downgrade). I run exactly the same CI on my account without failures:
https://dev.azure.com/slev0538/slev_/_build/results?buildId=101&view=res...
https://dev.azure.com/slev0538/slev_/_build/results?buildId=100&view=res...
Workaround: if test env's memory limit(sum of limits) doesn't exceed provided by Azure VM(7Gb+4Gb swap), then tests are OK:
https://github.com/freeipa/freeipa/pull/5656/commits/3f0308c275fc07a1cec87f3...
https://dev.azure.com/freeipa/freeipa/_build/results?buildId=8780&view=r...
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
-- / Alexander Bokovoy Sr. Principal Software Engineer Security / Identity Management Engineering Red Hat Limited, Finland
freeipa-devel@lists.fedorahosted.org
-
Alexander Bokovoy -
Endi Dewata -
Florence Renaud -
Rob Crittenden -
Stanislav Levin