Tyler
47e0f80786
Cyclone previously emitted stdlib default-formatted log lines that
operators couldn't parse with anything beyond grep. SP18 replaces
that with:
- JsonFormatter: newline-delimited JSON, ISO-8601 ms timestamps,
structured "extra" dict, exception tracebacks serialized as a
single string.
- CycloneDevFormatter: tabular format for tail -f in dev.
- PiiScrubber: logging.Filter that redacts NPIs, SSNs, DOBs,
patient names — both inline in the message ("npi 1881068062")
and via PHI-keyed extras ({"dob": "1980-04-12"}).
- setup_logging(): idempotent entry point used by the API lifespan
and CLI main; respects CYCLONE_LOG_LEVEL/FILE/JSON/NO_PII_SCRUB.
- CLI --log-format=json|dev + --log-file=… flags.
- Migrate 9 highest-value log sites in scheduler/backup_scheduler/
backup_service to use extra={...} (input_filename, claims, parser,
backup_id, db_fingerprint, etc.).
34 new tests (test_logging_formatter + test_logging_scrubber +
test_logging_setup). All 867 backend tests pass.
128 lines
4.3 KiB
Python
128 lines
4.3 KiB
Python
"""SP18 — ``setup_logging`` entry-point tests.
|
|
|
|
Covers level resolution, handler attachment, env-var overrides, and
|
|
the idempotent re-setup behavior used by the FastAPI lifespan and
|
|
the CLI's ``main()``.
|
|
"""
|
|
from __future__ import annotations
|
|
|
|
import logging
|
|
import os
|
|
from pathlib import Path
|
|
|
|
import pytest
|
|
|
|
from cyclone.logging_config import (
|
|
CycloneDevFormatter,
|
|
JsonFormatter,
|
|
PiiScrubber,
|
|
setup_logging,
|
|
)
|
|
|
|
|
|
@pytest.fixture(autouse=True)
|
|
def _reset_root_logger():
|
|
"""Strip our handlers + filters before each test so setup runs clean."""
|
|
root = logging.getLogger()
|
|
for h in list(root.handlers):
|
|
root.removeHandler(h)
|
|
for flt in list(root.filters):
|
|
if isinstance(flt, PiiScrubber):
|
|
root.removeFilter(flt)
|
|
yield
|
|
for h in list(root.handlers):
|
|
root.removeHandler(h)
|
|
for flt in list(root.filters):
|
|
if isinstance(flt, PiiScrubber):
|
|
root.removeFilter(flt)
|
|
|
|
|
|
def test_setup_respects_level_string():
|
|
setup_logging(level="DEBUG", json_format=True)
|
|
assert logging.getLogger().level == logging.DEBUG
|
|
setup_logging(level="WARNING", json_format=True)
|
|
assert logging.getLogger().level == logging.WARNING
|
|
|
|
|
|
def test_setup_attaches_rotating_file_handler(tmp_path: Path):
|
|
log_file = tmp_path / "cyclone.log"
|
|
setup_logging(level="INFO", log_file=str(log_file), json_format=True)
|
|
root = logging.getLogger()
|
|
assert len(root.handlers) == 1
|
|
h = root.handlers[0]
|
|
# RotatingFileHandler has ``baseFilename`` attr.
|
|
assert hasattr(h, "baseFilename")
|
|
assert Path(h.baseFilename).name == "cyclone.log"
|
|
|
|
|
|
def test_setup_defaults_to_json_formatter():
|
|
setup_logging(level="INFO")
|
|
root = logging.getLogger()
|
|
assert isinstance(root.handlers[0].formatter, JsonFormatter)
|
|
|
|
|
|
def test_setup_dev_toggle_uses_dev_formatter():
|
|
setup_logging(level="INFO", json_format=False)
|
|
root = logging.getLogger()
|
|
assert isinstance(root.handlers[0].formatter, CycloneDevFormatter)
|
|
|
|
|
|
def test_setup_idempotent_re_setup_replaces_handlers():
|
|
"""Re-calling setup_logging clears the previous handler(s)."""
|
|
setup_logging(level="INFO", json_format=True)
|
|
setup_logging(level="DEBUG", json_format=False)
|
|
root = logging.getLogger()
|
|
assert len(root.handlers) == 1
|
|
assert isinstance(root.handlers[0].formatter, CycloneDevFormatter)
|
|
assert root.level == logging.DEBUG
|
|
|
|
|
|
def test_setup_quietens_noisy_third_party_loggers():
|
|
setup_logging(level="DEBUG", json_format=True)
|
|
for noisy in ("urllib3", "paramiko", "sqlalchemy.engine"):
|
|
assert logging.getLogger(noisy).level >= logging.WARNING
|
|
|
|
|
|
def test_setup_attaches_pii_scrubber_by_default():
|
|
setup_logging(level="INFO", json_format=True)
|
|
root = logging.getLogger()
|
|
assert any(isinstance(f, PiiScrubber) for f in root.filters)
|
|
|
|
|
|
def test_setup_honors_scrub_pii_false():
|
|
setup_logging(level="INFO", json_format=True, scrub_pii=False)
|
|
root = logging.getLogger()
|
|
# Scrubber is still attached but disabled.
|
|
scrubbers = [f for f in root.filters if isinstance(f, PiiScrubber)]
|
|
assert len(scrubbers) == 1
|
|
assert scrubbers[0]._enabled is False # noqa: SLF001
|
|
|
|
|
|
def test_setup_honors_env_var_no_pii_scrub(monkeypatch):
|
|
monkeypatch.setenv("CYCLONE_LOG_NO_PII_SCRUB", "1")
|
|
setup_logging(level="INFO", json_format=True)
|
|
scrubbers = [f for f in logging.getLogger().filters if isinstance(f, PiiScrubber)]
|
|
assert scrubbers and scrubbers[0]._enabled is False # noqa: SLF001
|
|
|
|
|
|
def test_setup_emits_json_to_stderr_by_default(caplog):
|
|
"""Records emitted after setup flow through JsonFormatter."""
|
|
setup_logging(level="INFO", json_format=True)
|
|
logger = logging.getLogger("cyclone.test_setup")
|
|
logger.info("hello %s", "world", extra={"x": 1})
|
|
# Cyclone attaches the handler to root, not the named logger; caplog
|
|
# won't capture unless we propagate (which is the default).
|
|
# Just assert the handler is on root and would format correctly.
|
|
root = logging.getLogger()
|
|
h = root.handlers[0]
|
|
record = logger.makeRecord(
|
|
name="cyclone.test_setup", level=logging.INFO, fn="t.py", lno=1,
|
|
msg="hello %s", args=("world",), exc_info=None,
|
|
)
|
|
record.x = 1
|
|
formatted = h.formatter.format(record)
|
|
import json as _json
|
|
parsed = _json.loads(formatted)
|
|
assert parsed["msg"] == "hello world"
|
|
assert parsed["extra"]["x"] == 1
|