Bug 1500972

Summary: traceback when deleting organization: javax.persistence.RollbackException: Error while committing the transaction
Product: Red Hat Satellite Reporter: Jan Hutař <jhutar>
Component: Subscription ManagementAssignee: Justin Sherrill <jsherril>
Status: CLOSED ERRATA QA Contact: Jan Hutař <jhutar>
Severity: medium Docs Contact:
Priority: high    
Version: 6.3.0CC: bbuckingham, jsherril, khowell, mhulan, pcreech, wpoteat
Target Milestone: 6.5.0Keywords: Triaged
Target Release: Unused   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of:
: 1526016 (view as bug list) Environment:
Last Closed: 2019-05-14 12:36:38 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On: 1526016, 1526017    
Bug Blocks:    
Attachments:
Description Flags
tail -f on many satellite logs none

Description Jan Hutař 2017-10-11 21:17:38 UTC
Created attachment 1337427 [details]
tail -f on many satellite logs

Description of problem:
Traceback appears when deleting organization: javax.persistence.RollbackException: Error while committing the transaction


Version-Release number of selected component (if applicable):
satellite-6.3.0-19.0.beta.el7sat.noarch


How reproducible:
1 of 1


Steps to Reproduce:
1. In default organization sync (via lazy sync) RHEL7 + RHEL7 satellite tools + Software collections
2. Create new organization and user who is org admin in it
3. In the new organization sync RHEL7 + RHEL7 satellite tools
4. Delete the organization
   Administer -> Organizations -> in drop down list on a right end of the new org select "Delete"
5. Tail logs


Actual results:
There is a traceback


Expected results:
There should be no traceback


Additional info:
==> /var/log/candlepin/candlepin.log <==
2017-10-11 17:09:32,491 [thread=http-bio-8443-exec-3] [req=57deab18-f29d-4e1c-a9c7-937cfc744b3f, org=, csid=1f649599] INFO  org.candlepin.common.filter.LoggingFilter - Request: verb=GET, uri=/candlepin/environments/2
2017-10-11 17:09:32,503 [thread=http-bio-8443-exec-2] [req=1a66fff9-3cc4-4443-8741-70c31bac650b, org=, csid=1f649599] INFO  org.candlepin.common.filter.LoggingFilter - Request: verb=GET, uri=/candlepin/environments/2
2017-10-11 17:09:32,615 [thread=http-bio-8443-exec-3] [req=57deab18-f29d-4e1c-a9c7-937cfc744b3f, org=Another_Organization, csid=1f649599] INFO  org.candlepin.common.filter.LoggingFilter - Response: status=200, content-type="application/json", time=124
2017-10-11 17:09:32,616 [thread=http-bio-8443-exec-2] [req=1a66fff9-3cc4-4443-8741-70c31bac650b, org=Another_Organization, csid=1f649599] INFO  org.candlepin.common.filter.LoggingFilter - Response: status=200, content-type="application/json", time=113
2017-10-11 17:09:32,634 [thread=http-bio-8443-exec-5] [req=140bb6a3-6adb-48d1-91f8-2fd29432199b, org=, csid=1f649599] INFO  org.candlepin.common.filter.LoggingFilter - Request: verb=DELETE, uri=/candlepin/environments/2/content?content=4831&content=2456
2017-10-11 17:09:32,639 [thread=http-bio-8443-exec-1] [req=ff8be1fb-37ca-4bcb-8b1e-81032b723461, org=, csid=1f649599] INFO  org.candlepin.common.filter.LoggingFilter - Request: verb=DELETE, uri=/candlepin/environments/2/content?content=4831
2017-10-11 17:09:33,298 [thread=http-bio-8443-exec-5] [req=140bb6a3-6adb-48d1-91f8-2fd29432199b, org=Another_Organization, csid=1f649599] INFO  org.candlepin.resource.AdminResource - Concurrent content demotion will cause this request to fail.
javax.persistence.RollbackException: Error while committing the transaction
	at org.hibernate.jpa.internal.TransactionImpl.commit(TransactionImpl.java:87) ~[hibernate-entitymanager-5.1.1.Final.jar:5.1.1.Final]
	at com.google.inject.persist.jpa.JpaLocalTxnInterceptor.invoke(JpaLocalTxnInterceptor.java:87) ~[guice-persist-3.0.jar:na]
	at org.candlepin.resource.EnvironmentResource.demoteContent(EnvironmentResource.java:304) ~[EnvironmentResource.class:na]
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_144]
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_144]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_144]
	at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_144]
	at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:137) [resteasy-jaxrs-3.0.10.Final.jar:na]
	at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTarget(ResourceMethodInvoker.java:296) [resteasy-jaxrs-3.0.10.Final.jar:na]
	at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:250) [resteasy-jaxrs-3.0.10.Final.jar:na]
	at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:237) [resteasy-jaxrs-3.0.10.Final.jar:na]
	at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:356) [resteasy-jaxrs-3.0.10.Final.jar:na]
	at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:179) [resteasy-jaxrs-3.0.10.Final.jar:na]
	at org.jboss.resteasy.plugins.server.servlet.ServletContainerDispatcher.service(ServletContainerDispatcher.java:220) [resteasy-jaxrs-3.0.10.Final.jar:na]
	at org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(HttpServletDispatcher.java:56) [resteasy-jaxrs-3.0.10.Final.jar:na]
	at org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(HttpServletDispatcher.java:51) [resteasy-jaxrs-3.0.10.Final.jar:na]
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:731) [tomcat-servlet-3.0-api.jar:na]
	at com.google.inject.servlet.ServletDefinition.doService(ServletDefinition.java:263) [guice-servlet-3.0.jar:na]
	at com.google.inject.servlet.ServletDefinition.service(ServletDefinition.java:178) [guice-servlet-3.0.jar:na]
	at com.google.inject.servlet.ManagedServletPipeline.service(ManagedServletPipeline.java:91) [guice-servlet-3.0.jar:na]
	at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:62) [guice-servlet-3.0.jar:na]
	at org.candlepin.servlet.filter.EventFilter.doFilter(EventFilter.java:61) [EventFilter.class:na]
	at com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:163) [guice-servlet-3.0.jar:na]
	at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:58) [guice-servlet-3.0.jar:na]
	at org.candlepin.servlet.filter.ContentTypeHackFilter.doFilter(ContentTypeHackFilter.java:58) [ContentTypeHackFilter.class:na]
	at com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:163) [guice-servlet-3.0.jar:na]
	at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:58) [guice-servlet-3.0.jar:na]
	at org.candlepin.common.filter.LoggingFilter.doFilter(LoggingFilter.java:112) [candlepin-common-2.0.3.jar:na]
	at com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:163) [guice-servlet-3.0.jar:na]
	at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:58) [guice-servlet-3.0.jar:na]
	at org.candlepin.servlet.filter.CandlepinPersistFilter.doFilter(CandlepinPersistFilter.java:48) [CandlepinPersistFilter.class:na]
	at com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:163) [guice-servlet-3.0.jar:na]
	at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:58) [guice-servlet-3.0.jar:na]
	at org.candlepin.servlet.filter.CandlepinScopeFilter.doFilter(CandlepinScopeFilter.java:68) [CandlepinScopeFilter.class:na]
	at com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:163) [guice-servlet-3.0.jar:na]
	at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:58) [guice-servlet-3.0.jar:na]
	at com.google.inject.servlet.ManagedFilterPipeline.dispatch(ManagedFilterPipeline.java:118) [guice-servlet-3.0.jar:na]
	at com.google.inject.servlet.GuiceFilter.doFilter(GuiceFilter.java:113) [guice-servlet-3.0.jar:na]
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241) [catalina.jar:7.0.76]
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208) [catalina.jar:7.0.76]
	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:218) [catalina.jar:7.0.76]
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:110) [catalina.jar:7.0.76]
	at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:506) [catalina.jar:7.0.76]
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:169) [catalina.jar:7.0.76]
	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103) [catalina.jar:7.0.76]
	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:116) [catalina.jar:7.0.76]
	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:445) [catalina.jar:7.0.76]
	at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1087) [tomcat-coyote.jar:7.0.76]
	at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:637) [tomcat-coyote.jar:7.0.76]
	at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:316) [tomcat-coyote.jar:7.0.76]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [na:1.8.0_144]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [na:1.8.0_144]
	at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) [tomcat-coyote.jar:7.0.76]
	at java.lang.Thread.run(Thread.java:748) [na:1.8.0_144]
Caused by: javax.persistence.OptimisticLockException: Batch update returned unexpected row count from update [0]; actual row count: 0; expected: 1
	at org.hibernate.jpa.spi.AbstractEntityManagerImpl.wrapStaleStateException(AbstractEntityManagerImpl.java:1729) ~[hibernate-entitymanager-5.1.1.Final.jar:5.1.1.Final]
	at org.hibernate.jpa.spi.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1634) ~[hibernate-entitymanager-5.1.1.Final.jar:5.1.1.Final]
	at org.hibernate.jpa.spi.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1602) ~[hibernate-entitymanager-5.1.1.Final.jar:5.1.1.Final]
	at org.hibernate.jpa.internal.TransactionImpl.commit(TransactionImpl.java:68) ~[hibernate-entitymanager-5.1.1.Final.jar:5.1.1.Final]
	... 53 common frames omitted
Caused by: org.hibernate.StaleStateException: Batch update returned unexpected row count from update [0]; actual row count: 0; expected: 1
	at org.hibernate.jdbc.Expectations$BasicExpectation.checkBatched(Expectations.java:67) ~[hibernate-core-5.1.1.Final.jar:5.1.1.Final]
	at org.hibernate.jdbc.Expectations$BasicExpectation.verifyOutcome(Expectations.java:54) ~[hibernate-core-5.1.1.Final.jar:5.1.1.Final]
	at org.hibernate.engine.jdbc.batch.internal.NonBatchingBatch.addToBatch(NonBatchingBatch.java:46) ~[hibernate-core-5.1.1.Final.jar:5.1.1.Final]
	at org.hibernate.persister.entity.AbstractEntityPersister.delete(AbstractEntityPersister.java:3244) ~[hibernate-core-5.1.1.Final.jar:5.1.1.Final]
	at org.hibernate.persister.entity.AbstractEntityPersister.delete(AbstractEntityPersister.java:3481) ~[hibernate-core-5.1.1.Final.jar:5.1.1.Final]
	at org.hibernate.action.internal.EntityDeleteAction.execute(EntityDeleteAction.java:98) ~[hibernate-core-5.1.1.Final.jar:5.1.1.Final]
	at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:582) ~[hibernate-core-5.1.1.Final.jar:5.1.1.Final]
	at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:456) ~[hibernate-core-5.1.1.Final.jar:5.1.1.Final]
	at org.hibernate.event.internal.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:337) ~[hibernate-core-5.1.1.Final.jar:5.1.1.Final]
	at org.hibernate.event.internal.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:39) ~[hibernate-core-5.1.1.Final.jar:5.1.1.Final]
	at org.hibernate.internal.SessionImpl.flush(SessionImpl.java:1295) ~[hibernate-core-5.1.1.Final.jar:5.1.1.Final]
	at org.hibernate.internal.SessionImpl.managedFlush(SessionImpl.java:468) ~[hibernate-core-5.1.1.Final.jar:5.1.1.Final]
	at org.hibernate.internal.SessionImpl.flushBeforeTransactionCompletion(SessionImpl.java:3135) ~[hibernate-core-5.1.1.Final.jar:5.1.1.Final]
	at org.hibernate.internal.SessionImpl.beforeTransactionCompletion(SessionImpl.java:2352) ~[hibernate-core-5.1.1.Final.jar:5.1.1.Final]
	at org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.beforeTransactionCompletion(JdbcCoordinatorImpl.java:491) ~[hibernate-core-5.1.1.Final.jar:5.1.1.Final]
	at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl.beforeCompletionCallback(JdbcResourceLocalTransactionCoordinatorImpl.java:147) ~[hibernate-core-5.1.1.Final.jar:5.1.1.Final]
	at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl.access$100(JdbcResourceLocalTransactionCoordinatorImpl.java:38) ~[hibernate-core-5.1.1.Final.jar:5.1.1.Final]
	at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl$TransactionDriverControlImpl.commit(JdbcResourceLocalTransactionCoordinatorImpl.java:231) ~[hibernate-core-5.1.1.Final.jar:5.1.1.Final]
	at org.hibernate.engine.transaction.internal.TransactionImpl.commit(TransactionImpl.java:65) ~[hibernate-core-5.1.1.Final.jar:5.1.1.Final]
	at org.hibernate.jpa.internal.TransactionImpl.commit(TransactionImpl.java:61) ~[hibernate-entitymanager-5.1.1.Final.jar:5.1.1.Final]
	... 53 common frames omitted
2017-10-11 17:09:33,299 [thread=http-bio-8443-exec-5] [req=140bb6a3-6adb-48d1-91f8-2fd29432199b, org=Another_Organization, csid=1f649599] WARN  org.candlepin.audit.EventSinkImpl - Rolling back hornetq transaction.
2017-10-11 17:09:33,299 [thread=http-bio-8443-exec-5] [req=140bb6a3-6adb-48d1-91f8-2fd29432199b, org=Another_Organization, csid=1f649599] INFO  org.candlepin.common.filter.LoggingFilter - Response: status=404, content-type="application/json", time=665
2017-10-11 17:09:33,903 [thread=http-bio-8443-exec-1] [req=ff8be1fb-37ca-4bcb-8b1e-81032b723461, org=Another_Organization, csid=1f649599] INFO  org.candlepin.common.filter.LoggingFilter - Response: status=202, content-type="application/json", time=1264

Comment 2 Marek Hulan 2017-12-11 15:54:11 UTC
The trace comes from candlepin, most likely an issue in Katello orchestration or Candlepin itself, changing the component.

Comment 3 Justin Sherrill 2018-01-15 19:42:40 UTC
Looks like katello is removing the content from the environment unnecessarily.  Likely this patch will resolve it:

--- a/app/lib/actions/katello/repository/destroy.rb
+++ b/app/lib/actions/katello/repository/destroy.rb
@@ -26,7 +26,7 @@ module Actions
           sequence do
             repository.destroy! if planned_destroy
             if repository.redhat?
-              handle_redhat_content(repository)
+              handle_redhat_content(repository) unless skip_environment_update
             else
               handle_custom_content(repository) unless skip_environment_update
             end

Comment 4 Justin Sherrill 2018-09-19 19:28:21 UTC
Untriaging and proposing for 6.5.0.  Its a small change and shouldn't break anything

Comment 5 Justin Sherrill 2018-11-19 16:54:17 UTC
Created redmine issue https://projects.theforeman.org/issues/25509 from this bug

Comment 9 errata-xmlrpc 2019-05-14 12:36:38 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-2019:1222