summaryrefslogtreecommitdiff
diff options
context:
space:
mode:
authorhathach <[email protected]>2026-07-24 15:28:50 +0700
committerhathach <[email protected]>2026-07-24 15:56:14 +0700
commitc9226077bb39dd1f19997272db58596aeeb8fa71 (patch)
tree5b663aa706f2ccff3bf6907fc88a4eddbcc66ce0
parent24bb035be7881c2b4a95136bef4d03a91c9e31ce (diff)
add etm-trace skill: unattended J-Trace ETM capture and analysis
Headless instruction-trace capture on any TRACE_ETM-capable board via Ozone's automation socket (port 19201, xvfb): etm_capture.py generates a throwaway project from the board's committed ozone reference (device, TIF, width, timing, hooks, JLinkScript inheritance), drives the session, and exports profile/coverage; etm_profile.py renders hot functions, coverage, per-line/instruction counters and ISR timing from the itrace stream. SKILL.md carries rig discipline, capture recipes, a new-board bring-up ladder and troubleshooting; boards.md is the per-board reference (config table + caveats) for all validated boards.
-rw-r--r--.claude/skills/etm-trace/SKILL.md199
-rw-r--r--.claude/skills/etm-trace/boards.md134
-rw-r--r--.claude/skills/etm-trace/scripts/etm_capture.py567
-rw-r--r--.claude/skills/etm-trace/scripts/etm_profile.py428
4 files changed, 1328 insertions, 0 deletions
diff --git a/.claude/skills/etm-trace/SKILL.md b/.claude/skills/etm-trace/SKILL.md
new file mode 100644
index 000000000..8affe13ec
--- /dev/null
+++ b/.claude/skills/etm-trace/SKILL.md
@@ -0,0 +1,199 @@
+---
+name: etm-trace
+description: Use when you need instruction-level execution data from real hardware via a SEGGER J-Trace — cycle-accurate hot-function profiling, on-target code coverage, or raw instruction history (e.g. what ran right before a fault/hang) — beyond what logs, GDB, or DWT PC-sampling can answer. Covers unattended (headless) capture and analysis on ETM-capable TinyUSB boards.
+---
+
+# etm-trace — unattended ETM instruction trace via J-Trace + Ozone
+
+Streams full instruction (ETM) trace from a board wired to a SEGGER J-Trace,
+headlessly: no GUI, scripted end to end. Produces hot-function profile, code
+coverage, and optionally the raw instruction history.
+
+| Skill | Answers |
+|--------------------|----------------------------------------------------------------------------|
+| `usbmon` | what the host actually exchanged (URBs) |
+| `usb-target-debug` | what the device did (logs, driver state, sampled PCs) |
+| `usb-sniffer` | what crossed the wire |
+| **`etm-trace`** | **exactly which instructions executed, when** (profile, coverage, history) |
+
+Use `usb-target-debug`'s DWT PC-sampling for a quick statistical profile; use
+this skill for exact counts, coverage, or instruction-by-instruction history.
+
+## Requirements
+
+- J-Trace on USB (`lsusb -d 1366:1020`) wired to the board's trace header;
+ select it by J-Link USB **nickname** (this rig: `jtrace`) — never commit
+ serials.
+- `ozone` on PATH (≥ V3.38 for the automation socket) and `xvfb-run`.
+- Firmware built with **`-DTRACE_ETM=1`** (BSP trace-pin + trace-clock init).
+- Boards with a reference `hw/bsp/*/boards/<board>/ozone/*.jdebug` work out of
+ the box (`ls` that glob for the list); others fall back to `JLINK_DEVICE`
+ from `board.cmake` + default trace config. Verified boards: `boards.md` in
+ this skill directory.
+
+## Rig discipline
+
+- One probe, one client: quit interactive Ozone/JLinkExe/GDB on the probe
+ first. Kill only processes you started — if it's held by someone else's
+ session (check `fuser /dev/bus/usb/<bus>/<dev>`), surface it and ask. The
+ capture script uses automation port **19201**, never an interactive Ozone's
+ 19200.
+- Hold the board lock (see the `hil` skill):
+ `python3 test/hil/board_lock.py hold <board> --reason "etm capture"`.
+- Committed `hw/bsp/**/ozone/*.jdebug` are the maintainer's interactive
+ projects — automation never opens them (Ozone rewrites project files); the
+ script generates a throwaway project.
+- The default capture reflashes and resets the target (`--attach` doesn't).
+
+## Capture and analyze
+
+```bash
+# 1. Build with trace support:
+cd examples && cmake -B cmake-build-<board> -DBOARD=<board> -G Ninja \
+ -DCMAKE_BUILD_TYPE=MinSizeRel -DTRACE_ETM=1 . \
+ && cmake --build cmake-build-<board> --target <example>
+
+# 2. Capture (all options + defaults: etm_capture.py --help):
+python3 .claude/skills/etm-trace/scripts/etm_capture.py \
+ --board <board> --probe jtrace --duration-ms 10000 --out <dir>
+
+# 3. Analyze (hot functions, coverage, hottest lines, optimization hints):
+python3 .claude/skills/etm-trace/scripts/etm_profile.py <dir> --elf <elf>
+```
+
+Every capture — TinyUSB firmware or vendor demo — goes through
+`etm_capture.py`; extend it when a board needs something new, never
+hand-roll Ozone drivers.
+
+Choosing capture flags (semantics in `--help`):
+- fresh-boot profile/coverage: defaults (flash + reset + trace from startup)
+- narrowing debug on a LIVE target: `--attach` — no reflash/reset (flashed
+ firmware must match `--elf` and be TRACE_ETM-built)
+- raw history: `--trace-csv` (~80 MB/1M instructions) — when sequence/timing
+ matters, e.g. feeding `--isr`
+- stream dies (overflow/unknown-packet): `--no-timestamps`, then reduce the
+ core clock (`boards.md`); marginal wiring: sweep `--trace-timing`,
+ isolate lines with `--trace-width`. "capture OK" requires nonzero profile
+ totals — silence (no trace at all) fails with its own error
+- deeper data: `--profile-lines-csv` (hottest lines), `--profile-insts-csv`
+ (branch bias), `--sample "expr,.."` (data sampling), `--power` (probe-powered
+ targets only), `--os-plugin` (RTOS timeline), `--trace-only` (experimental,
+ see Warnings)
+- non-TinyUSB targets: `--device` + `--elf`, plus `--jlink-script` when the
+ firmware doesn't init the trace pins
+
+First trace on a board — or after any rewiring — is a bring-up, not a plain
+capture: follow "Adding a new board" below (vendor example first).
+
+Analyzer: `--isr ENTRY[,BODY..]` gives ISR min/median/avg/worst from a
+`--trace-csv` capture with timestamps (fast-enumerating boards need a short
+no-eviction run); `--exclude REGEX` drops idle/poll loops from the load
+ranking.
+
+Outputs in `<dir>`: `code_profile.txt` (run/fetch counts + coverage); on
+request `itrace.csv`, `profile_lines.csv`, `profile_insts.csv`, `samples.csv`,
+`power.csv`; `session.log` / `ozone_console.log` / `jlink.log` as evidence.
+
+## Reading results
+
+- **Load %** = share of instruction **fetches** — Ozone has no per-function
+ time; time comes only from itrace timestamps (`--isr`, time-share table).
+- ISR timing: sub-µs values are approximate (interpolated timestamps — hence
+ the SysTick calibration); instruction counts are exact. Time-share ≫
+ instruction-share = stalled/waiting (e.g. slave-mode FIFO at wire pace).
+- "Fully covered" needs both branch directions — 100% is not expected from an
+ idle run.
+- itrace timestamps scale by `VAR_TRACE_CORE_CLOCK` (from the board reference;
+ `--core-clock` overrides): ordering is exact, absolute times approximate.
+- A ms+ "largest gap" or `Trace overflow detected` beyond the startup burst =
+ lost packets — reduce the core clock or trace a quieter phase.
+- One `Invalid trace timestamp` line at `Debug.Halt` is a normal decoder
+ artifact.
+- `Unknown trace data packet … Trace collection stopped!` = stream dead from
+ that point (the script exits non-zero): retry with `--no-timestamps`, then
+ reduce the core clock.
+
+## Timing
+
+- Capture ≈ `--duration-ms` + 15 s overhead; add ~5 s per 1M instructions with
+ `--trace-csv`. Bash timeout: duration + 120000 ms.
+- Analyzer: < 5 s for a 2M-row itrace.csv.
+
+## Warnings
+
+- **Trace starts at `trace_etm_init()`**, not at reset: earlier `board_init()`
+ code shows as never-executed and Ozone logs `No trace clock present` — both
+ expected. Trace-from-reset needs a SEGGER J-Link script (`.pex`) instead of
+ firmware init.
+- Never commit capture output (`itrace.csv` can exceed 100 MB) — keep `--out`
+ in scratchpad/`/tmp`; `*.jdebug.user` files stay untracked.
+- The automation socket can't evaluate symbolic constants (`EXPORT_AS_CSV`):
+ the scripts send numeric/plain commands only — keep it that way when
+ extending them (UM08025 §6.7).
+- Without `xvfb-run`, Ozone opens on `DISPLAY` and steals keyboard focus.
+ Ozone has no `--help`/`--version` — any such probe opens the GUI; check
+ with `which ozone` only.
+- **`--trace-only` is experimental**: ETM start/stop comparators are scarce
+ and erratic — low-rate handler windows may silently not record, adjacent
+ instructions leak in, timestamps are invalid across gaps, and the profile
+ becomes share-of-traced-stream. Use only for instruction-exact inventories
+ of high-rate symbols; for ISR timing use full trace + `--isr`.
+
+## Adding a new board
+
+Bring-up ladder — each step gates the next:
+
+1. **Docs before hardware** (calibre library first, then vendor site): board
+ manual, schematics, MCU reference manual. Establish the trace clock
+ source and max — chip side and probe side (J-Trace PRO Cortex-M tops out
+ at a 150 MHz trace clock) — the pins carrying TRACE_CLK/D0-D3 (read the board's
+ debug-connector table — boards often route trace on alternate pins), and
+ required rework (jumpers, solder bridges, 0 Ω resistors to add/remove).
+ Hunt shared-net hazards: PHYs or other active drivers on trace nets,
+ boot straps, connector stubs.
+2. **Confirm with the user before any hardware change**: present the rework
+ findings as **[ACTION]** items and wait — the user solders/jumpers, you
+ verify afterward.
+3. **Vendor example before TinyUSB**: fetch SEGGER's trace example for the
+ same/similar MCU
+ (<https://www.segger.com/products/debug-probes/j-trace/technology/tested-devices/>)
+ and run it with `--device <MCU> --elf <demo ELF> --jlink-script
+ <demo .pex>`. Streaming proves the physical path — and only that: demo
+ firmware often runs reset-default clocks (the RA6M5 one traces at a few
+ MHz), so its success says nothing about your target's trace rate. The
+ example may target a different board (the LPC4357 one is tested on a
+ Keil MCB4300), so silence isn't final proof — but its J-Link
+ script/config is often borrowable.
+4. **TinyUSB support**: `trace_etm_init()` in the family BSP — mux trace
+ pins AFTER the final core-clock switch, enable the trace clock, enable
+ any funnel between ETM and TPIU; committed `ozone/*.jdebug` reference,
+ plus a `.JLinkScript` declaring off-ROM-table CSTF/TMC/TPIU (addresses
+ from the vendor demo's script); build with `TRACE_ETM=1`, validate with
+ `--board <board>`.
+5. **Still silent or corrupt?** In order: chip-side register audit (pinmux,
+ TPIU, ETM, DEMCR — and EVERY funnel in the path; an unprogrammed funnel
+ reads register-perfect and eats the stream), physically re-seat both
+ connector ends, then SEGGER's procedure (UM08001): find a stable
+ `--trace-timing` at `--trace-width 1`, step up to 2, then 4 (sampling
+ default is +2 ns) — then search the
+ MCU vendor's application notes and community forums for the chip's trace
+ recipe: more than one board's fix lived only in a forum thread.
+6. **Board note**: add the table row (core clock, TRACECLK pin + max,
+ width, timing, physical setup, TODO for anything left unvalidated) plus
+ a caveat bullet — both in `boards.md`.
+
+## Per-board notes
+
+Every validated board has a row (config: core clock, TRACECLK, width, timing,
+physical setup, TODO) and a caveat entry in `boards.md` (same directory) —
+**read a board's row and caveat before capturing on it**; new validations add
+both. Timing semantics and clock columns are explained at the top of that file.
+
+## References
+
+- Ozone manual (UM08025, automation socket §6.7, project commands §7):
+ <https://www.segger.com/downloads/jlink/UM08025_Ozone.pdf> — V3.50, same as
+ the installed Ozone (web is rev 1 vs the local copy's rev 0; the local PDF
+ under /opt/SEGGER/Ozone_V350/Doc remains the offline fallback).
+- J-Link / J-Trace manual (UM08001, trace ch. 10, timing troubleshooting):
+ <https://kb.segger.com/UM08001_J-Link_/_J-Trace_User_Guide>
diff --git a/.claude/skills/etm-trace/boards.md b/.claude/skills/etm-trace/boards.md
new file mode 100644
index 000000000..dd628ea80
--- /dev/null
+++ b/.claude/skills/etm-trace/boards.md
@@ -0,0 +1,134 @@
+# etm-trace — per-board reference
+
+Validated boards: trace config table + hard-won caveats. Read the row AND the
+caveat for a board before capturing on it; add a row + caveat when a new board
+is validated (jdebug reference, board.cmake/board.h clock selection and this
+file must agree).
+
+"Core (trace build)" is the CPU clock a `TRACE_ETM=1` build runs — where it
+differs from the stock clock, board.h selects it automatically. Timing
+"0 (unset)" = the reference sets no SetTraceTiming and Ozone then sends
+`TraceSampleAdjust TD = 0`; J-Link's own +2 ns default (UM08001) applies only
+outside Ozone-driven captures. Explicit values live in the committed
+reference.
+
+| Board | Core (trace build) | TRACECLK pin | Width | Timing | Physical setup | TODO |
+|--------------------|----------------------|-----------------------|-------|---------|-------------------------------|---------------------------------------------|
+| stm32h743eval | 400 MHz | 50 MHz (PLL1R, fixed) | 4 | +100 ps | — | — |
+| stm32n657nucleo | 300 MHz | 18.75 MHz (cpu/16) | 4 | 0 (unset) | none — CN1 MIPI20; JP2=1 | — |
+| stm32h7s3nucleo | 300 MHz | 50 MHz (cpu/3/2) | 2 | 0 (unset) | none — native CN1 MIPI20 | remove SB11/SB12 → width 4 @ 600 MHz |
+| stm32h563nucleo | 100 MHz | follows core | 1 | +5 ns | remove SB8/9/64/68/70/71/78 | retest width 4 / 250 MHz after SB removal |
+| metro_m7_1011 | 500 MHz | 66 MHz (root/2) | 4 | +50 ps | custom rev A ETM-header rework | — |
+| mcb1800 | 120 MHz | 60 MHz (CCLK/2) | 4 | 0 (unset) | fit J5 DBG_EN | — |
+| ea4088_quickstart | 120 MHz | 120 MHz | 4 | 0 (unset) | J7 (fully wired) | — |
+| nrf52840dk | 64 MHz | 16 MHz (hw cap) | 4 | 0 (unset) | solder P25, SW7 → Alt | — |
+| nrf5340dk (M33) | 64 MHz | 16 MHz (TAD, forced) | 4 | +3 ns | mount P25; cut SB27/SB28 | — |
+| mimxrt1170_evkb | 996 MHz | 25 MHz (root/2) | 1 | 0 | populate 0 Ω R1881-R1886; J58 | verify/reflow R1882-R1884 → width 4 |
+| ra6m5_ek (M33) | 200 MHz | 25 MHz (TRCLK/4 /2) | 4 | 0 (unset) | J9 closed; native J20 trace | — |
+| ra8m1_ek (M85) | 480 MHz | 60 MHz (TRCLK/4 /2) | 4 | 0 (unset) | J9 closed + Table 7 jumpers | — |
+| raspberry_pi_pico2 (RP2350 M33) | 48 MHz | 24 MHz (clk_sys/2) | 4 | 0 (unset) | fly-wire GPIO1-5 → MIPI20 (map in jdebug) | 72-80 MHz per seating (re-qualify); >80 needs V3 probe + trace board |
+| same54_xplained (E54 M4F) | 120 MHz | 60 MHz (CPU/2) | 4 | 0 (unset) | none — populated 20-pin ETM header | — |
+| SEGGER H7/F407 ref | demo defaults | demo | 4 | demo | probe-powered: add `--power` | — |
+
+Board caveats (beyond the table):
+
+- **stm32h743eval**: startup-burst overflow at 400 MHz is normal (reduce
+ PLLN in board.h for overflow-free capture); timestamp ref 200 MHz.
+- **stm32n657nucleo** (M55, flashless): **JP2 (BOOT1) must be 1** — the app
+ is a RAM image the debugger loads (Development boot); in flash boot theb
+ bootROM parks the chip un-attachable ("Can not attach to CPU"). SEGGER's
+ KB says BOOT0/BOOT1 = 0/0 for their example — that is flash boot and it
+ does NOT attach; the board manual's Table 11 is right. 600 MHz core kills
+ the stream in the startup burst (timestamp flux, not overflow) — TRACE_ETM
+ builds run 300 MHz; at 600 use `--no-timestamps`. No J-Link script needed:
+ N6 trace components are ROM-table-discoverable.
+- **stm32h7s3nucleo**: width 4 is clean at idle but SB11/SB12 (default ON)
+ stub D2/D3 onto Zio CN8 and the stream dies under IRQ-heavy USB traffic —
+ remove them to try width 4 / 600 MHz. `--attach` while a USB host is
+ actively polling the device wedges its USB session (needs target reset).
+- **stm32h563nucleo**: width 4 or 250 MHz corrupts. H5 hangs its debug AP if
+ trace CoreSight is touched unclocked — handled by the committed
+ `AfterTargetConnect` hook; un-attachable after a killed session →
+ power-cycle.
+- **metro_m7_1011** (RT1011): a custom Adafruit rev with a hand-added 2x10
+ ETM header (KiCad schematic in the calibre library). No SEGGER RT1011
+ example exists — the committed .jdebug (tuned +50 ps) is the known-good
+ reference. BOARD_BootClockRUN sets the 132 MHz trace root but leaves it
+ gated; `trace_etm_init` ungates it. The first Ozone run after a fresh
+ flash can fail to reach main — transient, retry once.
+- **mcb1800**: a bad ribbon mating yields register-perfect silence — re-seat
+ BOTH ribbon ends first; SWD working proves nothing about the trace lines.
+ `--isr USB0_IRQHandler,dcd_int_handler`.
+- **nrf5340dk**: the interface MCU's UART1 flow control rides the trace
+ pins — it actively drives CTS onto P0.10/TRACEDATA1 (dead line, any
+ timing) and loads P0.11/TRACEDATA0: cut SB27/SB28 (or flip SW7 to FC-off).
+ SB57's SWO stub can stay — harmless at the +3 ns sample point. TRACE_ETM
+ builds force the TAD port to 16 MHz (SystemInit's 64 MHz is marginal).
+- **ea4088_quickstart**: FS enumeration ends < 100 ms — for `--isr` use
+ `--duration-ms 150`. Boot-ROM address warning (0x1FFF1FF0) is normal.
+- **mimxrt1170_evkb**: width 4 fails (D1-D3 path under investigation).
+ `trace_etm_init` fixes the JTAG_nTRST/DMIC_DATA1 pad, pins CSTRACE to
+ 50 MHz (stock 132 MHz corrupts — the 100M PHY drives the CLK net) and
+ enables the CM7 platform trace-funnel port, which J-Link doesn't program:
+ without it everything reads register-perfect yet zero data arrives.
+ FlexSPI apps: ROM bootloader must set SP/PC — the committed reset/download
+ hooks handle this. Startup-burst overflow at 996 MHz is normal.
+- **ra6m5_ek**: TRCKCR div-2 (100 MHz TRCLK = 50 MHz pin, the chip max) is
+ unusable on this board — swept widths 1/4 across -2..+4 ns, all dead;
+ TRACE_ETM builds use div-4 (25 MHz pin). The TCLK pin runs TRCLK/2. 50 MHz SWD TIF
+ caused intermittent "Failed to initialize DAP" — the reference runs 4 MHz.
+ ISR entry: `--isr tusb_int_handler,dcd_int_handler` (FSP's
+ usbfs_interrupt_handler symbol never actually executes).
+- **ra8m1_ek**: **J9 must be closed** (holds the on-board J-Link OB in
+ reset — open = SWD contention, intermittent "Failed to initialize DAP",
+ even an apparent brick recoverable only by power-cycle/J16 boot mode).
+ J-Link's RA8 support enables trace from reset; the committed JLinkScript's
+ empty `OnTraceStart` suppresses that so the firmware enables the trace
+ clock after the FSP clock switch — without it the MOCO→PLL step desyncs
+ the decoder at t≈0.05 s every run. Runs both chip maxima (120 MHz TRCLK,
+ 60 MHz pin) clean. `ReadIntoTraceCache 0x0 0x10000` in the download hook
+ covers runtime chip-ROM execution. ISR entry: `tusb_int_handler`.
+- **raspberry_pi_pico2** (RP2350): TRACECLK is a fixed clk_sys/2, no divider
+ (DDR data, like every ARM TPIU pin port). **Measured cliff on this rig:**
+ 80 MHz core (40 MHz TRACECLK) traces idle code but dies under dense data;
+ 88 MHz+ dies instantly at any width/global-timing/TIF/pad setting. Cause
+ not pinned down: the same V2 probe samples 66 MHz TRACECLK (132 Msample/s)
+ on metro_m7_1011, so it is NOT a plain probe sample-rate ceiling. The
+ cliff at >40 MHz TRACECLK (84+ MHz core) survived a full sweep - global
+ AND per-pin `--trace-timing`, pad drive 2/4/8/12 mA + slew, width 4/2/1,
+ TIF 1-25 MHz, newer J-Link library - all flat, so it is V3-probe / real-
+ trace-board territory (SEGGER's Pico 2 KB requires J-Trace PRO **V3.0+**
+ and recommends a proper trace board; community reports fly-wires fail at
+ 75 MHz for everyone, PCBs work). Separately, fly-wire seating quality
+ sets the width-4 DENSE-data ceiling (48-72 MHz observed across seatings):
+ after ANY rewiring re-qualify with idle blinky at the target clock, then
+ cdc_msc x3. Random unknown-packet deaths KB into a clean stream = one
+ marginal wire; `--trace-width` 1 vs 2 vs 4 bisects which (width 1 =
+ CLK+D0 only; D1 = GPIO3->MIPI20 pin 16 has gone marginal twice on this
+ rig). Width-1 is a full-quality fallback: complete cdc_msc profiles at up
+ to 80 MHz core even when width 4 is broken.
+ **Never set a custom JLinkScript** — it
+ replaces J-Link's built-in RP2350 device script, which both declares the
+ trace component map (funnel/TPIU/ETM are not in the ROM table → "Required
+ trace components for pin trace not found", 0 fetches) and re-arms the whole
+ chip-side path via `OnTraceStart` at every resume. Firmware therefore does
+ no trace setup; TRACE_ETM builds only (a) pin clk_sys to 72 MHz from crt0
+ (board.cmake) — the fly-wire ceiling: 96/150 MHz kill the stream in the
+ startup burst at any sample timing (and at 150 MHz the saturated probe
+ stops answering halts, "CPU could not be halted"); any post-arm clock
+ change steps TRACECLK mid-stream and kills the decoder — and (b)
+ clear TIMER0/1 DBGPAUSE (family.c): debug sessions leave cores
+ halted-at-reset and the default DBGPAUSE freezes the µs timer, so every
+ `sleep_ms()` spins forever (looks like a dead board; watchdog-scratch
+ breadcrumbs survive warm resets but not POR when diagnosing). UART console
+ is TX-only (GPIO1 = TRACECLK). Empty reset/download hooks: the bootrom
+ must run the IMAGE_DEF. If the chip ends up wedged/un-attachable:
+ J-Link `erase` + reset drops it into BOOTSEL (2e8a:000f) for picotool.
+- **same54_xplained**: the CM4 trace unit is clocked from **GCLK channel 47
+ (GCLK_CM4_TRACE)** — with it disabled the pins mux fine, TPIU/ETM arm
+ fine, and the port stays perfectly silent (zero fetches, no errors);
+ `trace_etm_init` feeds it GCLK0. Pins PC24-28 mux to function H. The
+ populated 20-pin header runs chip-max 60 MHz TRACECLK width 4 with no
+ timing adjustment - the connector-vs-flywire contrast board.
+- **SEGGER ref boards**: run their own demo (ladder step 3 flags); `--isr`
+ degrades gracefully without a live SysTick.
diff --git a/.claude/skills/etm-trace/scripts/etm_capture.py b/.claude/skills/etm-trace/scripts/etm_capture.py
new file mode 100644
index 000000000..6468be12d
--- /dev/null
+++ b/.claude/skills/etm-trace/scripts/etm_capture.py
@@ -0,0 +1,567 @@
+#!/usr/bin/env python3
+"""Capture streaming ETM instruction trace unattended via J-Trace + Ozone.
+
+Generates a throwaway Ozone project (never touches the committed
+hw/bsp/**/ozone/*.jdebug), launches Ozone on a virtual display (xvfb-run),
+drives the whole session over Ozone's automation TCP socket (UM08025 §6.7):
+connect -> flash -> run for --duration-ms under streaming trace -> halt ->
+export. Outputs in --out:
+ code_profile.txt hot functions (run/fetch counts) + code coverage
+ itrace.csv raw instruction history (only with --trace-csv)
+ ozone_console.log, jlink.log, ozone_gui.log session evidence
+
+Requires firmware built with -DTRACE_ETM=1 and the board wired to a J-Trace.
+Analyze results with etm_profile.py in this directory.
+"""
+
+import argparse
+import glob
+import os
+import re
+import shutil
+import signal
+import socket
+import string
+import subprocess
+import sys
+import tempfile
+import time
+
+REPO_ROOT = os.path.abspath(os.path.join(os.path.dirname(__file__), *[".."] * 4))
+
+# Throwaway Ozone project. SP/PC-from-vector-table hooks match the committed
+# reference projects (Cortex-M generic). $$(InstallDir) -> literal $(InstallDir).
+PROJECT_TEMPLATE = string.Template("""\
+/* Auto-generated by etm_capture.py (etm-trace skill) - throwaway, do not commit. */
+void OnProjectLoad (void) {
+ Project.SetDevice ("$device");
+ Project.SetHostIF ("USB", "$probe");
+ Project.SetTargetIF ("SWD");
+ Project.SetTIFSpeed ("$tif_speed");
+ Project.SetTraceSource ("Trace Pins");
+ Project.SetTracePortWidth ($port_width);
+$timing_line$core_clock_line$timestamps_line$hss_line$power_lines Edit.SysVar (VAR_TRACE_MAX_INST_CNT, $max_inst);
+ Edit.Preference (PREF_TIMESTAMP_FORMAT, TIMESTAMP_FORMAT_TIME);
+ Project.AddSvdFile ("$$(InstallDir)/Config/Peripherals/ARMv7M.svd");
+ Project.SetConsoleLogFile ("$outdir/ozone_console.log");
+ Project.SetJLinkLogFile ("$outdir/jlink.log");
+$os_plugin_line File.Open ("$elf");
+}
+$jlink_script_hook
+
+$reset_hook
+
+$download_hook
+$user_funcs""")
+
+# Cortex-M generic SP/PC-from-vector-table init. A committed board reference
+# overrides these verbatim (e.g. RT1176 apps in FlexSPI NOR need the ROM
+# bootloader to do SP/PC init, plus a JTAG_nTRST pad fix).
+DEFAULT_HOOK = """\
+void %s (void) {
+ unsigned int SP;
+ unsigned int PC;
+ unsigned int VectorTableAddr;
+ VectorTableAddr = Elf.GetBaseAddr();
+ if (VectorTableAddr == 0xFFFFFFFF) {
+ Util.Log("etm_capture: failed to get program base");
+ } else {
+ SP = Target.ReadU32(VectorTableAddr);
+ Target.SetReg("SP", SP);
+ PC = Target.ReadU32(VectorTableAddr + 4);
+ Target.SetReg("PC", PC);
+ }
+}"""
+
+# Symbolic constants (TP_OP_*, EXPORT_*) only evaluate in project-script
+# context, never over the automation socket - so these live in generated user
+# functions invoked via Script.Exec (UM08025 SS6.7, SS7.9.9.1).
+TRACEPOINT_FUNC = """\
+
+void SetupTracepoints (void) {
+%s}
+"""
+
+LINES_CSV_FUNC = """\
+
+void ExportLinesCsv (void) {
+ Export.CodeProfile ("%s", EXPORT_AS_CSV | EXPORT_CSV_LINES | EXPORT_FILE_PATHS, "");
+}
+"""
+
+INSTS_CSV_FUNC = """\
+
+void ExportInstsCsv (void) {
+ Export.CodeProfile ("%s", EXPORT_AS_CSV | EXPORT_CSV_INSTS | EXPORT_FILE_PATHS, "");
+}
+"""
+
+
+JLINK_SCRIPT_HOOK = """\
+
+void BeforeTargetConnect (void) {
+ Project.SetJLinkScript ("%s");
+}
+"""
+
+
+def resolve_board(board):
+ """Board config from its committed ozone reference project, else board.cmake/mk."""
+ cfg = {"device": None, "tif_speed": "4 MHz", "timing": None, "port_width": 4,
+ "core_clock": None, "ref": None}
+ jdebugs = sorted(glob.glob(f"{REPO_ROOT}/hw/bsp/*/boards/{board}/ozone/*.jdebug"))
+ if jdebugs:
+ cfg["ref"] = jdebugs[0]
+ text = open(jdebugs[0]).read()
+ # config regexes must not match //-commented lines
+ cfgtext = re.sub(r"^\s*//.*$", "", text, flags=re.M)
+ # inherit every user function verbatim except OnProjectLoad, which the
+ # template owns (e.g. STM32H5's AfterTargetConnect must clock the trace
+ # CoreSight domain; RT1176 replaces the SP/PC reset/download hooks for
+ # ROM-bootloader boot; Nordic hooks call a _SetupTarget helper that
+ # must ride along or hook execution fails at runtime)
+ extra = []
+ for m in re.finditer(r"^void (\w+)\s*\(void\)\s*\{.*?^\}", text,
+ re.M | re.S):
+ name, block = m.group(1), m.group(0)
+ if name == "OnProjectLoad":
+ continue
+ elif name == "AfterTargetReset":
+ cfg["reset_hook"] = block
+ elif name == "AfterTargetDownload":
+ cfg["download_hook"] = block
+ else:
+ extra.append(block)
+ if extra:
+ cfg["connect_hook"] = "\n\n".join(extra) + "\n"
+ for key, pat in (("device", r'Project\.SetDevice\s*\(\s*"([^"]+)"'),
+ ("tif_speed", r'Project\.SetTIFSpeed\s*\(\s*"([^"]+)"'),
+ ("timing", r'Project\.SetTraceTiming\s*\(([-\d\s,]+)\)'),
+ ("port_width", r'Project\.SetTracePortWidth\s*\(\s*(\d+)'),
+ ("core_clock", r'VAR_TRACE_CORE_CLOCK\s*,\s*(\d+)')):
+ m = re.search(pat, cfgtext)
+ if m:
+ cfg[key] = m.group(1).strip()
+ # inherit a J-Link script (e.g. RT1176 must declare its off-ROM-table
+ # TPIU/funnel); relative paths resolve against the reference's dir
+ m = re.search(r'Project\.SetJLinkScript\s*\(\s*"([^"]+)"', cfgtext)
+ if m:
+ # $(ProjectDir) = the reference's own directory
+ rel = m.group(1).replace("$(ProjectDir)", ".")
+ cfg["jlink_script"] = os.path.normpath(os.path.join(
+ os.path.dirname(jdebugs[0]), rel))
+ else:
+ for path in glob.glob(f"{REPO_ROOT}/hw/bsp/*/boards/{board}/board.cmake"):
+ m = re.search(r'JLINK_DEVICE\s+([^\s)]+)\s*\)', open(path).read())
+ if m:
+ cfg["device"] = m.group(1)
+ cfg["ref"] = path
+ break
+ if not cfg["device"]:
+ sys.exit(f"error: cannot resolve J-Link device for board '{board}' "
+ f"(no hw/bsp/*/boards/{board}/ozone/*.jdebug or board.cmake)")
+ return cfg
+
+
+def trace_only_points(elf, syms_arg):
+ """Tracepoint lines for --trace-only: start trace at each symbol's entry,
+ stop at each return instruction inside it (pop ...pc / bx lr, via objdump).
+ Hardware comparators are scarce (ETM-M7) - keep the symbol list short."""
+ lines = ""
+ nm = subprocess.run(["arm-none-eabi-nm", "-S", "--defined-only", elf],
+ capture_output=True, text=True).stdout
+ for want in [s.strip() for s in syms_arg.split(",") if s.strip()]:
+ m = re.search(rf"^([0-9a-f]+) ([0-9a-f]+) [TtWw] {re.escape(want)}$",
+ nm, re.M)
+ if not m:
+ sys.exit(f"error: --trace-only symbol '{want}' not in ELF")
+ lo, sz = int(m.group(1), 16) & ~1, int(m.group(2), 16)
+ lines += f' Trace.SetPoint (TP_OP_START_TRACE, "{want}");\n'
+ dis = subprocess.run(
+ ["arm-none-eabi-objdump", "-d", f"--start-address={lo:#x}",
+ f"--stop-address={lo + sz:#x}", elf],
+ capture_output=True, text=True).stdout
+ exits = re.findall(
+ r"^\s*([0-9a-f]+):.*?(?:(?:pop|ldmia[.\w]*\s+sp!,)[^\n]*\bpc\b|bx\s+lr)",
+ dis, re.M | re.I)
+ if not exits:
+ sys.exit(f"error: no return instruction found in '{want}'")
+ for addr in exits:
+ lines += f' Trace.SetPoint (TP_OP_STOP_TRACE, "0x{int(addr, 16):08X}");\n'
+ return lines
+
+
+def resolve_probe(probe):
+ """Ozone's SetHostIF needs a serial - with several probes connected a
+ nickname makes it block on a selection dialog. JLinkExe DOES resolve
+ nicknames, so borrow its banner to map nickname -> serial. The serial only
+ ever lands in the throwaway project file, never in committed files."""
+ if not probe or probe.isdigit():
+ return probe
+ r = subprocess.run(["JLinkExe", "-USB", probe, "-nogui", "1"],
+ input="qc\n", capture_output=True, text=True, timeout=30)
+ m = re.search(r"S/N:\s*(\d+)", r.stdout)
+ if not m:
+ sys.exit(f"error: cannot resolve probe nickname '{probe}' to a serial "
+ f"(JLinkExe -USB {probe} found no emulator)")
+ return m.group(1)
+
+
+def gen_project(cfg, args, outdir):
+ timing = ""
+ if args.trace_timing is not None:
+ d = [int(v) for v in str(args.trace_timing).split(",")]
+ if len(d) not in (1, 4):
+ sys.exit("error: --trace-timing takes one value or d0,d1,d2,d3")
+ d = d * 4 if len(d) == 1 else d
+ timing = (" Project.SetTraceTiming "
+ f"({d[0]}, {d[1]}, {d[2]}, {d[3]});\n")
+ elif cfg["timing"]:
+ timing = f" Project.SetTraceTiming ({cfg['timing']});\n"
+ core_clock = args.core_clock or cfg["core_clock"]
+ clk_line = f" Edit.SysVar (VAR_TRACE_CORE_CLOCK, {core_clock});\n" if core_clock else ""
+ ts_line = (" Edit.SysVar (VAR_TRACE_TIMESTAMPS_ENABLED, 0);\n"
+ if args.no_timestamps else "")
+ user_funcs = ""
+ if cfg.get("connect_hook"):
+ user_funcs += "\n" + cfg["connect_hook"]
+ if args.trace_only:
+ user_funcs += TRACEPOINT_FUNC % trace_only_points(
+ os.path.abspath(args.elf), args.trace_only)
+ if args.profile_lines_csv:
+ user_funcs += LINES_CSV_FUNC % os.path.join(outdir, "profile_lines.csv")
+ if args.profile_insts_csv:
+ user_funcs += INSTS_CSV_FUNC % os.path.join(outdir, "profile_insts.csv")
+ if args.os_plugin and not glob.glob(
+ f"/opt/SEGGER/Ozone*/Plugins/OS/{args.os_plugin}.js"):
+ sys.exit(f"error: RTOS plugin '{args.os_plugin}' not in "
+ f"/opt/SEGGER/Ozone*/Plugins/OS (e.g. FreeRTOSPlugin_CM7)")
+ os_plugin = (f' Project.SetOSPlugin ("{args.os_plugin}");\n'
+ if args.os_plugin else "")
+ if args.attach:
+ # attach to the running target: no download, no reset - trace a window
+ # mid-run (firmware must match the ELF and have trace pins enabled)
+ os_plugin += " Debug.SetConnectMode (CM_ATTACH_HALT);\n"
+ # HSS sampling rate belongs in OnProjectLoad (persistent) per UM08025 4.6.2;
+ # setting it mid-session over the socket is rejected.
+ hss = (f" Edit.SysVar (VAR_HSS_SPEED, {args.sample_hz});\n"
+ if args.sample else "")
+ power = (" Edit.SysVar (VAR_TARGET_POWER_ON, 1);\n"
+ f" Edit.SysVar (VAR_POWER_SAMPLING_SPEED, {args.power_hz});\n"
+ if args.power else "")
+ jlink_script = args.jlink_script or cfg.get("jlink_script")
+ jls_hook = (JLINK_SCRIPT_HOOK % os.path.abspath(jlink_script)
+ if jlink_script else "")
+ proj = os.path.join(outdir, "etm_capture.jdebug")
+ if args.trace_width:
+ cfg["port_width"] = args.trace_width
+ with open(proj, "w") as f:
+ f.write(PROJECT_TEMPLATE.substitute(
+ device=cfg["device"], probe=resolve_probe(args.probe),
+ tif_speed=cfg["tif_speed"],
+ port_width=cfg["port_width"], timing_line=timing, core_clock_line=clk_line,
+ timestamps_line=ts_line, max_inst=args.max_inst, outdir=outdir,
+ elf=os.path.abspath(args.elf), user_funcs=user_funcs,
+ os_plugin_line=os_plugin, hss_line=hss, power_lines=power,
+ jlink_script_hook=jls_hook,
+ reset_hook=cfg.get("reset_hook", DEFAULT_HOOK % "AfterTargetReset"),
+ download_hook=cfg.get("download_hook",
+ DEFAULT_HOOK % "AfterTargetDownload")))
+ return proj
+
+
+class OzoneSession:
+ """Drive Ozone via its automation TCP socket (one connection at a time)."""
+
+ def __init__(self, port, logf):
+ self.port = port
+ self.logf = logf
+ self.sock = None
+
+ def log(self, msg):
+ line = f"[{time.strftime('%H:%M:%S')}] {msg}"
+ print(line, flush=True)
+ self.logf.write(line + "\n")
+ self.logf.flush()
+
+ def connect(self, timeout_s):
+ deadline = time.time() + timeout_s
+ while time.time() < deadline:
+ try:
+ self.sock = socket.create_connection(("127.0.0.1", self.port), timeout=5)
+ self.sock.settimeout(0.5)
+ self.log(f"connected to Ozone automation socket :{self.port}")
+ return
+ except OSError:
+ time.sleep(1)
+ raise TimeoutError(f"Ozone automation socket :{self.port} not reachable "
+ f"after {timeout_s}s (see ozone_gui.log)")
+
+ def drain(self, wait_s=1.0):
+ buf = b""
+ end = time.time() + wait_s
+ while time.time() < end:
+ try:
+ chunk = self.sock.recv(65536)
+ if not chunk:
+ break
+ buf += chunk
+ end = time.time() + 0.5 # keep reading while data flows
+ except socket.timeout:
+ pass
+ text = buf.decode(errors="replace")
+ for ln in text.splitlines():
+ self.log(f" ozone> {ln}")
+ return text
+
+ def send(self, cmd, wait_s=1.0):
+ self.log(f"cmd: {cmd}")
+ self.sock.sendall((cmd + "\n").encode())
+ return self.drain(wait_s)
+
+ def wait_echo(self, cmd, timeout_s):
+ """Send cmd; wait until Ozone echoes its execution (echo comes after the
+ command completed, e.g. a large Export). Returns all received text."""
+ name = cmd.split("(")[0].strip()
+ text = self.send(cmd, 1.0)
+ deadline = time.time() + timeout_s
+ while name + " (" not in text and name + "(" not in text:
+ if time.time() > deadline:
+ raise TimeoutError(f"no echo for '{name}' after {timeout_s}s")
+ text += self.drain(1.0)
+ return text
+
+ def is_halted(self, timeout_s):
+ """Poll Debug.IsHalted until it returns 1; parse the '// returns 0xN' echo."""
+ deadline = time.time() + timeout_s
+ while time.time() < deadline:
+ text = self.send("Debug.IsHalted", 1.0)
+ end2 = time.time() + 4.0
+ while "Debug.IsHalted" not in text and time.time() < end2:
+ text += self.drain(1.0)
+ m = re.findall(r"Debug\.IsHalted\s*\(\);\s*//\s*returns\s*0x(\d+)", text)
+ if m and m[-1] == "1":
+ return True
+ time.sleep(1)
+ return False
+
+
+def main():
+ p = argparse.ArgumentParser(description=__doc__,
+ formatter_class=argparse.RawDescriptionHelpFormatter)
+ p.add_argument("--board", help="TinyUSB board name, e.g. stm32h743eval")
+ p.add_argument("--device", help="J-Link device name for non-TinyUSB targets "
+ "(e.g. STM32F407VE for a SEGGER trace reference board); "
+ "requires --elf, bypasses hw/bsp board resolution")
+ p.add_argument("--tif-speed", default="4 MHz",
+ help="SWD speed for --device targets (default '4 MHz')")
+ p.add_argument("--jlink-script",
+ help="J-Link script file (.pex/.JLinkScript) for trace-pin "
+ "init when the firmware doesn't do it (SEGGER per-MCU "
+ "examples); wired into BeforeTargetConnect")
+ p.add_argument("--power", action="store_true",
+ help="power the target from the probe and record a power "
+ "profile (power.csv); probe power is switched off after "
+ "the session. Target must be wired for probe power!")
+ p.add_argument("--power-hz", type=int, default=10000,
+ help="power sampling frequency in Hz (default 10000)")
+ p.add_argument("--elf", help="firmware ELF built with -DTRACE_ETM=1 "
+ "(default: examples/cmake-build-<board>/device/cdc_msc/cdc_msc.elf)")
+ p.add_argument("--duration-ms", type=int, default=10000, help="traced run time")
+ p.add_argument("--out", help="output dir (default: mkdtemp under /tmp)")
+ p.add_argument("--port", type=int, default=19201,
+ help="automation socket port (19200 = interactive Ozone default; keep 19201)")
+ p.add_argument("--probe", default="",
+ help="J-Link USB nickname or serial ('' = sole connected probe)")
+ p.add_argument("--trace-csv", action="store_true",
+ help="also export raw instruction history (itrace.csv, can be >100 MB)")
+ p.add_argument("--max-inst", type=int, default=10000000,
+ help="VAR_TRACE_MAX_INST_CNT: instruction-trace window/export depth")
+ p.add_argument("--core-clock", type=int,
+ help="CPU Hz for timestamp conversion (default: board reference value)")
+ p.add_argument("--trace-timing",
+ help="trace sample delay in ps (-5000..5000, overrides the "
+ "board reference; sweep this when the stream dies with "
+ "unknown-packet errors). One value for all 4 pins, or "
+ "'d0,d1,d2,d3' to de-skew individual lines (boards can "
+ "have per-line RC delays, e.g. strap pulls on muxed pads)")
+ p.add_argument("--trace-width", type=int, choices=(1, 2, 4),
+ help="trace port width override (fewer pins = tolerant of a "
+ "single bad line, at reduced bandwidth)")
+ p.add_argument("--no-timestamps", action="store_true",
+ help="disable trace timestamps (less trace bandwidth -> fewer "
+ "overflows/decode errors; itrace.csv loses its time column)")
+ p.add_argument("--trace-only",
+ help="comma-separated symbols: trace ONLY these functions via "
+ "hardware tracepoints (e.g. an ISR + SysTick_Handler for "
+ "calibration); needs few symbols (scarce comparators)")
+ p.add_argument("--profile-lines-csv", action="store_true",
+ help="also export per-source-line profile/coverage counters "
+ "(profile_lines.csv)")
+ p.add_argument("--profile-insts-csv", action="store_true",
+ help="also export per-instruction counters (profile_insts.csv, "
+ "enables branch-bias analysis in etm_profile.py)")
+ p.add_argument("--attach", action="store_true",
+ help="attach to the RUNNING target instead of flash+reset: "
+ "capture a window mid-run (narrowing debug). The flashed "
+ "firmware must match --elf and have been built with "
+ "TRACE_ETM=1")
+ p.add_argument("--sample",
+ help="comma-separated C expressions to sample periodically "
+ "during the run (samples.csv, e.g. 'system_ticks')")
+ p.add_argument("--sample-hz", type=int, default=1000,
+ help="data sampling frequency in Hz (default 1000)")
+ p.add_argument("--os-plugin",
+ help="Ozone RTOS-awareness plugin for task/ISR-attributed "
+ "timeline, e.g. FreeRTOSPlugin_CM7 (see "
+ "/opt/SEGGER/Ozone*/Plugins/OS)")
+ args = p.parse_args()
+
+ if not args.board and not args.device:
+ sys.exit("error: need --board (TinyUSB) or --device + --elf (other targets)")
+ if args.device and not args.elf:
+ sys.exit("error: --device requires --elf")
+ if args.max_inst > 10000000:
+ # >10M yielded a silently EMPTY Export.Trace on Ozone V3.50
+ print("warning: --max-inst clamped to 10000000 (larger values produce "
+ "an empty instruction-trace export)", file=sys.stderr)
+ args.max_inst = 10000000
+ if not args.elf:
+ args.elf = (f"{REPO_ROOT}/examples/cmake-build-{args.board}"
+ f"/device/cdc_msc/cdc_msc.elf")
+ if not os.path.isfile(args.elf):
+ sys.exit(f"error: ELF not found: {args.elf}\n"
+ f"build it with -DTRACE_ETM=1 (see the etm-trace skill) or pass --elf")
+
+ if args.trace_only:
+ print("warning: --trace-only is EXPERIMENTAL - on some targets windows "
+ "for low-rate handlers fail to record, and timestamps are invalid "
+ "across trace gaps (instruction counts remain exact). For ISR "
+ "timing prefer a full --trace-csv capture + etm_profile.py --isr.",
+ file=sys.stderr)
+ if args.device:
+ cfg = {"device": args.device, "tif_speed": args.tif_speed, "timing": None,
+ "port_width": 4, "core_clock": None, "ref": "--device"}
+ else:
+ cfg = resolve_board(args.board)
+ outdir = os.path.abspath(args.out) if args.out else tempfile.mkdtemp(
+ prefix=f"etm-{args.board or args.device}-")
+ os.makedirs(outdir, exist_ok=True)
+ proj = gen_project(cfg, args, outdir)
+
+ ozone_bin = shutil.which("ozone") or shutil.which("Ozone")
+ if not ozone_bin:
+ sys.exit("error: ozone not on PATH (install SEGGER Ozone)")
+ cmd = [ozone_bin, "-project", proj, "-port", str(args.port)]
+ if shutil.which("xvfb-run"):
+ cmd = ["xvfb-run", "-a"] + cmd
+ elif os.environ.get("DISPLAY"):
+ print("warning: xvfb-run not found - Ozone window will appear on "
+ f"DISPLAY={os.environ['DISPLAY']} and may steal keyboard focus",
+ file=sys.stderr)
+ else:
+ sys.exit("error: no DISPLAY and no xvfb-run; install xvfb")
+
+ gui_log = open(os.path.join(outdir, "ozone_gui.log"), "w")
+ ses_logf = open(os.path.join(outdir, "session.log"), "w")
+ ses = OzoneSession(args.port, ses_logf)
+ ses.log(f"board={args.board} device={cfg['device']} ref={cfg['ref']}")
+ ses.log(f"elf={args.elf}")
+ ses.log(f"out={outdir}")
+ proc = subprocess.Popen(cmd, stdout=gui_log, stderr=gui_log,
+ start_new_session=True)
+ profile_out = os.path.join(outdir, "code_profile.txt")
+ itrace_out = os.path.join(outdir, "itrace.csv")
+ ok = False
+ try:
+ ses.connect(20)
+ ses.drain(3) # version banner
+ ses.send("Debug.Start", 5)
+ if not ses.is_halted(90):
+ raise TimeoutError("Debug.Start did not reach the startup completion "
+ "point (connect/flash failed? see jlink.log)")
+ ses.log("startup complete (halted at main)")
+ if args.trace_only:
+ ses.wait_echo('Script.Exec ("SetupTracepoints")', 15)
+ ses.send('Window.Show ("Code Profile")', 2)
+ if args.trace_csv:
+ ses.send('Window.Show ("Instruction Trace")', 2)
+ if args.sample:
+ ses.send('Window.Show ("Data Sampling")', 2)
+ for expr in args.sample.split(","):
+ ses.send(f'Window.Add ("Data Sampling", "{expr.strip()}")', 2)
+ ses.send("Coverage.ExcludeNOPs()", 2)
+
+ ses.log(f"=== traced run: {args.duration_ms} ms ===")
+ ses.send("Debug.Continue", 1)
+ time.sleep(args.duration_ms / 1000.0)
+ ses.send("Debug.Halt", 3)
+ if not ses.is_halted(30):
+ raise TimeoutError("target did not halt")
+ ses.send("Window.WaitForUpdateComplete(120000)", 5)
+
+ ses.wait_echo(f'Export.CodeProfile ("{profile_out}", 0, "")', 60)
+ if args.profile_lines_csv:
+ ses.wait_echo('Script.Exec ("ExportLinesCsv")', 60)
+ if args.profile_insts_csv:
+ ses.wait_echo('Script.Exec ("ExportInstsCsv")', 120)
+ if args.trace_csv:
+ ses.wait_echo(f'Export.Trace ("{itrace_out}", 0)', 300)
+ if args.sample:
+ ses.wait_echo(f'Export.DataGraphs ("{outdir}/samples.csv")', 60)
+ if args.power:
+ ses.wait_echo(f'Export.PowerGraphs ("{outdir}/power.csv")', 60)
+ ses.send("Debug.Stop", 5)
+ ses.send("File.Exit", 2)
+ ok = True
+ finally:
+ for _ in range(15):
+ if proc.poll() is not None:
+ break
+ time.sleep(1)
+ if proc.poll() is None:
+ ses.log("killing leftover Ozone process group")
+ os.killpg(proc.pid, signal.SIGKILL)
+ if args.power:
+ # guarantee probe power is off, whatever happened above
+ sel = ["-USB", args.probe] if args.probe else []
+ r = subprocess.run(["JLinkExe", *sel, "-nogui", "1"],
+ input="power off\nqc\n", capture_output=True,
+ text=True, timeout=30)
+ ses.log("probe power off " +
+ ("issued" if r.returncode == 0 else f"FAILED rc={r.returncode}"))
+
+ if not (os.path.isfile(profile_out) and os.path.getsize(profile_out) > 0
+ and "Code Profile Report" in open(profile_out, errors="replace").read(200)):
+ sys.exit(f"error: capture ran but {profile_out} is missing/empty - "
+ f"check {outdir}/session.log and ozone_console.log")
+ if args.trace_csv and not (os.path.isfile(itrace_out)
+ and os.path.getsize(itrace_out) > 0):
+ sys.exit(f"error: --trace-csv requested but {itrace_out} is missing/empty")
+ if args.power and not os.path.getsize(os.path.join(outdir, "power.csv")):
+ sys.exit("error: --power requested but power.csv is missing/empty")
+ if "Trace collection stopped!" in open(os.path.join(outdir, "session.log"),
+ errors="replace").read():
+ sys.exit("error: trace stream died mid-run (unknown trace data packet) - "
+ "the profile only covers up to that point. Retry with "
+ "--no-timestamps, or reduce the core clock (see SKILL.md).")
+ prof = open(profile_out, errors="replace").read()
+ m = re.search(r"^\s*Total\s*\|[\d ]*\|\s*([\d ]+)$", prof, re.M)
+ if not m or int(m.group(1).replace(" ", "") or 0) == 0:
+ sys.exit("error: session completed but NO trace data was collected "
+ "(profile totals are zero) - trace signal not reaching the "
+ "probe: check wiring/connector, trace pinmux, sample timing.")
+ if not ok:
+ sys.exit("error: session did not complete cleanly (see session.log)")
+
+ print(f"\ncapture OK: {outdir}")
+ print(f" code_profile.txt ({os.path.getsize(profile_out)} bytes)")
+ if args.trace_csv:
+ print(f" itrace.csv ({os.path.getsize(itrace_out)} bytes)")
+ print(f"analyze: python3 {os.path.dirname(os.path.abspath(__file__))}"
+ f"/etm_profile.py {outdir} --elf {args.elf}")
+ return 0
+
+
+if __name__ == "__main__":
+ sys.exit(main())
diff --git a/.claude/skills/etm-trace/scripts/etm_profile.py b/.claude/skills/etm-trace/scripts/etm_profile.py
new file mode 100644
index 000000000..c5ddf27a7
--- /dev/null
+++ b/.claude/skills/etm-trace/scripts/etm_profile.py
@@ -0,0 +1,428 @@
+#!/usr/bin/env python3
+"""Analyze an etm_capture.py output dir: hot functions, coverage, itrace digest,
+ISR episode timing, and optimization hints.
+
+Input: code_profile.txt (Ozone Export.CodeProfile text report), and optionally
+ itrace.csv (Export.Trace raw instruction history) with --elf for
+ address->function mapping (arm-none-eabi-nm).
+Output: markdown report on stdout.
+
+--isr SYM[,SYM..] episode timing for an interrupt handler: first symbol is the
+ entry anchor (its first instruction marks each ISR entry), all symbols
+ form the body address set. Example: --isr OTG_HS_IRQHandler,dcd_int_handler
+ Durations are calibrated against SysTick_Handler beats (1 ms apart), so
+ the itrace must be captured with timestamps enabled.
+"""
+
+import argparse
+import bisect
+import csv
+import os
+import re
+import statistics
+import subprocess
+import sys
+
+
+def parse_profile(path):
+ """Parse the two report sections. Function rows are indented 2 spaces under
+ a non-indented module row; columns are '|'-separated."""
+ lines = open(path, errors="replace").read().splitlines()
+ try:
+ cov_start = lines.index("Code Coverage Summary")
+ prof_start = lines.index("Code Profile Summary")
+ except ValueError:
+ sys.exit(f"error: {path} is not an Ozone code-profile text report")
+
+ def rows(section):
+ module = None
+ for ln in section:
+ if "|" not in ln:
+ continue
+ cells = ln.split("|")
+ name = cells[0].rstrip()
+ if (not name or name.startswith("Module/Function")
+ or set(name.strip()) <= {"-", "+"}):
+ continue
+ if not name.startswith(" "):
+ module = name.strip()
+ continue
+ yield module, name.strip(), cells[1:]
+
+ def num(s):
+ s = s.strip().replace(" ", "")
+ return int(s) if s else 0
+
+ cov_pat = re.compile(r"^\s*([\d ]+)/\s*([\d ]+)\s+([\d.]+)%")
+ funcs, totals = {}, {}
+ for module, name, cells in rows(lines[prof_start:]):
+ run, fetch = (num(cells[0]) if cells else 0), (num(cells[1]) if len(cells) > 1 else 0)
+ if name == "Total":
+ totals["run"], totals["fetch"] = run, fetch
+ elif name == "[Unaccounted]":
+ totals["unaccounted"] = fetch
+ else:
+ funcs[name] = {"module": module, "run": run, "fetch": fetch}
+ for module, name, cells in rows(lines[cov_start:prof_start]):
+ m_src = cov_pat.match(cells[0]) if cells else None
+ m_inst = cov_pat.match(cells[1]) if len(cells) > 1 else None
+ if name == "Total" and m_inst:
+ totals["src_cov"] = num(m_src.group(1)), num(m_src.group(2))
+ totals["inst_cov"] = num(m_inst.group(1)), num(m_inst.group(2))
+ elif name in funcs and m_inst:
+ funcs[name]["inst_pct"] = float(m_inst.group(3))
+ return funcs, totals
+
+
+def load_symbols(elf):
+ """Sorted (addr, size, name) from nm; for mapping itrace addresses."""
+ nm = "arm-none-eabi-nm"
+ out = subprocess.run([nm, "-S", "--defined-only", "-C", elf],
+ capture_output=True, text=True)
+ if out.returncode != 0:
+ sys.exit(f"error: {nm} failed on {elf}: {out.stderr.strip()}")
+ syms = []
+ for ln in out.stdout.splitlines():
+ parts = ln.split(maxsplit=3)
+ if len(parts) == 4 and parts[2].lower() in ("t", "w"):
+ syms.append((int(parts[0], 16) & ~1, int(parts[1], 16), parts[3]))
+ elif len(parts) == 3 and parts[1].lower() in ("t", "w"):
+ # sizeless symbol (e.g. weak asm stub): assume a 2-byte body
+ syms.append((int(parts[0], 16) & ~1, 2, parts[2]))
+ return sorted(syms)
+
+
+def addr_to_func(syms, addr):
+ i = bisect.bisect_right(syms, (addr, 1 << 62, "")) - 1
+ if i >= 0 and syms[i][0] <= addr < syms[i][0] + syms[i][1]:
+ return syms[i][2]
+ return None
+
+
+def sym_ranges(syms, names):
+ """(lo, hi) address ranges for the named symbols (base name match);
+ None if any symbol is missing (caller degrades gracefully)."""
+ out = []
+ for want in names:
+ for a, sz, n in syms:
+ if n == want or n.split("(")[0] == want:
+ out.append((a, a + sz))
+ break
+ else:
+ print(f"note: symbol '{want}' not found in ELF")
+ return None
+ return out
+
+
+def iter_itrace(path):
+ """Yield (t_raw, addr) chronologically-reversed (file order: newest first).
+ Also returns the timestamp unit from the header via generator .send? No -
+ caller reads unit separately with itrace_unit()."""
+ with open(path, newline="", errors="replace") as f:
+ rd = csv.reader(f)
+ next(rd, None)
+ for row in rd:
+ if not row or row[0] == "PC" or len(row) < 2:
+ continue
+ try:
+ yield float(row[0]), int(row[1], 16)
+ except ValueError:
+ continue
+
+
+def itrace_unit(path):
+ hdr = open(path, errors="replace").readline()
+ m = re.search(r"Timestamp\[([^\]]+)\]", hdr)
+ return m.group(1) if m else "?"
+
+
+def time_by_func(path, syms):
+ """Per-function raw-time and instruction attribution from the itrace.
+ Rows are newest-first; the gap to the next (older) row is attributed to the
+ older instruction's function. Outlier gaps (trace-block boundaries) are
+ capped so one discontinuity cannot skew a function. Shares are scale-free."""
+ sample = []
+ t_prev = None
+ for t, _ in iter_itrace(path):
+ if t_prev is not None and t_prev - t > 0:
+ sample.append(t_prev - t)
+ if len(sample) >= 200000:
+ break
+ t_prev = t
+ cap = 10000 * statistics.median(sample) if sample else float("inf")
+ t_prev = None
+ tf, cf = {}, {}
+ n = 0
+ for t, a in iter_itrace(path):
+ n += 1
+ fn = addr_to_func(syms, a)
+ if fn:
+ cf[fn] = cf.get(fn, 0) + 1
+ if t_prev is not None:
+ d = t_prev - t
+ if 0 < d < cap and fn:
+ tf[fn] = tf.get(fn, 0) + d
+ t_prev = t
+ return tf, cf, n
+
+
+def isr_report(itrace, elf, isr_arg, top):
+ syms = load_symbols(elf)
+ names = [s.strip() for s in isr_arg.split(",") if s.strip()]
+ body = sym_ranges(syms, names)
+ tick = sym_ranges(syms, ["SysTick_Handler"])
+ if not body or not tick:
+ print("\n## ISR timing: skipped (missing symbols above - needs the ISR "
+ "symbol(s) and SysTick_Handler for calibration)")
+ return
+ entry = body[0][0]
+ unit = itrace_unit(itrace)
+
+ usb_rows, tick_rows, tmin, tmax = [], [], None, None
+ for t, a in iter_itrace(itrace):
+ tmin = t if tmin is None else min(tmin, t)
+ tmax = t if tmax is None else max(tmax, t)
+ if any(lo <= a < hi for lo, hi in body):
+ usb_rows.append((t, a))
+ # independent, not elif: when the ISR under test IS SysTick_Handler,
+ # its rows must still feed the calibration
+ if any(lo <= a < hi for lo, hi in tick):
+ tick_rows.append((t, a))
+ usb_rows.reverse()
+ tick_rows.reverse()
+ if len(tick_rows) < 20:
+ print(f"\n## ISR timing: not enough SysTick beats for calibration "
+ f"({len(tick_rows)} rows) - capture with timestamps enabled")
+ return
+
+ # rough raw-units-per-1ms from the large mode of consecutive tick deltas
+ deltas = [b[0] - a[0] for a, b in zip(tick_rows, tick_rows[1:])]
+ big = [d for d in deltas if d > max(deltas) / 10]
+ raw_ms = statistics.median(big)
+ gap = 0.03 * raw_ms # 30 us in raw units
+ edge = 0.05 * raw_ms
+
+ def episodes(rows, g):
+ out, cur = [], []
+ for t, a in rows:
+ if cur and t - cur[-1][0] > g:
+ out.append(cur)
+ cur = []
+ cur.append((t, a))
+ if cur:
+ out.append(cur)
+ return out
+
+ starts = [e[0][0] for e in episodes(tick_rows, 0.1 * raw_ms)]
+
+ def local_scale(t):
+ i = bisect.bisect_left(starts, t)
+ if 0 < i < len(starts):
+ sp = starts[i] - starts[i - 1]
+ if 0 < sp < 3 * raw_ms:
+ return 1e-3 / sp
+ return 1e-3 / raw_ms
+
+ eps = []
+ for cluster in episodes(usb_rows, gap):
+ cur = None
+ for t, a in cluster:
+ if a == entry:
+ if cur:
+ eps.append(cur)
+ cur = [(t, a)]
+ elif cur:
+ cur.append((t, a))
+ if cur:
+ eps.append(cur)
+ eps = [e for e in eps if e[0][0] - tmin > edge and tmax - e[-1][0] > edge
+ and len(e) >= 10]
+ print(f"\n## ISR timing: {names[0]} (+{len(names) - 1} body syms), "
+ f"unit '{unit}', {len(starts)} SysTick beats")
+ if not eps:
+ print("- no complete episodes in window (wrong symbols? window missed "
+ "the traffic phase?)")
+ return
+ stats = sorted(((e[-1][0] - e[0][0]) * local_scale(e[0][0]), len(e), e[0][0])
+ for e in eps)
+ cal = [s[0] for s in stats]
+ print(f"- episodes: {len(cal)} | fastest {min(cal) * 1e6:.2f} us, "
+ f"median {statistics.median(cal) * 1e6:.2f} us, "
+ f"avg {statistics.mean(cal) * 1e6:.2f} us, "
+ f"worst {max(cal) * 1e6:.2f} us")
+ insts = [s[1] for s in stats]
+ print(f"- instructions/episode: min {min(insts)}, avg "
+ f"{statistics.mean(insts):.0f}, max {max(insts)}")
+ print("- worst episodes (duration, instructions, raw start):")
+ for c, n, t0 in stats[-5:][::-1]:
+ print(f" - {c * 1e6:8.2f} us {n:5d} instr t={t0:.6f}")
+ print("- caveats: timestamps are interpolated between packets (sub-us "
+ "values are approximate); episodes may merge if trace overflow "
+ "dropped an entry")
+
+
+def short(name):
+ return re.sub(r"\(.*\)$", "()", name)
+
+
+def branch_bias(insts_csv, funcs, top):
+ """One-sided conditional branches in executed functions (profile_insts.csv):
+ a conditional fetched N times but taken/executed 0 or N times = a branch
+ that never varied -> hot always-true assert, dead path, or an invariant
+ that could hoist out of a loop (UM08025 SS5.19)."""
+ def n(v):
+ v = (v or "").replace(" ", "")
+ return int(v) if v.lstrip("-").isdigit() else 0
+ biased = []
+ with open(insts_csv, newline="", errors="replace") as f:
+ for r in csv.DictReader(f):
+ if (r.get("Is Conditional") or "0").strip() != "1":
+ continue
+ fetched = n(r.get("Times Fetched"))
+ executed = n(r.get("Times Executed"))
+ if fetched < 1000: # only hot conditionals matter
+ continue
+ if executed == 0 or executed == fetched:
+ biased.append((fetched, r.get("Function", "?"),
+ r.get("Address", ""), r.get("AsmCode", "").strip(),
+ "always-taken" if executed == fetched else "never-taken"))
+ if not biased:
+ return
+ biased.sort(reverse=True)
+ print(f"\n## One-sided hot branches (profile_insts.csv)\n")
+ print("Conditionals that never varied - candidates to hoist/remove "
+ "(UM08025 §5.19):")
+ for fetched, fn, addr, asm, kind in biased[:top]:
+ print(f"- `{short(fn)}` @{addr} {kind} ({fetched:,}x): `{asm[:50]}`")
+
+
+def suggestions(funcs, totals, tshare, cshare, exclude):
+ """Rule-based optimization hints (after UM08025 §5.19)."""
+ print("\n## Optimization hints")
+ total_fetch = totals.get("fetch") or 1
+ ex = [n for n in funcs if exclude and re.search(exclude, n)]
+ ex_fetch = sum(funcs[n]["fetch"] for n in ex)
+ if ex:
+ print(f"- excluded from load ranking (--exclude): {len(ex)} functions, "
+ f"{100.0 * ex_fetch / total_fetch:.1f}% of fetches")
+ rest = {n: v for n, v in funcs.items() if n not in ex}
+ rt = sum(v["fetch"] for v in rest.values()) or 1
+ hot = sorted(rest.items(), key=lambda kv: -kv[1]["fetch"])[:5]
+ print("- top load after exclusion: " + ", ".join(
+ f"`{short(n)}` {100.0 * v['fetch'] / rt:.1f}%" for n, v in hot))
+ polls = [(n, v) for n, v in rest.items()
+ if v["fetch"] / total_fetch > 0.02 and v["run"]
+ and v["fetch"] / v["run"] < 40]
+ if polls:
+ print("- busy-poll candidates (>2% load, <40 instr/entry - called in a "
+ "tight loop; consider event-driven or rate-limiting):")
+ for n, v in sorted(polls, key=lambda kv: -kv[1]["fetch"]):
+ print(f" - `{short(n)}`: {v['run']:,} calls, "
+ f"{v['fetch'] / v['run']:.0f} instr/call, "
+ f"{100.0 * v['fetch'] / total_fetch:.1f}% load")
+ if tshare:
+ stalls = []
+ for n, ts in tshare.items():
+ cs = cshare.get(n, 0)
+ if ts > 0.01 and cs and ts / cs > 4:
+ stalls.append((n, ts, ts / cs))
+ if stalls:
+ print("- stall/wait-dominated (time share >> instruction share - "
+ "waiting on hardware, consider DMA/IRQ instead of polling):")
+ for n, ts, ratio in sorted(stalls, key=lambda x: -x[1])[:5]:
+ print(f" - `{short(n)}`: {100 * ts:.1f}% of time, "
+ f"{ratio:.0f}x its instruction share")
+
+
+def main():
+ p = argparse.ArgumentParser(description=__doc__,
+ formatter_class=argparse.RawDescriptionHelpFormatter)
+ p.add_argument("capture_dir", help="etm_capture.py output dir")
+ p.add_argument("--top", type=int, default=10, help="table size")
+ p.add_argument("--elf", help="firmware ELF, enables itrace analyses")
+ p.add_argument("--isr", help="entry[,body..] symbols for ISR episode timing")
+ p.add_argument("--exclude", help="regex of functions to exclude from the "
+ "optimization load ranking (e.g. the idle poll loop)")
+ args = p.parse_args()
+
+ profile = os.path.join(args.capture_dir, "code_profile.txt")
+ itrace = os.path.join(args.capture_dir, "itrace.csv")
+ funcs, totals = parse_profile(profile)
+ total_fetch = totals.get("fetch") or 1
+ hot = sorted(funcs.items(), key=lambda kv: kv[1]["fetch"], reverse=True)[:args.top]
+
+ print(f"# ETM profile: {args.capture_dir}\n")
+ print(f"## Top {args.top} hottest functions (instruction-fetch share)\n")
+ print("| # | Function | Module | Run Count | Fetch Count | Load % |")
+ print("|---|----------|--------|-----------|-------------|--------|")
+ for i, (name, v) in enumerate(hot, 1):
+ print(f"| {i} | `{short(name)}` | {v['module']} | {v['run']:,} "
+ f"| {v['fetch']:,} | {100.0 * v['fetch'] / total_fetch:.2f}% |")
+ print(f"\nTotal fetches {totals.get('fetch', 0):,} "
+ f"(runs {totals.get('run', 0):,}, unaccounted {totals.get('unaccounted', 0):,})\n")
+
+ ic, sc = totals.get("inst_cov"), totals.get("src_cov")
+ print("## Coverage (NOPs excluded)\n")
+ if ic:
+ print(f"- instructions fully executed: {ic[0]:,} / {ic[1]:,} "
+ f"({100.0 * ic[0] / ic[1]:.1f}%)")
+ if sc:
+ print(f"- source lines fully covered: {sc[0]:,} / {sc[1]:,} "
+ f"({100.0 * sc[0] / sc[1]:.1f}%)")
+ partial = [n for n, v in funcs.items()
+ if v["fetch"] > 0 and 0 < v.get("inst_pct", 100) < 100]
+ print(f"- executed but only partially covered: {len(partial)} functions")
+ dead = sorted(n for n, v in funcs.items()
+ if v["fetch"] == 0 and "(always inlined)" not in n)
+ print(f"- never-executed out-of-line functions: {len(dead)}")
+ by_mod = {}
+ for n in dead:
+ by_mod.setdefault(funcs[n]["module"], []).append(short(n))
+ for mod in sorted(by_mod, key=str):
+ print(f" - {mod}: {', '.join('`%s`' % f for f in by_mod[mod])}")
+
+ tshare, cshare = {}, {}
+ if os.path.isfile(itrace) and args.elf:
+ syms = load_symbols(args.elf)
+ tf, cf, n = time_by_func(itrace, syms)
+ tt, tc = sum(tf.values()) or 1, sum(cf.values()) or 1
+ tshare = {k: v / tt for k, v in tf.items()}
+ cshare = {k: v / tc for k, v in cf.items()}
+ unit = itrace_unit(itrace)
+ print(f"\n## Instruction history (itrace.csv, unit '{unit}')\n")
+ print(f"- {n:,} instructions; top {args.top} by TIME share "
+ f"(vs instruction share):")
+ for name, ts in sorted(tshare.items(), key=lambda kv: -kv[1])[:args.top]:
+ print(f" - `{short(name)}`: {100 * ts:.1f}% time, "
+ f"{100 * cshare.get(name, 0):.1f}% instructions")
+
+ lines_csv = os.path.join(args.capture_dir, "profile_lines.csv")
+ if os.path.isfile(lines_csv):
+ def n(v): # Ozone groups thousands with spaces
+ v = (v or "").replace(" ", "")
+ return int(v) if v.isdigit() else 0
+ with open(lines_csv, newline="", errors="replace") as f:
+ rows = [r for r in csv.DictReader(f)
+ if r.get("File") and n(r.get("Instructions Fetched")) > 0]
+ rows.sort(key=lambda r: -n(r["Instructions Fetched"]))
+ print(f"\n## Hottest source lines (profile_lines.csv)\n")
+ for r in rows[:args.top]:
+ src = (r.get("Content") or "").strip()
+ print(f"- {os.path.basename(r['File'])}:{r['Line']} "
+ f"{n(r['Instructions Fetched']):,} fetches `{src[:60]}`")
+
+ insts_csv = os.path.join(args.capture_dir, "profile_insts.csv")
+ if os.path.isfile(insts_csv):
+ branch_bias(insts_csv, funcs, args.top)
+
+ if args.isr:
+ if not (os.path.isfile(itrace) and args.elf):
+ sys.exit("error: --isr needs itrace.csv (--trace-csv capture) and --elf")
+ isr_report(itrace, args.elf, args.isr, args.top)
+
+ suggestions(funcs, totals, tshare, cshare, args.exclude)
+ return 0
+
+
+if __name__ == "__main__":
+ sys.exit(main())