skip to content

In a Laravel checkout, a trace id set with Log::withContext() appears in request logs but not in logs of the queued jobs it dispatches. Why, and how do you fix it?

level: seniorimportance: must knowfreq 40%

answer

  1. withContext lives in the web process
  2. Context::add in a middleware
  3. payload key illuminate:log:context
  4. hydrated on JobProcessing, before handle
  5. captured at dispatch time, not later

basics

~20 s

Log::withContext() only changes the web process's logger; the job runs later in a worker with a fresh one. Put the id in the Context facade instead: Laravel serialises Context into each job payload and restores it before the job runs.

solid answer

~40 s

`Log::withContext()` stores data on an in-memory `Logger` in the web process, and the job runs later in a queue worker that never saw it (the worker even clears log context between jobs). The fix is `Context::add('trace_id', $id)` in a middleware. The framework's `ContextServiceProvider` registers a `Queue::createPayloadUsing()` hook that dehydrates the current Context into the job payload under `illuminate:log:context`, and a `JobProcessing` listener hydrates it back before `handle()` runs. A log processor then appends `Context::all()` to every record's `extra`, so the payment and receipt jobs log the same `trace_id`, and jobs they dispatch carry it on. Context is captured at dispatch, so values added after `dispatch()` do not reach that job.

code

php · 19 lines
php
<?php

namespace App\Http\Middleware;

use Closure;
use Illuminate\Http\Request;
use Illuminate\Support\Facades\Context;
use Illuminate\Support\Str;
use Symfony\Component\HttpFoundation\Response;

class TraceCheckout
{
    public function handle(Request $request, Closure $next): Response
    {
        Context::add('trace_id', $request->header('X-Trace-Id') ?? (string) Str::uuid());

        return $next($request);
    }
}

go deeper

for a junior

Know that a queued job runs later in another process, so it does not share the request's in-memory logger, and that the Context facade exists to carry values across.

for a middle

Explain the dehydrate-into-payload and hydrate-on-JobProcessing cycle, the illuminate:log:context key, and why the trace id shows up in extra.

for a senior

Cover the timing rule at dispatch, chained propagation, model re-querying and deleted-model reports, and how to wire one trace id across web, worker and downstream services.

for a principal

Decide on one correlation convention across services, including accepting an inbound trace header, and weigh Context's convenience against a full tracing system.

## Why the id disappears A Laravel web request and a queued job are **separate executions**. `ChargeOrder::dispatch($order)` serialises the job into a payload and stores it on the queue connection (the `database` queue in the skeleton). Later a `queue:work` process, a different PHP process with its own application instance, pulls the payload and runs `handle()`. `Log::withContext()` stores its array on the `Logger` object for the default channel **inside the web process**. Nothing copies that object into the payload. On top of that, the worker's reset callback runs `Log::flushSharedContext()` and `Log::withoutContext()` before each job, so even context a previous job set is gone. The job's log lines therefore carry only what the job itself adds. ## The Context facade Laravel's **Context** (`Illuminate\Support\Facades\Context`, backed by `Illuminate\Log\Context\Repository`) is a request- or job-scoped key-value store that is wired into both logging and the queue: - the repository is registered as a **scoped** binding, so each request, and each job in a worker, starts with an empty one; - the log manager pushes a `ContextLogProcessor` onto every Monolog channel it builds; the processor appends `Context::all()` to each record's **`extra`** part; - `ContextServiceProvider::boot()` registers `Queue::createPayloadUsing()`, which calls `Context::dehydrate()` and adds the result to the payload under the key `illuminate:log:context`; - the same provider listens for `JobProcessing` and calls `Context::hydrate()` with that payload key before the job's `handle()` method runs. Because the hook sits on the queue payload, it covers everything that is queued: jobs, queued listeners, queued mail and queued notifications. ## Tracing one checkout end to end 1. A middleware on the checkout routes calls `Context::add('trace_id', (string) Str::uuid())`. 2. The controller logs `Log::info('Checkout started.', ['cart_id' => $cart->id])`; the line ends with `{"trace_id":"…"}` in the extra slot. 3. The controller dispatches `ChargeOrder`. The payload now contains the serialised trace id. 4. The worker hydrates Context, so `ChargeOrder`'s log lines show the same `trace_id`. 5. `ChargeOrder` dispatches `SendReceipt`. Context is dehydrated again from the worker's hydrated copy, so the receipt job carries the id too. Searching the log store for one `trace_id` now returns the request and every job in the chain. ## Timing and serialisation rules | Situation | What the job sees | |---|---| | `Context::add()` before `dispatch()` | the value | | `Context::add()` after `dispatch()` | nothing; the payload was already built | | an Eloquent model in Context | re-queried by id when hydrated, without relations | | that model deleted before the job runs | `ModelNotFoundException` is reported and the value becomes `null` | | a value PHP cannot `serialize()`, such as a closure | dispatch fails while building the payload | `Context::handleUnserializeExceptionsUsing()` lets you replace the default handling of values that fail to unserialise. ## Other Context tools that help tracing - `Context::push('breadcrumbs', 'cart.validated')` appends to a list, giving an ordered trail; it throws a `RuntimeException` if the key already holds a non-list value. - `Context::scope(fn () => ..., data: ['step' => 'charge'])` adds keys only while the callback runs and restores the previous state afterwards, even if it throws. - `Context::addIf()` sets a key only when it is absent, which suits shared code that runs both in requests and in jobs: it creates a trace id only when none was propagated. ## Reading Context back in application code Context is not only for logs. Code running in the request or in the job can read it: - `Context::get('trace_id')` returns the value or `null`; `Context::has()` is `true` even for a stored `null`, while `Context::missing()` is its negation; - the global `context('trace_id')` helper does the same, and `context(['k' => 'v'])` adds values; - a constructor or method parameter marked `#[Context('trace_id')]` is filled by the container, which keeps services testable; - an outbound HTTP call can forward the id in a header so a downstream service logs the same value. ## Why not job middleware? The logging docs mention job middleware for sharing log context in jobs. That works, but each job class must opt in and something must still carry the value across. Context does both automatically, and application code can read it back with `Context::get()` or the `#[Context('trace_id')]` container attribute.

  • In the log line, why does the trace id appear in a second JSON object rather than next to order_id?
    The per-call array and `withContext()` data go into the Monolog record's `context` part. Context facade data is added by `ContextLogProcessor` to the record's `extra` part. The default line format prints `%context% %extra%`, so they appear as two JSON objects, and a JSON formatter writes them as separate `context` and `extra` keys.
  • A job needs a value from the request that must not appear in logs. What changes?
    Store it with `Context::addHidden()` and read it with `Context::getHidden()`. Hidden context is dehydrated into the payload and hydrated in the worker like normal context, but the log processor only appends `Context::all()`, which excludes hidden data. It is still stored unencrypted in the payload, so it is not a vault for secrets.
  • Under Octane, could one request's trace id leak into the next request's logs?
    Not through Context: the repository is a scoped binding, and scoped instances are forgotten between requests, so each request starts empty. Log channel context is flushed by Octane's `FlushLogContext` listener. A leak would come from your own singleton holding the id.

Context works like the tag an airline staples to a checked bag: whatever is written on it at check-in travels with the bag to every connecting flight, while notes you scribble on your boarding pass afterwards never reach the bag. Log::withContext() is the boarding pass; Context::add() before dispatch() is the tag.

saying these in an interview costs you the question

  • Log::withContext() data is serialised into jobs dispatched afterwards.
  • Context added after dispatch() still reaches the already queued job.
  • Context data is written into the record's context part beside per-call keys.
  • Every job class must use a trait to receive Context.
  • An Eloquent model in Context is restored as a stale snapshot of its attributes.