Primary L2 (and then Secondary L2) crashes with what appears to be a BDB Deadlock Exception

Type: Bug
Status: Closed
Priority: 2 Major
Resolution: Fixed
Component/s:
Labels:

Assignee: ssubbiah
Reporter: foshea
Created: August 23, 2007
Votes: 0
Watchers: 0
Updated:
July 27, 2012
Resolved:
August 23, 2007

Description

The TC primary server crashed with the errors listed below. It looks very a serious problem to me. Fortunately the stand by TC server picked up the requests.

ock expired. Locker -1_WorkerThread(commit_changes_stage,1)_ReadCommittedLocker: waited for lock on database=mapsdatabase node=828277 type=READ grant=WAIT_NEW timeoutMillis=180000 startTime=1187033207882 endTime=1187033387884 Owners: [] Waiters: []

    at com.tc.objectserver.persistence.sleepycat.ManagedObjectPersistorImpl.saveAllObjects(ManagedObjectPersistorImpl.java:296) 
    at com.tc.objectserver.impl.PersistentManagedObjectStore.commitAllObjects(PersistentManagedObjectStore.java:81) 
    at com.tc.objectserver.impl.ObjectManagerImpl.flushAll(ObjectManagerImpl.java:660) 
    at com.tc.objectserver.impl.ObjectManagerImpl.releaseAll(ObjectManagerImpl.java:526) 
    at com.tc.objectserver.tx.ServerTransactionManagerImpl.release(ServerTransactionManagerImpl.java:262) 
    at com.tc.objectserver.tx.ServerTransactionManagerImpl.commit(ServerTransactionManagerImpl.java:253) 
    at com.tc.objectserver.handler.CommitTransactionChangeHandler.handleEvent(CommitTransactionChangeHandler.java:30) 
    at com.tc.async.impl.StageImpl$WorkerThread.run(StageImpl.java:140)  Caused by: com.tc.objectserver.persistence.sleepycat.TCDatabaseException: com.sleepycat.je.DeadlockException: (JE 3.2.23) Lock expired. Locker -1\_WorkerThread(commit\_changes\_stage,1)\_ReadCommittedLocker: waited for lock on database=mapsdatabase node=828277 type=READ grant=WAIT\_NEW timeoutMillis=180000 startTime=1187033207882 endTime=1187033387884  Owners: [<LockInfo locker="182254\_WorkerThread(commit\_changes\_stage,2)\_Txn" type="WRITE"/>]  Waiters: [] 

    at com.tc.objectserver.persistence.sleepycat.ManagedObjectPersistorImpl.basicSaveCollection(ManagedObjectPersistorImpl.java:271)
    at com.tc.objectserver.persistence.sleepycat.ManagedObjectPersistorImpl.basicSaveObject(ManagedObjectPersistorImpl.java:249) 
    at com.tc.objectserver.persistence.sleepycat.ManagedObjectPersistorImpl.saveAllObjects(ManagedObjectPersistorImpl.java:284) 
    ... 7 more  Caused by: com.sleepycat.je.DeadlockException: (JE 3.2.23) Lock expired. Locker -1\_WorkerThread(commit\_changes\_stage,1)\_ReadCommittedLocker: waited for lock on database=mapsdatabase node=828277 type=READ grant=WAIT\_NEW timeoutMillis=180000 startTime=1187033207882 endTime=1187033387884  Owners: [<LockInfo locker="182254\_WorkerThread(commit\_changes\_stage,2)\_Txn" type="WRITE"/>]  Waiters: [] 

    at com.sleepycat.je.txn.LockManager.lock(LockManager.java:266) 
    at com.sleepycat.je.txn.BasicLocker.lockInternal(BasicLocker.java:90) 
    at com.sleepycat.je.txn.ReadCommittedLocker.lockInternal(ReadCommittedLocker.java:69) 
    at com.sleepycat.je.txn.Locker.lock(Locker.java:257) 
    at com.sleepycat.je.dbi.CursorImpl.lockLNDeletedAllowed(CursorImpl.java:2349) 
    at com.sleepycat.je.dbi.CursorImpl.lockLN(CursorImpl.java:2271) 
    at com.sleepycat.je.dbi.CursorImpl.fetchCurrent(CursorImpl.java:2207) 
    at com.sleepycat.je.dbi.CursorImpl.getCurrentAlreadyLatched(CursorImpl.java:1276) 
    at com.sleepycat.je.dbi.CursorImpl.getNextWithKeyChangeStatus(CursorImpl.java:1422) 
    at com.sleepycat.je.dbi.CursorImpl.getNext(CursorImpl.java:1348) 
    at com.sleepycat.je.dbi.CursorImpl.getNextNoDup(CursorImpl.java:1535) 
    at com.sleepycat.je.Cursor.searchInternal(Cursor.java:1336) 
    at com.sleepycat.je.Cursor.searchAllowPhantoms(Cursor.java:1148) 
    at com.sleepycat.je.Cursor.search(Cursor.java:1014) 
    at com.sleepycat.je.Cursor.getSearchKeyRange(Cursor.java:573) 
    at com.tc.objectserver.persistence.sleepycat.SleepycatPersistableMap.basicClear(SleepycatPersistableMap.java:207) 
    at com.tc.objectserver.persistence.sleepycat.SleepycatPersistableMap.commit(SleepycatPersistableMap.java:131) 
    at com.tc.objectserver.persistence.sleepycat.SleepycatCollectionsPersistor.saveMap(SleepycatCollectionsPersistor.java:47) 
    at com.tc.objectserver.persistence.sleepycat.ManagedObjectPersist 

com.tc.objectserver.persistence.sleepycat.DBException: com.tc.objectserver.persistence.sleepycat.TCDatabaseException: com.sleepycat.je.DeadlockException: (JE 3.2.23) Lock expired. Locker -1_WorkerThread(commit_changes_stage,2)_ReadCommittedLocker: waited for lock on database=mapsdatabase node=828047 type=READ grant=WAIT_NEW timeoutMillis=180000 startTime=1187033207882 endTime=1187033387884 Owners: [] Waiters: []

    at com.tc.objectserver.persistence.sleepycat.ManagedObjectPersistorImpl.saveAllObjects(ManagedObjectPersistorImpl.java:296) 
    at com.tc.objectserver.impl.PersistentManagedObjectStore.commitAllObjects(PersistentManagedObjectStore.java:81) 
    at com.tc.objectserver.impl.ObjectManagerImpl.flushAll(ObjectManagerImpl.java:660) 
    at com.tc.objectserver.impl.ObjectManagerImpl.releaseAll(ObjectManagerImpl.java:526) 
    at com.tc.objectserver.tx.ServerTransactionManagerImpl.release(ServerTransactionManagerImpl.java:262) 
    at com.tc.objectserver.tx.ServerTransactionManagerImpl.commit(ServerTransactionManagerImpl.java:253) 
    at com.tc.objectserver.handler.CommitTransactionChangeHandler.handleEvent(CommitTransactionChangeHandler.java:30) 
    at com.tc.async.impl.StageImpl$WorkerThread.run(StageImpl.java:140)  Caused by: com.tc.objectserver.persistence.sleepycat.TCDatabaseException: com.sleepycat.je.DeadlockException: (JE 3.2.23) Lock expired. Locker -1\_WorkerThread(commit\_changes\_stage,2)\_ReadCommittedLocker: waited for lock on database=mapsdatabase node=828047 type=READ grant=WAIT\_NEW timeoutMillis=180000 startTime=1187033207882 endTime=1187033387884  Owners: [<LockInfo locker="182255\_WorkerThread(commit\_changes\_stage,1)\_Txn" type="WRITE"/>]  Waiters: [<LockInfo locker="-1\_WorkerThread(commit\_changes\_stage,0)\_ReadCommittedLocker" type="READ"/>] 

    at com.tc.objectserver.persistence.sleepycat.ManagedObjectPersistorImpl.basicSaveCollection(ManagedObjectPersistorImpl.java:271)
    at com.tc.objectserver.persistence.sleepycat.ManagedObjectPersistorImpl.basicSaveObject(ManagedObjectPersistorImpl.java:249) 
    at com.tc.objectserver.persistence.sleepycat.ManagedObjectPersistorImpl.saveAllObjects(ManagedObjectPersistorImpl.java:284) 
    ... 7 more  Caused by: com.sleepycat.je.DeadlockException: (JE 3.2.23) Lock expired. Locker -1\_WorkerThread(commit\_changes\_stage,2)\_ReadCommittedLocker: waited for lock on database=mapsdatabase node=828047 type=READ grant=WAIT\_NEW timeoutMillis=180000 startTime=1187033207882 endTime=1187033387884  Owners: [<LockInfo locker="182255\_WorkerThread(commit\_changes\_stage,1)\_Txn" type="WRITE"/>]  Waiters: [<LockInfo locker="-1\_WorkerThread(commit\_changes\_stage,0)\_ReadCommittedLocker" type="READ"/>] 

    at com.sleepycat.je.txn.LockManager.lock(LockManager.java:266) 
    at com.sleepycat.je.txn.BasicLocker.lockInternal(BasicLocker.java:90) 
    at com.sleepycat.je.txn.ReadCommittedLocker.lockInternal(ReadCommittedLocker.java:69) 
    at com.sleepycat.je.txn.Locker.lock(Locker.java:257) 
    at com.sleepycat.je.dbi.CursorImpl.lockLNDeletedAllowed(CursorImpl.java:2349) 
    at com.sleepycat.je.dbi.CursorImpl.lockLN(CursorImpl.java:2271) 
    at com.sleepycat.je.dbi.CursorImpl.fetchCurrent(CursorImpl.java:2207) 
    at com.sleepycat.je.dbi.CursorImpl.getCurrentAlreadyLatched(CursorImpl.java:1276) 
    at com.sleepycat.je.dbi.CursorImpl.getNextWithKeyChangeStatus(CursorImpl.java:1422) 
    at com.sleepycat.je.dbi.CursorImpl.getNext(CursorImpl.java:1348) 
    at com.sleepycat.je.Cursor.retrieveNextAllowPhantoms(Cursor.java:1577) 
    at com.sleepycat.je.Cursor.retrieveNext(Cursor.java:1387) 
    at com.sleepycat.je.Cursor.getNext(Cursor.java:446) 
    at com.tc.objectserver.persistence.sleepycat.SleepycatPersistableMap.basicClear(SleepycatPersistableMap.java:214) 
    at com.tc.objectserver.persistence.sleepycat.SleepycatPersistableMap.commit(SleepycatPersistableMap.java:131) 
    at com.tc.objectserver.persistence.sleepycat.SleepycatCollectionsPersistor.saveMap(SleepycatCollectionsPersistor.java:47) 
    at com.tc.objectserver.persistence.sleepycat.ManagedObjectPersistorImpl.basicSaveCollection(ManagedObjectPersistorImpl.java:269)
    ... 9 more  com.tc.objectserver.persistence.sleepycat.TCDatabaseException: com.sleepycat.je.DeadlockException: (JE 3.2.23) Lock expired. Locker -1\_WorkerThread(commit\_changes\_stage,1)\_ReadCommittedLocker: waited for lock on database=mapsdatabase node=828277 type=READ grant=WAIT\_NEW timeoutMillis=180000 startTime=1187033207882 endTime=1187033387884  Owners: [<LockInfo locker="182254\_WorkerThread(commit\_changes\_stage,2)\_Txn" type="WRITE"/>] 

Comments

Fiona OShea 2007-08-23

Hi Saravanan, can you add a comment explaining what the issue was? This is for community so that we have a reason for 2.4.2 release:) thanks. Fiona

Saravanan Subbiah 2007-08-23

This was due to a lock ordering problem which got exposed in sleepycat as a transaction deadlock. This is fixed.