Bienvenue sur IndexError.

Ici vous pouvez poser des questions sur Python et le Framework Django.

Mais aussi sur les technos front comme React, Angular, Typescript et Javascript en général.

Consultez la FAQ pour améliorer vos chances d'avoir des réponses à vos questions.

Logging, le nombre de logs s'incrément à chaque demande de création de Log.

+4 votes

J'ai commencé Python il y a peu et j'ai repris le code permettant de générer des logs dans l'excellent tutorial de Sam.

Les logs s'affichent correctement sauf qu'à chaque appel de logger.bidule("xxx"), le résultat est affiché plusieurs fois et s'incrémente à chaque fois.

Exemple :

logger.info('Hello')

Hello

logger.info('Hello')

Hello
Hello

logger.info('Hello')
Hello
Hello
Hello
[...]

Je n'ai rien trouvé de concluant sur Internet si ce n'est qq explications qui dépassent mon niveau actuel. Je travaille sous Spyder sous Python 3.4 sous Windows. J'ai rencontré le même problème sous PyScripter en 3.2 toujours sous Windows. Par contre lorsque je passe directement par la console Python, le phénomène ne se reproduit pas.

J'ai aussi repris un exemple dans la doc officielle Python et ... idem.

J'ai contourné le problème en utilisant.

Logger.handlers.clear()

Pour vider les "handlers" mais je ne pense pas que cela soit très "propre" (je n'ai vu aucun programme utilisant Logging sur le net utilisant cet méthode.

Le problème vient-il de mon environnement de développement (Spyder) ou y a-t-il un concept que je n'ai pas compris.

Merci pour votre aide.

Code :

#!/usr/bin/env python
# -*- coding: utf-8 -*-

import logging

from logging.handlers import RotatingFileHandler

logger = logging.getLogger()
logger.setLevel(logging.DEBUG)

formatter = logging.Formatter('%(asctime)s :: %(levelname)s :: %(message)s')
file_handler = RotatingFileHandler('activity.log', 'a', 1000000, 1)
file_handler.setLevel(logging.DEBUG)
file_handler.setFormatter(formatter)
logger.addHandler(file_handler)

steam_handler = logging.StreamHandler()
steam_handler.setLevel(logging.DEBUG)
logger.addHandler(steam_handler)

Après 3 heures, on peut enfin logguer

Il est temps de spammer votre code avec des logs partout :

logger.info('Hello')
logger.warning('Testing %s', 'foo')
demandé 28-Aou-2015 par Tuxou (124 points)
reclassée 28-Aou-2015 par max

Voilà une solution possible au problème :
Ne pas utiliser spyder.

Autour de moi, une trentaine de personnes ont attaqué l'apprentissage de python en cadre universitaire. Beaucoup ont commencé par spyder.
Durant un an, il y a eu à résoudre des problèmes, qui, quand ils n'étaient pas liés à l'apprentissage du langage, était miraculeusement réglés lorsque spyder était remplacé par un autre IDE.

Eric, IDLE, voir un éditeur de texte (EMACS, (neo)vim) dans un environnement un minimum configuré sont de bonnes solutions que j'ai pu (voir) expérimenter.

Le fait qu'au sein de la console le problème ne se reproduise pas me conforte dans l'idée de spyder est à la source d'un problème qui n'a pas lieu d'être.

Discard technologies that need a hack today because they will need a design plan tomorrow.

1 Réponse

+5 votes

Le problème vient du fait que ton code initialisant logging et son logger est appelé plusieurs fois : à chaque import monModuleInitialisantLeLogging.

De fait, à chaque appel, un nouveau logger est configuré et ajouté, d'où une apparition incrémentale de message de log identiques. Cela explique aussi pourquoi Logger.handlers.clear() résoud le problème : à chaque appel le logger précédent est supprimé, et le nouveau est ajouté.

Une solution plus propre est de mettre l'initialisation de logging dans un fichier à part, par exemple initlogger.py, et de ne l'importer que dans un seul module, par exemple logs.

# file: logs/initlogger.py

import logging
from logging.handlers import RotatingFileHandler
# next lines of initialization…

Dans le même module, le fichier qui fait l'interface (ou dans l'init.py) :

# file: logs/logs.py

import logs.initlogger
from logging import *  # on veux un accès à tous les membres du module logging
# autres imports, définitions,… relatives à l'usage des logs

logs est importé de multiple fois, mais n'importera lui-même qu'une seule fois le module initlogger, évitant ainsi les initialisations incrémentales.

Et, dans tous les modules qui veulent faire des logs :

# file: entity/monster.py
import logs.logs as logs  # peut être simplifié avec l'usage d'un __init__.py dans le module logs

logger = logs.getLogger()
logger.info("here's Johnny !")

Personnellement, j'utilise le snippet suivant pour les logs, définition que j'ajoute dans initlogger.py, lui-même importé une seule fois dans le module poubelle commons.py ou utils.py :

LOGGER_NAME = 'HeliosOne'

def logger(sublogger=None, name=LOGGER_NAME):
    if sublogger:
        return logging.getLogger(name + '.' + sublogger)
    else:
        return logging.getLogger(name)

L'intérêt est qu'aucun module n'utilise logging directement, mais demande uniquement un point d'accès au logger.
Les autres modules fonctionnent donc ainsi :

import commons
logger = commons.logger('engine')  # ou gui, ou database, ou sans argument, selon le module
logger.info('Folsom Prison Blues')
répondu 28-Aou-2015 par lucas (2,314 points)
edité 28-Aou-2015 par lucas

En principe, le mécanisme d'import de python assure que le module importé n'est exécuté qu'une seule fois.

Qui plus est, le comportement décrit ne correspond pas, puisque le comportement est modufié au runtime, lors des appels à logger.info().

Merci pour cette réponse rapide.

Je vais essayer cela...

@yoch: il y a effectivement une protection built-in contre l’exécution multiple ; il y a donc un autre problème avec mon code qui nécessite cette protection.
Je testerais plus avant, car cela me titille un peu.

Et effectivement, je suis allé un peu vite en besogne pour ma réponse, croyant voir quelqu'un ayant le même problème que moi.

Et de fait, la question manque de code pour pouvoir reproduire le problème et y répondre. Peut-être ma réponse sera-t-elle tout de même aidante.

...