Commit 26a526cf by PLN (Algolia)

fix(audio): detect and heal the undead server — the spin that wedges the DSP

An scsynth whose pipewire-jack client loses its startup race gets no
negotiated format (quantum 0) and busy-spins its data loop at ~95% of a
core at RT priority, unit green, process alive. Hours of that starved
the SOF DSP's IPC until the firmware wedged and every sink vanished.
Same config also boots clean at 1.5% — a probabilistic race, so the
durable answer is detection + self-heal:

- sc-watchdog spin detector: /proc CPU deltas every poll (zero forks),
  after 10s sustained >=85% ONE pw-top shot decides — quantum>0 is a
  musician playing and is never touched; quantum 0 is the spin
  (restart via the shared rate limit). Suite 15/15 incl driven-guard.
- rig-doctor: SOF DSP IPC-timeout check (with the no-root cold-boot
  cure), failed-units check (start-limit trap, negative-tested),
  scsynth orphan-spin check on the same quantum oracle. 51 checks.
- start_and_midi.scd: mi global effects measured LIGHT (all=1.3% vs
  off=1.7% idle, 5 boots) — acquitted, kept ON, gated behind PV_MI_FX
  so the next suspicion is a knob-flip, not a guess.
- CHANGELOG Sprint 8 + backlog closure.
parent 1289e086
...@@ -4,6 +4,56 @@ Sprint entries, newest first. Player-facing: what changed about *playing*, not ...@@ -4,6 +4,56 @@ Sprint entries, newest first. Player-facing: what changed about *playing*, not
about the code. Task IDs reference the L'Armada board; `n/a` where the work was about the code. Task IDs reference the L'Armada board; `n/a` where the work was
unplanned (which, on a gig night, is most of it). unplanned (which, on a gig night, is most of it).
## Sprint 8 — 2026-09-07 (afternoon) · the undead server
The glitchy media keys were never about media keys. An scsynth whose
pipewire-jack client loses its startup race ends up with no negotiated format
(quantum 0) and busy-spins its data loop at ~95% of a core AT REALTIME
PRIORITY — unit green, process alive, every existing check blind. Hours of
that starved the Intel SOF audio DSP's IPC until the firmware wedged
(`IPC timeout` -110) and every sink on the box vanished: Zoom, media keys,
Bluetooth, FIP. 9h21m of CPU burned overnight doing nothing.
### Fixed
- **autoroute pruned SuperCollider's only links when Ardour was absent**
every 2s, by design, "monitoring is via Ardour Master". True at a gig, an
orphan factory on the idle laptop. Routing and pruning now both require
Tidal tracks in the graph.
- **A wedged SOF DSP has a no-root cure**, found live: opening a PCM
(`speaker-test -D hw:sofsoundwire,2`) forces a runtime resume and the
driver cold-boots the firmware; then restart wireplumber to rebuild sinks
on the healthy DSP.
- **xpswatch died the start-limit death at 01:02** (WiFi down → exit 1 in
61ms × RestartSec=5): now 60s pacing (SRE repo `c0c03e3`), which can never
exhaust the budget.
### Added
- **sc-watchdog spin detector**: per-poll CPU from /proc (zero forks); after
10s sustained ≥85%, ONE pw-top shot decides — quantum>0 is a musician
playing (never touched), quantum 0 is the spin (restart, shared rate
limit). Tests 12-15: a hot-but-driven server is left alone; the spin is
caught and recovered. Suite now 15/15.
- **rig-doctor: three checks born from this incident**`SOF audio DSP`
(IPC timeouts this boot, FAIL if recent, with the cold-boot cure),
`failed units` (any user/system unit in `failed`, the start-limit trap
surfaced; negative-tested with a planted corpse), `scsynth orphan spin`
(same quantum oracle as the watchdog). 51 checks.
- **PV_MI_FX gate** in start_and_midi.scd, default all-on. Measured (5
boots, idle): off=1.7%, all=1.3% — the mi effects are LIGHT and were never
the hog; the knob exists so the next suspicion is settled by flipping it,
not by guessing.
### Doctrine
- **The spin is a probabilistic race, not a config bug** — same boot config
spun at 13:41 and idled at 1.5% at 14:00. You cannot prevent a race in a
library you don't ship; you detect and self-heal. Detection is a pair,
never CPU alone: sustained-hot + quantum 0.
- **pw-top's negotiated quantum is the one-line health oracle** for a
pipewire-jack client: driven = 1024/48000, undead = 0/0.
- **The DSP only logs its wedge when poked** — a suspended sink is silent
evidence; `journalctl -k` grep for `sof-audio.*IPC timeout` is the
fingerprint even when audio currently works.
## Sprint 7 — 2026-09-07 (morning) · the rig stops lying about itself ## Sprint 7 — 2026-09-07 (morning) · the rig stops lying about itself
Five separate things were reporting green while doing nothing. None of them were Five separate things were reporting green while doing nothing. None of them were
......
...@@ -2357,6 +2357,39 @@ scattered through this file resolve locally. ...@@ -2357,6 +2357,39 @@ scattered through this file resolve locally.
## Audio session — opened 2026-09-07 ## Audio session — opened 2026-09-07
### Afternoon — the undead server (closed 2026-09-07)
- ~~**Glitchy/laggy desktop audio (media keys, FIP)**~~ **ROOT-CAUSED + LAYERED
FIXES 2026-09-07 afternoon.** An scsynth whose pipewire-jack client loses its
startup race gets NO negotiated format (pw-top: quantum 0/rate 0,
self-driving, BUSY overflowing) and busy-spins its data loop at ~95% of a
core at SCHED_FIFO — while both the unit and the process look perfectly
healthy. Hours of that starved the SOF DSP's IPC until the firmware wedged
(`sof-audio ... IPC timeout` -110) and EVERY sink vanished. The overnight
instance burned 9h21m of CPU. Three occurrences in one day; same config also
booted clean at 1.5% — **a probabilistic race, so the durable protection is
detection + self-heal** (sc-watchdog spin detector, tests 12-15; rig-doctor
`scsynth orphan spin` + `SOF audio DSP` + `failed units` checks), plus one
real prevention: autoroute no longer prunes SC's links when Ardour is absent.
- **Wedged SOF DSP, no-root cure (verified live):** `timeout 5 speaker-test
-D hw:sofsoundwire,2 -c 2 -t sine` forces a runtime resume → driver
cold-boots the firmware (`IMR restore failed, trying to cold boot`) → then
`systemctl --user restart wireplumber` rebuilds sinks. No reboot needed.
- **mi global effects: measured LIGHT, acquitted.** 5 idle boots: off=1.7%,
all=1.3%, verb=1.7%, clouds=1.7%, ripples=2.0% of one core. Gated behind
`PV_MI_FX` (default all) so the next suspicion is a knob-flip, not a guess.
NOTE: no track in live/ or copycat/ uses their params yet — the ear test
(PLN, deferred) is still the only consumer.
- **FIP stuttering on Display-1 output:** two causes overlapped. The hard
stutter at 13:41-13:47 coincided exactly with a spinning scsynth (82% RT).
With SuperDirt stopped, mpv ran ERR 0 / µs waits over 20s — residual
hiccups are the FIP network feed / mpv buffering, not the graph.
- **Open:** the quantum sweep (needs SuperDirt DRIVEN + dense track; now
meaningful since the DSP-load red herring is resolved); watchdog spin
detector unproven against a REAL spin (only the fake) — next natural
occurrence is its live test, watch for `SPINNING` in the watchdog journal.
- 🔴 **`wireplumber` hitting `start-limit-hit` takes ALL audio out, and looks - 🔴 **`wireplumber` hitting `start-limit-hit` takes ALL audio out, and looks
like dead hardware.** Reported by PLN as "media keys dont work" + "tried like dead hardware.** Reported by PLN as "media keys dont work" + "tried
bluetooth headset couldnt get sound there". Diagnosis: bluetooth headset couldnt get sound there". Diagnosis:
......
...@@ -350,16 +350,35 @@ s.waitForBoot { ...@@ -350,16 +350,35 @@ s.waitForBoot {
// //
// We are inside s.waitForBoot's Routine, so s.sync is legal here — the // We are inside s.waitForBoot's Routine, so s.sync is legal here — the
// idiom is even sitting commented out at the top of this block. // idiom is even sitting commented out at the top of this block.
//
// GATED since 2026-09-07, default ALL ON. Measured that day (5 boots,
// idle, fresh graph): off=1.7%, all=1.3%, verb=1.7%, clouds=1.7%,
// ripples=2.0% of one core — these effects are LIGHT at wet=0, so they
// stay on. The knob exists for venue-day fallback and for blaming them
// honestly instead of guessing: PV_MI_FX=off disables all, or a comma
// list picks a subset — e.g.
// systemctl --user set-environment PV_MI_FX=off && systemctl --user restart parvagues-sc
// (An 80%-CPU scsynth is NOT these: that is the linkless pipewire-jack
// data-loop spin — see sc-watchdog's spin detector and rig-doctor's
// "scsynth orphan spin" check.)
~miFx = ("PV_MI_FX".getenv ? "all").split($,).collect({ |w| w.asString.toLower.stripWhiteSpace }).select({ |w| w.notEmpty });
if(~miFx.includes("off")) { ~miFx = [] };
if(~miFx.includes("all")) { ~miFx = ["verb", "clouds", "ripples"] };
if(~miFx.notEmpty) {
s.sync; s.sync;
// Register global effects on all orbits
~dirt.orbits.do { |x| ~dirt.orbits.do { |x|
var verb = GlobalDirtEffect(\global_mi_verb, [\verbwet, \verbtime, \verbdamp, \verbhp, \verbfreeze, \verbdiff, \verbgain]); // addFirst order preserved from the original: verb, clouds,
var clouds = GlobalDirtEffect(\global_mi_clouds, [\cloudspitch, \cloudspos, \cloudssize, \cloudsdens, \cloudstex, \cloudswet, \cloudsgain, \cloudsspread, \cloudsrvb, \cloudsfb, \cloudsfreeze, \cloudsmode, \cloudslofi]); // ripples — leaving the enabled subset in the same relative
var ripples = GlobalDirtEffect(\global_mi_ripples, [\ripplescf, \ripplesreson, \ripplesdrive, \ripplesgain]); // chain position as before the gate.
x.globalEffects = x.globalEffects.addFirst(verb).addFirst(clouds).addFirst(ripples); if(~miFx.includes("verb")) { x.globalEffects = x.globalEffects.addFirst(GlobalDirtEffect(\global_mi_verb, [\verbwet, \verbtime, \verbdamp, \verbhp, \verbfreeze, \verbdiff, \verbgain])) };
if(~miFx.includes("clouds")) { x.globalEffects = x.globalEffects.addFirst(GlobalDirtEffect(\global_mi_clouds, [\cloudspitch, \cloudspos, \cloudssize, \cloudsdens, \cloudstex, \cloudswet, \cloudsgain, \cloudsspread, \cloudsrvb, \cloudsfb, \cloudsfreeze, \cloudsmode, \cloudslofi])) };
if(~miFx.includes("ripples")) { x.globalEffects = x.globalEffects.addFirst(GlobalDirtEffect(\global_mi_ripples, [\ripplescf, \ripplesreson, \ripplesdrive, \ripplesgain])) };
x.initNodeTree; x.initNodeTree;
}; };
("mi global fx ON: " ++ ~miFx.join(",")).postln;
} {
"mi global fx OFF (PV_MI_FX=off; default is all)".postln;
};
// Sample watcher responder: lets tools/sample-watcher.py register a newly // Sample watcher responder: lets tools/sample-watcher.py register a newly
// dropped pack into THIS running rig, no reboot. Non-essential — if the // dropped pack into THIS running rig, no reboot. Non-essential — if the
......
...@@ -550,6 +550,161 @@ def check_pipewire() -> None: ...@@ -550,6 +550,161 @@ def check_pipewire() -> None:
f"{dflt.split('.')[-1] if '.' in dflt else dflt}") f"{dflt.split('.')[-1] if '.' in dflt else dflt}")
def check_sof_dsp() -> None:
"""Is the Intel SOF audio DSP firmware answering its driver?
On 2026-09-07 the DSP wedged silently: every kernel IPC to it timed out
(`sof-audio-pci-intel-tgl ... IPC timeout`, error -110), so wireplumber
could not build a single cAVS sink — speakers, jack and HDMI all gone,
while `pipewire`/`wireplumber` sat green and this doctor said YES. The
trigger was hours of an orphaned scsynth spinning its PipeWire data loop
at realtime priority (see check_sc_orphan), but once wedged the DSP stays
wedged until something re-boots its firmware.
The kernel only logs the wedge when the device is POKED — a suspended sink
logs nothing — so an error anywhere in this boot is worth surfacing even
if audio currently works: it is the fingerprint of the failure mode, not
noise. Recent errors (last 10 min) are a FAIL.
The no-root recovery, verified live: opening a PCM forces a runtime
resume, and the SOF driver cold-boots the firmware on resume.
"""
cure = ("timeout 5 speaker-test -D hw:sofsoundwire,2 -c 2 -t sine "
">/dev/null 2>&1; systemctl --user restart wireplumber "
"# then wait ~30s for sinks to re-enumerate")
rc, out, err = run_cmd(["journalctl", "-k", "-b", "--no-pager"], timeout=15)
if rc != 0:
add("DEVICES", "SOF audio DSP", WARN,
f"cannot read the kernel journal ({err.strip() or rc}) — "
f"DSP health unknown", "")
return
hits = [l for l in out.splitlines()
if "sof-audio" in l and ("IPC timeout" in l or "ipc tx timed out" in l)]
if not hits:
add("DEVICES", "SOF audio DSP", PASS,
"no DSP IPC timeouts this boot")
return
rc2, recent, _ = run_cmd(["journalctl", "-k", "--since", "-10 min",
"--no-pager"], timeout=15)
recent_hits = [l for l in recent.splitlines()
if "sof-audio" in l and ("IPC timeout" in l
or "ipc tx timed out" in l)] if rc2 == 0 else []
if recent_hits:
add("DEVICES", "SOF audio DSP", FAIL,
f"{len(recent_hits)} DSP IPC timeout(s) in the last 10 min "
f"({len(hits)} this boot) — the audio DSP firmware is wedged or "
f"wedging; cAVS sinks will fail to activate",
cure)
else:
add("DEVICES", "SOF audio DSP", WARN,
f"{len(hits)} DSP IPC timeout(s) earlier this boot (none in the "
f"last 10 min) — recovered or dormant; if sinks vanish, this is "
f"why", cure)
def check_failed_units() -> None:
"""Any systemd unit sitting in `failed` is a landmine, and the worst kind
is `start-limit-hit`: the unit is then UNSTARTABLE until reset-failed, and
restarting it again — everyone's instinct — is the one action that cannot
work. Three units fell into that hole on 2026-09-06/07 alone
(parvagues-sc twice, wireplumber, then xpswatch overnight), and each time
the rig looked mysteriously dead while systemd knew exactly why.
Scans user AND system scope; read-only.
"""
bad: list[str] = []
for scope, args in (("user", ["systemctl", "--user"]),
("system", ["systemctl"])):
rc, out, _ = run_cmd(args + ["--failed", "--no-legend", "--plain"])
if rc not in (0, 1): # 1 = "some units failed" on older systemd
continue
for line in out.splitlines():
unit = line.split()[0] if line.split() else ""
if unit.endswith((".service", ".socket", ".timer", ".path")):
bad.append(f"{unit} ({scope})")
if bad:
add("SERVICES", "failed units", FAIL,
f"{len(bad)} unit(s) in failed state: {', '.join(bad)} — if the "
f"reason is start-limit-hit, plain restart CANNOT revive them",
"systemctl [--user] reset-failed <unit> && "
"systemctl [--user] start <unit>")
else:
add("SERVICES", "failed units", PASS,
"no failed units in user or system scope")
def check_sc_orphan() -> None:
"""Is scsynth burning a core while connected to NOTHING?
The signature (2026-09-07): a pipewire-jack client whose output ports
have no links self-drives its data loop into a ~95%-CPU error spin at
realtime priority. Hours of that starved the SOF DSP's IPC until the
firmware wedged (see check_sof_dsp). The links vanish when Ardour is
absent and something prunes SC->hardware (tidal-ardour-autoroute did,
unconditionally, until 2026-09-07).
Detection is the pair, not either half: high CPU alone is a legit busy
set; no links alone is a booting client. Both at once is the spin.
"""
pid = ""
for proc in Path("/proc").glob("[0-9]*"):
try:
if (proc / "comm").read_text().strip() == "scsynth":
pid = proc.name
break
except OSError:
continue
if not pid:
add("SERVICES", "scsynth orphan spin", PASS,
"scsynth not running (on-demand rig) — nothing to assess")
return
def cpu_ticks() -> int:
try:
stat = (Path("/proc") / pid / "stat").read_text()
f = stat.rsplit(")", 1)[1].split()
return int(f[11]) + int(f[12]) # utime + stime
except (OSError, IndexError, ValueError):
return -1
t1 = cpu_ticks()
time.sleep(0.6)
t2 = cpu_ticks()
if t1 < 0 or t2 < 0:
add("SERVICES", "scsynth orphan spin", WARN,
f"scsynth pid {pid} vanished mid-measurement", "")
return
hz = os.sysconf("SC_CLK_TCK") or 100
cpu_pct = (t2 - t1) / hz / 0.6 * 100
# The oracle is the NEGOTIATED QUANTUM, same as sc-watchdog's spin
# detector: a driven node shows quantum 1024 / rate 48000 in pw-top, the
# spin shows 0 / 0. Links are NOT the oracle — the 12:55 occurrence on
# 2026-09-07 spun WITH its output links present.
rc, out, _ = run_cmd(["pw-top", "-b", "-n", "1"], timeout=10)
quant = None
for line in out.splitlines():
toks = line.split()
if toks and toks[-1] == "SuperCollider" and len(toks) >= 3:
try:
quant = int(toks[2])
except ValueError:
pass
if cpu_pct > 60 and quant == 0:
add("SERVICES", "scsynth orphan spin", FAIL,
f"scsynth at {cpu_pct:.0f}% CPU with NO negotiated format "
f"(quantum 0) — the data-loop spin that wedges the audio DSP",
"systemctl --user restart parvagues-sc # sc-watchdog should "
"have caught this; check it is running")
elif cpu_pct > 60 and quant is None:
add("SERVICES", "scsynth orphan spin", WARN,
f"scsynth at {cpu_pct:.0f}% CPU and pw-top shows no "
f"SuperCollider row — cannot tell a set from a spin", "")
else:
add("SERVICES", "scsynth orphan spin", PASS,
f"scsynth cpu {cpu_pct:.0f}%, quantum "
f"{quant if quant is not None else 'n/a'}")
def check_alsa_ffmpeg() -> None: def check_alsa_ffmpeg() -> None:
for binname, why in ( for binname, why in (
("aconnect", "gig-up.sh's MIDI-claim probe needs it"), ("aconnect", "gig-up.sh's MIDI-claim probe needs it"),
...@@ -1246,7 +1401,8 @@ def check_secrets() -> None: ...@@ -1246,7 +1401,8 @@ def check_secrets() -> None:
CHECKS = ( CHECKS = (
check_sc, check_quarks, check_mi_ugens, check_sc_boot_errors, check_sc, check_quarks, check_mi_ugens, check_sc_boot_errors,
check_haskell, check_pulsar, check_haskell, check_pulsar,
check_ardour, check_pipewire, check_alsa_ffmpeg, check_python_modules, check_ardour, check_pipewire, check_sof_dsp, check_failed_units,
check_sc_orphan, check_alsa_ffmpeg, check_python_modules,
check_scd_sample_roots, check_scd_sample_roots,
check_synthdefs, check_synthdefs,
check_midi_controller, check_audio_interface, check_midi_controller, check_audio_interface,
......
...@@ -141,14 +141,19 @@ notify() { ...@@ -141,14 +141,19 @@ notify() {
# #
# STATELESS on purpose — no pid cache. The kernel recycles pids, and this rig's # STATELESS on purpose — no pid cache. The kernel recycles pids, and this rig's
# most expensive recurring bug shape is a binding that was true once. # most expensive recurring bug shape is a binding that was true once.
# Sets PROC_PID on success so the spin detector can read the SAME process's
# /proc stats without a second scan. Read fresh every poll, never cached across
# polls (see the STATELESS note above).
PROC_PID=""
proc_alive() { proc_alive() {
local p comm want="$1" first="${1:0:1}" local p comm want="$1" first="${1:0:1}"
for p in /proc/[0-9]*; do for p in /proc/[0-9]*; do
read -r comm 2>/dev/null < "$p/comm" || continue read -r comm 2>/dev/null < "$p/comm" || continue
case "$comm" in case "$comm" in
"$first"*) [ "$comm" = "$want" ] && return 0 ;; "$first"*) [ "$comm" = "$want" ] && { PROC_PID="${p##*/}"; return 0; } ;;
esac esac
done done
PROC_PID=""
return 1 return 1
} }
...@@ -181,6 +186,102 @@ unit_state() { ...@@ -181,6 +186,102 @@ unit_state() {
return 0 return 0
} }
# --- SPIN DETECTOR (2026-09-07) -------------------------------------------
# A DEAD scsynth is not the only failure. An UNDEAD one is worse: a
# pipewire-jack client that loses the startup race can end up with no
# negotiated format (pw-top shows QUANT 0 / RATE 0, self-driving) and its
# data loop then busy-spins at ~95% of a core AT REALTIME PRIORITY. Hours of
# that starved the SOF audio DSP's IPC until the firmware wedged (kernel:
# `IPC timeout` -110) and every sink on the box vanished — Zoom, media keys,
# Bluetooth, all of it. The unit is `active`, scsynth is alive, the old
# checks are green. Measured 2026-09-07: three occurrences in one day; a
# healthy idle SuperDirt is 1.3-2.0%, so the two states cannot be confused.
#
# Detection is deliberately two-stage:
# 1. every poll, CPU% from /proc/<pid>/stat deltas — zero forks, and a
# legit busy SET can hit high CPU, so this alone never triggers;
# 2. only after SPIN_TICKS_TO_ACT consecutive hot polls, ONE pw-top shot:
# a DRIVEN node (quantum > 0) is a musician playing and is never
# touched; quantum 0 while pegged is the spin.
# Restarts go through the same rolling rate limit as the gone-path — the
# flap budget is shared because the failure domain is.
SPIN_CPU="${SCWD_SPIN_CPU:-85}" # %; 0 disables the detector
SPIN_TICKS_TO_ACT="${SCWD_SPIN_TICKS:-5}" # consecutive hot polls (x POLL_SECS)
PWTOP_CMD="${SCWD_PWTOP_CMD:-pw-top}" # injectable for the test harness
CLK_TCK=$(getconf CLK_TCK 2>/dev/null || echo 100) # one fork, at startup
spin_prev_pid=""; spin_prev_ticks=0; spin_prev_t=0
spin_ticks=0; spin_quiet=0
spin_check() {
(( SPIN_CPU > 0 )) || return 0
local stat rest now ticks dt pct quant
local -a f
read -r stat 2>/dev/null < "/proc/$PROC_PID/stat" || { spin_prev_pid=""; return 0; }
# comm may contain spaces/parens: parse past the LAST ')'. Field N of
# proc(5) is f[N-3] after the strip; utime=14 -> f[11], stime=15 -> f[12].
rest="${stat##*\) }"; read -ra f <<< "$rest"
ticks=$(( f[11] + f[12] ))
now=$(printf '%(%s)T' -1)
if [ "$spin_prev_pid" != "$PROC_PID" ]; then
# New (or replaced) pid: first sample is a baseline, never a verdict.
spin_prev_pid="$PROC_PID"; spin_prev_ticks=$ticks; spin_prev_t=$now
spin_ticks=0; spin_quiet=0
return 0
fi
dt=$(( now - spin_prev_t )); (( dt <= 0 )) && dt=1
pct=$(( (ticks - spin_prev_ticks) * 100 / (CLK_TCK * dt) ))
spin_prev_ticks=$ticks; spin_prev_t=$now
if (( pct < SPIN_CPU )); then
spin_ticks=0; spin_quiet=0
return 0
fi
spin_ticks=$(( spin_ticks + 1 ))
(( spin_ticks < SPIN_TICKS_TO_ACT )) && return 0
quant=$(timeout 5 $PWTOP_CMD -b -n 1 2>/dev/null | awk '$NF=="SuperCollider"{q=$3} END{print q}')
if [ -z "$quant" ]; then
(( spin_quiet )) || log "scsynth hot (${pct}%, $((spin_ticks*POLL_SECS))s) but no SuperCollider row from ${PWTOP_CMD} — not acting on CPU alone"
spin_quiet=1
return 0
fi
if [ "$quant" != "0" ]; then
(( spin_quiet )) || log "scsynth hot (${pct}%) but DRIVEN (quantum ${quant}) — a busy set, not a spin"
spin_quiet=1
return 0
fi
spin_ticks=0
if (( DRY_RUN )); then
(( spin_quiet )) || { log "[dry-run] scsynth SPINNING (${pct}% CPU, quantum 0) — WOULD restart ${UNIT}"; spin_quiet=1; }
return 0
fi
local n; n=$(recent_restarts)
if (( n >= MAX_RESTARTS )); then
(( spin_quiet )) || {
log "GIVING UP on spin: ${n} restarts in ${WINDOW_SECS}s and scsynth keeps spinning."
notify critical 0 "SuperDirt keeps spinning" \
"${n} restarts in $((WINDOW_SECS/60)) min. Giving up — this needs your eyes.
journalctl --user -u ${UNIT} -n 50"
spin_quiet=1
}
return 0
fi
log "scsynth SPINNING (${pct}% CPU sustained $((SPIN_TICKS_TO_ACT*POLL_SECS))s, quantum 0 — the orphan data-loop spin) — restarting (${n} prior in window)"
notify normal 6000 "Audio server spinning" "scsynth is burning a core doing nothing. Restarting SuperDirt…"
record_restart
systemctl --user restart "$UNIT" || log "systemctl restart returned non-zero"
if await_scsynth; then
log "recovered from spin"
notify normal 9000 "Audio server recovered" \
"SuperDirt is back. If the music does not resume on its own, ctrl+enter in Pulsar."
else
log "$PROC did not appear within ${BOOT_WAIT_SECS}s"
notify critical 0 "SuperDirt did not come back" \
"No scsynth ${BOOT_WAIT_SECS}s after restart. journalctl --user -u ${UNIT} -n 50"
fi
spin_prev_pid=""
return 0
}
# Restart timestamps within the rolling window, persisted across our own death. # Restart timestamps within the rolling window, persisted across our own death.
recent_restarts() { recent_restarts() {
local now t keep=() local now t keep=()
...@@ -226,8 +327,11 @@ while true; do ...@@ -226,8 +327,11 @@ while true; do
if proc_alive "$PROC"; then if proc_alive "$PROC"; then
(( misses > 0 )) && log "$PROC back after ${misses} miss(es)" (( misses > 0 )) && log "$PROC back after ${misses} miss(es)"
misses=0; gave_up=0; continue misses=0; gave_up=0
spin_check
continue
fi fi
spin_prev_pid=""; spin_ticks=0
misses=$(( misses + 1 )) misses=$(( misses + 1 ))
(( misses < MISSES_TO_ACT )) && continue (( misses < MISSES_TO_ACT )) && continue
......
...@@ -35,6 +35,12 @@ cleanup() { ...@@ -35,6 +35,12 @@ cleanup() {
systemctl --user stop "$SLOW_UNIT" 2>/dev/null systemctl --user stop "$SLOW_UNIT" 2>/dev/null
systemctl --user reset-failed "$SLOW_UNIT" 2>/dev/null systemctl --user reset-failed "$SLOW_UNIT" 2>/dev/null
fi fi
[ -n "${DRIVEN_WD:-}" ] && kill "$DRIVEN_WD" 2>/dev/null
[ -n "${SPIN_WD:-}" ] && kill "$SPIN_WD" 2>/dev/null
if [ -n "${SPIN_UNIT:-}" ]; then
systemctl --user stop "$SPIN_UNIT" 2>/dev/null
systemctl --user reset-failed "$SPIN_UNIT" 2>/dev/null
fi
pkill -x "$PROC" 2>/dev/null pkill -x "$PROC" 2>/dev/null
rm -rf "$TMP" rm -rf "$TMP"
} }
...@@ -185,10 +191,86 @@ systemctl --user stop "$SLOW_UNIT" 2>/dev/null ...@@ -185,10 +191,86 @@ systemctl --user stop "$SLOW_UNIT" 2>/dev/null
systemctl --user reset-failed "$SLOW_UNIT" 2>/dev/null systemctl --user reset-failed "$SLOW_UNIT" 2>/dev/null
pkill -x "$PROC" 2>/dev/null pkill -x "$PROC" 2>/dev/null
# --- 7+8. THE SPIN DETECTOR (2026-09-07) -----------------------------------------
# The undead failure mode: scsynth alive but its pipewire-jack data loop
# busy-spinning at ~95% CPU with no negotiated format (pw-top quantum 0),
# which over hours wedges the SOF audio DSP. The watchdog must (7) leave a
# HOT-BUT-DRIVEN server alone — that is a musician playing — and (8) restart
# a hot server whose quantum is 0.
#
# The fake spinner: a subshell that renames itself to $PROC via
# /proc/self/comm (what prctl PR_SET_NAME writes) and busy-loops. pw-top is
# injectable (SCWD_PWTOP_CMD) so each case scripts the graph's answer.
SPIN_UNIT="scwd-spin-$$.service"
cat > "$TMP/fake-lang-spin.sh" <<EOF
#!/usr/bin/env bash
( printf '%s' "$PROC" > /proc/self/comm; while :; do :; done ) &
while true; do sleep 1; done
EOF
chmod +x "$TMP/fake-lang-spin.sh"
cat > "$TMP/pwtop-driven" <<'EOF'
#!/usr/bin/env bash
echo 'S ID QUANT RATE WAIT BUSY W/Q B/Q ERR FORMAT NAME'
echo 'R 189 1024 48000 885.8us 4.1ms 0.04 0.19 0 F32P 2 48000 + SuperCollider'
EOF
cat > "$TMP/pwtop-orphan" <<'EOF'
#!/usr/bin/env bash
echo 'S ID QUANT RATE WAIT BUSY W/Q B/Q ERR FORMAT NAME'
echo 'R 189 0 0 12.0us +++ 0.56 +++ 7084 + SuperCollider'
EOF
chmod +x "$TMP/pwtop-driven" "$TMP/pwtop-orphan"
systemd-run --user --unit="$SPIN_UNIT" --quiet \
--property=Restart=no --property=Type=simple \
"$TMP/fake-lang-spin.sh" >/dev/null 2>&1 || bad "could not create spin unit"
sleep 2
# --- 7. hot but DRIVEN: hands off --------------------------------------------
SCWD_UNIT="$SPIN_UNIT" SCWD_PROC="$PROC" SCWD_STATE="$TMP/restarts-driven" \
SCWD_NO_NOTIFY=1 SCWD_BOOT_GRACE=0 SCWD_SPIN_CPU=50 SCWD_SPIN_TICKS=2 \
SCWD_PWTOP_CMD="$TMP/pwtop-driven" \
./tools/sc-watchdog.sh >"$TMP/wd-driven.log" 2>&1 &
DRIVEN_WD=$!
sleep 14
if grep -q 'busy set, not a spin' "$TMP/wd-driven.log" 2>/dev/null \
&& ! grep -q 'SPINNING' "$TMP/wd-driven.log" 2>/dev/null; then
ok "left a hot-but-driven server alone (a set is not a spin)"
else
bad "driven guard failed — a live gig would have been restarted"
fi
[ -s "$TMP/restarts-driven" ] && bad "driven case spent rate-limit budget" \
|| ok "driven case spent no rate-limit budget"
kill "$DRIVEN_WD" 2>/dev/null
# --- 8. hot with quantum 0: the spin — restart it -----------------------------
SCWD_UNIT="$SPIN_UNIT" SCWD_PROC="$PROC" SCWD_STATE="$TMP/restarts-spin" \
SCWD_NO_NOTIFY=1 SCWD_BOOT_GRACE=0 SCWD_SPIN_CPU=50 SCWD_SPIN_TICKS=2 \
SCWD_PWTOP_CMD="$TMP/pwtop-orphan" \
./tools/sc-watchdog.sh >"$TMP/wd-spin.log" 2>&1 &
SPIN_WD=$!
sleep 20
if grep -q 'SPINNING' "$TMP/wd-spin.log" 2>/dev/null; then
ok "detected the orphan spin (hot + quantum 0)"
else
bad "never detected the spin"
fi
if grep -q 'recovered from spin' "$TMP/wd-spin.log" 2>/dev/null; then
ok "restarted the unit and saw the server return"
else
bad "no recovery logged after a detected spin"
fi
kill "$SPIN_WD" 2>/dev/null
systemctl --user stop "$SPIN_UNIT" 2>/dev/null
systemctl --user reset-failed "$SPIN_UNIT" 2>/dev/null
pkill -x "$PROC" 2>/dev/null
echo echo
echo "--- watchdog log (crash recovery) ---"; sed 's/^/ /' "$TMP/wd.log" echo "--- watchdog log (crash recovery) ---"; sed 's/^/ /' "$TMP/wd.log"
echo echo
echo "--- watchdog log (slow boot) ---"; sed 's/^/ /' "$TMP/wd-slow.log" echo "--- watchdog log (slow boot) ---"; sed 's/^/ /' "$TMP/wd-slow.log"
echo echo
echo "--- watchdog log (spin) ---"; sed 's/^/ /' "$TMP/wd-spin.log" 2>/dev/null
echo
printf 'test-sc-watchdog: %d passed, %d failed\n' "$PASS" "$FAIL" printf 'test-sc-watchdog: %d passed, %d failed\n' "$PASS" "$FAIL"
[ "$FAIL" -eq 0 ] [ "$FAIL" -eq 0 ]
Markdown is supported
0% or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment