jackrabbit-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From <Robert.Sa...@sungard.com>
Subject Deadlock with a twist
Date Mon, 27 Aug 2012 10:29:23 GMT
Dear jackrabit-DEVs,

first of all, my apologies for this rather long post. But while investigating a deadlock scenario
at a customer site we observed program state that should - according to the source code -
not be (obviously) possible. We have an idea how this happened and I would kindly like to
ask for either confirmation or correction.

The deadlock itself matches JCR-2820, which we already backported to the 1.6.4 codebase that's
being used in our scenario (I know it's old, but it serves its purpose, generally).

But while trying to recreate the error condition to actually verify the fix, we discovered
in the HEAP dump taken from the deadlocked system the following:
- the JR TX is about to be committed, already in the commit phase
- the actual thread performing the commit is taken from the app server's work manager thread
pool and executing asynchronously (this is why JCR-2820 hit)
- while trying to send out post-commit notifications the thread gets blocked within FineGrainedISMLocking#acquireReadLock

The twist is: going back the invocation stack, event notifications get triggered from line
780 in SharedItemStateManager (see below). Being in this line, the write lock held during
commit should already be downgraded (see lines 764 and 765).
However, a heap dump we got from the blocked application shows that the writeLock member of
SharedItemStateManager still refers to a lock, the very one that prevents acquireReadLock
from proceeding.
The write lock being held is the correct one, namely the one obtained during the previous
prepare of the same TX.

All this happens on an IBM JVM on AIX. It happens very sporadically, between occurrences can
be several days, but only minutes as well.

The only explanation I can think of so far is that some broad out-of-order execution might
be happening (due to the JVMs JIT applying optimizations). Is there anything known? Or any
obvious other explanation I'm missing?
I'm mostly concerned that the currently available fix might not cover such scenario and some
further synchronization might be required.

Many thanks in advance and kind regards

[snip class="SharedItemStateManager"]
            ISMLocking.ReadLock readLock = null;
            try {
                // downgrade to read lock
764             readLock = writeLock.downgrade();
765             writeLock = null;

                // Let the shared item listeners know about the change
                // JCR-2171: This must happen after downgrading the lock!

                /* notify virtual providers about node references */
                for (int i = 0; i < virtualNodeReferences.length; i++) {
                    ChangeLog virtualRefs = virtualNodeReferences[i];
                    if (virtualRefs != null) {

                /* dispatch the events */
780             events.dispatch();

                /* let listener know about finished operation */
                if (eventChannel != null) {
                    String path = events.getSession().getUserID() + "@" + events.getCommonPath();
                    eventChannel.updateCommitted(this, path);

3XMTHREADINFO      "[STUCK] ExecuteThread: '11' for queue: 'weblogic.kernel.Default (self-tuning)'"
J9VMThread:0x0000010033796D00, j9thread_t:0x000001003630E380, java/lang/Thread:0x070000003A97B798,
state:CW, prio=1
3XMTHREADINFO1            (native thread ID:0x69F00F1, native priority:0x1, native policy:UNKNOWN)
3XMTHREADINFO3           Java callstack:
4XESTACKTRACE                at java/lang/Object.wait(Native Method)
4XESTACKTRACE                at java/lang/Object.wait(Object.java:167(Compiled Code))
4XESTACKTRACE                at EDU/oswego/cs/dl/util/concurrent/Latch.acquire(Bytecode PC:22)
4XESTACKTRACE                at org/apache/jackrabbit/core/state/FineGrainedISMLocking.acquireReadLock(FineGrainedISMLocking.java:112(Compiled
4XESTACKTRACE                at org/apache/jackrabbit/core/state/SharedItemStateManager.acquireReadLock(SharedItemStateManager.java:1822(Compiled
4XESTACKTRACE                at org/apache/jackrabbit/core/state/SharedItemStateManager.getItemState(SharedItemStateManager.java:253(Compiled
4XESTACKTRACE                at org/apache/jackrabbit/core/SearchManager$1.nextNodeState(SearchManager.java:450)
4XESTACKTRACE                at org/apache/jackrabbit/core/SearchManager$1.next(SearchManager.java:443)
4XESTACKTRACE                at org/apache/commons/collections/iterators/TransformIterator.next(TransformIterator.java:87(Compiled
4XESTACKTRACE                at org/apache/commons/collections/IteratorUtils.toList(IteratorUtils.java:848(Compiled
4XESTACKTRACE                at org/apache/commons/collections/IteratorUtils.toList(IteratorUtils.java:824)
4XESTACKTRACE                at org/apache/jackrabbit/core/query/lucene/SearchIndex.updateNodes(SearchIndex.java:588)
4XESTACKTRACE                at org/apache/jackrabbit/core/SearchManager.onEvent(SearchManager.java:486(Compiled
4XESTACKTRACE                at org/apache/jackrabbit/core/observation/EventConsumer.consumeEvents(EventConsumer.java:244(Compiled
4XESTACKTRACE                at org/apache/jackrabbit/core/observation/ObservationDispatcher.dispatchEvents(ObservationDispatcher.java:201(Compiled
4XESTACKTRACE                at org/apache/jackrabbit/core/observation/EventStateCollection.dispatch(EventStateCollection.java:474)
4XESTACKTRACE                at org/apache/jackrabbit/core/observation/DelegatingObservationDispatcher.dispatch(DelegatingObservationDispatcher.java:127)
4XESTACKTRACE                at org/apache/jackrabbit/core/observation/DelegatingObservationDispatcher.dispatchEvents(DelegatingObservationDispatcher.java:99)
4XESTACKTRACE                at org/apache/jackrabbit/core/observation/EventStateCollection.dispatch(EventStateCollection.java:474(Compiled
4XESTACKTRACE                at org/apache/jackrabbit/core/state/SharedItemStateManager$Update.end(SharedItemStateManager.java:780(Compiled
4XESTACKTRACE                at org/apache/jackrabbit/core/state/XAItemStateManager.commit(XAItemStateManager.java:181(Compiled
4XESTACKTRACE                at org/apache/jackrabbit/core/version/XAVersionManager.commit(XAVersionManager.java:521)
4XESTACKTRACE                at org/apache/jackrabbit/core/TransactionContext.commit(TransactionContext.java:205(Compiled
4XESTACKTRACE                at org/apache/jackrabbit/core/XASessionImpl.commit(XASessionImpl.java:346)
4XESTACKTRACE                at org/apache/jackrabbit/jca/TransactionBoundXAResource.commit(TransactionBoundXAResource.java:39)

Robert Sauer . Chief Architect - Infinity . SunGard . Global Business Services and Technology
. Solmsstraße 18, 60486 Frankfurt am Main, Germany
Tel +49 69 70768 572 . Mobile +49 176 1111 0181 . robert.sauer@sungard.com . www.sungard.com/infinity 

Join the online conversation with SunGard's customers, partners and industry experts and find
an event near you at: www.sungard.com/ten. 
CONFIDENTIALITY: This e-mail (including any attachments) may contain confidential, proprietary
and privileged information, and unauthorized disclosure or use is prohibited. If you receive
this e-mail in error, please notify the sender and delete this e-mail from your system.

SunGard Systeme GmbH . Registered: Frankfurt am Main, Handelsregister Frankfurt HRB 56839
. Geschäftsführer: Harold Finders, Christian U. Haas, Henry Morton Miller Jr., Victoria
E. Silbey

View raw message