Tirer partie du logger Symfony

par | 29/09/2018 | symfony | 0 commentaires

Symfony utilise le désormais célèbre monolog. Il est facilement accessible sous forme de service (merci l’injection de dépendance) :

namespace App\Controller\Api;

use Symfony\Bundle\FrameworkBundle\Controller\AbstractController;
use Psr\Log\LoggerInterface;

class FooController extends AbstractController
{
    public function edit(LoggerInterface $logger)
    {
        $logger->info('Hey ! I am writing in logs !!');
    }
}

Handlers (gestionnaires)

A chaque fois qu’on va envoyer une entrée vers monolog (comme ci dessus), ce dernier va appeler la liste (dans l’ordre) des « handlers » (on appelle ça une pile) définis et leur passer la dite entrée. Un « handler » peut être perçu comme un gestionnaire qui va écrire le message quelque part (fichier, base de données, mail, etc) sous certaines conditions. Sous Symfony 4, en mode dev, on a les gestionnaires suivants (config/packages/dev/monolog.yaml) :

monolog:
    handlers:
        # Handler name
        main:
            # Handler type
            type: stream
            # Where to write the entry log
            path: "%kernel.logs_dir%/%kernel.environment%.log"
            # Handler level
            level: debug
            # Handler channels
            channels: ["!event"]
        console:
            type:   console
            process_psr_3_messages: false
            channels: ["!event", "!doctrine", "!console"]
  • main et console sont les noms des gestionnaires
  • type défini le type du gestionnaire. Pour l’instant on se cantonne à stream (système de fichier)
  • level est le niveau d’erreur minimal requis pour déclencher le gestionnaire
  • channels permet d’indiquer quelles catégories d’entrées sont autorisées ou non

J’admets, ça déroute un peu au début… La question est : que fait le gestionnaire lorsqu’il reçoit une entrée ? Réponse : cela dépend d’abord du niveau d’erreur et du « channel ».

Les gestionnaires sont appelés dans l’ordre dans lequel ils sont définis dans la clé handlers. Pour cette raison, il est conseillé de ne pas utiliser plusieurs fichiers de configuration : un fichier dans le répertoire /prod et un dans le répertoire /dev (et éventuellement un dans /test).

Niveaux d’erreurs

Dans l’ordre, les niveaux d’erreurs (levels) disponibles dans monolog :

  • debug
  • info
  • notice
  • warning
  • error
  • critical
  • alert
  • emergency

Pour reprendre l’exemple précédent, le gestionnaire main a un niveau (clé level) d’erreur fixé à debug. C’est le niveau le plus faible, ce gestionnaire sera donc toujours utilisé quelque soit le niveau d’erreur :

use Psr\Log\LoggerInterface;

class FooController extends AbstractController
{
    public function edit(LoggerInterface $logger)
    {
        $logger->info('Hey ! I am writing in logs !!');
        $logger->critical('Oops something bad is happening');
    }
}

Autrement dit, en mode dev, tout est écrit dans le fichier var/dev.log (clé path). Si maintenant on défini le niveau d’erreur du gestionnaire main à critical, l’entrée info ne sera pas écrite. A noter que la pile des gestionnaires est toujours appelée en totalité, c’est à dire qu’une même entrée peut être écrite à plusieurs endroits (l’utilisation d’un gestionnaire n’arrête pas le traitement de la pile).

Channels

Les channels servent à identifier les entrées log. A chaque channel correspond un service monolog.logger.XXX (remplacez XXX par le nom du channel). Pour lister les channels utilisés dans Symfony, on liste les services correspondant :

$ ./bin/console debug:container --show-private monolog.log

# Output
[0 ] monolog.logger
[1 ] monolog.logger_prototype
[2 ] monolog.logger.request
[3 ] monolog.logger.console
[4 ] monolog.logger.cache
[5 ] monolog.logger.translation
[6 ] monolog.logger.profiler
[7 ] monolog.logger.php
[8 ] monolog.logger.event
[9 ] monolog.logger.router
[10] monolog.logger.security
[11] monolog.logger.doctrine
[12] monolog.logger.debug

Lorsqu’on écrit quelque chose comme :

$logger->info('Hi there');

C’est la classe de $logger (donc le service utilisé) qui va définir le channel de l’entrée log. Par défaut, Symfony va utiliser le service monolog.logger. Dans l’exemple précédent, cela se traduit par les deux entrés suivantes (dans le fichier var/dev.log) :

[2018-10-06 10:18:36] app.INFO: Hey ! I am writing in logs !! [] []
[2018-10-06 10:18:36] app.CRITICAL: Oops something bad is happening [] []

Le service monolog.logger correspond donc au channel app. A noter qu’on on voit le niveau d’erreur juste après le channel (format channel.LEVEL). Maintenant, comment faire pour utiliser un autre channel ?

Il suffit juste d’injecter le service approprié. Par exemple, pour utiliser le channel doctrine, on modifie légèrement notre code précédent :

namespace App\Controller\Api;

use Symfony\Bundle\FrameworkBundle\Controller\AbstractController;
use Psr\Log\LoggerInterface;

class FooController extends AbstractController
{
    /**
     * @var LoggerInterface
     */
    private $logger;

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

    public function edit()
    {
        $this->logger->info('Hey ! I am writing in logs !!');
        $this->logger->critical('Oops something bad is happening');
    }
}

Puis on spécifie le service à utiliser dans services.yaml :

services:
    App\Controller\Api\FooController:
        arguments:
            $logger: '@monolog.logger.doctrine'

On vérifie que le channel doctrine est bien utilisé :

[2018-10-06 13:07:46] doctrine.INFO: Hey ! I am writing in logs !! [] []
[2018-10-06 13:07:46] doctrine.CRITICAL: Oops something bad is happening [] []

Type de gestionnaire

Pour le moment on a utilisé un seul type de gestionnaire : stream. Il en existe d’autres :

  • fingers_crossed : ce gestionnaire stocke dans un buffer les entrées log qu’il reçoit. Si une entrée atteint un certain niveau d’erreur, cela déclenche le « vidage » du buffer en direction d’un autre handler. Plus d’explications juste après.
  • rotating_file : permet de ne conserver les logs (dans le cas d’un stockage dans un système de fichier) qu’un certain nombre de jours. Plus d’explications juste après.
  • syslog : ce gestionnaire utilise la fonction php syslog pour l’entrée log reçue.

Plusieurs fichiers de logs

Grâce aux channels, on va pouvoir séparer nos logs dans différents fichiers. Supposons que je veuille que les entrées log de doctrine soient stockées dans un fichier séparé. Il suffit de créer un gestionnaire qui va prendre en compte que le channel doctrine, et pas les autres :

monolog:
    handlers:
        doctrine_logging:
            type: stream
            path: "%kernel.logs_dir%/doctrine.%kernel.environment%.log"
            level: debug
            channels: ['doctrine']

On a maintenant un fichier /var/log/doctrine.dev.log qui contient, entre autres, nos deux entrées log :

[2018-10-06 21:28:35] doctrine.INFO: Hey ! I am writing in logs !! [] []
[2018-10-06 21:28:35] doctrine.CRITICAL: Oops something bad is happening [] []

Mais ces deux entrées se trouvent encore dans /var/log/dev.log. C’est normal, il faut modifier la configuration du gestionnaire principal pour qu’il écarte le channel doctrine :

monolog:
    handlers:
        main:
            type: stream
            path: "%kernel.logs_dir%/%kernel.environment%.log"
            level: debug
            channels: ["!event", "!doctrine"]

Voyez la syntaxe pour exclure un channel : !channel_name.

Rotation des logs

Il suffit de remplacer stream par rotating_file. Dans ce cas, monolog crée un fichier par jour.

monolog:
    handlers:
        main:
            type:  rotating_file
            path:  '%kernel.logs_dir%/%kernel.environment%.log'
            level: debug
            max_files: 10

Utilisez max_files pour modifier le nombre de jours à conserver.

Filtrer les messages d’erreurs

En production, on a souvent besoin d’une journalisation réduite. Dans ce cas, on utilise le gestionnaire de type fingers_crossed qui va agir comme un buffer : il stocke toutes les entrées de la requête courante puis les transfère à un autre gestionnaire que lorsqu’une entrée log a un niveau d’erreur au moins équivalente à un seuil (qu’on défini bien sûr). Voyons la configuration du mode production de Symfony :

monolog:
    handlers:
        main:
            type: fingers_crossed
            action_level: error
            handler: nested
            excluded_404s:
                # regex: exclude all 404 errors from the logs
                - ^/
        nested:
            type: stream
            path: "%kernel.logs_dir%/%kernel.environment%.log"
            level: debug

La clé action_level défini le seuil de déclenchement, handler défini le gestionnaire à utiliser. Ici, dès qu’une erreur a niveau au moins égal à error, toutes entrées (y compris celle qui déclenche le gestionnaire) sont envoyées au gestionnaire nested qui lui va va écrire dans le fichier prod.log. Comme précédemment, la clé level du gestionnaire nested défini le niveau d’erreur minimal des entrées à inscrire dans le fichier.
L’intérêt de ce gestionnaire est majeur : s’il n’y a pas d’erreurs d’un certain niveau, on n’encombre pas les logs inutilement… Par contre, en cas d’erreur sérieuse, on a tous les messages d’erreur à notre disposition.

Logs système

Un type de gestionnaire intéressant est syslog. Il permet de stocker des entrées log via le système de log de la machine qui fait tourner l’application. Par exemple, en production, on peut ajouter un tel gestionnaire :

monolog:
    handlers:
        main:
            type: fingers_crossed
            action_level: error
            handler: nested
            excluded_404s:
                # regex: exclude all 404 errors from the logs
                - ^/
        nested:
            type: stream
            path: "%kernel.logs_dir%/%kernel.environment%.log"
        # still passed *all* logs, and still only logs error or higher
        syslog_handler:
            type: syslog
            level: debug

Souvenez vous, les gestionnaires sont appelés dans l’ordre. Donc le gestionnaire syslog sera toujours appelé et il inscrira toutes les entrées dans les logs de la machine. Par exemple, sur une machine debian, le fichier est /var/log/syslog.

Happy debugging

monolog est compatible firephp et chromephp. Il suffit d’ajouter un gestionnaire :

monolog:
    handlers:
        firephp:
            type: firephp
            level: info

L’extension du même nom doit être installée et activée sur le navigateur. Ensuite, les entrées log s’affichent dans la console. A réserver au mode dev bien sûr…

Références externes

Poster le commentaire

Votre adresse e-mail ne sera pas publiée. Les champs obligatoires sont indiqués avec *