Python 日誌記錄：深度教程

已發表: 2022-03-11

隨著應用程序變得越來越複雜，擁有良好的日誌可能非常有用，不僅在調試時，而且還可以為應用程序問題/性能提供洞察力。

Python 標準庫帶有一個日誌模塊，它提供了大部分基本的日誌功能。 通過正確設置，日誌消息可以帶來很多有用的信息，包括觸發日誌的時間和地點以及日誌上下文，例如正在運行的進程/線程。

儘管有這些優勢，但日誌模塊經常被忽視，因為它需要一些時間才能正確設置，雖然完整，但在我看來，官方日誌文檔位於 https://docs.python.org/3/library/logging.html並沒有真正給出日誌記錄的最佳實踐或突出一些日誌記錄的驚喜。

本 Python 日誌記錄教程並不是關於日誌記錄模塊的完整文檔，而是一個“入門”指南，介紹了一些日誌記錄概念以及一些需要注意的“陷阱”。 這篇文章將以最佳實踐結尾，並包含一些指向更高級日誌記錄主題的指針。

請注意，帖子中的所有代碼片段都假設您已經導入了日誌記錄模塊：

 import logging

Python 日誌記錄的概念

本節概述了日誌模塊中經常遇到的一些概念。

Python 日誌記錄級別

日誌級別對應於給定日誌的“重要性”：“錯誤”日誌應該比“警告”日誌更緊急，而“調試”日誌應該僅在調試應用程序時有用。

Python中有六個日誌級別； 每個級別都與一個指示日誌嚴重性的整數相關聯：NOTSET=0、DEBUG=10、INFO=20、WARN=30、ERROR=40 和 CRITICAL=50。

Python Logging 的日誌級別

除了 NOTSET，所有級別都相當簡單（DEBUG < INFO < WARN），其特殊性將在接下來解決。

Python 日誌格式

日誌格式化程序基本上通過向其添加上下文信息來豐富日誌消息。 了解日誌的發送時間、位置（Python 文件、行號、方法等）以及線程和進程等附加上下文（在調試多線程應用程序時非常有用）會很有用。

例如，當通過日誌格式化程序發送日誌“hello world”時：

 "%(asctime)s — %(name)s — %(levelname)s — %(funcName)s:%(lineno)d — %(message)s"

它會變成

2018-02-07 19:47:41,864 - abc - WARNING - <module>:1 - hello world

Python 日誌消息格式化

Python 日誌處理程序

日誌處理程序是有效寫入/顯示日誌的組件：將其顯示在控制台中（通過 StreamHandler）、文件中（通過 FileHandler），甚至通過 SMTPHandler 向您發送電子郵件等。

每個日誌處理程序都有 2 個重要字段：

  • 將上下文信息添加到日誌的格式化程序。
  • 過濾掉級別較低的日誌的日誌級別。 因此，具有 INFO 級別的日誌處理程序將不會處理 DEBUG 日誌。

Python 日誌記錄處理程序

標準庫提供了一些處理程序，對於常見用例來說應該足夠了：https://docs.python.org/3/library/logging.handlers.html#module-logging.handlers。 最常見的是 StreamHandler 和 FileHandler：

 console_handler = logging.StreamHandler() file_handler = logging.FileHandler("filename")

Python 記錄器

Logger 可能是代碼中直接使用最多的，也是最複雜的。 可以通過以下方式獲得新的記錄器：

 toto_logger = logging.getLogger("toto")

記錄器具有三個主要字段：

  • 傳播：決定是否應將日誌傳播到記錄器的父級。 默認情況下，其值為 True。
  • A 級別：與日誌處理程序級別一樣，記錄器級別用於過濾掉“不太重要”的日誌。 除了，與日誌處理程序不同，級別僅在“子”記錄器中檢查； 一旦日誌傳播到其父級，將不會檢查級別。 這是一種不直觀的行為。
  • 處理程序：日誌到達記錄器時將發送到的處理程序列表。 這允許靈活的日誌處理——例如，您可以有一個記錄所有 DEBUG 日誌的文件日誌處理程序和一個僅用於 CRITICAL 日誌的電子郵件日誌處理程序。 在這方面，logger-handler 關係類似於發布者-消費者關係：一旦通過 logger 級別檢查，日誌將被廣播到所有處理程序。

Python 日誌記錄的過程

記錄器在名稱上是唯一的，這意味著如果創建了名為“toto”的記錄器，隨後的logging.getLogger("toto")調用將返回相同的對象：

 assert id(logging.getLogger("toto")) == id(logging.getLogger("toto"))

正如您可能已經猜到的那樣，記錄器具有層次結構。 層次結構的頂部是根記錄器，可以通過 logging.root 訪問。 當使用類似logging.debug()的方法時，會調用此記錄器。 默認情況下，根日誌級別為 WARN，因此每個級別較低的日誌（例如通過logging.info("info") ）都將被忽略。 根記錄器的另一個特殊性是它的默認處理程序將在第一次記錄級別高於 WARN 的日誌時創建。 通常不建議通過類似logging.debug()的方法直接或間接使用根記錄器。

默認情況下，當創建一個新的記錄器時，它的父級將被設置為根記錄器：

 lab = logging.getLogger("ab") assert lab.parent == logging.root # lab's parent is indeed the root logger

但是，記錄器使用“點表示法”，這意味著名稱為“ab”的記錄器將是記錄器“a”的子級。 但是，這僅在記錄器“a”已創建時才成立，否則“ab”父級仍然是根。

 la = logging.getLogger("a") assert lab.parent == la # lab's parent is now la instead of root

當記錄器根據級別檢查決定是否應該通過日誌時（例如，如果日誌級別低於記錄器級別，則日誌將被忽略），它使用其“有效級別”而不是實際級別。 如果級別不是 NOTSET，則有效級別與記錄器級別相同，即從 DEBUG 到 CRITICAL 的所有值； 但是，如果記錄器級別為 NOTSET，則有效級別將是第一個具有非 NOTSET 級別的祖先級別。

默認情況下，新記錄器具有 NOTSET 級別，並且由於根記錄器具有 WARN 級別，因此記錄器的有效級別將為 WARN。 因此，即使一個新的記錄器附加了一些處理程序，這些處理程序也不會被調用，除非日誌級別超過 WARN：

 toto_logger = logging.getLogger("toto") assert toto_logger.level == logging.NOTSET # new logger has NOTSET level assert toto_logger.getEffectiveLevel() == logging.WARN # and its effective level is the root logger level, ie WARN # attach a console handler to toto_logger console_handler = logging.StreamHandler() toto_logger.addHandler(console_handler) toto_logger.debug("debug") # nothing is displayed as the log level DEBUG is smaller than toto effective level toto_logger.setLevel(logging.DEBUG) toto_logger.debug("debug message") # now you should see "debug message" on screen

默認情況下，日誌級別將用於決定日誌通過：如果日誌級別低於日誌級別，則日誌將被忽略。

Python 日誌記錄最佳實踐

日誌模塊確實非常方便，但它包含一些怪癖，即使是最好的 Python 開發人員也會長時間頭疼。 以下是我認為使用此模塊的最佳實踐：

  • 配置根記錄器，但永遠不要在代碼中使用它——例如，永遠不要調用像logging.info()這樣的函數，它實際上會在後台調用根記錄器。 如果您想從您使用的庫中捕獲錯誤消息，請確保將根記錄器配置為寫入文件，例如，使調試更容易。 默認情況下，root logger 只輸出到stderr ，因此日誌很容易丟失。
  • 要使用日誌記錄，請確保使用logging.getLogger(logger name)創建一個新的記錄器。 我通常使用__name__作為 logger 名稱，但任何東西都可以使用，只要它是一致的。 要添加更多處理程序，我通常有一個返回記錄器的方法（您可以在 https://gist.github.com/nguyenkims/e92df0f8bd49973f0c94bddf36ed7fd0 上找到要點）。
 import logging import sys from logging.handlers import TimedRotatingFileHandler FORMATTER = logging.Formatter("%(asctime)s — %(name)s — %(levelname)s — %(message)s") LOG_FILE = "my_app.log" def get_console_handler(): console_handler = logging.StreamHandler(sys.stdout) console_handler.setFormatter(FORMATTER) return console_handler def get_file_handler(): file_handler = TimedRotatingFileHandler(LOG_FILE, when='midnight') file_handler.setFormatter(FORMATTER) return file_handler def get_logger(logger_name): logger = logging.getLogger(logger_name) logger.setLevel(logging.DEBUG) # better to have too much log than not enough logger.addHandler(get_console_handler()) logger.addHandler(get_file_handler()) # with this pattern, it's rarely necessary to propagate the error up to parent logger.propagate = False return logger

在您可以創建一個新的記錄器並使用它之後：

 my_logger = get_logger("my module name") my_logger.debug("a debug message")
  • 使用 RotatingFileHandler 類，例如示例中使用的 TimedRotatingFileHandler 而不是 FileHandler，因為它會在文件達到大小限製或每天執行時自動為您旋轉文件。
  • 使用 Sentry、Airbrake、Raygun 等工具自動為您捕獲錯誤日誌。 這在 Web 應用程序的上下文中特別有用，其中日誌可能非常冗長，錯誤日誌很容易丟失。 使用這些工具的另一個優點是您可以獲取有關錯誤中變量值的詳細信息，這樣您就可以知道哪個 URL 觸發了錯誤、關注的是哪個用戶等。

如果您對更多最佳實踐感興趣，請閱讀 Toptaler Martin Chikilian 的 The 10 Most Common Mistakes That Python Developers Make。