Commit 79ff7c9f by PLN (Algolia)

perf(latency): s.latency 0.3 -> 0.2, and make 'late' a counted metric

The comment read 'increase this if you get late messages', and the rig had 136
of them on 2026-09-06, so the arrow only ever pointed one way. Value history: 1
second, then 0.3, never revisited.

Those 136 were not a latency shortfall. Two bursts (64 at 19:58, 72 at 20:03)
with values DECAYING 8.1s -> 0.65s: a backlog draining, not a trickle of
near-misses. Both sit against SuperDirt restarts, and the 20:03 one is the
watchdog's spurious restart-on-boot fixed in b9564095 -- SC restarted, its clock
reset, Tidal kept its logical clock, the backlog flushed as 'late'. The
documented reason to pad this was a misdiagnosis of a bug that no longer exists.

0.2 is SuperCollider's own documented default and this is a direct tax on how a
ctrl+enter feels. Lower is fair game; the floor is whatever keeps 'late' at zero
under the densest material. Clean boot after the change: 0 lates.

latency-lens now counts 'late' per candidate alongside pw-top's ERR, and a late
rejects a quantum on its own: ERR is the audio graph missing its deadline, late
is the MUSIC being handed over too late to play on time. Different failures, and
a quantum decision wants both. Matched as 'late <digits>' -- an earlier hand
grep for the bare word scored six hits on metalPlate.scd and inflated the count.
parent 46b521d8
......@@ -373,5 +373,39 @@ s.waitForBoot {
s.volume = 2; // +6dB — SuperDirt defaults are conservative
StageLimiter.activate; // BatLib safety limiter on master out
s.latency = 0.3; // increase this if you get "late" messages
// SCHEDULING LOOKAHEAD. This is the delay between a message leaving Tidal and
// the server being told to play it, so it is a direct tax on how responsive a
// ctrl+enter feels. It is NOT a fix for xruns; it only buys slack against the
// message arriving after its own timestamp.
//
// It was 1 second, then 0.3 (d008a31), and nobody revisited it. The comment used
// to read "increase this if you get late messages", and the rig HAD late
// messages — 136 of them on 2026-09-06 — so the arrow pointed one way only.
//
// Except those 136 were not a latency shortfall. They came in TWO BURSTS (64 at
// 19:58, 72 at 20:03) with values DECAYING 8.1 s -> 0.65 s, which is a backlog
// draining, not a trickle of near-misses. Both bursts sit against SuperDirt
// RESTARTS, and the 20:03 one is in the journal by name:
//
// 20:03:29 Stopped parvagues-sc … Started parvagues-sc
// 20:03:35 sc-watchdog: scsynth GONE (3 polls) … restarting (1 prior)
//
// i.e. the watchdog's spurious restart-on-boot, fixed 2026-09-06 in b956409. SC
// restarted, its clock reset, Tidal kept its logical clock, and the backlog
// flushed as `late`. So the documented reason to pad this was a misdiagnosis of
// a bug that no longer exists.
//
// 0.2 is SuperCollider's own documented default. Going lower is fair game — the
// floor is whatever keeps `late` at zero under the densest thing PLN plays.
//
// HOW TO KNOW IF IT IS TOO LOW, now that it is countable:
// journalctl --user -u parvagues-sc -b --no-pager | grep -cE '\blate [0-9]'
// Zero is the target. `tools/latency-lens.py` reports it per candidate too.
// Match `late <digits>` and not the bare word: `late` is a substring of
// ordinary text and a loose grep scored six hits on `metalPlate.scd`.
//
// Tidal adds its own oLatency per target on top (BootTidal.hs: 0.1 for
// SuperDirt, 0.02 for the visuals target), so the total lookahead is the sum —
// do not tune one while forgetting the other.
s.latency = 0.2;
);
......@@ -173,6 +173,27 @@ def driven_nodes(seconds: float = 4.0) -> dict[str, str]:
return found
def late_count(since: str) -> int:
"""SuperDirt `late N` lines since a wall-clock time.
This is the timing metric that maps to what PLN hears. A `late` means the
server was handed a bundle whose timestamp had already passed: language
logical time + latency ran out before the message arrived. pw-top's ERR
counts the audio graph missing its deadline; `late` counts the MUSIC being
handed over too late to play on time. They are different failures and a
quantum decision wants both.
Matched narrowly (`late <digits>`) because `late` is a substring of
ordinary words — an earlier hand grep for it scored 6 hits on
`metalPlate.scd` and inflated the count.
"""
rc, out = run(["journalctl", "--user", "-u", "parvagues-sc",
"--since", since, "--no-pager"], timeout=20)
if rc != 0:
return -1
return sum(1 for l in out.splitlines() if re.search(r"\blate \d", l))
def quantum_state() -> dict[str, str]:
rc, out = run(["pw-metadata", "-n", "settings"])
st = {}
......@@ -355,7 +376,9 @@ def main() -> int:
for q in candidates:
set_force_quantum(q)
time.sleep(SETTLE_S)
t_mark = time.strftime("%Y-%m-%d %H:%M:%S")
s = dwell(a.dwell, enforce_mute=not a.allow_sound)
lates = late_count(t_mark)
deltas = s.err_delta()
worst_wq = max(s.wq_max.values(), default=0.0)
total_err = sum(deltas.values())
......@@ -368,7 +391,11 @@ def main() -> int:
"wq_max": s.wq_max,
"wq_worst": worst_wq,
"quant_seen": sorted(s.quant_seen),
"verdict": "ok" if (total_err == 0 and 0.0 < worst_wq < 0.75)
"late": lates,
# A `late` is a musical miss, not just a graph miss, so it
# rejects on its own however clean the xrun column looks.
"verdict": "ok" if (total_err == 0 and lates == 0
and 0.0 < worst_wq < 0.75)
else ("no-data" if s.rows == 0 or worst_wq == 0.0
else "reject"),
})
......@@ -376,8 +403,9 @@ def main() -> int:
results[-1]["worst_node"] = worst_node
results[-1]["nodes_seen"] = sorted(s.err_last)
print(f" {q:>5} frames ({q/int(rate)*1000:5.1f} ms) "
f"xruns+{total_err:<4} maxW/Q={worst_wq:.3f} on {worst_node:<16} "
f"samples={s.rows:<6} -> {results[-1]['verdict']}", flush=True)
f"xruns+{total_err:<4} late+{lates:<4} maxW/Q={worst_wq:.3f} "
f"on {worst_node:<16} samples={s.rows:<5} "
f"-> {results[-1]['verdict']}", flush=True)
except Unmuted as e:
why = ("could not be confirmed as muted" if "UNDETERMINED" in str(e)
else "stopped being muted")
......@@ -390,10 +418,12 @@ def main() -> int:
print(f"latency-lens: restored clock.force-quantum={orig_force}")
print()
print(f"{'quantum':>8} {'period':>8} {'xruns':>6} {'maxW/Q':>7} {'worst node':<18} verdict")
print(f"{'quantum':>8} {'period':>8} {'xruns':>6} {'late':>5} {'maxW/Q':>7} "
f"{'worst node':<18} verdict")
for r in results:
print(f"{r['quantum']:>8} {r['period_ms']:>7.1f}ms {r['err_total']:>6} "
f"{r['wq_worst']:>7.3f} {r.get('worst_node','-'):<18} {r['verdict']}")
f"{r.get('late',-1):>5} {r['wq_worst']:>7.3f} "
f"{r.get('worst_node','-'):<18} {r['verdict']}")
seen = sorted({n for r in results for n in r.get("nodes_seen", [])})
print(f"\nnodes actually sampled: {', '.join(seen) if seen else 'NONE'}")
if not any("SuperCollider" in n for n in seen):
......
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