|
| 1 | +#!/usr/bin/env bash |
| 2 | +# |
| 3 | +# Run a broadcast long enough for the slow faults to show. |
| 4 | +# |
| 5 | +# #380's DURATION gap: "the longest suite is 75s; real broadcasts run for hours. |
| 6 | +# Backoff crawl toward the 30s ceiling, memory growth, disk fill and reconnect |
| 7 | +# churn are duration bugs and nothing would currently see them." |
| 8 | +# |
| 9 | +# All four are invisible to a 75-second suite by construction. A leak of 200 kB |
| 10 | +# a minute is 12 MB an hour and a quarter of a megabyte in 75 seconds, which is |
| 11 | +# allocator noise. A backoff that doubles per failure needs several failures to |
| 12 | +# reach its ceiling. Churn is a COUNT that only becomes a rate once there is |
| 13 | +# enough time to divide by. |
| 14 | +# |
| 15 | +# WHAT MAKES A DURATION SUITE WORTHLESS. Every trend it watches reads FLAT on an |
| 16 | +# idle server: no memory growth, no restarts, no disk growth. So a long run |
| 17 | +# against a broadcast that died in its first minute reports perfect health, at |
| 18 | +# length and with graphs. The concurrency suite next door learned this from a |
| 19 | +# per-destination cost that halved beautifully because the processes were dead. |
| 20 | +# |
| 21 | +# So delivery is asserted FIRST and everything else is conditional on it: the |
| 22 | +# relay's byte counter must advance across EVERY interval, not just between the |
| 23 | +# endpoints, because a stall in the middle that recovered is exactly the churn |
| 24 | +# this is looking for and endpoints alone would average it away. |
| 25 | +# |
| 26 | +# TRENDS, NOT POINT VALUES. Peak RSS is a property of the machine; RSS climbing |
| 27 | +# across an hour is a property of the code. |
| 28 | +# |
| 29 | +# Usage: ./scripts/acceptance-duration.sh [workdir] |
| 30 | +# DURATION_MINUTES=10 how long to sample for |
| 31 | +# DURATION_DESTS=2 how many destinations to run |
| 32 | +set -u |
| 33 | + |
| 34 | +WORK="${1:-/tmp/polyemesis-acceptance-duration}" |
| 35 | +PORT=8099 |
| 36 | +MINUTES="${DURATION_MINUTES:-10}" |
| 37 | +DESTS="${DURATION_DESTS:-2}" |
| 38 | + |
| 39 | +SCRIPTS="$(cd "$(dirname "$0")" && pwd)" |
| 40 | +. "$SCRIPTS/lib-cleanup.sh" |
| 41 | +. "$SCRIPTS/lib-watchdog.sh" |
| 42 | +ROOT="$(cd "$SCRIPTS/.." && pwd)" |
| 43 | +BIN="$ROOT/polyemesis" |
| 44 | +. "$SCRIPTS/lib-preflight.sh" |
| 45 | + |
| 46 | +pass=0; fail=0 |
| 47 | +ok() { printf " \033[32mPASS\033[0m %s\n" "$1"; pass=$((pass+1)); } |
| 48 | +bad() { printf " \033[31mFAIL\033[0m %s\n" "$1"; fail=$((fail+1)); } |
| 49 | +note() { printf " %s\n" "$1"; } |
| 50 | +step() { printf "\n\033[1m%s\033[0m\n" "$1"; poly_step_record "$1"; } |
| 51 | + |
| 52 | +cleanup() { |
| 53 | + pkill -f "acceptance-duration-source" 2>/dev/null |
| 54 | + poly_cleanup_exit "${1:-0}" "$PORT" "$WORK" |
| 55 | +} |
| 56 | +trap 'poly_teardown_trap $? cleanup' EXIT |
| 57 | + |
| 58 | +poly_require_exec "$BIN" |
| 59 | +poly_require_cmd go "needed to run the acceptance driver via 'go run'" |
| 60 | +poly_require_cmd ffmpeg |
| 61 | +poly_require_cmd ps "the memory trend is read out of the process table" |
| 62 | +poly_require_cmd du "the disk trend is read off the data directory" |
| 63 | + |
| 64 | +rm -rf "$WORK"; mkdir -p "$WORK"; cd "$WORK" || exit 1 |
| 65 | +poly_watchdog_arm |
| 66 | + |
| 67 | +step "1. Start the binary" |
| 68 | +"$BIN" -addr ":$PORT" -data ./data -log warn > server.log 2>&1 & |
| 69 | +for _ in $(seq 1 40); do |
| 70 | + sleep 0.3 |
| 71 | + if grep -q "web ui" server.log 2>/dev/null; then break; fi |
| 72 | +done |
| 73 | +sleep 1 |
| 74 | +grep -q "polyemesis" server.log && ok "server started" || bad "server did not start" |
| 75 | + |
| 76 | +SRVPID=$(pgrep -f "polyemesis -addr :$PORT" | head -1) |
| 77 | +RELAY=$(lsof -nP -iUDP -a -p "$SRVPID" 2>/dev/null | awk '/UDP 127.0.0.1/{split($NF,a,":"); print a[2]; exit}') |
| 78 | + |
| 79 | +step "2. Broadcast for $MINUTES minute(s) with $DESTS destination(s)" |
| 80 | +FACTS="$WORK/facts.env" |
| 81 | +# RUN FROM $ROOT, IN A SUBSHELL: `go run` resolves module imports against the |
| 82 | +# CURRENT directory's go.mod, and this suite has cd'd into a workdir under /tmp |
| 83 | +# that is inside no module. driverlib's package comment records the same trap. |
| 84 | +( cd "$ROOT" && go run "$SCRIPTS/acceptance_duration_driver.go" \ |
| 85 | + "$PORT" "$RELAY" "$FACTS" "$MINUTES" "$DESTS" "$WORK/data" 2>&1 ) | sed 's/^/ /' |
| 86 | + |
| 87 | +[[ -s "$FACTS" ]] || { bad "driver wrote no facts"; step "Summary"; printf " %d passed, %d failed\n\n" "$pass" "$fail"; exit 1; } |
| 88 | +# shellcheck disable=SC1090 |
| 89 | +source "$FACTS" |
| 90 | +if [[ -n "${DRIVER_FAILED:-}" ]]; then bad "driver aborted: $DRIVER_FAILED"; fi |
| 91 | + |
| 92 | +# ------------------------------------------------------------- 3. delivery |
| 93 | +# |
| 94 | +# BEFORE EVERY OTHER CHECK, because every other check passes trivially on a |
| 95 | +# server that was doing nothing. This is the one that makes the rest mean |
| 96 | +# something. |
| 97 | +step "3. It was actually broadcasting the whole time" |
| 98 | +RX_DELTA=$(( ${DUR_RX_END:-0} - ${DUR_RX_START:-0} )) |
| 99 | +if [[ "$RX_DELTA" -gt 1000000 ]]; then |
| 100 | + ok "the relay took $(( RX_DELTA / 1000000 )) MB across the window" |
| 101 | +else |
| 102 | + bad "the relay took only ${RX_DELTA} bytes across the window" |
| 103 | + note "Every trend below reads flat on an idle server, so they are not" |
| 104 | + note "evidence of anything while this is failing. Check the source" |
| 105 | + note "published at all, and that /status still reports rxBytes where this" |
| 106 | + note "expects it -- a shape change here looks exactly like a dead broadcast." |
| 107 | +fi |
| 108 | +if [[ "${DUR_STALLS:-1}" == "0" ]]; then |
| 109 | + ok "no sampling interval saw the byte counter stall" |
| 110 | +else |
| 111 | + bad "${DUR_STALLS} interval(s) saw no bytes arrive" |
| 112 | + note "A stall that recovered still happened. Endpoints alone would have" |
| 113 | + note "averaged it away, which is why every interval is checked." |
| 114 | +fi |
| 115 | + |
| 116 | +# --------------------------------------------------------------- 4. churn |
| 117 | +step "4. Nothing reconnected" |
| 118 | +if [[ "${DUR_RESTARTS_END:-1}" == "${DUR_RESTARTS_START:-0}" ]]; then |
| 119 | + ok "no ingest or destination restarted (${DUR_RESTARTS_END:-?} total, unchanged)" |
| 120 | +else |
| 121 | + bad "restarts went ${DUR_RESTARTS_START:-?} -> ${DUR_RESTARTS_END:-?}" |
| 122 | + note "Reconnect churn is the fault this measures: a healthy broadcast does" |
| 123 | + note "not restart anything, and a count that climbs with wall time is the" |
| 124 | + note "backoff crawl #380 names." |
| 125 | +fi |
| 126 | + |
| 127 | +# -------------------------------------------------------------- 5. memory |
| 128 | +# |
| 129 | +# A CEILING ON THE RATE, not on the value. Go's heap and the GC make RSS noisy |
| 130 | +# enough that a tight bound would fail on scheduling; what a leak looks like is |
| 131 | +# a rate that does not fall off. |
| 132 | +step "5. Memory is not climbing" |
| 133 | +# GATED ON THE POST-WARM-UP RATE, not the overall one. A server's first minute |
| 134 | +# allocates caches, opens files and starts children, and on a short run that |
| 135 | +# startup dominates the overall figure entirely -- a two-minute run read |
| 136 | +# 1535 kB/min overall against 912 kB across its whole last third. Gating on the |
| 137 | +# overall number would need a ceiling loose enough to catch nothing, or would |
| 138 | +# fail on run LENGTH rather than on a leak. |
| 139 | +RSS_TAIL="${DUR_RSS_TAIL_PER_MIN_KB:-0}" |
| 140 | +CEIL=1024 |
| 141 | +# A MINIMUM RUN LENGTH, because this gate is not meaningful below one and |
| 142 | +# saying so is better than firing. Measured on an idle-but-broadcasting server: |
| 143 | +# the post-warm-up slope reads 1255 kB/min over a 3-minute run and 239 kB/min |
| 144 | +# over a 10-minute one, on the same machine with the same workload. Nothing |
| 145 | +# leaked; the heap was still climbing toward steady state, and a shorter window |
| 146 | +# is mostly measuring that climb no matter how the warm-up is excluded. |
| 147 | +# |
| 148 | +# So below MIN_GATE_MIN this REPORTS and does not gate. A short run is still |
| 149 | +# worth doing -- it exercises delivery, churn and disk -- but a memory verdict |
| 150 | +# from one would be a false alarm about arithmetic rather than a finding about |
| 151 | +# the code. |
| 152 | +MIN_GATE_MIN=5 |
| 153 | +if awk -v m="${DUR_MINUTES:-0}" -v n="$MIN_GATE_MIN" 'BEGIN{exit !(m < n)}'; then |
| 154 | + ok "server RSS moved ${RSS_TAIL} kB/min after warm-up (not gated: needs >= ${MIN_GATE_MIN} min)" |
| 155 | + note "A run this short is dominated by the heap reaching steady state. The" |
| 156 | + note "same server reads 1255 kB/min over 3 minutes and 239 over 10, with" |
| 157 | + note "nothing leaking. Run with DURATION_MINUTES=${MIN_GATE_MIN} or more for a verdict." |
| 158 | +elif awk -v r="$RSS_TAIL" -v c="$CEIL" 'BEGIN{exit !(r <= c)}'; then |
| 159 | + ok "server RSS moved ${RSS_TAIL} kB/min after warm-up (ceiling ${CEIL})" |
| 160 | +else |
| 161 | + bad "server RSS grew ${RSS_TAIL} kB/min after warm-up, over the ${CEIL} kB/min ceiling" |
| 162 | + note "At that rate an eight-hour broadcast would add about $(awk -v r="$RSS_TAIL" 'BEGIN{printf "%.0f", r*480/1024}') MB." |
| 163 | + note "Overall rate including warm-up was ${DUR_RSS_PER_MIN_KB:-?} kB/min." |
| 164 | +fi |
| 165 | +# Reported rather than gated. Warm-up allocates and a leak does not stop, so |
| 166 | +# the two thirds tell them apart -- but GC timing makes this noisy enough that |
| 167 | +# failing on it would cost more in false alarms than it catches. |
| 168 | +note "first third ${DUR_RSS_EARLY_KB:-?} kB, last third ${DUR_RSS_LATE_KB:-?} kB" |
| 169 | +note "(warm-up shows in the first and not the last; a leak shows in both)" |
| 170 | + |
| 171 | +# ---------------------------------------------------------------- 6. disk |
| 172 | +step "6. Disk growth is the recordings and nothing else" |
| 173 | +# The destinations are writing files, so growth is EXPECTED and roughly the |
| 174 | +# media bitrate. What this refuses is growth far beyond it -- logs, temp files, |
| 175 | +# or a recording nothing rotates. The bound is generous: the source is 3000k |
| 176 | +# video plus 128k audio, so about 23 MB a minute per destination. |
| 177 | +BUDGET=$(awk -v m="${DUR_MINUTES:-1}" -v d="${DUR_DESTS_WANTED:-1}" 'BEGIN{printf "%d", m*d*23*1024*2}') |
| 178 | +GROWTH="${DUR_DATA_GROWTH_KB:-0}" |
| 179 | +if [[ "$GROWTH" -le "$BUDGET" ]]; then |
| 180 | + ok "data directory grew ${GROWTH} kB, within the ${BUDGET} kB media budget" |
| 181 | +else |
| 182 | + bad "data directory grew ${GROWTH} kB, past the ${BUDGET} kB media budget" |
| 183 | + note "That is more than twice the media the destinations should have" |
| 184 | + note "written, so something else on disk is growing with wall time." |
| 185 | +fi |
| 186 | + |
| 187 | +# ------------------------------------------------------------ 7. still up |
| 188 | +step "7. Everything was still running at the end" |
| 189 | +if [[ "${DUR_DESTS_UP_END:-0}" == "${DUR_DESTS_WANTED:-1}" ]]; then |
| 190 | + ok "all ${DUR_DESTS_WANTED:-?} destination(s) were running at the end" |
| 191 | +else |
| 192 | + bad "${DUR_DESTS_UP_END:-0} of ${DUR_DESTS_WANTED:-?} destination(s) running at the end" |
| 193 | +fi |
| 194 | + |
| 195 | +step "Summary" |
| 196 | +printf " %d passed, %d failed (%s minutes, %s samples)\n\n" \ |
| 197 | + "$pass" "$fail" "${DUR_MINUTES:-?}" "${DUR_SAMPLES:-?}" |
| 198 | +[[ "$fail" -eq 0 ]] || exit 1 |
0 commit comments