python logging 做得好，維護沒煩惱

請訪問 iCoding Blog 主站 

跟 print 大法說再見

每次在寫程式的時候，我們一定會把程式運行中的訊息記錄下來。在 Python 中，我們很順手地，就會做下面這件事:

    print( "The program meets error %d" % error_code )

比如說，當我們遇到讓我們害怕的bug, 慌張的程師設計師一定會用 print 大法，開始到處印內部的變數。 當你開心地找出問題以後，你一定會很無力地看到不少無用的訊息噴出來....

懶惰的天性使然，一定會等到上線再來整理這些一團亂。

另外，程式中有許多有意義的指標，可以讓我們知道程式運行的狀態，你不會希望它們只是被  print 到螢幕上而已，資訊一定要好好地保存好，甚至是很專業地把log 傳送到 splunk 這種log 分析系統裡，程式才可以被清楚地掌握與管理。

說了這麼多，就是要你除了Business Logic 之外，程式裡面不要有無義意的 print。

請開始用 logging 模組

我們現在就開始用使用python logging 來印出資訊。

首先，用簡單一點的寫法，在你的程式的開頭，可以寫這段code.

import logging

logging.basicConfig(level=logging.DEBUG)

logger = logging.getLogger( __name__ )

這樣就好，沒有別的事情了。

然後，在你的程式中，依照你的需要，你可以寫出如下的 code

logger.debug( "enter the XXX function" )
logger.debug(" user exists 10000 ")

從此以後，你需要做的事就是把資訊，依照 debug, info, warning, error, critical 這些分類來把資訊印出來，像是前面的例子，你只要把第二行的 logging.basicConfig(level=logging.DEBUG) 中的 level 換成別的level: logging.basicConfig(level=logging.INFO)。這樣子的話，程式中為了除錯所加的 debug 訊息就不會再出現了。


不過，上面講的簡略的做法，只是讓你了解logging該怎麼使用，並且只是把 logger.debug 當做可依情況關閉的 print 來用而已，我們需要如下更有彈性的寫法。

	import logging
	logger = logging.getLogger( __name__ )
	def some_method():
	logger.debug('begin of some_method')
	def main():
	logging.basicConfig(level=logging.DEBUG)
	some_method()
	if __name__ == '__main__':
	main()

view raw gistfile1.py hosted with ❤ by GitHub

這個寫法的原則很重要，請都用下面所說的想法來設計 logging 相關的程式:

1. 每個 module, class, 都用自已的logger, 當你寫的code, 是一個被人使用的module, 請不要去做多餘的設定。
2. logger 的名字為了要能方便找出問題，所以不要亂取，通常都是以 module 或是 class 的名稱來命名。
3. logging 的設定，由整個應用程式的main 函式來決定, 比如說決定該把log 寫到檔案或是將log 傳送到syslogd .我們目前是為了簡單好用才以 logging.basicConfig 當作例子。更實際的例子會用 logging.config.fileConfig. 

所以，當你寫一個 Utility 型式的程式的時候，你只要記好下面這三行code. 其它都不要多想。

import logging

logger = logging.getLogger( __name__ )

logger.debug( "XXX" )

 logging.basicConfig

講完了 Utility 該注意的事情了。你免不了要寫程式進入點。在這裡就是設定logger的地方, 但是python 的logger 由於很有彈性，所以有點複雜。看完了Python logging 的 Reference 以後，我們可要寫像下面落落長的設定才可以把log 寫到 standard error 

	import logging
	logger = logging.getLogger( 'my_module' )
	def some_method():
	logger.debug('begin of some_method')
	def main():
	# Produce formater first
	formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
	# Setup Handler
	console = logging.StreamHandler()
	console.setLevel(logging.DEBUG)
	console.setFormatter(formatter)
	# Setup Logger
	logger.addHandler(console)
	logger.setLevel(logging.DEBUG)
	some_method()
	if __name__ == '__main__':
	main()

view raw complex-logging.py hosted with ❤ by GitHub

恩，要先弄懂 formater, handler。能先弄懂是很好，但若是第一時間弄不懂，你可以把那些設定換成 logging.basicConfig(level=logging.DEBUG) , 就像更前面的例子一樣。若是你想把log 導到檔案中的話，那就只要做一點修改: logging.basicConfig(filename='/tmp/logs', level=logging.DEBUG), 加上 filename 這個 argument就好。 記好 basicConfig 這個捷徑，logging 更快樂~

logging.config.fileConfig

為了更有彈性，更完整的功能，logging module 提供了 ini 檔的格式的設定檔。

有的時候我在想，連logging這件事情都要寫一個config 檔案，就覺得程式設計師好辛苦啊~ 不過苦歸苦，生活還是要過.....

在這裡不講logging 的config 檔怎麼寫，就只講 logging.config.fileConfig 這個function 該怎麼用。

這個function call 做的事還是設定logger, 所以它該出現的地方，跟 logging.basicConfig該出現的地方是一樣的。

不過，在 python 2.6 後，這個 function call 多了一個參數，叫做disable_existing_loggers，使用上，請把它設定成False, 但python 為了向後相容2.5版以前的python，把它的預設值設成了 True. 

如果照它的預設值 disable_existing_loggers=True 來執行的話，在這個function call 之前所get出來的logger,  如果沒有在 config file裡面設定過的話，就會被disable。也就是說，極容易發生你的 module 寫的log 都寫到空氣裡了。

所以，請這樣子用 fileConfig:

    logging.config.fileConfig('log_config_file", disable_existing_loggers=False)

如此，你才有機會看到各個 module 所寫出來的log。

最後

logging 有點複雜，但請熟悉一下這篇文章整理的做法，這樣才能在短時間寫出好維護的好Code!! 當然，還有很多不同的Style 來設定 logger, 如果有不同的Style, 也可以一起討論!

然後，幫強者我同學 Scott 廣告一下他的手機APP (真是不搭) http://blog.walkthisway.tw/post/27802609152/taiwan-host-bnb