Python中的logging子產品

最近修改了項目裡的logging相關功能，用到了python标準庫裡的logging子產品，在此做一些記錄。主要是從官方文檔和stackoverflow上查詢到的一些内容。

<a href="https://docs.python.org/2.7/library/logging.html">官方文檔</a>

<a href="http://blog.csdn.net/balderfan/article/details/7644807">技術部落格</a>

下面的代碼展示了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)

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

1

2

3

4

5

6

7

8

9

# 格式化輸出

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子產品記錄異常資訊時，不需要傳入該異常對象，隻要你直接調用<code>logger.error()</code> 或者 <code>logger.exception()</code>就可以将目前異常記錄下來。

10

11

12

13

# 記錄異常資訊

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

#     1 / 0

# ZeroDivisionError: integer division or modulo by zero

這是最基本的入口，該方法參數可以為空，預設的logger名稱是root，如果在同一個程式中一直都使用同名的logger，其實會拿到同一個執行個體，使用這個技巧就可以跨子產品調用同樣的logger來記錄日志。

另外你也可以通過日志名稱來區分同一程式的不同子產品，比如這個例子。

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

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

Formatter對象定義了log資訊的結構和内容，構造時需要帶兩個參數：

一個是格式化的模闆<code>fmt</code>，預設會包含最基本的<code>level</code>和 <code>message</code>資訊

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

<code>fmt</code>中允許使用的變量可以參考下表。

%(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 使用者輸出的消息

Logging有如下級别: DEBUG，INFO，WARNING，ERROR，CRITICAL

預設級别是WARNING，logging子產品隻會輸出指定level以上的log。這樣的好處, 就是在項目開發時debug用的log，在産品release階段不用一一注釋，隻需要調整logger的級别就可以了，很友善。

最常用的是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.

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

通過代碼進行完整配置，參考開頭的例子，主要是通過getLogger方法實作。

通過代碼進行簡單配置，下面有例子，主要是通過basicConfig方法實作。

通過配置檔案，下面有例子，主要是通過 <code>logging.config.fileConfig(filepath)</code>

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語句對日後項目維護會有很大幫助。

14

15

16

17

18

19

20

21

22

23

24

25

26

27

28

29

30

31

32

33

34

35

36

37

38

39

40

41

42

43

44

45

46

47

48

# logging.conf

[loggers]

keys=root

[logger_root]

level=DEBUG

handlers=consoleHandler

#,timedRotateFileHandler,errorTimedRotateFileHandler

#################################################

[handlers]

keys=consoleHandler,timedRotateFileHandler,errorTimedRotateFileHandler

[handler_consoleHandler]

class=StreamHandler

formatter=simpleFormatter

args=(sys.stdout,)

[handler_timedRotateFileHandler]

class=handlers.TimedRotatingFileHandler

args=('debug.log', 'H')

[handler_errorTimedRotateFileHandler]

level=WARN

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。

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行調用<code>basicConfig()</code>方法時系統會預設建立一個handler，如果你再添加一個控制台handler時就會出現重複日志。

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()

# INFO:hi

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

    fmt = '%(levelname)s: %(message)s'

def foo():

    logging.basicConfig(format='[%(name)s]: %(message)s')

    logging.warn('some module use root logger')

def main():

    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.

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

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

logging.getLogger().handlers = []  # 删除所有的handler

logging.getLogger().setLevel(logging.CRITICAL)  # 将它的級别設定到最高

Python中的日志子產品作為标準庫的一部分，功能還是比較完善的。個人覺得上手簡單，另外也支援比如過濾，檔案鎖等進階功能，能滿足大多數項目需求。

轉自：http://python.jobbole.com/86887/