diff --git a/CHANGELOG.md b/CHANGELOG.md index 90cd1fc71..a8fd54035 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -7,6 +7,17 @@ Write the date in place of the "Unreleased" in the case a new version is release ### Added +- OpenTelemetry tracing for the server, exported over OTLP. The example monitoring + stack (`compose.monitoring.yml`) now includes an OpenTelemetry Collector, Jaeger, + and Grafana Tempo (traces are sent to both backends), and the Collector also + scrapes and re-exposes Tiled's Prometheus metrics. +- Emit OpenTelemetry spans for internal request phases (access control, read, + tokenize, pack) so they appear as child spans in a request's trace, giving a + per-request breakdown of where time is spent. +- Disable FastAPI's built-in OpenTelemetry auto-configuration + (`telemetry={"auto_configure": False}`) so that, on FastAPI >=0.142, it does + not register a second OTLP exporter alongside Tiled's own tracing pipeline and + export every span twice. - Expose the Deployment `strategy` in the helm chart, so that a deployment can use `Recreate` instead of the default `RollingUpdate`. - Add a `DELETE /api/v1/asset/{path}?id=N` endpoint to dissociate a single diff --git a/compose.monitoring.yml b/compose.monitoring.yml index 9f5a31a73..b31a140b0 100644 --- a/compose.monitoring.yml +++ b/compose.monitoring.yml @@ -1,5 +1,17 @@ --- services: + # Turn on OpenTelemetry tracing for the Tiled server (defined in compose.yml + # or compose.dev.yml) and point it at the collector below. These variables + # live here, alongside the collector, so that running the base compose files + # on their own leaves tracing off instead of exporting to a collector that is + # not running. + tiled: + environment: + - OTEL_EXPORTER_OTLP_ENDPOINT=http://otel-collector:4318 + - OTEL_SERVICE_NAME=tiled + # Don't trace health checks and metrics scrapes (operational chatter). + - OTEL_PYTHON_FASTAPI_EXCLUDED_URLS=healthz,api/v1/metrics + prometheus: image: docker.io/prom/prometheus:v2.42.0 volumes: @@ -14,7 +26,7 @@ services: restart: unless-stopped grafana: - image: docker.io/grafana/grafana:8.2.6 + image: docker.io/grafana/grafana:11.3.0 depends_on: - prometheus ports: @@ -33,5 +45,50 @@ services: GF_AUTH_DISABLE_SIGNOUT_MENU: "true" GF_AUTH_DISABLE_LOGIN_FORM: "true" + # OpenTelemetry Collector: receives OTLP telemetry from apps and fans it + # out to backends (traces -> Jaeger and Tempo). It also scrapes Tiled's + # Prometheus metrics endpoint and re-exposes it for Prometheus. Apps on the + # 'backend' network export to http://otel-collector:4318; apps on the host + # export to http://localhost:4318. + otel-collector: + image: otel/opentelemetry-collector-contrib:0.130.0 + command: ["--config=/etc/otelcol/config.yaml"] + volumes: + - ./monitoring_example/otel-collector/otel-collector.yml:/etc/otelcol/config.yaml + ports: + - 4317:4317 # OTLP gRPC + - 4318:4318 # OTLP HTTP + - 8889:8889 # Prometheus exporter (re-exposed scraped metrics) + depends_on: + - jaeger + - tempo + networks: + - backend + restart: unless-stopped + + # Jaeger all-in-one: trace storage + query UI. In-memory storage (dev + # only; traces are lost on restart). Natively accepts OTLP. + jaeger: + image: jaegertracing/all-in-one:1.62.0 + environment: + COLLECTOR_OTLP_ENABLED: "true" + ports: + - 16686:16686 # Jaeger web UI + networks: + - backend + restart: unless-stopped + + # Grafana Tempo: trace storage queried from Grafana (no UI of its own). + # Stores traces on local ephemeral storage (see monitoring_example/tempo). + # Natively accepts OTLP. Explore traces in Grafana via the Tempo datasource. + tempo: + image: docker.io/grafana/tempo:2.6.1 + command: ["-config.file=/etc/tempo/tempo.yml"] + volumes: + - ./monitoring_example/tempo/tempo.yml:/etc/tempo/tempo.yml + networks: + - backend + restart: unless-stopped + networks: backend: {} diff --git a/docs/source/_toc.yml b/docs/source/_toc.yml index 98b9e5ef9..70f461128 100644 --- a/docs/source/_toc.yml +++ b/docs/source/_toc.yml @@ -42,6 +42,7 @@ subtrees: - file: user-guide/api-keys - file: user-guide/custom-clients - file: user-guide/metrics + - file: user-guide/tracing - file: user-guide/direct-client - file: user-guide/tiled-authn-database - file: user-guide/register diff --git a/docs/source/user-guide/tracing.md b/docs/source/user-guide/tracing.md new file mode 100644 index 000000000..6d1cf3bb1 --- /dev/null +++ b/docs/source/user-guide/tracing.md @@ -0,0 +1,129 @@ +# Distributed Tracing + +In addition to [Prometheus metrics](./metrics.md), Tiled can emit +[OpenTelemetry](https://opentelemetry.io/) traces. Whereas metrics describe +aggregate behavior across many requests, a *trace* records the timeline of a +single request as a tree of *spans*. This is useful for investigating why a +particular request was slow. + +Traces are exported using the OpenTelemetry Protocol (OTLP) to an +[OpenTelemetry Collector](https://opentelemetry.io/docs/collector/), which +forwards them to one or more tracing backends for storage and visualization, +such as [Jaeger](https://www.jaegertracing.io/) or +[Grafana Tempo](https://grafana.com/oss/tempo/). + +```{mermaid} +flowchart LR + tiled["Tiled server"] + collector["OpenTelemetry
Collector"] + + subgraph backends["Storage backends"] + direction TB + jaeger["Jaeger"] + tempo["Grafana Tempo"] + prometheus["Prometheus"] + loki["Loki"] + end + + subgraph viz["Visualization"] + direction TB + jaegerui["Jaeger UI"] + grafana["Grafana"] + end + + %% Configured in the example + tiled -->|"traces (OTLP)"| collector + collector -->|OTLP| jaeger + collector -->|OTLP| tempo + tiled -->|"metrics (scrape)"| prometheus + + %% Visualization + jaeger --> jaegerui + tempo --> grafana + prometheus --> grafana + + %% Metrics and logs over OTLP: possible extension, not enabled + tiled -.->|"metrics (OTLP)"| collector + tiled -.->|"logs (OTLP)"| collector + collector -.->|metrics| prometheus + collector -.->|logs| loki + loki -.-> grafana +``` + +Solid arrows are what the example configures today: Tiled pushes **traces** over +OTLP to the Collector, which fans them out to Jaeger and Grafana Tempo, while +Prometheus scrapes Tiled's metrics endpoint. Dashed arrows show how the same +Collector could also carry OpenTelemetry's other two signals — **metrics** and +**logs** — over OTLP to backends such as Prometheus and Loki. Those paths are +not currently enabled. + +## Enabling tracing + +Tracing is **disabled by default**. It is turned on by setting the standard +OpenTelemetry environment variable `OTEL_EXPORTER_OTLP_ENDPOINT` to the address +of an OTLP endpoint (an OpenTelemetry Collector, or a backend that accepts OTLP +directly). Related environment variables: + +| Variable | Purpose | +| --- | --- | +| `OTEL_EXPORTER_OTLP_ENDPOINT` | OTLP endpoint, e.g. `http://otel-collector:4318`. Tracing is off when this is unset. | +| `OTEL_SERVICE_NAME` | Name shown for the service in the tracing backend, e.g. `tiled`. | +| `OTEL_PYTHON_FASTAPI_EXCLUDED_URLS` | Comma-separated URL patterns to exclude from tracing, e.g. `healthz,api/v1/metrics` to skip health checks and metrics scrapes. | + + +## How does it work? + +1. When `OTEL_EXPORTER_OTLP_ENDPOINT` is set, Tiled configures an OpenTelemetry + tracer and instruments the ASGI application, creating one span per incoming + HTTP request. + +2. Spans are exported over OTLP to the OpenTelemetry Collector. + +3. The Collector forwards traces to one or more backends (Jaeger and Grafana + Tempo in the example stack), which store them and make them available to + search and visualize. + + +## Try it with the example stack + +Tiled ships example configuration that runs an OpenTelemetry Collector and +Jaeger alongside the server, Prometheus, and Grafana. From the repository root, +start the server together with the monitoring services: + +``` +TILED_SINGLE_USER_API_KEY=secret \ + docker compose -f compose.dev.yml -f compose.monitoring.yml up --build +``` + +`compose.dev.yml` builds the Tiled image from this checkout (so it includes the +tracing support), and `compose.monitoring.yml` sets the `OTEL_*` variables above +and runs the Collector, so the server exports traces to it. (The published image +referenced by `compose.yml` may not yet include tracing.) + +Generate some activity using the Tiled Python client: + +```python +from tiled.client import from_uri + +c = from_uri("http://localhost:8000", api_key="secret") +c.create_container('test') +list(c) +``` + +The example forwards traces to two backends so you can compare their functionality: + +- **Jaeger:** open [http://localhost:16686](http://localhost:16686), select the + **tiled** service, and click **Find Traces**. Click a trace to see its span + waterfall. +- **Grafana Tempo:** open [http://localhost:3000](http://localhost:3000), go to + **Explore**, select the **Tempo** data source, and search using + [TraceQL](https://grafana.com/docs/tempo/latest/traceql/), for example + `{ resource.service.name = "tiled" }`. + +```{note} +The bundled Collector also scrapes Tiled's `/api/v1/metrics` endpoint and +re-exposes it on port 8889, in addition to Prometheus scraping it directly. +To disable this, remove the `metrics` pipeline from the Collector +configuration in `monitoring_example/otel-collector/otel-collector.yml`. +See [Prometheus Metrics](./metrics.md). +``` diff --git a/monitoring_example/grafana/provisioning/datasources/prometheus.yml b/monitoring_example/grafana/provisioning/datasources/prometheus.yml index 0cd616ec1..6509b42b5 100644 --- a/monitoring_example/grafana/provisioning/datasources/prometheus.yml +++ b/monitoring_example/grafana/provisioning/datasources/prometheus.yml @@ -1,3 +1,4 @@ +apiVersion: 1 datasources: - name: Prometheus access: proxy diff --git a/monitoring_example/grafana/provisioning/datasources/tempo.yml b/monitoring_example/grafana/provisioning/datasources/tempo.yml new file mode 100644 index 000000000..65c2d04b0 --- /dev/null +++ b/monitoring_example/grafana/provisioning/datasources/tempo.yml @@ -0,0 +1,7 @@ +apiVersion: 1 +datasources: +- name: Tempo + access: proxy + type: tempo + url: http://tempo:3200 + uid: tempo diff --git a/monitoring_example/otel-collector/otel-collector.yml b/monitoring_example/otel-collector/otel-collector.yml new file mode 100644 index 000000000..cc78bd99c --- /dev/null +++ b/monitoring_example/otel-collector/otel-collector.yml @@ -0,0 +1,67 @@ +# OpenTelemetry Collector configuration. +# +# Traces: tiled --OTLP--> otel-collector --OTLP--> jaeger +# Metrics: otel-collector <--scrape-- tiled:8000/api/v1/metrics +# otel-collector --expose--> :8889 (Prometheus format) +# +# The collector receives OTLP traces and forwards them to Jaeger. It also +# scrapes Tiled's Prometheus metrics endpoint and re-exposes those metrics in +# Prometheus format on port 8889. + +receivers: + otlp: + protocols: + grpc: + endpoint: 0.0.0.0:4317 + http: + endpoint: 0.0.0.0:4318 + + # Scrape Tiled's Prometheus metrics endpoint. This is a standard Prometheus + # scrape config. The API key must match TILED_SINGLE_USER_API_KEY (or an API + # key carrying the "metrics" scope in a multi-user deployment). + prometheus: + config: + scrape_configs: + - job_name: tiled + metrics_path: /api/v1/metrics + scrape_interval: 5s + authorization: + type: Apikey + credentials: secret + static_configs: + - targets: ['tiled:8000'] + +processors: + batch: {} + +exporters: + # Forward traces to Jaeger's OTLP gRPC receiver. + otlp/jaeger: + endpoint: jaeger:4317 + tls: + insecure: true + # Forward the same traces to Grafana Tempo's OTLP gRPC receiver. + otlp/tempo: + endpoint: tempo:4317 + tls: + insecure: true + # Re-expose scraped metrics in Prometheus format for Prometheus to scrape. + prometheus: + endpoint: 0.0.0.0:8889 + # Log received spans to the collector's stdout (useful for debugging). + debug: + verbosity: detailed + +service: + pipelines: + traces: + receivers: [otlp] + processors: [batch] + exporters: [otlp/jaeger, otlp/tempo, debug] + metrics: + receivers: [prometheus] + processors: [batch] + exporters: [prometheus] + telemetry: + logs: + level: info diff --git a/monitoring_example/prometheus/prometheus.yml b/monitoring_example/prometheus/prometheus.yml index 17fc476e0..8cc092c10 100644 --- a/monitoring_example/prometheus/prometheus.yml +++ b/monitoring_example/prometheus/prometheus.yml @@ -3,6 +3,10 @@ global: scrape_interval: 5s scrape_configs: + # Scrape Tiled's metrics endpoint directly. The OpenTelemetry Collector + # independently scrapes the same endpoint and brings the metrics into its + # pipeline (see monitoring_example/otel-collector/otel-collector.yml), + # re-exposing them on otel-collector:8889 for forwarding to other backends. - job_name: 'tiled' metrics_path: /api/v1/metrics authorization: # Set Authorization header to 'Apikey secret'. diff --git a/monitoring_example/tempo/tempo.yml b/monitoring_example/tempo/tempo.yml new file mode 100644 index 000000000..c887d1f3c --- /dev/null +++ b/monitoring_example/tempo/tempo.yml @@ -0,0 +1,33 @@ +# Grafana Tempo configuration (single binary, for the example stack). +# +# Tempo receives traces over OTLP from the OpenTelemetry Collector and stores +# them on the local filesystem. This example writes to /tmp (ephemeral, lost on +# restart) so it needs no volume or permission setup. Traces are queried from +# Grafana via the Tempo datasource. + +server: + http_listen_port: 3200 + +distributor: + receivers: + otlp: + protocols: + grpc: + endpoint: 0.0.0.0:4317 + http: + endpoint: 0.0.0.0:4318 + +ingester: + max_block_duration: 5m + +compactor: + compaction: + block_retention: 1h + +storage: + trace: + backend: local + local: + path: /tmp/tempo/blocks + wal: + path: /tmp/tempo/wal diff --git a/pyproject.toml b/pyproject.toml index c36d2e36f..0a1e85e40 100644 --- a/pyproject.toml +++ b/pyproject.toml @@ -87,6 +87,9 @@ all = [ "numba >=0.59.0", # indirect, pinned to assist uv solve "obstore", "openpyxl", + "opentelemetry-exporter-otlp-proto-http", + "opentelemetry-instrumentation-fastapi", + "opentelemetry-sdk", "packaging", "pandas <3", "pillow", @@ -226,6 +229,9 @@ server = [ "numpy", "obstore", "openpyxl", + "opentelemetry-exporter-otlp-proto-http", + "opentelemetry-instrumentation-fastapi", + "opentelemetry-sdk", "packaging", "pandas", "pillow", diff --git a/tests/test_tracing.py b/tests/test_tracing.py new file mode 100644 index 000000000..45e16cf02 --- /dev/null +++ b/tests/test_tracing.py @@ -0,0 +1,165 @@ +"""In-process tests for the OpenTelemetry request tracing configured by +`tiled.server.app._setup_opentelemetry_tracing`. + +These use an in-memory span exporter, so they need no running OpenTelemetry +Collector, Jaeger, or Tempo. OpenTelemetry's global tracer provider can only be +set once per process, so a single provider is installed for the whole module and +the exporter is cleared between tests. +""" +import os + +import pytest +from opentelemetry import trace +from opentelemetry.sdk.trace import TracerProvider +from opentelemetry.sdk.trace.export import SimpleSpanProcessor +from opentelemetry.sdk.trace.export.in_memory_span_exporter import InMemorySpanExporter +from opentelemetry.trace import SpanKind + +from tiled.client import Context +from tiled.server.app import build_app_from_config + +pytest.importorskip("opentelemetry.sdk") + +# The FastAPI instrumentation reads OTEL_PYTHON_FASTAPI_EXCLUDED_URLS once, at +# import time, into a module-level default that `instrument_app` uses. Set it +# before that module is first imported (which the tracing hook does lazily on +# the first traced `build_app`). In deployments this variable is likewise set +# in the environment before the process starts. +os.environ["OTEL_PYTHON_FASTAPI_EXCLUDED_URLS"] = "healthz,api/v1/metrics" + +CONFIG = { + "authentication": {"single_user_api_key": "secret"}, + "trees": [{"path": "/", "tree": "tiled.examples.generated_minimal:tree"}], +} +# A syntactically valid endpoint that is never actually contacted: the tracing +# hook reuses the in-memory provider installed below instead of creating an OTLP +# exporter, so no network traffic occurs. +ENDPOINT = "http://otel-collector.invalid:4318" + +# Global library instrumentation installed by the tracing hook, which must be +# undone so it does not leak into other test modules. +_GLOBAL_INSTRUMENTORS = [ + ("opentelemetry.instrumentation.asyncpg", "AsyncPGInstrumentor"), + ("opentelemetry.instrumentation.redis", "RedisInstrumentor"), + ("opentelemetry.instrumentation.httpx", "HTTPXClientInstrumentor"), +] + + +@pytest.fixture(scope="module") +def span_exporter(): + exporter = InMemorySpanExporter() + current = trace.get_tracer_provider() + if isinstance(current, TracerProvider): + # Another module already installed a real provider; attach to it. + provider = current + else: + provider = TracerProvider() + trace.set_tracer_provider(provider) + provider.add_span_processor(SimpleSpanProcessor(exporter)) + yield exporter + for module, cls in _GLOBAL_INSTRUMENTORS: + try: + mod = __import__(module, fromlist=[cls]) + getattr(mod, cls)().uninstrument() + except Exception: + pass + + +@pytest.fixture(autouse=True) +def _clear_spans(span_exporter): + span_exporter.clear() + yield + span_exporter.clear() + + +def _build_app(monkeypatch, *, endpoint=ENDPOINT): + if endpoint is None: + monkeypatch.delenv("OTEL_EXPORTER_OTLP_ENDPOINT", raising=False) + else: + monkeypatch.setenv("OTEL_EXPORTER_OTLP_ENDPOINT", endpoint) + return build_app_from_config(CONFIG) + + +def _is_descendant_of(span, ancestor_span_id, by_id): + seen = set() + cur = span + while cur is not None and cur.parent is not None: + parent_id = cur.parent.span_id + if parent_id == ancestor_span_id: + return True + if parent_id in seen: + break + seen.add(parent_id) + cur = by_id.get(parent_id) + return False + + +def test_traced_request_emits_server_and_phase_spans(monkeypatch, span_exporter): + app = _build_app(monkeypatch) + with Context.from_app(app) as context: + # Discard spans emitted while the Context was being set up, so we measure + # exactly one request. + span_exporter.clear() + response = context.http_client.get("/api/v1/metadata/") + assert response.status_code == 200 + spans = span_exporter.get_finished_spans() + + assert spans, "expected spans to be exported for a traced request" + ids = [s.context.span_id for s in spans] + assert len(ids) == len(set(ids)), "spans must not be duplicated" + assert len({s.context.trace_id for s in spans}) == 1, "one request => one trace" + + roots = [s for s in spans if s.parent is None] + assert len(roots) == 1, "expected exactly one root span" + assert roots[0].kind == SpanKind.SERVER, "root should be the FastAPI server span" + + by_id = {s.context.span_id: s for s in spans} + names = {s.name for s in spans} + assert "tiled.app" in names, "expected the per-request phase span 'tiled.app'" + app_span = next(s for s in spans if s.name == "tiled.app") + assert _is_descendant_of( + app_span, roots[0].context.span_id, by_id + ), "phase spans should be children of the request's server span" + + +def test_excluded_endpoint_emits_no_spans(monkeypatch, span_exporter): + app = _build_app(monkeypatch) + with Context.from_app(app) as context: + span_exporter.clear() + response = context.http_client.get("/healthz") + assert response.status_code == 200 + assert ( + not span_exporter.get_finished_spans() + ), "excluded endpoints must not produce spans (no orphan traces)" + + +def test_tracing_disabled_by_default(monkeypatch): + # Without OTEL_EXPORTER_OTLP_ENDPOINT the tracing hook returns early and does + # not instrument the app, so tracing is off and adds no overhead. (Asserting + # on emitted spans is not reliable here: FastAPI >=0.142 ships its own + # telemetry that emits request spans on any globally installed provider when + # the app is not instrumented by OpenTelemetry.) + app = _build_app(monkeypatch, endpoint=None) + assert not getattr(app, "_is_instrumented_by_opentelemetry", False) + + +def test_no_duplicate_export_pipeline(monkeypatch, span_exporter): + """Guard against FastAPI's built-in telemetry (>=0.142) registering a second + OTLP export pipeline, which would export every span twice.""" + from starlette.testclient import TestClient + + provider = trace.get_tracer_provider() + processors = provider._active_span_processor._span_processors + before = len(processors) + + app = _build_app(monkeypatch) + # Entering the TestClient runs the ASGI lifespan; FastAPI configures its + # built-in telemetry on `lifespan.startup`. + with TestClient(app): + pass + + after = len(provider._active_span_processor._span_processors) + assert after == before, ( + "a second span processor was registered on the global provider; " + "FastAPI's built-in OpenTelemetry auto-configuration is not disabled" + ) diff --git a/tiled/server/app.py b/tiled/server/app.py index 9e7c2d421..b058cf304 100644 --- a/tiled/server/app.py +++ b/tiled/server/app.py @@ -1,6 +1,7 @@ import asyncio import collections import contextvars +import importlib.metadata import logging import os import secrets @@ -79,6 +80,7 @@ CSRF_QUERY_PARAMETER = "csrf" MINIMUM_SUPPORTED_PYTHON_CLIENT_VERSION = packaging.version.parse("0.1.0a104") +FASTAPI_VERSION = packaging.version.Version(importlib.metadata.version("fastapi")) logger = logging.getLogger(__name__) logger.setLevel("INFO") @@ -286,7 +288,17 @@ async def lifespan(app: FastAPI): finally: await shutdown_event() - app = FastAPI(lifespan=lifespan, strict_content_type=False) + # FastAPI >=0.142 ships built-in OpenTelemetry support that, when + # `OTEL_EXPORTER_OTLP_ENDPOINT` (or a related variable) is set, + # auto-registers its own OTLP export pipeline on the global tracer + # provider. Tiled configures and manages its own tracing pipeline (see + # `_setup_opentelemetry_tracing`), so FastAPI's auto-configuration + # would register a second exporter and emit every span twice. Opt out. + kwargs = dict(lifespan=lifespan, strict_content_type=False) + if FASTAPI_VERSION >= packaging.version.Version("0.142"): + kwargs["telemetry"] = {"auto_configure": False} + + app = FastAPI(**kwargs) # Healthcheck for deployment to containerized systems, needs to preempt other responses. # Standardized for Kubernetes, but also used by other systems. @@ -1067,9 +1079,47 @@ async def current_principal_logging_filter( generator=lambda: secrets.token_hex(8), ) + _setup_opentelemetry_tracing(app) + return app +def _setup_opentelemetry_tracing(app: FastAPI) -> None: + """Enable OpenTelemetry request tracing when an OTLP endpoint is configured. + + Tracing is activated only when the standard `OTEL_EXPORTER_OTLP_ENDPOINT` + environment variable is set, so it is off by default and adds no overhead + unless explicitly enabled. Spans are exported over OTLP/HTTP. + """ + if not os.getenv("OTEL_EXPORTER_OTLP_ENDPOINT"): + return + try: + from opentelemetry import trace + from opentelemetry.exporter.otlp.proto.http.trace_exporter import ( + OTLPSpanExporter, + ) + from opentelemetry.instrumentation.fastapi import FastAPIInstrumentor + from opentelemetry.sdk.resources import Resource + from opentelemetry.sdk.trace import TracerProvider + from opentelemetry.sdk.trace.export import BatchSpanProcessor + except ImportError: + logger.warning( + "OTEL_EXPORTER_OTLP_ENDPOINT is set but the OpenTelemetry packages " + "are not installed; tracing is disabled." + ) + return + + # Configure the global tracer provider once per process. + if not isinstance(trace.get_tracer_provider(), TracerProvider): + resource = Resource.create( + {"service.name": os.getenv("OTEL_SERVICE_NAME", "tiled")} + ) + provider = TracerProvider(resource=resource) + provider.add_span_processor(BatchSpanProcessor(OTLPSpanExporter())) + trace.set_tracer_provider(provider) + FastAPIInstrumentor.instrument_app(app) + + def build_app_from_config(config: Union[Config, dict[str, Any]], scalable=False): """ Convenience function that calls build_app(...) given config as parsed Config instance diff --git a/tiled/server/utils.py b/tiled/server/utils.py index 6f1e3d634..84900eb5b 100644 --- a/tiled/server/utils.py +++ b/tiled/server/utils.py @@ -1,4 +1,5 @@ import contextlib +import importlib.util import time from collections.abc import Generator from typing import Any, Literal, Mapping, Optional, Sequence @@ -18,6 +19,26 @@ API_KEY_QUERY_PARAMETER = "api_key" CSRF_COOKIE_NAME = "tiled_csrf" +# Human-readable OpenTelemetry span names for the phases timed below. +_SPAN_NAMES = { + "app": "tiled.app", + "acl": "tiled.access_control", + "read": "tiled.read", + "tok": "tiled.tokenize", + "pack": "tiled.pack", +} + +# Enable tracing if the OpenTelemetry API is installed. `opentelemetry` is a +# namespace package shared by all `opentelemetry-*` distributions, so check for +# the `trace` module itself and its parent (first). +_tracer = None +if importlib.util.find_spec("opentelemetry") and importlib.util.find_spec( + "opentelemetry.trace" +): + from opentelemetry import trace + + _tracer = trace.get_tracer("tiled.server") + def normalize_root_path(root_path: Optional[str]) -> str: """Coerce a root_path to "" or "/prefix" (no trailing slash).""" @@ -28,10 +49,21 @@ def normalize_root_path(root_path: Optional[str]) -> str: @contextlib.contextmanager def record_timing(metrics: dict[str, Any], key: str) -> Generator[None]: """ - Set timings[key] equal to the run time (in milliseconds) of the context body. + Set timings[key] equal to the run time (in seconds) of the context body. + + When there is an active recording trace span (i.e. this request is being + traced), also open a child OpenTelemetry span around the body so these + phases appear in the request's trace. Outside a traced request (tracing + disabled, or an excluded endpoint such as health checks and metrics + scrapes) no span is created, avoiding orphaned single-span traces. """ + if _tracer is not None and trace.get_current_span().is_recording(): + span = _tracer.start_as_current_span(_SPAN_NAMES.get(key, f"tiled.{key}")) + else: + span = contextlib.nullcontext() t0 = time.perf_counter() - yield + with span: + yield metrics[key]["dur"] += time.perf_counter() - t0 # Units: seconds