From 4c2b043051c455d3af6370d0c5f2df78d8fd98c5 Mon Sep 17 00:00:00 2001 From: ChatGPT-assisted development Date: Tue, 13 Oct 2026 22:03:26 +0000 Subject: [PATCH] Correlate Docker planned stops before crash alerts --- Dockerfile | 2 +- README.md | 25 +++- lifecycle.py | 114 ++++++++++++++++++ tests/test_lifecycle.py | 222 ++++++++++++++++++++++++++++++++++ watchdog-config.yaml.example | 16 +++ watchdog.py | 226 ++++++++++++++++++++++++++++------- 6 files changed, 559 insertions(+), 46 deletions(-) create mode 100644 lifecycle.py create mode 100644 tests/test_lifecycle.py diff --git a/Dockerfile b/Dockerfile index 6109679..082acd8 100644 --- a/Dockerfile +++ b/Dockerfile @@ -11,7 +11,7 @@ RUN pip install --no-cache-dir \ "cryptography>=42.0" # Copy agent -COPY watchdog.py . +COPY watchdog.py lifecycle.py . # UID 1000 account for install.sh's non-root hardening path (docker-compose.yaml # defaults to root; install.sh instead sets WATCHDOG_UID/GID to run as this user). diff --git a/README.md b/README.md index 30a825f..0533fe8 100644 --- a/README.md +++ b/README.md @@ -42,7 +42,7 @@ The watchdog runs two parallel monitoring paths: | Path | Mechanism | What It Catches | |------|-----------|-----------------| -| **Event stream** | `docker events` (real-time) | Crashes (`die`), OOM-kills (`oom`), health status changes | +| **Event stream** | `docker events` (real-time) | Crashes (`die`), OOM-kills (`oom`), health changes, requested stops (`stop`), kill signals (`kill`) | | **Active Probes** | `docker ps` + Probes | **Integrity**: Periodic verification of liveness, stuck states, and restart-loops | The watchdog selects one of **4 active probe types** per container, chosen automatically based on the container's configuration. Probe selection is cached for the container's lifetime and re-discovered on restart. @@ -61,7 +61,11 @@ 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. -**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. +**Planned-stop correlation** (enabled by default): the event listener also captures Docker `stop`, `kill` and `start`. A lightweight worker holds `die` for up to 3 seconds so it can correlate a subsequent or preceding `stop` event for the **same container ID**. A matching `stop` is treated as a Docker-requested stop rather than an application crash, even if exit code is 137 (SIGKILL); that forced shutdown is logged as WARNING. `kill` alone never suppresses CRITICAL: direct `docker kill` does not prove an administrative stop. OOM events still produce the existing OOM CRITICAL instead of duplicate CRASH. If stop evidence is absent or delayed beyond the configured window, the watchdog alerts on the nonzero death (fail-closed). The 3-second grace does not block event ingestion. The INFO notification for requested stops is optional and **off** by default. An observed Docker stop does not establish operator authorization or acceptable service downtime. + +**Opt-in critical-service availability**: configure exact container names under `expected_running_containers` (default empty) to receive a CRITICAL `not-running` alert when a specified service is exited, restarting, or missing for `expected_running_grace_seconds` (default 120 seconds). This covers accidental or intentional stops that leave an essential service offline. A pre-existing CRASH/OOM/health alert takes precedence to avoid duplicate outage messages. On watchdog restart, the downtime grace timer starts fresh. The feature monitors Docker state and is not a substitute for application readiness or an audited maintenance workflow. + +**Recovery alerts**: once a container that was previously alarmed (`crashed`, `oom`, `unhealthy`, `restart-loop`, or `not-running`) 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. --- @@ -72,6 +76,7 @@ Two additional deduplication rules suppress redundant alerts at the event level: ``` . ├── watchdog.py # Main monitor script +├── lifecycle.py # Docker stop/die/oom correlation ├── watchdog-config.yaml # All configuration (no secrets) ├── docker-compose.yaml # Production / offline runtime (image only) ├── docker-compose.build.yaml # Developer / online build @@ -132,6 +137,12 @@ All non-secret settings live in `watchdog-config.yaml`. Secrets (webhook URLs, p | `restart_window_minutes` | `10` | Rolling window for restart counting | | `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 | +| `lifecycle_detection.enabled` | `true` | Enable Docker stop/kill/start event correlation | +| `lifecycle_detection.correlation_window_seconds` | `3` | Hold die decisions up to 3 seconds to match a Docker stop (0.5-30 seconds supported) | +| `lifecycle_detection.notify_on_docker_stop` | `false` | Send INFO on Docker-requested stops, including forced stops (otherwise log locally) | +| `lifecycle_detection.log_forced_stop_warning` | `true` | Log WARNING when a requested stop ends in exit 137/SIGKILL | +| `expected_running_containers` | `[]` | Exact container names to monitor for prolonged stopped/missing state | +| `expected_running_grace_seconds` | `120` | Seconds to wait before alerting on a configured expected-running container | | `excluded_containers` | `[]` | Container names to never alert on | | `ignored_container_events` | MariaDB syntax-check label rule | Label-based event suppressions for intentional temporary containers | | `auto_health_check` | enabled | Probe containers reporting `health=none` by discovering an HTTP/TCP endpoint | @@ -231,7 +242,7 @@ Each trap carries five var-binds, all under the Radware enterprise OID arc (`1.3 | `1.3.6.1.4.1.89.110.1.1.0` | `cwHost` | Hostname of the alerting node | | `1.3.6.1.4.1.89.110.1.2.0` | `cwSummary` | Human-readable alert summary | | `1.3.6.1.4.1.89.110.1.3.0` | `cwContainerName` | Container name | -| `1.3.6.1.4.1.89.110.1.4.0` | `cwFailureType` | `crashed` / `oom` / `unhealthy` / `restart-loop` / `recovered` | +| `1.3.6.1.4.1.89.110.1.4.0` | `cwFailureType` | `crashed` / `oom` / `unhealthy` / `restart-loop` / `not-running` / `docker-stop` / `recovered` | | `1.3.6.1.4.1.89.110.1.5.0` | `cwProbeDetail` | Probe failure detail | --- @@ -252,11 +263,13 @@ bash install.sh | Failure | Severity | Trigger | |---------|----------|---------| -| `crashed` | CRITICAL | Container exited with non-zero exit code | +| `crashed` | CRITICAL | Nonzero death without a matching Docker stop or OOM event | | `oom` | CRITICAL | Container was OOM-killed by the kernel | | `unhealthy` | HIGH | Health probe failing for N consecutive cycles | | `restart-loop` | HIGH | Container restarted ≥ threshold times within window | -| `recovered` | INFO | Previously-alarmed container (`crashed`/`oom`/`unhealthy`/`restart-loop`) is healthy/running again. Fires once per incident; controlled by `alert_on_recovery` (default `true`) | +| `docker-stop` | INFO (opt-in) | Matching Docker stop event detected; does not create an open alert | +| `not-running` | CRITICAL (opt-in) | Explicitly expected-running container remains exited, restarting, or missing beyond grace period | +| `recovered` | INFO | Previously-alarmed container (`crashed`/`oom`/`unhealthy`/`restart-loop`/`not-running`) is healthy/running again. Fires once per incident; controlled by `alert_on_recovery` (default `true`) | | `reboot-summary` | INFO / HIGH | Sent once after a host reboot is detected, when the `boot_grace_seconds` window closes. Reports boot time, how many containers are running, which recovered, and which are still failing. Always sent after a reboot — an INFO summary confirms the node came back cleanly. HIGH if any container is still failing | OOM alerts include **memory stats** (usage / limit / peak) prepended to the log snippet. @@ -270,6 +283,8 @@ Every alert includes two probe fields that identify exactly how and why the fail |---------|------------|-------------------------| | `crashed` | `Docker event (crash)` | `Crash probe failed — container exited with exit code 1` | | `oom` | `Docker event (OOM)` | `OOM probe failed — container was OOM-killed by the kernel` | +| `docker-stop` | `Docker event (stop)` | `Docker stop event confirmed; exit code 137; observed kill signals: 15, 9` | +| `not-running` | `Docker state (poll)` | `Expected-running container is exited; not running for at least 120s` | | `unhealthy` (Docker native HEALTHCHECK) | `Docker HEALTHCHECK` | `Docker health probe failed — exit code 1, output: connection refused` | | `unhealthy` (HTTP auto-probe) | `HTTP GET` | `HTTP probe failed — error response 503 Service Unavailable, URI http://172.18.0.5:8080/health` | | `unhealthy` (TCP connect) | `TCP connect` | `TCP probe failed — connection refused or timed out on 172.18.0.5:6379 (Connection refused)` | diff --git a/lifecycle.py b/lifecycle.py new file mode 100644 index 0000000..1a9b465 --- /dev/null +++ b/lifecycle.py @@ -0,0 +1,114 @@ +"""Small, thread-safe Docker lifecycle event correlator. + +Docker emits die and stop in either order for requested stops. A kill event by +itself is not evidence of an administrative stop (docker kill also emits kill). +The listener records events; the watchdog resolves pending deaths asynchronously. +""" + +from dataclasses import dataclass +import threading +import time + + +@dataclass +class PendingDeath: + container_id: str + name: str + exit_code: int | None + container: object + happened_at: float + signals: tuple[str, ...] = () + stopped: bool = False + oom: bool = False + + +class DockerLifecycleCorrelator: + """Correlate stop/kill/oom with die, keyed by Docker container ID. + + The window is measured from event ingestion on a monotonic clock. + Unknown or absent stop evidence must NOT suppress a crash. + """ + + def __init__(self, window_seconds: float = 3.0): + self.window = max(0.0, float(window_seconds)) + self._lock = threading.Lock() + self._pending: list[PendingDeath] = [] + self._recent_stops: dict[str, float] = {} + self._recent_kills: dict[str, list[tuple[float, str]]] = {} + self._signal_history_seconds = max(120.0, self.window) + + def record( + self, + action: str, + container_id: str, + *, + name: str = "", + container: object = None, + exit_code: int | None = None, + signal: str = "", + now: float | None = None, + ) -> bool: + if not container_id: + return False + now = time.monotonic() if now is None else now + matched = False + with self._lock: + # Prune bounded correlation evidence even for short-lived containers. + self._recent_stops = { + cid: at for cid, at in self._recent_stops.items() + if 0 <= now - at <= self.window + } + self._recent_kills = { + cid: [(at, sig) for at, sig in values + if 0 <= now - at <= self._signal_history_seconds] + for cid, values in self._recent_kills.items() + if any(0 <= now - at <= self._signal_history_seconds + for at, _ in values) + } + if action == "start": + # Prevent a stop from a preceding run matching a new death. + self._recent_stops.pop(container_id, None) + self._recent_kills.pop(container_id, None) + elif action == "kill": + value = str(signal or "unknown") + entries = self._recent_kills.setdefault(container_id, []) + entries.append((now, value)) + if len(entries) > 8: + del entries[:-8] + # Event delivery can be slightly out of order. + for death in self._pending: + if death.container_id == container_id and 0 <= now - death.happened_at <= self.window: + death.signals = (*death.signals, value)[-8:] + elif action == "stop": + self._recent_stops[container_id] = now + for death in self._pending: + if death.container_id == container_id and 0 <= now - death.happened_at <= self.window: + death.stopped = True + elif action == "oom": + for death in self._pending: + if death.container_id == container_id and 0 <= now - death.happened_at <= self.window: + death.oom = True + matched = True + elif action == "die": + stopped_at = self._recent_stops.get(container_id) + stopped = stopped_at is not None and 0 <= now - stopped_at <= self.window + signals = tuple(sig for _, sig in self._recent_kills.get(container_id, ())) + self._pending.append(PendingDeath( + container_id=container_id, name=name, exit_code=exit_code, + container=container, happened_at=now, + signals=signals, stopped=stopped, + )) + return matched + + def drain_ready(self, *, now: float | None = None, force: bool = False) -> list[PendingDeath]: + """Return resolved events. Unmatched deaths wait for the full window.""" + now = time.monotonic() if now is None else now + with self._lock: + ready, waiting = [], [] + for death in self._pending: + if force or death.stopped or death.oom or now - death.happened_at >= self.window: + ready.append(death) + else: + waiting.append(death) + self._pending = waiting + return ready diff --git a/tests/test_lifecycle.py b/tests/test_lifecycle.py new file mode 100644 index 0000000..b0e1004 --- /dev/null +++ b/tests/test_lifecycle.py @@ -0,0 +1,222 @@ +"""Regression coverage for planned Docker stops and real termination failures.""" + +import threading +import unittest +from types import SimpleNamespace + +from lifecycle import DockerLifecycleCorrelator +import watchdog + + +CID = "a" * 64 +OTHER_ID = "b" * 64 + + +class LifecycleCorrelatorTests(unittest.TestCase): + def test_forced_docker_stop_die_before_stop(self): + tracker = DockerLifecycleCorrelator(3) + tracker.record("kill", CID, signal="15", now=100) + tracker.record("kill", CID, signal="9", now=110) + tracker.record("die", CID, name="svc", exit_code=137, now=110.01) + self.assertEqual(tracker.drain_ready(now=110.02), []) + tracker.record("stop", CID, now=110.05) + [death] = tracker.drain_ready(now=110.06) + self.assertTrue(death.stopped) + self.assertEqual(death.signals, ("15", "9")) + self.assertEqual(death.exit_code, 137) + + def test_stop_before_die_is_correlated(self): + tracker = DockerLifecycleCorrelator(3) + tracker.record("stop", CID, now=200) + tracker.record("die", CID, name="svc", exit_code=143, now=200.1) + [death] = tracker.drain_ready(now=200.2) + self.assertTrue(death.stopped) + + def test_kill_without_stop_cannot_suppress(self): + tracker = DockerLifecycleCorrelator(3) + tracker.record("kill", CID, signal="9", now=100) + tracker.record("die", CID, name="svc", exit_code=137, now=100.1) + tracker.record("stop", OTHER_ID, now=100.2) + self.assertEqual(tracker.drain_ready(now=102), []) + [death] = tracker.drain_ready(now=103.1) + self.assertFalse(death.stopped) + self.assertEqual(death.signals, ("9",)) + + def test_late_stop_cannot_suppress_timeout(self): + tracker = DockerLifecycleCorrelator(3) + tracker.record("die", CID, name="svc", exit_code=137, now=100) + tracker.record("stop", CID, now=105) + [death] = tracker.drain_ready(now=105) + self.assertFalse(death.stopped) + + def test_restart_clears_stale_stop_evidence(self): + tracker = DockerLifecycleCorrelator(3) + tracker.record("stop", CID, now=100) + tracker.record("start", CID, now=100.1) + tracker.record("die", CID, name="svc", exit_code=1, now=100.2) + [death] = tracker.drain_ready(now=104) + self.assertFalse(death.stopped) + + def test_oom_after_die_marks_pending(self): + tracker = DockerLifecycleCorrelator(3) + tracker.record("die", CID, name="svc", exit_code=137, now=100) + self.assertTrue(tracker.record("oom", CID, now=100.1)) + [death] = tracker.drain_ready(now=100.1) + self.assertTrue(death.oom) + + def test_unmatched_oom_returns_false(self): + tracker = DockerLifecycleCorrelator(3) + self.assertFalse(tracker.record("oom", CID, now=100)) + + +class DummyContainer: + def __init__(self, name="svc", cid=CID): + self.name = name + self.id = cid + self.labels = {} + self.attrs = { + "Config": {"Image": "test/svc:latest", "Labels": {}}, + "HostConfig": {"AutoRemove": False}, + "State": {"OOMKilled": False}, + "Mounts": [], + } + self.image = SimpleNamespace(tags=["test/svc:latest"]) + + def logs(self, **kwargs): + return b"test container log" + + def stats(self, **kwargs): + return {"memory_stats": {}} + + +class WatchdogLifecycleTests(unittest.TestCase): + def setUp(self): + self.container = DummyContainer() + w = object.__new__(watchdog.Watchdog) + w.cfg = {"alert_on_recovery": True} + w.host = "lab" + w.runbook_base = "https://example.invalid/runbook" + w._excluded = set() + w._ignored_events = [] + w._discovered_checks = {} + w._oom_containers = set() + w._lifecycle_enabled = True + w._lifecycle = DockerLifecycleCorrelator(3) + w._lifecycle_wake = threading.Event() + w._lifecycle_cfg = { + "notify_on_docker_stop": False, + "log_forced_stop_warning": True, + } + w.state = watchdog.WatchdogState("") + w._cooldown_minutes = 5 + w._boot_time = 0 + w._unhealthy_threshold = 3 + self.alerts = [] + w._dispatch = self.alerts.append + w.client = SimpleNamespace(containers=SimpleNamespace(get=lambda cid: self.container)) + w._expected_running = set() + w._expected_down_since = {} + w._expected_running_grace = 120 + self.w = w + + def event(self, action, *, exit_code=None, signal=None, cid=CID): + attrs = {"name": "svc"} + if exit_code is not None: + attrs["exitCode"] = str(exit_code) + if signal is not None: + attrs["signal"] = str(signal) + return {"Action": action, "Actor": {"ID": cid, "Attributes": attrs}} + + def resolve(self, *, force=False): + for death in self.w._lifecycle.drain_ready(force=force): + self.w._resolve_lifecycle_death(death) + + def test_exact_october_incident_planned_sigkill_no_critical(self): + self.w._handle_event(self.event("kill", signal=15)) + self.w._handle_event(self.event("kill", signal=9)) + self.w._handle_event(self.event("die", exit_code=137)) + self.assertEqual(self.alerts, []) + self.w._handle_event(self.event("stop")) + self.resolve() + self.assertEqual(self.alerts, []) + self.assertEqual(self.w.state.get("svc").alerted_for, "") + + def test_requested_stop_notification_is_info_only(self): + self.w._lifecycle_cfg["notify_on_docker_stop"] = True + self.w._handle_event(self.event("die", exit_code=137)) + self.w._handle_event(self.event("stop")) + self.resolve() + self.assertEqual(len(self.alerts), 1) + self.assertEqual(self.alerts[0].severity, "INFO") + self.assertEqual(self.alerts[0].failure_type, "docker-stop") + self.assertEqual(self.w.state.get("svc").alerted_for, "") + + def test_direct_docker_kill_is_critical(self): + self.w._handle_event(self.event("kill", signal=9)) + self.w._handle_event(self.event("die", exit_code=137)) + self.resolve(force=True) + self.assertEqual(len(self.alerts), 1) + self.assertEqual(self.alerts[0].failure_type, "crashed") + self.assertEqual(self.alerts[0].severity, "CRITICAL") + self.assertIn("OOM", self.alerts[0].recommended_action) + + def test_unexpected_nonzero_exit_is_critical(self): + self.w._handle_event(self.event("die", exit_code=1)) + self.resolve(force=True) + self.assertEqual([a.failure_type for a in self.alerts], ["crashed"]) + + def test_exit_zero_no_alert(self): + self.w._handle_event(self.event("die", exit_code=0)) + self.resolve(force=True) + self.assertEqual(self.alerts, []) + + def test_oom_before_die_only_oom(self): + self.w._handle_event(self.event("oom")) + self.w._handle_event(self.event("die", exit_code=137)) + self.resolve(force=True) + self.assertEqual([a.failure_type for a in self.alerts], ["oom"]) + + def test_oom_after_die_only_oom_and_no_stale_marker(self): + self.w._handle_event(self.event("die", exit_code=137)) + self.w._handle_event(self.event("oom")) + self.resolve() + self.assertEqual([a.failure_type for a in self.alerts], ["oom"]) + self.assertEqual(self.w._oom_containers, set()) + + def test_established_restart_loop_suppresses_die(self): + self.w.state.get("svc").alerted_for = "restart-loop" + self.w._handle_event(self.event("die", exit_code=1)) + self.resolve(force=True) + self.assertEqual(self.alerts, []) + + def test_expected_running_alerts_after_grace(self): + self.w._expected_running = {"svc"} + self.w._check_expected_running({"svc": "exited"}, now=100) + self.w._check_expected_running({"svc": "exited"}, now=219) + self.assertEqual(self.alerts, []) + self.w._check_expected_running({"svc": "exited"}, now=220) + self.assertEqual([a.failure_type for a in self.alerts], ["not-running"]) + self.w._check_expected_running({"svc": "exited"}, now=250) + self.assertEqual(len(self.alerts), 1) + self.w._check_expected_running({"svc": "running"}, now=251) + self.w._maybe_alert_recovery(self.container, self.w.state.get("svc")) + self.assertEqual([a.failure_type for a in self.alerts], + ["not-running", "recovered"]) + + def test_expected_running_missing_container_alerts(self): + self.w._expected_running = {"svc"} + self.w._check_expected_running({}, now=100) + self.w._check_expected_running({}, now=230) + self.assertEqual(self.alerts[0].failure_type, "not-running") + self.assertIn("missing", self.alerts[0].probe_detail) + + def test_expected_running_does_not_duplicate_open_crash(self): + self.w._expected_running = {"svc"} + self.w.state.get("svc").alerted_for = "crashed" + self.w._check_expected_running({"svc": "exited"}, now=100) + self.w._check_expected_running({"svc": "exited"}, now=230) + self.assertEqual(self.alerts, []) + + +if __name__ == "__main__": + unittest.main() diff --git a/watchdog-config.yaml.example b/watchdog-config.yaml.example index ad27b58..4adf508 100644 --- a/watchdog-config.yaml.example +++ b/watchdog-config.yaml.example @@ -23,6 +23,22 @@ restart_window_minutes: 10 # rolling window for restart counting unhealthy_cycles_threshold: 3 # consecutive unhealthy cycles before alerting alert_on_recovery: true # send an INFO "recovered" alert when a container returns to normal +# Docker stop events may arrive before OR after "die". Briefly hold a crash +# decision so intentional docker stop/restart does not appear as an app crash. +# docker kill alone is NOT considered a planned stop. +lifecycle_detection: + enabled: true + correlation_window_seconds: 3 # live-event correlation, valid range 0.5-30s + notify_on_docker_stop: false # if true, send INFO notification for stopped containers + log_forced_stop_warning: true # local WARNING if requested stop finished with SIGKILL (137) + +# Optional safety net: containers that should always run. A requested docker +# stop suppresses a crash alert, but sustained downtime remains CRITICAL here. +# These names must be explicitly listed; empty list disables the check. +expected_running_containers: [] + # - config_kvision-vdirect_1 +expected_running_grace_seconds: 120 + # Containers to never alert on (debug, test, or one-shot containers) excluded_containers: [] # - my-temp-container diff --git a/watchdog.py b/watchdog.py index aab65fa..d8d1621 100644 --- a/watchdog.py +++ b/watchdog.py @@ -26,6 +26,8 @@ import socket import yaml +from lifecycle import DockerLifecycleCorrelator + # ── Logging setup ───────────────────────────────────────────────────────────── LOG_FORMAT = "%(asctime)s [%(levelname)s] %(name)s: %(message)s" SYSLOG_FORMAT = "watchdog[%(process)d]: %(levelname)s %(name)s: %(message)s" @@ -88,6 +90,14 @@ def setup_logging(level: str, log_file: str | None, syslog_cfg: dict | None = No "restart_window_minutes": 10, "unhealthy_cycles_threshold": 3, "alert_on_recovery": True, + "lifecycle_detection": { + "enabled": True, + "correlation_window_seconds": 3, + "notify_on_docker_stop": False, + "log_forced_stop_warning": True, + }, + "expected_running_containers": [], + "expected_running_grace_seconds": 120, "excluded_containers": [], "ignored_container_events": [ { @@ -271,6 +281,10 @@ def _probe_type_label(detail: str) -> str: return "Docker event (crash)" if detail.startswith("OOM probe failed"): return "Docker event (OOM)" + if detail.startswith("Docker stop event confirmed"): + return "Docker event (stop)" + if detail.startswith("Expected-running container"): + return "Docker state (poll)" if detail.startswith("Restart-loop probe failed"): return "Restart-loop tracking" return "" @@ -283,6 +297,8 @@ def _default_probe_type(failure_type: str) -> str: "oom": "Docker event (OOM)", "unhealthy": "Docker HEALTHCHECK", "restart-loop": "Restart-loop tracking", + "docker-stop": "Docker event (stop)", + "not-running": "Docker state (poll)", }.get(failure_type, "") @@ -966,7 +982,8 @@ def _suppress_invalid_state(loop, context): "crashed": ( "CRITICAL", "Check exit code and logs. Run: docker logs --tail 50. " - "If exit code 137, likely OOM — increase memory limit.", + "Exit 137 means SIGKILL, not necessarily OOM. Check OOMKilled and " + "Docker kill/stop/oom events before adjusting memory limits.", ), "oom": ( "CRITICAL", @@ -983,6 +1000,15 @@ def _suppress_invalid_state(loop, context): "Container is in a restart loop. Check logs for crash reason. " "Consider increasing RestartSec or investigating root cause.", ), + "docker-stop": ( + "INFO", + "Docker requested a stop. Check whether the service was expected to stop.", + ), + "not-running": ( + "CRITICAL", + "A designated always-running container is stopped or missing. Confirm " + "maintenance, inspect container events, and restore the service.", + ), "recovered": ( "INFO", "Container is back to normal operation. No action required.", @@ -1232,6 +1258,27 @@ def __init__(self, cfg: dict): self._ignored_events: list[dict] = cfg.get("ignored_container_events") or [] self._discovered_checks: dict[str, dict | None] = {} # auto-discovery cache self._oom_containers: set[str] = set() # suppress die alert when oom already fired + _lcfg = cfg.get("lifecycle_detection") or {} + self._lifecycle_cfg = _lcfg if isinstance(_lcfg, dict) else {} + self._lifecycle_enabled = bool(self._lifecycle_cfg.get("enabled", True)) + try: + _window = float(self._lifecycle_cfg.get("correlation_window_seconds", 3)) + except (TypeError, ValueError): + _window = 3.0 + if not 0.5 <= _window <= 30.0: + log.warning("Invalid lifecycle correlation window %r; using 3 seconds", _window) + _window = 3.0 + self._lifecycle = DockerLifecycleCorrelator(_window) + self._lifecycle_wake = threading.Event() + _expected = cfg.get("expected_running_containers") or [] + self._expected_running = (set(str(n) for n in _expected if n) + if isinstance(_expected, list) else set()) + self._expected_running.difference_update(self._excluded) + try: + self._expected_running_grace = max(0, int(cfg.get("expected_running_grace_seconds", 120))) + except (TypeError, ValueError): + self._expected_running_grace = 120 + self._expected_down_since: dict[str, float] = {} self._auto_cfg: dict = cfg.get("auto_health_check", {}) _manual = cfg.get("container_health_checks") or {} self._manual_checks: dict = _manual if isinstance(_manual, dict) else {} @@ -1381,10 +1428,72 @@ def _maybe_alert_recovery(self, container, state: ContainerState) -> None: probe_detail=f"Recovered from '{previous}'") self._dispatch(payload) + # ── Docker lifecycle correlation ──────────────────────────────────────── + def _lifecycle_worker(self) -> None: + """Deliver queued deaths after a short window without blocking events.""" + while not self._stop_event.is_set(): + self._lifecycle_wake.wait(0.2) + self._lifecycle_wake.clear() + for death in self._lifecycle.drain_ready(): + try: + self._resolve_lifecycle_death(death) + except Exception: + log.exception("Failed to resolve Docker death event for %s", death.name) + + def _emit_crash(self, container, name: str, exit_code: int | None, + observed_signals: tuple[str, ...] = ()) -> None: + state = self.state.get(name) + if state.alerted_for == "restart-loop": + log.info("%s: die during restart-loop — suppressing redundant crash", name) + return + if exit_code == 0: + log.info("%s exited cleanly (code 0) — no alert", name) + return + if exit_code == 137: + log.warning("%s: exit 137 (SIGKILL) without matching Docker stop/oom; " + "inspect OOMKilled and recent Docker events. signals=%s", + name, observed_signals or "none") + if self._claim_alert(state, "crashed"): + reason = (f"no matching Docker stop/oom event within {self._lifecycle.window:g}s" + if self._lifecycle_enabled else "lifecycle correlation disabled") + detail = (f"Crash probe failed - container exited with code {exit_code}; " + f"{reason}; observed kill signals: " + f"{', '.join(observed_signals) or 'none'}") + payload = build_payload(container, "crashed", self.host, + self.runbook_base, exit_code, probe_detail=detail) + self._dispatch(payload) + + def _resolve_lifecycle_death(self, death) -> None: + if death.oom: + log.info("%s: die correlated with OOM — no duplicate crash", death.name) + return + signals = ", ".join(death.signals) or "none" + if death.stopped: + detail = (f"Docker stop event confirmed; exit code {death.exit_code}; " + f"observed kill signals: {signals}. " + "This confirms a Docker-requested stop, not authorization.") + if death.exit_code == 137 and self._lifecycle_cfg.get("log_forced_stop_warning", True): + log.warning("%s: Docker-requested stop ended with SIGKILL (exit 137); " + "the application may not handle graceful shutdown; signals=%s", + death.name, signals) + else: + log.info("%s: Docker-requested stop; exit=%s signals=%s", + death.name, death.exit_code, signals) + if self._lifecycle_cfg.get("notify_on_docker_stop", False): + payload = build_payload(death.container, "docker-stop", self.host, + self.runbook_base, death.exit_code, + probe_detail=detail) + self._dispatch(payload) + return + self._emit_crash(death.container, death.name, death.exit_code, death.signals) + # ── Event stream listener ───────────────────────────────────────────────── def _event_listener(self) -> None: log.info("Docker event listener started") - filters = {"type": "container", "event": ["die", "oom", "health_status"]} + events = ["die", "oom", "health_status"] + if self._lifecycle_enabled: + events += ["stop", "kill", "start"] + filters = {"type": "container", "event": events} try: for event in self.client.events(decode=True, filters=filters): if self._stop_event.is_set(): @@ -1397,17 +1506,27 @@ def _event_listener(self) -> None: threading.Thread(target=self._event_listener, daemon=True).start() def _handle_event(self, event: dict) -> None: - action = event.get("Action", "") - attributes = event.get("Actor", {}).get("Attributes", {}) - name = attributes.get("name", "unknown") + action = event.get("Action", "") + actor = event.get("Actor") or {} + attributes = actor.get("Attributes") or {} + name = attributes.get("name", "unknown") + container_id = str(actor.get("ID") or event.get("id") or event.get("ID") or "") if name in self._excluded: return - log.debug("Docker event: %s on %s", action, name) + # Stop/kill can occur after the container has disappeared from Docker's + # API. Record them BEFORE attempting a container lookup. + if action in ("stop", "kill", "start"): + if self._lifecycle_enabled: + self._lifecycle.record(action, container_id, + signal=attributes.get("signal", "")) + self._lifecycle_wake.set() + return + try: - container = self.client.containers.get(name) + container = self.client.containers.get(container_id or name) except docker.errors.NotFound: log.warning("Container %s not found for event %s", name, action) return @@ -1415,57 +1534,47 @@ def _handle_event(self, event: dict) -> None: 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) 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 + self._discovered_checks.pop(name, None) + # Keep existing deduplication for OOM and established restart loops. if name in self._oom_containers: self._oom_containers.discard(name) - log.info("%s: die event follows OOM — suppressing duplicate crashed alert", name) + log.info("%s: die follows OOM — suppressing duplicate crash", 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) + log.info("%s: die during restart loop — suppressing duplicate crash", name) return - exit_code_str = attributes.get("exitCode", "0") try: - exit_code = int(exit_code_str) + exit_code = int(attributes.get("exitCode", "0")) 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)", + "%s: Suppressing expected Cyber Controller SQL dump syntax-check " + "container termination (image=%s, AutoRemove=true, mount=%s, exit=137)", name, _KVISION_MARIADB_DUMP_HELPER_IMAGE, _KVISION_MARIADB_DUMP_MOUNT, ) return - # exit 0 = graceful stop, no alert - if exit_code == 0: - log.info("%s exited cleanly (code 0) — no 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}") - self._dispatch(payload) + if self._lifecycle_enabled and container_id: + self._lifecycle.record("die", container_id, name=name, + container=container, exit_code=exit_code) + self._lifecycle_wake.set() + else: + self._emit_crash(container, name, exit_code) elif action == "oom": - failure_type = "oom" - self._oom_containers.add(name) # mark so the imminent die event is suppressed - if self._claim_alert(state, failure_type): - payload = build_payload(container, failure_type, self.host, - self.runbook_base, + # OOM takes precedence over a pending crash even if events are reordered. + matched_pending = False + if self._lifecycle_enabled: + matched_pending = self._lifecycle.record("oom", container_id) + self._lifecycle_wake.set() + # A late OOM attached to a queued die must not suppress the NEXT die. + if not matched_pending: + self._oom_containers.add(name) + if self._claim_alert(state, "oom"): + payload = build_payload(container, "oom", self.host, self.runbook_base, extra_context=get_memory_stats(container), probe_detail="OOM probe failed - container was OOM-killed by the kernel") self._dispatch(payload) @@ -1492,6 +1601,34 @@ def _handle_event(self, event: dict) -> None: state.unhealthy_cycles = 0 self._maybe_alert_recovery(container, state) + def _check_expected_running(self, observed: dict[str, str], now: float) -> None: + """Opt-in check: planned maintenance must not hide prolonged downtime.""" + for name in sorted(self._expected_running): + status = observed.get(name, "missing") + if status in ("running", "unknown"): + self._expected_down_since.pop(name, None) + continue + down_since = self._expected_down_since.setdefault(name, now) + if now - down_since < self._expected_running_grace: + continue + state = self.state.get(name) + with state.lock: + open_reason = state.alerted_for + if open_reason and open_reason not in ("recovered", "not-running"): + # A crash/OOM/health alert already describes this outage. + continue + if self._claim_alert(state, "not-running"): + payload = AlertPayload( + severity="CRITICAL", container_name=name, container_id="", + host=self.host, failure_type="not-running", + exit_code=None, log_tail="", + recommended_action=ACTIONS["not-running"][1], + runbook_url=self.runbook_base, + probe_detail=(f"Expected-running container is {status}; " + f"not running for at least {self._expected_running_grace}s."), + ) + self._dispatch(payload) + # ── Poll loop ───────────────────────────────────────────────────────────── def _poll_loop(self) -> None: interval = self.cfg.get("check_interval_seconds", 60) @@ -1510,6 +1647,7 @@ def _poll_all_containers(self) -> None: unhealthy_threshold = self._unhealthy_threshold now = time.time() seen_names: set[str] = set() + observed_statuses: dict[str, str] = {} for container in self.client.containers.list(all=True): name = container.name @@ -1520,8 +1658,10 @@ def _poll_all_containers(self) -> None: try: container.reload() except Exception: + observed_statuses[name] = "unknown" continue + observed_statuses[name] = container.status status = container.status # running, exited, restarting, etc. health = self._get_health(container) # healthy, unhealthy, none state = self.state.get(name) @@ -1622,6 +1762,8 @@ def _poll_all_containers(self) -> None: # During the post-reboot window a restored container may not exist yet — # keep its open alert so the recovery still fires once it comes back. + self._check_expected_running(observed_statuses, time.monotonic()) + seen_names.update(self._expected_running) self.state.cleanup_stale(seen_names, retain_open=bool(self._grace_until)) # Clean up discovery cache for containers no longer running for _name in self._discovered_checks.keys() - seen_names: @@ -1956,6 +2098,9 @@ def start(self) -> None: target=self._event_listener, name="event-listener", daemon=True ) event_thread.start() + if self._lifecycle_enabled: + threading.Thread(target=self._lifecycle_worker, name="lifecycle-worker", + daemon=True).start() # Poll runs in the main thread try: self._poll_loop() @@ -1967,6 +2112,7 @@ def start(self) -> None: def stop(self) -> None: log.info("Watchdog shutting down") self._stop_event.set() + self._lifecycle_wake.set() self.state.save(self._boot_time)