Tracing SQLAlchemy Async Queries with OpenTelemetry
An asyncio service that instruments create_async_engine the obvious way gets no database spans at all — the call succeeds, no error is raised, and the traces simply have a hole where every query should be. This page is for backend engineers and SREs running SQLAlchemy 2.x on asyncpg or aiomysql who need query spans nested correctly under their request spans. It sits within the async tracing patterns guide, part of Distributed Tracing and OpenTelemetry in Python, and it shows the exact SQLAlchemyInstrumentor configuration that produces correct spans without inflating statement cardinality.
The async engine in SQLAlchemy is a thin coroutine-aware facade over a conventional synchronous Engine. OpenTelemetry's instrumentation listens to the Core execution events on that inner engine, so you reach it through the engine.sync_engine attribute. Once attached, every executed statement opens a span carrying the operation, the table, and optionally the SQL text, while enable_commenter writes the active trace context back into the database's own query log for correlation that survives the process boundary.
Prerequisites
Pin the instrumentation against a working SDK installation and an async driver such as asyncpg. The instrumentation packages track the unstable instrumentation channel, so a bounded range keeps builds reproducible.
pip install "opentelemetry-sdk>=1.30.0,<2.0.0" \
"opentelemetry-instrumentation-sqlalchemy>=0.51b0,<1.0.0" \
"opentelemetry-exporter-otlp-proto-grpc>=1.30.0,<2.0.0" \
"sqlalchemy>=2.0.0,<3.0.0" \
"asyncpg>=0.29.0,<0.31.0"
Set the exporter endpoint and a service name so the database spans land under the right service in your backend. OTEL_SERVICE_NAME becomes the service.name resource attribute that groups these client spans with the request spans they belong to.
export OTEL_EXPORTER_OTLP_ENDPOINT="http://localhost:4317"
export OTEL_SERVICE_NAME="orders-api"
Implementation
Step 1 — install the tracer provider before any engine exists. Configure the TracerProvider and a BatchSpanProcessor at import time. Instrumentation resolves its tracer at patch time, so a provider installed after the engine is created leaves the listeners bound to a NoOpTracer and database spans silently disappear. This mirrors the SDK bootstrap described in setting up OpenTelemetry in FastAPI.
import os
from opentelemetry import trace
from opentelemetry.sdk.trace import TracerProvider
from opentelemetry.sdk.trace.export import BatchSpanProcessor
from opentelemetry.exporter.otlp.proto.grpc.trace_exporter import OTLPSpanExporter
# 1. Provider first, so the instrumentation binds to a real tracer.
provider = TracerProvider()
provider.add_span_processor(
BatchSpanProcessor(
OTLPSpanExporter(endpoint=os.getenv("OTEL_EXPORTER_OTLP_ENDPOINT"))
)
)
trace.set_tracer_provider(provider)
Step 2 — build the async engine and instrument its synchronous counterpart. The create_async_engine call returns an AsyncEngine; its sync_engine attribute is the object SQLAlchemyInstrumentor knows how to patch. Pass it explicitly rather than relying on a bare instrument() call, so the binding is scoped to the engine you mean.
from sqlalchemy.ext.asyncio import create_async_engine
from opentelemetry.instrumentation.sqlalchemy import SQLAlchemyInstrumentor
# 2. Build the async engine.
engine = create_async_engine(
"postgresql+asyncpg://app:secret@localhost/orders",
pool_size=10,
max_overflow=5,
)
# 3. Instrument the underlying synchronous engine, not the async facade.
SQLAlchemyInstrumentor().instrument(
engine=engine.sync_engine, # the layer where Core events fire
enable_commenter=True, # append trace context to SQL
commenter_options={"db_driver": True, "opentelemetry_values": True},
)
Step 3 — run queries through the normal async session API. Each execute now opens a child span under whatever span is active in the current asyncio context, so a query issued inside a request handler nests beneath the request span with no manual propagation.
import asyncio
from sqlalchemy import text
from sqlalchemy.ext.asyncio import AsyncSession
async def fetch_order(order_id: int) -> dict | None:
async with AsyncSession(engine) as session:
# Bound parameter keeps the captured statement parameterized.
result = await session.execute(
text("SELECT id, status FROM orders WHERE id = :oid"),
{"oid": order_id},
)
row = result.first()
return dict(row._mapping) if row else None
asyncio.run(fetch_order(42))
Step 4 — confirm the trace context reaches the database. With enable_commenter active, the statement that arrives at PostgreSQL carries the active context as a trailing comment, letting you pivot from a slow query in the database log straight to its span.
Expected Output: the SQL recorded by the database (for example in pg_stat_statements or the query log) includes the appended commenter block.
SELECT id, status FROM orders WHERE id = $1
/*db_driver='asyncpg',traceparent='00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01'*/
Why the async engine delegates to sync_engine
create_async_engine does not implement its own SQL execution. It builds a normal synchronous Engine configured with an async-capable DBAPI shim (the asyncpg or aiomysql adapter), then wraps it in an AsyncEngine facade. Every await session.execute(...) ultimately drives that inner engine through a greenlet bridge: SQLAlchemy runs the synchronous Core machinery inside a greenlet and yields back to the event loop whenever the driver would block on the socket. The Core execution events — before_cursor_execute and after_cursor_execute, which the instrumentation subscribes to — fire on the inner synchronous engine inside that greenlet. That is the entire reason you instrument engine.sync_engine: it is the only object that actually emits the events, even though your code only ever touches the async facade. Passing the AsyncEngine to instrument(engine=...) registers listeners on an object that never fires them, which is why it silently produces no spans.
The span the instrumentation opens is created from the same contextvars-based active context your coroutine runs under, so a query issued inside a request handler's span nests beneath it automatically. The greenlet bridge preserves that context across the yield — the same mechanism that makes context propagation and baggage work across await boundaries — so the span the database events open is a child of whatever was active at the call site.
Connection-pool behaviour in the span timeline
The query span wraps the cursor execution, but acquiring a pooled connection happens before execution begins, so checkout latency is not inside the query span by default. Under pool exhaustion — more concurrent execute calls than pool_size + max_overflow — a coroutine waits up to pool_timeout for a free connection, and that wait shows up as a gap in the trace between the parent span and its first child query span rather than as inflated query duration. If you see request spans whose database children start late but run fast, the pool, not the database, is the constraint; raise pool_size or shorten the time connections are held. For visibility into checkout itself, open a thin application span around engine.connect() so the wait becomes a measurable span rather than dead time.
async def fetch_order_measured(order_id: int) -> dict | None:
tracer = trace.get_tracer(__name__)
# Wrap checkout so pool wait becomes a span instead of a gap.
with tracer.start_as_current_span("db.checkout"):
conn = await engine.connect()
async with conn:
result = await conn.execute(
text("SELECT id, status FROM orders WHERE id = :oid"),
{"oid": order_id},
)
row = result.first()
return dict(row._mapping) if row else None
Expected Output: the checkout wait is now attributed rather than invisible.
GET /orders/42 duration=214ms
db.checkout duration=198ms <- pool exhausted, not the database
SELECT orders duration=11ms
A second pool subtlety: pool_pre_ping issues a lightweight liveness check before handing out a connection. With instrumentation active that ping is itself a traced statement, so you may see small extra spans (a SELECT 1 or a driver-specific ping) interleaved with your real queries. They are expected; filter them at query time rather than disabling pre-ping, which guards against stale connections after a database failover.
What enable_commenter writes, precisely
enable_commenter=True turns on SQLCommenter, which appends a structured, URL-encoded key-value comment to the end of each statement just before execution. The keys are controlled by commenter_options: db_driver adds the driver name and version, opentelemetry_values adds the W3C traceparent (and tracestate when present) drawn from the active span. The comment is appended to the statement text but is not part of the bound-parameter set, so it does not affect the query plan or the result.
Two consequences follow. First, the appended comment changes the literal SQL string, which means tools that fingerprint queries by exact text — some query-cache or normalization layers — see each statement as unique unless they strip comments; pg_stat_statements ignores comments by default, but verify any prepared-statement caching or proxy in front of the database tolerates it. Second, set enable_attribute_commenter=True only when you want the fully commented statement mirrored onto the span's db.statement attribute; leaving it off keeps db.statement clean and parameterized while the database log still carries the correlation comment. That commented statement is also the bridge to your log pipeline: a database slow-query line and an application log line enriched by adding trace ids to log records then share one trace id, so a single search reaches both.
Configuration options
SQLAlchemyInstrumentor().instrument accepts the following arguments, of which these are the ones that matter for async engines.
| Option | Type | Default | Production use |
|---|---|---|---|
engine |
Engine |
none (global patch) | Pass async_engine.sync_engine — the layer where Core execution events fire. |
enable_commenter |
bool |
False |
Append a SQL comment carrying trace context so database-side logs correlate to spans. |
commenter_options |
dict |
all keys on | Select which fields appear, e.g. db_driver, opentelemetry_values, db_framework. |
enable_attribute_commenter |
bool |
False |
Mirror the commented statement onto db.statement; leave off to keep the attribute clean. |
tracer_provider |
TracerProvider |
global provider | Point these spans at a dedicated provider, mainly useful in tests. |
You can omit engine and call instrument() to patch every engine class-wide, but per-engine instrumentation is the supported, predictable path for asyncio services that build engines lazily — and it is the only way to trace a read replica and a primary with different settings in the same process. Call it once per engine, each time with that engine's own sync_engine.
Verification
Add a ConsoleSpanExporter during local development to confirm spans are emitted. A correctly instrumented query produces a CLIENT span whose name is the operation plus table and whose attributes include db.system and a parameterized db.statement.
{
"name": "SELECT orders",
"kind": "SpanKind.CLIENT",
"attributes": {
"db.system": "postgresql",
"db.name": "orders",
"db.statement": "SELECT id, status FROM orders WHERE id = $1"
},
"parent_id": "00f067aa0ba902b7"
}
A non-null parent_id confirms the query span nested under the active request span, and a parameterized db.statement confirms cardinality is controlled. If parent_id is null, the query ran outside any active span context; if db.statement contains literal values, switch the offending call to bound parameters. For a check that needs no collector, assert the same two properties against an InMemorySpanExporter in a test that runs one query under a manually opened parent span.
Detecting N+1 queries from spans
The most valuable thing async query spans reveal is the N+1 pattern: a request that issues one parent query, then fires a separate follow-up query per returned row instead of joining or batching. Because every execute opens a sibling span under the request, an N+1 renders as a long, flat run of near-identical query spans whose db.statement differs only in a bound parameter. A lazy relationship access on an ORM result inside an async for loop is the usual culprit — and in async code it is doubly expensive, since each round trip re-enters the greenlet bridge and pays another network hop.
[
{"name": "SELECT orders", "db.statement": "SELECT id, customer_id FROM orders LIMIT 50", "parent_id": "req"},
{"name": "SELECT customers", "db.statement": "SELECT name FROM customers WHERE id = $1", "parent_id": "req"},
{"name": "SELECT customers", "db.statement": "SELECT name FROM customers WHERE id = $1", "parent_id": "req"},
{"name": "SELECT customers", "db.statement": "SELECT name FROM customers WHERE id = $1", "parent_id": "req"}
]
Fifty repeated SELECT customers spans under one request is the signature. The remedy is a single batched query (WHERE id = ANY(:ids)) or an eager-loading strategy such as selectinload, which collapses the fan-out into one or two spans. Counting siblings by db.statement in a backend query turns this into an alert rather than a manual hunt — the same span-aggregation thinking applied when managing span attributes for queryability. On a busy service, keep the fan-out visible under sampling by choosing a policy that does not throw away the slow outliers; see sampling strategies for distributed tracing.
Common mistakes
-
Error signature: the exporter emits request spans but no database children, and no error is logged. Root cause: the
AsyncEngineobject was passed toinstrument(engine=...), so listeners were registered on a facade that never fires Core execution events. Remediation: passengine.sync_engine, and assert in a startup check that the object you hand over is asqlalchemy.engine.Engine, not anAsyncEngine. -
Error signature: trace search slows down and the backend reports tens of thousands of distinct span names such as
SELECT orders WHERE id = 4471. Root cause: statements are built with f-strings, folding literal values intodb.statementand therefore into the span name. Remediation: use bound parameters everywhere so the captured statement stays parameterized — the same cardinality discipline described in managing span attributes, and the direct analogue of controlling label cardinality in Prometheus. -
Error signature: database spans look fast and healthy, yet unrelated spans in the same process inflate and tail latency climbs under load. Root cause: a synchronous
create_engineandSessionare mixed into the async service, blocking the event loop for the duration of every query while other coroutines stall behind it. Remediation: usecreate_async_enginewith an async driver throughout and keep blocking database libraries off the loop — the rule that governs all I/O across the async tracing patterns guide, including outbound aiohttp calls. -
Error signature: spans appear with
trace_id 00000000000000000000000000000000, or vanish entirely after a deployment that only reordered imports. Root cause: theTracerProviderwas installed after the engine was created and instrumented, so the listeners captured a no-op tracer. Remediation: fix the order — provider, then engine, theninstrument(engine=engine.sync_engine)— and in pre-fork servers run all three inside the worker rather than at import time in the master process.
Related
- Async tracing patterns — the parent guide covering contextvars, task boundaries, and non-blocking export.
- Instrumenting aiohttp client requests — the HTTP half of the same asyncio request.
- OpenTelemetry SDK setup — provider lifecycle and processor tuning these query spans depend on.
- Span lifecycle and attributes — naming, attribute and cardinality rules for the spans your queries produce.
- Context propagation and baggage — how the active context that parents each query span moves between coroutines and services.
Frequently Asked Questions
Why do I instrument engine.sync_engine instead of the async engine?
SQLAlchemyInstrumentor hooks the synchronous Core execution events that the async engine drives underneath. The async engine wraps a real synchronous engine exposed as the sync_engine attribute, so passing that object lets the instrumentation patch the layer where statements actually run.
Does enable_commenter slow down my queries?
The overhead is a short string concatenation appended to each statement before execution. It is negligible relative to network and query time, but it does change the SQL text, so review it against any prepared-statement caching or query-fingerprinting tooling first.
Why do my database spans have thousands of distinct names?
By default the span name derives from the operation and table, but literal values folded into the statement can explode cardinality. Use bound parameters rather than f-string interpolation so the captured db.statement stays parameterized and the span names stay stable.
Can one SQLAlchemyInstrumentor call cover multiple engines?
Call instrument once per engine you want traced, passing each engine's sync_engine. A global instrument() call patches the Engine class broadly, but per-engine instrumentation is the supported path for async engines.
How do I spot an N+1 query problem from the traces?
Look for a parent span that contains a long run of sibling query spans with near-identical db.statement values differing only in a bound parameter. A request that fires one SELECT per row of a prior result, rather than a single joined or batched query, is the classic N+1 pattern, and the span fan-out under the request makes it obvious in the trace timeline.