Monolog, Rollbar, and the Case of the Missing Exception

I recently worked on a project that used the PHP client library for Rollbar. More specifically, I was entasked with upgrading that library from the 0.x version in use to a more recent 1.x version.

One of the features specific to the newer version was an optional integration with the popular Monolog logging library, which was already being used by the project I was working on. I thought using this feature would make our code a bit cleaner, so I set about trying to use it.

Within my codebase, there was a line that looked something like this, where $exception was an instance of an Exception subclass:

$this->logger->critical(
    'Uncaught PHP Exception.',
    ['exception' => $exception]
);

Upon executing this code and checking the Rollbar dashboard, I found that the 'exception' context data entry was assigned an empty object, rather than the serialized exception data I was expecting.

It would take me a fair amount of head-scratching and digging through the internals of the Monolog and Rollbar client libraries to figure out what was going on.

The Serialized Exception

The ultimate issue turned out to be that PHP exceptions don't natively support JSON serialization, and there was no userland logic being executed to handle it.

var_dump(json_encode(new Exception("message", 1)));

/*
Output:
string(2) "{}"
*/

If you search the source for Monolog, you'll find that it does include the aforementioned userland logic for serializing exceptions in the form of the normalizeException() method declared by Monolog\Formatter\NormalizerFormatter and its subclasses LineFormatter (which Monolog uses by default when a formatter is requested) and JsonFormatter.

So, why wasn't this logic being executed in my case?

The Missing Formatter

I reviewed the documented example of integrating Rollbar with Monolog. Doing this ultimately involves creating an instance of Rollbar\RollbarLogger, passing that to an instance of Monolog\Handler\PsrHandler, and then adding that handler to your instance of Monolog\Logger.

Monolog has two relevant base classes for handlers: AbstractHandler and AbstractProcessingHandler. The important difference between the two in this case is that AbstractProcessingHandler supports the use of formatters while AbstractHandler does not.

As it turns out, PsrHandler extends from AbstractHandler and does not implement its own support for formatters, so none was being used.

The New Handler

To address this, I would need a handler that would proxy to the Rollbar\RollbarLogger instance as PsrHandler did, but also support use of formatters. So I wrote my own handler.

use Monolog\Handler\AbstractProcessingHandler;
use Monolog\Logger;
use Psr\Log\LoggerInterface;

class PsrProcessingHandler extends AbstractProcessingHandler
{
    protected $logger;

    public function __construct(
        LoggerInterface $logger,
        $level = Logger::DEBUG,
        $bubble = true
    ) {
        parent::__construct($level, $bubble);
        $this->logger = $logger;
    }

    protected function write(array $record)
    {
        $formatted = empty($record['formatted']) ? $record : $record['formatted'];
        $this->logger->log(
            strtolower($record['level_name']),
            $formatted['message'],
            $formatted['context']
        );
    }
}

Let's break this down.

First, I made my handler extend AbstractProcessingHandler rather than AbstractHandler as PsrHandler does. This gave me access to a handle() implementation that supported use of formatters.

Next, I copied over the $logger property and __construct() method declarations from PsrHandler, which allowed me to pass my Rollbar\RollbarLogger instance to my new handler.

Finally, since I wanted to keep the existing handle() implementation from AbstractProcessingHandler(), and that implementation called write() to actually write the log record to its destination, I overrode write() to handle sending the record to the Rollbar\RollbarLogger instance.

When Monolog uses a formatter, the formatted version of the record is stored back in the record itself with a key of 'formatted'. As such, I included a check for the presence of a formatted version and used that when available. Otherwise, I simply used the record as-is.

I implemented use of this handler, re-ran the code that logged the exception... and still found an empty object in Rollbar.

The Correct Formatter

If you look at the source for Monolog\Formatter\LineFormatter, you'll find that while it does have a normalizeException() method, it doesn't actually call it internally. The method is protected, so I can only assume it's intended for potential subclasses to use.

Remember when I said earlier that this is the formatter Monolog uses by default? This explained why, even with my new handler, I still wasn't seeing exception information in Rollbar.

To address this, I modified my handler to instead use NormalizerFormatter, which does call its normalizeException() method internally.

Case Closed

Once both the new handler and the NormalizerFormatter configuration were in place, I was able to re-run the code and see exception data in Rollbar.

Hope the tale of my journey helps you, or at least proved to be an interesting read!