From af94451ac1a1a6745aebc3c95a3fe83d23aa1f09 Mon Sep 17 00:00:00 2001 From: rdwr-egore Date: Wed, 14 Oct 2026 19:59:40 +0000 Subject: [PATCH 1/2] fix: align notification details and syslog event priorities --- README.md | 13 ++++- tests/test_ha_monitor.py | 7 ++- tests/test_notifications.py | 106 ++++++++++++++++++++++++++++++++++++ watchdog.py | 90 ++++++++++++++++++++++-------- 4 files changed, 191 insertions(+), 25 deletions(-) create mode 100644 tests/test_notifications.py diff --git a/README.md b/README.md index 2574a8c..cf9092c 100644 --- a/README.md +++ b/README.md @@ -250,6 +250,17 @@ syslog: facility: local0 ``` +Syslog is an **alert and error stream**, not a per-poll health feed. It sends +one structured, single-line event="container_alert" record per emitted incident +(including INFO recoveries and reboot summaries), plus watchdog ERROR/CRITICAL +diagnostics. Routine INFO/WARNING polling messages stay local; per-container +poll output is available at log_level: DEBUG. The alert records include the +severity, UTC time, host, container, failure type, detection evidence and action, +with special previous/new active-node fields for HA. The syslog priority is +CRITICAL=2, HIGH=3 (error), WARNING=4 and INFO=6; the facility remains +configurable. Values are quoted, escaped and length-limited for ingestion. +Syslog is configured independently from alert_channels. + ### SMTP (Email) Add `smtp` to `alert_channels` to enable. @@ -289,7 +300,7 @@ snmp_trap: # v3_local_engine_id: "" # hex engine ID pinned from first-run log; see DEPLOYMENT.md ``` -Each trap carries five var-binds, all under the Radware enterprise OID arc (`1.3.6.1.4.1.89.110`): +SNMP retains its five existing var-binds and OIDs for NMS compatibility.\nThe human-readable cwSummary contains severity; cwProbeDetail contains\ndetection evidence. No additional SNMP objects are introduced in v1.6.0.\n\nEach trap carries five var-binds, all under the Radware enterprise OID arc (`1.3.6.1.4.1.89.110`): | OID | Object | Value | |-----|--------|-------| diff --git a/tests/test_ha_monitor.py b/tests/test_ha_monitor.py index 93023fd..8351736 100644 --- a/tests/test_ha_monitor.py +++ b/tests/test_ha_monitor.py @@ -351,9 +351,12 @@ def test_slack_ha_fields_and_no_false_container(self): def test_syslog_logging_includes_transition_and_dispatches_snmp(self): alert = self.make_alert() - with patch("watchdog.log.warning") as warn, patch("watchdog.send_snmp_trap") as trap: + with patch("watchdog.log.log") as logged, patch("watchdog.send_snmp_trap") as trap: watchdog.dispatch_alert(alert, {"alert_channels": ["snmp_trap", "syslog"]}) - self.assertIn(f"{A} -> {B}", warn.call_args.args[1]) + self.assertEqual(logged.call_args.args[0], watchdog.logging.WARNING) + self.assertIn(f'previous_active="{A}"', logged.call_args.args[1]) + self.assertIn(f'new_active="{B}"', logged.call_args.args[1]) + self.assertTrue(logged.call_args.kwargs["extra"]["watchdog_alert"]) trap.assert_called_once() def test_smtp_ha_notification_identifies_role_change(self): diff --git a/tests/test_notifications.py b/tests/test_notifications.py new file mode 100644 index 0000000..c11a24c --- /dev/null +++ b/tests/test_notifications.py @@ -0,0 +1,106 @@ +"""Notification consistency and syslog regression tests (no network).""" +import logging +import unittest +from unittest.mock import patch +from email.parser import BytesParser +from email.policy import default + +import watchdog + + +def alert(severity="CRITICAL", failure="crashed"): + return watchdog.AlertPayload( + severity, "demo-service", "abcdef123456789", "vision", failure, 137, + "", "Inspect Docker events and logs.", "https://example.invalid/runbook", + 'Crash probe failed - SIGKILL; OOM not confirmed', + ) + + +class NotificationTests(unittest.TestCase): + def test_oom_evidence_only_when_confirmed(self): + p = alert("CRITICAL", "oom") + p.probe_detail = ("OOM probe failed - container was OOM-killed by the kernel; " + "memory usage=63.0 MB limit=64.0 MB") + data = watchdog.format_syslog_alert(p) + self.assertIn('failure_type="oom"', data) + self.assertIn('memory usage=63.0 MB', data) + self.assertNotIn('failure_type="crashed"', data) + + def test_native_levels_match_incident_severity(self): + for severity, expected in (("CRITICAL", logging.CRITICAL), + ("HIGH", logging.ERROR), + ("WARNING", logging.WARNING), + ("INFO", logging.INFO)): + with self.subTest(severity=severity): + p = alert(severity) + with patch("watchdog.log.log") as log: + watchdog.dispatch_alert(p, {"alert_channels": []}) + self.assertEqual(log.call_args.args[0], expected) + self.assertIn(f'severity="{severity}"', log.call_args.args[1]) + self.assertTrue(log.call_args.kwargs["extra"]["watchdog_alert"]) + + def test_syslog_filter_rejects_poll_noise_and_keeps_recovery_and_errors(self): + f = watchdog.AlertSyslogFilter() + def record(level, is_alert=False): + r = logging.LogRecord("watchdog", level, __file__, 1, "message", (), None) + if is_alert: + r.watchdog_alert = True + return r + self.assertFalse(f.filter(record(logging.INFO))) + self.assertFalse(f.filter(record(logging.WARNING))) + self.assertTrue(f.filter(record(logging.INFO, True))) + self.assertTrue(f.filter(record(logging.WARNING, True))) + self.assertTrue(f.filter(record(logging.ERROR))) + + def test_syslog_has_evidence_without_false_oom_and_escapes_content(self): + p = alert() + p.probe_detail = 'line one\nline "two"' + data = watchdog.format_syslog_alert(p) + for fragment in ('event="container_alert"', 'severity="CRITICAL"', + 'failure_type="crashed"', 'exit_code="137"', + 'host="vision"', 'container="demo-service"', + 'container_id="abcdef123456"', + 'probe_type="Docker event (crash)"', + 'action="Inspect Docker events and logs."'): + self.assertIn(fragment, data) + self.assertIn(r'line one\nline \"two\"', data) + self.assertNotIn('failure_type="oom"', data) + self.assertNotIn("\n", data) + + def test_long_untrusted_detection_is_bounded(self): + p = alert() + p.probe_detail = "x" * 20000 + data = watchdog.format_syslog_alert(p) + self.assertLess(len(data), 2000) + self.assertIn('...', data) + + def test_email_includes_detection_without_assuming_oom(self): + p = alert() + cfg = {"smtp": {"enabled": True, "auth": False, "tls": False, + "host": "mail.invalid", "port": 25, + "sender": "alerts@example.invalid", + "recipients": ["ops@example.invalid"]}} + with patch("smtplib.SMTP") as smtp: + watchdog.send_smtp(p, cfg) + sent = smtp.return_value.__enter__.return_value.sendmail.call_args.args[2] + body = BytesParser(policy=default).parsebytes(sent).get_body( + preferencelist=("plain",)).get_content() + for item in ("Container ID: abcdef123456", "Severity: CRITICAL", + "Exit Code: 137", "Probe Type: Docker event (crash)", + "OOM not confirmed", "Runbook: https://example.invalid/runbook"): + self.assertIn(item, body) + + def test_slack_fields_match_alert_payload(self): + p = alert() + with patch.dict("os.environ", {"SLACK_WEBHOOK_URL": "https://example.invalid/slack"}): + with patch("watchdog.requests.post") as post: + watchdog.send_slack(p, {"slack": {"enabled": True}}) + fields = post.call_args.kwargs["json"]["attachments"][0]["fields"] + values = {field["title"]: field["value"] for field in fields} + self.assertEqual(values["Severity"], "CRITICAL") + self.assertEqual(values["Exit Code"], "137") + self.assertEqual(values["Detection"], p.probe_detail) + + +if __name__ == "__main__": + unittest.main() diff --git a/watchdog.py b/watchdog.py index 61c1b0e..f5434e2 100644 --- a/watchdog.py +++ b/watchdog.py @@ -31,7 +31,15 @@ # ── Logging setup ───────────────────────────────────────────────────────────── LOG_FORMAT = "%(asctime)s [%(levelname)s] %(name)s: %(message)s" -SYSLOG_FORMAT = "watchdog[%(process)d]: %(levelname)s %(name)s: %(message)s" +SYSLOG_FORMAT = "watchdog[%(process)d]: %(message)s" + + +class AlertSyslogFilter(logging.Filter): + """Forward alert records and actual errors, not routine poll diagnostics.""" + + def filter(self, record: logging.LogRecord) -> bool: + return bool(getattr(record, "watchdog_alert", False) or record.levelno >= logging.ERROR) + log = logging.getLogger("watchdog") @@ -70,6 +78,7 @@ def setup_logging(level: str, log_file: str | None, syslog_cfg: dict | None = No log.warning("Syslog disabled — cannot reach %s:%d (%s): %s", host, port, proto, exc) else: syslog_handler.setFormatter(logging.Formatter(SYSLOG_FORMAT)) + syslog_handler.addFilter(AlertSyslogFilter()) handlers.append(syslog_handler) # Use a plain formatter for other handlers, syslog gets its own log.info("Syslog handler added: %s:%d (%s)", host, port, proto) @@ -402,12 +411,14 @@ def send_slack(payload: AlertPayload, cfg: dict) -> None: ha_event = payload.failure_type == "ha-failover" ha_fields = [ {"title": "Event", "value": "HA active-node change", "short": True}, + {"title": "Severity", "value": payload.severity, "short": True}, {"title": "Previous active", "value": payload.ha_previous_node, "short": True}, {"title": "New active", "value": payload.ha_new_node, "short": True}, {"title": "Host", "value": payload.host, "short": True}, {"title": "Time (UTC)", "value": payload.timestamp, "short": True}, *probe_field, {"title": "Action", "value": payload.recommended_action, "short": False}, + {"title": "Runbook", "value": payload.runbook_url, "short": False}, ] body = { "attachments": [{ @@ -439,19 +450,47 @@ def send_slack(payload: AlertPayload, cfg: dict) -> None: +def _syslog_field(value: object, limit: int = 512) -> str: + """Single-line, bounded, quote-safe key/value field for SIEM parsing.""" + value = str(value).replace("\\", "\\\\").replace("\r", "\\r").replace("\n", "\\n") + value = value[:limit] + ("..." if len(value) > limit else "") + return '"' + value.replace('"', '\\"') + '"' + + +def format_syslog_alert(payload: AlertPayload) -> str: + """Same incident facts as human-facing notifications; bounded for UDP syslog.""" + details = { + "event": "container_alert", + "severity": payload.severity, + "failure_type": payload.failure_type, + "time_utc": payload.timestamp, + "host": payload.host, + "container": payload.container_name, + "container_id": payload.container_id, + "probe_type": payload.probe_type, + "detection": payload.probe_detail, + "action": payload.recommended_action, + "runbook": payload.runbook_url, + } + if payload.exit_code is not None: + details["exit_code"] = payload.exit_code + if payload.failure_type == "ha-failover": + details["previous_active"] = payload.ha_previous_node + details["new_active"] = payload.ha_new_node + return " ".join(f"{key}={_syslog_field(value, 250 if key in ('detection', 'action') else 120)}" + for key, value in details.items() if value not in ("", "N/A")) + + +def _alert_log_level(severity: str) -> int: + return {"CRITICAL": logging.CRITICAL, "HIGH": logging.ERROR, + "WARNING": logging.WARNING, "INFO": logging.INFO}.get(severity, logging.WARNING) + + def dispatch_alert(payload: AlertPayload, cfg: dict) -> None: """Send alert to all configured channels.""" channels = cfg.get("alert_channels", ["slack"]) - log_fn = log.info if payload.failure_type == "recovered" else log.warning - if payload.failure_type == "ha-failover": - log_fn("ALERT %s (channels: %s) — %s", - payload.subject(), channels, payload.probe_detail) - else: - log_fn( - "ALERT [%s] %s — %s (channels: %s)", - payload.severity, payload.container_name, - payload.failure_type, channels, - ) + log.log(_alert_log_level(payload.severity), format_syslog_alert(payload), + extra={"watchdog_alert": True}) if "slack" in channels: send_slack(payload, cfg) if "smtp" in channels: send_smtp(payload, cfg) if "snmp_trap" in channels: send_snmp_trap(payload, cfg) @@ -520,18 +559,23 @@ def send_smtp(payload: AlertPayload, cfg: dict) -> None: f"Previous active: {payload.ha_previous_node}\n" f"New active: {payload.ha_new_node}\n" f"Host: {payload.host}\n" + f"Severity: {payload.severity}\n" f"Observed (UTC): {payload.timestamp}\n" - f"Evidence: {payload.probe_detail}\n\n" - f"Action: {payload.recommended_action}") + f"Evidence: {payload.probe_detail}\n" + f"Action: {payload.recommended_action}\n" + f"Runbook: {payload.runbook_url}") else: body = f"""Container: {payload.container_name} Host: {payload.host} Status: {payload.failure_type} Severity: {payload.severity} Time: {payload.timestamp} +Container ID: {payload.container_id} Exit Code: {payload.exit_code if payload.exit_code is not None else 'N/A'} - -{payload.recommended_action}""" +Probe Type: {payload.probe_type or 'N/A'} +Detection: {payload.probe_detail or 'N/A'} +Action: {payload.recommended_action} +Runbook: {payload.runbook_url or 'N/A'}""" # Build an RFC-compliant MIME message. smtplib.sendmail(str) tries to # encode the whole message as ASCII, which breaks on Unicode text such as @@ -1626,7 +1670,7 @@ def _resolve_lifecycle_death(self, death) -> None: return if death.stopped: if death.exit_code == 137: - log.warning("%s: Docker-requested stop ended with SIGKILL (137), " + log.info("%s: Docker-requested stop ended with SIGKILL (137), " "not proof of OOM", death.name) else: log.info("%s: Docker-requested stop (exit %s)", death.name, death.exit_code) @@ -1789,10 +1833,12 @@ def _handle_event(self, event: dict) -> None: log.info("%s: OOM during active restart-loop — suppressing per-cycle OOM alert", name) return if self._claim_alert(state, failure_type): + memory = get_memory_stats(container) payload = build_payload(container, failure_type, self.host, self.runbook_base, - extra_context=get_memory_stats(container), - probe_detail="OOM probe failed - container was OOM-killed by the kernel") + extra_context=memory, + probe_detail=("OOM probe failed - container was OOM-killed by the kernel" + + (f"; {memory}" if memory.startswith("memory usage=") else ""))) self._dispatch(payload) elif action == "health_status: unhealthy": @@ -1949,11 +1995,11 @@ def _poll_all_containers(self) -> None: self._dispatch(payload) if status == "restarting": - log.info("CONTAINER %-30s status=%-12s health=%s", name, status, health) + log.debug("CONTAINER %-30s status=%-12s health=%s", name, status, health) # Detect stuck containers missed by event stream elif status == "running" and health == "unhealthy": - log.info("CONTAINER %-30s status=%-12s health=%s", name, status, health) + log.debug("CONTAINER %-30s status=%-12s health=%s", name, status, health) with state.lock: state.unhealthy_cycles += 1 cycles = state.unhealthy_cycles @@ -1981,7 +2027,7 @@ def _poll_all_containers(self) -> None: # Log with watchdog-assessed health (replaces Docker's "none") display_health = health if health != "none" else ("healthy" if is_healthy else "unhealthy") - log.info("CONTAINER %-30s status=%-12s health=%s", name, status, display_health) + log.debug("CONTAINER %-30s status=%-12s health=%s", name, status, display_health) if not is_healthy: with state.lock: @@ -2010,7 +2056,7 @@ def _poll_all_containers(self) -> None: self._maybe_alert_recovery(container, state) else: - log.info("CONTAINER %-30s status=%-12s health=%s", name, status, health) + log.debug("CONTAINER %-30s status=%-12s health=%s", name, status, health) # 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. From 81f06e26dd274722936f2ad6420cf1168b8ec2d5 Mon Sep 17 00:00:00 2001 From: rdwr-egore Date: Wed, 14 Oct 2026 20:18:09 +0000 Subject: [PATCH 2/2] fix: preserve syslog alerts at local thresholds and run release CI --- .github/workflows/ci.yml | 1 + README.md | 12 ++++- tests/test_ha_monitor.py | 13 ++++++ tests/test_notifications.py | 92 +++++++++++++++++++++++++++++++++++-- watchdog.py | 42 +++++++++-------- 5 files changed, 137 insertions(+), 23 deletions(-) diff --git a/.github/workflows/ci.yml b/.github/workflows/ci.yml index 950e08f..60f9293 100644 --- a/.github/workflows/ci.yml +++ b/.github/workflows/ci.yml @@ -4,6 +4,7 @@ on: pull_request: branches: - main + - "release/**" jobs: validate: diff --git a/README.md b/README.md index cf9092c..f740e79 100644 --- a/README.md +++ b/README.md @@ -251,7 +251,7 @@ syslog: ``` Syslog is an **alert and error stream**, not a per-poll health feed. It sends -one structured, single-line event="container_alert" record per emitted incident +one structured, single-line event="watchdog_alert" record per emitted incident (including INFO recoveries and reboot summaries), plus watchdog ERROR/CRITICAL diagnostics. Routine INFO/WARNING polling messages stay local; per-container poll output is available at log_level: DEBUG. The alert records include the @@ -260,6 +260,10 @@ with special previous/new active-node fields for HA. The syslog priority is CRITICAL=2, HIGH=3 (error), WARNING=4 and INFO=6; the facility remains configurable. Values are quoted, escaped and length-limited for ingestion. Syslog is configured independently from alert_channels. +Local log_level controls only console/file verbosity; INFO recoveries and +WARNING HA alerts still reach Syslog when local log_level is WARNING or ERROR. +HA and reboot-summary records omit pseudo-container fields. + ### SMTP (Email) @@ -300,7 +304,11 @@ snmp_trap: # v3_local_engine_id: "" # hex engine ID pinned from first-run log; see DEPLOYMENT.md ``` -SNMP retains its five existing var-binds and OIDs for NMS compatibility.\nThe human-readable cwSummary contains severity; cwProbeDetail contains\ndetection evidence. No additional SNMP objects are introduced in v1.6.0.\n\nEach trap carries five var-binds, all under the Radware enterprise OID arc (`1.3.6.1.4.1.89.110`): +SNMP retains its five existing var-binds and OIDs for NMS compatibility. +The human-readable cwSummary contains severity; cwProbeDetail contains +detection evidence. No additional SNMP objects are introduced in v1.6.0. + +Each trap carries five var-binds, all under the Radware enterprise OID arc (`1.3.6.1.4.1.89.110`): | OID | Object | Value | |-----|--------|-------| diff --git a/tests/test_ha_monitor.py b/tests/test_ha_monitor.py index 8351736..1ff5c9a 100644 --- a/tests/test_ha_monitor.py +++ b/tests/test_ha_monitor.py @@ -183,6 +183,19 @@ def test_real_watchdog_event_and_persistence(self): restarted._poll_ha(restarted._session) restarted._dispatch.assert_not_called() + def test_ha_exporter_failure_is_error_but_throttled(self): + with tempfile.TemporaryDirectory() as td: + w = self.create_shell(f"{td}/state.json") + with patch("watchdog.read_ha_observation", side_effect=TimeoutError("offline")), \ + patch("watchdog.time.monotonic", side_effect=[1000, 1000, 1100, 1301, 1301]), \ + patch("watchdog.log.error") as err: + w._poll_ha(w._session) + w._poll_ha(w._session) + w._poll_ha(w._session) + self.assertEqual(err.call_count, 2) + self.assertIn("HA check unavailable", err.call_args.args[0]) + w._dispatch.assert_not_called() + def test_failed_exporter_does_not_overwrite_state_or_alert(self): with tempfile.TemporaryDirectory() as td: w = self.create_shell(f"{td}/state.json") diff --git a/tests/test_notifications.py b/tests/test_notifications.py index c11a24c..604de8b 100644 --- a/tests/test_notifications.py +++ b/tests/test_notifications.py @@ -1,9 +1,12 @@ """Notification consistency and syslog regression tests (no network).""" import logging +import socket +import tempfile import unittest from unittest.mock import patch from email.parser import BytesParser from email.policy import default +from pathlib import Path import watchdog @@ -20,12 +23,95 @@ class NotificationTests(unittest.TestCase): def test_oom_evidence_only_when_confirmed(self): p = alert("CRITICAL", "oom") p.probe_detail = ("OOM probe failed - container was OOM-killed by the kernel; " - "memory usage=63.0 MB limit=64.0 MB") + "post-event memory snapshot: usage=63.0 MB, limit=64.0 MB") data = watchdog.format_syslog_alert(p) self.assertIn('failure_type="oom"', data) - self.assertIn('memory usage=63.0 MB', data) + self.assertIn('post-event memory snapshot: usage=63.0 MB', data) self.assertNotIn('failure_type="crashed"', data) + def test_real_syslog_keeps_recovery_and_ha_at_local_warning_or_error(self): + for level in ("WARNING", "ERROR"): + with self.subTest(level=level), tempfile.TemporaryDirectory() as td: + with socket.socket(socket.AF_INET, socket.SOCK_DGRAM) as receiver: + receiver.bind(("127.0.0.1", 0)) + receiver.settimeout(0.6) + watchdog.setup_logging( + level, f"{td}/watchdog.log", + {"enabled": True, "host": "127.0.0.1", + "port": receiver.getsockname()[1], "protocol": "udp"} + ) + try: + watchdog.log.info("routine polling must stay local") + recovery = alert("INFO", "recovered") + recovery.exit_code = None + watchdog.dispatch_alert(recovery, {"alert_channels": []}) + ha = watchdog.AlertPayload( + "WARNING", "(HA cluster)", "", "vision", "ha-failover", + None, "", "Check cluster health", "", + "HA Operator promoted to new node", + ha_previous_node="node-a", ha_new_node="node-b" + ) + watchdog.dispatch_alert(ha, {"alert_channels": []}) + watchdog.log.error("HA check unavailable (TimeoutError): offline") + received = [receiver.recvfrom(8192)[0].decode() + for _ in range(3)] + with self.assertRaises(socket.timeout): + receiver.recvfrom(8192) + self.assertEqual( + [int(msg.split(">", 1)[0][1:]) % 8 for msg in received], + [6, 4, 3]) + self.assertIn('failure_type="recovered"', received[0]) + self.assertIn('failure_type="ha-failover"', received[1]) + self.assertIn("HA check unavailable", received[2]) + self.assertFalse(any("routine polling" in msg for msg in received)) + text = Path(f"{td}/watchdog.log").read_text() + self.assertNotIn("routine polling", text) + self.assertNotIn('failure_type="recovered"', text) + if level == "ERROR": + self.assertNotIn('failure_type="ha-failover"', text) + else: + self.assertIn('failure_type="ha-failover"', text) + finally: + logging.basicConfig( + handlers=[logging.NullHandler()], + level=logging.WARNING, force=True) + + def test_pseudo_container_fields_absent_in_ha_and_reboot_events(self): + for failure, container_name in ( + ("ha-failover", "(HA cluster)"), + ("reboot-summary", "(post-reboot summary)") + ): + with self.subTest(failure=failure): + p = watchdog.AlertPayload( + "INFO", container_name, "", "vision", failure, None, "", + "Check cluster", "", "Event details", + ha_previous_node="node-a", ha_new_node="node-b") + record = watchdog.format_syslog_alert(p) + self.assertIn('event="watchdog_alert"', record) + self.assertIn(f'failure_type="{failure}"', record) + self.assertNotIn('container=', record) + self.assertNotIn('container_id=', record) + self.assertIn('host="vision"', record) + if failure == "ha-failover": + self.assertIn('previous_active="node-a"', record) + self.assertIn('new_active="node-b"', record) + + def test_memory_snapshot_omits_missing_zero_and_unavailable_stats(self): + from unittest.mock import Mock + container = Mock() + container.stats.return_value = { + "memory_stats": {"usage": 0, "limit": 67108864, "max_usage": 12582912} + } + sample = watchdog.get_memory_stats(container) + self.assertIn("post-event memory snapshot:", sample) + self.assertIn("limit=64.0 MB", sample) + self.assertIn("peak=12.0 MB", sample) + self.assertNotIn("usage=", sample) + container.stats.return_value = {"memory_stats": {}} + self.assertEqual(watchdog.get_memory_stats(container), "") + container.stats.side_effect = RuntimeError("unavailable after OOM") + self.assertEqual(watchdog.get_memory_stats(container), "") + def test_native_levels_match_incident_severity(self): for severity, expected in (("CRITICAL", logging.CRITICAL), ("HIGH", logging.ERROR), @@ -56,7 +142,7 @@ def test_syslog_has_evidence_without_false_oom_and_escapes_content(self): p = alert() p.probe_detail = 'line one\nline "two"' data = watchdog.format_syslog_alert(p) - for fragment in ('event="container_alert"', 'severity="CRITICAL"', + for fragment in ('event="watchdog_alert"', 'severity="CRITICAL"', 'failure_type="crashed"', 'exit_code="137"', 'host="vision"', 'container="demo-service"', 'container_id="abcdef123456"', diff --git a/watchdog.py b/watchdog.py index f5434e2..af69d1d 100644 --- a/watchdog.py +++ b/watchdog.py @@ -47,6 +47,7 @@ def filter(self, record: logging.LogRecord) -> bool: def setup_logging(level: str, log_file: str | None, syslog_cfg: dict | None = None) -> None: numeric = getattr(logging, level.upper(), logging.INFO) handlers: list[logging.Handler] = [logging.StreamHandler(sys.stdout)] + syslog_active = False if log_file: log_dir = os.path.dirname(log_file) if log_dir: @@ -56,6 +57,8 @@ def setup_logging(level: str, log_file: str | None, syslog_cfg: dict | None = No log_file, maxBytes=10 * 1024 * 1024, backupCount=5 ) ) + for handler in handlers: + handler.setLevel(numeric) if syslog_cfg and syslog_cfg.get("enabled"): host = syslog_cfg.get("host", "localhost") port = int(syslog_cfg.get("port", 514)) @@ -78,11 +81,15 @@ def setup_logging(level: str, log_file: str | None, syslog_cfg: dict | None = No log.warning("Syslog disabled — cannot reach %s:%d (%s): %s", host, port, proto, exc) else: syslog_handler.setFormatter(logging.Formatter(SYSLOG_FORMAT)) + syslog_handler.setLevel(logging.INFO) syslog_handler.addFilter(AlertSyslogFilter()) handlers.append(syslog_handler) + syslog_active = True # Use a plain formatter for other handlers, syslog gets its own log.info("Syslog handler added: %s:%d (%s)", host, port, proto) - logging.basicConfig(level=numeric, format=LOG_FORMAT, handlers=handlers, force=True) + # Let INFO recovery alerts reach Syslog even when local logs are WARNING/ERROR. + root_level = min(numeric, logging.INFO) if syslog_active else numeric + logging.basicConfig(level=root_level, format=LOG_FORMAT, handlers=handlers, force=True) # Suppress noisy third-party debug chatter (urllib3 Docker socket calls, etc.) for noisy in ("urllib3", "urllib3.connectionpool", "docker", "requests"): logging.getLogger(noisy).setLevel(logging.WARNING) @@ -460,18 +467,19 @@ def _syslog_field(value: object, limit: int = 512) -> str: def format_syslog_alert(payload: AlertPayload) -> str: """Same incident facts as human-facing notifications; bounded for UDP syslog.""" details = { - "event": "container_alert", + "event": "watchdog_alert", "severity": payload.severity, "failure_type": payload.failure_type, "time_utc": payload.timestamp, "host": payload.host, - "container": payload.container_name, - "container_id": payload.container_id, "probe_type": payload.probe_type, "detection": payload.probe_detail, "action": payload.recommended_action, "runbook": payload.runbook_url, } + if payload.failure_type not in ("ha-failover", "reboot-summary"): + details["container"] = payload.container_name + details["container_id"] = payload.container_id if payload.exit_code is not None: details["exit_code"] = payload.exit_code if payload.failure_type == "ha-failover": @@ -1129,19 +1137,17 @@ def get_docker_health_log(container) -> str: def get_memory_stats(container) -> str: + """Best-effort post-event sample, not memory usage at the time of the OOM.""" try: - stats = container.stats(stream=False) - mem = stats.get("memory_stats", {}) - usage = mem.get("usage", 0) - limit = mem.get("limit", 0) - peak = mem.get("max_usage", 0) - def _mb(b: int) -> str: - return f"{b / 1024 / 1024:.1f} MB" - return ( - f"memory usage={_mb(usage)} limit={_mb(limit)} peak={_mb(peak)}" - ) - except Exception as exc: - return f"(memory stats unavailable: {exc})" + mem = container.stats(stream=False).get("memory_stats") or {} + parts = [] + for key, label in (("usage", "usage"), ("limit", "limit"), ("max_usage", "peak")): + value = mem.get(key) + if type(value) is int and value > 0: + parts.append(f"{label}={value / 1024 / 1024:.1f} MB") + return ("post-event memory snapshot: " + ", ".join(parts)) if parts else "" + except Exception: + return "" def get_container_id(container) -> str: @@ -1838,7 +1844,7 @@ def _handle_event(self, event: dict) -> None: self.runbook_base, extra_context=memory, probe_detail=("OOM probe failed - container was OOM-killed by the kernel" - + (f"; {memory}" if memory.startswith("memory usage=") else ""))) + + (f"; {memory}" if memory else ""))) self._dispatch(payload) elif action == "health_status: unhealthy": @@ -1878,7 +1884,7 @@ def _poll_ha(self, session: requests.Session) -> None: self._ha_tracker.reset_candidate() if time.monotonic() - self._ha_error_log_at >= 300: self._ha_error_log_at = time.monotonic() - log.warning("HA check unavailable (%s): %s", type(exc).__name__, exc) + log.error("HA check unavailable (%s): %s", type(exc).__name__, exc) return changed, change = self._ha_tracker.observe(observation)