How to Turn Slow SQL Queries Into Actionable Reliability Metrics With OpenTelemetry

Every application that talks to a database eventually runs into a “why is this slow” problem. The usual first move is to turn on tracing: instrument the code with OpenTelemetry, watch spans come in, and look for the slowest ones. That gets you data, but data is not the same thing as an answer. A raw list of slow spans tells you which single calls took the longest. It does not tell you which queries are actually costing your system the most time, and it does not tell you which ones just started behaving abnormally.

This tutorial builds a small, fully local lab that closes that gap. You will trace real, honestly slow SQL queries against a 400,000-row SQLite database with OpenTelemetry, then progressively turn those raw traces into three increasingly useful views: a naive “slowest queries” list, a traffic-weighted impact ranking, and an adaptive anomaly detector that catches regressions a fixed threshold would miss. Everything runs on plain Python: no Docker, no Grafana, no hosted observability backend required.

The approach here follows the same reliability-engineering idea laid out in Causely’s CNCF Blog post How to turn slow queries into actionable reliability metrics with OpenTelemetry, which builds its own version of this lab with Docker, Tempo, and Grafana. If you have Docker available, that post is worth reading directly for the full dashboard-based version. This tutorial teaches the same underlying mechanism with nothing but the Python standard library, SQLite, and the OpenTelemetry SDK, so you can follow along on any machine.

What You Will Learn

Before writing any code, it helps to define the vocabulary precisely, since the rest of this tutorial leans on these words constantly:

• Span: OpenTelemetry’s basic unit of work. A span has a name, a start time, an end time, and a set of key/value attributes attached to it. In this lab, one SQL query execution becomes one span.
• Trace: a collection of related spans, typically all the spans produced while handling a single request. This lab mostly looks at individual spans rather than full traces, but the same principles apply either way.
• Attribute: a label on a span, such as db.query.fingerprint = "get_order_by_id". Attributes are what you group and filter by later.
• Metric: a number that changes over time, usually built by aggregating many spans together, for example “how many times did this query run, and what was its average duration.”
• Cardinality: how many distinct label combinations a metric ends up with. Group by something too specific, like a raw SQL string with a literal value baked in, and cardinality explodes. You will reproduce this exact problem in Step 6.
• Baseline and z-score: instead of one hardcoded “alert if duration is greater than X milliseconds” rule, an adaptive baseline compares current behavior to what is normal for that specific query. A z-score expresses that comparison as “how many standard deviations away from normal is this,” which you will compute yourself in Step 8.

What Makes a Query Slow

“Slow” is not one problem with one fix. The CNCF post above groups the causes into five categories, which are worth knowing even though this tutorial only builds hands-on demonstrations for two of them:

• Excessive work: the query itself has to scan or process more data than necessary, often because of a missing index. This tutorial demonstrates this directly in Step 1.
• Resource contention: something else on the same database (a bulk import, a backup job, a noisy neighbor) is competing for locks, disk I/O, or CPU. This tutorial reproduces this directly in Step 7.
• Environmental pressure: the underlying infrastructure, disk, network, or host, is degraded.
• Plan regressions: the database’s query planner silently switches to a worse execution plan, often after a statistics update or a data-distribution shift.
• Pathological patterns: the query shape itself is fundamentally inefficient, such as an unbounded N+1 query pattern.

The last three are real and worth understanding, but they need infrastructure (a real disk, a real query planner making real decisions over time, a real application issuing N+1 calls) that would not add much by faking it here. This tutorial focuses on the two causes you can reproduce honestly and measure directly.

Prerequisites

• Python 3.11 or newer with pip. This tutorial was built and tested on Python 3.13.14.
• Basic familiarity with SQL (SELECT, WHERE, GROUP BY) and the command line.
• No Docker, no database server, and no cloud account. SQLite and the OpenTelemetry Python SDK are both pure pip installs.
• About 30 MB of free disk space for the practice database.

Step 1: Build a Database That Is Honestly Slow

To trust the timing numbers in this tutorial, the slowness needs to be real, not simulated with time.sleep(). Create a project folder, a virtual environment, and install the one dependency this lab needs beyond the standard library:

mkdir slow-query-lab
cd slow-query-lab
python -m venv venv
venv\Scripts\activate            # on Linux/macOS: source venv/bin/activate
pip install opentelemetry-api opentelemetry-sdk

Now create setup_db.py. It builds a 400,000-row orders table and deliberately leaves every column except the primary key unindexed:

import random
import sqlite3
import time

random.seed(42)

REGIONS = ["us-east", "us-west", "eu-central", "ap-south"]
STATUSES = ["pending", "paid", "shipped", "refunded"]
ROW_COUNT = 400_000


def build():
    conn = sqlite3.connect("orders.db")
    conn.execute("DROP TABLE IF EXISTS orders")
    conn.execute(
        """
        CREATE TABLE orders (
            id INTEGER PRIMARY KEY,
            customer_email TEXT NOT NULL,
            region TEXT NOT NULL,
            status TEXT NOT NULL,
            amount_cents INTEGER NOT NULL,
            created_at TEXT NOT NULL
        )
        """
    )

    def rows():
        for i in range(ROW_COUNT):
            yield (
                i,
                f"customer{i % 50000}@example.com",
                random.choice(REGIONS),
                random.choice(STATUSES),
                random.randint(500, 50000),
                f"2026-{random.randint(1, 8):02d}-{random.randint(1, 28):02d}",
            )

    t0 = time.perf_counter()
    conn.executemany("INSERT INTO orders VALUES (?, ?, ?, ?, ?, ?)", rows())
    conn.commit()
    print(f"inserted {ROW_COUNT} rows in {time.perf_counter() - t0:.2f}s")

    # Deliberately no index on customer_email, region, status, or created_at.
    # Only the PRIMARY KEY (id) is indexed, which SQLite creates automatically.
    counts = conn.execute("SELECT COUNT(*) FROM orders").fetchone()
    print("row count:", counts[0])
    conn.close()


if __name__ == "__main__":
    build()

Run it:

python setup_db.py

Real output from this run:

inserted 400000 rows in 0.76s
row count: 400000

Before writing any tracing code, confirm the slowness is genuine by timing a few queries directly:

python -c "
import sqlite3, time
conn = sqlite3.connect('orders.db')

def timeit(label, sql, params=()):
    t0 = time.perf_counter()
    rows = conn.execute(sql, params).fetchall()
    dt = (time.perf_counter() - t0) * 1000
    print(f'{label}: {dt:.3f} ms, {len(rows)} rows')

timeit('pk lookup', 'SELECT * FROM orders WHERE id = ?', (12345,))
timeit('email lookup (unindexed)', 'SELECT * FROM orders WHERE customer_email = ?', ('[email protected]',))
timeit('region+status range (unindexed)', 'SELECT * FROM orders WHERE region = ? AND status = ? AND created_at >= ?', ('us-east', 'paid', '2026-06-01'))
timeit('group by region (aggregate)', 'SELECT region, COUNT(*), SUM(amount_cents) FROM orders GROUP BY region')
"

Real captured output:

pk lookup: 0.295 ms, 1 rows
email lookup (unindexed): 23.567 ms, 8 rows
region+status range (unindexed): 33.690 ms, 9479 rows
group by region (aggregate): 99.803 ms, 4 rows

That is a real, measured 300x difference between an indexed primary-key lookup and an unindexed full table scan, and the aggregate query is nearly 340x slower than the primary-key lookup. Nothing here is staged. This is exactly what “excessive work” looks like: SQLite has to walk every one of the 400,000 rows to answer the email, region+status, and group-by queries because there is no index to narrow the search.

Step 2: Instrument Your Queries With Real OpenTelemetry Spans

Now wrap every database call in a span. In production you would export spans over OTLP to a Collector, but for this lab, create tracing_utils.py with a small custom exporter that writes each finished span to a JSON Lines file instead. This lets you inspect exactly what OpenTelemetry captures, using nothing but a text editor:

import json
import time
from contextlib import contextmanager

from opentelemetry import trace
from opentelemetry.sdk.trace import TracerProvider
from opentelemetry.sdk.trace.export import SimpleSpanProcessor, SpanExporter, SpanExportResult


class JSONLSpanExporter(SpanExporter):
    """Appends each finished span to a JSON Lines file as a flat dict.

    A real deployment sends spans to an OpenTelemetry Collector over OTLP.
    This exporter skips the network hop and writes the same shape of data
    (name, attributes, start/end time, duration) straight to disk so we can
    analyze it with plain Python afterward.
    """

    def __init__(self, path):
        self.path = path
        self._fh = open(path, "a", encoding="utf-8")

    def export(self, spans):
        for span in spans:
            duration_ms = (span.end_time - span.start_time) / 1_000_000
            record = {
                "name": span.name,
                "attributes": dict(span.attributes or {}),
                "start_time_ns": span.start_time,
                "duration_ms": duration_ms,
            }
            self._fh.write(json.dumps(record) + "\n")
        self._fh.flush()
        return SpanExportResult.SUCCESS

    def shutdown(self):
        self._fh.close()


def make_tracer(jsonl_path, service_name="slow-query-lab"):
    provider = TracerProvider()
    exporter = JSONLSpanExporter(jsonl_path)
    provider.add_span_processor(SimpleSpanProcessor(exporter))
    return provider.get_tracer(service_name), exporter


@contextmanager
def traced_query(tracer, fingerprint, raw_sql, phase="quiet"):
    """Wrap a DB call in a span carrying both a normalized fingerprint
    and the raw SQL text, so later steps can compare grouping by each."""
    with tracer.start_as_current_span("db.query") as span:
        span.set_attribute("db.query.fingerprint", fingerprint)
        span.set_attribute("db.statement", raw_sql)
        span.set_attribute("phase", phase)
        t0 = time.perf_counter()
        yield
        span.set_attribute("wall_ms", (time.perf_counter() - t0) * 1000)

Two design choices here matter, and both are worth understanding before you move on. First, SimpleSpanProcessor exports each span immediately as it finishes, which is fine for a lab like this; production systems typically use BatchSpanProcessor instead, so spans are exported in batches for efficiency. Second, every span carries both a normalized db.query.fingerprint (a fixed label describing the query’s shape) and the raw db.statement text, which usually contains the literal parameter values. You will use that second attribute in Step 6 to demonstrate exactly why grouping by raw SQL text is a mistake.

Next, create queries.py with four query shapes: one indexed lookup and three unindexed ones of increasing cost, matching the queries you timed in Step 1:

from tracing_utils import traced_query


def get_order_by_id(conn, tracer, order_id, phase="quiet"):
    # Indexed: id is the PRIMARY KEY, so SQLite uses a B-tree lookup.
    with traced_query(tracer, "get_order_by_id", f"SELECT * FROM orders WHERE id = {order_id}", phase):
        return conn.execute("SELECT * FROM orders WHERE id = ?", (order_id,)).fetchall()


def search_orders_by_email(conn, tracer, email, phase="quiet"):
    # Unindexed: customer_email has no index, so this is a full table scan.
    with traced_query(tracer, "search_orders_by_email", f"SELECT * FROM orders WHERE customer_email = '{email}'", phase):
        return conn.execute("SELECT * FROM orders WHERE customer_email = ?", (email,)).fetchall()


def search_orders_by_region_status(conn, tracer, region, status, since, phase="quiet"):
    # Unindexed: filters on region, status, and created_at all require a full scan.
    sql = f"region={region} status={status} since={since}"
    with traced_query(tracer, "search_orders_by_region_status", sql, phase):
        return conn.execute(
            "SELECT * FROM orders WHERE region = ? AND status = ? AND created_at >= ?",
            (region, status, since),
        ).fetchall()


def orders_count_by_region(conn, tracer, phase="quiet"):
    # Aggregate: full scan plus a GROUP BY, the most expensive single call.
    with traced_query(tracer, "orders_count_by_region", "SELECT region, COUNT(*) FROM orders GROUP BY region", phase):
        return conn.execute(
            "SELECT region, COUNT(*), SUM(amount_cents) FROM orders GROUP BY region"
        ).fetchall()

Notice that get_order_by_id and search_orders_by_email deliberately build their db.statement attribute with an f-string that bakes the literal value directly into the text, rather than using the parameterized placeholder. That is realistic; plenty of real instrumentation logs the rendered SQL for debugging convenience. It is also the setup for the cardinality problem in Step 6.

Step 3: Generate Realistic, Uneven Traffic

Real production traffic is never evenly distributed across query types. A “view order” lookup by primary key might run a thousand times for every one time a nightly dashboard runs an aggregate query. Reproducing that unevenness is what makes the next two steps meaningful. Create generate_traffic.py:

import argparse
import random
import sqlite3
import threading
import time

from queries import (
    get_order_by_id,
    orders_count_by_region,
    search_orders_by_email,
    search_orders_by_region_status,
)
from tracing_utils import make_tracer

random.seed(7)

# (function, call_count): deliberately uneven, like real production traffic.
CALL_PLAN = [
    ("get_order_by_id", 1000),
    ("search_orders_by_email", 80),
    ("search_orders_by_region_status", 30),
    ("orders_count_by_region", 5),
]


def run_writer_thread(stop_event, busy_timeout_ms):
    """Simulates a concurrent bulk-import job hammering the table with inserts."""
    conn = sqlite3.connect("orders.db", timeout=busy_timeout_ms / 1000)
    conn.execute(f"PRAGMA busy_timeout = {busy_timeout_ms}")
    next_id = 500_000
    locked_errors = 0
    while not stop_event.is_set():
        try:
            conn.execute(
                "INSERT INTO orders VALUES (?, ?, ?, ?, ?, ?)",
                (next_id, f"bulk{next_id}@example.com", "us-east", "pending", 999, "2026-08-21"),
            )
            conn.commit()
            next_id += 1
        except sqlite3.OperationalError as exc:
            conn.rollback()
            locked_errors += 1
            if locked_errors <= 3:
                print(f"  [writer] {exc}")
        time.sleep(0.001)
    conn.close()
    print(f"  [writer] inserted {next_id - 500_000} rows, hit 'database is locked' {locked_errors} time(s)")


def main():
    parser = argparse.ArgumentParser()
    parser.add_argument("--out", required=True)
    parser.add_argument("--mode", choices=["quiet", "contended"], required=True)
    parser.add_argument("--busy-timeout-ms", type=int, default=0)
    args = parser.parse_args()

    tracer, exporter = make_tracer(args.out)
    conn = sqlite3.connect("orders.db", timeout=args.busy_timeout_ms / 1000)
    conn.execute(f"PRAGMA busy_timeout = {args.busy_timeout_ms}")

    stop_event = threading.Event()
    writer = None
    if args.mode == "contended":
        writer = threading.Thread(target=run_writer_thread, args=(stop_event, args.busy_timeout_ms))
        writer.start()
        time.sleep(0.05)  # let the writer get moving before we start reading

    plan = []
    for name, count in CALL_PLAN:
        plan += [name] * count
    random.shuffle(plan)

    phase = args.mode
    t0 = time.perf_counter()
    read_errors = 0
    for name in plan:
        try:
            if name == "get_order_by_id":
                get_order_by_id(conn, tracer, random.randint(0, 399_999), phase)
            elif name == "search_orders_by_email":
                search_orders_by_email(conn, tracer, f"customer{random.randint(0, 49999)}@example.com", phase)
            elif name == "search_orders_by_region_status":
                search_orders_by_region_status(conn, tracer, "us-east", "paid", "2026-06-01", phase)
            elif name == "orders_count_by_region":
                orders_count_by_region(conn, tracer, phase)
        except sqlite3.OperationalError as exc:
            read_errors += 1
            if read_errors <= 3:
                print(f"  [reader] {exc}")
        time.sleep(0.001)
    wall_s = time.perf_counter() - t0

    if writer:
        stop_event.set()
        writer.join()

    exporter.shutdown()
    conn.close()
    print(f"mode={args.mode} calls={len(plan)} wall={wall_s:.2f}s read_errors={read_errors} -> {args.out}")


if __name__ == "__main__":
    main()

Ignore the --mode contended and run_writer_thread parts for now; you will use them in Step 7. For this step, generate a quiet baseline (no concurrent writer):

python generate_traffic.py --out spans_quiet.jsonl --mode quiet

Real output:

mode=quiet calls=1115 wall=5.96s read_errors=0 -> spans_quiet.jsonl

That produced 1,115 spans (1000 + 80 + 30 + 5, shuffled into a random order) in spans_quiet.jsonl. Open the file and you will see one JSON object per line, each with a fingerprint, the raw SQL text, and a duration in milliseconds. This is your raw trace data, exactly as an OpenTelemetry backend would store it before any aggregation.

Step 4: The Naive View, Sort by Duration

The most direct thing you can build from raw spans is a ranking by duration: which individual calls took the longest? This is what a “queries by duration” dashboard gives you when it is built straight on trace data. Create analyze_naive.py:

import json
import sys
from collections import defaultdict


def load_spans(path):
    spans = []
    with open(path, encoding="utf-8") as fh:
        for line in fh:
            spans.append(json.loads(line))
    return spans


def main():
    path = sys.argv[1] if len(sys.argv) > 1 else "spans_quiet.jsonl"
    spans = load_spans(path)

    by_fingerprint = defaultdict(list)
    for s in spans:
        fp = s["attributes"]["db.query.fingerprint"]
        by_fingerprint[fp].append(s["duration_ms"])

    print(f"loaded {len(spans)} spans from {path}\n")
    print("Naive ranking: single slowest call per query fingerprint")
    print(f"{'fingerprint':<32} {'max_ms':>10} {'calls':>8}")
    ranked = sorted(by_fingerprint.items(), key=lambda kv: max(kv[1]), reverse=True)
    for fp, durations in ranked:
        print(f"{fp:<32} {max(durations):>10.2f} {len(durations):>8}")


if __name__ == "__main__":
    main()

Run it against the quiet baseline:

python analyze_naive.py spans_quiet.jsonl

Real output:

loaded 1115 spans from spans_quiet.jsonl

Naive ranking: single slowest call per query fingerprint
fingerprint                          max_ms    calls
orders_count_by_region               178.33        5
search_orders_by_region_status        79.54       30
search_orders_by_email                50.23       80
get_order_by_id                        1.03     1000

By this view, orders_count_by_region is your worst offender: its slowest single call took 178 milliseconds, further than any other query got. If you had a limited amount of engineering time and picked your next optimization target from this list, you would start there. That decision would be a mistake, and the next step shows exactly why.

Step 5: Traffic-Weighted Impact Analysis

A single slow call is not the same thing as a costly query. orders_count_by_region only ran 5 times in this traffic sample. search_orders_by_email ran 80 times. Even though each individual search_orders_by_email call is faster, the query shape as a whole consumed far more total server time, because it ran so much more often. Create analyze_impact.py to rank by total cost instead of peak latency:

import json
import sys
from collections import defaultdict
from statistics import mean


def load_spans(path):
    spans = []
    with open(path, encoding="utf-8") as fh:
        for line in fh:
            spans.append(json.loads(line))
    return spans


def main():
    path = sys.argv[1] if len(sys.argv) > 1 else "spans_quiet.jsonl"
    spans = load_spans(path)

    by_fingerprint = defaultdict(list)
    for s in spans:
        fp = s["attributes"]["db.query.fingerprint"]
        by_fingerprint[fp].append(s["duration_ms"])

    naive_rank = {
        fp: i + 1
        for i, (fp, _) in enumerate(
            sorted(by_fingerprint.items(), key=lambda kv: max(kv[1]), reverse=True)
        )
    }

    rows = []
    for fp, durations in by_fingerprint.items():
        total = sum(durations)
        rows.append((fp, len(durations), mean(durations), total))
    rows.sort(key=lambda r: r[3], reverse=True)

    print(f"Traffic-weighted impact ranking ({path})\n")
    print(f"{'fingerprint':<32} {'calls':>7} {'mean_ms':>9} {'total_ms':>10} {'naive_rank':>11}")
    for i, (fp, calls, mean_ms, total_ms) in enumerate(rows, 1):
        print(f"{fp:<32} {calls:>7} {mean_ms:>9.2f} {total_ms:>10.1f} {'#' + str(naive_rank[fp]):>11}  -> impact rank #{i}")


if __name__ == "__main__":
    main()

Run it:

python analyze_impact.py spans_quiet.jsonl

Real output:

Traffic-weighted impact ranking (spans_quiet.jsonl)

fingerprint                        calls   mean_ms   total_ms  naive_rank
search_orders_by_email                80     28.31     2264.9          #3  -> impact rank #1
search_orders_by_region_status        30     42.77     1283.1          #2  -> impact rank #2
orders_count_by_region                 5    115.08      575.4          #1  -> impact rank #3
get_order_by_id                     1000      0.17      174.3          #4  -> impact rank #4

The ranking flips almost completely. orders_count_by_region, the naive #1, drops to impact rank #3. search_orders_by_email, which the naive view ranked third, is actually the single biggest consumer of total server time, at 2,264.9 milliseconds across the sample versus 575.4 milliseconds for the aggregate query. The formula behind this ranking is simple: call_count × mean_duration = total_time, and total time is what your database server actually spends, regardless of how that time is distributed across individual calls. This is the traffic-weighted impact idea, and it is the same reasoning that a production spanmetrics pipeline applies automatically once it aggregates spans into histograms (more on that in the Next Steps section).

Step 6: Why Grouping by Raw SQL Text Breaks Everything

Both analysis scripts above group spans by db.query.fingerprint, a fixed label describing each query’s shape. What happens if you group by the raw db.statement text instead, the one with the literal value baked in? Check directly:

python -c "
import json
from collections import defaultdict

by_fp = defaultdict(set)
by_raw = defaultdict(set)
with open('spans_quiet.jsonl', encoding='utf-8') as fh:
    for line in fh:
        s = json.loads(line)
        attrs = s['attributes']
        if attrs['db.query.fingerprint'] != 'get_order_by_id':
            continue
        by_fp['get_order_by_id'].add(attrs['db.query.fingerprint'])
        by_raw['raw'].add(attrs['db.statement'])

print('distinct groups by fingerprint:', len(by_fp['get_order_by_id']))
print('distinct groups by raw db.statement:', len(by_raw['raw']))
"

Real output:

distinct groups by fingerprint: 1
distinct groups by raw db.statement: 998

1,000 calls to the same logical query produced 998 distinct “groups” when grouped by raw text (two collided by chance on the same random order ID). Instead of one meaningful metric series describing “how fast is order lookup by ID,” a metrics backend grouping by raw SQL text would create 998 near-useless series instead, almost all of them with just a single data point. This is the cardinality problem the CNCF post’s own “Metric Cardinality” section warns about: grouping choices that look harmless at the code level can blow up the number of distinct label combinations a metrics system has to track.

There is a second, sharper problem hiding in the same mistake: db.statement in this lab also captures a customer’s email address for the search_orders_by_email query. If you exported that raw attribute as a metric label, you would be leaking personal data into your observability backend’s labels, which is exactly the privacy risk the same source article calls out. The fix for both problems is the same one this lab used from the start: attach a normalized fingerprint attribute at instrumentation time, and reserve the raw statement (if you keep it at all) for span-level detail that stays in your tracing backend rather than becoming a metric label.

Step 7: Reproduce Resource Contention (and a Real Locking Bug)

Excessive work is one cause of slowness. Resource contention, something else competing for the same database, is a completely different one, and it needs a different kind of demonstration. Run the traffic generator again, this time with --mode contended and a busy-timeout of zero, so a background writer thread hammers the table with inserts while your reads are running:

python generate_traffic.py --out spans_contended_broken.jsonl --mode contended --busy-timeout-ms 0

Real output:

  [reader] database is locked
  [reader] database is locked
  [reader] database is locked
  [writer] database is locked
  [writer] database is locked
  [writer] database is locked
  [writer] inserted 2762 rows, hit 'database is locked' 858 time(s)
mode=contended calls=1115 wall=24.40s read_errors=424 -> spans_contended_broken.jsonl

With no busy timeout, 424 of the 1,115 read calls (38 percent) failed outright with sqlite3.OperationalError: database is locked. By default, SQLite lets each connection wait timeout seconds (5 by default in Python’s sqlite3 module) before raising that error when it cannot immediately acquire the lock it needs; setting --busy-timeout-ms 0 here removes that grace period entirely, so any lock conflict fails instantly instead of waiting.

A Real Bug: Retrying After a Failed Commit

Getting a clean version of the output above took an extra debugging pass, and the bug is worth walking through because it is a realistic mistake. The first version of run_writer_thread looked correct: catch OperationalError, count it, and let the loop try again on the next iteration. Instead, it crashed with a completely different exception:

sqlite3.IntegrityError: UNIQUE constraint failed: orders.id

Here is what was actually happening. When conn.commit() raises OperationalError because the database is locked, the INSERT that came before it does not just disappear: it stays pending inside that connection’s still-open transaction. The except block caught the error and moved on without incrementing next_id, intending a clean retry. But on the next loop iteration, the code tried to insert a row with that same next_id again, on the same connection, while the previous attempt at that exact row was still sitting uncommitted in the same transaction. SQLite correctly rejected it as a duplicate key, not because two different rows collided, but because the same connection tried to insert the same not-yet-committed row twice.

The fix is one line: call conn.rollback() in the except block before retrying, which is already in the run_writer_thread code above. Rolling back discards the pending, uncommitted insert cleanly, so the next iteration’s retry of the same next_id is a fresh attempt rather than a collision with itself. The general lesson generalizes well beyond this lab: if a write fails partway through a transaction, you need to explicitly roll back before you retry, or leftover transaction state will produce confusing secondary errors that have nothing to do with your actual bug.

The Fix: A Real Busy Timeout

Now run the same contended scenario with a sane busy timeout instead of zero:

python generate_traffic.py --out spans_contended.jsonl --mode contended --busy-timeout-ms 5000

Real output:

  [writer] inserted 6928 rows, hit 'database is locked' 0 time(s)
mode=contended calls=1115 wall=65.17s read_errors=0 -> spans_contended.jsonl

Zero errors this time, because both the reader and the writer now wait (up to 5 seconds) for a lock instead of failing immediately. Notice the tradeoff, though: the whole run took 65.17 seconds instead of 5.96 seconds for the equivalent quiet run. Nothing failed, but everything got much slower. That distinction, “erroring out” versus “silently getting much slower,” matters, and it is exactly what the next step is built to catch.

SQLite’s default rollback-journal locking mode is what produces this contention in the first place. If your application does frequent concurrent reads and writes, SQLite’s Write-Ahead Logging (WAL) mode is worth knowing about too: with PRAGMA journal_mode=WAL, readers no longer block writers and a writer no longer blocks readers, which reduces this kind of contention substantially. It does not eliminate SQLITE_BUSY entirely (SQLite’s own WAL documentation has a section titled “Sometimes Queries Return SQLITE_BUSY In WAL Mode”), so a busy timeout is still worth setting even if you switch to WAL.

Step 8: Detect Anomalies With an Adaptive Baseline

You now have two traffic samples: a healthy baseline (spans_quiet.jsonl) and a genuinely degraded one (spans_contended.jsonl). A common next step is a fixed-threshold alert: “page someone if a query takes longer than 50 milliseconds.” Create analyze_anomaly.py to compare that approach against an adaptive baseline built from each fingerprint’s own normal behavior:

import json
import sys
from collections import defaultdict
from statistics import mean, pstdev


def load_by_fingerprint(path):
    by_fp = defaultdict(list)
    with open(path, encoding="utf-8") as fh:
        for line in fh:
            s = json.loads(line)
            fp = s["attributes"]["db.query.fingerprint"]
            by_fp[fp].append(s["duration_ms"])
    return by_fp


def main():
    baseline_path = sys.argv[1] if len(sys.argv) > 1 else "spans_quiet.jsonl"
    current_path = sys.argv[2] if len(sys.argv) > 2 else "spans_contended.jsonl"

    baseline = load_by_fingerprint(baseline_path)
    current = load_by_fingerprint(current_path)

    print(f"baseline: {baseline_path}   current: {current_path}\n")
    print(f"{'fingerprint':<32} {'base_mean':>10} {'base_std':>9} {'cur_mean':>9} {'z-score':>8}  verdict")

    FIXED_THRESHOLD_MS = 50.0

    results = []
    for fp in sorted(baseline):
        base_durations = baseline[fp]
        cur_durations = current.get(fp, [])
        if not cur_durations:
            continue
        b_mean, b_std = mean(base_durations), pstdev(base_durations)
        c_mean = mean(cur_durations)
        # Guard against a baseline so tight (near-zero variance) that
        # any tiny absolute jump would produce a meaningless huge z-score.
        effective_std = max(b_std, 0.05)
        z = (c_mean - b_mean) / effective_std
        results.append((fp, b_mean, b_std, c_mean, z))

    # Sorted by z-score, not by absolute latency: the query whose behavior
    # shifted the most relative to its OWN normal range comes first, even
    # if its absolute latency is still low compared to other queries.
    results.sort(key=lambda r: r[4], reverse=True)
    for fp, b_mean, b_std, c_mean, z in results:
        fixed_alert = "ALERT" if c_mean > FIXED_THRESHOLD_MS else "ok"
        adaptive_alert = "ANOMALY" if z > 3 else "ok"
        print(
            f"{fp:<32} {b_mean:>10.2f} {b_std:>9.2f} {c_mean:>9.2f} {z:>8.1f}  "
            f"fixed-threshold({FIXED_THRESHOLD_MS}ms)={fixed_alert:<6} adaptive-baseline={adaptive_alert}"
        )


if __name__ == "__main__":
    main()

Case 1: Nothing Is Actually Wrong

First, generate a second, independent healthy traffic sample and compare it against the first one, to see how each method behaves when nothing has actually gone wrong:

python generate_traffic.py --out spans_quiet2.jsonl --mode quiet --busy-timeout-ms 5000
python analyze_anomaly.py spans_quiet.jsonl spans_quiet2.jsonl

Real output:

fingerprint                       base_mean  base_std  cur_mean  z-score  verdict
orders_count_by_region               115.08     31.63    118.33      0.1  fixed-threshold(50.0ms)=ALERT  adaptive-baseline=ok
search_orders_by_region_status        42.77     13.79     41.27     -0.1  fixed-threshold(50.0ms)=ok     adaptive-baseline=ok
search_orders_by_email                28.31     10.79     26.47     -0.2  fixed-threshold(50.0ms)=ok     adaptive-baseline=ok
get_order_by_id                        0.17      0.15      0.12     -0.4  fixed-threshold(50.0ms)=ok     adaptive-baseline=ok

The fixed 50-millisecond threshold fires on orders_count_by_region even though its z-score of 0.1 shows it is behaving completely normally for itself. That query is simply always around 115 milliseconds because it is a full aggregate scan; a fixed threshold set below that will page someone every single time it runs, forever, whether or not anything is actually wrong. That is alert fatigue in its purest form. The adaptive baseline correctly reports “ok” across the board, because nothing has actually deviated from what is normal.

Case 2: Something Is Actually Wrong

Now compare the healthy baseline against the genuinely contended traffic from Step 7:

python analyze_anomaly.py spans_quiet.jsonl spans_contended.jsonl

Real output:

fingerprint                       base_mean  base_std  cur_mean  z-score  verdict
get_order_by_id                        0.17      0.15     52.44    339.9  fixed-threshold(50.0ms)=ALERT  adaptive-baseline=ANOMALY
search_orders_by_email                28.31     10.79     87.06      5.4  fixed-threshold(50.0ms)=ALERT  adaptive-baseline=ANOMALY
search_orders_by_region_status        42.77     13.79    102.95      4.4  fixed-threshold(50.0ms)=ALERT  adaptive-baseline=ANOMALY
orders_count_by_region               115.08     31.63    229.15      3.6  fixed-threshold(50.0ms)=ALERT  adaptive-baseline=ANOMALY

All four fingerprints get flagged now, which makes sense: a busy writer thread holding locks slows down every reader, not just one query. But look at the ranking. Sorted by z-score, get_order_by_id comes out on top with a z-score of 339.9, the most extreme deviation from normal of anything in the table, by nearly two orders of magnitude over the next entry. In absolute terms, though, it is the fastest of the four queries at 52.44 milliseconds, well below the 229.15 milliseconds recorded for orders_count_by_region. A dashboard sorted by raw latency, or an on-call engineer scanning for the biggest number, would notice orders_count_by_region first and might not even register that get_order_by_id barely crossed the fixed threshold at all.

That would be exactly backwards. A query that normally takes 0.17 milliseconds and now takes 52 milliseconds has gotten roughly 300 times slower. A query that normally takes 115 milliseconds and now takes 229 milliseconds has roughly doubled. Both are real regressions, but the first one represents a far more extreme change in behavior for that specific query, and the z-score ranking is what surfaces it. That is the entire value of an adaptive baseline: it measures how abnormal something is for itself, not how large the raw number looks next to other, unrelated queries.

Common Mistakes and Gotchas

• Grouping metrics by raw SQL text. As Step 6 showed directly, this explodes cardinality (998 groups instead of 1) and can leak sensitive literal values, like the email addresses in this lab’s own data, into metric labels. Always fingerprint or normalize before you aggregate.
• Retrying a write without rolling back first. The IntegrityError bug in Step 7 was not a SQLite quirk; it was a direct consequence of retrying an insert while a prior, failed attempt at the same row was still sitting in an open transaction. Any retry loop around a database write needs an explicit rollback in its error handling, not just a caught exception.
• Setting one global latency threshold. Case 1 in Step 8 showed a fixed threshold firing constantly on a query that is simply always slow by nature. If you must use fixed thresholds, they need to be set per query, which is effectively a manual, unmaintained version of what an adaptive baseline does automatically.
• Trusting a z-score without a variance floor. The effective_std = max(b_std, 0.05) line in analyze_anomaly.py is not decorative. Without it, a fingerprint with an extremely tight, near-zero baseline standard deviation (like the 0.15 ms baseline for get_order_by_id) would produce enormous, noisy z-scores from even trivial absolute jitter. Flooring the denominator keeps the score meaningful.
• Assuming WAL mode alone fixes contention. WAL mode meaningfully reduces reader/writer blocking, but SQLite’s own documentation is explicit that SQLITE_BUSY can still occur in WAL mode. Set a busy timeout regardless of which journal mode you use.

How to Verify Everything Works End to End

To confirm the full lab works from a clean state, run this sequence in order and check that your output matches the shape (not necessarily the exact numbers, which will vary run to run) of what is shown above:

python setup_db.py
python generate_traffic.py --out spans_quiet.jsonl --mode quiet
python analyze_naive.py spans_quiet.jsonl
python analyze_impact.py spans_quiet.jsonl
python generate_traffic.py --out spans_quiet2.jsonl --mode quiet --busy-timeout-ms 5000
python generate_traffic.py --out spans_contended.jsonl --mode contended --busy-timeout-ms 5000
python analyze_anomaly.py spans_quiet.jsonl spans_quiet2.jsonl
python analyze_anomaly.py spans_quiet.jsonl spans_contended.jsonl

You should see: a naive ranking that puts the aggregate query first, an impact ranking that reorders it down to third place, a quiet-vs-quiet comparison where the adaptive baseline stays calm despite a fixed-threshold false alarm, and a quiet-vs-contended comparison where the adaptive baseline flags every fingerprint, with get_order_by_id at the top of the z-score ranking despite having the lowest absolute latency in the table. If your ordering matches that pattern, the lab is working correctly.

Next Steps: Taking This to a Real Collector and Backend

This lab approximates, in plain Python, what a production OpenTelemetry pipeline does automatically with the Span Metrics Connector in the OpenTelemetry Collector Contrib distribution. That connector aggregates Request, Error, and Duration (R.E.D) metrics directly from span data, computing duration histograms per unique set of dimensions, which is the real-world equivalent of what analyze_impact.py approximates by hand here. A minimal Collector configuration looks like this:

connectors:
  spanmetrics:
    dimensions:
      - name: db.system
        default: "unknown"
      - name: db.query.fingerprint
    exemplars:
      enabled: true
service:
  pipelines:
    traces:
      receivers: [otlp]
      exporters: [spanmetrics]
    metrics:
      receivers: [spanmetrics]
      exporters: [otlphttp]

From there, a real deployment would send those metrics to a backend like Prometheus, and the traces themselves to a backend like Tempo, then visualize both in Grafana. If you have Docker available, the original CNCF Blog post this tutorial is based on walks through exactly that setup with a runnable docker-compose lab, including its own traffic-weighted impact dashboard and anomaly-baseline dashboard built in Grafana rather than in a standalone Python script.

Beyond that, the anomaly detection in Step 8 uses a simple mean-and-standard-deviation baseline, which is easy to reason about but sensitive to outliers and assumes a roughly normal distribution. Production observability tools typically use more robust techniques: percentile-based baselines (comparing against p95 or p99 rather than the mean), exponentially weighted moving averages that adapt gradually over time, or baselines that account for seasonality (a query that is always slow every night during a backup job should not page anyone at 2 AM). The core idea, compare current behavior to what is normal for that specific thing rather than to one fixed number, stays the same regardless of which statistical technique you pick.