Journalisation

Une introduction rapide sur la journalisation

Django utilise le module logging intégré de Python pour effectuer la journalisation système. L’utilisation de ce module est abordé en détails dans la propre documentation de Python. Cependant, si vous n’avez jamais utilisé le système de journalisation de Python (ou même si c’est le cas), voici un aperçu rapide.

Les acteurs en jeu

Une configuration de journalisation Python consiste en quatre parties :

• Journaliseurs
• Gestionnaires
• Filtres
• Formateurs

Journaliseurs

Un journaliseur (« logger ») est le point d’entrée dans le système de journalisation. Chaque journaliseur est un réceptacle nommé dans lequel les messages sont écrits en vue de leur traitement.

Un journaliseur est configuré avec un niveau de journalisation (« log level »). Ce niveau définit la sévérité des messages que le journaliseur va traiter. Python définit les niveaux de journalisation suivants :

• DEBUG: information système de bas niveau à des fins de débogage

• INFO: information système générale

• WARNING: information décrivant la présence d’un problème mineur.

• ERROR: information décrivant la présence d’un problème majeur.

• CRITICAL: information décrivant la présence d’un problème critique.

Chaque message écrit dans le journaliseur est un enregistrement de journal (« log record »). Chacun de ces enregistrements possède également un niveau de journalisation indiquant la sévérité de ce message spécifique. Un enregistrement de journal peut aussi contenir des métadonnées utiles décrivant l’événement à journaliser. Cela peut inclure des détails tels qu’une trace de débogage ou un code d’erreur.

Lorsqu’un message est transmis au journaliseur, le niveau de journalisation du message est comparé à celui du journaliseur. Si le niveau de journalisation du message correspond ou dépasse celui du journaliseur, le message continue d’être traité. Dans le cas contraire, le message est ignoré.

Dès qu’un journaliseur a déterminé qu’un message doit être traité, il est transmis à un gestionnaire (« handler »).

Gestionnaires

Le gestionnaire est le moteur déterminant ce qui doit arriver à chaque message d’un journaliseur. Il décrit un comportement particulier de journalisation, tel que l’écriture d’un message à l’écran, dans un fichier ou dans un connecteur réseau.

Comme les journaliseurs, les gestionnaires possèdent aussi un niveau de journalisation. Si le niveau de journalisation d’un enregistrement de journal n’est pas au moins équivalent à celui du gestionnaire, ce dernier ignore le message.

Un journaliseur peut avoir plusieurs gestionnaires et le niveau de journalisation de chaque gestionnaire peut être différent. De cette façon, il est possible de fournir différentes formes de notifications selon l’importance d’un message. Par exemple, vous pouvez installer un gestionnaire qui redirige les messages de niveau ERROR et CRITICAL vers un service de radiomessagerie, alors qu’un autre gestionnaire enverra tous les messages (y compris ceux de niveau ERROR et CRITICAL) dans un fichier pour analyse ultérieure.

Filtres

Un filtre permet d’ajouter un contrôle supplémentaire sur la sélection des enregistrements de journal lorsqu’ils sont transmis du journaliseur au gestionnaire.

Par défaut, tout message de journal dont le niveau de journalisation est suffisant sera traité. Cependant, en installant un filtre, vous pouvez définir des critères supplémentaires dans le processus de journalisation. Par exemple, vous pourriez installer un filtre limitant l’émission de messages de niveau ERROR à une source particulière.

Les filtres peuvent ont aussi la possibilité de modifier l’enregistrement de journal avant son émission. Par exemple, vous pourriez écrire un filtre qui abaisse le niveau de journalisation du message de ERROR à WARNING si certains critères sont respectés.

Les filtres peuvent être installés pour les journaliseurs ou pour les gestionnaires ; il est aussi possible d’enchaîner plusieurs filtres pour effectuer différentes actions de filtrage.

Formateurs

Pour terminer, un enregistrement de journal doit être produit sous forme de texte. Les formateurs spécifient le format exact de ce texte. En général, un formateur correspond à une chaîne de format Python contenant des attributs LogRecord ; cependant, vous pouvez très bien écrire vos propres formateurs afin d’implémenter un comportement de format spécifique.

La journalisation en pratique

Après avoir configuré les journaliseurs, les gestionnaires, les filtres et les formateurs, il reste à placer les appels de journalisation dans votre code. L’utilisation du système de journalisation est très simple. Voici un exemple :

# import the logging library
import logging

# Get an instance of a logger
logger = logging.getLogger(__name__)

def my_view(request, arg1, arg):
    ...
    if bad_mojo:
        # Log an error message
        logger.error('Something went wrong!')

Ça y est ! Lors de chaque entrée dans la condition bad_mojo, une ligne d’erreur sera insérée dans le journal.

Nommage des journaliseurs

L’appel à logging.getLogger() obtient (et crée si nécessaire) une instance de journaliseur. Cette instance est identifiée par un nom. Ce nom sert à identifier le journaliseur pour la configuration.

Par convention, le nom du journaliseur est habituellement __name__, le nom du module Python contenant le journaliseur. Cela permet de filtrer et de traiter les appels de journalisation selon les modules. Cependant, si vous organisez vos messages de journalisation d’une autre manière, vous pouvez indiquer n’importe quel nom sous forme de notation pointée pour identifier un journaliseur :

# Get an instance of a specific named logger
logger = logging.getLogger('project.interesting.stuff')

La notation pointée des noms de journaliseurs définit une hiérarchie. Le journaliseur project.interesting est considéré comme le parent du journaliseur project.interesting.stuff. Le journaliseur project est le parent du journaliseur project.interesting.

Pourquoi cette hiérarchie est-elle importante ? Et bien, parce que les journaliseurs peuvent être configurés pour propager les appels de journalisation qu’ils reçoivent vers leurs parents. De cette manière, vous pouvez définir un seul ensemble de gestionnaires à la racine de l’arborescence d’un journaliseur et capturer tous les appels de journalisation dans la sous-arborescence des journaliseurs. Un gestionnaire de journalisation défini dans l’espace de noms project intercepte tous les messages de journalisation émis au niveau des journaliseurs project.interesting et project.interesting.stuff.

Cette propagation peut être contrôlée pour chaque journaliseur individuellement. Si vous souhaitez qu’un journaliseur particulier ne propage pas les messages à ses parents, vous pouvez désactiver ce comportement.

Appels de journalisation

Toute instance de journaliseur contient une méthode d’appel correspondant à chaque niveau de journalisation par défaut :

• logger.debug()
• logger.info()
• logger.warning()
• logger.error()
• logger.critical()

Deux autres appels de journalisation sont disponibles :

• logger.log(): émet manuellement un message de journalisation au niveau indiqué.

• logger.exception(): crée un message de journalisation de niveau ERROR enveloppant la pile d’exception actuelle.

Configuration de la journalisation

Le placement d’appels de journalisation dans le code n’est naturellement pas suffisant. Il faut aussi configurer les journaliseurs, les gestionnaires, les filtres et les formateurs pour s’assurer que le résultat de la journalisation s’affiche de manière exploitable.

La bibliothèque de journalisation de Python fournit plusieurs techniques de configuration, que ce soit par interface programmable ou par des fichiers de configuration. Par défaut, Django utilise le format dictConfig.

Pour configurer la journalisation, il s’agit de définir un dictionnaire de réglages de journalisation dans LOGGING. Ces réglages décrivent les journaliseurs, les gestionnaires, les filtres et les formateurs que vous souhaitez mettre en place, ainsi que les niveaux de journalisation et d’autres propriétés que vous voulez attribuer à ces composants.

Par défaut, le réglage LOGGING est fusionné avec la configuration de journalisation par défaut de Django en se basant sur les principes suivants.

Si la clé disable_existing_loggers du dictionnaire LOGGING contient True (valeur par défaut), tous les journaliseurs de la configuration par défaut seront désactivés. Désactiver un journaliseur n’est pas équivalent à sa suppression ; le journaliseur existe toujours, mais il élimine silencieusement les messages qu’il reçoit, sans même les propager au journaliseur parent. Vous devez donc vous méfier du réglage 'disable_existing_loggers': True; cela ne fait souvent pas ce qu’on aimerait. Par contre, vous pouvez définir disable_existing_loggers à False et redéfinir certains ou tous les journaliseurs par défaut. Une autre stratégie est de définir LOGGING_CONFIG à None et vous charger vous-même de la configuration de la journalisation.

La journalisation est configurée dans le cadre de la fonction setup() générale de Django. Ainsi, vous pouvez être certain que les journaliseurs sont toujours prêts à être utilisés par le code de votre projet.

Exemples

La documentation complète du format dictConfig est la meilleure source d’informations concernant les dictionnaires de configuration de la journalisation. Cependant, pour vous donner un petit aperçu de ce qui est réalisable, voici quelques exemples.

Premièrement, voici une configuration simple qui écrit toutes les journalisations de requête provenant du journaliseur django.request dans un fichier local :

LOGGING = {
    'version': 1,
    'disable_existing_loggers': False,
    'handlers': {
        'file': {
            'level': 'DEBUG',
            'class': 'logging.FileHandler',
            'filename': '/path/to/django/debug.log',
        },
    },
    'loggers': {
        'django.request': {
            'handlers': ['file'],
            'level': 'DEBUG',
            'propagate': True,
        },
    },
}

Si vous utilisez cet exemple, prenez soin de remplacer le chemin 'filename' par un emplacement accessible en écriture par l’utilisateur faisant fonctionner l’application Django.

Deuxièmement, voici un exemple expliquant comment journaliser les messages de Django dans la console. Il surcharge le réglage qui empêche django.request et django.security de propager par défaut les messages qu’ils reçoivent. Cela peut se révéler utile en phase de développement local.

Par défaut, cette configuration n’envoie que les messages de niveau INFO ou plus élevé vers la console. Django ne génère pas tant de messages de ce genre. Définissez la variable d’environnement DJANGO_LOG_LEVEL=DEBUG pour voir tous les messages de débogage journalisés par Django, ce qui est très bavard car toutes les requêtes de base de données sont incluses :

import os

LOGGING = {
    'version': 1,
    'disable_existing_loggers': False,
    'handlers': {
        'console': {
            'class': 'logging.StreamHandler',
        },
    },
    'loggers': {
        'django': {
            'handlers': ['console'],
            'level': os.getenv('DJANGO_LOG_LEVEL', 'INFO'),
        },
    },
}

Finalement, voici un exemple d’une configuration de journalisation plutôt complexe :

LOGGING = {
    'version': 1,
    'disable_existing_loggers': False,
    'formatters': {
        'verbose': {
            'format': '%(levelname)s %(asctime)s %(module)s %(process)d %(thread)d %(message)s'
        },
        'simple': {
            'format': '%(levelname)s %(message)s'
        },
    },
    'filters': {
        'special': {
            '()': 'project.logging.SpecialFilter',
            'foo': 'bar',
        },
        'require_debug_true': {
            '()': 'django.utils.log.RequireDebugTrue',
        },
    },
    'handlers': {
        'console': {
            'level': 'INFO',
            'filters': ['require_debug_true'],
            'class': 'logging.StreamHandler',
            'formatter': 'simple'
        },
        'mail_admins': {
            'level': 'ERROR',
            'class': 'django.utils.log.AdminEmailHandler',
            'filters': ['special']
        }
    },
    'loggers': {
        'django': {
            'handlers': ['console'],
            'propagate': True,
        },
        'django.request': {
            'handlers': ['mail_admins'],
            'level': 'ERROR',
            'propagate': False,
        },
        'myproject.custom': {
            'handlers': ['console', 'mail_admins'],
            'level': 'INFO',
            'filters': ['special']
        }
    }
}

Cette configuration de journalisation effectue les choses suivantes :

• Elle identifie la configuration comme étant au format « dictConfig version 1 ». C’est actuellement la seule version du format dictConfig.

• Elle définit deux formateurs :

  • simple qui ne fait qu’afficher le nom du niveau de journal (par ex. DEBUG) et le message de journal.

    La chaîne format est une chaîne de format Python normale décrivant les détails de ce qui doit être affiché pour chaque ligne de journal. La liste complète des détails pouvant être affichés se trouve dans la documentation des formateurs.

  • verbose qui affiche le nom du niveau de journal, le message de journal ainsi que l’heure, le processus, le fil d’exécution et le module qui ont généré le message.

• Elle définit deux filtres :

  • project.logging.SpecialFilter par l’alias special. Si ce filtre nécessite des paramètres supplémentaires, ils peuvent être fournis sous forme de clés supplémentaires dans le dictionnaire de configuration du filtre. Dans ce cas, le paramètre foo reçoit la valeur bar au moment de l’instanciation de SpecialFilter.

  • django.utils.log.RequireDebugTrue, qui transmet plus loin les messages lorsque DEBUG vaut True.

• Elle définit deux gestionnaires :

  • console, un gestionnaire StreamHandler affichant tout message de niveau DEBUG ou plus élevé vers la sortie d’erreur (stderr). Ce gestionnaire utilise le format d’affichage simple.

  • mail_admins, un gestionnaire AdminEmailHandler qui avertit par courriel les administrateurs du site de tout message de niveau ERROR ou plus élevé. Ce gestionnaire utilise le filtre d’affichage special.

• Elle configure trois journaliseurs :

  • django, qui transmet tous les messages au gestionnaire console.

  • django.request qui transmet tous les messages de niveau ERROR au gestionnaire mail_admins. De plus, ce journaliseur est configuré pour ne pas propager les messages. Cela signifie que les messages à destination de django.request ne seront pas traités par le journaliseur parent django.

  • myproject.custom qui transmet tous les messages de niveau INFO ou plus élevé et correspondant au filtre special vers deux gestionnaires, console et mail_admins. Cela signifie que tous les messages de niveau INFO ou plus élevé seront affichés dans la console. Les messages de niveau ERROR et CRITICAL seront de plus expédiés par courriel.

Configuration personnalisée de la journalisation

Si vous ne souhaitez pas utiliser le format dictConfig de Python pour configurer la journalisation, il est possible d’indiquer un système de configuration alternatif.

Le réglage LOGGING_CONFIG définit l’exécutable utilisé pour configurer les journaliseurs de Django. Par défaut, il indique la fonction logging.config.dictConfig() de Python. Cependant, si vous souhaitez utiliser un autre procédé de configuration, vous pouvez indiquer n’importe quel autre exécutable acceptant un seul paramètre. Le contenu de LOGGING sera fourni comme valeur de ce paramètre au moment de la configuration de la journalisation.

Désactivation de la configuration de journalisation

Si vous ne souhaitez pas configurer de journalisation (ou que vous vouliez le faire manuellement selon votre propre méthode), vous pouvez définir LOGGING_CONFIG à None. Cela va désactiver le processus de configuration pour la ref:journalisation par défaut de Django <default-logging-configuration>. Voici un exemple qui désactive la configuration de journalisation de Django, puis qui configure manuellement la journalisation :

settings.py

LOGGING_CONFIG = None

import logging.config
logging.config.dictConfig(...)

En définissant LOGGING_CONFIG à None, vous ne faites que désactiver le processus de configuration automatique, pas la journalisation elle-même. Même quand vous désactivez le processus de configuration, Django continue de faire appel à la journalisation, dont le comportement correspondra alors à ce qui est défini par défaut.

Extensions de journalisation de Django

Django fournit un certain nombre d’utilitaires pour gérer les exigences particulières de la journalisation dans le contexte d’un environnement de serveur Web.

Journaliseurs

Django fournit plusieurs journaliseurs intégrés :

django

django est le journaliseur « fourre-tout ». Aucun message n’est directement envoyé à ce journaliseur.

django.request

Messages de journal liés au traitement des requêtes. Les réponses 5xx sont signalées comme des messages ERROR. Les réponses 4xx sont signalées comme des messages WARNING.

Les messages envoyés à ce journaliseur possèdent le contexte supplémentaire suivant :

• status_code: le code de réponse HTTP associé à la requête.

• request: l’objet requête qui a généré le message de journal.

django.db.backends

Messages en lien avec l’interaction entre le code et la base de données. Par exemple, chaque instruction SQL de niveau applicatif exécutée par une requête est envoyée à ce journaliseur au niveau DEBUG.

Les messages envoyés à ce journaliseur possèdent le contexte supplémentaire suivant :

• duration: le temps d’exécution de l’instruction SQL concernée.

• sql: l’instruction SQL exécutée.

• params: les paramètres utilisés dans l’appel SQL.

Pour des raisons de performance, la journalisation SQL n’est activée que lorsque settings.DEBUG est défini à True, peu importe le niveau de journalisation ou les gestionnaires installés.

Cette journalisation ne concerne pas l’initialisation au niveau infrastructure (par ex. SET TIMEZONE) ni les requêtes de gestion de transaction (par ex. BEGIN, COMMIT ou ROLLBACK). Activez la journalisation des requêtes au niveau de la base de données si vous souhaitez voir toutes les requêtes à la base de données.

django.security.*

Les journaliseurs security reçoivent les messages à chaque occurrence de SuspiciousOperation. Il existe un sous-sérialiseur pour chaque sous-type de SuspiciousOperation. Le niveau des événements journalisés dépend de l’endroit où l’exception est traitée. La plupart des occurrences sont journalisées comme des avertissements, alors que toute exception SuspiciousOperation atteignant le gestionnaire WSGI sera journalisée comme une erreur. Par exemple, lorsqu’un en-tête HTTP Host contenu dans une requête de client ne correspond pas à ALLOWED_HOSTS, Django renvoie une réponse 400 et un message d’erreur est journalisé dans le journaliseur django.security.DisallowedHost.

Seul le journaliseur parent django.security est configuré par défaut et tous les journaliseurs enfants propagent les messages à leur parent. Le journaliseur django.security est configuré de la même façon que django.request et tout événement de type erreur est envoyé par courriel aux administrateurs. Les requêtes aboutissant à une réponse 400 en raison d’une erreur SuspiciousOperation ne sont pas journalisées dans django.request, mais seulement dans le journaliseur django.security.

Pour réduire au silence un type particulier de SuspiciousOperation, vous pouvez surcharger le journaliseur correspondant en suivant cet exemple :

'handlers': {
    'null': {
        'class': 'logging.NullHandler',
    },
},
'loggers': {
    'django.security.DisallowedHost': {
        'handlers': ['null'],
        'propagate': False,
    },
},

django.db.backends.schema

New in Django 1.7.

Journalise les requêtes SQL exécutées pendant les modifications de schéma de la base de données effectuées par le système des migrations. Notez que les requêtes exécutées par RunPython ne sont pas journalisées.

Gestionnaires

Django propose un gestionnaire de journalisation en plus de ceux offerts par le module logging de Python.

class AdminEmailHandler(include_html=False, email_backend=None)[source]

Ce gestionnaire envoie un courriel aux administrateurs du site pour chaque message de journal qu’il reçoit.

Si le message de journalisation contient un attribut request, les détails complets de la requête seront inclus dans le courriel. Le sujet du courriel contiendra « internal IP » si l’adresse IP du client se trouve dans le réglage INTERNAL_IPS; sinon, il contiendra « EXTERNAL IP ».

Si la ligne de journal contient des informations sur une trace de débogage, celle-ci est incluse dans le courriel.

Le paramètre include_html de AdminEmailHandler est utilisé pour contrôler si le courriel contenant la trace de débogage doit inclure une pièce jointe HTML contenant la page Web complète de débogage qui aurait été affichée si le réglage DEBUG valait True. Pour définir cette valeur dans votre configuration, incluez ce paramètre dans la définition du gestionnaire pour django.utils.log.AdminEmailHandler, comme ceci :

'handlers': {
    'mail_admins': {
        'level': 'ERROR',
        'class': 'django.utils.log.AdminEmailHandler',
        'include_html': True,
    }
},

Notez que cette version HTML du courriel contient une trace de débogage complète, avec les noms et valeurs des variables locales à chaque niveau de la trace, en plus des valeurs de vos réglages Django. Ces informations peuvent contenir des éléments très sensibles et il n’est pas toujours souhaitable de les envoyer par courriel. Envisagez l’utilisation d’un service comme Sentry pour obtenir le meilleur des deux mondes, de riches informations avec des traces de débogage complètes, mais avec la sécurité de ne pas envoyer ces informations par messagerie. Vous pouvez aussi désigner explicitement certaines informations sensibles comme devant être exclues des rapports d’erreurs ; voir Filtrage des rapports d’erreurs pour plus de détails à ce sujet.

En définissant le paramètre email_backend de AdminEmailHandler, le moteur de messagerie utilisé par le gestionnaire peut être surchargé, comme ceci :

'handlers': {
    'mail_admins': {
        'level': 'ERROR',
        'class': 'django.utils.log.AdminEmailHandler',
        'email_backend': 'django.core.mail.backends.filebased.EmailBackend',
    }
},

Par défaut, c’est une instance du moteur de messagerie indiqué dans EMAIL_BACKEND qui est utilisée.

send_mail(subject, message, *args, **kwargs)[source]

New in Django 1.8.

Envoie des courriels aux utilisateurs administrateurs. Pour personnaliser ce comportement, vous pouvez créer une sous-classe de AdminEmailHandler et surcharger cette méthode.

Filtres

Django propose deux filtres de journalisation en plus de ceux offerts par le module logging de Python.

class CallbackFilter(callback)[source]

Ce filtre accepte une fonction de rappel (qui ne doit accepter qu’un seul paramètre, l’enregistrement à journaliser) et appelle celle-ci pour chaque enregistrement qui transite par ce filtre. Le traitement de l’enregistrement s’arrête si la fonction de rappel renvoie False.

Par exemple, pour exclure UnreadablePostError (généré lorsqu’un utilisateur annule un téléversement) des courriels envoyés aux administrateurs, cette fonction de filtre pourrait être créée :

from django.http import UnreadablePostError

def skip_unreadable_post(record):
    if record.exc_info:
        exc_type, exc_value = record.exc_info[:2]
        if isinstance(exc_value, UnreadablePostError):
            return False
    return True

puis ajoutée à la configuration de journalisation :

'filters': {
    'skip_unreadable_posts': {
        '()': 'django.utils.log.CallbackFilter',
        'callback': skip_unreadable_post,
    }
},
'handlers': {
    'mail_admins': {
        'level': 'ERROR',
        'filters': ['skip_unreadable_posts'],
        'class': 'django.utils.log.AdminEmailHandler'
    }
},

class RequireDebugFalse[source]

Ce filtre ne laisse passer les enregistrements que lorsque settings.DEBUG vaut False.

Ce filtre est utilisé comme le montre l’exemple ci-dessous dans la configuration par défaut de LOGGING pour garantir que AdminEmailHandler n’envoie des courriels d’erreur aux administrateurs que lorsque DEBUG vaut False:

'filters': {
    'require_debug_false': {
        '()': 'django.utils.log.RequireDebugFalse',
    }
},
'handlers': {
    'mail_admins': {
        'level': 'ERROR',
        'filters': ['require_debug_false'],
        'class': 'django.utils.log.AdminEmailHandler'
    }
},

class RequireDebugTrue[source]

Ce filtre est similaire à RequireDebugFalse, sauf que les enregistrements ne sont retransmis que lorsque DEBUG vaut True.

Configuration de journalisation par défaut de Django

Par défaut, Django configure la journalisation suivante :

Lorsque DEBUG vaut True:

• Le journaliseur « fourre-tout » django envoie tous les messages du niveau WARNING ou plus élevé vers la console. Pour l’instant, Django n’envoie aucun message de ce type (toute la journalisation se fait au niveau DEBUG ou est interceptée par les journaliseurs django.request et django.security).

• Le journaliseur py.warnings qui s’occupe des messages produits par warnings.warn(), envoie les messages vers la console.

Lorsque DEBUG vaut False:

• Les journaliseurs django.request et django.security envoie les messages de niveau ERROR ou CRITICAL vers AdminEmailHandler. Ces journaliseurs ignorent tout ce qui est au niveau WARNING (avertissement) ou plus bas et les messages journalisés ne sont pas propagés vers d’autres journaliseurs (ils n’atteindront pas le journaliseur « fourre-tout » django, même quand DEBUG vaut True).

Consultez aussi Configuration de la journalisation pour savoir comment compléter ou remplacer cette configuration de journalisation par défaut.