Add `perf` as the 12th skinny package with full OpenTelemetry instrumentation for pipeline traces, Prometheus metrics, and Loki-correlated logs. - src/perf/: TracerProvider, MeterProvider, LoggerProvider bridge, PipelineCollector, psutil system metrics, FileExporter fallback, FastAPI middleware, auto-file Gitea issues on step/test failure - infra/otel/: OTel Collector fan-out (traces→Jaeger, metrics→Prometheus, logs→Loki), all services migrated from jaeger:4317 to collector - infra/grafana/dashboards/: 8-panel pipeline performance dashboard - Pipeline runner auto-instruments all 189 steps with zero-cost MockTracer/MockSpan no-ops when telemetry is disabled - 82 new tests, 12,055 total passing Closes #203, closes #204, closes #205, closes #206, closes #207, closes #208, closes #209, closes #210, closes #211, closes #212, closes #213
111 lines
3.7 KiB
Python
111 lines
3.7 KiB
Python
"""Tests for the logging bridge — trace context injection."""
|
|
|
|
from __future__ import annotations
|
|
|
|
import logging
|
|
|
|
import pytest
|
|
from opentelemetry import trace
|
|
from opentelemetry.sdk.trace import TracerProvider
|
|
from opentelemetry.sdk.trace.export import (
|
|
SimpleSpanProcessor,
|
|
SpanExporter,
|
|
SpanExportResult,
|
|
)
|
|
|
|
from perf._logs import (
|
|
TraceContextFilter,
|
|
TraceContextFormatter,
|
|
attach_trace_filter,
|
|
detach_trace_filter,
|
|
)
|
|
|
|
|
|
class _NoopExporter(SpanExporter):
|
|
def export(self, spans):
|
|
return SpanExportResult.SUCCESS
|
|
|
|
def shutdown(self):
|
|
pass
|
|
|
|
|
|
@pytest.fixture()
|
|
def otel_provider():
|
|
"""Set up a real tracer provider for span context tests."""
|
|
original = trace.get_tracer_provider()
|
|
provider = TracerProvider()
|
|
provider.add_span_processor(SimpleSpanProcessor(_NoopExporter()))
|
|
trace.set_tracer_provider(provider)
|
|
yield provider
|
|
provider.shutdown()
|
|
trace._TRACER_PROVIDER = original
|
|
trace._TRACER_PROVIDER_SET_ONCE._done = False
|
|
|
|
|
|
class TestTraceContextFilter:
|
|
"""TraceContextFilter injects trace_id and span_id."""
|
|
|
|
def test_zero_ids_outside_span(self):
|
|
filt = TraceContextFilter()
|
|
record = logging.LogRecord("test", logging.INFO, "", 0, "msg", (), None)
|
|
result = filt.filter(record)
|
|
assert result is True
|
|
assert record.trace_id == "0" * 32 # type: ignore[attr-defined]
|
|
assert record.span_id == "0" * 16 # type: ignore[attr-defined]
|
|
|
|
def test_real_ids_inside_span(self, otel_provider):
|
|
filt = TraceContextFilter()
|
|
tracer = trace.get_tracer("test")
|
|
with tracer.start_as_current_span("log.test"):
|
|
record = logging.LogRecord("test", logging.INFO, "", 0, "msg", (), None)
|
|
filt.filter(record)
|
|
assert record.trace_id != "0" * 32 # type: ignore[attr-defined]
|
|
assert record.span_id != "0" * 16 # type: ignore[attr-defined]
|
|
assert len(record.trace_id) == 32 # type: ignore[attr-defined]
|
|
assert len(record.span_id) == 16 # type: ignore[attr-defined]
|
|
|
|
|
|
class TestAttachDetach:
|
|
"""attach_trace_filter and detach_trace_filter manage the root logger."""
|
|
|
|
def test_attach_adds_filter(self):
|
|
logger = logging.getLogger("test.attach")
|
|
attach_trace_filter(logger)
|
|
assert any(isinstance(f, TraceContextFilter) for f in logger.filters)
|
|
detach_trace_filter(logger)
|
|
|
|
def test_detach_removes_filter(self):
|
|
logger = logging.getLogger("test.detach")
|
|
attach_trace_filter(logger)
|
|
detach_trace_filter(logger)
|
|
assert not any(isinstance(f, TraceContextFilter) for f in logger.filters)
|
|
|
|
def test_double_attach_is_idempotent(self):
|
|
logger = logging.getLogger("test.double")
|
|
attach_trace_filter(logger)
|
|
attach_trace_filter(logger)
|
|
count = sum(1 for f in logger.filters if isinstance(f, TraceContextFilter))
|
|
assert count == 1
|
|
detach_trace_filter(logger)
|
|
|
|
|
|
class TestTraceContextFormatter:
|
|
"""Formatter includes trace context fields in output."""
|
|
|
|
def test_format_includes_trace_id(self, otel_provider):
|
|
formatter = TraceContextFormatter()
|
|
filt = TraceContextFilter()
|
|
tracer = trace.get_tracer("test")
|
|
|
|
with tracer.start_as_current_span("fmt.test"):
|
|
record = logging.LogRecord(
|
|
"test.logger", logging.INFO, "", 0, "hello world", (), None
|
|
)
|
|
filt.filter(record)
|
|
output = formatter.format(record)
|
|
assert "trace_id=" in output
|
|
assert "span_id=" in output
|
|
assert "hello world" in output
|
|
# Should NOT contain all-zero IDs
|
|
assert "trace_id=" + "0" * 32 not in output
|