[python]logging 有支援 multi-thread

以往，寫 log 都是很直覺，自己開個檔案就寫下去了。

f = open(filename,mode)
f.write(str(datetime.datetime.now())+ " " + string_to_write + "\n")
f.close()

然而，寫久了的確很煩，於是，進一步的，會寫成一個 module 來簡化。

def log(filename,mode,string_to_write):
  try:
    f = open(filename,mode)
    f.write(str(datetime.datetime.now())+ " " + string_to_write + "\n")
    f.close()
  except:
    if f != None:
      f.close()

但是，最近遇到，我的程式開始有 multi-thread，這樣子開檔寫，
有時會漏 log，有時會干擾，像這樣

2012-02-17 23:47:45.211000 DEBUG  doing ('e02_v2.py',)
2012-02-17 23:47:45.211000 DEBUG  doing ('e02_v2.py',)
',)
2012-02-17 23:47:45.211000 DEBUG  doing ('c17_json_v3.py',)
2012-02-17 23:47:52.215000 DEBUG  done ('e02_v2.py',)

這當然不能忍受，但是，要馬上處理這種問題又不會。
還好，python 內建的 logging 是 thread-safe 就可以應付 multi-thread。(還沒辦法處理 multi-process 寫檔案)

logging 最基本的使用方法：

logging.basicConfig(level=logging.DEBUG,
                  format='%(asctime)s %(levelname)s %(message)s',
                  filename=filename,
                  filemode=mode)
logging.debug(log_string)

第 1 行是設定 logging 的 level、每個記錄的格式、檔名、及開檔模式。
第 5 行就是寫 log。

level 預設是 NOTSET, DEBUG, INFO, WARNING, ERROR 及 CRITICAL 等 6 種。
最後面的等級越高。
舉例來說明，設定的等級為 INFO，則 logging.debug 是不會寫入 log 裡，
要 logging.info, logging.warn, logging.error, logging.critical 才會寫入 log 裡。

記錄的格式，可以使用的變數，這裡就不寫，請參考 python 線上手冊。
這裡要提的是，若我們要的，原來沒提供怎辦？
例如，%(asctime)s 寫出來的是：

2012-02-17 23:52:02,157 DEBUG mylog  doing ('e02_v2.py',)

可是我想要這樣，但 time.strftime 不支援 %f

2012-02-17 23:47:52.215000 DEBUG  done ('e02_v2.py',)

這時候可以這樣改，在format 裡加一個變數名，例如 %(curdatetime)s
然後準備一個 d = {'curdatetime' : datetime.datetime.now().strftime('%Y-%m-%d %H:%M:%S.%f')}
在寫 log 的時候，帶在 extra 的變數裡。logging.debug(log_string,extra=d)
為了方便，我又打包成一個 module 如下：

import datetime, logging
def log(filename,mode,log_string):
  logging.basicConfig(level=logging.DEBUG,
                    format='%(curdatetime)s %(levelname)s %(message)s',
                    filename=filename,
                    filemode=mode)
  d = {'curdatetime':datetime.datetime.now().strftime('%Y-%m-%d %H:%M:%S.%f')}
  logging.debug(log_string,extra=d)

這樣就不用每次寫 log 都自帶一個 extra 的 dict。

用了 logging，也就不怕 multi-thread 了。

當然 logging 還有很多其他功能。以後不用自己寫了。

http://docs.python.org/library/logging.html#logrecord-attributes