fix: tolerate a 1s timing tie in test-run-all-timing.sh (#482)

changelog.d/482.fixed.run-all-timing-tie.md

@@ -0,0 +1 @@
+- **A 1s tie in `tests/run-all.sh`'s timing block sorted by name, failing `tests/test-run-all-timing.sh` on a loaded Windows runner** (#482). `test-b-slow.sh` sleeps long enough that it almost never ties with the near-instant fixture, and the ordering check only fails the test when the two printed times actually differ -- a genuine tie is reported as inconclusive rather than as a flake.

tests/test-run-all-timing.sh

@@ -28,6 +28,7 @@ RUN_ALL="$REPO/tests/run-all.sh"
 
 PASS=0
 FAIL=0
+SKIP=0
 
 TMP="$(mktemp -d 2> /dev/null)" || TMP=""
 if [ -z "$TMP" ] || [ ! -d "$TMP" ]; then
@@ -47,6 +48,13 @@ bad() {
   [ $# -gt 0 ] && echo "    $*"
   return 0
 }
+# A third outcome, distinct from both -- an assertion that genuinely cannot be
+# evaluated this run (the two suites tied at whole-second resolution) is neither
+# a pass nor a failure, and counting it as either would misreport what ran.
+skip() {
+  SKIP=$((SKIP + 1))
+  echo "  SKIPPED: $1"
+}
 
 # A minimal fixture directory: run-all.sh cds to its own dirname and globs test-*.sh
 # there, so a copy of it plus a couple of stub suites is a complete sandbox -- nothing
@@ -61,7 +69,7 @@ exit 0
 EOF
   cat > "$dir/test-b-slow.sh" << 'EOF'
 #!/bin/bash
-sleep 1
+sleep 2
 exit 0
 EOF
   chmod +x "$dir"/test-*.sh
@@ -103,13 +111,36 @@ else
   bad "the timing block comes after the tally, not before it" "tally=$TALLY_LINE timing=$TIMING_LINE"
 fi
 
-# Slowest first: test-b-slow.sh (sleep 1) must be listed before test-a-fast.sh.
+# Slowest first: test-b-slow.sh (sleep 2) must be listed before test-a-fast.sh --
+# unless the two land on the same whole second, which a loaded runner can do even
+# with the 2s margin (#482). A tie makes the ORDER undefined at 1s resolution, not
+# wrong, so it is reported as inconclusive rather than failed. A real sort
+# regression still has to fail here: when the two printed times differ, the strict
+# line-position check below still applies -- this is the positive control a
+# tie-tolerant assertion needs.
+#
+# A tie is only legitimate at 2s or more. test-b-slow.sh sleeps a full 2 seconds,
+# so a correct measurement can never read below 2 for it -- if a broken timer
+# (or one stuck printing the same constant for every suite, as a stub would)
+# reports "1s" for both, that is not a resolution tie, it is the measurement
+# itself being wrong, and it must fail rather than slide into SKIPPED (review
+# finding on #482: the first draft let SLOW_SECS==FAST_SECS==1 through as a tie).
 SLOW_LINE=$(grep -n 'test-b-slow\.sh' "$OUT_PASS" | tail -1 | cut -d: -f1)
 FAST_LINE=$(grep -n 'test-a-fast\.sh' "$OUT_PASS" | tail -1 | cut -d: -f1)
-if [ -n "$SLOW_LINE" ] && [ -n "$FAST_LINE" ] && [ "$SLOW_LINE" -lt "$FAST_LINE" ]; then
+SLOW_SECS=$(grep 'test-b-slow\.sh' "$OUT_PASS" | tail -1 | sed -E 's/^[[:space:]]*([0-9]+)s.*/\1/')
+FAST_SECS=$(grep 'test-a-fast\.sh' "$OUT_PASS" | tail -1 | sed -E 's/^[[:space:]]*([0-9]+)s.*/\1/')
+if [ -z "$SLOW_LINE" ] || [ -z "$FAST_LINE" ] || [ -z "$SLOW_SECS" ] || [ -z "$FAST_SECS" ]; then
+  bad "the slower suite is listed before the faster one" "could not read a printed line/time for one or both suites"
+  cat "$OUT_PASS"
+elif [ "$SLOW_SECS" -lt 2 ]; then
+  bad "the slower suite is listed before the faster one" "test-b-slow.sh (sleep 2) printed ${SLOW_SECS}s, which a correct measurement cannot produce -- not a tie, a broken timer"
+  cat "$OUT_PASS"
+elif [ "$SLOW_SECS" -eq "$FAST_SECS" ]; then
+  skip "test-a-fast.sh and test-b-slow.sh both printed ${SLOW_SECS}s -- a tie at 1s resolution, order is undefined, not wrong"
+elif [ "$SLOW_LINE" -lt "$FAST_LINE" ]; then
   ok "the slower suite is listed before the faster one"
 else
-  bad "the slower suite is listed before the faster one" "slow_line=$SLOW_LINE fast_line=$FAST_LINE"
+  bad "the slower suite is listed before the faster one" "slow_line=$SLOW_LINE fast_line=$FAST_LINE slow_secs=$SLOW_SECS fast_secs=$FAST_SECS"
   cat "$OUT_PASS"
 fi
 
@@ -121,15 +152,16 @@ else
   cat "$OUT_PASS"
 fi
 
-# Positive control for the timing itself: the slow suite's own line names a number of
-# seconds greater than 0 -- this is the case "would this pass if the code did nothing"
-# is aimed at: a stub that always printed "1s" for every suite would pass every
-# assertion above except this one.
+# A second, independent positive control for the timing itself: the slow suite's
+# own line names a number of seconds greater than 0 -- this is the case "would
+# this pass if the code did nothing" is aimed at. The stronger form of this check
+# (SLOW_SECS -lt 2, above) already fails a stub that always prints "1s" for every
+# suite; this one is the last line of defense if that check is ever weakened.
 SLOW_TIME_LINE=$(grep 'test-b-slow\.sh' "$OUT_PASS" | tail -1)
 if grep -qE '^ *[1-9][0-9]*s' <<< "$SLOW_TIME_LINE"; then
-  ok "the slow suite (sleep 1) is timed at 1 second or more, not 0"
+  ok "the slow suite (sleep 2) is timed at 1 second or more, not 0"
 else
-  bad "the slow suite (sleep 1) is timed at 1 second or more, not 0" "$SLOW_TIME_LINE"
+  bad "the slow suite (sleep 2) is timed at 1 second or more, not 0" "$SLOW_TIME_LINE"
 fi
 
 # --- Failing fixture: the exit code and the tally text must not change shape ---
@@ -197,7 +229,11 @@ fi
 echo ""
 echo "========================"
 TOTAL=$((PASS + FAIL))
-echo "  $PASS/$TOTAL passed, $FAIL failed"
+if [ "$SKIP" -gt 0 ]; then
+  echo "  $PASS/$TOTAL passed, $FAIL failed, $SKIP skipped (inconclusive, not counted above)"
+else
+  echo "  $PASS/$TOTAL passed, $FAIL failed"
+fi
 echo "========================"
 
 [ "$FAIL" -eq 0 ] && exit 0 || exit 1