摘要：最近修改了項目里的相關功能，用到了標準庫里的模塊，在此做一些記錄?？赡軟]有線程名?？赡軟]有用戶輸出的消息日志級別有如下級別，，，，默認級別是，模塊只會輸出指定以上的。在或者中這是很常見的方式。正常的做法應該是全局只配置一次。

最近修改了項目里的logging相關功能，用到了python標準庫里的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 
#     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信息的結構和內容，構造時需要帶兩個參數：

一個是格式化的模板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 用戶輸出的消息

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方法實現。

通過配置文件，下面有例子，主要是通過 logging.config.fileConfig(filepath)

logging.basicConfig

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

如果你希望通過配置文件來管理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中的日志模塊作為標準庫的一部分，功能還是比較完善的。個人覺得上手簡單，另外也支持比如過濾，文件鎖等高級功能，能滿足大多數項目需求。

不過切記，小心坑。

關于作者：Python技術愛好者，目前從事測試開發相關工作，轉載請注明原文出處。
歡迎關注我的博客 https://betacat.online，你可以到我的公眾號中去當吃瓜群眾。