Structured Logging in Depth: Levels, Context, and Rotation
Choose the correct PSR-3 log level for a given situation, configure Monolog to emit structured JSON logs with automatically-attached request context, understand how correlation/trace IDs thread through a request, and configure log rotation so log files never grow unbounded.
The 'Observability' lesson in this course introduced the three pillars (logs, metrics, traces), the four golden signals, and the basic idea of structured JSON logging with correlation IDs. This lesson goes deeper specifically on logging: how to pick the right severity level every time instead of guessing, how to configure a real JSON formatter and a processor that stamps context onto every line automatically, how request/correlation/trace IDs actually flow through a single request, and why log rotation is a boring-sounding topic that causes very real production incidents when ignored.
The PSR-3 Log Levels and When to Use Each
PSR-3 (the PHP-FIG interface most PHP logging libraries, including Monolog, implement) defines eight severity levels, ordered from least to most severe: debug, info, notice, warning, error, critical, alert, and emergency. Picking the right one consistently is what makes a log stream searchable and alertable later — if everything is logged at 'error', nobody can tell a real outage from routine noise, and if everything is 'info', real errors get lost in volume.
debug is for fine-grained diagnostic detail useful only while actively developing or troubleshooting — a raw SQL query, a cache key being checked, the contents of a computed array. It should typically be disabled in production or sampled heavily, since it's the highest-volume level by far. info records normal, expected application events worth keeping a record of: a user logged in, an order was placed, a scheduled job started. notice sits between info and warning — a normal but noteworthy event, such as a deprecated API path being used with a working fallback, or a configuration value falling back to a default.
warning indicates something unexpected happened but the request or process still completed successfully — a retried HTTP call that eventually succeeded, a slow query that finished, a feature flag falling back to its off state because the flag service was unreachable. error means a specific operation failed and could not complete — a failed payment charge, an exception caught and handled gracefully, a single failed job in a queue. critical means a whole component or subsystem is broken — a database connection pool exhausted, a required third-party API entirely unreachable. alert means action must be taken immediately — data corruption detected, a security breach indicator. emergency means the system is completely unusable — total outage. In practice, most application code only ever needs four of the eight: debug, info, warning, and error; critical/alert/emergency are usually reserved for infrastructure-level or security-level conditions that page someone immediately.
• debug — verbose diagnostic detail, dev/troubleshooting only, usually off or sampled in production. • info — normal expected events worth recording (login, order placed). • notice — normal but noteworthy (deprecated path used, default value applied). • warning — unexpected but request/process still succeeded (retry succeeded, slow query). • error — a specific operation failed (payment failed, handled exception). • critical / alert / emergency — a subsystem is broken / immediate action needed / total outage — reserve for infra and security conditions that should page someone.
JSON Formatting and Context via a Processor
Monolog is the de facto standard logging library in the PHP ecosystem and is the underlying implementation most frameworks (Laravel, Symfony) use under their own logging facades. By default it formats a log line as plain text, but production systems almost always want JSON, because a JSON line is trivially parseable by a log aggregator (Elasticsearch, Loki, CloudWatch Logs Insights, Datadog) without brittle regex parsing. Monolog ships a JsonFormatter that turns each log record into a single JSON object per line — the message, level, timestamp, channel, and any context/extra data all become top-level or nested fields.
The mistake many teams make is attaching context — user ID, request ID, correlation ID — manually at every single call site: $logger->info('order placed', ['user_id' => $userId, 'request_id' => $requestId]). This works but is easy to forget, inconsistent across the codebase, and means anyone adding a new log call has to remember to thread the IDs through by hand. Monolog's answer is a processor: a callable registered once on the logger (or a handler) that runs on every single log record before it's formatted, and can inject fields into the record's extra array unconditionally. A correlation-ID processor reads the current request's ID (usually set once per request, early in the bootstrap, into a small request-context service or a static holder) and stamps it onto every record automatically — the call site ($logger->info('order placed')) stays clean, and the ID appears on every line without anyone having to remember it.
This separation matters at scale: a processor is written and tested once, and every future log call for the lifetime of the application benefits from it automatically, whereas manual context-passing is a policy that has to be re-enforced by code review forever and inevitably drifts.
• JsonFormatter (Monolog) — turns each record into one JSON object per line for aggregator ingestion. • Manual context per call site works but is easy to forget and inconsistent across a codebase. • A processor runs on every record automatically and injects fields (user ID, request ID) without touching call sites. • Register a processor once (on the logger or globally via pushProcessor) rather than repeating context at every log call.
How Correlation/Request/Trace IDs Thread Through a Request
A correlation ID (also called a request ID) is a unique identifier generated once, as early as possible in a request's lifecycle — ideally read from an inbound header if the caller already supplied one (so a chain of internal service calls shares a single ID), or generated fresh with a UUID if this is the entry point. That ID is then stored somewhere reachable for the rest of the request (a small singleton/service, a static property, or in frameworks, a request-scoped container binding) so every log line, every outbound HTTP call's headers, and every span created during that request can reference it.
In a distributed system this ID must propagate across service boundaries, not just within one process. The pattern is: read the ID from an inbound header if present (commonly X-Request-Id or X-Correlation-Id, or the trace ID embedded in a W3C traceparent header if using OpenTelemetry — see the 'Distributed Tracing: Spans in Depth' lesson for the full mechanics of traceparent), attach it to the logger's context for the current request, and forward it on every outbound call your service makes to another service, so that service can pick it up and continue the chain. The result is that a single JSON log query for one correlation ID, across every service's log stream, reconstructs the entire journey of one user request end to end — this is precisely what makes structured logging and distributed tracing complementary rather than redundant.
• Generate or extract the correlation ID as early as possible in the request lifecycle. • Prefer reusing an inbound ID (X-Request-Id, traceparent) over generating a new one, so a multi-service call chain shares one ID. • Store it request-scoped and attach it via a processor, not manual passing. • Forward it on every outbound call so downstream services continue the same chain.
Log Rotation: Size- and Time-Based
An application that logs to a plain file and never rotates it will, sooner or later, fill the disk — and a full disk on a production server is not a minor inconvenience, it typically also breaks anything else writing to that same volume (the database, temp files, session storage), turning a logging oversight into a full outage. Log rotation is the practice of periodically closing the current log file, renaming or compressing it, and starting a fresh one, optionally deleting or archiving files past a retention window.
There are two common rotation strategies. Size-based rotation rotates once a file reaches a configured size threshold (e.g. 100 MB), which bounds worst-case disk usage regardless of traffic volume but makes rotation timing unpredictable — useful for a service with bursty or unpredictable volume. Time-based rotation rotates on a fixed schedule (hourly, daily), which makes it easy to find 'yesterday's logs' by filename but doesn't protect against a sudden traffic spike filling the disk before the next scheduled rotation. Production systems often combine both: rotate daily, but also rotate early if the file exceeds a size cap.
In PHP, this is handled either by Monolog directly — RotatingFileHandler rotates by date and keeps a configurable number of days — or, more commonly in production, by the OS-level tool logrotate (on Linux) managing the file Monolog writes to via a StreamHandler, since logrotate also handles compression (gzip) of old files and can be configured once for every service on a box rather than per-application. Either way, unbounded log files are entirely preventable with a few lines of configuration, which is exactly why they remain a surprisingly common real-world incident — the fix is trivial, but it's easy to skip when a service is first stood up and only becomes an emergency months later once traffic has grown.
• Size-based rotation: rotate at a size threshold — bounds disk usage, timing is unpredictable. • Time-based rotation: rotate on a schedule (daily/hourly) — predictable filenames, no protection against spikes. • Production often combines both, and compresses/deletes files past a retention window. • PHP options: Monolog's RotatingFileHandler, or (more common) OS-level logrotate managing a StreamHandler's output file. • An unbounded log file can fill the disk and take down unrelated services on the same volume — treat rotation as mandatory, not optional.
Code Examples
RotatingFileHandler rotates the log file daily and keeps 14 days of history automatically; JsonFormatter emits one JSON object per line; the pushProcessor callback stamps request_id and user_id onto every single record without any call site having to pass them explicitly. Expected result: {"message":"order placed","context":{"order_id":4821,"total":59.99},"level":200,"level_name":"INFO","channel":"app","datetime":"2026-09-20T14:02:11.000000+00:00","extra":{"request_id":"a1b2c3d4e5f60718","user_id":42}}
$logger->pushProcessor(function (array $record): array { ... });
The exact same underlying failure (a timeout) is logged as a warning while retries can still succeed, and only escalates to error once retries are exhausted and the operation has genuinely failed — this is the kind of judgment call PSR-3 levels exist to make consistent across a codebase.
$logger->error('user viewed profile page');
$logger->info('user viewed profile page');
Nothing failed here — this is a routine, expected event. Logging it at 'error' trains everyone to ignore the error channel because it's full of non-errors, which is exactly how real errors get missed.
$logger->info('order placed', ['user_id' => $uid, 'request_id' => $rid]); // ...repeated at every single call site across the codebase
$logger->pushProcessor(fn($r) => [...$r, 'extra' => [...$r['extra'], 'user_id' => $uid, 'request_id' => $rid]]); $logger->info('order placed');
Passing the same context manually at every call site is inconsistent by nature — someone will eventually forget it on a new log line. A processor guarantees every record gets the context, with zero per-call-site effort.
// StreamHandler writing to app.log forever, no rotation configured
// RotatingFileHandler, or a StreamHandler + logrotate config with size/time limits and compression
A log file with no rotation grows without bound; eventually it fills the disk, which can take down the database or other services sharing that volume, not just logging.
An outbound HTTP call times out but succeeds on a retry one second later. Which PSR-3 level best fits the initial timeout? A. debug B. warning C. critical D. emergency
B. warning — The request ultimately succeeded, but something unexpected happened along the way — that's exactly what 'warning' is for. 'critical'/'emergency' are reserved for broken subsystems or total outages, not a single retried call.
Why attach the correlation ID via a Monolog processor instead of passing it manually to every log call? A. Processors run faster than passing an array argument B. A processor guarantees every record gets the context automatically, so it can never be forgotten at a new call site C. Manual context passing is not supported by JsonFormatter D. Processors are required for PSR-3 compliance
B. A processor guarantees every record gets the context automatically, so it can never be forgotten at a new call site — A processor runs on every record pushed through the logger, so context like the correlation ID is attached consistently everywhere without relying on every developer remembering to pass it by hand.
What is the main downside of pure time-based (e.g. daily) log rotation on its own? A. It cannot compress old files B. It makes finding 'yesterday's logs' harder C. A sudden traffic spike can fill the disk before the next scheduled rotation D. It is not supported by Monolog
C. A sudden traffic spike can fill the disk before the next scheduled rotation — Time-based rotation only rotates on a schedule, so it provides no protection against a burst of traffic filling the disk between scheduled rotations — which is why production setups often add a size cap as well.
<?php
declare(strict_types=1);
use Monolog\Logger;
use Monolog\Handler\RotatingFileHandler;
use Monolog\Formatter\JsonFormatter;
use Monolog\Level;
// A tiny request-scoped holder for the correlation ID. In a real app this
// would be set once, in middleware/bootstrap, reading an inbound header
// if present and generating a UUID otherwise.
final class RequestContext
{
private static ?string $correlationId = null;
public static function set(string $id): void
{
self::$correlationId = $id;
}
public static function id(): string
{
return self::$correlationId ??= bin2hex(random_bytes(8));
}
}
$logger = new Logger('app');
$handler = new RotatingFileHandler(__DIR__ . '/logs/app.log', maxFiles: 14, level: Level::Debug);
$handler->setFormatter(new JsonFormatter());
$logger->pushHandler($handler);
// Runs on EVERY record pushed through this logger, so call sites never
// need to remember to pass user_id / request_id themselves.
$logger->pushProcessor(function (array $record): array {
$record['extra']['request_id'] = RequestContext::id();
$record['extra']['user_id'] = $_SESSION['user_id'] ?? null;
return $record;
});
// Somewhere
…<?php
try {
$result = $httpClient->post('/charge', $payload);
} catch (TimeoutException $e) {
if ($attempt < $maxAttempts) {
$logger->warning('charge request timed out, retrying', ['attempt' => $attempt]);
// ...retry...
} else {
$logger->error('charge request failed after all retries', ['attempts' => $maxAttempts]);
throw $e;
}
}