Adding OpenTelemetry tracing to async SQLAlchemy

Start a CLIENT span in before_cursor_execute, stash it on conn.info, and end it in after_cursor_execute and handle_error — the greenlet bridge copies the context, so the span is correctly parented to whatever request span was active when the query was issued. This is the tracing instrument from instrumenting and observing async queries.

Quick Answer

Before — a trace that stops at the handler:

# The request span exists; the queries inside it are invisible, so a slow
# endpoint shows as one long span with no explanation.

After — one span per statement:

from __future__ import annotations

from opentelemetry import trace
from opentelemetry.trace import SpanKind, Status, StatusCode
from sqlalchemy import event
from sqlalchemy.ext.asyncio import AsyncEngine

tracer = trace.get_tracer("sqlalchemy")


def install_tracing(async_engine: AsyncEngine, db_name: str) -> None:
    engine = async_engine.sync_engine

    @event.listens_for(engine, "before_cursor_execute")
    def _start(conn, cursor, statement, parameters, context, executemany):
        span = tracer.start_span(
            _operation_name(statement),
            kind=SpanKind.CLIENT,
            attributes={
                "db.system": "postgresql",
                "db.name": db_name,
                "db.statement": " ".join(statement.split())[:1000],
                "db.sqlalchemy.executemany": bool(executemany),
            },
        )
        conn.info["otel_span"] = span

    @event.listens_for(engine, "after_cursor_execute")
    def _end(conn, cursor, statement, parameters, context, executemany):
        span = conn.info.pop("otel_span", None)
        if span is None:
            return
        if cursor.rowcount is not None and cursor.rowcount >= 0:
            span.set_attribute("db.row_count", cursor.rowcount)
        span.end()

    @event.listens_for(engine, "handle_error")
    def _failed(context):
        conn = context.connection
        span = conn.info.pop("otel_span", None) if conn is not None else None
        if span is None:
            return
        span.record_exception(context.original_exception)
        span.set_status(Status(StatusCode.ERROR))
        span.end()

The handle_error listener is what stops a failing statement from leaving its span open forever — without it, the trace shows a query that never completed rather than one that failed.

Execution Context & Async Workflow Integration

The question people expect to be hard — does the span end up under the right parent when the ORM runs inside a greenlet? — turns out to be handled for you. greenlet_spawn copies the current contextvars context into the greenlet, and OpenTelemetry's context is a ContextVar, so the active span inside the listener is the same one that was active in the awaiting coroutine.

What that means practically is that no manual context plumbing is needed, and attempts to add some usually make things worse:

# Wrong — carrying the context by hand, which double-parents or detaches the span
from opentelemetry import context as otel_context

def _start(conn, cursor, statement, parameters, context_, executemany):
    ctx = otel_context.get_current()        # already correct; capturing it is redundant
    token = otel_context.attach(ctx)        # and attaching it here leaks the token
    ...

# Right — let the copied context do its job
def _start(conn, cursor, statement, parameters, context_, executemany):
    span = tracer.start_span(_operation_name(statement), kind=SpanKind.CLIENT)
    conn.info["otel_span"] = span

The one place manual propagation is needed is a background task, because a task created inside a request captures the context at creation time and then outlives the request span. A query issued by that task is parented to a span that has already ended, which most backends render as an orphan. Starting a fresh root span at the top of the background task, and linking it to the originating trace, gives a trace that reflects what actually happened:

async def send_receipt(order_id: int) -> None:
    link = trace.Link(trace.get_current_span().get_span_context())
    with tracer.start_as_current_span("send_receipt", links=[link]):
        async with Session() as session:
            ...

The same lifetime rule appears from a different angle in using expire_on_commit=False in FastAPI dependencies: a background task started inside a request outlives everything the request owned, spans included.

Resolving Warnings, Errors & Common Mistakes

Advanced: Sampling, Noise and Span Naming

Tracing every statement in a busy service produces a volume nobody wants to pay for, and most of it is uninteresting. Three refinements make the trace both cheaper and more readable.

Sample at the request level, not the statement level. If the request span is sampled, its database children should be too — otherwise a sampled trace has gaps where queries should be, which is worse than not sampling. OpenTelemetry's ParentBased sampler does this by default; the mistake is configuring a separate sampler for the database instrumentation.

Skip the statements that carry no information. Pool pre-ping issues SELECT 1 on every checkout, and at a thousand requests per second that is a thousand spans per second saying nothing:

_UNINTERESTING = {"SELECT 1", "COMMIT", "ROLLBACK", "BEGIN"}


def _start(conn, cursor, statement, parameters, context, executemany):
    normalised = " ".join(statement.split())
    if normalised.upper() in _UNINTERESTING:
        return                              # no span, no stash, nothing to end
    ...

Note that skipping means storing nothing on conn.info, so the after hook's pop(..., None) finds nothing and returns — the two stay consistent without a flag.

Derive the name from the shape, not the text.

import re

_LEADING = re.compile(r"^\s*(?:/\*.*?\*/\s*)?(\w+)", re.S)


def _operation_name(statement: str) -> str:
    """A stable, low-cardinality operation name: the verb and the table."""
    match = _LEADING.match(statement)
    verb = match.group(1).upper() if match else "SQL"
    upper = statement.upper()
    table = ""
    if verb in {"SELECT", "DELETE"} and " FROM " in upper:
        table = statement[upper.index(" FROM ") + 6:].split()[0]
    elif verb == "INSERT" and " INTO " in upper:
        table = statement[upper.index(" INTO ") + 6:].split()[0]
    elif verb == "UPDATE":
        parts = statement.split()
        table = parts[1] if len(parts) > 1 else ""
    return f"{verb} {table.strip(chr(34)).split('.')[-1]}".strip()

That produces SELECT orders, INSERT order_items, UPDATE customers — a set whose size is bounded by the schema rather than by traffic. The regular expression skips a leading SQL comment, which matters because query-tagging middleware often prepends one and it would otherwise become the verb.

Deciding Whether Tracing Is Worth It Yet

Tracing is the most expensive of the four instruments in operational terms — a collector to run, a backend to pay for, sampling to tune — and in a single-service application it answers questions that timing and counting already answer more cheaply.

The point at which it earns its place is when a request crosses a process boundary. Once a slow endpoint might be slow because of its own queries, or because of a downstream service's queries, no amount of per-service instrumentation resolves the ambiguity and a trace does it immediately.

The second point is when the same database is used by several services. A slow query attributed to "the orders database" is not actionable; a trace attributes it to a request, an endpoint and a deploy.

Before that, the honest ordering is: query counting first, because it catches the failure mode that actually degrades applications; slow-query logging second, because it needs no infrastructure; pool metrics third, because they distinguish a leak from a spike; tracing last. Adopting them in that order means each one is earning its keep before the next is added — and it means the tracing configuration, when it arrives, is being tuned by someone who already knows what the database is doing.

When tracing does arrive, the official opentelemetry-instrumentation-sqlalchemy package is a reasonable starting point and handles the sync_engine attachment for you. The hand-written listeners here are worth it when you need attributes it does not emit, want precise control over naming and sampling, or want one hook feeding traces, metrics and logs together rather than three separate instrumentations walking the same events.

Frequently Asked Questions

Related

• Instrumenting and Observing Async Queries — The parent guide: timing, counting, pool metrics and query plans.
• Counting queries per request to catch N+1 regressions — The cheaper instrument to adopt first, and the one that becomes a test.
• Reading EXPLAIN output for a SQLAlchemy query — What to do once a trace has identified which statement is slow.
• Integrating SQLAlchemy async with FastAPI and Starlette — Request lifetimes, and why a background task outlives the span that created it.