IcedTea6 1.8.9 and Zero/Shark

Florian Weimer fw at deneb.enyo.de
Thu Aug 11 10:54:44 PDT 2011 

I'm trying to prepare another security update for Debian.  After
applying the changes from 1.8.9, Debian's Zero/Shark does not build
anymore.  It hangs during testing; jtreg hangs after throwing an
exception:

Exception in thread "ReadAheadIterator1" java.util.NoSuchElementException
	at java.util.LinkedList.remove(LinkedList.java:805)
	at java.util.LinkedList.removeFirst(LinkedList.java:151)
	at com.sun.javatest.TRT_Iterator.nextElement(TRT_Iterator.java:176)
	at com.sun.javatest.TRT_Iterator.next(TRT_Iterator.java:200)
	at com.sun.javatest.util.ReadAheadIterator.readAhead(ReadAheadIterator.java:258)
	at com.sun.javatest.util.ReadAheadIterator.access$000(ReadAheadIterator.java:36)
	at com.sun.javatest.util.ReadAheadIterator$1.run(ReadAheadIterator.java:192)

I managed to get a thread dump from the stuck VM:

Full thread dump OpenJDK 64-Bit Server VM (14.0-b16 mixed mode):

"Timer0" daemon prio=10 tid=0x00002abccc25a000 nid=0x2b16 in Object.wait() [0x00002abccaeb0000]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait(Native Method)
	- waiting on <0x00002abc0ccefaa8> (a com.sun.javatest.util.Timer)
	at java.lang.Object.wait(Object.java:502)
	at com.sun.javatest.util.Timer.getNextEntry(Timer.java:160)
	- locked <0x00002abc0ccefaa8> (a com.sun.javatest.util.Timer)
	at com.sun.javatest.util.Timer.access$000(Timer.java:39)
	at com.sun.javatest.util.Timer$1.run(Timer.java:79)

"DefaultTestRunner:Worker-0:0" prio=10 tid=0x0000000002855000 nid=0x2b14 in Object.wait() [0x00002abccacae000]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait(Native Method)
	- waiting on <0x00002abc0ce04fb8> (a com.sun.javatest.util.ReadAheadIterator)
	at java.lang.Object.wait(Object.java:502)
	at com.sun.javatest.util.ReadAheadIterator.next(ReadAheadIterator.java:206)
	- locked <0x00002abc0ce04fb8> (a com.sun.javatest.util.ReadAheadIterator)
	at com.sun.javatest.Harness$2.next(Harness.java:717)
	at com.sun.javatest.DefaultTestRunner.nextTest(DefaultTestRunner.java:144)
	- locked <0x00002abc0ccefac8> (a com.sun.javatest.DefaultTestRunner)
	at com.sun.javatest.DefaultTestRunner.access$000(DefaultTestRunner.java:43)
	at com.sun.javatest.DefaultTestRunner$1.run(DefaultTestRunner.java:65)

"TestResultCache.worker0[/tmp/buildd/openjdk-6-6b18-1.8.9/build/test/jdk/JTwork]" daemon prio=10 tid=0x00002abccc101800 nid=0x2b13 in Object.wait() [0x00002abccabad000]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
	at java.lang.Object.wait(Native Method)
	- waiting on <0x00002abc0c88ae10> (a com.sun.javatest.TestResultCache)
	at com.sun.javatest.TestResultCache.doWorkUntilDone(TestResultCache.java:245)
	- locked <0x00002abc0c88ae10> (a com.sun.javatest.TestResultCache)
	at com.sun.javatest.TestResultCache.access$000(TestResultCache.java:47)
	at com.sun.javatest.TestResultCache$1.run(TestResultCache.java:138)

"Low Memory Detector" daemon prio=10 tid=0x00002abccc024000 nid=0x2b11 runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"CompilerThread1" daemon prio=10 tid=0x00002abccc020800 nid=0x2b10 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"CompilerThread0" daemon prio=10 tid=0x00002abccc01e800 nid=0x2b0f waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Signal Dispatcher" daemon prio=10 tid=0x00002abccc01c800 nid=0x2b0e waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Finalizer" daemon prio=10 tid=0x00002abccc001000 nid=0x2b0d in Object.wait() [0x00002abcca550000]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait(Native Method)
	- waiting on <0x00002abc0c88e0a8> (a java.lang.ref.ReferenceQueue$Lock)
	at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:133)
	- locked <0x00002abc0c88e0a8> (a java.lang.ref.ReferenceQueue$Lock)
	at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:149)
	at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:177)

"Reference Handler" daemon prio=10 tid=0x0000000001988000 nid=0x2b0c in Object.wait() [0x00002abcca44f000]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait(Native Method)
	- waiting on <0x00002abc0c8880b0> (a java.lang.ref.Reference$Lock)
	at java.lang.Object.wait(Object.java:502)
	at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:133)
	- locked <0x00002abc0c8880b0> (a java.lang.ref.Reference$Lock)

"main" prio=10 tid=0x000000000190c800 nid=0x2b00 in Object.wait() [0x00002abbfdd12000]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait(Native Method)
	- waiting on <0x00002abc0ccefac8> (a com.sun.javatest.DefaultTestRunner)
	at java.lang.Object.wait(Object.java:502)
	at com.sun.javatest.DefaultTestRunner.runTests(DefaultTestRunner.java:84)
	- locked <0x00002abc0ccefac8> (a com.sun.javatest.DefaultTestRunner)
	at com.sun.javatest.Harness.runTests(Harness.java:712)
	at com.sun.javatest.Harness.batch(Harness.java:393)
	at com.sun.javatest.regtest.Main.batchHarness(Main.java:1493)
	at com.sun.javatest.regtest.Main.run(Main.java:823)
	at com.sun.javatest.regtest.Main.run(Main.java:690)
	at com.sun.javatest.regtest.Main.main(Main.java:634)

"VM Thread" prio=10 tid=0x0000000001980000 nid=0x2b0b runnable 

"GC task thread#0 (ParallelGC)" prio=10 tid=0x0000000001917000 nid=0x2b01 runnable 

"GC task thread#1 (ParallelGC)" prio=10 tid=0x0000000001918800 nid=0x2b02 runnable 

"GC task thread#2 (ParallelGC)" prio=10 tid=0x000000000191a800 nid=0x2b03 runnable 

"GC task thread#3 (ParallelGC)" prio=10 tid=0x000000000191c800 nid=0x2b04 runnable 

"GC task thread#4 (ParallelGC)" prio=10 tid=0x000000000191e800 nid=0x2b05 runnable 

"GC task thread#5 (ParallelGC)" prio=10 tid=0x0000000001920000 nid=0x2b06 runnable 

"GC task thread#6 (ParallelGC)" prio=10 tid=0x0000000001922000 nid=0x2b07 runnable 

"GC task thread#7 (ParallelGC)" prio=10 tid=0x0000000001924000 nid=0x2b08 runnable 

"GC task thread#8 (ParallelGC)" prio=10 tid=0x0000000001925800 nid=0x2b09 runnable 

"GC task thread#9 (ParallelGC)" prio=10 tid=0x0000000001927800 nid=0x2b0a runnable 

"VM Periodic Task Thread" prio=10 tid=0x00002abccc026800 nid=0x2b12 waiting on condition 

JNI global references: 699

Heap
 PSYoungGen      total 165952K, used 57866K [0x00002abc89f30000, 0x00002abc945e0000, 0x00002abcc8a80000)
  eden space 161856K, 33% used [0x00002abc89f30000,0x00002abc8d42a880,0x00002abc93d40000)
  from space 4096K, 88% used [0x00002abc94170000,0x00002abc944f8000,0x00002abc94570000)
  to   space 4288K, 0% used [0x00002abc93d40000,0x00002abc93d40000,0x00002abc94170000)
 PSOldGen        total 128448K, used 102042K [0x00002abc0c880000, 0x00002abc145f0000, 0x00002abc89f30000)
  object space 128448K, 79% used [0x00002abc0c880000,0x00002abc12c26bc8,0x00002abc145f0000)
 PSPermGen       total 32192K, used 17998K [0x00002abc02080000, 0x00002abc03ff0000, 0x00002abc0c880000)
  object space 32192K, 55% used [0x00002abc02080000,0x00002abc03213950,0x00002abc03ff0000)

The last test was java/io/InputStreamReader/One.java.  Testing hangs
always at this particular point.  The jtreg invocation leading to this
is:

/tmp/buildd/openjdk-6-6b18-1.8.9/build/bootstrap/jdk1.6.0/bin/java -jar test/jtreg.jar -v1 -a -ignore:quiet -w:test/jdk/JTwork -r:test/jdk/JTreport -othervm -jdk:/tmp/buildd/openjdk-6-6b18-1.8.9/build/openjdk/build/linux-amd64/j2sdk-image -exclude:/tmp/buildd/openjdk-6-6b18-1.8.9/build/../test/jtreg/excludelist.jdk.jtx -vmoption:-zero /tmp/buildd/openjdk-6-6b18-1.8.9/build/openjdk/jdk/test

Come to think of it, the underling issue is probably present in
Debian's older versions, too:

<http://bugs.debian.org/cgi-bin/bugreport.cgi?bug=613098>

So the above stack trace is likely totally misleading.

The mysterious thing is that it's not reproducible on other build
systems.

My build system is an Intel Core i7 X980, which as the following CPU
feature flags:

fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat
pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx
pdpe1gb rdtscp lm constant_tsc arch_perfmon pebs bts rep_good
xtopology nonstop_tsc aperfmperf pni pclmulqdq dtes64 monitor ds_cpl
vmx est tm2 ssse3 cx16 xtpr pdcm sse4_1 sse4_2 popcnt aes lahf_lm ida
arat tpr_shadow vnmi flexpriority ept vpid

Has anybody else seen this?

Does Shark offer CPU-dependent optimizations?  Is there a way to turn
them off?  (Debian squeeze uses llvm 2.7.)

More information about the distro-pkg-dev mailing list