Logging PHP applications

by Enrico Zimuel

Every PHP application generates errors, warnings, and notices and throws exceptions. If we do not log this information, we lose a way to identify and solve problems at runtime. Moreover, we may need to log specific actions such as a user login and logout attempts. All such information should be filtered and stored in an efficient way.

PHP offers the function error_log()1 to send an error message to the defined system logger, and the function set_error_handler()2 to specify a handler for intercepting warnings, errors, and notices generated by PHP.

These functions can be used to customize error management, but it's up to the developer to write the logic to filter and store the data.

Zend Framework offers a logging component, zend-log3; the library can be used as a general purpose logging system. It supports multiple log backends, formatting messages sent to the log, and filtering messages from being logged.

Last but not least, zend-log is compliant with PSR-34, the logger interface standard.

Installation

You can install zend-log5 using Composer:

composer require zendframework/zend-log

Usage

zend-log can be used to create log entries in different formats using multiple backends. You can also filter the log data from being saved, and process the log event prior to filtering or writing, allowing the ability to substitute, add, remove, or modify the data you log.

Basic usage of zend-log requires both a writer and a logger instance. A writer stores the log entry into a backend, and the logger consumes the writer to perform logging operations.

As an example:

use Zend\Log\Logger;
use Zend\Log\Writer\Stream;

$logger = new Logger;
$writer = new Stream('php://output');

$logger->addWriter($writer);
$logger->log(Logger::INFO, 'Informational message');

The above produces the following output:

2017-09-11T15:07:46+02:00 INFO (6): Informational message

The output is a string containing a timestamp, a priority (INFO (6)) and the message (Informational message). The output format can be changed using the setFormatter() method of the writer object ($writer). The default log format, produced by the Simple6 formatter, is as follows:

%timestamp% %priorityName% (%priority%): %message% %extra%

where %extra% is an optional value containing additional information.

For instance, if you wanted to change the format to include only log %message%, you could do the following:

$formatter = new Zend\Log\Formatter\Simple('log %message%' . PHP_EOL);
$writer->setFormatter($formatter);

Log PHP events

zend-log can also be used to log PHP errors and exceptions. You can log PHP errors using the static method Logger::registerErrorHandler($logger) and intercept exceptions using the static method Logger::registerExceptionHandler($logger).

use Zend\Log\Logger;
use Zend\Log\Writer;

$logger = new Logger;
$writer = new Writer\Stream(__DIR__ . '/test.log');
$logger->addWriter($writer);

// Log PHP errors
Logger::registerErrorHandler($logger);

// Log exceptions
Logger::registerExceptionHandler($logger);

Filtering data

As mentioned, we can filter the data to be logged; filtering removes messages that match the filter criteria, preventing them from being logged.

We can use the addFilter() method of the Writer interface7 to add a specific filter.

For instance, we can filter by priority, accepting only log entries with a priority less than or equal to a specific value:

$filter = new Zend\Log\Filter\Priority(Logger::CRIT);
$writer->addFilter($filter);

In the above example, the logger will only store log entries with a priority less than or equal to Logger::CRIT (critical). The priorities are defined by the Zend\Log\Logger class:

const EMERG   = 0;  // Emergency: system is unusable
const ALERT   = 1;  // Alert: action must be taken immediately
const CRIT    = 2;  // Critical: critical conditions
const ERR     = 3;  // Error: error conditions
const WARN    = 4;  // Warning: warning conditions
const NOTICE  = 5;  // Notice: normal but significant condition
const INFO    = 6;  // Informational: informational messages
const DEBUG   = 7;  // Debug: debug messages

As such, only emergency, alerts, or critical entries would be logged.

We can also filter log data based on regular expressions, timestamps, and more. One powerful filter uses a zend-validator8 ValidatorInterface instance to filter the log; only valid entries would be logged in such cases.

Processing data

If you need to provide additional information to logs in an automated fashion, you can use a Zend\Log\Processer class. A processor is executed before the log data are passed to the writer. The input of a processor is a log event, an array containing all of the information to log; the output is also a log event, but can contain modified or additional values. A processor modifies the log event to prior to sending it to the writer.

You can read about processor adapters offered by zend-log in the documentation9.

Multiple backends

One of the cool feature of zend-log is the possibility to write logs using multiple backends. For instance, you can write a log to both a file and a database using the following code:

use Zend\Db\Adapter\Adapter as DbAdapter;
use Zend\Log\Formatter;
use Zend\Log\Writer;
use Zend\Log\Logger;

// Create our adapter
$db = new DbAdapter([
    'driver'   => 'Pdo',
    'dsn'      => 'mysql:dbname=testlog;host=localhost',
    'username' => 'root',
    'password' => 'password'
]);

// Map event data to database columns
$mapping = [
    'timestamp' => 'date',
    'priority'  => 'type',
    'message'   => 'event',
];

// Create our database log writer
$writerDb = new Writer\Db($db, 'log', $mapping); // log table
$formatter = new Formatter\Base();
$formatter->setDateTimeFormat('Y-m-d H:i:s'); // MySQL DATETIME format
$writerDb->setFormatter($formatter);

// Create our file log writer
$writerFile = new Writer\Stream(__DIR__ . '/test.log');

// Create our logger and register both writers
$logger = new Logger();
$logger->addWriter($writerDb, 1);
$logger->addWriter($writerFile, 100);

// Log an information message
$logger->info('Informational message');

The database writer requires the credentials to access the table where you will store log information. You can customize the field names for the database table using a $mapping array, containing an associative array mapping log fields to database columns.

The database writer is composed in $writerDb and the file writer in $writerFile. The writers are added to the logger using the addWriter() method with a priority number; higher integer values indicate higher priority (triggered earliest). We chose priority 1 for the database writer, and priority 100 for the file writer; this means the file writer will log first, followed by logging to the database.

Note: we used a special date formatter for the database writer. This is required to translate the log timestamp into the DATETIME format of MySQL.

PSR-3 support

If you need to be compatible with PSR-310, you can use Zend\Log\PsrLoggerAdapter. This logger can be used anywhere a Psr\Log\LoggerInterface is expected.

As an example:

use Psr\Log\LogLevel;
use Zend\Log\Logger;
use Zend\Log\PsrLoggerAdapter;

$zendLogLogger = new Logger;
$psrLogger = new PsrLoggerAdapter($zendLogLogger);

$psrLogger->log(LogLevel::INFO, 'We have a PSR-compatible logger');

To select a PSR-3 backend for writing, we can use the Zend\Log\Writer\Psr class. In order to use it, you need to pass a Psr\Log\LoggerInterface instance to the $psrLogger constructor argument:

$writer = new Zend\Log\Writer\Psr($psrLogger);

zend-log also supports PSR-3 message placeholders11 via the Zend\Log\Processor\PsrPlaceholder class. To use it, you need to add a PsrPlaceholder instance to a logger, using the addProcess() method. Placeholder names correspond to keys in the "extra" array passed when logging a message:

use Zend\Log\Logger;
use Zend\Log\Processor\PsrPlaceholder;

$logger = new Logger;
$logger->addProcessor(new PsrPlaceholder);

$logger->info('User with email {email} registered', ['email' => '[email protected]']);

An informational log entry will be stored with the message User with email [email protected] registered.

Logging an MVC application

If you are using a zend-mvc12 based application, you can use zend-log as module. zend-log provides a Module.php13 class, which registers Zend\Log as a module in your application.

In particular, the zend-log module provides the following services (under the namespace Zend\Log):

Logger::class         => LoggerServiceFactory::class,
'LogFilterManager'    => FilterPluginManagerFactory::class,
'LogFormatterManager' => FormatterPluginManagerFactory::class,
'LogProcessorManager' => ProcessorPluginManagerFactory::class,
'LogWriterManager'    => WriterPluginManagerFactory::class,

The Logger::class service can be configured using the log config key; the documentation provides configuration examples14.

In order to use the Logger service in your MVC stack, grab it from the service container. For instance, you can pass the Logger service in a controller using a factory:

use Zend\Log\Logger;
use Zend\ServiceManager\Factory\FactoryInterface;

class IndexControllerFactory implements FactoryInterface
{
    public function __invoke(
        ContainerInterface $container,
        $requestedName,
        array $options = null
    ) {
        return new IndexController(
            $container->get(Logger::class)
        );
    }
}

via the following service configuration for the IndexController:

'controllers' => [
    'factories' => [
        IndexController::class => IndexControllerFactory::class,
    ],
],

Logging a middleware application

You can also integrate zend-log in your middleware applications. If you are using Expressive15, add the component's ConfigProvider16 to your config/config.php file.

Note: if you are using zend-component-installer17, you will be prompted to install zend-log's config provider when you install the component via Composer.

Note: This configuration registers the same services provided in the zend-mvc example, above.

To use zend-log in middleware, grab it from the dependency injection container and pass it as a dependency to your middleware:

namespace App\Action;

use Psr\Container\ContainerInterface;
use Zend\Log\Logger;

class HomeActionFactory
{
    public function __invoke(ContainerInterface $container) : HomeAction
    {
        return new HomeAction(
            $container->get(Logger::class)
        );
    }
}

As an example of logging in middleware:

namespace App\Action;

use Interop\Http\ServerMiddleware\DelegateInterface;
use Interop\Http\ServerMiddleware\MiddlewareInterface as ServerMiddlewareInterface;
use Psr\Http\Message\ServerRequestInterface;
use Zend\Log\Logger;

class HomeAction implements ServerMiddlewareInterface
{
    private $logger;

    public function __construct(Logger $logger)
    {
        $this->logger = logger;
    }

    public function process(
        ServerRequestInterface $request,
        DelegateInterface $delegate
    ) {
        $this->logger->info(__CLASS__ . ' has been executed');

        // ...
    }
}

Listening for errors in Expressive

Expressive and Stratigility18 provide a default error handler middleware implementation, Zend\Stratigility\Middleware\ErrorHandler which listens for PHP errors and exceptions/throwables. By default, it spits out a simple error page when an error occurs, but it also provides the ability to attach listeners, which can then act on the provided error.

Listeners receive the error, the request, and the response that the error handler will be returning. We can use that information to log information!

First, we create an error handler listener that composes a logger, and logs the information:

use Exception;
use Psr\Http\Message\ResponseInterface;
use Psr\Http\Message\ServerRequestInterface;
use Throwable;
use Zend\Log\Logger;

class LoggingErrorListener
{
    /**      
     * Log message string with placeholders
     */
    const LOG_STRING = '{status} [{method}] {uri}: {error}';

    private $logger;

    public function __construct(Logger $logger)
    {
        $this->logger = $logger;
    }

    public function __invoke(
        $error,
        ServerRequestInterface $request,
        ResponseInterface $response
    ) {
        $this->logger->error(self::LOG_STRING, [
            'status' => $response->getStatusCode(),
            'method' => $request->getMethod(),
            'uri'    => (string) $request->getUri(),
            'error'  => $error->getMessage(),
        ]);
    }
}

The ErrorHandler implementation casts PHP errors to ErrorException instances, which means that $error is always some form of throwable.

We can then write a delegator factory that will register this as a listener on the ErrorHandler:

use LoggingErrorListener;
use Psr\Container\ContainerInterface;
use Zend\Log\Logger;
use Zend\Log\Processor\PsrPlaceholder;
use Zend\Stratigility\Middleware\ErrorHandler;

class LoggingErrorListenerFactory
{
    public function __invoke(
        ContainerInterface $container,
        $serviceName,
        callable $callback
    ) : ErrorHandler {
        $logger = $container->get(Logger::class);
        $logger->addProcessor(new PsrPlaceholder());

        $listener = new LoggingErrorListener($logger);

        $errorHandler = $callback();
        $errorHandler->attachListener($listener);
        return $errorHandler;
    }
}

And then register the delegator in your configuration:

// In a ConfigProvider, or a config/autoload/*.global.php file:
use LoggingErrorListenerFactory;
use Zend\Stratigility\Middleware\ErrorHandler;

return [
    'dependencies' => [
        'delegators' => [
            ErrorHandler::class => [
                LoggingErrorListenerFactory::class,
            ],
        ],
    ],
];

At this point, your error handler will now also log errors to your configured writers!

Summary

The zend-log component offers a wide set of features, including support for multiple writers, filtering of log data, compatibility with PSR-319, and more.

Hopefully you can use the examples above for consuming zend-log in your standalone, zend-mvc, Expressive, or general middleware applications!

Learn more in the zend-log documentation20.

Footnotes

1. http://php.net/error_log ↩
2. http://php.net/set_error_handler ↩
3. https://docs.zendframework.com/zend-log/ ↩
4. http://www.php-fig.org/psr/psr-3/ ↩
5. https://docs.zendframework.com/zend-log/ ↩
6. https://github.com/zendframework/zend-log/blob/master/src/Formatter/Simple.php ↩
7. https://github.com/zendframework/zend-log/blob/master/src/Writer/WriterInterface.php ↩
8. https://docs.zendframework.com/zend-validator/ ↩
9. https://docs.zendframework.com/zend-log/processors/ ↩
10. http://www.php-fig.org/psr/psr-3/ ↩
11. http://www.php-fig.org/psr/psr-3/#12-message ↩
12. https://docs.zendframework.com/zend-mvc/ ↩
13. https://github.com/zendframework/zend-log/blob/master/src/Module.php ↩
14. https://docs.zendframework.com/zend-log/service-manager/#zend-log-as-a-module ↩
15. https://docs.zendframework.com/zend-expressive/ ↩
16. https://github.com/zendframework/zend-log/blob/master/src/ConfigProvider.php ↩
17. https://docs.zendframework.com/zend-component-installer/ ↩
18. https://docs.zendframework.com/zend-stratigility/ ↩
19. http://www.php-fig.org/psr/psr-3/ ↩
20. https://docs.zendframework.com/zend-log/ ↩

results matching ""

    No results matching ""