Commit 7e64736b by PLN (Algolia)

fix(gig-log): three lessons from the first real take

Bug 1: Ardour flushes stems in ~12MB bursts every ~3s — a 2s stop-grace read
every gap as stop/start and reset the clock eleven times in one 20s take.
Grace is now 6s, with the measured cadence in the comment.
Bug 2: transport-button feedback IS bit-gated — /set_surface feedback 8→9
(button-status + heartbeat); the 'not bit-gated' reading died on the live rig.
Bug 3: a mute lens is not a dissenting lens — combine_rec only counts OSC when
arm AND roll are concrete, so 'connected but silent' can no longer stamp
conflict:true on ground truth. src labeling now names actual contributors.
Regression tests drive RecPass through the real flush cadence; 169 green.
parent d1947eef
......@@ -638,7 +638,16 @@ class MidiReader(threading.Thread):
FILES_RESCAN_S = 10.0 # how often to re-resolve the session (Ardour can (re)start)
FILES_RECENT_S = 10.0 # a file untouched this long is not "being written now"
FILES_GRACE_S = 2.0 # a flush/buffer stall this short must not end the pass
# WHY 6s (2026-09-05, live 20s record test on "Tidal Live", 12 float stems):
# Ardour does not stream to disk continuously — it flushes each stem in ~12MB
# bursts roughly every 3s, not every tick. The first version of this grace
# was 2s, SHORTER than that flush cadence, so the silent tick between two
# flushes read as "stopped", resetting `el` to 0 and flapping rec True/False/
# True every ~3 ticks even though Ardour never stopped recording. 6s clears
# two missed flushes' worth of silence with margin, so a real pass survives
# any gap shorter than this with `el` continuous.
FILES_GRACE_S = 6.0 # a flush/buffer stall this short must not end the pass
def files_growth(prev_sizes: dict[str, int], entries: dict[str, tuple[float, int]],
......@@ -1012,14 +1021,26 @@ OSC_RETRY_S = 30.0 # re-send the handshake at most this often while quiet
OSC_STALE_S = 8.0 # /heartbeat is 1/s; silence this long means the link is dead
# Feedback bitmask for /set_surface, from manual.ardour.org's "Calculating
# Feedback and Strip-types Values": bit value 8 = "heartbeat to surface".
# That is the ONLY bit gig-log asks for. Every other defined bit is about
# STRIP feedback this lens does not want (button/fader state, meters, master-
# section gain, bar/beat, timecode, selection...) — none of them gate
# /transport_play, /transport_stop or /rec_enable_toggle, which the manual's
# OSC-control page lists as plain surface feedback, not tied to any bit. So
# heartbeat alone is the minimal request that also proves the link is alive.
OSC_FEEDBACK = 8
# Feedback and Strip-types Values": bit value 8 = "heartbeat to surface",
# bit value 1 = "Button status for strips".
#
# WRONG, DISPROVED LIVE (2026-09-05): the first version of this asked for
# heartbeat (8) ALONE, on the reading that /transport_play, /transport_stop
# and /rec_enable_toggle are plain surface feedback not gated by any bit.
# A live 20s record test proved that wrong: heartbeat flowed (the lens
# showed "connected") but arm/roll stayed null the entire session — Ardour
# never sent those three addresses under feedback=8. Requesting bit 1 as
# well (Ardour's own wording restricts it to "strips", but transport/record
# buttons are plausibly bucketed there too — this is the manual's best
# documented candidate, and cheap to ask for either way) is the fix.
#
# NOT independently re-verified live in this pass: Ardour was not running
# on this machine when the fix was made (confirmed: no ardour-9.* process,
# nothing on udp 3819), so the NEXT live session needs to confirm arm/roll
# actually populate under feedback=9. If they still don't, the next
# candidate to try is bit 16 ("master section feedback") — /rec_enable_toggle
# is a master-level toggle, not a per-strip one.
OSC_FEEDBACK = 1 | 8
def combine_rec(files_active: bool, files_rec: bool,
......@@ -1032,15 +1053,29 @@ def combine_rec(files_active: bool, files_rec: bool,
a side by trusting one lens more — it reports whichever says TRUE (an
unnoticed false negative is worse than a flagged uncertainty) and sets
conflict=True so a reviewer sees it instead of a quietly wrong "clean".
NULL IS ABSENCE, NOT DISSENT (bug found 2026-09-05 in the first live
test): `osc_active` only means the link is alive (heartbeat flowing) —
it does NOT mean arm/roll have ever actually been reported. Under the
old feedback bitmask they never were, so every tick had osc_active=True
with osc_arm=None, osc_roll=None, and `bool(True and None and None)`
quietly evaluated to False — a MUTE lens was read as a CONCRETE "not
recording" opinion, manufacturing a conflict against files on every
tick it said True, and (by coincidence) a matching-but-meaningless
"files+osc" on every tick it said False. OSC only gets a vote — and
only gets counted into `src` — once it has actually reported both
fields; until then it is exactly as silent as when `osc_active` is
False, and this must read the same as the "only files is live" case.
"""
osc_rec = bool(osc_active and osc_arm and osc_roll)
if files_active and osc_active:
osc_concrete = osc_active and osc_arm is not None and osc_roll is not None
osc_rec = bool(osc_concrete and osc_arm and osc_roll)
if files_active and osc_concrete:
if files_rec == osc_rec:
return files_rec, "files+osc", False
return (files_rec or osc_rec), ("files" if files_rec else "osc"), True
if files_active:
return files_rec, "files", False
if osc_active:
if osc_concrete:
return osc_rec, "osc", False
return False, None, False
......@@ -1337,8 +1372,14 @@ class Recorder:
"roll": None}
rec, src, conflict = combine_rec(f["active"], f["rec"],
o["active"], o["arm"], o["roll"])
arm = o["arm"] if o["active"] else None
emit = rec != self._rec_prev or rec or (o["active"] and arm != self._arm_prev)
# NULL IS ABSENCE, NOT A CHANGE: while OSC is alive but mute (arm not
# yet reported), `arm_concrete` stays False, so a None reading never
# trips a spurious "arm changed" transition, and `self._arm_prev`
# keeps its last known CONCRETE value rather than being overwritten
# with None — the same rule combine_rec applies to `src`/conflict.
arm_concrete = o["active"] and o["arm"] is not None
arm = o["arm"] if arm_concrete else self._arm_prev
emit = rec != self._rec_prev or rec or (arm_concrete and arm != self._arm_prev)
self._rec_prev = rec
self._arm_prev = arm
if not emit:
......
......@@ -1069,6 +1069,33 @@ def test_rec_pass_ends_after_the_grace_window_and_the_next_growth_starts_fresh()
assert fresh == {"rec": True, "el": 0.0, "by": 500}, "byte/elapsed must reset, not carry over"
def test_rec_pass_survives_ardours_real_flush_cadence_without_flapping():
"""Regression, 2026-09-05 live 20s record test: Ardour flushes each stem
in ~12MB bursts roughly every 3s, not every tick — growth on tick 0, 3,
6, 9..., silence in between. With the OLD 2s grace, the 2-tick silent
gap between flushes was already longer than the grace, so every gap
read as stop->start: `rec` flapped True/False/True and `el` reset to 0
on every single flush, even though Ardour never stopped. At the
DEFAULT (6s) grace this must be ONE continuous pass: `rec` stays True
throughout, `el` only ever goes up, and `by` only ever goes up.
"""
p = gl.RecPass() # the real default, not an override
FLUSH = 12 * 1024 * 1024
seen_rec = []
prev_el = -1.0
prev_by = -1
for tick in range(20): # a 20s take, matching the live test
growth = FLUSH if tick % 3 == 0 else 0
out = p.tick(growth, now_mono=float(tick))
seen_rec.append(out["rec"])
assert out["el"] >= prev_el, f"elapsed went BACKWARDS at tick {tick}"
assert out["by"] >= prev_by, f"bytes went BACKWARDS at tick {tick}"
prev_el, prev_by = out["el"], out["by"]
assert all(seen_rec), "the pass flapped to False between flushes — the exact bug"
assert prev_by == 7 * FLUSH # ticks 0,3,6,9,12,15,18 = 7 flushes
assert prev_el == 19.0 # continuous from tick 0 to tick 19
@pytest.mark.parametrize("files_active,files_rec,osc_active,osc_arm,osc_roll,want", [
# both live and AGREE
(True, True, True, True, True, (True, "files+osc", False)),
......@@ -1083,7 +1110,18 @@ def test_rec_pass_ends_after_the_grace_window_and_the_next_growth_starts_fresh()
(True, False, False, None, None, (False, "files", False)),
(False, False, True, True, True, (True, "osc", False)),
(False, False, True, True, False, (False, "osc", False)),
(False, False, True, None, None, (False, "osc", False)),
# NULL IS ABSENCE, NOT DISSENT (the 2026-09-05 bug): osc_active=True but
# arm/roll never reported (a link that's alive/heartbeating but MUTE —
# exactly the shape a heartbeat-only feedback bitmask produced) must
# read IDENTICALLY to osc being inactive, not as a concrete "not
# recording" vote. This is what caused every real tick to either
# false-conflict against files (when files said True) or coincidentally
# match it under a meaningless "files+osc" label (when files said False).
(False, False, True, None, None, (False, None, False)), # only lens, mute: nothing
(True, True, True, None, None, (True, "files", False)), # files says yes, osc mute
(True, False, True, None, None, (False, "files", False)), # files says no, osc mute
(True, True, True, True, None, (True, "files", False)), # HALF concrete (arm only)
(True, True, True, None, False, (True, "files", False)), # HALF concrete (roll only)
# neither live: quietly nothing
(False, False, False, None, None, (False, None, False)),
])
......@@ -1144,12 +1182,14 @@ def test_osc_encode_pads_address_and_types_to_4_byte_boundaries():
def test_osc_decode_of_the_set_surface_handshake_round_trips():
"""The actual handshake this file sends: bank_size strip_types feedback
fadermode send_page_size plugin_page_size port linkset linkid, all 0
except feedback=8 (heartbeat only) — manual.ardour.org's osc-control and
calculating-feedback-and-strip-types-values pages."""
except feedback=9 (button-status bit 1 + heartbeat bit 8 — a live 20s
record test on 2026-09-05 proved heartbeat ALONE (8) never gets
/transport_play/.../rec_enable_toggle sent) — manual.ardour.org's
osc-control and calculating-feedback-and-strip-types-values pages."""
msg = gl.osc_encode("/set_surface", 0, 0, gl.OSC_FEEDBACK, 0, 0, 0, 0, 0, 0)
addr, args = gl.osc_decode(msg)
assert addr == "/set_surface"
assert args == [0, 0, 8, 0, 0, 0, 0, 0, 0]
assert args == [0, 0, 9, 0, 0, 0, 0, 0, 0]
@pytest.mark.parametrize("junk", [b"", b"\x00", b"not-osc-at-all", b"/no/typetag\x00\x00\x00\x00garbage"])
......@@ -1425,3 +1465,29 @@ def test_recorder_with_rec_disabled_never_touches_the_lenses(tmp_path):
assert r.header()["rec"] is False
assert r.poll_rec() is None # both lenses report inactive -> no record
r.f.close()
def test_poll_rec_a_mute_osc_lens_never_conflicts_and_never_flaps_src(tmp_path):
"""Regression, 2026-09-05 live 20s record test — the EXACT observed bug:
files recording (rec=true), OSC alive but never having reported
arm/roll (the heartbeat-only feedback bitmask). Every real tick showed
`"conflict":true` while `rec` was true, and `"src":"files+osc"` while
`rec` was false — both artefacts of treating a MUTE osc as a concrete
"not recording" vote. A mute OSC lens must never produce a conflict,
and `src` must consistently say "files" regardless of the rec value,
tick after tick — no flapping between "files" and "files+osc".
"""
r = gl.Recorder(out_dir=tmp_path, hz=50.0, xruns=False, midi=False, rec=False)
mute_osc = {"active": True, "arm": None, "roll": None}
# A continuous recording pass (files says True every tick, matching the
# real log this reproduces) — every tick emits (the "while recording"
# rule), so this exercises 5 real ticks' worth of the src/conflict fix.
r.files = _FixedLens(*({"active": True, "rec": True, "el": float(i), "by": 12582912}
for i in range(5)))
r.osc = _FixedLens(*([mute_osc] * 5))
for _ in range(5):
got = r.poll_rec()
assert got is not None and got["rec"] is True
assert "conflict" not in got, "a mute lens must never manufacture a conflict"
assert got["src"] == "files", "src must not flap to files+osc just because osc is alive"
r.f.close()
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