marchwarden/tests/test_obs.py

"""Tests for the obs (structured logging) module."""

import io
import json
import logging
import os
from unittest.mock import patch

import pytest
import structlog

from obs import configure_logging, get_logger


@pytest.fixture(autouse=True)
def reset_logging():
    """Reset structlog + stdlib state between tests so configure_logging
    is forced to re-run."""
    import obs

    obs._CONFIGURED = False
    structlog.reset_defaults()
    structlog.contextvars.clear_contextvars()
    root = logging.getLogger()
    root.handlers = []
    root.setLevel(logging.WARNING)
    yield
    obs._CONFIGURED = False
    structlog.reset_defaults()
    structlog.contextvars.clear_contextvars()
    root.handlers = []


def _capture_stderr(monkeypatch):
    buf = io.StringIO()
    monkeypatch.setattr("sys.stderr", buf)
    return buf


class TestConfigureLogging:
    def test_json_format_emits_json(self, monkeypatch):
        monkeypatch.setenv("MARCHWARDEN_LOG_FORMAT", "json")
        monkeypatch.setenv("MARCHWARDEN_LOG_LEVEL", "INFO")
        buf = _capture_stderr(monkeypatch)

        configure_logging(force=True)
        log = get_logger("marchwarden.test")
        log.info("hello", key="value", count=3)

        line = buf.getvalue().strip()
        assert line, "expected at least one log line"
        parsed = json.loads(line)
        assert parsed["event"] == "hello"
        assert parsed["key"] == "value"
        assert parsed["count"] == 3
        assert parsed["level"] == "info"
        assert parsed["logger"] == "marchwarden.test"
        assert "timestamp" in parsed

    def test_console_format_is_human_readable(self, monkeypatch):
        monkeypatch.setenv("MARCHWARDEN_LOG_FORMAT", "console")
        monkeypatch.setenv("MARCHWARDEN_LOG_LEVEL", "INFO")
        buf = _capture_stderr(monkeypatch)

        configure_logging(force=True)
        log = get_logger("marchwarden.test")
        log.info("greeting", who="world")

        text = buf.getvalue()
        assert "greeting" in text
        assert "world" in text
        # Console renderer is not JSON
        with pytest.raises(json.JSONDecodeError):
            json.loads(text.strip().splitlines()[-1])

    def test_context_binding_propagates(self, monkeypatch):
        monkeypatch.setenv("MARCHWARDEN_LOG_FORMAT", "json")
        buf = _capture_stderr(monkeypatch)

        configure_logging(force=True)
        log = get_logger("marchwarden.test")
        structlog.contextvars.bind_contextvars(trace_id="abc-123", researcher="web")
        try:
            log.info("step")
        finally:
            structlog.contextvars.clear_contextvars()

        parsed = json.loads(buf.getvalue().strip())
        assert parsed["trace_id"] == "abc-123"
        assert parsed["researcher"] == "web"

    def test_log_level_filters(self, monkeypatch):
        monkeypatch.setenv("MARCHWARDEN_LOG_FORMAT", "json")
        monkeypatch.setenv("MARCHWARDEN_LOG_LEVEL", "WARNING")
        buf = _capture_stderr(monkeypatch)

        configure_logging(force=True)
        log = get_logger("marchwarden.test")
        log.info("ignored")
        log.warning("kept")

        lines = [l for l in buf.getvalue().strip().splitlines() if l]
        assert len(lines) == 1
        assert json.loads(lines[0])["event"] == "kept"

    def test_idempotent(self, monkeypatch):
        monkeypatch.setenv("MARCHWARDEN_LOG_FORMAT", "json")
        configure_logging(force=True)

        import obs

        obs._CONFIGURED = True
        # Second call should be a no-op
        before = logging.getLogger().handlers
        configure_logging()
        after = logging.getLogger().handlers
        assert before is after

    def test_get_logger_auto_configures(self, monkeypatch):
        monkeypatch.setenv("MARCHWARDEN_LOG_FORMAT", "json")
        buf = _capture_stderr(monkeypatch)

        # No explicit configure_logging() call
        log = get_logger("marchwarden.test")
        log.info("auto")

        parsed = json.loads(buf.getvalue().strip())
        assert parsed["event"] == "auto"