Looking at the df/mount outputs posted by @martux69 and @smithbr, I see you both use “non-standard” partitioning. While I don’t particularly think this should be an issue, could one of you try a vanilla (one / and that’s it) install? Or was the CentOS install that succeeded maybe like that?
If one of you is interested in an interactive debugging session (via tmate.io or similar), we can team up (I’m in central Europe)?
I can try it next weekend, but only in a virtual machine and there my try with RHEL 8.3 also worked.
But I try it and give feedback.
I can give RHEL v8.4 a go, I just need to update my build source for it.
Regarding “non standard” partitions. I am using the CIS Benchmark for my partition schema. After upgrading to RHEL v8.4, if it still fails 100% of the time, I will build a couple of test systems with a single root partition.
I would absolutely love an interactive debugging session if the above fails. As stated by @ekohl , it looks like it could be some weird race condition. I built it out like 5 times, and it worked just fine, and then 5 more times and it failed every single time.
Since my entire build, including Foreman, is automated, I can assure I didn’t fat finger something.
@evgeni : CentOS succeeded with my partitioning and I try it with one / also with RHEL 8.3 without success.
(Complete new build, not an upgrade)
cat /etc/redhat-release
Red Hat Enterprise Linux release 8.4 (Ootpa)
On the plus side, the first two side by side builds installed Foreman + Katello just fine.
I have rebuilt 2 servers 7 times each for a total of 14 builds.
Out of 14 builds, I had 14 complete 100% successfully.
I can kick off a few more to be safe, but this is significantly better than executing the installation against RHEL 8.3 (~ 50%?). It would appear that something in RHEL 8.3 with respects to Candlepin and Tomcat has been magically resolved. I only place blame there (could very much be else where) because of the webapp failing to start.
8 more rebuilds later and finally 1 failure.
2021-05-21 13:03:42 [ERROR ] [configure] /Stage[main]/Foreman::Database/Foreman::Rake[db:seed]/Exec[foreman-rake-db:seed]: Failed to call refresh: '/usr/sbin/foreman-rake db:seed' returned 1 instead of one of [0]
2021-05-21 13:03:42 [ERROR ] [configure] /Stage[main]/Foreman::Database/Foreman::Rake[db:seed]/Exec[foreman-rake-db:seed]: '/usr/sbin/foreman-rake db:seed' returned 1 instead of one of [0]
It is Tomcat failing to start because of Candlepin
May 21 13:02:28 sec1foreman server[43025]: 21-May-2021 13:02:28.198 SEVERE [main] org.apache.catalina.core.StandardContext.startInternal One or more listeners failed to start. Full details will be found in the appropriate container log file
May 21 13:02:28 sec1foreman server[43025]: 21-May-2021 13:02:28.200 SEVERE [main] org.apache.catalina.core.StandardContext.startInternal Context [/candlepin] startup failed due to previous errors
I enabled debug during the installation, so if there is anything that might peak your curiosity that you wish to see, I am happy to share.
cat /etc/redhat-release
Red Hat Enterprise Linux release 8.4 (Ootpa)
This is the same exact build as all of the other successes.
With RHEL 8.4 my installation is running fine now.
Thanks for all the follow up testing! Even though our CI is still breaking, I’m going to pause investigating this since newer RHEL seems to fix it and my attempts to figure out what the culprit is have hit a wall.
When I initially installed foreman, I managed to get it installed on CentOS 8.3.
But I had to wipe it because somehow the whole pulp-candlepin thing ended up in a mess.
Now, I can’t seem to re-install it, it always ends with
2021-06-03 17:24:15 [NOTICE] [configure] 1300 out of 2131 done.
2021-06-03 17:24:20 [NOTICE] [configure] 1400 out of 2132 done.
2021-06-03 17:26:18 [ERROR ] [configure] /Stage[main]/Foreman::Database/Foreman::Rake[db:seed]/Exec[foreman-rake-db:seed]: Failed to call refresh: '/usr/sbin/foreman-rake db:seed' returned 1 instead of one of [0]
2021-06-03 17:26:18 [ERROR ] [configure] /Stage[main]/Foreman::Database/Foreman::Rake[db:seed]/Exec[foreman-rake-db:seed]: '/usr/sbin/foreman-rake db:seed' returned 1 instead of one of [0]
2021-06-03 17:26:18 [NOTICE] [configure] 1500 out of 2132 done.
2021-06-03 17:24:15 [NOTICE] [configure] 1300 out of 2131 done.
2021-06-03 17:24:20 [NOTICE] [configure] 1400 out of 2132 done.
2021-06-03 17:26:18 [ERROR ] [configure] /Stage[main]/Foreman::Database/Foreman::Rake[db:seed]/Exec[foreman-rake-db:seed]: Failed to call refresh: '/usr/sbin/foreman-rake db:seed' returned 1 instead of one of [0]
2021-06-03 17:26:18 [ERROR ] [configure] /Stage[main]/Foreman::Database/Foreman::Rake[db:seed]/Exec[foreman-rake-db:seed]: '/usr/sbin/foreman-rake db:seed' returned 1 instead of one of [0]
2021-06-03 17:26:18 [NOTICE] [configure] 1500 out of 2132 done.
2021-06-03 17:26:18 [NOTICE] [configure] 1600 out of 2132 done.
2021-06-03 17:26:18 [NOTICE] [configure] 1600 out of 2132 done.
CentOS 8.4 isn’t out yet…
Hello
Maybe this is not adding any value to the issue. I have the same problem on CentOS 8.4 and seems to be related with Candlepin. It is being stopped by Tomcat with some weird messages:
root satellite11 /var/log/tomcat #systemctl start tomcat.service
root satellite11 /var/log/tomcat #systemctl status tomcat.service
● tomcat.service - Apache Tomcat Web Application Container
Loaded: loaded (/usr/lib/systemd/system/tomcat.service; enabled; vendor preset: disabled)
Active: active (running) since Tue 2021-06-08 19:07:38 CEST; 3s ago
Main PID: 2973 (java)
Tasks: 24 (limit: 153799)
…
08-Jun-2021 19:07:43.471 WARNING [main] com.google.inject.internal.ProxyFactory. Method [public org.candlepin.model.Persisted org.candlepin.model.RulesCurator.create(org.candlepin.model.Persisted)] is
synthetic and is being intercepted by [com.google.inject.persist.jpa.JpaLocalTxnInterceptor@496c7d29]. This could indicate a bug. The method may be intercepted twice, or may not be intercepted at all.
08-Jun-2021 19:07:43.484 WARNING [main] com.google.inject.internal.ProxyFactory. Method [public void org.candlepin.model.ContentCurator.delete(org.candlepin.model.Persisted)] is synthetic and is being
intercepted by [com.google.inject.persist.jpa.JpaLocalTxnInterceptor@496c7d29]. This could indicate a bug. The method may be intercepted twice, or may not be intercepted at all.
08-Jun-2021 19:07:43.582 WARNING [main] com.google.inject.internal.ProxyFactory. Method [public void org.candlepin.model.EntitlementCertificateCurator.delete(org.candlepin.model.Persisted)] is syntheti
c and is being intercepted by [com.google.inject.persist.jpa.JpaLocalTxnInterceptor@496c7d29]. This could indicate a bug. The method may be intercepted twice, or may not be intercepted at all.
08-Jun-2021 19:07:48.470 SEVERE [main] org.apache.catalina.core.StandardContext.startInternal One or more listeners failed to start. Full details will be found in the appropriate container log file
08-Jun-2021 19:07:48.472 SEVERE [main] org.apache.catalina.core.StandardContext.startInternal Context [/candlepin] startup failed due to previous errors
…
root satellite11 /var/log/tomcat #
root satellite11 /var/log/tomcat #less localhost.2021-06-08.log
08-Jun-2021 19:07:48.470 SEVERE [main] org.apache.catalina.core.StandardContext.listenerStart Exception sending context initialized event to listener instance of class [org.candlepin.guice.CandlepinContextListener]
java.lang.NoSuchFieldError: SERVER_SENT_EVENTS_TYPE
at org.jboss.resteasy.core.ResourceMethodInvoker.isSseResourceMethod(ResourceMethodInvoker.java:192)
at org.jboss.resteasy.core.ResourceMethodInvoker.(ResourceMethodInvoker.java:171)
at org.jboss.resteasy.core.ResourceMethodRegistry.processMethod(ResourceMethodRegistry.java:383)
at org.jboss.resteasy.core.ResourceMethodRegistry.register(ResourceMethodRegistry.java:310)
at org.jboss.resteasy.core.ResourceMethodRegistry.addResourceFactory(ResourceMethodRegistry.java:261)
at org.jboss.resteasy.core.ResourceMethodRegistry.addResourceFactory(ResourceMethodRegistry.java:228)
at org.jboss.resteasy.core.ResourceMethodRegistry.addResourceFactory(ResourceMethodRegistry.java:209)
at org.jboss.resteasy.core.ResourceMethodRegistry.addResourceFactory(ResourceMethodRegistry.java:193)
at org.jboss.resteasy.core.ResourceMethodRegistry.addResourceFactory(ResourceMethodRegistry.java:176)
Let me know if you are intetrsted on the full logs.
I’m trying to install Katello+Foreman 4.0 as per the instructions on CentOS 8.4
Thank you
Hello all.
This problem still appeared in CentOS 8.4.
At first I didn’t find this topic and create task in foreman redmine Bug #32865: CentOS 8 Katello::Errors::CandlepinNotRunning - Foreman
After reading this topic, I tried to update my host to CentOS-Stream (added repos and ran dnf update). But problem still exists
So, to somehow narrow down the search scope of the search, as I understand from the forum and my searches, the problem is in one of these packages:
katello
tomcatjss
java-11-openjdk
java-11-openjdk-headless
pki-servlet-4.0-api
pki-servlet-engine
I have success in instalation foreman in CentOS8 (VM). So, I had a logs with successed and failed installation. Comparing installation log not give anything, logs are same. And I start understand, that this error do not depend on package versions or installation process.
Hello, i have this problem too on CentOS 8. Upgrading to 8.4 didn’t help. Any ideas ?
This problem occasionally appears on CentOS 8 and AlmaLinux. And we figured out how fix it. (I hope this is temporary)
Rebuild packages candlepin and candlepin-selinux from git master branch
Then install new packages and run foreman-installer
Hi… Same problem with latest CentOS 8 Stream and latest Katello 4.1 / Foreman 2.5 fresh install. I can contribute some outputs, but everything looks absolutely same or very similar like outputs above.
[root@foreman ~]# rpm -qv tomcatjss
tomcatjss-7.7.0-0.1.alpha1.module_el8.5.0+838+8f96ca18.noarch
[root@foreman ~]# rpm -qv candlepin
candlepin-4.0.6-1.el8.noarch
[root@foreman ~]# cat /etc/os-release
NAME="CentOS Stream"
VERSION="8"
ID="centos"
ID_LIKE="rhel fedora"
VERSION_ID="8"
PLATFORM_ID="platform:el8"
PRETTY_NAME="CentOS Stream 8"
ANSI_COLOR="0;31"
CPE_NAME="cpe:/o:centos:centos:8"
HOME_URL="https://centos.org/"
BUG_REPORT_URL="https://bugzilla.redhat.com/"
REDHAT_SUPPORT_PRODUCT="Red Hat Enterprise Linux 8"
REDHAT_SUPPORT_PRODUCT_VERSION="CentOS Stream"
catalina log repeating this message:
11-Aug-2021 14:59:34.028 INFO [56] org.apache.catalina.loader.WebappClassLoaderBase.checkStateForResourceLoading Illegal access: this web application instance has been stopped already. Could not load [org.quartz.DisallowConcurrentExecution]. The following stack trace is thrown for debugging purposes as well as to attempt to terminate the thread which caused the illegal access.
java.lang.IllegalStateException: Illegal access: this web application instance has been stopped already. Could not load [org.quartz.DisallowConcurrentExecution]. The following stack trace is thrown for debugging purposes as well as to attempt to terminate the thread which caused the illegal access.
at org.apache.catalina.loader.WebappClassLoaderBase.checkStateForResourceLoading(WebappClassLoaderBase.java:1385)
at org.apache.catalina.loader.WebappClassLoaderBase.checkStateForClassLoading(WebappClassLoaderBase.java:1373)
at org.apache.catalina.loader.WebappClassLoaderBase.loadClass(WebappClassLoaderBase.java:1226)
at org.apache.catalina.loader.WebappClassLoaderBase.loadClass(WebappClassLoaderBase.java:1188)
at org.quartz.impl.JobDetailImpl.isConcurrentExectionDisallowed(JobDetailImpl.java:388)
at org.quartz.impl.jdbcjobstore.JobStoreSupport.acquireNextTrigger(JobStoreSupport.java:2875)
at org.quartz.impl.jdbcjobstore.JobStoreSupport$41.execute(JobStoreSupport.java:2805)
at org.quartz.impl.jdbcjobstore.JobStoreSupport$41.execute(JobStoreSupport.java:2803)
at org.quartz.impl.jdbcjobstore.JobStoreSupport.executeInNonManagedTXLock(JobStoreSupport.java:3864)
at org.quartz.impl.jdbcjobstore.JobStoreSupport.acquireNextTriggers(JobStoreSupport.java:2802)
at org.quartz.core.QuartzSchedulerThread.run(QuartzSchedulerThread.java:287)
interested startup messages from journalctl -u tomcat.service
Aug 11 15:05:48 foreman.dc01.cz server[5316]: 11-Aug-2021 15:05:48.063 INFO [main] org.apache.catalina.startup.Catalina.start Server startup in [19,995] milliseconds
Aug 11 15:05:48 foreman.dc01.cz server[5316]: 11-Aug-2021 15:05:48.764 INFO [activemq-failure-check-thread] org.apache.catalina.loader.WebappClassLoaderBase.checkStateForResourceLoading Illegal access: this web application instance has been stopped already. Could not load [org.apache.activemq.artemis.core.remoting.server.impl.RemotingServiceImpl$FailureCheckAndFlushThread$1]. The following stack trace is thrown for debugging purposes as well as to attempt to terminate the thread which caused the illegal access.
Aug 11 15:05:48 foreman.dc01.cz server[5316]: java.lang.IllegalStateException: Illegal access: this web application instance has been stopped already. Could not load [org.apache.activemq.artemis.core.remoting.server.impl.RemotingServiceImpl$FailureCheckAndFlushThread$1]. The following stack trace is thrown for debugging purposes as well as to attempt to terminate the thread which caused the illegal access.
Aug 11 15:05:48 foreman.dc01.cz server[5316]: at org.apache.catalina.loader.WebappClassLoaderBase.checkStateForResourceLoading(WebappClassLoaderBase.java:1385)
Aug 11 15:05:48 foreman.dc01.cz server[5316]: at org.apache.catalina.loader.WebappClassLoaderBase.checkStateForClassLoading(WebappClassLoaderBase.java:1373)
Aug 11 15:05:48 foreman.dc01.cz server[5316]: at org.apache.catalina.loader.WebappClassLoaderBase.loadClass(WebappClassLoaderBase.java:1226)
Aug 11 15:05:48 foreman.dc01.cz server[5316]: at org.apache.catalina.loader.WebappClassLoaderBase.loadClass(WebappClassLoaderBase.java:1188)
Aug 11 15:05:48 foreman.dc01.cz server[5316]: at org.apache.activemq.artemis.core.remoting.server.impl.RemotingServiceImpl$FailureCheckAndFlushThread.run(RemotingServiceImpl.java:731)
Aug 11 15:05:48 foreman.dc01.cz server[5316]: 11-Aug-2021 15:05:48.767 INFO [activemq-failure-check-thread] org.apache.catalina.loader.WebappClassLoaderBase.checkStateForResourceLoading Illegal access: this web application instance has been stopped already. Could not load [ch.qos.logback.classic.spi.ThrowableProxy]. The following stack trace is thrown for debugging purposes as well as to attempt to terminate the thread which caused the illegal access.
Aug 11 15:05:48 foreman.dc01.cz server[5316]: java.lang.IllegalStateException: Illegal access: this web application instance has been stopped already. Could not load [ch.qos.logback.classic.spi.ThrowableProxy]. The following stack trace is thrown for debugging purposes as well as to attempt to terminate the thread which caused the illegal access.
Aug 11 15:05:48 foreman.dc01.cz server[5316]: at org.apache.catalina.loader.WebappClassLoaderBase.checkStateForResourceLoading(WebappClassLoaderBase.java:1385)
Aug 11 15:05:48 foreman.dc01.cz server[5316]: at org.apache.catalina.loader.WebappClassLoaderBase.checkStateForClassLoading(WebappClassLoaderBase.java:1373)
Aug 11 15:05:48 foreman.dc01.cz server[5316]: at org.apache.catalina.loader.WebappClassLoaderBase.loadClass(WebappClassLoaderBase.java:1226)
Aug 11 15:05:48 foreman.dc01.cz server[5316]: at org.apache.catalina.loader.WebappClassLoaderBase.loadClass(WebappClassLoaderBase.java:1188)
Aug 11 15:05:48 foreman.dc01.cz server[5316]: at ch.qos.logback.classic.spi.LoggingEvent.<init>(LoggingEvent.java:119)
Aug 11 15:05:48 foreman.dc01.cz server[5316]: at ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(Logger.java:419)
Aug 11 15:05:48 foreman.dc01.cz server[5316]: at ch.qos.logback.classic.Logger.filterAndLog_0_Or3Plus(Logger.java:383)
Aug 11 15:05:48 foreman.dc01.cz server[5316]: at ch.qos.logback.classic.Logger.log(Logger.java:765)
Aug 11 15:05:48 foreman.dc01.cz server[5316]: at jdk.internal.reflect.GeneratedMethodAccessor49.invoke(Unknown Source)
Aug 11 15:05:48 foreman.dc01.cz server[5316]: at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
Aug 11 15:05:48 foreman.dc01.cz server[5316]: at java.base/java.lang.reflect.Method.invoke(Method.java:566)
Aug 11 15:05:48 foreman.dc01.cz server[5316]: at org.jboss.logging.Slf4jLocationAwareLogger.doLog(Slf4jLocationAwareLogger.java:89)
Aug 11 15:05:48 foreman.dc01.cz server[5316]: at org.jboss.logging.Slf4jLocationAwareLogger.doLog(Slf4jLocationAwareLogger.java:75)
Aug 11 15:05:48 foreman.dc01.cz server[5316]: at org.jboss.logging.Logger.logv(Logger.java:2226)
Aug 11 15:05:48 foreman.dc01.cz server[5316]: at org.apache.activemq.artemis.core.server.ActiveMQServerLogger_$logger.errorOnFailureCheck(ActiveMQServerLogger_$logger.java:1198)
Aug 11 15:05:48 foreman.dc01.cz server[5316]: at org.apache.activemq.artemis.core.remoting.server.impl.RemotingServiceImpl$FailureCheckAndFlushThread.run(RemotingServiceImpl.java:767)
Aug 11 15:05:48 foreman.dc01.cz server[5316]: Exception in thread "activemq-failure-check-thread" java.lang.NoClassDefFoundError: ch/qos/logback/classic/spi/ThrowableProxy
Aug 11 15:05:48 foreman.dc01.cz server[5316]: at ch.qos.logback.classic.spi.LoggingEvent.<init>(LoggingEvent.java:119)
Aug 11 15:05:48 foreman.dc01.cz server[5316]: at ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(Logger.java:419)
Aug 11 15:05:48 foreman.dc01.cz server[5316]: at ch.qos.logback.classic.Logger.filterAndLog_0_Or3Plus(Logger.java:383)
Aug 11 15:05:48 foreman.dc01.cz server[5316]: at ch.qos.logback.classic.Logger.log(Logger.java:765)
Aug 11 15:05:48 foreman.dc01.cz server[5316]: at jdk.internal.reflect.GeneratedMethodAccessor49.invoke(Unknown Source)
Aug 11 15:05:48 foreman.dc01.cz server[5316]: at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
Aug 11 15:05:48 foreman.dc01.cz server[5316]: at java.base/java.lang.reflect.Method.invoke(Method.java:566)
Aug 11 15:05:48 foreman.dc01.cz server[5316]: at org.jboss.logging.Slf4jLocationAwareLogger.doLog(Slf4jLocationAwareLogger.java:89)
Aug 11 15:05:48 foreman.dc01.cz server[5316]: at org.jboss.logging.Slf4jLocationAwareLogger.doLog(Slf4jLocationAwareLogger.java:75)
Aug 11 15:05:48 foreman.dc01.cz server[5316]: at org.jboss.logging.Logger.logv(Logger.java:2226)
Aug 11 15:05:48 foreman.dc01.cz server[5316]: at org.apache.activemq.artemis.core.server.ActiveMQServerLogger_$logger.errorOnFailureCheck(ActiveMQServerLogger_$logger.java:1198)
Aug 11 15:05:48 foreman.dc01.cz server[5316]: at org.apache.activemq.artemis.core.remoting.server.impl.RemotingServiceImpl$FailureCheckAndFlushThread.run(RemotingServiceImpl.java:767)
Aug 11 15:05:48 foreman.dc01.cz server[5316]: Caused by: java.lang.ClassNotFoundException: Illegal access: this web application instance has been stopped already. Could not load [ch.qos.logback.classic.spi.ThrowableProxy]. The following stack trace is thrown for debugging purposes as well as to attempt to terminate the thread which caused the illegal access.
Aug 11 15:05:48 foreman.dc01.cz server[5316]: at org.apache.catalina.loader.WebappClassLoaderBase.checkStateForClassLoading(WebappClassLoaderBase.java:1375)
Aug 11 15:05:48 foreman.dc01.cz server[5316]: at org.apache.catalina.loader.WebappClassLoaderBase.loadClass(WebappClassLoaderBase.java:1226)
Aug 11 15:05:48 foreman.dc01.cz server[5316]: at org.apache.catalina.loader.WebappClassLoaderBase.loadClass(WebappClassLoaderBase.java:1188)
Aug 11 15:05:48 foreman.dc01.cz server[5316]: ... 12 more
Aug 11 15:05:48 foreman.dc01.cz server[5316]: Caused by: java.lang.IllegalStateException: Illegal access: this web application instance has been stopped already. Could not load [ch.qos.logback.classic.spi.ThrowableProxy]. The following stack trace is thrown for debugging purposes as well as to attempt to terminate the thread which caused the illegal access.
Aug 11 15:05:48 foreman.dc01.cz server[5316]: at org.apache.catalina.loader.WebappClassLoaderBase.checkStateForResourceLoading(WebappClassLoaderBase.java:1385)
Aug 11 15:05:48 foreman.dc01.cz server[5316]: at org.apache.catalina.loader.WebappClassLoaderBase.checkStateForClassLoading(WebappClassLoaderBase.java:1373)
Aug 11 15:05:48 foreman.dc01.cz server[5316]: ... 14 more
Aug 11 15:05:50 foreman.dc01.cz server[5316]: 11-Aug-2021 15:05:50.201 INFO [Thread-0 (activemq-netty-threads)] org.apache.catalina.loader.WebappClassLoaderBase.checkStateForResourceLoading Illegal access: this web application instance has been stopped already. Could not load [io.netty.channel.AdaptiveRecvByteBufAllocator$HandleImpl]. The following stack trace is thrown for debugging purposes as well as to attempt to terminate the thread which caused the illegal access.
Welcome @milanzelenka and thanks for chiming in.
To better understand the nature of the problem (please do not interpret this as patronizing troubleshooting advice!):
Once the issue has occurred does it always continue to persist after the server has been rebooted completely? OR is rebooting ever observed to solve it temporarily, until it may occur again later?
Is the issue ever resolved temporarily by running foreman-installer --reset-data ? (NOTE: this will reset foreman and candlepin DBs in PostgreSQL and drop all application data)
My thinking is to reduce the size of the problem space in narrowing down whether the issue is caused by environment alone or is there an element of state. If the problem is ever observed to be relieved by a reboot or data reset, even if only temporarily, that would provide evidence that the problem, once it occurs, exists somewhere in the service or application state.