diff --git a/datasette/database.py b/datasette/database.py
index 2ba89923..ec83ecad 100644
--- a/datasette/database.py
+++ b/datasette/database.py
@@ -925,13 +925,9 @@ class Database:
if not timeout_expected:
span.set_status(Status(StatusCode.ERROR, str(e)))
span.record_exception(e)
- # A counter rather than only a span, because this is the
- # one thing an operator wants a rate and an alert on, and
- # spans under a 1% sampler cannot provide either. An
- # expected timeout - a caller that opted into a shorter
- # budget, like facet suggestion - is not counted, for the
- # same reason it is not a span error: it fires routinely
- # by design and would drown the signal this exists for.
+ # Expected timeouts (a caller that opted into a shorter
+ # budget, like facet suggestion) are not counted - see
+ # the M_QUERIES_INTERRUPTED registry entry for why.
record_query_interrupted(self.name)
raise
except Exception as e:
diff --git a/datasette/telemetry.py b/datasette/telemetry.py
index 581787fe..4693e1fb 100644
--- a/datasette/telemetry.py
+++ b/datasette/telemetry.py
@@ -109,11 +109,11 @@ def callback_name(fn) -> str:
# fixed allowlist - deliberately not a parse.
#
# This runs against arbitrary user-supplied SQL (the `?sql=` query string,
-# canned queries, anything typed into the query editor), and the attribute is
-# a candidate dimension on a query-duration metric in a later phase. A metric
-# series is keyed by its attribute values, so echoing back an arbitrary first
-# token would let one visitor's typo mint a new, permanent series. The
-# allowlist bounds that at a fixed, small set regardless of what anyone sends.
+# canned queries, anything typed into the query editor), and the attribute
+# has to stay safe to use as a metric dimension. A metric series is keyed by
+# its attribute values, so echoing back an arbitrary first token would let
+# one visitor's typo mint a new, permanent series. The allowlist bounds that
+# at a fixed, small set regardless of what anyone sends.
DB_OPERATION_ALLOWLIST = frozenset(
{
"SELECT",
@@ -382,23 +382,12 @@ class TelemetryMiddleware:
# --- Metrics --------------------------------------------------------------
#
-# Spans answer "what happened during this request". They cannot answer "am I
-# saturating my 3 SQL threads right now", because that is a gauge: a level
-# sampled at collection time, not an event with a duration. It is also the
-# single most useful operational question about a Datasette deployment, since
-# num_sql_threads defaults to 3 and every read query in the process competes
-# for those threads.
-#
-# Two shapes are used here:
-#
-# Observable gauges - a callback the SDK invokes on its own collection
-# cycle. Nothing is computed unless something is collecting, so the default
-# no-provider install pays literally nothing for them.
-#
-# Synchronous histograms/counters - recorded inline on the query path. These
-# survive trace sampling, which spans do not: an operator sampling 1% of
-# traces still gets 100% of the latency distribution and the interrupted
-# count.
+# Two shapes. Observable gauges - a callback the SDK invokes on its own
+# collection cycle, so a no-provider install never runs them - answer level
+# questions no span can, like "am I saturating my SQL threads right now".
+# Synchronous histograms/counters are recorded inline on the query path and
+# survive trace sampling: 1% of traces still means 100% of the latency
+# distribution. Why each metric exists is documented on its registry entry.
#
# Note a real difference from tracing: `_ProxyMeter` and its instruments
# forward to a provider installed *after* they were created, whereas
@@ -415,6 +404,10 @@ def _duration_attributes(database_name, operation):
}
+# Each instrument passes the SDK a short plain-text description; the registry
+# entry for the same metric carries a longer RST one for the generated docs
+# (it can use `:ref:` roles, which an exported description string cannot).
+
sql_operation_duration = meter.create_histogram(
M_OPERATION_DURATION,
unit=M_OPERATION_DURATION.unit,
diff --git a/docs/internals.rst b/docs/internals.rst
index 303857da..3b1ae285 100644
--- a/docs/internals.rst
+++ b/docs/internals.rst
@@ -2552,7 +2552,7 @@ Exemplars are kept per histogram bucket - the SDK's default reservoir for an exp
Correcting the bucket boundaries had a second effect beyond fixing the quantiles: it also multiplied the number of traces reachable from this metric, one to four for this workload.
-Which export path you use matters here. The OTLP exporter carries exemplars through unchanged. The pinned ``opentelemetry-exporter-prometheus`` (``0.65b0``) does not: the string ``exemplar`` does not appear anywhere in its source, and an OpenMetrics scrape of the workload above through that exporter contained zero exemplar markers - even though ``prometheus-client`` (``0.26.0``), the library it depends on for OpenMetrics output, supports the syntax. If exemplars need to reach Prometheus, the path that works is an OTLP collector writing to Prometheus, not Datasette's own Prometheus exporter. On that path, the Prometheus server needs `--enable-feature=exemplar-storage `__, and the scrape itself must use the OpenMetrics exposition format - Prometheus's default text format has no syntax for exemplars at all. Grafana then needs the Prometheus data source's `exemplar configuration `__ (``exemplarTraceIdDestinations``) pointed at a tracing data source before it will draw an exemplar as a clickable point rather than an ordinary sample.
+Which export path you use matters here. The OTLP exporter carries exemplars through unchanged. ``opentelemetry-exporter-prometheus`` (as of ``0.65b0``) does not: the string ``exemplar`` does not appear anywhere in its source, and an OpenMetrics scrape of the workload above through that exporter contained zero exemplar markers - even though ``prometheus-client`` (``0.26.0``), the library it depends on for OpenMetrics output, supports the syntax. If exemplars need to reach Prometheus, the path that works is an OTLP collector writing to Prometheus, not a plugin scraping through that exporter. On that path, the Prometheus server needs `--enable-feature=exemplar-storage `__, and the scrape itself must use the OpenMetrics exposition format - Prometheus's default text format has no syntax for exemplars at all. Grafana then needs the Prometheus data source's `exemplar configuration `__ (``exemplarTraceIdDestinations``) pointed at a tracing data source before it will draw an exemplar as a clickable point rather than an ordinary sample.
An exemplar can only exist for a trace that was sampled. The SDK's default exemplar filter only records one when the measurement happens inside a sampled span, and produces no exemplar at all rather than a link to a trace that was never kept. Verified: with the tracer provider's sampler set to ``ALWAYS_OFF``, the same four-query workload produced ``exemplars: 0`` on every data point. At 1% head sampling, 99% of measurements contribute no exemplar - but every exemplar you do get is guaranteed to resolve to a trace that exists.
diff --git a/tests/conftest.py b/tests/conftest.py
index e0c1cab1..ff33da98 100644
--- a/tests/conftest.py
+++ b/tests/conftest.py
@@ -123,12 +123,10 @@ def _otel_meter_provider():
Install a real OTel SDK MeterProvider + InMemoryMetricReader once per
process.
- Unlike the tracer, ordering is not load-bearing here: `_ProxyMeter` and
- the `_ProxyInstrument`s it hands out forward to a provider installed
- *after* they were created, whereas `ProxyTracer` permanently caches the
- first concrete tracer it resolves. This fixture is still session-scoped
- and autouse for symmetry, and so that a single reader collects for the
- whole run.
+ Unlike the tracer, ordering is not load-bearing here - see the metrics
+ banner in `datasette/telemetry.py` for the `_ProxyMeter`-vs-`ProxyTracer`
+ difference. This fixture is still session-scoped and autouse for
+ symmetry, and so that a single reader collects for the whole run.
DELTA temporality is chosen for counters and histograms so that each
collection reports only what happened since the previous one. With the
diff --git a/tests/test_telemetry_metrics.py b/tests/test_telemetry_metrics.py
index 1422fbcd..f1ac4a56 100644
--- a/tests/test_telemetry_metrics.py
+++ b/tests/test_telemetry_metrics.py
@@ -17,6 +17,8 @@ Two layers are tested separately and deliberately:
"""
import asyncio
+import threading
+import weakref
import pytest
@@ -74,22 +76,71 @@ async def test_no_thread_gauges_in_non_threaded_mode():
num_sql_threads=0 means there is no pool at all, so the pool gauges must
skip the instance rather than report a bogus limit of 0.
- The pool gauges carry no attributes, so the assertion is that adding this
- instance produces no *additional* observations.
+ The pool gauges carry no attributes, so the live-instance registry is
+ narrowed to just this instance for the assertion - counting global
+ observations instead would let an unrelated instance being garbage
+ collected mid-test shift the baseline.
"""
- before_limits = len(list(telemetry.observe_sql_thread_limit()))
- before_depths = len(list(telemetry.observe_sql_thread_queue_depth()))
ds = Datasette(memory=True, settings={"num_sql_threads": 0})
try:
assert ds.executor is None
- assert len(list(telemetry.observe_sql_thread_limit())) == before_limits
- assert len(list(telemetry.observe_sql_thread_queue_depth())) == before_depths
+ original = telemetry._live_datasettes
+ telemetry._live_datasettes = weakref.WeakSet([ds])
+ try:
+ assert list(telemetry.observe_sql_thread_limit()) == []
+ assert list(telemetry.observe_sql_thread_queue_depth()) == []
+ finally:
+ telemetry._live_datasettes = original
# Per-database gauges are unaffected - they do not depend on the pool.
assert observations(telemetry.observe_pending_queries, ds)
finally:
ds.close()
+@pytest.mark.asyncio
+async def test_thread_queue_depth_gauge_reports_saturation():
+ """
+ The headline alerting metric must actually read above zero when reads
+ queue behind num_sql_threads. This also pins the private
+ `ThreadPoolExecutor._work_queue` attribute the callback depends on: if a
+ stdlib rename ever removes it, this fails instead of the metric silently
+ vanishing (the callback tolerates its absence at collection time).
+ """
+ ds = Datasette(memory=True, settings={"num_sql_threads": 1})
+ db = ds.add_memory_database("metrics_saturation_db")
+ entered = threading.Event()
+ release = threading.Event()
+
+ def blocker(conn):
+ entered.set()
+ assert release.wait(timeout=10)
+ return 1
+
+ try:
+ first = asyncio.ensure_future(db.execute_fn(blocker))
+ # Wait until the blocker owns the pool's only thread.
+ await asyncio.get_running_loop().run_in_executor(None, entered.wait, 10)
+ second = asyncio.ensure_future(db.execute_fn(lambda conn: 2))
+ # The second submission lands in the executor's queue on the next
+ # event-loop turn; poll briefly rather than assume the timing.
+ depths = []
+ for _ in range(500):
+ depths = [
+ value
+ for _, value in observations(telemetry.observe_sql_thread_queue_depth)
+ ]
+ if any(value >= 1 for value in depths):
+ break
+ await asyncio.sleep(0.01)
+ assert any(value >= 1 for value in depths), depths
+ release.set()
+ assert await first == 1
+ assert await second == 2
+ finally:
+ release.set()
+ ds.close()
+
+
@pytest.mark.asyncio
async def test_pending_queries_gauge_tracks_in_flight_queries(metrics_ds):
db = metrics_ds.get_database("metrics_test_db")
@@ -224,6 +275,30 @@ async def test_operation_duration_records_error_type(otel_metrics):
ds.close()
+@pytest.mark.asyncio
+async def test_operation_duration_records_write_error_type(otel_metrics):
+ """
+ Same as the read-path error test, but the write wrappers time a different
+ code path - `execute_write_fn`, the write thread and its reply future -
+ so error propagation through them is pinned separately.
+ """
+ ds = Datasette(memory=True)
+ ds.add_memory_database("duration_write_error_db")
+ try:
+ db = ds.get_database("duration_write_error_db")
+ with pytest.raises(sqlite3.OperationalError):
+ await db.execute_write("insert into nope values (1)")
+ otel_metrics.collect()
+ point = otel_metrics.point(
+ "db.client.operation.duration",
+ {"db.namespace": "duration_write_error_db", "datasette.operation": "write"},
+ )
+ assert point.count == 1
+ assert dict(point.attributes)["error.type"] == "OperationalError"
+ finally:
+ ds.close()
+
+
@pytest.mark.asyncio
async def test_write_queue_wait_histogram(otel_metrics):
ds = Datasette(memory=True)