Emit an OpenTelemetry span for each HTTP request - #2863
Draft
asg017 wants to merge 2 commits into
Draft
Conversation
Nothing in Datasette created a span for the HTTP request itself, so every span the database layer emits was a root span. Measured on this branch: one faceted table page produces 70 spans in 36 separate traces, none of which carries a URL. A trace UI shows that as dozens of unrelated single-span traces per page, interleaved across concurrent requests - worse than ?_trace=1 at the exact job people reach for tracing to do. With the request span it is 71 spans in 1 trace. `opentelemetry-instrument` does not fix this on its own: auto-instrumentation only picks up frameworks that ship an instrumentor entry point, and Datasette's raw ASGI app is not one. TelemetryMiddleware is mounted outermost in Datasette.app(), after the asgi_wrapper() plugin loop, so plugin middleware and the CSRF layer run *inside* the span. Putting it in DatasetteRouter instead would leave a span created by an instrumented plugin as an orphan root - reintroducing the problem for exactly the code most likely to be instrumented. It stays at ~90 lines, against roughly 700 for opentelemetry-instrumentation-asgi, because Datasette's app does not return before its body is sent: route_path awaits response.asgi_send(send), and a streaming CSV export runs its generator inline inside AsgiStream.asgi_send. So a plain `finally` covers the response body and no deferred-end machinery is needed. Two decisions worth flagging for review: - Inbound W3C traceparent and baggage are extracted, using the *global* propagator. That is the ecosystem norm (Flask, Django, FastAPI, the ASGI instrumentation), and going through the global propagator leaves the operator in control with no Datasette setting to invent: OTEL_PROPAGATORS=none disables it entirely. A public instance that does not want client-influenced traces should strip those headers at the proxy. - url.query is not recorded, anywhere. Datasette query strings carry user-supplied SQL in ?sql= and canned query parameters. client.address is not recorded either. The status code is sniffed from the ASGI http.response.start message rather than read off a Response, because asgi_static, the favicon route, AsgiStream and AsgiFileDownload all send that message themselves and never build one. Only a >= 500 sets an error status - per semantic conventions a 4xx is the client's mistake, and Datasette 404s are routine enough that treating them as errors would bury a real 500. The registry gains a `dynamic` flag, because this span's name is composed at runtime and so can never equal a fixed registry string. Dynamic entries resolve by span kind instead, and only after exact and prefix matching has failed, so they cannot shadow a span that does have a registered name. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
The request span was created at the ASGI edge, before anything knew which
route would match, so it carried nothing but the method: every request in a
trace UI showed up as "GET", and the only URL on it was url.path, which is
unbounded on a public instance and useless as a grouping key. Routing
resolves in DatasetteRouter, so that is where the span gets http.route and
its semconv `{method} {route}` name.
http.route is the compiled route pattern, not a prettified
/{database}/{table} template. Datasette routes with compiled regexes and the
route table is fixed when the app is built, so the pattern is exact, bounded
and needs no parsing; the transform into something prettier accretes edge
cases, and Django's instrumentation ships regex-flavoured routes for the same
reason. A request that matches no route gets no http.route and keeps its bare
method name, which is what semantic conventions ask for.
Two things the obvious implementation gets wrong, both found by testing it:
- The router must not read `get_current_span()`. A plugin asgi_wrapper()
runs *inside* the request middleware, so an instrumented plugin makes its
own span current for the whole request - and the route then lands on that
plugin's INTERNAL span, renaming it, while the actual request span never
gets the one attribute a trace UI groups by. It reproduces with a five-line
plugin. The span is passed through the ASGI scope instead, falling back to
the current span so an externally-created SERVER span is still enriched.
- The method has to be clamped again here. The middleware clamps it for the
attribute, but the name is rebuilt from request.method, which is the raw
client string - so an unclamped rename put `FROB /(?P<database>...` back
into the span name that the middleware had just kept it out of.
Both guards are `is_recording()`, not `get_span_context().is_valid`: with no
provider but an inbound traceparent the API returns a NonRecordingSpan
carrying the remote context, which is valid and records nothing, so an
is_valid guard would do the work on every request from a traced caller.
Tests cover the route and name, the unrouted 404 fallback, the full attribute
set, db.query spans reaching the request span by parent walk, a 500, an
inbound traceparent becoming a remote parent, ?sql= never reaching a span
attribute, and - in a subprocess, because the suite's provider fixture is
session-scoped and unavoidable - the no-provider fast path handing the app
the original `send`. The streaming test uses a table larger than one page so
the export genuinely issues queries during the body send; without that it
passes however early the span ends.
Measured on this branch against fixtures.db: a faceted table page went from
112 spans in 56 traces to 113 spans in 1.
Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Follow-up to #2862. Adds a single
SERVERspan per HTTP request, so the database spans from thatPR have a trace to belong to.
Why this is needed
Without it, nothing in Datasette creates a span for the request, so every span is a root span and
a trace UI shows dozens of unrelated single-span traces per page with no URL on any of them —
interleaved across concurrent requests.
Measured on this branch against
fixtures.db, one warm request each (the first request of a processalso pays connection warm-up, so these are the second):
/fixtures/facetable?_facet=state&_facet=_city_id&_facet=on_earth/fixtures/facetable/1/fixtures/searchable.jsonEvery one of those "traces" without the PR is a two-span
db.query/db.query.executepair with noURL, no status and no method on it, arriving interleaved with every other concurrent request.
opentelemetry-instrumentdoes not fix this on its own. Auto-instrumentation only picks upframeworks that ship an instrumentor entry point, and Datasette's raw ASGI app is not one. So the
alternative to this PR is telling every operator to install
opentelemetry-instrumentation-asgiandwrite a three-line
asgi_wrapperplugin, which is a poor default.Here is
/fixtures/searchable.jsonin full, before and after. Same request, same spans; the onlydifference is whether they have a parent.
Before - four unrelated root traces:
After - one trace, rooted in a span that says what was requested and how it ended:
Design
The middleware is applied outermost in
Datasette.app(), after theasgi_wrapperplugin loop,so plugin middleware runs inside the span rather than outside it. Putting it in
DatasetteRouter.__call__instead would leave CSRF and every plugin middleware outside the span,which reintroduces the orphan problem for instrumented plugins.
Only
scope["type"] == "http"is wrapped; lifespan and websocket scopes pass straight through.Everything needed is in
opentelemetry-api—opentelemetry.propagate.extract,Getter,SpanKind.SERVER. No new dependency, and core still never owns a provider.Streaming works with a plain
finally, which is why this is ~130 lines rather than the ~700 thatopentelemetry-instrumentation-asgineeds. Datasette's app never returns before the body is sent:route_pathawaitsresponse.asgi_send(send), and for CSVAsgiStream.asgi_sendrunsstream_fninline. So no deferred-end machinery is required. Verified against
?_stream=1exports, wherenearly all the time is in the body send.
Status code comes from sniffing
http.response.start, not fromResponseobjects — views bypassResponsefreely (asgi_static,favicon,AsgiStream,AsgiFileDownloadall callsenddirectly), and a wrapped
sendis the only thing that sees every response including 404 and 500handlers.
Errors are driven by
status_code >= 500, since semconv says 4xx is not an error for a SERVER span.asyncio.CancelledErroron client disconnect is caught explicitly — it's aBaseException, soroute_path'sexcept Exceptiondeliberately doesn't see it.Attributes
http.request.method(clamped to the known set, else_OTHER),http.route,http.response.status_code,url.path,url.scheme,server.address,user_agent.original,error.type. Span name is{method} {route}, falling back to bare{method}for unrouted requests.http.routeis the compiled route pattern, e.g./(?P<database>[^\/\.]+)/(?P<table>[^\/\.]+)(\.(?P<format>\w+))?$. Ugly, but exact, bounded by theroute table and zero-parse. I deliberately did not write a regex→
/{database}/{table}prettifier —that transform accretes edge cases, and Django's instrumentation ships regex-flavoured routes too.
Happy to add one if you'd prefer prettier output.
Since routing happens in
DatasetteRouterbut the span starts at the edge,http.routeis set andthe span renamed from the router, after
resolve_routes.The router finds that span through the ASGI scope, not through
get_current_span(). That is acorrection I made while writing the tests: a plugin
asgi_wrapperruns inside this middleware, soan instrumented plugin makes its own span current for the whole request. Reading the current span in
the router therefore renamed the plugin's INTERNAL span to
GET <route>and hunghttp.routeoffit, while the actual request span kept a bare method name and never got the one attribute a trace UI
groups requests by. It reproduces with a five-line plugin. Going through the scope also keeps the
fallback: if no Datasette span is in the scope the router falls back to the current span, which is
how an externally-created SERVER span still gets enriched.
Deliberately not recorded:
url.query— Datasette query strings carry user SQL (?sql=) and canned-query parameters.Recording it by default would export exactly the class of data the rest of this work is careful
about.
client.address— an IP is borderline PII.The security question, stated plainly
This extracts W3C
traceparentfrom inbound request headers by default, which means on a publicinstance an arbitrary client can influence your traces:
parentbased_always_on, so under aparent-based ratio sampler a client's sampled flag can force 100% recording (a telemetry-cost
DoS) or suppress recording.
I've gone with extract-by-default because it's the ecosystem norm — Flask, Django, FastAPI and the
ASGI instrumentation all extract unconditionally, and edges that care strip or restart traces at the
proxy. Crucially it uses the global propagator, so the operator stays in control with no
Datasette-specific setting:
OTEL_PROPAGATORS=nonedisables extraction entirely,OTEL_PROPAGATORS=tracecontextdrops baggage, and a non-parent-based sampler neutralises (2).That's consistent with core never touching sampling or configuration. But it is a genuine decision
rather than an obvious one, and if you'd rather Datasette not trust inbound trace context by
default I'm happy to invert it.
Interactions
datasette.startupnests differently depending on how you run it.datasette servecallsinvoke_startup()before uvicorn starts, so the startup span stays its own trace. ASGI-hosted andprogrammatic deployments hit
AsgiRunOnFirstRequestcold, so startup nests under the firstrequest's span. That's benign and arguably more honest — it genuinely is that request's latency.
Double instrumentation is harmless. If an operator also installs
opentelemetry-instrumentation-asgi, its middleware lands inside this one and becomes a redundantchild SERVER span in the same trace. Nothing is re-orphaned. I haven't added an opt-out —
OTEL_SDK_DISABLEDand the no-provider default already cover "turn it off".No-provider cost is near zero. With no provider every span is a
NonRecordingSpan, themiddleware short-circuits on
span.is_recording(), and thesendwrapper is never allocated.Measured over 300 requests to
/fixtures/searchable.jsonin a process with no SDK loaded,interleaved in blocks to cancel out drift:
The median difference across four repeats of that benchmark was -11.4us, -4.8us, -2.8us and +2.3us -
it changes sign between runs, so it is smaller than the noise floor rather than merely small.
(The check has to be
is_recording(), notget_span_context().is_valid. With no provider and aninbound
traceparent, the API'sNoOpTracerreturns aNonRecordingSpancarrying the remotecontext: valid, sampled, and recording nothing. An
is_validguard would take the slow path forevery request arriving from an instrumented caller.)
How to test this
Known limitations
http.routeis a regex pattern, not a pretty template.Stack created with GitHub Stacks CLI • Give Feedback 💬