From 8222c031a01e9eabfea5f4baac023286f7fcc17e Mon Sep 17 00:00:00 2001 From: Rongsong Shen Date: Tue, 18 Aug 2026 11:30:43 +0000 Subject: [PATCH] feat(resource-value-verification): apiserver-side verification check (task 6.4) poll_apiserver_log()/query_apiserver_resvals() mirror task 6.3's scheduler-check pattern: bounded-wait polling (batched across all pending resources per iteration) of apiserver.log for task 4.2's "resource-location stored" trace line, parsing the trailing zap JSON block. Reports MATCH / MISMATCH (both values) / UNREACHABLE (timeout, distinct from mismatch), tracked in APISERVER_OBSERVED/APISERVER_CHECK_RESULTS + apiserver-check-results.tsv. This completes all three per-layer checks. Live-confirmed: the full default resource set (including cpuf, post-bug-1579-fix) MATCHes simultaneously at the controller, scheduler, and apiserver layers. Co-Authored-By: Claude Sonnet 5 --- .../xce-test-resources/run-resource-verify.sh | 261 +++++++++++++++--- .../resource-value-verification/tasks.md | 3 +- 2 files changed, 226 insertions(+), 38 deletions(-) diff --git a/.claude/skills/xce-test-resources/run-resource-verify.sh b/.claude/skills/xce-test-resources/run-resource-verify.sh index 97635860..74637d62 100755 --- a/.claude/skills/xce-test-resources/run-resource-verify.sh +++ b/.claude/skills/xce-test-resources/run-resource-verify.sh @@ -5,22 +5,26 @@ # 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+6.3 SCOPE (+ bug-1579 -# follow-up fix): this file currently implements deployment (task 5.1), -# worker join + resource 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 +# resource-value-verification spec, task 5.1+6.1+6.2+6.3+6.4 SCOPE (+ +# bug-1579 follow-up fix): this file currently implements deployment (task +# 5.1), worker join + resource injection (task 6.1), the controller-side +# per-layer verification check (task 6.2), the scheduler-side per-layer +# verification check (task 6.3), AND the apiserver-side per-layer +# verification check (task 6.4) -- 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 (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 +# MATCH/MISMATCH against the injected value, (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). +# from the controller-side result, and (c) poll the live apiserver's own log +# file (task 4.2's trace line) for the same ACCEPTED pairs, within a bounded +# wait, and report MATCH/MISMATCH/UNREACHABLE distinctly from both the +# controller-side and scheduler-side results, then clean up (trap-based, +# covering a mid-deployment abort, not just a completed run). # # bug-1579 follow-up fix (this revision): the controller-side check (a) above # now runs NESTED inside inject_resources()'s own xce_test worker session -- @@ -30,9 +34,9 @@ # internal_controller_check() function and the top-of-file bug-1579 note # below for why this matters and exactly how it works; DEFAULT_RESOURCE_ARGS # now includes `cpuf` again as proof the fix is real (see that note). -# 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. +# Verdict aggregation / cleanup-on-every-path (task 7.1) is added by a LATER +# task -- see the "Extension point" marker in main() below for exactly where +# it hooks in. # See .kiro/specs/resource-value-verification/{requirements,design}.md, # 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. @@ -126,21 +130,24 @@ # 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) 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). +# check (task 6.2), scheduler-side check (task 6.3), and apiserver-side check +# (task 6.4) each ran for every accepted resource -- a MATCH, a MISMATCH, or +# (scheduler-side/apiserver-side only) an UNREACHABLE/timeout are ALL a +# successful run of this script's own scope, see +# query_controller_resvals()/query_scheduler_resvals()/ +# query_apiserver_resvals(); only a structural failure to query the +# controller, or to read the injection manifest for the scheduler/apiserver +# checks, 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 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). +# to connect). Once task 7.1 lands, the exit code instead reflects the full +# injection/verification PASS/FAIL verdict -- tasks 6.2/6.3/6.4 deliberately +# do NOT fail the run on a controller-, scheduler-, or apiserver-layer +# MISMATCH/UNREACHABLE yet (see ANY_CONTROLLER_MISMATCH/ +# ANY_SCHEDULER_MISMATCH/ANY_SCHEDULER_UNREACHABLE/ANY_APISERVER_MISMATCH/ +# ANY_APISERVER_UNREACHABLE, groundwork for task 7.1's aggregation). # set -u @@ -939,6 +946,193 @@ query_scheduler_resvals() { done } +# ── Step 7: apiserver-side verification check (task 6.4) ─────────────────── +# Requirement 5.1/5.2/5.4: for every SUCCESSFULLY-injected (accepted) +# resource/worker pair, poll (short interval, bounded generous total wait -- +# same batched-polling design as query_scheduler_resvals()/task 6.3 above) +# the live apiserver's own log file for task 4.2's trace line -- a zap +# message "resource-location stored" with fields resource/host/value, e.g. +# `resource-location stored {"resource": "r15m", "host": "resverify-worker", +# "value": 1.5}` -- and compare the parsed value against the injected one, +# reusing controller_values_match() (numeric-with-tolerance vs. exact-string, +# same rule for every 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 xcecli +# query, no REST call -- a plain tail/grep of a live log file, per the System +# Flows sequence diagram. A REJECTED resource was never actually applied +# anywhere -- nothing to verify for it here either, same skip rule +# query_controller_resvals()/query_scheduler_resvals() already established. + +# Poll interval / bounded total wait -- identical shape to +# SCHED_POLL_INTERVAL/SCHED_POLL_MAX_ITERS above (task 6.3), shared across +# the whole batch of still-pending resources per iteration (see +# poll_apiserver_log below), not a separate bounded wait per resource. +APISERVER_POLL_INTERVAL="0.5" +APISERVER_POLL_MAX_ITERS=30 # 30 x 0.5s = 15s total bounded wait + +# poll_apiserver_log APISERVER_LOG_FILE HOST NAME... +# Core bounded-wait poller for the apiserver layer, mirroring +# poll_scheduler_log() above (task 6.3) in shape: factored out of +# query_apiserver_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. Each iteration takes ONE full pass over +# APISERVER_LOG_FILE (a single awk invocation building a name->value map for +# every "resource-location stored" 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. Prints "namevalue" +# 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. +# +# Line format (task 4.2, handler.go's OnResourceLocationUpdated, zap console +# encoding -- confirmed live against this script's own apiserver.log output): +# the message is followed by a trailing JSON object holding the structured +# fields, in a FIXED field order (resource, host, value) -- "value" renders +# unquoted for numeric/boolean resources (float64/bool zap fields, this +# script's default set) and double-quoted for string-typed resources +# (type/model, excluded from the default set per bug-1574). Parsed below via +# index()/substr()/sub() -- not a JSON library -- mirroring +# poll_scheduler_log()'s own non-gawk-specific approach for its fixed-format +# trace line; the trailing quote pair (if present) is stripped so the +# numeric-vs-string branch in controller_values_match() sees the same shape +# either way. +poll_apiserver_log() { + local api_log="$1" host="$2" + shift 2 + local pending=("$@") + local -A found=() + local iter=0 + + while [ "$iter" -lt "$APISERVER_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 host="$host" ' + index($0, "resource-location stored") > 0 && index($0, "\"host\": \"" host "\"") > 0 { + line = $0 + + rtag = "\"resource\": \"" + rstart = index(line, rtag) + if (rstart == 0) next + rest = substr(line, rstart + length(rtag)) + rend = index(rest, "\"") + if (rend == 0) next + name = substr(rest, 1, rend - 1) + + vtag = "\"value\": " + vstart = index(line, vtag) + if (vstart == 0) next + vraw = substr(line, vstart + length(vtag)) + sub(/}[ \r]*$/, "", vraw) + if (length(vraw) >= 2 && substr(vraw, 1, 1) == "\"" && substr(vraw, length(vraw), 1) == "\"") { + vraw = substr(vraw, 2, length(vraw) - 2) + } + seen[name] = vraw + } + END { for (n in seen) print n "\t" seen[n] } + ' "$api_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 "$APISERVER_POLL_MAX_ITERS" ]; then + sleep "$APISERVER_POLL_INTERVAL" + fi + done + + local n + for n in "${!found[@]}"; do + printf '%s\t%s\n' "$n" "${found[$n]}" + done +} + +declare -A APISERVER_OBSERVED=() # resource name -> raw stored value string from the apiserver's trace log (only set for accepted names actually observed) +declare -A APISERVER_CHECK_RESULTS=() # resource name -> "MATCH" | "MISMATCH: injected= observed=" | "UNREACHABLE: ..." +ANY_APISERVER_MISMATCH=0 # groundwork for task 7.1's verdict aggregation, mirrors ANY_CONTROLLER_MISMATCH/ANY_SCHEDULER_MISMATCH; this task's own exit code does NOT depend on it +ANY_APISERVER_UNREACHABLE=0 # groundwork for task 7.1, mirrors ANY_SCHEDULER_UNREACHABLE; kept distinct from ANY_APISERVER_MISMATCH per Requirement 5.2/5.4 and design.md's "Layer unreachable" being its own error category + +# query_apiserver_resvals -- reads $TOP/logs/injection-results.tsv (same +# durable, order-preserving source query_controller_resvals()/ +# query_scheduler_resvals() read) and, for every name marked "accepted", +# polls $TOP/logs/apiserver.log via poll_apiserver_log() above. Populates +# APISERVER_OBSERVED/APISERVER_CHECK_RESULTS and $TOP/logs/ +# apiserver-check-results.tsv (name\tinjected\tobserved\tresult), following +# the exact same pattern query_scheduler_resvals() (task 6.3) established for +# its own layer. +query_apiserver_resvals() { + local tsv="$TOP/logs/injection-results.tsv" + [ -f "$tsv" ] || fail "apiserver 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 "apiserver check: skipping ${#skipped_names[@]} non-accepted resource(s) -- never actually applied at the apiserver, nothing to verify there: ${skipped_names[*]}" + fi + + if [ "${#accepted_names[@]}" -eq 0 ]; then + log "apiserver check: no accepted resources to verify" + return 0 + fi + + local api_log="$TOP/logs/apiserver.log" + local total_wait + total_wait="$(awk -v i="$APISERVER_POLL_INTERVAL" -v n="$APISERVER_POLL_MAX_ITERS" 'BEGIN{printf "%.1f", i*n}')" + log "apiserver check: polling $api_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_apiserver_log "$api_log" "$WORKER_HOST" "${accepted_names[@]}") + + mkdir -p "$TOP/logs" + local results_tsv="$TOP/logs/apiserver-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 apiserver trace-log line observed within bounded wait (injected=$injected observed=)" + ANY_APISERVER_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_APISERVER_MISMATCH=1 + fi + fi + + APISERVER_OBSERVED["$name"]="$observed" + APISERVER_CHECK_RESULTS["$name"]="$result_str" + log "apiserver 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 @@ -962,26 +1156,19 @@ main() { 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. --- + query_apiserver_resvals + # --- 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/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. --- + # ANY_SCHEDULER_UNREACHABLE/ANY_APISERVER_MISMATCH/ + # ANY_APISERVER_UNREACHABLE (set by query_controller_resvals()/ + # query_scheduler_resvals()/query_apiserver_resvals() above) are + # groundwork for this aggregation -- tasks 6.2/6.3/6.4 themselves + # deliberately do not act on them. --- - 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" + log "PASS (task 5.1+6.1+6.2+6.3+6.4 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-side check ran for every accepted resource (see $TOP/logs/apiserver-check-results.tsv -- a MISMATCH or UNREACHABLE there is also a captured outcome, not a script failure at this stage, see ANY_APISERVER_MISMATCH/ANY_APISERVER_UNREACHABLE); the overall PASS/FAIL verdict lands in task 7.1; cleaning up" exit 0 } diff --git a/.kiro/specs/resource-value-verification/tasks.md b/.kiro/specs/resource-value-verification/tasks.md index 2a4a9b3e..50a770d9 100644 --- a/.kiro/specs/resource-value-verification/tasks.md +++ b/.kiro/specs/resource-value-verification/tasks.md @@ -84,7 +84,7 @@ - _Depends: 6.1, 6.2_ - _Boundary: xce-test-resources skill (scheduler check) — same file as 6.2/6.4, sequential_ -- [ ] 6.4 Implement the apiserver-side verification check via trace-log tail +- [x] 6.4 Implement the apiserver-side verification check via trace-log tail - Tail/grep the live apiserver's log file (task 4.2's trace line) for each injected resource/worker pair, polling with a short interval up to a generous, explicit bounded wait — no `xcecli` query, no REST call - Compare the apiserver's observed value against the injected value, reported distinctly from the controller-side and scheduler-side results; a timeout with no matching line is reported as "unreachable," distinct from a value mismatch - Observable completion: the check reports, per resource, whether the apiserver's observed value matches the injected value within the bounded wait, attributable specifically to the apiserver layer @@ -116,6 +116,7 @@ - _Depends: 7.1_ ## Implementation Notes +- Task 6.4: `poll_apiserver_log()`/`query_apiserver_resvals()` mirror task 6.3's scheduler-check pattern exactly (same bounded-wait/batched-polling shape). The apiserver's zap `console` encoder renders structured fields as a trailing JSON object (`resource-location stored {"resource": "r15m", "host": "...", "value": 1.5}`), not classic `key=value` text — grep for the message string, then parse the trailing JSON block. All three layers (controller/scheduler/apiserver) confirmed simultaneously MATCH on the full default set including `cpuf`, proving the bug-1579 fix holds end-to-end. - **bug-1579 is now FULLY fixed** (retrofit on top of tasks 6.1/6.2, not a numbered task — user-requested follow-up). `inject_resources()`'s worker-context `xce_test` script now inserts a `!` line between `resupdate` and `quit`: `! bash