skip to content

In Laravel, how do you log every SQL query with DB::listen(), and how does DB::whenQueryingForLongerThan() differ for spotting slow requests?

level: middleimportance: should knowfreq 30%

answer

  1. register in AppServiceProvider boot()
  2. QueryExecuted: sql, bindings, time
  3. time is milliseconds
  4. cumulative per request, fires once
  5. reset between queued jobs

basics

~10 s

DB::listen() registers a closure that receives a QueryExecuted event after every query, with sql, bindings, time in milliseconds and connectionName. whenQueryingForLongerThan() instead fires once when a connection's total query time exceeds a threshold.

solid answer

~30 s

Call `DB::listen(function (QueryExecuted $query) { ... })` in `AppServiceProvider::boot()`. After each statement the closure receives an `Illuminate\Database\Events\QueryExecuted` with `sql`, `bindings`, `time` (milliseconds, float), `connectionName`, `readWriteType` and a `toRawSql()` helper, so you can log slow individual statements, for example `if ($query->time > 100)`. `DB::whenQueryingForLongerThan(500, fn (Connection $connection, QueryExecuted $event) => ...)` tracks **cumulative** time on the connection and calls the handler **once** when the total passes the threshold; the queue resets the total and re-arms handlers after each job. The listener runs on every query, so keep it cheap and guard it by environment.

code

php · 16 lines
php
<?php

use Illuminate\Database\Events\QueryExecuted;
use Illuminate\Support\Facades\DB;
use Illuminate\Support\Facades\Log;

// AppServiceProvider::boot()
DB::listen(function (QueryExecuted $query) {
    if ($query->time > 100) { // milliseconds
        Log::warning('slow query', [
            'sql' => $query->sql,
            'ms' => $query->time,
            'connection' => $query->connectionName,
        ]);
    }
});

go deeper

for a junior

Recall that DB::listen() in a service provider's boot() receives each query's SQL, bindings and time.

for a middle

Explain the QueryExecuted fields, the millisecond unit, and how whenQueryingForLongerThan() measures cumulative time and fires once.

for a senior

Use these hooks to find N+1 and slow requests in staging without adding production overhead or leaking data through bindings.

for a principal

Decide what query telemetry is always on in production and what stays a development-time tool.

## Two hooks for two questions Laravel's database layer fires an event after every statement it runs. Two APIs on the `DB` facade build on that event, and they answer different questions: - **`DB::listen()`**: "what did each query look like, and how long did it take?" - **`DB::whenQueryingForLongerThan()`**: "did this request or job spend too long in the database overall?" Both are normally registered in the `boot()` method of `App\Providers\AppServiceProvider`, so they apply to every request, command and job. ## `DB::listen()` ```php use Illuminate\Database\Events\QueryExecuted; use Illuminate\Support\Facades\DB; use Illuminate\Support\Facades\Log; public function boot(): void { if (! app()->isProduction()) { DB::listen(function (QueryExecuted $query) { Log::debug($query->toRawSql(), [ 'ms' => $query->time, 'connection' => $query->connectionName, 'route' => $query->readWriteType, ]); }); } } ``` The `QueryExecuted` event carries: | Property or method | Contents | |---|---| | `sql` | the statement with `?` placeholders | | `bindings` | the values bound to those placeholders | | `time` | execution time in **milliseconds**, as a float | | `connection` / `connectionName` | the connection object and its name | | `readWriteType` | `read`, `write` or `direct` | | `toRawSql()` | the SQL with bindings substituted, for reading | Typical uses are logging statements over a threshold, counting queries per request in development, or confirming that a read went to a replica. ## `DB::whenQueryingForLongerThan()` ```php use Illuminate\Database\Connection; use Illuminate\Database\Events\QueryExecuted; DB::whenQueryingForLongerThan(500, function (Connection $connection, QueryExecuted $event) { Log::warning('Request spent over 500 ms in the database', [ 'connection' => $connection->getName(), 'last_sql' => $event->sql, ]); }); ``` How it works: 1. The connection keeps a running **total** of query time. 2. The method registers a listener that, after each query, compares the total with the threshold, given in milliseconds, or as a `DateTimeInterface` or `CarbonInterval`. 3. When the total first exceeds it, the handler runs with the connection and the query that crossed the line, and is marked as having run. 4. It does not fire again until `allowQueryDurationHandlersToRunAgain()` is called. The queue service provider resets the total and re-arms the handlers after each processed job, so every job is measured on its own. This catches the request that runs 300 fast queries, which a per-query threshold never flags, and it reports once rather than on every query after the threshold. ## Keeping the listener cheap - **It runs on every statement**, synchronously, in the request. Formatting and writing a log line per query can double the cost of a query-heavy page. - **Gate it** by environment or a config flag, and prefer thresholds (`$query->time > 100`) over logging everything in production. - **Mind the bindings**: they can contain personal data or secrets, so redact before writing them anywhere persistent. - **Avoid querying the database inside the listener**; the query it runs fires the listener again. ## Where this stops `DB::listen()` is the raw hook. Dashboards that aggregate slow queries across requests are provided by dedicated packages such as Pulse and Telescope, which build on the same event. When an interviewer asks how you found a slow endpoint, naming the hook, the millisecond unit, and the cumulative-versus-per-query distinction shows you have used it rather than read about it.

  • A queue worker's whenQueryingForLongerThan() handler fired for the first job but never again. Is that a bug?
    In current Laravel the queue resets the connection's total query duration and re-arms the handlers after each processed job, so each job is measured separately. If yours stays silent, check whether the later jobs really exceeded the threshold, and whether they use a different connection than the one the handler was registered on.
  • Why might logging every query with bindings in production be a problem even if it is fast enough?
    Bindings carry the real values: emails, tokens, password hashes, personal data. Writing them to logs copies that data into systems with different access controls and retention. Log the SQL with placeholders, or redact sensitive bindings, and keep full-binding logging to local environments.

saying these in an interview costs you the question

  • Thinks QueryExecuted time is in seconds
  • Believes whenQueryingForLongerThan fires on every slow query
  • Registers DB::listen inside a controller action
  • Logs full bindings from every production query
  • Queries the database from inside the listener