komunikaty dziennika pojawiające się dwukrotnie z rejestrowaniem w języku Python

Używam logowania w Pythonie iz jakiegoś powodu wszystkie moje wiadomości pojawiają się dwukrotnie.

Mam moduł do konfiguracji logowania:

# 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)

Później nazywam tę metodę, aby skonfigurować logowanie:

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

A potem, powiedzmy, moduł buy_ham zadzwoniłbym:

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

Z jakiegoś powodu wszystkie wiadomości pojawiają się dwukrotnie. Skomentowałem jeden z programów obsługi strumienia, wciąż to samo. Trochę dziwne, nie wiem, dlaczego tak się dzieje ... lol. Zakładając, że przegapiłem coś oczywistego.

Pozdrawiam, Victor

Dzwonisz configure_loggingdwukrotnie (może w __init__metodzie Boy): getLoggerzwróci ten sam obiekt, ale addHandlernie sprawdzi, czy podobny handler został już dodany do loggera.

Spróbuj prześledzić wywołania tej metody i wyeliminować jedną z nich. Lub skonfiguruj flagę logging_initializedzainicjowaną do Falsew __init__metodzie Boyi zmień, configure_loggingaby nic nie robić, jeśli logging_initializedtak True, i ustaw ją Truepo zainicjowaniu rejestratora.

Jeśli twój program tworzy kilka Boyinstancji, będziesz musiał zmienić sposób, w jaki robisz rzeczy za pomocą configure_loggingfunkcji globalnej dodającej moduły obsługi, a Boy.configure_loggingmetodę tylko inicjalizującą self.loggeratrybut.

Innym sposobem rozwiązania tego problemu jest sprawdzenie atrybutu handlers twojego loggera:

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

Jeśli widzisz ten problem i nie dodajesz programu obsługi dwa razy, zobacz odpowiedź abarnert tutaj

Z dokumentów :

Uwaga: Jeśli podłączysz program obsługi do rejestratora i jednego lub więcej jego przodków, może on wielokrotnie emitować ten sam rekord. Ogólnie rzecz biorąc, nie powinno być potrzeby dołączania programu obsługi do więcej niż jednego rejestratora - jeśli po prostu dołączysz go do odpowiedniego rejestratora, który znajduje się najwyżej w hierarchii rejestratorów, zobaczy on wszystkie zdarzenia zarejestrowane przez wszystkie podrzędne rejestratory, pod warunkiem, że ich propagacja ustawienie ma wartość True. Typowym scenariuszem jest dołączenie programów obsługi tylko do głównego programu rejestrującego, a propagacja zajmie się resztą.

Tak więc, jeśli chcesz, aby niestandardowy program obsługi był włączony „test” i nie chcesz, aby jego komunikaty również trafiały do ​​programu obsługi root, odpowiedź jest prosta: wyłącz propagateflagę:

logger.propagate = False

Program obsługi jest dodawany za każdym razem, gdy dzwonisz z zewnątrz. Spróbuj usunąć Handler po zakończeniu pracy:

self.logger.removeHandler(ch)

Jestem nowicjuszem w Pythonie, ale to wydawało się działać dla mnie (Python 2.7)

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

W moim przypadku ustawiłbym, logger.propagate = Falseaby zapobiec podwójnemu drukowaniu.

W poniższym kodzie, jeśli usuniesz logger.propagate = False, zobaczysz podwójne drukowanie.

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')

Wywołanie logging.debug()wywołań, logging.basicConfig()jeśli nie ma zainstalowanych programów obsługi root. Działo się to w przypadku mnie w ramach testów, w których nie mogłem kontrolować kolejności uruchamiania przypadków testowych. Mój kod inicjalizacyjny instalował drugi. Domyślnie używa logging.BASIC_FORMAT, którego nie chciałem.

Wygląda na to, że jeśli wypisujesz coś do rejestratora (przypadkowo), a następnie go skonfigurujesz, jest już za późno. Na przykład w moim kodzie miałem

logging.warning("look out)"

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

root.info("hello")

Dostałbym coś takiego (ignorując opcje formatu)

look out
hello
hello

i wszystko zostało dwukrotnie zapisane na standardowe wyjście. Uważam, że dzieje się tak, ponieważ pierwsze wywołanie logging.warningautomatycznie tworzy nową procedurę obsługi, a następnie wyraźnie dodałem kolejną procedurę. Problem zniknął, gdy usunąłem przypadkowe pierwsze logging.warningpołączenie.

Otrzymałem dziwną sytuację, w której dzienniki konsoli były podwojone, ale dzienniki moich plików nie. Po wielu kopaniu zrozumiałem.

Należy pamiętać, że pakiety stron trzecich mogą rejestrować loggery. Jest to coś, na co należy uważać (aw niektórych przypadkach nie można temu zapobiec). W wielu przypadkach kod strony trzeciej sprawdza, czy istnieje jakikolwiek root programy obsługi rejestrującego; a jeśli nie ma - rejestrują nowy program obsługi konsoli.

Rozwiązaniem tego problemu było zarejestrowanie mojego rejestratora konsoli na poziomie głównym:

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)