shenandoah-jdk28: add GC event counts per run (output/04-gc-events.txt)

Co-Authored-By: Claude Sonnet 5.5 <[email protected]>
Claude-Session: https://claude.ai/code/session_01HmvoHH3ZnCEaPNXRpDxDZe

shenandoah-jdk28/README.md

@@ -41,6 +41,7 @@ scripts/more-reps.sh 4 5              # append more reps and re-summarise
 | [`scripts/bench-one.sh`](scripts/bench-one.sh) | One run: 30 s warm-up, 60 s open-loop window, 20 s closed loop; pauses from `-Xlog:gc*`; peak RSS from `VmHWM` |
 | [`scripts/gc_pauses.py`](scripts/gc_pauses.py) | Stop-the-world pauses inside the measure window |
 | [`scripts/summarize.py`](scripts/summarize.py) | Median per configuration |
+| [`scripts/log-events.sh`](scripts/log-events.sh) | Counts `Cancelling GC`, `Pause Full`, degenerated pauses and allocation failures per run; output is [`output/04-gc-events.txt`](output/04-gc-events.txt) |
 
 ## Results (median of 5 interleaved runs, JDK 28+21 EA)
 
@@ -55,7 +56,7 @@ scripts/more-reps.sh 4 5              # append more reps and re-summarise
 
 **Read the last row carefully.** Per-run p99 for generational Shenandoah was 1,557, 3,077, 24.5, 1,658 and 692 ms: four of five
 runs contain a multi-second latency episode while the recorded stop-the-world pauses stay at a few milliseconds
-(one run had a 209 ms `Pause Full`). The GC logs do not show allocation failures (`Trigger: Failed to allocate` count is 0), and
+(one run had a 209 ms `Pause Full`). [`output/04-gc-events.txt`](output/04-gc-events.txt) shows no allocation failures and no degenerated pauses in any run, and
 the `Cancelling GC: Concurrent GC` lines are old-generation marking being preempted for a young collection, which is normal.
 So the cause of the stalls is **not established** here. One SATB run (811 ms p99) also stalled with no GC event at all,
 which says this 2-vCPU machine produces stalls of its own. Treat the generational result as "did not behave on this box

shenandoah-jdk28/output/04-gc-events.txt

@@ -0,0 +1,18 @@
+run                         cancelling_gc  pause_full  pause_degenerated  failed_to_allocate
+shenandoah-satb-1                       0           0                  0                   0
+shenandoah-satb-2                       0           0                  0                   0
+shenandoah-satb-3                       0           0                  0                   0
+shenandoah-satb-4                       0           0                  0                   0
+shenandoah-satb-5                       0           0                  0                   0
+shenandoah-generational-1               4           1                  0                   0
+shenandoah-generational-2               7           1                  0                   0
+shenandoah-generational-3               5           0                  0                   0
+shenandoah-generational-4               9           0                  0                   0
+shenandoah-generational-5               6           0                  0                   0
+
+== shenandoah-generational-4.log: what a 'Cancelling GC' line is (old marking preempted for a young cycle)
+[22.999s] Preempting old generation mark to allow Young GC
+[22.999s] Cancelling GC: Concurrent GC
+
+== shenandoah-generational-1.log: the Pause Full
+[34.040s] GC(62) Pause Full 737M->214M(1024M) 239.022ms

shenandoah-jdk28/scripts/log-events.sh

@@ -0,0 +1,16 @@
+#!/usr/bin/env bash
+# Counts stall-related events in the Shenandoah GC logs left in target/gclogs by bench-one.sh, and prints the
+# verbatim log lines for two of them. Output is committed as output/04-gc-events.txt.
+cd "$(dirname "$0")/../target/gclogs"
+echo "run                         cancelling_gc  pause_full  pause_degenerated  failed_to_allocate"
+for f in shenandoah-satb-[1-5].log shenandoah-generational-[1-5].log; do
+  printf "%-27s %13d %11d %18d %19d\n" "${f%.log}" \
+    "$(grep -c 'Cancelling GC' "$f")" "$(grep -c 'Pause Full [0-9]' "$f")" \
+    "$(grep -c 'Pause Degenerated.*ms$' "$f")" "$(grep -ci 'Failed to allocate' "$f")"
+done
+echo
+echo "== shenandoah-generational-4.log: what a 'Cancelling GC' line is (old marking preempted for a young cycle)"
+grep -m1 -B1 'Cancelling GC' shenandoah-generational-4.log | sed -E 's/^\[[^]]*\]//'
+echo
+echo "== shenandoah-generational-1.log: the Pause Full"
+grep -m1 'Pause Full [0-9]' shenandoah-generational-1.log | sed -E 's/^\[[^]]*\]//'