Candlepin crashing permanently. Server broke connection (POST /candlepin/owners/Default_Organization/uebercert)

Support
, ,
1

Hello everybody, this is my first post so i hope i’m doing everything right.

I installed the latest Foreman 1.22.0 with Katello 3.12 to a fresh installed CentOS 7 VM.

Problem:

After the installation there is a task with status error: “Create organization ‘Default Organization’” with error message:

Katello::Resources::Candlepin::Owner: Server broke connection  (POST /candlepin/owners/Default_Organization/uebercert)

The “Tomcat” service fails and i cannot find a valid log entry for this except for:

/var/log/messages 
Aug  2 09:11:33 llmprod-01 server: # A fatal error has been detected by the Java Runtime Environment:
Aug  2 09:11:33 llmprod-01 server: #
Aug  2 09:11:33 llmprod-01 server: #  SIGSEGV (0xb) at pc=0x00007f8bdd8d3a4f, pid=30253, tid=0x00007f8c09b6c700
Aug  2 09:11:33 llmprod-01 server: #
Aug  2 09:11:33 llmprod-01 server: # JRE version: OpenJDK Runtime Environment (8.0_222-b10) (build 1.8.0_222-b10)
Aug  2 09:11:33 llmprod-01 server: # Java VM: OpenJDK 64-Bit Server VM (25.222-b10 mixed mode linux-amd64 compressed oops)
Aug  2 09:11:33 llmprod-01 server: # Problematic frame:
Aug  2 09:11:33 llmprod-01 server: # C  [libplds4.so+0x1a4f]  PL_HashTableLookupConst+0xf
Aug  2 09:11:33 llmprod-01 server: #
Aug  2 09:11:33 llmprod-01 server: # Failed to write core dump. Core dumps have been disabled. To enable core dumping, try "ulimit -c unlimited" before starting Java again
Aug  2 09:11:33 llmprod-01 server: #
Aug  2 09:11:33 llmprod-01 server: # An error report file with more information is saved as:
Aug  2 09:11:33 llmprod-01 server: # /usr/share/tomcat/hs_err_pid30253.log
Aug  2 09:11:33 llmprod-01 server: #
Aug  2 09:11:33 llmprod-01 server: # If you would like to submit a bug report, please visit:
Aug  2 09:11:33 llmprod-01 server: #   http://bugreport.java.com/bugreport/crash.jsp
Aug  2 09:11:33 llmprod-01 server: # The crash happened outside the Java Virtual Machine in native code.
Aug  2 09:11:33 llmprod-01 server: # See problematic frame for where to report the bug.
Aug  2 09:11:33 llmprod-01 server: #
Aug  2 09:11:34 llmprod-01 systemd: tomcat.service: main process exited, code=killed, status=6/ABRT
Aug  2 09:11:34 llmprod-01 systemd: Unit tomcat.service entered failed state.
Aug  2 09:11:34 llmprod-01 systemd: tomcat.service failed.

I can see that Candlepin has failed with “hammer ping” and “systemctl status tomcat”.
I can start candlepin with “systemctl start tomcat” or “foreman-maintain service start”.

The same thing happens when i try to add a client to Katello using the subscription-manager on a client vm.
Expected outcome:
I should be able to resume the “Create organization ‘Default Organization’” Task and to add clients to Katello using the subscription-manager

Foreman and Proxy versions:
foreman-installer-1.22.0-1.el7.noarch
foreman-1.22.0-1.el7.noarch
foreman-proxy-1.22.0-1.el7.noarch

Foreman and Proxy plugin versions:
katello-3.12.1-1.el7.noarch
candlepin-2.6.5-1.el7.noarch
pulp-server-2.19.1-1.el7.noarch
puppetserver-6.5.0-1.el7.noarch

I found this as description in a redhat documentation but i don’t know what it means:

POST/owners/{owner_key}/uebercert -> Creates an Ueber entitlement certificate

3. API COMMANDS IN RED HAT SUBSCRIPTION MANAGEMENT

Thanks in Advance for your support and ideas!

2

It seems like Tomcat is catching a segfault and then stops itself via an abort. I have not seen this with candlepin before.

Can you add log entires from tomcat? It should be in /var/log/tomcat/catalina.YYYY-MM-DD.log (replace with the current date or date when it happened) or journalctl -u tomcat.service. Also the mentioned file /usr/share/tomcat/hs_err_pid30253.log could be helpful.

3

The tomcat logs don’t catch any entry for the error, the service just stops.
These are only entrys for the startup i initiated with systemctl start tomcat:

/var/log/tomcat/catalina.2019-08-02.log 
[root@llmprod-01 candlepin]# tail -n 0 -f /var/log/tomcat/catalina.2019-08-02.log
Aug 02, 2019 11:05:30 AM org.apache.catalina.startup.SetAllPropertiesRule begin
WARNING: [SetAllPropertiesRule]{Server/Service/Connector} Setting property 'sslProtocols' to 'TLSv1.1,TLSv1.2' did not find a matching property.
Aug 02, 2019 11:05:30 AM org.apache.tomcat.util.digester.SetPropertiesRule begin
WARNING: [SetPropertiesRule]{Server/Service/Engine/Host} Setting property 'xmlValidation' to 'false' did not find a matching property.
Aug 02, 2019 11:05:30 AM org.apache.tomcat.util.digester.SetPropertiesRule begin
WARNING: [SetPropertiesRule]{Server/Service/Engine/Host} Setting property 'xmlNamespaceAware' to 'false' did not find a matching property.
Aug 02, 2019 11:05:30 AM org.apache.catalina.core.AprLifecycleListener lifecycleEvent
INFO: The APR based Apache Tomcat Native library which allows optimal performance in production environments was not found on the java.library.path: /usr/java/packages/lib/amd64:/usr/lib64:/lib64:/lib:/usr/lib
Aug 02, 2019 11:05:30 AM org.apache.coyote.AbstractProtocol init
INFO: Initializing ProtocolHandler ["http-bio-8443"]
Aug 02, 2019 11:05:30 AM org.apache.catalina.startup.Catalina load
INFO: Initialization processed in 730 ms
Aug 02, 2019 11:05:30 AM org.apache.catalina.core.StandardService startInternal
INFO: Starting service Catalina
Aug 02, 2019 11:05:30 AM org.apache.catalina.core.StandardEngine startInternal
INFO: Starting Servlet Engine: Apache Tomcat/7.0.76
Aug 02, 2019 11:05:30 AM org.apache.catalina.startup.HostConfig deployDirectory
INFO: Deploying web application directory /var/lib/tomcat/webapps/candlepin
Aug 02, 2019 11:05:33 AM org.apache.catalina.startup.TldConfig execute
INFO: At least one JAR was scanned for TLDs yet contained no TLDs. Enable debug logging for this logger for a complete list of JARs that were scanned but no TLDs were found in them. Skipping unneeded JARs during scanning can improve startup time and JSP compilation time.
Aug 02, 2019 11:05:36 AM com.google.inject.internal.ProxyFactory <init>
WARNING: Method [public org.candlepin.model.Persisted org.candlepin.model.OwnerCurator.create(org.candlepin.model.Persisted)] is synthetic and is being intercepted by [com.google.inject.persist.jpa.JpaLocalTxnInterceptor@6b937774]. This could indicate a bug.  The method may be intercepted twice, or may not be intercepted at all.
Aug 02, 2019 11:05:36 AM com.google.inject.internal.ProxyFactory <init>
WARNING: Method [public void org.candlepin.model.ProductCurator.delete(org.candlepin.model.Persisted)] is synthetic and is being intercepted by [com.google.inject.persist.jpa.JpaLocalTxnInterceptor@6b937774]. This could indicate a bug.  The method may be intercepted twice, or may not be intercepted at all.
Aug 02, 2019 11:05:36 AM com.google.inject.internal.ProxyFactory <init>
WARNING: Method [public org.candlepin.model.Persisted org.candlepin.model.ProductCurator.create(org.candlepin.model.Persisted)] is synthetic and is being intercepted by [com.google.inject.persist.jpa.JpaLocalTxnInterceptor@6b937774]. This could indicate a bug.  The method may be intercepted twice, or may not be intercepted at all.
Aug 02, 2019 11:05:36 AM com.google.inject.internal.ProxyFactory <init>
WARNING: Method [public org.candlepin.model.Persisted org.candlepin.model.ProductCurator.merge(org.candlepin.model.Persisted)] is synthetic and is being intercepted by [com.google.inject.persist.jpa.JpaLocalTxnInterceptor@6b937774]. This could indicate a bug.  The method may be intercepted twice, or may not be intercepted at all.
Aug 02, 2019 11:05:36 AM com.google.inject.internal.ProxyFactory <init>
WARNING: Method [public void org.candlepin.model.EntitlementCurator.delete(org.candlepin.model.Persisted)] is synthetic and is being intercepted by [com.google.inject.persist.jpa.JpaLocalTxnInterceptor@6b937774]. This could indicate a bug.  The method may be intercepted twice, or may not be intercepted at all.
Aug 02, 2019 11:05:36 AM com.google.inject.internal.ProxyFactory <init>
WARNING: Method [public void org.candlepin.model.ConsumerCurator.delete(org.candlepin.model.Persisted)] is synthetic and is being intercepted by [com.google.inject.persist.jpa.JpaLocalTxnInterceptor@6b937774]. This could indicate a bug.  The method may be intercepted twice, or may not be intercepted at all.
Aug 02, 2019 11:05:36 AM com.google.inject.internal.ProxyFactory <init>
WARNING: Method [public org.candlepin.model.Persisted org.candlepin.model.ConsumerCurator.create(org.candlepin.model.Persisted,boolean)] is synthetic and is being intercepted by [com.google.inject.persist.jpa.JpaLocalTxnInterceptor@6b937774]. This could indicate a bug.  The method may be intercepted twice, or may not be intercepted at all.
Aug 02, 2019 11:05:36 AM com.google.inject.internal.ProxyFactory <init>
WARNING: Method [public void org.candlepin.model.PoolCurator.delete(org.candlepin.model.Persisted)] is synthetic and is being intercepted by [com.google.inject.persist.jpa.JpaLocalTxnInterceptor@6b937774]. This could indicate a bug.  The method may be intercepted twice, or may not be intercepted at all.
Aug 02, 2019 11:05:36 AM com.google.inject.internal.ProxyFactory <init>
WARNING: 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@6b937774]. This could indicate a bug.  The method may be intercepted twice, or may not be intercepted at all.
Aug 02, 2019 11:05:36 AM com.google.inject.internal.ProxyFactory <init>
WARNING: Method [public void org.candlepin.model.CdnCurator.delete(org.candlepin.model.Persisted)] is synthetic and is being intercepted by [com.google.inject.persist.jpa.JpaLocalTxnInterceptor@6b937774]. This could indicate a bug.  The method may be intercepted twice, or may not be intercepted at all.
Aug 02, 2019 11:05:36 AM com.google.inject.internal.ProxyFactory <init>
WARNING: Method [public void org.candlepin.model.RulesCurator.delete(org.candlepin.model.Persisted)] is synthetic and is being intercepted by [com.google.inject.persist.jpa.JpaLocalTxnInterceptor@6b937774]. This could indicate a bug.  The method may be intercepted twice, or may not be intercepted at all.
Aug 02, 2019 11:05:36 AM com.google.inject.internal.ProxyFactory <init>
WARNING: 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@6b937774]. This could indicate a bug.  The method may be intercepted twice, or may not be intercepted at all.
Aug 02, 2019 11:05:36 AM com.google.inject.internal.ProxyFactory <init>
WARNING: Method [public void org.candlepin.model.EntitlementCertificateCurator.delete(org.candlepin.model.Persisted)] is synthetic and is being intercepted by [com.google.inject.persist.jpa.JpaLocalTxnInterceptor@6b937774]. This could indicate a bug.  The method may be intercepted twice, or may not be intercepted at all.
Aug 02, 2019 11:05:42 AM org.apache.catalina.startup.HostConfig deployDirectory
INFO: Deployment of web application directory /var/lib/tomcat/webapps/candlepin has finished in 12,076 ms
Aug 02, 2019 11:05:42 AM org.apache.coyote.AbstractProtocol start
INFO: Starting ProtocolHandler ["http-bio-8443"]
Aug 02, 2019 11:05:42 AM org.apache.catalina.startup.Catalina start
INFO: Server startup in 12136 ms
journalctl -u tomcat.service 
Aug 02 10:24:22 llmprod-01.intern.m-net.de server[10273]: INFO: Destroying ProtocolHandler ["http-bio-8443"]
Aug 02 10:24:22 llmprod-01.intern.m-net.de systemd[1]: Stopped Apache Tomcat Web Application Container.
Aug 02 10:24:22 llmprod-01.intern.m-net.de systemd[1]: Started Apache Tomcat Web Application Container.
Aug 02 10:24:22 llmprod-01.intern.m-net.de server[20963]: Java virtual machine used: /usr/lib/jvm/jre/bin/java
Aug 02 10:24:22 llmprod-01.intern.m-net.de server[20963]: classpath used: /usr/share/tomcat/bin/bootstrap.jar:/usr/sh
Aug 02 10:24:22 llmprod-01.intern.m-net.de server[20963]: main class used: org.apache.catalina.startup.Bootstrap
Aug 02 10:24:22 llmprod-01.intern.m-net.de server[20963]: flags used: -Xms1024m -Xmx4096m
Aug 02 10:24:22 llmprod-01.intern.m-net.de server[20963]: options used: -Dcatalina.base=/usr/share/tomcat -Dcatalina.
Aug 02 10:24:22 llmprod-01.intern.m-net.de server[20963]: arguments used: start
Aug 02 10:24:23 llmprod-01.intern.m-net.de server[20963]: Aug 02, 2019 10:24:23 AM org.apache.catalina.startup.SetAll
Aug 02 10:24:23 llmprod-01.intern.m-net.de server[20963]: WARNING: [SetAllPropertiesRule]{Server/Service/Connector} S
Aug 02 10:24:23 llmprod-01.intern.m-net.de server[20963]: Aug 02, 2019 10:24:23 AM org.apache.tomcat.util.digester.Se
Aug 02 10:24:23 llmprod-01.intern.m-net.de server[20963]: WARNING: [SetPropertiesRule]{Server/Service/Engine/Host} Se
Aug 02 10:24:23 llmprod-01.intern.m-net.de server[20963]: Aug 02, 2019 10:24:23 AM org.apache.tomcat.util.digester.Se
Aug 02 10:24:23 llmprod-01.intern.m-net.de server[20963]: WARNING: [SetPropertiesRule]{Server/Service/Engine/Host} Se
Aug 02 10:24:23 llmprod-01.intern.m-net.de server[20963]: Aug 02, 2019 10:24:23 AM org.apache.catalina.core.AprLifecy
Aug 02 10:24:23 llmprod-01.intern.m-net.de server[20963]: INFO: The APR based Apache Tomcat Native library which allo
Aug 02 10:24:23 llmprod-01.intern.m-net.de server[20963]: Aug 02, 2019 10:24:23 AM org.apache.coyote.AbstractProtocol
Aug 02 10:24:23 llmprod-01.intern.m-net.de server[20963]: INFO: Initializing ProtocolHandler ["http-bio-8443"]
Aug 02 10:24:23 llmprod-01.intern.m-net.de server[20963]: Aug 02, 2019 10:24:23 AM org.apache.catalina.startup.Catali
Aug 02 10:24:23 llmprod-01.intern.m-net.de server[20963]: INFO: Initialization processed in 830 ms
Aug 02 10:24:23 llmprod-01.intern.m-net.de server[20963]: Aug 02, 2019 10:24:23 AM org.apache.catalina.core.StandardS
Aug 02 10:24:23 llmprod-01.intern.m-net.de server[20963]: INFO: Starting service Catalina
Aug 02 10:24:23 llmprod-01.intern.m-net.de server[20963]: Aug 02, 2019 10:24:23 AM org.apache.catalina.core.StandardE
Aug 02 10:24:23 llmprod-01.intern.m-net.de server[20963]: INFO: Starting Servlet Engine: Apache Tomcat/7.0.76
Aug 02 10:24:23 llmprod-01.intern.m-net.de server[20963]: Aug 02, 2019 10:24:23 AM org.apache.catalina.startup.HostCo
Aug 02 10:24:23 llmprod-01.intern.m-net.de server[20963]: INFO: Deploying web application directory /var/lib/tomcat/w
Aug 02 10:24:27 llmprod-01.intern.m-net.de server[20963]: Aug 02, 2019 10:24:27 AM org.apache.catalina.startup.TldCon
Aug 02 10:24:27 llmprod-01.intern.m-net.de server[20963]: INFO: At least one JAR was scanned for TLDs yet contained n
Aug 02 10:24:29 llmprod-01.intern.m-net.de server[20963]: Aug 02, 2019 10:24:29 AM com.google.inject.internal.ProxyFa
Aug 02 10:24:29 llmprod-01.intern.m-net.de server[20963]: WARNING: Method [public org.candlepin.model.Persisted org.c
Aug 02 10:24:29 llmprod-01.intern.m-net.de server[20963]: Aug 02, 2019 10:24:29 AM com.google.inject.internal.ProxyFa
Aug 02 10:24:29 llmprod-01.intern.m-net.de server[20963]: WARNING: Method [public void org.candlepin.model.ProductCur
Aug 02 10:24:29 llmprod-01.intern.m-net.de server[20963]: Aug 02, 2019 10:24:29 AM com.google.inject.internal.ProxyFa
Aug 02 10:24:29 llmprod-01.intern.m-net.de server[20963]: WARNING: Method [public org.candlepin.model.Persisted org.c
Aug 02 10:24:29 llmprod-01.intern.m-net.de server[20963]: Aug 02, 2019 10:24:29 AM com.google.inject.internal.ProxyFa
Aug 02 10:24:29 llmprod-01.intern.m-net.de server[20963]: WARNING: Method [public org.candlepin.model.Persisted org.c
Aug 02 10:24:29 llmprod-01.intern.m-net.de server[20963]: Aug 02, 2019 10:24:29 AM com.google.inject.internal.ProxyFa
Aug 02 10:24:29 llmprod-01.intern.m-net.de server[20963]: WARNING: Method [public void org.candlepin.model.Entitlemen
Aug 02 10:24:30 llmprod-01.intern.m-net.de server[20963]: Aug 02, 2019 10:24:30 AM com.google.inject.internal.ProxyFa
Aug 02 10:24:30 llmprod-01.intern.m-net.de server[20963]: WARNING: Method [public void org.candlepin.model.ConsumerCu
Aug 02 10:24:30 llmprod-01.intern.m-net.de server[20963]: Aug 02, 2019 10:24:30 AM com.google.inject.internal.ProxyFa
Aug 02 10:24:30 llmprod-01.intern.m-net.de server[20963]: WARNING: Method [public org.candlepin.model.Persisted org.c
Aug 02 10:24:30 llmprod-01.intern.m-net.de server[20963]: Aug 02, 2019 10:24:30 AM com.google.inject.internal.ProxyFa
Aug 02 10:24:30 llmprod-01.intern.m-net.de server[20963]: WARNING: Method [public void org.candlepin.model.PoolCurato
Aug 02 10:24:30 llmprod-01.intern.m-net.de server[20963]: Aug 02, 2019 10:24:30 AM com.google.inject.internal.ProxyFa
Aug 02 10:24:30 llmprod-01.intern.m-net.de server[20963]: WARNING: Method [public void org.candlepin.model.ContentCur
Aug 02 10:24:30 llmprod-01.intern.m-net.de server[20963]: Aug 02, 2019 10:24:30 AM com.google.inject.internal.ProxyFa
Aug 02 10:24:30 llmprod-01.intern.m-net.de server[20963]: WARNING: Method [public void org.candlepin.model.CdnCurator
Aug 02 10:24:30 llmprod-01.intern.m-net.de server[20963]: Aug 02, 2019 10:24:30 AM com.google.inject.internal.ProxyFa
Aug 02 10:24:30 llmprod-01.intern.m-net.de server[20963]: WARNING: Method [public void org.candlepin.model.RulesCurat
Aug 02 10:24:30 llmprod-01.intern.m-net.de server[20963]: Aug 02, 2019 10:24:30 AM com.google.inject.internal.ProxyFa
Aug 02 10:24:30 llmprod-01.intern.m-net.de server[20963]: WARNING: Method [public org.candlepin.model.Persisted org.c
Aug 02 10:24:30 llmprod-01.intern.m-net.de server[20963]: Aug 02, 2019 10:24:30 AM com.google.inject.internal.ProxyFa
Aug 02 10:24:30 llmprod-01.intern.m-net.de server[20963]: WARNING: Method [public void org.candlepin.model.Entitlemen
Aug 02 10:24:36 llmprod-01.intern.m-net.de server[20963]: Aug 02, 2019 10:24:36 AM org.apache.catalina.startup.HostCo
Aug 02 10:24:36 llmprod-01.intern.m-net.de server[20963]: INFO: Deployment of web application directory /var/lib/tomc
Aug 02 10:24:36 llmprod-01.intern.m-net.de server[20963]: Aug 02, 2019 10:24:36 AM org.apache.coyote.AbstractProtocol
Aug 02 10:24:36 llmprod-01.intern.m-net.de server[20963]: INFO: Starting ProtocolHandler ["http-bio-8443"]
Aug 02 10:24:36 llmprod-01.intern.m-net.de server[20963]: Aug 02, 2019 10:24:36 AM org.apache.catalina.startup.Catali
Aug 02 10:24:36 llmprod-01.intern.m-net.de server[20963]: INFO: Server startup in 13252 ms

As i cannot upload files as new user, i pasted the hs_err_pid30253.log to pastebin:
https://pastebin.com/Y8kMr9sn

Thank you very much for your time!

4

When i try to download a debug certificate for the organization i also get this error:

{
  "error": {"message":"Katello::Resources::Candlepin::Owner: Server broke connection  (POST /candlepin/owners/Default_Organization/uebercert)"}
}

In the hs_err_pid30253.log i can see the following that could be relevant:

Java frames: (J=compiled Java code, j=interpreted, Vv=VM code)
j  org.mozilla.jss.pkcs11.PK11PubKey.fromSPKI([B)Lorg/mozilla/jss/pkcs11/PK11PubKey;+0
j  org.mozilla.jss.provider.java.security.KeyFactorySpi1_2.engineGeneratePublic(Ljava/security/spec/KeySpec;)Ljava/security/PublicKey;+253
J 11550 C1 java.security.KeyFactory.generatePublic(Ljava/security/spec/KeySpec;)Ljava/security/PublicKey; (83 bytes) @ 0x00007f039ebb105c [0x00007f039ebb0ac0
+0x59c]
j  org.mozilla.jss.netscape.security.x509.X509Key.buildX509Key(Lorg/mozilla/jss/netscape/security/x509/AlgorithmId;[B)Lorg/mozilla/jss/netscape/security/x509
/X509Key;+63
j  org.mozilla.jss.netscape.security.x509.X509Key.parse(Lorg/mozilla/jss/netscape/security/util/DerValue;)Lorg/mozilla/jss/netscape/security/x509/X509Key;+38
j  org.candlepin.pki.impl.JSSPKIUtility.createX509Certificate(Ljava/lang/String;Ljava/util/Set;Ljava/util/Set;Ljava/util/Date;Ljava/util/Date;Ljava/security/
KeyPair;Ljava/math/BigInteger;Ljava/lang/String;)Ljava/security/cert/X509Certificate;+132
j  org.candlepin.model.UeberCertificateGenerator.createX509Certificate(Lorg/candlepin/model/UeberCertificateGenerator$UeberCertData;Ljava/math/BigInteger;Ljava/security/KeyPair;)Ljava/security/cert/X509Certificate;+271
j  org.candlepin.model.UeberCertificateGenerator.generateUeberCert(Lorg/candlepin/model/Owner;Ljava/lang/String;)Lorg/candlepin/model/UeberCertificate;+89
j  org.candlepin.model.UeberCertificateGenerator.generate(Ljava/lang/String;Lorg/candlepin/auth/Principal;)Lorg/candlepin/model/UeberCertificate;+55
j  org.candlepin.model.UeberCertificateGenerator$$EnhancerByGuice$$8096c1ab.CGLIB$generate$0(Ljava/lang/String;Lorg/candlepin/auth/Principal;)Lorg/candlepin/model/UeberCertificate;+3
j  org.candlepin.model.UeberCertificateGenerator$$EnhancerByGuice$$8096c1ab$$FastClassByGuice$$f771e6c0.invoke(ILjava/lang/Object;[Ljava/lang/Object;)Ljava/lang/Object;+101
J 10367 C1 com.google.inject.internal.InterceptorStackCallback$InterceptedMethodInvocation.proceed()Ljava/lang/Object; (91 bytes) @ 0x00007f039e8584ac [0x00007f039e858280+0x22c]
J 11388 C1 com.google.inject.persist.jpa.JpaLocalTxnInterceptor.invoke(Lorg/aopalliance/intercept/MethodInvocation;)Ljava/lang/Object; (264 bytes) @ 0x00007f039d703f74 [0x00007f039d703900+0x674]
J 10367 C1 com.google.inject.internal.InterceptorStackCallback$InterceptedMethodInvocation.proceed()Ljava/lang/Object; (91 bytes) @ 0x00007f039e8586ac [0x00007f039e858280+0x42c]
J 10661 C1 com.google.inject.internal.InterceptorStackCallback.intercept(Ljava/lang/Object;Ljava/lang/reflect/Method;[Ljava/lang/Object;Lcom/google/inject/internal/cglib/proxy/$MethodProxy;)Ljava/lang/Object; (17 bytes) @ 0x00007f039e93882c [0x00007f039e938660+0x1cc]
j  org.candlepin.model.UeberCertificateGenerator$$EnhancerByGuice$$8096c1ab.generate(Ljava/lang/String;Lorg/candlepin/auth/Principal;)Lorg/candlepin/model/UeberCertificate;+40
j  org.candlepin.resource.OwnerResource.createUeberCertificate(Lorg/candlepin/auth/Principal;Ljava/lang/String;)Lorg/candlepin/dto/api/v1/UeberCertificateDTO;+6
v  ~StubRoutines::call_stub

But i don’t know what this means exactly. I just found the “UeberCertificateGenerator” in there.

5

@freduardo: Can you create the Default Organization from the foreman UI after restarting tomcat? Or are you stuck with Candlepin in this state?
@Jonathon_Turel: Have you seen this before?

6

I haven’t seen this one before.

@freduardo can you tell me a little bit about how you installed foreman & katello - specifically what ‘foreman-installer’ command you ran? Did this command finish without any errors? Finally, how much RAM is available to your VM?

7

@sajha: No i can’t resume the Task for the creation. It’s stuck at ~65% and when i try to resume it candlepin crashes.
@Jonathon_Turel: yes:

We are using a Vmware environment. Our VM:
4x vCPUs
12GB vRAM
200GB VHD
CentOS 7.6.1810

The installation:

yum -y localinstall https://fedorapeople.org/groups/katello/releases/yum/3.12/katello/el7/x86_64/katello-repos-latest.rpm
yum -y localinstall https://yum.theforeman.org/releases/1.22/el7/x86_64/foreman-release.rpm
yum -y localinstall https://yum.puppet.com/puppet6-release-el-7.noarch.rpm
yum -y localinstall https://dl.fedoraproject.org/pub/epel/epel-release-latest-7.noarch.rpm
yum -y install foreman-release-scl

yum -y update
yum -y install katello

foreman-installer --scenario katello

The installation throws an error at the first attempt about rake, but it disapeared on a second attempt.
I checked rake after the first attempt with: “foreman-rake db:seed --trace” the result was a sucess.

After the installation i run:

foreman-installer --scenario katello \
--certs-server-cert "/etc/pki/tls/certs/llmprod-01[...].crt" \
--certs-server-key "/etc/pki/tls/private/llmprod-01[...].key" \
--certs-server-ca-cert "/etc/pki/tls/certs/[...]-Sub-Intern-01.crt" \
--certs-update-server --certs-update-server-ca

I don’t run the ssl-cert commands in the first run because they would throw an error like this guy does:
https://projects.theforeman.org/issues/27059

The candlepin error appears directly after the first start, even before i add the ssl certificate.
I tried this a couple of times, created a snapshot before the very first installation and tried again and again. Always the same result.
Next step for me would be to download a fresh CentOS image and set up a VM manually. The first one was provisioned over Chef cookbook, but i don’t now why this should be a problem.

8

Ok i tested this in an Hyper-V environment with a manually installed CentOS Image. It is working normal with the exact same steps, so i will have a look at our CentOS Chef deployment tomorrow.

Any ideas where to start?
I’d have a look again at the error from rake in the installer log and compare the installed packages and repos from the deployment?

9

If you run dmesg, do you see any out of memory errors?

10

@Chris_Duryee i checked this but i don’t see any memory issues. In my testenvironment i run foreman/katello successfully with 8GB RAM, in Prod it’s not working with 12GB RAM.

The only “Error” i got in Prod was this one from Rake:

Installer Error Rake 
[ERROR 2019-08-05T09:50:01 main]  /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]
[ERROR 2019-08-05T09:50:01 main]  /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]
[ERROR 2019-08-05T09:50:01 main] /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util/errors.rb:157:in `fail'
[ERROR 2019-08-05T09:50:01 main] /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/type/exec.rb:168:in `sync'
[ERROR 2019-08-05T09:50:01 main] /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/type/exec.rb:626:in `refresh'
[ERROR 2019-08-05T09:50:01 main] /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/transaction/event_manager.rb:149:in `process_callback'
[ERROR 2019-08-05T09:50:01 main] /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/transaction/event_manager.rb:34:in `block in process_events'
[ERROR 2019-08-05T09:50:01 main] /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/transaction/event_manager.rb:121:in `block in queued_events'
[ERROR 2019-08-05T09:50:01 main] /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/transaction/event_manager.rb:120:in `each'
[ERROR 2019-08-05T09:50:01 main] /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/transaction/event_manager.rb:120:in `queued_events'
[ERROR 2019-08-05T09:50:01 main] /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/transaction/event_manager.rb:33:in `process_events'
[ERROR 2019-08-05T09:50:01 main] /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/transaction.rb:284:in `eval_resource'
[ERROR 2019-08-05T09:50:01 main] /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/transaction.rb:187:in `call'
[ERROR 2019-08-05T09:50:01 main] /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/transaction.rb:187:in `block (2 levels) in evaluate'
[ERROR 2019-08-05T09:50:01 main] /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util.rb:521:in `block in thinmark'
[ERROR 2019-08-05T09:50:01 main] /opt/puppetlabs/puppet/lib/ruby/2.5.0/benchmark.rb:308:in `realtime'
[ERROR 2019-08-05T09:50:01 main] /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util.rb:520:in `thinmark'
[ERROR 2019-08-05T09:50:01 main] /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/transaction.rb:187:in `block in e
valuate'
[ERROR 2019-08-05T09:50:01 main] /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/graph/relationship_graph.rb:122:in `traverse'
[ERROR 2019-08-05T09:50:01 main] /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/transaction.rb:174:in `evaluate'
[ERROR 2019-08-05T09:50:01 main] /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/resource/catalog.rb:240:in `block (2 levels) in apply'
[ERROR 2019-08-05T09:50:01 main] /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util.rb:521:in `block in thinmark'
[ERROR 2019-08-05T09:50:01 main] /opt/puppetlabs/puppet/lib/ruby/2.5.0/benchmark.rb:308:in `realtime'
[ERROR 2019-08-05T09:50:01 main] /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util.rb:520:in `thinmark'
[ERROR 2019-08-05T09:50:01 main] /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/resource/catalog.rb:239:in `block in apply'
[ERROR 2019-08-05T09:50:01 main] /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util/log.rb:161:in `with_destination'
[ERROR 2019-08-05T09:50:01 main] /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/transaction/report.rb:146:in `as_logging_destination'
[ERROR 2019-08-05T09:50:01 main] /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/resource/catalog.rb:238:in `apply'
[ERROR 2019-08-05T09:50:01 main] /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/configurer.rb:194:in `block (2 levels) in apply_catalog'
[ERROR 2019-08-05T09:50:01 main] /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util.rb:521:in `block in thinmark'
[ERROR 2019-08-05T09:50:01 main] /opt/puppetlabs/puppet/lib/ruby/2.5.0/benchmark.rb:308:in `realtime'
[ERROR 2019-08-05T09:50:01 main] /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util.rb:520:in `thinmark'
[ERROR 2019-08-05T09:50:01 main] /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/configurer.rb:193:in `block in apply_catalog'
[ERROR 2019-08-05T09:50:01 main] /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util.rb:233:in `block in benchmark'
[ERROR 2019-08-05T09:50:01 main] /opt/puppetlabs/puppet/lib/ruby/2.5.0/benchmark.rb:308:in `realtime'
[ERROR 2019-08-05T09:50:01 main] /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util.rb:232:in `benchmark'
[ERROR 2019-08-05T09:50:01 main] /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/configurer.rb:192:in `apply_catalog'
[ERROR 2019-08-05T09:50:01 main] /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/configurer.rb:381:in `run_internal'
[ERROR 2019-08-05T09:50:01 main] /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/configurer.rb:242:in `block in run'
[ERROR 2019-08-05T09:50:01 main] /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/context.rb:65:in `override'
[ERROR 2019-08-05T09:50:01 main] /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet.rb:266:in `override'
[ERROR 2019-08-05T09:50:01 main] /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/configurer.rb:219:in `run'
[ERROR 2019-08-05T09:50:01 main] /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/application/apply.rb:343:in `apply_catalog'
[ERROR 2019-08-05T09:50:01 main] /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/application/apply.rb:260:in `block (2 levels) in main'
[ERROR 2019-08-05T09:50:01 main] /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/context.rb:65:in `override'
[ERROR 2019-08-05T09:50:01 main] /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet.rb:266:in `override'
[ERROR 2019-08-05T09:50:01 main] /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/application/apply.rb:243:in `block in main'
[ERROR 2019-08-05T09:50:01 main] /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/context.rb:65:in `override'
[ERROR 2019-08-05T09:50:01 main] /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet.rb:266:in `override'
[ERROR 2019-08-05T09:50:01 main] /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/application/apply.rb:207:in `main'
[ERROR 2019-08-05T09:50:01 main] /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/application/apply.rb:177:in `run_command'
[ERROR 2019-08-05T09:50:01 main] /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/application.rb:382:in `block in run'
[ERROR 2019-08-05T09:50:01 main] /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util.rb:687:in `exit_on_fail'
[ERROR 2019-08-05T09:50:01 main] /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/application.rb:382:in `run'
[ERROR 2019-08-05T09:50:01 main] /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util/command_line.rb:143:in `run'
[ERROR 2019-08-05T09:50:01 main] /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util/command_line.rb:77:in `execute'
[ERROR 2019-08-05T09:50:01 main] /opt/puppetlabs/puppet/bin/puppet:5:in `<main>'

But the command “/usr/sbin/foreman-rake db:seed --trace” executes propertly and another run of foreman-installer succeeds.

I will compare the installed packages and configuration from the clean CentOS 7 Image with our CentOS 7 Chef provisioning. I’ll keep you up to date.

If you all got some other ideas feel free to share :blush:

11

Ok, it turns out that the Rake error from the installer might occur because of the candlepin error.
But i didn’t figure out what exactly is the problem. I just know that all packages are installed correctly and that just happens within our Enterprise Environment on a Chef-provisioned CentOS 7 VM.

If i use the Stock CentOS Image everything is working as far i can see.

12

I have came across this thread after encountering similar errors after installing a disconnected Red Hat Satellite. RHEL 7.7 Satellite version 6.5.1.

It is startling how similar the details in this thread are to my scenario. I too see:

  • Katello::Resources::Candlepin::Owner: Server broke connection (POST /candlepin/owners/<MYORG>/uebercert) messages. Restarting tomcat and attempting to resume the Create Organization task results in the failure reappearing and tomcat entering a failed state.

  • hammer ping also fails on candlepin and candlepin auth.

  • Running journalctl -u tomcat reveals SIGSEGV errors which I appreciate appear to be different to @freduardo.

  • Whilst looking at /var/log/tomcat/catalina-date.log I also note WARNING: Method [public void org.candlepin.model.ConsumerCurator.....] is synthetic and is being intercepted by [com.google.injedt.persist.jpa.JpaLocalTxnIntercept...] This could be indicate a bug. The method may be intercepted twice or may not be intercepted at all. This message is repeated numerous times.

Okay now I write that I appreciate there are slight differences but I’m curious to see this thread resolved. I will raise a case with Red Hat if I don’t resolve this soon and report back.

(I can supply versions of packages I’m using if required. Running with SELinux enabled and ipv6 disabled if that makes a difference.)

13

any update on this… i have the exact same trouble… with a fresh install of centos7 (minimal)

14

Probably same issue as here (resolved) : Candlepin crash after upgrade to 1.22.1

TL;DR
Temporary fix: yum downgrade java-1.8.0-openjdk-1:1.8.0.222.b10-0.el7_6.x86_64 java-1.8.0-openjdk-headless-1:1.8.0.222.b10-0.el7_6.x86_64

2 Likes
15

I’ll have to test that. But currently running on a fresh image with foreman 1.22/ katello 3.12 with openjdk1.8.222 and running normally.
I’ll try to reproduce on the faulty system

16

Currently I am not able to install a working Foreman Installation with the latest Centos ISO Image.

I am having the same Rake Errors as @freduardo.
Downgrading java version does not change anything.

Is there anyone who know what causes this issue?

17

I’ve marked a solution which links to a central thread. https://bugzilla.redhat.com/show_bug.cgi?id=1751967 mentions this is probably fixed in a newer candlepin and we’re looking at including a newer version.

1 Like
18

Thanks, downgrading Java did fix my issue