2020年3月7日 星期六

Python logging 初學者速理解

給對於 logging 未曾接觸過，或剛接觸過的人。

logging 可以將記錄輸出，也可同時將記錄保存。除錯除了靠print大法，也可以靠logging保存下來的日誌中找出錯誤點。

有些程式運行會因為時間改變環境而出現問題，出現嚴重錯誤就會跳掉。沒有辦法總是在編寫或除錯模式下運行，出錯就告訴你哪裡有問題。若程式未能紀錄到當下運行狀況，就少了線索去發現問題所在。

logging有很多教學，也有繁體中文教學，寫得也不錯。

這裡就簡單寫下一點筆記，幫助初學者快速理解logging運作。


logging有程度(level)之分：最嚴重CRITIAL > ERROR > WARNING > INFO > DEBUG > 最輕微 NOTSET。

假如我只想保留 ERROR 以上的記錄在 log，顯示 INFO 以上的記錄在終端。

假設我有一個程式，命名為 HELLO.py。例1：

Import logging

loggerName = "HELLO"
fileName = "hello.log"

logging.basicConfig(level=logging.INFO)
logger = logging.getLogger(loggerName) 
FileHandler = logging.FileHandler(fileName)
FileHandler.setLevel("ERROR")
logger.addHandler(FileHandler)

logger.info("哈囉")
logger.debug("這個不會顯示出來 INFO > DEBUG")
logger.warning("注意下一個記錄")
logger.error("只有這個會被保存在log")

行6，先跳過。
行7，得到一個名字為 "HELLO" 的 Logger 物件。
行8，得到一個 FileHandler 物件。Handler 功能是把 Logger 的記錄傳出去，看官網文件，Handler的種類有很多種，這次用的 FileHandler ，簡單來說就是把 Logger 的記錄傳到指定檔案。
行6，logging基本設定，level是指 root 的 level，會自動生成一個 StreamHandler 添加到 root 上去。上行解釋 Handler 功能，這自動生成的 StreamHandler 會將記錄傳出然後顯示在終端。至於要多高層級的訊息才會顯示，就看這裡設定 root 的 level，之後新增 Logger 默認level也會跟這裡設定的相同 。官網文件
行9，設定 FileHandler 的 level 為 ERROR。
行10，讓 logger 添加 FileHandler。

行12~15，用 logger 傳入不同 level 紀錄，看看實際效果。

INFO:test:哈囉
WARNING:test:注意下一個訊息
ERROR:test:只有這個會被保存在log

複習一下：CRITIAL > ERROR > WARNING > INFO > DEBUG >  NOTSET
或者：CRITIAL(50) > ERROR(40)  > WARNING(30)  > INFO(20)  > DEBUG(10)

因自動生成 StreamHandler 的 level 為 INFO ，故只將行12、行14、行15紀錄輸出到終端。而行13的 level 為 DEBUG，小於 StreamHandler 的 level  INFO，所以被刷掉。
FileHandler 的 level 為 ERROR ，所以只有行15被保存在 hello.log 裡。

注意：這裡顯示在終端的紀錄，是經由 root 的 StreamHandler ，不是 logger 的，這可以利用 Logger.handlers 查看 logger有甚麼 handlers。root 是最上層的 Logger，可觀察到將資料傳入 logger 時，也會往上層傳到 root。

瞭解了 例1 之後，其實我們能把每個 Logger 顯示在終端的 level 有不同設定。如果有兩個 Logger ，一個要 INFO 以上，一個 ERROR 以上，只要分別針對兩者的 StreamHandler 有不同設定。

例2：

import logging

loggerName = "test"
loggerName2 = "test2"
fmt = logging.Formatter("%(name)s - %(levelname)s - %(message)s")
logger = logging.getLogger(loggerName)
logger2 = logging.getLogger(loggerName2)
logger.setLevel("DEBUG")
logger2.setLevel("DEBUG")
StreamHandler = logging.StreamHandler()
StreamHandler.setLevel("INFO")
StreamHandler.setFormatter(fmt)
StreamHandler2 = logging.StreamHandler()
StreamHandler2.setLevel("ERROR")
StreamHandler2.setFormatter(fmt)
logger.addHandler(StreamHandler)
logger2.addHandler(StreamHandler2)

for lg in [logger, logger2]:
    print(lg.getEffectiveLevel())
    lg.info("哈囉")
    lg.debug("這個如何")
    lg.warning("那這個呢")
    lg.error("最後一個")
執行結果為：
10
test - INFO - 哈囉
test - WARNING - 那這個呢
test - ERROR - 最後一個
10
test2 - ERROR - 最後一個
這裡沒有用到 logging.basicConfig() ，所以 Logger 的 level 默認為 WARNING。
若不在行8、行9設定 Logger 的 level，結果會變成如下：
30
test - WARNING - 那這個呢
test - ERROR - 最後一個
30
test2 - ERROR - 最後一個

Logger 默認的 level 為 WARNING 換算等級數值為 30，如果有logging.basicConfig()就會先以這裡設定的 level 為主，於是行21 INFO、行22 DEBUG的紀錄在 logger 這關就會被默認的 level WARNING 濾掉，接下來就沒有辦法進到 StreamHandler。

每個 level 都有對應的數值，在 Logger.setLevel() 時，也可以輸入正整數， Logger.setLevel(30) == Logger.setLevel("WARNING")。

透過 例2 ，瞭解如何分別設定顯示在終端的條件，自然也可以分別設定輸出檔案跟級別等。

雖然可以分別設定 Logger 但會讓程式碼看起來相當的長，不過也有一個方法，只要兩句，然後就能簡化成 logging.getLogger() 解決掉。
from logging import config
config.fileConfig(configName)

這邊在資料夾要多新增一個檔案名為 logging.conf，裡面寫 Logging 的設定，可以用記事本讀寫。

logging.conf：

[loggers]
keys=root, test, test2

[handlers]
keys=consoleHandler, StreamHandler, StreamHandler2

[formatters]
keys= default

[logger_root]
level=WARNING
handlers=consoleHandler

[logger_test]
level=DEBUG
handlers=StreamHandler
qualname=test
propagate=1

[logger_test2]
level=DEBUG
handlers=StreamHandler2
qualname=test2
propagate=1

[handler_consoleHandler]
class=StreamHandler
level=DEBUG
formatter=default
args=(sys.stdout,)

[handler_StreamHandler]
class=StreamHandler
level=INFO
formatter=default
args=(sys.stdout,)

[handler_StreamHandler2]
class=StreamHandler
level=ERROR
formatter=default
args=(sys.stdout,)

[formatter_default]
format=%(name)s - %(levelname)s - %(message)s
datefmt=

內容很明顯，就是將 例2 的那些設定寫進來，於是 例2 可以簡化成這個樣子。

例2改：
import logging
from logging import config

configName = "logging.conf"
loggerName = "test"
loggerName2 = "test2"

config.fileConfig(configName)
logger = logging.getLogger(loggerName)
logger2 = logging.getLogger(loggerName2)

for lg in [logger, logger2]:
    print(lg.getEffectiveLevel())
    lg.info("哈囉")
    lg.debug("這個如何")
    lg.warning("那這個呢")
    lg.error("最後一個")
這樣是不是就簡潔很多了。

這邊簡單整理一下 logging 的流程，舉個例：

假設我傳入一個 warning 的紀錄到 logger， logger 的級別若是超過 30，就會被濾掉。
沒有，則該紀錄傳往其所屬 handlers 跟上層的 root  handler 傳入。
若 logger handler 的級別小於等於 30，就會把該紀錄傳出去。
若 root handler 的級別小於等於 30，就會把該紀錄傳出去。
不重要：若 root 的級別超過 30與否都不影響，並沒有在判斷流程。

官網上也有流程圖，那裡寫得會更完整。

為了讓各位更清楚看見流程細節，最後一個範例4：
import logging
from logging import config
    
configName = "logging.conf"
loggerName = "test"
loggerName2 = "test2"

config.fileConfig(configName)
logger = logging.getLogger(loggerName) 
logger2 = logging.getLogger(loggerName2) 

fmt = logging.Formatter("%(name)s - %(levelname)s - %(message)s - root SH 20")
StreamHandler = logging.StreamHandler()
StreamHandler.setFormatter(fmt)
StreamHandler.setLevel(20)
fmt2 = logging.Formatter("%(name)s - %(levelname)s - %(message)s - root SH2 40")
StreamHandler2 = logging.StreamHandler()
StreamHandler2.setFormatter(fmt2)
StreamHandler2.setLevel(40)
logging.root.addHandler(StreamHandler)
logging.root.addHandler(StreamHandler2)

logger.setLevel(10)
logger2.setLevel(30)
logging.root.setLevel(20)

for lg in [logger, logger2]:
    lg.info("20")
    lg.debug("10")
    lg.warning("30")
    lg.error("40")
這裡將 root level = 20，並加了兩個 StreamHandler ，其 level 分別為 20、40。
test - INFO - 20
test - INFO - 20 - root SH 20
test - WARNING - 30
test - WARNING - 30 - root SH 20
test - ERROR - 40
test - ERROR - 40 - root SH 20
test - ERROR - 40 - root SH2 40
test2 - WARNING - 30 - root SH 20
test2 - ERROR - 40
test2 - ERROR - 40 - root SH 20
test2 - ERROR - 40 - root SH2 40
第一眼眼花撩亂，不要忘記：
test level = 10, test SH level = 20
test2 level = 30, test2 SH level = 40
root level = 20, root SH level = 20, root SH2 level = 40
順著 logger -> logger handlers & root handlers 這樣的流程就可以慢慢湊出每行輸出是怎麼來的。

如果不想要讓 Logger 往上傳遞，可以將其propagate設為 False。

總結一下：
如何設定 Logger 指定其輸出檔案跟終端的方式。
如何分別設定 Logger 。
如何使用 config.fileConfig()，簡化 Logger 設定。
描述 logging flow，瞭解傳播的方向與規則。

例1~例4的程式碼放在 github 。

祝各位學習順利，若有建議或想法可以留言告知。
於
標籤： ,