Merge pull request 'fix: updater survives Settings saves + cache unsniffable MLGs (v1.6.1)' (#13) from dev into main

Reviewed-on: #13

CHANGELOG.md

@@ -6,6 +6,41 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0
 
 ---
 
+## [6-25-26] — v1.6.1
+
+Reliability fixes for the tray app's auto-updater and scan logging.
+
+### Fixed
+- **Auto-updater no longer dies when Settings are saved.**  Saving the Settings dialog restarts the watcher thread via `_restart_watcher`, which sets and then replaces the shared `stop_event`.  Because the updater loop keyed off that *same* event, saving settings would terminate the auto-updater thread (a race — it could survive one save and die on the next).  The watcher kept running and reporting heartbeats, but the agent silently stopped checking for / applying updates until the tray app was relaunched.  The updater now keys off its own app-lifetime event (`_app_stop`) that watcher restarts never touch; it stops only on Exit or when applying an update.  (Same fix as thor-watcher 0.4.1.)
+- **Unsniffable `.MLG` files are logged once, not every scan.**  A `.MLG` file the watcher couldn't extract a unit ID from was never cached, so every scan (~every 5 min) re-sniffed *and* re-emitted its `[unsniffable-recent]` log line.  With a few hundred such files in a long-lived Blastware autocall folder that meant tens of thousands of duplicate lines per day (a 10-day-old log had grown to ~600K lines).  The scan now caches the unsniffable result, so each file is sniffed and logged once per session — and the redundant per-scan header reads are gone.
+- Added `test_scan_latest.py` (unsniffable cached / logged-once + happy-path sniff) and `test_series3_tray.py` (updater survives a watcher restart; stops on exit).
+
+## [6-25-26] — v1.6.0
+
+Optional dual-send mirror so a standby server stays a live replica.
+
+### Added — Mirror (dual-send)
+- **Post every heartbeat and event to a second ("mirror") server in addition to the primary.**  When `MIRROR_API_URL` and/or `MIRROR_SFM_URL` are set, each heartbeat POST and each forwarded Blastware event is *also* sent to the mirror destination — letting a standby box (e.g. the office NAS) stay a continuous replica of prod during a migration so the eventual cutover is a non-event.  **Default off** — blank URLs mean existing 1.5.x installs don't change behaviour after an auto-update.
+- **Heartbeat mirror (best-effort).**  After the primary `send_api_payload`, the same payload is fired at `MIRROR_API_URL` when set.  It is fully wrapped and bounded by the existing API timeout — the mirror can **never** delay or fail the primary heartbeat; its outcome is ignored except for a debug log line.
+- **Event mirror (reliable, isolated).**  Events are re-forwarded to `MIRROR_SFM_URL` through a *separate* sha256 state file (`MIRROR_SFM_STATE_FILE`, blank → `<log dir>/sfm_forwarded_mirror.json`) so the mirror tracks its own delivery independently of the primary forwarder.  Before each mirror pass a quick reachability probe (~3 s) checks the mirror server; if it's down the pass is skipped and retried next tick rather than blocking the loop on per-event timeouts.  Skipped events stay pending in the mirror state and deliver once the mirror returns — **no data loss**.
+- **Isolation invariant.**  Nothing on the mirror path can delay or fail the primary: its own state file, its own try/except, the reachability guard + bounded timeouts, and all exceptions swallowed-and-logged.  The primary path stays exactly as reliable as before.  The mirror rides along with the primary — there is no separate enable flag (heartbeat-mirror active iff the primary heartbeat is on *and* `MIRROR_API_URL` is set; event-mirror active iff primary forwarding is on *and* `MIRROR_SFM_URL` is set).
+- **Mirror fields in the Settings dialog**: `Mirror API URL` + `Mirror SFM URL` (blank = off).
+- New unit tests in `test_event_forwarder.py` covering mirror reachability, the down-mirror skip, separate-state idempotency, and the isolation invariant (a mirror failure leaves the primary's result + state untouched).
+
+### Configuration
+
+New `[agent]` keys (all default-off — existing 1.5.x deployments don't change behaviour on auto-update):
+
+| Key | Default | Notes |
+|---|---|---|
+| `MIRROR_API_URL` | empty | Second heartbeat base URL, e.g. `http://10.0.0.x:8001` (blank = off) |
+| `MIRROR_SFM_URL` | empty | Second SFM base URL, e.g. `http://10.0.0.x:8200` (blank = off) |
+| `MIRROR_SFM_STATE_FILE` | `<log dir>/sfm_forwarded_mirror.json` | Override location of the mirror's forwarded-sha256 state file |
+
+### Operational (migration seeding)
+
+To make the mirror re-deliver only the gap since a one-time replica snapshot, copy the primary state file to the mirror state file and drop entries whose `forwarded_at` is after the snapshot.  SFM-side dedup covers any overlap.  See `docs/mirror-dual-send-design.md`.
+
 ## [5-11-26] — v1.5.0
 
 First release of the SFM event forwarder.

README.md

@@ -1,4 +1,4 @@
-# Series 3 Watcher v1.5.0
+# Series 3 Watcher v1.6.1
 
 Monitors Instantel **Series 3 (Minimate)** call-in activity on a Blastware server. Runs as a **system tray app** that starts automatically on login, reports heartbeats to terra-view, and self-updates from Gitea.
 
@@ -124,6 +124,27 @@ Combine both for a fully controlled rollout: seed-state to skip the deep archive
 
 ---
 
+## Mirror (Dual-Send) — v1.6.0+
+
+The watcher can post every heartbeat and event to a **second ("mirror") server** in addition to the primary — useful for keeping a standby box (e.g. the office NAS) as a continuous replica during a server migration, so the eventual cutover is a non-event. **Default off.**
+
+The mirror rides along with the primary — there is no separate enable flag:
+
+- **Heartbeat mirror** is active when `API_ENABLED = true` **and** `MIRROR_API_URL` is set. After the primary heartbeat POST, the same payload is fired at the mirror.
+- **Event mirror** is active when `SFM_FORWARD_ENABLED = true` **and** `MIRROR_SFM_URL` is set. Events are re-forwarded to the mirror using a **separate** sha256 state file (`MIRROR_SFM_STATE_FILE`, blank → `<log dir>/sfm_forwarded_mirror.json`).
+
+**The mirror can never delay or fail the primary.** The heartbeat mirror is fully wrapped and bounded by the API timeout. The event mirror runs a quick reachability probe (~3 s) first and skips the pass if the mirror server is down — skipped events stay pending in the mirror state and deliver when it returns, so nothing is lost. All mirror exceptions are swallowed-and-logged; the primary path stays exactly as reliable as before.
+
+| Key | Description |
+|-----|-------------|
+| `MIRROR_API_URL` | Second heartbeat base URL, e.g. `http://10.0.0.x:8001` (blank = off) |
+| `MIRROR_SFM_URL` | Second SFM base URL, e.g. `http://10.0.0.x:8200` (blank = off) |
+| `MIRROR_SFM_STATE_FILE` | Path to the mirror's sha256 state file. Blank → `<log dir>/sfm_forwarded_mirror.json` |
+
+**Seeding for a migration.** To re-deliver only the gap since a one-time replica snapshot, copy the primary state file to the mirror state file and drop entries whose `forwarded_at` is after the snapshot. SFM-side dedup covers any overlap. See [`docs/mirror-dual-send-design.md`](docs/mirror-dual-send-design.md).
+
+---
+
 ## Tray Icon
 
 | Colour | Meaning |
@@ -167,7 +188,7 @@ where the corresponding server-side work lives.
 
 ## Versioning
 
-Follows **Semantic Versioning**. Current release: **v1.5.0**.
+Follows **Semantic Versioning**. Current release: **v1.6.1**.
 See `CHANGELOG.md` for full history.
 
 ---

installer.iss

@@ -3,7 +3,7 @@
 
 [Setup]
 AppName=Series 3 Watcher
-AppVersion=1.5.0
+AppVersion=1.6.1
 AppPublisher=Terra-Mechanics Inc.
 DefaultDirName={pf}\Series3Watcher
 DefaultGroupName=Series 3 Watcher

series3_tray.py

@@ -1,5 +1,5 @@
 """
-Series 3 Watcher — System Tray Launcher  v1.5.0
+Series 3 Watcher — System Tray Launcher  v1.6.1
 Requires: pystray, Pillow, tkinter (stdlib)
 
 Run with:  pythonw series3_tray.py   (no console window)
@@ -335,7 +335,8 @@ def _show_cancel_message():
 class WatcherTray:
     def __init__(self):
         self.state = {}
-        self.stop_event = threading.Event()
+        self.stop_event = threading.Event()   # watcher lifecycle; replaced on restart
+        self._app_stop = threading.Event()    # app lifetime; only set on exit/update
         self._watcher_thread = None
         self._icon = None
         # Lock guards _rebuild_menu calls from the updater thread
@@ -394,6 +395,7 @@ class WatcherTray:
                 subprocess.Popen(["explorer", HERE])
 
     def _exit(self, icon, item):
+        self._app_stop.set()
         self.stop_event.set()
         icon.stop()
 
@@ -459,7 +461,7 @@ class WatcherTray:
         last_status = None
         update_check_counter = 0  # check for updates every ~5 min (30 * 10s ticks)
 
-        while not self.stop_event.is_set():
+        while not self._app_stop.is_set():
             icon_status = self._tray_status()
 
             if self._icon is not None:
@@ -487,7 +489,7 @@ class WatcherTray:
                     self._do_update(url)
                     return  # exit loop; swap bat will relaunch
 
-            self.stop_event.wait(timeout=10)
+            self._app_stop.wait(timeout=10)
 
     def _do_update(self, download_url=None):
         """Notify tray icon then apply update. If url is None, fetch it first."""
@@ -502,6 +504,7 @@ class WatcherTray:
 
         success = apply_update(download_url)
         if success:
+            self._app_stop.set()
             self.stop_event.set()
             if self._icon is not None:
                 self._icon.stop()

series3_watcher.py

@@ -237,13 +237,16 @@ def scan_latest(
                     uid = cached[1]
                 else:
                     uid = sniff_unit_from_mlg(fpath, header_bytes)
-                    if not uid:
-                        # If unsniffable but very recent, log for later inspection
-                        if (recent_cutoff is not None) and (mtime >= recent_cutoff):
+                    # Cache the result either way — including unsniffable (uid=None) —
+                    # so the same file isn't re-sniffed and re-logged on every scan.
+                    cache[fpath] = (mtime, uid)
+                    if (not uid) and (recent_cutoff is not None) and (mtime >= recent_cutoff):
+                        # Log once, on first sight, for later inspection.
                         if logger:
                             logger("[unsniffable-recent] {}".format(fpath))
-                        continue  # skip file if no unit ID found in header
-                    cache[fpath] = (mtime, uid)
+
+                if not uid:
+                    continue  # no unit ID in header — skip (cached above, won't re-log)
 
                 if (uid not in latest) or (mtime > latest[uid]["mtime"]):
                     latest[uid] = {"mtime": mtime, "fname": e.name, "path": fpath}
@@ -253,7 +256,7 @@ def scan_latest(
 
 
 # --- API heartbeat / SFM telemetry helpers ---
-VERSION = "1.5.0"
+VERSION = "1.6.1"
 
 
 def _read_log_tail(log_file: str, n: int = 25) -> Optional[list]:

settings_dialog.py

@@ -1,5 +1,5 @@
 """
-Series 3 Watcher — Settings Dialog  v1.5.0
+Series 3 Watcher — Settings Dialog  v1.6.1
 
 Provides a Tkinter settings dialog that doubles as a first-run wizard.
 

test_scan_latest.py

@@ -0,0 +1,62 @@
+"""
+Tests for scan_latest's handling of unsniffable .MLG files.
+
+Regression guard: a .MLG file the watcher can't extract a unit ID from must
+be cached (as "no id") so it isn't re-sniffed and re-logged on every scan.
+Previously the unsniffable result was never cached, so the
+`[unsniffable-recent]` warning was re-emitted every scan cycle — ~200 files
+x 288 scans/day flooded the log with hundreds of thousands of duplicate lines.
+"""
+import os
+import time
+import tempfile
+import unittest
+
+import series3_watcher
+
+
+class UnsniffableCaching(unittest.TestCase):
+    def test_unsniffable_recent_file_logged_once_across_scans(self):
+        with tempfile.TemporaryDirectory() as d:
+            # A .MLG file with no BE####/BA#### pattern → sniff returns None.
+            path = os.path.join(d, "junk001.MLG")
+            with open(path, "wb") as f:
+                f.write(b"\x00" * 512)
+
+            calls = []
+            cache = {}
+            recent_cutoff = time.time() - 86400.0  # file (mtime≈now) counts as recent
+
+            for _ in range(3):
+                series3_watcher.scan_latest(
+                    watch=d,
+                    header_bytes=2048,
+                    cache=cache,
+                    recent_cutoff=recent_cutoff,
+                    max_age_days=365,
+                    logger=calls.append,
+                )
+
+            unsniff = [c for c in calls if "[unsniffable-recent]" in c]
+            self.assertEqual(
+                len(unsniff), 1,
+                "unsniffable file should log once across scans, got {}: {}".format(
+                    len(unsniff), unsniff),
+            )
+
+    def test_sniffable_file_still_returned(self):
+        # Sanity: a file WITH a unit id is still detected (happy path intact).
+        with tempfile.TemporaryDirectory() as d:
+            path = os.path.join(d, "evt001.MLG")
+            with open(path, "wb") as f:
+                f.write(b"hdr\x00BE12599\x00hdr")  # contains a sniffable unit id
+            cache = {}
+            result = series3_watcher.scan_latest(
+                watch=d, header_bytes=2048, cache=cache,
+                recent_cutoff=time.time() - 86400.0, max_age_days=365, logger=None,
+            )
+            self.assertIn("BE12599", result)
+
+
+if __name__ == "__main__":
+    unittest.main()

test_series3_tray.py

@@ -0,0 +1,78 @@
+"""
+Tests for series3_tray's thread lifecycle.
+
+Regression guard: saving the Settings dialog restarts the watcher thread via
+``_restart_watcher``, which sets and replaces the shared ``stop_event``. The
+auto-updater must key off its own lifetime event (``_app_stop``) so a watcher
+restart never kills it; it should only stop when the app actually exits.
+"""
+import sys
+import time
+import threading
+import unittest
+from unittest import mock
+
+# Series3's tray pulls in Windows-only GUI deps at import time; stub them.
+for _name in ("pystray", "PIL", "PIL.Image", "PIL.ImageDraw"):
+    sys.modules.setdefault(_name, mock.MagicMock())
+
+import series3_tray  # noqa: E402
+
+
+class TrayThreadLifecycle(unittest.TestCase):
+    def setUp(self):
+        # No-op watcher loop so restarting the watcher doesn't spin up the real
+        # Blastware scanner / network heartbeat.
+        patcher = mock.patch.object(
+            series3_tray.watcher, "run_watcher", lambda state, stop_event: None
+        )
+        patcher.start()
+        self.addCleanup(patcher.stop)
+
+    def test_app_stop_is_separate_lifetime_event(self):
+        app = series3_tray.WatcherTray()
+        self.assertIsInstance(app._app_stop, threading.Event)
+        self.assertIsNot(app._app_stop, app.stop_event)
+        self.assertFalse(app._app_stop.is_set())
+
+    def test_exit_signals_app_stop(self):
+        app = series3_tray.WatcherTray()
+        icon = mock.MagicMock()
+        app._exit(icon, None)
+        self.assertTrue(app._app_stop.is_set())
+        icon.stop.assert_called_once()
+
+    def test_restart_watcher_leaves_watcher_stop_unset(self):
+        app = series3_tray.WatcherTray()
+        app._restart_watcher()
+        self.assertFalse(app.stop_event.is_set())
+
+    def test_updater_survives_watcher_restart_then_stops_on_exit(self):
+        app = series3_tray.WatcherTray()
+        app._icon = None
+        with mock.patch.object(series3_tray, "check_for_update", return_value=(None, None)), \
+                mock.patch.object(app, "_tray_status", return_value="ok"):
+            t = threading.Thread(
+                target=app._icon_updater, daemon=True, name="test-updater"
+            )
+            t.start()
+            time.sleep(0.1)
+            self.assertTrue(t.is_alive(), "updater failed to start")
+
+            # A settings save restarts the watcher — it must NOT kill the updater.
+            app._restart_watcher()
+            time.sleep(0.2)
+            self.assertTrue(
+                t.is_alive(), "updater thread died on watcher restart (the bug)"
+            )
+
+            # Real app exit DOES stop the updater.
+            app._app_stop.set()
+            t.join(timeout=2)
+            self.assertFalse(
+                t.is_alive(), "updater thread did not stop on app exit"
+            )
+
+
+if __name__ == "__main__":
+    unittest.main()