sysview: fix cycle-3 review findings - kill_traffic(): stop the recording at --duration-ms exactly, then reap the workload, instead of waiting on it (up to 60s) before -stop - sysview_report.py: key open_calls by (func id, context) so interleaved callers of the same function don't cross-pair CALL/RET - build.yml: intersect the sysview dep-fetch board list with the PR's own HIL selection (tinyusb.json vs hfp.json), and skip entirely when HIL is not running for this PR - nrf54h20dk: shrink SYSVIEW_BUFFER_SIZE_DEFAULT to 4096 -- .data/.bss sit in the 32 KiB primary RAM, so the family's 65536 default fails to link - tusb_sysview.c: copy pcTaskName into a local buffer at snapshot time so a task deleted mid-lap can't leave SendTaskInfo() dereferencing a freed TCB - sysview_ci.py: drop a comparison against a baseline whose capture config (example/workload/duration_s) changed, and fail cdc_burst when the link stays enumerated but echoes nothing back - SKILL.md: document the WCH post-mortem dump path (OpenOCD, no J-Link)
diff --git a/.claude/skills/sysview/SKILL.md b/.claude/skills/sysview/SKILL.md index 5add708..a3581b6 100644 --- a/.claude/skills/sysview/SKILL.md +++ b/.claude/skills/sysview/SKILL.md
@@ -46,7 +46,9 @@ can work**: post-mortem autopsy of a hang (the halt IS the capture), and all WCH parts — their SDI attach is destructive (kills USB on ch32v2/v3, resets ch583-class, boards.md), so a live session and a USB workload are mutually - exclusive there. + exclusive there. `sysview_dump.py` scripts that dump over J-Link only; WCH has + no `JLINK_DEVICE`, so its dump is hand-driven over OpenOCD (post-mortem + section). - **Hold the board lock** for any route (see the recipe below). Every command here runs on the host the probe is attached to — for the ci.lan rig, reaching @@ -101,8 +103,9 @@ `python3 -c "import serial,time; p=serial.Serial('<node>',115200,timeout=0.2,write_timeout=2); [ (p.write(b'x'*64), p.read(64), time.sleep(0.002)) for _ in range(4000) ]"` **Only read back if the example echoes.** `cdc_msc` echoes; the dual examples do not call `tud_cdc_read()`, so a read-based workload blocks its full timeout per - iteration, outlives the recording window, and can hang the wrapper — drive - write-only there, and always set `write_timeout`. + iteration and never delivers the traffic you meant to record (the recorder + `-stop`s at `--duration-ms` and kills it there, so it costs a wasted capture, + not a hung run) — drive write-only there, and always set `write_timeout`. - `--no-events` skips the large `events.txt` (needed only for the percentile tables); `--export-terminal` adds `SEGGER_SYSVIEW_PrintfHost` output. `recording.SVDat` opens in a desktop SystemView for the visual timeline. @@ -176,6 +179,59 @@ halted (you're mid-autopsy). When done, step 5 of the live recipe applies unchanged: restore pristine firmware, then release the lock. +### WCH: the same dump by hand (no J-Link) + +`sysview_dump.py` is **J-Link-only** (`JLinkExe`, SWD) and every WCH row in +`boards.md` has `JLINK_DEVICE` `—`, so on `ch32v20x`/`ch32v30x` the dump is +hand-driven over OpenOCD: one attach reads the same channel-1 ring descriptor +and dumps the same bytes, and the WrOff split below is the script's +linearization verbatim. `ch32v10x` and `ch583` reset on every WCH-Link attach, +which wipes the ring — no dump route there either (`boards.md`). Build with the +same `cmake` lines as above (there is no `-jlink` flash target here); `<uid>` is +the board's `flasher.uid` in `test/hil/tinyusb.json`. + +```bash +ELF=build-pm/cdc_msc_freertos.elf +OUT=/tmp/sysview-pm; mkdir -p $OUT +OOCD=(openocd -c "tcl_port disabled" -c "gdb_port disabled" -c "telnet_port disabled" + -c "adapter serial <uid>" -c "adapter usb vid_pid 0x1a86 0x8010" + -f target/wch-riscv.cfg) + +# flash — no `verify`: read-back over SDI returns a repeated word, so it always mismatches +"${OOCD[@]}" -c "program $ELF reset exit" +# ... reproduce the hang ... + +CB=$(python3 -c "import sys; sys.path.insert(0,'.claude/skills/sysview/scripts'); \ + from sysview_record import rtt_cb_from_elf as f; print(f('$ELF'))") # _SEGGER_RTT +DESC=$(printf '0x%x' $((CB + 0x30))) # aUp[1] "SysView": sName,pBuffer,SizeOfBuffer,WrOff,RdOff,Flags + +# one attach, halt only — NEVER reset: the halt IS the autopsy point, and under +# SDI a reset target does not come back +"${OOCD[@]}" -c "init; halt; dump_image $OUT/header.bin $CB 0x48; \ + set d [read_memory $DESC 32 6]; \ + dump_image $OUT/ring.bin [lindex \$d 1] [lindex \$d 2]; shutdown" + +python3 - "$OUT" <<'EOF' +import struct, sys, pathlib +out = pathlib.Path(sys.argv[1]) +hdr = (out / "header.bin").read_bytes() +assert hdr[:10] == b"SEGGER RTT", "no control block there — wrong ELF, or RAM not initialized" +_, pbuf, size, wroff, rdoff, _fl = struct.unpack_from("<6I", hdr, 0x30) # aUp[1] = "SysView" +ring = (out / "ring.bin").read_bytes() +assert len(ring) == size, f"read {len(ring)} ring bytes, expected {size}" +(out / "capture.SVDat").write_bytes(ring[wroff:] + ring[:wroff]) # oldest byte first +print(f"pBuffer=0x{pbuf:x} SizeOfBuffer={size} WrOff={wroff} RdOff={rdoff}") +EOF +python3 .claude/skills/sysview/scripts/sysview_record.py \ + --from-raw $OUT/capture.SVDat --out $OUT-decoded +``` + +The core is left halted; recover the board by reflashing pristine firmware — +`reset run` under SDI never comes back. **Not bench-run yet**: the OpenOCD/Tcl +and the split are syntax-checked against openocd 0.12.0+dev and against +`sysview_dump.py`'s linearization, but no WCH post-mortem has been captured on +the rig. + ## Build options `-DSYSVIEW=` accepts `1..4` or `ON` (= 4); anything else is a configure error.
diff --git a/.claude/skills/sysview/boards.md b/.claude/skills/sysview/boards.md index d17ae05..690e880 100644 --- a/.claude/skills/sysview/boards.md +++ b/.claude/skills/sysview/boards.md
@@ -91,6 +91,13 @@ `SYSVIEW=4`. `boards/stm32f401blackpill/board.cmake` sets `SYSVIEW_BUFFER_SIZE_DEFAULT 4096`; the rest of the family (>=128 KiB) keeps 65536. Unmeasured — expect the small-buffer event loss the other 4096 rows show. +- **nrf54h20dk overrides its family default down to 4096** — its linker script puts + `.data`/`.bss` in the 32 KiB primary `RAM` (0x22000000), so nrf's family-wide 65536 + fails to link at `SYSVIEW=4` ("`.bss` is too large to fit in RAM memory segment"). + `boards/nrf54h20dk/board.cmake` sets `SYSVIEW_BUFFER_SIZE_DEFAULT 4096`; the rest of the + family keeps 65536. Unmeasured — expect the small-buffer event loss the other 4096 rows + show. Routing static `.bss` to RAM00 (512 KiB, already a TODO in that board.cmake) would + free the buffer to grow. - **nrf5340dk cannot be captured at present**: it HardFaults inside `vTaskStartScheduler()` before any task runs — reproduced on a plain non-instrumented build and after a full `nrfjprog --recover`, so it is a board/boot issue, not a SystemView one. The RTT control block
diff --git a/.claude/skills/sysview/scripts/sysview_record.py b/.claude/skills/sysview/scripts/sysview_record.py index 2653e60..425a309 100644 --- a/.claude/skills/sysview/scripts/sysview_record.py +++ b/.claude/skills/sysview/scripts/sysview_record.py
@@ -139,6 +139,19 @@ time.sleep(1) +def kill_traffic(proc): + """Kill a --traffic-cmd and reap it. The command runs under `sh -c`, which can spawn + children of its own (a pipeline), so the whole process group goes -- start_new_session + at Popen is what makes that group ours to kill.""" + if not proc or proc.poll() is not None: + return + try: + os.killpg(os.getpgid(proc.pid), signal.SIGKILL) + except ProcessLookupError: + pass + proc.wait() + + def free_display(display): run(["pkill", "-9", "-f", f"Xvfb {display} "]) time.sleep(1) @@ -334,19 +347,16 @@ time.sleep(1) time.sleep(3) # J-Link connect + first events - # start_new_session=True: traffic_cmd runs under `sh -c`, which can itself spawn - # children (e.g. a pipeline) -- putting it in its own process group lets the - # finally block below kill the whole group, not just the shell. + # start_new_session=True: its own process group, so kill_traffic() can take the + # whole workload down, not just the shell. traffic = subprocess.Popen(args.traffic_cmd, shell=True, start_new_session=True) \ if args.traffic_cmd else None time.sleep(args.duration_ms / 1000) - if traffic: - try: - traffic.wait(timeout=60) - except subprocess.TimeoutExpired: - pass # killed in the finally block below, whole process group - + # The window is --duration-ms, nothing else: stop the moment it expires, THEN deal + # with the workload. Waiting on the process first (as this did, up to 60 s) let a + # --traffic-cmd that outlives the interval stretch the recording by that much. sv_cmd("-stop") + kill_traffic(traffic) time.sleep(2) # After stop an "overflow events recorded" / info modal (with a Close # button) can block -save. Its title varies, so clear by size. @@ -368,11 +378,7 @@ env={**os.environ, "DISPLAY": disp}) raise finally: - if traffic and traffic.poll() is None: - try: - os.killpg(os.getpgid(traffic.pid), signal.SIGKILL) - except ProcessLookupError: - pass + kill_traffic(traffic) if sv and sv.poll() is None: sv.kill() xvfb.kill()
diff --git a/.claude/skills/sysview/scripts/sysview_report.py b/.claude/skills/sysview/scripts/sysview_report.py index 55213b3..c4090cc 100644 --- a/.claude/skills/sysview/scripts/sysview_report.py +++ b/.claude/skills/sysview/scripts/sysview_report.py
@@ -175,9 +175,12 @@ heap_last = None # last "Allocate Memory" / "Free Memory" match (running totals) func_durs = {} # func id (0-based, see TU_SV_FUNC_NAMES) -> [duration_s] marker_durs = {} # marker id -> [duration_s] - open_calls = {} # func id -> [True, ...] stack, one entry per CALL awaiting its RET + open_calls = {} # (func id, context) -> [call_ts, ...] stack, one per CALL awaiting its RET # (a list, not a bool: nesting -- CALL,CALL,RET,RET on the same id, e.g. - # a preempted task -- must pair LIFO, innermost CALL to innermost RET) + # a preempted task -- must pair LIFO, innermost CALL to innermost RET. + # Keyed by context too: two contexts calling the same function interleave + # (A-CALL, B-CALL, A-RET, B-RET), and a single per-id stack would pair + # A's return with B's call, quietly corrupting the duration percentiles) dropped_pairs = 0 # count of spliced CALL/RET pairs discarded due to data loss # Scheduling reconstruction for cpu_pct_workload: the export's transition events (Task Run / # System Idle switch the running task; ISR Enter/Exit nest on top) let per-context busy time @@ -343,10 +346,11 @@ # duration regex therefore misread almost every return as a call, which both # inflated dropped_pairs to nonsense (108923 against 706 paired) and left the # p50/p99 columns computed from the surviving ~0.5% subsample. + key = (fid, row.get("context", "")) if "Returns" not in detail: # a CALL - open_calls.setdefault(fid, []).append(_ts) + open_calls.setdefault(key, []).append(_ts) else: # a RET - stack = open_calls.get(fid) + stack = open_calls.get(key) if not stack: dropped_pairs += 1 # RET without its CALL: spliced else:
diff --git a/.github/workflows/build.yml b/.github/workflows/build.yml index fdfa1fa..f9d13aa 100644 --- a/.github/workflows/build.yml +++ b/.github/workflows/build.yml
@@ -631,23 +631,43 @@ # sysview_ci.py capture builds device/cdc_msc for the sysview-flagged boards on # this runner. "Clean workspace" above wipes the checkout every run, so this always # re-clones (get_deps.py's own already-at-pinned-commit skip never gets a chance to - # apply here); scoping to just the sysview-flagged boards keeps it to a handful of - # shallow (depth=1) clones rather than the full job matrix's dependency set. + # apply here); scoping to just the boards the capture step below actually selects + # keeps it to a handful of shallow (depth=1) clones rather than the full job + # matrix's dependency set. # N8: board list derived from $HIL_JSON itself -- the same "sysview" key sysview_ci.py's # own select_boards() checks -- instead of a hardcoded pair that silently drifts out of # sync with test/hil/tinyusb.json (a third sysview board added the documented way would # otherwise just build failed here, inside a continue-on-error step, with nothing to say - # why). + # why). That roster list is then intersected with the PR's own board selection, so a PR + # whose selection holds no sysview board clones nothing. if: ${{ !cancelled() && github.run_attempt == '1' }} continue-on-error: true + env: + SEL_ARGS_TINYUSB: ${{ needs.set-matrix.outputs.hil_args_tinyusb }} + SEL_RUN_TINYUSB: ${{ needs.set-matrix.outputs.hil_run_tinyusb }} + SEL_ARGS_HFP: ${{ needs.set-matrix.outputs.hil_args_hfp }} + SEL_RUN_HFP: ${{ needs.set-matrix.outputs.hil_run_hfp }} run: | - BOARDS=$(python3 -c " - import json + case "$HIL_JSON" in + *tinyusb.json) SEL_ARGS="$SEL_ARGS_TINYUSB"; SEL_RUN="$SEL_RUN_TINYUSB" ;; + *hfp.json) SEL_ARGS="$SEL_ARGS_HFP"; SEL_RUN="$SEL_RUN_HFP" ;; + esac + if [ "$SEL_RUN" = "false" ]; then + echo "HIL skipped by PR selection, no SystemView deps to fetch" + exit 0 + fi + BOARDS=$(SEL_ARGS="$SEL_ARGS" python3 -c " + import json, os + # -b names only, mirroring the capture step's own selection parse: a -bt board is + # never captured, and no -b at all (full matrix) still means every sysview board + argv = os.environ['SEL_ARGS'].split() + sel = {b for a, b in zip(argv, argv[1:]) if a == '-b'} cfg = json.load(open('$HIL_JSON')) - print(' '.join(b['name'] for b in cfg['boards'] if 'sysview' in b)) + print(' '.join(b['name'] for b in cfg['boards'] + if 'sysview' in b and (not sel or b['name'] in sel))) ") if [ -z "$BOARDS" ]; then - echo "no sysview-flagged boards in $HIL_JSON, nothing to fetch deps for" + echo "no selected sysview-flagged board in $HIL_JSON, nothing to fetch deps for" exit 0 fi ARGS=""
diff --git a/hw/bsp/nrf/boards/nrf54h20dk/board.cmake b/hw/bsp/nrf/boards/nrf54h20dk/board.cmake index 8095b59..3a2c4e9 100644 --- a/hw/bsp/nrf/boards/nrf54h20dk/board.cmake +++ b/hw/bsp/nrf/boards/nrf54h20dk/board.cmake
@@ -1,3 +1,7 @@ +# .data/.bss live in the 32 KiB primary RAM: the family's 65536 SystemView default +# cannot link here. +set(SYSVIEW_BUFFER_SIZE_DEFAULT 4096) + set(MCU_VARIANT nrf54h20) function(update_board TARGET)
diff --git a/src/common/tusb_sysview.c b/src/common/tusb_sysview.c index 40ca815..a507a73 100644 --- a/src/common/tusb_sysview.c +++ b/src/common/tusb_sysview.c
@@ -305,6 +305,9 @@ * Single writer (usbd's periodic report, or usbh's in a host-only build -- * never both, never reentered), so no locking is needed. */ static TaskStatus_t status[SYSVIEW_FREERTOS_MAX_NOF_TASKS]; + /* pcTaskName points into the live TCB, which a task deleted later in the lap frees; copy the + * name at snapshot time so SendTaskInfo() below never dereferences a dead TCB. */ + static char names[SYSVIEW_FREERTOS_MAX_NOF_TASKS][configMAX_TASK_NAME_LEN]; /* Report one task per call instead of looping over all of them: even with * the array off the stack, up to SYSVIEW_FREERTOS_MAX_NOF_TASKS back-to-back * SEGGER_SYSVIEW_SendTaskInfo() calls (each locking + writing the RTT ring buffer) in a @@ -321,12 +324,16 @@ // real time, even though this function only ever publishes ONE task per call. Cache its // result and refresh only when the rotation wraps back to index 0 (once per full lap over the // task list, not every call): same set of Stack Info events published, over the same rotation, - // at roughly 1/SYSVIEW_FREERTOS_MAX_NOF_TASKS the scheduler-suspended time. Entries point into - // live TCBs (pcTaskName), so a lap-old snapshot assumes no task is deleted meanwhile -- true of - // every instrumented example, and the same lifetime SEGGER's own FreeRTOS task list relies on. + // at roughly 1/SYSVIEW_FREERTOS_MAX_NOF_TASKS the scheduler-suspended time. Everything published + // from a cached entry is a value copy (the name into names[] here, the rest plain integers), so a + // task deleted mid-lap only makes its own entry stale, never a dangling dereference. static UBaseType_t n = 0; if (next_idx == 0) { n = uxTaskGetSystemState(status, TU_ARRAY_SIZE(status), NULL); + for (UBaseType_t t = 0; t < n; t++) { + strncpy(names[t], status[t].pcTaskName, configMAX_TASK_NAME_LEN - 1); + names[t][configMAX_TASK_NAME_LEN - 1] = '\0'; + } } if (n == 0) { return; } UBaseType_t const i = next_idx; @@ -334,7 +341,7 @@ SEGGER_SYSVIEW_TASKINFO info = {0}; info.TaskID = (U32)(uintptr_t) status[i].xHandle; - info.sName = status[i].pcTaskName; + info.sName = names[i]; info.Prio = status[i].uxCurrentPriority; info.StackBase = (U32)(uintptr_t) status[i].pxStackBase; uint32_t const free_bytes = status[i].usStackHighWaterMark * sizeof(StackType_t);
diff --git a/test/hil/sysview_ci.py b/test/hil/sysview_ci.py index fb534a2..c34adcb 100644 --- a/test/hil/sysview_ci.py +++ b/test/hil/sysview_ci.py
@@ -164,9 +164,13 @@ delta = delta_fn(b, p) return bcell, pcell, delta -def board_section(name, base_j, pr_j): +def board_section(name, base_j, pr_j, base_dropped=None): live_window_s = (pr_j.get("capture") or {}).get("live_window_s") heading = f"### {name}" + (f" — live {live_window_s:.1f} s" if live_window_s is not None else "") + if base_dropped: + # The report header states the PR-side config only, so a dropped baseline has to say + # here why every row reads "new" -- otherwise it looks like base never captured. + heading += f" — base dropped, capture config changed ({', '.join(base_dropped)})" lines = [heading, ""] if pr_j.get("error"): return "\n".join(lines + [f"capture failed: {pr_j['error']}", ""]) @@ -279,6 +283,17 @@ f' y-axis "µs" 0 --> {ymax:.1f}'] + bars + ["```"] return "\n".join(lines) + "\n" +CAPTURE_CFG_KEYS = ("example", "workload", "duration_s") + +def capture_cfg_changes(base_j, pr_j): + """Config differences that make a baseline incomparable: a PR that changes a board's + sysview example, workload or duration_s measures different work, so base-vs-PR deltas + would be noise dressed up as a regression.""" + if not base_j: + return [] + return [f"{k} `{base_j.get(k)}`→`{pr_j.get(k)}`" + for k in CAPTURE_CFG_KEYS if base_j.get(k) != pr_j.get(k)] + def report(base_dir, pr_dir): pr = load_set(pr_dir) if not pr: @@ -296,7 +311,8 @@ f"base `{base_commit}` → PR `{any_pr.get('commit', '?')}`*") parts = [HEADER, "", head, ""] for b in boards: - parts.append(board_section(b, base.get(b), pr[b])) + changed = capture_cfg_changes(base.get(b), pr[b]) + parts.append(board_section(b, None if changed else base.get(b), pr[b], changed)) parts.append(LEGEND) return "\n".join(parts) + "\n" @@ -340,8 +356,9 @@ "capture": capture_info or {}, "metrics": metrics, "error": error} def _workload_cdc_burst(node, duration_s): - """Returns True if traffic ran for the full window, False if the serial - link died early (device dropped off the bus) -- never raises.""" + """Returns True if traffic ran for the full window, False if the serial link died early + (device dropped off the bus) or the device stayed enumerated but echoed nothing back -- + never raises.""" import serial, time # write_timeout: without it, a device that stops draining its OUT endpoint blocks s.write() # forever, wedging PHASE 2 while the board flock is held -- the same failure mode hil_test.py @@ -351,17 +368,21 @@ # wedge faster, and importing hil_test would pull in its pymtp dependency for one constant. s = serial.Serial(node, 115200, timeout=0.02, write_timeout=2) end = time.monotonic() + duration_s + echoed = 0 while time.monotonic() < end: t = time.monotonic() while time.monotonic() - t < 0.30 and time.monotonic() < end: try: - s.write(b"x" * 64); s.read(64) + s.write(b"x" * 64); echoed += len(s.read(64)) except Exception: s.close() return False time.sleep(min(1.0, max(0, end - time.monotonic()))) s.close() - return True + # A device that keeps its CDC endpoints enumerated but never echoes a byte produces a + # capture of an idle bus; only writes throwing (the link-died path above) used to fail + # this workload, so such a run was published as a clean loaded capture. + return echoed > 0 WORKLOADS = {"cdc_burst": _workload_cdc_burst, "idle": lambda node, duration_s: __import__("time").sleep(duration_s) or True}