diff --git a/xCAT-test/autotest/testcase/commoncmd/check_provisioning_source.sh b/xCAT-test/autotest/testcase/commoncmd/check_provisioning_source.sh index 427afb73e..9b6f7f632 100755 --- a/xCAT-test/autotest/testcase/commoncmd/check_provisioning_source.sh +++ b/xCAT-test/autotest/testcase/commoncmd/check_provisioning_source.sh @@ -1,9 +1,10 @@ #!/bin/sh # +# check_provisioning_source.sh --baseline # check_provisioning_source.sh -# check_provisioning_source.sh --count +# check_provisioning_source.sh --count [] # -# Answer which server sent the compute node its boot payload. +# Answer which server sent the compute node its boot payload during THIS run. # # The hierarchy cases set noderes.servicenode and read SERVICEGROUP back out of the compute # node's xcatinfo. That records what xCAT wrote, not where the node fetched from. The management @@ -14,8 +15,13 @@ # # The httpd access logs settle it. The xNBA exchange hands out an http:// filename, so the # kernel, the initrd, the root image and the install tree are HTTP requests logged against the -# compute node's address on the server that answered them. The service node must have served the -# compute node, and the management node must have served it nothing. +# compute node's address on the server that answered them. +# +# Two things bound what counts, and without either one the answer is wrong in both directions. +# Run --baseline before provisioning: an earlier flat run leaves management-node requests for the +# same address, and counting the whole log fails a later hierarchical run for them. And only a +# request under /install or /tftpboot is a boot payload: a 404 for /favicon.ico is a request from +# the compute node that carries no payload, and it must not stand for one. # # Scope: the PXE ROM exchange hands out xcat/xnba.kpxe over TFTP and httpd never sees it. # xnba.kpxe is the same binary on both servers, so it decides nothing about the fetch source. @@ -26,14 +32,12 @@ set -u TOKEN=XCAT_HTTPD_REQUESTS +STATE="${XCAT_PROV_SOURCE_STATE:-/var/tmp/xcat-provisioning-source.base}" -# The first argument to --count is the address to count. Every readable candidate log is read: -# the combined format puts the client address in field 1, and the Debian per-vhost format puts -# the vhost there and the client in field 2. -count_local_requests() +# Every readable candidate log. The combined format puts the client address in field 1, and the +# Debian per-vhost format puts the vhost there and the client in field 2. +local_logs() { - ip="$1" - logs="" for f in ${XCAT_HTTPD_ACCESS_LOG:-} \ /var/log/httpd/access_log \ /var/log/apache2/access.log \ @@ -41,24 +45,81 @@ count_local_requests() /var/log/apache2/other_vhosts_access.log do [ -r "$f" ] || continue - logs="$logs $f" + echo "$f" done +} + +# Record how many lines each log holds now, as file:lines joined by commas. +baseline_local() +{ + spec="" + for f in $(local_logs); do + n=$(wc -l <"$f" 2>/dev/null | tr -d ' ') + [ -n "$n" ] || n=0 + spec="$spec,$f:$n" + done + echo "$TOKEN base $(echo "$spec" | sed 's/^,//')" +} + +# Count the boot-payload requests this address made AFTER the baseline. A log shorter than its +# baseline was rotated, so its baseline no longer locates anything and the whole file is new. +count_local_requests() +{ + ip="$1" + spec="${2:-}" + logs=$(local_logs | tr '\n' ' ') if [ -z "$logs" ]; then - echo "$TOKEN nolog 0 0" + echo "$TOKEN nolog 0 0 0" return 0 fi + checked="" + for f in $logs; do + base=$(echo "$spec" | tr ',' '\n' | sed -n "s|^$f:||p" | head -1) + [ -n "$base" ] || base=0 + now=$(wc -l <"$f" 2>/dev/null | tr -d ' ') + [ -n "$now" ] || now=0 + [ "$now" -lt "$base" ] && base=0 + checked="$checked,$f:$base" + done + # shellcheck disable=SC2086 - awk -v ip="$ip" -v token="$TOKEN" \ - '$1 == ip || $2 == ip { n++ } END { print token, "ok", n+0, NR+0 }' $logs + awk -v ip="$ip" -v token="$TOKEN" -v bases="$(echo "$checked" | sed 's/^,//')" ' + BEGIN { + n = split(bases, a, ",") + for (i = 1; i <= n; i++) { + if (a[i] == "") continue + p = index(a[i], ":") + if (p) base[substr(a[i], 1, p - 1)] = substr(a[i], p + 1) + 0 + } + } + { + total++ + b = (FILENAME in base) ? base[FILENAME] : 0 + if (FNR <= b) next + fresh++ + if ($1 != ip && $2 != ip) next + path = "" + for (i = 1; i <= NF; i++) if ($i ~ /^"(GET|HEAD|POST)$/) { path = $(i + 1); break } + if (path ~ /^\/(install|tftpboot)\//) payload++ + } + END { print token, "ok", payload + 0, fresh + 0, total + 0 } + ' $logs } # xdsh prefixes each line with the node name, so read the fields after the token. read_counts() { awk -v token="$TOKEN" ' - { for (i = 1; i <= NF; i++) if ($i == token) { print $(i+1), $(i+2), $(i+3); exit } } + { for (i = 1; i <= NF; i++) if ($i == token) { print $(i+1), $(i+2), $(i+3), $(i+4); exit } } + ' +} + +read_baseline() +{ + awk -v token="$TOKEN" ' + { for (i = 1; i <= NF; i++) if ($i == token && $(i+1) == "base") { print $(i+2); exit } } ' } @@ -71,36 +132,68 @@ node_address() } if [ "${1:-}" = "--count" ]; then - count_local_requests "${2:-}" + count_local_requests "${2:-}" "${3:-}" exit 0 fi +if [ "${1:-}" = "--baseline-local" ]; then + baseline_local + exit 0 +fi + +MODE=check +if [ "${1:-}" = "--baseline" ]; then + MODE=baseline + shift +fi + CN="${1:-}" SN="${2:-}" if [ -z "$CN" ] || [ -z "$SN" ]; then - echo "provisioning source error: usage: $0 " >&2 + echo "provisioning source error: usage: $0 [--baseline] " >&2 exit 2 fi SELF=$(readlink -f "$0") MN=$(hostname) +if [ "$MODE" = baseline ]; then + MN_BASE=$(baseline_local | read_baseline) + SN_BASE=$(xdsh "$SN" -e "$SELF" --baseline-local 2>&1 | read_baseline) + if [ -z "$MN_BASE" ] || [ -z "$SN_BASE" ]; then + echo "provisioning source error: no access log to baseline on ${MN_BASE:+$SN}${MN_BASE:-$MN}" >&2 + exit 1 + fi + printf 'MN %s\nSN %s\n' "$MN_BASE" "$SN_BASE" >"$STATE" || exit 1 + echo "provisioning source baseline recorded in $STATE" + exit 0 +fi + +# Without a baseline this cannot tell a request from this run from one an earlier run left +# behind, so it refuses rather than answering from the whole log. +if [ ! -r "$STATE" ]; then + echo "provisioning source error: no baseline in $STATE. Run --baseline before provisioning" >&2 + exit 1 +fi +MN_BASE=$(sed -n 's/^MN //p' "$STATE" | head -1) +SN_BASE=$(sed -n 's/^SN //p' "$STATE" | head -1) + CN_IP=$(node_address "$CN") if [ -z "$CN_IP" ]; then echo "provisioning source error: $CN has no address, so no log can be read for it" >&2 exit 1 fi -MN_COUNTS=$(count_local_requests "$CN_IP" | read_counts) -SN_COUNTS=$(xdsh "$SN" -e "$SELF" --count "$CN_IP" 2>&1 | read_counts) +MN_COUNTS=$(count_local_requests "$CN_IP" "$MN_BASE" | read_counts) +SN_COUNTS=$(xdsh "$SN" -e "$SELF" --count "$CN_IP" "$SN_BASE" 2>&1 | read_counts) set -- $MN_COUNTS -MN_STATE="${1:-none}" MN_REQ="${2:-0}" MN_LINES="${3:-0}" +MN_STATE="${1:-none}" MN_REQ="${2:-0}" MN_NEW="${3:-0}" MN_LINES="${4:-0}" set -- $SN_COUNTS -SN_STATE="${1:-none}" SN_REQ="${2:-0}" SN_LINES="${3:-0}" +SN_STATE="${1:-none}" SN_REQ="${2:-0}" SN_NEW="${3:-0}" SN_LINES="${4:-0}" -echo "$SN served $CN $SN_REQ request(s) (log $SN_STATE, $SN_LINES lines)" -echo "$MN served $CN $MN_REQ request(s) (log $MN_STATE, $MN_LINES lines)" +echo "$SN served $CN $SN_REQ boot-payload request(s) since the baseline (log $SN_STATE, $SN_NEW new of $SN_LINES lines)" +echo "$MN served $CN $MN_REQ boot-payload request(s) since the baseline (log $MN_STATE, $MN_NEW new of $MN_LINES lines)" RC=0 @@ -109,22 +202,22 @@ if [ "$SN_STATE" != ok ]; then RC=1 fi -# The management node provisioned the service node over http, so its log is never empty on a -# hierarchical run. An empty log cannot show that the management node served nothing. -if [ "$MN_STATE" != ok ] || [ "$MN_LINES" -eq 0 ]; then - echo "provisioning source error: no httpd access log with entries could be read on $MN" >&2 +# The management node provisioned the service node over http, so its log gains lines on every +# hierarchical run. A log with nothing new cannot show that the management node served nothing. +if [ "$MN_STATE" != ok ] || [ "$MN_NEW" -eq 0 ]; then + echo "provisioning source error: no httpd access log with new entries could be read on $MN" >&2 RC=1 fi if [ "$RC" -eq 0 ] && [ "$SN_REQ" -eq 0 ]; then - echo "provisioning source error: $SN served $CN nothing, so it did not provision it" >&2 + echo "provisioning source error: $SN served $CN no boot payload, so it did not provision it" >&2 RC=1 fi # Count requests, not bytes. A 304 or a HEAD carries no body, so the management node can answer # for the compute node and still log 0 bytes. if [ "$RC" -eq 0 ] && [ "$MN_REQ" -gt 0 ]; then - echo "provisioning source error: $MN answered $MN_REQ request(s) for $CN, so this provision was flat" >&2 + echo "provisioning source error: $MN answered $MN_REQ boot-payload request(s) for $CN, so this provision was flat" >&2 RC=1 fi diff --git a/xCAT-test/autotest/testcase/installation/reg_linux_diskfull_installation_hierarchy b/xCAT-test/autotest/testcase/installation/reg_linux_diskfull_installation_hierarchy index ad739928c..47b329f07 100644 --- a/xCAT-test/autotest/testcase/installation/reg_linux_diskfull_installation_hierarchy +++ b/xCAT-test/autotest/testcase/installation/reg_linux_diskfull_installation_hierarchy @@ -47,6 +47,10 @@ check:rc==0 cmd:if [[ -f /test.synclist ]] ;then mv -f /test.synclist /test.synclist.bak;fi; cmd:echo "/test.synclist -> /test.synclist" > /test.synclist;chdef -t osimage -o __GETNODEATTR($$CN,os)__-__GETNODEATTR($$CN,arch)__-install-compute synclists=/test.synclist check:rc==0 +# The logs carry requests from earlier runs, so record where both of them end +# before this provision. The check below reads only what comes after. +cmd:/opt/xcat/share/xcat/tools/autotest/testcase/commoncmd/check_provisioning_source.sh --baseline $$CN $$SN +check:rc==0 cmd:nodeset $$CN osimage=__GETNODEATTR($$CN,os)__-__GETNODEATTR($$CN,arch)__-install-compute check:rc==0 cmd:updatenode $$CN -f diff --git a/xCAT-test/autotest/testcase/installation/reg_linux_diskless_installation_hierarchy b/xCAT-test/autotest/testcase/installation/reg_linux_diskless_installation_hierarchy index 639bf0225..fbc24cc23 100644 --- a/xCAT-test/autotest/testcase/installation/reg_linux_diskless_installation_hierarchy +++ b/xCAT-test/autotest/testcase/installation/reg_linux_diskless_installation_hierarchy @@ -53,6 +53,10 @@ check:rc==0 cmd:packimage __GETNODEATTR($$CN,os)__-__GETNODEATTR($$CN,arch)__-netboot-compute check:rc==0 +# The logs carry requests from earlier runs, so record where both of them end +# before this provision. The check below reads only what comes after. +cmd:/opt/xcat/share/xcat/tools/autotest/testcase/commoncmd/check_provisioning_source.sh --baseline $$CN $$SN +check:rc==0 cmd:nodeset $$CN osimage=__GETNODEATTR($$CN,os)__-__GETNODEATTR($$CN,arch)__-netboot-compute check:rc==0 @@ -178,6 +182,10 @@ cmd:packimage -m squashfs __GETNODEATTR($$CN,os)__-__GETNODEATTR($$CN,arch)__-ne check:rc==0 check:output=~archive method:squashfs +# The logs carry requests from earlier runs, so record where both of them end +# before this provision. The check below reads only what comes after. +cmd:/opt/xcat/share/xcat/tools/autotest/testcase/commoncmd/check_provisioning_source.sh --baseline $$CN $$SN +check:rc==0 cmd:nodeset $$CN osimage=__GETNODEATTR($$CN,os)__-__GETNODEATTR($$CN,arch)__-netboot-compute check:rc==0 diff --git a/xCAT-test/bats/check_provisioning_source.bats b/xCAT-test/bats/check_provisioning_source.bats index 16ba69835..bcf5b76f9 100644 --- a/xCAT-test/bats/check_provisioning_source.bats +++ b/xCAT-test/bats/check_provisioning_source.bats @@ -5,6 +5,9 @@ # dhcpd instances answer for the compute node, so the management node can win the xNBA exchange # and serve the boot payload itself. The httpd access logs are the only record of that. # +# The check takes a baseline of both logs before provisioning and reads only what came after, so +# these tests write the old lines, take the baseline, then append the lines of the run. +# # lsdef, xdsh and hostname are stubbed. XCAT_HTTPD_ACCESS_LOG is the management node's log. load 'helpers/shell_source' @@ -19,7 +22,10 @@ setup() BIN="${BATS_TEST_TMPDIR}/bin" MN_LOG="${BATS_TEST_TMPDIR}/mn-access_log" SN_LOG="${BATS_TEST_TMPDIR}/sn-access_log" + STATE="${BATS_TEST_TMPDIR}/baseline" mkdir -p "$BIN" + : >"$MN_LOG" + : >"$SN_LOG" printf '#!/bin/sh\nprintf "Object name: %s\\n ip=%s\\n" "$3" "%s"\n' "%s" "%s" "$CN_IP" >"$BIN/lsdef" printf '#!/bin/sh\necho mn01\n' >"$BIN/hostname" @@ -35,20 +41,104 @@ setup() export PATH="$BIN:$PATH" } -# One access-log line in the combined format, from $1, for $2 bytes. +# One access-log line in the combined format: $1 client, $2 bytes, $3 path. access_line() { printf '%s - - [01/Jan/2026:00:00:00 +0000] "GET %s HTTP/1.1" 200 %s "-" "iPXE"\n' "$1" "$3" "$2" } +take_baseline() +{ + env XCAT_HTTPD_ACCESS_LOG="$MN_LOG" XCAT_PROV_SOURCE_STATE="$STATE" \ + "$SCRIPT" --baseline "$CN" "$SN" >/dev/null +} + run_check() { - run env XCAT_HTTPD_ACCESS_LOG="$MN_LOG" "$SCRIPT" "$CN" "$SN" + run env XCAT_HTTPD_ACCESS_LOG="$MN_LOG" XCAT_PROV_SOURCE_STATE="$STATE" "$SCRIPT" "$CN" "$SN" +} + +# A log that has to hold something at baseline time, so the baseline is not trivially zero. +seed_logs() +{ + access_line 192.0.2.30 512 /install/rh/x86_64/ >"$SN_LOG" + access_line 192.0.2.31 512 /install/rh/x86_64/ >"$MN_LOG" } @test "a service node that served the compute node and a silent management node pass" { + seed_logs + take_baseline + access_line "$CN_IP" 12345678 /tftpboot/xcat/genesis.kernel >>"$SN_LOG" + access_line 192.0.2.21 4096 /install/rh/x86_64/ >>"$MN_LOG" + + run_check + [ "$status" -eq 0 ] + [[ "$output" == *"provisioning source ok"* ]] +} + +@test "a management node request from BEFORE the baseline does not fail this run" { + access_line "$CN_IP" 12345678 /tftpboot/xcat/genesis.kernel >"$MN_LOG" + access_line 192.0.2.30 512 /install/rh/x86_64/ >"$SN_LOG" + take_baseline + access_line "$CN_IP" 12345678 /tftpboot/xcat/genesis.kernel >>"$SN_LOG" + access_line 192.0.2.21 4096 /install/rh/x86_64/ >>"$MN_LOG" + + run_check + [ "$status" -eq 0 ] + [[ "$output" == *"provisioning source ok"* ]] +} + +@test "a service node request from BEFORE the baseline does not satisfy the check" { access_line "$CN_IP" 12345678 /tftpboot/xcat/genesis.kernel >"$SN_LOG" - access_line 192.0.2.21 4096 /install/rh/x86_64/ >"$MN_LOG" + access_line 192.0.2.31 512 /install/rh/x86_64/ >"$MN_LOG" + take_baseline + access_line 192.0.2.21 4096 /install/rh/x86_64/ >>"$MN_LOG" + + run_check + [ "$status" -ne 0 ] + [[ "$output" == *"no boot payload"* ]] +} + +@test "a request that carries no boot payload does not satisfy the check" { + seed_logs + take_baseline + printf '%s - - [01/Jan/2026:00:00:00 +0000] "GET /favicon.ico HTTP/1.1" 404 209 "-" "iPXE"\n' \ + "$CN_IP" >>"$SN_LOG" + access_line 192.0.2.21 4096 /install/rh/x86_64/ >>"$MN_LOG" + + run_check + [ "$status" -ne 0 ] + [[ "$output" == *"no boot payload"* ]] +} + +@test "a management node request that carries no boot payload does not read as a flat provision" { + seed_logs + take_baseline + access_line "$CN_IP" 12345678 /tftpboot/xcat/genesis.kernel >>"$SN_LOG" + printf '%s - - [01/Jan/2026:00:00:00 +0000] "GET /favicon.ico HTTP/1.1" 404 209 "-" "iPXE"\n' \ + "$CN_IP" >>"$MN_LOG" + + run_check + [ "$status" -eq 0 ] + [[ "$output" == *"provisioning source ok"* ]] +} + +@test "the check refuses to answer with no baseline" { + seed_logs + access_line "$CN_IP" 12345678 /tftpboot/xcat/genesis.kernel >>"$SN_LOG" + + run_check + [ "$status" -ne 0 ] + [[ "$output" == *"no baseline"* ]] + [[ "$output" != *"provisioning source ok"* ]] +} + +@test "a log rotated below its baseline is read from its first line" { + for i in 1 2 3 4 5; do access_line 192.0.2.30 512 /install/rh/x86_64/; done >"$SN_LOG" + access_line 192.0.2.31 512 /install/rh/x86_64/ >"$MN_LOG" + take_baseline + access_line "$CN_IP" 12345678 /tftpboot/xcat/genesis.kernel >"$SN_LOG" + access_line 192.0.2.21 4096 /install/rh/x86_64/ >>"$MN_LOG" run_check [ "$status" -eq 0 ] @@ -56,11 +146,13 @@ run_check() } @test "the management node answering for the compute node fails the check" { - access_line "$CN_IP" 12345678 /tftpboot/xcat/genesis.kernel >"$SN_LOG" + seed_logs + take_baseline + access_line "$CN_IP" 12345678 /tftpboot/xcat/genesis.kernel >>"$SN_LOG" { access_line 192.0.2.21 4096 /install/rh/x86_64/ access_line "$CN_IP" 12345678 /tftpboot/xcat/genesis.kernel - } >"$MN_LOG" + } >>"$MN_LOG" run_check [ "$status" -ne 0 ] @@ -69,12 +161,14 @@ run_check() } @test "a management node answering only a bodyless request still fails the check" { - access_line "$CN_IP" 12345678 /tftpboot/xcat/genesis.kernel >"$SN_LOG" + seed_logs + take_baseline + access_line "$CN_IP" 12345678 /tftpboot/xcat/genesis.kernel >>"$SN_LOG" { access_line 192.0.2.21 4096 /install/rh/x86_64/ printf '%s - - [01/Jan/2026:00:00:00 +0000] "HEAD %s HTTP/1.1" 304 - "-" "iPXE"\n' \ "$CN_IP" /tftpboot/xcat/genesis.kernel - } >"$MN_LOG" + } >>"$MN_LOG" run_check [ "$status" -ne 0 ] @@ -82,16 +176,20 @@ run_check() } @test "a service node that served the compute node nothing fails the check" { - access_line 192.0.2.22 4096 /install/rh/x86_64/ >"$SN_LOG" - access_line 192.0.2.21 4096 /install/rh/x86_64/ >"$MN_LOG" + seed_logs + take_baseline + access_line 192.0.2.22 4096 /install/rh/x86_64/ >>"$SN_LOG" + access_line 192.0.2.21 4096 /install/rh/x86_64/ >>"$MN_LOG" run_check [ "$status" -ne 0 ] - [[ "$output" == *"served $CN nothing"* ]] + [[ "$output" == *"no boot payload"* ]] } @test "an unreadable service node log fails the check instead of passing it" { - access_line 192.0.2.21 4096 /install/rh/x86_64/ >"$MN_LOG" + seed_logs + take_baseline + access_line 192.0.2.21 4096 /install/rh/x86_64/ >>"$MN_LOG" printf '#!/bin/sh\nexit 1\n' >"$BIN/xdsh" chmod 0755 "$BIN/xdsh" @@ -100,20 +198,23 @@ run_check() [[ "$output" == *"no httpd access log could be read on $SN"* ]] } -@test "an empty management node log fails the check instead of reading as silence" { - access_line "$CN_IP" 12345678 /tftpboot/xcat/genesis.kernel >"$SN_LOG" - : >"$MN_LOG" +@test "a management node log with nothing new fails the check instead of reading as silence" { + seed_logs + take_baseline + access_line "$CN_IP" 12345678 /tftpboot/xcat/genesis.kernel >>"$SN_LOG" run_check [ "$status" -ne 0 ] - [[ "$output" == *"no httpd access log with entries could be read on mn01"* ]] + [[ "$output" == *"no httpd access log with new entries could be read on mn01"* ]] } @test "the Debian per-vhost log format is read as the client address" { + seed_logs + take_baseline printf 'xcat:80 %s - - [01/Jan/2026:00:00:00 +0000] "GET %s HTTP/1.1" 200 12345678\n' \ - "$CN_IP" /tftpboot/xcat/genesis.kernel >"$SN_LOG" + "$CN_IP" /tftpboot/xcat/genesis.kernel >>"$SN_LOG" printf 'xcat:80 %s - - [01/Jan/2026:00:00:00 +0000] "GET %s HTTP/1.1" 200 4096\n' \ - 192.0.2.21 /install/ubuntu/x86_64/ >"$MN_LOG" + 192.0.2.21 /install/ubuntu/x86_64/ >>"$MN_LOG" run_check [ "$status" -eq 0 ] @@ -121,11 +222,13 @@ run_check() } @test "a compute node with no address fails the check" { + seed_logs + take_baseline printf '#!/bin/sh\nexit 1\n' >"$BIN/lsdef" printf '#!/bin/sh\nexit 2\n' >"$BIN/getent" chmod 0755 "$BIN/lsdef" "$BIN/getent" - access_line "$CN_IP" 12345678 /tftpboot/xcat/genesis.kernel >"$SN_LOG" - access_line 192.0.2.21 4096 /install/rh/x86_64/ >"$MN_LOG" + access_line "$CN_IP" 12345678 /tftpboot/xcat/genesis.kernel >>"$SN_LOG" + access_line 192.0.2.21 4096 /install/rh/x86_64/ >>"$MN_LOG" run_check [ "$status" -ne 0 ]