Uploaded image for project: 'JDK'
  1. JDK
  2. JDK-8323066

gc/g1/TestSkipRebuildRemsetPhase.java fails with 'Skipping Remembered Set Rebuild.' missing

    XMLWordPrintable

Details

    • gc
    • b05

    Backports

      Description

        The following test failed in the JDK23 CI:

        gc/g1/TestSkipRebuildRemsetPhase.java

        Here's a snippet from the log file:

        #section:driver
        ----------messages:(7/258)----------
        command: driver gc.g1.TestSkipRebuildRemsetPhase
        reason: User specified action: run driver gc.g1.TestSkipRebuildRemsetPhase
        started: Fri Jan 05 11:16:56 UTC 2024
        Mode: agentvm
        Agent id: 9
        finished: Fri Jan 05 11:16:57 UTC 2024
        elapsed time (seconds): 0.418
        ----------configuration:(14/1870)----------

        <snip>

        ----------System.out:(5/2017)----------
        Command line: [/opt/mach5/mesos/work_dir/jib-master/install/jdk-23+5-209/linux-aarch64-debug.jdk/jdk-23/fastdebug/bin/java -cp /opt/mach5/mesos/work_dir/slaves/6a6709c5-8dd0-4c1a-8549-7a448290c389-S4087/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/46963134-5f49-451d-96b4-0af17157be99/runs/922e5e36-c5c6-45f6-9603-3f333cd4a70c/testoutput/test-support/jtreg_open_test_hotspot_jtreg_tier1_gc_1/classes/1/gc/g1/TestSkipRebuildRemsetPhase.d:/opt/mach5/mesos/work_dir/jib-master/install/jdk-23+5-209/src.full/open/test/hotspot/jtreg/gc/g1:/opt/mach5/mesos/work_dir/slaves/6a6709c5-8dd0-4c1a-8549-7a448290c389-S4087/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/46963134-5f49-451d-96b4-0af17157be99/runs/922e5e36-c5c6-45f6-9603-3f333cd4a70c/testoutput/test-support/jtreg_open_test_hotspot_jtreg_tier1_gc_1/classes/1/test/lib:/opt/mach5/mesos/work_dir/jib-master/install/jtreg/7.3.1/1/bundles/jtreg-7.3.1+1.zip/jtreg/lib/jtreg.jar:/opt/mach5/mesos/work_dir/jib-master/install/jtreg/7.3.1/1/bundles/jtreg-7.3.1+1.zip/jtreg/lib/junit-platform-console-standalone-1.9.2.jar:/opt/mach5/mesos/work_dir/jib-master/install/jtreg/7.3.1/1/bundles/jtreg-7.3.1+1.zip/jtreg/lib/testng-7.3.0.jar:/opt/mach5/mesos/work_dir/jib-master/install/jtreg/7.3.1/1/bundles/jtreg-7.3.1+1.zip/jtreg/lib/jcommander-1.82.jar:/opt/mach5/mesos/work_dir/jib-master/install/jtreg/7.3.1/1/bundles/jtreg-7.3.1+1.zip/jtreg/lib/guice-5.1.0.jar -Xbootclasspath/a:. -XX:+UseG1GC -XX:+UnlockExperimentalVMOptions -XX:+UnlockDiagnosticVMOptions -XX:+WhiteBoxAPI -XX:G1MixedGCLiveThresholdPercent=20 -Xlog:gc+marking=debug,gc+phases=debug,gc+remset+tracking=trace -Xms10M -Xmx10M gc.g1.TestSkipRebuildRemsetPhase$GCTest ]
        [2024-01-05T11:16:57.014543358Z] Gathering output for process 11606
        [2024-01-05T11:16:57.027737409Z] Waiting for completion for process 11606
        [2024-01-05T11:16:57.303702851Z] Waiting for completion finished for process 11606
        Output and diagnostic info for process 11606 was saved into 'pid-11606-output.log'
        ----------System.err:(227/23651)----------
         stdout: [[0.232s][debug][gc,phases] GC(0) Phase 1: Reference Processing 0.153ms
        [0.232s][debug][gc,phases] GC(0) VM Weak Min: 0.00, Avg: 0.00, Max: 0.00, Diff: 0.00, Sum: 0.00, Workers: 1
        [0.232s][debug][gc,phases] GC(0) Dead Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 1
        [0.232s][debug][gc,phases] GC(0) Total Min: 4, Avg: 4.0, Max: 4, Diff: 0, Sum: 4, Workers: 1
        [0.232s][debug][gc,phases] GC(0) ObjectSynchronizer Weak Min: 0.00, Avg: 0.00, Max: 0.00, Diff: 0.00, Sum: 0.00, Workers: 1
        [0.232s][debug][gc,phases] GC(0) Dead Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 1
        [0.232s][debug][gc,phases] GC(0) Total Min: 1, Avg: 1.0, Max: 1, Diff: 0, Sum: 1, Workers: 1
        [0.232s][debug][gc,phases] GC(0) JVMTI Tag Weak OopStorage Min: 0.00, Avg: 0.00, Max: 0.00, Diff: 0.00, Sum: 0.00, Workers: 1
        [0.232s][debug][gc,phases] GC(0) Dead Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 1
        [0.232s][debug][gc,phases] GC(0) Total Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 1
        [0.232s][debug][gc,phases] GC(0) StringTable Weak Min: 0.00, Avg: 0.00, Max: 0.00, Diff: 0.00, Sum: 0.00, Workers: 1
        [0.232s][debug][gc,phases] GC(0) Dead Min: 1, Avg: 1.0, Max: 1, Diff: 0, Sum: 1, Workers: 1
        [0.232s][debug][gc,phases] GC(0) Total Min: 45, Avg: 45.0, Max: 45, Diff: 0, Sum: 45, Workers: 1
        [0.232s][debug][gc,phases] GC(0) ResolvedMethodTable Weak Min: 0.00, Avg: 0.00, Max: 0.00, Diff: 0.00, Sum: 0.00, Workers: 1
        [0.232s][debug][gc,phases] GC(0) Dead Min: 2, Avg: 2.0, Max: 2, Diff: 0, Sum: 2, Workers: 1
        [0.232s][debug][gc,phases] GC(0) Total Min: 50, Avg: 50.0, Max: 50, Diff: 0, Sum: 50, Workers: 1
        [0.232s][debug][gc,phases] GC(0) JNI Weak Min: 0.00, Avg: 0.00, Max: 0.00, Diff: 0.00, Sum: 0.00, Workers: 1
        [0.232s][debug][gc,phases] GC(0) Dead Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 1
        [0.232s][debug][gc,phases] GC(0) Total Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 1
        [0.232s][debug][gc,phases] GC(0) StringDedup Table Weak Min: 0.00, Avg: 0.00, Max: 0.00, Diff: 0.00, Sum: 0.00, Workers: 1
        [0.232s][debug][gc,phases] GC(0) Dead Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 1
        [0.232s][debug][gc,phases] GC(0) Total Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 1
        [0.232s][debug][gc,phases] GC(0) StringDedup Requests0 Weak Min: 0.00, Avg: 0.00, Max: 0.00, Diff: 0.00, Sum: 0.00, Workers: 1
        [0.232s][debug][gc,phases] GC(0) Dead Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 1
        [0.232s][debug][gc,phases] GC(0) Total Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 1
        [0.232s][debug][gc,phases] GC(0) StringDedup Requests1 Weak Min: 0.00, Avg: 0.00, Max: 0.00, Diff: 0.00, Sum: 0.00, Workers: 1
        [0.232s][debug][gc,phases] GC(0) Dead Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 1
        [0.232s][debug][gc,phases] GC(0) Total Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 1
        [0.232s][debug][gc,phases] GC(0) Weak JFR Old Object Samples Min: 0.00, Avg: 0.00, Max: 0.00, Diff: 0.00, Sum: 0.00, Workers: 1
        [0.232s][debug][gc,phases] GC(0) Dead Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 1
        [0.232s][debug][gc,phases] GC(0) Total Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 1
        [0.232s][debug][gc,phases] GC(0) Phase 1: Weak Processing 0.648ms
        [0.232s][debug][gc,phases] GC(0) ClassLoaderData 0.002ms
        [0.232s][debug][gc,phases] GC(0) Trigger cleanups 0.000ms
        [0.233s][debug][gc,phases] GC(0) G1 Complete Cleaning 0.367ms
        [0.233s][debug][gc,phases] GC(0) Purge Unlinked NMethods 0.001ms
        [0.233s][debug][gc,phases] GC(0) Unregister NMethods 0.045ms
        [0.233s][debug][gc,phases] GC(0) Free Code Blobs 0.003ms
        [0.233s][debug][gc,phases] GC(0) Purge Class Loader Data 0.013ms
        [0.233s][debug][gc,phases] GC(0) Phase 1: Class Unloading and Cleanup 0.483ms
        [0.233s][debug][gc,phases] GC(0) Report Object Count 0.001ms
        [0.233s][info ][gc,phases] GC(0) Phase 1: Mark live objects 8.252ms
        [0.233s][debug][gc,phases] GC(0) Phase 2: Determine work lists 0.007ms
        [0.233s][debug][gc,phases] GC(0) Phase 2: Prepare parallel compaction 0.332ms
        [0.233s][info ][gc,phases] GC(0) Phase 2: Prepare compaction 0.368ms
        [0.238s][info ][gc,phases] GC(0) Phase 3: Adjust pointers 4.893ms
        [0.240s][info ][gc,phases] GC(0) Phase 4: Compact heap 2.030ms
        [0.241s][info ][gc,phases] GC(0) Phase 5: Reset Metadata 1.094ms
        [0.243s][info ][gc,phases] GC(1) Pre Evacuate Collection Set: 0.07ms
        [0.243s][debug][gc,phases] GC(1) Reset Marking State (ms): Min: 0.02, Avg: 0.02, Max: 0.02, Diff: 0.00, Sum: 0.02, Workers: 1
        [0.243s][debug][gc,phases] GC(1) Note Start Of Mark (ms): Min: 0.00, Avg: 0.00, Max: 0.00, Diff: 0.00, Sum: 0.00, Workers: 2
        [0.243s][debug][gc,phases] GC(1) Pre Evacuate Prepare: 0.02ms
        [0.243s][debug][gc,phases] GC(1) JT Retire TLABs And Flush Logs (ms): Min: 0.00, Avg: 0.00, Max: 0.00, Diff: 0.00, Sum: 0.00, Workers: 2
        [0.243s][debug][gc,phases] GC(1) Non-JT Flush Logs (ms): Min: 0.00, Avg: 0.00, Max: 0.00, Diff: 0.00, Sum: 0.00, Workers: 1
        [0.243s][debug][gc,phases] GC(1) Choose Collection Set: 0.00ms
        [0.243s][debug][gc,phases] GC(1) Region Register: 0.02ms
        [0.243s][debug][gc,phases] GC(1) Prepare Heap Roots: 0.00ms
        [0.243s][info ][gc,phases] GC(1) Merge Heap Roots: 0.04ms
        [0.243s][debug][gc,phases] GC(1) Prepare Merge Heap Roots: 0.00ms
        [0.243s][debug][gc,phases] GC(1) Remembered Sets (ms): Min: 0.00, Avg: 0.00, Max: 0.00, Diff: 0.00, Sum: 0.00, Workers: 2
        [0.243s][debug][gc,phases] GC(1) Eager Reclaim (ms): skipped
        [0.243s][debug][gc,phases] GC(1) Merged Inline Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 2
        [0.243s][debug][gc,phases] GC(1) Merged ArrayOfCards Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 2
        [0.243s][debug][gc,phases] GC(1) Merged Howl Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 2
        [0.243s][debug][gc,phases] GC(1) Merged Full Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 2
        [0.243s][debug][gc,phases] GC(1) Merged Howl Inline Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 2
        [0.243s][debug][gc,phases] GC(1) Merged Howl ArrayOfCards Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 2
        [0.243s][debug][gc,phases] GC(1) Merged Howl BitMap Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 2
        [0.243s][debug][gc,phases] GC(1) Merged Howl Full Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 2
        [0.243s][debug][gc,phases] GC(1) Merged Cards Min: 16, Avg: 16.0, Max: 16, Diff: 0, Sum: 32, Workers: 2
        [0.243s][debug][gc,phases] GC(1) Log Buffers (ms): Min: 0.00, Avg: 0.00, Max: 0.00, Diff: 0.00, Sum: 0.00, Workers: 2
        [0.243s][debug][gc,phases] GC(1) Dirty Cards: Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 2
        [0.243s][debug][gc,phases] GC(1) Skipped Cards: Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 2
        [0.243s][info ][gc,phases] GC(1) Evacuate Collection Set: 0.44ms
        [0.243s][debug][gc,phases] GC(1) Ext Root Scanning (ms): Min: 0.13, Avg: 0.25, Max: 0.37, Diff: 0.25, Sum: 0.50, Workers: 2
        [0.243s][debug][gc,phases] GC(1) Scan Heap Roots (ms): Min: 0.00, Avg: 0.00, Max: 0.00, Diff: 0.00, Sum: 0.00, Workers: 2
        [0.243s][debug][gc,phases] GC(1) Scanned Cards: Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 2
        [0.243s][debug][gc,phases] GC(1) Scanned Blocks: Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 2
        [0.243s][debug][gc,phases] GC(1) Claimed Chunks: Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 2
        [0.243s][debug][gc,phases] GC(1) Found Roots: Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 2
        [0.243s][debug][gc,phases] GC(1) Code Root Scan (ms): Min: 0.00, Avg: 0.00, Max: 0.00, Diff: 0.00, Sum: 0.00, Workers: 2
        [0.243s][debug][gc,phases] GC(1) Scanned Nmethods Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 2
        [0.243s][debug][gc,phases] GC(1) Object Copy (ms): Min: 0.00, Avg: 0.00, Max: 0.00, Diff: 0.00, Sum: 0.00, Workers: 2
        [0.243s][debug][gc,phases] GC(1) Termination (ms): Min: 0.00, Avg: 0.14, Max: 0.27, Diff: 0.27, Sum: 0.27, Workers: 2
        [0.243s][debug][gc,phases] GC(1) Termination Attempts: Min: 1, Avg: 1.0, Max: 1, Diff: 0, Sum: 2, Workers: 2
        [0.243s][debug][gc,phases] GC(1) GC Worker Other (ms): Min: 0.00, Avg: 0.01, Max: 0.01, Diff: 0.00, Sum: 0.01, Workers: 2
        [0.243s][debug][gc,phases] GC(1) GC Worker Total (ms): Min: 0.38, Avg: 0.39, Max: 0.40, Diff: 0.02, Sum: 0.79, Workers: 2
        [0.243s][info ][gc,phases] GC(1) Post Evacuate Collection Set: 0.13ms
        [0.243s][debug][gc,phases] GC(1) NMethod List Cleanup: 0.01ms
        [0.243s][debug][gc,phases] GC(1) Reference Processing: 0.00ms
        [0.243s][debug][gc,phases] GC(1) Weak Processing: 0.03ms
        [0.243s][debug][gc,phases] GC(1) VM Weak Min: 0.00, Avg: 0.00, Max: 0.00, Diff: 0.00, Sum: 0.00, Workers: 1
        [0.243s][debug][gc,phases] GC(1) Dead Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 1
        [0.243s][debug][gc,phases] GC(1) Total Min: 4, Avg: 4.0, Max: 4, Diff: 0, Sum: 4, Workers: 1
        [0.243s][debug][gc,phases] GC(1) ObjectSynchronizer Weak Min: 0.00, Avg: 0.00, Max: 0.00, Diff: 0.00, Sum: 0.00, Workers: 1
        [0.243s][debug][gc,phases] GC(1) Dead Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 1
        [0.243s][debug][gc,phases] GC(1) Total Min: 1, Avg: 1.0, Max: 1, Diff: 0, Sum: 1, Workers: 1
        [0.243s][debug][gc,phases] GC(1) JVMTI Tag Weak OopStorage Min: 0.00, Avg: 0.00, Max: 0.00, Diff: 0.00, Sum: 0.00, Workers: 1
        [0.243s][debug][gc,phases] GC(1) Dead Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 1
        [0.243s][debug][gc,phases] GC(1) Total Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 1
        [0.243s][debug][gc,phases] GC(1) StringTable Weak Min: 0.00, Avg: 0.00, Max: 0.00, Diff: 0.00, Sum: 0.00, Workers: 1
        [0.243s][debug][gc,phases] GC(1) Dead Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 1
        [0.243s][debug][gc,phases] GC(1) Total Min: 45, Avg: 45.0, Max: 45, Diff: 0, Sum: 45, Workers: 1
        [0.243s][debug][gc,phases] GC(1) ResolvedMethodTable Weak Min: 0.00, Avg: 0.00, Max: 0.00, Diff: 0.00, Sum: 0.00, Workers: 1
        [0.243s][debug][gc,phases] GC(1) Dead Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 1
        [0.243s][debug][gc,phases] GC(1) Total Min: 50, Avg: 50.0, Max: 50, Diff: 0, Sum: 50, Workers: 1
        [0.243s][debug][gc,phases] GC(1) JNI Weak Min: 0.00, Avg: 0.00, Max: 0.00, Diff: 0.00, Sum: 0.00, Workers: 1
        [0.243s][debug][gc,phases] GC(1) Dead Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 1
        [0.243s][debug][gc,phases] GC(1) Total Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 1
        [0.243s][debug][gc,phases] GC(1) StringDedup Table Weak Min: 0.00, Avg: 0.00, Max: 0.00, Diff: 0.00, Sum: 0.00, Workers: 1
        [0.243s][debug][gc,phases] GC(1) Dead Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 1
        [0.243s][debug][gc,phases] GC(1) Total Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 1
        [0.243s][debug][gc,phases] GC(1) StringDedup Requests0 Weak Min: 0.00, Avg: 0.00, Max: 0.00, Diff: 0.00, Sum: 0.00, Workers: 1
        [0.243s][debug][gc,phases] GC(1) Dead Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 1
        [0.243s][debug][gc,phases] GC(1) Total Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 1
        [0.243s][debug][gc,phases] GC(1) StringDedup Requests1 Weak Min: 0.00, Avg: 0.00, Max: 0.00, Diff: 0.00, Sum: 0.00, Workers: 1
        [0.243s][debug][gc,phases] GC(1) Dead Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 1
        [0.243s][debug][gc,phases] GC(1) Total Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 1
        [0.243s][debug][gc,phases] GC(1) Weak JFR Old Object Samples Min: 0.00, Avg: 0.00, Max: 0.00, Diff: 0.00, Sum: 0.00, Workers: 1
        [0.243s][debug][gc,phases] GC(1) Dead Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 1
        [0.243s][debug][gc,phases] GC(1) Total Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 1
        [0.243s][debug][gc,phases] GC(1) Post Evacuate Cleanup 1: 0.03ms
        [0.243s][debug][gc,phases] GC(1) Merge Per-Thread State (ms): Min: 0.01, Avg: 0.01, Max: 0.01, Diff: 0.00, Sum: 0.01, Workers: 1
        [0.243s][debug][gc,phases] GC(1) Copied Bytes Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 2
        [0.243s][debug][gc,phases] GC(1) LAB Waste Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 2
        [0.243s][debug][gc,phases] GC(1) LAB Undo Waste Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 2
        [0.243s][debug][gc,phases] GC(1) Evac Fail Extra Cards Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 2
        [0.243s][debug][gc,phases] GC(1) Clear Logged Cards (ms): Min: 0.00, Avg: 0.00, Max: 0.00, Diff: 0.00, Sum: 0.00, Workers: 2
        [0.243s][debug][gc,phases] GC(1) Recalculate Used Memory (ms): Min: 0.00, Avg: 0.00, Max: 0.00, Diff: 0.00, Sum: 0.00, Workers: 1
        [0.243s][debug][gc,phases] GC(1) Post Evacuate Cleanup 2: 0.03ms
        [0.243s][debug][gc,phases] GC(1) Update Derived Pointers (ms): Min: 0.00, Avg: 0.00, Max: 0.00, Diff: 0.00, Sum: 0.00, Workers: 1
        [0.243s][debug][gc,phases] GC(1) Eagerly Reclaim Humongous Objects (ms): skipped
        [0.243s][debug][gc,phases] GC(1) Humongous Total skipped
        [0.243s][debug][gc,phases] GC(1) Humongous Candidates skipped
        [0.243s][debug][gc,phases] GC(1) Humongous Reclaimed skipped
        [0.243s][debug][gc,phases] GC(1) Redirty Logged Cards (ms): Min: 0.00, Avg: 0.00, Max: 0.00, Diff: 0.00, Sum: 0.00, Workers: 2
        [0.243s][debug][gc,phases] GC(1) Redirtied Cards: Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 2
        [0.243s][debug][gc,phases] GC(1) Resize TLABs (ms): Min: 0.00, Avg: 0.00, Max: 0.00, Diff: 0.00, Sum: 0.00, Workers: 2
        [0.243s][debug][gc,phases] GC(1) Free Collection Set (ms): Min: 0.00, Avg: 0.00, Max: 0.00, Diff: 0.00, Sum: 0.00, Workers: 2
        [0.243s][debug][gc,phases] GC(1) Rebuild Free List: 0.03ms
        [0.243s][debug][gc,phases] GC(1) Prepare For Mutator: 0.00ms
        [0.243s][debug][gc,phases] GC(1) Expand Heap After Collection: 0.00ms
        [0.243s][info ][gc,phases] GC(1) Other: 0.08ms
        [0.243s][info ][gc,marking] GC(2) Concurrent Scan Root Regions
        [0.243s][info ][gc,marking] GC(2) Concurrent Scan Root Regions 0.034ms
        [0.243s][info ][gc,marking] GC(2) Concurrent Mark
        [0.244s][info ][gc,marking] GC(2) Concurrent Mark From Roots
        [0.254s][info ][gc,marking] GC(2) Concurrent Mark From Roots 10.043ms
        [0.254s][info ][gc,marking] GC(2) Concurrent Preclean
        [0.254s][info ][gc,marking] GC(2) Concurrent Preclean 0.027ms
        [0.254s][debug][gc,phases ] GC(2) Finalize Marking 0.308ms
        [0.254s][debug][gc,phases ] GC(2) Reference Processing 0.013ms
        [0.254s][debug][gc,phases ] GC(2) VM Weak Min: 0.00, Avg: 0.00, Max: 0.00, Diff: 0.00, Sum: 0.00, Workers: 1
        [0.254s][debug][gc,phases ] GC(2) Dead Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 1
        [0.254s][debug][gc,phases ] GC(2) Total Min: 4, Avg: 4.0, Max: 4, Diff: 0, Sum: 4, Workers: 1
        [0.254s][debug][gc,phases ] GC(2) ObjectSynchronizer Weak Min: 0.00, Avg: 0.00, Max: 0.00, Diff: 0.00, Sum: 0.00, Workers: 1
        [0.254s][debug][gc,phases ] GC(2) Dead Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 1
        [0.254s][debug][gc,phases ] GC(2) Total Min: 1, Avg: 1.0, Max: 1, Diff: 0, Sum: 1, Workers: 1
        [0.254s][debug][gc,phases ] GC(2) JVMTI Tag Weak OopStorage Min: 0.00, Avg: 0.00, Max: 0.00, Diff: 0.00, Sum: 0.00, Workers: 1
        [0.254s][debug][gc,phases ] GC(2) Dead Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 1
        [0.254s][debug][gc,phases ] GC(2) Total Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 1
        [0.254s][debug][gc,phases ] GC(2) StringTable Weak Min: 0.00, Avg: 0.00, Max: 0.00, Diff: 0.00, Sum: 0.00, Workers: 1
        [0.254s][debug][gc,phases ] GC(2) Dead Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 1
        [0.254s][debug][gc,phases ] GC(2) Total Min: 45, Avg: 45.0, Max: 45, Diff: 0, Sum: 45, Workers: 1
        [0.254s][debug][gc,phases ] GC(2) ResolvedMethodTable Weak Min: 0.00, Avg: 0.00, Max: 0.00, Diff: 0.00, Sum: 0.00, Workers: 1
        [0.254s][debug][gc,phases ] GC(2) Dead Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 1
        [0.254s][debug][gc,phases ] GC(2) Total Min: 50, Avg: 50.0, Max: 50, Diff: 0, Sum: 50, Workers: 1
        [0.254s][debug][gc,phases ] GC(2) JNI Weak Min: 0.00, Avg: 0.00, Max: 0.00, Diff: 0.00, Sum: 0.00, Workers: 1
        [0.254s][debug][gc,phases ] GC(2) Dead Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 1
        [0.254s][debug][gc,phases ] GC(2) Total Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 1
        [0.254s][debug][gc,phases ] GC(2) StringDedup Table Weak Min: 0.00, Avg: 0.00, Max: 0.00, Diff: 0.00, Sum: 0.00, Workers: 1
        [0.254s][debug][gc,phases ] GC(2) Dead Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 1
        [0.254s][debug][gc,phases ] GC(2) Total Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 1
        [0.254s][debug][gc,phases ] GC(2) StringDedup Requests0 Weak Min: 0.00, Avg: 0.00, Max: 0.00, Diff: 0.00, Sum: 0.00, Workers: 1
        [0.254s][debug][gc,phases ] GC(2) Dead Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 1
        [0.254s][debug][gc,phases ] GC(2) Total Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 1
        [0.254s][debug][gc,phases ] GC(2) StringDedup Requests1 Weak Min: 0.00, Avg: 0.00, Max: 0.00, Diff: 0.00, Sum: 0.00, Workers: 1
        [0.254s][debug][gc,phases ] GC(2) Dead Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 1
        [0.254s][debug][gc,phases ] GC(2) Total Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 1
        [0.254s][debug][gc,phases ] GC(2) Weak JFR Old Object Samples Min: 0.00, Avg: 0.00, Max: 0.00, Diff: 0.00, Sum: 0.00, Workers: 1
        [0.254s][debug][gc,phases ] GC(2) Dead Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 1
        [0.254s][debug][gc,phases ] GC(2) Total Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0, Workers: 1
        [0.254s][debug][gc,phases ] GC(2) Weak Processing 0.217ms
        [0.254s][debug][gc,phases ] GC(2) ClassLoaderData 0.002ms
        [0.254s][debug][gc,phases ] GC(2) Trigger cleanups 0.002ms
        [0.255s][debug][gc,phases ] GC(2) G1 Complete Cleaning 0.348ms
        [0.255s][debug][gc,phases ] GC(2) Purge Unlinked NMethods 0.027ms
        [0.255s][debug][gc,phases ] GC(2) Unregister NMethods 0.035ms
        [0.255s][debug][gc,phases ] GC(2) Free Code Blobs 0.005ms
        [0.255s][debug][gc,phases ] GC(2) Purge Class Loader Data 0.013ms
        [0.255s][debug][gc,phases ] GC(2) Class Unloading 0.484ms
        [0.255s][debug][gc,phases ] GC(2) Flush Task Caches 0.015ms
        [0.255s][trace][gc,remset,tracking] GC(2) Before rebuild region 0 (tams: 0x00000000fe0602b8) total_live_bytes 393912 selected false (live_bytes 393912 type OLD)
        [0.255s][trace][gc,remset,tracking] GC(2) Before rebuild region 1 (tams: 0x00000000fe120510) total_live_bytes 132368 selected true (live_bytes 132368 type OLD)
        [0.255s][trace][gc,remset,tracking] GC(2) Before rebuild region 30 (tams: 0x00000000fff00000) total_live_bytes 1040456 selected false (live_bytes 1040456 type OLD)
        [0.255s][debug][gc,remset,tracking] GC(2) Remembered Set Tracking update regions total 32, selected 1
        [0.255s][debug][gc,phases ] GC(2) Update Remembered Set Tracking Before Rebuild 0.044ms
        [0.255s][debug][gc,phases ] GC(2) Reclaim Empty Regions 0.031ms
        [0.255s][debug][gc,phases ] GC(2) Report Object Count 0.001ms
        [0.255s][info ][gc,marking ] GC(2) Concurrent Mark 11.631ms
        [0.255s][info ][gc,marking ] GC(2) Concurrent Rebuild Remembered Sets and Scrub Regions
        [0.259s][info ][gc,marking ] GC(2) Concurrent Rebuild Remembered Sets and Scrub Regions 4.239ms
        [0.259s][trace][gc,remset,tracking] GC(2) After rebuild region 0 (tams 0x00000000fe0602b8 liveness 393912 remset occ 0 size 688)
        [0.259s][trace][gc,remset,tracking] GC(2) After rebuild region 1 (tams 0x00000000fe120510 liveness 132368 remset occ 111 size 1536)
        [0.259s][trace][gc,remset,tracking] GC(2) After rebuild region 30 (tams 0x00000000fff00000 liveness 1040456 remset occ 0 size 688)
        [0.259s][debug][gc,phases ] GC(2) Update Remembered Set Tracking After Rebuild 0.049ms
        [0.260s][debug][gc,phases ] GC(2) Finalize Concurrent Mark Cleanup 0.062ms
        [0.260s][info ][gc,marking ] GC(2) Concurrent Clear Claimed Marks
        [0.260s][info ][gc,marking ] GC(2) Concurrent Clear Claimed Marks 0.016ms
        [0.260s][info ][gc,marking ] GC(2) Concurrent Cleanup for Next Mark
        [0.260s][info ][gc,marking ] GC(2) Concurrent Cleanup for Next Mark 0.071ms
        [B@15db9742
        ];
         stderr: []
         exitValue = 0

        java.lang.RuntimeException: 'Skipping Remembered Set Rebuild.' missing from stdout/stderr
        at jdk.test.lib.process.OutputAnalyzer.shouldContain(OutputAnalyzer.java:252)
        at gc.g1.TestSkipRebuildRemsetPhase.main(TestSkipRebuildRemsetPhase.java:53)
        at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
        at java.base/java.lang.reflect.Method.invoke(Method.java:580)
        at com.sun.javatest.regtest.agent.MainActionHelper$AgentVMRunnable.run(MainActionHelper.java:333)
        at java.base/java.lang.Thread.run(Thread.java:1570)

        JavaTest Message: Test threw exception: java.lang.RuntimeException
        JavaTest Message: shutting down test

        result: Failed. Execution failed: `main' threw exception: java.lang.RuntimeException: 'Skipping Remembered Set Rebuild.' missing from stdout/stderr

        Attachments

          Issue Links

            Activity

              People

                tschatzl Thomas Schatzl
                dcubed Daniel Daugherty
                Votes:
                0 Vote for this issue
                Watchers:
                5 Start watching this issue

                Dates

                  Created:
                  Updated:
                  Resolved: