Logování v jazyce Python

K logování stavu aplikace slouží v Pythonu velmi propracovaný standardní modul logging. Použít tento modul je velmi jednoduché, může se ale stát, že programátor potřebuje netriviální funkcionalitu, a pak je třeba modul logging znát opravdu dobře.

Log světe!

import logging      # import logovaciho modulu

logging.basicConfig(level="INFO")       # nastaveni root loggeru
log = logging.getLogger(__name__)       # vytvoreni loggeru aplikace
log.setLevel("INFO")                    # nastaveni log levelu aplikace
log.info("Ahoj světe!")                 # logovani aplikacnim loggerem

Takovýchto ukázek je internet plný. Důležité ale je, co se opravdu děje. Modul logging pracuje tak, že vytváří jeden globální kořenový logger objekt s názvem root, na který putuje vše. Tzn že jakýkoli další logger je vytvořen, zprávy vždy tečou i na jeho rodiče, tedy i na hlavní kořenový objekt. Schéma putování zpráv je následující:

Schéma průchodu logovací zprávy. (Zdroj: https://docs.python.org)

Každý logger objekt má vlastní nastavení stupně logování, a každý logger může, ale nemusí mít vlastní handlery, které se starají o výstup/zápis log záznamů.

V praxi se to používá tak, že každá knihovna si vytvoří vlastní logger objekt a nastaví jeho důležitost, v případě produkčního prostředí typicky INFO nebo WARNING. Aplikace, která knihovnu používá, pak nastaví kořenový logger dle vlastních preferencí např. funkcí basicConfig. Ta vedle požadovaného nastavení vytvoří nový handler s výstupem do standardního chybového výstupu a veškeré zprávy, dle své důležitosti vypisuje.

Pokud chcete například posílat některé zprávy i emailem, můžete nastavit příslušnému loggeru další handler na posílání emailů. Ten pak bude posílat jeho zprávy i mailem dle svého nastavení důležitosti.

import logging
from logging.handlers import SMTPHandler

mail_handler = SMTPHandler(
    mailhost='127.0.0.1',
    fromaddr='server-error@example.com',
    toaddrs=['admin@example.com'],
    subject='Application Error'
)

log = logging.getLogger(__name__)
log.addHandler(mail_handler)

# chyba bude poslána mailem a objeví se i na standardním chybovém výstupu
log.error("Some app error")

Netriviální případ

Může se ale stát, že chyby z nějakého loggeru nebudete chtít posílat na standardní chybový výstup. Většina řešení, které na internetu najdete, to řeší nastavením důležitosti. Můžete tak nastavit handler kořene, že nebude zpracovávat zprávy z důležitostí menší než WARNING.

import logging

handler = logging.StreamHandler()
handler.setLevel("WARNING")

logging.basicConfig(handlers=[handler])
log = logging.getLogger(__name__)
log.setLevel("INFO")
log.info("Not printed to stderr")
log.warning("Printed to stderr")

Toto řešení sice funguje, ale výsledek nemusí být dostatečný. Vraťme se tedy ke schématu. Každý jeden logger objekt má vlastní nastavení důležitosti metodou setLevel. To filtruje zprávy při jeho přímém volání. Znamená to, že logger nezpracuje zprávu, která byla zadaná metodami log, debug, info, warning, atd. Pokud ale zpráva přijde z jeho podřízených loggerů, což je typické pro kořenový logger, je zpráva zpracována dál.

Každý logger může mít nastaveny handlery, starající se o výstup. Nemusí mít žádný, a může jich mít několik. Handler pak má své vlastní nastavení důležitosti. Kořenový logger tak může mít dva handlery, jeden který vše vypisuje do chybového výstupu, a druhý, který posílá maily jen pokud jde o chyby.

A aby toho nebylo málo, každý obslužný handler, i každý logger může mít nastavené filtry. Pokud se tedy stane, že chcete ignorovat, nebo jinak zpracovávat zprávy z některého modulu, můžete tak např. na handleru nastavit filtr, který bude filtrovat zprávy, ne jen podle důležitosti ale i podle zdroje.

import logging


def log_filter(record):
    if record.name == "ignore":
        return False
    return True


handler = logging.StreamHandler()
handler.addFilter(log_filter)
logging.basicConfig(handlers=[handler])

ignore = logging.getLogger("ignore")
ignore.error("Ignored message")

log = logging.getLogger(__name__)
log.error("Not ignored message")

Další možností by samozřejmě bylo nastavit důležitost na loggeru ignore dostatečně vysokou. Pokud bychom chtěli tomuto loggeru nastavit vlastní handler, pak by do něj ale žádné zprávy nechodily.

import logging


def log_filter(record):
    if record.name == "mail":
        return False
    return True


root_handler = logging.StreamHandler()
root_handler.addFilter(log_filter)
logging.basicConfig(handlers=[root_handler])

mail_handler = = SMTPHandler(
    mailhost='127.0.0.1',
    fromaddr='server-error@example.com',
    toaddrs=['admin@example.com'],
    subject='Application Error'
)

mail = logging.getLogger("mail")
mail.addHandler(mail_handler)
mail.error("Logger is set")

log = logging.getLogger(__name__)
log.error("Normal output")

Logging modul je velmi mocný pomocník. Libovolný jiný modul bude tento logovací modul pravděpodobně používat a je tedy vhodné s ním pracovat i v koncových aplikacích, minimálně proto, aby z aplikace neutekli nějaké chyby, které by měli skončit v log souboru.