Lucene - Core
  1. Lucene - Core
  2. LUCENE-3339

TestNRTThreads hangs in nightly 3.x builds

    Details

    • Type: Bug Bug
    • Status: Closed
    • Priority: Major Major
    • Resolution: Fixed
    • Affects Version/s: None
    • Fix Version/s: 3.4
    • Component/s: None
    • Labels:
      None
    • Lucene Fields:
      New

      Description

      Maybe we have a problem, maybe its a bug in the test.

      But its strange that lately the 3.x nightlies have been hanging here.

      1. LUCENE-3339.patch
        2 kB
        Michael McCandless

        Activity

        Hide
        Robert Muir added a comment -
        [junit] 2011-07-25 01:41:48
            [junit] Full thread dump OpenJDK 64-Bit Server VM (20.0-b11 mixed mode):
            [junit] 
            [junit] "Thread-120" daemon prio=5 tid=0x0000000801cd8800 nid=0x19492 in Object.wait() [0x00007ffffdfe2000]
            [junit]    java.lang.Thread.State: WAITING (on object monitor)
            [junit] 	at java.lang.Object.wait(Native Method)
            [junit] 	- waiting on <0x000000080a5ccea8> (a org.apache.lucene.index.DocumentsWriter)
            [junit] 	at java.lang.Object.wait(Object.java:502)
            [junit] 	at org.apache.lucene.index.DocumentsWriter.waitForWaitQueue(DocumentsWriter.java:1064)
            [junit] 	- locked <0x000000080a5ccea8> (a org.apache.lucene.index.DocumentsWriter)
            [junit] 	at org.apache.lucene.index.DocumentsWriter.updateDocuments(DocumentsWriter.java:882)
            [junit] 	- locked <0x000000080a5ccea8> (a org.apache.lucene.index.DocumentsWriter)
            [junit] 	at org.apache.lucene.index.IndexWriter.updateDocuments(IndexWriter.java:2164)
            [junit] 	at org.apache.lucene.index.IndexWriter.addDocuments(IndexWriter.java:2122)
            [junit] 	at org.apache.lucene.index.IndexWriter.addDocuments(IndexWriter.java:2106)
            [junit] 	at org.apache.lucene.index.TestNRTThreads$2.run(TestNRTThreads.java:205)
            [junit] 
            [junit] "Thread-119" daemon prio=5 tid=0x0000000801cd9000 nid=0x19410 in Object.wait() [0x00007ffffe0e3000]
            [junit]    java.lang.Thread.State: WAITING (on object monitor)
            [junit] 	at java.lang.Object.wait(Native Method)
            [junit] 	- waiting on <0x000000080a5ccea8> (a org.apache.lucene.index.DocumentsWriter)
            [junit] 	at java.lang.Object.wait(Object.java:502)
            [junit] 	at org.apache.lucene.index.DocumentsWriter.waitForWaitQueue(DocumentsWriter.java:1064)
            [junit] 	- locked <0x000000080a5ccea8> (a org.apache.lucene.index.DocumentsWriter)
            [junit] 	at org.apache.lucene.index.DocumentsWriter.updateDocuments(DocumentsWriter.java:882)
            [junit] 	- locked <0x000000080a5ccea8> (a org.apache.lucene.index.DocumentsWriter)
            [junit] 	at org.apache.lucene.index.IndexWriter.updateDocuments(IndexWriter.java:2164)
            [junit] 	at org.apache.lucene.index.IndexWriter.addDocuments(IndexWriter.java:2122)
            [junit] 	at org.apache.lucene.index.IndexWriter.addDocuments(IndexWriter.java:2106)
            [junit] 	at org.apache.lucene.index.TestNRTThreads$2.run(TestNRTThreads.java:205)
            [junit] 
            [junit] "Low Memory Detector" daemon prio=5 tid=0x0000000801cea800 nid=0x18c7a runnable [0x0000000000000000]
            [junit]    java.lang.Thread.State: RUNNABLE
            [junit] 
            [junit] "C2 CompilerThread1" daemon prio=5 tid=0x0000000801ceb000 nid=0x18c6d waiting on condition [0x0000000000000000]
            [junit]    java.lang.Thread.State: RUNNABLE
            [junit] 
            [junit] "C2 CompilerThread0" daemon prio=5 tid=0x0000000801cec000 nid=0x18c67 waiting on condition [0x0000000000000000]
            [junit]    java.lang.Thread.State: RUNNABLE
            [junit] 
            [junit] "Signal Dispatcher" daemon prio=5 tid=0x0000000801cec800 nid=0x18c65 waiting on condition [0x0000000000000000]
            [junit]    java.lang.Thread.State: RUNNABLE
            [junit] 
            [junit] "Finalizer" daemon prio=5 tid=0x0000000801ced800 nid=0x18c63 in Object.wait() [0x00007ffffebee000]
            [junit]    java.lang.Thread.State: WAITING (on object monitor)
            [junit] 	at java.lang.Object.wait(Native Method)
            [junit] 	- waiting on <0x000000080a3602c0> (a java.lang.ref.ReferenceQueue$Lock)
            [junit] 	at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:133)
            [junit] 	- locked <0x000000080a3602c0> (a java.lang.ref.ReferenceQueue$Lock)
            [junit] 	at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:149)
            [junit] 	at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:177)
            [junit] 
            [junit] "Reference Handler" daemon prio=5 tid=0x0000000801cef000 nid=0x18c60 in Object.wait() [0x00007ffffecef000]
            [junit]    java.lang.Thread.State: WAITING (on object monitor)
            [junit] 	at java.lang.Object.wait(Native Method)
            [junit] 	- waiting on <0x000000080a360360> (a java.lang.ref.Reference$Lock)
            [junit] 	at java.lang.Object.wait(Object.java:502)
            [junit] 	at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:133)
            [junit] 	- locked <0x000000080a360360> (a java.lang.ref.Reference$Lock)
            [junit] 
            [junit] "main" prio=5 tid=0x0000000801cef800 nid=0x18bfa in Object.wait() [0x00007fffffbfd000]
            [junit]    java.lang.Thread.State: WAITING (on object monitor)
            [junit] 	at java.lang.Object.wait(Native Method)
            [junit] 	- waiting on <0x000000080a5ccea8> (a org.apache.lucene.index.DocumentsWriter)
            [junit] 	at java.lang.Object.wait(Object.java:502)
            [junit] 	at org.apache.lucene.index.DocumentsWriter.waitIdle(DocumentsWriter.java:987)
            [junit] 	- locked <0x000000080a5ccea8> (a org.apache.lucene.index.DocumentsWriter)
            [junit] 	at org.apache.lucene.index.DocumentsWriter.flush(DocumentsWriter.java:525)
            [junit] 	- locked <0x000000080a5ccea8> (a org.apache.lucene.index.DocumentsWriter)
            [junit] 	at org.apache.lucene.index.IndexWriter.doFlush(IndexWriter.java:3547)
            [junit] 	- locked <0x000000080a5ccf38> (a org.apache.lucene.index.IndexWriter)
            [junit] 	at org.apache.lucene.index.IndexWriter.flush(IndexWriter.java:3512)
            [junit] 	at org.apache.lucene.index.IndexWriter.getReader(IndexWriter.java:459)
            [junit] 	- locked <0x000000080a5ccf38> (a org.apache.lucene.index.IndexWriter)
            [junit] 	at org.apache.lucene.index.IndexWriter.getReader(IndexWriter.java:408)
            [junit] 	at org.apache.lucene.index.IndexReader.open(IndexReader.java:304)
            [junit] 	at org.apache.lucene.index.TestNRTThreads.testNRTThreads(TestNRTThreads.java:339)
            [junit] 	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
            [junit] 	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
            [junit] 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
            [junit] 	at java.lang.reflect.Method.invoke(Method.java:616)
            [junit] 	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44)
            [junit] 	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)
            [junit] 	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41)
            [junit] 	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:20)
            [junit] 	at org.junit.rules.TestWatchman$1.evaluate(TestWatchman.java:48)
            [junit] 	at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:28)
            [junit] 	at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:31)
            [junit] 	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:76)
            [junit] 	at org.apache.lucene.util.LuceneTestCase$LuceneTestCaseRunner.runChild(LuceneTestCase.java:1316)
            [junit] 	at org.apache.lucene.util.LuceneTestCase$LuceneTestCaseRunner.runChild(LuceneTestCase.java:1221)
            [junit] 	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:193)
            [junit] 	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:52)
            [junit] 	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:191)
            [junit] 	at org.junit.runners.ParentRunner.access$000(ParentRunner.java:42)
            [junit] 	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:184)
            [junit] 	at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:28)
            [junit] 	at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:31)
            [junit] 	at org.junit.runners.ParentRunner.run(ParentRunner.java:236)
            [junit] 	at junit.framework.JUnit4TestAdapter.run(JUnit4TestAdapter.java:39)
            [junit] 	at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JUnitTestRunner.java:420)
            [junit] 	at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.launch(JUnitTestRunner.java:911)
            [junit] 	at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.main(JUnitTestRunner.java:743)
            [junit] 
            [junit] "VM Thread" prio=5 tid=0x0000000801d27000 nid=0x18c52 runnable 
            [junit] 
            [junit] "GC task thread#0 (ParallelGC)" prio=5 tid=0x0000000801d30000 nid=0x18c0a runnable 
            [junit] 
            [junit] "GC task thread#1 (ParallelGC)" prio=5 tid=0x0000000801d2f000 nid=0x18c11 runnable 
            [junit] 
            [junit] "GC task thread#2 (ParallelGC)" prio=5 tid=0x0000000801d2e800 nid=0x18c16 runnable 
            [junit] 
            [junit] "GC task thread#3 (ParallelGC)" prio=5 tid=0x0000000801d2e000 nid=0x18c18 runnable 
            [junit] 
            [junit] "GC task thread#4 (ParallelGC)" prio=5 tid=0x0000000801d2d800 nid=0x18c19 runnable 
            [junit] 
            [junit] "GC task thread#5 (ParallelGC)" prio=5 tid=0x0000000801d2c800 nid=0x18c1a runnable 
            [junit] 
            [junit] "GC task thread#6 (ParallelGC)" prio=5 tid=0x0000000801d2c000 nid=0x18c20 runnable 
            [junit] 
            [junit] "GC task thread#7 (ParallelGC)" prio=5 tid=0x0000000801d2b800 nid=0x18c23 runnable 
            [junit] 
            [junit] "GC task thread#8 (ParallelGC)" prio=5 tid=0x0000000801d2a800 nid=0x18c25 runnable 
            [junit] 
            [junit] "GC task thread#9 (ParallelGC)" prio=5 tid=0x0000000801d2a000 nid=0x18c3b runnable 
            [junit] 
            [junit] "GC task thread#10 (ParallelGC)" prio=5 tid=0x0000000801d29800 nid=0x18c3c runnable 
            [junit] 
            [junit] "GC task thread#11 (ParallelGC)" prio=5 tid=0x0000000801d29000 nid=0x18c40 runnable 
            [junit] 
            [junit] "GC task thread#12 (ParallelGC)" prio=5 tid=0x0000000801d28000 nid=0x18c42 runnable 
            [junit] 
            [junit] "VM Periodic Task Thread" prio=5 tid=0x0000000801d26800 nid=0x18c81 waiting on condition 
            [junit] 
            [junit] JNI global references: 1449
            [junit] 
            [junit] Heap
            [junit]  PSYoungGen      total 163712K, used 31923K [0x000000081f8c0000, 0x000000082a2e0000, 0x000000082a360000)
            [junit]   eden space 154112K, 17% used [0x000000081f8c0000,0x00000008212d4cc8,0x0000000828f40000)
            [junit]   from space 9600K, 54% used [0x0000000828f40000,0x00000008294581b8,0x00000008298a0000)
            [junit]   to   space 9344K, 0% used [0x00000008299c0000,0x00000008299c0000,0x000000082a2e0000)
            [junit]  PSOldGen        total 70336K, used 42498K [0x000000080a360000, 0x000000080e810000, 0x000000081f8c0000)
            [junit]   object space 70336K, 60% used [0x000000080a360000,0x000000080cce0aa8,0x000000080e810000)
            [junit]  PSPermGen       total 25216K, used 12189K [0x0000000805160000, 0x0000000806a00000, 0x000000080a360000)
            [junit]   object space 25216K, 48% used [0x0000000805160000,0x0000000805d47768,0x0000000806a00000)
        
        Show
        Robert Muir added a comment - [junit] 2011-07-25 01:41:48 [junit] Full thread dump OpenJDK 64-Bit Server VM (20.0-b11 mixed mode): [junit] [junit] "Thread-120" daemon prio=5 tid=0x0000000801cd8800 nid=0x19492 in Object.wait() [0x00007ffffdfe2000] [junit] java.lang.Thread.State: WAITING (on object monitor) [junit] at java.lang.Object.wait(Native Method) [junit] - waiting on <0x000000080a5ccea8> (a org.apache.lucene.index.DocumentsWriter) [junit] at java.lang.Object.wait(Object.java:502) [junit] at org.apache.lucene.index.DocumentsWriter.waitForWaitQueue(DocumentsWriter.java:1064) [junit] - locked <0x000000080a5ccea8> (a org.apache.lucene.index.DocumentsWriter) [junit] at org.apache.lucene.index.DocumentsWriter.updateDocuments(DocumentsWriter.java:882) [junit] - locked <0x000000080a5ccea8> (a org.apache.lucene.index.DocumentsWriter) [junit] at org.apache.lucene.index.IndexWriter.updateDocuments(IndexWriter.java:2164) [junit] at org.apache.lucene.index.IndexWriter.addDocuments(IndexWriter.java:2122) [junit] at org.apache.lucene.index.IndexWriter.addDocuments(IndexWriter.java:2106) [junit] at org.apache.lucene.index.TestNRTThreads$2.run(TestNRTThreads.java:205) [junit] [junit] "Thread-119" daemon prio=5 tid=0x0000000801cd9000 nid=0x19410 in Object.wait() [0x00007ffffe0e3000] [junit] java.lang.Thread.State: WAITING (on object monitor) [junit] at java.lang.Object.wait(Native Method) [junit] - waiting on <0x000000080a5ccea8> (a org.apache.lucene.index.DocumentsWriter) [junit] at java.lang.Object.wait(Object.java:502) [junit] at org.apache.lucene.index.DocumentsWriter.waitForWaitQueue(DocumentsWriter.java:1064) [junit] - locked <0x000000080a5ccea8> (a org.apache.lucene.index.DocumentsWriter) [junit] at org.apache.lucene.index.DocumentsWriter.updateDocuments(DocumentsWriter.java:882) [junit] - locked <0x000000080a5ccea8> (a org.apache.lucene.index.DocumentsWriter) [junit] at org.apache.lucene.index.IndexWriter.updateDocuments(IndexWriter.java:2164) [junit] at org.apache.lucene.index.IndexWriter.addDocuments(IndexWriter.java:2122) [junit] at org.apache.lucene.index.IndexWriter.addDocuments(IndexWriter.java:2106) [junit] at org.apache.lucene.index.TestNRTThreads$2.run(TestNRTThreads.java:205) [junit] [junit] "Low Memory Detector" daemon prio=5 tid=0x0000000801cea800 nid=0x18c7a runnable [0x0000000000000000] [junit] java.lang.Thread.State: RUNNABLE [junit] [junit] "C2 CompilerThread1" daemon prio=5 tid=0x0000000801ceb000 nid=0x18c6d waiting on condition [0x0000000000000000] [junit] java.lang.Thread.State: RUNNABLE [junit] [junit] "C2 CompilerThread0" daemon prio=5 tid=0x0000000801cec000 nid=0x18c67 waiting on condition [0x0000000000000000] [junit] java.lang.Thread.State: RUNNABLE [junit] [junit] "Signal Dispatcher" daemon prio=5 tid=0x0000000801cec800 nid=0x18c65 waiting on condition [0x0000000000000000] [junit] java.lang.Thread.State: RUNNABLE [junit] [junit] "Finalizer" daemon prio=5 tid=0x0000000801ced800 nid=0x18c63 in Object.wait() [0x00007ffffebee000] [junit] java.lang.Thread.State: WAITING (on object monitor) [junit] at java.lang.Object.wait(Native Method) [junit] - waiting on <0x000000080a3602c0> (a java.lang.ref.ReferenceQueue$Lock) [junit] at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:133) [junit] - locked <0x000000080a3602c0> (a java.lang.ref.ReferenceQueue$Lock) [junit] at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:149) [junit] at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:177) [junit] [junit] "Reference Handler" daemon prio=5 tid=0x0000000801cef000 nid=0x18c60 in Object.wait() [0x00007ffffecef000] [junit] java.lang.Thread.State: WAITING (on object monitor) [junit] at java.lang.Object.wait(Native Method) [junit] - waiting on <0x000000080a360360> (a java.lang.ref.Reference$Lock) [junit] at java.lang.Object.wait(Object.java:502) [junit] at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:133) [junit] - locked <0x000000080a360360> (a java.lang.ref.Reference$Lock) [junit] [junit] "main" prio=5 tid=0x0000000801cef800 nid=0x18bfa in Object.wait() [0x00007fffffbfd000] [junit] java.lang.Thread.State: WAITING (on object monitor) [junit] at java.lang.Object.wait(Native Method) [junit] - waiting on <0x000000080a5ccea8> (a org.apache.lucene.index.DocumentsWriter) [junit] at java.lang.Object.wait(Object.java:502) [junit] at org.apache.lucene.index.DocumentsWriter.waitIdle(DocumentsWriter.java:987) [junit] - locked <0x000000080a5ccea8> (a org.apache.lucene.index.DocumentsWriter) [junit] at org.apache.lucene.index.DocumentsWriter.flush(DocumentsWriter.java:525) [junit] - locked <0x000000080a5ccea8> (a org.apache.lucene.index.DocumentsWriter) [junit] at org.apache.lucene.index.IndexWriter.doFlush(IndexWriter.java:3547) [junit] - locked <0x000000080a5ccf38> (a org.apache.lucene.index.IndexWriter) [junit] at org.apache.lucene.index.IndexWriter.flush(IndexWriter.java:3512) [junit] at org.apache.lucene.index.IndexWriter.getReader(IndexWriter.java:459) [junit] - locked <0x000000080a5ccf38> (a org.apache.lucene.index.IndexWriter) [junit] at org.apache.lucene.index.IndexWriter.getReader(IndexWriter.java:408) [junit] at org.apache.lucene.index.IndexReader.open(IndexReader.java:304) [junit] at org.apache.lucene.index.TestNRTThreads.testNRTThreads(TestNRTThreads.java:339) [junit] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [junit] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) [junit] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [junit] at java.lang.reflect.Method.invoke(Method.java:616) [junit] at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44) [junit] at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15) [junit] at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41) [junit] at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:20) [junit] at org.junit.rules.TestWatchman$1.evaluate(TestWatchman.java:48) [junit] at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:28) [junit] at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:31) [junit] at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:76) [junit] at org.apache.lucene.util.LuceneTestCase$LuceneTestCaseRunner.runChild(LuceneTestCase.java:1316) [junit] at org.apache.lucene.util.LuceneTestCase$LuceneTestCaseRunner.runChild(LuceneTestCase.java:1221) [junit] at org.junit.runners.ParentRunner$3.run(ParentRunner.java:193) [junit] at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:52) [junit] at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:191) [junit] at org.junit.runners.ParentRunner.access$000(ParentRunner.java:42) [junit] at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:184) [junit] at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:28) [junit] at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:31) [junit] at org.junit.runners.ParentRunner.run(ParentRunner.java:236) [junit] at junit.framework.JUnit4TestAdapter.run(JUnit4TestAdapter.java:39) [junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JUnitTestRunner.java:420) [junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.launch(JUnitTestRunner.java:911) [junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.main(JUnitTestRunner.java:743) [junit] [junit] "VM Thread" prio=5 tid=0x0000000801d27000 nid=0x18c52 runnable [junit] [junit] "GC task thread#0 (ParallelGC)" prio=5 tid=0x0000000801d30000 nid=0x18c0a runnable [junit] [junit] "GC task thread#1 (ParallelGC)" prio=5 tid=0x0000000801d2f000 nid=0x18c11 runnable [junit] [junit] "GC task thread#2 (ParallelGC)" prio=5 tid=0x0000000801d2e800 nid=0x18c16 runnable [junit] [junit] "GC task thread#3 (ParallelGC)" prio=5 tid=0x0000000801d2e000 nid=0x18c18 runnable [junit] [junit] "GC task thread#4 (ParallelGC)" prio=5 tid=0x0000000801d2d800 nid=0x18c19 runnable [junit] [junit] "GC task thread#5 (ParallelGC)" prio=5 tid=0x0000000801d2c800 nid=0x18c1a runnable [junit] [junit] "GC task thread#6 (ParallelGC)" prio=5 tid=0x0000000801d2c000 nid=0x18c20 runnable [junit] [junit] "GC task thread#7 (ParallelGC)" prio=5 tid=0x0000000801d2b800 nid=0x18c23 runnable [junit] [junit] "GC task thread#8 (ParallelGC)" prio=5 tid=0x0000000801d2a800 nid=0x18c25 runnable [junit] [junit] "GC task thread#9 (ParallelGC)" prio=5 tid=0x0000000801d2a000 nid=0x18c3b runnable [junit] [junit] "GC task thread#10 (ParallelGC)" prio=5 tid=0x0000000801d29800 nid=0x18c3c runnable [junit] [junit] "GC task thread#11 (ParallelGC)" prio=5 tid=0x0000000801d29000 nid=0x18c40 runnable [junit] [junit] "GC task thread#12 (ParallelGC)" prio=5 tid=0x0000000801d28000 nid=0x18c42 runnable [junit] [junit] "VM Periodic Task Thread" prio=5 tid=0x0000000801d26800 nid=0x18c81 waiting on condition [junit] [junit] JNI global references: 1449 [junit] [junit] Heap [junit] PSYoungGen total 163712K, used 31923K [0x000000081f8c0000, 0x000000082a2e0000, 0x000000082a360000) [junit] eden space 154112K, 17% used [0x000000081f8c0000,0x00000008212d4cc8,0x0000000828f40000) [junit] from space 9600K, 54% used [0x0000000828f40000,0x00000008294581b8,0x00000008298a0000) [junit] to space 9344K, 0% used [0x00000008299c0000,0x00000008299c0000,0x000000082a2e0000) [junit] PSOldGen total 70336K, used 42498K [0x000000080a360000, 0x000000080e810000, 0x000000081f8c0000) [junit] object space 70336K, 60% used [0x000000080a360000,0x000000080cce0aa8,0x000000080e810000) [junit] PSPermGen total 25216K, used 12189K [0x0000000805160000, 0x0000000806a00000, 0x000000080a360000) [junit] object space 25216K, 48% used [0x0000000805160000,0x0000000805d47768,0x0000000806a00000)
        Hide
        Michael McCandless added a comment -

        Patch attached.

        I can't repro this locally, but I think I see the problem: the bulk-add (IW.add/updateDocuments) methods cannot pause for the wait queue until after all docs in the block are added. Else, 2 threads could get only partway through their block and both would then pause and never resume.

        This does not affect trunk because w/ DWPT we no longer have the waitQueue.

        The fix is simple: move the pausing out of the loop. I'll commit shortly.

        Show
        Michael McCandless added a comment - Patch attached. I can't repro this locally, but I think I see the problem: the bulk-add (IW.add/updateDocuments) methods cannot pause for the wait queue until after all docs in the block are added. Else, 2 threads could get only partway through their block and both would then pause and never resume. This does not affect trunk because w/ DWPT we no longer have the waitQueue. The fix is simple: move the pausing out of the loop. I'll commit shortly.
        Hide
        Michael McCandless added a comment -

        Nightly build hung again...

        Show
        Michael McCandless added a comment - Nightly build hung again...
        Hide
        Michael McCandless added a comment -

        OK last fix wasn't quite right: we have to re-check whether or not to pause after the loop ends, and it must be inside sync block.

        I'll leave this open until we see that this no longer hangs in nightly build...

        Show
        Michael McCandless added a comment - OK last fix wasn't quite right: we have to re-check whether or not to pause after the loop ends, and it must be inside sync block. I'll leave this open until we see that this no longer hangs in nightly build...
        Hide
        Olve Sæther Hansen added a comment -

        I am testing Lucene for my project now, and it seems that I run into this (or something like this) in 3.3.0. I try to index three different sources concurrently and all three processes get stuck here.

        The indexation happens as cause of a scheduled event, and at startup time I try to debug and since my breakpoints synchronize the events, they continue in perfect sync om my four cores.
        I do not see that issue when I startup with my breakpoints disabled.

        The stacktrace for my three processes are exactly the same. Is there a workaround for this issue or do I have to wait for 3.5 (that is if it is the same problem)?

        minokWorkerExecutor-1@5444, prio=5, in group 'main', status: 'waiting'
          java.lang.Thread.State: WAITING
        	  at java.lang.Object.wait(Object.java:-1)
        	  at java.lang.Object.wait(Object.java:485)
        	  at org.apache.lucene.index.DocumentsWriter.waitForWaitQueue(DocumentsWriter.java:1057)
        	  at org.apache.lucene.index.DocumentsWriter.updateDocuments(DocumentsWriter.java:875)
        	  at org.apache.lucene.index.IndexWriter.updateDocuments(IndexWriter.java:2163)
        	  at org.apache.lucene.index.IndexWriter.addDocuments(IndexWriter.java:2121)
        	  at org.apache.lucene.index.IndexWriter.addDocuments(IndexWriter.java:2105)
        
        Show
        Olve Sæther Hansen added a comment - I am testing Lucene for my project now, and it seems that I run into this (or something like this) in 3.3.0. I try to index three different sources concurrently and all three processes get stuck here. The indexation happens as cause of a scheduled event, and at startup time I try to debug and since my breakpoints synchronize the events, they continue in perfect sync om my four cores. I do not see that issue when I startup with my breakpoints disabled. The stacktrace for my three processes are exactly the same. Is there a workaround for this issue or do I have to wait for 3.5 (that is if it is the same problem)? minokWorkerExecutor-1@5444, prio=5, in group 'main', status: 'waiting' java.lang. Thread .State: WAITING at java.lang. Object .wait( Object .java:-1) at java.lang. Object .wait( Object .java:485) at org.apache.lucene.index.DocumentsWriter.waitForWaitQueue(DocumentsWriter.java:1057) at org.apache.lucene.index.DocumentsWriter.updateDocuments(DocumentsWriter.java:875) at org.apache.lucene.index.IndexWriter.updateDocuments(IndexWriter.java:2163) at org.apache.lucene.index.IndexWriter.addDocuments(IndexWriter.java:2121) at org.apache.lucene.index.IndexWriter.addDocuments(IndexWriter.java:2105)
        Hide
        Simon Willnauer added a comment -

        mike did we hang on 3.x since your last commit? can we close this?

        Show
        Simon Willnauer added a comment - mike did we hang on 3.x since your last commit? can we close this?
        Hide
        Michael McCandless added a comment -

        Olve, which version of Lucene are you seeing deadlock in? This was fixed in 3.4.0.

        Show
        Michael McCandless added a comment - Olve, which version of Lucene are you seeing deadlock in? This was fixed in 3.4.0.
        Hide
        Michael McCandless added a comment -

        Simon, yes I think so; I believe this was fixed in 3.4.0.

        Show
        Michael McCandless added a comment - Simon, yes I think so; I believe this was fixed in 3.4.0.

          People

          • Assignee:
            Michael McCandless
            Reporter:
            Robert Muir
          • Votes:
            0 Vote for this issue
            Watchers:
            1 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved:

              Development