Commit a4dc37ba by PLN (Algolia)

fix(gig-log): say whether the recorder is RUNNING or was KILLED, don't offer a choice

The report ended an unclosed log with:

     no `end` record — the recorder is still running, or it was killed

Both readings are plausible and the reader has no way to pick. I picked wrong:
I asked systemd about `parvagues-gig-log` — a name I guessed instead of read; the
unit is `gig-log.service` — got "inactive", and used that false negative to
resolve the ambiguity into "killed". The recorder had in fact been up for eleven
hours, enabled, with its pw-top and aseqdump children alive, still writing. A
whole task got filed about restoring a service that was never down.

Two mistakes worth naming because they chain: guessing an identifier rather than
reading it, and then letting a broken check settle a question the tool had
deliberately left open. The wording invited exactly that.

So the tool now decides and says which:

    ● RECORDING NOW — this log is still open, numbers are partial
     no `end` record and no recent sample: the recorder was KILLED

is_live() decides from the DATA's own recency — last sample within a few periods
of now — and deliberately not from a process match. `pgrep -f` matches any shell
that merely mentions the string, and unit names are exactly the thing I just got
wrong. Recency needs no name and nothing to guess.

86 tests (was 83): a live log must say RECORDING NOW and never KILLED, a stale one
the reverse, and is_live must answer from timestamps alone.
parent 2648074d
...@@ -762,6 +762,25 @@ def slice_session(samples: list[dict], events: list[dict], marks: list[dict], ...@@ -762,6 +762,25 @@ def slice_session(samples: list[dict], events: list[dict], marks: list[dict],
return sl, win(events), win(marks) return sl, win(events), win(marks)
def is_live(samples: list[dict], hdr: dict) -> bool:
"""Is this log still being written RIGHT NOW?
Decided from the data's own recency, deliberately NOT from a process match:
`pgrep -f` matches any shell that merely mentions the string, and the unit
name is easy to get wrong (asking systemd about a mis-guessed
`parvagues-gig-log` instead of `gig-log.service` returned "inactive" for a
recorder that was running happily, and that false negative got used to
resolve the "still running, or killed" ambiguity the wrong way).
A log whose last sample is within a few periods of now is live. Nothing to
guess, nothing to name.
"""
if not samples:
return False
period = float(hdr.get("period") or 1.0)
return (time.time() - samples[-1]["t"]) < max(5.0, period * 5)
def parse_when(spec: str, t0: float) -> float: def parse_when(spec: str, t0: float) -> float:
"""`+M:SS` / `+H:MM:SS` = offset from session start; `HH:MM[:SS]` = wall clock. """`+M:SS` / `+H:MM:SS` = offset from session start; `HH:MM[:SS]` = wall clock.
...@@ -816,6 +835,7 @@ def cmd_report(path: Path, since: str | None = None, ...@@ -816,6 +835,7 @@ def cmd_report(path: Path, since: str | None = None,
print(f"gig-log: {path.name} has no samples yet", file=sys.stderr) print(f"gig-log: {path.name} has no samples yet", file=sys.stderr)
return 1 return 1
t0 = hdr.get("t") or samples[0]["t"] t0 = hdr.get("t") or samples[0]["t"]
live = is_live(samples, hdr)
win = None win = None
if since or until: if since or until:
# Measure the SET, not the corpus: a recorder that ran all night mixes # Measure the SET, not the corpus: a recorder that ran all night mixes
...@@ -978,8 +998,15 @@ def cmd_report(path: Path, since: str | None = None, ...@@ -978,8 +998,15 @@ def cmd_report(path: Path, since: str | None = None,
if end: if end:
p(f" session closed cleanly: {end.get('samples')} samples, " p(f" session closed cleanly: {end.get('samples')} samples, "
f"{end.get('midi_events')} midi events") f"{end.get('midi_events')} midi events")
elif live:
# Say WHICH, rather than offering the reader a choice. The old wording
# ("still running, or it was killed") made a running recorder look like a
# possible failure, and that ambiguity got resolved the wrong way once
# already — costing a whole invented task about a recorder that was fine.
p(" ● RECORDING NOW — this log is still open, numbers are partial")
else: else:
p(" ⚠ no `end` record — the recorder is still running, or it was killed") p(" ⚠ no `end` record and no recent sample: the recorder was KILLED")
p(" (a clean stop writes one; check `systemctl --user status gig-log`)")
p("=" * W) p("=" * W)
return 0 return 0
......
...@@ -700,3 +700,40 @@ def test_report_window_narrows_the_xrun_total(tmp_path, capsys): ...@@ -700,3 +700,40 @@ def test_report_window_narrows_the_xrun_total(tmp_path, capsys):
out = capsys.readouterr().out out = capsys.readouterr().out
assert "WINDOW" in out and "rebased" in out assert "WINDOW" in out and "rebased" in out
assert "500" in out and "1900" not in out assert "500" in out and "1900" not in out
def test_report_says_RECORDING_NOW_for_a_live_log(tmp_path, capsys):
# The ambiguous "still running, or it was killed" made a healthy recorder
# read as a possible failure; that ambiguity was once resolved the wrong way.
r = gl.Recorder(out_dir=tmp_path, hz=50.0, xruns=False, midi=False)
r._write(r.header())
r.f.write(json.dumps({"t": time.time(), "k": "s", "pkg": 50, "core_max": 50,
"fan": [1700], "fmax": 2900, "favg": 2900, "cpu_max": 5,
"cpu_avg": 5, "thr_core": 0, "thr_pkg": 0, "w": None,
"gear": {}}) + "\n")
r.f.close()
gl.cmd_report(r.path)
out = capsys.readouterr().out
assert "RECORDING NOW" in out
assert "KILLED" not in out
def test_report_says_KILLED_for_a_stale_log(tmp_path, capsys):
r = gl.Recorder(out_dir=tmp_path, hz=50.0, xruns=False, midi=False)
r._write(r.header())
r.f.write(json.dumps({"t": time.time() - 3600, "k": "s", "pkg": 50,
"core_max": 50, "fan": [1700], "fmax": 2900,
"favg": 2900, "cpu_max": 5, "cpu_avg": 5,
"thr_core": 0, "thr_pkg": 0, "w": None,
"gear": {}}) + "\n")
r.f.close()
gl.cmd_report(r.path)
out = capsys.readouterr().out
assert "KILLED" in out and "RECORDING NOW" not in out
def test_is_live_uses_data_recency_not_a_process_match():
hdr = {"period": 1.0}
assert gl.is_live([{"t": time.time()}], hdr) is True
assert gl.is_live([{"t": time.time() - 600}], hdr) is False
assert gl.is_live([], hdr) is False
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