From 64d1b2e317ef20caae6ac2c8fedba36e4a24c8ea Mon Sep 17 00:00:00 2001 From: Chemaclass Date: Wed, 9 Sep 2026 10:05:58 +0200 Subject: [PATCH] perf(runner): resolve a test's source location only when it is needed Every test forked a subshell to read its own definition line: `$(shopt -s extdebug; declare -F "$fn")`, 1.08ms per call on macOS arm64 (bash 3.2.57). It produced `:` for a failure message most tests never emit, and for a report row that add_test discards before reading when no report is configured. A 500-test file spent 0.35s of 2.75s on it. Carry the file and function name instead and resolve on the two paths that render the location. A plain run pays nothing; a run with `--report-*` pays what it paid before. The two obvious alternatives are both worse on Bash 3.2, so they are recorded here rather than retried: a parallel-array map scanned per test made a 500-test file 7.5ms/test against 6.3ms, because a Bash 3 array is a linked list and indexing is O(i); a single-string map read with `${map#*$'\n'$fn$'\t'}` made it 19ms/test, because prefix removal against a leading `*` is quadratic in the string length. The inputs are not exported. Every consumer runs in a fork, which inherits them regardless, while an exec'd process gets a function name its own shell never defined -- which is how a standalone `bashunit -a assert_same` came to print the location of whichever test had launched it. It now prints none, and the acceptance snapshot that pinned the leak loses that line. perf-fork-budget.md's 0.46ms figure for a bare `$( )` predates arm64 and read as "a subshell is not worth removing"; it now carries the arm64 numbers. Closes #1346 Claude-Session: https://claude.ai/code/session_01EXYWTGLjf7qM8Ru3GakDRm --- .claude/rules/perf-fork-budget.md | 6 +- CHANGELOG.md | 2 + src/console/test_line.sh | 1 + src/reports/collect.sh | 5 +- src/runner/context.sh | 38 ++++++++- ...t_bashunit_direct_fn_call_failure.snapshot | 1 - tests/unit/console/results_test.sh | 6 ++ tests/unit/runner/context_test.sh | 80 +++++++++++++++++++ 8 files changed, 135 insertions(+), 4 deletions(-) diff --git a/.claude/rules/perf-fork-budget.md b/.claude/rules/perf-fork-budget.md index f13d7f6e..f0422416 100644 --- a/.claude/rules/perf-fork-budget.md +++ b/.claude/rules/perf-fork-budget.md @@ -191,7 +191,11 @@ them: that does used to cost five more forks per test (#1345), which is why that never showed up here. A census fixture only measures the path it exercises. - **Not the capture subshell.** A bare `$( )` costs ~0.46 ms here, about 6% of - the 7.8 ms. The rest is bash work in the per-test machinery. + the 7.8 ms. The rest is bash work in the per-test machinery. That 0.46 ms + predates arm64 and must not be reused for estimates: the same measurement on + macOS arm64 (bash 3.2.57) is 1.1-1.4 ms, and a subshell that also runs + `shopt`/`declare` in it, 1.08 ms (#1346). A subshell per test is worth + removing on that hardware even when this note says it is not the bottleneck. - **Not quadratic.** Per-test cost is 7.17 ms at 100 tests and 8.06 ms at 1000 -- +12% over a 10x range, so the #830 fn-accumulation fix still holds. A regression there would show as per-test cost climbing with suite size. diff --git a/CHANGELOG.md b/CHANGELOG.md index c030cc7a..d3af5303 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -3,6 +3,8 @@ ## Unreleased ### Changed +- Performance: a sequential run is about 0.7ms faster per test — a 500-test file went from 2.75s to 2.40s on macOS arm64, bash 3.2. Every test forked a subshell to read its own definition line, for a `:` that only a failure message and a report row ever use. It is resolved on demand now (#1346) +- A standalone `bashunit assert …` no longer reports a source location belonging to another process. Launched from inside a test, it inherited that test's exported location and printed it as its own (#1346) - Performance: a test in a file that defines `set_up` or `tear_down` is about 2.6x faster, which brings it level with a hookless test (14.1ms to 5.4ms per test on macOS arm64, bash 3.2). Each hook minted its output file with `mktemp` and removed it with `rm`, and the ownership marker that left behind made the runner `rm -rf` the test's temp files at exit — five forks per test, even for a test that created no temp file of its own (#1345) ### Fixed diff --git a/src/console/test_line.sh b/src/console/test_line.sh index 5b06202f..8a24afb5 100644 --- a/src/console/test_line.sh +++ b/src/console/test_line.sh @@ -46,6 +46,7 @@ function bashunit::console_results::print_successful_test() { # is unknown. Used to append source context to failure output. ## function bashunit::console_results::test_location_suffix() { + bashunit::runner::ensure_test_location local location=${_BASHUNIT_TEST_LOCATION:-} if [ -z "$location" ]; then return 0 diff --git a/src/reports/collect.sh b/src/reports/collect.sh index 42bc2ec7..edfec052 100644 --- a/src/reports/collect.sh +++ b/src/reports/collect.sh @@ -100,7 +100,10 @@ function bashunit::reports::add_test() { # Capture the line number from the current test location ("file:line"), # but only when it belongs to this test's file, so a stale location from a - # prior test never mislabels this entry. + # prior test never mislabels this entry. Resolved here rather than per test: + # reports are opt-in and this function has already returned when they are off + # (#1346). + bashunit::runner::ensure_test_location local line="" case "${_BASHUNIT_TEST_LOCATION:-}" in "$file":*) line="${_BASHUNIT_TEST_LOCATION##*:}" ;; diff --git a/src/runner/context.sh b/src/runner/context.sh index a3429472..c2b55ad9 100644 --- a/src/runner/context.sh +++ b/src/runner/context.sh @@ -62,7 +62,18 @@ function bashunit::runner::export_test_identity() { local fn_name=$2 bashunit::helper::generate_id "$fn_name" export BASHUNIT_CURRENT_TEST_ID="$_BASHUNIT_HELPER_ID_OUT" - bashunit::runner::resolve_test_location "$test_file" "$fn_name" + # Carry the inputs; do not resolve. Reading the definition line costs a + # subshell, and only a failure message and a report row ever ask for it + # (#1346). Cleared per test so a previous test's line cannot answer for this + # one. + # + # The inputs are deliberately NOT exported. Every consumer runs in a fork of + # this shell, which inherits them anyway, while an exec'd process gets a name + # its own shell never defined. That is how a standalone `bashunit -a` used to + # report the location of whichever test had launched it. + _BASHUNIT_TEST_LOCATION="" + _BASHUNIT_TEST_LOCATION_FILE=$test_file + _BASHUNIT_TEST_LOCATION_FN=$fn_name export _BASHUNIT_TEST_LOCATION if [ "${_BASHUNIT_COVERAGE_ON:-0}" = 1 ]; then export _BASHUNIT_COVERAGE_CURRENT_TEST_FILE="$test_file" @@ -70,6 +81,31 @@ function bashunit::runner::export_test_identity() { fi } +## +# Resolves the running test's location, once, if anything asks for it. +# +# The lookup below forks a subshell, which measured 1.08ms per call on macOS +# arm64 (bash 3.2.57) -- about 2.7s across this suite when every test paid it +# up front. A passing test never reads the result, and reports are opt-in, so +# the cost now falls only where the line is actually rendered (#1346). +# +# A caller inside `$( )` loses the assignment with its subshell, which only +# means the next one resolves again: correct either way, and the failure path +# is not hot. +## +function bashunit::runner::ensure_test_location() { + if [ -n "${_BASHUNIT_TEST_LOCATION:-}" ]; then + return 0 + fi + + if [ -z "${_BASHUNIT_TEST_LOCATION_FN:-}" ]; then + return 0 + fi + + bashunit::runner::resolve_test_location \ + "${_BASHUNIT_TEST_LOCATION_FILE:-}" "$_BASHUNIT_TEST_LOCATION_FN" +} + ## # Resolves ":" for a test function and writes it into the # global _BASHUNIT_TEST_LOCATION, using `declare -F` under `extdebug` to read diff --git a/tests/acceptance/snapshots/bashunit_direct_fn_call_advanced_test_sh.test_bashunit_direct_fn_call_failure.snapshot b/tests/acceptance/snapshots/bashunit_direct_fn_call_advanced_test_sh.test_bashunit_direct_fn_call_failure.snapshot index c38ae128..c6f5a18c 100644 --- a/tests/acceptance/snapshots/bashunit_direct_fn_call_advanced_test_sh.test_bashunit_direct_fn_call_failure.snapshot +++ b/tests/acceptance/snapshots/bashunit_direct_fn_call_advanced_test_sh.test_bashunit_direct_fn_call_failure.snapshot @@ -1,4 +1,3 @@ ✗ Failed: assert same Expected 'foo' but got  'bar' - at tests/acceptance/bashunit_direct_fn_call_advanced_test.sh:16 diff --git a/tests/unit/console/results_test.sh b/tests/unit/console/results_test.sh index f04e51ff..72201ed7 100644 --- a/tests/unit/console/results_test.sh +++ b/tests/unit/console/results_test.sh @@ -798,9 +798,14 @@ function test_test_location_suffix_when_set() { export _BASHUNIT_TEST_LOCATION="$original" } +# The suffix resolves the location on demand now (#1346), so "unknown" means +# the inputs are gone too -- clearing only the cached value would just make it +# resolve the test that is running. function test_test_location_suffix_empty_when_unset() { local original=${_BASHUNIT_TEST_LOCATION:-} + local original_fn=${_BASHUNIT_TEST_LOCATION_FN:-} unset _BASHUNIT_TEST_LOCATION + unset _BASHUNIT_TEST_LOCATION_FN local output output="$(bashunit::console_results::test_location_suffix)" @@ -808,6 +813,7 @@ function test_test_location_suffix_empty_when_unset() { assert_empty "$output" export _BASHUNIT_TEST_LOCATION="$original" + export _BASHUNIT_TEST_LOCATION_FN="$original_fn" } # --- print_tap_line ----------------------------------------------------------- diff --git a/tests/unit/runner/context_test.sh b/tests/unit/runner/context_test.sh index 1654ee24..41fdf56e 100644 --- a/tests/unit/runner/context_test.sh +++ b/tests/unit/runner/context_test.sh @@ -69,3 +69,83 @@ function test_restore_workdir_aborts_loudly_when_the_directory_is_gone() { assert_contains "cannot restore the working directory" "$output" assert_contains "$gone" "$output" } + +# --- test location ------------------------------------------------------------ + +# Resolving ":" reads the definition line with +# `$(shopt -s extdebug; declare -F …)`, a subshell that costs 1.08ms on macOS +# arm64 — ~2.7s over this suite. Only a failure message and a report row ever +# read it, so the identity carries the inputs and nothing resolves up front +# (#1346). +function test_export_test_identity_leaves_the_location_unresolved() { + local orig_id=${BASHUNIT_CURRENT_TEST_ID:-} + local orig_location=${_BASHUNIT_TEST_LOCATION:-} + local orig_file=${_BASHUNIT_TEST_LOCATION_FILE:-} + local orig_fn=${_BASHUNIT_TEST_LOCATION_FN:-} + + bashunit::runner::export_test_identity "some_test.sh" "test_not_defined_here" + + assert_empty "$_BASHUNIT_TEST_LOCATION" + assert_same "some_test.sh" "$_BASHUNIT_TEST_LOCATION_FILE" + assert_same "test_not_defined_here" "$_BASHUNIT_TEST_LOCATION_FN" + + export BASHUNIT_CURRENT_TEST_ID="$orig_id" + export _BASHUNIT_TEST_LOCATION="$orig_location" + export _BASHUNIT_TEST_LOCATION_FILE="$orig_file" + export _BASHUNIT_TEST_LOCATION_FN="$orig_fn" +} + +function test_ensure_test_location_resolves_on_demand() { + local orig_location=${_BASHUNIT_TEST_LOCATION:-} + local orig_file=${_BASHUNIT_TEST_LOCATION_FILE:-} + local orig_fn=${_BASHUNIT_TEST_LOCATION_FN:-} + _BASHUNIT_TEST_LOCATION="" + _BASHUNIT_TEST_LOCATION_FILE="mine.sh" + _BASHUNIT_TEST_LOCATION_FN="test_ensure_test_location_resolves_on_demand" + + bashunit::runner::ensure_test_location + + assert_matches "^mine\.sh:[0-9]+$" "$_BASHUNIT_TEST_LOCATION" + + export _BASHUNIT_TEST_LOCATION="$orig_location" + export _BASHUNIT_TEST_LOCATION_FILE="$orig_file" + export _BASHUNIT_TEST_LOCATION_FN="$orig_fn" +} + +# Resolved once per test: the failure path renders the suffix up to three +# times, and each would otherwise pay the subshell again. +function test_ensure_test_location_keeps_an_already_resolved_location() { + local orig_location=${_BASHUNIT_TEST_LOCATION:-} + local orig_file=${_BASHUNIT_TEST_LOCATION_FILE:-} + local orig_fn=${_BASHUNIT_TEST_LOCATION_FN:-} + _BASHUNIT_TEST_LOCATION="already/resolved.sh:7" + _BASHUNIT_TEST_LOCATION_FILE="mine.sh" + _BASHUNIT_TEST_LOCATION_FN="test_ensure_test_location_keeps_an_already_resolved_location" + + bashunit::runner::ensure_test_location + + assert_same "already/resolved.sh:7" "$_BASHUNIT_TEST_LOCATION" + + export _BASHUNIT_TEST_LOCATION="$orig_location" + export _BASHUNIT_TEST_LOCATION_FILE="$orig_file" + export _BASHUNIT_TEST_LOCATION_FN="$orig_fn" +} + +# Nothing to resolve from, so nothing is claimed: an empty location renders no +# "at …" suffix at all. +function test_ensure_test_location_stays_empty_without_a_function_name() { + local orig_location=${_BASHUNIT_TEST_LOCATION:-} + local orig_file=${_BASHUNIT_TEST_LOCATION_FILE:-} + local orig_fn=${_BASHUNIT_TEST_LOCATION_FN:-} + _BASHUNIT_TEST_LOCATION="" + _BASHUNIT_TEST_LOCATION_FILE="" + _BASHUNIT_TEST_LOCATION_FN="" + + bashunit::runner::ensure_test_location + + assert_empty "$_BASHUNIT_TEST_LOCATION" + + export _BASHUNIT_TEST_LOCATION="$orig_location" + export _BASHUNIT_TEST_LOCATION_FILE="$orig_file" + export _BASHUNIT_TEST_LOCATION_FN="$orig_fn" +}