Slow Query Detection — Catching Performance Problems Before Users Do

Reading Time: 3 minutes

Series: Every Laravel Project Should Have These Building Blocks 
Part: 29 of 35 Level: Intermediate Prerequisites: App Service Provider, Structured Logging

---

What You’ll Learn

• Setting up DB::listen() with a configurable threshold
• Logging slow queries to a dedicated query channel
• Reconstructing the full SQL with bound parameters
• The DB::prohibitDestructiveCommands() safety rail
• Model::shouldBeStrict() for N+1 detection in development

---

Why Slow Queries Matter

Slow queries are the most common cause of slow pages in Laravel applications. They’re also the hardest to find post-production because:

• They only appear under real load
• Individual pages may seem fine until traffic increases
• They compound: a 3-second query running on every pageload is invisible in development but catastrophic at 100 concurrent users

Proactive slow query logging catches them before users experience them.

---

DB::listen() in AppServiceProvider

Register the listener in AppServiceProvider::boot():

// app/Providers/AppServiceProvider.php
public function boot(): void
{
    $this->registerSlowQueryDetection();
    // ... other boot logic
}

private function registerSlowQueryDetection(): void
{
    // Only log in production — Debugbar handles this in development
    if (! app()->isProduction()) {
        return;
    }

    $threshold = config('database.slow_query_threshold_ms', 1000);

    DB::listen(function (\Illuminate\Database\Events\QueryExecuted $query) use ($threshold): void {
        if ($query->time < $threshold) {
            return;
        }

        Log::channel('query')->warning('Slow query', [
            'sql'         => $this->interpolateSql($query->sql, $query->bindings),
            'duration_ms' => $query->time,
            'connection'  => $query->connectionName,
            'request_id'  => request()->header(\App\Http\Middleware\RequestLogger::X_REQUEST_ID),
            'url'         => request()->fullUrl(),
            'method'      => request()->method(),
        ]);
    });
}

/**
 * Replace ? placeholders with actual values for readability.
 */
private function interpolateSql(string $sql, array $bindings): string
{
    $bindings = array_map(function (mixed $binding): string {
        if (is_null($binding)) {
            return 'NULL';
        }
        if (is_bool($binding)) {
            return $binding ? '1' : '0';
        }
        if ($binding instanceof \DateTimeInterface) {
            return "'{$binding->format('Y-m-d H:i:s')}'";
        }
        if (is_string($binding)) {
            return "'" . addslashes($binding) . "'";
        }
        return (string) $binding;
    }, $bindings);

    return vsprintf(str_replace('?', '%s', $sql), $bindings);
}

Configure the threshold in config/database.php:

// config/database.php
'slow_query_threshold_ms' => env('DB_SLOW_QUERY_THRESHOLD_MS', 1000),

.env:

DB_SLOW_QUERY_THRESHOLD_MS=500

A 500ms threshold catches queries that need indexing without too much noise.

---

Reading Slow Query Logs

A typical entry in logs/query.log:

[2024-06-10 14:32:17] production.WARNING: Slow query {
    "sql": "SELECT * FROM `orders` WHERE `user_id` = '42' AND `status` = 'pending' ORDER BY `created_at` DESC",
    "duration_ms": 1243,
    "connection": "mysql",
    "request_id": "550e8400-e29b-41d4-a716-446655440000",
    "url": "https://app.example.com/dashboard",
    "method": "GET"
}

With the full SQL visible, you can paste it into a database client, run EXPLAIN, and see exactly which index is missing.

---

DB::prohibitDestructiveCommands() — Production Safety Rail

In AppServiceProvider::boot():

if (app()->isProduction()) {
    DB::prohibitDestructiveCommands();
}

This prevents php artisan migrate:fresh, php artisan db:wipe, and similar destructive commands from running in production. If someone accidentally runs these in a production SSH session, they get an error instead of a wiped database.

---

Model::shouldBeStrict() — N+1 Detection in Development

In AppServiceProvider::boot():

if (app()->isLocal() || app()->isTesting()) {
    Model::shouldBeStrict();
}

shouldBeStrict() enables three guards in non-production:

1. Lazy loading prevention — throws an exception when a relationship is accessed without with():

// ❌ N+1 — throws in strict mode
foreach ($orders as $order) {
    echo $order->user->name; // LazyLoadingViolationException
}

// ✅ Eager loaded — works fine
$orders = Order::with('user')->get();
foreach ($orders as $order) {
    echo $order->user->name;
}

2. Mass assignment prevention — throws when accessing a property that’s not in $fillable or $guarded.

3. Accessor prevention — throws when accessing attributes that don’t exist on the model.

These three errors are common sources of subtle bugs. Catching them in development (as exceptions, not silent nulls) means they never reach production.

---

DB::whenQueryingForLongerThan() — Request-Scoped Alerts

For detecting cumulative slow request times (many small queries adding up):

// In a middleware or AppServiceProvider:
DB::whenQueryingForLongerThan(2000, function (\Illuminate\Database\Connection $connection): void {
    Log::channel('query')->warning('Request spent >2s in database queries', [
        'request_id'  => request()->header(RequestLogger::X_REQUEST_ID),
        'url'         => request()->fullUrl(),
        'query_count' => $connection->totalQueryDuration(),
    ]);
});

This catches the “20 fast queries” problem — individually under threshold but collectively expensive.

---

Combining the Tools

The complete picture for query observability:

Tool	Environment	Catches
Model::shouldBeStrict()	Local + Testing	N+1 violations, missing fillable, undefined accessors
Laravel Debugbar	Local	All queries with timing, N+1, memory
DB::listen() threshold	Production	Queries over Xms
DB::whenQueryingForLongerThan()	Production	Requests with high cumulative query time
DB::prohibitDestructiveCommands()	Production	Accidental wipe commands

---

Key Takeaways

• DB::listen() with a threshold is the simplest way to catch slow queries in production. 500ms is a good starting threshold.
• interpolateSql() replaces ? placeholders with actual values — makes the logged SQL paste-ready for EXPLAIN.
• Always log the request_id alongside slow queries so you can trace which page triggered them.
• Model::shouldBeStrict() converts N+1 errors from silent runtime bugs into loud development exceptions.
• DB::prohibitDestructiveCommands() in production prevents accidental data loss from migration commands.
• DB::whenQueryingForLongerThan() catches pages with many small queries that individually look fine.

---

Tips and Gotchas

⚠️ Warning: DB::listen() runs synchronously for every query. Don’t do anything expensive inside the callback — no HTTP calls, no additional queries. Log to a file channel only; writing to the database from inside a query listener can create infinite loops.

💡 Tip: Use EXPLAIN on every slow query you find. In MySQL: EXPLAIN SELECT * FROM orders WHERE user_id = 42. Look for type: ALL (full table scan) and key: NULL (no index used). These are almost always fixable by adding an index.

🔥 Expert Note: Model::shouldBeStrict() raises a LazyLoadingViolationException in development. Don’t suppress these — fix them with ->with('relation'). Each lazy load exception is a silent N+1 query that runs once in development but 100 times in production with real data.

Further Reading

• Laravel Docs: Database Monitoring
• Laravel Docs: Model::shouldBeStrict()
• Laravel Debugbar — the essential local development query inspector
• MySQL EXPLAIN — understand query execution plans

---

← ErrorReporter | Next: Composer Scripts →