Logging with Monolog in Symfony2

The official points of reference for Monolog & Symfony2 are:

• The Symfony Cookbook entry about writing logs with Monolog
• The Monolog configuration reference
• How to change channel definitions
• How to inject a logging instance and channel into a service
• The Monolog readme-file

Monolog's general architecture

Let's start by throwing a glance at the main concepts.

• Clients send their log messages to a Logger instance (interface). Different clients (e.g. subsystems of an application) can use different instances, which is why Loggers are also called channels. The name of a channel is the first parameter $name in the Logger's constructor.
• The Logger creates a Record for each log message and passes it to each connected Handler. Technically, the Record is just an array.
• Handlers encapsulate the various ways of Record processing (e.g. create log files, log to syslog, send mails)
• Each Handler uses exactly one Formatter which converts the Record to a particular output format - that is, into the string that is finally written or otherwise processed by the Handler. The default formatter is the LineFormatter.
• Loggers as well as Handlers can have a set of Processors. All Records that pass through a Logger and/or Handler will be sent to the respective Processors. The Processors might alter the record, but in most cases they just add additional data to it.

Among others, Records have two properties context and extra:

• context collects data about the message and is a concept from PSR-3. The idea is that a log message may contain placeholders like "{someprop}" that may be replaced with corresponding values from thecontext. Some handlers can benefit from separating the message (as a meaningful string) and context data (event related details).
• extra is used for unspecified additional information, usually added by Processors.

The default output formats place the context and extra fields as JSON-encoded strings after the log message, so "[]" denotes empty fields (you will see this quite often).

Symfony2 integration via MonologBundle

Creation and injection of loggers

The MonologBundle provides a default logger instance named monolog.logger alias logger in the DIC. This logger forms the "app"-channel and you can inject it into other services as usual.

If, in addition, you tag your own (client) service with monolog.logger, you can choose the Logger instance to be injected by using the tag's channel attribute. If a channel name other than the default "app" is used,

• a Logger instance will be created (if necessary) and injected,
• be given that channel name and
• registered as service monolog.logger.[channelname].

Unless configured otherwise and as described in the following section, all handlers will be subscribed to and process all channels.

Giving a channel a meaningful name alone will improve log message readability. But separate channels are also useful for tracking and separating events of different subsystems. Also, they make it possible to apply different handler configurations later on.

Creation of handlers

Loggers (channels) are created according to the monolog.logger tags which are distributed over many places in the various container definition files.

Handlers, in contrast, are specified by the bundle configuration of the MonologBundle. They are created as services called monolog.handler.[name] with name referring to the section of the configuration that describes the handler.

Some configuration properties that apply to all available types of handlers are:

• level: Log level of the handler. Only log messages from this level (and up) are processed by this handler
• formatter: The formatter that should be used by the handler
• bubble and priority: Priority is used to put handlers in sequence. Bubble then defines if records should be passed to other handlers after a particular handler has processed them.
• channels: See next section.

Mapping channels to handlers

Every configured handler is added to all loggers by default (it will process messages from all channels). You can, however, specify an alternative set of channels a handler should process.

Extended log data and formatter

The default formatter for all loggers is the LineFormatter which extends the NormalizerFormatter.

The NormalizerFormatter traverses the MonologRecord (extra and context data included) and converts objects, instances of DateTime, resources etc. to strings. It is also able to evaluate the previous property of exceptions, thus following exception chains, in which case it creates stack traces of all exceptions in succession.

The LineFormatter overwrites this way of exception normalization and only outputs the method that started every exception in a chain instead. It also allows the expansion of placeholders of the form %extra.[name]% as a string against the extra variable of the same name.

Conclusion and best practices

Consistent and comprehensive logging is a requirement if you want to be able to quickly isolate and reproduce errors. With Symfony2 and Monolog it's readily available so there is really no good reason not to use it.

A few parting thoughts:

Nested exceptions

Problematic code

try { ... }
catch (ApplicationsspecificException $e) {
    throw new Http500OrSomethingException();
}

There's an issue with this code snippet: Whoever will catch and (hopefully) log this Http500OrSomethingException later on will get the catch block as starting point of the backtrace. The initial exception and with it the heart of the problem has been lost.

\Exception features a $previous property and constructor argument in which the preceding exception $e should be passed. If the new exception is passed in a logging context later on, Monolog's default formatters will log the entire exception chain and thus also show the original problem.

Distinct channels

Loggers can be injected (as described) into Symfony2 services via <tag name="monolog.logger" channel="my_bundle" />.

Every subsystem or even every bundle should use a distinct logging channel: It comes at almost no additional cost and also does not require additional handler configuration. On the plus side, you gain better log readability and the option to configure advanced logging setups later on.

Logging context instead of sprintf

I recommend to avoid code like $logger->info(sprintf("I've had %s for %s", $food, $meal)) and use the PSR-3 log context instead: $logger->info("I've had {food} for {meal}.", array("food" => $food, "meal" => $meal))

It is still possible to log human-readable messages with PsrLogMessageProcessor (which you can activate on a per-handler basis), but also allows for "neutral" messages plus context output. This can be really useful for subsequent processing in logfile monitoring systems (operational intelligence) as it makes it easier to identify similar messages, while context data can still be retrieved for individual cases.

Using log messages for console output

As of Symfony 2.4 there is an easy way to redirect log messages to console output. The verbosity level chosen on the command line can be mapped to a log level and be used to select the appropriate messages.

Erfahren Sie mehr über unsere Leistungen als Symfony Agentur.