wake-alarm/wake_alarm/_logging_setup.py
Krzysztof kuhy Rudnicki f5cfc3e452 Phase 1: structured JSONL logging with cross-process dedupe
Adds the diagnostic substrate the rest of the hardening work builds on. A
6am failure should be reconstructable afterwards instead of re-debugged.

Two sinks, deliberately. stderr -> journal is unchanged. Alongside it, one
JSON object per line in ~/.local/state/wake_alarm/events.jsonl, so a morning
can be replayed with jq.

The hard constraint is that _trigger is a fresh process every 60 seconds, so
an in-memory rate limiter would reset on every tick and suppress nothing.
_log_dedupe therefore persists the last emitted fingerprint to disk and
flushes a suppressed_repeats count onto the next distinct record. Verified
across separate processes: 4 invocations logging the same routine event
produce 1 record plus an accurate count of 3.

That is what satisfies the standing "do not raise the level of _sync's
degraded-read paths" rule by construction, rather than by keeping levels
artificially low and losing the signal.

The correlation id is derived, never generated: both halves compute
wake-YYYYMMDD-HHMM from the resolved alarm instant, so the PC and the phone
agree with no handshake and no uuid exchange -- which matters precisely when
sync is down.

Logging never raises. An unwritable sink degrades to journal-only.

_alarm.py and _sync.py keep the default component= for now; tagging them
means splitting them for the 250-line gate, which belongs in the phases that
actually restructure those files.

389 tests pass, 100% branch coverage held.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01EckWmyfetYq3Mi8MAnUudh
2026-08-26 23:00:08 +02:00

92 lines
2.9 KiB
Python

"""Logging configuration for the wake_alarm entry points.
Two sinks, deliberately:
* **stderr -> journal** -- unchanged, human-readable, what ``journalctl`` shows.
* **JSONL file** -- machine-readable, greppable with ``jq``, so a failed
wake-up can be reconstructed after the fact instead of re-debugged.
The JSONL handler carries a cross-process dedupe filter (see ``_log_dedupe``)
because ``_trigger`` runs as a fresh process every minute; without it, "log
everywhere" would mean 1440 identical lines a day.
Configuration never raises: a logging failure must not be the reason an alarm
does not go off.
"""
from __future__ import annotations
import logging
from wake_alarm._constants import LOG_DEDUPE_FILE, LOG_JSONL_FILE
from wake_alarm._log_dedupe import DedupeFilter
from wake_alarm._log_sink import build_handler
_STDERR_FORMAT = "%(asctime)s %(name)s %(levelname)s %(message)s"
# Marks the handler we own, so a second call is a no-op rather than a
# duplicate sink (main() runs once per process, but --demo and tests re-enter).
_HANDLER_FLAG = "_wake_alarm_jsonl"
def _already_attached(root: logging.Logger) -> bool:
"""Report whether the JSONL handler is already installed.
Args:
root: The root logger to inspect.
Returns:
True if a previous call already attached the handler.
"""
return any(getattr(h, _HANDLER_FLAG, False) for h in root.handlers)
def configure_logging(*, component: str = "wake_alarm") -> None:
"""Configure the daemon log format plus the structured JSONL sink.
Args:
component: Name recorded on every JSONL record, identifying which
entry point emitted it (``alarm``, ``trigger``, ``sync``).
"""
logging.basicConfig(level=logging.INFO, format=_STDERR_FORMAT)
root = logging.getLogger()
if _already_attached(root):
return
try:
handler = build_handler(LOG_JSONL_FILE)
except OSError:
# No structured log is survivable; a crash here is not.
logging.getLogger(__name__).info(
"structured log unavailable; journal only",
)
return
handler.addFilter(DedupeFilter(LOG_DEDUPE_FILE))
handler.addFilter(_ComponentFilter(component))
setattr(handler, _HANDLER_FLAG, True)
root.addHandler(handler)
class _ComponentFilter(logging.Filter):
"""Stamp every record with the entry point that produced it."""
def __init__(self, component: str) -> None:
"""Initialise the filter.
Args:
component: Value to set on each record.
"""
super().__init__()
self._component = component
def filter(self, record: logging.LogRecord) -> bool:
"""Attach the component name to *record*.
Args:
record: The record being emitted.
Returns:
Always True; this filter annotates rather than excludes.
"""
record.component = self._component
return True