aboutsummaryrefslogtreecommitdiff
path: root/docs/profiling.md
blob: 9978347e7b28a187889c30c597c84a14d9724bf7 (plain)
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
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-<timestamp>/` (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-<timestamp>/`:

- `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.