Skip to content

OpenTelemetry metrics: SQL thread saturation, query latency, write queue depth - #2897

Draft
asg017 wants to merge 7 commits into
asg017/otel-phase1-2-request-spanfrom
asg017/otel-phase1-5-metrics
Draft

OpenTelemetry metrics: SQL thread saturation, query latency, write queue depth#2897
asg017 wants to merge 7 commits into
asg017/otel-phase1-2-request-spanfrom
asg017/otel-phase1-5-metrics

Conversation

@asg017

@asg017 asg017 commented Sep 1, 2026

Copy link
Copy Markdown
Collaborator
🤖 Claude-generated PR description

Adds OpenTelemetry metrics to the phase-1 stack, alongside the spans from #2862 and #2863. Stacked directly on #2863.

Why metrics belong in phase 1

Spans answer "why was this request slow?" — but the most operationally important Datasette question is a level, not an event: am I saturating my SQL threads? num_sql_threads defaults to 3, and when they're full requests queue silently — no error, no slow query to point at, just a db.query span whose duration quietly includes the wait. datasette.sql.threads.queue_depth sustained above zero is the one number worth alerting on, and no amount of span work surfaces it.

Metrics also survive sampling: an operator keeping 1% of traces still keeps 100% of every histogram, and a rate (how often are queries killed at the time limit?) cannot be recovered from sampled spans at all.

Like the span work, this uses opentelemetry-api only — core records measurements, but without an SDK MeterProvider installed every one is a no-op. A plugin (or opentelemetry-instrument) supplies the provider and exporter; a working /-/metrics Prometheus plugin exists and runs against this branch, which is what makes e.g. Fly.io's free managed Prometheus+Grafana a three-line fly.toml deployment story.

The metrics

name kind what it answers
db.client.operation.duration histogram (s) query latency distribution, split by database, read/write, and error.type
datasette.write.queue_wait histogram (s) how long writes sat behind the single write thread
datasette.sql.queries.interrupted counter queries killed at the configured time limit (expected short-budget timeouts, e.g. facet suggestion, are excluded — same semantics as the span errors in #2862)
datasette.sql.threads.limit gauge the num_sql_threads ceiling
datasette.sql.threads.queue_depth gauge the alerting metric — reads waiting for a free thread
datasette.sql.queries.pending gauge reads submitted and not yet complete, per database
datasette.write.queue_depth gauge writes queued per database
datasette.connections.open gauge open SQLite file connections, per database

Gauges observe live Datasette instances via a weak registry (callbacks never take request-path locks). The internal database is deliberately included — permission checks hit it on essentially every request.

Histogram buckets are explicit, on purpose

All histograms declare unit="s" with explicit boundaries (0.0001 … 10 seconds). Without this, OpenTelemetry's default millisecond-scale buckets put every SQLite-speed measurement in a single bucket and histogram_quantile() returns noise while count/sum/min/max all stay correct — which is exactly why the bug is easy to ship without noticing. The bucket spread is pinned by a test.

Relationship to the hand-rolled tracer

This PR no longer depends on the tracer-removal PR (#2864, now closed): the metric recording call sites in datasette/database.py sit inside the OTel span blocks, which remain nested inside the existing trace() wrappers. Nothing about ?_trace=1 or trace_debug changes here, and removing the hand-rolled tracer stays available as a future standalone PR.

Commits

  1. Add OpenTelemetry metrics for SQL thread pool saturation and query latency — the instruments, recording call sites, and the live-instance gauge registry.
  2. Register metrics and give histograms bucket boundaries suited to seconds — the metric registry entries, shared bucket boundaries, and a cog-generated "Metric reference" section in the internals docs.
  3. Check metric attributes in the registry conformance test — every emitted metric's attributes are pinned against the registry, including a real (unexpected) interrupt via a 5ms time limit.
  4. Document metric exemplars — spans and metrics correlate out of the box when both are enabled; documents what exemplar support exists and where.
  5. Apply black to the metrics additions.

Docs

docs/internals.rst gains a metric reference table (cog-generated from the registry, so it can't drift) and exemplar documentation. The demos/otel/ additions from an earlier version of this branch were dropped along with the demo PR #2894.

🤖 Generated with Claude Code

https://claude.ai/code/session_012U7coQfVu8nK2R4q2mCULA

@asg017
asg017 force-pushed the asg017/otel-phase1-5-metrics branch from 2714722 to e12928d Compare September 1, 2026 23:24
@asg017
asg017 force-pushed the asg017/otel-phase1-5-metrics branch from e12928d to 89a9d62 Compare September 2, 2026 00:09
@asg017
asg017 changed the base branch from asg017/otel-phase1-4-otlp-demo to asg017/otel-phase1-2-request-span September 2, 2026 17:09
@asg017
asg017 force-pushed the asg017/otel-phase1-5-metrics branch from 89a9d62 to 735919e Compare September 2, 2026 17:09
@asg017
asg017 force-pushed the asg017/otel-phase1-5-metrics branch from 735919e to 69da984 Compare September 2, 2026 18:33
@asg017
asg017 force-pushed the asg017/otel-phase1-5-metrics branch from 69da984 to 04111f2 Compare September 2, 2026 18:54
@codecov

codecov Bot commented Sep 2, 2026

Copy link
Copy Markdown

Codecov Report

❌ Patch coverage is 0% with 126 lines in your changes missing coverage. Please review.
✅ Project coverage is 0.00%. Comparing base (1e44c3d) to head (9e5a402).

Files with missing lines Patch % Lines
datasette/telemetry.py 0.00% 75 Missing ⚠️
datasette/telemetry_registry.py 0.00% 26 Missing ⚠️
datasette/database.py 0.00% 23 Missing ⚠️
datasette/app.py 0.00% 2 Missing ⚠️
Additional details and impacted files
@@                        Coverage Diff                         @@
##           asg017/otel-phase1-2-request-span   #2897    +/-   ##
==================================================================
  Coverage                               0.00%   0.00%            
==================================================================
  Files                                     75      75            
  Lines                                  12625   12738   +113     
==================================================================
- Misses                                 12625   12738   +113     

☔ View full report in Codecov by Harness.
📢 Have feedback on the report? Share it here.

🚀 New features to boost your workflow:
  • ❄️ Test Analytics: Detect flaky tests, report on failures, and find test suite problems.
  • 📦 JS Bundle Analysis: Save yourself from yourself by tracking and limiting bundle sizes in JS merges.

asg017 and others added 7 commits September 2, 2026 14:20
…tency

Spans describe requests that have finished. They structurally cannot answer
"am I saturating my 3 SQL threads right now", because that is a level rather
than an event - and with num_sql_threads defaulting to 3, it is usually the
first thing worth knowing about a busy Datasette. This adds the metrics that
answer it.

Five observable gauges, computed only when something is collecting, so an
instance with no MeterProvider installed does no work for them at all:

  datasette.sql.threads.limit         num_sql_threads
  datasette.sql.threads.queue_depth   queries waiting for a free thread
  datasette.sql.queries.pending       in-flight reads, by db.namespace
  datasette.write.queue_depth         writes behind the single write thread
  datasette.connections.open          tracked file connections

Three instruments recorded inline, which matters because metrics survive
trace sampling and spans do not - an operator sampling 1% of traces still
gets 100% of the latency distribution:

  db.client.operation.duration        semconv histogram, with error.type
  datasette.write.queue_wait          the metric twin of the existing span
  datasette.sql.queries.interrupted   sql_time_limit_ms kills

The interrupted counter closes a gap the plan called out as unanswerable:
"how often are we killing queries at the limit" is a rate, and a rate cannot
be recovered from sampled spans.

Core still creates no provider of any kind, so the architecture is unchanged;
`grep -rn 'opentelemetry.sdk' datasette/` stays empty. One real difference
from tracing is worth recording: _ProxyMeter and its instruments forward to a
provider installed after they were created, whereas ProxyTracer permanently
caches the first concrete tracer it resolves. Module-level instruments are
therefore safe and the test fixture has no ordering constraint.

Live instances are tracked in a lock-guarded WeakSet so instrumenting an
instance never keeps it alive. The pool gauges carry no attribute saying
which Datasette produced them: production runs one instance per process, and
adding an id to disambiguate the test suite's hundreds of instances would buy
unbounded attribute cardinality to fix a case that does not occur. The
collision is documented instead, and the gauge callbacks are plain generator
functions so tests can assert exact values by calling them directly rather
than through the SDK's last-value aggregation.

demos/otel/metrics_demo.py fires 12 concurrent 40ms queries at a 3-thread
pool and samples the gauges mid-flight: queue_depth peaks at exactly 9, and
the duration histogram reads max=0.1695s for a query whose work is 40ms. That
gap is the queue, and it is the thing traces alone will not show you.

Also corrects the demo README's privacy section, which still claimed
parameter values are never recorded - that stopped being unconditionally true
when trace_sql_parameters landed.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>

(cherry picked from 6ef0dd8 and adapted to the rebuilt phase-1 stack:
attribute names now come from telemetry_registry where entries exist, the
meter carries the instrumentation-scope version and schema URL, and the
interrupted-queries counter skips expected timeouts - callers that opted
into a deliberately short budget, like facet suggestion - matching how
those are excluded from span error status. The internals.rst reference
lands with the registry commit that follows.)

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01F2h9ANGZ7paWSpqs5DUAcG
Both histograms declared unit="s" but inherited OpenTelemetry's default
boundaries, which are tuned for milliseconds - so every SQLite query
landed in the single (0, 5] second bucket and every quantile query
returned noise.

The boundaries are the semantic conventions' recommended set for
db.client.operation.duration plus 0.0001 and 0.0005 at the bottom, since
SQLite is in-process and many real queries take tens of microseconds.

(Adapted from 024f202: that commit assumed the metrics were already in
telemetry_registry.py, which on this lineage held spans only - so this
commit also brings the MetricName registry machinery, the registry
entries for all eight phase-3 metrics, the cog-generated Metric
reference in internals.rst, and the datasette.operation attribute. The
template and facet histograms it also touched belong to phase 5 and are
not included.)

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01F2h9ANGZ7paWSpqs5DUAcG
Span attributes were checked in both directions; metric attributes were not
checked at all, so the generated reference could publish an incomplete list
with nothing to catch it.

The metric workload lives in an `emitted_metrics` fixture, mirroring the
span side, and error.type is checked like every other attribute rather than
exempted for being optional - the workload reaches it two separate ways.

(Adapted from b30c534: the old workload's facet-timeout probe belongs to
phase 5 and is dropped, and the interrupted counter now needs a query that
exceeds the *configured* time limit - custom short budgets are excluded from
the count on this lineage - so the fixture runs one against a second
instance configured with sql_time_limit_ms=5.)

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01F2h9ANGZ7paWSpqs5DUAcG
Histograms recorded inside a sampled span carry trace IDs automatically, so a
latency spike links to a trace that caused it. Nothing said so.

Two things are documented because they were measured rather than assumed: an
exemplar is kept per histogram bucket, so the bucket boundaries fixed earlier
in this stack took the same workload from one reachable trace to four; and the
pinned opentelemetry-exporter-prometheus drops exemplars entirely, so the path
that works is an OTLP collector rather than Datasette's Prometheus exporter.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>

(cherry picked from 9d06625; section numbering and cross-references
adjusted to this branch's demo README, and the exemplar reference placed
as a subsection of the new Metric reference in internals.rst.)

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01F2h9ANGZ7paWSpqs5DUAcG
Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01F2h9ANGZ7paWSpqs5DUAcG
…est gaps

- The exemplars docs described "the pinned opentelemetry-exporter-prometheus"
  and "Datasette's own Prometheus exporter" - context from demo/plugin work
  that is no longer part of this stack. Reworded to stand alone.
- Saturate a num_sql_threads=1 pool and assert the queue-depth gauge reads
  above zero - the headline alerting metric previously only had an absence
  test, and this also pins the private ThreadPoolExecutor._work_queue
  attribute it depends on.
- Pin error.type on the write path of db.client.operation.duration - the
  write wrappers time a different code path than the read one already tested.
- Isolate the non-threaded-mode gauge test from other live instances instead
  of comparing global observation counts, which a GC pass could shift.
- Halve the metrics banner, point conftest's meter note at it, compact the
  interrupted-counter call-site comment to a registry pointer, note why
  instrument and registry descriptions are separate strings, and stop
  calling the metric dimension a "later phase" now that metrics shipped.

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_012U7coQfVu8nK2R4q2mCULA
The callback entry points gained db.query spans in the database-spans PR;
this adds their other half - the duration histogram measurement, so a
plugin's execute_fn/execute_write_fn work and the JSON write API's inserts
and deletes stop being invisible to the one series that survives trace
sampling. execute_isolated_fn records "write" when the database is mutable
(the call blocks the write queue) and "read" when immutable (it runs on
the read pool). error.type comes from the raised exception class, same as
the SQL-string paths.

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_012U7coQfVu8nK2R4q2mCULA
@asg017
asg017 force-pushed the asg017/otel-phase1-5-metrics branch from 04111f2 to 9e5a402 Compare September 2, 2026 21:28
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant