perf(reports): remove codec processes from collection

CHANGELOG.md

@@ -3,6 +3,7 @@
 ## Unreleased
 
 ### Changed
+- Parallel reports collect worker results without per-row base64 processes, preserving values and completion order (#1371)
 - Data providers pass arguments without per-argument base64 processes, preserving quoting, empty values and parser isolation (#1370)
 - JSON reports write ordinary filenames, test names and empty messages without per-field processes, preserving existing escaping (#1369)
 

src/reports/collect.sh

@@ -2,11 +2,6 @@
 
 # Collected per-test results: the shared arrays every report writer reads, and the API the runner calls to fill them.
 
-# Field separator for the rows parallel workers spool. ASCII unit separator: it
-# cannot appear in base64 output and is not an IFS whitespace character, so a
-# run of them yields empty fields instead of collapsing.
-_BASHUNIT_REPORTS_FIELD_SEP=$'\037'
-
 # Strips ANSI CSI escape sequences (color codes, cursor moves, erase-line, ...)
 # from $1. Shared by every writer's own escape/encode function below as their
 # first step, so the definition of "what is an ANSI escape sequence" for
@@ -30,6 +25,10 @@ _BASHUNIT_REPORTS_TEST_OUTPUTS=()
 # it (JUnit <system-out>) without threading one more argument through every
 # wrapper; add_test consumes and clears it.
 _BASHUNIT_REPORTS_CURRENT_OUTPUT=""
+_BASHUNIT_REPORTS_FILE_ORDINAL=0
+_BASHUNIT_REPORTS_CONTROL_RECORD_ORDINAL=0
+_BASHUNIT_REPORTS_WORKER_RECORD_ORDINAL=0
+_BASHUNIT_REPORTS_RECORD_SCOPE=control
 
 function bashunit::reports::set_current_test_output() {
   _BASHUNIT_REPORTS_CURRENT_OUTPUT="$1"
@@ -109,41 +108,48 @@ function bashunit::reports::add_test() {
     "$file":*) line="${_BASHUNIT_TEST_LOCATION##*:}" ;;
   esac
 
-  # Under --parallel this runs inside the per-test worker, so the arrays below
-  # are appended to in a process that is about to exit and the parent rebuilds
-  # nothing -- every report came out with zero tests while the run stayed green.
-  # Spool the row to a run-scoped file as well, the same way
-  # --snapshot-report-unused crosses the fork boundary, and replay it in the
-  # parent before the writers run.
-  #
-  # The arrays are still filled here rather than skipped: this function is also
-  # called directly, in the parent, by the reports unit tests, and returning
-  # early left them asserting against arrays nothing had touched. The parent
-  # never reaches this path for a real parallel test, so replaying the spool
-  # cannot double-count.
-  #
-  # Only the four fields that can hold arbitrary text are base64-encoded: a
-  # failure message or a captured output carries newlines, and a path or a test
-  # name (which may end in a provider's arguments) can hold anything. The other
-  # five are a status word and four numbers, produced by this file's own
-  # callers, so the unit separator carries them as they are.
-  #
-  # Encoding all nine cost fourteen `base64` forks per test -- nine here and
-  # five more decoding, each with a `tr` on top -- which made `--log-junit`
-  # several times more expensive than the run it was reporting on. Base64
-  # output is [A-Za-z0-9+/=] and the raw fields are numeric, so no field can
-  # contain the separator and the row stays one line.
+  # Sidecars avoid Bash 3's bytewise read on large diagnostics.
   if bashunit::parallel::is_enabled; then
-    local us=$_BASHUNIT_REPORTS_FIELD_SEP
-    local row
-    row="$(bashunit::helper::encode_base64 "$file")$us"
-    row="$row$(bashunit::helper::encode_base64 "$test_name")$us"
-    row="$row$status$us$duration$us$assertions$us"
-    row="$row$(bashunit::helper::encode_base64 "$failure_message")$us"
-    row="$row$line$us$retries$us"
-    row="$row$(bashunit::helper::encode_base64 "$test_output")"
-    printf '%s\n' "$row" \
-      >>"${REPORTS_OUTPUT_PATH:-/dev/null}" 2>/dev/null || true
+    local file_order="00000000${_BASHUNIT_REPORTS_FILE_ORDINAL:-0}"
+    file_order="${file_order: -8}"
+    local row_order="00000000${_BASHUNIT_RUNNER_RESULT_ORDINAL:-0}"
+    row_order="${row_order: -8}"
+    local record_kind=0
+    local record_order=00000000
+    if [ "$_BASHUNIT_REPORTS_RECORD_SCOPE" = worker ]; then
+      _BASHUNIT_REPORTS_WORKER_RECORD_ORDINAL=$((_BASHUNIT_REPORTS_WORKER_RECORD_ORDINAL + 1))
+      record_order="00000000$_BASHUNIT_REPORTS_WORKER_RECORD_ORDINAL"
+      record_order="${record_order: -8}"
+    else
+      record_kind=1
+      _BASHUNIT_REPORTS_CONTROL_RECORD_ORDINAL=$((_BASHUNIT_REPORTS_CONTROL_RECORD_ORDINAL + 1))
+      record_order="00000000$_BASHUNIT_REPORTS_CONTROL_RECORD_ORDINAL"
+      record_order="${record_order: -8}"
+    fi
+    local record_token="$file_order$row_order$record_kind$record_order"
+    local record="${REPORTS_OUTPUT_PATH:-/dev/null}.$record_token.record"
+    local has_failure=0
+    local has_output=0
+    local write_failed=false
+    if [ -n "$failure_message" ]; then
+      has_failure=1
+      printf '%s_' "$failure_message" >"$record.failure" 2>/dev/null || write_failed=true
+    fi
+    if [ -n "$test_output" ]; then
+      has_output=1
+      printf '%s_' "$test_output" >"$record.output" 2>/dev/null || write_failed=true
+    fi
+    if [ "$write_failed" = false ]; then
+      printf '%s\0' "$file" "$test_name" "$status" "$duration" "$assertions" "$line" "$retries" \
+        "$has_failure" "$has_output" >"$record" 2>/dev/null || write_failed=true
+    fi
+    if [ "$write_failed" = false ]; then
+      # A 26-byte builtin append publishes the complete row in completion order.
+      printf '%s\n' "$record_token" >>"${REPORTS_OUTPUT_PATH:-/dev/null}" 2>/dev/null || write_failed=true
+    fi
+    if [ "$write_failed" = true ]; then
+      printf 'bashunit: unable to write report record %s\n' "$record" >&2
+    fi
   fi
 
   _BASHUNIT_REPORTS_TEST_FILES[${#_BASHUNIT_REPORTS_TEST_FILES[@]}]="$file"
@@ -158,12 +164,13 @@ function bashunit::reports::add_test() {
 }
 
 ##
-# Replays rows spooled by parallel workers into the report arrays, in the order
-# they were written. Called once in the parent before any report is generated;
+# Replays rows spooled by parallel workers into the report arrays in publication
+# order. Called once in the parent before any report is generated;
 # a no-op sequentially, where add_test filled the arrays directly.
 ##
 function bashunit::reports::load_spooled() {
   bashunit::reports::is_enabled || return 0
+  bashunit::parallel::is_enabled || return 0
   [ -f "${REPORTS_OUTPUT_PATH:-}" ] || return 0
 
   # The spool is the complete record of a parallel run, so it replaces the
@@ -186,22 +193,71 @@ function bashunit::reports::load_spooled() {
   _BASHUNIT_REPORTS_TEST_RETRIES=()
   _BASHUNIT_REPORTS_TEST_OUTPUTS=()
 
-  local file test_name status duration assertions failure_message line retries test_output n
-  # The separator is not an IFS whitespace character, so a run of them yields
-  # empty fields rather than collapsing -- which is what an absent failure
-  # message or output has to produce.
-  while IFS="$_BASHUNIT_REPORTS_FIELD_SEP" read -r \
-    file test_name status duration assertions failure_message line retries test_output; do
-    [ -n "$file" ] || continue
+  local record_token record file test_name status duration assertions failure_message line retries test_output
+  local has_failure has_output
+  while IFS= read -r record_token; do
+    case "$record_token" in
+      *[!0-9]* | "")
+        printf 'bashunit: invalid report record token %s\n' "$record_token" >&2
+        continue
+        ;;
+    esac
+    if [ "${#record_token}" -ne 25 ]; then
+      printf 'bashunit: invalid report record token %s\n' "$record_token" >&2
+      continue
+    fi
+    record="$REPORTS_OUTPUT_PATH.$record_token.record"
+    if [ ! -f "$record" ]; then
+      printf 'bashunit: missing report record %s\n' "$record" >&2
+      continue
+    fi
+    if {
+      IFS= read -r -d '' file &&
+        IFS= read -r -d '' test_name &&
+        IFS= read -r -d '' status &&
+        IFS= read -r -d '' duration &&
+        IFS= read -r -d '' assertions &&
+        IFS= read -r -d '' line &&
+        IFS= read -r -d '' retries &&
+        IFS= read -r -d '' has_failure &&
+        IFS= read -r -d '' has_output
+    } <"$record"; then
+      :
+    else
+      printf 'bashunit: incomplete report record %s\n' "$record" >&2
+      continue
+    fi
+    failure_message=""
+    test_output=""
+    if [ "$has_failure" = 1 ] && [ -f "$record.failure" ]; then
+      failure_message=$(<"$record.failure")
+      case "$failure_message" in
+      *_) failure_message="${failure_message%?}" ;;
+      *) printf 'bashunit: incomplete report field %s\n' "$record.failure" >&2; continue ;;
+      esac
+    elif [ "$has_failure" = 1 ]; then
+      printf 'bashunit: missing report field %s\n' "$record.failure" >&2
+      continue
+    fi
+    if [ "$has_output" = 1 ] && [ -f "$record.output" ]; then
+      test_output=$(<"$record.output")
+      case "$test_output" in
+      *_) test_output="${test_output%?}" ;;
+      *) printf 'bashunit: incomplete report field %s\n' "$record.output" >&2; continue ;;
+      esac
+    elif [ "$has_output" = 1 ]; then
+      printf 'bashunit: missing report field %s\n' "$record.output" >&2
+      continue
+    fi
     local n=${#_BASHUNIT_REPORTS_TEST_FILES[@]}
-    _BASHUNIT_REPORTS_TEST_FILES[n]=$(bashunit::helper::decode_base64 "$file")
-    _BASHUNIT_REPORTS_TEST_NAMES[n]=$(bashunit::helper::decode_base64 "$test_name")
+    _BASHUNIT_REPORTS_TEST_FILES[n]=$file
+    _BASHUNIT_REPORTS_TEST_NAMES[n]=$test_name
     _BASHUNIT_REPORTS_TEST_STATUSES[n]=$status
     _BASHUNIT_REPORTS_TEST_DURATIONS[n]=$duration
     _BASHUNIT_REPORTS_TEST_ASSERTIONS[n]=$assertions
-    _BASHUNIT_REPORTS_TEST_FAILURES[n]=$(bashunit::helper::decode_base64 "$failure_message")
+    _BASHUNIT_REPORTS_TEST_FAILURES[n]=$failure_message
     _BASHUNIT_REPORTS_TEST_LINES[n]=$line
     _BASHUNIT_REPORTS_TEST_RETRIES[n]=$retries
-    _BASHUNIT_REPORTS_TEST_OUTPUTS[n]=$(bashunit::helper::decode_base64 "$test_output")
+    _BASHUNIT_REPORTS_TEST_OUTPUTS[n]=$test_output
   done <"$REPORTS_OUTPUT_PATH"
 }

src/runner/discovery.sh

@@ -65,6 +65,9 @@ function bashunit::runner::load_test_files() {
     export BASHUNIT_CURRENT_SCRIPT_ID="$_BASHUNIT_HELPER_ID_OUT"
     scripts_ids[scripts_ids_count]="${BASHUNIT_CURRENT_SCRIPT_ID}"
     scripts_ids_count=$((scripts_ids_count + 1))
+    _BASHUNIT_REPORTS_FILE_ORDINAL=$((_BASHUNIT_REPORTS_FILE_ORDINAL + 1))
+    _BASHUNIT_REPORTS_CONTROL_RECORD_ORDINAL=0
+    _BASHUNIT_RUNNER_RESULT_ORDINAL=0
     bashunit::internal_log "Loading file" "$test_file"
     # Files are sourced sequentially in this loop (parallel workers fork after),
     # so a fixed path in the run dir is safe: `2>` truncates it per file and the

src/runner/exec.sh

@@ -96,6 +96,11 @@ function bashunit::runner::report_provider_error() {
   fi
 }
 
+function bashunit::runner::run_test_parallel() {
+  _BASHUNIT_REPORTS_RECORD_SCOPE=worker
+  bashunit::runner::run_test "$@"
+}
+
 ##
 # Runs the given test functions of a script (sequentially, or one background
 # worker per test under --parallel).
@@ -177,7 +182,7 @@ function bashunit::runner::call_test_functions() {
         bashunit::runner::wait_for_job_slot
         _test_ordinal=$((_test_ordinal + 1))
         _BASHUNIT_RUNNER_RESULT_ORDINAL=$_test_ordinal
-        bashunit::runner::run_test "$script" "$fn_name" &
+        bashunit::runner::run_test_parallel "$script" "$fn_name" &
         _BASHUNIT_WORKER_TEST_PIDS="$_BASHUNIT_WORKER_TEST_PIDS $!"
       else
         bashunit::runner::run_test "$script" "$fn_name"
@@ -255,7 +260,7 @@ function bashunit::runner::call_test_functions() {
         bashunit::runner::wait_for_job_slot
         _test_ordinal=$((_test_ordinal + 1))
         _BASHUNIT_RUNNER_RESULT_ORDINAL=$_test_ordinal
-        bashunit::runner::run_test "$script" "$fn_name" ${parsed_data+"${parsed_data[@]}"} &
+        bashunit::runner::run_test_parallel "$script" "$fn_name" ${parsed_data+"${parsed_data[@]}"} &
         _BASHUNIT_WORKER_TEST_PIDS="$_BASHUNIT_WORKER_TEST_PIDS $!"
       else
         bashunit::runner::run_test "$script" "$fn_name" ${parsed_data+"${parsed_data[@]}"}

tests/acceptance/bashunit_run_forks_test.sh

@@ -277,15 +277,7 @@ function test_parallel_result_publishing_does_not_fork_per_test() {
   assert_equals "" "$forked"
 }
 
-# Regression guard for the report spool. A worker used to base64 each of the
-# nine fields of a result row separately, and the parent decoded each one the
-# same way -- fourteen `base64` forks per test (and, on the encode side, a `tr`
-# each), so turning on `--log-junit` cost more than running the tests. Only the
-# two fields that can hold arbitrary text need encoding; the rest are a status,
-# some numbers and a path, which a unit separator carries as they are.
-#
-# Counted with a PATH shim rather than a trace: these forks happen inside the
-# `--parallel` workers, which `bash -x` on the parent cannot see.
+# A PATH shim sees codec processes inside workers that the parent trace misses.
 function test_reports_do_not_fork_base64_per_field() {
   if bashunit::check_os::is_windows; then
     bashunit::skip "process tracing is unreliable under Git Bash" && return
@@ -321,11 +313,58 @@ function test_reports_do_not_fork_base64_per_field() {
     calls="$(grep -c . "$count_file" || true)"
   fi
 
-  # Four passing tests carry no failure message and no output, so both
-  # arbitrary fields are empty and short-circuit: the row costs one encode for
-  # the file and one for the test name, and the same two decodes. Sixteen is
-  # that, with room for the run's own bookkeeping; it was 56.
-  assert_less_or_equal_than 16 "$calls"
+  assert_equals 0 "$calls"
+}
+
+function test_parallel_reports_keep_lifecycle_rows_and_remove_scratch_records() {
+  local dir
+  dir="$(bashunit::temp_dir)"
+  mkdir "$dir/a" "$dir/b"
+  printf '%s\n' 'function data_spool_values() { printf "%s\n" "a:b" "a/b"; }
+# @data_provider data_spool_values
+function test_spool_provider_rows() { assert_true true; }
+# @skip intentional
+function test_spool_skip() { assert_same never ran; }
+# @retry 1
+function test_spool_retry() {
+  if [ -f "$REPORT_RETRY_MARKER" ]; then
+    assert_true true
+  else
+    : >"$REPORT_RETRY_MARKER"
+    assert_same first second
+  fi
+}
+# @data_provider undefined_spool_provider
+function test_spool_missing_provider() { assert_same never ran; }
+function tear_down_after_script() { printf "worker teardown failure\n"; return 1; }' >"$dir/a/same_test.sh"
+  printf '%s\n' 'function set_up_before_script() { printf "parent setup failure\n"; return 1; }
+function test_spool_blocked_by_setup() { assert_same never ran; }
+function tear_down_after_script() { printf "parent teardown failure\n"; return 1; }' >"$dir/b/same_test.sh"
+
+  local exit_code=0
+  TMPDIR="$dir" REPORT_RETRY_MARKER="$dir/retried" ./bashunit --skip-env-file --parallel --simple \
+    --report-junit "$dir/out.xml" --report-json "$dir/out.json" --report-tap "$dir/out.tap" \
+    --report-html "$dir/out.html" --report-md "$dir/out.md" --log-gha "$dir/out.gha" \
+    "$dir/a/same_test.sh" "$dir/b/same_test.sh" >"$dir/console" 2>&1 || exit_code=$?
+
+  assert_same 1 "$exit_code"
+  assert_file_contains "$dir/out.json" '"total": 8, "passed": 3, "failed": 4, "skipped": 1'
+  assert_file_contains "$dir/out.json" '"flaky": 1'
+  assert_same 8 "$("$GREP" -c '"name":' "$dir/out.json")"
+  assert_same 8 "$("$GREP" -c '<testcase ' "$dir/out.xml")"
+  assert_file_contains "$dir/out.xml" 'tests="8" failures="4" skipped="1"'
+  assert_file_contains "$dir/out.tap" '1..8'
+  assert_file_contains "$dir/out.html" 'parent setup failure'
+  assert_file_contains "$dir/out.md" '| Failed | 4 |'
+  assert_same 4 "$("$GREP" -c '^::error ' "$dir/out.gha")"
+  assert_same 1 "$("$GREP" -c '^::warning ' "$dir/out.gha")"
+
+  local leftover=0
+  local entry
+  for entry in "$dir/bashunit/run"/*/*; do
+    [ -e "$entry" ] && leftover=$((leftover + 1))
+  done
+  assert_same 0 "$leftover"
 }
 
 function test_provider_arguments_do_not_fork_base64_per_value() {