導語

日常開發(fā)中，定位程序異常，追溯事件發(fā)生場景都需要通過日志記錄的方式?？梢哉f一個好的開發(fā)日志設(shè)計可以讓開發(fā)人員在后續(xù)項目維護的過程中節(jié)省時間成本，提升解決問題的效率。

目前在網(wǎng)上已經(jīng)有許多關(guān)于Python日志操作的文章，部分文章總結(jié)的非常到位，Python官方也有日志常用的手冊。自己寫這篇文章是主要圍繞Python官方的logging模塊展開，結(jié)合自己學習過程以及項目開發(fā)中應(yīng)用場景，總結(jié)歸納下Python日志使用，方便自己梳理相關(guān)知識，更好的理解；

關(guān)于開發(fā)日志

對于開發(fā)日志，很多程序員誤區(qū)可能就是停留在直接print打印到后臺日志中，好的地方方便快捷，但是壞的地方就是日志輸出的內(nèi)容十分混亂，不方便排查。面對不同級別的事件，以及需要執(zhí)行的任務(wù)時，采取的日志操作動作是不一樣的。

對此結(jié)合Python官方文檔總結(jié)以下執(zhí)行任務(wù)對應(yīng)的工具：

日志功能事件級別對應(yīng)應(yīng)用場景（以嚴重性遞增）

logging模塊默認級別是WARNING，意味著只會追蹤該級別以上的事件，除非更改日志配置；

關(guān)于logging基礎(chǔ)使用

日志記錄保存到文件

import logging
logging.basicConfig(filename="example.log", level=logging.INFO,
datefmt="%Y-%m-%d %H:%M:%S",
encoding='utf-8')
# 記錄日志信息
logging.debug("test DEBUG")
logging.info("test Info")
logging.warning("test Warning")
logging.warning('%s before you %s', 'Look', 'leap!')
logging.error("test Error")

代碼注解：

• 3.9版本中才更新了encoding，encoding參數(shù)在更早的Python版本中沒有指定時，編碼會使用open()的默認值；
• level是設(shè)置默認日志追蹤級別的閾值，默認級別是WARNING
• filename是日志文件的存放路徑；

(上述腳本如果連續(xù)多次運行，連續(xù)運行的消息將追繳到指定的example.log日志文件，如果想每次都是重新開始，即example.log日志不保存之前的日志信息，則修改filemode參數(shù)為'w'；)

關(guān)于logging進階使用

結(jié)合Python官方文檔，日志庫采用模塊化的方法，并提供幾類組件：記錄器、處理器、過濾器和格式器。

• 記錄器：暴露了應(yīng)用程序代碼直接使用的接口。
• 處理器：將日志記錄（由記錄器創(chuàng)建）發(fā)送到適當?shù)哪繕恕?/li>
• 過濾器：提供了更細粒度的功能，用于確定要輸出的日志記錄。
• 格式器：指定最終輸出中日志記錄的樣式。

官方文檔中記錄器和處理在日志信息記錄流程：

解析：

• 首先是判斷Logger對象執(zhí)行的方法是否大于設(shè)置的最低嚴重性，大于則創(chuàng)建LogRecord對象，小于則終止；
• 注冊的Filter對象進行過濾，如果為False不記錄日志；
• 將LogRecord對象傳遞到當前注冊到Logger對象中的Handler對象；判斷Handler對象設(shè)置的級別大于Logger對象則證明有效，以及注冊到Handler對象中Filter過濾后是否返回True；
• 最后判斷當前是否還有父Logger對象，如果是重復第三步，知道當前Logger設(shè)置為root Looger；

記錄器

關(guān)于記錄器，主要的任務(wù)總結(jié)有三個：

• 暴露接口給應(yīng)用程序記錄消息；
• 根據(jù)嚴重性（默認嚴重級別）或者過濾器決定要處理的日志信息；
• 將日志信息發(fā)送傳遞給對應(yīng)日志處理器；

關(guān)于記錄器方法總結(jié)為兩類，配置和消息發(fā)送.

記錄器配置方法：

• Logger.setLevel()：設(shè)置記錄器處理的最低嚴重性日志信息（這就如果后續(xù)日志處理器設(shè)置的日志級別比記錄器低是無效的）；
• Logger.addHandler()和Logger.removeHandler()：從記錄器對象中增加和刪除日志處理器對象；
• Logger.addFilter()和Logger.removeFilter()：從記錄器對象中增加和刪除過濾器；

記錄器常用創(chuàng)建信息方法：

• Logger.debug() 、 Logger.info() 、 Logger.warning() 、 Logger.error() 和 Logger.critical() ；
• Logger.exception()和以上的方法有點不同，只在異常處理程序中調(diào)用此方法，同時還記錄當前堆棧跟蹤信息；

處理器

關(guān)于處理器，簡單的可以理解為將特定嚴重級別的日志信息發(fā)送到特定的位置，常用的處理類型主要有兩個：

• FileHandler
• StreamHandler

由于內(nèi)置處理對象常用的配置方法：

• setLevel()方法，設(shè)置處理器中的最低嚴重性，即決定處理器該發(fā)送哪些級別的日志信息；
• addFormatter，選擇該處理器使用的Formatter對象；
• addFilter和removeFilter，在處理器上增加和刪除過濾器對象；

格式器

格式器配置日志消息的最終順序、結(jié)構(gòu)和內(nèi)容，格式器類的構(gòu)造函數(shù)有三個可選參數(shù)：

• 消息格式字符串
• 日期格式字符串
• 樣式指示符

logging.Formatter.__init__(fmt=None, datefmt=None, style='%')

備注：

• fmt消息格式字符串一般不為空，為空默認就只打印message信息；
• datefmt默認日期格式為：%Y-%m-%d %H:%M:%S；
• style參數(shù)可選的范圍為：%、{、$這三個，主要用于fmt消息中字符串替換；

關(guān)于style：

fm = Formatter("%(asctime)s - %(name)s - %(levelname)s - %(message)s",
"%Y-%m-%d %H:%M:%S", style='{')
fm = Formatter("{asctime} - {name} - {levelname} - {message}",
"%Y-%m-%d %H:%M:%S", style='{')
fm = Formatter("$asctime - $name - $levelname - $message",
"%Y-%m-%d %H:%M:%S", style='$')

(這三種style使用方式，效果都一樣)

配置記錄

開發(fā)人員可以通過三種方式配置日志記錄：

• 使用提供的接口，顯示創(chuàng)建記錄器，處理器，格式器等直接配置；
• 通過fileConfig()函數(shù)讀取已經(jīng)創(chuàng)建好的配置文件；
• 創(chuàng)建好配置函數(shù)字典傳遞到dictConfig()函數(shù)；

關(guān)于fileConfig()讀取的配置文件(官方示例）：

[loggers]
keys=root,simpleExample
[handlers]
keys=consoleHandler
[formatters]
keys=simpleFormatter
[logger_root]
level=DEBUG
handlers=consoleHandler
[logger_simpleExample]
level=DEBUG
handlers=consoleHandler
qualname=simpleExample
propagate=0
[handler_consoleHandler]
class=StreamHandler
level=DEBUG
formatter=simpleFormatter
args=(sys.stdout,)
[formatter_simpleFormatter]
format=%(asctime)s - %(name)s - %(levelname)s - %(message)s

（關(guān)于讀取的配置文件格式類似ini格式）

實戰(zhàn)

關(guān)于logging模塊，這里介紹一下我目前最常用的業(yè)務(wù)場景：調(diào)用方請求一個后端的rest api接口，我需要記錄調(diào)用方請求的時間，地址，請求參數(shù)，處理請求后的結(jié)果，以及我需要將報錯的信息保存到指定的文件里，方便排查。

為了后期使用方便，在不更改原有處理函數(shù)的基礎(chǔ)下增加日志記錄的功能，我會選擇將日志記錄操作封裝在一個裝飾器函數(shù)。

所以我只需將這部分功能分成兩部分：生成記錄器、請求處理的裝飾器函數(shù)

生成記錄器

# -*- coding: utf-8 -*-
from logging import handlers
from datetime import date
import logging
def init_logger():
"""
生成記錄器
:return:
"""
app_logger = logging.getLogger(APP_NAME)
app_logger.setLevel(logging.INFO)
fmt = logging.Formatter("%(asctime)s %(levelname)s: %(message)s", "%Y-%m-%d %H:%M:%S")
# 正常日志打印到控制臺
console = logging.StreamHandler()
console.setFormatter(fmt)
console.setLevel(logging.INFO)
# 異常日志記錄到log文件
today = date.today()
file_name = "logs/exceptions_" + str(today) + ".log"
fh = handlers.TimedRotatingFileHandler(filename=file_name, when='D', backupCount=30, encoding='utf-8')
fh.setLevel("ERROR")
fh.setFormatter(fmt)
app_logger.addHandler(console)
app_logger.addHandler(fh)
return app_logger

代碼解析：

• APP_NAME是預(yù)設(shè)好的項目名稱，可根據(jù)實際業(yè)務(wù)進行調(diào)整；
• 關(guān)于普通的StreamHandler前面已經(jīng)提到了使用的方法，我這里之所選擇，是由于這個項目時Flask框架，后期部署通過uWSGI部署后端服務(wù)，我希望正常請求直接就打印在uwsgi的日志文件中，所以普通請求的處理器就選擇了StreamHandler
• 關(guān)于異常日志處理器，這里用到特殊的TimeRotatingFileHandler，這個內(nèi)置的處理器可以根據(jù)不同的時間跨度進行保存日志，就可以將異常日志信息按照一天的時間進行保存，注意設(shè)置最低嚴重性是ERROR

請求處理裝飾器

from functools import wraps
from flask import request
app_logger = init_logger()
def rest_log(return_type="dict"):
def decorator(func):
@wraps(func)
def inner(*args, **kwargs):
# 組裝打印的Message消息日志格式（請求URL，目標主機，請求方法，請求參數(shù)，響應(yīng)內(nèi)容）
log_params = {
"request": request.base_url,
"host": request.host,
"method": request.method
}
req_data = {}
if request.method == "POST":
req_data = dict(request.json)
elif request.method == "GET":
req_data = dict(request.args)
log_params.update({"params": req_data})
# 請求處理函數(shù)
try:
result = func(*args, **kwargs)
except Exception as e:
# 異常信息處理
err_msg = str(e)
result = {"ret_code": 500, "ret_info": err_msg}
app_logger.error(log_params, exc_info=True)
if return_type == "tuple":
result = (result, 500)
if return_type == "tuple":
log_params['result'] = result[0].data
else:
log_params['result'] = result
app_logger.info(log_params)
return result
return inner
return decorator

代碼解析：

• 主要分為三部分：HTTP請求request解析、異常請求信息處理、請求結(jié)果處理；
• app_logger.error(log_params, exc_info=True)中的exc_info可以將異常信息添加到日志信息中，即app_logger.exception()的效果；
• 關(guān)于return_type參數(shù)是考慮到flask支持返回元組，即返回響應(yīng)對象，響應(yīng)狀態(tài)碼?？紤]到日常使用場景會出現(xiàn)這種情況；

簡單使用示例：

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

from flask import request, Blueprint
from common.LogUtils import rest_log
test_api = Blueprint("TestApi", __name__)
@test_api.route("/log/test", methods=["GET"])
@rest_log()
def test_log():
name = request.args.get("name", "")
number = request.args.get('number', "")

if not name or not number:
raise Exception("number和name參數(shù)都不能為空")

response = {
"data": {
"name": f"Hello, {name}",
"number": number
},
"ret_code": 200,
"ret_info": "success"
}
return response

備注：

• rest_log裝飾器不能放在test_api.route的前面，因為只有當路由注冊函數(shù)執(zhí)行后，才能從request中獲取到對應(yīng)的信息（base_url,host,method)

控制臺日志打印效果：

2022-05-22 12:01:01 INFO: {'request': 'http://127.0.0.1:23102/log/test', 'host': '127.0.0.1:23102', 'method': 'GET', 'params': {'name': 'zhangsn', 'number': '22'}, 'result': {'data': {'name': 'Hello, zhangsn', 'number': '22'}, 'ret_code': 200, 'ret_info': 'success'}}

異常日志打?。?/strong>