1. 程式人生 > >python深入之日誌處理(logging)

python深入之日誌處理(logging)

本節內容


  1. 日誌相關概念
  2. logging模組簡介
  3. 使用logging提供的模組級別的函式記錄日誌
  4. logging模組日誌流處理流程
  5. 使用logging四大元件記錄日誌
  6. 配置logging的幾種方式
  7. 向日志輸出中新增上下文資訊
  8. 參考文件

一、日誌相關概念


日誌是一種可以追蹤某些軟體執行時所發生事件的方法。軟體開發人員可以向他們的程式碼中呼叫日誌記錄相關的方法來表明發生了某些事情。一個事件可以用一個可包含可選變數資料的訊息來描述。此外,事件也有重要性的概念,這個重要性也可以被稱為嚴重性級別(level)。

1.日誌的作用

通過log的分析,可以方便使用者瞭解系統或軟體、應用的執行情況;如果你的應用log足夠豐富,也可以分析以往使用者的操作行為、型別喜好、地域分佈或其他更多資訊;如果一個應用的log同時也分了多個級別,那麼可以很輕易地分析得到該應用的健康狀況,及時發現問題並快速定位、解決問題,補救損失。
簡單來講就是,我們通過記錄和分析日誌可以瞭解一個系統或軟體程式執行情況是否正常,也可以在應用程式出現故障時快速定位問題。比如,做運維的同學,在接收到報警或各種問題反饋後,進行問題排查時通常都會先去看各種日誌,大部分問題都可以在日誌中找到答案。再比如,做開發的同學,可以通過IDE控制檯上輸出的各種日誌進行程式除錯。對於運維老司機或者有經驗的開發人員,可以快速的通過日誌定位到問題的根源。可見,日誌的重要性不可小覷。日誌的作用可以簡單總結為以下3點:

  • 程式除錯
  • 瞭解軟體程式執行情況,是否正常
  • 軟體程式執行故障分析與問題定位

如果應用的日誌資訊足夠詳細和豐富,還可以用來做使用者行為分析,如:分析使用者的操作行為、型別洗好、地域分佈以及其它更多的資訊,由此可以實現改進業務、提高商業利益。

2.日誌的等級

我們先來思考下下面的兩個問題:

  • 作為開發人員,在開發一個應用程式時需要什麼日誌資訊?在應用程式正式上線後需要什麼日誌資訊?
  • 作為應用運維人員,在部署開發環境時需要什麼日誌資訊?在部署生產環境時需要什麼日誌資訊?

在軟體開發階段或部署開發環境時,為了儘可能詳細的檢視應用程式的執行狀態來保證上線後的穩定性,我們可能需要把該應用程式所有的執行日誌全部記錄下來進行分析,這是非常耗費機器效能的。當應用程式正式釋出或在生產環境部署應用程式時,我們通常只需要記錄應用程式的異常資訊、錯誤資訊等,這樣既可以減小伺服器的I/O壓力,也可以避免我們在排查故障時被淹沒在日誌的海洋裡。那麼,怎樣才能在不改動應用程式程式碼的情況下實現在不同的環境記錄不同詳細程度的日誌呢?這就是日誌等級的作用了,我們通過配置檔案指定我們需要的日誌等級就可以了。

不同的應用程式所定義的日誌等級可能會有所差別,分的詳細點的會包含以下幾個等級:

  • DEBUG
  • INFO
  • NOTICE
  • WARNING
  • ERROR
  • CRITICAL
  • ALERT
  • EMERGENCY

3.日誌欄位資訊與日誌格式

本節開始問題提到過,一條日誌資訊對應的是一個事件的發生,而一個事件通常需要包括以下幾個內容:

  • 事件發生時間
  • 事件發生位置
  • 事件的嚴重程度--日誌級別
  • 事件內容

上面這些都是一條日誌記錄中可能包含的欄位資訊,當然還可以包括一些其他資訊,如程序ID、程序名稱、執行緒ID、執行緒名稱等。日誌格式就是用來定義一條日誌記錄中包含那些欄位的,且日誌格式通常都是可以自定義的。

說明:

輸出一條日誌時,日誌內容和日誌級別是需要開發人員明確指定的。對於而其它欄位資訊,只需要是否顯示在日誌中就可以了。

4.日誌功能的實現

幾乎所有開發語言都會內建日誌相關功能,或者會有比較優秀的第三方庫來提供日誌操作功能,比如:log4j,log4php等。它們功能強大、使用簡單。Python自身也提供了一個用於記錄日誌的標準庫模組--logging。

二、logging模組簡介


logging模組定義的函式和類為應用程式和庫的開發實現了一個靈活的事件日誌系統。logging模組是Python的一個標準庫模組,由標準庫模組提供日誌記錄API的關鍵好處是所有Python模組都可以使用這個日誌記錄功能。所以,你的應用日誌可以將你自己的日誌資訊與來自第三方模組的資訊整合起來。

1. logging模組的日誌級別

logging模組預設定義了以下幾個日誌等級,它允許開發人員自定義其他日誌級別,但是這是不被推薦的,尤其是在開發供別人使用的庫時,因為這會導致日誌級別的混亂。

日誌等級(level) 描述
DEBUG 最詳細的日誌資訊,典型應用場景是 問題診斷
INFO 資訊詳細程度僅次於DEBUG,通常只記錄關鍵節點資訊,用於確認一切都是按照我們預期的那樣進行工作
WARNING 當某些不期望的事情發生時記錄的資訊(如,磁碟可用空間較低),但是此時應用程式還是正常執行的
ERROR 由於一個更嚴重的問題導致某些功能不能正常執行時記錄的資訊
CRITICAL 當發生嚴重錯誤,導致應用程式不能繼續執行時記錄的資訊

開發應用程式或部署開發環境時,可以使用DEBUG或INFO級別的日誌獲取儘可能詳細的日誌資訊來進行開發或部署除錯;應用上線或部署生產環境時,應該使用WARNING或ERROR或CRITICAL級別的日誌來降低機器的I/O壓力和提高獲取錯誤日誌資訊的效率。日誌級別的指定通常都是在應用程式的配置檔案中進行指定的。

說明:

  • 上面列表中的日誌等級是從上到下依次升高的,即:DEBUG < INFO < WARNING < ERROR < CRITICAL,而日誌的資訊量是依次減少的;
  • 當為某個應用程式指定一個日誌級別後,應用程式會記錄所有日誌級別大於或等於指定日誌級別的日誌資訊,而不是僅僅記錄指定級別的日誌資訊,nginx、php等應用程式以及這裡要提高的python的logging模組都是這樣的。同樣,logging模組也可以指定日誌記錄器的日誌級別,只有級別大於或等於該指定日誌級別的日誌記錄才會被輸出,小於該等級的日誌記錄將會被丟棄。

2. logging模組的使用方式介紹

logging模組提供了兩種記錄日誌的方式:

  • 第一種方式是使用logging提供的模組級別的函式
  • 第二種方式是使用Logging日誌系統的四大元件

其實,logging所提供的模組級別的日誌記錄函式也是對logging日誌系統相關類的封裝而已。

logging模組定義的模組級別的常用函式

函式 說明
logging.debug(msg, *args, **kwargs) 建立一條嚴重級別為DEBUG的日誌記錄
logging.info(msg, *args, **kwargs) 建立一條嚴重級別為INFO的日誌記錄
logging.warning(msg, *args, **kwargs) 建立一條嚴重級別為WARNING的日誌記錄
logging.error(msg, *args, **kwargs) 建立一條嚴重級別為ERROR的日誌記錄
logging.critical(msg, *args, **kwargs) 建立一條嚴重級別為CRITICAL的日誌記錄
logging.log(level, *args, **kwargs) 建立一條嚴重級別為level的日誌記錄
logging.basicConfig(**kwargs) 對root logger進行一次性配置

其中logging.basicConfig(**kwargs)函式用於指定“要記錄的日誌級別”、“日誌格式”、“日誌輸出位置”、“日誌檔案的開啟模式”等資訊,其他幾個都是用於記錄各個級別日誌的函式。

logging模組的四大元件

元件 說明
loggers 提供應用程式程式碼直接使用的介面
handlers 用於將日誌記錄傳送到指定的目的位置
filters 提供更細粒度的日誌過濾功能,用於決定哪些日誌記錄將會被輸出(其它的日誌記錄將會被忽略)
formatters 用於控制日誌資訊的最終輸出格式

說明: logging模組提供的模組級別的那些函式實際上也是通過這幾個元件的相關實現類來記錄日誌的,只是在建立這些類的例項時設定了一些預設值。

三、使用logging提供的模組級別的函式記錄日誌


回顧下前面提到的幾個重要資訊:

  • 可以通過logging模組定義的模組級別的方法去完成簡單的日誌記錄
  • 只有級別大於或等於日誌記錄器指定級別的日誌記錄才會被輸出,小於該級別的日誌記錄將會被丟棄。

1.最簡單的日誌輸出

先來試著分別輸出一條不同日誌級別的日誌記錄:

import logging

logging.debug("This is a debug log.")
logging.info("This is a info log.")
logging.warning("This is a warning log.")
logging.error("This is a error log.")
logging.critical("This is a critical log.")

也可以這樣寫:

logging.log(logging.DEBUG, "This is a debug log.")
logging.log(logging.INFO, "This is a info log.")
logging.log(logging.WARNING, "This is a warning log.")
logging.log(logging.ERROR, "This is a error log.")
logging.log(logging.CRITICAL, "This is a critical log.")

輸出結果:

WARNING:root:This is a warning log.
ERROR:root:This is a error log.
CRITICAL:root:This is a critical log.

2. 那麼問題來了

問題1:為什麼前面兩條日誌沒有被打印出來?

這是因為logging模組提供的日誌記錄函式所使用的日誌器設定的日誌級別是WARNING,因此只有WARNING級別的日誌記錄以及大於它的ERRORCRITICAL級別的日誌記錄被輸出了,而小於它的DEBUGINFO級別的日誌記錄被丟棄了。

問題2:打印出來的日誌資訊中各欄位表示什麼意思?為什麼會這樣輸出?

上面輸出結果中每行日誌記錄的各個欄位含義分別是:

日誌級別:日誌器名稱:日誌內容

之所以會這樣輸出,是因為logging模組提供的日誌記錄函式所使用的日誌器設定的日誌格式預設是BASIC_FORMAT,其值為:

"%(levelname)s:%(name)s:%(message)s"

問題3:如果將日誌記錄輸出到檔案中,而不是列印到控制檯?

因為在logging模組提供的日誌記錄函式所使用的日誌器設定的處理器所指定的日誌輸出位置預設為:
sys.stderr

問題4:我是怎麼知道這些的?

檢視這些日誌記錄函式的實現程式碼,可以發現:當我們沒有提供任何配置資訊的時候,這些函式都會去呼叫logging.basicConfig(**kwargs)方法,且不會向該方法傳遞任何引數。繼續檢視basicConfig()方法的程式碼就可以找到上面這些問題的答案了。

問題5:怎麼修改這些預設設定呢?

其實很簡單,在我們呼叫上面這些日誌記錄函式之前,手動呼叫一下basicConfig()方法,把我們想設定的內容以引數的形式傳遞進去就可以了。

3. logging.basicConfig()函式說明

該方法用於為logging日誌系統做一些基本配置,方法定義如下:

logging.basicConfig(**kwargs)

該函式可接收的關鍵字引數如下:

引數名稱 描述
filename 指定日誌輸出目標檔案的檔名,指定該設定項後日志信心就不會被輸出到控制檯了
filemode 指定日誌檔案的開啟模式,預設為'a'。需要注意的是,該選項要在filename指定時才有效
format 指定日誌格式字串,即指定日誌輸出時所包含的欄位資訊以及它們的順序。logging模組定義的格式欄位下面會列出。
datefmt 指定日期/時間格式。需要注意的是,該選項要在format中包含時間欄位%(asctime)s時才有效
level 指定日誌器的日誌級別
stream 指定日誌輸出目標stream,如sys.stdout、sys.stderr以及網路stream。需要說明的是,stream和filename不能同時提供,否則會引發 ValueError異常
style Python 3.2中新新增的配置項。指定format格式字串的風格,可取值為'%'、'{'和'$',預設為'%'
handlers Python 3.3中新新增的配置項。該選項如果被指定,它應該是一個建立了多個Handler的可迭代物件,這些handler將會被新增到root logger。需要說明的是:filename、stream和handlers這三個配置項只能有一個存在,不能同時出現2個或3個,否則會引發ValueError異常。

4. logging模組定義的格式字串欄位

我們來列舉一下logging模組中定義好的可以用於format格式字串中欄位有哪些:

欄位/屬性名稱 使用格式 描述
asctime %(asctime)s 日誌事件發生的時間--人類可讀時間,如:2003-07-08 16:49:45,896
created %(created)f 日誌事件發生的時間--時間戳,就是當時呼叫time.time()函式返回的值
relativeCreated %(relativeCreated)d 日誌事件發生的時間相對於logging模組載入時間的相對毫秒數(目前還不知道幹嘛用的)
msecs %(msecs)d 日誌事件發生事件的毫秒部分
levelname %(levelname)s 該日誌記錄的文字形式的日誌級別('DEBUG', 'INFO', 'WARNING', 'ERROR', 'CRITICAL')
levelno %(levelno)s 該日誌記錄的數字形式的日誌級別(10, 20, 30, 40, 50)
name %(name)s 所使用的日誌器名稱,預設是'root',因為預設使用的是 rootLogger
message %(message)s 日誌記錄的文字內容,通過 msg % args計算得到的
pathname %(pathname)s 呼叫日誌記錄函式的原始碼檔案的全路徑
filename %(filename)s pathname的檔名部分,包含檔案字尾
module %(module)s filename的名稱部分,不包含字尾
lineno %(lineno)d 呼叫日誌記錄函式的原始碼所在的行號
funcName %(funcName)s 呼叫日誌記錄函式的函式名
process %(process)d 程序ID
processName %(processName)s 程序名稱,Python 3.1新增
thread %(thread)d 執行緒ID
threadName %(thread)s 執行緒名稱

5.經過配置的日誌輸出

先簡單配置下日誌器的日誌級別

logging.basicConfig(level=logging.DEBUG)

logging.debug("This is a debug log.")
logging.info("This is a info log.")
logging.warning("This is a warning log.")
logging.error("This is a error log.")
logging.critical("This is a critical log.")

輸出結果:

DEBUG:root:This is a debug log.
INFO:root:This is a info log.
WARNING:root:This is a warning log.
ERROR:root:This is a error log.
CRITICAL:root:This is a critical log.

所有等級的日誌資訊都被輸出了,說明配置生效了。

在配置日誌器日誌級別的基礎上,在配置下日誌輸出目標檔案和日誌格式

LOG_FORMAT = "%(asctime)s - %(levelname)s - %(message)s"
logging.basicConfig(filename='my.log', level=logging.DEBUG, format=LOG_FORMAT)

logging.debug("This is a debug log.")
logging.info("This is a info log.")
logging.warning("This is a warning log.")
logging.error("This is a error log.")
logging.critical("This is a critical log.")

此時會發現控制檯中已經沒有輸出日誌內容了,但是在python程式碼檔案的相同目錄下會生成一個名為'my.log'的日誌檔案,該檔案中的內容為:

2017-05-08 14:29:53,783 - DEBUG - This is a debug log.
2017-05-08 14:29:53,784 - INFO - This is a info log.
2017-05-08 14:29:53,784 - WARNING - This is a warning log.
2017-05-08 14:29:53,784 - ERROR - This is a error log.
2017-05-08 14:29:53,784 - CRITICAL - This is a critical log.

在上面的基礎上,我們再來設定下日期/時間格式

LOG_FORMAT = "%(asctime)s - %(levelname)s - %(message)s"
DATE_FORMAT = "%m/%d/%Y %H:%M:%S %p"

logging.basicConfig(filename='my.log', level=logging.DEBUG, format=LOG_FORMAT, datefmt=DATE_FORMAT)

logging.debug("This is a debug log.")
logging.info("This is a info log.")
logging.warning("This is a warning log.")
logging.error("This is a error log.")
logging.critical("This is a critical log.")

此時會在my.log日誌檔案中看到如下輸出內容:

05/08/2017 14:29:04 PM - DEBUG - This is a debug log.
05/08/2017 14:29:04 PM - INFO - This is a info log.
05/08/2017 14:29:04 PM - WARNING - This is a warning log.
05/08/2017 14:29:04 PM - ERROR - This is a error log.
05/08/2017 14:29:04 PM - CRITICAL - This is a critical log.

掌握了上面的內容之後,已經能夠滿足我們平時開發中需要的日誌記錄功能。

6. 其他說明

幾個要說明的內容:

  • logging.basicConfig()函式是一個一次性的簡單配置工具使,也就是說只有在第一次呼叫該函式時會起作用,後續再次呼叫該函式時完全不會產生任何操作的,多次呼叫的設定並不是累加操作。
  • 日誌器(Logger)是有層級關係的,上面呼叫的logging模組級別的函式所使用的日誌器是RootLogger類的例項,其名稱為'root',它是處於日誌器層級關係最頂層的日誌器,且該例項是以單例模式存在的。
  • 如果要記錄的日誌中包含變數資料,可使用一個格式字串作為這個事件的描述訊息(logging.debug、logging.info等函式的第一個引數),然後將變數資料作為第二個引數*args的值進行傳遞,如:logging.warning('%s is %d years old.', 'Tom', 10),輸出內容為WARNING:root:Tom is 10 years old.
  • logging.debug(), logging.info()等方法的定義中,除了msg和args引數外,還有一個**kwargs引數。它們支援3個關鍵字引數: exc_info, stack_info, extra,下面對這幾個關鍵字引數作個說明。

關於exc_info, stack_info, extra關鍵詞引數的說明:

  • exc_info: 其值為布林值,如果該引數的值設定為True,則會將異常異常資訊新增到日誌訊息中。如果沒有異常資訊則新增None到日誌資訊中。
  • stack_info: 其值也為布林值,預設值為False。如果該引數的值設定為True,棧資訊將會被新增到日誌資訊中。
  • extra: 這是一個字典(dict)引數,它可以用來自定義訊息格式中所包含的欄位,但是它的key不能與logging模組定義的欄位衝突。

一個例子:

在日誌訊息中新增exc_info和stack_info資訊,並新增兩個自定義的字端 ip和user

LOG_FORMAT = "%(asctime)s - %(levelname)s - %(user)s[%(ip)s] - %(message)s"
DATE_FORMAT = "%m/%d/%Y %H:%M:%S %p"

logging.basicConfig(format=LOG_FORMAT, datefmt=DATE_FORMAT)
logging.warning("Some one delete the log file.", exc_info=True, stack_info=True, extra={'user': 'Tom', 'ip':'47.98.53.222'})

輸出結果:

05/08/2017 16:35:00 PM - WARNING - Tom[47.98.53.222] - Some one delete the log file.
NoneType
Stack (most recent call last):
  File "C:/Users/wader/PycharmProjects/LearnPython/day06/log.py", line 45, in <module>
    logging.warning("Some one delete the log file.", exc_info=True, stack_info=True, extra={'user': 'Tom', 'ip':'47.98.53.222'})

四、logging模組日誌流處理流程


在介紹logging模組的高階用法之前,很有必要對logging模組所包含的重要元件以及其工作流程做個全面、簡要的介紹,這有助於我們更好的理解我們所寫的程式碼(將會觸發什麼樣的操作)。

1. logging日誌模組四大元件

在介紹logging模組的日誌流處理流程之前,我們先來介紹下logging模組的四大元件:

元件名稱 對應類名 功能描述
日誌器 Logger 提供了應用程式可一直使用的介面
處理器 Handler 將logger建立的日誌記錄傳送到合適的目的輸出
過濾器 Filter 提供了更細粒度的控制工具來決定輸出哪條日誌記錄,丟棄哪條日誌記錄
格式器 Formatter 決定日誌記錄的最終輸出格式

logging模組就是通過這些元件來完成日誌處理的,上面所使用的logging模組級別的函式也是通過這些元件對應的類來實現的。

這些元件之間的關係描述:

  • 日誌器(logger)需要通過處理器(handler)將日誌資訊輸出到目標位置,如:檔案、sys.stdout、網路等;
  • 不同的處理器(handler)可以將日誌輸出到不同的位置;
  • 日誌器(logger)可以設定多個處理器(handler)將同一條日誌記錄輸出到不同的位置;
  • 每個處理器(handler)都可以設定自己的過濾器(filter)實現日誌過濾,從而只保留感興趣的日誌;
  • 每個處理器(handler)都可以設定自己的格式器(formatter)實現同一條日誌以不同的格式輸出到不同的地方。

簡單點說就是:日誌器(logger)是入口,真正幹活兒的是處理器(handler),處理器(handler)還可以通過過濾器(filter)和格式器(formatter)對要輸出的日誌內容做過濾和格式化等處理操作。

2. logging日誌模組相關類及其常用方法介紹

下面介紹下與logging四大元件相關的類:Logger, Handler, Filter, Formatter。

Logger類

Logger物件有3個任務要做:

  • 1)嚮應用程式程式碼暴露幾個方法,使應用程式可以在執行時記錄日誌訊息;
  • 2)基於日誌嚴重等級(預設的過濾設施)或filter物件來決定要對哪些日誌進行後續處理;
  • 3)將日誌訊息傳送給所有感興趣的日誌handlers。

Logger物件最常用的方法分為兩類:配置方法 和 訊息傳送方法

最常用的配置方法如下:

方法 描述
Logger.setLevel() 設定日誌器將會處理的日誌訊息的最低嚴重級別
Logger.addHandler() 和 Logger.removeHandler() 為該logger物件新增 和 移除一個handler物件
Logger.addFilter() 和 Logger.removeFilter() 為該logger物件新增 和 移除一個filter物件

關於Logger.setLevel()方法的說明:

內建等級中,級別最低的是DEBUG,級別最高的是CRITICAL。例如setLevel(logging.INFO),此時函式引數為INFO,那麼該logger將只會處理INFO、WARNING、ERROR和CRITICAL級別的日誌,而DEBUG級別的訊息將會被忽略/丟棄。

logger物件配置完成後,可以使用下面的方法來建立日誌記錄:

方法 描述
Logger.debug(), Logger.info(), Logger.warning(), Logger.error(), Logger.critical() 建立一個與它們的方法名對應等級的日誌記錄
Logger.exception() 建立一個類似於Logger.error()的日誌訊息
Logger.log() 需要獲取一個明確的日誌level引數來建立一個日誌記錄

說明:

  • Logger.exception()與Logger.error()的區別在於:Logger.exception()將會輸出堆疊追蹤資訊,另外通常只是在一個exception handler中呼叫該方法。
  • Logger.log()與Logger.debug()、Logger.info()等方法相比,雖然需要多傳一個level引數,顯得不是那麼方便,但是當需要記錄自定義level的日誌時還是需要該方法來完成。

那麼,怎樣得到一個Logger物件呢?一種方式是通過Logger類的例項化方法建立一個Logger類的例項,但是我們通常都是用第二種方式--logging.getLogger()方法。

logging.getLogger()方法有一個可選引數name,該引數表示將要返回的日誌器的名稱標識,如果不提供該引數,則其值為'root'。若以相同的name引數值多次呼叫getLogger()方法,將會返回指向同一個logger物件的引用。

關於logger的層級結構與有效等級的說明:

  • logger的名稱是一個以'.'分割的層級結構,每個'.'後面的logger都是'.'前面的logger的children,例如,有一個名稱為 foo 的logger,其它名稱分別為 foo.bar, foo.bar.baz 和 foo.bam都是 foo 的後代。
  • logger有一個"有效等級(effective level)"的概念。如果一個logger上沒有被明確設定一個level,那麼該logger就是使用它parent的level;如果它的parent也沒有明確設定level則繼續向上查詢parent的parent的有效level,依次類推,直到找到個一個明確設定了level的祖先為止。需要說明的是,root logger總是會有一個明確的level設定(預設為 WARNING)。當決定是否去處理一個已發生的事件時,logger的有效等級將會被用來決定是否將該事件傳遞給該logger的handlers進行處理。
  • child loggers在完成對日誌訊息的處理後,預設會將日誌訊息傳遞給與它們的祖先loggers相關的handlers。因此,我們不必為一個應用程式中所使用的所有loggers定義和配置handlers,只需要為一個頂層的logger配置handlers,然後按照需要建立child loggers就可足夠了。我們也可以通過將一個logger的propagate屬性設定為False來關閉這種傳遞機制。

Handler類

Handler物件的作用是(基於日誌訊息的level)將訊息分發到handler指定的位置(檔案、網路、郵件等)。Logger物件可以通過addHandler()方法為自己新增0個或者更多個handler物件。比如,一個應用程式可能想要實現以下幾個日誌需求:

  • 1)把所有日誌都發送到一個日誌檔案中;
  • 2)把所有嚴重級別大於等於error的日誌傳送到stdout(標準輸出);
  • 3)把所有嚴重級別為critical的日誌傳送到一個email郵件地址。
    這種場景就需要3個不同的handlers,每個handler複雜傳送一個特定嚴重級別的日誌到一個特定的位置。

一個handler中只有非常少數的方法是需要應用開發人員去關心的。對於使用內建handler物件的應用開發人員來說,似乎唯一相關的handler方法就是下面這幾個配置方法:

方法 描述
Handler.setLevel() 設定handler將會處理的日誌訊息的最低嚴重級別
Handler.setFormatter() 為handler設定一個格式器物件
Handler.addFilter() 和 Handler.removeFilter() 為handler新增 和 刪除一個過濾器物件

需要說明的是,應用程式程式碼不應該直接例項化和使用Handler例項。因為Handler是一個基類,它只定義了素有handlers都應該有的介面,同時提供了一些子類可以直接使用或覆蓋的預設行為。下面是一些常用的Handler:

Handler 描述
logging.StreamHandler 將日誌訊息傳送到輸出到Stream,如std.out, std.err或任何file-like物件。
logging.FileHandler 將日誌訊息傳送到磁碟檔案,預設情況下檔案大小會無限增長
logging.handlers.RotatingFileHandler 將日誌訊息傳送到磁碟檔案,並支援日誌檔案按大小切割
logging.hanlders.TimedRotatingFileHandler 將日誌訊息傳送到磁碟檔案,並支援日誌檔案按時間切割
logging.handlers.HTTPHandler 將日誌訊息以GET或POST的方式傳送給一個HTTP伺服器
logging.handlers.SMTPHandler 將日誌訊息傳送給一個指定的email地址
logging.NullHandler 該Handler例項會忽略error messages,通常被想使用logging的library開發者使用來避免'No handlers could be found for logger XXX'資訊的出現。

Formater類

Formater物件用於配置日誌資訊的最終順序、結構和內容。與logging.Handler基類不同的是,應用程式碼可以直接例項化Formatter類。另外,如果你的應用程式需要一些特殊的處理行為,也可以實現一個Formatter的子類來完成。

Formatter類的構造方法定義如下:

logging.Formatter.__init__(fmt=None, datefmt=None, style='%')

可見,該構造方法接收3個可選引數:

  • fmt:指定訊息格式化字串,如果不指定該引數則預設使用message的原始值
  • datefmt:指定日期格式字串,如果不指定該引數則預設使用"%Y-%m-%d %H:%M:%S"
  • style:Python 3.2新增的引數,可取值為 '%', '{'和 '$',如果不指定該引數則預設使用'%'

Filter類

Filter可以被Handler和Logger用來做比level更細粒度的、更復雜的過濾功能。Filter是一個過濾器基類,它只允許某個logger層級下的日誌事件通過過濾。該類定義如下:

class logging.Filter(name='')
    filter(record)

比如,一個filter例項化時傳遞的name引數值為'A.B',那麼該filter例項將只允許名稱為類似如下規則的loggers產生的日誌記錄通過過濾:'A.B','A.B,C','A.B.C.D','A.B.D',而名稱為'A.BB', 'B.A.B'的loggers產生的日誌則會被過濾掉。如果name的值為空字串,則允許所有的日誌事件通過過濾。

filter方法用於具體控制傳遞的record記錄是否能通過過濾,如果該方法返回值為0表示不能通過過濾,返回值為非0表示可以通過過濾。

說明:

  • 如果有需要,也可以在filter(record)方法內部改變該record,比如新增、刪除或修改一些屬性。
  • 我們還可以通過filter做一些統計工作,比如可以計算下被一個特殊的logger或handler所處理的record數量等。

3. logging日誌流處理流程

下面這個圖描述了日誌流的處理流程:

我們來描述下上面這個圖的日誌流處理流程:

  • 1)(在使用者程式碼中進行)日誌記錄函式呼叫,如:logger.info(...),logger.debug(...)等;
  • 2)判斷要記錄的日誌級別是否滿足日誌器設定的級別要求(要記錄的日誌級別要大於或等於日誌器設定的級別才算滿足要求),如果不滿足則該日誌記錄會被丟棄並終止後續的操作,如果滿足則繼續下一步操作;
  • 3)根據日誌記錄函式呼叫時摻入的引數,建立一個日誌記錄(LogRecord類)物件;
  • 4)判斷日誌記錄器上設定的過濾器是否拒絕這條日誌記錄,如果日誌記錄器上的某個過濾器拒絕,則該日誌記錄會被丟棄並終止後續的操作,如果日誌記錄器上設定的過濾器不拒絕這條日誌記錄或者日誌記錄器上沒有設定過濾器則繼續下一步操作--將日誌記錄分別交給該日誌器上新增的各個處理器;
  • 5)判斷要記錄的日誌級別是否滿足處理器設定的級別要求(要記錄的日誌級別要大於或等於該處理器設定的日誌級別才算滿足要求),如果不滿足記錄將會被該處理器丟棄並終止後續的操作,如果滿足則繼續下一步操作;
  • 6)判斷該處理器上設定的過濾器是否拒絕這條日誌記錄,如果該處理器上的某個過濾器拒絕,則該日誌記錄會被當前處理器丟棄並終止後續的操作,如果當前處理器上設定的過濾器不拒絕這條日誌記錄或當前處理器上沒有設定過濾器測繼續下一步操作;
  • 7)如果能到這一步,說明這條日誌記錄經過了層層關卡允許被輸出了,此時當前處理器會根據自身被設定的格式器(如果沒有設定則使用預設格式)將這條日誌記錄進行格式化,最後將格式化後的結果輸出到指定位置(檔案、網路、類檔案的Stream等);
  • 8)如果日誌器被設定了多個處理器的話,上面的第5-8步會執行多次;
  • 9)這裡才是完整流程的最後一步:判斷該日誌器輸出的日誌訊息是否需要傳遞給上一級logger(之前提到過,日誌器是有層級關係的)的處理器,如果propagate屬性值為1則表示日誌訊息將會被輸出到處理器指定的位置,同時還會被傳遞給parent日誌器的handlers進行處理直到當前日誌器的propagate屬性為0停止,如果propagate值為0則表示不向parent日誌器的handlers傳遞該訊息,到此結束。

可見,一條日誌資訊要想被最終輸出需要依次經過以下幾次過濾:

  • 日誌器等級過濾;
  • 日誌器的過濾器過濾;
  • 日誌器的處理器等級過濾;
  • 日誌器的處理器的過濾器過濾;

需要說明的是: 關於上面第9個步驟,如果propagate值為1,那麼日誌訊息會直接傳遞交給上一級logger的handlers進行處理,此時上一級logger的日誌等級並不會對該日誌訊息進行等級過濾。

五、使用logging四大元件記錄日誌


現在,我們對logging模組的重要元件及整個日誌流處理流程都應該有了一個比較全面的瞭解,下面我們來看一個例子。

1. 需求

現在有以下幾個日誌記錄的需求:

  • 1)要求將所有級別的所有日誌都寫入磁碟檔案中
  • 2)all.log檔案中記錄所有的日誌資訊,日誌格式為:日期和時間 - 日誌級別 - 日誌資訊
  • 3)error.log檔案中單獨記錄error及以上級別的日誌資訊,日誌格式為:日期和時間 - 日誌級別 - 檔名[:行號] - 日誌資訊
  • 4)要求all.log在每天凌晨進行日誌切割

2. 分析

  • 1)要記錄所有級別的日誌,因此日誌器的有效level需要設定為最低級別--DEBUG;
  • 2)日誌需要被髮送到兩個不同的目的地,因此需要為日誌器設定兩個handler;另外,兩個目的地都是磁碟檔案,因此這兩個handler都是與FileHandler相關的;
  • 3)all.log要求按照時間進行日誌切割,因此他需要用logging.handlers.TimedRotatingFileHandler; 而error.log沒有要求日誌切割,因此可以使用FileHandler;
  • 4)兩個日誌檔案的格式不同,因此需要對這兩個handler分別設定格式器;

3. 程式碼實現

import logging
import logging.handlers
import datetime

logger = logging.getLogger('mylogger')
logger.setLevel(logging.DEBUG)

rf_handler = logging.handlers.TimedRotatingFileHandler('all.log', when='midnight', interval=1, backupCount=7, atTime=datetime.time(0, 0, 0, 0))
rf_handler.setFormatter(logging.Formatter("%(asctime)s - %(levelname)s - %(message)s"))

f_handler = logging.FileHandler('error.log')
f_handler.setLevel(logging.ERROR)
f_handler.setFormatter(logging.Formatter("%(asctime)s - %(levelname)s - %(filename)s[:%(lineno)d] - %(message)s"))

logger.addHandler(rf_handler)
logger.addHandler(f_handler)

logger.debug('debug message')
logger.info('info message')
logger.warning('warning message')
logger.error('error message')
logger.critical('critical message')

all.log檔案輸出

2017-05-13 16:12:40,612 - DEBUG - debug message
2017-05-13 16:12:40,612 - INFO - info message
2017-05-13 16:12:40,612 - WARNING - warning message
2017-05-13 16:12:40,612 - ERROR - error message
2017-05-13 16:12:40,613 - CRITICAL - critical message

error.log檔案輸出

2017-05-13 16:12:40,612 - ERROR - log.py[:81] - error message
2017-05-13 16:12:40,613 - CRITICAL - log.py[:82] - critical message

六、配置logging的幾種方式


作為開發者,我們可以通過以下3中方式來配置logging:

  • 1)使用Python程式碼顯式的建立loggers, handlers和formatters並分別呼叫它們的配置函式;
  • 2)建立一個日誌配置檔案,然後使用fileConfig()函式來讀取該檔案的內容;
  • 3)建立一個包含配置資訊的dict,然後把它傳遞個dictConfig()函式;

具體說明請參考另一篇博文《python之配置日誌的幾種方式》

七、向日志輸出中新增上下文資訊


除了傳遞給日誌記錄函式的引數外,有時候我們還想在日誌輸出中包含一些額外的上下文資訊。比如,在一個網路應用中,可能希望在日誌中記錄客戶端的特定資訊,如:遠端客戶端的IP地址和使用者名稱。這裡我們來介紹以下幾種實現方式:

  • 通過向日志記錄函式傳遞一個extra引數引入上下文資訊
  • 使用LoggerAdapters引入上下文資訊
  • 使用Filters引入上下文資訊