diff --git a/bin/fm-telemetry.sh b/bin/fm-telemetry.sh new file mode 100755 index 00000000000..2628340f5e0 --- /dev/null +++ b/bin/fm-telemetry.sh @@ -0,0 +1,679 @@ +#!/usr/bin/env bash +# fm-telemetry.sh - durable, low-overhead host resource snapshots. +# +# Usage: +# fm-telemetry.sh arm +# fm-telemetry.sh disarm +# fm-telemetry.sh status +# fm-telemetry.sh record [owner-token] internal detached recorder mode +# fm-telemetry.sh fsync internal durable-flush helper +# +# The recorder writes append-only daily logs under state/telemetry/. +# Each bounded snapshot contains macOS memory pressure, VM and swap summaries, +# one process-table sample reused for RSS/CPU rankings and parent/PGID counts, +# and root-volume free space. +# After every append the log and its containing directory are flushed with +# fsync(2) plus Darwin's F_FULLFSYNC, so a forced power-cycle loses at most +# the final interval even when that append created the day's log. +# Oldest daily logs are pruned until their total size is no more than +# FM_TELEMETRY_MAX_BYTES (default 209715200, or 200 MiB). +# +# `arm` is idempotent and starts one detached recorder per FM_HOME. +# The lock is one symlink whose target carries the PID, the cadence and a +# unique launch token, so it is published in a single atomic step and is never +# observable half-initialized; stale PID reuse is not trusted by status or +# disarm. +# Every lock reclaim-and-republish sequence is serialized by a guard symlink +# naming its holder, so a stale lock can never be retired on top of a fresh one. +# A guard is only ever reclaimed once its holder is gone from the process table, +# never on a timeout, so a slow holder blocks lock changes instead of losing the +# guard; `arm` and `disarm` then report that they could not reclaim the lock. +# `disarm` sends TERM and waits for the recorder's trap to release that lock. +# `arm` proves the durable-flush helper works before it detaches, and the +# detached recorder's diagnostics are appended to state/telemetry/recorder.err, +# which the loop trims back to its last 32 KiB whenever it exceeds 64 KiB. +# Every diagnostic carries a UTC timestamp and `status` reports the newest one +# with its age; losing the start-up race is reported on stdout instead, so it +# never lands in that stream. +# Nothing auto-arms this tool and it never installs a launch agent. +# +# FM_TELEMETRY_INTERVAL controls the cadence in whole seconds from 15 through +# 30 (default 20). +# FM_HOME and FM_STATE_OVERRIDE select the home and state root normally used by +# Firstmate scripts. +# FM_TELEMETRY_PYTHON selects the interpreter used for the durable flush +# (default /usr/bin/python3). +# FM_TELEMETRY_RECORD_ONCE=1 is a test seam that makes internal record mode take +# one snapshot and exit. +# Internal record mode without an owner token re-execs itself with a synthesized +# one, so every recorder carries its token in argv and status and disarm have a +# single liveness rule. +# +# Steady-state overhead is one sleeping Bash process. +# Each tick launches samplers sequentially, never recursively or on overlapping +# schedules, reuses one `ps` result for every process-derived section, and +# adds one short-lived interpreter process for the durable flush. +set -u +export LC_ALL=C + +SCRIPT_DIR="$(cd "$(dirname "${BASH_SOURCE[0]}")" && pwd)" +SCRIPT_PATH="$SCRIPT_DIR/$(basename "${BASH_SOURCE[0]}")" +FM_HOME="${FM_HOME:-${FM_ROOT_OVERRIDE:-$(cd "$SCRIPT_DIR/.." && pwd)}}" +STATE="${FM_STATE_OVERRIDE:-$FM_HOME/state}" +TELEMETRY_DIR="$STATE/telemetry" +LOCK_LINK="$TELEMETRY_DIR/.record.lock" +GUARD_LINK="$TELEMETRY_DIR/.record.guard" +DIAGNOSTICS_LOG="$TELEMETRY_DIR/recorder.err" +INTERVAL=${FM_TELEMETRY_INTERVAL:-20} +MAX_BYTES=${FM_TELEMETRY_MAX_BYTES:-209715200} +FSYNC_PYTHON="${FM_TELEMETRY_PYTHON:-/usr/bin/python3}" +TOP_COUNT=15 +DIAGNOSTICS_MAX_BYTES=65536 +SNAPSHOT_SCHEMA=fm-telemetry-v1 +SNAPSHOT_TMP= +SAMPLE_TMP= +PROCESS_TMP= +OWNER_TOKEN= +GUARD_TOKEN= + +usage() { + cat <<'EOF' +Usage: + fm-telemetry.sh arm start one detached recorder for this FM_HOME + fm-telemetry.sh disarm stop this home's recorder cleanly + fm-telemetry.sh status report running state and newest snapshot age + +Configuration: + FM_TELEMETRY_INTERVAL seconds between snapshots (15..30, default 20) + FM_TELEMETRY_MAX_BYTES total daily-log cap (default 209715200) + FM_HOME Firstmate home (defaults to this repository) + +This command never auto-arms itself or installs a launch agent. +EOF +} + +diagnostic_stamp() { + date -u '+%Y-%m-%dT%H:%M:%SZ' 2>/dev/null || printf 'unknown' +} + +diagnostic() { + printf 'fm-telemetry: %s %s\n' "$(diagnostic_stamp)" "$1" >&2 +} + +fail() { + diagnostic "$1" + exit 1 +} + +validate_configuration() { + case "$INTERVAL" in + ''|*[!0-9]*) fail "FM_TELEMETRY_INTERVAL must be a whole number from 15 to 30" ;; + esac + if [ "$INTERVAL" -lt 15 ] || [ "$INTERVAL" -gt 30 ]; then + fail "FM_TELEMETRY_INTERVAL must be a whole number from 15 to 30" + fi + case "$MAX_BYTES" in + ''|*[!0-9]*|0) fail "FM_TELEMETRY_MAX_BYTES must be a positive whole number" ;; + esac +} + +lock_exists() { + [ -L "$LOCK_LINK" ] || [ -e "$LOCK_LINK" ] +} + +read_lock_owner() { + local target rest + LOCK_PID= + LOCK_TOKEN= + LOCK_INTERVAL=unknown + target=$(readlink "$LOCK_LINK" 2>/dev/null) || return 1 + LOCK_PID=${target%%:*} + rest=${target#*:} + LOCK_INTERVAL=${rest%%:*} + LOCK_TOKEN=${rest#*:} + [ -n "$LOCK_INTERVAL" ] || LOCK_INTERVAL=unknown +} + +lock_owner_is_live() { + local command_line + read_lock_owner || return 1 + case "$LOCK_PID" in + ''|*[!0-9]*) return 1 ;; + esac + [ -n "$LOCK_TOKEN" ] || return 1 + kill -0 "$LOCK_PID" 2>/dev/null || return 1 + command_line=$(ps -p "$LOCK_PID" -o command= 2>/dev/null) || return 1 + case "$command_line" in + *fm-telemetry.sh*record*"$LOCK_TOKEN"*) return 0 ;; + *) return 1 ;; + esac +} + +remove_stale_lock() { + local observed + lock_exists || return 0 + if ! observed=$(readlink "$LOCK_LINK" 2>/dev/null); then + rm -rf "$LOCK_LINK" 2>/dev/null || return 1 + return 0 + fi + [ "$observed" = "$(readlink "$LOCK_LINK" 2>/dev/null)" ] || return 1 + rm -f "$LOCK_LINK" 2>/dev/null || return 1 +} + +guard_owner_is_live() { + local target pid command_line + target=$(readlink "$GUARD_LINK" 2>/dev/null) || return 1 + pid=${target%%:*} + case "$pid" in + ''|*[!0-9]*) return 1 ;; + esac + kill -0 "$pid" 2>/dev/null || return 1 + command_line=$(ps -p "$pid" -o command= 2>/dev/null) || return 1 + case "$command_line" in + *fm-telemetry.sh*) return 0 ;; + *) return 1 ;; + esac +} + +guard_acquire() { + local tries=0 observed + GUARD_TOKEN="$$:guard-$(date '+%s')-$RANDOM" + while [ "$tries" -lt 200 ]; do + tries=$((tries + 1)) + if ln -s "$GUARD_TOKEN" "$GUARD_LINK" 2>/dev/null; then + return 0 + fi + if guard_owner_is_live; then + sleep 0.05 + continue + fi + if ! observed=$(readlink "$GUARD_LINK" 2>/dev/null); then + [ -e "$GUARD_LINK" ] && rm -rf "$GUARD_LINK" 2>/dev/null + continue + fi + [ "$observed" = "$(readlink "$GUARD_LINK" 2>/dev/null)" ] || continue + rm -f "$GUARD_LINK" 2>/dev/null || true + done + GUARD_TOKEN= + return 1 +} + +guard_release() { + local target + [ -n "$GUARD_TOKEN" ] || return 0 + if target=$(readlink "$GUARD_LINK" 2>/dev/null) && [ "$target" = "$GUARD_TOKEN" ]; then + rm -f "$GUARD_LINK" 2>/dev/null || true + fi + GUARD_TOKEN= +} + +acquire_lock() { + local attempt=0 + while [ "$attempt" -lt 2 ]; do + if ln -s "$$:$INTERVAL:$OWNER_TOKEN" "$LOCK_LINK" 2>/dev/null; then + return 0 + fi + lock_owner_is_live && return 2 + remove_stale_lock || return 1 + attempt=$((attempt + 1)) + done + return 1 +} + +guarded_acquire_lock() { + local rc + guard_acquire || return 1 + acquire_lock + rc=$? + guard_release + return "$rc" +} + +guarded_remove_stale_lock() { + local rc + guard_acquire || return 1 + if lock_owner_is_live; then + guard_release + return 2 + fi + remove_stale_lock + rc=$? + guard_release + return "$rc" +} + +owns_lock() { + read_lock_owner || return 1 + [ "$LOCK_PID" = "$$" ] && [ "$LOCK_TOKEN" = "$OWNER_TOKEN" ] +} + +release_lock() { + owns_lock || return 0 + rm -f "$LOCK_LINK" 2>/dev/null || true +} + +cleanup_snapshot_temps() { + [ -n "$SNAPSHOT_TMP" ] && rm -f "$SNAPSHOT_TMP" + [ -n "$SAMPLE_TMP" ] && rm -f "$SAMPLE_TMP" + [ -n "$PROCESS_TMP" ] && rm -f "$PROCESS_TMP" + SNAPSHOT_TMP= + SAMPLE_TMP= + PROCESS_TMP= +} + +cleanup_record() { + cleanup_snapshot_temps + guard_release + release_lock +} + +capture_bounded() { + local label=$1 lines=$2 command_name=$3 + shift 3 + printf '%s\n' "$label" >> "$SNAPSHOT_TMP" + if ! command -v "$command_name" >/dev/null 2>&1; then + printf 'unavailable: %s not found\n' "$command_name" >> "$SNAPSHOT_TMP" + return 0 + fi + if "$command_name" "$@" > "$SAMPLE_TMP" 2>&1; then + sed -n "1,${lines}p" "$SAMPLE_TMP" >> "$SNAPSHOT_TMP" + else + printf 'sampler_failed: %s\n' "$command_name" >> "$SNAPSHOT_TMP" + sed -n "1,${lines}p" "$SAMPLE_TMP" >> "$SNAPSHOT_TMP" + fi +} + +# Emit at most TOP_COUNT leading lines while still draining stdin, so the +# upstream `sort` never takes SIGPIPE and never writes a broken-pipe +# diagnostic into the recorder's error stream. +take_top() { + awk -v limit="$TOP_COUNT" 'NR <= limit { print }' +} + +capture_processes() { + printf 'PROCESS_TABLE\n' >> "$SNAPSHOT_TMP" + if ! command -v ps >/dev/null 2>&1 || + ! ps -axo pid=,ppid=,pgid=,%cpu=,rss=,etime=,comm= > "$PROCESS_TMP" 2> "$SAMPLE_TMP"; then + printf 'sampler_failed: ps\n' >> "$SNAPSHOT_TMP" + sed -n '1,5p' "$SAMPLE_TMP" >> "$SNAPSHOT_TMP" + return 0 + fi + + { + awk 'NF { count++ } END { print "PROCESS_TOTAL " count + 0 }' "$PROCESS_TMP" + printf 'TOP_RSS_KIB pid ppid pgid cpu rss_kib etime command\n' + sort -k5,5nr -k1,1n "$PROCESS_TMP" | take_top + printf 'TOP_CPU_PERCENT pid ppid pgid cpu rss_kib etime command\n' + sort -k4,4nr -k1,1n "$PROCESS_TMP" | take_top + printf 'PROCESS_COUNTS_BY_PARENT count ppid\n' + awk 'NF { count[$2]++ } END { for (id in count) print count[id], id }' "$PROCESS_TMP" \ + | sort -k1,1nr -k2,2n | take_top + printf 'PROCESS_COUNTS_BY_PGID_COALITION_APPROX count pgid\n' + awk 'NF { count[$3]++ } END { for (id in count) print count[id], id }' "$PROCESS_TMP" \ + | sort -k1,1nr -k2,2n | take_top + } >> "$SNAPSHOT_TMP" +} + +fsync_file() { + local target=${1:-} + if [ -z "$target" ] || [ ! -f "$target" ]; then + diagnostic "fsync target ${target:-} is not a file" + return 1 + fi + "$FSYNC_PYTHON" - "$target" <<'FSYNC_PY' +import errno +import fcntl +import os +import sys + +F_FULLFSYNC = 51 + +def flush(fd, label): + os.fsync(fd) + if sys.platform != "darwin": + return + try: + fcntl.fcntl(fd, F_FULLFSYNC) + except OSError as exc: + if exc.errno not in (errno.ENOTSUP, errno.ENOTTY, errno.EINVAL): + raise + sys.stderr.write("fm-telemetry: F_FULLFSYNC unsupported for %s\n" % label) + + +path = sys.argv[1] +parent = os.path.dirname(path) or "." + +fd = os.open(path, os.O_WRONLY | os.O_APPEND) +try: + flush(fd, path) +finally: + os.close(fd) + +dfd = os.open(parent, os.O_RDONLY) +try: + flush(dfd, parent) +finally: + os.close(dfd) +FSYNC_PY +} + +probe_durability() { + local probe + probe=$(mktemp "$TELEMETRY_DIR/.durability.XXXXXX") || return 1 + printf 'durability-probe\n' > "$probe" || { + rm -f "$probe" + return 1 + } + if ! fsync_file "$probe"; then + rm -f "$probe" + return 1 + fi + rm -f "$probe" +} + +trim_diagnostics() { + local bytes tmp + [ -f "$DIAGNOSTICS_LOG" ] || return 0 + bytes=$(wc -c < "$DIAGNOSTICS_LOG" 2>/dev/null) || return 0 + [ "$bytes" -gt "$DIAGNOSTICS_MAX_BYTES" ] || return 0 + tmp=$(mktemp "$TELEMETRY_DIR/.diagnostics.XXXXXX") || return 1 + if ! tail -c "$((DIAGNOSTICS_MAX_BYTES / 2))" "$DIAGNOSTICS_LOG" > "$tmp" 2>/dev/null || + ! cat "$tmp" > "$DIAGNOSTICS_LOG" 2>/dev/null; then + rm -f "$tmp" + return 1 + fi + rm -f "$tmp" +} + +newest_diagnostic() { + [ -s "$DIAGNOSTICS_LOG" ] || return 1 + tail -n 1 "$DIAGNOSTICS_LOG" 2>/dev/null +} + +append_snapshot() { + local timestamp epoch day utc_offset log_file + timestamp=$(date -u '+%Y-%m-%dT%H:%M:%SZ') || return 1 + epoch=$(date '+%s') || return 1 + day=$(date -u '+%Y-%m-%d') || return 1 + utc_offset=$(date '+%z') || return 1 + log_file="$TELEMETRY_DIR/telemetry-$day.log" + SNAPSHOT_TMP=$(mktemp "$TELEMETRY_DIR/.snapshot.XXXXXX") || { + cleanup_snapshot_temps + return 1 + } + SAMPLE_TMP=$(mktemp "$TELEMETRY_DIR/.sample.XXXXXX") || { + cleanup_snapshot_temps + return 1 + } + PROCESS_TMP=$(mktemp "$TELEMETRY_DIR/.processes.XXXXXX") || { + cleanup_snapshot_temps + return 1 + } + + printf 'SNAPSHOT_BEGIN schema=%s timestamp=%s epoch=%s local_utc_offset=%s recorder_pid=%s\n' \ + "$SNAPSHOT_SCHEMA" "$timestamp" "$epoch" "$utc_offset" "$$" > "$SNAPSHOT_TMP" + capture_bounded MEMORY_PRESSURE 20 memory_pressure -Q + capture_bounded VM_STAT 80 vm_stat + capture_bounded SWAP_USAGE 10 sysctl vm.swapusage + capture_processes + capture_bounded DISK_FREE_KIB 10 df -k / + printf 'SNAPSHOT_END timestamp=%s\n\n' "$timestamp" >> "$SNAPSHOT_TMP" + + if ! cat "$SNAPSHOT_TMP" >> "$log_file"; then + cleanup_snapshot_temps + return 1 + fi + if ! fsync_file "$log_file"; then + diagnostic "durability flush failed for $log_file" + cleanup_snapshot_temps + return 1 + fi + cleanup_snapshot_temps +} + +daily_log_bytes() { + local file total=0 bytes + for file in "$TELEMETRY_DIR"/telemetry-*.log; do + [ -f "$file" ] || continue + bytes=$(wc -c < "$file") || return 1 + total=$((total + bytes)) + done + printf '%s\n' "$total" +} + +prune_daily_logs() { + local total file removed current_log + total=$(daily_log_bytes) || return 1 + current_log="telemetry-$(date -u '+%Y-%m-%d').log" + while [ "$total" -gt "$MAX_BYTES" ]; do + removed=0 + for file in "$TELEMETRY_DIR"/telemetry-*.log; do + [ -f "$file" ] || continue + if [ "${file##*/}" = "$current_log" ]; then + continue + fi + rm -f "$file" || return 1 + removed=1 + break + done + [ "$removed" -eq 1 ] || break + total=$(daily_log_bytes) || return 1 + done +} + +record() { + local tick_rc token + validate_configuration + mkdir -p "$TELEMETRY_DIR" || fail "could not create $TELEMETRY_DIR" + if [ -z "${1:-}" ]; then + token="manual-$(date '+%s')-$$" + exec "$SCRIPT_PATH" record "$token" + fi + OWNER_TOKEN=$1 + guarded_acquire_lock + case $? in + 0) ;; + 2) + printf 'fm-telemetry: recorder already running\n' + exit 1 + ;; + *) fail "could not acquire $LOCK_LINK" ;; + esac + trap 'cleanup_record; exit 0' TERM INT + trap cleanup_record EXIT + + while :; do + if ! owns_lock; then + diagnostic 'lock owner changed, standing down' + return 0 + fi + if ! trim_diagnostics; then + diagnostic "could not trim $DIAGNOSTICS_LOG" + fi + tick_rc=0 + if ! append_snapshot; then + diagnostic 'snapshot failed' + tick_rc=1 + fi + if ! prune_daily_logs; then + diagnostic 'rotation failed' + tick_rc=1 + fi + if [ "${FM_TELEMETRY_RECORD_ONCE:-0}" = 1 ]; then + return "$tick_rc" + fi + sleep "$INTERVAL" & + wait "$!" || break + done +} + +arm() { + local token child_pid tries=0 child_alive=1 + validate_configuration + mkdir -p "$TELEMETRY_DIR" || fail "could not create $TELEMETRY_DIR" + if lock_owner_is_live; then + printf 'fm-telemetry: already running pid=%s interval=%ss\n' "$LOCK_PID" "$LOCK_INTERVAL" + return 0 + fi + if lock_exists; then + guarded_remove_stale_lock + case $? in + 0) ;; + 2) + printf 'fm-telemetry: already running pid=%s interval=%ss\n' "$LOCK_PID" "$LOCK_INTERVAL" + return 0 + ;; + *) fail "could not remove stale lock $LOCK_LINK" ;; + esac + fi + probe_durability || + fail "durable-flush helper $FSYNC_PYTHON failed; set FM_TELEMETRY_PYTHON to a working interpreter" + token="fmtelemetry-$(date '+%s')-$$" + nohup "$SCRIPT_PATH" record "$token" /dev/null 2>>"$DIAGNOSTICS_LOG" & + child_pid=$! + while [ "$tries" -lt 30 ]; do + if lock_owner_is_live; then + printf 'fm-telemetry: running pid=%s interval=%ss directory=%s\n' \ + "$LOCK_PID" "$LOCK_INTERVAL" "$TELEMETRY_DIR" + return 0 + fi + if ! kill -0 "$child_pid" 2>/dev/null; then + child_alive=0 + break + fi + sleep 0.1 + tries=$((tries + 1)) + done + if [ "$child_alive" -eq 0 ]; then + wait "$child_pid" 2>/dev/null || true + else + read_lock_owner || true + if [ "$LOCK_PID" = "$child_pid" ]; then + printf 'fm-telemetry: running pid=%s interval=%ss directory=%s\n' \ + "$LOCK_PID" "$LOCK_INTERVAL" "$TELEMETRY_DIR" + return 0 + fi + kill -TERM "$child_pid" 2>/dev/null || true + tries=0 + while kill -0 "$child_pid" 2>/dev/null && [ "$tries" -lt 30 ]; do + sleep 0.1 + tries=$((tries + 1)) + done + fi + if lock_owner_is_live; then + printf 'fm-telemetry: already running pid=%s interval=%ss\n' "$LOCK_PID" "$LOCK_INTERVAL" + return 0 + fi + fail "recorder did not acquire its lock" +} + +disarm() { + local pid tries=0 + mkdir -p "$TELEMETRY_DIR" || fail "could not create $TELEMETRY_DIR" + if ! lock_owner_is_live; then + if lock_exists; then + guarded_remove_stale_lock + case $? in + 0|2) ;; + *) fail "could not remove stale lock $LOCK_LINK" ;; + esac + fi + printf 'fm-telemetry: not running\n' + return 0 + fi + pid=$LOCK_PID + kill -TERM "$pid" 2>/dev/null || fail "could not signal recorder pid $pid" + while kill -0 "$pid" 2>/dev/null && [ "$tries" -lt 50 ]; do + sleep 0.1 + tries=$((tries + 1)) + done + if kill -0 "$pid" 2>/dev/null; then + fail "recorder pid $pid did not stop cleanly" + fi + if lock_exists; then + guarded_remove_stale_lock + case $? in + 0|2) ;; + *) fail "could not retire $LOCK_LINK" ;; + esac + fi + printf 'fm-telemetry: stopped pid=%s\n' "$pid" +} + +# Portable mtime; Linux stat lacks -f (it means --file-system there), macOS stat lacks -c. +file_mtime() { + if [ "$(uname 2>/dev/null || true)" = Darwin ]; then + stat -f %m "$1" 2>/dev/null + else + stat -c %Y "$1" 2>/dev/null + fi +} + +newest_snapshot_age() { + local newest newest_mtime file mtime now + newest= + newest_mtime=0 + for file in "$TELEMETRY_DIR"/telemetry-*.log; do + [ -f "$file" ] || continue + mtime=$(file_mtime "$file") || continue + case "$mtime" in + '' | *[!0-9]*) continue ;; + esac + if [ "$mtime" -gt "$newest_mtime" ]; then + newest=$file + newest_mtime=$mtime + fi + done + [ -n "$newest" ] || { + printf 'none' + return 0 + } + now=$(date '+%s') || { + printf 'unknown' + return 0 + } + printf '%ss' "$((now - newest_mtime))" +} + +diagnostic_age() { + local stamp=$1 epoch now + epoch=$(date -u -j -f '%Y-%m-%dT%H:%M:%SZ' "$stamp" '+%s' 2>/dev/null) || + epoch=$(date -u -d "$stamp" '+%s' 2>/dev/null) || return 1 + now=$(date '+%s') || return 1 + printf '%ss\n' "$((now - epoch))" +} + +report_diagnostics() { + local newest stamp age + newest=$(newest_diagnostic) || return 0 + stamp=${newest#fm-telemetry: } + stamp=${stamp%% *} + age=$(diagnostic_age "$stamp") || age=unknown + printf 'fm-telemetry: newest diagnostic (age %s) in %s: %s\n' \ + "$age" "$DIAGNOSTICS_LOG" "$newest" +} + +status() { + local age rc + age=$(newest_snapshot_age) + if lock_owner_is_live; then + printf 'fm-telemetry: running pid=%s interval=%ss newest_snapshot_age=%s directory=%s\n' \ + "$LOCK_PID" "$LOCK_INTERVAL" "$age" "$TELEMETRY_DIR" + rc=0 + else + printf 'fm-telemetry: not running newest_snapshot_age=%s directory=%s\n' "$age" "$TELEMETRY_DIR" + rc=1 + fi + report_diagnostics + return "$rc" +} + +case "${1:-}" in + arm) arm ;; + disarm) disarm ;; + status) status ;; + record) shift; record "${1:-}" ;; + fsync) shift; fsync_file "${1:-}" ;; + -h|--help|help) usage ;; + *) usage >&2; exit 2 ;; +esac diff --git a/docs/scripts.md b/docs/scripts.md index 9f219592d79..ead852c5438 100644 --- a/docs/scripts.md +++ b/docs/scripts.md @@ -104,6 +104,7 @@ The shared no-mistakes gate refusal for fleet lifecycle entrypoints is summarize | `fm-check-register.sh` | Bind an intentional custom watcher check to its current bytes | | `fm-check-lib.sh` | Validate custom-check registrations and prepare private execution snapshots | | `fm-tool-update-check.sh` | Report watched tooling with an update available, and updates installed but left inert by PATH order | +| `fm-telemetry.sh` | Arm, disarm, or report the never-auto-armed detached host resource-snapshot recorder that keeps durable pruned daily logs under `state/telemetry/` | | `fm-pr-lib.sh` | Own canonical task and PR validation plus private atomic PR-poll publication and identity-bound retirement | | `fm-pr-poll.sh` | Provide the byte-static watcher program for validated PR/MR-poll sidecars | | `fm-pr-check-migrate.sh` | Quarantine older task polls without execution and rebuild only canonical polls | diff --git a/tests/fm-telemetry.test.sh b/tests/fm-telemetry.test.sh new file mode 100755 index 00000000000..cba5cad0c1d --- /dev/null +++ b/tests/fm-telemetry.test.sh @@ -0,0 +1,611 @@ +#!/usr/bin/env bash +# tests/fm-telemetry.test.sh - public recorder, rotation, durability, and +# singleton behavior. +set -u + +# shellcheck source=tests/lib.sh +. "$(dirname "${BASH_SOURCE[0]}")/lib.sh" + +TELEMETRY="$ROOT/bin/fm-telemetry.sh" +TMP_ROOT=$(fm_test_tmproot fm-telemetry-tests) +DAEMON_HOME= + +cleanup_telemetry_test() { + if [ -n "$DAEMON_HOME" ] && [ -x "$TELEMETRY" ]; then + FM_HOME="$DAEMON_HOME" "$TELEMETRY" disarm >/dev/null 2>&1 || true + fi + fm_test_cleanup +} +trap cleanup_telemetry_test EXIT +trap 'cleanup_telemetry_test; exit 130' INT +trap 'cleanup_telemetry_test; exit 143' TERM + +write_fake_samplers() { + local fakebin=$1 + mkdir -p "$fakebin" + cat > "$fakebin/memory_pressure" <<'SH' +#!/usr/bin/env bash +[ "${1:-}" = -Q ] || { + printf 'expected summary-only -Q mode\n' >&2 + exit 1 +} +printf 'System-wide memory free percentage: 42%%\n' +SH + cat > "$fakebin/vm_stat" <<'SH' +#!/usr/bin/env bash +printf 'Mach Virtual Memory Statistics: (page size of 16384 bytes)\nPages free: 123.\n' +SH + cat > "$fakebin/sysctl" <<'SH' +#!/usr/bin/env bash +printf 'vm.swapusage: total = 4096.00M used = 1024.00M free = 3072.00M\n' +SH + cat > "$fakebin/ps" <<'SH' +#!/usr/bin/env bash +cat <<'OUT' +101 1 101 7.5 9000 01:00 alpha +102 1 102 1.5 3000 00:30 beta +103 101 101 0.5 5000 00:10 gamma +OUT +SH + cat > "$fakebin/df" <<'SH' +#!/usr/bin/env bash +printf 'Filesystem 1024-blocks Used Available Capacity Mounted on\n/dev/fake 100000 25000 75000 25%% /\n' +SH + cat > "$fakebin/failing-python" <<'SH' +#!/usr/bin/env bash +printf 'fake interpreter refuses to flush\n' >&2 +exit 1 +SH + chmod +x "$fakebin"/* +} + +record_once() { + local home=$1 fakebin=$2 + FM_HOME="$home" FM_TELEMETRY_RECORD_ONCE=1 \ + PATH="$fakebin:/usr/bin:/bin" \ + "$TELEMETRY" record +} + +recorder_pids() { + pgrep -f 'fm-telemetry.sh record' 2>/dev/null | sort || true +} + +# Runs a command in the background and fails the test if it has not returned +# within , so a hang is reported instead of wedging the suite. +run_bounded() { + local label=$1 limit=$2 rc_file=$3 out_file=$4 + shift 4 + ( "$@" > "$out_file" 2>&1; printf '%s\n' "$?" > "$rc_file" ) & + local runner=$! tries=0 + while kill -0 "$runner" 2>/dev/null && [ "$tries" -lt "$limit" ]; do + sleep 0.1 + tries=$((tries + 1)) + done + if kill -0 "$runner" 2>/dev/null; then + kill -KILL "$runner" 2>/dev/null || true + wait "$runner" 2>/dev/null || true + fail "$label did not return within $((limit / 10))s" + fi + wait "$runner" 2>/dev/null || true +} + +write_guard_holder() { + local dir=$1 + mkdir -p "$dir" + cat > "$dir/fm-telemetry.sh" <<'SH' +#!/usr/bin/env bash +sleep "${1:-60}" +SH + chmod +x "$dir/fm-telemetry.sh" +} + +dead_pid() { + local pid + sleep 0 & + pid=$! + wait "$pid" 2>/dev/null || true + printf '%s\n' "$pid" +} + +test_record_writes_parseable_durable_snapshot() { + local home fakebin log expected_day offset + home="$TMP_ROOT/record-home" + fakebin="$TMP_ROOT/record-fakebin" + mkdir -p "$home/state" + write_fake_samplers "$fakebin" + + expected_day=$(date -u '+%Y-%m-%d') + offset=$(date '+%z') + record_once "$home" "$fakebin" || fail "record mode failed" + log="$home/state/telemetry/telemetry-$expected_day.log" + [ -f "$log" ] || fail "record mode did not key its daily log on the UTC date" + assert_contains "$(cat "$log")" 'SNAPSHOT_BEGIN schema=fm-telemetry-v1' "snapshot begin marker is missing" + assert_contains "$(cat "$log")" "local_utc_offset=$offset" "snapshot did not record the local UTC offset" + assert_contains "$(cat "$log")" 'MEMORY_PRESSURE' "memory-pressure section is missing" + assert_contains "$(cat "$log")" 'System-wide memory free percentage: 42%' "memory-pressure summary mode was not captured" + assert_contains "$(cat "$log")" 'vm.swapusage: total = 4096.00M' "swap sampler output is missing" + assert_contains "$(cat "$log")" 'PROCESS_TOTAL 3' "process total was not derived from the sampled table" + assert_contains "$(cat "$log")" 'TOP_RSS_KIB' "RSS ranking is missing" + assert_contains "$(cat "$log")" 'TOP_CPU_PERCENT' "CPU ranking is missing" + assert_contains "$(cat "$log")" 'PROCESS_COUNTS_BY_PARENT' "per-parent counts are missing" + assert_contains "$(cat "$log")" 'PROCESS_COUNTS_BY_PGID_COALITION_APPROX' "coalition approximation is missing" + assert_contains "$(cat "$log")" 'SNAPSHOT_END' "snapshot end marker is missing" + case "$(FM_HOME="$home" PATH="$fakebin:/usr/bin:/bin" "$TELEMETRY" status 2>&1)" in + *'not running newest_snapshot_age='[0-9]*s*) ;; + *) fail "status did not report the newest completed snapshot age" ;; + esac + [ ! -e "$home/state/telemetry/.record.lock" ] && [ ! -L "$home/state/telemetry/.record.lock" ] || + fail "one-shot record left its lock behind" + pass "record writes one bounded, parseable snapshot dated in UTC and releases its lock" +} + +test_fsync_helper_flushes_the_named_file() { + local home out rc + home="$TMP_ROOT/fsync-home" + mkdir -p "$home" + printf 'durable payload\n' > "$home/telemetry.log" + + FM_HOME="$home" "$TELEMETRY" fsync "$home/telemetry.log" || + fail "durable flush helper failed on a real file" + [ "$(cat "$home/telemetry.log")" = 'durable payload' ] || + fail "durable flush helper altered the file it flushed" + + out=$(FM_HOME="$home" "$TELEMETRY" fsync "$home/absent.log" 2>&1) + rc=$? + [ "$rc" -ne 0 ] || fail "durable flush helper accepted a missing target" + assert_contains "$out" 'is not a file' "durable flush helper did not identify the bad target" + + out=$(FM_HOME="$home" "$TELEMETRY" fsync "$home" 2>&1) + rc=$? + [ "$rc" -ne 0 ] || fail "durable flush helper accepted a directory target" + pass "the durable flush helper flushes real files and rejects non-files" +} + +test_record_surfaces_durability_failure() { + local home fakebin out rc + home="$TMP_ROOT/sync-failure-home" + fakebin="$TMP_ROOT/sync-failure-fakebin" + mkdir -p "$home/state" + write_fake_samplers "$fakebin" + + out=$(FM_HOME="$home" FM_TELEMETRY_RECORD_ONCE=1 \ + FM_TELEMETRY_PYTHON="$fakebin/failing-python" \ + PATH="$fakebin:/usr/bin:/bin" "$TELEMETRY" record 2>&1) + rc=$? + [ "$rc" -ne 0 ] || fail "one-shot record hid a failed durability flush" + assert_contains "$out" 'durability flush failed' "one-shot record did not identify the durability failure" + [ ! -e "$home/state/telemetry/.record.lock" ] && [ ! -L "$home/state/telemetry/.record.lock" ] || + fail "failed one-shot record left its lock behind" + pass "one-shot record returns failure when its durability flush fails" +} + +test_record_cleans_up_after_partial_temp_failure() { + local home fakebin telemetry leftovers pid tries + home="$TMP_ROOT/tempfail-home" + fakebin="$TMP_ROOT/tempfail-fakebin" + telemetry="$home/state/telemetry" + mkdir -p "$telemetry" + write_fake_samplers "$fakebin" + cat > "$fakebin/mktemp" <<'SH' +#!/usr/bin/env bash +case "${1:-}" in + *.sample.*) exit 1 ;; +esac +exec /usr/bin/mktemp "$@" +SH + chmod +x "$fakebin/mktemp" + + # The leak is only observable while the loop lives: a one-shot run's EXIT trap + # would sweep the orphan that a long-running recorder abandons every tick. + FM_HOME="$home" FM_TELEMETRY_INTERVAL=15 PATH="$fakebin:/usr/bin:/bin" \ + "$TELEMETRY" record "fmtelemetry-tempfail-$$" >/dev/null 2>"$home/record.err" & + pid=$! + tries=0 + while [ "$tries" -lt 100 ]; do + grep -q 'snapshot failed' "$home/record.err" 2>/dev/null && break + sleep 0.1 + tries=$((tries + 1)) + done + grep -q 'snapshot failed' "$home/record.err" 2>/dev/null || + fail "recorder did not report the failed temp-file allocation" + leftovers=$(find "$telemetry" \( -name '.snapshot.*' -o -name '.processes.*' -o -name '.sample.*' \) | wc -l) + kill -TERM "$pid" 2>/dev/null || true + wait "$pid" 2>/dev/null || true + + [ "$leftovers" -eq 0 ] || fail "recorder leaked $leftovers temp files outside the retention cap" + pass "the running recorder removes every temp file it created when a later allocation fails" +} + +test_interval_is_restricted_to_the_supported_cadence() { + local home fakebin out rc + home="$TMP_ROOT/interval-home" + fakebin="$TMP_ROOT/interval-fakebin" + mkdir -p "$home/state" + write_fake_samplers "$fakebin" + + out=$(FM_HOME="$home" FM_TELEMETRY_RECORD_ONCE=1 FM_TELEMETRY_INTERVAL=31 \ + PATH="$fakebin:/usr/bin:/bin" "$TELEMETRY" record 2>&1) + rc=$? + [ "$rc" -ne 0 ] || fail "record accepted a 31-second cadence" + assert_contains "$out" 'from 15 to 30' "record did not state the supported cadence range" + + FM_HOME="$home" FM_TELEMETRY_RECORD_ONCE=1 FM_TELEMETRY_INTERVAL=14 \ + PATH="$fakebin:/usr/bin:/bin" "$TELEMETRY" record >/dev/null 2>&1 && + fail "record accepted a 14-second cadence" + + FM_HOME="$home" FM_TELEMETRY_RECORD_ONCE=1 FM_TELEMETRY_INTERVAL=30 \ + PATH="$fakebin:/usr/bin:/bin" "$TELEMETRY" record >/dev/null 2>&1 || + fail "record rejected the supported 30-second cadence" + pass "record accepts only whole cadences from 15 through 30 seconds" +} + +test_rotation_prunes_oldest_daily_logs_to_cap() { + local home fakebin telemetry total + home="$TMP_ROOT/rotation-home" + fakebin="$TMP_ROOT/rotation-fakebin" + telemetry="$home/state/telemetry" + mkdir -p "$telemetry" + write_fake_samplers "$fakebin" + head -c 1200 /dev/zero | tr '\0' a > "$telemetry/telemetry-2026-01-01.log" + head -c 1200 /dev/zero | tr '\0' b > "$telemetry/telemetry-2026-01-02.log" + + FM_HOME="$home" FM_TELEMETRY_RECORD_ONCE=1 FM_TELEMETRY_MAX_BYTES=3000 \ + PATH="$fakebin:/usr/bin:/bin" "$TELEMETRY" record || fail "rotation record failed" + + assert_absent "$telemetry/telemetry-2026-01-01.log" "rotation did not prune the oldest daily log" + total=$(find "$telemetry" -name 'telemetry-*.log' -type f -exec wc -c {} + | awk 'END { print $1 + 0 }') + [ "$total" -le 3000 ] || fail "rotation retained $total bytes above the 3000-byte cap" + pass "rotation prunes oldest daily logs until total bytes are within the cap" +} + +test_arm_is_idempotent_and_disarm_stops_singleton() { + local home fakebin first_pid second_pid out tries + home="$TMP_ROOT/daemon-home" + fakebin="$TMP_ROOT/daemon-fakebin" + mkdir -p "$home/state" + write_fake_samplers "$fakebin" + rm -f "$fakebin/ps" + DAEMON_HOME=$home + + FM_HOME="$home" FM_TELEMETRY_INTERVAL=15 PATH="$fakebin:/usr/bin:/bin" \ + "$TELEMETRY" arm >/dev/null || fail "first arm failed" + tries=0 + while [ ! -L "$home/state/telemetry/.record.lock" ] && [ "$tries" -lt 50 ]; do + sleep 0.1 + tries=$((tries + 1)) + done + [ -L "$home/state/telemetry/.record.lock" ] || fail "arm did not publish its singleton owner" + first_pid=$(readlink "$home/state/telemetry/.record.lock") + first_pid=${first_pid%%:*} + + FM_HOME="$home" FM_TELEMETRY_INTERVAL=15 PATH="$fakebin:/usr/bin:/bin" \ + "$TELEMETRY" arm >/dev/null || fail "idempotent arm failed" + second_pid=$(readlink "$home/state/telemetry/.record.lock") + second_pid=${second_pid%%:*} + [ "$first_pid" = "$second_pid" ] || fail "second arm replaced the live recorder ($first_pid -> $second_pid)" + + out=$(FM_HOME="$home" PATH="$fakebin:/usr/bin:/bin" "$TELEMETRY" status) || fail "status did not report the live recorder" + assert_contains "$out" "running pid=$first_pid" "status did not identify the singleton owner" + assert_contains "$out" 'interval=15s' "status did not report the live recorder's configured cadence" + + FM_HOME="$home" PATH="$fakebin:/usr/bin:/bin" "$TELEMETRY" disarm >/dev/null || fail "disarm failed" + kill -0 "$first_pid" 2>/dev/null && fail "disarm left recorder pid $first_pid alive" + out=$(FM_HOME="$home" PATH="$fakebin:/usr/bin:/bin" "$TELEMETRY" status 2>&1) + assert_contains "$out" 'not running' "status did not report the stopped recorder" + DAEMON_HOME= + pass "arm is idempotent and disarm cleanly stops the one per-home recorder" +} + +test_fsync_helper_commits_the_containing_directory() { + local home out rc + home="$TMP_ROOT/dirsync-home" + mkdir -p "$home/logs" + printf 'durable payload\n' > "$home/logs/telemetry.log" + + FM_HOME="$home" "$TELEMETRY" fsync "$home/logs/telemetry.log" || + fail "durable flush helper failed on a real file" + + if [ "$(id -u)" -eq 0 ]; then + pass "the durable flush helper commits the file (directory check skipped as root)" + return 0 + fi + + chmod 0111 "$home/logs" + out=$(FM_HOME="$home" "$TELEMETRY" fsync "$home/logs/telemetry.log" 2>&1) + rc=$? + chmod 0755 "$home/logs" + [ "$rc" -ne 0 ] || + fail "durable flush helper reported success without committing the containing directory" + pass "the durable flush helper commits the log's containing directory too" +} + +test_tokenless_record_is_visible_to_status_and_disarm() { + local home fakebin pid tries out + home="$TMP_ROOT/tokenless-home" + fakebin="$TMP_ROOT/tokenless-fakebin" + mkdir -p "$home/state" + write_fake_samplers "$fakebin" + rm -f "$fakebin/ps" + DAEMON_HOME=$home + + FM_HOME="$home" FM_TELEMETRY_INTERVAL=30 PATH="$fakebin:/usr/bin:/bin" \ + "$TELEMETRY" record >/dev/null 2>&1 & + pid=$! + tries=0 + while [ ! -L "$home/state/telemetry/.record.lock" ] && [ "$tries" -lt 50 ]; do + sleep 0.1 + tries=$((tries + 1)) + done + [ -L "$home/state/telemetry/.record.lock" ] || fail "token-less record did not publish a lock" + + out=$(FM_HOME="$home" PATH="$fakebin:/usr/bin:/bin" "$TELEMETRY" status) || + fail "status reported a token-less recorder as not running" + assert_contains "$out" "running pid=$pid" "status did not identify the token-less recorder" + + out=$(FM_HOME="$home" PATH="$fakebin:/usr/bin:/bin" "$TELEMETRY" disarm) || + fail "disarm failed against a token-less recorder" + assert_contains "$out" "stopped pid=$pid" "disarm did not stop the token-less recorder" + kill -0 "$pid" 2>/dev/null && fail "disarm left token-less recorder pid $pid alive" + wait "$pid" 2>/dev/null || true + DAEMON_HOME= + pass "a token-less recorder is reported by status and stopped by disarm" +} + +test_arm_refuses_to_detach_without_a_working_durability_helper() { + local home fakebin out rc + home="$TMP_ROOT/probe-home" + fakebin="$TMP_ROOT/probe-fakebin" + mkdir -p "$home/state" + write_fake_samplers "$fakebin" + rm -f "$fakebin/ps" + + out=$(FM_HOME="$home" FM_TELEMETRY_PYTHON="$fakebin/failing-python" \ + PATH="$fakebin:/usr/bin:/bin" "$TELEMETRY" arm 2>&1) + rc=$? + [ "$rc" -ne 0 ] || fail "arm detached a recorder without a working durability helper" + assert_contains "$out" 'durable-flush helper' "arm did not name the broken durability helper" + [ ! -L "$home/state/telemetry/.record.lock" ] || fail "failed arm published a lock" + FM_HOME="$home" PATH="$fakebin:/usr/bin:/bin" "$TELEMETRY" status >/dev/null 2>&1 && + fail "status reported a recorder after arm refused to detach" + pass "arm refuses to detach when the durable-flush helper does not work" +} + +test_detached_recorder_diagnostics_are_persisted_and_bounded() { + local home fakebin diagnostics tries out bytes + home="$TMP_ROOT/diagnostics-home" + fakebin="$TMP_ROOT/diagnostics-fakebin" + diagnostics="$home/state/telemetry/recorder.err" + mkdir -p "$home/state/telemetry" + write_fake_samplers "$fakebin" + rm -f "$fakebin/ps" + cat > "$fakebin/mktemp" <<'SH' +#!/usr/bin/env bash +case "${1:-}" in + *.sample.*) exit 1 ;; +esac +exec /usr/bin/mktemp "$@" +SH + chmod +x "$fakebin/mktemp" + head -c 200000 /dev/zero | tr '\0' 'x' > "$diagnostics" + printf '\n' >> "$diagnostics" + DAEMON_HOME=$home + + FM_HOME="$home" FM_TELEMETRY_INTERVAL=15 PATH="$fakebin:/usr/bin:/bin" \ + "$TELEMETRY" arm >/dev/null || fail "arm failed" + tries=0 + while [ "$tries" -lt 100 ]; do + grep -q 'snapshot failed' "$diagnostics" 2>/dev/null && break + sleep 0.1 + tries=$((tries + 1)) + done + grep -q 'snapshot failed' "$diagnostics" 2>/dev/null || + fail "the detached recorder's diagnostics were discarded instead of persisted" + + bytes=$(wc -c < "$diagnostics") + [ "$bytes" -le 65536 ] || fail "recorder diagnostics grew to $bytes bytes without being trimmed" + + case "$(grep 'snapshot failed' "$diagnostics" | tail -n 1)" in + 'fm-telemetry: '[0-9][0-9][0-9][0-9]-[0-9][0-9]-[0-9][0-9]T[0-9][0-9]:[0-9][0-9]:[0-9][0-9]Z' snapshot failed') ;; + *) fail "persisted diagnostics are not UTC timestamped: $(grep 'snapshot failed' "$diagnostics" | tail -n 1)" ;; + esac + + out=$(FM_HOME="$home" PATH="$fakebin:/usr/bin:/bin" "$TELEMETRY" status) + assert_contains "$out" 'newest diagnostic' "status did not surface the recorder's diagnostics" + case "$out" in + *'newest diagnostic (age '[0-9]*'s)'*) ;; + *) fail "status did not report how old the newest diagnostic is: $out" ;; + esac + + FM_HOME="$home" PATH="$fakebin:/usr/bin:/bin" "$TELEMETRY" disarm >/dev/null || + fail "disarm failed" + DAEMON_HOME= + pass "a detached recorder persists bounded diagnostics that status surfaces" +} + +test_arm_returns_even_when_liveness_cannot_be_confirmed() { + local home fakebin rc out pid + home="$TMP_ROOT/blindps-home" + fakebin="$TMP_ROOT/blindps-fakebin" + mkdir -p "$home/state" + write_fake_samplers "$fakebin" + cat > "$fakebin/ps" <<'SH' +#!/usr/bin/env bash +exit 0 +SH + chmod +x "$fakebin/ps" + DAEMON_HOME=$home + + run_bounded 'arm with unusable ps' 150 "$home/arm.rc" "$home/arm.out" \ + env FM_HOME="$home" FM_TELEMETRY_INTERVAL=15 PATH="$fakebin:/usr/bin:/bin" \ + "$TELEMETRY" arm + rc=$(cat "$home/arm.rc") + out=$(cat "$home/arm.out") + [ "$rc" -eq 0 ] || fail "arm failed against an unusable ps: $out" + assert_contains "$out" 'running pid=' "arm did not converge on the observed lock owner" + + pid=$(readlink "$home/state/telemetry/.record.lock") + pid=${pid%%:*} + FM_HOME="$home" PATH="/usr/bin:/bin" "$TELEMETRY" disarm >/dev/null || + fail "disarm could not stop the recorder arm reported" + kill -0 "$pid" 2>/dev/null && fail "disarm left recorder pid $pid alive" + DAEMON_HOME= + pass "arm returns bounded and reports the owner when liveness cannot be confirmed" +} + +test_guard_is_reclaimed_only_after_its_holder_is_gone() { + local home fakebin holderbin holder_pid stale rc out + home="$TMP_ROOT/guard-home" + fakebin="$TMP_ROOT/guard-fakebin" + holderbin="$TMP_ROOT/guard-holderbin" + mkdir -p "$home/state/telemetry" + write_fake_samplers "$fakebin" + rm -f "$fakebin/ps" + write_guard_holder "$holderbin" + + stale=$(dead_pid) + ln -s "$stale:20:fmtelemetry-stale" "$home/state/telemetry/.record.lock" || + fail "could not stage a stale lock" + + "$holderbin/fm-telemetry.sh" 60 & + holder_pid=$! + ln -s "$holder_pid:guard-live" "$home/state/telemetry/.record.guard" || + fail "could not stage a live guard" + + run_bounded 'arm against a live guard holder' 250 "$home/arm.rc" "$home/arm.out" \ + env FM_HOME="$home" FM_TELEMETRY_INTERVAL=15 PATH="$fakebin:/usr/bin:/bin" \ + "$TELEMETRY" arm + rc=$(cat "$home/arm.rc") + out=$(cat "$home/arm.out") + [ "$rc" -ne 0 ] || fail "arm stole the guard from a live holder: $out" + [ "$(readlink "$home/state/telemetry/.record.guard")" = "$holder_pid:guard-live" ] || + fail "a live holder's guard was replaced" + [ -L "$home/state/telemetry/.record.lock" ] || + fail "arm retired the stale lock while another process held the guard" + + kill -TERM "$holder_pid" 2>/dev/null || true + wait "$holder_pid" 2>/dev/null || true + DAEMON_HOME=$home + run_bounded 'arm against a dead guard holder' 250 "$home/arm2.rc" "$home/arm2.out" \ + env FM_HOME="$home" FM_TELEMETRY_INTERVAL=15 PATH="$fakebin:/usr/bin:/bin" \ + "$TELEMETRY" arm + rc=$(cat "$home/arm2.rc") + out=$(cat "$home/arm2.out") + [ "$rc" -eq 0 ] || fail "arm did not reclaim a guard whose holder is gone: $out" + assert_contains "$out" 'running pid=' "arm did not start a recorder after reclaiming the guard" + + FM_HOME="$home" PATH="$fakebin:/usr/bin:/bin" "$TELEMETRY" disarm >/dev/null || + fail "disarm failed" + DAEMON_HOME= + pass "the guard is held against live holders and reclaimed once its holder is gone" +} + +test_losing_the_start_up_race_stays_out_of_diagnostics() { + local home fakebin diagnostics rc out + home="$TMP_ROOT/loser-home" + fakebin="$TMP_ROOT/loser-fakebin" + diagnostics="$home/state/telemetry/recorder.err" + mkdir -p "$home/state" + write_fake_samplers "$fakebin" + rm -f "$fakebin/ps" + DAEMON_HOME=$home + + FM_HOME="$home" FM_TELEMETRY_INTERVAL=15 PATH="$fakebin:/usr/bin:/bin" \ + "$TELEMETRY" arm >/dev/null || fail "arm failed" + + out=$(FM_HOME="$home" FM_TELEMETRY_INTERVAL=15 PATH="$fakebin:/usr/bin:/bin" \ + "$TELEMETRY" record "fmtelemetry-loser-$$" 2>>"$diagnostics") + rc=$? + [ "$rc" -ne 0 ] || fail "a second recorder started against the same FM_HOME" + assert_contains "$out" 'recorder already running' "the losing recorder did not report the live owner" + [ ! -s "$diagnostics" ] || + fail "losing the start-up race polluted the diagnostics stream: $(cat "$diagnostics")" + + out=$(FM_HOME="$home" PATH="$fakebin:/usr/bin:/bin" "$TELEMETRY" status) || + fail "status did not report the live recorder" + assert_not_contains "$out" 'newest diagnostic' "status reported a benign lost race as a diagnostic" + + FM_HOME="$home" PATH="$fakebin:/usr/bin:/bin" "$TELEMETRY" disarm >/dev/null || + fail "disarm failed" + DAEMON_HOME= + pass "losing the start-up race is reported without polluting persisted diagnostics" +} + +test_concurrent_arms_over_a_stale_lock_keep_one_recorder() { + local home fakebin before after fresh count stale_pid tries i survivor rc_file + home="$TMP_ROOT/race-home" + fakebin="$TMP_ROOT/race-fakebin" + mkdir -p "$home/state/telemetry" + write_fake_samplers "$fakebin" + rm -f "$fakebin/ps" + DAEMON_HOME=$home + + sleep 0 & + stale_pid=$! + wait "$stale_pid" 2>/dev/null || true + ln -s "$stale_pid:20:fmtelemetry-stale-token" "$home/state/telemetry/.record.lock" || + fail "could not stage a stale lock" + + before="$home/recorders.before" + after="$home/recorders.after" + recorder_pids > "$before" + i=0 + while [ "$i" -lt 4 ]; do + ( + out=$(FM_HOME="$home" FM_TELEMETRY_INTERVAL=30 PATH="$fakebin:/usr/bin:/bin" \ + "$TELEMETRY" arm 2>&1) + printf '%s\n' "$?" > "$home/arm.$i.rc" + printf '%s\n' "$out" > "$home/arm.$i.out" + ) & + i=$((i + 1)) + done + wait + + for rc_file in "$home"/arm.*.rc; do + [ "$(cat "$rc_file")" = 0 ] || + fail "a concurrent cold arm failed with rc $(cat "$rc_file"): $(cat "${rc_file%.rc}.out")" + case "$(cat "${rc_file%.rc}.out")" in + *'fm-telemetry: running pid='*|*'fm-telemetry: already running pid='*) ;; + *) fail "a concurrent cold arm did not report the live recorder: $(cat "${rc_file%.rc}.out")" ;; + esac + done + + count=0 + fresh= + tries=0 + while [ "$tries" -lt 50 ]; do + recorder_pids > "$after" + fresh=$(comm -13 "$before" "$after") + count=$(printf '%s' "$fresh" | grep -c . || true) + [ "$count" -le 1 ] && break + sleep 0.1 + tries=$((tries + 1)) + done + [ "$count" -eq 1 ] || fail "concurrent arms left $count recorders running for one FM_HOME" + + survivor=$(readlink "$home/state/telemetry/.record.lock") + survivor=${survivor%%:*} + [ "$survivor" = "$fresh" ] || + fail "the published lock ($survivor) does not name the surviving recorder ($fresh)" + + FM_HOME="$home" PATH="$fakebin:/usr/bin:/bin" "$TELEMETRY" disarm >/dev/null || + fail "disarm could not stop the surviving recorder" + kill -0 "$survivor" 2>/dev/null && fail "disarm left recorder pid $survivor alive" + DAEMON_HOME= + pass "concurrent arms over a stale lock converge on exactly one live recorder" +} + +test_record_writes_parseable_durable_snapshot +test_fsync_helper_flushes_the_named_file +test_fsync_helper_commits_the_containing_directory +test_record_surfaces_durability_failure +test_record_cleans_up_after_partial_temp_failure +test_interval_is_restricted_to_the_supported_cadence +test_rotation_prunes_oldest_daily_logs_to_cap +test_arm_is_idempotent_and_disarm_stops_singleton +test_tokenless_record_is_visible_to_status_and_disarm +test_arm_refuses_to_detach_without_a_working_durability_helper +test_detached_recorder_diagnostics_are_persisted_and_bounded +test_arm_returns_even_when_liveness_cannot_be_confirmed +test_guard_is_reclaimed_only_after_its_holder_is_gone +test_losing_the_start_up_race_stays_out_of_diagnostics +test_concurrent_arms_over_a_stale_lock_keep_one_recorder