mirror of
https://github.com/cozystack/cozystack.git
synced 2026-11-09 22:13:18 +09:00
test(e2e): split the tenant worker CPU time across QEMU threads (#3843)
## What this PR does The node-join diagnostics already read the worker's CPU counters twice on failure, but they read the compute container's cgroup, and that cgroup holds every thread QEMU runs: the guest vCPUs, the emulator thread, the IO threads. A container spending most of its quota while the guest makes no progress has two incompatible readings and no container-level counter picks one. This adds the per-thread split. It execs into each Running worker's compute container and copies the QEMU process's `/proc/<pid>/task/<tid>/stat` lines into the artifact verbatim, with a legend. Nothing is computed in the collector. The legend is there because the field positions are a trap that gives a wrong answer instead of an error: a vCPU thread is named `CPU 0/KVM`, that space sits inside the comm parentheses, and awk over whitespace then reads the wrong column for exactly the threads the split is about. It runs in the sampling loop the other two subjects already share, so there is no second wait. Rates come from the two files and the stamps in them. Every way the read can fall short gets its own sentence in the artifact instead of an empty directory, and neither the legend nor the pairing instruction is attached to a read that did not finish. Coverage is `hack/run-kubernetes-thread-cpu_test.bats`, under `make unit-tests`. It drives those outcomes rather than grepping the source for them, and runs the probe against staged `/proc` trees. Context: cozystack/cozystack#3513. This is an instrument, not a fix, and it does not close that issue. ### Screenshots Not a UI change. ### Downstream repositories Walked against the diff. It touches `hack/e2e-chainsaw/_lib/run-kubernetes.sh`, the two kubernetes chainsaw suites, three `hack/*.bats` files and one paragraph in `docs/agents/e2e-testing.md`. Nothing under `packages/` moves, no ApplicationDefinition, schema, enum or default changes, no namespace or platform variant is renamed, no metric changes, and no label or annotation another component matches as a literal is touched. The two repositories that vendor out of `hack/` take `hack/package.mk` and `hack/update-crd.sh`, and neither is in this diff. - [x] No downstream repository is affected by this change - [ ] [cozystack/website](https://github.com/cozystack/website) - follow-up: - [ ] [cozystack/terraform-provider-cozystack](https://github.com/cozystack/terraform-provider-cozystack) - follow-up: - [ ] [cozystack/ansible-cozystack](https://github.com/cozystack/ansible-cozystack) - follow-up: - [ ] [cozystack/ccp](https://github.com/cozystack/ccp) - follow-up: - [ ] [cozystack/talm](https://github.com/cozystack/talm) - follow-up: - [ ] [cozystack/cozyhr](https://github.com/cozystack/cozyhr) - follow-up: - [ ] [cozystack/cozy-proxy](https://github.com/cozystack/cozy-proxy) - follow-up: - [ ] [cozystack/cozystack-telemetry-server](https://github.com/cozystack/cozystack-telemetry-server) - follow-up: - [ ] [cozystack/external-apps-example](https://github.com/cozystack/external-apps-example) - follow-up: - [ ] [cozystack/examples](https://github.com/cozystack/examples) - follow-up: ### Release note ```release-note test(e2e): on tenant node-join failure, capture how the compute container's CPU time splits across QEMU's vCPU, emulator and IO threads ``` <!-- This is an auto-generated comment: release notes by coderabbit.ai --> ## Summary by CodeRabbit - **New Features** - Added per-thread CPU diagnostics for worker compute processes. - Reports sampling timestamps, outcomes, interpretation notes, and relevant missing or incomplete data. - Improved Pod and node discovery for diagnostic collection. - **Documentation** - Clarified diagnostic sampling intervals, timing, and collection budgets. - **Tests** - Added comprehensive coverage for per-thread CPU diagnostics, bounded sampling, failure handling, fallbacks, and budget enforcement. <!-- end of auto-generated comment: release notes by coderabbit.ai -->
This commit is contained in:
7 files changed
+1330
-73
No files matched your search
@@ -37,7 +37,7 @@ A Chainsaw `assert` polls until the resource matches its expected shape or the p
|
||||
|
||||
- Condition checks use the **filter-as-list** form `(conditions[?type == 'Ready'])`. Chainsaw v0.2.15 throws "field not found" on the indexed `(...)[0]` form.
|
||||
- Imperative checks that no Kubernetes API condition models — S3 reachability through a port-forward, an external LB HTTP path, MetalLB advertisement — stay in a `script` step. A bare `sleep N` inside such a script is allowed **only** when nothing better models the wait; annotate it with a `TODO(e2e-replace-fixed-timeouts):` comment. The bootstrap BATS (`hack/e2e-install-cozystack.bats`, `hack/e2e-chainsaw/_lib/run-kubernetes.sh`) carries the sanctioned `until kubectl get` exceptions.
|
||||
- A **measurement interval** is not one of those waits and does not take the marker. The rule above governs a `sleep` standing in for a condition nobody wrote a wait for, and the marker means "replace this once something models it". A gap between two readings of a cumulative counter models nothing and is the quantity itself: the diagnostics phase in `hack/e2e-chainsaw/_lib/run-kubernetes.sh` reads the tenant worker CPU counters and the sandbox nodes' `/proc/stat` on either side of one `COZY_DIAG_RATE_INTERVAL` wait, because a single reading of a counter that accumulates from container start is an average over the whole uptime and no rate at all. There is no event to wait for instead, so a `TODO` there would promise a replacement that cannot exist. Carve-outs are named here rather than judged case by case, and this is the only measurement-interval one.
|
||||
- A **measurement interval** is not one of those waits and does not take the marker. The rule above governs a `sleep` standing in for a condition nobody wrote a wait for, and the marker means "replace this once something models it". A gap between two readings of a cumulative counter models nothing and is the quantity itself: the diagnostics phase in `hack/e2e-chainsaw/_lib/run-kubernetes.sh` reads the tenant worker CPU counters, the sandbox nodes' `/proc/stat` and QEMU's per-thread `/proc/<pid>/task/<tid>/stat` on either side of one shared `COZY_DIAG_RATE_INTERVAL` wait, because a single reading of a counter that accumulates from container start is an average over the whole uptime and no rate at all. There is no event to wait for instead, so a `TODO` there would promise a replacement that cannot exist. Carve-outs are named here rather than judged case by case, and this is the only measurement-interval one.
|
||||
|
||||
### 3. Let Chainsaw own cleanup; no test-level EXIT/RETURN traps
|
||||
|
||||
|
||||
@@ -1205,7 +1205,9 @@ _cozy_capture_worker_cadvisor() {
|
||||
COZY_DIAG_READ_TIMEOUT=$(_cozy_diag_seconds "${COZY_DIAG_READ_TIMEOUT-}" "$COZY_DIAG_READ_TIMEOUT_DEFAULT" COZY_DIAG_READ_TIMEOUT positive)
|
||||
COZY_DIAG_READ_GRACE=$(_cozy_diag_seconds "${COZY_DIAG_READ_GRACE-}" "$COZY_DIAG_READ_GRACE_DEFAULT" COZY_DIAG_READ_GRACE)
|
||||
|
||||
nodes=$(_cozy_cadvisor_worker_nodes "${report_dir}" "${label}") || return 1
|
||||
nodes=$(_cozy_virt_launcher_listing "${report_dir}" "${label}" \
|
||||
'{range .items[*]}{.spec.nodeName}{"\n"}{end}' \
|
||||
'no virt-launcher Pod with a node assigned in namespace tenant-test; an unscheduled Pod has no kubelet to ask') || return 1
|
||||
|
||||
for node in ${nodes}; do
|
||||
seen=$((seen + 1))
|
||||
@@ -1426,17 +1428,27 @@ _cozy_capture_worker_cadvisor() {
|
||||
done
|
||||
}
|
||||
|
||||
# The worker node listing, shared by both captures as code and issued fresh by
|
||||
# The virt-launcher listing, shared by the captures as code and issued fresh by
|
||||
# each of them: they ask the same question of the same apiserver, and the answer
|
||||
# is deliberately not carried between them, for the reason given at the read.
|
||||
# Echoes the node names and returns non-zero when there is no walk to make, with
|
||||
# the reason written where the reader of that capture will look for it.
|
||||
_cozy_cadvisor_worker_nodes() {
|
||||
# Echoes the projected field and returns non-zero when there is no walk to make,
|
||||
# with the reason written where the reader of that capture will look for it.
|
||||
#
|
||||
# The whole query is a parameter, not just the field inside it, because what a
|
||||
# caller walks is not always what it reads: a capture that talks to a kubelet
|
||||
# needs the node a worker landed on, one that talks to the container needs the
|
||||
# Pod, and one that has to reach into a container needs to skip the Pods there
|
||||
# is nothing to reach into. The sentence for an answer that named nothing
|
||||
# travels with it, since an empty listing means something different under each
|
||||
# query and a shared wording would be wrong for one of them.
|
||||
_cozy_virt_launcher_listing() {
|
||||
local report_dir="$1"
|
||||
local label="$2"
|
||||
local jsonpath="$3"
|
||||
local empty_msg="$4"
|
||||
local err_log="${report_dir}/COLLECTION-FAILED.txt"
|
||||
local warn_log="${report_dir}/READ-WARNINGS.txt"
|
||||
local raw_nodes nodes
|
||||
local raw_values values
|
||||
local list_rc=0
|
||||
|
||||
# stderr is kept out of the captured stdout so a warning on an otherwise
|
||||
@@ -1448,13 +1460,13 @@ _cozy_cadvisor_worker_nodes() {
|
||||
# a listing that never answered indistinguishable from a namespace with no
|
||||
# workers in it -- the one conflation these collectors must not make.
|
||||
if command -v timeout >/dev/null 2>&1; then
|
||||
raw_nodes=$(timeout -k "${COZY_DIAG_READ_GRACE}" "${COZY_DIAG_READ_TIMEOUT}" \
|
||||
raw_values=$(timeout -k "${COZY_DIAG_READ_GRACE}" "${COZY_DIAG_READ_TIMEOUT}" \
|
||||
kubectl -n tenant-test get pods -l kubevirt.io=virt-launcher \
|
||||
-o jsonpath='{range .items[*]}{.spec.nodeName}{"\n"}{end}' \
|
||||
-o "jsonpath=${jsonpath}" \
|
||||
"--request-timeout=${COZY_DIAG_READ_TIMEOUT}s" 2>"${warn_log}") || list_rc=$?
|
||||
else
|
||||
raw_nodes=$(kubectl -n tenant-test get pods -l kubevirt.io=virt-launcher \
|
||||
-o jsonpath='{range .items[*]}{.spec.nodeName}{"\n"}{end}' \
|
||||
raw_values=$(kubectl -n tenant-test get pods -l kubevirt.io=virt-launcher \
|
||||
-o "jsonpath=${jsonpath}" \
|
||||
"--request-timeout=${COZY_DIAG_READ_TIMEOUT}s" 2>"${warn_log}") || list_rc=$?
|
||||
fi
|
||||
if [ "${list_rc}" -ne 0 ]; then
|
||||
@@ -1466,15 +1478,13 @@ _cozy_cadvisor_worker_nodes() {
|
||||
return 1
|
||||
fi
|
||||
[ -s "${warn_log}" ] || rm -f "${warn_log}"
|
||||
nodes=$(printf '%s\n' "${raw_nodes}" | sort -u | grep -v '^$' || true)
|
||||
if [ -z "${nodes}" ]; then
|
||||
echo "no virt-launcher Pod with a node assigned for ${label}" >&2
|
||||
printf '%s\n' \
|
||||
'no virt-launcher Pod with a node assigned in namespace tenant-test; an unscheduled Pod has no kubelet to ask' \
|
||||
>"${err_log}"
|
||||
values=$(printf '%s\n' "${raw_values}" | sort -u | grep -v '^$' || true)
|
||||
if [ -z "${values}" ]; then
|
||||
echo "${empty_msg} (${label})" >&2
|
||||
printf '%s\n' "${empty_msg}" >"${err_log}"
|
||||
return 1
|
||||
fi
|
||||
printf '%s\n' "${nodes}"
|
||||
printf '%s\n' "${values}"
|
||||
}
|
||||
|
||||
# The one answer here that is not a failure, and until it is written down the
|
||||
@@ -1854,6 +1864,274 @@ ${rows}
|
||||
EOF
|
||||
}
|
||||
|
||||
# The shell run inside a worker's compute container to list QEMU's threads.
|
||||
#
|
||||
# A function rather than a literal at the call site so it can be run against a
|
||||
# tree of files instead of against a container: it takes the /proc to walk as
|
||||
# its first argument and defaults to the real one, which is the only argument
|
||||
# the caller passes. That seam is the whole reason the branches below can be
|
||||
# exercised at all -- staging a process whose threads are worth reading needs a
|
||||
# hypervisor, and the two outcomes this has to get right are "found QEMU" and
|
||||
# "QEMU is gone", the second of which is a routine result on this failure path.
|
||||
#
|
||||
# Written for the container's shell rather than for the runner's: virt-launcher
|
||||
# ships no bash, and every construct here is POSIX. It also shells out to
|
||||
# nothing except `getconf`, whose absence it names: `read` is a builtin, and a
|
||||
# probe that needed `cat` would report a container missing coreutils as a
|
||||
# container whose QEMU had exited -- which is one of the two readings this
|
||||
# collector exists to tell apart, manufactured rather than observed.
|
||||
#
|
||||
# For the same reason the walk counts what it managed to read. Having read no
|
||||
# process at all and having read them all without finding QEMU are different
|
||||
# findings, and only the second is about the guest.
|
||||
_cozy_thread_cpu_probe() {
|
||||
cat <<'PROBE'
|
||||
proc_root=${1:-/proc}
|
||||
found=0
|
||||
seen=0
|
||||
lines=0
|
||||
printf 'clock ticks per second: %s\n' "$(getconf CLK_TCK 2>/dev/null || echo unavailable)"
|
||||
for comm_file in "${proc_root}"/[0-9]*/comm; do
|
||||
comm=
|
||||
read -r comm <"${comm_file}"
|
||||
[ -n "${comm}" ] || continue
|
||||
seen=$((seen + 1))
|
||||
case "${comm}" in
|
||||
qemu-*) ;;
|
||||
*) continue ;;
|
||||
esac
|
||||
pid_dir=${comm_file%/comm}
|
||||
found=1
|
||||
printf 'process %s comm %s\n' "${pid_dir##*/}" "${comm}"
|
||||
# One line per file, because that is all /proc/<pid>/task/<tid>/stat is, and
|
||||
# `read` returns non-zero on a last line with no newline while still setting
|
||||
# the variable -- so the status is not what decides whether anything arrived.
|
||||
for stat_file in "${pid_dir}"/task/*/stat; do
|
||||
stat_line=
|
||||
read -r stat_line <"${stat_file}"
|
||||
[ -n "${stat_line}" ] || continue
|
||||
lines=$((lines + 1))
|
||||
printf '%s\n' "${stat_line}"
|
||||
done
|
||||
# On the loop rather than on either read, and that is not a style choice.
|
||||
# Redirections are applied left to right, so a `2>/dev/null` written after the
|
||||
# input redirect is not in place yet when opening the input fails -- and `read`
|
||||
# is a builtin, so the complaint is the shell's own and there is no child whose
|
||||
# stderr was ever covered. A thread that exits between the glob and the read is
|
||||
# routine here, this probe's stderr is the collector's error artifact, and a
|
||||
# healthy capture must not ship a warnings file naming something that did not
|
||||
# affect the reading. On the loop the redirect is in place before the body runs,
|
||||
# which is also the only spelling that holds in every shell.
|
||||
done 2>/dev/null
|
||||
if [ "${seen}" -eq 0 ]; then
|
||||
printf '%s\n' 'NO-PROC-READ: not one process could be read under the proc mount, so this says nothing about what the container was running'
|
||||
elif [ "${found}" -eq 0 ]; then
|
||||
printf '%s\n' "NO-QEMU-PROCESS: ${seen} process(es) were read and none is named qemu-*, so this container had no QEMU threads to read"
|
||||
elif [ "${lines}" -eq 0 ]; then
|
||||
# QEMU was named and then gone: its comm was read and not one of its task
|
||||
# stat files could be. Without this the probe exits clean carrying only a
|
||||
# heading, and a heading is enough to make the capture non-empty, so the
|
||||
# collector would pin a legend about columns onto a file that has none.
|
||||
printf '%s\n' 'NO-THREAD-LINES: a qemu-* process was named and not one of its task stat files could be read, so it exited between the two reads'
|
||||
fi
|
||||
PROBE
|
||||
}
|
||||
|
||||
# Split the compute container's CPU time across QEMU's threads, from inside it.
|
||||
#
|
||||
# This exists because the collector beside it measures the wrong subject for the
|
||||
# question it is usually read for. The throttling capture reads the compute
|
||||
# container's cgroup, and that cgroup holds every thread QEMU runs: the guest's
|
||||
# vCPUs, QEMU's main thread, and its IO and worker threads. So a container
|
||||
# burning most of its quota while the guest reports no progress at all is two
|
||||
# incompatible findings wearing one number -- a guest computing at its ceiling,
|
||||
# and a guest standing still while something beside it spends the quota -- and
|
||||
# no container-level counter can separate them. The per-thread split is the only
|
||||
# reading that can, and nothing else in this tree collects it.
|
||||
#
|
||||
# Read from inside the container rather than from the kubelet, which is the
|
||||
# opposite of what the throttling capture does and for a reason that does not
|
||||
# apply here: cAdvisor publishes per-container series and no per-thread ones, so
|
||||
# there is no outside surface carrying this at all. The cost of going inside is
|
||||
# the one that capture's comment names -- a reader that shares the cgroup it
|
||||
# measures slows down exactly when the answer matters -- which is why the read
|
||||
# is bounded and why a container that never answers gets a sentence rather than
|
||||
# an empty file. hack/e2e-capture-dataplane.sh reads a container's own cpu.stat
|
||||
# the same way, and the exec here carries no --request-timeout for the same
|
||||
# reason its execs do not: the flag bounds a request, and this is a streamed
|
||||
# connection whose bound is the wall-clock wrapper.
|
||||
#
|
||||
# Nothing is computed here. The stat lines go into the artifact verbatim and the
|
||||
# legend beside them says how to read the two fields that matter, because the
|
||||
# field positions are a trap that produces a wrong answer rather than an error:
|
||||
# the thread this capture exists to identify is the one whose name contains a
|
||||
# space.
|
||||
#
|
||||
# Takes the sample number it is writing, because it is called twice, and it is
|
||||
# called from the loop the other two subjects already share rather than from one
|
||||
# of its own: every counter here is cumulative since the thread started, so a
|
||||
# rate needs two readings, and the wait between them is the one already being
|
||||
# paid.
|
||||
cozy_capture_tenant_worker_thread_cpu() {
|
||||
local sample="$1"
|
||||
local report_dir="${COZY_REPORT_DIR:-/workspace/_out/cozyreport}/snapshots/${COZY_SNAPSHOT_NAME:-kubernetes}/tenant-thread-cpu/sample-${sample}"
|
||||
local pods pod rc raw pod_err probe read_at read_done
|
||||
local seen=0
|
||||
# The pool's declared minimum is two workers, and the listing below counts
|
||||
# only the Running ones, so this covers that pool scaled once over rather than
|
||||
# a sample of it. Raising it is not free, and at today's knobs it is not
|
||||
# possible: this walk is taken twice, the budget derivation in
|
||||
# hack/run-kubernetes-node-join_test.bats holds the whole sampling group
|
||||
# against the room the tenant snapshot needs behind it, and the next value up
|
||||
# fails that guard. Read the current margin off the guard, which computes both
|
||||
# sides, rather than off a number written here.
|
||||
local max_pods=4
|
||||
|
||||
mkdir -p "${report_dir}"
|
||||
# Re-validated here for the reason every collector re-validates them: a value
|
||||
# assigned after this file is sourced never passed the assignment-time check,
|
||||
# and zero reaches `timeout` as no bound at all.
|
||||
COZY_DIAG_READ_TIMEOUT=$(_cozy_diag_seconds "${COZY_DIAG_READ_TIMEOUT-}" "$COZY_DIAG_READ_TIMEOUT_DEFAULT" COZY_DIAG_READ_TIMEOUT positive)
|
||||
COZY_DIAG_READ_GRACE=$(_cozy_diag_seconds "${COZY_DIAG_READ_GRACE-}" "$COZY_DIAG_READ_GRACE_DEFAULT" COZY_DIAG_READ_GRACE)
|
||||
|
||||
# Running only, which the sibling caller does not ask for and does not need:
|
||||
# it reduces its answer to node names, so a launcher left over from an earlier
|
||||
# attempt costs it nothing. Here each Pod costs a bounded exec and a slot under
|
||||
# the cap, and a Pod that is not Running has no container to exec into at all,
|
||||
# so three dead launchers could push a live worker out of the walk and spend
|
||||
# the budget on tombstones. Filtered in the query rather than after it: a Pod
|
||||
# dropped here was never counted.
|
||||
pods=$(_cozy_virt_launcher_listing "${report_dir}" 'per-thread CPU time capture' \
|
||||
'{range .items[?(@.status.phase=="Running")]}{.metadata.name}{"\n"}{end}' \
|
||||
'no Running virt-launcher Pod in namespace tenant-test; a Pod that is not Running has no compute container to read threads from, and that it is not Running is itself a finding about this failure') || return 1
|
||||
|
||||
probe=$(_cozy_thread_cpu_probe)
|
||||
|
||||
for pod in ${pods}; do
|
||||
seen=$((seen + 1))
|
||||
if [ "${seen}" -gt "${max_pods}" ]; then
|
||||
echo "--- worker per-thread CPU capture stopped at ${max_pods} Pods ---"
|
||||
printf 'capture stopped after %s Pods; %s matched in total\n' \
|
||||
"${max_pods}" "$(printf '%s\n' "${pods}" | wc -l | tr -d ' ')" \
|
||||
>"${report_dir}/COLLECTION-TRUNCATED.txt"
|
||||
break
|
||||
fi
|
||||
echo "--- capturing worker per-thread CPU time: ${pod} ---"
|
||||
raw="${report_dir}/${pod}.txt"
|
||||
pod_err="${report_dir}/${pod}.exec-error.log"
|
||||
rc=0
|
||||
# Stamped on both sides of the read, which is what makes a pair of captures
|
||||
# subtractable. One stamp would leave the sampling instant somewhere inside
|
||||
# a read whose duration is exactly what goes wrong on the run this collector
|
||||
# exists for; on a healthy read the two are the same second.
|
||||
read_at=$(date -u +%s)
|
||||
# Guarded the way the other collectors in this pair guard it: without the
|
||||
# guard a runner with no `timeout` would exit 127 here and leave an empty
|
||||
# directory, which is the one outcome this collector may not produce.
|
||||
# stdin closed explicitly: `sh -c` inherits it, and this walk shares its
|
||||
# stdin with the caller.
|
||||
if command -v timeout >/dev/null 2>&1; then
|
||||
timeout -k "${COZY_DIAG_READ_GRACE}" "${COZY_DIAG_READ_TIMEOUT}" \
|
||||
kubectl -n tenant-test exec "${pod}" -c compute -- \
|
||||
sh -c "${probe}" >"${raw}" 2>"${pod_err}" </dev/null || rc=$?
|
||||
else
|
||||
kubectl -n tenant-test exec "${pod}" -c compute -- \
|
||||
sh -c "${probe}" >"${raw}" 2>"${pod_err}" </dev/null || rc=$?
|
||||
fi
|
||||
read_done=$(date -u +%s)
|
||||
if [ ! -s "${pod_err}" ]; then
|
||||
rm -f "${pod_err}"
|
||||
pod_err=
|
||||
elif [ "${rc}" -eq 0 ]; then
|
||||
mv "${pod_err}" "${report_dir}/${pod}.READ-WARNINGS.txt" 2>/dev/null || true
|
||||
pod_err=
|
||||
fi
|
||||
# Tested before anything is appended, or nothing is ever empty. Which arm
|
||||
# fires is decided by the STATUS and never by whether anything landed on
|
||||
# stderr: `timeout` kills its child without a word and kubectl dies on
|
||||
# SIGTERM the same way, so the dominant failure here -- a container on a
|
||||
# wedged node -- arrives non-zero with an empty error log, and keyed on
|
||||
# stderr the artifact would state the opposite of what happened.
|
||||
#
|
||||
# An empty file is the dangerous outcome rather than a neutral one. Every
|
||||
# thread of a stalled guest still accumulates a stat line, so zero bytes
|
||||
# here reads as a guest whose threads were all idle -- which is one of the
|
||||
# two readings this collector was added to tell apart, arrived at by
|
||||
# default.
|
||||
if [ ! -s "${raw}" ] && [ "${rc}" -ne 0 ]; then
|
||||
if [ -n "${pod_err}" ]; then
|
||||
printf '%s\n' \
|
||||
'the thread split is unknown: the compute container was not reached; see the exec-error.log beside this file, named for the same Pod' \
|
||||
>>"${raw}"
|
||||
else
|
||||
printf '%s\n' \
|
||||
'the thread split is unknown: the compute container was not reached, and the read died without a word on either stream' \
|
||||
>>"${raw}"
|
||||
fi
|
||||
elif [ ! -s "${raw}" ]; then
|
||||
printf '%s\n' \
|
||||
'the thread split is unknown: the compute container answered and returned nothing, which a shell that ran cannot produce -- the probe prints a line before it looks for a process' \
|
||||
>>"${raw}"
|
||||
elif [ "${rc}" -ne 0 ]; then
|
||||
printf '%s\n' \
|
||||
'these thread counters are incomplete: the read was cut short part way through the thread list, so the threads missing from it are the ones listed last rather than an arbitrary subset' \
|
||||
>>"${raw}"
|
||||
elif grep -q '^NO-QEMU-PROCESS:' "${raw}"; then
|
||||
# A clean read that found nothing to read, which on this path is a
|
||||
# finding: the guest's QEMU has already exited. Kept apart from the legend
|
||||
# below because that legend describes stat lines, and this file holds
|
||||
# none -- an explanation of a column layout over a file without columns is
|
||||
# the same overclaim as a pairing instruction over a partial read.
|
||||
printf '%s\n' \
|
||||
'there is nothing to split: the container answered and carried no QEMU process, so this Pod contributes no thread counters to the pair' \
|
||||
>>"${raw}"
|
||||
elif grep -q '^NO-THREAD-LINES:' "${raw}"; then
|
||||
# A heading and nothing under it. The file is not empty, so none of the
|
||||
# arms above fire, and the legend below would explain a column layout the
|
||||
# capture does not carry -- which is why the probe says this rather than
|
||||
# leaving it to be inferred from a line count nobody takes.
|
||||
printf '%s\n' \
|
||||
'the thread split is unknown: QEMU was still named when the probe looked and its threads were gone before they could be read, so this Pod contributes no thread counters to the pair' \
|
||||
>>"${raw}"
|
||||
elif grep -q '^NO-PROC-READ:' "${raw}"; then
|
||||
# Not the arm above, and the difference is the whole point of the probe
|
||||
# counting what it read. That one is a statement about the guest; this one
|
||||
# is a statement about the probe, and reading it as the guest's would put
|
||||
# "QEMU had already exited" in the artifact on the strength of a proc
|
||||
# mount nobody could open.
|
||||
printf '%s\n' \
|
||||
'the thread split is unknown: the shell ran and could not read a single process, so nothing here is a reading about what the guest was doing' \
|
||||
>>"${raw}"
|
||||
else
|
||||
printf '%s\n' \
|
||||
'[each line above beginning with a number is /proc/<pid>/task/<tid>/stat verbatim: the first field is the thread id, the second is the thread name in parentheses, utime is the 14th field and stime the 15th]' \
|
||||
'[counting those fields over whitespace reads the wrong column for exactly the threads this capture exists to identify: a KVM vCPU thread is named CPU 0/KVM, that space sits inside the parentheses, and every field after it shifts by one. Parse from the last ) in the line instead, after which the state is the first field, utime the 12th and stime the 13th]' \
|
||||
"[the names: CPU N/KVM is the guest's vCPU N, the thread whose id equals the process id is QEMU's main thread and its emulator thread, and the rest are QEMU's own IO and worker threads, which carry the process name unless QEMU renamed them]" \
|
||||
'[utime and stime are clock ticks, at the rate the first line above reports, and both are cumulative since the thread started: subtract this Pod file from its sibling under the other sample directory, and the stamps below from each other, to get a rate per thread]' \
|
||||
>>"${raw}"
|
||||
fi
|
||||
# kubectl exits 1 for a refused connection as readily as for a container
|
||||
# that is gone, so the status alone names none of them and the error log is
|
||||
# the only thing that can.
|
||||
if [ "${rc}" -eq 124 ]; then
|
||||
printf '%s\n' \
|
||||
'[exit 124: this collector timing out and the read exiting 124 on its own cannot be told apart]' \
|
||||
>>"${raw}"
|
||||
fi
|
||||
# 128+SIGKILL. The grace signal produces it, and so does anything else that
|
||||
# kills the read, so the note says what the status establishes and stops
|
||||
# there.
|
||||
if [ "${rc}" -eq 137 ]; then
|
||||
printf '%s\n' \
|
||||
'[exit 137: the read was killed rather than stopping on its own; the status does not say what killed it]' \
|
||||
>>"${raw}"
|
||||
fi
|
||||
printf '[read attempted from %s to %s epoch seconds]\n' \
|
||||
"${read_at}" "${read_done}" >>"${raw}"
|
||||
printf '\n[capture exit code: %s]\n' "${rc}" >>"${raw}"
|
||||
done
|
||||
}
|
||||
|
||||
# Two properties of the network family are invisible to anyone writing this
|
||||
# filter from the metric documentation, and both fail by capturing nothing:
|
||||
#
|
||||
@@ -2240,17 +2518,17 @@ cozy_diag_phase_start() {
|
||||
# cozystack/cozystack#3666; the warning names both halves rather than promising the
|
||||
# better one for all of them.
|
||||
#
|
||||
# The worker CPU throttling, worker network counter and sandbox node CPU time
|
||||
# captures belong to neither half: they call `timeout` directly AND carry the
|
||||
# same fallback, so on a runner without the binary they run unbounded rather
|
||||
# than exiting 127. That
|
||||
# is the opposite failure from the one the sentence above would lead a reader
|
||||
# to, and it is the half with the snapshot behind it, so they are named here
|
||||
# rather than left to be inferred. The list is derived from the source by
|
||||
# The worker CPU throttling, worker network counter, sandbox node CPU time and
|
||||
# worker per-thread CPU time captures belong to neither half: they call
|
||||
# `timeout` directly AND carry the same fallback, so on a runner without the
|
||||
# binary they run unbounded rather than exiting 127. That is the opposite
|
||||
# failure from the one the sentence above would lead a reader to, and it is
|
||||
# the half with the snapshot behind it, so they are named here rather than
|
||||
# left to be inferred. The list is derived from the source by
|
||||
# hack/run-kubernetes-node-join_test.bats, so a collector that joins this
|
||||
# group without joining the sentence fails there.
|
||||
command -v timeout >/dev/null 2>&1 || \
|
||||
echo "» WARNING: timeout is not on PATH; the bounded reads below run UNBOUNDED, so one that hangs can still take the op and the tenant snapshot with it, and the collectors that call timeout directly (wedge check, serial console, guest Talos) exit 127 and collect nothing; the ones that guard the call with command -v -- the worker CPU throttling, worker network counter, sandbox node CPU time, ghcr-mirror and talos-image-cache captures -- keep collecting instead, unbounded" >&2
|
||||
echo "» WARNING: timeout is not on PATH; the bounded reads below run UNBOUNDED, so one that hangs can still take the op and the tenant snapshot with it, and the collectors that call timeout directly (wedge check, serial console, guest Talos) exit 127 and collect nothing; the ones that guard the call with command -v -- the worker CPU throttling, worker network counter, sandbox node CPU time, worker per-thread CPU time, ghcr-mirror and talos-image-cache captures -- keep collecting instead, unbounded" >&2
|
||||
# Re-checked here, not only at assignment: a value set after this file is sourced
|
||||
# -- which is how a test sets it -- would otherwise reach the arithmetic below
|
||||
# unvalidated, and that is the one failure that costs the whole block.
|
||||
@@ -2632,11 +2910,11 @@ cozy_report_node_join_failure() {
|
||||
# settle that, and these counters do.
|
||||
#
|
||||
# It sits BELOW the console, and its ceiling rather than its worth is the
|
||||
# reason. Each collector spends a listing plus up to three node reads per
|
||||
# sample, so the pair is sixteen bounded reads and one interval: at the read
|
||||
# bound and the three-node cap that is most of the phase budget on its own. In
|
||||
# practice it costs the interval plus a handful of reads that an apiserver or
|
||||
# an apid answering at all answers in under a second -- but the run where
|
||||
# reason. Each collector spends a listing plus one read per subject it walks,
|
||||
# twice, and at the read bound and today's caps that ceiling is well past the
|
||||
# whole phase budget rather than a share of it. In practice it costs the
|
||||
# interval plus a handful of reads that an apiserver or an apid answering at
|
||||
# all answers in under a second -- but the run where
|
||||
# those reads DO approach their bound is a wedged kubelet, which is the
|
||||
# failure this whole block is written for. So the ceiling is not a remote
|
||||
# case here, and a collector carrying one that large must not sit ahead of the
|
||||
@@ -2651,28 +2929,33 @@ cozy_report_node_join_failure() {
|
||||
# because it is the first question this pair invites. The phase budget is
|
||||
# derived as budget + largest overshoot + snapshot <= op - bringup, where the
|
||||
# overshoot term is exactly "one collector admitted a moment before the
|
||||
# deadline runs its whole cost". This pair's ceiling is sixteen bounded reads
|
||||
# plus the interval; the term is the guest-Talos walk, which is larger. So a
|
||||
# pair admitted at the last second finishes inside the room already left for
|
||||
# the tenant crust-gather snapshot rather than pushing it past the op.
|
||||
# deadline runs its whole cost". This group's ceiling is the sum of its walks
|
||||
# plus the interval; the term is the guest-Talos walk, which is still larger,
|
||||
# though no longer by much. So a group admitted at the last second finishes
|
||||
# inside the room already left for the tenant crust-gather snapshot rather
|
||||
# than pushing it past the op.
|
||||
# hack/run-kubernetes-node-join_test.bats holds that against both numbers, so
|
||||
# a later change to the cap, the read bound or the interval cannot quietly
|
||||
# make this pair the binding term.
|
||||
# a later change to a cap, the read bound or the interval cannot quietly make
|
||||
# this group the binding term. The margin is not uniform across those knobs
|
||||
# and is not restated here: every walk enters the sum multiplied by its cap
|
||||
# and by two samples, while the interval enters it once, so a cap and the
|
||||
# interval are nowhere near equally expensive. The guard computes both sides
|
||||
# from the source, so it is where a reader finds out which knob has room, and
|
||||
# where the failure surfaces rather than in a timed-out run.
|
||||
#
|
||||
# Both collectors are read twice with one wait between the passes, and the
|
||||
# wait is shared: the counters on both sides are cumulative, so one reading of
|
||||
# either is an average over an uptime rather than a rate over the failure.
|
||||
# Taking the first reading of both, waiting once, and taking the second of
|
||||
# both costs the wait once rather than twice.
|
||||
# Each collector is read twice with one wait between the passes, and the wait
|
||||
# is shared: every counter here is cumulative, so one reading of any of them
|
||||
# is an average over an uptime rather than a rate over the failure. Taking the
|
||||
# first reading of each, waiting once, and taking the second of each costs the
|
||||
# wait once rather than once per subject.
|
||||
#
|
||||
# What the knob does NOT give is the interval either subject's counters span.
|
||||
# The worker's two readings are separated by the wait plus the sandbox pass
|
||||
# between them, the sandbox's by the wait plus the worker pass, and on the run
|
||||
# this exists for those passes are the slow part rather than the wait. So each
|
||||
# capture stamps the moment it was read and the reader subtracts stamps rather
|
||||
# than assuming the knob. The two subjects' windows overlap and are offset by
|
||||
# one pass; they are not identical, and treating them as identical is the
|
||||
# error the stamps remove.
|
||||
# What the knob does NOT give is the interval a subject's counters span. Each
|
||||
# subject's two readings are separated by the wait plus the other subjects'
|
||||
# passes, and on the run this exists for those passes are the slow part rather
|
||||
# than the wait. So each capture stamps the moment it was read and the reader
|
||||
# subtracts stamps rather than assuming the knob. The subjects' windows
|
||||
# overlap and are offset from one another; they are not identical, and
|
||||
# treating them as identical is the error the stamps remove.
|
||||
#
|
||||
# This `sleep` is not the fixed-timeout kind the e2e conventions rule out.
|
||||
# Those stand in for a condition nobody wrote a wait for; this one is the
|
||||
@@ -2684,8 +2967,11 @@ cozy_report_node_join_failure() {
|
||||
# passed that check -- and zero, the value the flag rejects, would put both
|
||||
# readings at the same instant and leave a pair that divides to nothing.
|
||||
COZY_DIAG_RATE_INTERVAL=$(_cozy_diag_seconds "${COZY_DIAG_RATE_INTERVAL-}" "$COZY_DIAG_RATE_INTERVAL_DEFAULT" COZY_DIAG_RATE_INTERVAL positive "zero puts both readings at the same instant, so the pair divides to nothing")
|
||||
if cozy_diag_phase_has_time '(d) tenant worker CPU counters and sandbox node CPU time'; then
|
||||
echo "=== (d) tenant worker CPU counters + sandbox node CPU time, two samples with a ${COZY_DIAG_RATE_INTERVAL}s wait between the passes; each capture carries the time it was read ==="
|
||||
# The label names all three subjects because the phase reuses it verbatim in
|
||||
# the decline line, the way the (b) gate below does and for the same reason: a
|
||||
# decline that names two of them reports the third as lost to nobody.
|
||||
if cozy_diag_phase_has_time '(d) tenant worker CPU counters, sandbox node CPU time and worker per-thread CPU time'; then
|
||||
echo "=== (d) tenant worker CPU counters + sandbox node CPU time + worker per-thread CPU time, two samples with a ${COZY_DIAG_RATE_INTERVAL}s wait between the passes; each capture carries the time it was read ==="
|
||||
for _sample in 1 2; do
|
||||
# Guarded like every other external here, and for a sharper reason than
|
||||
# the reads: this call is not wrapped in `|| true`, and the block runs
|
||||
@@ -2703,6 +2989,7 @@ cozy_report_node_join_failure() {
|
||||
fi
|
||||
cozy_capture_tenant_worker_cpu_throttle "${_sample}" || true
|
||||
cozy_capture_sandbox_node_cpu_time "${_sample}" || true
|
||||
cozy_capture_tenant_worker_thread_cpu "${_sample}" || true
|
||||
done
|
||||
fi
|
||||
|
||||
|
||||
@@ -36,8 +36,9 @@ spec:
|
||||
# serial-console family (~6m25s at worst, ~4m05s at the pool's minimum)
|
||||
# worker CPU usage and throttling counters, two samples
|
||||
# sandbox node CPU time, two samples
|
||||
# (those two alternate rather than run to completion in turn: both
|
||||
# take their first reading, one wait passes, both take their second)
|
||||
# worker per-thread CPU time inside virt-launcher, two samples
|
||||
# (those alternate rather than run to completion in turn: each takes
|
||||
# its first reading, one wait passes, each takes its second)
|
||||
# guest Talos capture
|
||||
# ghcr-mirror state, access log and warm-up Job
|
||||
# talos-image-cache diagnosis
|
||||
|
||||
@@ -30,8 +30,9 @@ spec:
|
||||
# serial-console family (~6m25s at worst, ~4m05s at the pool's minimum)
|
||||
# worker CPU usage and throttling counters, two samples
|
||||
# sandbox node CPU time, two samples
|
||||
# (those two alternate rather than run to completion in turn: both
|
||||
# take their first reading, one wait passes, both take their second)
|
||||
# worker per-thread CPU time inside virt-launcher, two samples
|
||||
# (those alternate rather than run to completion in turn: each takes
|
||||
# its first reading, one wait passes, each takes its second)
|
||||
# guest Talos capture
|
||||
# ghcr-mirror state, access log and warm-up Job
|
||||
# talos-image-cache diagnosis
|
||||
|
||||
@@ -235,6 +235,12 @@ run_capture() {
|
||||
# name has to come from the Pod. Reading a fixed node, or the wrong one,
|
||||
# returns a healthy stranger's counters.
|
||||
assert_file_contains 'get --raw /api/v1/nodes/srv1/proxy/metrics/cadvisor' "$kubectl_calls"
|
||||
# And the node name comes from the field this caller asks the listing for.
|
||||
# That projection is a parameter of the shared listing, and the other caller
|
||||
# of it passes the Pod name instead; swapped, this capture would ask kubelets
|
||||
# named after Pods and get nothing, with no error to say why. The mock answers
|
||||
# any listing regardless of what was asked for, so nothing else here sees it.
|
||||
assert_file_contains 'jsonpath={range .items[*]}{.spec.nodeName}{"\n"}{end}' "$kubectl_calls"
|
||||
capture="$COZY_REPORT_DIR/snapshots/throttle-smoke/tenant-cpu-throttle/sample-1/srv1.txt"
|
||||
assert_file_contains 'container_cpu_cfs_throttled_periods_total' "$capture"
|
||||
# One assertion per alternative in the filter's regex, because a typo in an
|
||||
@@ -567,7 +573,7 @@ run_capture() {
|
||||
fn=$(awk '/^cozy_capture_tenant_worker_cpu_throttle\(\)/,/^}/' "$lib"
|
||||
awk '/^_cozy_capture_worker_cadvisor\(\)/,/^}/' "$lib"
|
||||
awk '/^_cozy_cadvisor_node_stream\(\)/,/^}/' "$lib"
|
||||
awk '/^_cozy_cadvisor_worker_nodes\(\)/,/^}/' "$lib")
|
||||
awk '/^_cozy_virt_launcher_listing\(\)/,/^}/' "$lib")
|
||||
case "$fn" in
|
||||
*'max_nodes=3'*) ;;
|
||||
*) echo "expected the collector to cap the walk at the 3 nodes the comments state" >&2; return 1 ;;
|
||||
@@ -668,7 +674,7 @@ run_capture() {
|
||||
# declined the cheaper reads around it -- which is the failure the phase
|
||||
# budget exists to prevent, reintroduced by the newest caller.
|
||||
lib=hack/e2e-chainsaw/_lib/run-kubernetes.sh
|
||||
gate=$(grep -n "^ *if cozy_diag_phase_has_time '(d) tenant worker CPU counters and sandbox node CPU time'; then$" \
|
||||
gate=$(grep -n "^ *if cozy_diag_phase_has_time '(d) tenant worker CPU counters, sandbox node CPU time and worker per-thread CPU time'; then$" \
|
||||
"$lib" | head -n 1 | cut -d: -f1)
|
||||
call=$(grep -n '^ *cozy_capture_tenant_worker_cpu_throttle "${_sample}" || true$' "$lib" | head -n 1 | cut -d: -f1)
|
||||
if [ -z "$gate" ] || [ -z "$call" ]; then
|
||||
|
||||
@@ -232,6 +232,7 @@ stub_gated_collectors() {
|
||||
cozy_capture_tenant_worker_cpu_throttle() { printf 'cpu-throttle-stub\n'; }
|
||||
cozy_capture_tenant_worker_network_counters() { printf 'network-counters-stub\n'; }
|
||||
cozy_capture_sandbox_node_cpu_time() { printf 'sandbox-cpu-time-stub\n'; }
|
||||
cozy_capture_tenant_worker_thread_cpu() { printf 'thread-cpu-stub\n'; }
|
||||
ghcr_mirror_diagnose() { printf 'ghcr-mirror-stub\n'; }
|
||||
}
|
||||
|
||||
@@ -702,7 +703,7 @@ assert_file_lacks_pattern() {
|
||||
# A rule written for additions does not catch a removal, so both directions
|
||||
# are named here.
|
||||
for marker in serial-console-stub talos-stub image-cache-stub cpu-throttle-stub \
|
||||
network-counters-stub ghcr-mirror-stub; do
|
||||
network-counters-stub sandbox-cpu-time-stub thread-cpu-stub ghcr-mirror-stub; do
|
||||
if grep -q "$marker" "$tmp/out"; then
|
||||
echo "FAIL: $marker ran after the phase ran out of budget" >&2
|
||||
false
|
||||
@@ -711,7 +712,7 @@ assert_file_lacks_pattern() {
|
||||
assert_file_contains '(b1) tenant worker guest serial console: not collected' "$tmp/out"
|
||||
assert_file_contains '(b) in-guest Talos dmesg + kubelet logs + service states + links: not collected' "$tmp/out"
|
||||
assert_file_contains 're-probe talos-image-cache ClusterIP + cacher debug bundle: not collected' "$tmp/out"
|
||||
assert_file_contains '(d) tenant worker CPU counters and sandbox node CPU time: not collected' "$tmp/out"
|
||||
assert_file_contains '(d) tenant worker CPU counters, sandbox node CPU time and worker per-thread CPU time: not collected' "$tmp/out"
|
||||
assert_file_contains '(d2) tenant worker network counters: not collected' "$tmp/out"
|
||||
assert_file_contains 'ghcr-mirror state, access log and warm-up Job: not collected' "$tmp/out"
|
||||
rm -rf "$tmp"
|
||||
@@ -933,6 +934,7 @@ assert_file_lacks_pattern() {
|
||||
cozy_capture_tenant_worker_network_counters() { :; }
|
||||
ghcr_mirror_diagnose() { :; }
|
||||
cozy_capture_sandbox_node_cpu_time() { :; }
|
||||
cozy_capture_tenant_worker_thread_cpu() { :; }
|
||||
kubectl() { printf "KUBECTL_RAN\n" >&2; }
|
||||
PATH='"$tmp"'/bin
|
||||
cozy_report_node_join_failure test-latest-version
|
||||
@@ -1215,17 +1217,21 @@ assert_file_lacks_pattern() {
|
||||
return 1
|
||||
fi
|
||||
done
|
||||
# Every walk's cap, not the first one. The two subjects declare their own
|
||||
# `local max_nodes` and are equal today, so taking the first would be right by
|
||||
# accident: raise one alone and the arithmetic below would keep using the
|
||||
# other, under-counting the pair while reading as satisfied.
|
||||
caps=$(grep -oE 'local max_nodes=[0-9]+' "$lib" | sed -E 's/.*=//')
|
||||
# Every walk's cap, not the first one, and not only the ones spelled
|
||||
# `max_nodes`: the subjects declare their own literal and two of them are
|
||||
# equal today, so taking the first would be right by accident, and a subject
|
||||
# that walks Pods rather than nodes would be left out of the sum entirely --
|
||||
# under-counting the pair while reading as satisfied.
|
||||
#
|
||||
# A literal cap only. The serial-console walk takes its cap from its caller,
|
||||
# which is what keeps it out of this expression: it is not part of the pair.
|
||||
caps=$(grep -oE 'local max_(nodes|pods)=[0-9]+' "$lib" | sed -E 's/.*=//')
|
||||
# `|| true`: grep -c exits 1 on a count of zero, and under errexit that ends
|
||||
# the test before the branch below can say what was missing -- the guard would
|
||||
# still fail, with the diagnostic it was given replaced by silence.
|
||||
ncaps=$(printf '%s\n' "$caps" | grep -c . || true)
|
||||
if [ "$ncaps" -ne 2 ]; then
|
||||
echo "expected two capped walks in $lib, found $ncaps; the pair arithmetic below is written for exactly the two subjects the sampling loop reads" >&2
|
||||
if [ "$ncaps" -ne 3 ]; then
|
||||
echo "expected three capped walks in $lib, found $ncaps; the pair arithmetic below is written for exactly the subjects the sampling loop reads" >&2
|
||||
return 1
|
||||
fi
|
||||
# A capped walk costs a listing plus one read per node, each at the read bound
|
||||
@@ -1293,9 +1299,10 @@ assert_file_lacks_pattern() {
|
||||
return 1
|
||||
fi
|
||||
done
|
||||
# Two subjects, two samples each, one walk apiece at that subject's own cap,
|
||||
# plus the single wait. Summed per subject rather than doubling one walk, so a
|
||||
# cap raised on one side alone is counted where it lands.
|
||||
# Each subject, two samples each, one walk apiece at that subject's own cap,
|
||||
# plus the single wait -- single because the subjects share the pass rather
|
||||
# than each waiting for their own. Summed per subject rather than multiplying
|
||||
# one walk, so a cap raised on one side alone is counted where it lands.
|
||||
pair=$interval
|
||||
for c in $caps; do
|
||||
pair=$(( pair + 2 * (1 + c) * (bound + grace) ))
|
||||
@@ -1372,9 +1379,10 @@ assert_file_lacks_pattern() {
|
||||
# A helper renamed or a guard removed drops it out of `guarded`, and this
|
||||
# fails; a capture dropped from the warning fails on the phrase check below.
|
||||
for entry in \
|
||||
'cozy_capture_tenant_worker_cpu_throttle:CPU throttling:_cozy_cadvisor_node_stream _cozy_cadvisor_worker_nodes' \
|
||||
'cozy_capture_tenant_worker_network_counters:network counter:_cozy_cadvisor_node_stream _cozy_cadvisor_worker_nodes' \
|
||||
'cozy_capture_tenant_worker_cpu_throttle:CPU throttling:_cozy_cadvisor_node_stream _cozy_virt_launcher_listing' \
|
||||
'cozy_capture_tenant_worker_network_counters:network counter:_cozy_cadvisor_node_stream _cozy_virt_launcher_listing' \
|
||||
'cozy_capture_sandbox_node_cpu_time:sandbox node CPU time:cozy_capture_sandbox_node_cpu_time' \
|
||||
'cozy_capture_tenant_worker_thread_cpu:worker per-thread CPU time:cozy_capture_tenant_worker_thread_cpu _cozy_virt_launcher_listing' \
|
||||
'ghcr_mirror_diagnose:ghcr-mirror:ghcr_mirror_diagnose _ghcr_mirror_bounded_read' \
|
||||
'talos_image_cache_diagnose:talos-image-cache:talos_image_cache_diagnose _talos_image_cache_bounded_read'; do
|
||||
fn=${entry%%:*}
|
||||
@@ -1410,6 +1418,7 @@ ${carrier}
|
||||
cozy_capture_tenant_worker_cpu_throttle) phrase='CPU throttling' ;;
|
||||
cozy_capture_tenant_worker_network_counters) phrase='network counter' ;;
|
||||
cozy_capture_sandbox_node_cpu_time) phrase='sandbox node CPU time' ;;
|
||||
cozy_capture_tenant_worker_thread_cpu) phrase='worker per-thread CPU time' ;;
|
||||
ghcr_mirror_diagnose) phrase='ghcr-mirror' ;;
|
||||
talos_image_cache_diagnose) phrase='talos-image-cache' ;;
|
||||
# The sentence enumerates the CAPTURES. Two other kinds of function guard
|
||||
@@ -1421,7 +1430,7 @@ ${carrier}
|
||||
# step. A function that is neither still fails below, which is what makes
|
||||
# this a list of exemptions rather than a list of everything.
|
||||
cozy_diag_read | _ghcr_mirror_bounded_read | _talos_image_cache_bounded_read) continue ;;
|
||||
_cozy_cadvisor_node_stream | _cozy_cadvisor_worker_nodes) continue ;;
|
||||
_cozy_cadvisor_node_stream | _cozy_virt_launcher_listing) continue ;;
|
||||
cozy_report_node_join_failure | _talos_image_cache_deploy_state) continue ;;
|
||||
*)
|
||||
echo "$fn guards its call with command -v but this test has no phrase for it; add one here and to the warning" >&2
|
||||
@@ -1473,6 +1482,7 @@ ${carrier}
|
||||
case "$fn" in
|
||||
cozy_capture_tenant_worker_cpu_throttle) phrase='worker CPU usage and throttling counters' ;;
|
||||
cozy_capture_sandbox_node_cpu_time) phrase='sandbox node CPU time' ;;
|
||||
cozy_capture_tenant_worker_thread_cpu) phrase='worker per-thread CPU time' ;;
|
||||
cozy_capture_tenant_worker_network_counters) phrase='worker network counters' ;;
|
||||
cozy_capture_tenant_serial_console) phrase='serial-console family' ;;
|
||||
cozy_capture_tenant_talos) phrase='guest Talos capture' ;;
|
||||
|
||||
@@ -0,0 +1,952 @@
|
||||
#!/usr/bin/env bats
|
||||
# Regression coverage for the tenant-worker per-thread CPU capture in
|
||||
# hack/e2e-chainsaw/_lib/run-kubernetes.sh. cozytest.sh ends an @test block at
|
||||
# the first bare closing brace, so command mocks stay at top level.
|
||||
#
|
||||
# What this capture answers, and why the collector beside it cannot: the
|
||||
# throttling capture reads the compute container's cgroup, and that cgroup holds
|
||||
# every thread QEMU runs -- the guest's vCPUs, the emulator thread, and the IO
|
||||
# helpers. A container burning most of its quota while the guest reports no
|
||||
# progress is therefore two different findings wearing the same number, and the
|
||||
# container-level counter cannot separate them. Only the per-thread split can,
|
||||
# and it exists nowhere else in this tree. These tests pin the split and the
|
||||
# separation between an unread container and a quiet one, not the reading.
|
||||
|
||||
kubectl_calls=/dev/null
|
||||
kubectl_pod_names=
|
||||
kubectl_list_rc=0
|
||||
kubectl_list_stderr=
|
||||
kubectl_exec_rc=0
|
||||
kubectl_exec_stderr=
|
||||
# Two stat lines from one process, in the shape /proc writes them. The second
|
||||
# is the one every field-counting reader gets wrong: a KVM vCPU thread is named
|
||||
# "CPU 0/KVM", the space sits inside the parentheses, and every field after it
|
||||
# shifts by one.
|
||||
kubectl_exec_output='clock ticks per second: 100
|
||||
process 41 comm qemu-kvm
|
||||
41 (qemu-kvm) S 1 41 41 0 -1 4194560 8100 0 0 0 4210 1180 0 0 20 0 9 0 5512
|
||||
57 (CPU 0/KVM) R 1 41 41 0 -1 4194368 120 0 0 0 39120 2210 0 0 20 0 9 0 5530'
|
||||
timeout_calls=/dev/null
|
||||
timeout_fail_pod=
|
||||
|
||||
kubectl() {
|
||||
printf '%s\n' "$*" >>"${kubectl_calls}"
|
||||
|
||||
if [ "${3:-}" = get ] && [ "${4:-}" = pods ]; then
|
||||
[ -z "${kubectl_list_stderr}" ] || printf '%s\n' "${kubectl_list_stderr}" >&2
|
||||
[ "${kubectl_list_rc}" -eq 0 ] || return "${kubectl_list_rc}"
|
||||
[ -z "${kubectl_pod_names}" ] || printf '%s\n' ${kubectl_pod_names}
|
||||
return 0
|
||||
fi
|
||||
|
||||
if [ "${3:-}" = exec ]; then
|
||||
[ -z "${kubectl_exec_stderr}" ] || printf '%s\n' "${kubectl_exec_stderr}" >&2
|
||||
# Output before the status, so the branch that labels a partial capture is
|
||||
# reachable: a read cut off part way through has already written what it
|
||||
# managed to read, and a stub that returns first can only ever stage
|
||||
# empty-plus-failure.
|
||||
[ -z "${kubectl_exec_output}" ] || printf '%s\n' "${kubectl_exec_output}"
|
||||
return "${kubectl_exec_rc}"
|
||||
fi
|
||||
|
||||
return 0
|
||||
}
|
||||
|
||||
timeout() {
|
||||
local command_rc=0
|
||||
printf '%s\n' "$*" >>"${timeout_calls}"
|
||||
# Return 97 rather than running the command when the wrapper is not the
|
||||
# bounded form: a read that lost its ceiling must not pass as a read.
|
||||
[ "${1:-}" = -k ] || return 97
|
||||
shift 3
|
||||
"$@" || command_rc=$?
|
||||
if [ -n "${timeout_fail_pod}" ]; then
|
||||
case " $* " in
|
||||
*"${timeout_fail_pod}"*) return 124 ;;
|
||||
esac
|
||||
fi
|
||||
return "${command_rc}"
|
||||
}
|
||||
|
||||
assert_file_contains() {
|
||||
local needle="$1"
|
||||
local file="$2"
|
||||
|
||||
if [ ! -f "${file}" ]; then
|
||||
printf 'expected %s to exist so it could be checked for: %s\n' "${file}" "${needle}" >&2
|
||||
return 1
|
||||
fi
|
||||
case "$(cat "${file}")" in
|
||||
*"${needle}"*) return 0 ;;
|
||||
esac
|
||||
printf 'expected %s to contain: %s\n' "${file}" "${needle}" >&2
|
||||
return 1
|
||||
}
|
||||
|
||||
assert_file_lacks_pattern() {
|
||||
local pattern="$1"
|
||||
local file="$2"
|
||||
|
||||
# A missing file must fail rather than vacuously pass: a bare `! grep -q`
|
||||
# succeeds on an unreadable path, which is indistinguishable from "the file
|
||||
# exists and does not carry the label".
|
||||
if [ ! -f "${file}" ]; then
|
||||
printf 'expected %s to exist so it could be checked for: %s\n' "${file}" "${pattern}" >&2
|
||||
return 1
|
||||
fi
|
||||
# Branched on awk's exact status. awk exits 1 for "no line matched" and 2 for
|
||||
# "I could not evaluate this"; folded into an `if`, both land in the passing
|
||||
# branch and the assertion "this pattern is absent" is satisfied by the
|
||||
# matcher giving up. Every claim in this file about something NOT appearing
|
||||
# rests on the three-way split below.
|
||||
local _rc=0
|
||||
awk -v pattern="${pattern}" '$0 ~ pattern { found = 1 } END { exit found ? 0 : 1 }' "${file}" || _rc=$?
|
||||
case "${_rc}" in
|
||||
0)
|
||||
printf 'expected %s not to match: %s\n' "${file}" "${pattern}" >&2
|
||||
return 1
|
||||
;;
|
||||
1) return 0 ;;
|
||||
*)
|
||||
printf 'awk could not evaluate pattern %s against %s\n' "${pattern}" "${file}" >&2
|
||||
return 1
|
||||
;;
|
||||
esac
|
||||
}
|
||||
|
||||
# The function under test redirects a command's stderr into a report file and
|
||||
# decides which artifact to write from it. cozytest.sh runs under `set -x`, so
|
||||
# the tracer's own line for that command lands on the very stderr being
|
||||
# redirected, and every assertion about those files would be reading the
|
||||
# tracer. Call through this wrapper so the sinks hold what production writes.
|
||||
run_capture() {
|
||||
local _rc=0
|
||||
( set +x; cozy_capture_tenant_worker_thread_cpu 1 ) || _rc=$?
|
||||
return "${_rc}"
|
||||
}
|
||||
|
||||
@test "a negative assertion fails when its own matcher cannot evaluate" {
|
||||
# The helper below every "must not appear" claim in this file. What rides on
|
||||
# it here is the collector's contract stated negatively -- that an unreachable
|
||||
# container is not written up as one that answered, that an incomplete read
|
||||
# carries no pairing instruction -- so a matcher that fails open turns each of
|
||||
# them into a sentence nobody checked.
|
||||
tmp=$(mktemp -d)
|
||||
printf 'anything\n' >"$tmp/subject"
|
||||
|
||||
if assert_file_lacks_pattern '*(' "$tmp/subject" 2>/dev/null; then
|
||||
echo "FAIL: an unparseable pattern was reported as absent" >&2
|
||||
rm -rf "$tmp"
|
||||
return 1
|
||||
fi
|
||||
assert_file_lacks_pattern 'nothinglikethis' "$tmp/subject"
|
||||
if assert_file_lacks_pattern 'anything' "$tmp/subject" 2>/dev/null; then
|
||||
echo "FAIL: a present pattern was reported as absent" >&2
|
||||
rm -rf "$tmp"
|
||||
return 1
|
||||
fi
|
||||
rm -rf "$tmp"
|
||||
}
|
||||
|
||||
@test "the threads are read from inside the compute container of each worker Pod" {
|
||||
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
|
||||
tmp=$(mktemp -d)
|
||||
kubectl_calls="$tmp/kubectl.calls"
|
||||
timeout_calls="$tmp/timeout.calls"
|
||||
kubectl_pod_names="virt-launcher-a"
|
||||
COZY_REPORT_DIR="$tmp/report"
|
||||
COZY_SNAPSHOT_NAME=thread-smoke
|
||||
|
||||
run_capture
|
||||
|
||||
# The container has to be named. virt-launcher runs several, and kubectl's
|
||||
# default is the first one in the spec rather than the one running QEMU, so an
|
||||
# unnamed exec reads a stranger's threads or fails on a container with no shell.
|
||||
assert_file_contains 'exec virt-launcher-a -c compute' "$kubectl_calls"
|
||||
# The projection is a parameter now, and the two callers of that listing pass
|
||||
# different ones from twelve hundred lines apart. Swapped, this collector
|
||||
# would exec into Pods named after nodes and the cAdvisor one would ask
|
||||
# kubelets named after Pods: both dead, neither with an error, and every
|
||||
# artifact full of sentences saying the subject was not reached. Nothing else
|
||||
# in either suite sees the argument, because the mocks answer any listing
|
||||
# regardless of what was asked for.
|
||||
assert_file_contains 'jsonpath={range .items[?(@.status.phase=="Running")]}{.metadata.name}' "$kubectl_calls"
|
||||
capture="$COZY_REPORT_DIR/snapshots/thread-smoke/tenant-thread-cpu/sample-1/virt-launcher-a.txt"
|
||||
# The vCPU line and the emulator line both, because the whole question is
|
||||
# which of them carries the time: a capture that kept only one of the two
|
||||
# would answer it by construction.
|
||||
assert_file_contains '(CPU 0/KVM)' "$capture"
|
||||
assert_file_contains '(qemu-kvm)' "$capture"
|
||||
assert_file_lacks_pattern 'incomplete' "$capture"
|
||||
assert_file_lacks_pattern 'unknown' "$capture"
|
||||
dir="$COZY_REPORT_DIR/snapshots/thread-smoke/tenant-thread-cpu/sample-1"
|
||||
[ ! -f "$dir/virt-launcher-a.exec-error.log" ]
|
||||
[ ! -f "$dir/COLLECTION-FAILED.txt" ]
|
||||
rm -rf "$tmp"
|
||||
}
|
||||
|
||||
@test "each read is bounded and keeps its exit code" {
|
||||
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
|
||||
tmp=$(mktemp -d)
|
||||
kubectl_calls="$tmp/kubectl.calls"
|
||||
timeout_calls="$tmp/timeout.calls"
|
||||
kubectl_pod_names="virt-launcher-a"
|
||||
COZY_REPORT_DIR="$tmp/report"
|
||||
COZY_SNAPSHOT_NAME=thread-smoke
|
||||
|
||||
run_capture
|
||||
|
||||
# An unbounded exec would hold the whole diagnostics block against the wedged
|
||||
# kubelet this collector exists to study, and the phase budget bounds when a
|
||||
# read may START, never how long one already running may take.
|
||||
# Named by their verbs: both reads carry the same bound, so a bare '-k 5 20'
|
||||
# would be satisfied twice by whichever one survived.
|
||||
assert_file_contains '-k 5 20 kubectl -n tenant-test get pods -l kubevirt.io=virt-launcher' "$timeout_calls"
|
||||
assert_file_contains '-k 5 20 kubectl -n tenant-test exec' "$timeout_calls"
|
||||
# The listing is a request and carries the second bound too; the exec is a
|
||||
# streamed connection and the tree's other exec captures bound it with the
|
||||
# wrapper alone.
|
||||
assert_file_contains '--request-timeout=20s' "$kubectl_calls"
|
||||
assert_file_contains '[capture exit code: 0]' \
|
||||
"$COZY_REPORT_DIR/snapshots/thread-smoke/tenant-thread-cpu/sample-1/virt-launcher-a.txt"
|
||||
rm -rf "$tmp"
|
||||
}
|
||||
|
||||
@test "the sample number decides which reading a file belongs to" {
|
||||
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
|
||||
tmp=$(mktemp -d)
|
||||
kubectl_calls="$tmp/kubectl.calls"
|
||||
timeout_calls="$tmp/timeout.calls"
|
||||
kubectl_pod_names="virt-launcher-a"
|
||||
COZY_REPORT_DIR="$tmp/report"
|
||||
COZY_SNAPSHOT_NAME=thread-smoke
|
||||
|
||||
( set +x; cozy_capture_tenant_worker_thread_cpu 2 )
|
||||
|
||||
# utime and stime are cumulative since the thread started, so one reading is
|
||||
# an average over an uptime and says nothing about which thread burned the
|
||||
# window the deadline covered. A second reading written over the first leaves
|
||||
# one file and no interval.
|
||||
assert_file_contains '(CPU 0/KVM)' \
|
||||
"$COZY_REPORT_DIR/snapshots/thread-smoke/tenant-thread-cpu/sample-2/virt-launcher-a.txt"
|
||||
[ ! -d "$COZY_REPORT_DIR/snapshots/thread-smoke/tenant-thread-cpu/sample-1" ]
|
||||
rm -rf "$tmp"
|
||||
}
|
||||
|
||||
@test "each reading records when it was taken" {
|
||||
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
|
||||
tmp=$(mktemp -d)
|
||||
kubectl_calls="$tmp/kubectl.calls"
|
||||
timeout_calls="$tmp/timeout.calls"
|
||||
kubectl_pod_names="virt-launcher-a"
|
||||
COZY_REPORT_DIR="$tmp/report"
|
||||
COZY_SNAPSHOT_NAME=thread-smoke
|
||||
|
||||
run_capture
|
||||
|
||||
capture="$COZY_REPORT_DIR/snapshots/thread-smoke/tenant-thread-cpu/sample-1/virt-launcher-a.txt"
|
||||
# The wait between the two passes is not the interval this subject's two
|
||||
# readings span: the other two subjects' passes fall between them, and on the
|
||||
# run this collector exists for those passes are the slow part. The stamps are
|
||||
# what make the real interval readable off the pair.
|
||||
assert_file_contains 'read attempted from' "$capture"
|
||||
stamp=$(sed -n 's/.*read attempted from \([0-9][0-9]*\) to \([0-9][0-9]*\) epoch seconds.*/\1 \2/p' "$capture")
|
||||
if [ -z "$stamp" ]; then
|
||||
echo "expected a bare epoch stamp in $capture" >&2
|
||||
cat "$capture" >&2
|
||||
return 1
|
||||
fi
|
||||
rm -rf "$tmp"
|
||||
}
|
||||
|
||||
@test "the legend names the field positions and the thread name that shifts them" {
|
||||
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
|
||||
tmp=$(mktemp -d)
|
||||
kubectl_calls="$tmp/kubectl.calls"
|
||||
timeout_calls="$tmp/timeout.calls"
|
||||
kubectl_pod_names="virt-launcher-a"
|
||||
COZY_REPORT_DIR="$tmp/report"
|
||||
COZY_SNAPSHOT_NAME=thread-smoke
|
||||
|
||||
run_capture
|
||||
|
||||
capture="$COZY_REPORT_DIR/snapshots/thread-smoke/tenant-thread-cpu/sample-1/virt-launcher-a.txt"
|
||||
# Raw lines with no legend are a trap rather than data. The two numbers a
|
||||
# reader wants sit at fixed positions in /proc/<pid>/task/<tid>/stat, and the
|
||||
# thread this capture exists to identify is the one whose name breaks the
|
||||
# count: awk over whitespace reads the wrong column for exactly the vCPU
|
||||
# threads and the right one for every other thread, which is the shape of a
|
||||
# wrong answer that looks right.
|
||||
assert_file_contains 'utime' "$capture"
|
||||
assert_file_contains 'stime' "$capture"
|
||||
assert_file_contains 'CPU 0/KVM' "$capture"
|
||||
# The escape from the trap, not just a warning about it. A legend that names
|
||||
# the hazard without naming the parse leaves the next reader to invent one.
|
||||
assert_file_contains 'last )' "$capture"
|
||||
rm -rf "$tmp"
|
||||
}
|
||||
|
||||
@test "the legend names which thread each comm belongs to" {
|
||||
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
|
||||
tmp=$(mktemp -d)
|
||||
kubectl_calls="$tmp/kubectl.calls"
|
||||
timeout_calls="$tmp/timeout.calls"
|
||||
kubectl_pod_names="virt-launcher-a"
|
||||
COZY_REPORT_DIR="$tmp/report"
|
||||
COZY_SNAPSHOT_NAME=thread-smoke
|
||||
|
||||
run_capture
|
||||
|
||||
capture="$COZY_REPORT_DIR/snapshots/thread-smoke/tenant-thread-cpu/sample-1/virt-launcher-a.txt"
|
||||
# The whole discriminator is which of four kinds of thread holds the time, so
|
||||
# a capture that does not say which name is which kind leaves the reader to
|
||||
# guess the answer it was collected to settle.
|
||||
assert_file_contains 'emulator' "$capture"
|
||||
rm -rf "$tmp"
|
||||
}
|
||||
|
||||
@test "the capture tells the reader how to pair it with its sibling sample" {
|
||||
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
|
||||
tmp=$(mktemp -d)
|
||||
kubectl_calls="$tmp/kubectl.calls"
|
||||
timeout_calls="$tmp/timeout.calls"
|
||||
kubectl_pod_names="virt-launcher-a"
|
||||
COZY_REPORT_DIR="$tmp/report"
|
||||
COZY_SNAPSHOT_NAME=thread-smoke
|
||||
|
||||
run_capture
|
||||
|
||||
capture="$COZY_REPORT_DIR/snapshots/thread-smoke/tenant-thread-cpu/sample-1/virt-launcher-a.txt"
|
||||
assert_file_contains 'subtract this Pod file from its sibling under the other sample directory' "$capture"
|
||||
rm -rf "$tmp"
|
||||
}
|
||||
|
||||
@test "a read that did not finish is not told to pair with a sibling" {
|
||||
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
|
||||
tmp=$(mktemp -d)
|
||||
kubectl_calls="$tmp/kubectl.calls"
|
||||
timeout_calls="$tmp/timeout.calls"
|
||||
kubectl_pod_names="virt-launcher-a"
|
||||
COZY_REPORT_DIR="$tmp/report"
|
||||
COZY_SNAPSHOT_NAME=thread-smoke
|
||||
# Lines arrived and the read still failed, which is a stream cut off part way
|
||||
# through the thread list.
|
||||
kubectl_exec_rc=124
|
||||
|
||||
run_capture
|
||||
|
||||
capture="$COZY_REPORT_DIR/snapshots/thread-smoke/tenant-thread-cpu/sample-1/virt-launcher-a.txt"
|
||||
assert_file_contains 'these thread counters are incomplete' "$capture"
|
||||
# Telling a reader to subtract two files asserts that both hold a whole
|
||||
# reading. A difference taken against a truncated one understates whichever
|
||||
# threads the read did not reach, and the threads it did not reach are the
|
||||
# ones listed last -- so the understated set is not even random.
|
||||
assert_file_lacks_pattern 'subtract this Pod file from its sibling' "$capture"
|
||||
# And a legend that explains a column layout the file may not carry in full
|
||||
# is the same overclaim one line down.
|
||||
assert_file_lacks_pattern 'last \)' "$capture"
|
||||
rm -rf "$tmp"
|
||||
}
|
||||
|
||||
@test "a compute container that was not reached is recorded as unknown, not as an idle guest" {
|
||||
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
|
||||
tmp=$(mktemp -d)
|
||||
kubectl_calls="$tmp/kubectl.calls"
|
||||
timeout_calls="$tmp/timeout.calls"
|
||||
kubectl_pod_names="virt-launcher-a"
|
||||
COZY_REPORT_DIR="$tmp/report"
|
||||
COZY_SNAPSHOT_NAME=thread-smoke
|
||||
kubectl_exec_rc=1
|
||||
kubectl_exec_output=
|
||||
kubectl_exec_stderr='Error from server: error dialing backend: remote error: tls: internal error'
|
||||
|
||||
run_capture
|
||||
|
||||
dir="$COZY_REPORT_DIR/snapshots/thread-smoke/tenant-thread-cpu/sample-1"
|
||||
capture="$dir/virt-launcher-a.txt"
|
||||
# An empty file here reads as a guest whose threads were all idle, which is
|
||||
# the one conclusion this collector must never manufacture: the container
|
||||
# dying is a routine outcome on this failure path and it is not a reading.
|
||||
assert_file_contains 'was not reached' "$capture"
|
||||
assert_file_contains 'exec-error.log' "$capture"
|
||||
assert_file_lacks_pattern 'subtract this Pod file from its sibling' "$capture"
|
||||
assert_file_contains 'error dialing backend' "$dir/virt-launcher-a.exec-error.log"
|
||||
rm -rf "$tmp"
|
||||
}
|
||||
|
||||
@test "an exec that died without a word is not reported as a container that answered" {
|
||||
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
|
||||
tmp=$(mktemp -d)
|
||||
kubectl_calls="$tmp/kubectl.calls"
|
||||
timeout_calls="$tmp/timeout.calls"
|
||||
kubectl_pod_names="virt-launcher-a"
|
||||
COZY_REPORT_DIR="$tmp/report"
|
||||
COZY_SNAPSHOT_NAME=thread-smoke
|
||||
# timeout kills its child without a word and kubectl dies on SIGTERM the same
|
||||
# way, so the dominant failure here arrives non-zero with an empty error log.
|
||||
# Keyed on stderr rather than on the status, the artifact would say the
|
||||
# opposite of what happened.
|
||||
kubectl_exec_rc=137
|
||||
kubectl_exec_output=
|
||||
kubectl_exec_stderr=
|
||||
|
||||
run_capture
|
||||
|
||||
dir="$COZY_REPORT_DIR/snapshots/thread-smoke/tenant-thread-cpu/sample-1"
|
||||
capture="$dir/virt-launcher-a.txt"
|
||||
assert_file_contains 'was not reached' "$capture"
|
||||
assert_file_contains 'without a word on either stream' "$capture"
|
||||
# Naming a file that was never written sends the reader looking for evidence
|
||||
# that does not exist.
|
||||
[ ! -f "$dir/virt-launcher-a.exec-error.log" ]
|
||||
assert_file_contains '[exit 137:' "$capture"
|
||||
rm -rf "$tmp"
|
||||
}
|
||||
|
||||
@test "a container that answered and said nothing is not reported as unreachable" {
|
||||
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
|
||||
tmp=$(mktemp -d)
|
||||
kubectl_calls="$tmp/kubectl.calls"
|
||||
timeout_calls="$tmp/timeout.calls"
|
||||
kubectl_pod_names="virt-launcher-a"
|
||||
COZY_REPORT_DIR="$tmp/report"
|
||||
COZY_SNAPSHOT_NAME=thread-smoke
|
||||
kubectl_exec_rc=0
|
||||
kubectl_exec_output=
|
||||
|
||||
run_capture
|
||||
|
||||
capture="$COZY_REPORT_DIR/snapshots/thread-smoke/tenant-thread-cpu/sample-1/virt-launcher-a.txt"
|
||||
# Two different problems that leave the same empty file: an exec that never
|
||||
# landed, and a shell that ran and printed nothing. They are fixed by looking
|
||||
# in different places, so they must not share a sentence.
|
||||
assert_file_contains 'answered and returned nothing' "$capture"
|
||||
assert_file_lacks_pattern 'was not reached' "$capture"
|
||||
rm -rf "$tmp"
|
||||
}
|
||||
|
||||
@test "a container whose QEMU is gone carries no legend for columns it does not have" {
|
||||
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
|
||||
tmp=$(mktemp -d)
|
||||
kubectl_calls="$tmp/kubectl.calls"
|
||||
timeout_calls="$tmp/timeout.calls"
|
||||
kubectl_pod_names="virt-launcher-a"
|
||||
COZY_REPORT_DIR="$tmp/report"
|
||||
COZY_SNAPSHOT_NAME=thread-smoke
|
||||
kubectl_exec_rc=0
|
||||
kubectl_exec_output='clock ticks per second: 100
|
||||
NO-QEMU-PROCESS: no process whose name starts with qemu- exists in this container, so it had no threads to read'
|
||||
|
||||
run_capture
|
||||
|
||||
capture="$COZY_REPORT_DIR/snapshots/thread-smoke/tenant-thread-cpu/sample-1/virt-launcher-a.txt"
|
||||
# A clean read that found nothing to read is a finding about the failure, and
|
||||
# a different one from every arm around it.
|
||||
assert_file_contains 'nothing to split' "$capture"
|
||||
# A legend explaining a column layout over a file with no columns is the same
|
||||
# overclaim as a pairing instruction over a partial read, and it would send
|
||||
# the reader looking for stat lines that are not there.
|
||||
assert_file_lacks_pattern 'last \)' "$capture"
|
||||
assert_file_lacks_pattern 'subtract this Pod file from its sibling' "$capture"
|
||||
rm -rf "$tmp"
|
||||
}
|
||||
|
||||
@test "a warning beside a healthy listing is not filed as a failure" {
|
||||
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
|
||||
tmp=$(mktemp -d)
|
||||
kubectl_calls="$tmp/kubectl.calls"
|
||||
timeout_calls="$tmp/timeout.calls"
|
||||
kubectl_pod_names="virt-launcher-a"
|
||||
kubectl_list_stderr='Warning: v1 Pod is deprecated in this cluster'
|
||||
COZY_REPORT_DIR="$tmp/report"
|
||||
COZY_SNAPSHOT_NAME=thread-smoke
|
||||
|
||||
run_capture
|
||||
|
||||
dir="$COZY_REPORT_DIR/snapshots/thread-smoke/tenant-thread-cpu/sample-1"
|
||||
# kubectl writes deprecation and partial-result warnings with a zero exit, so
|
||||
# a sink chosen by "something was written" files a healthy read as a failed
|
||||
# one and the capture beside it reads as salvage.
|
||||
[ ! -f "$dir/COLLECTION-FAILED.txt" ]
|
||||
assert_file_contains 'deprecated' "$dir/READ-WARNINGS.txt"
|
||||
rm -rf "$tmp"
|
||||
}
|
||||
|
||||
@test "a warning beside a healthy exec is not filed as a failure" {
|
||||
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
|
||||
tmp=$(mktemp -d)
|
||||
kubectl_calls="$tmp/kubectl.calls"
|
||||
timeout_calls="$tmp/timeout.calls"
|
||||
kubectl_pod_names="virt-launcher-a"
|
||||
COZY_REPORT_DIR="$tmp/report"
|
||||
COZY_SNAPSHOT_NAME=thread-smoke
|
||||
kubectl_exec_rc=0
|
||||
kubectl_exec_stderr='Defaulted container "compute" out of: compute, volumecontainerdisk'
|
||||
|
||||
run_capture
|
||||
|
||||
dir="$COZY_REPORT_DIR/snapshots/thread-smoke/tenant-thread-cpu/sample-1"
|
||||
# kubectl writes deprecation and defaulted-container notices on stderr with a
|
||||
# zero exit, so the sink is chosen by the status rather than by something
|
||||
# having been written. Filed as an error, a healthy exec would look failed and
|
||||
# the capture beside it would read as salvage; discarded, a real notice about
|
||||
# the read would be gone. The two sibling collectors pin this branch, and the
|
||||
# round that suppressed the probe's own stderr rests on it.
|
||||
assert_file_contains 'Defaulted container' "$dir/virt-launcher-a.READ-WARNINGS.txt"
|
||||
[ ! -f "$dir/virt-launcher-a.exec-error.log" ]
|
||||
assert_file_contains '(CPU 0/KVM)' "$dir/virt-launcher-a.txt"
|
||||
rm -rf "$tmp"
|
||||
}
|
||||
|
||||
@test "a Pod list that never returned is not reported as no workers" {
|
||||
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
|
||||
tmp=$(mktemp -d)
|
||||
kubectl_calls="$tmp/kubectl.calls"
|
||||
timeout_calls="$tmp/timeout.calls"
|
||||
kubectl_list_rc=1
|
||||
kubectl_list_stderr='Unable to connect to the server: dial tcp: i/o timeout'
|
||||
COZY_REPORT_DIR="$tmp/report"
|
||||
COZY_SNAPSHOT_NAME=thread-smoke
|
||||
|
||||
run_capture || true
|
||||
|
||||
dir="$COZY_REPORT_DIR/snapshots/thread-smoke/tenant-thread-cpu/sample-1"
|
||||
# An apiserver that never answered and a namespace with no worker in it are
|
||||
# different findings, and an empty directory is how they become one.
|
||||
assert_file_contains 'failed to list' "$dir/COLLECTION-FAILED.txt"
|
||||
assert_file_contains 'i/o timeout' "$dir/COLLECTION-FAILED.txt"
|
||||
rm -rf "$tmp"
|
||||
}
|
||||
|
||||
@test "a namespace with no worker Pod says so instead of leaving an empty tree" {
|
||||
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
|
||||
tmp=$(mktemp -d)
|
||||
kubectl_calls="$tmp/kubectl.calls"
|
||||
timeout_calls="$tmp/timeout.calls"
|
||||
kubectl_pod_names=
|
||||
COZY_REPORT_DIR="$tmp/report"
|
||||
COZY_SNAPSHOT_NAME=thread-smoke
|
||||
|
||||
run_capture || true
|
||||
|
||||
dir="$COZY_REPORT_DIR/snapshots/thread-smoke/tenant-thread-cpu/sample-1"
|
||||
# Named for the filter the query carries. A namespace whose launchers are all
|
||||
# Pending is a different finding from one with no launcher at all, and the
|
||||
# sentence has to be true of the listing that was actually issued.
|
||||
assert_file_contains 'no Running virt-launcher Pod' "$dir/COLLECTION-FAILED.txt"
|
||||
rm -rf "$tmp"
|
||||
}
|
||||
|
||||
@test "the walk is capped and names both counts when it stops" {
|
||||
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
|
||||
tmp=$(mktemp -d)
|
||||
kubectl_calls="$tmp/kubectl.calls"
|
||||
timeout_calls="$tmp/timeout.calls"
|
||||
kubectl_pod_names="virt-launcher-a virt-launcher-b virt-launcher-c virt-launcher-d virt-launcher-e"
|
||||
COZY_REPORT_DIR="$tmp/report"
|
||||
COZY_SNAPSHOT_NAME=thread-smoke
|
||||
|
||||
run_capture
|
||||
|
||||
dir="$COZY_REPORT_DIR/snapshots/thread-smoke/tenant-thread-cpu/sample-1"
|
||||
# A short listing otherwise reads as a small pool rather than a truncated
|
||||
# walk, and the two counts are what separate them. Asserted as the whole
|
||||
# sentence, the way the sibling suites assert theirs: the marker's claim is
|
||||
# that the two numbers DIFFER, and a pair of bare digit checks is satisfied by
|
||||
# a marker reading "stopped after 4 Pods; 4 matched in total".
|
||||
assert_file_contains 'capture stopped after 4 Pods; 5 matched in total' \
|
||||
"$dir/COLLECTION-TRUNCATED.txt"
|
||||
# And the cap's VALUE, not just its wording. The marker prints max_pods rather
|
||||
# than what the walk read, so an off-by-one in the boundary test leaves the
|
||||
# sentence byte-identical while a Pod goes unread -- and max_pods is the term
|
||||
# the node-join budget guard multiplies, so the arithmetic and the marker
|
||||
# would misstate the same run together.
|
||||
[ -f "$dir/virt-launcher-d.txt" ]
|
||||
[ ! -f "$dir/virt-launcher-e.txt" ]
|
||||
rm -rf "$tmp"
|
||||
}
|
||||
|
||||
@test "a pool below the cap leaves no truncation marker" {
|
||||
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
|
||||
tmp=$(mktemp -d)
|
||||
kubectl_calls="$tmp/kubectl.calls"
|
||||
timeout_calls="$tmp/timeout.calls"
|
||||
kubectl_pod_names="virt-launcher-a virt-launcher-b"
|
||||
COZY_REPORT_DIR="$tmp/report"
|
||||
COZY_SNAPSHOT_NAME=thread-smoke
|
||||
|
||||
run_capture
|
||||
|
||||
dir="$COZY_REPORT_DIR/snapshots/thread-smoke/tenant-thread-cpu/sample-1"
|
||||
# A marker on every run is a marker nobody reads, and this one is the only
|
||||
# thing that says a capture answered for part of the pool.
|
||||
[ ! -f "$dir/COLLECTION-TRUNCATED.txt" ]
|
||||
[ -f "$dir/virt-launcher-b.txt" ]
|
||||
rm -rf "$tmp"
|
||||
}
|
||||
|
||||
@test "a Pod whose read times out does not stop the next one" {
|
||||
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
|
||||
tmp=$(mktemp -d)
|
||||
kubectl_calls="$tmp/kubectl.calls"
|
||||
timeout_calls="$tmp/timeout.calls"
|
||||
kubectl_pod_names="virt-launcher-a virt-launcher-b"
|
||||
timeout_fail_pod=virt-launcher-a
|
||||
COZY_REPORT_DIR="$tmp/report"
|
||||
COZY_SNAPSHOT_NAME=thread-smoke
|
||||
|
||||
run_capture
|
||||
|
||||
dir="$COZY_REPORT_DIR/snapshots/thread-smoke/tenant-thread-cpu/sample-1"
|
||||
# The two workers of one cluster are the comparison this capture is for, so a
|
||||
# walk that abandons the rest after one wedged container answers half the
|
||||
# question while looking like it answered all of it.
|
||||
assert_file_contains '[exit 124:' "$dir/virt-launcher-a.txt"
|
||||
assert_file_contains '(CPU 0/KVM)' "$dir/virt-launcher-b.txt"
|
||||
rm -rf "$tmp"
|
||||
}
|
||||
|
||||
@test "the probe finds the qemu process and reads every one of its threads" {
|
||||
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
|
||||
tmp=$(mktemp -d)
|
||||
# A /proc the size of the one inside a virt-launcher: the QEMU process, a
|
||||
# neighbour that is not it, and two threads under QEMU.
|
||||
mkdir -p "$tmp/proc/41/task/41" "$tmp/proc/41/task/57" "$tmp/proc/9/task/9"
|
||||
printf 'qemu-kvm\n' >"$tmp/proc/41/comm"
|
||||
printf 'virt-launcher\n' >"$tmp/proc/9/comm"
|
||||
printf '41 (qemu-kvm) S 1 41 41 0 -1 4194560 8100 0 0 0 4210 1180\n' >"$tmp/proc/41/task/41/stat"
|
||||
printf '57 (CPU 0/KVM) R 1 41 41 0 -1 4194368 120 0 0 0 39120 2210\n' >"$tmp/proc/41/task/57/stat"
|
||||
printf '9 (virt-launcher) S 0 9 9 0 -1 4194304 900 0 0 0 12 4\n' >"$tmp/proc/9/task/9/stat"
|
||||
|
||||
out=$(sh -c "$(_cozy_thread_cpu_probe)" probe "$tmp/proc")
|
||||
|
||||
printf '%s\n' "$out" >"$tmp/out"
|
||||
# Both threads of the QEMU process, or the split this capture exists for is
|
||||
# taken over a subset chosen by the probe rather than by the guest.
|
||||
assert_file_contains '(qemu-kvm)' "$tmp/out"
|
||||
assert_file_contains '(CPU 0/KVM)' "$tmp/out"
|
||||
# And nothing from the neighbour: virt-launcher's own threads are outside the
|
||||
# question and would be read as QEMU's under a heading that says QEMU's.
|
||||
assert_file_lacks_pattern 'virt-launcher\) S' "$tmp/out"
|
||||
rm -rf "$tmp"
|
||||
}
|
||||
|
||||
@test "a process that vanished mid-walk leaves nothing on the probe's stderr" {
|
||||
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
|
||||
tmp=$(mktemp -d)
|
||||
mkdir -p "$tmp/proc/41/task/41" "$tmp/proc/99"
|
||||
printf 'qemu-kvm\n' >"$tmp/proc/41/comm"
|
||||
printf '41 (qemu-kvm) S 1 41 41 0 -1 0 0 0 0 0 4210 1180\n' >"$tmp/proc/41/task/41/stat"
|
||||
# An entry the glob finds and the read cannot open, which is what a thread
|
||||
# exiting between the two looks like. A dangling symlink stages it the same
|
||||
# way whatever uid the suite runs as, where a chmod would not.
|
||||
ln -s /definitely-not-here "$tmp/proc/99/comm"
|
||||
|
||||
sh -c "$(_cozy_thread_cpu_probe)" probe "$tmp/proc" >"$tmp/out" 2>"$tmp/err"
|
||||
|
||||
# The probe's stderr is the collector's error artifact. A shell complaint
|
||||
# about a process that had already exited lands there, and on a clean read the
|
||||
# collector files it as a read warning -- a healthy capture shipping a warning
|
||||
# about something that did not affect the reading, which is the misfiling
|
||||
# every branch in this collector is written against.
|
||||
if [ -s "$tmp/err" ]; then
|
||||
echo "expected the probe to say nothing on stderr; it wrote:" >&2
|
||||
cat "$tmp/err" >&2
|
||||
return 1
|
||||
fi
|
||||
# And the suppression did not cost the reading it was protecting.
|
||||
assert_file_contains '(qemu-kvm)' "$tmp/out"
|
||||
rm -rf "$tmp"
|
||||
}
|
||||
|
||||
@test "the probe says so when no qemu process exists rather than returning nothing" {
|
||||
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
|
||||
tmp=$(mktemp -d)
|
||||
mkdir -p "$tmp/proc/9/task/9"
|
||||
printf 'virt-launcher\n' >"$tmp/proc/9/comm"
|
||||
printf '9 (virt-launcher) S 0 9 9 0 -1 4194304 900 0 0 0 12 4\n' >"$tmp/proc/9/task/9/stat"
|
||||
|
||||
out=$(sh -c "$(_cozy_thread_cpu_probe)" probe "$tmp/proc")
|
||||
|
||||
printf '%s\n' "$out" >"$tmp/out"
|
||||
# A container whose QEMU has already exited is a finding about the failure,
|
||||
# and silence from the probe would reach the artifact as a container that
|
||||
# answered and said nothing -- a different problem, in a different place.
|
||||
assert_file_contains 'NO-QEMU-PROCESS' "$tmp/out"
|
||||
# And it reports having read the neighbour, because that is what separates
|
||||
# this from a probe that could read nothing at all.
|
||||
assert_file_lacks_pattern 'NO-PROC-READ' "$tmp/out"
|
||||
rm -rf "$tmp"
|
||||
}
|
||||
|
||||
@test "the probe says so when QEMU is named and its threads are already gone" {
|
||||
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
|
||||
tmp=$(mktemp -d)
|
||||
# The race the probe runs into by construction: the comm read succeeds and
|
||||
# the task directory is gone by the time it is opened. Staged as a process
|
||||
# with no task tree at all, which is what the walk sees either way.
|
||||
mkdir -p "$tmp/proc/41"
|
||||
printf 'qemu-kvm\n' >"$tmp/proc/41/comm"
|
||||
|
||||
out=$(sh -c "$(_cozy_thread_cpu_probe)" probe "$tmp/proc")
|
||||
|
||||
printf '%s\n' "$out" >"$tmp/out"
|
||||
# The heading alone makes the capture non-empty, so nothing downstream can
|
||||
# tell this from a reading unless the probe says it. Reported as its own
|
||||
# outcome rather than as "no QEMU": QEMU was there, which is a different
|
||||
# sentence about the guest.
|
||||
assert_file_contains 'NO-THREAD-LINES' "$tmp/out"
|
||||
assert_file_lacks_pattern 'NO-QEMU-PROCESS' "$tmp/out"
|
||||
rm -rf "$tmp"
|
||||
}
|
||||
|
||||
@test "a capture carrying only a process heading is not given a column legend" {
|
||||
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
|
||||
tmp=$(mktemp -d)
|
||||
kubectl_calls="$tmp/kubectl.calls"
|
||||
timeout_calls="$tmp/timeout.calls"
|
||||
kubectl_pod_names="virt-launcher-a"
|
||||
COZY_REPORT_DIR="$tmp/report"
|
||||
COZY_SNAPSHOT_NAME=thread-smoke
|
||||
kubectl_exec_rc=0
|
||||
kubectl_exec_output='clock ticks per second: 100
|
||||
process 41 comm qemu-kvm
|
||||
NO-THREAD-LINES: a qemu-* process was named and not one of its task stat files could be read, so it exited between the two reads'
|
||||
|
||||
run_capture
|
||||
|
||||
capture="$COZY_REPORT_DIR/snapshots/thread-smoke/tenant-thread-cpu/sample-1/virt-launcher-a.txt"
|
||||
assert_file_contains 'threads were gone before they could be read' "$capture"
|
||||
# The whole hazard: a heading is enough to make the file non-empty, so every
|
||||
# "was it read" arm above passes and the legend would describe columns this
|
||||
# capture does not have.
|
||||
assert_file_lacks_pattern 'last \)' "$capture"
|
||||
assert_file_lacks_pattern 'subtract this Pod file from its sibling' "$capture"
|
||||
rm -rf "$tmp"
|
||||
}
|
||||
|
||||
@test "the probe reports a proc it could not read apart from a container without QEMU" {
|
||||
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
|
||||
tmp=$(mktemp -d)
|
||||
# A proc mount with nothing readable under it. The two outcomes are fixed in
|
||||
# different places, and only one of them is about the guest: reported as the
|
||||
# other, the artifact would state that QEMU had exited on the strength of a
|
||||
# read that never happened.
|
||||
mkdir -p "$tmp/proc"
|
||||
|
||||
out=$(sh -c "$(_cozy_thread_cpu_probe)" probe "$tmp/proc")
|
||||
|
||||
printf '%s\n' "$out" >"$tmp/out"
|
||||
assert_file_contains 'NO-PROC-READ' "$tmp/out"
|
||||
assert_file_lacks_pattern 'NO-QEMU-PROCESS' "$tmp/out"
|
||||
rm -rf "$tmp"
|
||||
}
|
||||
|
||||
@test "a proc the probe could not read is not written up as a guest without QEMU" {
|
||||
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
|
||||
tmp=$(mktemp -d)
|
||||
kubectl_calls="$tmp/kubectl.calls"
|
||||
timeout_calls="$tmp/timeout.calls"
|
||||
kubectl_pod_names="virt-launcher-a"
|
||||
COZY_REPORT_DIR="$tmp/report"
|
||||
COZY_SNAPSHOT_NAME=thread-smoke
|
||||
kubectl_exec_rc=0
|
||||
kubectl_exec_output='clock ticks per second: 100
|
||||
NO-PROC-READ: not one process could be read under the proc mount, so this says nothing about what the container was running'
|
||||
|
||||
run_capture
|
||||
|
||||
capture="$COZY_REPORT_DIR/snapshots/thread-smoke/tenant-thread-cpu/sample-1/virt-launcher-a.txt"
|
||||
# The collector has to carry the distinction the probe drew, or drawing it
|
||||
# bought nothing: a statement about the probe filed as a statement about the
|
||||
# guest is the conflation this whole collector is built against.
|
||||
assert_file_contains 'the thread split is unknown' "$capture"
|
||||
assert_file_lacks_pattern 'nothing to split' "$capture"
|
||||
assert_file_lacks_pattern 'last \)' "$capture"
|
||||
rm -rf "$tmp"
|
||||
}
|
||||
|
||||
@test "the probe reports the tick rate its two numbers are counted in" {
|
||||
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
|
||||
tmp=$(mktemp -d)
|
||||
mkdir -p "$tmp/proc/9/task/9"
|
||||
printf 'virt-launcher\n' >"$tmp/proc/9/comm"
|
||||
|
||||
out=$(sh -c "$(_cozy_thread_cpu_probe)" probe "$tmp/proc")
|
||||
|
||||
printf '%s\n' "$out" >"$tmp/out"
|
||||
# utime and stime are clock ticks, and the figure this capture is read
|
||||
# against is cores. Without the rate on the same page the reader supplies one
|
||||
# from memory, which is where a factor of ten enters a measurement.
|
||||
assert_file_contains 'clock ticks per second' "$tmp/out"
|
||||
rm -rf "$tmp"
|
||||
}
|
||||
|
||||
@test "with timeout off PATH the exec still runs instead of exiting 127" {
|
||||
# The fallback arm is what the phase-start warning promises for this
|
||||
# collector: on a runner without the binary it runs UNBOUNDED rather than
|
||||
# exiting 127 and leaving an empty directory. A promise the code does not keep
|
||||
# is what this collector's every other branch is against, so the arm is
|
||||
# entered here rather than inspected.
|
||||
#
|
||||
# A subprocess with a stripped PATH, because this file mocks `timeout` as a
|
||||
# shell function and `command -v` finds functions -- the condition cannot be
|
||||
# reached from inside a test body.
|
||||
tmp=$(mktemp -d)
|
||||
mkdir -p "$tmp/bin"
|
||||
# Everything the collector shells out to, minus `timeout` itself. Missing one
|
||||
# would fail this test for the wrong reason and read as the arm being broken.
|
||||
for c in mkdir sort grep mv rm wc tr cat date; do
|
||||
for d in /bin /usr/bin /usr/local/bin /opt/homebrew/bin; do
|
||||
if [ -x "$d/$c" ]; then
|
||||
ln -sf "$d/$c" "$tmp/bin/$c"
|
||||
break
|
||||
fi
|
||||
done
|
||||
done
|
||||
for c in mkdir sort grep mv rm wc tr cat date; do
|
||||
if [ ! -x "$tmp/bin/$c" ]; then
|
||||
echo "FAIL: could not stage $c in the stripped PATH; the check below would be vacuous" >&2
|
||||
return 1
|
||||
fi
|
||||
done
|
||||
# Only the staged directory is checked. `command -v timeout` is always true
|
||||
# here -- this file defines it as a shell function, which is the very fact the
|
||||
# subprocess exists to escape.
|
||||
if [ -e "$tmp/bin/timeout" ]; then
|
||||
echo "FAIL: timeout leaked into the stripped PATH; this test would prove nothing" >&2
|
||||
return 1
|
||||
fi
|
||||
|
||||
out=$(bash -c '
|
||||
set -eu
|
||||
. hack/e2e-chainsaw/_lib/run-kubernetes.sh
|
||||
kubectl() {
|
||||
# To a file, not to stderr. The collector redirects the stderr of every
|
||||
# read into its own artifact, so a stub that announces itself there is
|
||||
# captured by the code under test and never reaches this output.
|
||||
printf "KUBECTL %s\n" "$*" >>"$CALLS"
|
||||
if [ "${3:-}" = get ] && [ "${4:-}" = pods ]; then printf "virt-launcher-a\n"; return 0; fi
|
||||
if [ "${3:-}" = exec ]; then printf "41 (qemu-kvm) S 1 41 41 0 -1 0 0 0 0 0 4210 1180\n"; return 0; fi
|
||||
return 0
|
||||
}
|
||||
CALLS='"$tmp"'/calls
|
||||
COZY_REPORT_DIR='"$tmp"'/report
|
||||
COZY_SNAPSHOT_NAME=fallback
|
||||
PATH='"$tmp"'/bin
|
||||
cozy_capture_tenant_worker_thread_cpu 1
|
||||
' 2>&1) || true
|
||||
printf '%s\n' "$out" >"$tmp/out"
|
||||
|
||||
# The read ran at all -- bounded into exit 127 would leave nothing here.
|
||||
assert_file_contains 'KUBECTL -n tenant-test exec virt-launcher-a -c compute' "$tmp/calls"
|
||||
# And produced thread lines rather than an "unknown" label.
|
||||
assert_file_contains '(qemu-kvm)' \
|
||||
"$tmp/report/snapshots/fallback/tenant-thread-cpu/sample-1/virt-launcher-a.txt"
|
||||
rm -rf "$tmp"
|
||||
}
|
||||
|
||||
@test "the collector's own caps stay what its comments claim" {
|
||||
lib=hack/e2e-chainsaw/_lib/run-kubernetes.sh
|
||||
# The Pod listing lives in the body this collector shares with the cAdvisor
|
||||
# captures, so the subject here is the code the collector runs rather than the
|
||||
# function that carries its name; reading only the named function would leave
|
||||
# the listing assertions vacuously true against a body it does not contain.
|
||||
fn=$(awk '/^cozy_capture_tenant_worker_thread_cpu\(\)/,/^}/' "$lib"
|
||||
awk '/^_cozy_virt_launcher_listing\(\)/,/^}/' "$lib")
|
||||
if [ -z "$fn" ]; then
|
||||
echo "expected to find the collector in $lib" >&2
|
||||
return 1
|
||||
fi
|
||||
case "$fn" in
|
||||
*'max_pods=4'*) ;;
|
||||
*) echo "expected the collector to cap the walk at the 4 Pods the comments state" >&2; return 1 ;;
|
||||
esac
|
||||
# The knob, not a literal that equals it today. A hardcoded 20 keeps its value
|
||||
# when the block's budget is lowered, so the one read that ignores the knob is
|
||||
# the one that outlives it.
|
||||
case "$fn" in
|
||||
*'timeout -k "${COZY_DIAG_READ_GRACE}" "${COZY_DIAG_READ_TIMEOUT}"'*) ;;
|
||||
*) echo "expected each read to take the block's read-budget knob" >&2; return 1 ;;
|
||||
esac
|
||||
case "$fn" in
|
||||
*'timeout -k 5 20'*) echo "expected no hardcoded bound to survive beside the knob" >&2; return 1 ;;
|
||||
esac
|
||||
# The listing is an apiserver request and carries the HTTP bound as well as
|
||||
# the wall-clock one; without it a client retrying against a wedged apiserver
|
||||
# is bounded only by the wrapper.
|
||||
reads=$(printf '%s\n' "$fn" | grep -c 'kubectl -n tenant-test get pods' || true)
|
||||
bounded=$(printf '%s\n' "$fn" | grep -A3 'kubectl -n tenant-test get pods' | grep -c -- '--request-timeout=' || true)
|
||||
if [ "$reads" -eq 0 ] || [ "$reads" -ne "$bounded" ]; then
|
||||
echo "every Pod listing must carry --request-timeout; $bounded of $reads do" >&2
|
||||
return 1
|
||||
fi
|
||||
}
|
||||
|
||||
@test "the capture is declined by the phase budget rather than running unconditionally" {
|
||||
lib=hack/e2e-chainsaw/_lib/run-kubernetes.sh
|
||||
gate=$(grep -n "^ *if cozy_diag_phase_has_time '(d) tenant worker CPU counters, sandbox node CPU time and worker per-thread CPU time'; then$" \
|
||||
"$lib" | head -n 1 | cut -d: -f1)
|
||||
call=$(grep -n '^ *cozy_capture_tenant_worker_thread_cpu "${_sample}" || true$' "$lib" | head -n 1 | cut -d: -f1)
|
||||
if [ -z "$gate" ] || [ -z "$call" ]; then
|
||||
echo "expected the capture to sit behind a cozy_diag_phase_has_time gate" >&2
|
||||
return 1
|
||||
fi
|
||||
# THIS gate, not just some gate above the call. A line comparison alone is
|
||||
# satisfied by any earlier gate in the block, which would leave the capture
|
||||
# guarded by a decision taken about something else.
|
||||
next=$(awk -v g="$gate" 'NR > g && /cozy_diag_phase_has_time/ { print NR; exit }' "$lib")
|
||||
if [ -z "$next" ]; then
|
||||
echo "expected another phase gate after line $gate, so this test could bound the section" >&2
|
||||
return 1
|
||||
fi
|
||||
if [ "$call" -le "$gate" ] || [ "$call" -ge "$next" ]; then
|
||||
echo "the capture (line $call) must sit between its gate ($gate) and the next one ($next)" >&2
|
||||
return 1
|
||||
fi
|
||||
}
|
||||
|
||||
@test "the capture shares the pass the other two subjects already wait for" {
|
||||
lib=hack/e2e-chainsaw/_lib/run-kubernetes.sh
|
||||
# A second wait would be paid on every failing run for a second rate over the
|
||||
# same window, and the window is already the scarce term: the phase declines
|
||||
# whatever has not started, so an added pause is taken out of the collectors
|
||||
# below it rather than out of slack.
|
||||
waits=$(grep -c '^ *sleep "\${COZY_DIAG_RATE_INTERVAL}"$' "$lib" || true)
|
||||
if [ "$waits" -ne 1 ]; then
|
||||
echo "expected exactly one measurement wait in the block, found $waits" >&2
|
||||
return 1
|
||||
fi
|
||||
loop=$(grep -n '^ *for _sample in 1 2; do$' "$lib" | head -n 1 | cut -d: -f1)
|
||||
done_line=$(awk -v l="$loop" 'NR > l && /^ *done$/ { print NR; exit }' "$lib")
|
||||
call=$(grep -n '^ *cozy_capture_tenant_worker_thread_cpu "${_sample}" || true$' "$lib" | head -n 1 | cut -d: -f1)
|
||||
for v in loop done_line call; do
|
||||
eval "n=\$$v"
|
||||
if [ -z "$n" ]; then
|
||||
echo "expected to locate $v in $lib" >&2
|
||||
return 1
|
||||
fi
|
||||
done
|
||||
if [ "$call" -le "$loop" ] || [ "$call" -ge "$done_line" ]; then
|
||||
echo "the capture (line $call) must run inside the existing sampling loop ($loop..$done_line)" >&2
|
||||
return 1
|
||||
fi
|
||||
}
|
||||
|
||||
@test "the capture runs behind the console it could otherwise starve" {
|
||||
lib=hack/e2e-chainsaw/_lib/run-kubernetes.sh
|
||||
call=$(grep -n '^ *cozy_capture_tenant_worker_thread_cpu "${_sample}" || true$' "$lib" | head -n 1 | cut -d: -f1)
|
||||
console=$(grep -n "cozy_capture_tenant_serial_console 'node-join failed" "$lib" | head -n 1 | cut -d: -f1)
|
||||
if [ -z "$call" ] || [ -z "$console" ]; then
|
||||
echo "expected the failure path to call both the console and this capture" >&2
|
||||
return 1
|
||||
fi
|
||||
# Admission gates only when a collector may START, so a collector read twice
|
||||
# and placed ahead of the console can leave the console never started rather
|
||||
# than cut short -- and the console is the only surface that survives a worker
|
||||
# which never reached apid, the shape this failure usually takes.
|
||||
if [ "$call" -le "$console" ]; then
|
||||
echo "the thread capture (line $call) must run after the console capture (line $console)" >&2
|
||||
return 1
|
||||
fi
|
||||
}
|
||||
Reference in new issue
Block a user