203 lines
8.0 KiB
Python
203 lines
8.0 KiB
Python
"""Tests for custom structlog processors."""
|
|
|
|
from __future__ import annotations
|
|
|
|
from typing import TYPE_CHECKING
|
|
from unittest.mock import MagicMock, patch
|
|
|
|
import pytest
|
|
|
|
from noteflow.infrastructure.logging.config import LoggingConfig
|
|
from noteflow.infrastructure.logging.processors import (
|
|
add_noteflow_context,
|
|
add_otel_trace_context,
|
|
build_processor_chain,
|
|
safe_filter_by_level,
|
|
)
|
|
from noteflow.infrastructure.logging.structured import (
|
|
request_id_var,
|
|
user_id_var,
|
|
workspace_id_var,
|
|
)
|
|
|
|
if TYPE_CHECKING:
|
|
from structlog.typing import WrappedLogger
|
|
|
|
|
|
def _create_mock_wrapped_logger() -> WrappedLogger:
|
|
return MagicMock()
|
|
|
|
|
|
# Test constants
|
|
SAMPLE_REQUEST_ID = "req-12345"
|
|
SAMPLE_USER_ID = "user-67890"
|
|
SAMPLE_WORKSPACE_ID = "ws-abcdef"
|
|
SAMPLE_TRACE_ID = 0x123456789ABCDEF0123456789ABCDEF0
|
|
SAMPLE_SPAN_ID = 0x123456789ABCDEF0
|
|
EXPECTED_TRACE_HEX = "0123456789abcdef0123456789abcdef0"
|
|
EXPECTED_SPAN_HEX = "123456789abcdef0"
|
|
|
|
|
|
@pytest.mark.usefixtures("reset_context_vars")
|
|
class TestAddNoteflowContext:
|
|
"""Tests for add_noteflow_context processor."""
|
|
|
|
def test_injects_request_id_when_set(self) -> None:
|
|
"""Processor injects request_id from context var."""
|
|
request_id_var.set(SAMPLE_REQUEST_ID)
|
|
event_dict: dict[str, str] = {"event": "test"}
|
|
|
|
result = add_noteflow_context(_create_mock_wrapped_logger(), "info", event_dict)
|
|
|
|
assert result["request_id"] == SAMPLE_REQUEST_ID, "request_id should be injected"
|
|
|
|
def test_injects_user_id_when_set(self) -> None:
|
|
"""Processor injects user_id from context var."""
|
|
user_id_var.set(SAMPLE_USER_ID)
|
|
event_dict: dict[str, str] = {"event": "test"}
|
|
|
|
result = add_noteflow_context(_create_mock_wrapped_logger(), "info", event_dict)
|
|
|
|
assert result["user_id"] == SAMPLE_USER_ID, "user_id should be injected"
|
|
|
|
def test_injects_workspace_id_when_set(self) -> None:
|
|
"""Processor injects workspace_id from context var."""
|
|
workspace_id_var.set(SAMPLE_WORKSPACE_ID)
|
|
event_dict: dict[str, str] = {"event": "test"}
|
|
|
|
result = add_noteflow_context(_create_mock_wrapped_logger(), "info", event_dict)
|
|
|
|
assert result["workspace_id"] == SAMPLE_WORKSPACE_ID, "workspace_id should be injected"
|
|
|
|
def test_does_not_override_existing_values(self) -> None:
|
|
"""Processor does not override values already in event_dict."""
|
|
request_id_var.set(SAMPLE_REQUEST_ID)
|
|
existing_id = "existing-request-id"
|
|
event_dict: dict[str, str] = {"event": "test", "request_id": existing_id}
|
|
|
|
result = add_noteflow_context(_create_mock_wrapped_logger(), "info", event_dict)
|
|
|
|
assert result["request_id"] == existing_id, "existing value should not be overridden"
|
|
|
|
def test_skips_none_values(self) -> None:
|
|
"""Processor skips None context values."""
|
|
event_dict: dict[str, str] = {"event": "test"}
|
|
|
|
result = add_noteflow_context(_create_mock_wrapped_logger(), "info", event_dict)
|
|
|
|
assert "request_id" not in result, "None values should not be added"
|
|
assert "user_id" not in result, "None values should not be added"
|
|
assert "workspace_id" not in result, "None values should not be added"
|
|
|
|
|
|
class TestAddOtelTraceContext:
|
|
"""Tests for add_otel_trace_context processor."""
|
|
|
|
def test_handles_missing_opentelemetry(self) -> None:
|
|
"""Processor handles missing OpenTelemetry gracefully."""
|
|
event_dict: dict[str, str] = {"event": "test"}
|
|
|
|
with patch.dict("sys.modules", {"opentelemetry": None}):
|
|
result = add_otel_trace_context(_create_mock_wrapped_logger(), "info", event_dict)
|
|
|
|
assert "trace_id" not in result, "should not add trace_id without OTel"
|
|
assert "span_id" not in result, "should not add span_id without OTel"
|
|
|
|
def test_handles_no_active_span(self) -> None:
|
|
"""Processor handles no active span gracefully."""
|
|
event_dict: dict[str, str] = {"event": "test"}
|
|
|
|
with patch("opentelemetry.trace.get_current_span", return_value=None):
|
|
result = add_otel_trace_context(_create_mock_wrapped_logger(), "info", event_dict)
|
|
|
|
assert "trace_id" not in result, "should not add trace_id without span"
|
|
|
|
def test_handles_non_recording_span(self) -> None:
|
|
"""Processor handles non-recording span gracefully."""
|
|
event_dict: dict[str, str] = {"event": "test"}
|
|
mock_span = MagicMock()
|
|
mock_span.is_recording.return_value = False
|
|
|
|
with patch("opentelemetry.trace.get_current_span", return_value=mock_span):
|
|
result = add_otel_trace_context(_create_mock_wrapped_logger(), "info", event_dict)
|
|
|
|
assert "trace_id" not in result, "should not add trace_id for non-recording span"
|
|
|
|
def test_injects_trace_and_span_ids(self) -> None:
|
|
"""Processor injects trace_id and span_id from active span."""
|
|
event_dict: dict[str, str] = {"event": "test"}
|
|
mock_span_ctx = MagicMock()
|
|
mock_span_ctx.trace_id = SAMPLE_TRACE_ID
|
|
mock_span_ctx.span_id = SAMPLE_SPAN_ID
|
|
mock_span_ctx.is_valid = True
|
|
|
|
mock_span = MagicMock()
|
|
mock_span.is_recording.return_value = True
|
|
mock_span.get_span_context.return_value = mock_span_ctx
|
|
mock_span.parent = None
|
|
|
|
with patch("opentelemetry.trace.get_current_span", return_value=mock_span):
|
|
result = add_otel_trace_context(_create_mock_wrapped_logger(), "info", event_dict)
|
|
|
|
assert "trace_id" in result, "should inject trace_id"
|
|
assert "span_id" in result, "should inject span_id"
|
|
|
|
|
|
class TestBuildProcessorChain:
|
|
"""Tests for build_processor_chain function."""
|
|
|
|
def test_includes_standard_processors(self) -> None:
|
|
"""Processor chain includes standard structlog processors."""
|
|
config = LoggingConfig()
|
|
|
|
processors = build_processor_chain(config)
|
|
|
|
assert len(processors) >= 5, "should include at least 5 standard processors"
|
|
assert safe_filter_by_level in processors, "should include safe_filter_by_level"
|
|
|
|
def test_includes_noteflow_context_when_enabled(self) -> None:
|
|
"""Processor chain includes NoteFlow context when enabled."""
|
|
config = LoggingConfig(enable_noteflow_context=True)
|
|
|
|
processors = build_processor_chain(config)
|
|
|
|
assert add_noteflow_context in processors, "should include add_noteflow_context"
|
|
|
|
def test_excludes_noteflow_context_when_disabled(self) -> None:
|
|
"""Processor chain excludes NoteFlow context when disabled."""
|
|
config = LoggingConfig(enable_noteflow_context=False)
|
|
|
|
processors = build_processor_chain(config)
|
|
|
|
assert add_noteflow_context not in processors, "should exclude add_noteflow_context"
|
|
|
|
def test_includes_otel_context_when_enabled(self) -> None:
|
|
"""Processor chain includes OTEL context when enabled."""
|
|
config = LoggingConfig(enable_otel_context=True)
|
|
|
|
processors = build_processor_chain(config)
|
|
|
|
assert add_otel_trace_context in processors, "should include add_otel_trace_context"
|
|
|
|
def test_excludes_otel_context_when_disabled(self) -> None:
|
|
"""Processor chain excludes OTEL context when disabled."""
|
|
config = LoggingConfig(enable_otel_context=False)
|
|
|
|
processors = build_processor_chain(config)
|
|
|
|
assert add_otel_trace_context not in processors, "should exclude add_otel_trace_context"
|
|
|
|
def test_processor_order_is_correct(self) -> None:
|
|
"""Processor chain maintains correct order."""
|
|
config = LoggingConfig(enable_noteflow_context=True, enable_otel_context=True)
|
|
|
|
processors = build_processor_chain(config)
|
|
|
|
# safe_filter_by_level should come before context injection
|
|
filter_idx = processors.index(safe_filter_by_level)
|
|
noteflow_idx = processors.index(add_noteflow_context)
|
|
otel_idx = processors.index(add_otel_trace_context)
|
|
|
|
assert filter_idx < noteflow_idx, "filter should come before noteflow context"
|
|
assert noteflow_idx < otel_idx, "noteflow context should come before otel context"
|