Uploaded image for project: 'Blazegraph (by SYSTAP)'
  1. Blazegraph (by SYSTAP)
  2. BLZG-1051

Deadlock between AbstractRunningQuery.cancel(), QueryLog.log(), and ArbitraryLengthPathTask

    Details

      Description

      There appears to be a deadlock around QueryLog.log() and ChunkedRunningQuery.getQueueStats().

      1LKDEADLOCK    Deadlock detected !!!
      NULL           ---------------------
      NULL           
      2LKDEADLOCKTHR  Thread "com.bigdata.journal.Journal.executorService3" (0x0000000000D78D00)
      3LKDEADLOCKWTR    is waiting for:
      4LKDEADLOCKMON      sys_mon_t:0x00007F9C50201F98 infl_mon_t: 0x00007F9C50202010:
      4LKDEADLOCKOBJ      java/lang/StringBuilder@0x00000007D9C9B678
      3LKDEADLOCKOWN    which is owned by:
      2LKDEADLOCKTHR  Thread "class com.bigdata.bop.engine.QueryEngine.engineService1" (0x0000000000D18700)
      3LKDEADLOCKWTR    which is waiting for:
      4LKDEADLOCKOBJ      java/util/concurrent/locks/ReentrantLock$NonfairSync@0x00000006890058A0
      3LKDEADLOCKOWN    which is owned by:
      2LKDEADLOCKTHR  Thread "com.bigdata.journal.Journal.executorService3" (0x0000000000D78D00)
      
      3XMTHREADINFO      "com.bigdata.journal.Journal.executorService6" J9VMThread:0x0000000000D81E00, j9thread_t:0x00007F9C5692EFE0, java/lang/Thread:0x0000000688FAE068, state:P, prio=5
      3XMJAVALTHREAD            (java/lang/Thread getId:0x47, isDaemon:true)
      3XMTHREADINFO1            (native thread ID:0x38F2, native priority:0x5, native policy:UNKNOWN)
      3XMTHREADINFO2            (native stack address range from:0x00007F9C2EF6E000, to:0x00007F9C2EFAF000, size:0x41000)
      3XMCPUTIME               CPU usage total: 24.768194700 secs
      3XMTHREADBLOCK     Parked on: java/util/concurrent/locks/ReentrantLock$NonfairSync@0x00000006890058A0 Owned by: "com.bigdata.journal.Journal.executorService3" (J9VMThread:0x0000000000D78D00, java/lang/Thread:0x0000000688FAE1A0)
      3XMHEAPALLOC             Heap bytes allocated since last GC cycle=0 (0x0)
      3XMTHREADINFO3           Java callstack:
      4XESTACKTRACE                at sun/misc/Unsafe.park(Native Method)
      4XESTACKTRACE                at java/util/concurrent/locks/LockSupport.park(LockSupport.java:197)
      4XESTACKTRACE                at java/util/concurrent/locks/AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:845(Compiled Code))
      4XESTACKTRACE                at java/util/concurrent/locks/AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:878(Compiled Code))
      4XESTACKTRACE                at java/util/concurrent/locks/AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1208(Compiled Code))
      4XESTACKTRACE                at java/util/concurrent/locks/ReentrantLock$NonfairSync.lock(ReentrantLock.java:229(Compiled Code))
      4XESTACKTRACE                at java/util/concurrent/locks/ReentrantLock.lock(ReentrantLock.java:305(Compiled Code))
      4XESTACKTRACE                at com/bigdata/bop/engine/ChunkedRunningQuery.haltOp(ChunkedRunningQuery.java:378)
      4XESTACKTRACE                at com/bigdata/bop/engine/ChunkedRunningQuery$SendHaltMessageTask.run(ChunkedRunningQuery.java:1822)
      4XESTACKTRACE                at java/util/concurrent/ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1176)
      4XESTACKTRACE                at java/util/concurrent/ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
      4XESTACKTRACE                at java/lang/Thread.run(Thread.java:795)
      
      3XMTHREADINFO      "com.bigdata.journal.Journal.executorService5" J9VMThread:0x0000000000DC5400, j9thread_t:0x00007F9C5692EA50, java/lang/Thread:0x0000000688FAE0D0, state:P, prio=5
      3XMJAVALTHREAD            (java/lang/Thread getId:0x46, isDaemon:true)
      3XMTHREADINFO1            (native thread ID:0x38F1, native priority:0x5, native policy:UNKNOWN)
      3XMTHREADINFO2            (native stack address range from:0x00007F9C541F1000, to:0x00007F9C54232000, size:0x41000)
      3XMCPUTIME               CPU usage total: 47.481163886 secs
      3XMTHREADBLOCK     Parked on: java/util/concurrent/locks/ReentrantLock$NonfairSync@0x00000006890058A0 Owned by: "com.bigdata.journal.Journal.executorService3" (J9VMThread:0x0000000000D78D00, java/lang/Thread:0x0000000688FAE1A0)
      3XMHEAPALLOC             Heap bytes allocated since last GC cycle=0 (0x0)
      3XMTHREADINFO3           Java callstack:
      4XESTACKTRACE                at sun/misc/Unsafe.park(Native Method)
      4XESTACKTRACE                at java/util/concurrent/locks/LockSupport.park(LockSupport.java:197)
      4XESTACKTRACE                at java/util/concurrent/locks/AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:845(Compiled Code))
      4XESTACKTRACE                at java/util/concurrent/locks/AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:878(Compiled Code))
      4XESTACKTRACE                at java/util/concurrent/locks/AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1208(Compiled Code))
      4XESTACKTRACE                at java/util/concurrent/locks/ReentrantLock$NonfairSync.lock(ReentrantLock.java:229(Compiled Code))
      4XESTACKTRACE                at java/util/concurrent/locks/ReentrantLock.lock(ReentrantLock.java:305(Compiled Code))
      4XESTACKTRACE                at com/bigdata/bop/engine/ChunkedRunningQuery.scheduleNext(ChunkedRunningQuery.java:414)
      4XESTACKTRACE                at com/bigdata/bop/engine/ChunkedRunningQuery.access$300(ChunkedRunningQuery.java:91)
      4XESTACKTRACE                at com/bigdata/bop/engine/ChunkedRunningQuery$ChunkFutureTask.run(ChunkedRunningQuery.java:825)
      4XESTACKTRACE                at java/util/concurrent/ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1176)
      4XESTACKTRACE                at java/util/concurrent/ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
      4XESTACKTRACE                at java/lang/Thread.run(Thread.java:795)
      
      
      3XMTHREADINFO      "com.bigdata.journal.Journal.executorService3" J9VMThread:0x0000000000D78D00, j9thread_t:0x00007F9C565930C0, java/lang/Thread:0x0000000688FAE1A0, state:B, prio=5
      3XMJAVALTHREAD            (java/lang/Thread getId:0x44, isDaemon:true)
      3XMTHREADINFO1            (native thread ID:0x38EF, native priority:0x5, native policy:UNKNOWN)
      3XMTHREADINFO2            (native stack address range from:0x00007F9C54232000, to:0x00007F9C54273000, size:0x41000)
      3XMCPUTIME               CPU usage total: 90.607886143 secs
      3XMTHREADBLOCK     Blocked on: java/lang/StringBuilder@0x00000007D9C9B678 Owned by: "class com.bigdata.bop.engine.QueryEngine.engineService1" (J9VMThread:0x0000000000D18700, java/lang/Thread:0x0000000688FAE270)
      3XMHEAPALLOC             Heap bytes allocated since last GC cycle=0 (0x0)
      3XMTHREADINFO3           Java callstack:
      4XESTACKTRACE                at com/bigdata/bop/engine/QueryLog.log(QueryLog.java:132)
      4XESTACKTRACE                at com/bigdata/bop/engine/AbstractRunningQuery.cancel(AbstractRunningQuery.java:1361)
      4XESTACKTRACE                at com/bigdata/bop/paths/ArbitraryLengthPathOp$ArbitraryLengthPathTask.processChunk(ArbitraryLengthPathOp.java:579(Compiled Code))
      4XESTACKTRACE                at com/bigdata/bop/paths/ArbitraryLengthPathOp$ArbitraryLengthPathTask.call(ArbitraryLengthPathOp.java:277)
      4XESTACKTRACE                at com/bigdata/bop/paths/ArbitraryLengthPathOp$ArbitraryLengthPathTask.call(ArbitraryLengthPathOp.java:202)
      4XESTACKTRACE                at java/util/concurrent/FutureTask.run(FutureTask.java:273)
      4XESTACKTRACE                at com/bigdata/bop/engine/ChunkedRunningQuery$ChunkTask.call(ChunkedRunningQuery.java:1314)
      4XESTACKTRACE                at com/bigdata/bop/engine/ChunkedRunningQuery$ChunkTaskWrapper.run(ChunkedRunningQuery.java:894)
      4XESTACKTRACE                at java/util/concurrent/Executors$RunnableAdapter.call(Executors.java:482)
      4XESTACKTRACE                at java/util/concurrent/FutureTask.run(FutureTask.java:273)
      4XESTACKTRACE                at com/bigdata/concurrent/FutureTaskMon.run(FutureTaskMon.java:63)
      4XESTACKTRACE                at com/bigdata/bop/engine/ChunkedRunningQuery$ChunkFutureTask.run(ChunkedRunningQuery.java:789)
      4XESTACKTRACE                at java/util/concurrent/ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1176)
      4XESTACKTRACE                at java/util/concurrent/ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
      4XESTACKTRACE                at java/lang/Thread.run(Thread.java:795)
      
      
      3XMTHREADINFO      "class com.bigdata.bop.engine.QueryEngine.engineService1" J9VMThread:0x0000000000D18700, j9thread_t:0x00007F9C566DB1A0, java/lang/Thread:0x0000000688FAE270, state:P, prio=5
      3XMJAVALTHREAD            (java/lang/Thread getId:0x42, isDaemon:true)
      3XMTHREADINFO1            (native thread ID:0x38ED, native priority:0x5, native policy:UNKNOWN)
      3XMTHREADINFO2            (native stack address range from:0x00007F9C2EFF0000, to:0x00007F9C2F031000, size:0x41000)
      3XMCPUTIME               CPU usage total: 0.084981409 secs
      3XMTHREADBLOCK     Parked on: java/util/concurrent/locks/ReentrantLock$NonfairSync@0x00000006890058A0 Owned by: "com.bigdata.journal.Journal.executorService3" (J9VMThread:0x0000000000D78D00, java/lang/Thread:0x0000000688FAE1A0)
      3XMHEAPALLOC             Heap bytes allocated since last GC cycle=0 (0x0)
      3XMTHREADINFO3           Java callstack:
      4XESTACKTRACE                at sun/misc/Unsafe.park(Native Method)
      4XESTACKTRACE                at java/util/concurrent/locks/LockSupport.park(LockSupport.java:197)
      4XESTACKTRACE                at java/util/concurrent/locks/AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:845(Compiled Code))
      4XESTACKTRACE                at java/util/concurrent/locks/AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:878(Compiled Code))
      4XESTACKTRACE                at java/util/concurrent/locks/AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1208(Compiled Code))
      4XESTACKTRACE                at java/util/concurrent/locks/ReentrantLock$NonfairSync.lock(ReentrantLock.java:229(Compiled Code))
      4XESTACKTRACE                at java/util/concurrent/locks/ReentrantLock.lock(ReentrantLock.java:305(Compiled Code))
      4XESTACKTRACE                at com/bigdata/jsr166/LinkedBlockingDeque.toArray(LinkedBlockingDeque.java:952)
      4XESTACKTRACE                at com/bigdata/bop/engine/ChunkedRunningQuery.getQueueStats(ChunkedRunningQuery.java:1923)
      4XESTACKTRACE                at com/bigdata/bop/engine/QueryLog.log(QueryLog.java:152)
      5XESTACKTRACE                   (entered lock: java/lang/StringBuilder@0x00000007D9C9B678, entry count: 1)
      4XESTACKTRACE                at com/bigdata/bop/engine/AbstractRunningQuery.cancel(AbstractRunningQuery.java:1361)
      4XESTACKTRACE                at com/bigdata/bop/engine/AbstractRunningQuery.halt(AbstractRunningQuery.java:1273)
      4XESTACKTRACE                at com/bigdata/bop/engine/AbstractRunningQuery.checkDeadline(AbstractRunningQuery.java:374)
      4XESTACKTRACE                at com/bigdata/bop/engine/QueryDeadline.checkDeadline(QueryDeadline.java:99)
      4XESTACKTRACE                at com/bigdata/bop/engine/QueryEngine.checkHeadOfDeadlineQueue(QueryEngine.java:723(Compiled Code))
      4XESTACKTRACE                at com/bigdata/bop/engine/QueryEngine.checkDeadlines(QueryEngine.java:694)
      5XESTACKTRACE                   (entered lock: java/util/concurrent/PriorityBlockingQueue@0x0000000688FF2220, entry count: 1)
      4XESTACKTRACE                at com/bigdata/bop/engine/QueryEngine.access$100(QueryEngine.java:209)
      4XESTACKTRACE                at com/bigdata/bop/engine/QueryEngine$QueryEngineTask.run(QueryEngine.java:965)
      4XESTACKTRACE                at java/util/concurrent/Executors$RunnableAdapter.call(Executors.java:482)
      4XESTACKTRACE                at java/util/concurrent/FutureTask.run(FutureTask.java:273)
      4XESTACKTRACE                at com/bigdata/concurrent/FutureTaskMon.run(FutureTaskMon.java:63)
      4XESTACKTRACE                at java/util/concurrent/ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1176)
      4XESTACKTRACE                at java/util/concurrent/ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
      4XESTACKTRACE                at java/lang/Thread.run(Thread.java:795)
      

        Activity

        Hide
        bryanthompson bryanthompson added a comment -

        Fix for BLZG-1051 (deadlock in QueryLog.log()).

        Note: The static StringBuilder can not be used if the parent query has child subqueries without running into a deadlock on the [sb] object. If there are no children, we could reuse the global static [sb] and the AbstractRunningQuery.lock().

        However, log(IRunningQuery) is ONLY invoke by AbstractRunningQuery.cancel() and then only runs IFF QueryLog is @ INFO. Since this is a rare combination, allocating a new StringBuilder object here will not have an adverse impact on the heap and avoids the possibility of a deadlock.

        Committed revision r8565.

        Show
        bryanthompson bryanthompson added a comment - Fix for BLZG-1051 (deadlock in QueryLog.log()). Note: The static StringBuilder can not be used if the parent query has child subqueries without running into a deadlock on the [sb] object. If there are no children, we could reuse the global static [sb] and the AbstractRunningQuery.lock(). However, log(IRunningQuery) is ONLY invoke by AbstractRunningQuery.cancel() and then only runs IFF QueryLog is @ INFO. Since this is a rare combination, allocating a new StringBuilder object here will not have an adverse impact on the heap and avoids the possibility of a deadlock. Committed revision r8565.

          People

          • Assignee:
            bryanthompson bryanthompson
            Reporter:
            bryanthompson bryanthompson
          • Votes:
            0 Vote for this issue
            Watchers:
            0 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved: