Description of problem: During satellite-sync the Database is reporting deadlocks which aborts the sync How reproducible: Always on customer system Steps to Reproduce: 1. run satellite-sync 2. 3. Actual results: Error: deadlock detected while waiting for resource... Sync aborts Expected results: For sync to complete. Additional info:
Created attachment 1329159 [details] Driver for client calling setBaseChannel between 6base and clone Reproduced. Steps: 1) Up-to-date Sat5.7, ORA db 2) rhel-x86_64-server-6 and rhn-tools-rhel-x86_64-server-6 sync'd into satellite 3) the above cloned as labels clone-rhel-x86_64-server-6 and clone-rhn-tools-rhel-x86_64-server-6 4) 'Many' (in this instance 1228) RHEL6 systems registered and subscribed to rhn-tools-rhel-x86_64-server-6 5) 4 clients running attached setbase_label.pl: # setbase_label.pl 4 0 # setbase_label.pl 4 1 # setbase_label.pl 4 2 # setbase_label.pl 4 3 6) # satellite-sync Result at sat-sync terminal was a deadlock that killed the sat-sync: === [root@<sat-name> ~]# satellite-sync 14:48:13 Red Hat Satellite - live synchronization 14:48:13 url: https://satellite.rhn.redhat.com 14:48:13 debug/output level: 1 14:48:13 db: spaceuser/<password>@//127.0.0.1:1521/xrhnsatx.world 14:48:13 14:48:13 Retrieving / parsing channel-families data 14:48:16 channel-families data complete 14:48:16 14:48:16 Retrieving / parsing product names data 14:48:17 product names data complete +++ sending log as an email +++ SYNC ERROR: unhandled exception occurred: (Check logs/email for potentially more detail) <rhnFault class (code = 23, text = 'ORA-00060: deadlock detected while waiting for resource ORA-06512: at "SPACEUSER.RHN_CHANNEL", line 674 ORA-06512: at "SPACEUSER.RHN_ENTITLEMENTS", line 1586 ORA-06512: at "SPACEUSER.RHN_ENTITLEMENTS", line 1621 ORA-06512: at "SPACEUSER.RHN_ENTITLEMENTS", line 1514 ORA-06512: at line 1 : org_id [1] family [rhn-tools-rhel-server-6] max [1]')> (23, 'ORA-00060: deadlock detected while waiting for resource\nORA-06512: at "SPACEUSER.RHN_CHANNEL", line 674\nORA-06512: at "SPACEUSER.RHN_ENTITLEMENTS", line 1586\nORA-06512: at "SPACEUSER.RHN_ENTITLEMENTS", line 1621\nORA-06512: at "SPACEUSER.RHN_ENTITLEMENTS", line 1514\nORA-06512: at line 1\n: org_id [1] family [rhn-tools-rhel-server-6] max [1]', 'Could not update database entry.') [root@<sat-name> ~]# === On a different run, the deadlock manifested in a way that killed the *clients*: === id 1000010514 Fault returned from XML RPC Server, fault code -1: redstone.xmlrpc.XmlRpcFault: unhandled internal exception: ORA-00060: deadlock detected while waiting for resource ORA-06512: at "SPACEUSER.LOCK_COUNTS", line 16 ORA-06512: at "SPACEUSER.RHN_CHANNEL", line 448 ORA-06512: at line 1 [root@host-8-176-15 deadlock_recreate]# === While the symptoms are different, it's just that Oracle decided to kill the 'other side' of the deadlock, the root casue is the same. What's happening here is sat-sync is updating channel-family metadata, while the setbase_label calls are forcing systems to be constantly switching between a cloned base-channel and the original. This updates curr_members in the same entities that sat-sync is attempting to update. This would also collide on the registration and profile-deletion paths, if the profiles in question are assigned to Red Hat channels. Next steps: code-inspection of the sat-sync code paths to determine the best place to add a gatekeeper, to insure that sat-sync is acquiring and releasing locks on the same order as the subscribe/unsubscribe path already is.
Update: root cause is that: * sat-sync validates the activated sat-cert * this validation includes test-updates to servergroup and channelfamily tables * sat-sync interrogates/affects these tables in exactly the reverse order of the lock_counts call that is protecting server-create/subscribe/unsubscribe/delete This is exactly the lock-ordering problem that leads to deadly-embrace/deadlocks. Can be recreated under postgresql with a slightly-different symptom but the same root cause. Next steps: implement and test code changes to enforce the same lock ordering everywhere.
Tested using the reproducer from the comment #4. I wasn't able to reproduce the issue on Oracle. PostgreSQL deadlocked nearly instantly after running the "cdn-sync -c rhn-tools-rhel-x86_64-server-6" while 4 clients were running "./setbase_label.pl 4 X". The deadlock always manifested on the client, never in the cdn-sync run. /var/log/tomcat6/catalina.out: 2017-11-29 10:47:16,469 [TP-Processor2] ERROR com.redhat.rhn.frontend.xmlrpc.BaseHandler - Error calling method: java.lang.reflect.InvocationTargetException at sun.reflect.GeneratedMethodAccessor765.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:55) at java.lang.reflect.Method.invoke(Method.java:508) at com.redhat.rhn.frontend.xmlrpc.BaseHandler.invoke(BaseHandler.java:174) 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:101) 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:785) Caused by: com.redhat.rhn.common.db.WrappedSQLException: ERROR: deadlock detected Detail: Process 15380 waits for ShareLock on transaction 182747; blocked by process 15441. Process 15441 waits for ShareLock on transaction 182748; blocked by process 15380. Hint: See server log for query details. Where: while locking tuple (0,3) in relation "rhnservergroup" SQL statement "select sg.created from rhnservergroup sg inner join rhnserver s on s.org_id = sg.org_id where s.id = server_id_in for update" PL/pgSQL function lock_counts(numeric) line 16 at SQL statement SQL statement "SELECT lock_counts(server_id_in)" PL/pgSQL function rhn_channel.unsubscribe_server(numeric,numeric,numeric,numeric,numeric,numeric) line 19 at PERFORM at com.redhat.rhn.common.translation.SqlExceptionTranslator.postgreSqlException(SqlExceptionTranslator.java:54) at com.redhat.rhn.common.translation.SqlExceptionTranslator.sqlException(SqlExceptionTranslator.java:44) at com.redhat.rhn.common.db.datasource.CachedStatement.executeCallable(CachedStatement.java:487) at com.redhat.rhn.common.db.datasource.CallableMode.execute(CallableMode.java:39) at com.redhat.rhn.manager.system.SystemManager.unsubscribeServerFromChannel(SystemManager.java:1557) at com.redhat.rhn.manager.system.SystemManager.unsubscribeServerFromChannel(SystemManager.java:1531) at com.redhat.rhn.manager.system.SystemManager.unsubscribeServerFromChannel(SystemManager.java:1488) at com.redhat.rhn.manager.system.SystemManager.unsubscribeServerFromChannel(SystemManager.java:1449) at com.redhat.rhn.manager.system.UpdateBaseChannelCommand.store(UpdateBaseChannelCommand.java:106) at com.redhat.rhn.frontend.xmlrpc.system.SystemHandler.setBaseChannel(SystemHandler.java:472) ... 40 more Caused by: org.postgresql.util.PSQLException: ERROR: deadlock detected Detail: Process 15380 waits for ShareLock on transaction 182747; blocked by process 15441. Process 15441 waits for ShareLock on transaction 182748; blocked by process 15380. Hint: See server log for query details. Where: while locking tuple (0,3) in relation "rhnservergroup" SQL statement "select sg.created from rhnservergroup sg inner join rhnserver s on s.org_id = sg.org_id where s.id = server_id_in for update" PL/pgSQL function lock_counts(numeric) line 16 at SQL statement SQL statement "SELECT lock_counts(server_id_in)" PL/pgSQL function rhn_channel.unsubscribe_server(numeric,numeric,numeric,numeric,numeric,numeric) line 19 at PERFORM at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2094) at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:1827) at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:255) at org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.java:508) at org.postgresql.jdbc2.AbstractJdbc2Statement.executeWithFlags(AbstractJdbc2Statement.java:384) at org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.java:377) at com.mchange.v2.c3p0.impl.NewProxyCallableStatement.execute(NewProxyCallableStatement.java:2706) at com.redhat.rhn.common.db.NamedPreparedStatement.execute(NamedPreparedStatement.java:117) at com.redhat.rhn.common.db.datasource.CachedStatement.executeCallable(CachedStatement.java:474) ... 47 more 2017-11-29 10:47:16,473 [TP-Processor2] ERROR com.redhat.rhn.frontend.xmlrpc.BaseHandler - Caused by: com.redhat.rhn.common.db.WrappedSQLException: ERROR: deadlock detected Detail: Process 15380 waits for ShareLock on transaction 182747; blocked by process 15441. Process 15441 waits for ShareLock on transaction 182748; blocked by process 15380. Hint: See server log for query details. Where: while locking tuple (0,3) in relation "rhnservergroup" SQL statement "select sg.created from rhnservergroup sg inner join rhnserver s on s.org_id = sg.org_id where s.id = server_id_in for update" PL/pgSQL function lock_counts(numeric) line 16 at SQL statement SQL statement "SELECT lock_counts(server_id_in)" PL/pgSQL function rhn_channel.unsubscribe_server(numeric,numeric,numeric,numeric,numeric,numeric) line 19 at PERFORM at com.redhat.rhn.common.translation.SqlExceptionTranslator.postgreSqlException(SqlExceptionTranslator.java:54) at com.redhat.rhn.common.translation.SqlExceptionTranslator.sqlException(SqlExceptionTranslator.java:44) at com.redhat.rhn.common.db.datasource.CachedStatement.executeCallable(CachedStatement.java:487) at com.redhat.rhn.common.db.datasource.CallableMode.execute(CallableMode.java:39) at com.redhat.rhn.manager.system.SystemManager.unsubscribeServerFromChannel(SystemManager.java:1557) at com.redhat.rhn.manager.system.SystemManager.unsubscribeServerFromChannel(SystemManager.java:1531) at com.redhat.rhn.manager.system.SystemManager.unsubscribeServerFromChannel(SystemManager.java:1488) at com.redhat.rhn.manager.system.SystemManager.unsubscribeServerFromChannel(SystemManager.java:1449) at com.redhat.rhn.manager.system.UpdateBaseChannelCommand.store(UpdateBaseChannelCommand.java:106) at com.redhat.rhn.frontend.xmlrpc.system.SystemHandler.setBaseChannel(SystemHandler.java:472) at sun.reflect.GeneratedMethodAccessor765.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:55) at java.lang.reflect.Method.invoke(Method.java:508) at com.redhat.rhn.frontend.xmlrpc.BaseHandler.invoke(BaseHandler.java:174) 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:101) 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:785) Caused by: org.postgresql.util.PSQLException: ERROR: deadlock detected Detail: Process 15380 waits for ShareLock on transaction 182747; blocked by process 15441. Process 15441 waits for ShareLock on transaction 182748; blocked by process 15380. Hint: See server log for query details. Where: while locking tuple (0,3) in relation "rhnservergroup" SQL statement "select sg.created from rhnservergroup sg inner join rhnserver s on s.org_id = sg.org_id where s.id = server_id_in for update" PL/pgSQL function lock_counts(numeric) line 16 at SQL statement SQL statement "SELECT lock_counts(server_id_in)" PL/pgSQL function rhn_channel.unsubscribe_server(numeric,numeric,numeric,numeric,numeric,numeric) line 19 at PERFORM at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2094) at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:1827) at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:255) at org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.java:508) at org.postgresql.jdbc2.AbstractJdbc2Statement.executeWithFlags(AbstractJdbc2Statement.java:384) at org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.java:377) at com.mchange.v2.c3p0.impl.NewProxyCallableStatement.execute(NewProxyCallableStatement.java:2706) at com.redhat.rhn.common.db.NamedPreparedStatement.execute(NamedPreparedStatement.java:117) at com.redhat.rhn.common.db.datasource.CachedStatement.executeCallable(CachedStatement.java:474) ... 47 more 2017-11-29 10:47:16,475 [TP-Processor2] ERROR com.redhat.rhn.frontend.xmlrpc.BaseHandler - Rolling back transaction Nov 29, 2017 10:47:16 AM redstone.xmlrpc.XmlRpcDispatcher writeError WARNING: redstone.xmlrpc.XmlRpcFault: unhandled internal exception: ERROR: deadlock detected Detail: Process 15380 waits for ShareLock on transaction 182747; blocked by process 15441. Process 15441 waits for ShareLock on transaction 182748; blocked by process 15380. Hint: See server log for query details. Where: while locking tuple (0,3) in relation "rhnservergroup" SQL statement "select sg.created from rhnservergroup sg inner join rhnserver s on s.org_id = sg.org_id where s.id = server_id_in for update" PL/pgSQL function lock_counts(numeric) line 16 at SQL statement SQL statement "SELECT lock_counts(server_id_in)" PL/pgSQL function rhn_channel.unsubscribe_server(numeric,numeric,numeric,numeric,numeric,numeric) line 19 at PERFORM 2017-11-29 10:47:17,531 [TP-Processor16] ERROR com.redhat.rhn.frontend.xmlrpc.BaseHandler - Error calling method: java.lang.reflect.InvocationTargetException at sun.reflect.GeneratedMethodAccessor765.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:55) at java.lang.reflect.Method.invoke(Method.java:508) at com.redhat.rhn.frontend.xmlrpc.BaseHandler.invoke(BaseHandler.java:174) 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:101) 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:785) Caused by: com.redhat.rhn.common.db.WrappedSQLException: ERROR: deadlock detected Detail: Process 15440 waits for ShareLock on transaction 182746; blocked by process 15404. Process 15404 waits for ShareLock on transaction 182749; blocked by process 15440. Hint: See server log for query details. Where: while locking tuple (0,3) in relation "rhnservergroup" SQL statement "select sg.created from rhnservergroup sg inner join rhnserver s on s.org_id = sg.org_id where s.id = server_id_in for update" PL/pgSQL function lock_counts(numeric) line 16 at SQL statement SQL statement "SELECT lock_counts(server_id_in)" PL/pgSQL function rhn_channel.unsubscribe_server(numeric,numeric,numeric,numeric,numeric,numeric) line 19 at PERFORM at com.redhat.rhn.common.translation.SqlExceptionTranslator.postgreSqlException(SqlExceptionTranslator.java:54) at com.redhat.rhn.common.translation.SqlExceptionTranslator.sqlException(SqlExceptionTranslator.java:44) at com.redhat.rhn.common.db.datasource.CachedStatement.executeCallable(CachedStatement.java:487) at com.redhat.rhn.common.db.datasource.CallableMode.execute(CallableMode.java:39) at com.redhat.rhn.manager.system.SystemManager.unsubscribeServerFromChannel(SystemManager.java:1557) at com.redhat.rhn.manager.system.SystemManager.unsubscribeServerFromChannel(SystemManager.java:1531) at com.redhat.rhn.manager.system.SystemManager.unsubscribeServerFromChannel(SystemManager.java:1488) at com.redhat.rhn.manager.system.SystemManager.unsubscribeServerFromChannel(SystemManager.java:1449) at com.redhat.rhn.manager.system.UpdateBaseChannelCommand.store(UpdateBaseChannelCommand.java:106) at com.redhat.rhn.frontend.xmlrpc.system.SystemHandler.setBaseChannel(SystemHandler.java:472) ... 40 more Caused by: org.postgresql.util.PSQLException: ERROR: deadlock detected Detail: Process 15440 waits for ShareLock on transaction 182746; blocked by process 15404. Process 15404 waits for ShareLock on transaction 182749; blocked by process 15440. Hint: See server log for query details. Where: while locking tuple (0,3) in relation "rhnservergroup" SQL statement "select sg.created from rhnservergroup sg inner join rhnserver s on s.org_id = sg.org_id where s.id = server_id_in for update" PL/pgSQL function lock_counts(numeric) line 16 at SQL statement SQL statement "SELECT lock_counts(server_id_in)" PL/pgSQL function rhn_channel.unsubscribe_server(numeric,numeric,numeric,numeric,numeric,numeric) line 19 at PERFORM at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2094) at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:1827) at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:255) at org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.java:508) at org.postgresql.jdbc2.AbstractJdbc2Statement.executeWithFlags(AbstractJdbc2Statement.java:384) at org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.java:377) at com.mchange.v2.c3p0.impl.NewProxyCallableStatement.execute(NewProxyCallableStatement.java:2706) at com.redhat.rhn.common.db.NamedPreparedStatement.execute(NamedPreparedStatement.java:117) at com.redhat.rhn.common.db.datasource.CachedStatement.executeCallable(CachedStatement.java:474) ... 47 more 2017-11-29 10:47:17,534 [TP-Processor16] ERROR com.redhat.rhn.frontend.xmlrpc.BaseHandler - Caused by: com.redhat.rhn.common.db.WrappedSQLException: ERROR: deadlock detected Detail: Process 15440 waits for ShareLock on transaction 182746; blocked by process 15404. Process 15404 waits for ShareLock on transaction 182749; blocked by process 15440. Hint: See server log for query details. Where: while locking tuple (0,3) in relation "rhnservergroup" SQL statement "select sg.created from rhnservergroup sg inner join rhnserver s on s.org_id = sg.org_id where s.id = server_id_in for update" PL/pgSQL function lock_counts(numeric) line 16 at SQL statement SQL statement "SELECT lock_counts(server_id_in)" PL/pgSQL function rhn_channel.unsubscribe_server(numeric,numeric,numeric,numeric,numeric,numeric) line 19 at PERFORM at com.redhat.rhn.common.translation.SqlExceptionTranslator.postgreSqlException(SqlExceptionTranslator.java:54) at com.redhat.rhn.common.translation.SqlExceptionTranslator.sqlException(SqlExceptionTranslator.java:44) at com.redhat.rhn.common.db.datasource.CachedStatement.executeCallable(CachedStatement.java:487) at com.redhat.rhn.common.db.datasource.CallableMode.execute(CallableMode.java:39) at com.redhat.rhn.manager.system.SystemManager.unsubscribeServerFromChannel(SystemManager.java:1557) at com.redhat.rhn.manager.system.SystemManager.unsubscribeServerFromChannel(SystemManager.java:1531) at com.redhat.rhn.manager.system.SystemManager.unsubscribeServerFromChannel(SystemManager.java:1488) at com.redhat.rhn.manager.system.SystemManager.unsubscribeServerFromChannel(SystemManager.java:1449) at com.redhat.rhn.manager.system.UpdateBaseChannelCommand.store(UpdateBaseChannelCommand.java:106) at com.redhat.rhn.frontend.xmlrpc.system.SystemHandler.setBaseChannel(SystemHandler.java:472) at sun.reflect.GeneratedMethodAccessor765.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:55) at java.lang.reflect.Method.invoke(Method.java:508) at com.redhat.rhn.frontend.xmlrpc.BaseHandler.invoke(BaseHandler.java:174) 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:101) 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:785) Caused by: org.postgresql.util.PSQLException: ERROR: deadlock detected Detail: Process 15440 waits for ShareLock on transaction 182746; blocked by process 15404. Process 15404 waits for ShareLock on transaction 182749; blocked by process 15440. Hint: See server log for query details. Where: while locking tuple (0,3) in relation "rhnservergroup" SQL statement "select sg.created from rhnservergroup sg inner join rhnserver s on s.org_id = sg.org_id where s.id = server_id_in for update" PL/pgSQL function lock_counts(numeric) line 16 at SQL statement SQL statement "SELECT lock_counts(server_id_in)" PL/pgSQL function rhn_channel.unsubscribe_server(numeric,numeric,numeric,numeric,numeric,numeric) line 19 at PERFORM at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2094) at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:1827) at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:255) at org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.java:508) at org.postgresql.jdbc2.AbstractJdbc2Statement.executeWithFlags(AbstractJdbc2Statement.java:384) at org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.java:377) at com.mchange.v2.c3p0.impl.NewProxyCallableStatement.execute(NewProxyCallableStatement.java:2706) at com.redhat.rhn.common.db.NamedPreparedStatement.execute(NamedPreparedStatement.java:117) at com.redhat.rhn.common.db.datasource.CachedStatement.executeCallable(CachedStatement.java:474) ... 47 more 2017-11-29 10:47:17,536 [TP-Processor16] ERROR com.redhat.rhn.frontend.xmlrpc.BaseHandler - Rolling back transaction Nov 29, 2017 10:47:17 AM redstone.xmlrpc.XmlRpcDispatcher writeError WARNING: redstone.xmlrpc.XmlRpcFault: unhandled internal exception: ERROR: deadlock detected Detail: Process 15440 waits for ShareLock on transaction 182746; blocked by process 15404. Process 15404 waits for ShareLock on transaction 182749; blocked by process 15440. Hint: See server log for query details. Where: while locking tuple (0,3) in relation "rhnservergroup" SQL statement "select sg.created from rhnservergroup sg inner join rhnserver s on s.org_id = sg.org_id where s.id = server_id_in for update" PL/pgSQL function lock_counts(numeric) line 16 at SQL statement SQL statement "SELECT lock_counts(server_id_in)" PL/pgSQL function rhn_channel.unsubscribe_server(numeric,numeric,numeric,numeric,numeric,numeric) line 19 at PERFORM After upgrading to spacewalk-backend-2.5.3-157 satellite-schema-5.8.0.37-1 spacewalk-schema-2.5.1-53 and running the reproducer again, there were no deadlocks. 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://access.redhat.com/errata/RHBA-2017:3445