Description of problem: Encountered while testing the fix for BZ 1452362. This deadlock is triggered only during an extremely rare user scenario (we are subscribing to a channel, while we actually delete the channel), so it's not a critical problem. Still, it can be symptom of a problem in some more probable user scenario, so let's have it documented. Version-Release number of selected component (if applicable): spacewalk-backend-2.5.3-157.el6sat.noarch spacewalk-schema-2.5.1-53.el6sat.noarch satellite-schema-5.8.0.37-1.el6sat.noarch How reproducible: always Steps to Reproduce: 1. Have a lot of systems registered to a Sat 5.8 server (1200 fake regs in my case) 2. All these systems are subscribed to rhel-x86_64-server-6 base channel and rhn-tools-rhel-x86_64-server-6 child channel 3. Have four clients running the ./setbase_label.pl 4 X reproducer script from BZ 1452362 4. Run "spacewalk-remove-channel -c rhn-tools-rhel-x86_64-server-6 --unsubscribe" on the sat server Actual results: Result in the server shell: $ spacewalk-remove-channel -c rhn-tools-rhel-x86_64-server-6 --unsubscribe The following channels will have their systems unsubscribed: rhn-tools-rhel-x86_64-server-6 1110 ________________________________________ Unsubscribing: ERROR: unhandled exception occurred: ((99999, 'ERROR: deadlock detected', 'DETAIL: Process 18222 waits for ShareLock on transaction 190922; blocked by process 18208.\nProcess 18208 waits for AccessExclusiveLock on tuple (6,26) of relation 20451 of database 16384; blocked by process 18187.\nProcess 18187 waits for ShareLock on transaction 190919; blocked by process 18222.\nHINT: See server log for query details.\nCONTEXT: while locking tuple (0,11) in relation "rhnserver"\nSQL statement "select s.created from rhnServer s\n where s.id = server_id_in\n for update"\nPL/pgSQL function lock_counts(numeric) line 6 at SQL statement\nSQL statement "SELECT lock_counts(server_id_in)"\nPL/pgSQL function rhn_channel.unsubscribe_server(numeric,numeric,numeric,numeric,numeric,numeric) line 19 at PERFORM\n', TransactionRollbackError('deadlock detected\nDETAIL: Process 18222 waits for ShareLock on transaction 190922; blocked by process 18208.\nProcess 18208 waits for AccessExclusiveLock on tuple (6,26) of relation 20451 of database 16384; blocked by process 18187.\nProcess 18187 waits for ShareLock on transaction 190919; blocked by process 18222.\nHINT: See server log for query details.\nCONTEXT: while locking tuple (0,11) in relation "rhnserver"\nSQL statement "select s.created from rhnServer s\n where s.id = server_id_in\n for update"\nPL/pgSQL function lock_counts(numeric) line 6 at SQL statement\nSQL statement "SELECT lock_counts(server_id_in)"\nPL/pgSQL function rhn_channel.unsubscribe_server(numeric,numeric,numeric,numeric,numeric,numeric) line 19 at PERFORM\n',))). Traceback (most recent call last): File "/usr/bin/spacewalk-remove-channel", line 182, in <module> sys.exit(main() or 0) File "/usr/bin/spacewalk-remove-channel", line 154, in main if __serverCheck(channels.keys(), options.unsubscribe): File "/usr/lib/python2.6/site-packages/spacewalk/satellite_tools/ contentRemove.py", line 41, in __serverCheck return __unsubscribeServers(labels) File "/usr/lib/python2.6/site-packages/spacewalk/satellite_tools/ contentRemove.py", line 91, in __unsubscribeServers unsubscribe_server_proc(i['server_id'], i['channel_id']) File "/usr/lib/python2.6/site-packages/spacewalk/server/rhnSQL/ driver_postgresql.py", line 116, in __call__ result = Function.__call__(self, *args) File "/usr/lib/python2.6/site-packages/spacewalk/server/rhnSQL/ driver_postgresql.py", line 92, in __call__ raise sql_base.SQLSchemaError(error_code, e.pgerror, e) SQLSchemaError: (99999, 'ERROR: deadlock detected', 'DETAIL: Process 18222 waits for ShareLock on transaction 190922; blocked by process 18208.\nProcess 18208 waits for AccessExclusiveLock on tuple (6,26) of relation 20451 of database 16384; blocked by process 18187.\nProcess 18187 waits for ShareLock on transaction 190919; blocked by process 18222.\nHINT: See server log for query details.\nCONTEXT: while locking tuple (0,11) in relation "rhnserver"\nSQL statement "select s.created from rhnServer s\n where s.id = server_id_in\n for update"\nPL/pgSQL function lock_counts(numeric) line 6 at SQL statement\nSQL statement "SELECT lock_counts(server_id_in)"\nPL/pgSQL function rhn_channel.unsubscribe_server(numeric,numeric,numeric,numeric,numeric,numeric) line 19 at PERFORM\n', TransactionRollbackError('deadlock detected\nDETAIL: Process 18222 waits for ShareLock on transaction 190922; blocked by process 18208.\nProcess 18208 waits for AccessExclusiveLock on tuple (6,26) of relation 20451 of database 16384; blocked by process 18187.\nProcess 18187 waits for ShareLock on transaction 190919; blocked by process 18222.\nHINT: See server log for query details.\nCONTEXT: while locking tuple (0,11) in relation "rhnserver"\nSQL statement "select s.created from rhnServer s\n where s.id = server_id_in\n for update"\nPL/pgSQL function lock_counts(numeric) line 6 at SQL statement\nSQL statement "SELECT lock_counts(server_id_in)"\nPL/pgSQL function rhn_channel.unsubscribe_server(numeric,numeric,numeric,numeric,numeric,numeric) line 19 at PERFORM\n',)) =================================================== =================================================== Error in the /var/log/tomcat6/catalina.out: 2017-11-29 12:38:48,079 [TP-Processor8] ERROR com.redhat.rhn.frontend.xmlrpc.BaseHandler - Error calling method: java.lang.reflect.InvocationTargetException at sun.reflect.GeneratedMethodAccessor522.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 18218 waits for ShareLock on transaction 190919; blocked by process 18222. Process 18222 waits for ShareLock on transaction 190922; blocked by process 18208. Process 18208 waits for AccessExclusiveLock on tuple (6,26) of relation 20451 of database 16384; blocked by process 18218. Hint: See server log for query details. Where: while locking tuple (6,26) in relation "rhnprivatechannelfamily" SQL statement "select pcf.created from rhnPrivateChannelFamily pcf inner join rhnserver s on s.org_id = pcf.org_id where s.id = server_id_in order by channel_family_id asc for update" PL/pgSQL function lock_counts(numeric) line 11 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.UpdateChildChannelsCommand.unsubscribeFromOldChannels(UpdateChildChannelsCommand.java: 194) at com.redhat.rhn.manager.system.UpdateChildChannelsCommand.store(UpdateChildChannelsCommand.java: 107) at com.redhat.rhn.manager.system.UpdateBaseChannelCommand.store(UpdateBaseChannelCommand.java: 101) 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 18218 waits for ShareLock on transaction 190919; blocked by process 18222. Process 18222 waits for ShareLock on transaction 190922; blocked by process 18208. Process 18208 waits for AccessExclusiveLock on tuple (6,26) of relation 20451 of database 16384; blocked by process 18218. Hint: See server log for query details. Where: while locking tuple (6,26) in relation "rhnprivatechannelfamily" SQL statement "select pcf.created from rhnPrivateChannelFamily pcf inner join rhnserver s on s.org_id = pcf.org_id where s.id = server_id_in order by channel_family_id asc for update" PL/pgSQL function lock_counts(numeric) line 11 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) ... 49 more 2017-11-29 12:38:48,083 [TP-Processor8] ERROR com.redhat.rhn.frontend.xmlrpc.BaseHandler - Caused by: com.redhat.rhn.common.db.WrappedSQLException: ERROR: deadlock detected Detail: Process 18218 waits for ShareLock on transaction 190919; blocked by process 18222. Process 18222 waits for ShareLock on transaction 190922; blocked by process 18208. Process 18208 waits for AccessExclusiveLock on tuple (6,26) of relation 20451 of database 16384; blocked by process 18218. Hint: See server log for query details. Where: while locking tuple (6,26) in relation "rhnprivatechannelfamily" SQL statement "select pcf.created from rhnPrivateChannelFamily pcf inner join rhnserver s on s.org_id = pcf.org_id where s.id = server_id_in order by channel_family_id asc for update" PL/pgSQL function lock_counts(numeric) line 11 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.UpdateChildChannelsCommand.unsubscribeFromOldChannels(UpdateChildChannelsCommand.java: 194) at com.redhat.rhn.manager.system.UpdateChildChannelsCommand.store(UpdateChildChannelsCommand.java: 107) at com.redhat.rhn.manager.system.UpdateBaseChannelCommand.store(UpdateBaseChannelCommand.java: 101) at com.redhat.rhn.frontend.xmlrpc.system.SystemHandler.setBaseChannel(SystemHandler.java: 472) at sun.reflect.GeneratedMethodAccessor522.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 18218 waits for ShareLock on transaction 190919; blocked by process 18222. Process 18222 waits for ShareLock on transaction 190922; blocked by process 18208. Process 18208 waits for AccessExclusiveLock on tuple (6,26) of relation 20451 of database 16384; blocked by process 18218. Hint: See server log for query details. Where: while locking tuple (6,26) in relation "rhnprivatechannelfamily" SQL statement "select pcf.created from rhnPrivateChannelFamily pcf inner join rhnserver s on s.org_id = pcf.org_id where s.id = server_id_in order by channel_family_id asc for update" PL/pgSQL function lock_counts(numeric) line 11 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) ... 49 more 2017-11-29 12:38:48,084 [TP-Processor8] ERROR com.redhat.rhn.frontend.xmlrpc.BaseHandler - Rolling back transaction Nov 29, 2017 12:38:48 PM redstone.xmlrpc.XmlRpcDispatcher writeError WARNING: redstone.xmlrpc.XmlRpcFault: unhandled internal exception: ERROR: deadlock detected Detail: Process 18218 waits for ShareLock on transaction 190919; blocked by process 18222. Process 18222 waits for ShareLock on transaction 190922; blocked by process 18208. Process 18208 waits for AccessExclusiveLock on tuple (6,26) of relation 20451 of database 16384; blocked by process 18218. Hint: See server log for query details. Where: while locking tuple (6,26) in relation "rhnprivatechannelfamily" SQL statement "select pcf.created from rhnPrivateChannelFamily pcf inner join rhnserver s on s.org_id = pcf.org_id where s.id = server_id_in order by channel_family_id asc for update" PL/pgSQL function lock_counts(numeric) line 11 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 Expected results: Server should handle this "conflict of interests" more gracefully. Additional info:
We have re-reviewed this bug, as part of an ongoing effort to improve Satellite/Proxy feature and bug updates, review and backlog. This bug has currently no open customer cases. While this bug may still valid, we do not see it being implemented prior to the EOL of the Satellite 5.x product. As such, this is being CLOSED DEFERRED.