span_id и trace_id

.gitea/workflows/deploy.yml

@@ -125,5 +125,6 @@ jobs:
               -u ${{ secrets.REGISTRY_USER }} \
               -p ${{ secrets.REGISTRY_TOKEN }} &&
             docker compose -p $COMPOSE_PROJECT pull &&
+            docker compose -p $COMPOSE_PROJECT up -d --force-recreate otel-collector &&
             docker compose -p $COMPOSE_PROJECT up -d
           "

app/runtime/logging.py

@@ -7,6 +7,7 @@ from collections.abc import Iterable
 from typing import Any, TextIO
 
 import structlog
+from opentelemetry import trace
 
 
 _UVICORN_LOGGER_NAMES = ("uvicorn", "uvicorn.error", "uvicorn.access")
@@ -19,7 +20,11 @@ def configure_logging(
 ) -> None:
     resolved_stream = sys.stdout if stream is None else stream
     formatter = structlog.stdlib.ProcessorFormatter(
-        foreign_pre_chain=list(_shared_processors()),
+        foreign_pre_chain=[
+            _add_trace_context,
+            _render_context_in_event,
+            *_shared_processors(),
+        ],
         processors=[
             structlog.stdlib.ProcessorFormatter.remove_processors_meta,
             structlog.processors.JSONRenderer(sort_keys=True, ensure_ascii=False),
@@ -33,6 +38,7 @@ def configure_logging(
     structlog.configure(
         processors=[
             structlog.stdlib.PositionalArgumentsFormatter(),
+            _add_trace_context,
             _render_context_in_event,
             *_shared_processors(),
             structlog.processors.StackInfoRenderer(),
@@ -62,6 +68,20 @@ def _shared_processors() -> tuple[structlog.types.Processor, ...]:
     )
 
 
+def _add_trace_context(
+    _logger: Any,
+    _method_name: str,
+    event_dict: structlog.types.EventDict,
+) -> structlog.types.EventDict:
+    span_context = trace.get_current_span().get_span_context()
+    if not span_context.is_valid:
+        return event_dict
+
+    event_dict["trace_id"] = format(span_context.trace_id, "032x")
+    event_dict["span_id"] = format(span_context.span_id, "016x")
+    return event_dict
+
+
 def _render_context_in_event(
     _logger: Any,
     _method_name: str,
@@ -71,7 +91,14 @@ def _render_context_in_event(
     context = " ".join(
         f"{key}={_serialize_log_value(value)}"
         for key, value in sorted(event_dict.items())
-        if key not in {"event", "exc_info", "stack_info"}
+        if key
+        not in {
+            "event",
+            "exc_info",
+            "stack_info",
+            "_record",
+            "_from_structlog",
+        }
     )
     event_dict["event"] = f"{event} {context}" if context else event
     return event_dict

tests/logging/test_json_logging.py

@@ -3,6 +3,8 @@ import logging
 from io import StringIO
 
 import structlog
+from opentelemetry import trace
+from opentelemetry.trace import NonRecordingSpan, SpanContext, TraceFlags
 
 from app.runtime.logging import configure_logging
 
@@ -20,6 +22,8 @@ def test_application_log_is_serialized_as_json() -> None:
     assert payload["level"] == "info"
     assert payload["logger"] == "app.test"
     assert isinstance(payload["timestamp"], str)
+    assert "trace_id" not in payload
+    assert "span_id" not in payload
 
     _reset_logging()
 
@@ -75,6 +79,49 @@ def test_uvicorn_loggers_use_shared_json_logging_setup() -> None:
     _reset_logging()
 
 
+def test_active_trace_context_is_added_to_structlog_and_standard_logs() -> None:
+    stream = StringIO()
+    trace_id = 0x1234567890ABCDEF1234567890ABCDEF
+    span_id = 0x1234567890ABCDEF
+    span = NonRecordingSpan(
+        SpanContext(
+            trace_id=trace_id,
+            span_id=span_id,
+            is_remote=False,
+            trace_flags=TraceFlags.SAMPLED,
+        )
+    )
+
+    configure_logging(stream=stream)
+
+    with trace.use_span(span, end_on_exit=False):
+        structlog.get_logger("app.test").info("structured_event")
+        logging.getLogger("app.test").info("standard_event")
+
+    records = [json.loads(line) for line in stream.getvalue().splitlines()]
+    expected_trace_id = "1234567890abcdef1234567890abcdef"
+    expected_span_id = "1234567890abcdef"
+
+    assert [record["trace_id"] for record in records] == [
+        expected_trace_id,
+        expected_trace_id,
+    ]
+    assert [record["span_id"] for record in records] == [
+        expected_span_id,
+        expected_span_id,
+    ]
+    assert records[0]["event"] == (
+        f'structured_event span_id="{expected_span_id}" '
+        f'trace_id="{expected_trace_id}"'
+    )
+    assert records[1]["event"] == (
+        f'standard_event span_id="{expected_span_id}" '
+        f'trace_id="{expected_trace_id}"'
+    )
+
+    _reset_logging()
+
+
 def _reset_logging() -> None:
     structlog.reset_defaults()
     root_logger = logging.getLogger()

tests/smoke/test_local_infra_stack.py

@@ -6,6 +6,7 @@ import yaml
 PROJECT_ROOT = Path(__file__).resolve().parents[2]
 COMPOSE_FILE = PROJECT_ROOT / "docker-compose.yml"
 INFRA_README = PROJECT_ROOT / "infra" / "README.md"
+DEPLOY_WORKFLOW = PROJECT_ROOT / ".gitea" / "workflows" / "deploy.yml"
 
 
 def _load_compose() -> dict:
@@ -28,3 +29,15 @@ def test_smoke_command_sequence_is_documented() -> None:
     assert "docker compose config" in readme
     assert "docker compose up -d redis" in readme
     assert "docker compose ps" in readme
+
+
+def test_deploy_recreates_collector_after_config_update() -> None:
+    workflow = DEPLOY_WORKFLOW.read_text(encoding="utf-8")
+
+    recreate_command = (
+        "docker compose -p $COMPOSE_PROJECT up -d --force-recreate otel-collector"
+    )
+    application_command = "docker compose -p $COMPOSE_PROJECT up -d"
+
+    assert recreate_command in workflow
+    assert workflow.index(recreate_command) < workflow.rindex(application_command)