Logging

The main logging mechanism in Drupal is a database log through which client code can use an API to save messages into the watchdog table. The messages in there are cleared after they reach a certain number, but meanwhile, they can be viewed in the browser via a handy interface (at admin/reports/dblog):

Figure 3.1: Viewing Recent log messages

Alternatively, a core module that is disabled by default, Syslog, can be used to complement/replace this logging mechanism with the Syslog of the server the site is running on. For the purposes of this book, we will focus on how logging works with any mechanism, but we will also take a look at how we can implement our own logging system.

Drupal 7 developers are very familiar with the watchdog() function, which they use for logging their messages. This is a procedural API for logging that exposes a simple function that takes some parameters:

• $type – the category of the message
• $message – the logged message
• $variables – an array of values to replace placeholders found in the message
• $severity – a constant
• $link – a link to where the message should link to from the UI

It's pretty obvious that this solution is a very Drupal-specific one and not really common to the wider PHP community.

Since Drupal 8, this has changed. The Database Logging module remains and the table for storing the messages is still called watchdog, but this logging destination is just one possible implementation that can be chosen. This is because the logging framework has been refactored to be object-oriented and PSR-3-compliant. And in this context, database logging is just the default implementation.

The Drupal logging theory

Before going ahead with our example, let's cover some theoretical notions regarding the logging framework in Drupal 9. In doing so, we'll try to understand the key players we will need to interact with.

First, we have the LoggerChannel objects, which represent a category of logged messages. They resemble the former $type argument of the Drupal 7 watchdog() function. A key difference, however, is that they are objects through which we do the actual logging, via logger plugins that are injected into them.

In this respect, they are used by our second main player, LoggerChannelFactory, a service that is normally our main contact point with the logging framework as client code.

To understand these things better, let's consider the following example of a simple usage:

\Drupal::logger('hello_world')->error('This is my error message');

That's it. We just used the available registered loggers to log an error message through the hello_world channel. This is our own custom channel that we just came up with on the fly and that simply categorizes this message as belonging to the hello_world category (the module we started in the previous chapter). Moreover, you'll see that I used the static call for getting the logging service. Under the hood, the logger factory service is loaded, a channel is requested from it, and the error() method is called on that channel:

\Drupal::service('logger.factory')->get('hello_world')->error('This is my error message');

When you request a channel from LoggerChannelFactory, you give it a name, and based on that name, the factory creates a new instance of LoggerChannel, which is the default channel class. The factory will then pass to that channel all the available loggers so that when we call any of the RfcLoggerTrait logging methods on it, it will delegate to each of the loggers to do the actual logging.

We also have the option of creating our own, more specific channel. An advantage of doing this is that we can inject it directly into our classes instead of the entire channel factory. Also, we can do it in a way where we don't even require the creation of a new class, but it will inherit from the default one. We'll see how to do that in the next section.

The third main player is the LoggerInterface implementation, which follows the PSR-3 standard. If we look at the DbLog class, which is the database logging implementation we mentioned earlier, we note that it also uses RfcLoggerTrait, which takes care of all the necessary methods so that the actual LoggerInterface implementation only has to handle the main log() method. This class is then registered as a service with the logger tag, which in turn means it gets registered with with LoggerChannelFactory (which acts as a service collector).

As we saw in Chapter 2, Creating Your First Module, tags can be used to categorize service definitions and we can have them collected by another service for a specific purpose. In this case, all services tagged with logger have a standard "purpose", and they are gathered and used by LoggerChannelFactory.

I know this has been quite a lot of theory, but these are some important concepts to understand. Don't worry; as usual, we will go through some examples.

Our own logger channel

I mentioned earlier how we can define our own logger channel so that we don't have to always inject the entire factory. So, let's take a look at how to create one for the Hello World module we're now writing.

Most of the time, all we have to do is add such a definition to the services definition file:

hello_world.logger.channel.hello_world:

  parent: logger.channel_base

  arguments: ['hello_world']

Before talking about the actual logger channel, let's see what this weird service definition actually means, because this is not something we've seen before. I mean, where's the class?

The parent key means that our service will inherit the definition from another service. In our case, the parent key is logger.channel_base, and this means that the class used will be Drupal\Core\Logger\LoggerChannel (the default). If we look closely at the logger.channel_base service definition in core.services.yml, we also see a factory key. This means that this service class is not being instantiated by the service container but by another service, namely the logger.factory service's get() method.

The arguments key is also slightly different. First of all, we don't have the @ sign. That is because this sign is used to denote a service name, whereas our argument is a simple string. As a bonus tidbit, if the string is preceded and followed by a %, it denotes a parameter that can be defined in any *.services.yml file (like a variable).

Getting back to our example then, if you remember the logger theory, this service definition will mean that requesting this service will perform, under the hood, the following task:

\Drupal::service('logger.factory')->get('hello_world');

It uses the logger factory to load a channel with a certain argument. So, now we can inject our hello_world.logger.channel.hello_world service and call any of the LoggerInterface methods on it directly in our client code.

Our own logger

Now that we have a channel for our module, let's assume that we also want to log messages elsewhere. They are fine to be stored in the database, but let's also send an email whenever we encounter an error log. In this section, we will only cover the logging architecture needed for this and defer the actual mailing implementation to the second part of this chapter when we discuss mailing.

The first thing that we will need to create is the LoggerInterface implementation, which typically goes in the Logger folder of our namespace. So, let's call ours MailLogger. And it can look like this:

namespace Drupal\hello_world\Logger;

use Drupal\Core\Logger\RfcLoggerTrait;

use Psr\Log\LoggerInterface;

/**

* A logger that sends an email when the log type is "error".

*/

class MailLogger implements LoggerInterface {

  use RfcLoggerTrait;

  /**

   * {@inheritdoc}

   */

  public function log($level, $message, array $context =   array()) {

    // Log our message to the logging system.

  }

}

The first thing to note is that we are implementing the PSR-3 LoggerInterface. This will require a bunch of methods, but we will take care of most of them via the RfcLoggerTrait. The only one left to implement is the log() method, which will be responsible for doing the actual logging. For now, we will keep it empty.

By itself, having this class does nothing. We will need to register it as a tagged service so that LoggingChannelFactory picks it up and passes it to the logging channel when something needs to be logged. Let's take a look at what that definition looks like:

hello_world.logger.mail_logger:

  class: Drupal\hello_world\Logger\MailLogger

  tags:

    - { name: logger }

As it stands, our logger doesn't need any dependencies. However, note the property called tags with which we tag this service with the logger tag. This will register it as a specific service that another service (called a collector) looks for – just like we discussed in the previous chapter. In this case, the collector is LoggingChannelFactory.

Clearing the cache should enable our logger. This means that when a message is being logged, via any channel, our logger is also used, together with any other enabled loggers (by default, the database one). So, if we want our logger to be the only one, we will need to disable the DB Log module from Drupal core.

We will continue working on this class later in this chapter when we cover sending out emails programmatically.

Now that we have all the tools at our disposal, and more importantly, understand how logging works in Drupal, let's add some logging to our module.

Logging for Hello World

There is one place where we can log an action that may prove helpful. Let's log an info message when an administrator changes the greeting message via the form we wrote. This could happen at one of two moments: whenever the salutation configuration is changed or when the actual form is submitted. Technically, in this case, the former is the more appropriate one because this configuration could also be changed via the code (API), so it stands to reason that logging would be needed then as well. However, to keep things simpler, let's handle it in the submit handler of SalutationConfigurationForm.

If you remember my rant in the previous chapter, there is no way we should use a service statically if we can instead inject it, and we can easily inject services into our form. So, let's do this now.

First of all, FormBase already implements ContainerInjectionInterface, so we don't need to implement it in our class, as we are extending from it somewhere down the line. Second of all, the ConfigFormBase class we are directly extending already has config.factory injected, so this complicates things for us a bit—well, not really. All we need to do is copy over the constructor and the create() methods, add our own service, store it in a property, and pass the services the parent needs to the parent constructor call. It will look like this:

/**

* @var \Drupal\Core\Logger\LoggerChannelInterface

*/

protected $logger;

/**

* SalutationConfigurationForm constructor.

*

* @param \Drupal\Core\Config\ConfigFactoryInterface $config_   factory

*   The factory for configuration objects.

* @param \Drupal\Core\Logger\LoggerChannelInterface $logger

*   The logger.

*/

public function __construct(ConfigFactoryInterface $config_factory, LoggerChannelInterface $logger) {

  parent::__construct($config_factory);

  $this->logger = $logger;

}

/**

* {@inheritdoc}

*/

public static function create(ContainerInterface $container) {

  return new static(

    $container->get('config.factory'),

    $container->get('hello_world.logger.channel.hello_world')

  );

}

And the relevant use statements at the top:

use Drupal\Core\Config\ConfigFactoryInterface;

use Drupal\Core\Logger\LoggerChannelInterface;

use Symfony\Component\DependencyInjection\ContainerInterface;

As you can see, we get all the services that any of the parents need, plus the one we want (the logger channel) via the create() method. Also, in our constructor, we store the channel as a property and then pass the parent arguments to the parent constructor. Now, we have our hello_world logger channel available in our configuration form class. So, let's use it.

At the end of the submitForm() method, let's add the following line:

$this->logger->info('The Hello World salutation has been changed to @message.', ['@message' => $form_state->getValue('salutation')]);

We are logging a regular information message. However, since we also want to log the message that has been set, we use the second argument, which represents an array of context values. Under the hood, the database logger will extract the context variables that start with @, !, or % with the values from the entire context array. This is done using the LogMessageParser service. If you implement your own logger plugin, you will have to handle this yourself as well—but we'll see that in action soon.

And now we are done with logging a message when the salutation configuration form is saved.

Logging recap

In this first section, we saw how logging works in Drupal 9. Specifically, we covered a bit of theory so that you understand how things play together and you don't just mindlessly use the logger factory without actually having a clue what goes on under the hood.

As examples, we created our own logging channel, which allows us to inject it wherever we need without always having to go through the factory. We will use this channel going forward for the Hello World module. Additionally, we created our own logger implementation. It won't do much at the moment, except getting registered, but we will use it in the next section to send emails when errors get logged to the site.

Finally, we used the logging framework (and our channel) in the salutation configuration form to log a message whenever the form is submitted. In doing so, we also passed the message that was saved so that it also gets included in the log. This should already work with the database log, so go ahead and save the configuration form and then check the logging UI for that information message. We defined some new services, so make sure you clear the caches first if you haven't already.

Now that we know how to log things in our application, let's turn our attention to the Drupal Mail API.