From f54e55d33001c5cec219288d60efd3476530415a Mon Sep 17 00:00:00 2001 From: ferponse <47328511+ferponse@users.noreply.github.com> Date: Tue, 28 Jul 2026 18:17:37 +0200 Subject: [PATCH 1/4] feat(server): measure lifecycle operations server-side The server exported one metric and did not measure itself: sandbox.create.duration is a number the SDK reports to POST /metrics/events, which the server forwards. A deployment whose clients call the REST API directly therefore exports nothing at all, and even when clients do report, the number describes their experience rather than the server's work. Nothing was counted either. SandboxErrorCodes lists around forty failure modes - image pull failed, pod ready timeout, execd start failed - and none of them ever reached a metric, so when creation starts failing the server's telemetry stays silent and only the logs know. Add opensandbox.sandbox.operation.duration and .total, recorded by a decorator on the eight mutating lifecycle handlers. The API boundary is where every runtime converges and where the error code has already been decided, so one seam covers docker and kubernetes alike. Read-only endpoints are left alone. error.code goes on the counter only, keeping the histogram low-cardinality, and passes through a shape check: codes are source constants today, but a future call site interpolating a message into detail["code"] must not be able to turn the attribute unbounded. The decorator cannot affect a request: it re-raises untouched, and a failure inside the recording is logged rather than propagated. functools.wraps is load-bearing here - FastAPI builds the request model from the handler signature, and there is a test pinning that. create is time-to-scheduled, not time-to-ready: POST /sandboxes answers 202 and provisions asynchronously. Instrumenting the provisioning path is a separate decision, noted in the docs and the issue. Fixes #1408 --- server/configuration.md | 31 ++- server/opensandbox_server/api/lifecycle.py | 9 + .../integrations/otel/__init__.py | 6 +- .../integrations/otel/instrument.py | 109 +++++++++ .../integrations/otel/metrics.py | 94 +++++++- server/tests/test_otel_server_metrics.py | 219 ++++++++++++++++++ 6 files changed, 465 insertions(+), 3 deletions(-) create mode 100644 server/opensandbox_server/integrations/otel/instrument.py create mode 100644 server/tests/test_otel_server_metrics.py diff --git a/server/configuration.md b/server/configuration.md index c175979f5..8762fe877 100644 --- a/server/configuration.md +++ b/server/configuration.md @@ -300,7 +300,7 @@ Per-sandbox enablement uses create request extensions (see OSEP-0009 and `exampl ## `[otel]` -Optional OpenTelemetry metrics export for SDK-reported sandbox creation latency (`POST /v1/metrics/events`). Off by default; the ingestion endpoint still accepts events and records them as noop. +Optional OpenTelemetry metrics export. Off by default; the ingestion endpoint still accepts events and records them as noop. | Key | Type | Default | Description | |-----|------|---------|-------------| @@ -309,6 +309,35 @@ Optional OpenTelemetry metrics export for SDK-reported sandbox creation latency | `service_name` | string | `"opensandbox-server"` | `service.name` resource attribute. | | `export_interval_millis` | integer | `60000` | Periodic export interval (≥ 1000). | +### Exported metrics + +| Metric | Type | Unit | Source | +|---|---|---|---| +| `opensandbox.sandbox.create.duration` | Histogram | `ms` | **Reported by the SDK** via `POST /v1/metrics/events` | +| `opensandbox.sandbox.operation.duration` | Histogram | `ms` | Measured by the server at the API boundary | +| `opensandbox.sandbox.operation.total` | Counter | - | Measured by the server at the API boundary | + +The distinction matters. `create.duration` is a number the client measured and sent, so it +covers the client's whole experience — network and SDK overhead included — and **only exists +in deployments whose clients report it**. An integration that calls the REST API directly +produces none of it. + +The `operation.*` pair is the server timing its own work, so it exists in every deployment. +Attributes: + +- `operation` — a lifecycle verb from a closed set: `create`, `update_metadata`, `delete`, + `pause`, `resume`, `renew`, `create_snapshot`, `delete_snapshot`. Read-only endpoints are + not instrumented. +- `outcome` — `success` or `error`. +- `error.code` — on the counter only, and only when the operation failed. Values come from + `SandboxErrorCodes` (`KUBERNETES::POD_READY_TIMEOUT`, `DOCKER::SANDBOX_IMAGE_PULL_FAILED`, + and so on), so the server's existing error taxonomy becomes queryable: + `sum by (error_code) (rate(opensandbox_sandbox_operation_total{outcome="error"}[5m]))`. + +Note `POST /sandboxes` returns `202 Accepted` and provisions asynchronously, so `create` +here is **time-to-scheduled, not time-to-ready**. Time-to-ready needs instrumentation in the +provisioning path, which this does not yet cover. + --- ## Environment variables (outside TOML) diff --git a/server/opensandbox_server/api/lifecycle.py b/server/opensandbox_server/api/lifecycle.py index fe152765d..bc22ad3f1 100644 --- a/server/opensandbox_server/api/lifecycle.py +++ b/server/opensandbox_server/api/lifecycle.py @@ -48,6 +48,7 @@ from opensandbox_server.services.constants import SandboxErrorCodes from opensandbox_server.services.factory import create_sandbox_service from opensandbox_server.services.snapshot_service import create_snapshot_service +from opensandbox_server.integrations.otel import instrumented_operation # Initialize router router = APIRouter(tags=["Sandboxes"]) @@ -74,6 +75,7 @@ 500: {"model": ErrorResponse, "description": "An unexpected server error occurred"}, }, ) +@instrumented_operation("create") async def create_sandbox( request: CreateSandboxRequest, x_request_id: Optional[str] = Header(None, alias="X-Request-ID", description="Unique request identifier for tracing"), @@ -214,6 +216,7 @@ def get_sandbox( 500: {"model": ErrorResponse, "description": "An unexpected server error occurred"}, }, ) +@instrumented_operation("update_metadata") def patch_sandbox_metadata( sandbox_id: str, patch: PatchSandboxMetadataRequest = Body(...), @@ -239,6 +242,7 @@ def patch_sandbox_metadata( 500: {"model": ErrorResponse, "description": "An unexpected server error occurred"}, }, ) +@instrumented_operation("delete") def delete_sandbox( sandbox_id: str, x_request_id: Optional[str] = Header(None, alias="X-Request-ID", description="Unique request identifier for tracing"), @@ -279,6 +283,7 @@ def delete_sandbox( 500: {"model": ErrorResponse, "description": "An unexpected server error occurred"}, }, ) +@instrumented_operation("pause") def pause_sandbox( sandbox_id: str, x_request_id: Optional[str] = Header(None, alias="X-Request-ID", description="Unique request identifier for tracing"), @@ -316,6 +321,7 @@ def pause_sandbox( 500: {"model": ErrorResponse, "description": "An unexpected server error occurred"}, }, ) +@instrumented_operation("resume") def resume_sandbox( sandbox_id: str, x_request_id: Optional[str] = Header(None, alias="X-Request-ID", description="Unique request identifier for tracing"), @@ -355,6 +361,7 @@ def resume_sandbox( 500: {"model": ErrorResponse, "description": "An unexpected server error occurred"}, }, ) +@instrumented_operation("renew") def renew_sandbox_expiration( sandbox_id: str, request: RenewSandboxExpirationRequest, @@ -402,6 +409,7 @@ def renew_sandbox_expiration( 500: {"model": ErrorResponse, "description": "An unexpected server error occurred"}, }, ) +@instrumented_operation("create_snapshot") def create_snapshot( sandbox_id: str, response: Response, @@ -485,6 +493,7 @@ def get_snapshot( 500: {"model": ErrorResponse, "description": "An unexpected server error occurred"}, }, ) +@instrumented_operation("delete_snapshot") def delete_snapshot( snapshot_id: str, x_request_id: Optional[str] = Header(None, alias="X-Request-ID", description="Unique request identifier for tracing"), diff --git a/server/opensandbox_server/integrations/otel/__init__.py b/server/opensandbox_server/integrations/otel/__init__.py index 8a4b455d1..91ba24dec 100644 --- a/server/opensandbox_server/integrations/otel/__init__.py +++ b/server/opensandbox_server/integrations/otel/__init__.py @@ -12,16 +12,20 @@ # See the License for the specific language governing permissions and # limitations under the License. -"""Optional OpenTelemetry integration for SDK metrics ingestion.""" +"""Optional OpenTelemetry integration for SDK metrics ingestion and server metrics.""" +from opensandbox_server.integrations.otel.instrument import instrumented_operation from opensandbox_server.integrations.otel.metrics import ( record_sandbox_create_duration, + record_sandbox_operation, setup_otel_metrics, shutdown_otel_metrics, ) __all__ = [ + "instrumented_operation", "record_sandbox_create_duration", + "record_sandbox_operation", "setup_otel_metrics", "shutdown_otel_metrics", ] diff --git a/server/opensandbox_server/integrations/otel/instrument.py b/server/opensandbox_server/integrations/otel/instrument.py new file mode 100644 index 000000000..f97b6f530 --- /dev/null +++ b/server/opensandbox_server/integrations/otel/instrument.py @@ -0,0 +1,109 @@ +# Copyright 2026 Alibaba Group Holding Ltd. +# +# 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. + +"""Server-side instrumentation for lifecycle API handlers.""" + +from __future__ import annotations + +import functools +import inspect +import logging +import time +from typing import Any, Callable, Optional + +from fastapi import HTTPException + +from opensandbox_server.integrations.otel.metrics import record_sandbox_operation +from opensandbox_server.services.constants import SandboxErrorCodes + +logger = logging.getLogger(__name__) + +OUTCOME_SUCCESS = "success" +OUTCOME_ERROR = "error" + + +def _error_code_from(exc: BaseException) -> str: + """Pull the server error code out of a raised exception. + + Handlers raise ``HTTPException`` with ``detail={"code": ..., "message": ...}``. When the + detail is a plain string, or the exception is not an ``HTTPException`` at all, fall back + to the generic code so a failure is still counted rather than dropped. + """ + if isinstance(exc, HTTPException): + detail = exc.detail + if isinstance(detail, dict): + code = detail.get("code") + if code is not None: + return str(code) + return f"HTTP_{exc.status_code}" + return SandboxErrorCodes.UNKNOWN_ERROR + + +def instrumented_operation(operation: str) -> Callable[[Callable], Callable]: + """Record duration and outcome of a lifecycle handler. + + Measures the server's own work at the API boundary, which is the one place where every + runtime converges and where the error code has already been decided. Note that + ``POST /sandboxes`` returns 202 and provisions asynchronously, so for ``create`` this is + time-to-scheduled, not time-to-ready. + + ``functools.wraps`` is load-bearing: FastAPI builds the request model from the handler + signature, and ``inspect.signature`` follows ``__wrapped__``, so the route keeps its + parameters. Never swallows or alters an exception, and never lets a metrics failure + affect the response. + """ + + def decorator(func: Callable) -> Callable: + def _record(started: float, outcome: str, error_code: Optional[str]) -> None: + # record_sandbox_operation already swallows instrument errors, but this sits on + # every mutating route: a bug in telemetry must not be able to fail a request. + try: + record_sandbox_operation( + operation=operation, + duration_ms=(time.perf_counter() - started) * 1000.0, + outcome=outcome, + error_code=error_code, + ) + except Exception: + logger.exception("Failed to record %s operation metric", operation) + + if inspect.iscoroutinefunction(func): + + @functools.wraps(func) + async def async_wrapper(*args: Any, **kwargs: Any) -> Any: + started = time.perf_counter() + try: + result = await func(*args, **kwargs) + except BaseException as exc: + _record(started, OUTCOME_ERROR, _error_code_from(exc)) + raise + _record(started, OUTCOME_SUCCESS, None) + return result + + return async_wrapper + + @functools.wraps(func) + def wrapper(*args: Any, **kwargs: Any) -> Any: + started = time.perf_counter() + try: + result = func(*args, **kwargs) + except BaseException as exc: + _record(started, OUTCOME_ERROR, _error_code_from(exc)) + raise + _record(started, OUTCOME_SUCCESS, None) + return result + + return wrapper + + return decorator diff --git a/server/opensandbox_server/integrations/otel/metrics.py b/server/opensandbox_server/integrations/otel/metrics.py index d24b60a54..12c1fbc29 100644 --- a/server/opensandbox_server/integrations/otel/metrics.py +++ b/server/opensandbox_server/integrations/otel/metrics.py @@ -17,6 +17,7 @@ from __future__ import annotations import logging +import re from typing import TYPE_CHECKING, Optional from opentelemetry import metrics @@ -35,6 +36,21 @@ _CREATE_DURATION_DESCRIPTION = ( "Sandbox creation latency from SDK create start until ready or failure" ) +_OPERATION_DURATION_HISTOGRAM_NAME = "opensandbox.sandbox.operation.duration" +_OPERATION_COUNTER_NAME = "opensandbox.sandbox.operation.total" +_OPERATION_DURATION_UNIT = "ms" +_OPERATION_DURATION_DESCRIPTION = ( + "Server-side latency of a sandbox lifecycle operation, measured at the API boundary" +) +_OPERATION_COUNTER_DESCRIPTION = ( + "Sandbox lifecycle operations by outcome, with the server error code when they fail" +) +# An error code is a constant in the source, never interpolated user input. Validating the +# shape anyway keeps the attribute's cardinality bounded no matter what a future call site +# puts in an HTTPException detail. +_ERROR_CODE_PATTERN = re.compile(r"^[A-Z][A-Z0-9_:]{0,63}$") +_ERROR_CODE_FALLBACK = "OTHER" + _CREATE_DURATION_BOUNDARIES = ( 100.0, 250.0, @@ -49,6 +65,8 @@ _meter_provider: Optional[MeterProvider] = None _create_duration_histogram = None +_operation_duration_histogram = None +_operation_counter = None def _histogram_from_provider(provider: MeterProvider): @@ -59,13 +77,30 @@ def _histogram_from_provider(provider: MeterProvider): ) +def _operation_instruments_from_provider(provider: MeterProvider): + meter = provider.get_meter("opensandbox.server") + histogram = meter.create_histogram( + name=_OPERATION_DURATION_HISTOGRAM_NAME, + unit=_OPERATION_DURATION_UNIT, + description=_OPERATION_DURATION_DESCRIPTION, + ) + counter = meter.create_counter( + name=_OPERATION_COUNTER_NAME, + description=_OPERATION_COUNTER_DESCRIPTION, + ) + return histogram, counter + + def setup_otel_metrics(config: OtelConfig) -> None: """Configure OTEL metrics export when enabled; otherwise keep recording as noop.""" global _meter_provider, _create_duration_histogram + global _operation_duration_histogram, _operation_counter # Disabled: do not attach instruments to any global provider (may already export). if not config.enabled: _create_duration_histogram = None + _operation_duration_histogram = None + _operation_counter = None logger.info( "OpenTelemetry metrics export disabled; SDK events are accepted but not exported" ) @@ -97,7 +132,15 @@ def setup_otel_metrics(config: OtelConfig) -> None: aggregation=ExplicitBucketHistogramAggregation( boundaries=list(_CREATE_DURATION_BOUNDARIES) ), - ) + ), + # Same ladder: both measure a lifecycle operation in milliseconds, and the SDK + # default boundaries top out at 10s, which is short for a sandbox operation. + View( + instrument_name=_OPERATION_DURATION_HISTOGRAM_NAME, + aggregation=ExplicitBucketHistogramAggregation( + boundaries=list(_CREATE_DURATION_BOUNDARIES) + ), + ), ] provider = MeterProvider( resource=resource, @@ -118,6 +161,7 @@ def setup_otel_metrics(config: OtelConfig) -> None: # even when set_meter_provider() cannot override a preexisting global provider. _meter_provider = provider _create_duration_histogram = _histogram_from_provider(provider) + _operation_duration_histogram, _operation_counter = _operation_instruments_from_provider(provider) logger.info( "OpenTelemetry metrics enabled (service=%s, endpoint=%s)", config.service_name, @@ -128,9 +172,12 @@ def setup_otel_metrics(config: OtelConfig) -> None: def shutdown_otel_metrics() -> None: """Flush and shut down the configured MeterProvider if any.""" global _meter_provider, _create_duration_histogram + global _operation_duration_histogram, _operation_counter provider = _meter_provider _meter_provider = None _create_duration_histogram = None + _operation_duration_histogram = None + _operation_counter = None if provider is None: return try: @@ -164,3 +211,48 @@ def record_sandbox_create_duration( ) except Exception: logger.exception("Failed to record sandbox create duration metric") + + +def normalize_error_code(code: object) -> str: + """Coerce a server error code into a bounded attribute value. + + Codes are constants in the source (``SandboxErrorCodes`` and a few literals), so this + normally passes them straight through. Anything that is not code-shaped becomes + ``OTHER``, which keeps the counter's cardinality bounded even if a future call site + interpolates a message into ``detail["code"]``. + """ + if isinstance(code, str) and _ERROR_CODE_PATTERN.match(code): + return code + return _ERROR_CODE_FALLBACK + + +def record_sandbox_operation( + *, + operation: str, + duration_ms: float, + outcome: str, + error_code: Optional[str] = None, +) -> None: + """Record a server-side lifecycle operation. Never raises. + + Unlike ``record_sandbox_create_duration``, which stores a number the SDK measured and + reported, this is the server timing its own work, so it exists for every deployment + rather than only for those whose clients report metrics. + + ``operation`` is a lifecycle verb from a closed set, ``outcome`` is ``success`` or + ``error``, and ``error_code`` is attached only on failure. + + No-ops when OTEL export is disabled or setup has not installed the instruments. + """ + histogram = _operation_duration_histogram + counter = _operation_counter + if histogram is None or counter is None: + return + attributes = {"operation": operation, "outcome": outcome} + try: + histogram.record(float(duration_ms), attributes=attributes) + if error_code is not None: + attributes = {**attributes, "error.code": normalize_error_code(error_code)} + counter.add(1, attributes=attributes) + except Exception: + logger.exception("Failed to record sandbox operation metric") diff --git a/server/tests/test_otel_server_metrics.py b/server/tests/test_otel_server_metrics.py new file mode 100644 index 000000000..243fb451e --- /dev/null +++ b/server/tests/test_otel_server_metrics.py @@ -0,0 +1,219 @@ +# Copyright 2026 Alibaba Group Holding Ltd. +# +# 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. + +"""Server-side lifecycle operation metrics.""" + +import asyncio +from unittest.mock import MagicMock, patch + +import pytest +from fastapi import HTTPException + +import opensandbox_server.integrations.otel.metrics as otel_metrics +from opensandbox_server.integrations.otel.instrument import instrumented_operation +from opensandbox_server.integrations.otel.metrics import ( + normalize_error_code, + record_sandbox_operation, +) +from opensandbox_server.services.constants import SandboxErrorCodes + + +class TestNormalizeErrorCode: + """Codes are source constants, but the attribute must stay bounded regardless.""" + + @pytest.mark.parametrize( + "code", + [ + SandboxErrorCodes.IMAGE_PULL_FAILED, + SandboxErrorCodes.K8S_POD_READY_TIMEOUT, + "INVALID_METADATA_FORMAT", + "HTTP_409", + ], + ) + def test_passes_through_code_shaped_values(self, code): + assert normalize_error_code(code) == code + + @pytest.mark.parametrize( + "value", + [ + "Invalid metadata format: unexpected token at line 4", # a message, not a code + "sbx_0a1b2c3d", # an identifier + "", + None, + 42, + "X" * 100, # unbounded length + ], + ) + def test_rejects_anything_else(self, value): + assert normalize_error_code(value) == "OTHER" + + +class TestRecordSandboxOperation: + def test_noop_when_instruments_are_absent(self): + """Export disabled must not raise, and must not touch anything.""" + with patch.object(otel_metrics, "_operation_duration_histogram", None), patch.object( + otel_metrics, "_operation_counter", None + ): + record_sandbox_operation(operation="create", duration_ms=12.0, outcome="success") + + def test_records_duration_and_count_on_success(self): + histogram, counter = MagicMock(), MagicMock() + with patch.object(otel_metrics, "_operation_duration_histogram", histogram), patch.object( + otel_metrics, "_operation_counter", counter + ): + record_sandbox_operation(operation="delete", duration_ms=34.5, outcome="success") + + histogram.record.assert_called_once_with( + 34.5, attributes={"operation": "delete", "outcome": "success"} + ) + counter.add.assert_called_once_with( + 1, attributes={"operation": "delete", "outcome": "success"} + ) + + def test_error_code_is_attached_to_the_counter_only(self): + """The histogram stays low-cardinality; the error taxonomy lives on the counter.""" + histogram, counter = MagicMock(), MagicMock() + with patch.object(otel_metrics, "_operation_duration_histogram", histogram), patch.object( + otel_metrics, "_operation_counter", counter + ): + record_sandbox_operation( + operation="create", + duration_ms=1.0, + outcome="error", + error_code=SandboxErrorCodes.IMAGE_PULL_FAILED, + ) + + assert "error.code" not in histogram.record.call_args.kwargs["attributes"] + assert counter.add.call_args.kwargs["attributes"]["error.code"] == ( + SandboxErrorCodes.IMAGE_PULL_FAILED + ) + + def test_never_raises_when_the_instrument_fails(self): + histogram, counter = MagicMock(), MagicMock() + histogram.record.side_effect = RuntimeError("exporter exploded") + with patch.object(otel_metrics, "_operation_duration_histogram", histogram), patch.object( + otel_metrics, "_operation_counter", counter + ): + record_sandbox_operation(operation="pause", duration_ms=1.0, outcome="success") + + +class TestInstrumentedOperation: + """The decorator must be invisible to the handler it wraps.""" + + def test_sync_success(self): + @instrumented_operation("pause") + def handler(sandbox_id: str) -> str: + return f"paused {sandbox_id}" + + with patch( + "opensandbox_server.integrations.otel.instrument.record_sandbox_operation" + ) as record: + assert handler("sbx-1") == "paused sbx-1" + + call = record.call_args.kwargs + assert call["operation"] == "pause" + assert call["outcome"] == "success" + assert call["error_code"] is None + assert call["duration_ms"] >= 0 + + def test_async_success_preserves_the_signature(self): + @instrumented_operation("create") + async def handler(request: str, x_request_id: str = "") -> str: + return f"created {request}" + + # FastAPI builds the request model from the signature, so it has to survive. + import inspect + + assert list(inspect.signature(handler).parameters) == ["request", "x_request_id"] + + with patch( + "opensandbox_server.integrations.otel.instrument.record_sandbox_operation" + ) as record: + assert asyncio.run(handler("spec")) == "created spec" + + assert record.call_args.kwargs["outcome"] == "success" + + def test_http_exception_with_code_is_counted_and_reraised(self): + @instrumented_operation("delete") + def handler() -> None: + raise HTTPException( + status_code=404, + detail={"code": SandboxErrorCodes.SANDBOX_NOT_FOUND, "message": "gone"}, + ) + + with patch( + "opensandbox_server.integrations.otel.instrument.record_sandbox_operation" + ) as record: + with pytest.raises(HTTPException) as raised: + handler() + + assert raised.value.status_code == 404 + call = record.call_args.kwargs + assert call["outcome"] == "error" + assert call["error_code"] == SandboxErrorCodes.SANDBOX_NOT_FOUND + + def test_http_exception_without_a_code_falls_back_to_the_status(self): + @instrumented_operation("resume") + def handler() -> None: + raise HTTPException(status_code=409, detail="conflict") + + with patch( + "opensandbox_server.integrations.otel.instrument.record_sandbox_operation" + ) as record: + with pytest.raises(HTTPException): + handler() + + assert record.call_args.kwargs["error_code"] == "HTTP_409" + + def test_unexpected_exception_is_counted_and_reraised(self): + @instrumented_operation("create_snapshot") + def handler() -> None: + raise ValueError("boom") + + with patch( + "opensandbox_server.integrations.otel.instrument.record_sandbox_operation" + ) as record: + with pytest.raises(ValueError, match="boom"): + handler() + + assert record.call_args.kwargs["error_code"] == SandboxErrorCodes.UNKNOWN_ERROR + + def test_a_metrics_failure_does_not_break_the_handler(self): + """Instrumentation sits on every mutating route; it must not be able to fail one.""" + + @instrumented_operation("renew") + def handler() -> str: + return "renewed" + + with patch( + "opensandbox_server.integrations.otel.instrument.record_sandbox_operation", + side_effect=RuntimeError("metrics down"), + ): + assert handler() == "renewed" + + def test_a_metrics_failure_does_not_mask_a_handler_error(self): + """And it must not swallow the failure the caller actually needs to see.""" + + @instrumented_operation("delete") + def handler() -> None: + raise HTTPException(status_code=404, detail="gone") + + with patch( + "opensandbox_server.integrations.otel.instrument.record_sandbox_operation", + side_effect=RuntimeError("metrics down"), + ): + with pytest.raises(HTTPException) as raised: + handler() + + assert raised.value.status_code == 404 From e0f9370f4b99968dc29c9e8b4a4ea209d8fce4fb Mon Sep 17 00:00:00 2001 From: ferponse <47328511+ferponse@users.noreply.github.com> Date: Tue, 28 Jul 2026 18:39:37 +0200 Subject: [PATCH 2/4] docs(server): distinguish SDK-reported from server-measured metrics in docs/ MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Per AGENTS.md operations-visible behavior goes in docs/ first, and the published telemetry guide described the SDK histogram as the only thing [otel] exports. Kept to the repo's existing pattern for server config: docs/ links to server/configuration.md rather than duplicating the reference. What docs/ gains is the part a reader cannot infer from a table — that the SDK histogram only exists where clients report it, so a dashboard built on it alone looks empty rather than healthy, and that the server-measured create is time-to-scheduled while the SDK number approximates time-to-ready. --- docs/guides/sdk-telemetry.md | 26 +++++++++++++++++++++++++- 1 file changed, 25 insertions(+), 1 deletion(-) diff --git a/docs/guides/sdk-telemetry.md b/docs/guides/sdk-telemetry.md index 3603b31c0..9291d50de 100644 --- a/docs/guides/sdk-telemetry.md +++ b/docs/guides/sdk-telemetry.md @@ -45,7 +45,31 @@ After create succeeds or fails, the SDK fire-and-forget posts to `POST /v1/metri - `sandboxId` / `image` may be omitted when create fails early. - SDK language and version come from the HTTP `User-Agent` header (for example `OpenSandbox-Python-SDK/0.1.15`), not from body fields. -The server accepts the event with `204` and, when `[otel]` is enabled, records an OTEL histogram. See [server configuration](https://github.com/opensandbox-group/OpenSandbox/blob/main/server/configuration.md#otel). +The server accepts the event with `204` and, when `[otel]` is enabled, records an OTEL histogram (`opensandbox.sandbox.create.duration`). See [server configuration](https://github.com/opensandbox-group/OpenSandbox/blob/main/server/configuration.md#otel). + +## SDK-reported vs server-measured + +This page describes what the **SDK** reports. `[otel]` also exports metrics the **server** +measures itself, and the difference matters when you build dashboards: + +| Metric | Measured by | Covers | +|---|---|---| +| `opensandbox.sandbox.create.duration` | the SDK | the client's whole experience, network and SDK overhead included | +| `opensandbox.sandbox.operation.duration` | the server | the server's own work at the API boundary | +| `opensandbox.sandbox.operation.total` | the server | the same, as a count, with the error code on failure | + +Two consequences: + +- The SDK histogram **only exists where clients report it**. An integration calling the REST + API directly produces none of it, so a dashboard built on it alone will look empty rather + than healthy. The `operation.*` pair exists in every deployment. +- `operation.total` carries `error.code` from the server's own taxonomy, which is what makes + failures queryable: + `sum by (error_code) (rate(opensandbox_sandbox_operation_total{outcome="error"}[5m]))`. + +Note `POST /sandboxes` answers `202` and provisions asynchronously, so the server-measured +`create` is **time-to-scheduled**. Time-to-ready is what the SDK number approximates. Full +attribute reference: [server configuration](https://github.com/opensandbox-group/OpenSandbox/blob/main/server/configuration.md#otel). ## When it runs From 208834f092d7bf965902a5568ee880cb60f428eb Mon Sep 17 00:00:00 2001 From: ferponse <47328511+ferponse@users.noreply.github.com> Date: Tue, 28 Jul 2026 19:02:09 +0200 Subject: [PATCH 3/4] docs(server): correct what operation.duration{create} measures MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit I wrote that create was time-to-scheduled because POST /sandboxes answers 202. The status code is a convention here, not a description: the handler blocks until the sandbox is provisioned. KubernetesSandboxService.create_sandbox awaits _wait_for_sandbox_ready, so the sample includes pod readiness, and the Docker path awaits the provisioning thread, so it includes container start and egress sidecar readiness. That makes it a usable server-side cold-start signal — the opposite of what the note said, and the reason the note mattered: it steered operators away from the only cold-start metric here that does not depend on clients reporting anything. --- docs/guides/sdk-telemetry.md | 10 +++++++--- server/configuration.md | 12 +++++++++--- .../integrations/otel/instrument.py | 7 ++++--- 3 files changed, 20 insertions(+), 9 deletions(-) diff --git a/docs/guides/sdk-telemetry.md b/docs/guides/sdk-telemetry.md index 9291d50de..cb34fbb09 100644 --- a/docs/guides/sdk-telemetry.md +++ b/docs/guides/sdk-telemetry.md @@ -67,9 +67,13 @@ Two consequences: failures queryable: `sum by (error_code) (rate(opensandbox_sandbox_operation_total{outcome="error"}[5m]))`. -Note `POST /sandboxes` answers `202` and provisions asynchronously, so the server-measured -`create` is **time-to-scheduled**. Time-to-ready is what the SDK number approximates. Full -attribute reference: [server configuration](https://github.com/opensandbox-group/OpenSandbox/blob/main/server/configuration.md#otel). +Both cover provisioning: despite the `202 Accepted` status, `POST /sandboxes` blocks until +the sandbox exists — Kubernetes awaits pod readiness, Docker awaits container start and +egress sidecar readiness. So `operation.duration{operation="create"}` is a **server-side +cold-start signal**, and unlike the SDK histogram it does not depend on clients reporting +anything. The difference between the two is the client's share: network, auth, SDK overhead. + +Full attribute reference: [server configuration](https://github.com/opensandbox-group/OpenSandbox/blob/main/server/configuration.md#otel). ## When it runs diff --git a/server/configuration.md b/server/configuration.md index 8762fe877..ea4818f8a 100644 --- a/server/configuration.md +++ b/server/configuration.md @@ -334,9 +334,15 @@ Attributes: and so on), so the server's existing error taxonomy becomes queryable: `sum by (error_code) (rate(opensandbox_sandbox_operation_total{outcome="error"}[5m]))`. -Note `POST /sandboxes` returns `202 Accepted` and provisions asynchronously, so `create` -here is **time-to-scheduled, not time-to-ready**. Time-to-ready needs instrumentation in the -provisioning path, which this does not yet cover. +`create` covers **provisioning, not just scheduling**, despite the `202 Accepted` status: the +handler blocks until the sandbox exists. In Kubernetes `create_sandbox` awaits +`_wait_for_sandbox_ready`, so the sample includes pod readiness; in Docker it awaits the +provisioning thread, so it includes container start and egress sidecar readiness. This is +therefore a usable **server-side cold-start signal**, and the one metric here that does not +depend on clients reporting anything. + +What it does not include is anything the sandbox does after it is ready — execd bootstrapping +its own workload, for instance. --- diff --git a/server/opensandbox_server/integrations/otel/instrument.py b/server/opensandbox_server/integrations/otel/instrument.py index f97b6f530..1f05682be 100644 --- a/server/opensandbox_server/integrations/otel/instrument.py +++ b/server/opensandbox_server/integrations/otel/instrument.py @@ -54,9 +54,10 @@ def instrumented_operation(operation: str) -> Callable[[Callable], Callable]: """Record duration and outcome of a lifecycle handler. Measures the server's own work at the API boundary, which is the one place where every - runtime converges and where the error code has already been decided. Note that - ``POST /sandboxes`` returns 202 and provisions asynchronously, so for ``create`` this is - time-to-scheduled, not time-to-ready. + runtime converges and where the error code has already been decided. Despite the 202 + status, ``POST /sandboxes`` blocks until the sandbox is provisioned — Kubernetes awaits + ``_wait_for_sandbox_ready``, Docker awaits the provisioning thread — so ``create`` is a + cold-start measurement rather than a scheduling one. ``functools.wraps`` is load-bearing: FastAPI builds the request model from the handler signature, and ``inspect.signature`` follows ``__wrapped__``, so the route keeps its From 9ad80dc33ddd5ebf7af4a2894afcd809675d8bf1 Mon Sep 17 00:00:00 2001 From: ferponse <47328511+ferponse@users.noreply.github.com> Date: Tue, 28 Jul 2026 19:25:49 +0200 Subject: [PATCH 4/4] fix(server): record operations at the route, so rejected requests are counted too MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit A decorator on the handler cannot see a request FastAPI never delivers. Validation happens before the endpoint is called, so a malformed create body returned 422 with nothing recorded — an error-rate dashboard built on operation.total would have undercounted exactly the failures a caller is most likely to produce. Move recording into an APIRoute subclass and reduce the decorator to a marker that tags the handler with its operation name. The route sees RequestValidationError (counted as HTTP_422), HTTPException, unexpected exceptions, and error statuses returned rather than raised. Unmarked read-only routes get the untouched handler, so they pay nothing. Dropping the wrapper also removes the functools.wraps dependency: nothing stands between FastAPI and the handler signature any more. Two tests guard the wiring rather than the logic, because that is where this breaks silently: one pins the eight marked handlers and that the router really uses the route class, the other pins that a call is recorded exactly once. Verified both fail when the route_class or the marker order is wrong. --- docs/guides/sdk-telemetry.md | 4 + server/configuration.md | 3 + server/opensandbox_server/api/lifecycle.py | 20 +- .../integrations/otel/__init__.py | 8 +- .../integrations/otel/instrument.py | 134 +++++++----- server/tests/test_otel_server_metrics.py | 196 +++++++++++------- 6 files changed, 222 insertions(+), 143 deletions(-) diff --git a/docs/guides/sdk-telemetry.md b/docs/guides/sdk-telemetry.md index cb34fbb09..9ad350cd9 100644 --- a/docs/guides/sdk-telemetry.md +++ b/docs/guides/sdk-telemetry.md @@ -67,6 +67,10 @@ Two consequences: failures queryable: `sum by (error_code) (rate(opensandbox_sandbox_operation_total{outcome="error"}[5m]))`. +The `operation.*` pair is recorded at the route, so it also counts requests rejected before +the handler runs — a malformed body appears with `error.code = "HTTP_422"` instead of being +missing from your error rate. + Both cover provisioning: despite the `202 Accepted` status, `POST /sandboxes` blocks until the sandbox exists — Kubernetes awaits pod readiness, Docker awaits container start and egress sidecar readiness. So `operation.duration{operation="create"}` is a **server-side diff --git a/server/configuration.md b/server/configuration.md index ea4818f8a..04782691f 100644 --- a/server/configuration.md +++ b/server/configuration.md @@ -328,6 +328,9 @@ Attributes: - `operation` — a lifecycle verb from a closed set: `create`, `update_metadata`, `delete`, `pause`, `resume`, `renew`, `create_snapshot`, `delete_snapshot`. Read-only endpoints are not instrumented. +- Recorded at the **route**, so it also covers requests rejected before the handler runs — a + body that fails validation is counted with `error.code = "HTTP_422"` rather than going + missing from the error rate. - `outcome` — `success` or `error`. - `error.code` — on the counter only, and only when the operation failed. Values come from `SandboxErrorCodes` (`KUBERNETES::POD_READY_TIMEOUT`, `DOCKER::SANDBOX_IMAGE_PULL_FAILED`, diff --git a/server/opensandbox_server/api/lifecycle.py b/server/opensandbox_server/api/lifecycle.py index bc22ad3f1..801263d1e 100644 --- a/server/opensandbox_server/api/lifecycle.py +++ b/server/opensandbox_server/api/lifecycle.py @@ -48,10 +48,10 @@ from opensandbox_server.services.constants import SandboxErrorCodes from opensandbox_server.services.factory import create_sandbox_service from opensandbox_server.services.snapshot_service import create_snapshot_service -from opensandbox_server.integrations.otel import instrumented_operation +from opensandbox_server.integrations.otel import InstrumentedRoute, lifecycle_operation # Initialize router -router = APIRouter(tags=["Sandboxes"]) +router = APIRouter(tags=["Sandboxes"], route_class=InstrumentedRoute) # Initialize service based on configuration from config.toml (defaults to docker) sandbox_service = create_sandbox_service() @@ -75,7 +75,7 @@ 500: {"model": ErrorResponse, "description": "An unexpected server error occurred"}, }, ) -@instrumented_operation("create") +@lifecycle_operation("create") async def create_sandbox( request: CreateSandboxRequest, x_request_id: Optional[str] = Header(None, alias="X-Request-ID", description="Unique request identifier for tracing"), @@ -216,7 +216,7 @@ def get_sandbox( 500: {"model": ErrorResponse, "description": "An unexpected server error occurred"}, }, ) -@instrumented_operation("update_metadata") +@lifecycle_operation("update_metadata") def patch_sandbox_metadata( sandbox_id: str, patch: PatchSandboxMetadataRequest = Body(...), @@ -242,7 +242,7 @@ def patch_sandbox_metadata( 500: {"model": ErrorResponse, "description": "An unexpected server error occurred"}, }, ) -@instrumented_operation("delete") +@lifecycle_operation("delete") def delete_sandbox( sandbox_id: str, x_request_id: Optional[str] = Header(None, alias="X-Request-ID", description="Unique request identifier for tracing"), @@ -283,7 +283,7 @@ def delete_sandbox( 500: {"model": ErrorResponse, "description": "An unexpected server error occurred"}, }, ) -@instrumented_operation("pause") +@lifecycle_operation("pause") def pause_sandbox( sandbox_id: str, x_request_id: Optional[str] = Header(None, alias="X-Request-ID", description="Unique request identifier for tracing"), @@ -321,7 +321,7 @@ def pause_sandbox( 500: {"model": ErrorResponse, "description": "An unexpected server error occurred"}, }, ) -@instrumented_operation("resume") +@lifecycle_operation("resume") def resume_sandbox( sandbox_id: str, x_request_id: Optional[str] = Header(None, alias="X-Request-ID", description="Unique request identifier for tracing"), @@ -361,7 +361,7 @@ def resume_sandbox( 500: {"model": ErrorResponse, "description": "An unexpected server error occurred"}, }, ) -@instrumented_operation("renew") +@lifecycle_operation("renew") def renew_sandbox_expiration( sandbox_id: str, request: RenewSandboxExpirationRequest, @@ -409,7 +409,7 @@ def renew_sandbox_expiration( 500: {"model": ErrorResponse, "description": "An unexpected server error occurred"}, }, ) -@instrumented_operation("create_snapshot") +@lifecycle_operation("create_snapshot") def create_snapshot( sandbox_id: str, response: Response, @@ -493,7 +493,7 @@ def get_snapshot( 500: {"model": ErrorResponse, "description": "An unexpected server error occurred"}, }, ) -@instrumented_operation("delete_snapshot") +@lifecycle_operation("delete_snapshot") def delete_snapshot( snapshot_id: str, x_request_id: Optional[str] = Header(None, alias="X-Request-ID", description="Unique request identifier for tracing"), diff --git a/server/opensandbox_server/integrations/otel/__init__.py b/server/opensandbox_server/integrations/otel/__init__.py index 91ba24dec..5af7bbd24 100644 --- a/server/opensandbox_server/integrations/otel/__init__.py +++ b/server/opensandbox_server/integrations/otel/__init__.py @@ -14,7 +14,10 @@ """Optional OpenTelemetry integration for SDK metrics ingestion and server metrics.""" -from opensandbox_server.integrations.otel.instrument import instrumented_operation +from opensandbox_server.integrations.otel.instrument import ( + InstrumentedRoute, + lifecycle_operation, +) from opensandbox_server.integrations.otel.metrics import ( record_sandbox_create_duration, record_sandbox_operation, @@ -23,7 +26,8 @@ ) __all__ = [ - "instrumented_operation", + "InstrumentedRoute", + "lifecycle_operation", "record_sandbox_create_duration", "record_sandbox_operation", "setup_otel_metrics", diff --git a/server/opensandbox_server/integrations/otel/instrument.py b/server/opensandbox_server/integrations/otel/instrument.py index 1f05682be..85e703f66 100644 --- a/server/opensandbox_server/integrations/otel/instrument.py +++ b/server/opensandbox_server/integrations/otel/instrument.py @@ -12,17 +12,19 @@ # See the License for the specific language governing permissions and # limitations under the License. -"""Server-side instrumentation for lifecycle API handlers.""" +"""Server-side instrumentation for lifecycle API routes.""" from __future__ import annotations -import functools -import inspect import logging import time -from typing import Any, Callable, Optional +from typing import Callable, Optional from fastapi import HTTPException +from fastapi.exceptions import RequestValidationError +from fastapi.routing import APIRoute +from starlette.requests import Request +from starlette.responses import Response from opensandbox_server.integrations.otel.metrics import record_sandbox_operation from opensandbox_server.services.constants import SandboxErrorCodes @@ -32,14 +34,34 @@ OUTCOME_SUCCESS = "success" OUTCOME_ERROR = "error" +# Set by lifecycle_operation, read by InstrumentedRoute. +_OPERATION_ATTRIBUTE = "__opensandbox_operation__" + + +def lifecycle_operation(operation: str) -> Callable[[Callable], Callable]: + """Mark a route handler as a lifecycle operation, for ``InstrumentedRoute`` to record. + + A marker rather than a wrapper: recording happens in the route class, which also sees + requests rejected before the handler runs. Wrapping here as well would double-count, and + would put a layer between FastAPI and the handler signature for no benefit. + """ + + def decorator(func: Callable) -> Callable: + setattr(func, _OPERATION_ATTRIBUTE, operation) + return func + + return decorator + def _error_code_from(exc: BaseException) -> str: - """Pull the server error code out of a raised exception. + """Pull a bounded error code out of a failure. - Handlers raise ``HTTPException`` with ``detail={"code": ..., "message": ...}``. When the - detail is a plain string, or the exception is not an ``HTTPException`` at all, fall back - to the generic code so a failure is still counted rather than dropped. + Handlers raise ``HTTPException`` with ``detail={"code": ..., "message": ...}``. Request + validation fails before any handler runs and carries no server code, so it is reported by + status. Anything unexpected gets the generic code, so a failure is still counted. """ + if isinstance(exc, RequestValidationError): + return "HTTP_422" if isinstance(exc, HTTPException): detail = exc.detail if isinstance(detail, dict): @@ -50,61 +72,59 @@ def _error_code_from(exc: BaseException) -> str: return SandboxErrorCodes.UNKNOWN_ERROR -def instrumented_operation(operation: str) -> Callable[[Callable], Callable]: - """Record duration and outcome of a lifecycle handler. - - Measures the server's own work at the API boundary, which is the one place where every - runtime converges and where the error code has already been decided. Despite the 202 - status, ``POST /sandboxes`` blocks until the sandbox is provisioned — Kubernetes awaits - ``_wait_for_sandbox_ready``, Docker awaits the provisioning thread — so ``create`` is a - cold-start measurement rather than a scheduling one. +def _record(operation: str, started: float, outcome: str, error_code: Optional[str]) -> None: + """Record one sample, swallowing anything that goes wrong. - ``functools.wraps`` is load-bearing: FastAPI builds the request model from the handler - signature, and ``inspect.signature`` follows ``__wrapped__``, so the route keeps its - parameters. Never swallows or alters an exception, and never lets a metrics failure - affect the response. + This sits on every mutating route, so a bug in telemetry must not be able to fail a + request. ``record_sandbox_operation`` already guards its instruments; this guards the rest. + """ + try: + record_sandbox_operation( + operation=operation, + duration_ms=(time.perf_counter() - started) * 1000.0, + outcome=outcome, + error_code=error_code, + ) + except Exception: + logger.exception("Failed to record %s operation metric", operation) + + +class InstrumentedRoute(APIRoute): + """Records duration and outcome for routes marked with ``lifecycle_operation``. + + Instrumenting the route rather than the handler covers the whole API boundary: FastAPI + raises ``RequestValidationError`` before the endpoint is called, so a decorator on the + handler never sees a malformed request and an error-rate dashboard would undercount it. + + Unmarked routes — the read-only endpoints — get the untouched handler, so nothing is paid + for them. + + Note ``POST /sandboxes`` answers 202 but blocks until the sandbox is provisioned + (Kubernetes awaits pod readiness, Docker awaits the provisioning thread), so ``create`` + measures cold start rather than scheduling. """ - def decorator(func: Callable) -> Callable: - def _record(started: float, outcome: str, error_code: Optional[str]) -> None: - # record_sandbox_operation already swallows instrument errors, but this sits on - # every mutating route: a bug in telemetry must not be able to fail a request. - try: - record_sandbox_operation( - operation=operation, - duration_ms=(time.perf_counter() - started) * 1000.0, - outcome=outcome, - error_code=error_code, - ) - except Exception: - logger.exception("Failed to record %s operation metric", operation) - - if inspect.iscoroutinefunction(func): - - @functools.wraps(func) - async def async_wrapper(*args: Any, **kwargs: Any) -> Any: - started = time.perf_counter() - try: - result = await func(*args, **kwargs) - except BaseException as exc: - _record(started, OUTCOME_ERROR, _error_code_from(exc)) - raise - _record(started, OUTCOME_SUCCESS, None) - return result - - return async_wrapper - - @functools.wraps(func) - def wrapper(*args: Any, **kwargs: Any) -> Any: + def get_route_handler(self) -> Callable: + handler = super().get_route_handler() + operation: Optional[str] = getattr(self.endpoint, _OPERATION_ATTRIBUTE, None) + if operation is None: + return handler + + async def instrumented_handler(request: Request) -> Response: started = time.perf_counter() try: - result = func(*args, **kwargs) + response = await handler(request) except BaseException as exc: - _record(started, OUTCOME_ERROR, _error_code_from(exc)) + _record(operation, started, OUTCOME_ERROR, _error_code_from(exc)) raise - _record(started, OUTCOME_SUCCESS, None) - return result + # A handler that returns an error status instead of raising still failed. + if response.status_code >= 400: + _record(operation, started, OUTCOME_ERROR, f"HTTP_{response.status_code}") + else: + _record(operation, started, OUTCOME_SUCCESS, None) + return response - return wrapper + return instrumented_handler - return decorator + +__all__ = ["InstrumentedRoute", "lifecycle_operation"] diff --git a/server/tests/test_otel_server_metrics.py b/server/tests/test_otel_server_metrics.py index 243fb451e..3c8010b1c 100644 --- a/server/tests/test_otel_server_metrics.py +++ b/server/tests/test_otel_server_metrics.py @@ -14,14 +14,18 @@ """Server-side lifecycle operation metrics.""" -import asyncio from unittest.mock import MagicMock, patch import pytest -from fastapi import HTTPException +from fastapi import APIRouter, FastAPI, HTTPException +from fastapi.testclient import TestClient +from pydantic import BaseModel import opensandbox_server.integrations.otel.metrics as otel_metrics -from opensandbox_server.integrations.otel.instrument import instrumented_operation +from opensandbox_server.integrations.otel.instrument import ( + InstrumentedRoute, + lifecycle_operation, +) from opensandbox_server.integrations.otel.metrics import ( normalize_error_code, record_sandbox_operation, @@ -108,112 +112,156 @@ def test_never_raises_when_the_instrument_fails(self): record_sandbox_operation(operation="pause", duration_ms=1.0, outcome="success") -class TestInstrumentedOperation: - """The decorator must be invisible to the handler it wraps.""" +class _Body(BaseModel): + name: str - def test_sync_success(self): - @instrumented_operation("pause") - def handler(sandbox_id: str) -> str: - return f"paused {sandbox_id}" - with patch( - "opensandbox_server.integrations.otel.instrument.record_sandbox_operation" - ) as record: - assert handler("sbx-1") == "paused sbx-1" +def _app() -> FastAPI: + """A router using the real route class, with one marked and one unmarked endpoint.""" + router = APIRouter(route_class=InstrumentedRoute) - call = record.call_args.kwargs - assert call["operation"] == "pause" - assert call["outcome"] == "success" - assert call["error_code"] is None - assert call["duration_ms"] >= 0 + @router.post("/marked") + @lifecycle_operation("create") + async def marked(body: _Body) -> dict: + if body.name == "boom": + raise ValueError("boom") + if body.name == "missing": + raise HTTPException( + status_code=404, + detail={"code": SandboxErrorCodes.SANDBOX_NOT_FOUND, "message": "gone"}, + ) + if body.name == "conflict": + raise HTTPException(status_code=409, detail="conflict") + return {"created": body.name} - def test_async_success_preserves_the_signature(self): - @instrumented_operation("create") - async def handler(request: str, x_request_id: str = "") -> str: - return f"created {request}" + @router.get("/unmarked") + def unmarked() -> dict: + return {"ok": True} + + app = FastAPI() + app.include_router(router) + return app - # FastAPI builds the request model from the signature, so it has to survive. - import inspect - assert list(inspect.signature(handler).parameters) == ["request", "x_request_id"] +class TestInstrumentedRoute: + """Recording happens at the route, so it covers the whole API boundary.""" + def _call(self, method: str, path: str, **kwargs): with patch( "opensandbox_server.integrations.otel.instrument.record_sandbox_operation" ) as record: - assert asyncio.run(handler("spec")) == "created spec" + response = getattr(TestClient(_app(), raise_server_exceptions=False), method)( + path, **kwargs + ) + return response, record - assert record.call_args.kwargs["outcome"] == "success" + def test_success(self): + response, record = self._call("post", "/marked", json={"name": "sbx"}) - def test_http_exception_with_code_is_counted_and_reraised(self): - @instrumented_operation("delete") - def handler() -> None: - raise HTTPException( - status_code=404, - detail={"code": SandboxErrorCodes.SANDBOX_NOT_FOUND, "message": "gone"}, - ) + assert response.status_code == 200 + call = record.call_args.kwargs + assert call["operation"] == "create" + assert call["outcome"] == "success" + assert call["error_code"] is None + assert call["duration_ms"] >= 0 - with patch( - "opensandbox_server.integrations.otel.instrument.record_sandbox_operation" - ) as record: - with pytest.raises(HTTPException) as raised: - handler() + def test_http_exception_with_code(self): + response, record = self._call("post", "/marked", json={"name": "missing"}) - assert raised.value.status_code == 404 + assert response.status_code == 404 call = record.call_args.kwargs assert call["outcome"] == "error" assert call["error_code"] == SandboxErrorCodes.SANDBOX_NOT_FOUND def test_http_exception_without_a_code_falls_back_to_the_status(self): - @instrumented_operation("resume") - def handler() -> None: - raise HTTPException(status_code=409, detail="conflict") - - with patch( - "opensandbox_server.integrations.otel.instrument.record_sandbox_operation" - ) as record: - with pytest.raises(HTTPException): - handler() + response, record = self._call("post", "/marked", json={"name": "conflict"}) + assert response.status_code == 409 assert record.call_args.kwargs["error_code"] == "HTTP_409" - def test_unexpected_exception_is_counted_and_reraised(self): - @instrumented_operation("create_snapshot") - def handler() -> None: - raise ValueError("boom") - - with patch( - "opensandbox_server.integrations.otel.instrument.record_sandbox_operation" - ) as record: - with pytest.raises(ValueError, match="boom"): - handler() + def test_unexpected_exception(self): + response, record = self._call("post", "/marked", json={"name": "boom"}) + assert response.status_code == 500 assert record.call_args.kwargs["error_code"] == SandboxErrorCodes.UNKNOWN_ERROR - def test_a_metrics_failure_does_not_break_the_handler(self): - """Instrumentation sits on every mutating route; it must not be able to fail one.""" + def test_request_rejected_before_the_handler_runs_is_still_counted(self): + """A malformed body never reaches the endpoint; the route still sees the failure.""" + response, record = self._call("post", "/marked", json={"wrong": "field"}) + + assert response.status_code == 422 + call = record.call_args.kwargs + assert call["operation"] == "create" + assert call["outcome"] == "error" + assert call["error_code"] == "HTTP_422" + + def test_unmarked_routes_are_not_recorded(self): + response, record = self._call("get", "/unmarked") + + assert response.status_code == 200 + record.assert_not_called() - @instrumented_operation("renew") - def handler() -> str: - return "renewed" + def test_recorded_exactly_once(self): + """The marker must not wrap the handler as well, or every call counts twice.""" + _, record = self._call("post", "/marked", json={"name": "sbx"}) + assert record.call_count == 1 + + def test_a_metrics_failure_does_not_break_the_request(self): + """Instrumentation sits on every mutating route; it must not be able to fail one.""" with patch( "opensandbox_server.integrations.otel.instrument.record_sandbox_operation", side_effect=RuntimeError("metrics down"), ): - assert handler() == "renewed" + response = TestClient(_app()).post("/marked", json={"name": "sbx"}) - def test_a_metrics_failure_does_not_mask_a_handler_error(self): - """And it must not swallow the failure the caller actually needs to see.""" - - @instrumented_operation("delete") - def handler() -> None: - raise HTTPException(status_code=404, detail="gone") + assert response.status_code == 200 + assert response.json() == {"created": "sbx"} + def test_a_metrics_failure_does_not_mask_a_handler_error(self): with patch( "opensandbox_server.integrations.otel.instrument.record_sandbox_operation", side_effect=RuntimeError("metrics down"), ): - with pytest.raises(HTTPException) as raised: - handler() + response = TestClient(_app()).post("/marked", json={"name": "missing"}) + + assert response.status_code == 404 - assert raised.value.status_code == 404 + +class TestLifecycleOperationMarker: + def test_returns_the_handler_untouched(self): + """FastAPI reads the signature; the marker must not stand in front of it.""" + + async def handler(request: str, x_request_id: str = "") -> str: + return request + + marked = lifecycle_operation("create")(handler) + + assert marked is handler + + +class TestLifecycleRouterIsInstrumented: + """Guards the wiring itself: decorator order and route_class are easy to get wrong.""" + + def test_mutating_routes_are_marked_and_use_the_route_class(self): + from opensandbox_server.api.lifecycle import router + + marked = { + route.endpoint.__name__: getattr(route.endpoint, "__opensandbox_operation__") + for route in router.routes + if hasattr(route.endpoint, "__opensandbox_operation__") + } + + assert marked == { + "create_sandbox": "create", + "patch_sandbox_metadata": "update_metadata", + "delete_sandbox": "delete", + "pause_sandbox": "pause", + "resume_sandbox": "resume", + "renew_sandbox_expiration": "renew", + "create_snapshot": "create_snapshot", + "delete_snapshot": "delete_snapshot", + } + # A marker with the wrong decorator order, or a router without route_class, would + # leave the metric silently unrecorded. + assert all(isinstance(route, InstrumentedRoute) for route in router.routes)