From 1041cc63abadbdc38a67f2153e5da0a457c283d5 Mon Sep 17 00:00:00 2001 From: Artur Shiriev Date: Tue, 3 Nov 2026 20:57:36 +0300 Subject: [PATCH] Omit tracing metadata outside recording spans Closes #396 --- docs/migration/to-2.x.md | 6 +++ .../instruments/logging_instrument.py | 2 +- tests/instruments/test_logging_instrument.py | 45 +++++++------------ 3 files changed, 24 insertions(+), 29 deletions(-) diff --git a/docs/migration/to-2.x.md b/docs/migration/to-2.x.md index b350339..e0dfe6d 100644 --- a/docs/migration/to-2.x.md +++ b/docs/migration/to-2.x.md @@ -20,3 +20,9 @@ metrics. Existing user-defined exclusions still apply. Dashboards and alerts that previously included these requests may show lower request totals and different latency percentiles. Review thresholds that were based on the old traffic mix. + +## Trace context in JSON logs + +JSON log lines include `tracing` only when emitted inside a recording +OpenTelemetry span. The object contains `span_id` and `trace_id`. +Update log parsers to treat `tracing` as optional. diff --git a/lite_bootstrap/instruments/logging_instrument.py b/lite_bootstrap/instruments/logging_instrument.py index 2115459..42e67f8 100644 --- a/lite_bootstrap/instruments/logging_instrument.py +++ b/lite_bootstrap/instruments/logging_instrument.py @@ -41,7 +41,7 @@ def format(self, record: logging.LogRecord) -> str: def tracer_injection(_: "WrappedLogger", __: str, event_dict: "EventDict") -> "EventDict": current_span = trace.get_current_span() if not current_span.is_recording(): - event_dict["tracing"] = {} + event_dict.pop("tracing", None) return event_dict current_span_context = current_span.get_span_context() diff --git a/tests/instruments/test_logging_instrument.py b/tests/instruments/test_logging_instrument.py index 2aa89fa..282e433 100644 --- a/tests/instruments/test_logging_instrument.py +++ b/tests/instruments/test_logging_instrument.py @@ -8,7 +8,7 @@ import pytest import structlog -from opentelemetry.trace import get_tracer +from opentelemetry.trace import format_span_id, format_trace_id, get_tracer from lite_bootstrap.exceptions import TeardownError from lite_bootstrap.instruments.logging_instrument import LoggingConfig, LoggingInstrument @@ -45,40 +45,29 @@ def test_logging_instrument_simple(logging_mock: LoggingMock) -> None: logging_instrument.teardown() -def test_logging_instrument_tracer_injection(logging_mock: LoggingMock) -> None: - logging_instrument = LoggingInstrument( - bootstrap_config=LoggingConfig( - logging_unset_handlers=["uvicorn"], - logging_extra_processors=[logging_mock], - ) - ) +def test_logging_instrument_tracer_injection(capsys: pytest.CaptureFixture[str]) -> None: + logging_instrument = LoggingInstrument(bootstrap_config=LoggingConfig()) opentelemetry_instrument = OpenTelemetryInstrument( - bootstrap_config=OpenTelemetryConfig( - opentelemetry_log_traces=True, - ) + bootstrap_config=OpenTelemetryConfig(opentelemetry_log_traces=True) ) try: logging_instrument.bootstrap() opentelemetry_instrument.bootstrap() logger = structlog.getLogger(__name__) - tracer = get_tracer(__name__) - logger.info("testing tracer injection without spans") - with tracer.start_as_current_span("my_fake_span") as span: - logger.info("testing tracer injection without span attributes") - span.set_attribute("example_attribute", "value") - span.add_event("example_event", {"event_attr": 1}) - logger.info("testing tracer injection with span attributes") - - assert logging_mock.entries[0]["event"] == "testing tracer injection without spans" - - assert logging_mock.entries[1]["event"] == "testing tracer injection without span attributes" - assert logging_mock.entries[2]["event"] == "testing tracer injection with span attributes" - - tracing1 = logging_mock.entries[1]["tracing"] - tracing2 = logging_mock.entries[2]["tracing"] - assert tracing1 - assert tracing1 == tracing2 + logger.info("outside span") + with get_tracer(__name__).start_as_current_span("test span") as span: + context = span.get_span_context() + logger.info("inside span") + + outside, inside = [json.loads(line) for line in capsys.readouterr().out.splitlines()] + assert outside["event"] == "outside span" + assert "tracing" not in outside + assert inside["event"] == "inside span" + assert inside["tracing"] == { + "span_id": format_span_id(context.span_id), + "trace_id": format_trace_id(context.trace_id), + } finally: logging_instrument.teardown() opentelemetry_instrument.teardown()