1385099 – Satellite 5.6: Deadlock with system.obtainReactivationKey API call

Bug 1385099 - Satellite 5.6: Deadlock with system.obtainReactivationKey API call

Summary: Satellite 5.6: Deadlock with system.obtainReactivationKey API call

Keywords:
Status:	CLOSED ERRATA
Alias:	None
Product:	Red Hat Satellite 5
Classification:	Red Hat
Component:	API
Sub Component:
Version:	560
Hardware:	Unspecified
OS:	Unspecified
Priority:	high
Severity:	high
Target Milestone:	---
Assignee:	Grant Gainey
QA Contact:	Radovan Drazny
Docs Contact:
URL:
Whiteboard:
Depends On:
Blocks:	sat5-errata 1388160 1400108
TreeView+	depends on / blocked

Reported:	2016-10-14 18:24 UTC by Shannon Hughes
Modified:	2021-03-11 14:45 UTC (History)
CC List:	11 users (show)
Fixed In Version:	spacewalk-java-2.0.2-114-sat
Doc Type:	If docs needed, set a value
Doc Text:
Clone Of:
Clones:	1388160 1400108 (view as bug list)
Environment:
Last Closed:	2017-02-22 13:38:12 UTC
Target Upstream Version:
Embargoed:

Attachments	(Terms of Use)
main deadlock driver bash script (612 bytes, application/x-shellscript) 2016-10-14 18:24 UTC, Shannon Hughes	no flags	Details
reactivation key generator (2.37 KB, text/x-python) 2016-10-14 18:25 UTC, Shannon Hughes	no flags	Details
base channel updater (11.05 KB, text/x-python) 2016-10-14 18:25 UTC, Shannon Hughes	no flags	Details
base channel updater (1.37 KB, text/x-python) 2016-10-14 19:49 UTC, Shannon Hughes	no flags	Details
grab reactivation key (1.97 KB, text/x-python) 2016-10-14 19:50 UTC, Shannon Hughes	no flags	Details
oracle trace file (1021.41 KB, text/plain) 2016-10-19 17:46 UTC, Shannon Hughes	no flags	Details
Show Obsolete (2) View All

Links
System	ID	Private	Priority	Status	Summary	Last Updated
Red Hat Product Errata	RHBA-2017:0292	0	normal	SHIPPED_LIVE	Satellite 5.6 bug fix update	2017-02-22 18:37:33 UTC

Description Shannon Hughes 2016-10-14 18:24:06 UTC

Created attachment 1210627 [details]
main deadlock driver bash script

Description of problem:

Hitting deadlock with calls to the system.obtainReactivationKey API call and the rhnRegToken table:

2016-10-14 17:17:32,475] ERROR - REQUESTED FROM: 192.168.100.2 CALL: system.obtainReactivationKey(832x56d180cb3a6dbedc9e08b3e2e1b4a7f9, 1000010167) CALLER: (admin) TIME: 9.264 seconds
redstone.xmlrpc.XmlRpcFault: unhandled internal exception: java.sql.SQLException: ORA-00060: deadlock detected while waiting for resource

        at com.redhat.rhn.frontend.xmlrpc.BaseHandler.invoke(BaseHandler.java:173)
        at redstone.xmlrpc.XmlRpcDispatcher.dispatch(XmlRpcDispatcher.java:123)
        at com.redhat.rhn.frontend.xmlrpc.RhnXmlRpcServer.execute(RhnXmlRpcServer.java:54)
        at com.redhat.rhn.frontend.xmlrpc.XmlRpcServlet.doPost(XmlRpcServlet.java:162)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:710)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:803)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:269)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:188)
        at com.opensymphony.sitemesh.webapp.SiteMeshFilter.obtainContent(SiteMeshFilter.java:129)
        at com.opensymphony.sitemesh.webapp.SiteMeshFilter.doFilter(SiteMeshFilter.java:77)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:215)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:188)
        at com.redhat.rhn.frontend.servlets.LocalizedEnvironmentFilter.doFilter(LocalizedEnvironmentFilter.java:67)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:215)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:188)
        at com.redhat.rhn.frontend.servlets.EnvironmentFilter.doFilter(EnvironmentFilter.java:100)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:215)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:188)
        at com.redhat.rhn.frontend.servlets.SessionFilter.doFilter(SessionFilter.java:57)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:215)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:188)
        at com.redhat.rhn.frontend.servlets.SetCharacterEncodingFilter.doFilter(SetCharacterEncodingFilter.java:97)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:215)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:188)
        at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:210)
        at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:172)


Problematic code looks to be potentially in Hibernate where we need to add a lock on the factory/table from the SystemHandler API code: 

List<ActivationKey> existingKeys = ActivationKeyFactory.lookupByServer(server);
        for (ActivationKey key : existingKeys) {
            ActivationKeyFactory.removeKey(key);
        }

Took a while to figure out how to reproduce but will outline the steps below and attach the scripts used: 

1) reactivation.py is used to generate reactivation keys for clients calling in and is placed in the /var/www/cgi-bin directory of Satellite
2) updatechannels.py is used to update base channel of the client calling in and is also placed in the /var/www/cgi-bin directory of the Satellite
3) deadlock.sh is placed on the client and is the main driver to create the deadlock situation. 

Procedure is as follows: 

1) Kickstart 3+ clients to rhel 6u8. Place the deadlock.sh script on the clients and update the satellite url inside script. 
2) modify the two python cgi scripts to contain the correct user/pass information. 
3) create a activation key to assign a clone base channel to client for the main driver deadlock.sh script and name "shell" or rename the ACTIVATION_KEYS variable in deadlock.sh to your new name. 
4) run the deadlock.sh script on your clients and tail -f /var/log/rhn/rhn_web_api.log. 

I started seeing the deadlock about 20 times after the 2nd client script started looping.

Comment 1 Shannon Hughes 2016-10-14 18:25:06 UTC

Created attachment 1210628 [details]
reactivation key generator

Comment 2 Shannon Hughes 2016-10-14 18:25:34 UTC

Created attachment 1210629 [details]
base channel updater

Comment 4 Shannon Hughes 2016-10-14 19:49:38 UTC

Created attachment 1210659 [details]
base channel updater

Comment 5 Shannon Hughes 2016-10-14 19:50:05 UTC

Created attachment 1210660 [details]
grab reactivation key

Comment 11 Shannon Hughes 2016-10-19 17:46:07 UTC

Created attachment 1212232 [details]
oracle trace file

Comment 12 Shannon Hughes 2016-10-19 17:55:07 UTC

attached the oracle trace file but looks like the table issue is rhnRegToken, 

----- Information for the OTHER waiting sessions -----
Session 172:
  sid: 172 ser: 23793 audsid: 211720 user: 87/SHUGHESDBA
    flags: (0x45) USR/- flags_idl: (0x1) BSY/-/-/-/-/-
    flags2: (0x40008) -/-
  pid: 45 O/S info: user: oracle, term: UNKNOWN, ospid: 22295

  client details:
    O/S info: user: tomcat, term: , ospid: 3101


  current SQL:
  delete from rhnRegToken where id=:1

----- End of information for the OTHER waiting sessions -----

Information for THIS session:

----- Current SQL Statement for this session (sql_id=8n5sg3ka24t05) -----
delete from rhnRegToken where id=:1

Comment 20 Grant Gainey 2016-11-30 20:38:55 UTC

spacewalk.github:
d11976e6ad0f2a6206fc8667fbf6e40d9d578701

Comment 23 Radovan Drazny 2017-02-15 08:52:00 UTC

Reproduced on spacewalk-java-2.0.2-112 and satellite-schema-5.6.0.31-1 using the provided reproducer scripts. Used four concurrent clients, with following output in catalina.out log after 20 minutes run:

2017-02-13 10:09:38,940 [TP-Processor1] WARN  org.hibernate.util.JDBCExceptionReporter - SQL Error: 60, SQLState: 61000
2017-02-13 10:09:38,962 [TP-Processor1] ERROR org.hibernate.util.JDBCExceptionReporter - ORA-00060: deadlock detected while waiting for resource

2017-02-13 10:09:38,962 [TP-Processor1] ERROR org.hibernate.event.def.AbstractFlushingEventListener - Could not synchronize database state with session
org.hibernate.exception.LockAcquisitionException: could not delete: [com.redhat.rhn.domain.token.Token#468]
	at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:110)
	at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:66)
	at org.hibernate.persister.entity.AbstractEntityPersister.delete(AbstractEntityPersister.java:2559)
	at org.hibernate.persister.entity.AbstractEntityPersister.delete(AbstractEntityPersister.java:2715)
	at org.hibernate.action.EntityDeleteAction.execute(EntityDeleteAction.java:96)
	at org.hibernate.engine.ActionQueue.execute(ActionQueue.java:278)
	at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:262)
	at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:171)
	at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:321)
	at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:50)
	at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1030)
	at com.redhat.rhn.common.db.datasource.CachedStatement.stealConnection(CachedStatement.java:892)
	at com.redhat.rhn.common.db.datasource.CachedStatement.execute(CachedStatement.java:454)
	at com.redhat.rhn.common.db.datasource.CachedStatement.execute(CachedStatement.java:443)
	at com.redhat.rhn.common.db.datasource.CachedStatement.execute(CachedStatement.java:345)
	at com.redhat.rhn.common.db.datasource.CachedStatement.execute(CachedStatement.java:351)
	at com.redhat.rhn.common.db.datasource.CachedStatement.execute(CachedStatement.java:287)
	at com.redhat.rhn.common.db.datasource.SelectMode.execute(SelectMode.java:110)
	at com.redhat.rhn.manager.system.SystemManager.isAvailableToUser(SystemManager.java:2168)
	at com.redhat.rhn.manager.system.SystemManager.ensureAvailableToUser(SystemManager.java:2177)
	at com.redhat.rhn.manager.system.SystemManager.lookupByIdAndUser(SystemManager.java:1095)
	at com.redhat.rhn.manager.token.ActivationKeyManager.createNewReActivationKey(ActivationKeyManager.java:157)
	at com.redhat.rhn.manager.token.ActivationKeyManager.createNewReActivationKey(ActivationKeyManager.java:137)
	at com.redhat.rhn.frontend.xmlrpc.system.SystemHandler.getReactivationKey(SystemHandler.java:220)
	at com.redhat.rhn.frontend.xmlrpc.system.SystemHandler.obtainReactivationKey(SystemHandler.java:201)
	at sun.reflect.GeneratedMethodAccessor892.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:56)
	at java.lang.reflect.Method.invoke(Method.java:620)
	at com.redhat.rhn.frontend.xmlrpc.BaseHandler.invoke(BaseHandler.java:150)
	at redstone.xmlrpc.XmlRpcDispatcher.dispatch(XmlRpcDispatcher.java:123)
	at com.redhat.rhn.frontend.xmlrpc.RhnXmlRpcServer.execute(RhnXmlRpcServer.java:54)
	at com.redhat.rhn.frontend.xmlrpc.XmlRpcServlet.doPost(XmlRpcServlet.java:162)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:643)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:723)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
	at com.opensymphony.sitemesh.webapp.SiteMeshFilter.obtainContent(SiteMeshFilter.java:129)
	at com.opensymphony.sitemesh.webapp.SiteMeshFilter.doFilter(SiteMeshFilter.java:77)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
	at com.redhat.rhn.frontend.servlets.LocalizedEnvironmentFilter.doFilter(LocalizedEnvironmentFilter.java:67)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
	at com.redhat.rhn.frontend.servlets.EnvironmentFilter.doFilter(EnvironmentFilter.java:100)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
	at com.redhat.rhn.frontend.servlets.SessionFilter.doFilter(SessionFilter.java:57)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
	at com.redhat.rhn.frontend.servlets.SetCharacterEncodingFilter.doFilter(SetCharacterEncodingFilter.java:97)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233)
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:299)
	at org.apache.jk.server.JkCoyoteHandler.invoke(JkCoyoteHandler.java:190)
	at org.apache.jk.common.HandlerRequest.invoke(HandlerRequest.java:291)
	at org.apache.jk.common.ChannelSocket.invoke(ChannelSocket.java:769)
	at org.apache.jk.common.ChannelSocket.processConnection(ChannelSocket.java:698)
	at org.apache.jk.common.ChannelSocket$SocketConnection.runIt(ChannelSocket.java:891)
	at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:690)
	at java.lang.Thread.run(Thread.java:809)
Caused by: 
java.sql.SQLException: ORA-00060: deadlock detected while waiting for resource

	at oracle.jdbc.driver.DatabaseError.throwSqlException(DatabaseError.java:112)
	at oracle.jdbc.driver.T2CConnection.checkError(T2CConnection.java:676)
	at oracle.jdbc.driver.T2CConnection.checkError(T2CConnection.java:602)
	at oracle.jdbc.driver.T2CPreparedStatement.executeForDescribe(T2CPreparedStatement.java:571)
	at oracle.jdbc.driver.T2CPreparedStatement.executeForRows(T2CPreparedStatement.java:764)
	at oracle.jdbc.driver.OracleStatement.doExecuteWithTimeout(OracleStatement.java:1190)
	at oracle.jdbc.driver.OraclePreparedStatement.executeInternal(OraclePreparedStatement.java:3370)
	at oracle.jdbc.driver.OraclePreparedStatement.executeUpdate(OraclePreparedStatement.java:3454)
	at com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.executeUpdate(NewProxyPreparedStatement.java:79)
	at org.hibernate.jdbc.NonBatchingBatcher.addToBatch(NonBatchingBatcher.java:46)
	at org.hibernate.persister.entity.AbstractEntityPersister.delete(AbstractEntityPersister.java:2538)
	... 62 more
2017-02-13 10:09:38,963 [TP-Processor1] ERROR com.redhat.rhn.frontend.xmlrpc.BaseHandler - Error calling method: 
java.lang.reflect.InvocationTargetException
	at sun.reflect.GeneratedMethodAccessor892.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:56)
	at java.lang.reflect.Method.invoke(Method.java:620)
	at com.redhat.rhn.frontend.xmlrpc.BaseHandler.invoke(BaseHandler.java:150)
	at redstone.xmlrpc.XmlRpcDispatcher.dispatch(XmlRpcDispatcher.java:123)
	at com.redhat.rhn.frontend.xmlrpc.RhnXmlRpcServer.execute(RhnXmlRpcServer.java:54)
	at com.redhat.rhn.frontend.xmlrpc.XmlRpcServlet.doPost(XmlRpcServlet.java:162)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:643)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:723)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
	at com.opensymphony.sitemesh.webapp.SiteMeshFilter.obtainContent(SiteMeshFilter.java:129)
	at com.opensymphony.sitemesh.webapp.SiteMeshFilter.doFilter(SiteMeshFilter.java:77)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
	at com.redhat.rhn.frontend.servlets.LocalizedEnvironmentFilter.doFilter(LocalizedEnvironmentFilter.java:67)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
	at com.redhat.rhn.frontend.servlets.EnvironmentFilter.doFilter(EnvironmentFilter.java:100)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
	at com.redhat.rhn.frontend.servlets.SessionFilter.doFilter(SessionFilter.java:57)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
	at com.redhat.rhn.frontend.servlets.SetCharacterEncodingFilter.doFilter(SetCharacterEncodingFilter.java:97)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233)
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:299)
	at org.apache.jk.server.JkCoyoteHandler.invoke(JkCoyoteHandler.java:190)
	at org.apache.jk.common.HandlerRequest.invoke(HandlerRequest.java:291)
	at org.apache.jk.common.ChannelSocket.invoke(ChannelSocket.java:769)
	at org.apache.jk.common.ChannelSocket.processConnection(ChannelSocket.java:698)
	at org.apache.jk.common.ChannelSocket$SocketConnection.runIt(ChannelSocket.java:891)
	at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:690)
	at java.lang.Thread.run(Thread.java:809)
Caused by: 
com.redhat.rhn.common.hibernate.HibernateRuntimeException: HibernateException executing CachedStatement
	at com.redhat.rhn.common.db.datasource.CachedStatement.execute(CachedStatement.java:482)
	at com.redhat.rhn.common.db.datasource.CachedStatement.execute(CachedStatement.java:443)
	at com.redhat.rhn.common.db.datasource.CachedStatement.execute(CachedStatement.java:345)
	at com.redhat.rhn.common.db.datasource.CachedStatement.execute(CachedStatement.java:351)
	at com.redhat.rhn.common.db.datasource.CachedStatement.execute(CachedStatement.java:287)
	at com.redhat.rhn.common.db.datasource.SelectMode.execute(SelectMode.java:110)
	at com.redhat.rhn.manager.system.SystemManager.isAvailableToUser(SystemManager.java:2168)
	at com.redhat.rhn.manager.system.SystemManager.ensureAvailableToUser(SystemManager.java:2177)
	at com.redhat.rhn.manager.system.SystemManager.lookupByIdAndUser(SystemManager.java:1095)
	at com.redhat.rhn.manager.token.ActivationKeyManager.createNewReActivationKey(ActivationKeyManager.java:157)
	at com.redhat.rhn.manager.token.ActivationKeyManager.createNewReActivationKey(ActivationKeyManager.java:137)
	at com.redhat.rhn.frontend.xmlrpc.system.SystemHandler.getReactivationKey(SystemHandler.java:220)
	at com.redhat.rhn.frontend.xmlrpc.system.SystemHandler.obtainReactivationKey(SystemHandler.java:201)
	... 40 more
Caused by: 
org.hibernate.exception.LockAcquisitionException: could not delete: [com.redhat.rhn.domain.token.Token#468]
	at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:110)
	at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:66)
	at org.hibernate.persister.entity.AbstractEntityPersister.delete(AbstractEntityPersister.java:2559)
	at org.hibernate.persister.entity.AbstractEntityPersister.delete(AbstractEntityPersister.java:2715)
	at org.hibernate.action.EntityDeleteAction.execute(EntityDeleteAction.java:96)
	at org.hibernate.engine.ActionQueue.execute(ActionQueue.java:278)
	at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:262)
	at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:171)
	at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:321)
	at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:50)
	at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1030)
	at com.redhat.rhn.common.db.datasource.CachedStatement.stealConnection(CachedStatement.java:892)
	at com.redhat.rhn.common.db.datasource.CachedStatement.execute(CachedStatement.java:454)
	... 52 more
Caused by: 
java.sql.SQLException: ORA-00060: deadlock detected while waiting for resource

	at oracle.jdbc.driver.DatabaseError.throwSqlException(DatabaseError.java:112)
	at oracle.jdbc.driver.T2CConnection.checkError(T2CConnection.java:676)
	at oracle.jdbc.driver.T2CConnection.checkError(T2CConnection.java:602)
	at oracle.jdbc.driver.T2CPreparedStatement.executeForDescribe(T2CPreparedStatement.java:571)
	at oracle.jdbc.driver.T2CPreparedStatement.executeForRows(T2CPreparedStatement.java:764)
	at oracle.jdbc.driver.OracleStatement.doExecuteWithTimeout(OracleStatement.java:1190)
	at oracle.jdbc.driver.OraclePreparedStatement.executeInternal(OraclePreparedStatement.java:3370)
	at oracle.jdbc.driver.OraclePreparedStatement.executeUpdate(OraclePreparedStatement.java:3454)
	at com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.executeUpdate(NewProxyPreparedStatement.java:79)
	at org.hibernate.jdbc.NonBatchingBatcher.addToBatch(NonBatchingBatcher.java:46)
	at org.hibernate.persister.entity.AbstractEntityPersister.delete(AbstractEntityPersister.java:2538)
	... 62 more
2017-02-13 10:09:38,963 [TP-Processor1] ERROR com.redhat.rhn.frontend.xmlrpc.BaseHandler - Caused by: 
com.redhat.rhn.common.hibernate.HibernateRuntimeException: HibernateException executing CachedStatement
	at com.redhat.rhn.common.db.datasource.CachedStatement.execute(CachedStatement.java:482)
	at com.redhat.rhn.common.db.datasource.CachedStatement.execute(CachedStatement.java:443)
	at com.redhat.rhn.common.db.datasource.CachedStatement.execute(CachedStatement.java:345)
	at com.redhat.rhn.common.db.datasource.CachedStatement.execute(CachedStatement.java:351)
	at com.redhat.rhn.common.db.datasource.CachedStatement.execute(CachedStatement.java:287)
	at com.redhat.rhn.common.db.datasource.SelectMode.execute(SelectMode.java:110)
	at com.redhat.rhn.manager.system.SystemManager.isAvailableToUser(SystemManager.java:2168)
	at com.redhat.rhn.manager.system.SystemManager.ensureAvailableToUser(SystemManager.java:2177)
	at com.redhat.rhn.manager.system.SystemManager.lookupByIdAndUser(SystemManager.java:1095)
	at com.redhat.rhn.manager.token.ActivationKeyManager.createNewReActivationKey(ActivationKeyManager.java:157)
	at com.redhat.rhn.manager.token.ActivationKeyManager.createNewReActivationKey(ActivationKeyManager.java:137)
	at com.redhat.rhn.frontend.xmlrpc.system.SystemHandler.getReactivationKey(SystemHandler.java:220)
	at com.redhat.rhn.frontend.xmlrpc.system.SystemHandler.obtainReactivationKey(SystemHandler.java:201)
	at sun.reflect.GeneratedMethodAccessor892.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:56)
	at java.lang.reflect.Method.invoke(Method.java:620)
	at com.redhat.rhn.frontend.xmlrpc.BaseHandler.invoke(BaseHandler.java:150)
	at redstone.xmlrpc.XmlRpcDispatcher.dispatch(XmlRpcDispatcher.java:123)
	at com.redhat.rhn.frontend.xmlrpc.RhnXmlRpcServer.execute(RhnXmlRpcServer.java:54)
	at com.redhat.rhn.frontend.xmlrpc.XmlRpcServlet.doPost(XmlRpcServlet.java:162)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:643)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:723)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
	at com.opensymphony.sitemesh.webapp.SiteMeshFilter.obtainContent(SiteMeshFilter.java:129)
	at com.opensymphony.sitemesh.webapp.SiteMeshFilter.doFilter(SiteMeshFilter.java:77)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
	at com.redhat.rhn.frontend.servlets.LocalizedEnvironmentFilter.doFilter(LocalizedEnvironmentFilter.java:67)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
	at com.redhat.rhn.frontend.servlets.EnvironmentFilter.doFilter(EnvironmentFilter.java:100)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
	at com.redhat.rhn.frontend.servlets.SessionFilter.doFilter(SessionFilter.java:57)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
	at com.redhat.rhn.frontend.servlets.SetCharacterEncodingFilter.doFilter(SetCharacterEncodingFilter.java:97)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233)
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:299)
	at org.apache.jk.server.JkCoyoteHandler.invoke(JkCoyoteHandler.java:190)
	at org.apache.jk.common.HandlerRequest.invoke(HandlerRequest.java:291)
	at org.apache.jk.common.ChannelSocket.invoke(ChannelSocket.java:769)
	at org.apache.jk.common.ChannelSocket.processConnection(ChannelSocket.java:698)
	at org.apache.jk.common.ChannelSocket$SocketConnection.runIt(ChannelSocket.java:891)
	at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:690)
	at java.lang.Thread.run(Thread.java:809)
Caused by: 
org.hibernate.exception.LockAcquisitionException: could not delete: [com.redhat.rhn.domain.token.Token#468]
	at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:110)
	at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:66)
	at org.hibernate.persister.entity.AbstractEntityPersister.delete(AbstractEntityPersister.java:2559)
	at org.hibernate.persister.entity.AbstractEntityPersister.delete(AbstractEntityPersister.java:2715)
	at org.hibernate.action.EntityDeleteAction.execute(EntityDeleteAction.java:96)
	at org.hibernate.engine.ActionQueue.execute(ActionQueue.java:278)
	at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:262)
	at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:171)
	at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:321)
	at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:50)
	at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1030)
	at com.redhat.rhn.common.db.datasource.CachedStatement.stealConnection(CachedStatement.java:892)
	at com.redhat.rhn.common.db.datasource.CachedStatement.execute(CachedStatement.java:454)
	... 52 more
Caused by: 
java.sql.SQLException: ORA-00060: deadlock detected while waiting for resource

	at oracle.jdbc.driver.DatabaseError.throwSqlException(DatabaseError.java:112)
	at oracle.jdbc.driver.T2CConnection.checkError(T2CConnection.java:676)
	at oracle.jdbc.driver.T2CConnection.checkError(T2CConnection.java:602)
	at oracle.jdbc.driver.T2CPreparedStatement.executeForDescribe(T2CPreparedStatement.java:571)
	at oracle.jdbc.driver.T2CPreparedStatement.executeForRows(T2CPreparedStatement.java:764)
	at oracle.jdbc.driver.OracleStatement.doExecuteWithTimeout(OracleStatement.java:1190)
	at oracle.jdbc.driver.OraclePreparedStatement.executeInternal(OraclePreparedStatement.java:3370)
	at oracle.jdbc.driver.OraclePreparedStatement.executeUpdate(OraclePreparedStatement.java:3454)
	at com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.executeUpdate(NewProxyPreparedStatement.java:79)
	at org.hibernate.jdbc.NonBatchingBatcher.addToBatch(NonBatchingBatcher.java:46)
	at org.hibernate.persister.entity.AbstractEntityPersister.delete(AbstractEntityPersister.java:2538)
	... 62 more
Feb 13, 2017 10:09:38 AM redstone.xmlrpc.XmlRpcDispatcher writeError
WARNING: redstone.xmlrpc.XmlRpcFault: unhandled internal exception: HibernateException executing CachedStatement
2017-02-13 10:09:38,965 [TP-Processor1] ERROR org.hibernate.event.def.AbstractFlushingEventListener - Could not synchronize database state with session
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:85)
	at org.hibernate.jdbc.Expectations$BasicExpectation.verifyOutcome(Expectations.java:70)
	at org.hibernate.jdbc.NonBatchingBatcher.addToBatch(NonBatchingBatcher.java:47)
	at org.hibernate.persister.entity.AbstractEntityPersister.delete(AbstractEntityPersister.java:2538)
	at org.hibernate.persister.entity.AbstractEntityPersister.delete(AbstractEntityPersister.java:2715)
	at org.hibernate.action.EntityDeleteAction.execute(EntityDeleteAction.java:96)
	at org.hibernate.engine.ActionQueue.execute(ActionQueue.java:278)
	at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:262)
	at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:171)
	at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:321)
	at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:50)
	at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1030)
	at org.hibernate.impl.SessionImpl.managedFlush(SessionImpl.java:367)
	at org.hibernate.transaction.JDBCTransaction.commit(JDBCTransaction.java:137)
	at com.redhat.rhn.common.hibernate.ConnectionManager.commitTransaction(ConnectionManager.java:253)
	at com.redhat.rhn.common.hibernate.HibernateFactory.commitTransaction(HibernateFactory.java:331)
	at com.redhat.rhn.frontend.servlets.SessionFilter.doFilter(SessionFilter.java:58)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
	at com.redhat.rhn.frontend.servlets.SetCharacterEncodingFilter.doFilter(SetCharacterEncodingFilter.java:97)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233)
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:299)
	at org.apache.jk.server.JkCoyoteHandler.invoke(JkCoyoteHandler.java:190)
	at org.apache.jk.common.HandlerRequest.invoke(HandlerRequest.java:291)
	at org.apache.jk.common.ChannelSocket.invoke(ChannelSocket.java:769)
	at org.apache.jk.common.ChannelSocket.processConnection(ChannelSocket.java:698)
	at org.apache.jk.common.ChannelSocket$SocketConnection.runIt(ChannelSocket.java:891)
	at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:690)
	at java.lang.Thread.run(Thread.java:809)
2017-02-13 10:09:38,965 [TP-Processor1] ERROR com.redhat.rhn.frontend.servlets.SessionFilter - Error during transaction. Rolling back
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:85)
	at org.hibernate.jdbc.Expectations$BasicExpectation.verifyOutcome(Expectations.java:70)
	at org.hibernate.jdbc.NonBatchingBatcher.addToBatch(NonBatchingBatcher.java:47)
	at org.hibernate.persister.entity.AbstractEntityPersister.delete(AbstractEntityPersister.java:2538)
	at org.hibernate.persister.entity.AbstractEntityPersister.delete(AbstractEntityPersister.java:2715)
	at org.hibernate.action.EntityDeleteAction.execute(EntityDeleteAction.java:96)
	at org.hibernate.engine.ActionQueue.execute(ActionQueue.java:278)
	at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:262)
	at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:171)
	at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:321)
	at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:50)
	at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1030)
	at org.hibernate.impl.SessionImpl.managedFlush(SessionImpl.java:367)
	at org.hibernate.transaction.JDBCTransaction.commit(JDBCTransaction.java:137)
	at com.redhat.rhn.common.hibernate.ConnectionManager.commitTransaction(ConnectionManager.java:253)
	at com.redhat.rhn.common.hibernate.HibernateFactory.commitTransaction(HibernateFactory.java:331)
	at com.redhat.rhn.frontend.servlets.SessionFilter.doFilter(SessionFilter.java:58)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
	at com.redhat.rhn.frontend.servlets.SetCharacterEncodingFilter.doFilter(SetCharacterEncodingFilter.java:97)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233)
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:299)
	at org.apache.jk.server.JkCoyoteHandler.invoke(JkCoyoteHandler.java:190)
	at org.apache.jk.common.HandlerRequest.invoke(HandlerRequest.java:291)
	at org.apache.jk.common.ChannelSocket.invoke(ChannelSocket.java:769)
	at org.apache.jk.common.ChannelSocket.processConnection(ChannelSocket.java:698)
	at org.apache.jk.common.ChannelSocket$SocketConnection.runIt(ChannelSocket.java:891)
	at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:690)
	at java.lang.Thread.run(Thread.java:809)


After updating to satellite-schema-5.6.0.34-1 and spacewalk-java-2.0.2-114, there were no deadlocks and output in the catalina.out even after 12 hours run on four concurrent clients.

VERIFIED

Comment 25 errata-xmlrpc 2017-02-22 13:38:12 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://rhn.redhat.com/errata/RHBA-2017-0292.html

Note You need to log in before you can comment on or make changes to this bug.