diff --git a/backend/consultations/apps.py b/backend/consultations/apps.py index 37d8b0f19..ad4d035ab 100644 --- a/backend/consultations/apps.py +++ b/backend/consultations/apps.py @@ -10,10 +10,16 @@ class ConsultationsConfig(AppConfig): def ready(self): logger = settings.LOGGER + # Import lazily so a load-time error in the OTel modules can't crash + # startup before the guarded setup gets a chance to warn-and-continue. if settings.EXECUTION_CONTEXT == "worker": from otel_bootstrap import bootstrap_otel bootstrap_otel(service_name="consult-worker") + else: + from otel_django import configure_django_otel + + configure_django_otel(logger) if settings.ENVIRONMENT.upper() in ["LOCAL", "TEST"]: s3_client = s3.get_s3_client() diff --git a/backend/otel_bootstrap.py b/backend/otel_bootstrap.py index cc74343ff..3cba4dc77 100644 --- a/backend/otel_bootstrap.py +++ b/backend/otel_bootstrap.py @@ -8,21 +8,14 @@ from __future__ import annotations import contextlib -import os from collections.abc import Iterator from typing import Any from django.conf import settings -OTEL_ENDPOINT_ENV = "OTEL_EXPORTER_OTLP_ENDPOINT" -OTEL_ENABLED_ENV = "OTEL_ENABLED" -_TRACER_NAME = "consult.worker" - +from otel_common import otel_requested -def otel_requested() -> bool: - """Bootstrap only when the flag is on and a collector endpoint is configured.""" - enabled = os.environ.get(OTEL_ENABLED_ENV, "").strip().lower() == "true" - return enabled and bool(os.environ.get(OTEL_ENDPOINT_ENV)) +_TRACER_NAME = "consult.worker" def bootstrap_otel(service_name: str) -> None: @@ -47,10 +40,9 @@ def bootstrap_otel(service_name: str) -> None: try: configure_otel(service_name=service_name) ensure_structlog_otel_processors() - except RuntimeError: + except Exception: # noqa: BLE001 - telemetry setup must never block the worker logger.warning( - "OTel endpoint is set but the exporter is unavailable; telemetry " - "disabled for {service_name}", + "OTel setup failed; telemetry disabled for {service_name}", service_name=service_name, ) diff --git a/backend/otel_common.py b/backend/otel_common.py new file mode 100644 index 000000000..4dcbd3f6e --- /dev/null +++ b/backend/otel_common.py @@ -0,0 +1,18 @@ +"""Shared gating for the OTel bootstraps. + +Kept tiny so the Django and worker entrypoints agree on when telemetry is +requested and never drift. +""" + +from __future__ import annotations + +import os + +OTEL_ENDPOINT_ENV = "OTEL_EXPORTER_OTLP_ENDPOINT" +OTEL_ENABLED_ENV = "OTEL_ENABLED" + + +def otel_requested() -> bool: + """Telemetry is requested only when the flag is on and an endpoint is set.""" + enabled = os.environ.get(OTEL_ENABLED_ENV, "").strip().lower() == "true" + return enabled and bool(os.environ.get(OTEL_ENDPOINT_ENV)) diff --git a/backend/otel_django.py b/backend/otel_django.py new file mode 100644 index 000000000..3062baf81 --- /dev/null +++ b/backend/otel_django.py @@ -0,0 +1,41 @@ +"""OpenTelemetry bootstrap for the Django request path. + +Dormant unless otel_requested(), so prod keeps running on the existing +StructuredLogger with no behaviour change. +""" + +from __future__ import annotations + +from otel_common import otel_requested + +_SERVICE_NAME = "consult-backend" + + +def configure_django_otel(logger) -> None: + """Instrument Django and restore the trace-context processor. No-op unless requested.""" + if not otel_requested(): + return + + try: + from i_dot_ai_utilities.logging._otel import ( + configure_otel_for_django, + ensure_structlog_otel_processors, + ) + except ImportError: + logger.warning( + "OTel endpoint is set but the i-dot-ai-utilities [otel] extra is not " + "installed; telemetry disabled for {service_name}", + service_name=_SERVICE_NAME, + ) + return + + try: + # The logger is built at settings import, so restore processors after + # instrumenting or logs ship without trace ids. + configure_otel_for_django(service_name=_SERVICE_NAME) + ensure_structlog_otel_processors() + except Exception: # noqa: BLE001 - telemetry setup must never block app startup + logger.warning( + "OTel setup failed; telemetry disabled for {service_name}", + service_name=_SERVICE_NAME, + ) diff --git a/backend/tests/unit/test_otel_bootstrap.py b/backend/tests/unit/test_otel_bootstrap.py index 95bf59438..94c6030e8 100644 --- a/backend/tests/unit/test_otel_bootstrap.py +++ b/backend/tests/unit/test_otel_bootstrap.py @@ -5,39 +5,18 @@ import pytest import otel_bootstrap +import otel_common @pytest.fixture(autouse=True) def _clear_otel_env(monkeypatch): - monkeypatch.delenv(otel_bootstrap.OTEL_ENDPOINT_ENV, raising=False) - monkeypatch.delenv(otel_bootstrap.OTEL_ENABLED_ENV, raising=False) + monkeypatch.delenv(otel_common.OTEL_ENDPOINT_ENV, raising=False) + monkeypatch.delenv(otel_common.OTEL_ENABLED_ENV, raising=False) def _enable(monkeypatch): - monkeypatch.setenv(otel_bootstrap.OTEL_ENABLED_ENV, "true") - monkeypatch.setenv(otel_bootstrap.OTEL_ENDPOINT_ENV, "http://collector:4318") - - -class TestOtelRequested: - def test_false_by_default(self): - assert otel_bootstrap.otel_requested() is False - - def test_false_with_endpoint_but_flag_off(self, monkeypatch): - monkeypatch.setenv(otel_bootstrap.OTEL_ENDPOINT_ENV, "http://collector:4318") - assert otel_bootstrap.otel_requested() is False - - def test_false_with_flag_but_no_endpoint(self, monkeypatch): - monkeypatch.setenv(otel_bootstrap.OTEL_ENABLED_ENV, "true") - assert otel_bootstrap.otel_requested() is False - - def test_false_when_flag_not_true(self, monkeypatch): - monkeypatch.setenv(otel_bootstrap.OTEL_ENABLED_ENV, "false") - monkeypatch.setenv(otel_bootstrap.OTEL_ENDPOINT_ENV, "http://collector:4318") - assert otel_bootstrap.otel_requested() is False - - def test_true_with_flag_and_endpoint(self, monkeypatch): - _enable(monkeypatch) - assert otel_bootstrap.otel_requested() is True + monkeypatch.setenv(otel_common.OTEL_ENABLED_ENV, "true") + monkeypatch.setenv(otel_common.OTEL_ENDPOINT_ENV, "http://collector:4318") class TestBootstrapOtel: diff --git a/backend/tests/unit/test_otel_common.py b/backend/tests/unit/test_otel_common.py new file mode 100644 index 000000000..1d0b2c14b --- /dev/null +++ b/backend/tests/unit/test_otel_common.py @@ -0,0 +1,47 @@ +"""The shared OTel gate stays off unless the flag is on and an endpoint is set.""" + +import pytest + +import otel_common + +ENDPOINT = "http://collector:4317" + + +@pytest.fixture(autouse=True) +def _clear_otel_env(monkeypatch): + monkeypatch.delenv(otel_common.OTEL_ENABLED_ENV, raising=False) + monkeypatch.delenv(otel_common.OTEL_ENDPOINT_ENV, raising=False) + + +def test_not_requested_when_env_absent(): + assert otel_common.otel_requested() is False + + +def test_not_requested_when_enabled_without_endpoint(monkeypatch): + monkeypatch.setenv(otel_common.OTEL_ENABLED_ENV, "true") + assert otel_common.otel_requested() is False + + +def test_not_requested_when_endpoint_without_enabled(monkeypatch): + monkeypatch.setenv(otel_common.OTEL_ENDPOINT_ENV, ENDPOINT) + assert otel_common.otel_requested() is False + + +@pytest.mark.parametrize("value", ["false", "0", "", "yes"]) +def test_enabled_flag_requires_true(monkeypatch, value): + monkeypatch.setenv(otel_common.OTEL_ENABLED_ENV, value) + monkeypatch.setenv(otel_common.OTEL_ENDPOINT_ENV, ENDPOINT) + assert otel_common.otel_requested() is False + + +@pytest.mark.parametrize("value", ["true", "True ", " TRUE"]) +def test_enabled_flag_tolerates_case_and_whitespace(monkeypatch, value): + monkeypatch.setenv(otel_common.OTEL_ENABLED_ENV, value) + monkeypatch.setenv(otel_common.OTEL_ENDPOINT_ENV, ENDPOINT) + assert otel_common.otel_requested() is True + + +def test_requested_when_enabled_with_endpoint(monkeypatch): + monkeypatch.setenv(otel_common.OTEL_ENABLED_ENV, "true") + monkeypatch.setenv(otel_common.OTEL_ENDPOINT_ENV, ENDPOINT) + assert otel_common.otel_requested() is True diff --git a/backend/tests/unit/test_otel_django.py b/backend/tests/unit/test_otel_django.py new file mode 100644 index 000000000..5c2ac25e7 --- /dev/null +++ b/backend/tests/unit/test_otel_django.py @@ -0,0 +1,83 @@ +import json +import sys +from unittest.mock import MagicMock + +import pytest + +import otel_django + +ENDPOINT = "http://collector:4317" + + +@pytest.fixture +def dormant_env(monkeypatch): + monkeypatch.delenv("OTEL_ENABLED", raising=False) + monkeypatch.delenv("OTEL_EXPORTER_OTLP_ENDPOINT", raising=False) + + +@pytest.fixture +def enabled_env(monkeypatch): + monkeypatch.setenv("OTEL_ENABLED", "true") + monkeypatch.setenv("OTEL_EXPORTER_OTLP_ENDPOINT", ENDPOINT) + + +def test_configure_is_noop_when_dormant(dormant_env): + logger = MagicMock() + otel_django.configure_django_otel(logger) + logger.warning.assert_not_called() + + +def test_configure_warns_when_extra_missing(enabled_env, monkeypatch): + # The [otel] extra is installed in CI, so fake its absence to reach the ImportError branch. + monkeypatch.setitem(sys.modules, "i_dot_ai_utilities.logging._otel", None) + logger = MagicMock() + otel_django.configure_django_otel(logger) + logger.warning.assert_called_once() + + +def test_enabled_correlates_existing_logs_with_the_active_span(enabled_env, monkeypatch, capsys): + from i_dot_ai_utilities.logging._otel import setup as otel_setup + from i_dot_ai_utilities.logging.structured_logger import StructuredLogger + from i_dot_ai_utilities.logging.types.enrichment_types import ExecutionEnvironmentType + from i_dot_ai_utilities.logging.types.log_output_format import LogOutputFormat + from opentelemetry import trace + from opentelemetry.sdk.trace import TracerProvider + from opentelemetry.sdk.trace.export.in_memory_span_exporter import InMemorySpanExporter + + exporter = InMemorySpanExporter() + monkeypatch.setattr(otel_setup, "_default_otlp_span_exporter", lambda: exporter) + + # Build the logger before configure runs: constructing a StructuredLogger + # resets structlog config, and configure re-inserts the trace processor after. + logger = StructuredLogger( + level="info", + options={ + "execution_environment": ExecutionEnvironmentType.LOCAL, + "log_format": LogOutputFormat.JSON, + }, + ) + + otel_setup._reset_for_tests() + try: + otel_django.configure_django_otel(logger) + assert isinstance(trace.get_tracer_provider(), TracerProvider) + + # Drop the parallel request-logging middleware: the existing logger's + # lines pick up trace ids from whatever span is active, as they would + # inside a DjangoInstrumentor request span. + with trace.get_tracer("test").start_as_current_span("request"): + logger.info("handled request") + + trace.get_tracer_provider().force_flush() + spans = exporter.get_finished_spans() + finally: + otel_setup._reset_for_tests() + + events = [json.loads(line) for line in capsys.readouterr().out.splitlines() if line.startswith("{")] + logged = next(e for e in events if e.get("message") == "handled request") + + assert len(logged["trace_id"]) == 32 + assert len(logged["span_id"]) == 16 + + assert spans, "the active span should be recorded and exported" + assert format(spans[0].context.trace_id, "032x") == logged["trace_id"]