RFR: 8350314: Shenandoah: Capture thread state sync times in GC timings

Xiaolong Peng xpeng at openjdk.org
Tue Feb 25 22:47:16 UTC 2025


The change is to improve the observability of  Shenandoah GC, basically there are two changes for  Shenandoah GC timings in this PR:

1. Net GC pause timings include the time to propagate GC state to Java threads
2. Add new timing "Propagate GC state" in Shenandoah GC timing logs

With the change, the new GC timing log will be like:

[11.056s][info][gc,stats    ] Concurrent Reset                     89 us
[11.056s][info][gc,stats    ] Pause Init Mark (G)                 257 us
[11.056s][info][gc,stats    ] Pause Init Mark (N)                  17 us
[11.056s][info][gc,stats    ]   Update Region States                3 us
[11.056s][info][gc,stats    ]   Propagate GC state                  1 us
[11.056s][info][gc,stats    ] Concurrent Mark Roots               232 us, parallelism: 1.96x
[11.056s][info][gc,stats    ]   CMR: <total>                      456 us
[11.056s][info][gc,stats    ]   CMR: Thread Roots                 429 us, workers (us): 139, 148, 142, ---, ---, ---, 
[11.057s][info][gc,stats    ]   CMR: VM Strong Roots               11 us, workers (us):   8,   3,   0, ---, ---, ---, 
[11.057s][info][gc,stats    ]   CMR: CLDG Roots                    16 us, workers (us):  16, ---, ---, ---, ---, ---, 
[11.057s][info][gc,stats    ] Concurrent Marking                 1304 us, parallelism: 2.33x
[11.057s][info][gc,stats    ]   CM: <total>                      3043 us
[11.057s][info][gc,stats    ]   CM: Parallel Mark                3043 us, workers (us): 1023, 1017, 1003, ---, ---, ---, 
[11.057s][info][gc,stats    ]   Flush SATB                        204 us
[11.057s][info][gc,stats    ] Pause Final Mark (G)                865 us
[11.057s][info][gc,stats    ] Pause Final Mark (N)                234 us
[11.057s][info][gc,stats    ]   Finish Mark                       129 us, parallelism: 0.01x
[11.057s][info][gc,stats    ]   Propagate GC state                  2 us
[11.057s][info][gc,stats    ]   Update Region States               12 us
[11.057s][info][gc,stats    ]   Choose Collection Set              25 us
[11.057s][info][gc,stats    ]   Rebuild Free Set                   29 us
[11.057s][info][gc,stats    ] Concurrent Weak References           67 us, parallelism: 0.25x
[11.057s][info][gc,stats    ]   CWRF: <total>                      17 us
[11.057s][info][gc,stats    ]   CWRF: Weak References              17 us, workers (us):  15,   1,   0, ---, ---, ---, 
[11.057s][info][gc,stats    ] Concurrent Weak Roots               413 us
[11.057s][info][gc,stats    ]   Roots                             203 us, parallelism: 1.95x
[11.057s][info][gc,stats    ]     CWR: <total>                    396 us
[11.057s][info][gc,stats    ]     CWR: Code Cache Roots           295 us, workers (us):  90,  96, 109, ---, ---, ---, 
[11.057s][info][gc,stats    ]     CWR: VM Weak Roots              100 us, workers (us):  48,  37,  14, ---, ---, ---, 
[11.057s][info][gc,stats    ]     CWR: CLDG Roots                   2 us, workers (us): ---, ---,   2, ---, ---, ---, 
[11.058s][info][gc,stats    ]   Rendezvous                        197 us
[11.058s][info][gc,stats    ] Concurrent Cleanup                   35 us
[11.058s][info][gc,stats    ] Concurrent Class Unloading          486 us
[11.058s][info][gc,stats    ]   Unlink Stale                      398 us
[11.058s][info][gc,stats    ]     System Dictionary                 5 us
[11.058s][info][gc,stats    ]     Weak Class Links                  0 us
[11.058s][info][gc,stats    ]     Code Roots                      391 us
[11.058s][info][gc,stats    ]   Rendezvous                         69 us
[11.058s][info][gc,stats    ]   Purge Unlinked                      4 us
[11.058s][info][gc,stats    ]     Code Roots                        0 us
[11.058s][info][gc,stats    ]     CLDG                              3 us
[11.058s][info][gc,stats    ] Pause Final Roots (G)               272 us
[11.058s][info][gc,stats    ] Pause Final Roots (N)                18 us
[11.058s][info][gc,stats    ]   Propagate GC state                  3 us



### Test
- [x] make test TEST=hotspot_gc_shenandoah

-------------

Commit messages:
 - Log time to propagate GC state
 - 8350314: Shenandoah: Capture thread state sync times in GC timings

Changes: https://git.openjdk.org/jdk/pull/23759/files
  Webrev: https://webrevs.openjdk.org/?repo=jdk&pr=23759&range=00
  Issue: https://bugs.openjdk.org/browse/JDK-8350314
  Stats: 47 lines in 5 files changed: 40 ins; 7 del; 0 mod
  Patch: https://git.openjdk.org/jdk/pull/23759.diff
  Fetch: git fetch https://git.openjdk.org/jdk.git pull/23759/head:pull/23759

PR: https://git.openjdk.org/jdk/pull/23759


More information about the hotspot-gc-dev mailing list