[Python] Basic Logging

這世界看起來好像很安全, 其實很危險, 像是北韓看起來很想要打仗, 但是打過去了要是南韓系統沒有log那怎麼救? (被飛彈炸到還有的救? 還有南韓好像跟我無關...雖然reddit天天都是他們的新聞)

寫程式會有bug, 會有例外狀況, 既然有這種可能會有的突發狀況意外狀況, 有防火牆也防不了的火災......那還是要乖乖的用log紀錄當下系統資訊起來比較保險

python有一個log module相當好使用, 叫做logging

python logging: http://docs.python.org/2/library/logging.html

中文目前描述較詳細的網站: http://www.icoding.co/2012/08/logging-html

英文教學還是歐萊禮比較完整: http://www.onlamp.com/pub/a/python/2005/06/02/logging.html

用print沒什麼不好, 就是管理麻煩了點(懶...), 還是用log比較方便, 一開始設定痛一次, 就好了XD


其實Pyhton Logging不簡單, 而且Handler眾多, 要講起來太花時間, 這邊只給"Basic"設定

先給個簡易設定 (他可以設定要存成檔案或者印出在console, 這邊先印出console)

import logging

logging.basicConfig(level=logging.INFO)

logger = logging.getLogger('logtest')
logger.info('MSG: This is a test log')
logger.debug('MSG: This is a test log')
logger.warning('MSG: This is a test log')
logger.error('MSG: This is a test log')
logger.critical('MSG: This is a test log')

可以看得出來, 當然是要先import logging模組, 接下來事情就簡單了, 需要先設定一個基本Config

然後設定這個log使用名稱logtest, 接著就隨便你加log訊息了

可以使用的種類滿多的, 有info, debug, warning, error, critical...etc 看個人需要加

不過這範例結果會很有趣

INFO:a log test:MSG: This is a test log
WARNING:a log test:MSG: This is a test log
ERROR:a log test:MSG: This is a test log
CRITICAL:a log test:MSG: This is a test log

debug居然沒有印出來?!!

其實也很合理, 當你在寫程式的時候, debug是給你debug用的, 真的要開始正常運作, 都會拿掉debug訊息

這模組就特地讓你可以設定, 在前面的config, 如果改成logging.DEBUG, debug就可以順利的印出了

目前只是很單純的使用, 接著要稍微討論一下格式問題

結果看起來都很單純, 但是有些人可能覺的不好看, 或者是log想要加一些時間紀錄或者是類別等的需求

其實只要小改一下就可以了, 在basicConfig設定format

import logging

logging.basicConfig(level=logging.INFO, format='[%(levelname)s] %(asctime)s - %(message)s')
logger = logging.getLogger('test')
logger.info('MSG: This is a test log')
logger.warning('Protocol problem: This is a test log')
logger.error('Protocol problem: This is a test log')
logger.critical('Protocol problem: This is a test log')

也就是在basicConfig後面加個format, 加入你想要的格式即可, 這邊解釋一下

%(levelname)s <--- 這個就是根據你是用info, warning, error...etc等的類別呼叫的結果

%(asctime)s <--- 會印出這時候的時間, 看下面範例會發現, ','號後面還有數字, 因為他可以細到微秒

%(message)s <--- 就是你傳入的訊息

從上面可以看出, 如果都不設定format, 他其實就是預設%(message)s為你的基本格式

下面為輸出結果

[INFO] 2013-03-31 12:29:35,473 - MSG: This is a test log
[WARNING] 2013-03-31 12:29:35,473 - MSG: This is a test log
[ERROR] 2013-03-31 12:29:35,473 - MSG: This is a test log
[CRITICAL] 2013-03-31 12:29:35,473 - MSG: This is a test log

這樣可以看得出來好看了一點對吧, 當然可以根據個人需求修改

PS: 其實還有很多的內建變數可以使用, 不是只有時間, 詳表請參閱官網:
http://docs.python.org/2/library/logging.html#logrecord-attributes

另外, 傳入的message, 也可以長的跟print一樣格式

例如:

num = 12345
logger.info("Test number: %d" % num)

印出結果

[INFO] 2013-03-31 14:05:12,382 - Test number: 12345

當然, 還有更複雜的使用方式, 例如因為你要傳入的格式比較複雜, 可以用變數的方式代入

這邊用官網的第一個範例

import logging

FORMAT = '%(asctime)-15s %(clientip)s %(user)-8s %(message)s'
logging.basicConfig(format=FORMAT)
d = {'clientip': '192.168.0.1', 'user': 'fbloggs'}
logger = logging.getLogger('tcpserver')
logger.warning('Protocol problem: %s', 'connection reset', extra=d)

印出結果

2013-03-31 14:08:07,234 192.168.0.1 fbloggs  Protocol problem: connection reset

簡單看一下, 跟我之前範例最大不一樣的地方是, 在warning語句他後面多了一個extra = d

d設定為{'clientip': '192.168.0.1', 'user': 'fbloggs'}

FORMAT那邊則是有看到沒見過的clientip跟user變數, 其實對照一下, 可以發現他是設定好變數在format

只要傳入的的參數先設定好成一個dict (也就是d), 就可以輕鬆的帶入使用

補充說明一下, 因為前面都是印出在console, 其實可以選擇存入檔案或者是印出或者是兼併

如果要把資訊都印到檔案裡面則在basicConfig修改設定加上filename即可

例如我要把這些log訊息寫到執行的目錄下的logs就可以設定成:

logpath = os.getcwd() + "/logs"
logging.basicConfig(format=FORMAT, filename = logpath)

這樣就只會寫到檔案而已了

那, 如果想要又寫檔案又輸出到console, 甚至想要輸出console跟寫到檔案的格式要不一樣, 就要多加一點設定

用官方網站做修改

import os, logging

FORMAT = '%(asctime)-15s %(clientip)s %(user)-8s %(message)s'
logpath = os.getcwd() + "/logs"
logging.basicConfig(format = FORMAT, filename = logpath)
d = {'clientip': '192.168.0.1', 'user': 'fbloggs'}
logger = logging.getLogger('tcpserver')

console = logging.StreamHandler()
aformat = logging.Formatter('%(asctime)s - %(name)s - [%(levelname)s] - %(message)s')
console.setFormatter(aformat)
logger.addHandler(console)

logger.warning('Protocol problem: %s', 'connection reset', extra=d)

多了三四行指令, 首先是用logging另外宣告出一個StreamHandler, 他其實就可以控制串流輸出

然後用logging.Formatter設定好你想要的輸出格式, 在利用StreamHandler的setFormatter來載入

最後記得加入現行使用的logger裡面(addHanlder), 就可以同時又寫檔案又輸出console而且格式可以分開設定

看結果, 首先是console的

2013-03-31 14:19:12,002 - tcpserver - [WARNING] - Protocol problem: connection reset

再來是log file的

2013-03-31 14:19:12,002 192.168.0.1 fbloggs  Protocol problem: connection reset

再來, log其實就是有分level的, info < warning < error < critical

logging module其實提供關閉部份log的機制

logging.disable(logging.INFO)
logger.info('Protocol problem: %s', 'connection reset', extra=d)
logger.warning('Protocol problem: %s', 'connection reset', extra=d)
logger.error('Protocol problem: %s', 'connection reset', extra=d)
logger.critical('Protocol problem: %s', 'connection reset', extra=d)

logging.disable後面接logging的level, 像是上面範例, 就會關掉INFO以上的訊息

如果換成logging.WARNING, 就會info跟warning都被關掉, 以此類推

補充一個exception的logger

import os, logging

FORMAT = '%(asctime)s - %(name)s - [%(levelname)s] - %(message)s'
logpath = os.getcwd() + "/logs"
logging.basicConfig(format = FORMAT, filename = logpath)
logger = logging.getLogger('tcpserver')

console = logging.StreamHandler()
aformat = logging.Formatter('%(asctime)s - %(name)s - [%(levelname)s] - %(message)s')
console.setFormatter(aformat)
logger.addHandler(console)

try:
    open("NotExist")
except Exception, err:
    logger.exception('Open File Error')

在exception那邊, 加個logger.exception, 就會把跟一般錯誤訊息的Error Message一樣的寫到log file之中

---

當然...這世界是很可怕的, 因為不可能回到火星, 所以只好乖乖在地球拼命寫log...

其實logging module可以在細分出兩件大事情,一個是handler, 另外一個是config

當log太複雜或者是人老色衰腦袋不好使, 只好用一點config把他記錄下來, 下面是一個範例檔案(logging.conf)

[loggers]
keys: root

[logger_root]
handlers: console,file

[formatters]
keys: console,file
 
[handlers]
keys: console,file
 
[formatter_file]
format: %(asctime)-15s %(clientip)s %(user)-8s %(message)s
 
[formatter_console]
format: %(asctime)s - %(name)s - [%(levelname)s] - %(message)s
 
[handler_console]
class: StreamHandler
args: []
formatter: console
 
[handler_file]
class: FileHandler
formatter=file
args=('logs',)

這樣原始的程式碼需要打的內容就變得相當少了, 只要下列

import logging, logging.config

logging.config.fileConfig("logging.conf")
logger = logging.getLogger("root")
d = {'clientip': '192.168.0.1', 'user': 'fbloggs'}
logger.warning('Protocol problem: %s', 'connection reset', extra=d)

這樣就可以了, 結果是跟上述其他範例差不多

稍微解釋一下幾個重點

loggers下面一定要有root, 我一開始一直打別的名稱一直錯誤, 才發現一定要有root

看起來有點複雜, 其實只要記住, 有keys的設定, 就表示要在config另外設定相對的內容

例如我設定了handlers
[handlers]
keys: console, file

那我檔案就必須相對的要設定[handler_console] 跟 [handler_file], 而keys其實可以自訂 不一定要打console or file

format也是同樣道理, 把之前設定分別設定到兩種不同的formatter即可

但是handler這邊要注意, handler_console那邊其實就只是StreamHander 之前範例有

但是handler_file那個是要輸出檔案, 所以要設定FileHandler

在handler那邊要設定args, 不設定也要給個args: [] 不然會錯誤

而Handler其實有相當多種, 每個都可以寫不少範例...等我哪天腦細胞比較多的時候再來寫..

還有其他更重要的東西需要紀錄....

其餘Handler: http://docs.python.org/2/library/logging.handlers.html#module-logging.handlers