Daily auto-fix log on NA Ingest's Desktop
~/Desktop/Auto-Fix Logs/<YYYY-MM-DD Weekday> Auto-Fix.log, written line by line as it happens: auto-fix on/off, each problem and what was done (try n of 2), the result, when the fault cleared, give-ups, and when it held back (network problem, several Dante devices gone). Tests write to a temp folder. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
This commit is contained in:
Claude Opus 5.5
@@ -73,6 +73,7 @@ During that window, with ALARMS on, the panel fixes a problem by itself once it
|
||||
- At most 2 tries per problem, 90 s apart; then it is yours to hold.
|
||||
- It waits while the network is having a blip, and does nothing to Dante when several devices vanish at once (that is NA Ingest's view or the Dante network, not the Macs).
|
||||
- Never automatic: restarting a running ProPresenter, Bible app, ProdCom (or DVS on NA Ingest, which restarts ProdCom), captions or the bridge, power-cycling a switch port, or turning on a connection someone switched off. `load_config` refuses an auto fix that closes a program.
|
||||
- **Daily log:** everything auto-fix does is written as it happens to `~/Desktop/Auto-Fix Logs/<date> <weekday> Auto-Fix.log` on NA Ingest (e.g. `2026-10-11 Sunday Auto-Fix.log`): the problem, what it did, whether it worked, when the fault cleared, when it gave up or held back. Double-click it to open it in Console, which shows new lines live.
|
||||
- Press ALARMS to mute the panel for maintenance: that also stops auto-fix. The window and the list are `"auto_fix"` in `config.json`.
|
||||
|
||||
## Restart page (page 20)
|
||||
|
||||
+92
-5
@@ -580,6 +580,37 @@ class Tracker:
|
||||
DAYS = ["mon", "tue", "wed", "thu", "fri", "sat", "sun"]
|
||||
|
||||
|
||||
class AutoLog:
|
||||
"""One plain-text file per day of everything auto-fix does, written line by line as it happens,
|
||||
e.g. "~/Desktop/Auto-Fix Logs/2026-10-11 Sunday Auto-Fix.log" (a .log opens in Console, which
|
||||
shows new lines live)."""
|
||||
|
||||
def __init__(self, directory):
|
||||
self.dir = os.path.expanduser(directory)
|
||||
self.lock = threading.Lock()
|
||||
|
||||
def path(self, now):
|
||||
return os.path.join(self.dir, datetime.fromtimestamp(now).strftime("%Y-%m-%d %A") + " Auto-Fix.log")
|
||||
|
||||
def write(self, now, button, text):
|
||||
dt = datetime.fromtimestamp(now)
|
||||
line = "%s %-8s %s\n" % (dt.strftime("%H:%M:%S"), button, text.replace("\n", " "))
|
||||
try:
|
||||
with self.lock:
|
||||
os.makedirs(self.dir, exist_ok=True)
|
||||
path = self.path(now)
|
||||
new = not os.path.exists(path)
|
||||
with open(path, "a", encoding="utf-8") as f:
|
||||
if new:
|
||||
f.write("Status panel auto-fixes - %s\n"
|
||||
"(NA Ingest fixes these by itself on Sundays 06:30-13:30; anything that closes a\n"
|
||||
" running program stays a hold. Newest lines at the bottom.)\n\n"
|
||||
% dt.strftime("%A %-d %B %Y"))
|
||||
f.write(line)
|
||||
except OSError as e:
|
||||
log.warning("auto-fix log %s: %s", self.dir, e)
|
||||
|
||||
|
||||
def in_windows(windows, now):
|
||||
"""Is `now` inside one of [{"days": [...], "start": "HH:MM", "end": "HH:MM"}]?"""
|
||||
dt = datetime.fromtimestamp(now)
|
||||
@@ -665,6 +696,10 @@ class Engine:
|
||||
self.auto = cfg.get("auto_fix") or {}
|
||||
self.auto_tries = {} # fix identity -> [tries, last try time] for the fault now going on
|
||||
self.auto_seen = {} # fix identity -> last time it was in an auto plan
|
||||
self.autolog = AutoLog(self.auto.get("log_dir", "~/Desktop/Auto-Fix Logs")) if self.auto else None
|
||||
self.auto_watch = {} # "BUTTON FAULT" auto-fix went after -> when (to log when it clears)
|
||||
self.auto_paused = False
|
||||
self.auto_on = False # inside the window (for the "auto-fix on" line)
|
||||
self.auto_last = 0.0
|
||||
self.deck_ips = {} # HyperDeck connection -> last address Companion reported
|
||||
self.now = 0.0
|
||||
@@ -766,7 +801,12 @@ class Engine:
|
||||
if event == "fault":
|
||||
self.events.append(("FAULT", "%s %s" % (self.tiles[tile_id]["label"], res.msg)))
|
||||
elif event == "clear":
|
||||
self.events.append(("CLEAR", "%s %s" % (self.tiles[tile_id]["label"], tr.last_fault_msg)))
|
||||
text = "%s %s" % (self.tiles[tile_id]["label"], tr.last_fault_msg)
|
||||
self.events.append(("CLEAR", text))
|
||||
fixed_at = self.auto_watch.pop(text, None)
|
||||
if fixed_at is not None and self.autolog:
|
||||
self.autolog.write(now, self.tiles[tile_id]["label"],
|
||||
"OK again: %s (%d s after the auto-fix)" % (tr.last_fault_msg, now - fixed_at))
|
||||
# A check may stop reporting a fault instead of reporting it OK: a Shure or PSM check says
|
||||
# "conn" while its connection is down and per channel once it is back (2026-10-08). Such a
|
||||
# fault is over - clear it, or it lingers unseen and a hold would still try to fix it.
|
||||
@@ -947,7 +987,7 @@ class Engine:
|
||||
return plan
|
||||
return self.run_plan(tile_id, plan, snap, comp, now, cooldown)
|
||||
|
||||
def run_plan(self, tile_id, plan, snap, comp, now, cooldown=60, auto=False):
|
||||
def run_plan(self, tile_id, plan, snap, comp, now, cooldown=60, auto=False, on_done=None):
|
||||
"""Carry out fix_plan() items for one button (a hold, or auto-fix during service)."""
|
||||
started, names, waited, midi = [], [], False, []
|
||||
for ident, kind, what, chk in plan:
|
||||
@@ -993,6 +1033,8 @@ class Engine:
|
||||
summary = names[0] if len(set(names)) == 1 else "%d FIXES" % len(names)
|
||||
if not started: # only Companion reconnects: quick
|
||||
self.note(tile_id, "CHECKING\n" + summary, "fixing", now, 15)
|
||||
if on_done:
|
||||
on_done("asked Companion to reconnect")
|
||||
return plan
|
||||
self.note(tile_id, ("AUTO-FIXING\n" if auto else "FIXING\n") + summary, "fixing", now, 180)
|
||||
results = []
|
||||
@@ -1008,12 +1050,18 @@ class Engine:
|
||||
done = time.time()
|
||||
if WAKING in results:
|
||||
self.note(tile_id, "WAKING PC\n" + summary, "fixing", done, 120)
|
||||
outcome = "the PC was off: sent Wake-on-LAN"
|
||||
elif said: # the fix says what to do next
|
||||
self.note(tile_id, said[0], "failed", done, 60)
|
||||
outcome = "did not work: " + said[0]
|
||||
elif all(r is not False for r in results):
|
||||
self.note(tile_id, "CHECKING\n" + summary, "fixing", done, 20)
|
||||
outcome = "done, checking it comes back"
|
||||
else:
|
||||
self.note(tile_id, "FIX FAILED\n" + summary, "failed", done, 20)
|
||||
outcome = "the fix command failed"
|
||||
if on_done:
|
||||
on_done(outcome)
|
||||
said = []
|
||||
for fn, args, short in started:
|
||||
threading.Thread(target=work, args=(fn, args, short), daemon=True).start()
|
||||
@@ -1030,14 +1078,28 @@ class Engine:
|
||||
return []
|
||||
self.auto_last = now
|
||||
if not in_windows(a.get("windows", []), now) or not self.service.on(now):
|
||||
if self.auto_on and self.autolog:
|
||||
self.autolog.write(now, "PANEL", "auto-fix off (%s)" % ("ALARMS muted" if in_windows(
|
||||
a.get("windows", []), now) else "end of the window"))
|
||||
self.auto_on = False
|
||||
self.auto_tries.clear()
|
||||
self.auto_seen.clear()
|
||||
return []
|
||||
if not self.auto_on and self.autolog: # opens today's file, so it can be watched from the start
|
||||
ends = [w["end"] for w in a.get("windows", []) if in_windows([w], now)]
|
||||
self.autolog.write(now, "PANEL", "auto-fix on%s" % (" until " + ends[0] if ends else ""))
|
||||
self.auto_on = True
|
||||
net_down = any(self.trackers.get("net:" + k) and self.trackers["net:" + k].confirmed
|
||||
and self.trackers["net:" + k].result.level == ERR for k in ("link", "gateway"))
|
||||
if net_down or (self.burst and (self.burst["cleared"] is None
|
||||
or now - self.burst["cleared"] < a.get("pause_after_network_seconds", 60))):
|
||||
if not self.auto_paused and self.autolog:
|
||||
self.autolog.write(now, "NET", "network problem: no auto-fixes until it settles")
|
||||
self.auto_paused = True
|
||||
return [] # everything looks broken at once: wait it out
|
||||
if self.auto_paused and self.autolog:
|
||||
self.autolog.write(now, "NET", "network settled: auto-fix is back on")
|
||||
self.auto_paused = False
|
||||
gentle = set(a.get("fixes", []))
|
||||
done = []
|
||||
for t in self.cfg["tiles"]:
|
||||
@@ -1051,6 +1113,9 @@ class Engine:
|
||||
if self.auto_seen.get(("dante-wide", t["id"]), 0) < now - 600:
|
||||
log.info("AUTO %s: %d Dante devices gone at once - not touching them, hold DANTE if needed",
|
||||
t["id"], len(gone))
|
||||
if self.autolog:
|
||||
self.autolog.write(now, t["label"], "left alone: %d Dante devices gone at once (NA Ingest's "
|
||||
"view of Dante or the Dante network) - hold DANTE if needed" % len(gone))
|
||||
self.auto_seen[("dante-wide", t["id"])] = now
|
||||
continue
|
||||
plan = []
|
||||
@@ -1062,6 +1127,9 @@ class Engine:
|
||||
if tries >= a.get("max_tries", 2):
|
||||
if tries == a.get("max_tries", 2):
|
||||
log.info("AUTO %s: gave up on %s %s after %d tries - hold it to try again", t["id"], kind, what, tries)
|
||||
if self.autolog:
|
||||
self.autolog.write(now, t["label"], "gave up after %d tries: %s - hold %s to try again"
|
||||
% (tries, self.describe(kind, what), t["label"]))
|
||||
self.auto_tries[ident] = (tries + 1, last)
|
||||
continue
|
||||
if now - last < a.get("retry_seconds", 90) or now - self.fix_last.get(ident, 0) < 60:
|
||||
@@ -1069,9 +1137,20 @@ class Engine:
|
||||
self.auto_tries[ident] = (tries + 1, now)
|
||||
plan.append((ident, kind, what, chk))
|
||||
if plan:
|
||||
log.info("AUTO %s: fixing %s (try %d)", t["id"], ", ".join("%s %s" % (k, w) for _, k, w, _ in plan),
|
||||
max(self.auto_tries[i][0] for i, _, _, _ in plan))
|
||||
self.run_plan(t["id"], plan, snap, comp, now, auto=True)
|
||||
try_no = max(self.auto_tries[i][0] for i, _, _, _ in plan)
|
||||
log.info("AUTO %s: fixing %s (try %d)", t["id"], ", ".join("%s %s" % (k, w) for _, k, w, _ in plan), try_no)
|
||||
faults = [r.msg for k in self.keys_for(t["id"]) for r in [self.trackers[k].result]
|
||||
if self.trackers[k].confirmed and r.level == ERR]
|
||||
for f in faults:
|
||||
self.auto_watch["%s %s" % (t["label"], f)] = now
|
||||
label = t["label"]
|
||||
if self.autolog:
|
||||
self.autolog.write(now, label, "problem: %s - fixing: %s (try %d of %d)" % (
|
||||
", ".join(faults) or "?", "; ".join(self.describe(k, w) for _, k, w, _ in plan),
|
||||
try_no, a.get("max_tries", 2)))
|
||||
self.run_plan(t["id"], plan, snap, comp, now, auto=True,
|
||||
on_done=(lambda outcome, label=label: self.autolog.write(time.time(), label, "-> " + outcome))
|
||||
if self.autolog else None)
|
||||
done.append(t["id"])
|
||||
forget = a.get("forget_seconds", 600)
|
||||
for ident in list(self.auto_tries):
|
||||
@@ -1081,6 +1160,14 @@ class Engine:
|
||||
del self.auto_tries[ident]
|
||||
return done
|
||||
|
||||
def describe(self, kind, what):
|
||||
"""A plan item in words, for the auto-fix log."""
|
||||
if kind == "restart":
|
||||
return "reconnect Companion's %s connection" % what
|
||||
if kind == "fix":
|
||||
return self.cfg["fixes"][what].get("label", what)
|
||||
return "%s %s" % (kind, what)
|
||||
|
||||
def run_force(self, key_id, snap, comp, now, cooldown=60, fix_id=None, chk=None):
|
||||
"""Run one fix whatever the status says: a Restart page key, or a button's "hold_always".
|
||||
Shares the 60 s guard with holds, so a hold and a restart key never double up."""
|
||||
|
||||
@@ -29,6 +29,7 @@ CONFIG["service_windows"] = [{"days": ["sun"], "start": "07:00", "end": "12:30"}
|
||||
CONFIG["tiles"] = [dict(t, label="SERVICE") if t["id"] == "service" else t for t in CONFIG["tiles"]]
|
||||
# A Sunday 08:00 (inside the service window) and a Wednesday 15:00 (outside it).
|
||||
SUNDAY = datetime(2026, 10, 11, 8, 0).timestamp()
|
||||
CONFIG["auto_fix"]["log_dir"] = tempfile.mkdtemp(prefix="sp-autolog-") # never the real Desktop
|
||||
WEDNESDAY = datetime(2026, 10, 7, 15, 0).timestamp()
|
||||
|
||||
|
||||
@@ -585,8 +586,9 @@ class TestFixes(unittest.TestCase):
|
||||
def setUp(self):
|
||||
self.snap = healthy_snapshot(SUNDAY)
|
||||
self.engine = sp.Engine(CONFIG)
|
||||
# Safety net: a hold in these tests must never reach a real machine.
|
||||
# Safety net: a hold in these tests must never reach a real machine (or write a real log).
|
||||
self.engine.executor = self.engine.poe_executor = lambda *a: True
|
||||
self.engine.autolog = sp.AutoLog(tempfile.mkdtemp())
|
||||
|
||||
def plan(self, tile):
|
||||
run_steps(self.engine, self.snap, SUNDAY, 4)
|
||||
@@ -699,6 +701,27 @@ class TestFixes(unittest.TestCase):
|
||||
self.assertEqual(self.engine.notes["apps"]["text"], "AUTO-FIXING\nABLETON")
|
||||
gate.set()
|
||||
|
||||
def test_auto_fix_writes_a_daily_log(self):
|
||||
ran, comp = self.auto_setup()
|
||||
t = SUNDAY
|
||||
self.snap.remote["tracks\0pgrep -xq Live"] = False
|
||||
run_steps(self.engine, self.snap, t, 25)
|
||||
self.engine.auto_fix(self.snap, comp, t + 25)
|
||||
time.sleep(0.2)
|
||||
self.snap.remote["tracks\0pgrep -xq Live"] = True # Ableton is back
|
||||
run_steps(self.engine, self.snap, t + 40, 1)
|
||||
path = self.engine.autolog.path(t)
|
||||
self.assertTrue(path.endswith("2026-10-11 Sunday Auto-Fix.log"))
|
||||
lines = open(path).read().splitlines()
|
||||
self.assertTrue(lines[0].startswith("Status panel auto-fixes - Sunday 11 October 2026"))
|
||||
body = [l for l in lines if l[:2].isdigit()]
|
||||
self.assertIn("PANEL auto-fix on until 13:30", body.pop(0))
|
||||
self.assertEqual(body[0][:8], "08:00:25")
|
||||
self.assertIn("APPS problem: ABLETON NOT RUNNING - fixing: start Ableton", body[0])
|
||||
self.assertIn("(try 1 of 2)", body[0])
|
||||
self.assertIn("-> done, checking it comes back", body[1])
|
||||
self.assertIn("OK again: ABLETON NOT RUNNING (15 s after the auto-fix)", body[2])
|
||||
|
||||
def test_auto_fix_tries_twice_then_leaves_it_to_you(self):
|
||||
ran, comp = self.auto_setup()
|
||||
self.snap.remote["tracks\0pgrep -xq Live"] = False
|
||||
|
||||
Reference in New Issue
Block a user