By Software development is a complex endeavor. There are many things that must work just right for the whole system to remain stable and useful. Most of the time, there is only so much a developer can anticipate regarding all the possible scenarios that may arise during the lifetime of an application. The bottom line is that good software is the result of a long line of iterations, each building upon the feedback obtained from the use of previous ones.
This feedback comes in many forms, with the most obvious being user comments and complaints. However, a message such as "This isn't working!" doesn’t provide quite enough information for us to fix things. What we, as developers, need is detailed information on what was happening when things went south.
This information can typically be found in log files; at least, that's what we'd expect when doing this kind of forensic analysis. However, for this information to exist, we have to be very proactive in having our programs leave clues behind as they progress towards their goals.
There are two questions that need to be answered when thinking of logs:
- What should you log?
- Where should you store your logs?
The first question is probably too specific to provide a general answer, but the best rule-of-thumb is "log anything you think you might need to figure out what went wrong". It's ultimately a delicate equilibrium between having enough information and flooding the server disks. It’s not an easy choice.
The second question is a little easier to tackle, as there are only so many places where information can be stored in a computing environment.
In this article, I'll analyze three ways to approach this common task. The first two are built-in functions, and the last one is a popular third-party library:
trigger_errorerror_log- Monolog
Let's dig in, shall we?
Error Logging via trigger_error
The first tool a PHP developer encounters when looking for logging mechanisms is the trigger_error function.
This function is very simple to use; it takes a message explaining what was wrong and an integer number signaling the error type. This number can be supplied using pre-defined constants.
An example of its usage is as follows:
trigger_error('Something went wrong', E_USER_ERROR);
This will produce an output similar to the following:
PHP Fatal error: Something went wrong in php shell code on line 1
That is true, of course, if you run the code from the command line. If you were to put it in a PHP file to be accessed via the browser, for example:
<?php
trigger_error('Something went wrong', E_USER_ERROR);
And then brought the built-in webserver up by issuing:
php -S localhost:8000
And finally made a request to http://localhost:8000, you'd see, right there in the console, something similar to the following:
[Wed Apr 20 15:15:21 2022] PHP 7.4.3 Development Server (http://localhost:8000) started
[Wed Apr 20 15:15:25 2022] 127.0.0.1:34614 Accepted
[Wed Apr 20 15:15:25 2022] 127.0.0.1:34616 Accepted
[Wed Apr 20 15:15:25 2022] PHP Fatal error: Something went wrong in /mnt/c/Users/mchoj/PhpstormProjects/Honeybadger/index.php on line 2
[Wed Apr 20 15:15:25 2022] 127.0.0.1:34614 [500]: GET / - Something went wrong in /mnt/c/Users/mchoj/PhpstormProjects/Honeybadger/index.php on line 2
[Wed Apr 20 15:15:25 2022] 127.0.0.1:34614 Closing
[Wed Apr 20 15:15:26 2022] 127.0.0.1:34620 Accepted
[Wed Apr 20 15:15:29 2022] 127.0.0.1:34620 Closed without sending a request; it was probably just an unused speculative preconnection
In the browser, you'd see the following:
One particular feature of this function is that it's heavily influenced by the interpreter's configuration. This means that depending on the settings, such as error_reporting, display_errors, and a few others, the actual behavior of the function can change significantly.
For instance, if you were to re-start the server with the following command:
php -S localhost:8000 -d display_errors=1
You'd see the following:
What this means in practice is that it's difficult to ensure a consistent result among different running environments. It’s not really something you want for your projects.
Error Logging via error_log
Another built-in tool that PHP provides is the error_log function.
This function is more predictable than trigger_error, as it only depends on the error_log setting; however, its actual behavior can change dramatically depending on its parameters (particularly the message_type).
For instance, if you change the code to:
<?php
error_log('Something went wrong');
And refresh the page, you'll be staring at a blank screen; however, when looking at the console output, you'll find the following:
[Wed Apr 20 15:39:41 2022] PHP 7.4.3 Development Server (http://localhost:8000) started
[Wed Apr 20 15:39:47 2022] 127.0.0.1:34648 Accepted
[Wed Apr 20 15:39:47 2022] 127.0.0.1:34646 Accepted
[Wed Apr 20 15:39:47 2022] Something went wrong
[Wed Apr 20 15:39:47 2022] 127.0.0.1:34646 [200]: GET /
[Wed Apr 20 15:39:47 2022] 127.0.0.1:34646 Closing
[Wed Apr 20 15:39:47 2022] 127.0.0.1:34650 Accepted
[Wed Apr 20 15:39:57 2022] 127.0.0.1:34648 Closed without sending a request; it was probably just an unused speculative preconnection
[Wed Apr 20 15:39:57 2022] 127.0.0.1:34648 Closing
[Wed Apr 20 15:39:57 2022] 127.0.0.1:34650 Closed without sending a request; it was probably just an unused speculative preconnection
[Wed Apr 20 15:39:57 2022] 127.0.0.1:34650 Closing
Even if you use the same php -S localhost:8000 -d display_errors=1 to bring the server up.
In fact, this function stores the error messages together with those from the webserver by default.
You can change this behavior via the message_type parameter. If you fill it with a number 3 when calling the function, you'll be asking the interpreter to output your message to a specific file, which is determined by the value of the next parameter: destination. Like this:
<?php
error_log('Something went wrong', 3, __DIR__.'/log');
If you refresh the page. you'll end up with the same blank screen, but the server logs will be different:
[Wed Apr 20 15:46:11 2022] PHP 7.4.3 Development Server (http://localhost:8000) started
[Wed Apr 20 15:46:15 2022] 127.0.0.1:34652 Accepted
[Wed Apr 20 15:46:15 2022] 127.0.0.1:34654 Accepted
[Wed Apr 20 15:46:15 2022] 127.0.0.1:34652 [200]: GET /
[Wed Apr 20 15:46:15 2022] 127.0.0.1:34652 Closing
[Wed Apr 20 15:46:16 2022] 127.0.0.1:34658 Accepted
[Wed Apr 20 15:46:18 2022] 127.0.0.1:34658 Closed without sending a request; it was probably just an unused speculative preconnection
[Wed Apr 20 15:46:18 2022] 127.0.0.1:34658 Closing
[Wed Apr 20 15:46:18 2022] 127.0.0.1:34654 Closed without sending a request; it was probably just an unused speculative preconnection
[Wed Apr 20 15:46:18 2022] 127.0.0.1:34654 Closing
However, as expected, if you look at the files present in the project's directory, you'll find a newly created log one, and if you look at its contents, you'll find the following:
Something went wrong
One of the main differences between error_log and trigger_error is that a call to the latter will most likely result in an execution interruption, while the former will simply write the message to the appropriate stream and yield back control.
At first glance, you could get the impression that this function adds little to no value over other functions aimed at writing strings to files.
However, if you take a closer look, you'll notice a very particular, and certainly useful, feature of error_log; it handles locking internally, meaning you won't have to deal with nasty race conditions in high concurrency environments, such as a web server.
Although either trigger_error or error_log will technically work, it's pretty clear that the developer experience they provide is sub-optimal at best.
Think for a minute what it would take for you to store log information both locally and remotely just using these tools, not to mention choosing the log destination by severity.
Of course, the PHP community has better options at your disposal. Read on to discover an professional tool.
Error Logging via Monolog
So far, I've been discussing what PHP itself has to offer, which, quite frankly, is not very appealing. Luckily, though, there are great developers involved in pushing beyond those boundaries, making the appearance of great tools a reality. That is the case for Monolog.
Monolog is an object-oriented library that can be brought into any PHP project thanks to composer, which provides a lot of really cool features, such as the ability to send the same message through different channels (a file, a database, and an email) and apply different filtering and formatting logic before storing, allowing you to build really complex logging mechanisms without too much hassle.
Let's start with a simple example: you want to keep a log of every IP address that visits your website.
Your code would look something like the following:
<?php
$currentIp = $_SERVER['REMOTE_ADDR'];
error_log('Got a visitor from '.$currentIp, 3, __DIR__.'/ip.log');
The next step is to bring Monolog in by using the following command:
composer require monolog/monolog
Which will produce an output similar to the following:
Loading composer repositories with package information
Updating dependencies
Lock file operations: 2 installs, 0 updates, 0 removals
- Locking monolog/monolog (2.5.0)
- Locking psr/log (3.0.0)
Writing lock file
Installing dependencies from lock file (including require-dev)
Package operations: 2 installs, 0 updates, 0 removals
- Installing psr/log (3.0.0): Extracting archive
- Installing monolog/monolog (2.5.0): Extracting archive
10 package suggestions were added by new dependencies, use `composer suggest` to see details.
Generating autoload files
1 package you are using is looking for funding.
Use the `composer fund` command to find out more!
PSR-4 autoloading configured. Use "namespace Mauro\Log;" in src/
Include the Composer autoloader with: require 'vendor/autoload.php';
After the installation is finished, you need to make use of the library in your code. As usual, it all starts with including the autoloading definition:
<?php
require_once 'vendor/autoload.php';
$currentIp = $_SERVER['REMOTE_ADDR'];
error_log('Got a visitor from '.$currentIp, 3, __DIR__.'/ip.log');
Now, before we move forward with this refactoring, there are a few concepts you need to know about. The thing is, while Monolog takes logging to a whole new level, that kind of power comes with a price tag... no, I'm not talking about money, but about a learning curve.
The first one is the Logger itself. This class constitutes the backbone of the whole library. In fact, it’s the one you'll use most of the time.
You can have as many loggers as you need, each one with its own configuration.
Every Logger is identified by its channel name. This can be useful if, for instance, you're sending logs to the same file and need to differentiate them later.
The idea is for the logs generated via Monolog to be easily parsed using simple tools like grep.
The Logger relies on three other classes to fulfill its purpose:
- Handlers
- Processors
- Formatters
Monolog Handlers
Handlers are the lowest level component. A handler's responsibility is to answer the question "Where should this log be stored?". There are many handler classes defined within the Monolog library. Here are a few of them:
- ErrorLogHandler: the simplest one, just a little wrapper around
error_log - NativeMailerHandler: send logs to an email address using php's
mailfunction - SQSHandler: send logs to an AWS SQS queue.
Monolog Processors
Processors are used to transform raw log data before it is passed to the handlers for storage.
Usually, this means adding standard context information, such as the date and time, user, and IP.
The library comes bundled with quite a few very useful processors, such as:
- WebProcessor which adds information about the client making the request that spawned this message
- MemoryProcessor which adds information about the memory usage
- GitProcessor which adds information about the Git commits involved
And, of course, you can build your own processors by creating new classes which implement the ProcessorInterface.
In summary, processors are meant to answer the question "What else should be logged?"
Monolog Formatters
Finally, formatters are meant to answer the question "How should messages be stored?"
Formatters work in conjunction with handlers to add formatting information around the messages, so they can be better rendered in a particular environment.
For instance, if you're sending logs via email, a nicely crafted HTML will make the logs more easily readable within an email client.
Monolog in Action
Ok, it's been a lot of theory right? Let's see some code to make sense of all we've been discussing.
Going back to our little example, the first thing we'll need is a Logger:
<?php
require_once 'vendor/autoload.php';
use Monolog\Logger;
$logger = new Logger('my-app');
$currentIp = $_SERVER['REMOTE_ADDR'];
But ... where are the logs going to be stored? We need a Handler for that!
Let's add one:
<?php
require_once 'vendor/autoload.php';
use Monolog\Logger;
use Monolog\Handler\StreamHandler;
$logger = new Logger('my-app');
$handler = new StreamHandler(__DIR__.'/ip.log');
$currentIp = $_SERVER['REMOTE_ADDR'];
Now we have a handler that will save every log record to the file ip.log in the same directory as our application.
What we need to do now is attach this Handler to the Logger, like this:
<?php
require_once 'vendor/autoload.php';
use Monolog\Logger;
use Monolog\Handler\StreamHandler;
$logger = new Logger('my-app');
$handler = new StreamHandler(__DIR__.'/ip.log');
$logger->pushHandler($handler);
$currentIp = $_SERVER['REMOTE_ADDR'];
And now, let's write our first log message using Monolog:
<?php
require_once 'vendor/autoload.php';
use Monolog\Logger;
use Monolog\Handler\StreamHandler;
$logger = new Logger('my-app');
$handler = new StreamHandler(__DIR__.'/ip.log');
$logger->pushHandler($handler);
$currentIp = $_SERVER['REMOTE_ADDR'];
$logger->info('Got a visitor from '.$currentIp);
The info method is just one of many that can be called to signal the severity of the message.
If you start a local webserver (php -S localhost:8000) and visit http://localhost:8000, you'll find something like this in your ip.log file:
[2022-04-29T11:41:39.121355+02:00] my-app.INFO: Got a visitor from 127.0.0.1 [] []
Now let's say you want to not only save this information to a local file but also send it to an admin via email. You could do it using a NativeMailerHandler, like this:
<?php
require_once 'vendor/autoload.php';
use Monolog\Logger;
use Monolog\Handler\{StreamHandler, NativeMailerHandler};
$logger = new Logger('my-app');
$handler = new StreamHandler(__DIR__.'/ip.log');
$emailHandler = new NativeMailerHandler('you@yourdomain.com', 'Message from Honeybadger\'s App', 'app@localhost');
$logger->pushHandler($handler);
$logger->pushHandler($emailHandler);
$currentIp = $_SERVER['REMOTE_ADDR'];
$logger->info('Got a visitor from '.$currentIp);
If you refresh your page, you'll see a new entry in your file but no email in your inbox. Why did this happen?
NativeMailerHandler is designed to only react to error messages by default, so you have two options here; you can either change the severity of your message:
<?php
require_once 'vendor/autoload.php';
use Monolog\Logger;
use Monolog\Handler\{StreamHandler, NativeMailerHandler};
$logger = new Logger('my-app');
$handler = new StreamHandler(__DIR__.'/ip.log');
$emailHandler = new NativeMailerHandler('you@yourdomain.com', 'Message from HoneBadger\'s App', 'app@localhost');
$logger->pushHandler($handler);
$logger->pushHandler($emailHandler);
$currentIp = $_SERVER['REMOTE_ADDR'];
$logger->error('Got a visitor from '.$currentIp);
Or you can have your $emailHandler also take info messages into account:
<?php
require_once 'vendor/autoload.php';
use Monolog\Logger;
use Monolog\Handler\{StreamHandler, NativeMailerHandler};
$logger = new Logger('my-app');
$handler = new StreamHandler(__DIR__.'/ip.log');
$emailHandler = new NativeMailerHandler('you@yourdomain.com', 'Message from Honeybadger\'s App', 'app@localhost', Logger::INFO);
$logger->pushHandler($handler);
$logger->pushHandler($emailHandler);
$currentIp = $_SERVER['REMOTE_ADDR'];
$logger->info('Got a visitor from '.$currentIp);
In this case, your inbox should contain a message similar to the following:
As you can see, an HTML formatter was used to produce this nice email without you doing anything. Are you sold on the idea of using Monolog yet? :)
You could keep adding handlers, formatters and processors as you see fit; the possibilities are endless.
Integration with Honeybadger
Now, if you're familiar with Honeybadger, you already know all the benefits it can bring to your development team.
Wouldn't it be great to integrate it into your Monolog-powered logs? Well, guess what? It is really simple.
All it takes is an instance of Honeybadger\LogHandler as a Monolog Handler.
Start by adding the required library:
composer require Honeybadger-io/Honeybadger-php
Then update your code to look like this:
<?php
require_once 'vendor/autoload.php';
use Monolog\Logger;
use Monolog\Handler\{StreamHandler, NativeMailerHandler};
use Honeybadger\{Honeybager, LogHandler};
$logger = new Logger('my-app');
$handler = new StreamHandler(__DIR__.'/ip.log');
$emailHandler = new NativeMailerHandler('you@yourdomain.com', 'Message from Honeybadger\'s App', 'app@localhost', Logger::INFO);
$honeybadger = Honeybadger\Honeybadger::new([
'api_key' => 'YOUR_API_KEY'
]);
$honeyBadgerHandler = new LogHandler($honeybadger);
$logger->pushHandler($handler);
$logger->pushHandler($emailHandler);
$logger->pushHandler($honeyBadgerHandler);
$currentIp = $_SERVER['REMOTE_ADDR'];
$logger->info('Got a visitor from '.$currentIp);
And, after refreshing the page again, you'll find a message like this on your Honeybadger dashboard:
.
Is your project based on Laravel? You're also covered. Read here for a complete integration guide.
Conclusion
As we're accustomed when it comes to PHP, there are quick-and-dirty solutions you can implement in a heartbeat, and there are professional ones that take a little more effort, but the difference in the long run makes them well worth the trouble.
Which one will you choose for your projects?
