[
https://issues.apache.org/jira/browse/QPID-6809?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Lorenz Quack updated QPID-6809:
-------------------------------
Description:
A user using the Asynchronous Recovery (0.32) feature encountered the following
issue during a lengthy asynchronous recovery. This suggests that the Broker is
not handling JE's LockException properly. In other parts of the code, the code
takes lengths to backoff/retry in the event of a locking exception.
{noformat}
2015-10-21 13:48:49,245 ERROR [Queue Recoverer : xxxx-xxxx (vh: default)]
org.apache.qpid.server.util.ServerScopedRuntimeException Unexpected exception
occurred on store operation
com.sleepycat.je.LockTimeoutException: (JE 5.0.104) Lock expired. Locker
1538378594 -1_Queue Recoverer : xxxx-xxxxx (vh: default)_ThreadLocker: waited
for lock on database=QUEUE_ENTRIES LockAddr:1973403125 LSN=0x9e7d/0x68098
type=READ grant=WAIT_NEW timeoutMillis=500 startTime=1445435328744
endTime=1445435329244
Owners: [<LockInfo locker="1886923901 215323278_IoReceiver -
/xxx.xxx.xxx.xx:59827_Txn" type="WRITE"/>]
Waiters: []
at
com.sleepycat.je.txn.LockManager.newLockTimeoutException(LockManager.java:665)
at
com.sleepycat.je.txn.LockManager.makeTimeoutMsgInternal(LockManager.java:623)
at
com.sleepycat.je.txn.SyncedLockManager.makeTimeoutMsg(SyncedLockManager.java:97)
at com.sleepycat.je.txn.LockManager.lockInternal(LockManager.java:390)
at com.sleepycat.je.txn.LockManager.lock(LockManager.java:276)
at com.sleepycat.je.txn.BasicLocker.lockInternal(BasicLocker.java:118)
at com.sleepycat.je.txn.Locker.lock(Locker.java:443)
at com.sleepycat.je.dbi.CursorImpl.lockLN(CursorImpl.java:2642)
at com.sleepycat.je.dbi.CursorImpl.lockLN(CursorImpl.java:2443)
at com.sleepycat.je.dbi.CursorImpl.fetchCurrent(CursorImpl.java:2272)
at
com.sleepycat.je.dbi.CursorImpl.getCurrentAlreadyLatched(CursorImpl.java:1480)
at com.sleepycat.je.dbi.CursorImpl.getNext(CursorImpl.java:1607)
at com.sleepycat.je.Cursor.retrieveNextAllowPhantoms(Cursor.java:3080)
at com.sleepycat.je.Cursor.retrieveNextNoDups(Cursor.java:2957)
at com.sleepycat.je.Cursor.retrieveNext(Cursor.java:2931)
at com.sleepycat.je.Cursor.getNext(Cursor.java:1148)
at
org.apache.qpid.server.store.berkeleydb.AbstractBDBMessageStore.visitMessageInstances(AbstractBDBMessageStore.java:202)
at
org.apache.qpid.server.virtualhost.AsynchronousMessageStoreRecoverer$AsynchronousRecoverer.recoverQueue(AsynchronousMessageStoreRecoverer.java:145)
at
org.apache.qpid.server.virtualhost.AsynchronousMessageStoreRecoverer$AsynchronousRecoverer.access$900(AsynchronousMessageStoreRecoverer.java:81)
at
org.apache.qpid.server.virtualhost.AsynchronousMessageStoreRecoverer$AsynchronousRecoverer$QueueRecoveringTask.run(AsynchronousMessageStoreRecoverer.java:409)
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:744)
{noformat}
was:
A user using the Asynchronous Recovery (0.32) feature encountered the following
issue during a lengthy asynchronous recovery. This suggests that the Broker is
handling JE's LockException properly. In other parts of the code, the code
takes lengths to backoff/retry in the event of a locking exception.
{noformat}
2015-10-21 13:48:49,245 ERROR [Queue Recoverer : xxxx-xxxx (vh: default)]
org.apache.qpid.server.util.ServerScopedRuntimeException Unexpected exception
occurred on store operation
com.sleepycat.je.LockTimeoutException: (JE 5.0.104) Lock expired. Locker
1538378594 -1_Queue Recoverer : xxxx-xxxxx (vh: default)_ThreadLocker: waited
for lock on database=QUEUE_ENTRIES LockAddr:1973403125 LSN=0x9e7d/0x68098
type=READ grant=WAIT_NEW timeoutMillis=500 startTime=1445435328744
endTime=1445435329244
Owners: [<LockInfo locker="1886923901 215323278_IoReceiver -
/xxx.xxx.xxx.xx:59827_Txn" type="WRITE"/>]
Waiters: []
at
com.sleepycat.je.txn.LockManager.newLockTimeoutException(LockManager.java:665)
at
com.sleepycat.je.txn.LockManager.makeTimeoutMsgInternal(LockManager.java:623)
at
com.sleepycat.je.txn.SyncedLockManager.makeTimeoutMsg(SyncedLockManager.java:97)
at com.sleepycat.je.txn.LockManager.lockInternal(LockManager.java:390)
at com.sleepycat.je.txn.LockManager.lock(LockManager.java:276)
at com.sleepycat.je.txn.BasicLocker.lockInternal(BasicLocker.java:118)
at com.sleepycat.je.txn.Locker.lock(Locker.java:443)
at com.sleepycat.je.dbi.CursorImpl.lockLN(CursorImpl.java:2642)
at com.sleepycat.je.dbi.CursorImpl.lockLN(CursorImpl.java:2443)
at com.sleepycat.je.dbi.CursorImpl.fetchCurrent(CursorImpl.java:2272)
at
com.sleepycat.je.dbi.CursorImpl.getCurrentAlreadyLatched(CursorImpl.java:1480)
at com.sleepycat.je.dbi.CursorImpl.getNext(CursorImpl.java:1607)
at com.sleepycat.je.Cursor.retrieveNextAllowPhantoms(Cursor.java:3080)
at com.sleepycat.je.Cursor.retrieveNextNoDups(Cursor.java:2957)
at com.sleepycat.je.Cursor.retrieveNext(Cursor.java:2931)
at com.sleepycat.je.Cursor.getNext(Cursor.java:1148)
at
org.apache.qpid.server.store.berkeleydb.AbstractBDBMessageStore.visitMessageInstances(AbstractBDBMessageStore.java:202)
at
org.apache.qpid.server.virtualhost.AsynchronousMessageStoreRecoverer$AsynchronousRecoverer.recoverQueue(AsynchronousMessageStoreRecoverer.java:145)
at
org.apache.qpid.server.virtualhost.AsynchronousMessageStoreRecoverer$AsynchronousRecoverer.access$900(AsynchronousMessageStoreRecoverer.java:81)
at
org.apache.qpid.server.virtualhost.AsynchronousMessageStoreRecoverer$AsynchronousRecoverer$QueueRecoveringTask.run(AsynchronousMessageStoreRecoverer.java:409)
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:744)
{noformat}
> LockTimeoutExceptions not handled during asynchronous recovery
> --------------------------------------------------------------
>
> Key: QPID-6809
> URL: https://issues.apache.org/jira/browse/QPID-6809
> Project: Qpid
> Issue Type: Bug
> Components: Java Broker
> Affects Versions: 0.32
> Reporter: Keith Wall
>
> A user using the Asynchronous Recovery (0.32) feature encountered the
> following issue during a lengthy asynchronous recovery. This suggests that
> the Broker is not handling JE's LockException properly. In other parts of
> the code, the code takes lengths to backoff/retry in the event of a locking
> exception.
> {noformat}
> 2015-10-21 13:48:49,245 ERROR [Queue Recoverer : xxxx-xxxx (vh: default)]
> org.apache.qpid.server.util.ServerScopedRuntimeException Unexpected exception
> occurred on store operation
> com.sleepycat.je.LockTimeoutException: (JE 5.0.104) Lock expired. Locker
> 1538378594 -1_Queue Recoverer : xxxx-xxxxx (vh: default)_ThreadLocker: waited
> for lock on database=QUEUE_ENTRIES LockAddr:1973403125 LSN=0x9e7d/0x68098
> type=READ grant=WAIT_NEW timeoutMillis=500 startTime=1445435328744
> endTime=1445435329244
> Owners: [<LockInfo locker="1886923901 215323278_IoReceiver -
> /xxx.xxx.xxx.xx:59827_Txn" type="WRITE"/>]
> Waiters: []
>
> at
> com.sleepycat.je.txn.LockManager.newLockTimeoutException(LockManager.java:665)
> at
> com.sleepycat.je.txn.LockManager.makeTimeoutMsgInternal(LockManager.java:623)
> at
> com.sleepycat.je.txn.SyncedLockManager.makeTimeoutMsg(SyncedLockManager.java:97)
> at com.sleepycat.je.txn.LockManager.lockInternal(LockManager.java:390)
> at com.sleepycat.je.txn.LockManager.lock(LockManager.java:276)
> at com.sleepycat.je.txn.BasicLocker.lockInternal(BasicLocker.java:118)
> at com.sleepycat.je.txn.Locker.lock(Locker.java:443)
> at com.sleepycat.je.dbi.CursorImpl.lockLN(CursorImpl.java:2642)
> at com.sleepycat.je.dbi.CursorImpl.lockLN(CursorImpl.java:2443)
> at com.sleepycat.je.dbi.CursorImpl.fetchCurrent(CursorImpl.java:2272)
> at
> com.sleepycat.je.dbi.CursorImpl.getCurrentAlreadyLatched(CursorImpl.java:1480)
> at com.sleepycat.je.dbi.CursorImpl.getNext(CursorImpl.java:1607)
> at com.sleepycat.je.Cursor.retrieveNextAllowPhantoms(Cursor.java:3080)
> at com.sleepycat.je.Cursor.retrieveNextNoDups(Cursor.java:2957)
> at com.sleepycat.je.Cursor.retrieveNext(Cursor.java:2931)
> at com.sleepycat.je.Cursor.getNext(Cursor.java:1148)
> at
> org.apache.qpid.server.store.berkeleydb.AbstractBDBMessageStore.visitMessageInstances(AbstractBDBMessageStore.java:202)
> at
> org.apache.qpid.server.virtualhost.AsynchronousMessageStoreRecoverer$AsynchronousRecoverer.recoverQueue(AsynchronousMessageStoreRecoverer.java:145)
> at
> org.apache.qpid.server.virtualhost.AsynchronousMessageStoreRecoverer$AsynchronousRecoverer.access$900(AsynchronousMessageStoreRecoverer.java:81)
> at
> org.apache.qpid.server.virtualhost.AsynchronousMessageStoreRecoverer$AsynchronousRecoverer$QueueRecoveringTask.run(AsynchronousMessageStoreRecoverer.java:409)
> at
> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
> at java.util.concurrent.FutureTask.run(FutureTask.java:262)
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
> at java.lang.Thread.run(Thread.java:744)
> {noformat}
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
