messages de journal apparaissant deux fois avec la journalisation Python

J'utilise la journalisation Python et, pour une raison quelconque, tous mes messages apparaissent deux fois.

J'ai un module pour configurer la journalisation:

# BUG: It's outputting logging messages twice - not sure why - it's not the propagate setting.
def configure_logging(self, logging_file):
    self.logger = logging.getLogger("my_logger")
    self.logger.setLevel(logging.DEBUG)
    self.logger.propagate = 0
    # Format for our loglines
    formatter = logging.Formatter("%(asctime)s - %(name)s - %(levelname)s - %(message)s")
    # Setup console logging
    ch = logging.StreamHandler()
    ch.setLevel(logging.DEBUG)
    ch.setFormatter(formatter)
    self.logger.addHandler(ch)
    # Setup file logging as well
    fh = logging.FileHandler(LOG_FILENAME)
    fh.setLevel(logging.DEBUG)
    fh.setFormatter(formatter)
    self.logger.addHandler(fh)

Plus tard, j'appelle cette méthode pour configurer la journalisation:

if __name__ == '__main__':
    tom = Boy()
    tom.configure_logging(LOG_FILENAME)
    tom.buy_ham()

Et puis dans disons, le module buy_ham, j'appellerais:

self.logger.info('Successfully able to write to %s' % path)

Et pour une raison quelconque, tous les messages apparaissent deux fois. J'ai commenté l'un des gestionnaires de flux, toujours la même chose. Un peu bizarre, je ne sais pas pourquoi cela se produit ... lol. En supposant que j'ai raté quelque chose d'évident.

Bravo, Victor

Vous appelez configure_loggingdeux fois (peut-être dans la __init__méthode de Boy): getLoggerrenvoie le même objet, mais addHandlerne vérifie pas si un gestionnaire similaire a déjà été ajouté à l'enregistreur.

Essayez de suivre les appels à cette méthode et d'éliminer l'un d'entre eux. Ou configurez un indicateur logging_initializedinitialisé Falsedans la __init__méthode de Boyet changez configure_loggingpour ne rien faire si logging_initializedc'est le cas True, et pour le définir Trueaprès avoir initialisé le logger.

Si votre programme crée plusieurs Boyinstances, vous devrez changer la façon dont vous faites les choses avec une configure_loggingfonction globale ajoutant les gestionnaires, et la Boy.configure_loggingméthode initialisant uniquement l' self.loggerattribut.

Une autre façon de résoudre ce problème consiste à vérifier l'attribut handlers de votre enregistreur:

logger = logging.getLogger('my_logger')
if not logger.handlers:
    # create the handlers and call logger.addHandler(logging_handler)

Si vous rencontrez ce problème et que vous n'ajoutez pas deux fois le gestionnaire, consultez la réponse d'abarnert ici

À partir de la documentation :

Remarque: Si vous attachez un gestionnaire à un enregistreur et à un ou plusieurs de ses ancêtres, il peut émettre le même enregistrement plusieurs fois. En général, vous ne devriez pas avoir besoin d'attacher un gestionnaire à plus d'un enregistreur - si vous l'attachez simplement à l'enregistreur approprié qui est le plus élevé dans la hiérarchie des enregistreurs, alors il verra tous les événements enregistrés par tous les enregistreurs descendants, à condition que leur propagation le paramètre est laissé sur True. Un scénario courant consiste à attacher les gestionnaires uniquement à l'enregistreur racine et à laisser la propagation s'occuper du reste.

Donc, si vous voulez un gestionnaire personnalisé sur "test", et que vous ne voulez pas que ses messages soient également envoyés au gestionnaire racine, la réponse est simple: désactivez son propagateindicateur:

logger.propagate = False

Le gestionnaire est ajouté chaque fois que vous appelez de l'extérieur. Essayez de supprimer le gestionnaire après avoir terminé votre travail:

self.logger.removeHandler(ch)

Je suis un débutant en python, mais cela a semblé fonctionner pour moi (Python 2.7)

while logger.handlers:
     logger.handlers.pop()

Dans mon cas, je devrais régler logger.propagate = Falsepour éviter la double impression.

Dans le code ci-dessous, si vous supprimez, logger.propagate = Falsevous verrez une double impression.

import logging
from typing import Optional

_logger: Optional[logging.Logger] = None

def get_logger() -> logging.Logger:
    global _logger
    if _logger is None:
        raise RuntimeError('get_logger call made before logger was setup!')
    return _logger

def set_logger(name:str, level=logging.DEBUG) -> None:
    global _logger
    if _logger is not None:
        raise RuntimeError('_logger is already setup!')
    _logger = logging.getLogger(name)
    _logger.handlers.clear()
    _logger.setLevel(level)
    ch = logging.StreamHandler()
    ch.setLevel(level)
    # warnings.filterwarnings("ignore", "(Possibly )?corrupt EXIF data", UserWarning)
    ch.setFormatter(_get_formatter())
    _logger.addHandler(ch)
    _logger.propagate = False # otherwise root logger prints things again


def _get_formatter() -> logging.Formatter:
    return logging.Formatter(
        '[%(asctime)s] [%(name)s] [%(levelname)s] %(message)s')

Un appel aux logging.debug()appels logging.basicConfig()s'il n'y a pas de gestionnaire racine installé. Cela se passait pour moi dans un cadre de test où je ne pouvais pas contrôler l'ordre dans lequel les cas de test étaient déclenchés. Mon code d'initialisation installait le second. La valeur par défaut utilise logging.BASIC_FORMAT que je ne voulais pas.

Il semble que si vous envoyez quelque chose à l'enregistreur (accidentellement) puis le configurez, il est trop tard. Par exemple, dans mon code j'avais

logging.warning("look out)"

...
ch = logging.StreamHandler(sys.stdout)
root = logging.getLogger()
root.addHandler(ch)

root.info("hello")

J'obtiendrais quelque chose comme (en ignorant les options de format)

look out
hello
hello

et tout a été écrit deux fois sur stdout. Je pense que c'est parce que le premier appel à logging.warningcrée un nouveau gestionnaire automatiquement, puis j'ai explicitement ajouté un autre gestionnaire. Le problème a disparu lorsque j'ai supprimé le premier logging.warningappel accidentel .

J'avais une situation étrange où les journaux de la console étaient doublés mais pas mes journaux de fichiers. Après une tonne de fouilles, j'ai compris.

Veuillez noter que les packages tiers peuvent enregistrer des enregistreurs. C'est quelque chose à surveiller (et dans certains cas ne peut être évité). Dans de nombreux cas, le code tiers vérifie s'il existe une racine gestionnaires de journalisation ; et s'il n'y en a pas, ils enregistrent un nouveau gestionnaire de console.

Ma solution était d'enregistrer mon enregistreur de console au niveau racine:

rootLogger = logging.getLogger()  # note no text passed in--that's how we grab the root logger
if not rootLogger.handlers:
        ch = logging.StreamHandler()
        ch.setLevel(logging.INFO)
        ch.setFormatter(logging.Formatter('%(process)s|%(levelname)s] %(message)s'))
        rootLogger.addHandler(ch)