Python Logging – najprostszy przewodnik z pełnym kodem i przykładami

Moduł logowania pozwala monitorować działanie kodu, dzięki czemu w przypadku awarii kodu można sprawdzić logi i określić, co ją spowodowało. Komunikaty dziennika mają wbudowaną hierarchię – począwszy od debugowania, komunikatów informacyjnych, ostrzeżeń, błędów i komunikatów krytycznych. Możesz również dołączyć informacje o powrocie do źródła. Jest on przeznaczony dla małych i dużych projektów python z wieloma modułami i jest wysoce zalecany dla każdego modułowego programowania python. Ten post jest prostym i jasnym wyjaśnieniem, jak używać modułu logowania.

Logowanie w Pythonie – uproszczony przewodnik z pełnym kodem i przykładami. Photo by Andrea Reiman.

Content

1. 1. Dlaczego logowanie?
   2. Podstawowy przykład logowania
   3. Pięć poziomów logowania
   4. Jak logować do pliku zamiast do konsoli
   5. Jak zmienić format logowania
   6. Dlaczego praca z głównym loggerem dla wszystkich modułów nie jest najlepszym pomysłem
   7. Jak utworzyć nowy logger?
   8. Co to jest i jak skonfigurować File Handler i Formatter?
   9. Jak dołączyć informacje zwrotne do logowanych wiadomości
   10. Ćwiczenia
   11. Zakończenie

Dlaczego warto logować?

Wyobraź sobie, że uruchamiasz skrypt w pythonie i chcesz wiedzieć, jaka część skryptu została wykonana, w jakim czasie i w niektórych przypadkach sprawdzić, jakie wartości mają zmienne.

Zwykle możesz po prostu 'print()' wypisać znaczące komunikaty, abyś mógł je zobaczyć w konsoli. I to prawdopodobnie jest wszystko, czego potrzebujesz, gdy tworzysz małe programy.

Problem polega na tym, że gdy używasz tego podejścia w większych projektach zawierających wiele modułów, chcesz bardziej uporządkowanego, solidnego podejścia.

Dlaczego?

Ponieważ, kod może przechodzić przez różne etapy, takie jak rozwój, debugowanie, przegląd, testowanie lub przejście do produkcji, chcesz zobaczyć różne poziomy szczegółów w wydrukowanych wiadomościach.

Typ wiadomości, które chcesz wydrukować podczas rozwoju lub debugowania może być bardzo różny od tego, co chcesz zobaczyć, gdy trafi do produkcji. W zależności od celu, chcesz, aby kod drukował różne typy wiadomości.

Wyobraź sobie, że robisz to wszystko używając tylko if else i print.

Poza tym, istnieje pewien poziom hierarchii potrzebny w drukowanych komunikatach.

To znaczy, podczas pewnego 'testowego' uruchomienia, chcesz zobaczyć tylko ostrzeżenia i komunikaty o błędach. Podczas gdy podczas „debugowania” potrzebne są bardziej szczegółowe komunikaty, które pomagają w debugowaniu. Poza tym, jeśli chcemy wypisać na jakim module i w jakim czasie zostały uruchomione kody, w skrypcie pythona robi się bałagan.

Wszystkie te kwestie są ładnie rozwiązane przez moduł logging.

Używając logowania, możesz:

1. Kontrolować poziom komunikatów, aby logować tylko te wymagane
2. Kontrolować gdzie pokazywać lub zapisywać logi
3. Kontrolować jak formatować logi za pomocą wbudowanych-w szablonach wiadomości
4. Wiedzieć, z którego modułu pochodzą wiadomości

Możesz powiedzieć 'Widzę, że logging może być użyteczny, ale wydaje się zbyt techniczny i wydaje się być trochę trudny do ogarnięcia'. Cóż, tak, logging wymaga trochę krzywej uczenia się, ale właśnie po to jest ten post: sprawić, aby logowanie było łatwe do nauczenia.

Bez dalszej zwłoki, przejdźmy od razu do rzeczy.

Podstawowy przykład logowania

Python dostarcza wbudowany logging moduł, który jest częścią standardowej biblioteki Pythona. Nie musisz więc niczego instalować.

Aby używać logowania, wystarczy podstawowa konfiguracja za pomocą logging.basicConfig(). Właściwie, jest to również opcjonalne. Przekonamy się o tym wkrótce.

Wtedy, zamiast print(), wywołujemy logging.{level}(message) aby pokazać komunikat w konsoli.

import logginglogging.basicConfig(level=logging.INFO)def hypotenuse(a, b): """Compute the hypotenuse""" return (a**2 + b**2)**0.5logging.info("Hypotenuse of {a}, {b} is {c}".format(a=3, b=4, c=hypotenuse(a,b)))#> INFO:root:Hypotenuse of 3, 4 is 5.0

Wydrukowany komunikat logu ma następujący domyślny format: {LEVEL}:{LOGGER}:{MESSAGE}.

W powyższym przypadku, poziom to info, ponieważ, wywołałem logging.info().

Logger nazywa się root, ponieważ jest to domyślny logger, a ja nie utworzyłem jeszcze nowego.

Ale czym w ogóle jest logger?

Logger jest jak encja, którą możesz stworzyć i skonfigurować do logowania różnego typu i formatu wiadomości.

Możesz skonfigurować logger, który drukuje na konsolę i inny logger, który wysyła logi do pliku, ma inny poziom logowania i jest specyficzny dla danego modułu. Więcej wyjaśnień i przykładów na ten temat już wkrótce.

Na koniec, wiadomość to ciąg znaków, który przekazałem do logging.info().

Teraz, co by się stało, gdybyś nie skonfigurował logging.basicConfig(level=logging.INFO)?

Odpowiedź: Log nie zostałby wydrukowany.

Dlaczego?

Aby to wiedzieć, zrozummy poziomy logowania.

Pięć poziomów logowania

logging Ma 5 różnych hierarchicznych poziomów logów, do których dany logger może być skonfigurowany.

Zobaczmy, co python docs ma do powiedzenia na temat każdego poziomu:

1. DEBUG: Szczegółowe informacje, do diagnozowania problemów. Wartość=10.
2. INFO: Potwierdzenie, że rzeczy działają zgodnie z oczekiwaniami. Wartość=20.
3. Ostrzeżenie: Stało się coś nieoczekiwanego, lub wskazującego na jakiś problem. Ale oprogramowanie nadal działa zgodnie z oczekiwaniami. Value=30.
4. ERROR: Poważniejszy problem, oprogramowanie nie jest w stanie wykonać jakiejś funkcji. Wartość=40
5. KRYTYCZNY: Poważny błąd, sam program może nie być w stanie kontynuować pracy. Wartość=50

Teraz, wracając do poprzedniego pytania, co by się stało gdybyś nie ustawił logging.basicConfig(level=logging.INFO) w poprzednim przykładzie.

Odpowiedź brzmi: log nie zostałby wydrukowany ponieważ, domyślnym loggerem jest 'root' a jego domyślny poziom basicConfig to 'WARNING'. Oznacza to, że tylko wiadomości z logging.warning() i wyższych poziomów będą logowane.

Więc, wiadomość z logging.info() nie zostanie wydrukowana. I właśnie dlatego podstawowy config został ustawiony jako INFO początkowo (w logging.basicConfig(level=logging.INFO)).

Gdybym ustawił poziom jako logging.ERROR zamiast tego, tylko wiadomość z logging.error i logging.critical będzie rejestrowana. Jasne?

import logginglogging.basicConfig(level=logging.WARNING)def hypotenuse(a, b): """Compute the hypotenuse""" return (a**2 + b**2)**0.5kwargs = {'a':3, 'b':4, 'c':hypotenuse(3, 4)}logging.debug("a = {a}, b = {b}".format(**kwargs))logging.info("Hypotenuse of {a}, {b} is {c}".format(**kwargs))logging.warning("a={a} and b={b} are equal".format(**kwargs))logging.error("a={a} and b={b} cannot be negative".format(**kwargs))logging.critical("Hypotenuse of {a}, {b} is {c}".format(**kwargs))#> WARNING:root:a=3 and b=3 are equal#> ERROR:root:a=-1 and b=4 cannot be negative#> CRITICAL:root:Hypotenuse of a, b is 5.0

Jak logować do pliku zamiast do konsoli

Aby wysyłać logi do pliku z głównego loggera, musisz ustawić argument file w logging.basicConfig()

import logginglogging.basicConfig(level=logging.INFO, file='sample.log')

Teraz wszystkie kolejne komunikaty dziennika będą trafiały bezpośrednio do pliku 'sample.log' w twoim bieżącym katalogu roboczym. Jeśli chcesz wysłać je do pliku w innym katalogu, podaj pełną ścieżkę do pliku.

Jak zmienić format logowania

Moduł logowania dostarcza skrótów do dodawania różnych szczegółów do logowanych wiadomości. Poniższy obrazek z dokumentów Pythona pokazuje tę listę.

Zmieńmy format komunikatu logowania, aby pokazywał CZAS, POZIOM i WIADOMOŚĆ. Aby to zrobić, wystarczy dodać format do argumentu format logging.basiconfig().

import logginglogging.basicConfig(level=logging.INFO, format='%(asctime)s :: %(levelname)s :: %(message)s')logging.info("Just like that!")#> 2019-02-17 11:40:38,254 :: INFO :: Just like that!

6. Dlaczego praca z loggerem root dla wszystkich modułów nie jest najlepszym pomysłem

Ponieważ wszystkie będą współdzielić ten sam logger 'root'.

Ale dlaczego to jest złe?

Przyjrzyjrzyjmy się poniższemu kodowi:

# 1. code inside myprojectmodule.pyimport logginglogging.basicConfig(file='module.log')#-----------------------------# 2. code inside main.py (imports the code from myprojectmodule.py)import loggingimport myprojectmodule # This runs the code in myprojectmodule.pylogging.basicConfig(file='main.log') # No effect, because!

Wyobraź sobie, że masz jeden lub więcej modułów w swoim projekcie. I te moduły używają podstawowego modułu root. Następnie, podczas importowania modułu ('myprojectmodule.py'), cały kod tego modułu zostanie uruchomiony, a logger zostanie skonfigurowany.

Po skonfigurowaniu, logger root w głównym pliku (który zaimportował moduł 'myprojectmodule') nie będzie już mógł zmienić ustawień loggera root. Ponieważ, logging.basicConfig() raz ustawione nie mogą być zmienione.

To znaczy, jeśli chcesz logować wiadomości z myprojectmodule do jednego pliku i logi z głównego modułu w innym pliku, root logger nie może tego zrobić.

Aby to zrobić musisz utworzyć nowy logger.

Jak utworzyć nowy logger?

Możesz utworzyć nowy logger używając metody 'logger.getLogger(name)'. Jeśli logger o tej samej nazwie istnieje, to zostanie on użyty.

Mimo, że możesz nadać loggerowi dowolną nazwę, konwencją jest użycie zmiennej __name__ w ten sposób:

logger = logging.getLogger(__name__)logger.info('my logging message')

Ale dlaczego używać __name__ jako nazwy loggera, zamiast wpisywać nazwę na sztywno?

Ponieważ zmienna __name__ będzie przechowywała nazwę modułu (pliku python), który wywołał kod. Tak więc, gdy zostanie użyty wewnątrz modułu, utworzy logger z wartością dostarczoną przez atrybut __name__ modułu.

Dzięki temu, jeśli w przyszłości zmienisz nazwę modułu (nazwę pliku), nie będziesz musiał modyfikować wewnętrznego kodu.

Teraz, po utworzeniu nowego loggera, powinieneś pamiętać, aby logować wszystkie swoje wiadomości używając nowego logger.info() zamiast metody root’a logging.info().

Innym aspektem, na który należy zwrócić uwagę, jest to, że wszystkie loggery mają wbudowaną hierarchię.

Co przez to rozumiem?

Na przykład, jeśli skonfigurowałeś logger root do logowania wiadomości do określonego pliku. Masz również niestandardowy logger, dla którego nie skonfigurowałeś obsługi plików do wysyłania wiadomości do konsoli lub innego pliku dziennika.

W tym przypadku, niestandardowy logger będzie się wycofywał i zapisywał do pliku ustawionego przez sam logger główny. Dopóki i o ile nie skonfigurujesz pliku dziennika swojego niestandardowego loggera.

Więc czym jest obsługa plików i jak ją skonfigurować?

Co to jest i jak skonfigurować obsługę plików i formatowanie?

Klasy FileHandler() i Formatter() są używane do ustawiania pliku wyjściowego i formatu wiadomości dla loggerów innych niż logger główny.

Pamiętasz jak wcześniej ustawialiśmy nazwę pliku i format komunikatu w loggerze głównym (wewnątrz logging.basicConfig())?

Po prostu określiliśmy parametry filename i format w logging.basicConfig() i wszystkie kolejne logi trafiały do tego pliku.

Jednakże, gdy tworzysz oddzielny logger, musisz skonfigurować je indywidualnie za pomocą obiektów logging.FileHandler() i logging.Formatter().

A FileHandler służy do tego, aby twój niestandardowy logger logował się do innego pliku. Podobnie, Formatter jest używany do zmiany formatu logowanych wiadomości.

import logging# Gets or creates a loggerlogger = logging.getLogger(__name__) # set log levellogger.setLevel(logging.WARNING)# define file handler and set formatterfile_handler = logging.FileHandler('logfile.log')formatter = logging.Formatter('%(asctime)s : %(levelname)s : %(name)s : %(message)s')file_handler.setFormatter(formatter)# add file handler to loggerlogger.addHandler(file_handler)# Logslogger.debug('A debug message')logger.info('An info message')logger.warning('Something is not right.')logger.error('A Major error has happened.')logger.critical('Fatal error. Cannot continue')

Zauważ jak ustawiliśmy formatter na 'file_handler' a nie bezpośrednio na 'logger'.

Zakładając, że powyższy kod jest uruchamiany z głównego programu, jeśli zajrzymy do katalogu roboczego, plik o nazwie logfile.log zostanie utworzony, jeśli jeszcze nie istnieje i będzie zawierał poniższe komunikaty.

#> 2019-02-17 12:40:14,797 : WARNING : __main__ : Something is not right.#> 2019-02-17 12:40:14,798 : ERROR : __main__ : A Major error has happened.#> 2019-02-17 12:40:14,798 : CRITICAL : __main__ : Fatal error. Cannot continue

Zauważ ponownie, Formatter jest ustawiony na obiekcie FileHandler, a nie bezpośrednio na loggerze. Coś, do czego możesz chcieć się przyzwyczaić.

Jak dołączyć informacje o traceback w logowanych wiadomościach

Poza 'debuginfowarningerror', oraz 'critical' wiadomości, można rejestrować wyjątki, które będą zawierały wszelkie powiązane informacje zwrotne.

Z pomocą logger.exception, możesz rejestrować informacje zwrotne, jeśli kod napotka jakikolwiek błąd. logger.exception będzie logował wiadomość podaną w swoich argumentach, jak również informację o błędzie traceback info.

Poniżej znajduje się ładny przykład.

import logging# Create or get the loggerlogger = logging.getLogger(__name__) # set log levellogger.setLevel(logging.INFO)def divide(x, y): try: out = x / y except ZeroDivisionError: logger.exception("Division by zero problem") else: return out# Logslogger.error("Divide {x} / {y} = {c}".format(x=10, y=0, c=divide(10,0)))#> ERROR:__main__:Division by zero problem#> Traceback (most recent call last):#> File "<ipython-input-16-a010a44fdc0a>", line 12, in divide#> out = x / y#> ZeroDivisionError: division by zero#> ERROR:__main__:None

Ćwiczenia

1. Utwórz nowy katalog projektu i nowy plik pythona o nazwie 'example.py'. Zaimportuj moduł logowania i skonfiguruj główny logger do poziomu komunikatów 'debug'. Zaloguj komunikat 'info' z tekstem: „This is root logger’s logging message!”.
2. Skonfiguruj root logger tak, aby formatował komunikat „This is root logger’s logging message!” jak poniżej:

#> 2019-03-03 17:18:32,703 :: INFO :: Module <stdin> :: Line No 1 :: This is root logger's logging message!

Pokaż rozwiązanie

import logginglogging.basicConfig(level=logging.INFO, format='%(asctime)s :: %(levelname)s :: Module %(module)s :: Line No %(lineno)s :: %(message)s')logging.info("This is root logger's logging mesage!")

1. Utwórz inny plik python w tym samym katalogu o nazwie 'mymod.py' i utwórz nowy logger noszący nazwę modułu. Skonfiguruj go do poziomu komunikatów 'error' i spraw, aby wysyłał dane wyjściowe logu do pliku o nazwie „mymod_{current_date}.log”.
2. Z loggera 'mymod' utworzonego powyżej, wyloguj następujący komunikat 'krytyczny' do wspomnianego pliku logu: „To jest krytyczna wiadomość! Don’t ignore it”.

Podsumowanie

Wielkie gratulacje, jeśli udało Ci się rozwiązać ćwiczenia!

To było całkiem przydatne i proste, prawda?

Logowanie jest świetnym narzędziem, ale nie jest popularne w Data science workflows, tak jak powinno być. Mam nadzieję, że koncepcje logowania są jasne i następnym razem, gdy będziesz pracował nad projektem opartym na Pythonie, moja prośba będzie taka, abyś pamiętał o module logging.