Refs #1019
This commit is contained in:
@@ -42,7 +42,29 @@ Make `test-ci-queue-wait-tristate.sh` deterministic without changing any asserte
|
|||||||
- GREEN host focused harness: `evidence/1019-harness-fix/green-host.log` — rc 0, all outcome classes passed.
|
- GREEN host focused harness: `evidence/1019-harness-fix/green-host.log` — rc 0, all outcome classes passed.
|
||||||
- Load-bearing clock negative control: a temporary same-directory mutant replaced the virtual `date` body with `/bin/date`; `evidence/1019-harness-fix/red-clock-not-intercepted.log` — rc 1 with named `virtual clock interception did not run` failures. The mutant file was removed after the run.
|
- Load-bearing clock negative control: a temporary same-directory mutant replaced the virtual `date` body with `/bin/date`; `evidence/1019-harness-fix/red-clock-not-intercepted.log` — rc 1 with named `virtual clock interception did not run` failures. The mutant file was removed after the run.
|
||||||
- Exact CI-base repeat: `git.mosaicstack.dev/mosaicstack/stack/ci-base:latest`, repository mounted read-only, harness work under container `/tmp`; `evidence/1019-harness-fix/ci-image-repeat/summary.log` — **100 pass / 0 fail / 100 total**.
|
- Exact CI-base repeat: `git.mosaicstack.dev/mosaicstack/stack/ci-base:latest`, repository mounted read-only, harness work under container `/tmp`; `evidence/1019-harness-fix/ci-image-repeat/summary.log` — **100 pass / 0 fail / 100 total**.
|
||||||
- Synchronization design: provider-status observation creates the event marker; virtual time is 1000 before the event and 2000 afterward. Pending alone reaches the stubbed no-op sleep and a post-observation deadline check. `-t 1` is numeric subject semantics under virtual time, not a wall-clock synchronization duration.
|
- Synchronization design: provider-status observation creates the event marker; virtual time is 1000 before the event and 1002 afterward. Pending alone reaches the stubbed no-op sleep and a post-observation deadline check. `-t 1` is uniquely load-bearing because removing it restores the 900-second default deadline at virtual time 1900, which 1002 does not cross. The numeric timeout is subject semantics under virtual time, not a wall-clock synchronization duration.
|
||||||
|
|
||||||
|
## Review remediation — semantic timeout vs. liveness bound
|
||||||
|
|
||||||
|
Security review found that virtual time remained at 1000 forever before provider observation and stubbed sleep never waited. A regression looping before the status endpoint—or blocking in the first provider call—therefore could prevent `run_guard` from returning, so the post-return provider assertion could never fire.
|
||||||
|
|
||||||
|
**General rule:** A timeout usually serves two purposes: semantics and liveness. Removing wall time from semantic synchronization can silently remove the only independent hang bound. Preserve deterministic virtual time for subject semantics, but provide a separately implemented real-clock liveness watchdog and prove that watchdog fires.
|
||||||
|
|
||||||
|
Remediation:
|
||||||
|
|
||||||
|
- Every guard subject invocation is launched by absolute `/usr/bin/python3` in a new session. Python's internal monotonic `wait(timeout=...)` provides real-clock liveness independently of PATH; expiry kills the entire isolated process group, so neither PATH-front shims nor a blocked provider descendant can retain the capture pipe.
|
||||||
|
- Watchdog expiry returns distinct harness rc 90 plus `FAIL HANG watchdog`, separate from subject timeout rc 124.
|
||||||
|
- A first attempt using absolute `/usr/bin/timeout -s KILL` passed on GNU coreutils but failed in the exact Alpine CI-base image: BusyBox killed the immediate wrapper while the guard/provider descendants survived and retained the command-substitution pipe. The process-group kill is therefore required behavior, not portability polish.
|
||||||
|
- A committed positive control hangs the branch-provider stub before the status endpoint. It must terminate through the watchdog, emit the hang-specific diagnostic, return rc 90, and prove the status provider was never reached.
|
||||||
|
- RED before remediation: a temporary ordinary-success mutant hung before provider observation; only an external control could kill the suite (rc 137), and there was no internal hang-specific diagnostic (`red-watchdog-absent.log`).
|
||||||
|
- The watchdog mutant/control is load-bearing: removing the internal watchdog leaves the control unable to produce its required rc 90 and diagnostic.
|
||||||
|
|
||||||
|
Post-review evidence:
|
||||||
|
|
||||||
|
- Host focused harness with process-group watchdog: rc 0 (`green-watchdog-process-group-host.log`).
|
||||||
|
- Exact Alpine CI-base focused harness with process-group watchdog: rc 0 (`green-watchdog-ci-image.log`).
|
||||||
|
- Hanging ordinary-success mutant: suite rc 1; success returned rc 90, emitted `FAIL HANG watchdog`, and loudly reported that provider/clock observation did not occur (`red-watchdog-fires.log`).
|
||||||
|
- Removed-`-t 1` mutant: suite rc 1; pending was terminated by the watchdog instead of producing `ASSERTED_NOT_READY`, proving the explicit timeout is load-bearing (`red-timeout-argument-removed.log`).
|
||||||
|
|
||||||
## 60% context hold
|
## 60% context hold
|
||||||
|
|
||||||
|
|||||||
@@ -11,10 +11,49 @@ STUB_DIR="$WORK_DIR/stubs"
|
|||||||
AUDIT_LOG="$WORK_DIR/audit/ci-queue-wait.jsonl"
|
AUDIT_LOG="$WORK_DIR/audit/ci-queue-wait.jsonl"
|
||||||
STATUS_OBSERVED="$WORK_DIR/status-observed"
|
STATUS_OBSERVED="$WORK_DIR/status-observed"
|
||||||
CLOCK_LOG="$WORK_DIR/clock.log"
|
CLOCK_LOG="$WORK_DIR/clock.log"
|
||||||
|
WATCHDOG_PYTHON="/usr/bin/python3"
|
||||||
|
WATCHDOG_SCRIPT="$WORK_DIR/real-clock-watchdog.py"
|
||||||
|
WATCHDOG_TIMEOUT_SEC=5
|
||||||
|
WATCHDOG_EXIT=90
|
||||||
FEATURE_BRANCH="fix/rm-03-fixture"
|
FEATURE_BRANCH="fix/rm-03-fixture"
|
||||||
|
|
||||||
|
if [[ ! -x "$WATCHDOG_PYTHON" ]]; then
|
||||||
|
echo "FAIL setup: required real-clock watchdog runtime is unavailable at $WATCHDOG_PYTHON" >&2
|
||||||
|
exit 1
|
||||||
|
fi
|
||||||
|
|
||||||
rm -rf "$WORK_DIR"
|
rm -rf "$WORK_DIR"
|
||||||
mkdir -p "$REPO_DIR" "$STUB_DIR"
|
mkdir -p "$REPO_DIR" "$STUB_DIR"
|
||||||
|
cat > "$WATCHDOG_SCRIPT" <<'PY'
|
||||||
|
import os
|
||||||
|
import signal
|
||||||
|
import subprocess
|
||||||
|
import sys
|
||||||
|
|
||||||
|
if len(sys.argv) < 3:
|
||||||
|
raise SystemExit(2)
|
||||||
|
|
||||||
|
timeout_seconds = float(sys.argv[1])
|
||||||
|
process = subprocess.Popen(sys.argv[2:], start_new_session=True)
|
||||||
|
try:
|
||||||
|
return_code = process.wait(timeout=timeout_seconds)
|
||||||
|
except subprocess.TimeoutExpired:
|
||||||
|
try:
|
||||||
|
os.killpg(process.pid, signal.SIGKILL)
|
||||||
|
except ProcessLookupError:
|
||||||
|
pass
|
||||||
|
process.wait()
|
||||||
|
print(
|
||||||
|
f"FAIL HANG watchdog: subject exceeded {timeout_seconds:g}s "
|
||||||
|
"before completing its intended path",
|
||||||
|
file=sys.stderr,
|
||||||
|
)
|
||||||
|
raise SystemExit(90)
|
||||||
|
|
||||||
|
if return_code < 0:
|
||||||
|
raise SystemExit(128 - return_code)
|
||||||
|
raise SystemExit(return_code)
|
||||||
|
PY
|
||||||
git -C "$REPO_DIR" init -q
|
git -C "$REPO_DIR" init -q
|
||||||
git -C "$REPO_DIR" checkout -q -b "$FEATURE_BRANCH"
|
git -C "$REPO_DIR" checkout -q -b "$FEATURE_BRANCH"
|
||||||
git -C "$REPO_DIR" remote add origin https://git.example.test/acme/widgets.git
|
git -C "$REPO_DIR" remote add origin https://git.example.test/acme/widgets.git
|
||||||
@@ -35,6 +74,9 @@ printf '%s\n' "$url" >> "${MOSAIC_STUB_URL_LOG:?}"
|
|||||||
|
|
||||||
case "$url" in
|
case "$url" in
|
||||||
*/branches/*)
|
*/branches/*)
|
||||||
|
if [[ "${MOSAIC_STUB_BRANCH_MODE:-ok}" == "hang-before-provider" ]]; then
|
||||||
|
while :; do :; done
|
||||||
|
fi
|
||||||
if [[ "${MOSAIC_STUB_BRANCH_MODE:-ok}" == "unreachable" ]]; then
|
if [[ "${MOSAIC_STUB_BRANCH_MODE:-ok}" == "unreachable" ]]; then
|
||||||
exit 7
|
exit 7
|
||||||
fi
|
fi
|
||||||
@@ -78,7 +120,7 @@ fi
|
|||||||
|
|
||||||
if [[ -e "${MOSAIC_STUB_STATUS_OBSERVED:?}" ]]; then
|
if [[ -e "${MOSAIC_STUB_STATUS_OBSERVED:?}" ]]; then
|
||||||
printf 'date-phase=after-status\n' >> "${MOSAIC_STUB_CLOCK_LOG:?}"
|
printf 'date-phase=after-status\n' >> "${MOSAIC_STUB_CLOCK_LOG:?}"
|
||||||
printf '2000\n'
|
printf '1002\n'
|
||||||
else
|
else
|
||||||
printf 'date-phase=before-status\n' >> "${MOSAIC_STUB_CLOCK_LOG:?}"
|
printf 'date-phase=before-status\n' >> "${MOSAIC_STUB_CLOCK_LOG:?}"
|
||||||
printf '1000\n'
|
printf '1000\n'
|
||||||
@@ -117,7 +159,17 @@ run_guard() {
|
|||||||
export MOSAIC_CI_QUEUE_AUDIT_LOG="$audit_log"
|
export MOSAIC_CI_QUEUE_AUDIT_LOG="$audit_log"
|
||||||
# Provider observation is the synchronization event. The one-second
|
# Provider observation is the synchronization event. The one-second
|
||||||
# timeout is subject semantics under virtual time, never a wall wait.
|
# timeout is subject semantics under virtual time, never a wall wait.
|
||||||
"$SCRIPT_DIR/ci-queue-wait.sh" --purpose "${MOSAIC_TEST_PURPOSE:-push}" -t 1 -i 1 "$@"
|
# The absolute Python runtime uses an internal monotonic wait and kills
|
||||||
|
# the subject's isolated process group. Neither operation can resolve
|
||||||
|
# to the virtual date/sleep stubs at the front of PATH.
|
||||||
|
local subject_rc
|
||||||
|
if "$WATCHDOG_PYTHON" "$WATCHDOG_SCRIPT" "$WATCHDOG_TIMEOUT_SEC" \
|
||||||
|
"$SCRIPT_DIR/ci-queue-wait.sh" --purpose "${MOSAIC_TEST_PURPOSE:-push}" -t 1 -i 1 "$@"; then
|
||||||
|
subject_rc=0
|
||||||
|
else
|
||||||
|
subject_rc=$?
|
||||||
|
fi
|
||||||
|
return "$subject_rc"
|
||||||
)
|
)
|
||||||
}
|
}
|
||||||
|
|
||||||
@@ -197,6 +249,27 @@ run_assertion large-payload not126 large-success 'state=terminal-success'
|
|||||||
run_assertion credential-unresolvable zero credential-unresolvable 'CANNOT_ASSERT'
|
run_assertion credential-unresolvable zero credential-unresolvable 'CANNOT_ASSERT'
|
||||||
run_assertion provider-unreachable zero unreachable 'CANNOT_ASSERT'
|
run_assertion provider-unreachable zero unreachable 'CANNOT_ASSERT'
|
||||||
|
|
||||||
|
# Positive liveness control: a subject mutant hangs before the branch lookup
|
||||||
|
# can reach the status provider. Only the independent real-clock watchdog may
|
||||||
|
# terminate it, and its failure must be distinct from subject timeout rc=124.
|
||||||
|
set +e
|
||||||
|
watchdog_output=$(MOSAIC_STUB_BRANCH_MODE=hang-before-provider run_guard success "$AUDIT_LOG" 2>&1)
|
||||||
|
watchdog_rc=$?
|
||||||
|
set -e
|
||||||
|
if [[ "$watchdog_rc" -ne "$WATCHDOG_EXIT" ]]; then
|
||||||
|
echo "FAIL watchdog-control: expected hang-specific rc=$WATCHDOG_EXIT, got rc=$watchdog_rc" >&2
|
||||||
|
failures=$((failures + 1))
|
||||||
|
fi
|
||||||
|
if [[ "$watchdog_output" != *"FAIL HANG watchdog:"* ]]; then
|
||||||
|
echo "FAIL watchdog-control: expected distinct hang-specific diagnostic" >&2
|
||||||
|
printf '%s\n' "$watchdog_output" >&2
|
||||||
|
failures=$((failures + 1))
|
||||||
|
fi
|
||||||
|
if [[ -e "$STATUS_OBSERVED" ]]; then
|
||||||
|
echo "FAIL watchdog-control: hanging mutant unexpectedly reached the status provider" >&2
|
||||||
|
failures=$((failures + 1))
|
||||||
|
fi
|
||||||
|
|
||||||
if [[ ! -s "$AUDIT_LOG" ]] || ! grep -q '"outcome":"CANNOT_ASSERT"' "$AUDIT_LOG"; then
|
if [[ ! -s "$AUDIT_LOG" ]] || ! grep -q '"outcome":"CANNOT_ASSERT"' "$AUDIT_LOG"; then
|
||||||
echo "FAIL provider-unreachable-audit: expected durable CANNOT_ASSERT JSONL record" >&2
|
echo "FAIL provider-unreachable-audit: expected durable CANNOT_ASSERT JSONL record" >&2
|
||||||
failures=$((failures + 1))
|
failures=$((failures + 1))
|
||||||
|
|||||||
Reference in New Issue
Block a user