From 44d0195e0e836c3efee34900eba05f4cb4d91891 Mon Sep 17 00:00:00 2001 From: rdwr-egore Date: Mon, 12 Oct 2026 17:11:31 +0000 Subject: [PATCH 1/4] Fix restart-loop alerts and stable recovery detection --- README.md | 7 +- tests/test_restart_loop.py | 243 +++++++++++++++++++++++++++++++++++ watchdog-config.yaml.example | 1 + watchdog.py | 201 +++++++++++++++++++++++------ 4 files changed, 407 insertions(+), 45 deletions(-) create mode 100644 tests/test_restart_loop.py diff --git a/README.md b/README.md index 30a825f..21a6981 100644 --- a/README.md +++ b/README.md @@ -59,9 +59,9 @@ Alerts are deduplicated via a **cooldown** — once an alert fires for a contain Two additional deduplication rules suppress redundant alerts at the event level: - **OOM → die suppression**: when a container is OOM-killed, Docker emits both an `oom` event and an immediately following `die` event. The watchdog fires the `oom` CRITICAL alert and suppresses the subsequent `crashed` alert to avoid a duplicate for the same incident. -- **Restart-loop → die suppression**: once a `restart-loop` HIGH alert is active for a container, subsequent per-cycle `die` events are suppressed — the restart-loop alert is the primary signal until the container stabilises. +- **Restart-loop incident coalescing**: for containers with automatic restart policies, the first unexpected exit sends one CRITICAL `crashed` alert. At `restart_threshold` failures within `restart_window_minutes`, one HIGH `restart-loop` alert escalates the incident. Further per-cycle crashes, OOMs, and unhealthy events do not replace it. The event listener counts failed runs immediately; the poller cross-checks `RestartCount` for missed events. -**Recovery alerts**: once a container that was previously alarmed (`crashed`, `oom`, `unhealthy`, or `restart-loop`) is observed running and healthy again, the watchdog dispatches a one-time INFO `recovered` alert through the same channels and clears its alarm state. Controlled by `alert_on_recovery` (default `true`). Detection depends on the same probe path used for the original failure — a container with a Docker `HEALTHCHECK` recovers via the `health_status: healthy` event; containers on active probes (HTTP/TCP/`/proc`) recover on the next successful poll cycle. +**Recovery alerts**: once a previously-alarmed container is healthy and running, the watchdog sends a one-time INFO `recovered` notification (if `alert_on_recovery: true`). For an auto-restarting container recovering from `crashed`, `oom`, or `restart-loop`, a fleeting `running` state is *not* recovery: Docker's `State.StartedAt` must prove at least `restart_recovery_stability_seconds` continuous uptime (default 120 seconds), with no intervening failure. On recovery, restart history is reset to avoid immediate re-alerting. Docker health events cannot bypass this check. Other container recovery checks preserve their existing behavior. --- @@ -130,6 +130,7 @@ All non-secret settings live in `watchdog-config.yaml`. Secrets (webhook URLs, p | `cooldown_minutes` | `5` | Suppress duplicate alerts per container per failure type | | `restart_threshold` | `5` | Restart count within window that triggers a restart-loop alert | | `restart_window_minutes` | `10` | Rolling window for restart counting | +| `restart_recovery_stability_seconds` | `120` | Minimum uninterrupted running time before a recovered alert for automatically restarted crash/OOM/restart-loop incidents | | `unhealthy_cycles_threshold` | `3` | Consecutive unhealthy cycles before alerting | | `alert_on_recovery` | `true` | Send an INFO "recovered" alert once a previously-alarmed container returns to normal | | `excluded_containers` | `[]` | Container names to never alert on | @@ -275,7 +276,7 @@ Every alert includes two probe fields that identify exactly how and why the fail | `unhealthy` (TCP connect) | `TCP connect` | `TCP probe failed — connection refused or timed out on 172.18.0.5:6379 (Connection refused)` | | `unhealthy` (/proc fallback) | `/proc alive check` | `/proc alive check failed — PID 1 is zombie/stopped (exit code 1)` | -> **Restart-loop detection** is not a probe — it is tracked by the **Poll loop** path and fires when a container restarts ≥ `restart_threshold` times within `restart_window_minutes`. See the Poll loop row in the monitoring paths table above. +> **Restart-loop detection** uses both event-stream `die` records (nonzero exits with an automatic restart policy) and Docker `RestartCount` sampled by the poll loop. This detects rapid failures that can occur entirely between polls; counts from both paths are reconciled without double-counting. --- diff --git a/tests/test_restart_loop.py b/tests/test_restart_loop.py new file mode 100644 index 0000000..92101cd --- /dev/null +++ b/tests/test_restart_loop.py @@ -0,0 +1,243 @@ +"""Regressions for Docker auto-restart failures, loop escalation and recovery.""" +import threading +import time +import unittest +from datetime import datetime, timedelta, timezone +from types import SimpleNamespace + +import watchdog + + +def started_ago(seconds): + return (datetime.now(timezone.utc) - timedelta(seconds=seconds)).isoformat() + + +class FakeContainer: + name = "test-restart-service" + id = "abc123def" + def __init__(self, policy="always", count=0, uptime=3): + self.status = "running" + self.attrs = { + "HostConfig": {"RestartPolicy": {"Name": policy}}, + "State": {"Status": "running", "StartedAt": started_ago(uptime)}, + "RestartCount": count, + "NetworkSettings": {"Networks": {}}, + } + def reload(self): + pass + def logs(self, **kwargs): + return b"test error in dependency" + + +def make_watchdog(container, threshold=3, stable=120): + wd = object.__new__(watchdog.Watchdog) + wd.cfg = {"restart_recovery_stability_seconds": stable, "alert_on_recovery": True} + wd.state = watchdog.WatchdogState("") + wd.host = "test-host" + wd.runbook_base = "" + wd._excluded = set() + wd._restart_threshold = threshold + wd._restart_window_secs = 600 + wd._restart_recovery_stability_secs = stable + wd._unhealthy_threshold = 3 + wd._cooldown_minutes = 5 + wd._ignored_events = [] + wd._discovered_checks = {} + wd._oom_containers = set() + wd._auto_cfg = {"enabled": False} + wd._manual_checks = {} + wd._boot_time = 1 + wd._grace_until = 0 + wd._folded = [] + wd._folded_lock = threading.Lock() + wd.client = SimpleNamespace(containers=SimpleNamespace( + get=lambda name: container, list=lambda all=True: [container])) + alerts = [] + wd._dispatch = alerts.append + return wd, alerts + + +def die(wd, code=2): + wd._handle_event({"Action": "die", "Actor": {"Attributes": { + "name": "test-restart-service", "exitCode": str(code)}}}) + + +class RestartLoopRegressionTests(unittest.TestCase): + def test_event_stream_raises_loop_at_threshold_without_waiting_for_poll(self): + container = FakeContainer() + wd, alerts = make_watchdog(container) + die(wd) + die(wd) + die(wd) + self.assertEqual([a.failure_type for a in alerts], + ["crashed", "restart-loop"]) + + def test_event_stream_does_not_repeat_crash_after_loop_alert(self): + container = FakeContainer() + wd, alerts = make_watchdog(container) + for _ in range(7): + die(wd) + self.assertEqual([a.failure_type for a in alerts], + ["crashed", "restart-loop"]) + + def test_running_between_crashes_is_not_recovered(self): + container = FakeContainer(uptime=3) + wd, alerts = make_watchdog(container) + die(wd) + wd._poll_all_containers() + self.assertEqual([a.failure_type for a in alerts], ["crashed"]) + + def test_loop_stays_open_during_short_successful_run(self): + container = FakeContainer(uptime=3) + wd, alerts = make_watchdog(container) + for _ in range(3): + die(wd) + wd._poll_all_containers() + self.assertEqual([a.failure_type for a in alerts], ["crashed", "restart-loop"]) + self.assertEqual(wd.state.get(container.name).alerted_for, "restart-loop") + + def test_after_sustained_recovery_send_once_and_reset_loop_counters(self): + container = FakeContainer(uptime=3) + wd, alerts = make_watchdog(container, stable=120) + for _ in range(3): + die(wd) + container.attrs["State"]["StartedAt"] = started_ago(130) + wd.state.get(container.name).last_failure_time = time.time() - 130 + wd._poll_all_containers() + wd._poll_all_containers() + self.assertEqual([a.failure_type for a in alerts], + ["crashed", "restart-loop", "recovered"]) + self.assertFalse(wd.state.get(container.name).restart_times) + + def test_healthy_event_cannot_bypass_restart_stability(self): + container = FakeContainer(uptime=2) + wd, alerts = make_watchdog(container) + die(wd) + wd._handle_event({"Action": "health_status: healthy", + "Actor": {"Attributes": {"name": container.name}}}) + self.assertEqual([a.failure_type for a in alerts], ["crashed"]) + + def test_single_auto_restart_recovers_only_after_stability(self): + container = FakeContainer(uptime=3) + wd, alerts = make_watchdog(container, stable=120) + die(wd) + wd._poll_all_containers() + self.assertEqual([a.failure_type for a in alerts], ["crashed"]) + container.attrs["State"]["StartedAt"] = started_ago(130) + wd.state.get(container.name).last_failure_time = time.time() - 130 + wd._poll_all_containers() + self.assertEqual([a.failure_type for a in alerts], ["crashed", "recovered"]) + + def test_no_restart_policy_keeps_existing_immediate_recovery(self): + container = FakeContainer(policy="no", uptime=3) + wd, alerts = make_watchdog(container) + die(wd) + wd._poll_all_containers() + self.assertEqual([a.failure_type for a in alerts], ["crashed", "recovered"]) + + def test_poll_detects_lost_events_from_docker_restart_count(self): + container = FakeContainer(count=0) + wd, alerts = make_watchdog(container) + wd._poll_all_containers() + container.attrs["RestartCount"] = 3 + wd._poll_all_containers() + self.assertIn("restart-loop", [a.failure_type for a in alerts]) + + def test_oom_restart_loop_does_not_alternate_oom_and_loop_alerts(self): + container = FakeContainer() + wd, alerts = make_watchdog(container) + for _ in range(6): + wd._handle_event({"Action": "oom", "Actor": {"Attributes": { + "name": container.name}}}) + die(wd, code=137) + self.assertEqual([a.failure_type for a in alerts], ["oom", "restart-loop"]) + self.assertFalse(wd._oom_containers) + + def test_unhealthy_events_do_not_replace_open_restart_loop(self): + container = FakeContainer() + wd, alerts = make_watchdog(container) + for _ in range(3): + die(wd) + for _ in range(4): + wd._handle_event({"Action": "health_status: unhealthy", + "Actor": {"Attributes": {"name": container.name}}}) + self.assertEqual([a.failure_type for a in alerts], ["crashed", "restart-loop"]) + + def test_native_unhealthy_polls_do_not_replace_open_restart_loop(self): + container = FakeContainer() + wd, alerts = make_watchdog(container) + for _ in range(3): + die(wd) + container.attrs["State"]["Health"] = {"Status": "unhealthy"} + for _ in range(4): + wd._poll_all_containers() + self.assertEqual([a.failure_type for a in alerts], ["crashed", "restart-loop"]) + + def test_changing_restart_policy_does_not_falsely_recover_active_loop(self): + container = FakeContainer() + wd, alerts = make_watchdog(container, stable=120) + for _ in range(3): + die(wd) + container.attrs["HostConfig"]["RestartPolicy"]["Name"] = "no" + wd._poll_all_containers() + self.assertEqual([a.failure_type for a in alerts], ["crashed", "restart-loop"]) + container.attrs["State"]["StartedAt"] = started_ago(130) + wd.state.get(container.name).last_failure_time = time.time() - 130 + wd._poll_all_containers() + self.assertEqual([a.failure_type for a in alerts], + ["crashed", "restart-loop", "recovered"]) + + def test_recreated_container_name_starts_fresh_restart_history(self): + container = FakeContainer() + wd, alerts = make_watchdog(container, threshold=3) + die(wd) + die(wd) + container.id = "new-container-id" + container.attrs["RestartCount"] = 0 + die(wd) + self.assertEqual([a.failure_type for a in alerts], ["crashed"]) + self.assertEqual(len(wd.state.get(container.name).restart_times), 1) + + def test_recovery_disabled_clears_loop_state_after_stability(self): + container = FakeContainer(uptime=1) + wd, alerts = make_watchdog(container) + wd.cfg["alert_on_recovery"] = False + for _ in range(3): + die(wd) + container.attrs["State"]["StartedAt"] = started_ago(130) + wd.state.get(container.name).last_failure_time = time.time() - 130 + wd._poll_all_containers() + self.assertEqual(wd.state.get(container.name).alerted_for, "") + self.assertEqual([a.failure_type for a in alerts], ["crashed", "restart-loop"]) + + def test_manual_clean_stop_with_restart_policy_is_not_a_restart_loop(self): + container = FakeContainer() + wd, alerts = make_watchdog(container) + for _ in range(5): + die(wd, code=0) + wd._poll_all_containers() # Docker RestartCount remains unchanged. + self.assertEqual(alerts, []) + + def test_clean_exit_loop_detected_when_docker_restart_count_advances(self): + container = FakeContainer(count=0) + wd, alerts = make_watchdog(container) + wd._poll_all_containers() + for _ in range(3): + die(wd, code=0) + container.attrs["RestartCount"] = 3 + wd._poll_all_containers() + self.assertEqual([a.failure_type for a in alerts], ["restart-loop"]) + + def test_event_and_poll_counts_are_not_double_counted(self): + container = FakeContainer(count=0) + wd, alerts = make_watchdog(container, threshold=5) + wd._poll_all_containers() + die(wd) + die(wd) + container.attrs["RestartCount"] = 2 + wd._poll_all_containers() + self.assertEqual([a.failure_type for a in alerts], ["crashed"]) + + +if __name__ == "__main__": + unittest.main() diff --git a/watchdog-config.yaml.example b/watchdog-config.yaml.example index ad27b58..4a3dff1 100644 --- a/watchdog-config.yaml.example +++ b/watchdog-config.yaml.example @@ -20,6 +20,7 @@ check_interval_seconds: 60 # how often to poll all containers cooldown_minutes: 5 # suppress duplicate alerts per container restart_threshold: 5 # number of restarts within the window triggers alert restart_window_minutes: 10 # rolling window for restart counting +restart_recovery_stability_seconds: 120 # require 2 min continuous uptime before RECOVERED for auto-restarting containers unhealthy_cycles_threshold: 3 # consecutive unhealthy cycles before alerting alert_on_recovery: true # send an INFO "recovered" alert when a container returns to normal diff --git a/watchdog.py b/watchdog.py index aab65fa..ab2d2c8 100644 --- a/watchdog.py +++ b/watchdog.py @@ -86,6 +86,7 @@ def setup_logging(level: str, log_file: str | None, syslog_cfg: dict | None = No "cooldown_minutes": 5, "restart_threshold": 5, "restart_window_minutes": 10, + "restart_recovery_stability_seconds": 120, # prevent false recovery between restarts "unhealthy_cycles_threshold": 3, "alert_on_recovery": True, "excluded_containers": [], @@ -153,14 +154,18 @@ def _host_boot_time() -> int: class ContainerState: - __slots__ = ("name", "lock", "unhealthy_cycles", "restart_times", "last_alert_time", - "alerted_for", "last_restart_count") + __slots__ = ("name", "lock", "unhealthy_cycles", "restart_times", + "poll_restart_times", "last_failure_time", "last_container_id", + "last_alert_time", "alerted_for", "last_restart_count") def __init__(self, name: str): self.name = name self.lock = threading.Lock() # event thread and poll thread both mutate this self.unhealthy_cycles: int = 0 - self.restart_times: list[float] = [] + self.restart_times: list[float] = [] # timestamped Docker die events + self.poll_restart_times: list[float] = [] # missing events inferred from RestartCount + self.last_failure_time: float = 0.0 + self.last_container_id: str = "" self.last_alert_time: float = 0.0 self.alerted_for: str = "" self.last_restart_count: int = -1 # -1 = no baseline taken yet @@ -980,8 +985,8 @@ def _suppress_invalid_state(loop, context): ), "restart-loop": ( "HIGH", - "Container is in a restart loop. Check logs for crash reason. " - "Consider increasing RestartSec or investigating root cause.", + "Container is repeatedly restarting. Inspect docker logs and the " + "restart policy; fix application crash, OOM, or dependency failure.", ), "recovered": ( "INFO", @@ -1214,6 +1219,30 @@ def record_alert(state: ContainerState, failure_type: str) -> None: state.alerted_for = failure_type +# ── Docker restart policy / uptime helpers ──────────────────────────────────── +def has_automatic_restart_policy(container) -> bool: + """Only restart-policy containers need crash-cycle coalescing.""" + try: + policy = container.attrs.get("HostConfig", {}).get("RestartPolicy", {}).get("Name", "") + return policy in ("always", "unless-stopped", "on-failure") + except (AttributeError, TypeError): + return False + + +def container_started_timestamp(container) -> float | None: + """Docker's State.StartedAt, parsed as an aware UTC timestamp.""" + try: + started = container.attrs.get("State", {}).get("StartedAt", "") + if not started or started.startswith("0001-"): + return None + dt = datetime.fromisoformat(started.replace("Z", "+00:00")) + if dt.tzinfo is None: + dt = dt.replace(tzinfo=timezone.utc) + return dt.timestamp() + except (AttributeError, TypeError, ValueError, OverflowError): + return None + + # ── Core watchdog logic ─────────────────────────────────────────────────────── class Watchdog: def __init__(self, cfg: dict): @@ -1227,6 +1256,8 @@ def __init__(self, cfg: dict): self._excluded: set[str] = set(cfg.get("excluded_containers") or []) self._restart_threshold = cfg.get("restart_threshold", 5) self._restart_window_secs = cfg.get("restart_window_minutes", 10) * 60 + self._restart_recovery_stability_secs = max( + 0, int(cfg.get("restart_recovery_stability_seconds", 120))) self._unhealthy_threshold = cfg.get("unhealthy_cycles_threshold", 3) self._cooldown_minutes = cfg.get("cooldown_minutes", 5) self._ignored_events: list[dict] = cfg.get("ignored_container_events") or [] @@ -1365,13 +1396,34 @@ def _flush_boot_summary(self) -> None: # ── Recovery alert ───────────────────────────────────────────────────────── def _maybe_alert_recovery(self, container, state: ContainerState) -> None: - """Clear resolved state and optionally fire a one-time RECOVERED alert.""" + """Resolve once stable; a brief RUNNING state is not loop recovery.""" + automatic = has_automatic_restart_policy(container) + started = container_started_timestamp(container) + now = time.time() with state.lock: previous = state.alerted_for if not previous or previous == "recovered": return + # Once a restart-loop was reported, changing Docker's restart + # policy must not bypass the stability period. + if previous == "restart-loop" or (automatic and previous in ("crashed", "oom")): + stability = self._restart_recovery_stability_secs + # If we cannot prove continuous uptime, don't clear a real incident. + if started is None or now - started < stability: + return + if state.last_failure_time and now - state.last_failure_time < stability: + return + # A resolved loop must not re-alert from restarts still in the + # rolling 10-minute window. Start a fresh episode on next failure. + state.restart_times.clear() + state.poll_restart_times.clear() + try: + state.last_restart_count = int(container.attrs.get("RestartCount", 0) or 0) + except (TypeError, ValueError): + state.last_restart_count = -1 + state.last_failure_time = 0.0 state.alerted_for = "" - state.last_alert_time = time.time() + state.last_alert_time = now self.state.save(self._boot_time) if not self.cfg.get("alert_on_recovery", True): log.info("%s recovered from %s — recovery notification disabled", @@ -1419,50 +1471,103 @@ def _handle_event(self, event: dict) -> None: state = self.state.get(name) if action == "die": - self._discovered_checks.pop(name, None) # clear cache — container will restart - # OOM kills also emit a die event immediately after — skip the crashed alert - # to avoid duplicate: the oom alert already covers the incident - if name in self._oom_containers: - self._oom_containers.discard(name) - log.info("%s: die event follows OOM — suppressing duplicate crashed alert", name) - return - # Containers already flagged as restart-loop: suppress the per-cycle crashed - # alert — the restart-loop HIGH is the active signal for this incident. - # A first-time crash on a container with a restart policy still fires crashed. - if state.alerted_for == "restart-loop": - log.info("%s: die event during active restart-loop — suppressing redundant crashed alert", name) - return + self._discovered_checks.pop(name, None) # clear cache — container may restart exit_code_str = attributes.get("exitCode", "0") try: exit_code = int(exit_code_str) except (ValueError, TypeError): exit_code = None + if is_kvision_mariadb_dump_helper_crash(container, attributes, exit_code): log.info( "%s: Suppressing expected Cyber Controller SQL dump syntax-check container termination (exit 137) alert " - "(image=%s, AutoRemove=true, mount=%s, exit_code=137)", + "(image=%s, AutoRemove=True, mount=%s, exit_code=137)", name, _KVISION_MARIADB_DUMP_HELPER_IMAGE, _KVISION_MARIADB_DUMP_MOUNT, ) return - # exit 0 = graceful stop, no alert + + # Consume the OOM -> die pairing even if this die promotes an + # existing OOM alert to restart-loop. + oom_die = name in self._oom_containers + if oom_die: + self._oom_containers.discard(name) + automatic = has_automatic_restart_policy(container) + now = time.time() + with state.lock: + cid = getattr(container, "id", "") or "" + if cid and state.last_container_id and cid != state.last_container_id: + # Same name, new container: don't inherit its predecessor's loop. + state.restart_times.clear() + state.poll_restart_times.clear() + state.last_restart_count = -1 + if cid: + state.last_container_id = cid + if automatic and exit_code != 0: + state.restart_times = [ + t for t in state.restart_times if now - t < self._restart_window_secs + ] + # A die event reliably records a failed *run*, even when + # several Docker restarts happen between 60-second polls. + # Clean exit 0 is not counted here: Docker stop/start during + # maintenance is not evidence of an automatic restart. + # The poller still catches clean-exit loops via RestartCount. + state.restart_times.append(now) + state.last_failure_time = now + elif exit_code != 0: + state.last_failure_time = now + restarts = max(len(state.restart_times), len(state.poll_restart_times)) + previous = state.alerted_for + + if automatic and restarts >= self._restart_threshold: + if self._claim_alert(state, "restart-loop"): + payload = build_payload( + container, "restart-loop", self.host, self.runbook_base, + probe_detail=( + f"Restart-loop event detected - at least {restarts} restarts " + f"in {int(self._restart_window_secs // 60)}min window" + )) + self._dispatch(payload) + return + + if previous == "restart-loop": + log.info("%s: die event during active restart-loop — suppressing crashed alert", name) + return + + # OOM kills also emit a die; count the restart above but do not + # downgrade the OOM incident into a redundant crashed alert. + if oom_die: + log.info("%s: die event follows OOM — suppressing duplicate crashed alert", name) + return + if exit_code == 0: - log.info("%s exited cleanly (code 0) — no alert", name) + log.info("%s exited cleanly (code 0) — no crashed alert", name) return + if exit_code == 137: - # Suppression did not match — surface the real signals so the - # mismatched one (image / AutoRemove / mount) is visible in logs. log.warning("%s: exit 137 not suppressed — signals: %s", name, _mariadb_helper_signals(container, attributes)) - failure_type = "crashed" - if self._claim_alert(state, failure_type): - payload = build_payload(container, failure_type, self.host, - self.runbook_base, exit_code, - probe_detail=f"Crash probe failed - container exited with exit code {exit_code}") + # One CRASH for the initial incident; subsequent crashes coalesce + # until restart-loop escalation or sustained recovery. + if previous == "crashed" or (automatic and previous == "oom"): + log.debug("%s: additional die within open %s incident — suppressing", + name, previous) + return + if self._claim_alert(state, "crashed"): + payload = build_payload( + container, "crashed", self.host, self.runbook_base, exit_code, + probe_detail=f"Crash probe failed - container exited with exit code {exit_code}") self._dispatch(payload) elif action == "oom": failure_type = "oom" + with state.lock: + if has_automatic_restart_policy(container): + state.last_failure_time = time.time() + active_loop = state.alerted_for == "restart-loop" self._oom_containers.add(name) # mark so the imminent die event is suppressed + if active_loop: + log.info("%s: OOM during active restart-loop — suppressing per-cycle OOM alert", name) + return if self._claim_alert(state, failure_type): payload = build_payload(container, failure_type, self.host, self.runbook_base, @@ -1476,6 +1581,10 @@ def _handle_event(self, event: dict) -> None: cycles = state.unhealthy_cycles threshold = self._unhealthy_threshold log.debug("%s unhealthy cycle %d/%d", name, cycles, threshold) + with state.lock: + active_loop = state.alerted_for == "restart-loop" + if active_loop: + return # keep the primary incident until sustained recovery if cycles >= threshold: failure_type = "unhealthy" if self._claim_alert(state, failure_type): @@ -1538,15 +1647,25 @@ def _poll_all_containers(self) -> None: with state.lock: state.restart_times = [t for t in state.restart_times if now - t < restart_window] + state.poll_restart_times = [t for t in state.poll_restart_times + if now - t < restart_window] + cid = getattr(container, "id", "") or "" + if cid and state.last_container_id and cid != state.last_container_id: + state.restart_times.clear() + state.poll_restart_times.clear() + state.last_restart_count = -1 + if cid: + state.last_container_id = cid if state.last_restart_count < 0 or restart_count < state.last_restart_count: - # First sighting, or the container was recreated (count resets): - # take a baseline instead of alerting on history we never saw. + # Establish a baseline, without counting historical restarts. state.last_restart_count = restart_count elif restart_count > state.last_restart_count: new_restarts = restart_count - state.last_restart_count - state.restart_times.extend([now] * min(new_restarts, restart_threshold)) + state.poll_restart_times.extend([now] * min(new_restarts, restart_threshold)) state.last_restart_count = restart_count - restarts = len(state.restart_times) + # Docker events and RestartCount describe the same restarts. + # Use the higher observation count, never their sum. + restarts = max(len(state.restart_times), len(state.poll_restart_times)) if restarts >= restart_threshold: failure_type = "restart-loop" @@ -1565,7 +1684,9 @@ def _poll_all_containers(self) -> None: with state.lock: state.unhealthy_cycles += 1 cycles = state.unhealthy_cycles - if cycles >= unhealthy_threshold: + with state.lock: + active_loop = state.alerted_for == "restart-loop" + if cycles >= unhealthy_threshold and not active_loop: failure_type = "unhealthy" if self._claim_alert(state, failure_type): probe_detail = get_docker_health_log(container) or "Docker health probe failed - health_status: unhealthy (poll-detected)" @@ -1609,13 +1730,9 @@ def _poll_all_containers(self) -> None: if state.unhealthy_cycles > 0: log.info("%s: check recovered — resetting counters", name) state.unhealthy_cycles = 0 - # restart_times ages out on its own. Clearing it here would - # declare recovery for a container merely caught healthy - # between two crashes of an ongoing restart loop. - still_looping = (state.alerted_for == "restart-loop" - and len(state.restart_times) >= restart_threshold) - if not still_looping: - self._maybe_alert_recovery(container, state) + # Recovery is gated on continuous Docker uptime below, + # not on whether the last poll happened to see RUNNING. + self._maybe_alert_recovery(container, state) else: log.info("CONTAINER %-30s status=%-12s health=%s", name, status, health) From e45be4024866933ebd852451eae3b0c2d358e535 Mon Sep 17 00:00:00 2001 From: rdwr-egore Date: Mon, 12 Oct 2026 17:45:44 +0000 Subject: [PATCH 2/4] fix: reconcile restart counts and preserve loop incident identity --- README.md | 2 +- tests/test_restart_loop.py | 174 ++++++++++++++++++++++++++++++++++++- watchdog.py | 94 ++++++++++++++------ 3 files changed, 243 insertions(+), 27 deletions(-) diff --git a/README.md b/README.md index 21a6981..fffd0cc 100644 --- a/README.md +++ b/README.md @@ -59,7 +59,7 @@ Alerts are deduplicated via a **cooldown** — once an alert fires for a contain Two additional deduplication rules suppress redundant alerts at the event level: - **OOM → die suppression**: when a container is OOM-killed, Docker emits both an `oom` event and an immediately following `die` event. The watchdog fires the `oom` CRITICAL alert and suppresses the subsequent `crashed` alert to avoid a duplicate for the same incident. -- **Restart-loop incident coalescing**: for containers with automatic restart policies, the first unexpected exit sends one CRITICAL `crashed` alert. At `restart_threshold` failures within `restart_window_minutes`, one HIGH `restart-loop` alert escalates the incident. Further per-cycle crashes, OOMs, and unhealthy events do not replace it. The event listener counts failed runs immediately; the poller cross-checks `RestartCount` for missed events. +- **Restart-loop incident coalescing**: for containers with automatic restart policies, the first unexpected exit sends one CRITICAL `crashed` alert. At `restart_threshold` failures within `restart_window_minutes`, one HIGH `restart-loop` alert escalates the incident. Further per-cycle crashes, OOMs, or failed Docker, manual, and auto-discovered probes cannot replace it. A restart-loop alert is sent once per incident until recovery, even after the cooldown. The event listener counts failed runs immediately; the poller reconciles counter deltas with unmatched events, adding only missing restarts. Docker IDs are persisted so a replacement container using the same name starts a new incident. **Recovery alerts**: once a previously-alarmed container is healthy and running, the watchdog sends a one-time INFO `recovered` notification (if `alert_on_recovery: true`). For an auto-restarting container recovering from `crashed`, `oom`, or `restart-loop`, a fleeting `running` state is *not* recovery: Docker's `State.StartedAt` must prove at least `restart_recovery_stability_seconds` continuous uptime (default 120 seconds), with no intervening failure. On recovery, restart history is reset to avoid immediate re-alerting. Docker health events cannot bypass this check. Other container recovery checks preserve their existing behavior. diff --git a/tests/test_restart_loop.py b/tests/test_restart_loop.py index 92101cd..2352f63 100644 --- a/tests/test_restart_loop.py +++ b/tests/test_restart_loop.py @@ -1,9 +1,12 @@ """Regressions for Docker auto-restart failures, loop escalation and recovery.""" import threading +import json +import tempfile import time import unittest from datetime import datetime, timedelta, timezone from types import SimpleNamespace +from unittest.mock import patch import watchdog @@ -195,8 +198,9 @@ def test_recreated_container_name_starts_fresh_restart_history(self): container.id = "new-container-id" container.attrs["RestartCount"] = 0 die(wd) - self.assertEqual([a.failure_type for a in alerts], ["crashed"]) + self.assertEqual([a.failure_type for a in alerts], ["crashed", "crashed"]) self.assertEqual(len(wd.state.get(container.name).restart_times), 1) + self.assertEqual(len(wd.state.get(container.name).pending_event_times), 1) def test_recovery_disabled_clears_loop_state_after_stability(self): container = FakeContainer(uptime=1) @@ -228,6 +232,174 @@ def test_clean_exit_loop_detected_when_docker_restart_count_advances(self): wd._poll_all_containers() self.assertEqual([a.failure_type for a in alerts], ["restart-loop"]) + def test_manual_http_probe_does_not_overwrite_restart_loop(self): + container = FakeContainer() + wd, alerts = make_watchdog(container) + for _ in range(3): + die(wd) + wd._manual_checks[container.name] = {"type": "http", "internal_port": 8080} + with patch.object(wd, "_manual_health_check", return_value=(False, "HTTP probe failed - 503")): + for _ in range(4): + wd._poll_all_containers() + self.assertEqual([a.failure_type for a in alerts], ["crashed", "restart-loop"]) + self.assertEqual(wd.state.get(container.name).alerted_for, "restart-loop") + + def test_manual_exec_probe_does_not_overwrite_restart_loop(self): + container = FakeContainer() + wd, alerts = make_watchdog(container) + for _ in range(3): + die(wd) + wd._manual_checks[container.name] = {"type": "exec", "command": ["false"]} + with patch.object(wd, "_manual_health_check", return_value=(False, "Exec probe failed")): + for _ in range(4): + wd._poll_all_containers() + self.assertEqual([a.failure_type for a in alerts], ["crashed", "restart-loop"]) + + def test_auto_discovered_probe_does_not_overwrite_restart_loop(self): + container = FakeContainer() + wd, alerts = make_watchdog(container) + for _ in range(3): + die(wd) + wd._auto_cfg = {"enabled": True} + with patch.object(wd, "_auto_discover_health_check", return_value=(False, "HTTP probe failed - 503")): + for _ in range(4): + wd._poll_all_containers() + self.assertEqual([a.failure_type for a in alerts], ["crashed", "restart-loop"]) + + def test_mixed_event_and_poll_missing_restarts_escalate(self): + container = FakeContainer(count=0) + wd, alerts = make_watchdog(container, threshold=5) + die(wd) + die(wd) + # First polling baseline was established after two event-observed failures. + container.attrs["RestartCount"] = 2 + wd._poll_all_containers() + # Event stream has missed three further Docker auto-restarts. + container.attrs["RestartCount"] = 5 + wd._poll_all_containers() + self.assertEqual([a.failure_type for a in alerts], ["crashed", "restart-loop"]) + + def test_mixed_event_and_poll_overlap_does_not_double_count(self): + container = FakeContainer(count=0) + wd, alerts = make_watchdog(container, threshold=5) + wd._poll_all_containers() # establish count=0 baseline + die(wd) + die(wd) + container.attrs["RestartCount"] = 3 # 2 event-observed + 1 missed + wd._poll_all_containers() + self.assertEqual([a.failure_type for a in alerts], ["crashed"]) + self.assertEqual(len(wd.state.get(container.name).restart_times) + + len(wd.state.get(container.name).poll_restart_times), 3) + # Second interval: one event seen and one event missed = 5 total. + die(wd) + container.attrs["RestartCount"] = 5 + wd._poll_all_containers() + self.assertEqual([a.failure_type for a in alerts], ["crashed", "restart-loop"]) + + def test_restart_loop_emits_once_even_after_cooldown(self): + container = FakeContainer() + wd, alerts = make_watchdog(container, threshold=3) + for _ in range(3): + die(wd) + state = wd.state.get(container.name) + state.last_alert_time = time.time() - 1000 + for _ in range(5): + die(wd) + wd._poll_all_containers() + self.assertEqual([a.failure_type for a in alerts], ["crashed", "restart-loop"]) + + def test_recreated_container_must_raise_new_crash_incident(self): + container = FakeContainer() + wd, alerts = make_watchdog(container, threshold=5) + die(wd) + container.id = "replacement-unique-id" + container.attrs["RestartCount"] = 0 + die(wd) + self.assertEqual([a.failure_type for a in alerts], ["crashed", "crashed"]) + + def test_recreated_container_does_not_inherit_restart_loop(self): + container = FakeContainer() + wd, alerts = make_watchdog(container, threshold=3) + for _ in range(3): + die(wd) + container.id = "replacement-unique-id" + container.attrs["RestartCount"] = 0 + die(wd) + self.assertEqual([a.failure_type for a in alerts], + ["crashed", "restart-loop", "crashed"]) + self.assertEqual(wd.state.get(container.name).alerted_for, "crashed") + + def test_die_before_restartcount_advances_is_matched_on_later_poll(self): + container = FakeContainer(count=0) + wd, alerts = make_watchdog(container, threshold=5) + wd._poll_all_containers() + die(wd) + wd._poll_all_containers() # Docker's RestartCount is still 0 at this point + self.assertEqual(len(wd.state.get(container.name).pending_event_times), 1) + container.attrs["RestartCount"] = 1 + wd._poll_all_containers() + self.assertEqual(len(wd.state.get(container.name).restart_times), 1) + self.assertEqual(len(wd.state.get(container.name).poll_restart_times), 0) + self.assertEqual(len(wd.state.get(container.name).pending_event_times), 0) + self.assertEqual([a.failure_type for a in alerts], ["crashed"]) + + def test_first_poll_after_die_before_restartcount_advance_keeps_pending(self): + container = FakeContainer(count=0) + wd, _ = make_watchdog(container, threshold=5) + die(wd) + wd._poll_all_containers() # baseline=0 while event's start is still pending + self.assertEqual(len(wd.state.get(container.name).pending_event_times), 1) + container.attrs["RestartCount"] = 1 + wd._poll_all_containers() + self.assertEqual(len(wd.state.get(container.name).poll_restart_times), 0) + + def test_old_instance_event_id_cannot_crash_replacement(self): + container = FakeContainer() + wd, alerts = make_watchdog(container) + die(wd) + container.id = "new-unique-id" + wd._poll_all_containers() + wd._handle_event({"Action": "die", "Actor": { + "ID": "abc123def", "Attributes": { + "name": container.name, "exitCode": "17"}}}) + self.assertEqual([a.failure_type for a in alerts], ["crashed"]) + self.assertEqual(wd.state.get(container.name).last_container_id, "new-unique-id") + + def test_poll_clears_stale_incident_for_replacement_instance(self): + container = FakeContainer() + wd, alerts = make_watchdog(container) + for _ in range(3): + die(wd) + container.id = "new-unique-id" + container.attrs["RestartCount"] = 0 + wd._poll_all_containers() + self.assertEqual(wd.state.get(container.name).alerted_for, "") + die(wd) + self.assertEqual([a.failure_type for a in alerts], + ["crashed", "restart-loop", "crashed"]) + + def test_persisted_container_identity_prevents_stale_alert_after_restart(self): + with tempfile.TemporaryDirectory() as td: + path = f"{td}/state.json" + source = watchdog.WatchdogState(path) + old = source.get("test-restart-service") + old.last_container_id = "old-id" + old.alerted_for = "restart-loop" + old.last_alert_time = time.time() + source.save(123) + with open(path) as f: + entry = json.load(f)["containers"]["test-restart-service"] + self.assertEqual(entry["container_id"], "old-id") + replacement = FakeContainer() + replacement.id = "replacement-id" + wd, alerts = make_watchdog(replacement) + wd._boot_time = 123 # persisted baseline was saved on the same boot + wd.state = watchdog.WatchdogState(path) + wd._restore_state() + self.assertEqual(wd.state.get(replacement.name).last_container_id, "old-id") + die(wd) + self.assertEqual([a.failure_type for a in alerts], ["crashed"]) + def test_event_and_poll_counts_are_not_double_counted(self): container = FakeContainer(count=0) wd, alerts = make_watchdog(container, threshold=5) diff --git a/watchdog.py b/watchdog.py index ab2d2c8..a5b17a8 100644 --- a/watchdog.py +++ b/watchdog.py @@ -155,15 +155,16 @@ def _host_boot_time() -> int: class ContainerState: __slots__ = ("name", "lock", "unhealthy_cycles", "restart_times", - "poll_restart_times", "last_failure_time", "last_container_id", - "last_alert_time", "alerted_for", "last_restart_count") + "poll_restart_times", "pending_event_times", "last_failure_time", + "last_container_id", "last_alert_time", "alerted_for", "last_restart_count") def __init__(self, name: str): self.name = name self.lock = threading.Lock() # event thread and poll thread both mutate this self.unhealthy_cycles: int = 0 self.restart_times: list[float] = [] # timestamped Docker die events - self.poll_restart_times: list[float] = [] # missing events inferred from RestartCount + self.poll_restart_times: list[float] = [] # missing restarts inferred from RestartCount + self.pending_event_times: list[float] = [] # die events not yet matched to RestartCount self.last_failure_time: float = 0.0 self.last_container_id: str = "" self.last_alert_time: float = 0.0 @@ -240,6 +241,7 @@ def save(self, boot_time: int) -> None: containers[st.name] = { "alerted_for": st.alerted_for, "last_alert_time": st.last_alert_time, + "container_id": st.last_container_id, } record = { "version": _STATE_VERSION, @@ -1290,6 +1292,7 @@ def _restore_state(self) -> None: continue st = self.state.get(str(name)) st.alerted_for = failure_type + st.last_container_id = str(entry.get("container_id") or "") # unhealthy_cycles and restart_times stay at zero on purpose: they are # rolling observation windows, and a stale count would alert instantly. try: @@ -1316,6 +1319,10 @@ def _restore_state(self) -> None: def _claim_alert(self, state: ContainerState, failure_type: str) -> bool: """Atomically take the alert slot so both threads cannot fire the same alert.""" with state.lock: + if state.alerted_for == "restart-loop": + # One incident, one loop notification until sustained recovery, + # including after the normal cooldown has elapsed. + return False if not should_alert(state, failure_type, self._cooldown_minutes): return False record_alert(state, failure_type) @@ -1394,6 +1401,34 @@ def _flush_boot_summary(self) -> None: ) dispatch_alert(payload, self.cfg) + def _sync_container_identity(self, state: ContainerState, container) -> None: + """Keep incidents scoped to a Docker instance, not a reusable name.""" + cid = getattr(container, "id", "") or "" + if not cid: + return + changed = False + with state.lock: + previous_id = state.last_container_id + if previous_id and previous_id != cid: + changed = True + # Do not suppress a new instance's crash because the old + # instance had an open crash/loop/unhealthy incident. + log.info("%s: replaced Docker instance %s -> %s; resetting incident", + state.name, previous_id[:12], cid[:12]) + state.unhealthy_cycles = 0 + state.restart_times.clear() + state.poll_restart_times.clear() + state.pending_event_times.clear() + state.last_restart_count = -1 + state.last_failure_time = 0.0 + state.alerted_for = "" + state.last_alert_time = 0.0 + state.last_container_id = cid + if changed: + # Docker names are reusable; cached probes and OOM pairing are not. + self._discovered_checks.pop(state.name, None) + self._oom_containers.discard(state.name) + # ── Recovery alert ───────────────────────────────────────────────────────── def _maybe_alert_recovery(self, container, state: ContainerState) -> None: """Resolve once stable; a brief RUNNING state is not loop recovery.""" @@ -1417,6 +1452,7 @@ def _maybe_alert_recovery(self, container, state: ContainerState) -> None: # rolling 10-minute window. Start a fresh episode on next failure. state.restart_times.clear() state.poll_restart_times.clear() + state.pending_event_times.clear() try: state.last_restart_count = int(container.attrs.get("RestartCount", 0) or 0) except (TypeError, ValueError): @@ -1463,12 +1499,19 @@ def _handle_event(self, event: dict) -> None: except docker.errors.NotFound: log.warning("Container %s not found for event %s", name, action) return + # A late event from a removed instance must not be attributed to the + # replacement currently occupying the same name. + event_id = event.get("Actor", {}).get("ID") or event.get("id") + if event_id and getattr(container, "id", "") != event_id: + log.debug("%s: stale %s event belongs to a different container ID", name, action) + return if is_ignored_container_event(container, attributes, action, self._ignored_events): log.info("%s: ignoring Docker %s event due to configured label rule", name, action) return state = self.state.get(name) + self._sync_container_identity(state, container) if action == "die": self._discovered_checks.pop(name, None) # clear cache — container may restart @@ -1494,14 +1537,6 @@ def _handle_event(self, event: dict) -> None: automatic = has_automatic_restart_policy(container) now = time.time() with state.lock: - cid = getattr(container, "id", "") or "" - if cid and state.last_container_id and cid != state.last_container_id: - # Same name, new container: don't inherit its predecessor's loop. - state.restart_times.clear() - state.poll_restart_times.clear() - state.last_restart_count = -1 - if cid: - state.last_container_id = cid if automatic and exit_code != 0: state.restart_times = [ t for t in state.restart_times if now - t < self._restart_window_secs @@ -1512,10 +1547,11 @@ def _handle_event(self, event: dict) -> None: # maintenance is not evidence of an automatic restart. # The poller still catches clean-exit loops via RestartCount. state.restart_times.append(now) + state.pending_event_times.append(now) state.last_failure_time = now elif exit_code != 0: state.last_failure_time = now - restarts = max(len(state.restart_times), len(state.poll_restart_times)) + restarts = len(state.restart_times) + len(state.poll_restart_times) previous = state.alerted_for if automatic and restarts >= self._restart_threshold: @@ -1634,6 +1670,7 @@ def _poll_all_containers(self) -> None: status = container.status # running, exited, restarting, etc. health = self._get_health(container) # healthy, unhealthy, none state = self.state.get(name) + self._sync_container_identity(state, container) # Restart tracking reads Docker's RestartCount rather than counting # polls that observe status == "restarting": one slow restart seen on @@ -1649,23 +1686,28 @@ def _poll_all_containers(self) -> None: if now - t < restart_window] state.poll_restart_times = [t for t in state.poll_restart_times if now - t < restart_window] - cid = getattr(container, "id", "") or "" - if cid and state.last_container_id and cid != state.last_container_id: - state.restart_times.clear() - state.poll_restart_times.clear() - state.last_restart_count = -1 - if cid: - state.last_container_id = cid + state.pending_event_times = [t for t in state.pending_event_times + if now - t < restart_window] if state.last_restart_count < 0 or restart_count < state.last_restart_count: - # Establish a baseline, without counting historical restarts. + # Initial baseline and Docker counter resets: existing + # RestartCount may include events seen before our first poll. + # Consume only events already reflected in that count. + matched = min(restart_count, len(state.pending_event_times)) + del state.pending_event_times[:matched] state.last_restart_count = restart_count elif restart_count > state.last_restart_count: + # Reconcile *this interval's* counter delta with event + # observations not yet reflected by Docker's counter. + # A die can arrive before Docker increments RestartCount, + # so carry unmatched events forward until a later poll. new_restarts = restart_count - state.last_restart_count - state.poll_restart_times.extend([now] * min(new_restarts, restart_threshold)) + matched = min(new_restarts, len(state.pending_event_times)) + del state.pending_event_times[:matched] + missing = new_restarts - matched + state.poll_restart_times.extend([now] * min(missing, restart_threshold)) state.last_restart_count = restart_count - # Docker events and RestartCount describe the same restarts. - # Use the higher observation count, never their sum. - restarts = max(len(state.restart_times), len(state.poll_restart_times)) + # Only inferred MISSING restarts are additive to die events. + restarts = len(state.restart_times) + len(state.poll_restart_times) if restarts >= restart_threshold: failure_type = "restart-loop" @@ -1718,7 +1760,9 @@ def _poll_all_containers(self) -> None: "%s: health check failed — cycle %d/%d", name, cycles, unhealthy_threshold, ) - if cycles >= unhealthy_threshold: + with state.lock: + active_loop = state.alerted_for == "restart-loop" + if cycles >= unhealthy_threshold and not active_loop: failure_type = "unhealthy" if self._claim_alert(state, failure_type): payload = build_payload(container, failure_type, From dc18973264f527e2113dedcf956bc57c1a0d99a7 Mon Sep 17 00:00:00 2001 From: rdwr-egore Date: Tue, 13 Oct 2026 22:29:17 +0000 Subject: [PATCH 3/4] fix: count restart loops only from Docker RestartCount --- README.md | 4 +- tests/test_restart_loop.py | 251 +++++++++++++++++++++++++---------- watchdog-config.yaml.example | 2 +- watchdog.py | 122 ++++++++--------- 4 files changed, 240 insertions(+), 139 deletions(-) diff --git a/README.md b/README.md index fffd0cc..c8c3ce3 100644 --- a/README.md +++ b/README.md @@ -59,7 +59,7 @@ Alerts are deduplicated via a **cooldown** — once an alert fires for a contain Two additional deduplication rules suppress redundant alerts at the event level: - **OOM → die suppression**: when a container is OOM-killed, Docker emits both an `oom` event and an immediately following `die` event. The watchdog fires the `oom` CRITICAL alert and suppresses the subsequent `crashed` alert to avoid a duplicate for the same incident. -- **Restart-loop incident coalescing**: for containers with automatic restart policies, the first unexpected exit sends one CRITICAL `crashed` alert. At `restart_threshold` failures within `restart_window_minutes`, one HIGH `restart-loop` alert escalates the incident. Further per-cycle crashes, OOMs, or failed Docker, manual, and auto-discovered probes cannot replace it. A restart-loop alert is sent once per incident until recovery, even after the cooldown. The event listener counts failed runs immediately; the poller reconciles counter deltas with unmatched events, adding only missing restarts. Docker IDs are persisted so a replacement container using the same name starts a new incident. +- **Restart-loop incident coalescing**: Docker `die`/OOM events provide an immediate first failure alert. Only periodic Docker `RestartCount` increments determine the number of automatic restarts and whether the `restart_threshold` has been reached within `restart_window_minutes`; event deliveries are **never** added to the restart total. One HIGH `restart-loop` alert then suppresses per-cycle crashes, OOMs and failed Docker, manual or auto-discovered probes until sustained recovery, regardless of cooldown. Docker IDs identify distinct container instances even when names are reused. **Recovery alerts**: once a previously-alarmed container is healthy and running, the watchdog sends a one-time INFO `recovered` notification (if `alert_on_recovery: true`). For an auto-restarting container recovering from `crashed`, `oom`, or `restart-loop`, a fleeting `running` state is *not* recovery: Docker's `State.StartedAt` must prove at least `restart_recovery_stability_seconds` continuous uptime (default 120 seconds), with no intervening failure. On recovery, restart history is reset to avoid immediate re-alerting. Docker health events cannot bypass this check. Other container recovery checks preserve their existing behavior. @@ -276,7 +276,7 @@ Every alert includes two probe fields that identify exactly how and why the fail | `unhealthy` (TCP connect) | `TCP connect` | `TCP probe failed — connection refused or timed out on 172.18.0.5:6379 (Connection refused)` | | `unhealthy` (/proc fallback) | `/proc alive check` | `/proc alive check failed — PID 1 is zombie/stopped (exit code 1)` | -> **Restart-loop detection** uses both event-stream `die` records (nonzero exits with an automatic restart policy) and Docker `RestartCount` sampled by the poll loop. This detects rapid failures that can occur entirely between polls; counts from both paths are reconciled without double-counting. +> **Restart-loop detection** uses Docker `RestartCount` from the polling loop as its sole restart count. The first poll establishes a baseline without interpreting historical restarts. Counter increases are timestamped when observed, so detection can take up to one polling interval; the rolling window is approximate to polling precision. After a polling gap longer than the restart window, unknown-age increments are ignored rather than misattributed to the current window. Delayed Docker events cannot double-count restarts; timestamps on events also prevent failures from before confirmed recovery from reopening an incident. --- diff --git a/tests/test_restart_loop.py b/tests/test_restart_loop.py index 2352f63..bcbba1b 100644 --- a/tests/test_restart_loop.py +++ b/tests/test_restart_loop.py @@ -60,28 +60,42 @@ def make_watchdog(container, threshold=3, stable=120): return wd, alerts -def die(wd, code=2): - wd._handle_event({"Action": "die", "Actor": {"Attributes": { - "name": "test-restart-service", "exitCode": str(code)}}}) +def die(wd, code=2, occurred_at=None): + event = {"Action": "die", "Actor": {"Attributes": { + "name": "test-restart-service", "exitCode": str(code)}}} + if occurred_at is not None: + event["timeNano"] = int(occurred_at * 1_000_000_000) + wd._handle_event(event) + + +def trigger_loop(wd, container, code=2): + """Count a real Docker restart-counter delta, not event deliveries.""" + wd._poll_all_containers() # establish the current counter baseline + if code is not None: + die(wd, code) + container.attrs["RestartCount"] += wd._restart_threshold + wd._poll_all_containers() class RestartLoopRegressionTests(unittest.TestCase): - def test_event_stream_raises_loop_at_threshold_without_waiting_for_poll(self): + def test_events_send_initial_crash_but_loop_waits_for_counter_poll(self): container = FakeContainer() wd, alerts = make_watchdog(container) - die(wd) - die(wd) - die(wd) - self.assertEqual([a.failure_type for a in alerts], - ["crashed", "restart-loop"]) + wd._poll_all_containers() + for _ in range(3): + die(wd) + self.assertEqual([a.failure_type for a in alerts], ["crashed"]) + container.attrs["RestartCount"] = 3 + wd._poll_all_containers() + self.assertEqual([a.failure_type for a in alerts], ["crashed", "restart-loop"]) def test_event_stream_does_not_repeat_crash_after_loop_alert(self): container = FakeContainer() wd, alerts = make_watchdog(container) + trigger_loop(wd, container) for _ in range(7): die(wd) - self.assertEqual([a.failure_type for a in alerts], - ["crashed", "restart-loop"]) + self.assertEqual([a.failure_type for a in alerts], ["crashed", "restart-loop"]) def test_running_between_crashes_is_not_recovered(self): container = FakeContainer(uptime=3) @@ -93,8 +107,7 @@ def test_running_between_crashes_is_not_recovered(self): def test_loop_stays_open_during_short_successful_run(self): container = FakeContainer(uptime=3) wd, alerts = make_watchdog(container) - for _ in range(3): - die(wd) + trigger_loop(wd, container) wd._poll_all_containers() self.assertEqual([a.failure_type for a in alerts], ["crashed", "restart-loop"]) self.assertEqual(wd.state.get(container.name).alerted_for, "restart-loop") @@ -102,14 +115,12 @@ def test_loop_stays_open_during_short_successful_run(self): def test_after_sustained_recovery_send_once_and_reset_loop_counters(self): container = FakeContainer(uptime=3) wd, alerts = make_watchdog(container, stable=120) - for _ in range(3): - die(wd) + trigger_loop(wd, container) container.attrs["State"]["StartedAt"] = started_ago(130) wd.state.get(container.name).last_failure_time = time.time() - 130 wd._poll_all_containers() wd._poll_all_containers() - self.assertEqual([a.failure_type for a in alerts], - ["crashed", "restart-loop", "recovered"]) + self.assertEqual([a.failure_type for a in alerts], ["crashed", "restart-loop", "recovered"]) self.assertFalse(wd.state.get(container.name).restart_times) def test_healthy_event_cannot_bypass_restart_stability(self): @@ -149,9 +160,13 @@ def test_poll_detects_lost_events_from_docker_restart_count(self): def test_oom_restart_loop_does_not_alternate_oom_and_loop_alerts(self): container = FakeContainer() wd, alerts = make_watchdog(container) - for _ in range(6): - wd._handle_event({"Action": "oom", "Actor": {"Attributes": { - "name": container.name}}}) + wd._poll_all_containers() + wd._handle_event({"Action": "oom", "Actor": {"Attributes": {"name": container.name}}}) + die(wd, code=137) + container.attrs["RestartCount"] = 3 + wd._poll_all_containers() + for _ in range(5): + wd._handle_event({"Action": "oom", "Actor": {"Attributes": {"name": container.name}}}) die(wd, code=137) self.assertEqual([a.failure_type for a in alerts], ["oom", "restart-loop"]) self.assertFalse(wd._oom_containers) @@ -159,8 +174,7 @@ def test_oom_restart_loop_does_not_alternate_oom_and_loop_alerts(self): def test_unhealthy_events_do_not_replace_open_restart_loop(self): container = FakeContainer() wd, alerts = make_watchdog(container) - for _ in range(3): - die(wd) + trigger_loop(wd, container) for _ in range(4): wd._handle_event({"Action": "health_status: unhealthy", "Actor": {"Attributes": {"name": container.name}}}) @@ -169,8 +183,7 @@ def test_unhealthy_events_do_not_replace_open_restart_loop(self): def test_native_unhealthy_polls_do_not_replace_open_restart_loop(self): container = FakeContainer() wd, alerts = make_watchdog(container) - for _ in range(3): - die(wd) + trigger_loop(wd, container) container.attrs["State"]["Health"] = {"Status": "unhealthy"} for _ in range(4): wd._poll_all_containers() @@ -179,35 +192,32 @@ def test_native_unhealthy_polls_do_not_replace_open_restart_loop(self): def test_changing_restart_policy_does_not_falsely_recover_active_loop(self): container = FakeContainer() wd, alerts = make_watchdog(container, stable=120) - for _ in range(3): - die(wd) + trigger_loop(wd, container) container.attrs["HostConfig"]["RestartPolicy"]["Name"] = "no" wd._poll_all_containers() self.assertEqual([a.failure_type for a in alerts], ["crashed", "restart-loop"]) container.attrs["State"]["StartedAt"] = started_ago(130) wd.state.get(container.name).last_failure_time = time.time() - 130 wd._poll_all_containers() - self.assertEqual([a.failure_type for a in alerts], - ["crashed", "restart-loop", "recovered"]) + self.assertEqual([a.failure_type for a in alerts], ["crashed", "restart-loop", "recovered"]) def test_recreated_container_name_starts_fresh_restart_history(self): container = FakeContainer() wd, alerts = make_watchdog(container, threshold=3) + wd._poll_all_containers() die(wd) die(wd) container.id = "new-container-id" container.attrs["RestartCount"] = 0 die(wd) self.assertEqual([a.failure_type for a in alerts], ["crashed", "crashed"]) - self.assertEqual(len(wd.state.get(container.name).restart_times), 1) - self.assertEqual(len(wd.state.get(container.name).pending_event_times), 1) + self.assertEqual(len(wd.state.get(container.name).restart_times), 0) def test_recovery_disabled_clears_loop_state_after_stability(self): container = FakeContainer(uptime=1) wd, alerts = make_watchdog(container) wd.cfg["alert_on_recovery"] = False - for _ in range(3): - die(wd) + trigger_loop(wd, container) container.attrs["State"]["StartedAt"] = started_ago(130) wd.state.get(container.name).last_failure_time = time.time() - 130 wd._poll_all_containers() @@ -235,20 +245,17 @@ def test_clean_exit_loop_detected_when_docker_restart_count_advances(self): def test_manual_http_probe_does_not_overwrite_restart_loop(self): container = FakeContainer() wd, alerts = make_watchdog(container) - for _ in range(3): - die(wd) + trigger_loop(wd, container) wd._manual_checks[container.name] = {"type": "http", "internal_port": 8080} with patch.object(wd, "_manual_health_check", return_value=(False, "HTTP probe failed - 503")): for _ in range(4): wd._poll_all_containers() self.assertEqual([a.failure_type for a in alerts], ["crashed", "restart-loop"]) - self.assertEqual(wd.state.get(container.name).alerted_for, "restart-loop") def test_manual_exec_probe_does_not_overwrite_restart_loop(self): container = FakeContainer() wd, alerts = make_watchdog(container) - for _ in range(3): - die(wd) + trigger_loop(wd, container) wd._manual_checks[container.name] = {"type": "exec", "command": ["false"]} with patch.object(wd, "_manual_health_check", return_value=(False, "Exec probe failed")): for _ in range(4): @@ -258,39 +265,36 @@ def test_manual_exec_probe_does_not_overwrite_restart_loop(self): def test_auto_discovered_probe_does_not_overwrite_restart_loop(self): container = FakeContainer() wd, alerts = make_watchdog(container) - for _ in range(3): - die(wd) + trigger_loop(wd, container) wd._auto_cfg = {"enabled": True} with patch.object(wd, "_auto_discover_health_check", return_value=(False, "HTTP probe failed - 503")): for _ in range(4): wd._poll_all_containers() self.assertEqual([a.failure_type for a in alerts], ["crashed", "restart-loop"]) - def test_mixed_event_and_poll_missing_restarts_escalate(self): + def test_counter_detects_restarts_even_with_missing_events(self): container = FakeContainer(count=0) wd, alerts = make_watchdog(container, threshold=5) + wd._poll_all_containers() die(wd) die(wd) - # First polling baseline was established after two event-observed failures. container.attrs["RestartCount"] = 2 wd._poll_all_containers() - # Event stream has missed three further Docker auto-restarts. container.attrs["RestartCount"] = 5 wd._poll_all_containers() self.assertEqual([a.failure_type for a in alerts], ["crashed", "restart-loop"]) + self.assertEqual(len(wd.state.get(container.name).restart_times), 5) - def test_mixed_event_and_poll_overlap_does_not_double_count(self): + def test_counter_counts_each_restart_once_despite_event_overlap(self): container = FakeContainer(count=0) wd, alerts = make_watchdog(container, threshold=5) - wd._poll_all_containers() # establish count=0 baseline + wd._poll_all_containers() die(wd) die(wd) - container.attrs["RestartCount"] = 3 # 2 event-observed + 1 missed + container.attrs["RestartCount"] = 3 wd._poll_all_containers() self.assertEqual([a.failure_type for a in alerts], ["crashed"]) - self.assertEqual(len(wd.state.get(container.name).restart_times) + - len(wd.state.get(container.name).poll_restart_times), 3) - # Second interval: one event seen and one event missed = 5 total. + self.assertEqual(len(wd.state.get(container.name).restart_times), 3) die(wd) container.attrs["RestartCount"] = 5 wd._poll_all_containers() @@ -298,13 +302,13 @@ def test_mixed_event_and_poll_overlap_does_not_double_count(self): def test_restart_loop_emits_once_even_after_cooldown(self): container = FakeContainer() - wd, alerts = make_watchdog(container, threshold=3) - for _ in range(3): - die(wd) + wd, alerts = make_watchdog(container) + trigger_loop(wd, container) state = wd.state.get(container.name) state.last_alert_time = time.time() - 1000 - for _ in range(5): + for i in range(5): die(wd) + container.attrs["RestartCount"] += 1 wd._poll_all_containers() self.assertEqual([a.failure_type for a in alerts], ["crashed", "restart-loop"]) @@ -319,39 +323,36 @@ def test_recreated_container_must_raise_new_crash_incident(self): def test_recreated_container_does_not_inherit_restart_loop(self): container = FakeContainer() - wd, alerts = make_watchdog(container, threshold=3) - for _ in range(3): - die(wd) + wd, alerts = make_watchdog(container) + trigger_loop(wd, container) container.id = "replacement-unique-id" container.attrs["RestartCount"] = 0 die(wd) - self.assertEqual([a.failure_type for a in alerts], - ["crashed", "restart-loop", "crashed"]) + self.assertEqual([a.failure_type for a in alerts], ["crashed", "restart-loop", "crashed"]) self.assertEqual(wd.state.get(container.name).alerted_for, "crashed") - def test_die_before_restartcount_advances_is_matched_on_later_poll(self): + def test_die_before_counter_increment_does_not_count_early(self): container = FakeContainer(count=0) wd, alerts = make_watchdog(container, threshold=5) wd._poll_all_containers() die(wd) - wd._poll_all_containers() # Docker's RestartCount is still 0 at this point - self.assertEqual(len(wd.state.get(container.name).pending_event_times), 1) + wd._poll_all_containers() + self.assertEqual(len(wd.state.get(container.name).restart_times), 0) container.attrs["RestartCount"] = 1 wd._poll_all_containers() self.assertEqual(len(wd.state.get(container.name).restart_times), 1) - self.assertEqual(len(wd.state.get(container.name).poll_restart_times), 0) - self.assertEqual(len(wd.state.get(container.name).pending_event_times), 0) self.assertEqual([a.failure_type for a in alerts], ["crashed"]) - def test_first_poll_after_die_before_restartcount_advance_keeps_pending(self): + def test_initial_zero_counter_baseline_does_not_count_event(self): container = FakeContainer(count=0) - wd, _ = make_watchdog(container, threshold=5) + wd, alerts = make_watchdog(container) die(wd) - wd._poll_all_containers() # baseline=0 while event's start is still pending - self.assertEqual(len(wd.state.get(container.name).pending_event_times), 1) + wd._poll_all_containers() # establishes baseline at 0 + self.assertEqual(len(wd.state.get(container.name).restart_times), 0) container.attrs["RestartCount"] = 1 wd._poll_all_containers() - self.assertEqual(len(wd.state.get(container.name).poll_restart_times), 0) + self.assertEqual(len(wd.state.get(container.name).restart_times), 1) + self.assertEqual([a.failure_type for a in alerts], ["crashed"]) def test_old_instance_event_id_cannot_crash_replacement(self): container = FakeContainer() @@ -368,15 +369,13 @@ def test_old_instance_event_id_cannot_crash_replacement(self): def test_poll_clears_stale_incident_for_replacement_instance(self): container = FakeContainer() wd, alerts = make_watchdog(container) - for _ in range(3): - die(wd) + trigger_loop(wd, container) container.id = "new-unique-id" container.attrs["RestartCount"] = 0 wd._poll_all_containers() self.assertEqual(wd.state.get(container.name).alerted_for, "") die(wd) - self.assertEqual([a.failure_type for a in alerts], - ["crashed", "restart-loop", "crashed"]) + self.assertEqual([a.failure_type for a in alerts], ["crashed", "restart-loop", "crashed"]) def test_persisted_container_identity_prevents_stale_alert_after_restart(self): with tempfile.TemporaryDirectory() as td: @@ -400,6 +399,116 @@ def test_persisted_container_identity_prevents_stale_alert_after_restart(self): die(wd) self.assertEqual([a.failure_type for a in alerts], ["crashed"]) + def test_timestamp_parser_prefers_nanoseconds_then_seconds(self): + now = time.time() + self.assertAlmostEqual( + watchdog.docker_event_timestamp({"timeNano": int(now * 1_000_000_000), "time": 1}), + now, places=4) + self.assertEqual(watchdog.docker_event_timestamp({"time": 123}), 123) + self.assertIsNone(watchdog.docker_event_timestamp({})) + + def test_genuinely_new_event_after_recovery_creates_new_crash(self): + container = FakeContainer() + wd, alerts = make_watchdog(container) + trigger_loop(wd, container) + container.attrs["State"]["StartedAt"] = started_ago(130) + wd.state.get(container.name).last_failure_time = time.time() - 130 + wd._poll_all_containers() + when = time.time() + die(wd, occurred_at=when) + self.assertEqual([a.failure_type for a in alerts], + ["crashed", "restart-loop", "recovered", "crashed"]) + + def test_counter_before_delayed_events_cannot_duplicate_restarts(self): + container = FakeContainer(count=0) + wd, alerts = make_watchdog(container, threshold=5) + wd._poll_all_containers() + occurred_at = time.time() - 3 + container.attrs["RestartCount"] = 3 + wd._poll_all_containers() + for _ in range(2): + die(wd, occurred_at=occurred_at) + self.assertEqual(len(wd.state.get(container.name).restart_times), 3) + self.assertNotIn("restart-loop", [a.failure_type for a in alerts]) + wd._poll_all_containers() + self.assertNotIn("restart-loop", [a.failure_type for a in alerts]) + + def test_nonzero_historical_baseline_does_not_consume_a_new_event(self): + container = FakeContainer(count=7) + wd, alerts = make_watchdog(container, threshold=5) + wd._poll_all_containers() + die(wd) + wd._poll_all_containers() # RestartCount still 7 + self.assertFalse(wd.state.get(container.name).restart_times) + container.attrs["RestartCount"] = 8 + wd._poll_all_containers() + self.assertEqual(len(wd.state.get(container.name).restart_times), 1) + self.assertEqual([a.failure_type for a in alerts], ["crashed"]) + + def test_delayed_events_older_than_window_are_not_counted(self): + container = FakeContainer(count=0) + wd, alerts = make_watchdog(container, threshold=5) + wd._poll_all_containers() + for _ in range(5): + die(wd, occurred_at=time.time() - 700) + self.assertNotIn("restart-loop", [a.failure_type for a in alerts]) + self.assertFalse(wd.state.get(container.name).restart_times) + + def test_poll_gap_longer_than_window_baselines_unknown_increments(self): + container = FakeContainer(count=0) + wd, alerts = make_watchdog(container, threshold=5) + wd._poll_all_containers() + state = wd.state.get(container.name) + state.last_restart_poll_at = time.time() - 700 + container.attrs["RestartCount"] = 9 + wd._poll_all_containers() + self.assertEqual(len(state.restart_times), 0) + self.assertNotIn("restart-loop", [a.failure_type for a in alerts]) + container.attrs["RestartCount"] = 10 + wd._poll_all_containers() + self.assertEqual(len(state.restart_times), 1) + + def test_expired_restart_observations_are_not_counted_after_poll_gap(self): + container = FakeContainer(count=0) + wd, alerts = make_watchdog(container, threshold=5) + wd._poll_all_containers() + container.attrs["RestartCount"] = 4 + wd._poll_all_containers() + state = wd.state.get(container.name) + state.restart_times = [time.time() - 700] * 4 + state.last_restart_poll_at = time.time() - 700 + container.attrs["RestartCount"] = 5 + wd._poll_all_containers() + self.assertFalse(state.restart_times) + self.assertNotIn("restart-loop", [a.failure_type for a in alerts]) + + def test_delayed_die_after_recovery_does_not_reopen_incident(self): + container = FakeContainer(count=0) + wd, alerts = make_watchdog(container) + trigger_loop(wd, container) + old_failure = time.time() - 150 + container.attrs["State"]["StartedAt"] = started_ago(130) + wd.state.get(container.name).last_failure_time = time.time() - 130 + wd._poll_all_containers() + self.assertEqual([a.failure_type for a in alerts], ["crashed", "restart-loop", "recovered"]) + die(wd, occurred_at=old_failure) + self.assertEqual([a.failure_type for a in alerts], ["crashed", "restart-loop", "recovered"]) + self.assertEqual(wd.state.get(container.name).alerted_for, "") + + def test_counter_rollover_restarts_new_baseline(self): + container = FakeContainer(count=0) + wd, alerts = make_watchdog(container) + wd._poll_all_containers() + container.attrs["RestartCount"] = 2 + wd._poll_all_containers() + container.attrs["RestartCount"] = 0 + wd._poll_all_containers() + self.assertFalse(wd.state.get(container.name).restart_times) + container.attrs["RestartCount"] = 1 + wd._poll_all_containers() + self.assertEqual(len(wd.state.get(container.name).restart_times), 1) + self.assertNotIn("restart-loop", [a.failure_type for a in alerts]) + def test_event_and_poll_counts_are_not_double_counted(self): container = FakeContainer(count=0) wd, alerts = make_watchdog(container, threshold=5) diff --git a/watchdog-config.yaml.example b/watchdog-config.yaml.example index 4a3dff1..cdf9429 100644 --- a/watchdog-config.yaml.example +++ b/watchdog-config.yaml.example @@ -18,7 +18,7 @@ alert_channels: # ── Watchdog global settings ──────────────────────────────────────────────────────── check_interval_seconds: 60 # how often to poll all containers cooldown_minutes: 5 # suppress duplicate alerts per container -restart_threshold: 5 # number of restarts within the window triggers alert +restart_threshold: 5 # Docker RestartCount increments within the window trigger alert restart_window_minutes: 10 # rolling window for restart counting restart_recovery_stability_seconds: 120 # require 2 min continuous uptime before RECOVERED for auto-restarting containers unhealthy_cycles_threshold: 3 # consecutive unhealthy cycles before alerting diff --git a/watchdog.py b/watchdog.py index a5b17a8..d411876 100644 --- a/watchdog.py +++ b/watchdog.py @@ -155,17 +155,17 @@ def _host_boot_time() -> int: class ContainerState: __slots__ = ("name", "lock", "unhealthy_cycles", "restart_times", - "poll_restart_times", "pending_event_times", "last_failure_time", - "last_container_id", "last_alert_time", "alerted_for", "last_restart_count") + "last_restart_count", "last_restart_poll_at", "last_failure_time", + "last_recovery_time", "last_container_id", "last_alert_time", "alerted_for") def __init__(self, name: str): self.name = name self.lock = threading.Lock() # event thread and poll thread both mutate this self.unhealthy_cycles: int = 0 - self.restart_times: list[float] = [] # timestamped Docker die events - self.poll_restart_times: list[float] = [] # missing restarts inferred from RestartCount - self.pending_event_times: list[float] = [] # die events not yet matched to RestartCount + self.restart_times: list[float] = [] # counter increments observed via Docker inspect + self.last_restart_poll_at: float = 0.0 self.last_failure_time: float = 0.0 + self.last_recovery_time: float = 0.0 self.last_container_id: str = "" self.last_alert_time: float = 0.0 self.alerted_for: str = "" @@ -1245,6 +1245,18 @@ def container_started_timestamp(container) -> float | None: return None +def docker_event_timestamp(event: dict) -> float | None: + """Use the Docker occurrence time, not the receipt time, if supplied.""" + try: + if event.get("timeNano"): + return float(event["timeNano"]) / 1_000_000_000 + if event.get("time"): + return float(event["time"]) + except (ValueError, TypeError, OverflowError): + pass + return None + + # ── Core watchdog logic ─────────────────────────────────────────────────────── class Watchdog: def __init__(self, cfg: dict): @@ -1417,10 +1429,10 @@ def _sync_container_identity(self, state: ContainerState, container) -> None: state.name, previous_id[:12], cid[:12]) state.unhealthy_cycles = 0 state.restart_times.clear() - state.poll_restart_times.clear() - state.pending_event_times.clear() state.last_restart_count = -1 + state.last_restart_poll_at = 0.0 state.last_failure_time = 0.0 + state.last_recovery_time = 0.0 state.alerted_for = "" state.last_alert_time = 0.0 state.last_container_id = cid @@ -1451,8 +1463,7 @@ def _maybe_alert_recovery(self, container, state: ContainerState) -> None: # A resolved loop must not re-alert from restarts still in the # rolling 10-minute window. Start a fresh episode on next failure. state.restart_times.clear() - state.poll_restart_times.clear() - state.pending_event_times.clear() + state.last_restart_poll_at = now try: state.last_restart_count = int(container.attrs.get("RestartCount", 0) or 0) except (TypeError, ValueError): @@ -1460,6 +1471,7 @@ def _maybe_alert_recovery(self, container, state: ContainerState) -> None: state.last_failure_time = 0.0 state.alerted_for = "" state.last_alert_time = now + state.last_recovery_time = now self.state.save(self._boot_time) if not self.cfg.get("alert_on_recovery", True): log.info("%s recovered from %s — recovery notification disabled", @@ -1513,6 +1525,14 @@ def _handle_event(self, event: dict) -> None: state = self.state.get(name) self._sync_container_identity(state, container) + event_time = docker_event_timestamp(event) + if action in ("die", "oom", "health_status: unhealthy") and event_time is not None: + with state.lock: + stale = bool(state.last_recovery_time and event_time <= state.last_recovery_time) + if stale: + log.debug("%s: ignoring delayed %s event from before recovery", name, action) + return + if action == "die": self._discovered_checks.pop(name, None) # clear cache — container may restart exit_code_str = attributes.get("exitCode", "0") @@ -1529,41 +1549,20 @@ def _handle_event(self, event: dict) -> None: ) return - # Consume the OOM -> die pairing even if this die promotes an - # existing OOM alert to restart-loop. + # Consume paired OOM/die events, but never count event deliveries + # as restarts: Docker RestartCount is authoritative. oom_die = name in self._oom_containers if oom_die: self._oom_containers.discard(name) automatic = has_automatic_restart_policy(container) - now = time.time() - with state.lock: - if automatic and exit_code != 0: - state.restart_times = [ - t for t in state.restart_times if now - t < self._restart_window_secs - ] - # A die event reliably records a failed *run*, even when - # several Docker restarts happen between 60-second polls. - # Clean exit 0 is not counted here: Docker stop/start during - # maintenance is not evidence of an automatic restart. - # The poller still catches clean-exit loops via RestartCount. - state.restart_times.append(now) - state.pending_event_times.append(now) - state.last_failure_time = now - elif exit_code != 0: - state.last_failure_time = now - restarts = len(state.restart_times) + len(state.poll_restart_times) - previous = state.alerted_for - - if automatic and restarts >= self._restart_threshold: - if self._claim_alert(state, "restart-loop"): - payload = build_payload( - container, "restart-loop", self.host, self.runbook_base, - probe_detail=( - f"Restart-loop event detected - at least {restarts} restarts " - f"in {int(self._restart_window_secs // 60)}min window" - )) - self._dispatch(payload) - return + if exit_code != 0: + with state.lock: + failure_at = event_time if event_time is not None else time.time() + state.last_failure_time = max(state.last_failure_time, failure_at) + previous = state.alerted_for + else: + with state.lock: + previous = state.alerted_for if previous == "restart-loop": log.info("%s: die event during active restart-loop — suppressing crashed alert", name) @@ -1598,7 +1597,8 @@ def _handle_event(self, event: dict) -> None: failure_type = "oom" with state.lock: if has_automatic_restart_policy(container): - state.last_failure_time = time.time() + failure_at = event_time if event_time is not None else time.time() + state.last_failure_time = max(state.last_failure_time, failure_at) active_loop = state.alerted_for == "restart-loop" self._oom_containers.add(name) # mark so the imminent die event is suppressed if active_loop: @@ -1682,32 +1682,24 @@ def _poll_all_containers(self) -> None: restart_count = 0 with state.lock: - state.restart_times = [t for t in state.restart_times - if now - t < restart_window] - state.poll_restart_times = [t for t in state.poll_restart_times - if now - t < restart_window] - state.pending_event_times = [t for t in state.pending_event_times - if now - t < restart_window] + state.restart_times = [ + t for t in state.restart_times if now - t < restart_window + ] if state.last_restart_count < 0 or restart_count < state.last_restart_count: - # Initial baseline and Docker counter resets: existing - # RestartCount may include events seen before our first poll. - # Consume only events already reflected in that count. - matched = min(restart_count, len(state.pending_event_times)) - del state.pending_event_times[:matched] - state.last_restart_count = restart_count + # First observation or counter reset: do not count history. + state.restart_times.clear() elif restart_count > state.last_restart_count: - # Reconcile *this interval's* counter delta with event - # observations not yet reflected by Docker's counter. - # A die can arrive before Docker increments RestartCount, - # so carry unmatched events forward until a later poll. - new_restarts = restart_count - state.last_restart_count - matched = min(new_restarts, len(state.pending_event_times)) - del state.pending_event_times[:matched] - missing = new_restarts - matched - state.poll_restart_times.extend([now] * min(missing, restart_threshold)) - state.last_restart_count = restart_count - # Only inferred MISSING restarts are additive to die events. - restarts = len(state.restart_times) + len(state.poll_restart_times) + if state.last_restart_poll_at and now - state.last_restart_poll_at < restart_window: + delta = restart_count - state.last_restart_count + state.restart_times.extend([now] * min(delta, restart_threshold)) + else: + # A long pause makes the age of increments unknowable. + # Baseline rather than risking a false 10-minute loop. + log.info("%s: skipping %d restarts after polling gap", + name, restart_count - state.last_restart_count) + state.last_restart_count = restart_count + state.last_restart_poll_at = now + restarts = len(state.restart_times) if restarts >= restart_threshold: failure_type = "restart-loop" From 1b55b9d010a0ea97c2d3c70ad1534a115029333b Mon Sep 17 00:00:00 2001 From: Container Alert Integration Date: Wed, 14 Oct 2026 14:56:59 +0000 Subject: [PATCH 4/4] test: align restart and event fixtures after PR6 integration --- tests/test_event_missing.py | 2 +- tests/test_restart_loop.py | 1 + 2 files changed, 2 insertions(+), 1 deletion(-) diff --git a/tests/test_event_missing.py b/tests/test_event_missing.py index 4be608e..6687daf 100644 --- a/tests/test_event_missing.py +++ b/tests/test_event_missing.py @@ -80,7 +80,7 @@ def test_idless_legacy_name_is_reinspected(self): def test_rename_and_name_reuse_records_old_container_not_new(self): monitor = self.make_subject() - old = SimpleNamespace(name="service-old", attrs={"Config": {"Labels": {}}}) + old = SimpleNamespace(name="service-old", id="old-id", attrs={"Config": {"Labels": {}}}) monitor.client.containers.get.side_effect = None monitor.client.containers.get.return_value = old monitor._ignored_events = [] diff --git a/tests/test_restart_loop.py b/tests/test_restart_loop.py index bcbba1b..9c533c0 100644 --- a/tests/test_restart_loop.py +++ b/tests/test_restart_loop.py @@ -47,6 +47,7 @@ def make_watchdog(container, threshold=3, stable=120): wd._ignored_events = [] wd._discovered_checks = {} wd._oom_containers = set() + wd._missing_events = {} # PR #6 event cache (normal Watchdog init owns it) wd._auto_cfg = {"enabled": False} wd._manual_checks = {} wd._boot_time = 1