From 71d382bbd49320df2c2151e036733707a5cc036f Mon Sep 17 00:00:00 2001 From: Alex Garcia Date: Wed, 2 Sep 2026 14:26:45 -0700 Subject: [PATCH] Capstone review fixes: per-test reset, rename, provider guard, UpDownCounter, naming rules, privacy walk Outcome of a whole-stack review with the kit visible as one system: - otel_reset: an autouse fixture draining the span exporter and metric reader after every test. Without it a large suite accumulates hundreds of thousands of recorded spans in the session-scoped exporter - the likeliest amplifier of the slow-runner CI flakes - and plugins would inherit the same leak. - assert_registry_covered renamed to assert_spans_covered: the old name read as covering the whole registry, which is exactly wrong next to assert_metrics_covered. Public API is forever; renamed before anything ships, no alias. - The installers now verify their provider actually took: with a provider installed first (opentelemetry-instrument, an embedding app), set_*_provider() is silently ignored, and fixtures would assert against an exporter wired to nothing. They skip clearly instead. - UPDOWN_COUNTER registry kind, mapped to Sum with monotonicity checked both ways - a Counter must collect monotonic, an UpDownCounter must not. Previously an UpDownCounter's kind check was silently skipped. - The docs page now prescribes naming: scope = import package name (underscores), signal prefix = a name you own, never bare datasette.*; its own examples no longer teach the hyphenated outlier. Plus an observable-gauges pattern section and a prefix-overlap note. - assert_no_forbidden_values(): the enforcement half of the privacy rules - plant sentinel secrets in a workload and assert they never appear in any span name, attribute, event, status description or metric attribute, across all scopes by default. Co-Authored-By: Claude Fable 5 Claude-Session: https://claude.ai/code/session_012U7coQfVu8nK2R4q2mCULA --- datasette/telemetry_registry.py | 1 + datasette/telemetry_testing.py | 114 ++++++++++++++++++++++++++-- docs/changelog.rst | 2 +- docs/plugin_telemetry.rst | 41 +++++++--- tests/conftest.py | 1 + tests/test_telemetry_testing_kit.py | 67 +++++++++++++++- 6 files changed, 207 insertions(+), 19 deletions(-) diff --git a/datasette/telemetry_registry.py b/datasette/telemetry_registry.py index 19a08055..cad5acb2 100644 --- a/datasette/telemetry_registry.py +++ b/datasette/telemetry_registry.py @@ -122,6 +122,7 @@ class MetricName(str): COUNTER = "Counter" +UPDOWN_COUNTER = "UpDownCounter" HISTOGRAM = "Histogram" GAUGE = "Observable gauge" diff --git a/datasette/telemetry_testing.py b/datasette/telemetry_testing.py index d9e953f1..86cb5641 100644 --- a/datasette/telemetry_testing.py +++ b/datasette/telemetry_testing.py @@ -20,7 +20,7 @@ signal. Tests then take ``otel_spans`` / ``otel_metrics``. Everything here imports the OpenTelemetry SDK lazily: with no SDK installed the fixtures skip rather than fail, and importing this module costs nothing. -The conformance helpers (`assert_spans_conform`, `assert_registry_covered`) +The conformance helpers (`assert_spans_conform`, `assert_spans_covered`) check a registry of `SpanName` entries against actually-finished spans in both directions - emitted-but-unregistered and registered-but-never-emitted, the two drift modes documented in `tests/test_telemetry_registry.py`. @@ -69,6 +69,14 @@ def install_span_exporter(): provider = TracerProvider() provider.add_span_processor(SimpleSpanProcessor(exporter)) otel_trace.set_tracer_provider(provider) + # set_tracer_provider() is once-per-process: if something else installed + # a provider first (another conftest, opentelemetry-instrument, an + # embedding app), the call above was silently ignored - and an exporter + # wired to nothing would make every span assertion fail confusingly, or + # pass vacuously on empty input. Leave the global unset in that case so + # the fixtures skip with a clear message instead. + if otel_trace.get_tracer_provider() is not provider: + return None _span_exporter = exporter return exporter @@ -101,7 +109,12 @@ def install_metric_reader(): Histogram: AggregationTemporality.DELTA, } ) - otel_metrics_api.set_meter_provider(MeterProvider(metric_readers=[reader])) + provider = MeterProvider(metric_readers=[reader]) + otel_metrics_api.set_meter_provider(provider) + # Same once-per-process guard as the tracer side: a provider that did + # not take must not leave a reader that collects nothing. + if otel_metrics_api.get_meter_provider() is not provider: + return None _metric_reader = reader return reader @@ -134,6 +147,25 @@ def otel_meter_provider(): install_metric_reader() +@pytest.fixture(autouse=True) +def otel_reset(): + """ + Autouse, function-scoped: drain the span exporter and metric reader + after every test - including the ones that never look at telemetry. + + Without this, every test that exercises the app leaves its recorded + spans in the session-scoped exporter's list forever: a large suite + accumulates hundreds of thousands of ReadableSpans, degrading memory + and per-span export cost as the run goes on. Draining the metric reader + likewise stops delta state piling up between metric tests. + """ + yield + if _span_exporter is not None: + _span_exporter.clear() + if _metric_reader is not None: + _metric_reader.get_metrics_data() + + @pytest.fixture def otel_spans(): """ @@ -251,7 +283,7 @@ def assert_spans_conform(registry_spans, finished_spans, scope_name=None): assert not problems, "\n".join(problems) -def assert_registry_covered(registry_spans, finished_spans, scope_name=None): +def assert_spans_covered(registry_spans, finished_spans, scope_name=None): """ Every entry in `registry_spans` was emitted at least once, and every one of its registered non-`optional` attributes appeared on it at least @@ -287,13 +319,15 @@ def assert_registry_covered(registry_spans, finished_spans, scope_name=None): # Registry instrument kinds mapped to the SDK data type collected for them. # A registry kind outside this table (a plugin's own vocabulary) is not -# kind-checked. "Counter" maps to Sum; monotonicity is not asserted, so -# UpDownCounters registered as "Counter" pass too. +# kind-checked. Both counter kinds collect as Sum; monotonicity is what +# tells them apart, checked separately below. _KIND_TO_DATA_TYPE = { "Counter": "Sum", + "UpDownCounter": "Sum", "Histogram": "Histogram", "Observable gauge": "Gauge", } +_KIND_IS_MONOTONIC = {"Counter": True, "UpDownCounter": False} def _scoped_metrics(collector, scope_name): @@ -327,6 +361,17 @@ def assert_metrics_conform(registry_metrics, collector, scope_name=None): f"{metric.name}: registry declares {entry.kind}, " f"SDK collected {actual_data_type}" ) + expected_monotonic = _KIND_IS_MONOTONIC.get(entry.kind) + actual_monotonic = getattr(metric.data, "is_monotonic", None) + if ( + expected_monotonic is not None + and actual_monotonic is not None + and actual_monotonic != expected_monotonic + ): + problems.add( + f"{metric.name}: registry declares {entry.kind}, but the " + f"collected Sum is_monotonic={actual_monotonic}" + ) if (metric.unit or "") != (entry.unit or ""): problems.add( f"{metric.name}: instrument unit {metric.unit!r} != " @@ -378,6 +423,65 @@ def assert_metrics_covered(registry_metrics, collector, scope_name=None): assert not problems, "\n".join(problems) +def assert_no_forbidden_values( + forbidden, finished_spans=None, collector=None, scope_name=None +): + """ + Assert that none of the `forbidden` strings appear anywhere in the + emitted telemetry: span names, span attribute values, span event names + and attributes, span status descriptions, or metric point attributes. + + This is the enforcement half of the privacy rules in the plugin + telemetry documentation. The strongest way to use it is to *plant* + sentinel values in your test workload - a fake email address, a token, + a username your fixtures log in with - and assert they never leak into + a signal: + + FORBIDDEN = {"secret-token-123", "alice@example.com"} + run_workload_using_those_values() + assert_no_forbidden_values( + FORBIDDEN, + finished_spans=otel_spans.get_finished_spans(), + collector=otel_metrics, + scope_name="my_plugin", + ) + + Matching is plain substring on the string form of each value; empty + strings in `forbidden` are ignored. Pass `finished_spans` and/or a + collected `MetricsCollector`; `scope_name=None` checks every scope, + which is the right default here - a leak through *core's* signals (e.g. + SQL text carrying a secret) is still a leak. + """ + needles = [needle for needle in forbidden if needle] + leaks = set() + + def check(value, where): + text = str(value) + for needle in needles: + if needle in text: + leaks.add(f"{where} contains {needle!r}") + + if finished_spans is not None: + for span in _scoped(finished_spans, scope_name): + check(span.name, f"span name {str(span.name)!r}") + for key, value in (span.attributes or {}).items(): + check(value, f"{span.name} attribute {key}") + for event in span.events or (): + check(event.name, f"{span.name} event name") + for key, value in (event.attributes or {}).items(): + check(value, f"{span.name} event {event.name} attribute {key}") + if span.status is not None and span.status.description: + check(span.status.description, f"{span.name} status description") + if collector is not None: + for metric in _scoped_metrics(collector, scope_name): + for point in metric.data.data_points: + for key, value in dict(point.attributes or {}).items(): + check(value, f"metric {metric.name} attribute {key}") + assert not leaks, "forbidden values leaked into telemetry:\n" + "\n".join( + sorted(leaks) + ) + + def assert_package_never_imports_sdk(*module_names): """ Import the named modules in a fresh interpreter and assert none of them diff --git a/docs/changelog.rst b/docs/changelog.rst index a0a34530..8698285e 100644 --- a/docs/changelog.rst +++ b/docs/changelog.rst @@ -14,7 +14,7 @@ Unreleased - Every HTTP request now gets an OpenTelemetry ``SERVER`` span, named after the request method and matched route, carrying ``http.route``, the response status and W3C trace context extracted from inbound headers - so every database span has a request to belong to, and Datasette joins distributed traces started by a proxy or calling service. The query string is never recorded. See :ref:`internals_telemetry_requests`. (:issue:`1730`) - Datasette core now also emits OpenTelemetry **metrics** covering SQL thread pool saturation, per-database write queue depth, open connections, query latency and time-limit interruptions. These answer operational questions that spans structurally cannot - "am I saturating my :ref:`setting_num_sql_threads` threads?" is a level, not an event - and they survive trace sampling. As with spans, core installs no ``MeterProvider``, so there is no cost unless metrics are collected externally. See :ref:`internals_telemetry`. (:issue:`1730`) -- New :ref:`plugin telemetry kit ` for plugins that emit their own OpenTelemetry signals: the registry classes (``Attribute`` with closed-enum ``values=``, ``SpanName`` with prefix-matched families, ``MetricName``) are now documented public API, ``datasette.telemetry.linked_root_span_kwargs()`` provides the root-span-with-link shape for background work, ``datasette.telemetry.request_span()`` is documented, and ``datasette.telemetry_testing`` ships the pytest fixtures and two-way conformance checks - for spans and metrics, including instrument kind/unit verification and enum enforcement - that core's own suite uses. (:issue:`1730`) +- New :ref:`plugin telemetry kit ` for plugins that emit their own OpenTelemetry signals: the registry classes (``Attribute`` with closed-enum ``values=``, ``SpanName`` with prefix-matched families, ``MetricName``) are now documented public API, ``datasette.telemetry.linked_root_span_kwargs()`` provides the root-span-with-link shape for background work, ``datasette.telemetry.request_span()`` is documented, and ``datasette.telemetry_testing`` ships the pytest fixtures and two-way conformance checks - for spans and metrics, including instrument kind/unit verification, enum enforcement and a forbidden-values privacy walk - that core's own suite uses. (:issue:`1730`) Nothing is removed by the OpenTelemetry work: the ``?_trace=1`` query string parameter, the ``trace_debug`` setting and the :ref:`internals_tracer` module all continue to work as before. diff --git a/docs/plugin_telemetry.rst b/docs/plugin_telemetry.rst index 8bf5d1d0..d4be782a 100644 --- a/docs/plugin_telemetry.rst +++ b/docs/plugin_telemetry.rst @@ -20,12 +20,17 @@ Never emit through core's tracer or meter. Your plugin's scope name is the machi from my_plugin import __version__ - tracer = trace.get_tracer("my-plugin", __version__) - meter = metrics.get_meter("my-plugin", __version__) + tracer = trace.get_tracer("my_plugin", __version__) + meter = metrics.get_meter("my_plugin", __version__) If every attribute you emit follows current semantic conventions you can also pass ``schema_url=``; ``datasette.telemetry.SCHEMA_URL`` is the version core's own spellings track, with a comment explaining how to choose one. When in doubt, omit it - a wrong schema URL is worse than none. -Name your own signals under a prefix you own (``my_plugin.*``). Reuse core's shared attribute spellings where they mean the same thing - ``db.namespace`` for a database name, ``error.type`` for a failure class - rather than minting parallel ones. +Two naming rules keep the ecosystem's signals tellable-apart: + +- **Scope**: use your plugin's *import package* name - ``my_plugin``, underscores and all. Consumers filter on the scope, and one spelling convention means they can guess it. +- **Signal prefix**: name spans, metrics and custom attributes under a prefix you own - your package name (``my_plugin.*``) or a short product name (``paper.*``). **Never a bare** ``datasette.*`` **prefix**: that namespace belongs to core, an operator could no longer tell core signals from plugin signals, and a future core signal could collide with yours. + +Reuse core's shared attribute spellings where they mean the same thing - ``db.namespace`` for a database name, ``error.type`` for a failure class - rather than minting parallel ones. If a span family in your registry shares a prefix with another entry, exact names always win over prefix matches, but two overlapping ``prefix=True`` entries resolve to whichever is listed first - avoid overlapping families rather than relying on order. .. _plugin_telemetry_registry: @@ -88,6 +93,8 @@ Core's instrumentation records **no data users put into Datasette and no identif - If you time user-influenced SQL, follow core: record the SQL via ``datasette.telemetry.sql_attribute()`` (truncated, never parameters) on spans only. - When a value is interesting but unbounded, record a bounded proxy instead: a count, a byte size, a truncation flag, or the enum outcome. +These rules are enforceable: see ``assert_no_forbidden_values()`` in :ref:`plugin_telemetry_testing`. + .. _plugin_telemetry_callbacks: Your database work is already traced @@ -140,6 +147,17 @@ Two propagation facts worth knowing (details in ``datasette/telemetry.py``): - Core's ``tracer`` and yours are proxies. A ``ProxyTracer`` permanently caches the first concrete tracer it resolves *after* a provider exists, so in embedded deployments the provider must be installed before the first span - importing the module is fine, starting spans is not. Meters forward retroactively; tracers do not. - ``asyncio.create_task`` copies the ambient context, so a long-running task created during a request will silently parent to that request's span - exactly the bug ``linked_root_span_kwargs()`` exists to avoid. +.. _plugin_telemetry_gauges: + +Observable gauges +----------------- + +For a *level* - how many streams are open, how deep is a queue - register an observable gauge whose callback the SDK invokes on its own collection cycle. Three disciplines, all inherited from how core implements its pool gauges in ``datasette/telemetry.py``: + +- Hold live objects **weakly** (a ``weakref.WeakSet`` guarded by a lock), so instrumenting an object never keeps it alive, and unregister on close. +- The callback runs on the SDK's **collection thread**: never take a lock the request path holds, never await, never do I/O. Read cached state and yield ``Observation`` values; if freshness matters, refresh the cache from your own code and expose its staleness as another gauge. +- With no provider installed the callback is **never invoked at all**, so gauges are free by default. + .. _plugin_telemetry_testing: Testing your instrumentation @@ -153,10 +171,11 @@ Testing your instrumentation otel_metrics, otel_meter_provider, otel_provider, + otel_reset, otel_spans, ) -``otel_provider`` and ``otel_meter_provider`` are session-scoped and autouse - they install a real SDK provider (in-memory, synchronous export) once per process, and do nothing when the SDK is not installed, so add ``opentelemetry-sdk`` to your test dependencies only. Tests then take ``otel_spans`` (an ``InMemorySpanExporter``) or ``otel_metrics`` (a collector with ``collect()`` / ``point()`` helpers). +``otel_provider`` and ``otel_meter_provider`` are session-scoped and autouse - they install a real SDK provider (in-memory, synchronous export) once per process, and do nothing when the SDK is not installed, so add ``opentelemetry-sdk`` to your test dependencies only. If a different provider was installed first (an embedding app, ``opentelemetry-instrument``), the fixtures detect that the install did not take and skip with a clear message rather than asserting against an exporter wired to nothing. ``otel_reset`` is autouse too: it drains the exporter and reader after every test, so a large suite does not accumulate recorded spans for its whole lifetime. Tests then take ``otel_spans`` (an ``InMemorySpanExporter``) or ``otel_metrics`` (a collector with ``collect()`` / ``point()`` helpers). Wire your registry to reality with the conformance helpers - the two directions catch instrumentation added without documentation and documentation describing signals that no longer exist: @@ -166,7 +185,7 @@ Wire your registry to reality with the conformance helpers - the two directions assert_metrics_conform, assert_metrics_covered, assert_package_never_imports_sdk, - assert_registry_covered, + assert_spans_covered, assert_spans_conform, ) @@ -177,13 +196,13 @@ Wire your registry to reality with the conformance helpers - the two directions run_a_workload_that_exercises_everything() finished = otel_spans.get_finished_spans() # Everything emitted is registered (and enum values are legal): - assert_spans_conform(SPANS, finished, scope_name="my-plugin") + assert_spans_conform(SPANS, finished, scope_name="my_plugin") # Everything registered was emitted: - assert_registry_covered(SPANS, finished, scope_name="my-plugin") + assert_spans_covered(SPANS, finished, scope_name="my_plugin") # Same two directions for metrics - one collect() after the workload: otel_metrics.collect() - assert_metrics_conform(METRICS, otel_metrics, scope_name="my-plugin") - assert_metrics_covered(METRICS, otel_metrics, scope_name="my-plugin") + assert_metrics_conform(METRICS, otel_metrics, scope_name="my_plugin") + assert_metrics_covered(METRICS, otel_metrics, scope_name="my_plugin") def test_api_only_dependency(): @@ -193,6 +212,8 @@ Always pass ``scope_name`` - the exporter and reader also hold core's signals, a The metric helpers check more than names: ``assert_metrics_conform`` asserts each instrument was created as the **kind** and **unit** its registry entry declares (the registry entry and the ``meter.create_*()`` call are separate statements, and a dashboard built on the registry's word breaks silently if they drift), and that every value on a ``values=`` enum attribute is a member - which is what makes a metric dimension *provably* bounded rather than bounded by intent. Both ``*_covered`` helpers exempt attributes marked ``optional=True`` (an ``error.type`` only present on failures should not force your workload to manufacture errors - pin those with targeted tests instead), and the metrics reader uses delta temporality, so run one broad workload followed by a single ``collect()``. +Finally, enforce the privacy rules with ``assert_no_forbidden_values()``: plant sentinel values in your workload - a fake email your fixtures log in with, a token, a username - and assert they never appear in any span name, attribute, event, status description or metric attribute. Leave ``scope_name`` unset for this one: a secret leaking through *core's* signals (SQL text, say) is still a leak. Schedule the test that calls ``assert_package_never_imports_sdk()`` early in your suite - see its docstring for the macOS threading hazard. + .. _plugin_telemetry_caveats: Known caveats @@ -200,4 +221,4 @@ Known caveats - **Streaming responses hold the request span open.** Core's request span ends when the response body finishes, so for an SSE or long-streaming route its duration is the connection lifetime. If you need per-message timing on a stream, emit your own child spans or span events per message, and use gauges for concurrent-stream counts. - **A plugin timing core's work double-measures by design.** See :ref:`plugin_telemetry_callbacks` above. -- ``datasette.client`` requests made from inside a request currently produce a nested ``SERVER`` span, which can double-count requests in kind-based dashboards. +- ``datasette.client`` requests made from inside a request produce a nested ``SERVER`` span. Those spans carry ``datasette.internal_client: true`` - filter on it to keep kind-based dashboards from double-counting requests. diff --git a/tests/conftest.py b/tests/conftest.py index d886c5fe..83b4d9e7 100644 --- a/tests/conftest.py +++ b/tests/conftest.py @@ -65,6 +65,7 @@ from datasette.telemetry_testing import ( # noqa: F401, E402 otel_metrics, otel_meter_provider, otel_provider, + otel_reset, otel_spans, ) diff --git a/tests/test_telemetry_testing_kit.py b/tests/test_telemetry_testing_kit.py index d2123f7c..5fcfcbe1 100644 --- a/tests/test_telemetry_testing_kit.py +++ b/tests/test_telemetry_testing_kit.py @@ -15,7 +15,7 @@ from datasette import telemetry_registry as reg from datasette.telemetry import linked_root_span_kwargs from datasette.telemetry_testing import ( assert_package_never_imports_sdk, - assert_registry_covered, + assert_spans_covered, assert_spans_conform, ) @@ -56,7 +56,7 @@ def test_conformance_passes_for_a_conforming_workload(otel_spans): assert_spans_conform(TOY_SPANS, finished, scope_name=SCOPE) # Coverage direction needs prefix families seen too - the chat span # resolves to the CHAT entry despite its variable suffix. - assert_registry_covered(TOY_SPANS, finished, scope_name=SCOPE) + assert_spans_covered(TOY_SPANS, finished, scope_name=SCOPE) def test_conformance_catches_an_unregistered_span(otel_spans): @@ -92,7 +92,7 @@ def test_coverage_catches_a_never_emitted_span(otel_spans): span.set_attribute(JOB_NAME, "nightly") # CHAT never emitted with pytest.raises(AssertionError, match="never emitted"): - assert_registry_covered( + assert_spans_covered( TOY_SPANS, otel_spans.get_finished_spans(), scope_name=SCOPE ) @@ -268,3 +268,64 @@ def test_metrics_scope_filter_ignores_other_scopes(otel_metrics): stranger.add(1) otel_metrics.collect() assert_metrics_conform(registry, otel_metrics, scope_name=SCOPE) + + +# --- UpDownCounter kind + privacy walk -------------------------------------- + +from datasette.telemetry_testing import assert_no_forbidden_values + + +def test_updown_counter_kind_passes(otel_metrics): + name = f"toyplugin.active.{next(_metric_ids)}" + registry = _toy_metric_registry(name, kind=reg.UPDOWN_COUNTER, unit="{turn}") + updown = toy_meter.create_up_down_counter(name, unit="{turn}") + updown.add(1, {OUTCOME: "ok"}) + otel_metrics.collect() + assert_metrics_conform(registry, otel_metrics, scope_name=SCOPE) + + +def test_counter_registered_as_updown_fails_on_monotonicity(otel_metrics): + name = f"toyplugin.monoclash.{next(_metric_ids)}" + registry = _toy_metric_registry(name, kind=reg.UPDOWN_COUNTER, unit="{job}") + counter = toy_meter.create_counter(name, unit="{job}") + counter.add(1, {OUTCOME: "ok"}) + otel_metrics.collect() + with pytest.raises(AssertionError, match="is_monotonic"): + assert_metrics_conform(registry, otel_metrics, scope_name=SCOPE) + + +def test_forbidden_values_walk_catches_a_leak(otel_spans, otel_metrics): + secret = "sentinel-token-xyzzy" + with toy_tracer.start_as_current_span(JOB) as span: + span.set_attribute(OUTCOME, "ok") + span.set_attribute(JOB_NAME, f"job for {secret}") + with pytest.raises(AssertionError, match="sentinel-token-xyzzy"): + assert_no_forbidden_values( + {secret}, + finished_spans=otel_spans.get_finished_spans(), + scope_name=SCOPE, + ) + + +def test_forbidden_values_walk_passes_a_clean_workload(otel_spans, otel_metrics): + _run_workload() + name = f"toyplugin.clean.{next(_metric_ids)}" + counter = toy_meter.create_counter(name, unit="{job}") + counter.add(1, {OUTCOME: "ok"}) + otel_metrics.collect() + assert_no_forbidden_values( + {"sentinel-token-xyzzy", "alice@example.com", ""}, + finished_spans=otel_spans.get_finished_spans(), + collector=otel_metrics, + scope_name=SCOPE, + ) + + +def test_forbidden_values_walk_checks_metric_attributes(otel_metrics): + secret = "leaky-metric-value" + name = f"toyplugin.leak.{next(_metric_ids)}" + counter = toy_meter.create_counter(name, unit="{job}") + counter.add(1, {"toyplugin.note": secret}) + otel_metrics.collect() + with pytest.raises(AssertionError, match="leaky-metric-value"): + assert_no_forbidden_values({secret}, collector=otel_metrics, scope_name=SCOPE)