Support Migration Notice: To update migrated JIRA cases click here to open a new case use www.vmware.com/go/sr | vFabric Hyperic 5.7.0 is Now Available

Hyperic HQ

Deadlock with async delete

Details

  • Type: Bug Bug
  • Status: Closed Closed
  • Priority: Major Major
  • Resolution: Fixed
  • Affects Version/s: 4.1.2
  • Fix Version/s: 4.1.1
  • Component/s: Deprecated: Server
  • Environment:
    4.1.1 with MySQL backend
  • Case Links:
    none

Description

Deleting 3 platforms with 600 services on each causes following deadlock. This results in orphaned platform/servers/services. Full server log attached.

2009-03-08 10:00:05,595 ERROR [org.hyperic.hq.bizapp.server.session.AppdefBossEJBImpl$1@de35691] [org.hyperic.hq.appdef.server.session.CPropManagerEJBImpl@550] Unable to delete CProp values: Deadlock found when trying to get lock; try restarting transaction
com.mysql.jdbc.exceptions.MySQLTransactionRollbackException: Deadlock found when trying to get lock; try restarting transaction
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:941)
at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:2941)
at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:1623)
at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:1715)
at com.mysql.jdbc.Connection.execSQL(Connection.java:3249)
at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:1268)
at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:1541)
at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:1455)
at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:1440)
at org.jboss.resource.adapter.jdbc.CachedPreparedStatement.executeUpdate(CachedPreparedStatement.java:95)
at org.jboss.resource.adapter.jdbc.WrappedPreparedStatement.executeUpdate(WrappedPreparedStatement.java:365)
at org.hyperic.hq.appdef.server.session.CPropManagerEJBImpl.deleteValues(CPropManagerEJBImpl.java:548)
at sun.reflect.GeneratedMethodAccessor2203.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
at java.lang.reflect.Method.invoke(Unknown Source)
at org.jboss.invocation.Invocation.performCall(Invocation.java:359)
at org.jboss.ejb.StatelessSessionContainer$ContainerInterceptor.invoke(StatelessSessionContainer.java:237)
at org.jboss.resource.connectionmanager.CachedConnectionInterceptor.invoke(CachedConnectionInterceptor.java:158)
at org.jboss.ejb.plugins.StatelessSessionInstanceInterceptor.invoke(StatelessSessionInstanceInterceptor.java:169)
at org.jboss.ejb.plugins.CallValidationInterceptor.invoke(CallValidationInterceptor.java:63)
at org.hyperic.hq.application.HQApp$Snatcher.invokeNextBoth(HQApp.java:515)
at org.hyperic.hq.application.HQApp$Snatcher.invokeNext(HQApp.java:587)
at org.hyperic.txsnatch.TxSnatch.invoke(TxSnatch.java:71)
at org.jboss.ejb.plugins.AbstractTxInterceptor.invokeNext(AbstractTxInterceptor.java:121)
at org.jboss.ejb.plugins.TxInterceptorCMT.runWithTransactions(TxInterceptorCMT.java:350)
at org.jboss.ejb.plugins.TxInterceptorCMT.invoke(TxInterceptorCMT.java:181)
at org.hyperic.hq.application.HQApp$Snatcher.invokeNextBoth(HQApp.java:515)
at org.hyperic.hq.application.HQApp$Snatcher.invokeNext(HQApp.java:587)
at org.hyperic.txsnatch.TxSnatch.invoke(TxSnatch.java:71)
at org.jboss.ejb.plugins.SecurityInterceptor.invoke(SecurityInterceptor.java:168)
at org.jboss.ejb.plugins.LogInterceptor.invoke(LogInterceptor.java:205)
at org.jboss.ejb.plugins.ProxyFactoryFinderInterceptor.invoke(ProxyFactoryFinderInterceptor.java:138)
at org.jboss.ejb.SessionContainer.internalInvoke(SessionContainer.java:648)
at org.jboss.ejb.Container.invoke(Container.java:960)
at org.jboss.ejb.plugins.local.BaseLocalProxyFactory.invoke(BaseLocalProxyFactory.java:430)
at org.jboss.ejb.plugins.local.StatelessSessionProxy.invoke(StatelessSessionProxy.java:103)
at $Proxy266.deleteValues(Unknown Source)
at org.hyperic.hq.appdef.server.session.AppdefSessionEJB.deleteCustomProperties(AppdefSessionEJB.java:1041)
at org.hyperic.hq.appdef.server.session.ServiceManagerEJBImpl.removeService(ServiceManagerEJBImpl.java:1349)
at sun.reflect.GeneratedMethodAccessor2222.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
at java.lang.reflect.Method.invoke(Unknown Source)
at org.jboss.invocation.Invocation.performCall(Invocation.java:359)
at org.jboss.ejb.StatelessSessionContainer$ContainerInterceptor.invoke(StatelessSessionContainer.java:237)
at org.jboss.resource.connectionmanager.CachedConnectionInterceptor.invoke(CachedConnectionInterceptor.java:158)
at org.jboss.ejb.plugins.StatelessSessionInstanceInterceptor.invoke(StatelessSessionInstanceInterceptor.java:169)
at org.jboss.ejb.plugins.CallValidationInterceptor.invoke(CallValidationInterceptor.java:63)
at org.hyperic.hq.application.HQApp$Snatcher.invokeNextBoth(HQApp.java:515)
at org.hyperic.hq.application.HQApp$Snatcher.invokeNext(HQApp.java:587)
at org.hyperic.txsnatch.TxSnatch.invoke(TxSnatch.java:71)
at org.jboss.ejb.plugins.AbstractTxInterceptor.invokeNext(AbstractTxInterceptor.java:121)
at org.jboss.ejb.plugins.TxInterceptorCMT.runWithTransactions(TxInterceptorCMT.java:350)
at org.jboss.ejb.plugins.TxInterceptorCMT.invoke(TxInterceptorCMT.java:181)
at org.hyperic.hq.application.HQApp$Snatcher.invokeNextBoth(HQApp.java:515)
at org.hyperic.hq.application.HQApp$Snatcher.invokeNext(HQApp.java:587)
at org.hyperic.txsnatch.TxSnatch.invoke(TxSnatch.java:71)
at org.jboss.ejb.plugins.SecurityInterceptor.invoke(SecurityInterceptor.java:168)
at org.jboss.ejb.plugins.LogInterceptor.invoke(LogInterceptor.java:205)
at org.jboss.ejb.plugins.ProxyFactoryFinderInterceptor.invoke(ProxyFactoryFinderInterceptor.java:138)
at org.jboss.ejb.SessionContainer.internalInvoke(SessionContainer.java:648)
at org.jboss.ejb.Container.invoke(Container.java:960)
at org.jboss.ejb.plugins.local.BaseLocalProxyFactory.invoke(BaseLocalProxyFactory.java:430)
at org.jboss.ejb.plugins.local.StatelessSessionProxy.invoke(StatelessSessionProxy.java:103)
at $Proxy310.removeService(Unknown Source)
at org.hyperic.hq.bizapp.server.session.AppdefBossEJBImpl._removeServiceInNewTran(AppdefBossEJBImpl.java:1622)
at sun.reflect.GeneratedMethodAccessor2219.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
at java.lang.reflect.Method.invoke(Unknown Source)
at org.jboss.invocation.Invocation.performCall(Invocation.java:359)
at org.jboss.ejb.StatelessSessionContainer$ContainerInterceptor.invoke(StatelessSessionContainer.java:237)
at org.jboss.resource.connectionmanager.CachedConnectionInterceptor.invoke(CachedConnectionInterceptor.java:158)
at org.jboss.ejb.plugins.StatelessSessionInstanceInterceptor.invoke(StatelessSessionInstanceInterceptor.java:169)
at org.jboss.ejb.plugins.CallValidationInterceptor.invoke(CallValidationInterceptor.java:63)
at org.hyperic.hq.application.HQApp$Snatcher.invokeNextBoth(HQApp.java:515)
at org.hyperic.hq.application.HQApp$Snatcher.invokeNext(HQApp.java:587)
at org.hyperic.txsnatch.TxSnatch.invoke(TxSnatch.java:71)
at org.jboss.ejb.plugins.AbstractTxInterceptor.invokeNext(AbstractTxInterceptor.java:121)
at org.jboss.ejb.plugins.TxInterceptorCMT.runWithTransactions(TxInterceptorCMT.java:404)
at org.jboss.ejb.plugins.TxInterceptorCMT.invoke(TxInterceptorCMT.java:181)
at org.hyperic.hq.application.HQApp$Snatcher.invokeNextBoth(HQApp.java:515)
at org.hyperic.hq.application.HQApp$Snatcher.invokeNext(HQApp.java:587)
at org.hyperic.txsnatch.TxSnatch.invoke(TxSnatch.java:71)
at org.jboss.ejb.plugins.SecurityInterceptor.invoke(SecurityInterceptor.java:168)
at org.jboss.ejb.plugins.LogInterceptor.invoke(LogInterceptor.java:205)
at org.jboss.ejb.plugins.ProxyFactoryFinderInterceptor.invoke(ProxyFactoryFinderInterceptor.java:138)
at org.jboss.ejb.SessionContainer.internalInvoke(SessionContainer.java:648)
at org.jboss.ejb.Container.invoke(Container.java:960)
at org.jboss.ejb.plugins.local.BaseLocalProxyFactory.invoke(BaseLocalProxyFactory.java:430)
at org.jboss.ejb.plugins.local.StatelessSessionProxy.invoke(StatelessSessionProxy.java:103)
at $Proxy258._removeServiceInNewTran(Unknown Source)
at org.hyperic.hq.bizapp.server.session.AppdefBossEJBImpl.removeDeletedResources(AppdefBossEJBImpl.java:1424)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
at java.lang.reflect.Method.invoke(Unknown Source)
at org.jboss.invocation.Invocation.performCall(Invocation.java:359)
at org.jboss.ejb.StatelessSessionContainer$ContainerInterceptor.invoke(StatelessSessionContainer.java:237)
at org.jboss.resource.connectionmanager.CachedConnectionInterceptor.invoke(CachedConnectionInterceptor.java:158)
at org.jboss.ejb.plugins.StatelessSessionInstanceInterceptor.invoke(StatelessSessionInstanceInterceptor.java:169)
at org.jboss.ejb.plugins.CallValidationInterceptor.invoke(CallValidationInterceptor.java:63)
at org.hyperic.hq.application.HQApp$Snatcher.invokeNextBoth(HQApp.java:515)
at org.hyperic.hq.application.HQApp$Snatcher.invokeNext(HQApp.java:587)
at org.hyperic.txsnatch.TxSnatch.invoke(TxSnatch.java:71)
at org.jboss.ejb.plugins.AbstractTxInterceptor.invokeNext(AbstractTxInterceptor.java:121)
at org.jboss.ejb.plugins.TxInterceptorCMT.runWithTransactions(TxInterceptorCMT.java:315)
at org.jboss.ejb.plugins.TxInterceptorCMT.invoke(TxInterceptorCMT.java:181)
at org.hyperic.hq.application.HQApp$Snatcher.invokeNextBoth(HQApp.java:515)
at org.hyperic.hq.application.HQApp$Snatcher.invokeNext(HQApp.java:587)
at org.hyperic.txsnatch.TxSnatch.invoke(TxSnatch.java:71)
at org.jboss.ejb.plugins.SecurityInterceptor.invoke(SecurityInterceptor.java:168)
at org.jboss.ejb.plugins.LogInterceptor.invoke(LogInterceptor.java:205)
at org.jboss.ejb.plugins.ProxyFactoryFinderInterceptor.invoke(ProxyFactoryFinderInterceptor.java:138)
at org.jboss.ejb.SessionContainer.internalInvoke(SessionContainer.java:648)
at org.jboss.ejb.Container.invoke(Container.java:960)
at org.jboss.ejb.plugins.local.BaseLocalProxyFactory.invoke(BaseLocalProxyFactory.java:430)
at org.jboss.ejb.plugins.local.StatelessSessionProxy.invoke(StatelessSessionProxy.java:103)
at $Proxy258.removeDeletedResources(Unknown Source)
at org.hyperic.hq.bizapp.server.session.AppdefBossEJBImpl$1.processEvents(AppdefBossEJBImpl.java:3933)
at org.hyperic.hq.zevents.TimingListenerWrapper.processEvents(TimingListenerWrapper.java:44)
at org.hyperic.hq.zevents.BufferedListener$BufferedEventRunnable.run(BufferedListener.java:64)
at edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1061)
at edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:575)
at java.lang.Thread.run(Unknown Source)

Activity

Kashyap Parikh made changes -
Field Original Value New Value
Attachment server.log.1.gz [ 19493 ]
Hide
Scott Feldstein added a comment -

This only occurs on MySQL. I believe the reason is the innodb "next key locking"

from http://dev.mysql.com/doc/refman/5.0/en/innodb-next-key-locking.html

"To prevent phantoms, InnoDB uses an algorithm called next-key locking that combines index-row locking with gap locking. InnoDB performs row-level locking in such a way that when it searches or scans a table index, it sets shared or exclusive locks on the index records it encounters. Thus, the row-level locks are actually index-record locks. In addition, a next-key lock on an index record also affects the "gap" before that index record. That is, a next-key lock is an index-record lock plus a gap lock on the gap preceding the index record. If one session has a shared or exclusive lock on record R in an index, another session cannot insert a new index record in the gap immediately before R in the index order. "

since most of the queries / updates are dependent on the keyid / appdefID, spreading out the unique index so that its leading edge is appdefID then keyid seems to alleviate the problem.

Show
Scott Feldstein added a comment - This only occurs on MySQL. I believe the reason is the innodb "next key locking" from http://dev.mysql.com/doc/refman/5.0/en/innodb-next-key-locking.html "To prevent phantoms, InnoDB uses an algorithm called next-key locking that combines index-row locking with gap locking. InnoDB performs row-level locking in such a way that when it searches or scans a table index, it sets shared or exclusive locks on the index records it encounters. Thus, the row-level locks are actually index-record locks. In addition, a next-key lock on an index record also affects the "gap" before that index record. That is, a next-key lock is an index-record lock plus a gap lock on the gap preceding the index record. If one session has a shared or exclusive lock on record R in an index, another session cannot insert a new index record in the gap immediately before R in the index order. " since most of the queries / updates are dependent on the keyid / appdefID, spreading out the unique index so that its leading edge is appdefID then keyid seems to alleviate the problem.
Scott Feldstein made changes -
Status Open [ 1 ] Resolved [ 5 ]
Resolution Fixed [ 1 ]
Hide
Kashyap Parikh added a comment -

I can see deadlocks are still occurring leaving undeleted resources. The current work around is to restart server, which kicks off the delete service again. Lowering priority and moving to 4.1.2

Show
Kashyap Parikh added a comment - I can see deadlocks are still occurring leaving undeleted resources. The current work around is to restart server, which kicks off the delete service again. Lowering priority and moving to 4.1.2
Kashyap Parikh made changes -
Status Resolved [ 5 ] Reopened [ 4 ]
Resolution Fixed [ 1 ]
Kashyap Parikh made changes -
Priority Blocker [ 1 ] Major [ 3 ]
Affects Version/s 4.1.1 [ 10430 ]
Affects Version/s 4.1.2 [ 10442 ]
Hide
Kashyap Parikh added a comment -

Resolving as we have not seen this in latest build #1035

Show
Kashyap Parikh added a comment - Resolving as we have not seen this in latest build #1035
Kashyap Parikh made changes -
Resolution Fixed [ 1 ]
Status Reopened [ 4 ] Resolved [ 5 ]
Kashyap Parikh made changes -
Status Resolved [ 5 ] Closed [ 6 ]

People

Vote (0)
Watch (0)

Dates

  • Created:
    Updated:
    Resolved:
    Last comment:
    5 years, 3 weeks, 6 days ago