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.

SQLAlchemy async instrumentation flow An await call passes through the async engine to its inner sync_engine, where SQLAlchemyInstrumentor opens a span and the SQL commenter appends trace context before the statement reaches the database. await session.execute AsyncEngine facade sync_engine span opened + SQL comment Database traceparent log Where the span is created
The query span is created at the inner sync_engine, which is why instrumentation targets engine.sync_engine.

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.

Cutaway of an await session.execute call Three nested layers. The outermost AsyncEngine facade is where instrument(engine=async_engine) attaches listeners that never fire, so no spans are emitted. Inside it the greenlet bridge runs the synchronous Core code and yields to the asyncio event loop while the socket waits. The innermost sync_engine fires before_cursor_execute and after_cursor_execute, which bracket the CLIENT span for the statement, so instrument(engine=engine.sync_engine) is the call that produces spans. one await session.execute(...), cut away no spans emitted AsyncEngine — the async facade instrument(engine=async_engine) binds listeners, nothing ever fires them greenlet bridge runs sync Core code; yields to the loop on I/O events fire sync_engine — Engine before_cursor_execute CLIENT span: SELECT orders after_cursor_execute instrument(engine=engine.sync_engine) asyncio event loop other coroutines run while the socket waits yield resume the active context survives the yield, so the span nests
Listeners on the outer facade are never called; the events that bracket the query span fire on the inner engine, inside the greenlet.

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.

Pool exhaustion appears as a gap in the trace Fifteen pool slots, the sum of pool_size ten and max_overflow five, are all checked out, so further coroutines queue and each blocks for up to pool_timeout. In the trace this is a 214 millisecond GET /orders span whose first child does not start for 198 milliseconds; the query itself then runs in 11 milliseconds. The wait is dead time between the parent span and its first child rather than inflated query duration, until a db.checkout span is opened around engine.connect to measure it. pool exhaustion reads as a gap, not as a slow query pool_size=10 + max_overflow=5 — all 15 checked out 10 pooled + 5 overflow, none free queued coroutines each blocks up to pool_timeout what the trace shows GET /orders 214ms connection wait SELECT orders 11ms 198 ms before the first child span starts Wrap engine.connect() in a db.checkout span and that dead time becomes a measurable child.
The database is fast; the request is slow. Checkout latency lives in the gap ahead of the first query span.
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.

Anatomy of a statement commented by SQLCommenter The executed SQL keeps its bound parameter placeholder untouched. Below it, the appended comment is broken into fields: db_driver equals asyncpg, added by commenter_options from the DBAPI driver; then traceparent, whose four dash-separated fields are the version 00, the trace id copied from the active span, the span id of the span active when the statement ran, and the sampled flag 01. The comment is appended to the statement text only, never to the bound parameters. what enable_commenter appends the statement — parameters still bound, db.statement stays clean SELECT id, status FROM orders WHERE id = $1 version sampled /* db_driver='asyncpg' , traceparent=' 00 - 4bf92f35…4736 - 00f067aa0ba902b7 - 01 '*/ db_driver driver name and version, added by commenter_options trace id taken from the active span — identical to the request's trace 01 = sampled unsampled writes 00 span id the span that was active when the statement ran Appended to the statement text only — never to the bound parameters, so the plan and the result are unchanged.
SQLCommenter appends key-value fields: the driver from commenter_options, the rest lifted from the active span context.

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"}
]
N+1 fan-out in the trace timeline, before and after selectinload Top waterfall: a GET /orders request span spans the whole timeline, with a short SELECT orders child followed by a descending staircase of fifty short, identical SELECT customers sibling spans, each one a separate round trip. Bottom waterfall: after switching to selectinload, the same request finishes in a fraction of the time and contains just two query spans, a SELECT orders and a single batched SELECT customers WHERE id = ANY of the ids. N+1: one query per row fifty sibling spans, one per returned row time → GET /orders SELECT orders SELECT customers × 50 siblings … 50 total each await is another round trip through the greenlet bridge selectinload: two spans GET /orders SELECT orders SELECT customers WHERE id = ANY(:ids) — one round trip
The N+1 signature is the staircase: identical sibling spans differing only in a bound parameter. Eager loading collapses it to two.

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 AsyncEngine object was passed to instrument(engine=...), so listeners were registered on a facade that never fires Core execution events. Remediation: pass engine.sync_engine, and assert in a startup check that the object you hand over is a sqlalchemy.engine.Engine, not an AsyncEngine.

  • 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 into db.statement and 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_engine and Session are mixed into the async service, blocking the event loop for the duration of every query while other coroutines stall behind it. Remediation: use create_async_engine with 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: the TracerProvider was installed after the engine was created and instrumented, so the listeners captured a no-op tracer. Remediation: fix the order — provider, then engine, then instrument(engine=engine.sync_engine) — and in pre-fork servers run all three inside the worker rather than at import time in the master process.

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.