Structured Logging — Finding the Bug at 2am

Reading Time: 4 minutes

Series: Every Laravel Project Should Have These Building Blocks 
Part: 19 of 35 Level: Intermediate Prerequisites: App Service Provider

---

What You’ll Learn

• Why structured logging matters (and what it means)
• Named log channels — one concern per channel
• The RequestLogger middleware — full request lifecycle logging
• The ErrorReporter — rate-limited exception emails
• Slow query detection and logging
• How the X-Request-ID ties everything together

---

Why Logging Is an Architectural Decision

Most Laravel projects use one log file: storage/logs/laravel.log. Everything goes in there — exceptions, emails, slow queries, requests, scheduled commands. After a few months of production, debugging means searching through a wall of text where every line looks equally important.

Good logging is:

• Structured — machine-parseable JSON, not free-form strings
• Channeled — separate concerns in separate files
• Contextual — every log entry includes enough data to understand what happened
• Linked — related events can be traced together

---

Named Log Channels

The first change to make: create dedicated channels per concern.

// config/logging.php
'channels' => [
    'stack' => [
        'driver'   => 'stack',
        'channels' => ['single'],
    ],

    'single' => [
        'driver' => 'single',
        'path'   => storage_path('logs/laravel.log'),
        'level'  => env('LOG_LEVEL', 'debug'),
    ],

    // One channel per concern:
    'request' => [
        'driver' => 'daily',
        'path'   => storage_path('logs/request.log'),
        'level'  => 'debug',
        'days'   => 30,
    ],

    'error' => [
        'driver' => 'daily',
        'path'   => storage_path('logs/error.log'),
        'level'  => 'error',
        'days'   => 90,
    ],

    'query' => [
        'driver' => 'daily',
        'path'   => storage_path('logs/query.log'),
        'level'  => 'debug',
        'days'   => 7,
    ],

    'mail' => [
        'driver' => 'daily',
        'path'   => storage_path('logs/mail.log'),
        'level'  => 'info',
        'days'   => 30,
    ],

    'heartbeat' => [
        'driver' => 'daily',
        'path'   => storage_path('logs/heartbeat.log'),
        'level'  => 'info',
        'days'   => 14,
    ],
],

Now instead of one 500MB log file, you have targeted files. When investigating a slow query, you open query.log. When checking queue health, heartbeat.log. When investigating a user-reported error, request.log + error.log.

---

The RequestLogger Middleware

This is the most powerful observability tool in the stack. Every HTTP request gets:

• A unique X-Request-ID header
• A full log entry (method, URL, user, duration, response status)
• A database record (request_logs table) for cross-referencing with model changes

// app/Http/Middleware/RequestLogger.php
<?php

declare(strict_types=1);

namespace App\Http\Middleware;

use App\Models\RequestLog;
use Closure;
use Illuminate\Http\Request;
use Illuminate\Http\Response;
use Illuminate\Support\Facades\Log;
use Illuminate\Support\Str;
use Symfony\Component\HttpFoundation\Response as SymfonyResponse;

class RequestLogger
{
    public const X_REQUEST_ID = 'X-Request-ID';

    public function handle(Request $request, Closure $next): SymfonyResponse
    {
        // Generate or propagate a request ID
        $requestId = $request->header(self::X_REQUEST_ID) ?? (string) Str::uuid();
        $request->headers->set(self::X_REQUEST_ID, $requestId);

        $startTime = microtime(true);

        $response = $next($request);

        $duration = round((microtime(true) - $startTime) * 1000, 2); // ms

        // Add the ID to the response so clients can reference it
        $response->headers->set(self::X_REQUEST_ID, $requestId);

        $this->logRequest($request, $response, $requestId, $duration);

        return $response;
    }

    private function logRequest(
        Request $request,
        SymfonyResponse $response,
        string $requestId,
        float $durationMs
    ): void {
        $context = [
            'request_id'  => $requestId,
            'method'      => $request->method(),
            'url'         => $request->fullUrl(),
            'status'      => $response->getStatusCode(),
            'duration_ms' => $durationMs,
            'ip'          => $request->ip(),
            'user_id'     => auth()->id(),
            'user_type'   => $this->resolveGuard(),
        ];

        Log::channel('request')->info('Request', $context);

        // Persist to database for cross-referencing with ModelChangeLog
        RequestLog::create([
            'request_id'  => $requestId,
            'method'      => $request->method(),
            'url'         => $request->fullUrl(),
            'status_code' => $response->getStatusCode(),
            'duration_ms' => $durationMs,
            'ip_address'  => $request->ip(),
            'user_id'     => auth()->id(),
            'user_type'   => $this->resolveGuard(),
        ]);
    }

    private function resolveGuard(): ?string
    {
        foreach (['admin', 'merchandiser', 'web'] as $guard) {
            if (auth($guard)->check()) {
                return $guard;
            }
        }
        return null;
    }
}

Register it globally in bootstrap/app.php (Laravel 11):

->withMiddleware(function (Middleware $middleware): void {
    $middleware->append(RequestLogger::class);
})

---

What the X-Request-ID Unlocks

Every log entry in every channel can include the X-Request-ID:

// In ErrorReporter
Log::channel('error')->error('Exception', [
    'request_id' => request()->header(RequestLogger::X_REQUEST_ID),
    'exception'  => $e::class,
    'message'    => $e->getMessage(),
    'trace'      => $e->getTraceAsString(),
]);

// In ModelChangeLogger
ModelChangeLog::create([
    ...
    'request_id' => request()->header(RequestLogger::X_REQUEST_ID),
]);

// In any service or action:
logger()->info('Processing payment', [
    'request_id' => request()->header(RequestLogger::X_REQUEST_ID),
    'order_id'   => $order->id,
    'gateway'    => $gateway::class,
]);

Now when a user reports “something went wrong at 14:32”, you:

1. Find the RequestLog row for that URL at that time
2. Get the request_id
3. Search all log files for that request_id
4. Find all ModelChangeLog records with that request_id

You have the complete picture of what happened during that request.

---

The ErrorReporter

The ErrorReporter is in Services/Core/ and handles exception notification with rate limiting:

// app/Services/Core/ErrorReporter.php
final class ErrorReporter
{
    /**
     * @return array<string>
     */
    private static function validRecipients(): array
    {
        $recipients = config('app.error_report_emails', []);
        return array_filter($recipients, fn ($email) => filter_var($email, FILTER_VALIDATE_EMAIL));
    }

    public static function report(Throwable $e): void
    {
        $recipients = self::validRecipients();
        if ($recipients === []) {
            return;
        }

        // Rate limit: don't send the same exception more than once per 5 minutes
        $key = 'exception:' . hash('sha256', $e::class . $e->getMessage() . $e->getFile());

        if (! Cache::add($key, true, now()->addMinutes(5))) {
            return; // already reported this exception recently
        }

        Log::channel('error')->error('Exception reported', [
            'class'       => $e::class,
            'message'     => $e->getMessage(),
            'file'        => $e->getFile(),
            'line'        => $e->getLine(),
            'request_id'  => request()->header(RequestLogger::X_REQUEST_ID),
            'url'         => request()->fullUrl(),
            'user_id'     => auth()->id(),
        ]);

        Mail::to($recipients)->send(new ExceptionOccurred($e));
    }
}

Wire it up in the exception handler:

// bootstrap/app.php (Laravel 11)
->withExceptions(function (Exceptions $exceptions): void {
    $exceptions->report(function (Throwable $e): void {
        if (app()->isProduction()) {
            ErrorReporter::report($e);
        }
    });
})

Cache::add() is the key: it only sets the key if it doesn’t exist yet. If the same exception fires 100 times in 30 seconds, only the first email goes out.

---

Slow Query Detection

Register a DB::listen() callback in AppServiceProvider::boot():

// In AppServiceProvider::boot():
if (! app()->isProduction()) {
    return; // Only log slow queries in production
}

DB::listen(function (QueryExecuted $query): void {
    $thresholdMs = config('database.slow_query_threshold_ms', 1000);

    if ($query->time < $thresholdMs) {
        return;
    }

    Log::channel('query')->warning('Slow query detected', [
        'sql'         => $query->sql,
        'bindings'    => $query->bindings,
        'duration_ms' => $query->time,
        'connection'  => $query->connectionName,
        'request_id'  => request()->header(RequestLogger::X_REQUEST_ID),
        'url'         => request()->fullUrl(),
    ]);
});

Set the threshold in .env:

DB_SLOW_QUERY_THRESHOLD_MS=500

And in config/database.php:

'slow_query_threshold_ms' => env('DB_SLOW_QUERY_THRESHOLD_MS', 1000),

Every query over 500ms gets logged to query.log with the full SQL, bindings, and the URL that triggered it.

---

Key Takeaways

• Named log channels (request, error, query, mail, heartbeat) replace one monolithic log file with targeted, searchable files.
• The RequestLogger middleware gives every request a unique ID, logs timing and status, and persists a DB record.
• X-Request-ID flows through every log entry — it’s the thread that connects a user report to a specific request, model changes, and exceptions.
• ErrorReporter uses Cache::add() to rate-limit duplicate exception emails: one email per exception type per 5 minutes.
• Slow query detection via DB::listen() catches N+1 and expensive queries automatically.

---

Tips and Gotchas

⚠️ Warning: Never log passwords, tokens, card numbers, or PII. Once something is in a log file, it persists — log rotation doesn’t retroactively remove sensitive data from backups, log aggregators, or SIEM systems. Sanitize before you log.

💡 Tip: Use Log::withContext(['order_id' => $order->id]) to temporarily enrich all log entries within a specific scope (a job’s handle() method, a service method). Unlike Log::shareContext(), withContext() doesn’t persist across the full request.

🔥 Expert Note: JSON-formatted log output ('formatter' => Monolog\Formatter\JsonFormatter::class) makes logs machine-parseable. Log aggregators (Datadog, Papertrail, Logtail) ingest JSON natively — every key becomes a searchable field. Plain text logs require fragile regex parsing.

Further Reading

• Laravel Docs: Logging
• Monolog — the underlying logging library; Laravel wraps it
• Laravel Docs: Log Channels
• Logtail / Datadog — production log aggregation platforms

---

← HeartBeat Job | Next: Events and Listeners →