JDK-8293824 : gc/whitebox/TestConcMarkCycleWB.java failed "RuntimeException: assertTrue: expected true, was false"
  • Type: Bug
  • Component: hotspot
  • Sub-Component: gc
  • Affected Version: 20
  • Priority: P2
  • Status: Resolved
  • Resolution: Fixed
  • OS: windows
  • CPU: x86_64
  • Submitted: 2022-09-14
  • Updated: 2023-01-09
  • Resolved: 2023-01-04
The Version table provides details related to the release that this issue/RFE will be addressed.

Unresolved : Release in which this issue/RFE will be addressed.
Resolved: Release in which this issue/RFE has been resolved.
Fixed : Release in which this issue/RFE has been fixed. The release containing this fix may be available for download as an Early Access Release or a General Availability Release.

To download the current JDK release, click here.
JDK 20 JDK 21
20 b30Fixed 21Fixed
Related Reports
Relates :  
JDK-8290025 - Remove the Sweeper
Relates :  
JDK-8299701 - Remove unused GCCause::_wb_conc_mark
Description
The following test failed in the JDK20 CI:

gc/whitebox/TestConcMarkCycleWB.java

Here's a snippet from the log file:

#section:main
----------messages:(7/669)----------
command: main -Xbootclasspath/a:. -XX:+UnlockDiagnosticVMOptions -XX:+WhiteBoxAPI -XX:+UseG1GC gc.whitebox.TestConcMarkCycleWB
reason: User specified action: run main/othervm -Xbootclasspath/a:. -XX:+UnlockDiagnosticVMOptions -XX:+WhiteBoxAPI -XX:+UseG1GC gc.whitebox.TestConcMarkCycleWB 
started: Wed Sep 14 19:31:11 UTC 2022
Mode: othervm [/othervm specified]
Additional options from @modules: --add-modules java.base,java.compiler,java.management,jdk.internal.jvmstat --add-exports java.base/jdk.internal.misc=ALL-UNNAMED --add-exports jdk.internal.jvmstat/sun.jvmstat.monitor=ALL-UNNAMED
finished: Wed Sep 14 19:32:50 UTC 2022
elapsed time (seconds): 99.148
----------configuration:(5/230)----------
Boot Layer
  add modules: java.base java.compiler java.management jdk.internal.jvmstat 
  add exports: java.base/jdk.internal.misc              ALL-UNNAMED
               jdk.internal.jvmstat/sun.jvmstat.monitor ALL-UNNAMED

----------System.out:(0/0)----------
----------System.err:(14/858)----------
java.lang.RuntimeException: assertTrue: expected true, was false
	at jdk.test.lib.Asserts.fail(Asserts.java:594)
	at jdk.test.lib.Asserts.assertTrue(Asserts.java:486)
	at jdk.test.lib.Asserts.assertTrue(Asserts.java:472)
	at gc.whitebox.TestConcMarkCycleWB.main(TestConcMarkCycleWB.java:49)
	at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:104)
	at java.base/java.lang.reflect.Method.invoke(Method.java:578)
	at com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:125)
	at java.base/java.lang.Thread.run(Thread.java:1589)

JavaTest Message: Test threw exception: java.lang.RuntimeException: assertTrue: expected true, was false
Comments
Changeset: b743519b Author: Kim Barrett <kbarrett@openjdk.org> Date: 2023-01-04 03:28:31 +0000 URL: https://git.openjdk.org/jdk20/commit/b743519ba911a254669fa8a96e6006c14e3f5ad1
04-01-2023
A pull request was submitted for review. URL: https://git.openjdk.org/jdk20/pull/71 Date: 2022-12-22 02:04:30 +0000
22-12-2022
A pull request was submitted for review. URL: https://git.openjdk.org/jdk/pull/11435 Date: 2022-11-30 16:40:19 +0000
30-11-2022
Easily reproduced by adding a call to wb.g1StartConcMarkCycle() at the beginning of the test. So a test bug, as it isn't resiliant to the situation where a cycle is already in progress because of some ongoing background work. Adding noreg-self to take this out of the JDK 20 exit criteria. I'm going to review uses of that function to figure out whether it really should return false when a cycle is already in progress, or should do something else like (wait and) start a new cycle. Maybe it can also be reimplemented using the concurrent GC control API, eliminating a whitebox entry point.
09-11-2022
The failure indicates WhiteBox.g1StartConcMarkCycle returned false. That function returns true unless there was already a concurrent mark cycle in progress. The failure is with -Xcomp, so there's more background stuff happening than usual. This is also soon after the removal of the sweeper (JDK-8290025). This could be a test bug, with the test needing to ensure it's not already in a concurrent cycle. (Though how does one do that without concern that the answer could change immediately after the asking, due to background activity.) Alternatively, perhaps something has recently changed leading to more aggressive (perhaps excessively so) running of concurrent cycles?
16-09-2022
Probably related to JDK-8290025. GC took over the code cache sweeper, which means that particularly with -Xcomp there will be more possibly unexpected marking cycles.
16-09-2022
Spotted in the jdk-20+15-1005-tier7 CI job set: gc/whitebox/TestConcMarkCycleWB.java https://mach5.us.oracle.com/mdash/jobs/mach5-one-jdk-20+15-1005-tier7-20220914-1759-36486937/tasks/mach5-one-jdk-20+15-1005-tier7-20220914-1759-36486937-tier7-comp-open_test_hotspot_jtreg_hotspot_gc-windows-x64-debug-37/results?search=status%3Afailed%20AND%20-state%3Ainvalid https://mach5.us.oracle.com:10060/api/v1/results/mach5-one-jdk-20+15-1005-tier7-20220914-1759-36486937-tier7-comp-open_test_hotspot_jtreg_hotspot_gc-windows-x64-debug-37-1663184457-255/log windows-x64-debug: win2019-x64-414726.s4.javaplatfo1iad.oraclevcn.com The test task's JVM args are: -Xcomp -XX:+CreateCoredumpOnCrash -ea -esa -XX:CompileThreshold=100 -XX:+UnlockExperimentalVMOptions -server -XX:-TieredCompilation -XX:-DoEscapeAnalysis
14-09-2022