diff --git a/cli/src/pixl_cli/main.py b/cli/src/pixl_cli/main.py index ec758c2d2..492cfe1b7 100644 --- a/cli/src/pixl_cli/main.py +++ b/cli/src/pixl_cli/main.py @@ -23,9 +23,8 @@ import click import requests from core.exports import ParquetExport -from core.logging import configure_logging from core.patient_queue.producer import PixlProducer -from core.tracing import configure_tracing +from core.telemetry import configure_logging, configure_tracing, telemetry_is_enabled from decouple import RepositoryEnv, UndefinedValueError from loguru import logger from opentelemetry.instrumentation.pika import PikaInstrumentor @@ -53,7 +52,7 @@ os.environ["NO_PROXY"] = os.environ["no_proxy"] = "localhost" -def _configure_telemetry_env_vars() -> None: +def _configure_telemetry(logging_level: str) -> None: """ Set the OTel environment variables needed by the CLI. @@ -62,24 +61,25 @@ def _configure_telemetry_env_vars() -> None: Load the config and set the relevant environment variables. """ - endpoint = config("OTEL_EXPORTER_OTLP_ENDPOINT", default="") - if not endpoint: + if not telemetry_is_enabled(): return - os.environ["OTEL_EXPORTER_OTLP_ENDPOINT"] = endpoint + os.environ["OTEL_SDK_DISABLED"] = "false" + os.environ["OTEL_EXPORTER_OTLP_ENDPOINT"] = config("OTEL_EXPORTER_OTLP_ENDPOINT") os.environ["OTEL_SERVICE_NAME"] = "pixl-cli" os.environ["OTEL_RESOURCE_ATTRIBUTES"] = "service.namespace=pixl" + configure_logging(level=logging_level) + configure_tracing() + PikaInstrumentor().instrument() + @click.group() @click.option("--debug/--no-debug", default=False) def cli(*, debug: bool) -> None: """PIXL command line interface""" logging_level = "DEBUG" if debug else "INFO" - _configure_telemetry_env_vars() - configure_logging(level=logging_level) - configure_tracing() - PikaInstrumentor().instrument() + _configure_telemetry(logging_level=logging_level) cli.add_command(dc) diff --git a/cli/tests/conftest.py b/cli/tests/conftest.py index 4ff9ffb8d..582583c16 100644 --- a/cli/tests/conftest.py +++ b/cli/tests/conftest.py @@ -42,6 +42,7 @@ os.environ[key] = value # Set the remaining environment variables +os.environ["OTEL_SDK_DISABLED"] = "true" os.environ["PROJECT_CONFIGS_DIR"] = str(Path(__file__).parents[2] / "projects/configs") os.environ["EXPORT_AZ_CLIENT_ID"] = "export client id" diff --git a/docs/setup/developer.md b/docs/setup/developer.md index 14a5c606f..7917c71cd 100644 --- a/docs/setup/developer.md +++ b/docs/setup/developer.md @@ -139,18 +139,17 @@ PIXL can export structured logs to an PIXL exports telemetry via the OpenTelemetry Protocol (OTLP) and works with any OTel-compatible observability backend. -To enable observability, set `OTEL_EXPORTER_OTLP_ENDPOINT` in the `.env` file to -the gRPC endpoint of an OTel collector, e.g. `localhost:4317` (4317 is the -standard OTLP gRPC port). +To enable observability, set `OTEL_SDK_DISABLED` to `false` and define an `OTEL_EXPORTER_OTLP_ENDPOINT` +in the `.env`. The endpoint be for the gRPC endpoint of an OTel collector, e.g. +`localhost:4317` (4317 is the standard OTLP gRPC port). After starting the PIXL services, logs should start to appear in your collector's UI. ### Disabling OTel -Leave `OTEL_EXPORTER_OTLP_ENDPOINT` empty (or unset) to disable all telemetry. No -other configuration is needed — the services detect the absence of the endpoint -and skip OTel initialisation. +Set `OTEL_SDK_DISABLED` to `true` to disable all telemetry. No other configuration is +needed. ### Adding context to logs diff --git a/hasher/src/hasher/main.py b/hasher/src/hasher/main.py index d8069f592..c2c87a8bf 100644 --- a/hasher/src/hasher/main.py +++ b/hasher/src/hasher/main.py @@ -15,7 +15,7 @@ from __future__ import annotations -from core.logging import configure_logging +from core.telemetry import configure_logging from decouple import config # type: ignore [import-untyped] from fastapi import FastAPI from fastapi.middleware.cors import CORSMiddleware diff --git a/hasher/tests/conftest.py b/hasher/tests/conftest.py index e57f9d988..f644891b9 100644 --- a/hasher/tests/conftest.py +++ b/hasher/tests/conftest.py @@ -20,6 +20,7 @@ os.environ["LOG_LEVEL"] = "DEBUG" os.environ["AZURE_KEY_VAULT_SECRET_NAME"] = "test-key" os.environ["LOCAL_SALT_VALUE"] = "pixl_salt" +os.environ["OTEL_SDK_DISABLED"] = "true" class MockKeyVault: diff --git a/orthanc/orthanc-anon/plugin/pixl.py b/orthanc/orthanc-anon/plugin/pixl.py index f8a835906..8d1c5b041 100644 --- a/orthanc/orthanc-anon/plugin/pixl.py +++ b/orthanc/orthanc-anon/plugin/pixl.py @@ -35,9 +35,8 @@ import pydicom import requests from core.exceptions import PixlDiscardError, PixlSkipInstanceError -from core.logging import configure_logging from core.project_config.pixl_config_model import load_project_config -from core.tracing import configure_tracing +from core.telemetry import configure_logging, configure_tracing from decouple import config from loguru import logger from opentelemetry import trace diff --git a/orthanc/orthanc-raw/plugin/pixl.py b/orthanc/orthanc-raw/plugin/pixl.py index 101b1b6a8..552801867 100644 --- a/orthanc/orthanc-raw/plugin/pixl.py +++ b/orthanc/orthanc-raw/plugin/pixl.py @@ -23,8 +23,7 @@ import os from typing import TYPE_CHECKING -from core.logging import configure_logging -from core.tracing import configure_tracing +from core.telemetry import configure_logging, configure_tracing from decouple import config from loguru import logger from opentelemetry import trace diff --git a/pixl_core/src/core/logging.py b/pixl_core/src/core/logging.py index af003968b..3fc52f1fb 100644 --- a/pixl_core/src/core/logging.py +++ b/pixl_core/src/core/logging.py @@ -12,7 +12,7 @@ # See the License for the specific language governing permissions and # limitations under the License. """ -Configure loguru to emit structured logs to an OpenTelemetry collector via OTLP. +Provides a loguru sink that forwards records to an OpenTelemetry collector via OTLP. Note, only loguru records are exported. Logs from third-party libraries are not forwarded to the OTel collector. @@ -21,12 +21,9 @@ from __future__ import annotations import atexit -import os -import sys from typing import TYPE_CHECKING -from loguru import logger -from opentelemetry._logs import SeverityNumber, set_logger_provider +from opentelemetry._logs import SeverityNumber, get_logger_provider, set_logger_provider from opentelemetry.exporter.otlp.proto.grpc._log_exporter import OTLPLogExporter from opentelemetry.sdk._logs import LoggerProvider from opentelemetry.sdk._logs.export import BatchLogRecordProcessor @@ -35,7 +32,7 @@ if TYPE_CHECKING: from loguru import Message -__all__ = ["configure_logging"] +__all__ = ["OTelSink"] # Map loguru level names to OTel severity LOGURU_TO_OTEL: dict[str, SeverityNumber] = { @@ -53,15 +50,26 @@ class OTelSink: """Send loguru records to an OTel logs exporter via OTLP.""" def __init__(self) -> None: + """Initialise the OTel sink.""" self.provider = self._build_provider() def _build_provider(self) -> LoggerProvider: """ - Create a LoggerProvider for exporting logs via OTLP. + Return LoggerProvider for exporting logs via OTLP. + + Re-use an existing provider if one has already been created. Otherwise, create + a new provider and set it as the global provider. The provider is flushed on exit so we can include logs from short-lived processes, i.e. the CLI. """ + # If we have auto-instrumented the service, there's no way to tell the OTel SDK not to + # create the provider. So we have to reuse it here to avoid warnings in the logs. + # The provider created by the OTel SDK is equivalent to the one we create below. + existing_provider = get_logger_provider() + if isinstance(existing_provider, LoggerProvider): + return existing_provider + exporter = OTLPLogExporter() processor = BatchLogRecordProcessor(exporter) provider = LoggerProvider(resource=Resource.create()) @@ -95,18 +103,3 @@ def __call__(self, message: Message) -> None: attributes=attributes, exception=exception.value if exception else None, ) - - -def configure_logging(level: str) -> None: - """ - Configure loguru for a PIXL service. - - Always logs to stderr, which will be viewable in the Docker logs. When - OTEL_EXPORTER_OTLP_ENDPOINT is set, also send logs to the OTel collector. - """ - logger.remove() - logger.add(sys.stderr, level=level.upper()) - - if os.environ.get("OTEL_EXPORTER_OTLP_ENDPOINT"): - sink = OTelSink() - logger.add(sink, level=level.upper()) diff --git a/pixl_core/src/core/telemetry.py b/pixl_core/src/core/telemetry.py new file mode 100644 index 000000000..17157e913 --- /dev/null +++ b/pixl_core/src/core/telemetry.py @@ -0,0 +1,100 @@ +# Copyright (c) University College London Hospitals NHS Foundation Trust +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. +"""Configure OpenTelemetry for PIXL services.""" + +from __future__ import annotations + +import atexit +import os +import sys + +from decouple import config +from loguru import logger +from opentelemetry import trace +from opentelemetry.exporter.otlp.proto.grpc.trace_exporter import OTLPSpanExporter +from opentelemetry.sdk.resources import Resource +from opentelemetry.sdk.trace import TracerProvider +from opentelemetry.sdk.trace.export import BatchSpanProcessor + +from core.logging import OTelSink + +__all__ = [ + "configure_logging", + "configure_tracing", + "telemetry_is_enabled", +] + + +def telemetry_is_enabled() -> bool: + """ + Check whether telemetry should be enabled. + + It should be disabled if OTEL_SDK_DISABLED is true or if OTEL_EXPORTER_OTLP_ENDPOINT is not set. + """ + disabled = config("OTEL_SDK_DISABLED", cast=bool) + if disabled: + logger.warning("OTEL_SDK_DISABLED is set, skipping OTel configuration") + return False + + endpoint = config("OTEL_EXPORTER_OTLP_ENDPOINT") + if not endpoint: + logger.warning( + "OTEL_EXPORTER_OTLP_ENDPOINT is not set. Telemetry will not be sent to the collector." + ) + # Disable the SDK to avoid errors from the OTel SDK + os.environ["OTEL_SDK_DISABLED"] = "true" + return False + + return True + + +def configure_logging(level: str) -> None: + """ + Configure loguru for a PIXL service. + + Always logs to stderr, which will be viewable in the Docker logs. When + OTEL_SDK_DISABLED is false and OTEL_EXPORTER_OTLP_ENDPOINT is set, also + sends logs to the OTel collector. + """ + logger.remove() + logger.add(sys.stderr, level=level.upper()) + + if not telemetry_is_enabled(): + return + + sink = OTelSink() + logger.add(sink, level=level.upper()) + + +def configure_tracing() -> None: + """ + Set up an OTLP span exporter when OTEL_SDK_DISABLED is false + and OTEL_EXPORTER_OTLP_ENDPOINT is set in the environment. + """ + if not telemetry_is_enabled(): + return + + # If we have auto-instrumented the service, there's no way to tell the OTel SDK not to + # create the provider. So we have to reuse it here to avoid warnings in the logs. + # The provider created by the OTel SDK is equivalent to the one we create below. + existing_provider = trace.get_tracer_provider() + if isinstance(existing_provider, TracerProvider): + return + + exporter = OTLPSpanExporter() + processor = BatchSpanProcessor(exporter) + provider = TracerProvider(resource=Resource.create()) + provider.add_span_processor(processor) + trace.set_tracer_provider(provider) + atexit.register(provider.shutdown) diff --git a/pixl_core/src/core/tracing.py b/pixl_core/src/core/tracing.py deleted file mode 100644 index f091000f8..000000000 --- a/pixl_core/src/core/tracing.py +++ /dev/null @@ -1,44 +0,0 @@ -# Copyright (c) University College London Hospitals NHS Foundation Trust -# -# Licensed under the Apache License, Version 2.0 (the "License"); -# you may not use this file except in compliance with the License. -# You may obtain a copy of the License at -# -# http://www.apache.org/licenses/LICENSE-2.0 -# -# Unless required by applicable law or agreed to in writing, software -# distributed under the License is distributed on an "AS IS" BASIS, -# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. -# See the License for the specific language governing permissions and -# limitations under the License. -"""Configure OpenTelemetry tracing for services not wrapped by opentelemetry-instrument.""" - -from __future__ import annotations - -import atexit -import os - -from opentelemetry import trace -from opentelemetry.exporter.otlp.proto.grpc.trace_exporter import OTLPSpanExporter -from opentelemetry.sdk.resources import Resource -from opentelemetry.sdk.trace import TracerProvider -from opentelemetry.sdk.trace.export import BatchSpanProcessor - -__all__ = ["configure_tracing"] - - -def configure_tracing() -> None: - """ - Set up an OTLP span exporter when OTEL_EXPORTER_OTLP_ENDPOINT is set. - - When the endpoint is not set, tracing and spans are no-ops. - """ - if not os.environ.get("OTEL_EXPORTER_OTLP_ENDPOINT"): - return - - exporter = OTLPSpanExporter() - processor = BatchSpanProcessor(exporter) - provider = TracerProvider(resource=Resource.create()) - provider.add_span_processor(processor) - trace.set_tracer_provider(provider) - atexit.register(provider.shutdown) diff --git a/pixl_core/tests/conftest.py b/pixl_core/tests/conftest.py index ca1e5df0e..324ce88e5 100644 --- a/pixl_core/tests/conftest.py +++ b/pixl_core/tests/conftest.py @@ -69,7 +69,7 @@ os.environ["XNAT_PORT"] = "8080" os.environ["XNAT_DESTINATION"] = "/archive" os.environ["XNAT_OVERWRITE"] = "none" -os.environ["OTEL_EXPORTER_OTLP_ENDPOINT"] = "http://localhost:4317" +os.environ["OTEL_SDK_DISABLED"] = "true" @pytest.fixture(scope="package") @@ -248,6 +248,7 @@ def otel_logger( log_exporter: InMemoryLogRecordExporter, ) -> Generator[None]: """Configure an OTelSink using the in-memory exporter.""" + monkeypatch.setenv("OTEL_SDK_DISABLED", "false") processor = SimpleLogRecordProcessor(log_exporter) provider = LoggerProvider(resource=Resource.create({"service.name": "test"})) provider.add_log_record_processor(processor) diff --git a/pixl_core/tests/test_logging.py b/pixl_core/tests/test_logging.py index 5a0293e31..a8b7f76a7 100644 --- a/pixl_core/tests/test_logging.py +++ b/pixl_core/tests/test_logging.py @@ -20,17 +20,37 @@ import pytest from loguru import logger from opentelemetry._logs import SeverityNumber +from opentelemetry.sdk._logs import LoggerProvider -from core.logging import configure_logging +from core.logging import OTelSink +from core.telemetry import configure_logging if TYPE_CHECKING: from opentelemetry.sdk._logs.export import InMemoryLogRecordExporter -def test_configure_logging_creates_otel_sink() -> None: - """Test that configure_logging adds the OTel sink when the endpoint is set.""" +def test_build_provider_reuses_existing_provider(monkeypatch: pytest.MonkeyPatch) -> None: + """Test that OTelSink reuses a LoggerProvider already set by opentelemetry-instrument.""" + existing = LoggerProvider() + monkeypatch.setattr("core.logging.get_logger_provider", lambda: existing) + sink = OTelSink() + assert sink.provider is existing + + +def test_configure_logging_skips_otel_when_sdk_disabled() -> None: + """Test that configure_logging only adds stderr when OTEL_SDK_DISABLED is true.""" + configure_logging(level="INFO") + assert len(logger._core.handlers) == 1 # stderr only + logger.remove() + + +def test_configure_logging_creates_otel_sink(monkeypatch: pytest.MonkeyPatch) -> None: + """Test that configure_logging adds the OTel sink when telemetry is enabled.""" + monkeypatch.setenv("OTEL_SDK_DISABLED", "false") + monkeypatch.setenv("OTEL_EXPORTER_OTLP_ENDPOINT", "http://localhost:4317") configure_logging(level="INFO") assert len(logger._core.handlers) == 2 # stderr and OTel sink + logger.remove() @pytest.mark.usefixtures("otel_logger") diff --git a/pixl_export/src/pixl_export/main.py b/pixl_export/src/pixl_export/main.py index 39742f850..fc7b8554b 100644 --- a/pixl_export/src/pixl_export/main.py +++ b/pixl_export/src/pixl_export/main.py @@ -23,8 +23,8 @@ from typing import Annotated from core.exports import ParquetExport -from core.logging import configure_logging from core.rest_api.router import router +from core.telemetry import configure_logging from core.uploader import get_uploader from decouple import config # type: ignore [import-untyped] from fastapi import Body, FastAPI, HTTPException diff --git a/pixl_export/tests/conftest.py b/pixl_export/tests/conftest.py index fe0c9efe6..180c9ad96 100644 --- a/pixl_export/tests/conftest.py +++ b/pixl_export/tests/conftest.py @@ -36,6 +36,7 @@ os.environ["ORTHANC_ANON_USERNAME"] = "orthanc_anon_username" os.environ["ORTHANC_ANON_PASSWORD"] = "orthanc_anon_password" os.environ["ORTHANC_ANON_URL"] = "http://orthanc-anon:8042" +os.environ["OTEL_SDK_DISABLED"] = "true" TEST_DIR = Path(__file__).parent diff --git a/pixl_imaging/src/pixl_imaging/main.py b/pixl_imaging/src/pixl_imaging/main.py index 751aa4492..f664a03eb 100644 --- a/pixl_imaging/src/pixl_imaging/main.py +++ b/pixl_imaging/src/pixl_imaging/main.py @@ -18,9 +18,9 @@ import asyncio import importlib.metadata -from core.logging import configure_logging from core.patient_queue.subscriber import PixlConsumer from core.rest_api.router import router, state +from core.telemetry import configure_logging from decouple import config from fastapi import FastAPI from fastapi.responses import JSONResponse diff --git a/pixl_imaging/tests/conftest.py b/pixl_imaging/tests/conftest.py index ed1c38071..6e745821a 100644 --- a/pixl_imaging/tests/conftest.py +++ b/pixl_imaging/tests/conftest.py @@ -42,6 +42,7 @@ os.environ["ORTHANC_PACS_URL"] = "http://localhost:8045" os.environ["ORTHANC_PACS_USERNAME"] = "orthanc" os.environ["ORTHANC_PACS_PASSWORD"] = "orthanc" +os.environ["OTEL_SDK_DISABLED"] = "true" os.environ["PRIMARY_DICOM_SOURCE_MODALITY"] = "UCPRIMARYQR" os.environ["PRIMARY_DICOM_SOURCE_AE_TITLE"] = "PRIMARYQR" os.environ["SECONDARY_DICOM_SOURCE_MODALITY"] = "UCSECONDARYQR" diff --git a/test/conftest.py b/test/conftest.py index 9d6f3c29e..b238a0018 100644 --- a/test/conftest.py +++ b/test/conftest.py @@ -30,6 +30,7 @@ os.environ["PIXL_DB_USER"] = "pixl_db_username" os.environ["PIXL_DB_PASSWORD"] = "pixl_db_password" os.environ["PIXL_DB_NAME"] = "pixl" +os.environ["OTEL_SDK_DISABLED"] = "false" os.environ["OTEL_EXPORTER_OTLP_ENDPOINT"] = "http://localhost:4317" os.environ["OTEL_RESOURCE_ATTRIBUTES"] = "service.namespace=pixl" os.environ["OTEL_SERVICE_NAME"] = "pixl-cli"