-
Bug
-
Resolution: Fixed
-
P3
-
8-shenandoah, 11.0.9, 15, 16
-
b24
(synopsis is provisional)
Seems to happen only with release bits and Shenandoah. I think the tests tries to find "Concurrent weak roots" line before "Uncleaned items:0" line. It is either a test bug, or Shenandoah reports something incorrectly.
$ CONF=linux-x86_64-server-release make run-test TEST=runtime/stringtable/StringTableCleaningTest.java TEST_VM_OPTS="-XX:+UseShenandoahGC"
--- Output check failed: 0 -----
[0.001s][info][gc] Min heap equals to max heap, disabling ShenandoahUncommit
[0.002s][info][gc] Using Shenandoah
[0.003s][info][gc] Heuristics ergonomically sets -XX:+ExplicitGCInvokesConcurrent
[0.003s][info][gc] Heuristics ergonomically sets -XX:+ShenandoahImplicitGCInvokesConcurrent
[0.003s][trace][stringtable] Start size: 65536 (16)
[11.008s][debug][stringtable] Table imbalanced, rehashing called.
[11.008s][debug][stringtable] Choosing growing over rehashing.
[11.008s][debug][stringtable,perf] Concurrent work, live factor: 53.4117
[11.009s][trace][stringtable ] Started to grow
[12.020s][debug][stringtable ] Table imbalanced, rehashing called.
[12.020s][debug][stringtable ] Choosing growing over rehashing.
[12.381s][info ][gc ] Trigger: Learning 1 of 5. Free (716M) is below initial threshold (716M)
[12.381s][info ][gc,start ] GC(0) Concurrent reset
[12.383s][info ][gc ] GC(0) Concurrent reset 1.940ms
[12.396s][debug][stringtable ] Table imbalanced, rehashing called.
[12.397s][debug][stringtable ] Choosing growing over rehashing.
[12.397s][info ][gc,start ] GC(0) Pause Init Mark (unload classes)
[12.398s][info ][gc ] GC(0) Pause Init Mark (unload classes) 1.595ms
[12.398s][info ][gc,start ] GC(0) Concurrent marking (unload classes)
[12.854s][info ][gc ] GC(0) Concurrent marking (unload classes) 456.073ms
[12.862s][debug][stringtable ] Table imbalanced, rehashing called.
[12.862s][debug][stringtable ] Choosing growing over rehashing.
[12.862s][info ][gc,start ] GC(0) Pause Final Mark (unload classes)
[12.862s][trace][stringtable ] Uncleaned items:0
[12.862s][info ][gc ] GC(0) Pause Final Mark (unload classes) 0.510ms
...
STDERR:
java.lang.RuntimeException: Callback without Start: 23
at runtime.stringtable.StringTableCleaningTest.fail(StringTableCleaningTest.java:67)
at runtime.stringtable.StringTableCleaningTest.findStart(StringTableCleaningTest.java:163)
at runtime.stringtable.StringTableCleaningTest.check(StringTableCleaningTest.java:210)
at runtime.stringtable.StringTableCleaningTest.checkOutput(StringTableCleaningTest.java:224)
at runtime.stringtable.StringTableCleaningTest.main(StringTableCleaningTest.java:63)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:64)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:564)
at com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:127)
at java.base/java.lang.Thread.run(Thread.java:831)
Seems to happen only with release bits and Shenandoah. I think the tests tries to find "Concurrent weak roots" line before "Uncleaned items:0" line. It is either a test bug, or Shenandoah reports something incorrectly.
$ CONF=linux-x86_64-server-release make run-test TEST=runtime/stringtable/StringTableCleaningTest.java TEST_VM_OPTS="-XX:+UseShenandoahGC"
--- Output check failed: 0 -----
[0.001s][info][gc] Min heap equals to max heap, disabling ShenandoahUncommit
[0.002s][info][gc] Using Shenandoah
[0.003s][info][gc] Heuristics ergonomically sets -XX:+ExplicitGCInvokesConcurrent
[0.003s][info][gc] Heuristics ergonomically sets -XX:+ShenandoahImplicitGCInvokesConcurrent
[0.003s][trace][stringtable] Start size: 65536 (16)
[11.008s][debug][stringtable] Table imbalanced, rehashing called.
[11.008s][debug][stringtable] Choosing growing over rehashing.
[11.008s][debug][stringtable,perf] Concurrent work, live factor: 53.4117
[11.009s][trace][stringtable ] Started to grow
[12.020s][debug][stringtable ] Table imbalanced, rehashing called.
[12.020s][debug][stringtable ] Choosing growing over rehashing.
[12.381s][info ][gc ] Trigger: Learning 1 of 5. Free (716M) is below initial threshold (716M)
[12.381s][info ][gc,start ] GC(0) Concurrent reset
[12.383s][info ][gc ] GC(0) Concurrent reset 1.940ms
[12.396s][debug][stringtable ] Table imbalanced, rehashing called.
[12.397s][debug][stringtable ] Choosing growing over rehashing.
[12.397s][info ][gc,start ] GC(0) Pause Init Mark (unload classes)
[12.398s][info ][gc ] GC(0) Pause Init Mark (unload classes) 1.595ms
[12.398s][info ][gc,start ] GC(0) Concurrent marking (unload classes)
[12.854s][info ][gc ] GC(0) Concurrent marking (unload classes) 456.073ms
[12.862s][debug][stringtable ] Table imbalanced, rehashing called.
[12.862s][debug][stringtable ] Choosing growing over rehashing.
[12.862s][info ][gc,start ] GC(0) Pause Final Mark (unload classes)
[12.862s][trace][stringtable ] Uncleaned items:0
[12.862s][info ][gc ] GC(0) Pause Final Mark (unload classes) 0.510ms
...
STDERR:
java.lang.RuntimeException: Callback without Start: 23
at runtime.stringtable.StringTableCleaningTest.fail(StringTableCleaningTest.java:67)
at runtime.stringtable.StringTableCleaningTest.findStart(StringTableCleaningTest.java:163)
at runtime.stringtable.StringTableCleaningTest.check(StringTableCleaningTest.java:210)
at runtime.stringtable.StringTableCleaningTest.checkOutput(StringTableCleaningTest.java:224)
at runtime.stringtable.StringTableCleaningTest.main(StringTableCleaningTest.java:63)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:64)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:564)
at com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:127)
at java.base/java.lang.Thread.run(Thread.java:831)
- relates to
-
JDK-8255955 Shenandoah: Only STW GC should process concurrent roots at pauses
-
- Resolved
-