Profiling a Slow PHP Endpoint With Laravel Debugbar and Clockwork: A Real Walkthrough

A dashboard endpoint that had always felt "a bit slow" crossed into "someone actually filed a complaint" territory once a customer's account had enough historical data to make the problem impossible to ignore — 3.8 seconds to load a page that should have been near-instant. Here's the actual profiling session, using both Debugbar and Clockwork side by side, down to the specific query that turned out to be the problem.

Setting up both tools

composer require barryvdh/laravel-debugbar --dev
composer require itsgoingd/clockwork --dev

Both are safe to install as dev dependencies only — neither ships to production by default, and Debugbar specifically checks APP_DEBUG before rendering anything, which matters, because a profiling toolbar accidentally left active in production is both a performance cost and a real information disclosure risk, exposing query details and internal paths to anyone who loads the page.

First look: Debugbar's query count told the obvious part of the story

Loading the dashboard with Debugbar active immediately surfaced the headline number: 214 database queries for a single page load. That number alone doesn't diagnose anything, but it's an unmissable signal that something is fetching data in a loop rather than in bulk — a well-optimized dashboard page has no business running over two hundred separate queries.

// Debugbar's Queries tab showed a repeating pattern:
select * from `projects` where `id` = ? limit 1     (34ms)
select * from `projects` where `id` = ? limit 1     (29ms)
select * from `projects` where `id` = ? limit 1     (31ms)
// ... repeated 47 more times, each with a different bound ID

Forty-nine nearly identical queries, each fetching a single project by ID, one row at a time — this is the textbook signature of an N+1 query problem: one query to fetch a list, then N additional queries fetching a related record for each item in that list, one at a time, instead of a single query fetching all the related records at once.

Finding the actual line: Clockwork's timeline view

Debugbar's query list showed what was happening. Clockwork's timeline view, which breaks down time spent by request lifecycle phase alongside a stack trace for each query, showed exactly where in the code each of those 49 queries originated:

// Clockwork query detail, showing the originating call
Query: select * from `projects` where `id` = ? limit 1
Time: 31ms
Origin: app/Http/Controllers/DashboardController.php:42
        -> app/Models/Task.php:18 (relationship accessor: project())

The stack trace pointed directly at line 42 of the dashboard controller, inside a loop iterating over the current user's tasks and accessing each task's project relationship one at a time:

public function index()
{
    $tasks = Task::where('user_id', auth()->id())->get();

    $summaries = $tasks->map(function ($task) {
        return [
            'title' => $task->title,
            'project_name' => $task->project->name, // triggers a query, once per task
            'due_date' => $task->due_date,
        ];
    });

    return view('dashboard', compact('summaries'));
}

Every call to $task->project inside the map() callback lazily triggers a fresh database query the first time it's accessed on that specific model instance, because Eloquent relationships load lazily by default — the framework has no way to know, from inside the loop, that you're about to ask for the same kind of related data 49 more times, so it fetches one at a time, exactly as asked.

The fix: eager loading

public function index()
{
    $tasks = Task::where('user_id', auth()->id())
        ->with('project') // eager load in one additional query, not N
        ->get();

    $summaries = $tasks->map(function ($task) {
        return [
            'title' => $task->title,
            'project_name' => $task->project->name, // no query here now — already loaded
            'due_date' => $task->due_date,
        ];
    });

    return view('dashboard', compact('summaries'));
}

with('project') tells Eloquent to fetch every task's related project in a single additional query — using a WHERE id IN (...) clause against all the project IDs referenced by the loaded tasks — rather than one query per task. The query count dropped from 214 to 9 on the same page load, and total response time dropped from 3.8 seconds to 340 milliseconds, an order-of-magnitude difference from a one-line change.

What was in the other 165 queries, and why eager loading alone wasn't enough

Fixing the project relationship dropped the query count from 214 to roughly 49 — the project queries were 49 of the total, but there were more N+1 patterns stacked on top of each other in the same loop, each contributing its own batch. A second, near-identical pattern was loading each task's assigned user one at a time, and a third was checking each task's comment count individually:

$tasks = Task::where('user_id', auth()->id())
    ->with(['project', 'assignedUser'])
    ->withCount('comments') // adds comment_count without a separate query per task
    ->get();

withCount() is the specific tool for the comment-count case — rather than loading every comment for every task just to count them, it adds a single subquery-based count column to the original query, which is both faster and lighter than eager-loading the full comments relationship just to call ->count() on it per task afterward.

Why the endpoint had been "a bit slow" for a long time before anyone noticed

The reason this went unnoticed for so long is itself worth naming: the N+1 pattern's cost scales directly with the number of tasks a user has, and most accounts used during development and QA had a handful of test tasks — five or ten — where 214 queries collapses down to something like 15, fast enough that nobody would think to check. The customer who filed the complaint had several hundred tasks accumulated over months of real use, which is exactly the kind of data-scale difference between a test environment and a real one that N+1 problems are notorious for hiding behind, invisible until an account's data grows past whatever size the team happened to be testing with.

Debugbar vs. Clockwork: what each one was actually better at in this session

• Debugbar's strength here: the query count badge in the toolbar is an immediate, impossible-to-miss signal — you don't have to go looking for a problem, it's visibly wrong the moment the page loads.
• Clockwork's strength here: the per-query stack trace pointing at the exact originating line saved real time — without it, tracing 49 identical queries back to one specific loop would have meant manually searching the codebase for every place a ->project access could occur.
• Using both together wasn't redundant in this session — Debugbar caught the "something's wrong" signal fast, Clockwork answered "where exactly" faster than reading through controller code cold would have.

A guardrail to catch the next one automatically

Manual profiling caught this instance. Preventing the next one from shipping unnoticed is a different problem, and the practical fix was adding a strict-mode setting that throws an exception in local and CI environments — never in production — the moment lazy loading is triggered anywhere in the request:

// AppServiceProvider::boot()
Model::preventLazyLoading(! app()->isProduction());

With this enabled, any future N+1 pattern fails loudly in local development and in CI test runs the moment it's introduced, rather than shipping silently and waiting for a customer with enough data to notice. This is a genuinely cheap guardrail for the entire category of bug this walkthrough is about, not just the specific instance found here.

If profiling tools like these are new to your workflow generally, they pair naturally with the debugging techniques in a real Xdebug session finding an off-by-one bug — Xdebug for tracing incorrect logic step by step, Debugbar and Clockwork for measuring where time and queries actually go once the logic is correct but slow.

A second pass: the remaining 340 milliseconds

Fixing the N+1 patterns got the endpoint to 340 milliseconds, which was fast enough that nobody pushed further at the time — but revisiting the same page a few weeks later with Clockwork's timeline view specifically to look for anything else worth trimming turned up a second, smaller issue: roughly 80 of those 340 milliseconds were spent in a view-rendering step recalculating the same date formatting logic for every row in the dashboard table, using a locale-aware formatter that wasn't being cached across calls within the same request.

// Before: a fresh, locale-aware formatter instantiated on every call
@foreach ($summaries as $summary)
    {{ Carbon::parse($summary['due_date'])->translatedFormat('D, M j') }}
@endforeach

// After: format once, reuse — or better, do it in the controller
// so the view has no formatting logic to repeat at all
$summaries = $tasks->map(fn ($task) => [
    'title' => $task->title,
    'project_name' => $task->project->name,
    'due_date_formatted' => $task->due_date->translatedFormat('D, M j'),
]);

Moving the formatting into the controller, computed once per row rather than left for the view to recompute (and in this case, computed using a formatter that had to reload locale data internally on each call), trimmed those 80 milliseconds. Small compared to the original N+1 fix, and worth doing anyway — it's a reminder that profiling is rarely a one-shot exercise where a single big fix resolves everything; the first pass catches the dominant cost, and a second look, once that dominant cost is gone, often surfaces a smaller one that was previously too small to notice against the original 3.8-second baseline.

Making this repeatable instead of a one-time investigation

The specific N+1 bug got fixed, and the strict lazy-loading guardrail mentioned above prevents that specific category from recurring silently — but neither of those catches a future regression in raw response time from an unrelated cause: a new feature added to the same dashboard, a third-party API call added to the request path, a slow view partial nobody profiled. Adding a lightweight response-time log specifically for this endpoint, checked against a fixed threshold, catches that broader category without requiring anyone to remember to profile manually again:

class LogSlowDashboardRequests
{
    public function handle(Request $request, Closure $next)
    {
        $start = microtime(true);
        $response = $next($request);
        $durationMs = (microtime(true) - $start) * 1000;

        if ($durationMs > 1000) {
            Log::warning("Slow dashboard request: {$durationMs}ms", [
                'user_id' => $request->user()?->id,
            ]);
        }

        return $response;
    }
}

A 1-second threshold is generous relative to the 340ms baseline established above, deliberately — it's meant to catch a genuine regression, not to fire on ordinary variance, and setting a threshold too close to the measured baseline just produces noise that eventually gets ignored. The actual value of a check like this isn't catching every possible slowdown — it's making sure the next N+1-shaped regression gets caught by an automated log line instead of waiting for a customer with enough data to notice and complain, the same way the original one was found.