摘要：最近修改了項(xiàng)目里的相關(guān)功能，用到了標(biāo)準(zhǔn)庫(kù)里的模塊，在此做一些記錄?？赡軟](méi)有線程名。可能沒(méi)有用戶輸出的消息日志級(jí)別有如下級(jí)別，，，，默認(rèn)級(jí)別是，模塊只會(huì)輸出指定以上的。在或者中這是很常見(jiàn)的方式。正常的做法應(yīng)該是全局只配置一次。

最近修改了項(xiàng)目里的logging相關(guān)功能，用到了python標(biāo)準(zhǔn)庫(kù)里的logging模塊，在此做一些記錄。主要是從官方文檔和stackoverflow上查詢到的一些內(nèi)容。

官方文檔

技術(shù)博客

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

# -*- coding: utf-8 -*-

import logging
import sys

# 獲取logger實(shí)例，如果參數(shù)為空則返回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)  # 可以通過(guò)setFormatter指定輸出格式

# 控制臺(tái)日志
console_handler = logging.StreamHandler(sys.stdout)
console_handler.formatter = formatter  # 也可以直接給formatter賦值

# 為logger添加的日志處理器
logger.addHandler(file_handler)
logger.addHandler(console_handler)

# 指定日志的最低輸出級(jí)別，默認(rèn)為WARN級(jí)別
logger.setLevel(logging.INFO)

# 輸出不同級(jí)別的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)

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

# 格式化輸出

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")  # 多參數(shù)格式化
logger.error("{} service is {}".format(service_name, "down")) # 使用format函數(shù)，推薦

# 2016-10-08 21:59:19,493 ERROR   : Booking service is down!

當(dāng)你使用logging模塊記錄異常信息時(shí)，不需要傳入該異常對(duì)象，只要你直接調(diào)用logger.error() 或者 logger.exception()就可以將當(dāng)前異常記錄下來(lái)。

# 記錄異常信息

try:
    1 / 0
except:
    # 等同于error級(jí)別，但是會(huì)額外記錄當(dāng)前拋出的異常堆棧信息
    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

這是最基本的入口，該方法參數(shù)可以為空，默認(rèn)的logger名稱是root，如果在同一個(gè)程序中一直都使用同名的logger，其實(shí)會(huì)拿到同一個(gè)實(shí)例，使用這個(gè)技巧就可以跨模塊調(diào)用同樣的logger來(lái)記錄日志。

另外你也可以通過(guò)日志名稱來(lái)區(qū)分同一程序的不同模塊，比如這個(gè)例子。

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

Formatter對(duì)象定義了log信息的結(jié)構(gòu)和內(nèi)容，構(gòu)造時(shí)需要帶兩個(gè)參數(shù)：

一個(gè)是格式化的模板fmt，默認(rèn)會(huì)包含最基本的level和 message信息

一個(gè)是格式化的時(shí)間樣式datefmt，默認(rèn)為 2003-07-08 16:49:45,896 (%Y-%m-%d %H:%M:%S)

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

%(name)s Logger的名字

%(levelno)s 數(shù)字形式的日志級(jí)別

%(levelname)s 文本形式的日志級(jí)別

%(pathname)s 調(diào)用日志輸出函數(shù)的模塊的完整路徑名，可能沒(méi)有

%(filename)s 調(diào)用日志輸出函數(shù)的模塊的文件名

%(module)s 調(diào)用日志輸出函數(shù)的模塊名|

%(funcName)s 調(diào)用日志輸出函數(shù)的函數(shù)名|

%(lineno)d 調(diào)用日志輸出函數(shù)的語(yǔ)句所在的代碼行

%(created)f 當(dāng)前時(shí)間，用UNIX標(biāo)準(zhǔn)的表示時(shí)間的浮點(diǎn)數(shù)表示|

%(relativeCreated)d 輸出日志信息時(shí)的，自Logger創(chuàng)建以來(lái)的毫秒數(shù)|

%(asctime)s 字符串形式的當(dāng)前時(shí)間。默認(rèn)格式是“2003-07-08 16:49:45,896”。逗號(hào)后面的是毫秒

%(thread)d 線程ID。可能沒(méi)有

%(threadName)s 線程名?？赡軟](méi)有

%(process)d 進(jìn)程ID?？赡軟](méi)有

%(message)s 用戶輸出的消息

Logging有如下級(jí)別: DEBUG，INFO，WARNING，ERROR，CRITICAL
默認(rèn)級(jí)別是WARNING，logging模塊只會(huì)輸出指定level以上的log。這樣的好處, 就是在項(xiàng)目開(kāi)發(fā)時(shí)debug用的log，在產(chǎn)品release階段不用一一注釋，只需要調(diào)整logger的級(jí)別就可以了，很方便。

最常用的是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的配置大致有下面幾種方式。

通過(guò)代碼進(jìn)行完整配置，參考開(kāi)頭的例子，主要是通過(guò)getLogger方法實(shí)現(xiàn)。

通過(guò)代碼進(jìn)行簡(jiǎn)單配置，下面有例子，主要是通過(guò)basicConfig方法實(shí)現(xiàn)。

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

logging.basicConfig

basicConfig()提供了非常便捷的方式讓你配置logging模塊并馬上開(kāi)始使用，可以參考下面的例子。具體可以配置的項(xiàng)目請(qǐng)查閱官方文檔。

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.")

備注： 其實(shí)你甚至可以什么都不配置直接使用默認(rèn)值在控制臺(tái)中打log，用這樣的方式替換print語(yǔ)句對(duì)日后項(xiàng)目維護(hù)會(huì)有很大幫助。

通過(guò)文件配置logging

如果你希望通過(guò)配置文件來(lái)管理logging，可以參考這個(gè)官方文檔。在log4net或者log4j中這是很常見(jiàn)的方式。

# 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

假設(shè)以上的配置文件放在和模塊相同的目錄，代碼中的調(diào)用如下。

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

你有可能會(huì)看到你打的日志會(huì)重復(fù)顯示多次，可能的原因有很多，但總結(jié)下來(lái)無(wú)非就一個(gè)，日志中使用了重復(fù)的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!

上面這個(gè)例子出現(xiàn)了重復(fù)日志，因?yàn)樵诘?行調(diào)用basicConfig()方法時(shí)系統(tǒng)會(huì)默認(rèn)創(chuàng)建一個(gè)handler，如果你再添加一個(gè)控制臺(tái)handler時(shí)就會(huì)出現(xiàn)重復(fù)日志。

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

在這個(gè)例子里hi居然打印了三次，如果再調(diào)用一次call_me()呢？我告訴你會(huì)打印6次。why? 因?yàn)槟忝看握{(diào)用get_logger()方法時(shí)都會(huì)給它加一個(gè)新的handler，你是自作自受。正常的做法應(yīng)該是全局只配置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上很多人都問(wèn)，我應(yīng)該怎么樣把root logger關(guān)掉，root logger太坑爹坑?jì)屃?。只要你在程序中使用過(guò)root logger，那么默認(rèn)你打印的所有日志都算它一份。上面的例子沒(méi)有什么很好的辦法，我建議你招到那個(gè)沒(méi)有經(jīng)過(guò)大腦就使用root logger的人，亂棍打死他或者開(kāi)除他。

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

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

Python中的日志模塊作為標(biāo)準(zhǔn)庫(kù)的一部分，功能還是比較完善的。個(gè)人覺(jué)得上手簡(jiǎn)單，另外也支持比如過(guò)濾，文件鎖等高級(jí)功能，能滿足大多數(shù)項(xiàng)目需求。

不過(guò)切記，小心坑。

關(guān)于作者：Python技術(shù)愛(ài)好者，目前從事測(cè)試開(kāi)發(fā)相關(guān)工作，轉(zhuǎn)載請(qǐng)注明原文出處。
歡迎關(guān)注我的博客 https://betacat.online，你可以到我的公眾號(hào)中去當(dāng)吃瓜群眾。