python的logging日誌模組(一)

最近修改了專案裡的logging相關功能，用到了標準庫裡的logging模組，在此做一些記錄。主要是從官方文件和stackoverflow上查詢到的一些內容。

• 技術部落格

基本用法

下面的程式碼展示了logging最基本的用法。

# -*- coding: utf-8 -*- import logging import sys # 獲取logger例項，如果引數為空則返回root logger logger = logging.getLogger("AppName") # 指定logger輸出格式 formatter = logging.Formatter('%(asctime)s %(levelname)-8s: %(message)s') # 檔案日誌 file_handler = logging.FileHandler("test.log")
file_handler.setFormatter(formatter) # 可以透過setFormatter指定輸出格式 # 控制檯日誌 console_handler = logging.StreamHandler(sys.stdout)
console_handler.formatter = formatter # 也可以直接給formatter賦值 # 為logger新增的日誌處理器 logger.addHandler(file_handler)
logger.addHandler(console_handler) # 指定日誌的最低輸出級別，預設為WARN級別 logger.setLevel(logging.INFO) # 輸出不同級別的log logger.debug('this is debug info')
logger.info('this is information')
logger.warn('this is warning message')
logger.error('this is error message')
logger.fatal('this is fatal message, it is same as logger.critical')
logger.critical('this is critical message') # 2016-10-08 21:59:19,493 INFO    : this is information # 2016-10-08 21:59:19,493 WARNING : this is warning message # 2016-10-08 21:59:19,493 ERROR   : this is error message # 2016-10-08 21:59:19,493 CRITICAL: this is fatal message, it is same as logger.critical # 2016-10-08 21:59:19,493 CRITICAL: this is critical message # 移除一些日誌處理器 logger.removeHandler(file_handler)

除了這些基本用法，還有一些常見的小技巧可以分享一下。

格式化輸出日誌

# 格式化輸出 service_name = "Booking" logger.error('%s service is down!' % service_name) # 使用python自帶的字串格式化，不推薦 logger.error('%s service is down!', service_name) # 使用logger的格式化，推薦 logger.error('%s service is %s!', service_name, 'down') # 多引數格式化 logger.error('{} service is {}'.format(service_name, 'down')) # 使用format函式，推薦 # 2016-10-08 21:59:19,493 ERROR   : Booking service is down!

記錄異常資訊

當你使用logging模組記錄異常資訊時，不需要傳入該異常物件，只要你直接呼叫logger.error() 或者 logger.exception()就可以將當前異常記錄下來。

# 記錄異常資訊 try: 1 / 0 except: # 等同於error級別，但是會額外記錄當前丟擲的異常堆疊資訊 logger.exception('this is an exception message') # 2016-10-08 21:59:19,493 ERROR   : this is an exception message # Traceback (most recent call last): #   File "D:/Git/py_labs/demo/use_logging.py", line 45, in <module> #     1 / 0 # ZeroDivisionError: integer division or modulo by zero

logging配置要點

GetLogger()方法

這是最基本的入口，該方法引數可以為空，預設的logger名稱是root，如果在同一個程式中一直都使用同名的logger，其實會拿到同一個例項，使用這個技巧就可以跨模組呼叫同樣的logger來記錄日誌。

另外你也可以透過日誌名稱來區分同一程式的不同模組，比如這個例子。

logger = logging.getLogger("App.UI")
logger = logging.getLogger("App.Service")

Formatter日誌格式

Formatter物件定義了log資訊的結構和內容，構造時需要帶兩個引數：

• 一個是格式化的模板fmt，預設會包含最基本的level和 message資訊

• 一個是格式化的時間樣式datefmt，預設為 2003-07-08 16:49:45,896 (%Y-%m-%d %H:%M:%S)

fmt中允許使用的變數可以參考下表。

• %(name)s Logger的名字

• %(levelno)s 數字形式的日誌級別

• %(levelname)s 文字形式的日誌級別

• %(pathname)s 呼叫日誌輸出函式的模組的完整路徑名，可能沒有

• %(filename)s 呼叫日誌輸出函式的模組的檔名

• %(module)s 呼叫日誌輸出函式的模組名|

• %(funcName)s 呼叫日誌輸出函式的函式名|

• %(lineno)d 呼叫日誌輸出函式的語句所在的程式碼行

• %(created)f 當前時間，用UNIX標準的表示時間的浮點數表示|

• %(relativeCreated)d 輸出日誌資訊時的，自Logger建立以來的毫秒數|

• %(asctime)s 字串形式的當前時間。預設格式是“2003-07-08 16:49:45,896”。逗號後面的是毫秒

• %(thread)d 執行緒ID。可能沒有

• %(threadName)s 執行緒名。可能沒有

• %(process)d 程式ID。可能沒有

• %(message)s 使用者輸出的訊息

SetLevel 日誌級別

Logging有如下級別: DEBUG，INFO，WARNING，ERROR，CRITICAL預設級別是WARNING，logging模組只會輸出指定level以上的log。這樣的好處, 就是在專案開發時debug用的log，在產品release階段不用一一註釋，只需要調整logger的級別就可以了，很方便。

Handler 日誌處理器

最常用的是StreamHandler和FileHandler, Handler用於向不同的輸出端打log。Logging包含很多handler, 可能用到的有下面幾種

• StreamHandler instances send error messages to streams (file-like objects).

• FileHandler instances send error messages to disk files.

• RotatingFileHandler instances send error messages to disk files, with support for maximum log file sizes and log file rotation.

• TimedRotatingFileHandler instances send error messages to disk files, rotating the log file at certain timed intervals.

• SocketHandler instances send error messages to TCP/IP sockets.

• DatagramHandler instances send error messages to UDP sockets.

• SMTPHandler instances send error messages to a designated email address.

Configuration 配置方法

logging的配置大致有下面幾種方式。

1. 透過程式碼進行完整配置，參考開頭的例子，主要是透過getLogger方法實現。

2. 透過程式碼進行簡單配置，下面有例子，主要是透過basicConfig方法實現。

3. 透過配置檔案，下面有例子，主要是透過 logging.config.fileConfig(filepath)

basicConfig()提供了非常便捷的方式讓你配置logging模組並馬上開始使用，可以參考下面的例子。具體可以配置的專案請查閱。

import logging

logging.basicConfig(filename='example.log',level=logging.DEBUG)
logging.debug('This message should go to the log file')

logging.basicConfig(format='%(levelname)s:%(message)s', level=logging.DEBUG)
logging.debug('This message should appear on the console')

logging.basicConfig(format='%(asctime)s %(message)s', datefmt='%m/%d/%Y %I:%M:%S %p')
logging.warning('is when this event was logged.')

備註： 其實你甚至可以什麼都不配置直接使用預設值在控制檯中打log，用這樣的方式替換print語句對日後專案維護會有很大幫助。

如果你希望透過配置檔案來管理logging，可以參考這個。在log4net或者log4j中這是很常見的方式。

# logging.conf [loggers] keys=root [logger_root] level=DEBUG handlers=consoleHandler #,timedRotateFileHandler,errorTimedRotateFileHandler

################################################# [handlers] keys=consoleHandler,timedRotateFileHandler,errorTimedRotateFileHandler [handler_consoleHandler] class=StreamHandler level=DEBUG formatter=simpleFormatter args=(sys.stdout,) [handler_timedRotateFileHandler] class=handlers.TimedRotatingFileHandler level=DEBUG formatter=simpleFormatter args=('debug.log', 'H') [handler_errorTimedRotateFileHandler] class=handlers.TimedRotatingFileHandler level=WARN formatter=simpleFormatter args=('error.log', 'H') ################################################# [formatters] keys=simpleFormatter, multiLineFormatter [formatter_simpleFormatter] format= %(levelname)s %(threadName)s %(asctime)s:   %(message)s datefmt=%H:%M:%S [formatter_multiLineFormatter] format= ------------------------- %(levelname)s ------------------------- Time:      %(asctime)s
 Thread:    %(threadName)s
 File:      %(filename)s(line %(lineno)d)
 Message:
 %(message)s datefmt=%Y-%m-%d %H:%M:%S

假設以上的配置檔案放在和模組相同的目錄，程式碼中的呼叫如下。

import os
filepath = os.path.join(os.path.dirname(__file__), 'logging.conf')
logging.config.fileConfig(filepath) return logging.getLogger()

日誌重複輸出的坑

你有可能會看到你打的日誌會重複顯示多次，可能的原因有很多，但總結下來無非就一個，日誌中使用了重複的handler。

第一坑

import logging

logging.basicConfig(level=logging.DEBUG)

fmt = '%(levelname)s:%(message)s' console_handler = logging.StreamHandler()
console_handler.setFormatter(logging.Formatter(fmt))
logging.getLogger().addHandler(console_handler)

logging.info('hello!') # INFO:root:hello! # INFO:hello!

上面這個例子出現了重複日誌，因為在第3行呼叫basicConfig()方法時系統會預設建立一個handler，如果你再新增一個控制檯handler時就會出現重複日誌。

第二坑

import logging def get_logger(): fmt = '%(levelname)s:%(message)s' console_handler = logging.StreamHandler()
    console_handler.setFormatter(logging.Formatter(fmt))
    logger = logging.getLogger('App')
    logger.setLevel(logging.INFO)
    logger.addHandler(console_handler) return logger def call_me(): logger = get_logger()
    logger.info('hi')

call_me()
call_me() # INFO:hi # INFO:hi # INFO:hi

在這個例子裡hi居然列印了三次，如果再呼叫一次call_me()呢？我告訴你會列印6次。why? 因為你每次呼叫get_logger()方法時都會給它加一個新的handler，你是自作自受。正常的做法應該是全域性只配置logger一次。

第三坑

import logging def get_logger(): fmt = '%(levelname)s: %(message)s' console_handler = logging.StreamHandler()
    console_handler.setFormatter(logging.Formatter(fmt))
    logger = logging.getLogger('App')
    logger.setLevel(logging.INFO)
    logger.addHandler(console_handler) return logger def foo(): logging.basicConfig(format='[%(name)s]: %(message)s')
    logging.warn('some module use root logger') def main(): logger = get_logger()
    logger.info('App start.')
    foo()
    logger.info('App shutdown.')

main() # INFO: App start. # [root]: some module use root logger # INFO: App shutdown. # [App]: App shutdown.

為嘛最後的App shutdown列印了兩次？所以在Stackoverflow上很多人都問，我應該怎麼樣把root logger關掉，root logger太坑爹坑媽了。只要你在程式中使用過root logger，那麼預設你列印的所有日誌都算它一份。上面的例子沒有什麼很好的辦法，我建議你招到那個沒有經過大腦就使用root logger的人，亂棍打死他或者開除他。

如果你真的想禁用root logger，有兩個不是辦法的辦法：

logging.getLogger().handlers = [] # 刪除所有的handler logging.getLogger().setLevel(logging.CRITICAL) # 將它的級別設定到最高

小結

Python中的日誌模組作為標準庫的一部分，功能還是比較完善的。個人覺得上手簡單，另外也支援比如過濾，檔案鎖等高階功能，能滿足大多數專案需求。

不過切記，小心坑。