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. --- scripts/README.md | 50 +++++++++ scripts/coverage-tests.sh | 143 ++++++++++++++++++++++++ scripts/generate-reports.sh | 58 ++++++++++ scripts/hotspot-tests.sh | 204 ++++++++++++++++++++++++++++++++++ scripts/lib/common.sh | 105 +++++++++++++++++ scripts/lib/coverage-report.awk | 84 ++++++++++++++ scripts/lib/render-coverage-index.awk | 48 ++++++++ scripts/lib/render-hotspots.awk | 56 ++++++++++ scripts/lib/render-phases.awk | 41 +++++++ scripts/lib/render-timing.awk | 41 +++++++ scripts/lib/timing-extract.awk | 32 ++++++ scripts/lib/trace-extract.awk | 71 ++++++++++++ scripts/lib/trace-init.sh | 42 +++++++ scripts/lib/trace-phase-extract.awk | 75 +++++++++++++ scripts/profile-run.sh | 180 ++++++++++++++++++++++++++++++ scripts/profile-tests.sh | 184 ++++++++++++++++++++++++++++++ 16 files changed, 1414 insertions(+) create mode 100644 scripts/README.md create mode 100644 scripts/coverage-tests.sh create mode 100644 scripts/generate-reports.sh create mode 100644 scripts/hotspot-tests.sh create mode 100644 scripts/lib/common.sh create mode 100644 scripts/lib/coverage-report.awk create mode 100644 scripts/lib/render-coverage-index.awk create mode 100644 scripts/lib/render-hotspots.awk create mode 100644 scripts/lib/render-phases.awk create mode 100644 scripts/lib/render-timing.awk create mode 100644 scripts/lib/timing-extract.awk create mode 100644 scripts/lib/trace-extract.awk create mode 100644 scripts/lib/trace-init.sh create mode 100644 scripts/lib/trace-phase-extract.awk create mode 100644 scripts/profile-run.sh create mode 100644 scripts/profile-tests.sh (limited to 'scripts') diff --git a/scripts/README.md b/scripts/README.md new file mode 100644 index 0000000..91adbd3 --- /dev/null +++ b/scripts/README.md @@ -0,0 +1,50 @@ +# Report scripts + +Portable POSIX-sh tooling to generate reports from the bats test suite. All +entrypoints run under mingw bash, WSL bash and Alpine/busybox ash, and depend +only on `bats`, `awk`, `sort` and coreutils. + +## `profile-tests.sh` + +Per-test timing (and optional per-line hotspots). See `doc/profiling.md`. +## `profile-run.sh` + +Direct profiling for real `trbldoc.sh` invocations (outside bats). Produces: + +- per-run wall-clock summary (`run-summary.csv`) +- line hotspots (`hotspots.html`) +- pipeline phase hotspots inferred from trace line ranges (`phase-hotspots.html`) + +Example: + +```sh +sh scripts/profile-run.sh -n 3 -C -- -s tests/fixtures/pipeline -o .trblcache/built +``` +## `hotspot-tests.sh` + +Repeatable hotspot analysis for the bats suite without relying on JUnit output. +It captures: + +- per-test timing from raw `bats --timing` output +- line hotspots from xtrace logs +- optional phase hotspots for `trbldoc.sh` (when helper scripts are present) + +```sh +sh scripts/hotspot-tests.sh -s all -n 30 +``` + +## `coverage-tests.sh` + +Shell line coverage of `trbldoc.sh`. See `doc/coverage.md`. + +## `generate-reports.sh` + +Run both into one timestamped `reports/` directory. Puts reports into a +`reports/run-/` directory. + +```sh +sh scripts/generate-reports.sh -p +``` + +`lib/` holds shared helpers: `common.sh` (sh helpers), `trace-init.sh` (the +`BASH_ENV` xtrace hook), and the `*.awk` extractors/renderers. diff --git a/scripts/coverage-tests.sh b/scripts/coverage-tests.sh new file mode 100644 index 0000000..cf03825 --- /dev/null +++ b/scripts/coverage-tests.sh @@ -0,0 +1,143 @@ +#!/bin/sh +# scripts/coverage-tests.sh +# Generate line-coverage reports for trbldoc's shell sources from the test +# suite. Answers "what is the test suite not exercising". +# +# Mechanism: the suite runs the tool via `bash "$TRBLDOC"`, so exporting +# BASH_ENV=scripts/lib/trace-init.sh makes each target process emit an xtrace +# of every executed line. We union the executed lines across the whole run and +# compare against the executable lines in each target source. No modification +# of trbldoc.sh or the tests is required. +# +# POSIX sh; works under mingw bash, WSL bash and Alpine/busybox ash. The traced +# run itself uses bash (the suite already invokes bash), which is one of the +# supported target shells. +# +# Usage: +# scripts/coverage-tests.sh [-s all|unit|integration] [-o OUTDIR] +# [-t "file.sh ..."] [-m MIN_PERCENT] +# +# -s SUITE suite to run (default: integration) +# -o OUTDIR output directory (default: reports/coverage-) +# -t LIST space-separated target source files (default: trbldoc.sh) +# -m MIN_PERCENT fail (exit 2) if overall coverage is below this (default: 0) + +set -u + +SELF="$0" +. "$(dirname -- "$0")/lib/common.sh" +tb_resolve_paths "$SELF" + +SUITE=integration +OUTDIR="" +TARGETS="trbldoc.sh" +MIN_PERCENT=0 + +while getopts ":s:o:t:m:h" opt; do + case "$opt" in + s) SUITE="$OPTARG" ;; + o) OUTDIR="$OPTARG" ;; + t) TARGETS="$OPTARG" ;; + m) MIN_PERCENT="$OPTARG" ;; + h) sed -n '2,30p' "$SELF"; exit 0 ;; + :) tb_die "option -$OPTARG requires an argument" ;; + \?) tb_die "unknown option -$OPTARG" ;; + esac +done + +tb_require awk +tb_require sort + +[ -n "$OUTDIR" ] || OUTDIR="$REPO_ROOT/reports/coverage-$(tb_timestamp)" +case "$OUTDIR" in + /*|[A-Za-z]:[\\/]*) + ;; + *) + OUTDIR="$REPO_ROOT/$OUTDIR" + ;; +esac +mkdir -p "$OUTDIR/html" || tb_die "cannot create output dir: $OUTDIR" +JUNIT_DIR="$OUTDIR/junit"; mkdir -p "$JUNIT_DIR" +TRACE_DIR="$OUTDIR/trace"; rm -rf "$TRACE_DIR"; mkdir -p "$TRACE_DIR" + +SUITE_DIRS="$(tb_suite_dirs "$SUITE")" +SUITE_DIRS_REL="$(tb_suite_dirs_rel "$SUITE")" + +# Basename filter for the trace hook + absolute source paths for reporting. +TRACE_TARGETS="" +SRC_FILES="" +for tf in $TARGETS; do + TRACE_TARGETS="$TRACE_TARGETS ${tf##*/}" + case "$tf" in + /*) p="$tf" ;; + *) p="$REPO_ROOT/$tf" ;; + esac + [ -f "$p" ] || tb_die "target source not found: $p" + SRC_FILES="$SRC_FILES $p" +done + +# ── run suite under xtrace ─────────────────────────────────────────────────── +tb_info "running bats ($SUITE) under coverage instrumentation..." +if tb_bats_usable "$SUITE"; then + BASH_ENV="$LIB_DIR/trace-init.sh" + TRBLDOC_TRACE_DIR="$TRACE_DIR" + TRBLDOC_TRACE_MODE="cov" + TRBLDOC_TRACE_TARGETS="$TRACE_TARGETS" + export BASH_ENV TRBLDOC_TRACE_DIR TRBLDOC_TRACE_MODE TRBLDOC_TRACE_TARGETS + # shellcheck disable=SC2086 + bats --report-formatter junit --output "$JUNIT_DIR" $SUITE_DIRS \ + > "$OUTDIR/bats-output.txt" 2>&1 || tb_info "bats reported failures (see bats-output.txt)" + unset BASH_ENV TRBLDOC_TRACE_DIR TRBLDOC_TRACE_MODE TRBLDOC_TRACE_TARGETS +elif command -v wsl >/dev/null 2>&1; then + tb_info "local bats appears unusable; retrying via WSL bats..." + WSL_REPO="$(tb_to_wsl_path "$REPO_ROOT")" + WSL_LIB="$(tb_to_wsl_path "$LIB_DIR")" + WSL_TRACE="$(tb_to_wsl_path "$TRACE_DIR")" + WSL_JUNIT="$(tb_to_wsl_path "$JUNIT_DIR")" + wsl -- bash -lc \ + "cd '$WSL_REPO' && export BASH_ENV='$WSL_LIB/trace-init.sh' TRBLDOC_TRACE_DIR='$WSL_TRACE' TRBLDOC_TRACE_MODE='cov' TRBLDOC_TRACE_TARGETS='$TRACE_TARGETS'; bats --report-formatter junit --output '$WSL_JUNIT' $SUITE_DIRS_REL" \ + > "$OUTDIR/bats-output.txt" 2>&1 || tb_info "bats (WSL) reported failures (see bats-output.txt)" +else + tb_die "local bats command appears unusable and no WSL fallback is available" +fi + +if ! ls "$TRACE_DIR"/trace.*.log >/dev/null 2>&1; then + if grep -qi "bash\\\\r" "$OUTDIR/bats-output.txt" 2>/dev/null; then + tb_die "bats appears broken (CRLF shebang: 'bash\\r'). Reinstall bats or run dos2unix on the bats scripts, then retry." + fi + tb_die "no trace data captured; ensure bats actually runs tests (see $OUTDIR/bats-output.txt)" +fi + +# ── union executed lines ───────────────────────────────────────────────────── +awk -f "$LIB_DIR/trace-extract.awk" -v MODE=cov "$TRACE_DIR"/trace.*.log \ + | sort -u > "$OUTDIR/covered.tsv" + +# ── per-file coverage report + summary ─────────────────────────────────────── +# shellcheck disable=SC2086 +awk -f "$LIB_DIR/coverage-report.awk" \ + -v COVERED="$OUTDIR/covered.tsv" \ + -v HTMLDIR="$OUTDIR/html" \ + $SRC_FILES > "$OUTDIR/summary.rows" + +{ + printf 'file,executable,covered,percent\n' + cat "$OUTDIR/summary.rows" +} > "$OUTDIR/summary.csv" + +awk -f "$LIB_DIR/render-coverage-index.awk" \ + -v TITLE="trbldoc coverage ($SUITE)" \ + "$OUTDIR/summary.rows" > "$OUTDIR/index.html" + +# ── overall percent + threshold gate ───────────────────────────────────────── +OVERALL="$(awk -F',' '{t+=$2; c+=$3} END{ if(t>0) printf "%.1f", c*100.0/t; else print "0.0" }' "$OUTDIR/summary.rows")" + +printf '\n==== coverage summary (%s) ====\n' "$SUITE" +awk -F',' '{ printf "%6.1f%% %-20s (%d/%d)\n", $4, $1, $3, $2 }' "$OUTDIR/summary.rows" +printf ' overall: %s%%\n' "$OVERALL" +printf '\nReports written to: %s\n' "$OUTDIR" +printf ' coverage index: %s\n' "$OUTDIR/index.html" + +# Threshold enforcement (integer or decimal compare via awk). +if awk -v o="$OVERALL" -v m="$MIN_PERCENT" 'BEGIN{ exit !(m>0 && o+0 < m+0) }'; then + tb_die "coverage ${OVERALL}% is below the required minimum ${MIN_PERCENT}%" +fi diff --git a/scripts/generate-reports.sh b/scripts/generate-reports.sh new file mode 100644 index 0000000..77c4b0f --- /dev/null +++ b/scripts/generate-reports.sh @@ -0,0 +1,58 @@ +#!/bin/sh +# scripts/generate-reports.sh +# Convenience wrapper: run both the profiler and the coverage report for a +# suite into a single timestamped directory under reports/. +# +# POSIX sh; works under mingw bash, WSL bash and Alpine/busybox ash. +# +# Usage: +# scripts/generate-reports.sh [-s all|unit|integration] [-o OUTDIR] +# [-p] [-m MIN_PERCENT] [-t "file.sh ..."] +# +# -s SUITE suite to run (default: integration) +# -o OUTDIR base output directory (default: reports/run-) +# -p include per-line hotspots in the profile report +# -m MIN_PERCENT coverage threshold to enforce (default: 0 = no gate) +# -t LIST space-separated target source files (default: trbldoc.sh) + +set -u + +SELF="$0" +. "$(dirname -- "$0")/lib/common.sh" +tb_resolve_paths "$SELF" + +SUITE=integration +OUTDIR="" +HOTSPOTS=0 +MIN_PERCENT=0 +TARGETS="trbldoc.sh" + +while getopts ":s:o:pm:t:h" opt; do + case "$opt" in + s) SUITE="$OPTARG" ;; + o) OUTDIR="$OPTARG" ;; + p) HOTSPOTS=1 ;; + m) MIN_PERCENT="$OPTARG" ;; + t) TARGETS="$OPTARG" ;; + h) sed -n '2,20p' "$SELF"; exit 0 ;; + :) tb_die "option -$OPTARG requires an argument" ;; + \?) tb_die "unknown option -$OPTARG" ;; + esac +done + +[ -n "$OUTDIR" ] || OUTDIR="$REPO_ROOT/reports/run-$(tb_timestamp)" +mkdir -p "$OUTDIR" || tb_die "cannot create output dir: $OUTDIR" + +PROFILE_ARGS="-s $SUITE -o $OUTDIR/profile -t $TARGETS" +[ "$HOTSPOTS" -eq 1 ] && PROFILE_ARGS="$PROFILE_ARGS -p" + +tb_info "=== profiling ===" +# shellcheck disable=SC2086 +sh "$SCRIPTS_DIR/profile-tests.sh" $PROFILE_ARGS + +tb_info "=== coverage ===" +# shellcheck disable=SC2086 +sh "$SCRIPTS_DIR/coverage-tests.sh" -s "$SUITE" -o "$OUTDIR/coverage" \ + -t "$TARGETS" -m "$MIN_PERCENT" + +printf '\nAll reports under: %s\n' "$OUTDIR" diff --git a/scripts/hotspot-tests.sh b/scripts/hotspot-tests.sh new file mode 100644 index 0000000..8973e6b --- /dev/null +++ b/scripts/hotspot-tests.sh @@ -0,0 +1,204 @@ +#!/bin/sh +# scripts/hotspot-tests.sh +# Repeatable hotspot analysis for the trbldoc test suite. +# +# Produces: +# - per-test timings (parsed from `bats --timing`) +# - line-level hotspots for target scripts from xtrace logs +# - optional phase hotspots for trbldoc.sh +# +# Usage: +# scripts/hotspot-tests.sh [-s all|unit|integration] [-o OUTDIR] +# [-n TOPN] [-t "file.sh ..."] +# +# -s SUITE suite to run (default: all) +# -o OUTDIR output directory (default: reports/hotspots-) +# -n TOPN number of slowest tests to print (default: 25) +# -t LIST space-separated target scripts for trace hotspots (default: trbldoc.sh) + +set -u + +SELF="$0" +. "$(dirname -- "$0")/lib/common.sh" +tb_resolve_paths "$SELF" + +SUITE=all +OUTDIR="" +TOPN=25 +TARGETS="trbldoc.sh" + +while getopts ":s:o:n:t:h" opt; do + case "$opt" in + s) SUITE="$OPTARG" ;; + o) OUTDIR="$OPTARG" ;; + n) TOPN="$OPTARG" ;; + t) TARGETS="$OPTARG" ;; + h) sed -n '2,24p' "$SELF"; exit 0 ;; + :) tb_die "option -$OPTARG requires an argument" ;; + \?) tb_die "unknown option -$OPTARG" ;; + esac +done + +tb_require awk +tb_require sort + +case "$TOPN" in + ''|*[!0-9]*|0) tb_die "-n TOPN must be a positive integer" ;; +esac + +[ -n "$OUTDIR" ] || OUTDIR="$REPO_ROOT/reports/hotspots-$(tb_timestamp)" +case "$OUTDIR" in + /*|[A-Za-z]:[\\/]*) ;; + *) OUTDIR="$REPO_ROOT/$OUTDIR" ;; +esac +mkdir -p "$OUTDIR" || tb_die "cannot create output dir: $OUTDIR" + +SUITE_DIRS="$(tb_suite_dirs "$SUITE")" +SUITE_DIRS_REL="$(tb_suite_dirs_rel "$SUITE")" +TIMING_RAW="$OUTDIR/bats-timing-output.txt" +TRACE_DIR="$OUTDIR/trace" +rm -rf "$TRACE_DIR"; mkdir -p "$TRACE_DIR" + +# Build trace target filter and resolve first target source for HTML context. +TRACE_TARGETS="" +FIRST_TARGET="" +for tf in $TARGETS; do + TRACE_TARGETS="$TRACE_TARGETS ${tf##*/}" + if [ -z "$FIRST_TARGET" ]; then + FIRST_TARGET="$tf" + fi +done + +tb_info "running bats ($SUITE) with --timing output..." +if tb_bats_usable "$SUITE"; then + # shellcheck disable=SC2086 + bats --timing $SUITE_DIRS > "$TIMING_RAW" 2>&1 || tb_info "bats reported failures (timing output still collected)" + BATS_MODE="local" +elif command -v wsl >/dev/null 2>&1; then + tb_info "local bats appears unusable; retrying timing run via WSL bats..." + WSL_REPO="$(tb_to_wsl_path "$REPO_ROOT")" + wsl -- bash -lc \ + "cd '$WSL_REPO' && bats --timing $SUITE_DIRS_REL" \ + > "$TIMING_RAW" 2>&1 || tb_info "bats (WSL) reported failures (timing output still collected)" + BATS_MODE="wsl" +else + tb_die "local bats command appears unusable and no WSL fallback is available" +fi + +# Parse bats timing lines: "ok N in ms" +awk ' +match($0, /^ok [0-9]+ (.*) in ([0-9]+)ms$/, m) { + name = m[1] + ms = m[2] + 0 + suite = name + sub(/:.*/, "", suite) + printf "%.3f\t%s\t%s\t%d\n", ms / 1000.0, suite, name, ms +} +' "$TIMING_RAW" > "$OUTDIR/timings.tsv" + +if [ ! -s "$OUTDIR/timings.tsv" ]; then + tb_die "no per-test timing rows parsed (check $TIMING_RAW)" +fi + +sort -t "$(printf '\t')" -k1,1nr "$OUTDIR/timings.tsv" > "$OUTDIR/timings.sorted.tsv" +{ + printf 'seconds,suite,test,milliseconds\n' + awk -F '\t' '{ gsub(/"/,"\"\"",$3); printf "%s,%s,\"%s\",%s\n",$1,$2,$3,$4 }' "$OUTDIR/timings.sorted.tsv" +} > "$OUTDIR/timings.csv" + +awk -f "$LIB_DIR/render-timing.awk" \ + -v TITLE="trbldoc test timings ($SUITE)" \ + "$OUTDIR/timings.sorted.tsv" > "$OUTDIR/timings.html" + +tb_info "running bats ($SUITE) under xtrace timing hook..." +if [ "$BATS_MODE" = "local" ]; then + BASH_ENV="$LIB_DIR/trace-init.sh" + TRBLDOC_TRACE_DIR="$TRACE_DIR" + TRBLDOC_TRACE_MODE="time" + TRBLDOC_TRACE_TARGETS="$TRACE_TARGETS" + export BASH_ENV TRBLDOC_TRACE_DIR TRBLDOC_TRACE_MODE TRBLDOC_TRACE_TARGETS + # shellcheck disable=SC2086 + bats $SUITE_DIRS > "$OUTDIR/bats-trace-output.txt" 2>&1 || tb_info "bats reported failures during trace run" + unset BASH_ENV TRBLDOC_TRACE_DIR TRBLDOC_TRACE_MODE TRBLDOC_TRACE_TARGETS +else + WSL_REPO="$(tb_to_wsl_path "$REPO_ROOT")" + WSL_LIB="$(tb_to_wsl_path "$LIB_DIR")" + WSL_TRACE="$(tb_to_wsl_path "$TRACE_DIR")" + wsl -- bash -lc \ + "cd '$WSL_REPO' && export BASH_ENV='$WSL_LIB/trace-init.sh' TRBLDOC_TRACE_DIR='$WSL_TRACE' TRBLDOC_TRACE_MODE='time' TRBLDOC_TRACE_TARGETS='$TRACE_TARGETS'; bats $SUITE_DIRS_REL" \ + > "$OUTDIR/bats-trace-output.txt" 2>&1 || tb_info "bats (WSL) reported failures during trace run" +fi + +if ls "$TRACE_DIR"/trace.*.log >/dev/null 2>&1; then + awk -f "$LIB_DIR/trace-extract.awk" -v MODE=time "$TRACE_DIR"/trace.*.log \ + | sort -t "$(printf '\t')" -k1 -rn > "$OUTDIR/hotspots.tsv" + { + printf 'total_ms,hits,file,line\n' + awk -F '\t' '{ printf "%s,%s,%s,%s\n",$1,$2,$3,$4 }' "$OUTDIR/hotspots.tsv" + } > "$OUTDIR/hotspots.csv" + + case "$FIRST_TARGET" in + /*|[A-Za-z]:[\\/]*) SRC_PATH="$FIRST_TARGET" ;; + *) SRC_PATH="$REPO_ROOT/$FIRST_TARGET" ;; + esac + awk -f "$LIB_DIR/render-hotspots.awk" \ + -v TITLE="trbldoc line hotspots ($SUITE)" \ + -v SRC="$SRC_PATH" \ + "$OUTDIR/hotspots.tsv" > "$OUTDIR/hotspots.html" +else + tb_info "no trace logs captured for target(s):$TRACE_TARGETS" +fi + +# Optional phase hotspots when trbldoc.sh + helper scripts are available. +if [ -f "$OUTDIR/hotspots.tsv" ] && [ -f "$LIB_DIR/trace-phase-extract.awk" ] && [ -f "$LIB_DIR/render-phases.awk" ] && [ -f "$REPO_ROOT/trbldoc.sh" ]; then + _find_line() { + awk -v p="$1" 'index($0, p) { print NR; exit }' "$REPO_ROOT/trbldoc.sh" + } + L_DISCOVER_END="$(_find_line '> "$source_files_list"')" + L_EXTRACT_END="$(_find_line '# Resolve src_repo once before the chunk loop.')" + L_ORDER_END="$(_find_line 'done < "$sorted_chunk_order_file"')" + L_RENDER_END="$(_find_line 'done < "$chunk_render_records_file"')" + L_NAV_END="$(_find_line '# Second pass: resolve inline references now that global.meta is complete.')" + L_REFS_END="$(_find_line 'rm -f "$_ref_find_tmp"')" + L_TOC_END="$(_find_line '# Post-processing pass: substitute {{ toc }} in all rendered index.html files')" + L_ASSEMBLE_END="$(_find_line 'assemble_site "$cache_dir/namespace" "$out_dir"')" + + if [ -n "$L_DISCOVER_END" ] && [ -n "$L_EXTRACT_END" ] && [ -n "$L_ORDER_END" ] \ + && [ -n "$L_RENDER_END" ] && [ -n "$L_NAV_END" ] && [ -n "$L_REFS_END" ] \ + && [ -n "$L_TOC_END" ] && [ -n "$L_ASSEMBLE_END" ]; then + awk -f "$LIB_DIR/trace-phase-extract.awk" \ + -v SRC_BASE="trbldoc.sh" \ + -v L_DISCOVER_END="$L_DISCOVER_END" \ + -v L_EXTRACT_END="$L_EXTRACT_END" \ + -v L_ORDER_END="$L_ORDER_END" \ + -v L_RENDER_END="$L_RENDER_END" \ + -v L_NAV_END="$L_NAV_END" \ + -v L_REFS_END="$L_REFS_END" \ + -v L_TOC_END="$L_TOC_END" \ + -v L_ASSEMBLE_END="$L_ASSEMBLE_END" \ + "$TRACE_DIR"/trace.*.log \ + | sort -t "$(printf '\t')" -k1 -rn > "$OUTDIR/phase-hotspots.tsv" + + { + printf 'total_ms,hits,phase\n' + awk -F '\t' '{ printf "%s,%s,%s\n",$1,$2,$3 }' "$OUTDIR/phase-hotspots.tsv" + } > "$OUTDIR/phase-hotspots.csv" + + awk -f "$LIB_DIR/render-phases.awk" \ + -v TITLE="trbldoc phase hotspots ($SUITE)" \ + "$OUTDIR/phase-hotspots.tsv" > "$OUTDIR/phase-hotspots.html" + fi +fi + +printf '\n==== slowest %s tests ====\n' "$TOPN" +awk -F '\t' -v n="$TOPN" 'NR<=n { printf "%8.3fs %s\n", $1, $3 }' "$OUTDIR/timings.sorted.tsv" +printf '\nReports written to: %s\n' "$OUTDIR" +printf ' per-test timing : %s\n' "$OUTDIR/timings.html" +if [ -f "$OUTDIR/hotspots.html" ]; then + printf ' line hotspots : %s\n' "$OUTDIR/hotspots.html" +else + printf ' line hotspots : not generated (target not exercised)\n' +fi +if [ -f "$OUTDIR/phase-hotspots.html" ]; then + printf ' phase hotspots : %s\n' "$OUTDIR/phase-hotspots.html" +fi diff --git a/scripts/lib/common.sh b/scripts/lib/common.sh new file mode 100644 index 0000000..0fdf98a --- /dev/null +++ b/scripts/lib/common.sh @@ -0,0 +1,105 @@ +# scripts/lib/common.sh +# Shared helpers for the trbldoc report scripts. +# +# POSIX sh compatible. Verified to work under mingw bash, WSL bash and +# Alpine/busybox ash. Sourced by the entrypoint scripts; do not execute +# directly. + +# Resolve the repository root from the location of the scripts/ directory. +# Sets: REPO_ROOT, SCRIPTS_DIR, LIB_DIR +tb_resolve_paths() { + # $1: path to the calling script ($0) + script_path="$1" + # Directory containing the calling script (scripts/). + SCRIPTS_DIR="$(CDPATH= cd -- "$(dirname -- "$script_path")" && pwd)" + LIB_DIR="$SCRIPTS_DIR/lib" + REPO_ROOT="$(CDPATH= cd -- "$SCRIPTS_DIR/.." && pwd)" + export REPO_ROOT SCRIPTS_DIR LIB_DIR +} + +# Print an ISO-8601 UTC timestamp suitable for directory names. +# Falls back to epoch seconds when the platform date(1) cannot format UTC. +tb_timestamp() { + if date -u +%Y%m%dT%H%M%SZ 2>/dev/null; then + return 0 + fi + printf '%s\n' "$(date +%s)" +} + +# Emit an informational message to stderr. +tb_info() { + printf '[trbldoc-report] %s\n' "$*" >&2 +} + +# Emit an error message to stderr and return non-zero. +tb_die() { + printf '[trbldoc-report] ERROR: %s\n' "$*" >&2 + exit 1 +} + +# Verify a command exists on PATH, otherwise abort. +tb_require() { + command -v "$1" >/dev/null 2>&1 || tb_die "required tool not found on PATH: $1" +} + +# Resolve the bats suite directories for a target keyword. +# $1: all|unit|integration ; echoes space-separated dirs relative to REPO_ROOT. +tb_suite_dirs() { + case "$1" in + unit) printf '%s\n' "$REPO_ROOT/tests/unit" ;; + integration) printf '%s\n' "$REPO_ROOT/tests/integration" ;; + all) printf '%s\n' "$REPO_ROOT/tests/unit $REPO_ROOT/tests/integration" ;; + *) tb_die "unknown suite '$1' (expected: all|unit|integration)" ;; + esac +} + +# Resolve bats suite directories relative to repository root. +# $1: all|unit|integration ; echoes a space-separated relative path list. +tb_suite_dirs_rel() { + case "$1" in + unit) printf '%s\n' "tests/unit" ;; + integration) printf '%s\n' "tests/integration" ;; + all) printf '%s\n' "tests/unit tests/integration" ;; + *) tb_die "unknown suite '$1' (expected: all|unit|integration)" ;; + esac +} + +# Convert a POSIX-style MSYS path (/d/foo/bar) to a WSL Linux path +# (/mnt/d/foo/bar). Other paths are returned unchanged. +tb_to_wsl_path() { + p="$1" + case "$p" in + [A-Za-z]:\\*|[A-Za-z]:/*) + d="$(printf '%s' "$p" | cut -c1 | tr 'A-Z' 'a-z')" + rest="$(printf '%s' "$p" | cut -c3- | sed 's#\\\\#/#g')" + rest="$(printf '%s' "$rest" | sed 's#^/*##')" + printf '/mnt/%s/%s\n' "$d" "$rest" + ;; + /[A-Za-z]/*) + d="$(printf '%s' "$p" | cut -c2 | tr 'A-Z' 'a-z')" + rest="$(printf '%s' "$p" | cut -c4-)" + printf '/mnt/%s/%s\n' "$d" "$rest" + ;; + *) + printf '%s\n' "$p" + ;; + esac +} + +# Returns success if the local `bats` command appears usable for this repo. +# Some mixed Windows/MSYS setups expose a broken bats wrapper that exits 0 +# without running tests or producing output; this guard catches that case. +tb_bats_usable() { + suite="${1:-integration}" + dirs="$(tb_suite_dirs "$suite")" + # shellcheck disable=SC2086 + count="$(bats --count $dirs 2>/dev/null | tr -d '[:space:]')" + case "$count" in + ''|*[!0-9]*) + return 1 + ;; + *) + return 0 + ;; + esac +} diff --git a/scripts/lib/coverage-report.awk b/scripts/lib/coverage-report.awk new file mode 100644 index 0000000..982eb45 --- /dev/null +++ b/scripts/lib/coverage-report.awk @@ -0,0 +1,84 @@ +# scripts/lib/coverage-report.awk +# Produce line-coverage reports for shell sources from an executed-line set. +# +# Inputs: +# -v COVERED= TSV of "\t" executed lines (sorted -u). +# -v HTMLDIR= directory to write per-file .html reports into. +# ARGV the source files to report on (absolute paths). +# +# Output (stdout): one CSV row per source file: +# file,total_executable,covered,percent +# +# "Executable" lines are determined heuristically: non-blank, non-comment +# lines that are not pure structural tokens (then/do/done/else/fi/esac/{/}). +# Heredoc/multiline string bodies are approximated and may read as missed; +# see docs/coverage.md for the documented limitations. + +function trim(s) { sub(/^[ \t]+/, "", s); sub(/[ \t]+$/, "", s); return s } + +function is_exec(line, t) { + t = trim(line) + if (t == "") return 0 + if (t ~ /^#/) return 0 + if (t ~ /^(then|do|done|else|fi|esac)([ \t].*)?$/) return 0 + if (t ~ /^[{}]([ \t;].*)?$/) return 0 + if (t ~ /^[()]([ \t].*)?$/) return 0 + if (t ~ /^;;/) return 0 + return 1 +} + +function esc(s) { + gsub(/&/, "\\&", s) + gsub(//, "\\>", s) + return s +} + +function basename(p) { sub(/.*\//, "", p); sub(/.*\\/, "", p); return p } + +BEGIN { + FS = "\t" + # Load the executed-line set. + while ((getline ln < COVERED) > 0) { + nf = split(ln, a, "\t") + if (nf >= 2) covered[a[1] SUBSEP a[2]] = 1 + } + close(COVERED) +} + +# New source file: open its HTML report and reset counters. +FNR == 1 { + if (cur != "") finish_file() + cur = FILENAME + curbase = basename(FILENAME) + total = 0; hit = 0 + html = HTMLDIR "/" curbase ".html" + print "" > html + print "coverage: " esc(curbase) "" > html + print "" > html + print "

coverage: " esc(curbase) "

" > html +} + +{ + cls = "na" + if (is_exec($0)) { + total++ + if ((curbase SUBSEP FNR) in covered) { hit++; cls = "hit" } else { cls = "miss" } + } + print "" > html +} + +function finish_file( pct) { + print "
" FNR "" esc($0) "
" > html + close(html) + pct = (total > 0 ? (hit * 100.0 / total) : 0) + printf "%s,%d,%d,%.1f\n", curbase, total, hit, pct +} + +END { if (cur != "") finish_file() } diff --git a/scripts/lib/render-coverage-index.awk b/scripts/lib/render-coverage-index.awk new file mode 100644 index 0000000..cc5af1b --- /dev/null +++ b/scripts/lib/render-coverage-index.awk @@ -0,0 +1,48 @@ +# scripts/lib/render-coverage-index.awk +# Render the coverage index page from summary rows. +# Input CSV rows (no header): ",,,". +# Per-file detail pages are expected at html/.html. +# Variables: -v TITLE="..." + +function esc(s) { + gsub(/&/, "\\&", s); gsub(//, "\\>", s) + return s +} + +function color(p) { + if (p + 0 >= 80) return "#2da44e" + if (p + 0 >= 50) return "#bf8700" + return "#cf222e" +} + +BEGIN { FS = ","; n = 0; tot = 0; cov = 0 } + +{ + n++ + f[n] = $1; ex[n] = $2 + 0; cv[n] = $3 + 0; pc[n] = $4 + 0 + tot += $2 + 0; cov += $3 + 0 +} + +END { + overall = (tot > 0 ? cov * 100.0 / tot : 0) + print "" + print "" esc(TITLE) "" + print "" + print "

" esc(TITLE) "

" + printf "
Overall: %.1f%% (%d/%d executable lines)
\n", color(overall), overall, cov, tot + print "" + for (i = 1; i <= n; i++) { + printf "", esc(f[i]), esc(f[i]) + printf "", pc[i], color(pc[i]) + printf "\n", pc[i], cv[i], ex[i] + } + print "
filecoverage%coveredexecutable
%s
%.1f%%%d%d
" +} diff --git a/scripts/lib/render-hotspots.awk b/scripts/lib/render-hotspots.awk new file mode 100644 index 0000000..0eb2b6d --- /dev/null +++ b/scripts/lib/render-hotspots.awk @@ -0,0 +1,56 @@ +# scripts/lib/render-hotspots.awk +# Render a per-line hotspot HTML report from sorted TSV rows. +# Input TSV (sorted slowest-first): "\t\t\t". +# Variables: +# -v TITLE="..." +# -v SRC= source file for the primary target, used to show line text. + +function esc(s) { + gsub(/&/, "\\&", s); gsub(//, "\\>", s) + return s +} + +BEGIN { + FS = "\t"; n = 0 + # Load source lines for text display (best effort). + if (SRC != "") { + i = 0 + while ((getline ln < SRC) > 0) { i++; srctext[i] = ln } + close(SRC) + srcbase = SRC; sub(/.*\//, "", srcbase); sub(/.*\\/, "", srcbase) + } +} + +{ + n++ + ms[n] = $1 + 0 + hits[n] = $2 + 0 + file[n] = $3 + line[n] = $4 + 0 + if (n == 1) maxv = $1 + 0 +} + +END { + print "" + print "" esc(TITLE) "" + print "" + print "

" esc(TITLE) "

" + print "
cumulative self-time per source line, slowest first
" + print "" + for (i = 1; i <= n; i++) { + w = (maxv > 0 ? (ms[i] * 100.0 / maxv) : 0) + txt = "" + if (file[i] == srcbase && (line[i] in srctext)) txt = srctext[line[i]] + printf "", i, ms[i], hits[i] + printf "", esc(file[i]), line[i], esc(txt) + printf "\n", w + } + print "
#mshitsfile:linesource
%d%.1f%d%s:%d%s
" +} diff --git a/scripts/lib/render-phases.awk b/scripts/lib/render-phases.awk new file mode 100644 index 0000000..fcb11ec --- /dev/null +++ b/scripts/lib/render-phases.awk @@ -0,0 +1,41 @@ +# scripts/lib/render-phases.awk +# Render per-phase hotspot HTML from sorted TSV rows. +# Input TSV: "\t\t". +# Variables: +# -v TITLE="..." + +function esc(s) { + gsub(/&/, "\\&", s); gsub(//, "\\>", s) + return s +} + +BEGIN { FS = "\t"; n = 0 } + +{ + n++ + ms[n] = $1 + 0 + hits[n] = $2 + 0 + phase[n] = $3 + if (n == 1) maxv = ms[n] +} + +END { + print "" + print "" esc(TITLE) "" + print "" + print "

" esc(TITLE) "

" + print "
cumulative self-time by pipeline phase, slowest first
" + print "" + for (i = 1; i <= n; i++) { + w = (maxv > 0 ? (ms[i] * 100.0 / maxv) : 0) + printf "", i, ms[i], hits[i], esc(phase[i]) + printf "\n", w + } + print "
#mshitsphase
%d%.1f%d%s
" +} diff --git a/scripts/lib/render-timing.awk b/scripts/lib/render-timing.awk new file mode 100644 index 0000000..ffd807f --- /dev/null +++ b/scripts/lib/render-timing.awk @@ -0,0 +1,41 @@ +# scripts/lib/render-timing.awk +# Render a per-test timing HTML report from sorted TSV rows. +# Input TSV (already sorted slowest-first): "\t\t". +# Variables: -v TITLE="..." + +function esc(s) { + gsub(/&/, "\\&", s); gsub(//, "\\>", s) + return s +} + +BEGIN { FS = "\t"; n = 0; total = 0 } + +{ + n++ + sec[n] = $1 + 0 + suite[n] = $2 + name[n] = $3 + total += $1 + 0 + if (n == 1) maxv = $1 + 0 +} + +END { + print "" + print "" esc(TITLE) "" + print "" + print "

" esc(TITLE) "

" + printf "
%d tests · %.3f s total
\n", n, total + print "" + for (i = 1; i <= n; i++) { + w = (maxv > 0 ? (sec[i] * 100.0 / maxv) : 0) + printf "", i, sec[i], esc(name[i]) + printf "\n", w + } + print "
#secondstest
%d%.3f%s
" +} diff --git a/scripts/lib/timing-extract.awk b/scripts/lib/timing-extract.awk new file mode 100644 index 0000000..9cb15d7 --- /dev/null +++ b/scripts/lib/timing-extract.awk @@ -0,0 +1,32 @@ +# scripts/lib/timing-extract.awk +# Extract per-test durations from bats JUnit report XML. +# +# Emits TSV: "\t\t" for each . +# The caller sorts and renders. Handles testcase elements that span the line +# regardless of whether they are self-closing or contain children. + +function attr(line, key, re, s) { + re = key "=\"" + if (index(line, re) == 0) return "" + s = line + sub(".*" re, "", s) # drop up to opening quote + sub(/".*/, "", s) # drop from closing quote + return s +} + +function unesc(s) { + gsub(/"/, "\"", s) + gsub(/'/, "'", s) + gsub(/</, "<", s) + gsub(/>/, ">", s) + gsub(/&/, "\\&", s) + return s +} + +/ prints "\t" per marker line +# MODE=time -> prints "\t\t\t" at END, +# computing per-line durations from consecutive markers +# WITHIN each trace file (one file == one process, so +# parallel xargs workers are not cross-attributed). + +function basename(p) { + sub(/.*\//, "", p) # strip up to last forward slash + sub(/.*\\/, "", p) # strip up to last backslash (defensive) + return p +} + +# Parse a marker line into globals g_base and g_line (and g_epoch for time). +# Returns 1 on success, 0 if the line is not a usable marker. +function parse(line, s, n, f, loc, rest) { + if (line !~ /@+TBL@@ /) return 0 + s = line + sub(/^.*TBL@@ /, "", s) # drop marker and everything before it + n = split(s, f, " ") + if (n < 1) return 0 + loc = f[1] # : + if (!match(loc, /:[0-9]+$/)) return 0 + g_line = substr(loc, RSTART + 1) + g_base = basename(substr(loc, 1, RSTART - 1)) + if (MODE == "time") { + g_epoch = (n >= 2 ? f[2] : "") + } + return 1 +} + +BEGIN { if (MODE == "") MODE = "cov" } + +# Reset per-process state at the start of each trace file. +FNR == 1 { have_prev = 0 } + +{ + if (!parse($0)) next + if (MODE == "cov") { + print g_base "\t" g_line + next + } + # MODE == time: attribute elapsed time to the PREVIOUS marker. + if (have_prev && g_epoch != "" && prev_epoch != "") { + d = g_epoch - prev_epoch + if (d < 0) d = 0 + key = prev_base SUBSEP prev_line + ms[key] += d * 1000.0 + hits[key] += 1 + base_of[key] = prev_base + line_of[key] = prev_line + } + prev_base = g_base + prev_line = g_line + prev_epoch = g_epoch + have_prev = 1 +} + +END { + if (MODE != "time") exit + for (k in ms) { + printf "%.3f\t%d\t%s\t%s\n", ms[k], hits[k], base_of[k], line_of[k] + } +} diff --git a/scripts/lib/trace-init.sh b/scripts/lib/trace-init.sh new file mode 100644 index 0000000..80f1ab0 --- /dev/null +++ b/scripts/lib/trace-init.sh @@ -0,0 +1,42 @@ +# scripts/lib/trace-init.sh +# Instrumentation hook sourced automatically by every non-interactive bash +# invocation via the BASH_ENV environment variable. +# +# The bats suite runs the tool with `bash "$TRBLDOC"`, so exporting +# BASH_ENV= causes each trbldoc.sh process to enable xtrace at +# startup WITHOUT modifying trbldoc.sh or the test files. The emitted trace is +# consumed by the coverage and hotspot aggregators. +# +# Activated only when TRBLDOC_TRACE_DIR is set, and only for scripts whose +# basename appears in TRBLDOC_TRACE_TARGETS (default: trbldoc.sh). This keeps +# unrelated bash helpers (md2html stub, bats internals) out of the trace. +# +# TRBLDOC_TRACE_MODE selects the PS4 format: +# cov -> " :" (line coverage) +# time -> " : " (line timing; bash>=5) +# +# Every traced line is prefixed with the marker token @@TBL@@. bash repeats the +# FIRST PS4 character once per call-nesting level, so the aggregators match the +# marker with a tolerant pattern rather than a fixed prefix. + +if [ -n "${TRBLDOC_TRACE_DIR:-}" ]; then + __tb_self="$0" + __tb_base="${__tb_self##*/}" + case " ${TRBLDOC_TRACE_TARGETS:-trbldoc.sh} " in + *" ${__tb_base} "*) + # Dedicated append fd per process; PID keeps parallel xargs workers apart. + __tb_trace_file="${TRBLDOC_TRACE_DIR}/trace.$$.log" + # shellcheck disable=SC3023 + exec 7>>"$__tb_trace_file" + export BASH_XTRACEFD=7 + if [ "${TRBLDOC_TRACE_MODE:-cov}" = "time" ]; then + # EPOCHREALTIME is bash>=5; used only for the hotspot profiler. + PS4='@@TBL@@ ${BASH_SOURCE}:${LINENO} ${EPOCHREALTIME} ' + else + PS4='@@TBL@@ ${BASH_SOURCE}:${LINENO} ' + fi + export PS4 + set -x + ;; + esac +fi diff --git a/scripts/lib/trace-phase-extract.awk b/scripts/lib/trace-phase-extract.awk new file mode 100644 index 0000000..429f8cf --- /dev/null +++ b/scripts/lib/trace-phase-extract.awk @@ -0,0 +1,75 @@ +# scripts/lib/trace-phase-extract.awk +# Aggregate xtrace timing markers into coarse trbldoc pipeline phases. +# +# Input: trace.*.log files emitted by scripts/lib/trace-init.sh in time mode. +# Output rows: "\t\t" at END. +# +# Required -v vars: +# SRC_BASE +# L_DISCOVER_END +# L_EXTRACT_END +# L_ORDER_END +# L_RENDER_END +# L_NAV_END +# L_REFS_END +# L_TOC_END +# L_ASSEMBLE_END + +function basename(p) { + sub(/.*\//, "", p) + sub(/.*\\/, "", p) + return p +} + +function parse(line, s, n, f, loc) { + if (line !~ /@+TBL@@ /) return 0 + s = line + sub(/^.*TBL@@ /, "", s) + n = split(s, f, " ") + if (n < 2) return 0 + loc = f[1] + if (!match(loc, /:[0-9]+$/)) return 0 + g_line = substr(loc, RSTART + 1) + 0 + g_base = basename(substr(loc, 1, RSTART - 1)) + g_epoch = f[2] + return 1 +} + +function phase_for(line) { + if (line <= L_DISCOVER_END) return "discover_sources" + if (line <= L_EXTRACT_END) return "extract_chunks" + if (line <= L_ORDER_END) return "build_render_order" + if (line <= L_RENDER_END) return "render_chunks" + if (line <= L_NAV_END) return "build_nav" + if (line <= L_REFS_END) return "resolve_refs" + if (line <= L_TOC_END) return "apply_toc" + if (line <= L_ASSEMBLE_END) return "assemble_site" + return "other" +} + +BEGIN { + if (SRC_BASE == "") SRC_BASE = "trbldoc.sh" +} + +FNR == 1 { have_prev = 0 } + +{ + if (!parse($0)) next + if (g_base != SRC_BASE) next + if (have_prev && g_epoch != "" && prev_epoch != "") { + d = g_epoch - prev_epoch + if (d < 0) d = 0 + ph = phase_for(prev_line) + ms[ph] += d * 1000.0 + hits[ph] += 1 + } + prev_line = g_line + prev_epoch = g_epoch + have_prev = 1 +} + +END { + for (ph in ms) { + printf "%.3f\t%d\t%s\n", ms[ph], hits[ph], ph + } +} diff --git a/scripts/profile-run.sh b/scripts/profile-run.sh new file mode 100644 index 0000000..74ab425 --- /dev/null +++ b/scripts/profile-run.sh @@ -0,0 +1,180 @@ +#!/bin/sh +# scripts/profile-run.sh +# Profile direct trbldoc invocations (outside bats) using the existing xtrace +# hook and report pipeline. +# +# Outputs: +# - run-summary.tsv/csv wall-clock per run +# - hotspots.tsv/csv/html per-line cumulative self-time +# - phase-hotspots.tsv/csv/html per-phase cumulative self-time +# +# Usage: +# scripts/profile-run.sh [-o OUTDIR] [-n RUNS] [-C] [-t "file.sh ..."] -- [trbldoc args...] +# +# -o OUTDIR output directory (default: reports/profile-run-) +# -n RUNS number of repeated runs (default: 1) +# -C force clean rebuild (-C) on every run +# -t LIST trace target script basenames (default: trbldoc.sh) + +set -u + +SELF="$0" +. "$(dirname -- "$0")/lib/common.sh" +tb_resolve_paths "$SELF" + +OUTDIR="" +RUNS=1 +CLEAN=0 +TARGETS="trbldoc.sh" + +while getopts ":o:n:Ct:h" opt; do + case "$opt" in + o) OUTDIR="$OPTARG" ;; + n) RUNS="$OPTARG" ;; + C) CLEAN=1 ;; + t) TARGETS="$OPTARG" ;; + h) sed -n '2,24p' "$SELF"; exit 0 ;; + :) tb_die "option -$OPTARG requires an argument" ;; + \?) tb_die "unknown option -$OPTARG" ;; + esac +done +shift $((OPTIND - 1)) + +[ "${1:-}" = "--" ] && shift + +tb_require awk +tb_require sort +tb_require bash + +case "$RUNS" in + ''|*[!0-9]*|0) tb_die "-n RUNS must be a positive integer" ;; +esac + +[ -n "$OUTDIR" ] || OUTDIR="$REPO_ROOT/reports/profile-run-$(tb_timestamp)" +case "$OUTDIR" in + /*|[A-Za-z]:[\\/]*) ;; + *) OUTDIR="$REPO_ROOT/$OUTDIR" ;; +esac +mkdir -p "$OUTDIR" || tb_die "cannot create output dir: $OUTDIR" + +TRACE_DIR="$OUTDIR/trace" +RUN_DIR="$OUTDIR/runs" +mkdir -p "$TRACE_DIR" "$RUN_DIR" + +TRBLDOC_PATH="$REPO_ROOT/trbldoc.sh" +[ -f "$TRBLDOC_PATH" ] || tb_die "trbldoc source not found: $TRBLDOC_PATH" + +TRACE_TARGETS="" +for tf in $TARGETS; do + TRACE_TARGETS="$TRACE_TARGETS ${tf##*/}" +done + +# Resolve line anchors once for phase aggregation. If any anchor is missing, +# skip phase aggregation rather than failing the whole profiling run. +tb_find_line() { + _pat="$1" + awk -v p="$_pat" 'index($0, p) { print NR; exit }' "$TRBLDOC_PATH" +} +L_DISCOVER_END="$(tb_find_line '> "$source_files_list"')" +L_EXTRACT_END="$(tb_find_line '# Resolve src_repo once before the chunk loop.')" +L_ORDER_END="$(tb_find_line 'done < "$sorted_chunk_order_file"')" +L_RENDER_END="$(tb_find_line 'done < "$chunk_render_records_file"')" +L_NAV_END="$(tb_find_line '# Second pass: resolve inline references now that global.meta is complete.')" +L_REFS_END="$(tb_find_line 'rm -f "$_ref_find_tmp"')" +L_TOC_END="$(tb_find_line '# Post-processing pass: substitute {{ toc }} in all rendered index.html files')" +L_ASSEMBLE_END="$(tb_find_line 'assemble_site "$cache_dir/namespace" "$out_dir"')" + +: > "$OUTDIR/run-summary.tsv" + +run_idx=1 +while [ "$run_idx" -le "$RUNS" ]; do + tb_info "profiling run $run_idx/$RUNS..." + run_out="$RUN_DIR/run-$run_idx" + mkdir -p "$run_out" + run_stdout="$run_out/stdout.txt" + run_stderr="$run_out/stderr.txt" + run_start_s="$(date +%s)" + + BASH_ENV="$LIB_DIR/trace-init.sh" + TRBLDOC_TRACE_DIR="$TRACE_DIR" + TRBLDOC_TRACE_MODE="time" + TRBLDOC_TRACE_TARGETS="$TRACE_TARGETS" + export BASH_ENV TRBLDOC_TRACE_DIR TRBLDOC_TRACE_MODE TRBLDOC_TRACE_TARGETS + + if [ "$CLEAN" -eq 1 ]; then + (cd "$REPO_ROOT" && bash "$TRBLDOC_PATH" -C "$@") >"$run_stdout" 2>"$run_stderr" + else + (cd "$REPO_ROOT" && bash "$TRBLDOC_PATH" "$@") >"$run_stdout" 2>"$run_stderr" + fi + run_exit=$? + unset BASH_ENV TRBLDOC_TRACE_DIR TRBLDOC_TRACE_MODE TRBLDOC_TRACE_TARGETS + + run_end_s="$(date +%s)" + run_ms=$(( (run_end_s - run_start_s) * 1000 )) + printf '%s\t%s\t%s\n' "$run_idx" "$run_ms" "$run_exit" >> "$OUTDIR/run-summary.tsv" + run_idx=$((run_idx + 1)) +done + +sort -t "$(printf '\t')" -k2 -rn "$OUTDIR/run-summary.tsv" > "$OUTDIR/run-summary.sorted.tsv" +{ + printf 'run,total_ms,exit_code\n' + awk -F '\t' '{ printf "%s,%s,%s\n",$1,$2,$3 }' "$OUTDIR/run-summary.sorted.tsv" +} > "$OUTDIR/run-summary.csv" + +if ls "$TRACE_DIR"/trace.*.log >/dev/null 2>&1; then + awk -f "$LIB_DIR/trace-extract.awk" -v MODE=time "$TRACE_DIR"/trace.*.log \ + | sort -t "$(printf '\t')" -k1 -rn > "$OUTDIR/hotspots.tsv" + { + printf 'total_ms,hits,file,line\n' + awk -F '\t' '{ printf "%s,%s,%s,%s\n",$1,$2,$3,$4 }' "$OUTDIR/hotspots.tsv" + } > "$OUTDIR/hotspots.csv" + + FIRST_TARGET="${TARGETS%% *}" + case "$FIRST_TARGET" in + /*|[A-Za-z]:[\\/]*) SRC_PATH="$FIRST_TARGET" ;; + *) SRC_PATH="$REPO_ROOT/$FIRST_TARGET" ;; + esac + awk -f "$LIB_DIR/render-hotspots.awk" \ + -v TITLE="trbldoc line hotspots (direct runs)" \ + -v SRC="$SRC_PATH" \ + "$OUTDIR/hotspots.tsv" > "$OUTDIR/hotspots.html" +else + tb_die "no trace logs captured (check run stderr logs under $RUN_DIR)" +fi + +if [ -n "$L_DISCOVER_END" ] && [ -n "$L_EXTRACT_END" ] && [ -n "$L_ORDER_END" ] \ + && [ -n "$L_RENDER_END" ] && [ -n "$L_NAV_END" ] && [ -n "$L_REFS_END" ] \ + && [ -n "$L_TOC_END" ] && [ -n "$L_ASSEMBLE_END" ]; then + awk -f "$LIB_DIR/trace-phase-extract.awk" \ + -v SRC_BASE="trbldoc.sh" \ + -v L_DISCOVER_END="$L_DISCOVER_END" \ + -v L_EXTRACT_END="$L_EXTRACT_END" \ + -v L_ORDER_END="$L_ORDER_END" \ + -v L_RENDER_END="$L_RENDER_END" \ + -v L_NAV_END="$L_NAV_END" \ + -v L_REFS_END="$L_REFS_END" \ + -v L_TOC_END="$L_TOC_END" \ + -v L_ASSEMBLE_END="$L_ASSEMBLE_END" \ + "$TRACE_DIR"/trace.*.log \ + | sort -t "$(printf '\t')" -k1 -rn > "$OUTDIR/phase-hotspots.tsv" + + { + printf 'total_ms,hits,phase\n' + awk -F '\t' '{ printf "%s,%s,%s\n",$1,$2,$3 }' "$OUTDIR/phase-hotspots.tsv" + } > "$OUTDIR/phase-hotspots.csv" + + awk -f "$LIB_DIR/render-phases.awk" \ + -v TITLE="trbldoc phase hotspots (direct runs)" \ + "$OUTDIR/phase-hotspots.tsv" > "$OUTDIR/phase-hotspots.html" +else + tb_info "phase anchor discovery incomplete; skipping phase-hotspots report" +fi + +printf '\n==== slowest runs ====\n' +awk -F '\t' '{ printf "run %s %8.1f ms exit=%s\n",$1,$2,$3 }' "$OUTDIR/run-summary.sorted.tsv" +printf '\nReports written to: %s\n' "$OUTDIR" +printf ' run summary : %s\n' "$OUTDIR/run-summary.csv" +printf ' line hotspots : %s\n' "$OUTDIR/hotspots.html" +if [ -f "$OUTDIR/phase-hotspots.html" ]; then + printf ' phase hotspots : %s\n' "$OUTDIR/phase-hotspots.html" +fi diff --git a/scripts/profile-tests.sh b/scripts/profile-tests.sh new file mode 100644 index 0000000..498ae25 --- /dev/null +++ b/scripts/profile-tests.sh @@ -0,0 +1,184 @@ +#!/bin/sh +# scripts/profile-tests.sh +# Generate timing reports for the trbldoc test suite. +# +# Two levels of detail: +# 1. Per-test wall-clock timings from bats (--timing + JUnit report). Always +# produced. Answers "which tests take a long time". +# 2. Per-line hotspots inside trbldoc.sh (optional, --hotspots). Uses the +# BASH_ENV xtrace hook to time individual source lines across the whole +# run. Answers "which code takes a long time". +# +# POSIX sh; works under mingw bash, WSL bash and Alpine/busybox ash. +# +# Usage: +# scripts/profile-tests.sh [-s all|unit|integration] [-o OUTDIR] +# [-n TOPN] [-p] [-t "file.sh ..."] +# +# -s SUITE suite to run (default: integration) +# -o OUTDIR output directory (default: reports/profile-) +# -n TOPN number of rows in the printed "slowest" summary (default: 20) +# -p also collect per-line hotspots inside the target script(s) +# -t LIST space-separated target source files for -p (default: trbldoc.sh) + +set -u + +SELF="$0" +. "$(dirname -- "$0")/lib/common.sh" +tb_resolve_paths "$SELF" + +SUITE=integration +OUTDIR="" +TOPN=20 +HOTSPOTS=0 +TARGETS="trbldoc.sh" + +while getopts ":s:o:n:pt:h" opt; do + case "$opt" in + s) SUITE="$OPTARG" ;; + o) OUTDIR="$OPTARG" ;; + n) TOPN="$OPTARG" ;; + p) HOTSPOTS=1 ;; + t) TARGETS="$OPTARG" ;; + h) sed -n '2,30p' "$SELF"; exit 0 ;; + :) tb_die "option -$OPTARG requires an argument" ;; + \?) tb_die "unknown option -$OPTARG" ;; + esac +done + +tb_require awk +tb_require sort + +[ -n "$OUTDIR" ] || OUTDIR="$REPO_ROOT/reports/profile-$(tb_timestamp)" +case "$OUTDIR" in + /*|[A-Za-z]:[\\/]*) + ;; + *) + OUTDIR="$REPO_ROOT/$OUTDIR" + ;; +esac +mkdir -p "$OUTDIR" || tb_die "cannot create output dir: $OUTDIR" +JUNIT_DIR="$OUTDIR/junit" +mkdir -p "$JUNIT_DIR" + +SUITE_DIRS="$(tb_suite_dirs "$SUITE")" +SUITE_DIRS_REL="$(tb_suite_dirs_rel "$SUITE")" + +# ── 1. per-test timing via bats JUnit ─────────────────────────────────────── +tb_info "running bats ($SUITE) with timing..." +# --timing adds per-test durations; the junit report captures them in XML. +# We do not abort on test failures: timing is still useful. +if tb_bats_usable "$SUITE"; then + # shellcheck disable=SC2086 + bats --timing --report-formatter junit --output "$JUNIT_DIR" $SUITE_DIRS \ + > "$OUTDIR/bats-output.txt" 2>&1 || tb_info "bats reported failures (see bats-output.txt)" + BATS_MODE="local" +elif command -v wsl >/dev/null 2>&1; then + tb_info "local bats appears unusable; retrying via WSL bats..." + WSL_REPO="$(tb_to_wsl_path "$REPO_ROOT")" + WSL_JUNIT="$(tb_to_wsl_path "$JUNIT_DIR")" + wsl -- bash -lc \ + "cd '$WSL_REPO' && bats --timing --report-formatter junit --output '$WSL_JUNIT' $SUITE_DIRS_REL" \ + > "$OUTDIR/bats-output.txt" 2>&1 || tb_info "bats (WSL) reported failures (see bats-output.txt)" + BATS_MODE="wsl" +else + tb_die "local bats command appears unusable and no WSL fallback is available" +fi + +# Collect all JUnit XML the formatter produced. +: > "$OUTDIR/timings.tsv" +for xml in "$JUNIT_DIR"/*.xml; do + [ -f "$xml" ] || continue + awk -f "$LIB_DIR/timing-extract.awk" "$xml" >> "$OUTDIR/timings.tsv" +done + +if [ ! -s "$OUTDIR/timings.tsv" ]; then + if grep -qi "bash\\\\r" "$OUTDIR/bats-output.txt" 2>/dev/null; then + tb_die "bats appears broken (CRLF shebang: 'bash\\r'). Reinstall bats or run dos2unix on the bats scripts, then retry." + fi + tb_die "no per-test timings parsed (check $OUTDIR/bats-output.txt)" +fi + +# Sort slowest first. +sort -t "$(printf '\t')" -k1 -rn "$OUTDIR/timings.tsv" > "$OUTDIR/timings.sorted.tsv" + +# CSV summary. +{ + printf 'seconds,suite,test\n' + awk -F '\t' '{ gsub(/"/,"\"\"",$3); printf "%s,%s,\"%s\"\n",$1,$2,$3 }' \ + "$OUTDIR/timings.sorted.tsv" +} > "$OUTDIR/timings.csv" + +# HTML report. +awk -f "$LIB_DIR/render-timing.awk" \ + -v TITLE="trbldoc test timings ($SUITE)" \ + "$OUTDIR/timings.sorted.tsv" > "$OUTDIR/timings.html" + +# ── 2. optional per-line hotspots ──────────────────────────────────────────── +if [ "$HOTSPOTS" -eq 1 ]; then + tb_info "collecting per-line hotspots (this reruns the suite under xtrace)..." + TRACE_DIR="$OUTDIR/trace" + rm -rf "$TRACE_DIR"; mkdir -p "$TRACE_DIR" + + # Build the trace-target basename filter. + TRACE_TARGETS="" + for tf in $TARGETS; do + TRACE_TARGETS="$TRACE_TARGETS ${tf##*/}" + done + + BASH_ENV="$LIB_DIR/trace-init.sh" + TRBLDOC_TRACE_DIR="$TRACE_DIR" + TRBLDOC_TRACE_MODE="time" + TRBLDOC_TRACE_TARGETS="$TRACE_TARGETS" + if [ "$BATS_MODE" = "local" ]; then + export BASH_ENV TRBLDOC_TRACE_DIR TRBLDOC_TRACE_MODE TRBLDOC_TRACE_TARGETS + # shellcheck disable=SC2086 + bats --report-formatter junit --output "$JUNIT_DIR" $SUITE_DIRS \ + > "$OUTDIR/bats-hotspots-output.txt" 2>&1 \ + || tb_info "bats reported failures during hotspot run" + unset BASH_ENV TRBLDOC_TRACE_DIR TRBLDOC_TRACE_MODE TRBLDOC_TRACE_TARGETS + else + WSL_REPO="$(tb_to_wsl_path "$REPO_ROOT")" + WSL_LIB="$(tb_to_wsl_path "$LIB_DIR")" + WSL_TRACE="$(tb_to_wsl_path "$TRACE_DIR")" + WSL_JUNIT="$(tb_to_wsl_path "$JUNIT_DIR")" + wsl -- bash -lc \ + "cd '$WSL_REPO' && export BASH_ENV='$WSL_LIB/trace-init.sh' TRBLDOC_TRACE_DIR='$WSL_TRACE' TRBLDOC_TRACE_MODE='time' TRBLDOC_TRACE_TARGETS='$TRACE_TARGETS'; bats --report-formatter junit --output '$WSL_JUNIT' $SUITE_DIRS_REL" \ + > "$OUTDIR/bats-hotspots-output.txt" 2>&1 \ + || tb_info "bats (WSL) reported failures during hotspot run" + fi + + if ls "$TRACE_DIR"/trace.*.log >/dev/null 2>&1; then + awk -f "$LIB_DIR/trace-extract.awk" -v MODE=time "$TRACE_DIR"/trace.*.log \ + | sort -t "$(printf '\t')" -k1 -rn > "$OUTDIR/hotspots.tsv" + { + printf 'total_ms,hits,file,line\n' + awk -F '\t' '{ printf "%s,%s,%s,%s\n",$1,$2,$3,$4 }' "$OUTDIR/hotspots.tsv" + } > "$OUTDIR/hotspots.csv" + # Resolve first target path for source display in the HTML. + FIRST_TARGET="${TARGETS%% *}" + case "$FIRST_TARGET" in + /*) SRC_PATH="$FIRST_TARGET" ;; + *) SRC_PATH="$REPO_ROOT/$FIRST_TARGET" ;; + esac + awk -f "$LIB_DIR/render-hotspots.awk" \ + -v TITLE="trbldoc line hotspots ($SUITE)" \ + -v SRC="$SRC_PATH" \ + "$OUTDIR/hotspots.tsv" > "$OUTDIR/hotspots.html" + else + if grep -qi "bash\\\\r" "$OUTDIR/bats-hotspots-output.txt" 2>/dev/null; then + tb_die "bats appears broken (CRLF shebang: 'bash\\r') during hotspot run. Reinstall bats or run dos2unix on the bats scripts." + fi + tb_info "no trace data captured; skipping hotspots report" + HOTSPOTS=0 + fi +fi + +# ── printed summary ────────────────────────────────────────────────────────── +printf '\n==== slowest %s tests ====\n' "$TOPN" +awk -F '\t' -v n="$TOPN" 'NR<=n { printf "%8.3fs %s\n", $1, $3 }' \ + "$OUTDIR/timings.sorted.tsv" + +printf '\nReports written to: %s\n' "$OUTDIR" +printf ' per-test timing : %s\n' "$OUTDIR/timings.html" +[ "$HOTSPOTS" -eq 1 ] && printf ' line hotspots : %s\n' "$OUTDIR/hotspots.html" -- cgit v1.2.3-70-g09d2