python模塊之logging

　　在現實生活中，記錄日誌非常重要。銀行轉賬時會有轉賬記錄；飛機飛行過程中，會有黑盒子（飛行數據記錄器）記錄飛行過程中的一切。如果有出現什麼問題，人們可以通過日誌數據來搞清楚到底發生了什麼。對於系統開發、調試以及運行，記錄日誌都是同樣的重要。如果沒有日誌記錄，程式崩潰時你幾乎就沒辦法弄明白到底發生了什麼事情。舉個例子，當你在寫一個伺服器程式時，記錄日誌是非常有必要的。下麵展示的就是 EZComet.com 伺服器的日誌文件截圖。

　　服務崩潰後，如果沒有日誌，我幾乎沒辦法知道到底發生了錯誤。日誌不僅對於伺服器很重要，對於桌面圖形應用同樣十分重要。比如，當你的客戶的 PC 機程式崩潰時，你可以讓他們把日誌文件發給你，這樣你就可以找到問題到底出在哪兒。相信我，在不同的 PC 環境下，你永遠不會知道會有怎樣奇怪的問題。我曾經就接收到過這樣的錯誤日誌。

 1 2011-08-22 17:52:54,828 - root - ERROR - [Errno 10104] getaddrinfo failed
 2 Traceback (most recent call last):
 3   File "<string>", line 124, in main
 4   File "<string>", line 20, in __init__
 5   File "h:workspaceprojectbuildpyi.win32mrdjoutPYZ1.pyz/wx._core", line 7978, in __init__
 6   File "h:workspaceprojectbuildpyi.win32mrdjoutPYZ1.pyz/wx._core", line 7552, in _BootstrapApp
 7   File "<string>", line 84, in OnInit
 8   File "h:workspaceprojectbuildpyi.win32mrdjoutPYZ1.pyz/twisted.internet.wxreactor", line 175, in install
 9   File "h:workspaceprojectbuildpyi.win32mrdjoutPYZ1.pyz/twisted.internet._threadedselect", line 106, in __init__
10   File "h:workspaceprojectbuildpyi.win32mrdjoutPYZ1.pyz/twisted.internet.base", line 488, in __init__
11   File "h:workspaceprojectbuildpyi.win32mrdjoutPYZ1.pyz/twisted.internet.posixbase", line 266, in installWaker
12   File "h:workspaceprojectbuildpyi.win32mrdjoutPYZ1.pyz/twisted.internet.posixbase", line 74, in __init__
13   File "h:workspaceprojectbuildpyi.win32mrdjoutPYZ1.pyz/socket", line 224, in meth
14 gaierror: [Errno 10104] getaddrinfo failed

　　我最終發現，這個客戶的 PC 機被一種病毒感染，導致了調用 gethostname 函數失敗。看吧，如果沒有日誌可以查你怎麼可能知道這些。

列印輸出不是個好辦法

　　儘管記錄日誌非常重要，但是並不是所有的開發者都能正確地使用它。我曾看到一些開發者是這樣記錄日誌的，在開發的過程中插入 print 語句，開髮結束後再將這些語句移除。就像這樣:

1 print 'Start reading database'
2 records = model.read_recrods()
3 print '# records', records
4 print 'Updating record ...'
5 model.update_records(records)
6 print 'done'

　　這種方式對於簡單腳本型程式有用，但是如果是複雜的系統，你最好不要使用這樣的方式。首先，你沒辦法做到在日誌文件中只留下極其重要的消息。你會看到大量的消息日誌。但是你卻找不到任何有用的信息。你除了移除這輸出語句這外，沒別的辦法控制代碼，但是極有可能的是你忘記了移出那些沒用的輸出。再者，print 輸出的所有信息都到了標準輸出中，這將嚴重影響到你從標準輸出中查看其它輸出數據。當然，你也可以把消息輸出到 stderr ，但是用 print 做日誌記錄的方式還是不好。

使用 python 的標準日誌模塊

　　那麼，怎麼樣記錄日誌才是正確的呢？其實非常簡單，使用 python 的標準日誌模塊。多虧 python 社區將日誌做成了一個標準模塊。它非常簡單易用且十分靈活。你可以像這樣使用日誌系統：

 1 import logging
 2 logging.basicConfig(level=logging.INFO)
 3 logger = logging.getLogger(__name__)
 4 
 5 logger.info('Start reading database')
 6 # read database here
 7 
 8 records = {'john': 55, 'tom': 66}
 9 logger.debug('Records: %s', records)
10 logger.info('Updating records ...')
11 # update records here
12 
13 logger.info('Finish updating records')

運行的時候就可看到：

1 INFO:__main__:Start reading database
2 INFO:__main__:Updating records ...
3 INFO:__main__:Finish updating records

你可能會問這與使用 print 有什麼不同呢。它有以下的優勢：

• 你可以控制消息的級別，過濾掉那些並不重要的消息。
• 你可決定輸出到什麼地方，以及怎麼輸出。

　　有許多的重要性別級可供選擇，debug、info、warning、error 以及 critical。通過賦予 logger 或者 handler 不同的級別，你就可以只輸出錯誤消息到特定的記錄文件中，或者在調試時只記錄調試信息。讓我們把 logger 的級別改成 DEBUG 再看一下輸出結果：

1 logging.basicConfig(level=logging.DEBUG)

輸出變成了：

1 INFO:__main__:Start reading database
2 DEBUG:__main__:Records: {'john': 55, 'tom': 66}
3 INFO:__main__:Updating records ...
4 INFO:__main__:Finish updating records

　　正如看到的那樣，我們把 logger 的等級改為 DEBUG 後，調試記錄就出現在了輸出當中。你也可以選擇怎麼處理這些消息。例如，你可以使用 FileHandler 把記錄寫進文件中：

 1 import logging
 2 
 3 logger = logging.getLogger(__name__)
 4 logger.setLevel(logging.INFO)
 5 
 6 # create a file handler
 7 
 8 handler = logging.FileHandler('hello.log')
 9 handler.setLevel(logging.INFO)
10 
11 # create a logging format
12 
13 formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
14 handler.setFormatter(formatter)
15 
16 # add the handlers to the logger
17 
18 logger.addHandler(handler)
19 
20 logger.info('Hello baby')

以合適的等級輸出日誌記錄

　　有了靈活的日誌記錄模塊後，你可以按適當的等級將日誌記錄輸出到任何地方然後配置它們。那麼你可能會問，什麼是合適的等級呢？在這兒我將分享一些我的經驗。

大多數的情況下，你都不想閱讀日誌中的太多細節。因此，只有你在調試過程中才會使用 DEBUG 等級。我只使用 DEBUG 獲取詳細的調試信息，特別是當數據量很大或者頻率很高的時候，比如演算法內部每個迴圈的中間狀態。

1 def complex_algorithm(items):
2     for i, item in enumerate(items):
3         # do some complex algorithm computation
4 
5         logger.debug('%s iteration, item=%s', i, item)

在處理請求或者伺服器狀態變化等日常事務中，我會使用 INFO 等級。

 1 def handle_request(request):
 2     logger.info('Handling request %s', request)
 3     # handle request here
 4 
 5     result = 'result'
 6     logger.info('Return result: %s', result)
 7 
 8 def start_service():
 9     logger.info('Starting service at port %s ...', port)
10     service.start()
11     logger.info('Service is started')

當發生很重要的事件，但是並不是錯誤時，我會使用 WARNING 。比如，當用戶登錄密碼錯誤時，或者連接變慢時。

1 def authenticate(user_name, password, ip_address):
2     if user_name != USER_NAME and password != PASSWORD:
3         logger.warn('Login attempt to %s from IP %s', user_name, ip_address)
4         return False
5     # do authentication here

有錯誤發生時肯定會使用 ERROR 等級了。比如拋出異常，IO 操作失敗或者連接問題等。

1 def get_user_by_id(user_id):
2     user = db.read_user(user_id)
3     if user is None:
4         logger.error('Cannot find user with user_id=%s', user_id)
5         return user
6     return user

我很少使用 CRITICAL 。當一些特別糟糕的事情發生時，你可以使用這個級別來記錄。比方說，記憶體耗盡，磁碟滿了或者核危機（希望永遠別發生 :S）。

　　雖然不是非得將 logger 的名稱設置為 __name__ ，但是這樣做會給我們帶來諸多益處。在 python 中，變數 __name__ 的名稱就是當前模塊的名稱。比如，在模塊 “foo.bar.my_module” 中調用 logger.getLogger(__name__) 等價於調用logger.getLogger(“foo.bar.my_module”) 。當你需要配置 logger 時，你可以配置到 “foo” 中，這樣包 foo 中的所有模塊都會使用相同的配置。當你在讀日誌文件的時候，你就能夠明白消息到底來自於哪一個模塊。

捕捉異常並使用 traceback 記錄它

　　出問題的時候記錄下來是個好習慣，但是如果沒有 traceback ，那麼它一點兒用也沒有。你應該捕獲異常並用 traceback 把它們記錄下來。比如下麵這個例子：

1 try:
2     open('/path/to/does/not/exist', 'rb')
3 except (SystemExit, KeyboardInterrupt):
4     raise
5 except Exception, e:
6     logger.error('Failed to open file', exc_info=True)

使用參數 exc_info=true 調用 logger 方法, traceback 會輸出到 logger 中。你可以看到下麵的結果

1 ERROR:__main__:Failed to open file
2 Traceback (most recent call last):
3   File "example.py", line 6, in <module>
4     open('/path/to/does/not/exist', 'rb')
5 IOError: [Errno 2] No such file or directory: '/path/to/does/not/exist'

Python 使用logging模塊記錄日誌涉及四個主要類，使用官方文檔中的概括最為合適：

logger提供了應用程式可以直接使用的介面；

handler將(logger創建的)日誌記錄發送到合適的目的輸出；

filter提供了細度設備來決定輸出哪條日誌記錄；

formatter決定日誌記錄的最終輸出格式。

logging模塊是在2.3新引進的功能，下麵是一些常用的類和模塊級函數

模塊級函數
logging.getLogger([name]):返回一個logger對象，如果沒有指定名字將返回root logger
logging.debug()、logging.info()、logging.warning()、logging.error()、logging.critical()：設定root logger的日誌級別
logging.basicConfig():用預設Formatter為日誌系統建立一個StreamHandler，設置基礎配置並加到root logger中

每個程式在輸出信息之前都要獲得一個Logger。Logger通常對應了程式的模塊名，比如聊天工具的圖形界面模塊可以這樣獲得它的Logger：
LOG=logging.getLogger(”chat.gui”)
而核心模塊可以這樣：
LOG=logging.getLogger(”chat.kernel”)

Logger.setLevel(lel):指定最低的日誌級別，低於lel的級別將被忽略。debug是最低的內置級別，critical為最高
Logger.addFilter(filt)、Logger.removeFilter(filt):添加或刪除指定的filter
Logger.addHandler(hdlr)、Logger.removeHandler(hdlr)：增加或刪除指定的handler
Logger.debug()、Logger.info()、Logger.warning()、Logger.error()、Logger.critical()：可以設置的日誌級別
設置logger的level， level有以下幾個級別：

NOTSET < DEBUG < INFO < WARNING < ERROR < CRITICAL
如果把looger的級別設置為INFO， 那麼小於INFO級別的日誌都不輸出， 大於等於INFO級別的日誌都輸出

Handlers
handler對象負責發送相關的信息到指定目的地。Python的日誌系統有多種Handler可以使用。有些Handler可以把信息輸出到控制台，有些Logger可以把信息輸出到文件，還有些 Handler可以把信息發送到網路上。如果覺得不夠用，還可以編寫自己的Handler。可以通過addHandler()方法添加多個多handler
Handler.setLevel(lel):指定被處理的信息級別，低於lel級別的信息將被忽略
Handler.setFormatter()：給這個handler選擇一個格式
Handler.addFilter(filt)、Handler.removeFilter(filt)：新增或刪除一個filter對象

Formatters

Formatter對象設置日誌信息最後的規則、結構和內容，預設的時間格式為%Y-%m-%d %H:%M:%S，下麵是Formatter常用的一些信息

設置過濾器
細心的朋友一定會發現前文調用logging.getLogger()時參數的格式類似於“A.B.C”。採取這樣的格式其實就是為了可以配置過濾器。看一下這段代碼：
LOG=logging.getLogger(”chat.gui.statistic”)
console = logging.StreamHandler()
console.setLevel(logging.INFO)
formatter = logging.Formatter(’%(asctime)s %(levelname)s %(message)s’)
console.setFormatter(formatter)
filter=logging.Filter(”chat.gui”)
console.addFilter(filter)
LOG.addHandler(console)
和前面不同的是我們在Handler上添加了一個過濾器。現在我們輸出日誌信息的時候就會經過過濾器的處理。名為“A.B”的過濾器只讓名字帶有 “A.B”首碼的Logger輸出信息。可以添加多個過濾器，只要有一個過濾器拒絕，日誌信息就不會被輸出。當然名為“A”首碼的Logger會輸出信息。另外，在Logger中也可以添加過濾器。

每個Logger可以附加多個Handler。接下來我們就來介紹一些常用的Handler：
1)    logging.StreamHandler
使用這個Handler可以向類似與sys.stdout或者sys.stderr的任何文件對象(file object)輸出信息。它的構造函數是：
StreamHandler([strm])
其中strm參數是一個文件對象。預設是sys.stderr
2)   logging.FileHandler
和StreamHandler類似，用於向一個文件輸出日誌信息。不過FileHandler會幫你打開這個文件。它的構造函數是：
FileHandler(filename[,mode])
filename是文件名，必須指定一個文件名。
mode是文件的打開方式。參見Python內置函數open()的用法。預設是’a'，即添加到文件末尾。
3)   logging.handlers.RotatingFileHandler
這個Handler類似於上面的FileHandler，但是它可以管理文件大小。當文件達到一定大小之後，它會自動將當前日誌文件改名，然後創建 一個新的同名日誌文件繼續輸出。比如日誌文件是chat.log。當chat.log達到指定的大小之後，RotatingFileHandler自動把 文件改名為chat.log.1。不過，如果chat.log.1已經存在，會先把chat.log.1重命名為chat.log.2。。。最後重新創建 chat.log，繼續輸出日誌信息。它的構造函數是：
RotatingFileHandler( filename[, mode[, maxBytes[, backupCount]]])
其中filename和mode兩個參數和FileHandler一樣。
maxBytes用於指定日誌文件的最大文件大小。如果maxBytes為0，意味著日誌文件可以無限大，這時上面描述的重命名過程就不會發生。
backupCount用於指定保留的備份文件的個數。比如，如果指定為2，當上面描述的重命名過程發生時，原有的chat.log.2並不會被更名，而是被刪除。
4)   logging.handlers.TimedRotatingFileHandler
這個Handler和RotatingFileHandler類似，不過，它沒有通過判斷文件大小來決定何時重新創建日誌文件，而是間隔一定時間就 自動創建新的日誌文件。重命名的過程與RotatingFileHandler類似，不過新的文件不是附加數字，而是當前時間。它的構造函數是：
TimedRotatingFileHandler( filename [,when [,interval [,backupCount]]])
其中filename參數和backupCount參數和RotatingFileHandler具有相同的意義。
interval是時間間隔。
when參數是一個字元串。表示時間間隔的單位，不區分大小寫。它有以下取值：
S 秒
M 分
H 小時
D 天
W 每星期（interval==0時代表星期一）
midnight 每天凌晨
5)   logging.handlers.SocketHandler
6)   logging.handlers.DatagramHandler
以上兩個Handler類似，都是將日誌信息發送到網路。不同的是前者使用TCP協議，後者使用UDP協議。它們的構造函數是：
Handler(host, port)
其中host是主機名，port是埠名
7)  logging.handlers.SysLogHandler
8)  logging.handlers.NTEventLogHandler
9)  logging.handlers.SMTPHandler
10) logging.handlers.MemoryHandler
11) logging.handlers.HTTPHandler

 1 # encoding:utf-8
 2 #import logging
 3 
 4 #FORMAT = '%(asctime)-15s %(clientip)s %(user)-8s %(message)s'
 5 #logging.basicConfig(format=FORMAT)
 6 #d = {'clientip': '192.168.0.1', 'user': 'fbloggs'}
 7 #logger = logging.getLogger('tcpserver')
 8 #logger.warning('Protocol problem: %s', 'connection reset', extra=d)
 9 
10 #FORMAT = '%(asctime)-15s %(message)s'
11 #logging.basicConfig(filename = "C:\\Users\\june\\Desktop\\1.txt", level = logging.DEBUG, filemode = "a", format=FORMAT)  
12 #logging.debug('this is a message')  
13 #logging.debug('test')  
14 
15 #import logging
16 #import datetime
17 #
18 #curDate = datetime.date.today() - datetime.timedelta(days=0)
19 #logName =  'C:\\Users\\june\\Desktop\\error_%s.log' %curDate
20 #
21 #logging.basicConfig(level=logging.INFO,
22 #                format='%(asctime)s %(filename)s[line:%(lineno)d] %(levelname)s %(message)s',
23 #                #datefmt='%a, %d %b %Y %H:%M:%S',
24 #                filename=logName,
25 #                filemode='a')
26 #
27 ##2013-10-21 03:25:51,509 writeLog.py[line:14] INFO This is info message
28 ##2013-10-21 03:25:51,510 writeLog.py[line:15] WARNING This is warning message
29 #logging.debug('This is debug message')
30 #logging.info('This is info message')
31 #logging.warning('This is warning message')import logging
32 import logging.config
33 
34 logging.config.fileConfig("logging.conf")
35 
36 #create logger
37 loggerInfo = logging.getLogger("infoLogger")
38 
39 #"application" code
40 loggerInfo.debug("debug message")
41 loggerInfo.info("info message")
42 loggerInfo.warn("warn message")
43 loggerInfo.error("error message")
44 loggerInfo.critical("critical message")
45 
46 
47 loggerError = logging.getLogger("errorLogger")
48 loggerError.error("Error: Hello world!")

 1 #coding=utf-8
 2 import logging
 3 import datetime
 4 
 5 format='%(asctime)s - %(filename)s - [line:%(lineno)d] - %(levelname)s - %(message)s'
 6 curDate = datetime.date.today() - datetime.timedelta(days=0)
 7 infoLogName =  r'C:/Users/june/Desktop/info_%s.log' %curDate
 8 errorLogName =  r'C:/Users/june/Desktop/error_%s.log' %curDate
 9 
10 formatter = logging.Formatter(format)
11 
12 infoLogger = logging.getLogger("infoLog")
13 errorLogger = logging.getLogger("errorLog")
14 
15 infoLogger.setLevel(logging.INFO)
16 errorLogger.setLevel(logging.ERROR)
17 
18 infoHandler = logging.FileHandler(infoLogName, 'a')
19 infoHandler.setLevel(logging.INFO)
20 infoHandler.setFormatter(formatter)
21 
22 errorHandler = logging.FileHandler(errorLogName, 'a')
23 errorHandler.setLevel(logging.ERROR)
24 errorHandler.setFormatter(formatter)
25 
26 testHandler = logging.StreamHandler()
27 testHandler.setFormatter(formatter)
28 testHandler.setLevel(logging.ERROR)
29 
30 infoLogger.addHandler(infoHandler)
31 infoLogger.addHandler(testHandler)
32 errorLogger.addHandler(errorHandler)
33 
34 #infoLogger.debug("debug message")
35 #infoLogger.info("info message")
36 #infoLogger.warn("warn message")
37 # # 下麵這行會同時列印在文件和終端上
38 #infoLogger.error("error message")
39 #
40 #errorLogger.error("error message")
41 #errorLogger.critical("critical message")

  1 '''
  2 Created on 2016年8月18日
  3 
  4 @author: apple
  5 '''
  6 #-*- coding:utf-8 -*-
  7 
  8 #開發出一個日誌系統，既要把日誌輸出到控制台，還要寫入日誌文件
  9 
 10 import logging
 11 import time
 12 import os
 13 import os.path
 14 
 15 class Logger():
 16     def __init__(self, log_name, logger_name):
 17         
 18         '''
 19                 指定保存日誌的文件路徑，日誌級別以及調用文件
 20                 將日誌    存入到指定的文件中
 21     
 22         '''
 23         #設置日誌文件名稱：time.time()取得當前時間；time.localtime()取得本地時間；time.strftime()格式化日期；
 24         time_str = time.strftime("%Y_%m_%d_%H_%M_%S", time.localtime(time.time()))
 25         logname = time_str + '_' + log_name + '.log'
 26         
 27         #設置日誌文件所在的路徑
 28         log_filedir = 'Log'
 29         if not os.path.isdir(log_filedir):
 30             print("日誌文件夾 %s 不存在，開始創建此文件夾" %log_filedir)
 31             os.mkdir('Log')
 32         else:
 33             print("日誌文件夾 %s 存在" %log_filedir)
 34         
 35         os.chdir('Log')
 36         
 37         #創建一個logger以及設置日誌級別
 38         #logging有6個日誌級別:NOTSET, DEBUG, INFO, WARNING, ERROR, CRITICAL對應的值分別為：0,10,20,30,40,50
 39         #例如:logging.DEBUG和10是等價的表示方法
 40         #可以給日誌對象(Logger Instance)設置日誌級別，低於該級別的日誌消息將會被忽略，也可以給Hanlder設置日誌級別
 41         #對於低於該級別的日誌消息, Handler也會忽略。
 42         self.logger = logging.getLogger(logger_name)
 43         self.logger.setLevel(logging.DEBUG)
 44         
 45         #創建文件handler，用於寫入日誌文件並設置文件日誌級別
 46         file_handler = logging.FileHandler(logname)
 47         file_handler.setLevel(logging.DEBUG)
 48         
 49         #創建控制端輸出handler，用於輸出到控制端並設置輸出日誌級別
 50         console_handler = logging.StreamHandler()
 51         console_handler.setLevel(logging.DEBUG)
 52         
 53         #在控制端handler添加過濾器，將含有chat或者gui的handler信息輸出
 54         filter = logging.Filter("chat.gui")
 55         console_handler.addFilter(filter)
 56         
 57         #定義handler的輸出格式並將格式應用到handler
 58         formatter = logging.Formatter('%(asctime)s-%(name)s-%(levelname)s-%(message)s')
 59         file_handler.setFormatter(formatter)
 60         console_handler.setFormatter(formatter)
 61         
 62         #將handler加入到logger
 63         self.logger.addHandler(file_handler)
 64         self.logger.addHandler(console_handler)
 65         
 66         self.logger.debug("這個是debug日誌信息")
 67         self.logger.info("歡迎大家來到 Python的世界")
 68         
 69         
 70         #將handler從logger中移除
 71         self.logger.removeHandler(file_handler)
 72