Slow Query Logs Are Noise. Here’s How We Surface the Real Killers.

There’s a query running on your production database right now that will eventually take you down. It’s not in your alerts. It’s not the slowest query in your logs. It’s fast enough to fly under the radar — say, 80ms — but it runs 3,000 times a minute during peak hours.

That’s your real killer.

The Problem with “Slowest Query” Dashboards

When I first joined a team dealing with database latency spikes, the first thing I checked was the slow query log. We had a Grafana dashboard that ranked queries by P99 duration. Everyone loved that dashboard. It looked smart.

But it was lying to us.

The query at the top — a gnarly 4-second JOIN across three tables — ran maybe twice a day, during a batch report generation. Sure, it was slow. But it wasn’t causing our 2am pages. The actual culprit was a SELECT * FROM user_sessions WHERE user_id = ? with no covering index, running 50 times per second from a poorly designed mobile polling loop.

Four seconds twice a day = 8 seconds of DB load per day.

80ms × 50/s = 4 seconds of DB load per second.

The math isn’t subtle. But the tooling was only showing us half the picture.

Rethinking the Alert Model

Most observability setups alert on one of two things:

1. A query exceeded a duration threshold (e.g., > 1s)
2. Overall DB CPU or connection pool exhaustion

Both are lagging indicators. By the time they fire, users are already having a bad time.

What we actually want to catch is this: queries with compounding impact — the kind that look harmless in isolation but pile up into infrastructure debt at scale.

The signal I now use is what I call the Query Impact Score:

impact = avg_duration_ms × executions_per_minute

That’s it. Nothing fancy. A 100ms query running 1,000 times/min has the same score as a 10,000ms query running 10 times/min. Both deserve your attention. Neither shows up as “the slowest query.”

Building the Collector in Go

We built this as a lightweight sidecar that polls performance_schema in MySQL (or pg_stat_statements in Postgres) and publishes metrics. Here's a simplified version of the Go implementation.

Structs and setup

package querywatch

import (
    "database/sql"
    "log"
    "time"
)

type QueryStat struct {
    Digest          string
    DigestText      string
    ExecCount       int64
    AvgLatencyMs    float64
    ImpactScore     float64
}

type Watcher struct {
    db           *sql.DB
    interval     time.Duration
    impactThresh float64
    onAlert      func(QueryStat)
}

func NewWatcher(db *sql.DB, interval time.Duration, threshold float64, alertFn func(QueryStat)) *Watcher {
    return &Watcher{
        db:           db,
        interval:     interval,
        impactThresh: threshold,
        onAlert:      alertFn,
    }
}

Polling performance_schema

func (w *Watcher) fetchStats() ([]QueryStat, error) {
    query := `
        SELECT
            DIGEST,
            DIGEST_TEXT,
            COUNT_STAR,
            AVG_TIMER_WAIT / 1e9 AS avg_latency_ms
        FROM performance_schema.events_statements_summary_by_digest
        WHERE SCHEMA_NAME = DATABASE()
        ORDER BY COUNT_STAR * (AVG_TIMER_WAIT / 1e9) DESC
        LIMIT 50`
        rows, err := w.db.Query(query)
    if err != nil {
        return nil, err
    }
    defer rows.Close()

    var stats []QueryStat
    for rows.Next() {
        var s QueryStat
        if err := rows.Scan(&s.Digest, &s.DigestText, &s.ExecCount, &s.AvgLatencyMs); err != nil {
            continue
        }
        s.ImpactScore = float64(s.ExecCount) * s.AvgLatencyMs
        stats = append(stats, s)
    }

    return stats, rows.Err()
}

The alert loop

func (w *Watcher) Run() {
    ticker := time.NewTicker(w.interval)
    defer ticker.Stop()

        for range ticker.C {
        stats, err := w.fetchStats()
        if err != nil {
            log.Printf("querywatch: fetch error: %v", err)
            continue
        }

                for _, s := range stats {
            if s.ImpactScore >= w.impactThresh {
                w.onAlert(s)
            }
        }
    }
}

Wiring it up

func main() {
    db, err := sql.Open("mysql", "user:pass@tcp(localhost:3306)/myapp")
    if err != nil {
        log.Fatal(err)
    }
    defer db.Close()

    watcher := querywatch.NewWatcher(
        db,
        30*time.Second,
        500_000.0, // alert if impact score > 500k ms
        func(s querywatch.QueryStat) {
            log.Printf(
                "[ALERT] High-impact query detected\n  digest: %s\n  executions: %d\n  avg_latency: %.2fms\n  impact_score: %.0f\n  query: %s\n",
                s.Digest, s.ExecCount, s.AvgLatencyMs, s.ImpactScore, s.DigestText,
            )
        },
    )

    watcher.Run()
}

The onAlert callback is where you plug in whatever you want — a Slack webhook, PagerDuty, a write to your incident DB, or push to a Prometheus gauge.

Visualizing What You’re Missing

Here’s what the impact distribution actually looks like in a real-ish production workload. Notice how the “worst by duration” and “worst by impact” lists barely overlap:

Impact Score = avg_duration_ms × executions_per_10min

Query                                  Avg Duration   Exec/10min   Impact Score
─────────────────────────────────────────────────────────────────────────────────
SELECT * FROM sessions WHERE uid=?         80ms          6,000        480,000  ⚠️
UPDATE orders SET status=? WHERE id=?      45ms          9,200        414,000  ⚠️
SELECT name FROM products WHERE slug=?     12ms         30,000        360,000  ⚠️
INSERT INTO audit_logs (...)              120ms          2,100        252,000
SELECT * FROM report_data JOIN ...       4,200ms             4         16,800
SELECT COUNT(*) FROM users               3,100ms             2          6,200

── "Slowest" by duration ───────────────────────────────────────────────────────
  → report_data JOIN: 4,200ms  ← everyone's watching this one
  → COUNT(*) users:   3,100ms  ← and this

── Highest actual impact ───────────────────────────────────────────────────────
  → sessions lookup:  480,000  ← nobody's watching this
  → orders update:    414,000  ← or this
  → products slug:    360,000  ← or this

The 4,200ms query is the one that gets the Slack thread. The 80ms query is the one that causes the 2am page.

Adding a Rolling Window with a Snapshot Diff

One thing the naive implementation misses: COUNT_STAR in performance_schema is cumulative since server start. So to get "executions per interval," you need to diff against the previous snapshot.

type Watcher struct {
    db           *sql.DB
    interval     time.Duration
    impactThresh float64
    onAlert      func(QueryStat)
    lastSnapshot map[string]int64 // digest → last count
}

func (w *Watcher) fetchDeltaStats() ([]QueryStat, error) {
    raw, err := w.fetchStats()
    if err != nil {
        return nil, err
    }

    if w.lastSnapshot == nil {
        w.lastSnapshot = make(map[string]int64)
        for _, s := range raw {
            w.lastSnapshot[s.Digest] = s.ExecCount
        }
        return nil, nil // skip first tick; no delta yet
    }

    var result []QueryStat
    for _, s := range raw {
        prev := w.lastSnapshot[s.Digest]
        delta := s.ExecCount - prev
        w.lastSnapshot[s.Digest] = s.ExecCount

        if delta <= 0 {
            continue
        }

        s.ExecCount = delta
        s.ImpactScore = float64(delta) * s.AvgLatencyMs
        result = append(result, s)
    }

    return result, nil
}

Now ExecCount in the alert represents actual executions in the last interval, not lifetime totals. Your impact score becomes meaningful at any point in the server's uptime.

What to Do When an Alert Fires

The alert tells you which query is the problem. It doesn’t tell you why it’s running that often or what’s wrong with it. Here’s the workflow I’ve settled into:

Step 1 — Grab the EXPLAIN plan. Take the DIGEST_TEXT from the alert, swap in some real parameter values, and run EXPLAIN ANALYZE. You're looking for full table scans, bad row estimates, or filesorts on large tables.

Step 2 — Trace the call site. Search your codebase for the query pattern. Is it in a hot loop? Is it being called from a background job without batching? Is it a lazy-loaded ORM relation inside a for range over 500 records?

Step 3 — Check for a missing index first. Before rewriting anything, try SHOW INDEX FROM <table> and cross-reference with the WHERE clause. Nine times out of ten, a composite index on the right columns kills the impact score by 90%.

Step 4 — Consider caching for read-heavy patterns. If the query is reading data that changes infrequently, a short TTL in Redis often removes it from the chart entirely. The products WHERE slug=? query in our example above? Static catalog data. We cached it. Impact score went to zero.

This Is a Culture Problem Too

I want to be honest about something. The tooling is the easy part.

The harder problem is that most teams optimize for visible performance issues — the ones that show up red in dashboards, the ones that generate Slack noise, the ones that are obviously slow. The insidious medium-frequency, medium-latency query doesn’t look alarming at any given moment. It just slowly erodes your DB capacity margin until one day traffic spikes and you have nothing left.

Building this watcher was useful. But the more important change was making the impact score a first-class metric in our weekly engineering sync. We’d pull up the top 5 by impact and ask: “Has this changed since last week? Do we know why?”

That habit — treating query impact as a running conversation instead of a one-time fix — is what actually keeps the list short.

Closing

Slow query logs aren’t useless. They still catch outliers worth investigating. But if that’s all you’re watching, you’re optimizing for the dramatic and ignoring the structural.

The real killers are quiet. They’re fast enough to not look scary, frequent enough to matter enormously, and patient enough to wait for your next traffic spike.

Build the score. Watch the score. Fix the score. Everything else is noise.