Posted inDatabase

Database Observability: Connecting SQL Queries to Application Traces with OpenTelemetry

Database tutorial - IT technology blog
Database tutorial - IT technology blog

When Slow Logs Aren’t Enough

I’ve lost count of the nights I’ve spent squinting at PostgreSQL slow query logs, trying to guess which specific function triggered a rogue SELECT statement. In a simple monolith, you can usually guess based on the table name. But in a microservices environment with 50+ services and hundreds of endpoints, that guesswork fails. You might see a query dragging for 4.8 seconds, but you won’t know if it was sparked by a critical ‘Checkout’ request or a non-essential background ‘Analytics’ job.

Having managed MySQL, PostgreSQL, and MongoDB at scale, I’ve noticed they all share a frustrating limitation: the database is a black box regarding application context. Standard logs tell you what executed and how long it took. They rarely tell you who started it or why it happened.

Database observability changes this. By pairing OpenTelemetry (OTel) for distributed tracing with SQLCommenter for metadata injection, we can finally stitch application-level traces directly into the SQL queries hitting your server.

The Solution: SQLCommenter and Trace Context

Traditional monitoring focuses on infrastructure metrics like CPU spikes or memory pressure. Observability is different; it’s about context. OpenTelemetry tracks a request as it hops across services. Usually, that visibility dies the moment the request hits the database driver. The database engine has no concept of the trace_id living in your Python or Go backend.

SQLCommenter is an open-source library that fixes this by augmenting SQL statements with comments. These comments pack metadata like the controller name, the route, and the OpenTelemetry trace context. For example, a standard query looks like this:

SELECT * FROM users WHERE id = 10;

With SQLCommenter, it transforms into:

SELECT * FROM users WHERE id = 10 /* traceparent='00-84b54...-01', action='get_user', service='identity-provider' */;

Database engines ignore these comments during execution, but they still record them in logs like PostgreSQL’s log_statement. This allows you to grab a slow query from a log file and immediately find its matching trace in your dashboard.

Setting Up the Toolkit

For this example, we’ll use a Python stack with SQLAlchemy and FastAPI. This is a common environment where N+1 query problems and performance bottlenecks tend to hide. You’ll need the OpenTelemetry SDK and the SQLCommenter integration for your ORM.

1. Install OpenTelemetry Dependencies

Start by installing the core OTel packages along with the instrumentation for your web framework and database driver:

bash
pip install opentelemetry-api \
            opentelemetry-sdk \
            opentelemetry-instrumentation-fastapi \
            opentelemetry-instrumentation-sqlalchemy \
            opentelemetry-exporter-otlp

2. Install SQLCommenter

Google provides SQLCommenter plugins for various languages. For Python and SQLAlchemy, run:

bash
pip install google-cloud-sqlcommenter

Wiring the Integration

The integration clicks into place when you configure the SQLAlchemy engine to use the SQLCommenter execution wrapper. This ensures every query generated by the ORM carries the necessary trace metadata.

Initializing the Tracer

I prefer wrapping the OTel setup in a helper function. It ensures the tracer is active before the application begins processing traffic.

python
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

def setup_otel(service_name):
    provider = TracerProvider()
    processor = BatchSpanProcessor(OTLPSpanExporter(endpoint="http://localhost:4317"))
    provider.add_span_processor(processor)
    trace.set_tracer_provider(provider)

setup_otel("order-service")

Instrumenting SQLAlchemy

Now, we tell SQLAlchemy to attach comments to queries. Using the SQLCommenter plugin is the cleanest approach. It avoids the need to manually modify every query in your codebase.

python
from sqlalchemy import create_engine
from opentelemetry.instrumentation.sqlalchemy import SQLAlchemyInstrumentor
from google.cloud.sqlcommenter.sqlalchemy.executor import BeforeExecuteFactory

DATABASE_URL = "postgresql://user:password@localhost/dbname"
engine = create_engine(DATABASE_URL)

# Standard OTel instrumentation
SQLAlchemyInstrumentor().instrument(engine=engine)

# Attach SQLCommenter metadata via event listeners
from sqlalchemy import event

@event.listens_for(engine, "before_cursor_execute", retval=True)
def add_sql_comment(conn, cursor, statement, parameters, context, executemany):
    # SQLCommenter logic appends /* key='value' */ to the statement
    # In a real app, use the library's built-in factory for cleaner code
    return statement, parameters

In modern versions of these libraries, you can often use middleware to capture the route name automatically. For FastAPI, this ensures that every SQL query knows exactly which API endpoint triggered it.

Verification: Closing the Loop

Once you deploy this, verify that data is flowing into two separate streams: your Tracing Backend (like Jaeger or Honeycomb) and your Database Logs.

1. Inspecting Database Logs

Check your PostgreSQL or MySQL configuration. Ensure query logging is active. In PostgreSQL, setting log_min_duration_statement = 0 will log every query, which is helpful for initial testing.

bash
# Watch the Postgres logs in real-time
tail -f /var/log/postgresql/postgresql-15-main.log

You should see entries that look like this:

LOG:  duration: 15.210 ms  statement: SELECT * FROM orders WHERE status = 'pending' 
/* action='list_orders', traceparent='00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01' */

2. Correlating in Jaeger

When you spot a slow query in your logs, copy the traceparent ID. Paste that ID into your Jaeger search bar. You will immediately see the full lifecycle of that specific request. You’ll see which user hit the endpoint, which service called the database, and exactly how many milliseconds were spent on that SQL execution.

This is particularly effective for catching “N+1” issues. If you see 100 small queries in Jaeger, the SQL comments in your database logs will confirm they all originated from the same loop in your code.

Production Considerations

This setup is powerful, but you should deploy it thoughtfully to avoid performance or storage overhead:

  • Log Volume: Adding comments to every query increases log size. For high-traffic apps, consider logging only queries that exceed a specific threshold, such as 100ms.
  • Security: Never include PII (Personally Identifiable Information) in SQL comments. Stick to IDs, route names, and trace contexts.
  • Sampling: Use OpenTelemetry sampling. You don’t need to trace 100% of requests to find meaningful patterns. A 5% sample rate is often enough to identify the biggest bottlenecks.

Granular observability removes the guesswork from database tuning. Instead of a vague feeling that “the database is slow,” you can pinpoint the exact line of code causing the lag. It shifts the dynamic between DevOps and Developers from finger-pointing to solving the actual problem.

Share:
Tags: