feat(resource-value-verification): scheduler-side verification check (task 6.3)

poll_scheduler_log()/query_scheduler_resvals() tail the live scheduler
daemon's log (task 4.1's trace line) for each accepted injected resource,
with a bounded ~15s wait batched across all pending resources per poll
iteration (not N times the timeout). Reports MATCH / MISMATCH (both
values) / UNREACHABLE (timeout, distinct from mismatch), tracked in
SCHEDULER_OBSERVED/SCHEDULER_CHECK_RESULTS + scheduler-check-results.tsv.

Live-proven immune to bug-1579 (unlike the controller check): injecting a
host-attrs resource (cpuf) simultaneously produces a controller MISMATCH
and a scheduler MATCH, since this check reads task 4.1's trace log (written
once, at apply-time) rather than re-querying live state after the worker
disconnects.

Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
This commit is contained in:
Rongsong Shen 2026-08-18 10:21:50 +00:00
parent cb5bbfcca2
commit 72b6fdea4a
Signed by: rshen
SSH key fingerprint: SHA256:8Vf2pZ3h6rJa7EhGK+WaAQ9Mta/apZvteW6g9U/WKKk
2 changed files with 218 additions and 32 deletions

View file

@ -5,23 +5,27 @@
# resource value via xce_test's resupdate, confirm it is visible at the
# controller, live scheduler, and Go apiserver).
#
# resource-value-verification spec, task 5.1+6.1+6.2 SCOPE: this file
# resource-value-verification spec, task 5.1+6.1+6.2+6.3 SCOPE: this file
# currently implements deployment (task 5.1), worker join + resource
# injection (task 6.1), AND the controller-side per-layer verification check
# (task 6.2) -- stand up a fresh controller + scheduler (-vvv) + apiserver
# (debug logging) deployment via xce-deploy-ha's deploy-ha.sh + generated
# injection (task 6.1), the controller-side per-layer verification check
# (task 6.2), AND the scheduler-side per-layer verification check (task 6.3)
# -- stand up a fresh controller + scheduler (-vvv) + apiserver (debug
# logging) deployment via xce-deploy-ha's deploy-ha.sh + generated
# start-all.sh, confirm all three components are actually up, join a
# SYNTHETIC worker (no real worker daemon process) through xce_test's worker
# context, run resupdate for one or more resource=value pairs, then query the
# controller (xce_test client-context `resval`) for every ACCEPTED pair and
# report MATCH/MISMATCH against the injected value, and clean up (trap-based,
# covering a mid-deployment abort, not just a completed run). Scheduler/
# apiserver per-layer verification (tasks 6.3-6.4) and verdict aggregation /
# context, run resupdate for one or more resource=value pairs, then (a) query
# the controller (xce_test client-context `resval`) for every ACCEPTED pair
# and report MATCH/MISMATCH against the injected value, and (b) poll the live
# scheduler daemon's own log file (task 4.1's trace line) for the same
# ACCEPTED pairs, within a bounded wait, and report MATCH/MISMATCH/
# UNREACHABLE distinctly from the controller-side result, then clean up
# (trap-based, covering a mid-deployment abort, not just a completed run).
# Apiserver per-layer verification (task 6.4) and verdict aggregation /
# cleanup-on-every-path (task 7.1) are added by LATER tasks -- see the
# "Extension points" markers in main() below for exactly where they hook in.
# See .kiro/specs/resource-value-verification/{requirements,design}.md,
# Requirements 2.1, 2.2, 3.1, 3.2, 5.3, 6.1, 6.4, 6.5 for these tasks; the
# full skill covers 3.1-6.5.
# Requirements 2.1, 2.2, 3.1, 3.2, 4.1, 4.2, 4.3, 5.3, 6.1, 6.4, 6.5 for these
# tasks; the full skill covers 3.1-6.5.
#
# Task 6.1 deliberate deviation from design.md: the default (no-args)
# resource set is Requirement 1's gap-resource set (r15m, pg, ls, it, swp,
@ -83,18 +87,21 @@
# components confirmed up, worker joined, resupdate ran for every requested
# resource -- accepted AND rejected outcomes are both a successful run of
# THIS script's scope, see inject_resources() -- and the controller-side
# check (task 6.2) ran for every accepted resource -- a MATCH or a MISMATCH
# are BOTH a successful run of this script's own scope, see
# query_controller_resvals(); only a structural failure to query the
# controller at all is fatal here -- cleaned up per --keep-running).
# check (task 6.2) and scheduler-side check (task 6.3) each ran for every
# accepted resource -- a MATCH, a MISMATCH, or (scheduler-side only) an
# UNREACHABLE/timeout are ALL a successful run of this script's own scope,
# see query_controller_resvals()/query_scheduler_resvals(); only a structural
# failure to query the controller, or to read the injection manifest for the
# scheduler check, is fatal here -- cleaned up per --keep-running).
# Non-zero == deployment failed at some step, the worker failed to join,
# resupdate produced no observable accept/reject outcome for some name (a
# structural injection failure, distinct from a legitimate rejection), or the
# controller-side check itself could not run (e.g. the client context failed
# to connect). Once tasks 6.3-7.1 land, the exit code instead reflects the
# full injection/verification PASS/FAIL verdict -- task 6.2 deliberately does
# NOT fail the run on a controller-layer MISMATCH yet (see
# ANY_CONTROLLER_MISMATCH, groundwork for task 7.1's aggregation).
# to connect). Once task 6.4/7.1 land, the exit code instead reflects the
# full injection/verification PASS/FAIL verdict -- tasks 6.2/6.3 deliberately
# do NOT fail the run on a controller- or scheduler-layer MISMATCH/
# UNREACHABLE yet (see ANY_CONTROLLER_MISMATCH/ANY_SCHEDULER_MISMATCH/
# ANY_SCHEDULER_UNREACHABLE, groundwork for task 7.1's aggregation).
#
set -u
@ -623,6 +630,176 @@ $out"
done
}
# ── Step 6: scheduler-side verification check (task 6.3) ───────────────────
# Requirement 4.1/4.2/4.3: for every SUCCESSFULLY-injected (accepted)
# resource/worker pair, poll (short interval, bounded generous total wait --
# design.md's "poll with a short interval up to a generous timeout, not
# tight polling that could flake") the live scheduler daemon's own log file
# for task 4.1's trace line -- "resval applied host=<H> resource=<R>
# value=<V>" at DEBUG3 (`-vvv`, already how start-all.sh starts the
# scheduler, per task 3.1) -- and compare the parsed value against the
# injected one, reusing controller_values_match() (numeric-with-tolerance vs.
# exact-string, same rule for either layer). A resource whose trace line
# never appears within the bounded wait is reported as "unreachable" /
# timeout, explicitly distinct from a value MISMATCH (design.md Error
# Handling -- "Layer unreachable" is its own category, not folded into
# mismatch). No record/replay/REPL round-trip -- a plain tail/grep of a live
# log file, per the System Flows sequence diagram. A REJECTED resource was
# never actually applied anywhere (task 2.2's own follow-up query inside
# resupdate already confirmed that at injection time) -- nothing to verify
# for it here either, same skip rule query_controller_resvals() (task 6.2)
# already established.
# Poll interval / bounded total wait, shared across the WHOLE batch of
# still-pending resources per iteration (see poll_scheduler_log below), not
# a separate full bounded wait PER resource -- so N accepted resources costs
# at most one ~15s bounded wait in the worst case (all N stuck), not N of
# them stacked sequentially; in the common case (scheduler already applied
# everything by the time this runs, since it fires after inject_resources()
# AND query_controller_resvals()'s own extra RPC round trip) it costs one
# fast pass with no sleep at all.
SCHED_POLL_INTERVAL="0.5"
SCHED_POLL_MAX_ITERS=30 # 30 x 0.5s = 15s total bounded wait
# poll_scheduler_log SCHED_LOG_FILE HOST NAME...
# Core bounded-wait poller, deliberately factored out of
# query_scheduler_resvals() so it can be exercised directly (e.g. against a
# name/host combination that was never actually injected, to prove the
# "unreachable" path is genuinely reachable) independent of the
# accepted-injection bookkeeping -- same "pure/self-contained, independently
# testable" spirit as controller_values_match(). Each iteration takes ONE
# full pass over SCHED_LOG_FILE (a single awk invocation building a
# name->value map for every "resval applied host=<H> resource=..." line
# seen for HOST, last occurrence per name wins) and checks every STILL-
# PENDING name against that map, rather than a separate grep-with-its-own-
# timeout per name run in sequence -- by the time a later name in the batch
# is checked, an earlier name's line has almost certainly already appeared
# in the same log-file read. Prints "name<TAB>value" to stdout for every
# name that WAS observed within the bounded wait; a name with no
# corresponding output line was NOT observed -- the caller's job to report
# that distinctly as "unreachable", not silently as a mismatch with an empty
# value.
poll_scheduler_log() {
local sched_log="$1" host="$2"
shift 2
local pending=("$@")
local -A found=()
local iter=0
while [ "$iter" -lt "$SCHED_POLL_MAX_ITERS" ] && [ "${#pending[@]}" -gt 0 ]; do
iter=$((iter + 1))
local name val
while IFS=$'\t' read -r name val; do
[ -n "$name" ] || continue
found["$name"]="$val"
done < <(awk -v needle="resval applied host=${host} resource=" '
index($0, needle) > 0 {
line = $0
sub(/^.*resource=/, "", line)
sep = index(line, " value=")
if (sep > 0) {
seen[substr(line, 1, sep - 1)] = substr(line, sep + 7)
}
}
END { for (n in seen) print n "\t" seen[n] }
' "$sched_log" 2>/dev/null)
local still_pending=()
for name in "${pending[@]}"; do
if [ -z "${found[$name]+x}" ]; then
still_pending+=("$name")
fi
done
pending=("${still_pending[@]}")
if [ "${#pending[@]}" -gt 0 ] && [ "$iter" -lt "$SCHED_POLL_MAX_ITERS" ]; then
sleep "$SCHED_POLL_INTERVAL"
fi
done
local n
for n in "${!found[@]}"; do
printf '%s\t%s\n' "$n" "${found[$n]}"
done
}
declare -A SCHEDULER_OBSERVED=() # resource name -> raw applied value string from the scheduler's trace log (only set for accepted names actually observed)
declare -A SCHEDULER_CHECK_RESULTS=() # resource name -> "MATCH" | "MISMATCH: injected=<X> observed=<Y>" | "UNREACHABLE: ..."
ANY_SCHEDULER_MISMATCH=0 # groundwork for task 7.1's verdict aggregation, mirrors ANY_CONTROLLER_MISMATCH; this task's own exit code does NOT depend on it
ANY_SCHEDULER_UNREACHABLE=0 # groundwork for task 7.1; kept distinct from ANY_SCHEDULER_MISMATCH per Requirement 4.2/4.3 and design.md's "Layer unreachable" being its own error category
# query_scheduler_resvals -- reads $TOP/logs/injection-results.tsv (same
# durable, order-preserving source query_controller_resvals() (task 6.2)
# reads) and, for every name marked "accepted", polls $TOP/logs/
# scheduler.log via poll_scheduler_log() above. Populates
# SCHEDULER_OBSERVED/SCHEDULER_CHECK_RESULTS and $TOP/logs/
# scheduler-check-results.tsv (name\tinjected\tobserved\tresult), following
# the exact same pattern query_controller_resvals() established for its own
# layer.
query_scheduler_resvals() {
local tsv="$TOP/logs/injection-results.tsv"
[ -f "$tsv" ] || fail "scheduler check: $tsv not found -- inject_resources() must run first"
local name value result accepted_names=() skipped_names=()
while IFS=$'\t' read -r name value result; do
if [ "$result" = "accepted" ]; then
accepted_names+=("$name")
else
skipped_names+=("$name")
fi
done < "$tsv"
if [ "${#skipped_names[@]}" -gt 0 ]; then
log "scheduler check: skipping ${#skipped_names[@]} non-accepted resource(s) -- never actually applied at the scheduler, nothing to verify there: ${skipped_names[*]}"
fi
if [ "${#accepted_names[@]}" -eq 0 ]; then
log "scheduler check: no accepted resources to verify"
return 0
fi
local sched_log="$TOP/logs/scheduler.log"
local total_wait
total_wait="$(awk -v i="$SCHED_POLL_INTERVAL" -v n="$SCHED_POLL_MAX_ITERS" 'BEGIN{printf "%.1f", i*n}')"
log "scheduler check: polling $sched_log for ${#accepted_names[@]} accepted resource(s), bounded wait up to ${total_wait}s total: ${accepted_names[*]}"
local -A observed_map=()
local n v
while IFS=$'\t' read -r n v; do
[ -n "$n" ] || continue
observed_map["$n"]="$v"
done < <(poll_scheduler_log "$sched_log" "$WORKER_HOST" "${accepted_names[@]}")
mkdir -p "$TOP/logs"
local results_tsv="$TOP/logs/scheduler-check-results.tsv"
: > "$results_tsv"
local injected observed result_str
for name in "${accepted_names[@]}"; do
injected="${INJECTED_VALUES[$name]}"
if [ -z "${observed_map[$name]+x}" ]; then
observed=""
result_str="UNREACHABLE: no scheduler trace-log line observed within bounded wait (injected=$injected observed=<none>)"
ANY_SCHEDULER_UNREACHABLE=1
else
observed="${observed_map[$name]}"
if controller_values_match "$injected" "$observed"; then
result_str="MATCH"
else
result_str="MISMATCH: injected=$injected observed=$observed"
ANY_SCHEDULER_MISMATCH=1
fi
fi
SCHEDULER_OBSERVED["$name"]="$observed"
SCHEDULER_CHECK_RESULTS["$name"]="$result_str"
log "scheduler check: $name -> $result_str"
printf '%s\t%s\t%s\t%s\n' "$name" "$injected" "$observed" "$result_str" >> "$results_tsv"
done
}
main() {
parse_args "$@"
resolve_top
@ -644,21 +821,28 @@ main() {
query_controller_resvals
# --- Extension point (tasks 6.3-6.4): scheduler/apiserver per-layer
# verification checks here, consuming ${INJECTED_VALUES[@]}/
# ${INJECTED_RESULTS[@]} and $WORKER_HOST populated by
# inject_resources() above (also mirrored to
# $TOP/logs/injection-results.tsv), following the same pattern
# query_controller_resvals() (task 6.2) just established for its own
# layer -- CONTROLLER_OBSERVED/CONTROLLER_CHECK_RESULTS +
# $TOP/logs/controller-check-results.tsv. ---
query_scheduler_resvals
# --- Extension point (task 6.4): apiserver per-layer verification check
# here, consuming ${INJECTED_VALUES[@]}/${INJECTED_RESULTS[@]} and
# $WORKER_HOST populated by inject_resources() above (also mirrored
# to $TOP/logs/injection-results.tsv), following the same pattern
# query_controller_resvals() (task 6.2) and query_scheduler_resvals()
# (task 6.3) just established for their own layers --
# CONTROLLER_OBSERVED/CONTROLLER_CHECK_RESULTS +
# $TOP/logs/controller-check-results.tsv;
# SCHEDULER_OBSERVED/SCHEDULER_CHECK_RESULTS +
# $TOP/logs/scheduler-check-results.tsv. ---
# --- Extension point (task 7.1): aggregate results into a VERDICT line
# plus the terminal PASS/FAIL oracle line, replacing this task's
# placeholder success message and exit code below. ANY_CONTROLLER_MISMATCH
# (set by query_controller_resvals() above) is groundwork for this
# aggregation -- task 6.2 itself deliberately does not act on it. ---
# placeholder success message and exit code below.
# ANY_CONTROLLER_MISMATCH/ANY_SCHEDULER_MISMATCH/
# ANY_SCHEDULER_UNREACHABLE (set by query_controller_resvals()/
# query_scheduler_resvals() above) are groundwork for this
# aggregation -- tasks 6.2/6.3 themselves deliberately do not act on
# them. ---
log "PASS (task 5.1+6.1+6.2 scope): controller, scheduler, and apiserver confirmed up; worker '$WORKER_HOST' joined and resupdate ran for ${#INJECTED_RESULTS[@]} resource(s) under $TOP (see $TOP/logs/injection-results.tsv for the accept/reject detail per name -- a rejection there is a captured outcome, not a script failure at this stage); controller-side check ran for every accepted resource (see $TOP/logs/controller-check-results.tsv -- a MISMATCH there is also a captured outcome, not a script failure at this stage, see ANY_CONTROLLER_MISMATCH); scheduler/apiserver per-layer verification and the overall PASS/FAIL verdict land in tasks 6.3-7.1; cleaning up"
log "PASS (task 5.1+6.1+6.2+6.3 scope): controller, scheduler, and apiserver confirmed up; worker '$WORKER_HOST' joined and resupdate ran for ${#INJECTED_RESULTS[@]} resource(s) under $TOP (see $TOP/logs/injection-results.tsv for the accept/reject detail per name -- a rejection there is a captured outcome, not a script failure at this stage); controller-side check ran for every accepted resource (see $TOP/logs/controller-check-results.tsv -- a MISMATCH there is also a captured outcome, not a script failure at this stage, see ANY_CONTROLLER_MISMATCH); scheduler-side check ran for every accepted resource (see $TOP/logs/scheduler-check-results.tsv -- a MISMATCH or UNREACHABLE there is also a captured outcome, not a script failure at this stage, see ANY_SCHEDULER_MISMATCH/ANY_SCHEDULER_UNREACHABLE); apiserver per-layer verification and the overall PASS/FAIL verdict land in tasks 6.4-7.1; cleaning up"
exit 0
}