Bug 1385099
| Summary: | Satellite 5.6: Deadlock with system.obtainReactivationKey API call | ||||||||||||||||
|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|
| Product: | Red Hat Satellite 5 | Reporter: | Shannon Hughes <shughes> | ||||||||||||||
| Component: | API | Assignee: | Grant Gainey <ggainey> | ||||||||||||||
| Status: | CLOSED ERRATA | QA Contact: | Radovan Drazny <rdrazny> | ||||||||||||||
| Severity: | high | Docs Contact: | |||||||||||||||
| Priority: | high | ||||||||||||||||
| Version: | 560 | CC: | agadhave, chrobert, dyordano, ggainey, jdostal, rdrazny, rmarti, tlestach, tpapaioa, wpinheir, xdmoon | ||||||||||||||
| Target Milestone: | --- | ||||||||||||||||
| Target Release: | --- | ||||||||||||||||
| Hardware: | Unspecified | ||||||||||||||||
| OS: | Unspecified | ||||||||||||||||
| Whiteboard: | |||||||||||||||||
| Fixed In Version: | spacewalk-java-2.0.2-114-sat | Doc Type: | If docs needed, set a value | ||||||||||||||
| Doc Text: | Story Points: | --- | |||||||||||||||
| Clone Of: | |||||||||||||||||
| : | 1388160 1400108 (view as bug list) | Environment: | |||||||||||||||
| Last Closed: | 2017-02-22 13:38:12 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: | |||||||||||||||||
| Bug Blocks: | 1368978, 1388160, 1400108 | ||||||||||||||||
| Attachments: |
|
||||||||||||||||
Created attachment 1210628 [details]
reactivation key generator
Created attachment 1210629 [details]
base channel updater
Created attachment 1210659 [details]
base channel updater
Created attachment 1210660 [details]
grab reactivation key
Created attachment 1212232 [details]
oracle trace file
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
spacewalk.github: d11976e6ad0f2a6206fc8667fbf6e40d9d578701 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 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 |
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.