Red Hat Satellite engineering is moving the tracking of its product development work on Satellite to Red Hat Jira (issues.redhat.com). If you're a Red Hat customer, please continue to file support cases via the Red Hat customer portal. If you're not, please head to the "Satellite project" in Red Hat Jira and file new tickets here. Individual Bugzilla bugs will be migrated starting at the end of May. If you cannot log in to RH Jira, please consult article #7032570. That failing, please send an e-mail to the RH Jira admins at rh-issues@redhat.com to troubleshoot your issue as a user management inquiry. The email creates a ServiceNow ticket with Red Hat. Individual Bugzilla bugs that are migrated will be moved to status "CLOSED", resolution "MIGRATED", and set with "MigratedToJIRA" in "Keywords". The link to the successor Jira issue will be found under "Links", have a little "two-footprint" icon next to it, and direct you to the "Satellite project" in Red Hat Jira (issue links are of type "https://issues.redhat.com/browse/SAT-XXXX", where "X" is a digit). This same link will be available in a blue banner at the top of the page informing you that that bug has been migrated.
Bug 1342392 - [upgrade] Exception in candlepin logs: javax.persistence.PersistenceException: unexpected error when rollbacking
Summary: [upgrade] Exception in candlepin logs: javax.persistence.PersistenceException...
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Red Hat Satellite
Classification: Red Hat
Component: Content Management
Version: 6.2.0
Hardware: Unspecified
OS: Unspecified
unspecified
high
Target Milestone: Unspecified
Assignee: Partha Aji
QA Contact: Sachin Ghai
URL:
Whiteboard:
Depends On:
Blocks: 1335807
TreeView+ depends on / blocked
 
Reported: 2016-06-03 07:33 UTC by Sachin Ghai
Modified: 2020-02-14 17:47 UTC (History)
5 users (show)

Fixed In Version: katello-3.0.0-8
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2018-02-21 16:54:37 UTC
Target Upstream Version:
Embargoed:

Attachments (Terms of Use)
Complete exception from candlepin logs (41.58 KB, text/plain)
2016-06-03 07:34 UTC, Sachin Ghai 		no flags Details
foreman-debug logs (1.10 MB, application/x-xz)
2016-06-03 07:35 UTC, Sachin Ghai 		no flags Details
View All


Links
System ID Private Priority Status Summary Last Updated
Foreman Issue Tracker 15146 0 Normal Closed service-wait script needs to handle tomcat. 2020-11-03 17:07:33 UTC

Description Sachin Ghai 2016-06-03 07:33:50 UTC 
Description of problem: I got following exception in candlepin.log when sat6.1.9 -> 6.2 GA snap14.2 upgrade was running with installer step:

At first look, it seems that this is being raised as postgresql db is down. But still I would like to check with respective devs and get a confirmation if its harmless. And If its harmless, can we suppress this one or two lines ?

==> /var/log/candlepin/candlepin.log <==
2016-06-03 02:29:20,021 [thread=QuartzScheduler_Worker-8] [job=UnpauseJob-48e5971d-1462-40f2-8453-387df03e7539, org=] WARN  org.hibernate.engine.jdbc.spi.SqlExceptionHelper - SQL Error: 0, SQLState: 57P01
2016-06-03 02:29:20,021 [thread=QuartzScheduler_Worker-5] [job=UnpauseJob-48e5971d-1462-40f2-8453-387df03e7539, org=] WARN  org.hibernate.engine.jdbc.spi.SqlExceptionHelper - SQL Error: 0, SQLState: 57P01
2016-06-03 02:29:20,021 [thread=QuartzScheduler_Worker-8] [job=UnpauseJob-48e5971d-1462-40f2-8453-387df03e7539, org=] ERROR org.hibernate.engine.jdbc.spi.SqlExceptionHelper - FATAL: terminating connection due to administrator command
2016-06-03 02:29:20,021 [thread=QuartzScheduler_Worker-5] [job=UnpauseJob-48e5971d-1462-40f2-8453-387df03e7539, org=] ERROR org.hibernate.engine.jdbc.spi.SqlExceptionHelper - FATAL: terminating connection due to administrator command
2016-06-03 02:29:20,021 [thread=QuartzScheduler_Worker-8] [job=UnpauseJob-48e5971d-1462-40f2-8453-387df03e7539, org=] WARN  org.hibernate.engine.jdbc.spi.SqlExceptionHelper - SQL Error: 0, SQLState: 08006
2016-06-03 02:29:20,022 [thread=QuartzScheduler_Worker-5] [job=UnpauseJob-48e5971d-1462-40f2-8453-387df03e7539, org=] WARN  org.hibernate.engine.jdbc.spi.SqlExceptionHelper - SQL Error: 0, SQLState: 08006
2016-06-03 02:29:20,022 [thread=QuartzScheduler_Worker-5] [job=UnpauseJob-48e5971d-1462-40f2-8453-387df03e7539, org=] ERROR org.hibernate.engine.jdbc.spi.SqlExceptionHelper - An I/O error occured while sending to the backend.
2016-06-03 02:29:20,022 [thread=QuartzScheduler_Worker-8] [job=UnpauseJob-48e5971d-1462-40f2-8453-387df03e7539, org=] ERROR org.hibernate.engine.jdbc.spi.SqlExceptionHelper - An I/O error occured while sending to the backend.
2016-06-03 02:29:20,028 [thread=QuartzScheduler_Worker-5] [job=UnpauseJob-48e5971d-1462-40f2-8453-387df03e7539, org=] WARN  com.mchange.v2.c3p0.impl.NewPooledConnection - [c3p0] A PooledConnection that has already signalled a Connection error is still in use!
2016-06-03 02:29:20,030 [thread=QuartzScheduler_Worker-8] [job=UnpauseJob-48e5971d-1462-40f2-8453-387df03e7539, org=] WARN  com.mchange.v2.c3p0.impl.NewPooledConnection - [c3p0] A PooledConnection that has already signalled a Connection error is still in use!
2016-06-03 02:29:20,040 [thread=QuartzScheduler_Worker-5] [job=UnpauseJob-48e5971d-1462-40f2-8453-387df03e7539, org=] WARN  com.mchange.v2.c3p0.impl.NewPooledConnection - [c3p0] Another error has occurred [ org.postgresql.util.PSQLException: This connection has been closed. ] which will not be reported to listeners!
org.postgresql.util.PSQLException: This connection has been closed.
	at org.postgresql.jdbc2.AbstractJdbc2Connection.checkClosed(AbstractJdbc2Connection.java:714) ~[postgresql-9.0-801.jdbc4.jar:na]
	at org.postgresql.jdbc2.AbstractJdbc2Connection.rollback(AbstractJdbc2Connection.java:731) ~[postgresql-9.0-801.jdbc4.jar:na]
	at com.mchange.v2.c3p0.impl.NewProxyConnection.rollback(NewProxyConnection.java:855) ~[c3p0-0.9.1.2.jar:0.9.1.2]
	at org.hibernate.engine.transaction.internal.jdbc.JdbcTransaction.doRollback(JdbcTransaction.java:163) [hibernate-core-4.2.5.Final.jar:4.2.5.Final]
	at org.hibernate.engine.transaction.spi.AbstractTransactionImpl.rollback(AbstractTransactionImpl.java:209) [hibernate-core-4.2.5.Final.jar:4.2.5.Final]
	at org.hibernate.ejb.TransactionImpl.rollback(TransactionImpl.java:106) [hibernate-entitymanager-4.2.5.Final.jar:4.2.5.Final]
	at com.google.inject.persist.jpa.JpaLocalTxnInterceptor.rollbackIfNecessary(JpaLocalTxnInterceptor.java:149) [guice-persist-3.0.jar:na]
	at com.google.inject.persist.jpa.JpaLocalTxnInterceptor.invoke(JpaLocalTxnInterceptor.java:70) [guice-persist-3.0.jar:na]
	at com.google.inject.internal.InterceptorStackCallback$InterceptedMethodInvocation.proceed(InterceptorStackCallback.java:72) [guice-3.0.jar:na]
	at com.google.inject.internal.InterceptorStackCallback.intercept(InterceptorStackCallback.java:52) [guice-3.0.jar:na]
	at org.candlepin.model.JobCurator$$EnhancerByGuice$$6a18aec5.find(<generated>) [guice-3.0.jar:na]
	at org.candlepin.pinsetter.core.PinsetterJobListener.updateJob(PinsetterJobListener.java:127) [PinsetterJobListener.class:na]
	at org.candlepin.pinsetter.core.PinsetterJobListener.updateJob(PinsetterJobListener.java:122) [PinsetterJobListener.class:na]
	at org.candlepin.pinsetter.core.PinsetterJobListener.jobToBeExecuted(PinsetterJobListener.java:72) [PinsetterJobListener.class:na]
	at org.quartz.core.QuartzScheduler.notifyJobListenersToBeExecuted(QuartzScheduler.java:1945) [quartz-2.2.1.jar:na]
	at org.quartz.core.JobRunShell.notifyListenersBeginning(JobRunShell.java:324) [quartz-2.2.1.jar:na]
	at org.quartz.core.JobRunShell.run(JobRunShell.java:173) [quartz-2.2.1.jar:na]
	at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:573) [quartz-2.2.1.jar:na]
2016-06-03 02:29:20,040 [thread=QuartzScheduler_Worker-8] [job=UnpauseJob-48e5971d-1462-40f2-8453-387df03e7539, org=] WARN  com.mchange.v2.c3p0.impl.NewPooledConnection - [c3p0] Another error has occurred [ org.postgresql.util.PSQLException: This connection has been closed. ] which will not be reported to listeners!
org.postgresql.util.PSQLException: This connection has been closed.
	at org.postgresql.jdbc2.AbstractJdbc2Connection.checkClosed(AbstractJdbc2Connection.java:714) ~[postgresql-9.0-801.jdbc4.jar:na]
	at org.postgresql.jdbc2.AbstractJdbc2Connection.rollback(AbstractJdbc2Connection.java:731) ~[postgresql-9.0-801.jdbc4.jar:na]
	at com.mchange.v2.c3p0.impl.NewProxyConnection.rollback(NewProxyConnection.java:855) ~[c3p0-0.9.1.2.jar:0.9.1.2]
	at org.hibernate.engine.transaction.internal.jdbc.JdbcTransaction.doRollback(JdbcTransaction.java:163) [hibernate-core-4.2.5.Final.jar:4.2.5.Final]
	at org.hibernate.engine.transaction.spi.AbstractTransactionImpl.rollback(AbstractTransactionImpl.java:209) [hibernate-core-4.2.5.Final.jar:4.2.5.Final]
	at org.hibernate.ejb.TransactionImpl.rollback(TransactionImpl.java:106) [hibernate-entitymanager-4.2.5.Final.jar:4.2.5.Final]
	at com.google.inject.persist.jpa.JpaLocalTxnInterceptor.rollbackIfNecessary(JpaLocalTxnInterceptor.java:149) [guice-persist-3.0.jar:na]
	at com.google.inject.persist.jpa.JpaLocalTxnInterceptor.invoke(JpaLocalTxnInterceptor.java:70) [guice-persist-3.0.jar:na]
	at com.google.inject.internal.InterceptorStackCallback$InterceptedMethodInvocation.proceed(InterceptorStackCallback.java:72) [guice-3.0.jar:na]

::::<snip>:::::::


2016-06-03 02:29:20,044 [thread=QuartzScheduler_Worker-5] [job=UnpauseJob-48e5971d-1462-40f2-8453-387df03e7539, org=] ERROR org.candlepin.pinsetter.core.PinsetterJobListener - jobToBeExecuted encountered a problem. Usually means there was a problem storing the job status. Job will run.
javax.persistence.PersistenceException: unexpected error when rollbacking
	at org.hibernate.ejb.TransactionImpl.rollback(TransactionImpl.java:109) ~[hibernate-entitymanager-4.2.5.Final.jar:4.2.5.Final]
	at com.google.inject.persist.jpa.JpaLocalTxnInterceptor.rollbackIfNecessary(JpaLocalTxnInterceptor.java:149) ~[guice-persist-3.0.jar:na]
	at com.google.inject.persist.jpa.JpaLocalTxnInterceptor.invoke(JpaLocalTxnInterceptor.java:70) ~[guice-persist-3.0.jar:na]
	at org.candlepin.pinsetter.core.PinsetterJobListener.updateJob(PinsetterJobListener.java:127) ~[PinsetterJobListener.class:na]
	at org.candlepin.pinsetter.core.PinsetterJobListener.updateJob(PinsetterJobListener.java:122) ~[PinsetterJobListener.class:na]
	at org.candlepin.pinsetter.core.PinsetterJobListener.jobToBeExecuted(PinsetterJobListener.java:72) ~[PinsetterJobListener.class:na]
	at org.quartz.core.QuartzScheduler.notifyJobListenersToBeExecuted(QuartzScheduler.java:1945) [quartz-2.2.1.jar:na]
	at org.quartz.core.JobRunShell.notifyListenersBeginning(JobRunShell.java:324) [quartz-2.2.1.jar:na]
	at org.quartz.core.JobRunShell.run(JobRunShell.java:173) [quartz-2.2.1.jar:na]
	at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:573) [quartz-2.2.1.jar:na]
Caused by: org.hibernate.TransactionException: rollback failed
	at org.hibernate.engine.transaction.spi.AbstractTransactionImpl.rollback(AbstractTransactionImpl.java:215) ~[hibernate-core-4.2.5.Final.jar:4.2.5.Final]
	at org.hibernate.ejb.TransactionImpl.rollback(TransactionImpl.java:106) ~[hibernate-entitymanager-4.2.5.Final.jar:4.2.5.Final]
	... 9 common frames omitted
Caused by: org.hibernate.TransactionException: unable to rollback against JDBC connection
	at org.hibernate.engine.transaction.internal.jdbc.JdbcTransaction.doRollback(JdbcTransaction.java:167) ~[hibernate-core-4.2.5.Final.jar:4.2.5.Final]
	at org.hibernate.engine.transaction.spi.AbstractTransactionImpl.rollback(AbstractTransactionImpl.java:209) ~[hibernate-core-4.2.5.Final.jar:4.2.5.Final]
	... 10 common frames omitted
Caused by: org.postgresql.util.PSQLException: This connection has been closed.
	at org.postgresql.jdbc2.AbstractJdbc2Connection.checkClosed(AbstractJdbc2Connection.java:714) ~[postgresql-9.0-801.jdbc4.jar:na]
	at org.postgresql.jdbc2.AbstractJdbc2Connection.rollback(AbstractJdbc2Connection.java:731) ~[postgresql-9.0-801.jdbc4.jar:na]
	at com.mchange.v2.c3p0.impl.NewProxyConnection.rollback(NewProxyConnection.java:855) ~[c3p0-0.9.1.2.jar:0.9.1.2]
	at org.hibernate.engine.transaction.internal.jdbc.JdbcTransaction.doRollback(JdbcTransaction.java:163) ~[hibernate-core-4.2.5.Final.jar:4.2.5.Final]
	... 11 common frames omitted
2016-06-03 02:29:20,045 [thread=QuartzScheduler_Worker-5] [job=UnpauseJob-48e5971d-1462-40f2-8453-387df03e7539, org=] WARN  com.mchange.v2.c3p0.impl.NewPooledConnection - [c3p0] A PooledConnection that has already signalled a Connection error is still in use!
2016-06-03 02:29:20,045 [thread=QuartzScheduler_Worker-8] [job=UnpauseJob-48e5971d-1462-40f2-8453-387df03e7539, org=] ERROR org.candlepin.pinsetter.core.PinsetterJobListener - jobToBeExecuted encountered a problem. Usually means there was a problem storing the job status. Job will run.
javax.persistence.PersistenceException: unexpected error when rollbacking


Version-Release number of selected component (if applicable):
sat6.1.9 -> 6.2 GA snap14.2 upgrade on rhel7

How reproducible:


Steps to Reproduce:
1.
2.
3.

Actual results:


Expected results:
No exception should be raised in logs while performing upgrade

Additional info:
Comment 1 Sachin Ghai 2016-06-03 07:34:41 UTC 
Created attachment 1164360 [details]
Complete exception from candlepin logs
Comment 2 Sachin Ghai 2016-06-03 07:35:36 UTC 
Created attachment 1164362 [details]
foreman-debug logs
Comment 4 Sachin Ghai 2016-06-03 08:35:18 UTC 
Reproducible version:
-----------------------
upgrade from sat6.1.9 -> sat6.2 GA snap14.1 on rhel7. 
Rpm version is 14.2

satellite-6.2.0-14.2.el7sat.noarch
Comment 5 Brad Buckingham 2016-06-06 00:58:04 UTC 
Hi Barnaby, can you take a look at the error Sachin observed in the Satellite 6.1.9 to 6.2 upgrade?  Thanks!
Comment 6 Barnaby Court 2016-06-06 13:58:07 UTC 
The most likely reason for this is that the DB went down while Candlepin was still running. Instead of blocking the error (as discussed in comment 1) the installer should make sure that Candlepin/tomcat has been stopped before stopping the database.
Comment 7 Brad Buckingham 2016-06-06 14:11:43 UTC 
Barnaby, thanks for the feedback.

Looking at the code, this could indeed be the condition that we are hitting.  While the installer does stop candlepin and then the database, it looks like the stopping of candlepin does not properly wait for shutdown prior to stopping postgresql. 

It looks like this is captured by http://projects.theforeman.org/issues/15146 and fixed upstream.
Comment 8 Sachin Ghai 2016-06-10 06:35:27 UTC 
Note for QE: reproducible with upgrade to sat6.2 with snap15.1
Comment 9 Sachin Ghai 2016-06-27 11:52:09 UTC 
The reported issue is reproducible when performing upgrade from sat6.1.9 -> sat6.2 snap17 on rhel7

	at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:573) [quartz-2.2.1.jar:na]
2016-06-27 07:40:50,057 [thread=QuartzScheduler_Worker-6] [job=UnpauseJob-945b0203-be70-4b94-8437-6336b510bf7f, org=] ERROR org.candlepin.pinsetter.core.PinsetterJobListener - jobToBeExecuted encountered a problem. Usually means there was a problem storing the job status. Job will run.
javax.persistence.PersistenceException: unexpected error when rollbacking
	at org.hibernate.ejb.TransactionImpl.rollback(TransactionImpl.java:109) ~[hibernate-entitymanager-4.2.5.Final.jar:4.2.5.Final]
	at com.google.inject.persist.jpa.JpaLocalTxnInterceptor.rollbackIfNecessary(JpaLocalTxnInterceptor.java:149) ~[guice-persist-3.0.jar:na]
	at com.google.inject.persist.jpa.JpaLocalTxnInterceptor.invoke(JpaLocalTxnInterceptor.java:70) ~[guice-persist-3.0.jar:na]
	at org.candlepin.pinsetter.core.PinsetterJobListener.updateJob(PinsetterJobListener.java:127) ~[PinsetterJobListener.class:na]
	at org.candlepin.pinsetter.core.PinsetterJobListener.updateJob(PinsetterJobListener.java:122) ~[PinsetterJobListener.class:na]
	at org.candlepin.pinsetter.core.PinsetterJobListener.jobToBeExecuted(PinsetterJobListener.java:72) ~[PinsetterJobListener.class:na]
	at org.quartz.core.QuartzScheduler.notifyJobListenersToBeExecuted(QuartzScheduler.java:1945) [quartz-2.2.1.jar:na]
	at org.quartz.core.JobRunShell.notifyListenersBeginning(JobRunShell.java:324) [quartz-2.2.1.jar:na]
	at org.quartz.core.JobRunShell.run(JobRunShell.java:173) [quartz-2.2.1.jar:na]
	at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:573) [quartz-2.2.1.jar:na]
Caused by: org.hibernate.TransactionException: rollback failed
Comment 10 Bryan Kearney 2016-06-27 12:15:28 UTC 
Upstream bug component is Content Management
Comment 12 Partha Aji 2016-07-22 17:54:38 UTC 
Sachin
I am unable to reproduce this. Can you verify the occurrence of this error.
Comment 16 Sachin Ghai 2017-12-21 10:20:02 UTC 
Verified with sat6.2.z -> 6.3 snap29 upgrades. I don't see reported issue. Moreover, I tried a few different dbs and reported issue is not reproducible.


Also, I tested same with 6.2 -> 6.2.13 snap2 upgrades. This issue is no longer reproducible.
Comment 17 Satellite Program 2018-02-21 16:54:37 UTC 
Since the problem described in this bug report should be resolved in a recent advisory, it has been closed with a resolution of ERRATA.
> > 
> > For information on the advisory, and where to find the updated files, follow the link below.
> > 
> > If the solution does not work for you, open a new bug report.
> > 
> > https://access.redhat.com/errata/RHSA-2018:0336
Note You need to log in before you can comment on or make changes to this bug.