From 657fb0007f39f07cc0401e0c5d03e25df6234aa4 Mon Sep 17 00:00:00 2001 From: Alexander M Pickering Date: Tue, 21 Jul 2026 20:19:46 -0500 Subject: Inital commit. --- docs/profiling.md | 81 +++++++++++++++++++++++++++++++++++++++++++++++++++++++ 1 file changed, 81 insertions(+) create mode 100644 docs/profiling.md (limited to 'docs/profiling.md') diff --git a/docs/profiling.md b/docs/profiling.md new file mode 100644 index 0000000..9978347 --- /dev/null +++ b/docs/profiling.md @@ -0,0 +1,81 @@ +# Profiling the test suite + +`scripts/profile-tests.sh` reports where time goes when running the bats +suite, at two levels of detail. + +## What it produces + +1. **Per-test timing** (always). Runs bats with `--timing` and the JUnit + report formatter, then ranks every test slowest-first. Answers *which + tests take a long time*. +2. **Per-line hotspots** (with `-p`). Re-runs the suite with `trbldoc.sh` + under `bash` xtrace and attributes elapsed wall-time to individual source + lines. Answers *which code takes a long time*. + +## Usage + +```sh +# Per-test timing for the integration suite (default) +sh scripts/profile-tests.sh + +# Include per-line hotspots inside trbldoc.sh +sh scripts/profile-tests.sh -p + +# Profile the whole suite, show the 30 slowest tests +sh scripts/profile-tests.sh -s all -n 30 +``` + +Options: `-s all|unit|integration`, `-o OUTDIR`, `-n TOPN`, `-p` (hotspots), +`-t "file.sh ..."` (hotspot target scripts). + +## Output + +Written to `reports/profile-/` (or `-o`): + +- `timings.html` — ranked per-test bar chart. +- `timings.csv` / `timings.sorted.tsv` — raw per-test data. +- `hotspots.html` / `hotspots.csv` — per-line self-time (only with `-p`). +- `junit/`, `bats-output.txt` — raw bats artifacts. + +## Profiling real trbldoc runs (outside tests) + +Use `scripts/profile-run.sh` when you want hotspot data for real workloads +rather than test execution. + +```sh +# Single direct run +sh scripts/profile-run.sh -- -s src -o docs + +# Repeat 3 clean runs to stabilize hotspot ranking +sh scripts/profile-run.sh -n 3 -C -- -s src -o docs +``` + +Outputs under `reports/profile-run-/`: + +- `run-summary.csv` — wall-clock runtime per run. +- `hotspots.html` — per-line self-time aggregated from xtrace markers. +- `phase-hotspots.html` — coarse pipeline phase self-time (discovery, + extraction, render ordering, rendering, nav, ref resolution, toc, assemble), + inferred from traced line ranges in `trbldoc.sh`. + +## How the hotspot profiler works + +The bats tests invoke the tool as `bash "$TRBLDOC"`. The profiler exports +`BASH_ENV=scripts/lib/trace-init.sh`, which every non-interactive bash sources +at startup. For scripts whose basename is in `TRBLDOC_TRACE_TARGETS` +(default `trbldoc.sh`) it enables `set -x` with a `PS4` that stamps +`BASH_SOURCE:LINENO` and `EPOCHREALTIME` to a per-PID trace file. The +aggregator computes the delta between consecutive traced lines *within each +process*, so trbldoc's parallel `xargs -P` workers are not cross-attributed. + +## Limitations + +- Hotspot timing needs `bash` ≥ 5 (`EPOCHREALTIME`). The report scripts + themselves are POSIX sh and run under mingw bash, WSL bash and busybox ash. +- Subprocesses trbldoc spawns via `ash`/`xargs` are not bash and are not + traced; hotspots reflect the main-script control flow, not the render + helper's internals. +- Per-line self-time is derived from trace timestamps and includes tracing + overhead, so treat the numbers as relative, not absolute. +- Phase hotspots are inferred from source-line boundaries and are intended for + prioritisation, not exact accounting. -- cgit v1.2.3-70-g09d2