Package · logger

Log record lifecycle

Follow a single $log->info(…) from the call site to the byte on the stream. Knowing the order — especially where processors run — explains behaviour that’s otherwise surprising, like which fields get masked.

The path

text

your call  $log->info('msg', ['id' => 42])
  │
  ▼
Winter Logger::log()      merge boundContext (['class' => FQCN]) under the call's context
  │
  ▼
Monolog Logger::addRecord level check → build LogRecord(context, extra={})
  │
  ▼
processors (LIFO)         run in reverse push order:
  │                       1. SensitiveMaskingProcessor  (if added by app)
  │                       2. ContextInjectingProcessor  (added by the manager)
  ▼
handler (level check)     SafeStreamHandler / Syslog / RotatingFile / Null
  │
  ▼
formatter                 SpringLineFormatter or JsonFormatter
  │
  ▼
write                     @fwrite(stream, formatted)  — never throws

Step 1 — Bound context is merged first

Winter’s Logger::log() merges its boundContext into the call’s context before handing off to Monolog. For a per-class logger, boundContext is ['class' => FQCN]; withContext() adds more. The call’s own context wins on a key clash:

php

public function log(mixed $level, string|Stringable $message, array $context = []): void
{
  $this->monolog->log(
      $level,
      (string) $message,
      empty($this->boundContext) ? $context : array_merge($this->boundContext, $context),
  );
}

So by the time Monolog sees the record, context already carries class (and any bound fields). extra is still empty — it gets filled by a processor next.

Step 2 — Processors run in LIFO order

This is the part worth internalizing. Monolog’s pushProcessor() prepends to the processor list (array_unshift), and addRecord() iterates that list front-to-back. The net effect: the last processor pushed runs first.

The manager pushes ContextInjectingProcessor when it builds the channel. If your app later adds SensitiveMaskingProcessor via monolog()->pushProcessor(), that one was pushed later — so it runs first:

text

push order:   ContextInjecting (by manager)  →  Masking (by app)
run order:    Masking  →  ContextInjecting

SensitiveMaskingProcessor redacts sensitive keys in context and extra.
ContextInjectingProcessor then merges the current context-storage snapshot into extra (early-exiting when storage is empty).

Masking runs before context injection

Because masking runs first, it sees the per-call context (already populated) but not the request-context fields — those are injected into extra afterward. Secrets passed directly in a log call are masked; a secret set via contextStorage()->set() would be injected after masking and slip through. Keep secrets out of request-context storage.

Step 3 — Level filtering happens twice

The level is checked at the Monolog logger (against nothing — Monolog passes everything to handlers) and then at the handler, which was built with the channel’s level. A record below the channel’s minimum level is dropped by the handler before formatting. This is why level lives in the channel config, not the call.

Step 4 — Formatting

The handler’s formatter turns the LogRecord into a string. SpringLineFormatter merges context + extra into the JSON tail, pulls the short class name from context['class'], and stamps the PID via getmypid(). JsonFormatter emits one JSON object per line instead.

Step 5 — The safe write

For stream outputs the handler is SafeStreamHandler, whose streamWrite() uses @fwrite and never throws — so a broken pipe costs one line, not the process. Syslog, file, and null handlers take their own final step.

Why the order matters in practice

class is always present for per-class loggers — it’s merged at step 1, before anything else can touch it.
Request context is per-line, live — it’s read fresh at step 2 on every record, so changing it mid-request changes subsequent lines.
Mask what you pass, not what you inject — the LIFO order means masking and injection don’t compose the way you might assume.