日志是调试程序、记录代码执行过程和排查线上线下问题的重要手段，Python中内置了logging模块，可以很方便的根据需要输出日志。本文将详细的讲解和演示Python中logging模块的几个重要组件，并提供一些日志输出的经验和方法。

环境版本

Python 3.7.5
Ubuntu 18.04

logging的重要组件

Logger：用户程序调用Logger组件输出日志。
Handler：具体决定日志输出的日志处理器，日志处理器决定日志输出的格式、目标文件等。比如输出到日志文件或者标准输出。
Formatter：日志的格式，有许多变量可以使用，比如时间，级别，Logger的名字等。
Filter：过滤器，决定要输出哪些日志，本文中不会直接使用到。

Logger 组件

Logger组件采用树形结构组织，除顶层Logger(root)外，其他Logger都有自己的parent。Logger组件有name，level，parent，propagate，Handlers等主要属性。Logger的重要属性如下：

• name：组件的名字，可以使用__name__变量自动生成，也可以手动指定。形成层级关系，比如app.model这个Logger的parent通常是app。
• level：输出的最低日志级别。logging定义了6个日志级别，分别对应不同的数值，关系如下，Logger只会记录等于或高于设置级别的日志。

• parent：父级Logger。一般最顶层的parent是root。
• propagate：布尔类型，是否把本Logger的日志发送到父级的Logger。
• Handlers：这是一个列表类型的属性，一个Logger可能有多个Handler。
• disabled：布尔类型，是否禁用本Logger，禁用之后不再输出日志。
  我们可以通过__dict__方式观察Logger的以上属性：

In [1]: import logging         
In [2]: app_logger = logging.Logger("app", logging.INFO) 
In [3]: app_ogger.__dict__
Out[3]: 
{'filters': [],
 'name': 'app',
 'level': 20,
 'parent': None,
 'propagate': True,
 'handlers': [],
 'disabled': False,
 '_cache': {}}

Logger组件有2种主要的创建方式：

• logging.Logger()，接受2个参数：name和level。创建出来的Logger没有parent，官方文档提示永远不要采取这种方式直接实例化Logger。
• logging.getLogger(__name__)或logging.getLogger('app.model')，这种方式创建的Logger最顶层parent是root。以logging.getLogger('app.model')为例，如果有app这个Logger，则其parent是app这个Logger，否则，其parent是root。例如：

In [1]: import logging
In [2]: model_logger = logging.getLogger("app.model") # 创建 app.model这个Logger
In [3]: model_logger.parent
Out[3]: <RootLogger root (WARNING)> # 这时候的parent是`root`
In [4]: app_logger = logging.getLogger("app") # 创建app这个Logger           
In [5]: model_logger.parent                                        
Out[5]: <Logger app (WARNING)> # 创建app这个logger之后，这时候的parent是`app`

可以调用setLevel方法修改Logger的level属性：

In [1]: import logging
In [2]: app_logger = logging.getLogger("app")
In [3]: logging.getLevelName(app_logger.level)               
Out[3]: 'NOTSET'
In [4]: app_logger.setLevel(logging.DEBUG) # 修改Level
In [5]: logging.getLevelName(app_logger.level)                  
Out[5]: 'DEBUG'

重复使用相同的名字调用 getLogger() 会一直返回相同的 Logger 对象的引用。

Handler组件

Handler组件定义了如何处理日志，我目前常用的三类：StreamHandler、FileHandler和RotatingFileHandler。

• StreamHandler：将日志记录输出发送到数据流例如 sys.stdout, sys.stderr 或任何文件类对象。
• FileHandler：它可将日志记录输出到磁盘文件中。
• RotatingFileHandler：支持磁盘日志文件的轮转。可以设置到达多少大小之后切割日志文件；以及保留多少份最新的日志文件。

官方还支持了QueueHandler，HTTPHandler，SysLogHandler和SocketHandler等等不同发送目标的Handler，有需要可以到logging.handlers官方文档中了解。

接下来通过一小段代码演示如何把日志同时输出到stdout和日志文件。

In [1]: import logging
In [2]: app_logger = logging.getLogger(__name__)
In [3]: app_logger.setLevel(logging.DEBUG)
In [4]: app_handler = logging.FileHandler("/tmp/app.log")
In [5]: console_handler = logging.StreamHandler()        
In [6]: app_logger.addHandler(console_handler)   
In [7]: app_logger.addHandler(app_handler) 
In [8]: app_logger.info("a test log to both file and console")   
a test log to both file and console # 这条是StreamHandler输出的日志
In [9]: cat /tmp/app.log     
a test log to both file and console # 这条是输出到文件的日志
In [10]: app_logger.handlers        
Out[10]: [<StreamHandler <stderr> (NOTSET)>, <FileHandler /tmp/app.log (NOTSET)>] # 检查app_logger的属性，确实有2个handler

Formatter组件

Formatter 对象定义日志的输出格式，可以在LogRecord 属性中查看其支持的变量有哪些，下面是我比较常用的日志输出格式：

In [1]: import logging
In [2]: log = logging.getLogger() 
In [3]: console_handler = logging.StreamHandler()
In [4]: formatter = logging.Formatter(
    "[%(asctime)s] {%(pathname)s:%(lineno)d} %(levelname)s - %(message)s")
In [5]: console_handler.setFormatter(formatter)      
In [6]: log.addHandler(console_handler)
In [7]: log.warning("a msg with format")  
[2020-11-28 17:48:16,774] {<ipython-input-7-215da6f2522c>:1} WARNING - a msg with format

注意

通常Logger的propagate属性都为True，代表本Logger的日志会向上发送给父级Logger，所以，实践中，我们不需要给每个Logger都定义Handler，只需要在特定的父Logger中添加Handler即可。如果发现日志未正确输出，可以试着从propagate找找原因。
下图是python官方的logging模块日志处理流程图。

以上就介绍完了logging模块的主要组件和需要用到的知识点，下面进入实战模式，在实际代码中，我们应该如何使用logging。

实战logging

脚本中使用logging

每次都挨个定义Logger、Handler、Formatter还是很麻烦的，尤其是当你只需要一个简单脚本的时候。我们可以偷懒采取如下更简单的方式：

import logging


logging.basicConfig(filename="/tmp/demo.log",
                    format="%(asctime)s " + logging.BASIC_FORMAT,
                    level=logging.DEBUG)


logging.debug("debug msg")
logging.info("info msg")
logging.warning("warn msg")
logging.critical("critical msg")

为了简化流程，在一些简单的脚本开发中，我们可以使用如上的logging.basicConfig方法快速的定义日志记录方法。

flask中使用logging

在使用Flask框架的时候，Flask实例自带了app.logger这个Logger。使用自带的Logger固然很方便，但是往往不利于代码解耦合。例如，我们自己创建了一个模块文件，如果模块文件的日志输出使用的是app.logger，这会导致模块文件强依赖app这个对象。当copy模块到其它程序中将变得无法执行。我建议在每个模块中创建自己的Logger，实例如下。新建一个demo项目，目录结构如下：

$ tree demo
demo
├── api
│ └── __init__.py
└── __init__.py

demo/__init__.py文件的内容如下，这个是demo模块。

import logging
from flask import Flask, request, jsonify
from .api import simple_add


app = Flask(__name__)

handler = logging.FileHandler("app.log")
handler.setFormatter(logging.Formatter(logging.BASIC_FORMAT))
app.logger.setLevel(logging.DEBUG) # 设置级别为DEBUG
app.logger.addHandler(handler) 

app.logger.info("app_logger is ready")

@app.route("/api/simple_add")
def simple_add_view():
    app.logger.info(f"{request.remote_addr} send a request")
    a = request.args.get("a") or 0
    b = request.args.get("b") or 0

    return jsonify(
        arg_a=a,
        arg_b=b,
        result=simple_add(a, b)
    )

demo/api/__init__.py的内容如下，这个就是demo.api模块

import logging

log = logging.getLogger(__name__)

def simple_add(a, b):
    log.debug(f"computing a + b, a is {a} and b is {b}")
    try:
        return float(a) + float(b)
    except ValueError as ex:
        log.error("convert value to float type error")
        log.exception(ex) # 在日志中打印异常traceback

运行以上的代码：

$ export FLASK_APP=demo/__init__.py
$ flask run
 * Serving Flask app "demo"
 * Running on http://127.0.0.1:5000/ (Press CTRL+C to quit)

开一个新终端，使用curl命令测试下上面的程序：

$ curl http://127.0.0.1:5000/api/simple_add # 无参数的情况
{
  "arg_a": 0, 
  "arg_b": 0, 
  "result": 0.0
}
$ curl "http://127.0.0.1:5000/api/simple_add?a=1&b=2" # 提供正常的参数
{
  "arg_a": "1", 
  "arg_b": "2", 
  "result": 3.0
}
$ curl "http://127.0.0.1:5000/api/simple_add?a=1&b=a" # 提供错误的参数
{
  "arg_a": "1", 
  "arg_b": "a", 
  "result": null
}

查看日志的输出情况：

INFO:demo:app_logger is ready
INFO:demo:127.0.0.1 send a request
DEBUG:demo.api:computing a + b, a is 0 and b is 0 
INFO:demo:127.0.0.1 send a request
DEBUG:demo.api:computing a + b, a is 1 and b is 2
INFO:demo:127.0.0.1 send a request
DEBUG:demo.api:computing a + b, a is 1 and b is a # demo.api模块输出的日志
ERROR:demo.api:convert value to float type error
ERROR:demo.api:could not convert string to float: 'a' # log.exception(ex)方法输出的traceback信息
Traceback (most recent call last):
  File "/tmp/demo/api/__init__.py", line 8, in simple_add
    return float(a) + float(b)
ValueError: could not convert string to float: 'a'

通过观察日志可以看到2个模块中各自打印了多行日志，Logger的名字分别为demo和demo.api，而且log.exception(ex)记录下了异常情况下的traceback信息 。在这个案例中，demo和demo.api2个模块进行了解耦，api模块可以复制到其他项目中直接使用。

三方模块的日志记录

在实际的项目中，我们会使用许多外部的开源库，如在flask中就常常会使用flask-apscheduler和flask-sqlalchemy这两个模块。如果不做特殊处理，日志最后会逐层向上传到root Logger，其默认的输出是stdout。为了保证日志输出的一致性，我的习惯是把三方的日志也输出到应用日志文件中，比如app.log文件。做法是：首先创建对应模块的Logger，然后把应用的Handler附加到对应模块的Logger上。核心部分代码如下：

import os
import logging
from flask import Flask
from logging.handlers import RotatingFileHandler
from flask_sqlalchemy import SQLAlchemy
from flask_apscheduler import APScheduler

app = Flask(__name__)
db = SQLAlchemy(app)
scheduler = APScheduler()
scheduler.init_app(app)

MAX_LOG_SIZE = 500000000 # 500MB
RESERVE_COUNT = 10 # keep 10 log file

pwd = os.path.split(os.path.realpath(__file__))[0]  
app_log = pwd + '/app.log'
# 统一的日志handler
handler = RotatingFileHandler(app_log, maxBytes=MAX_LOG_SIZE,
                              backupCount=RESERVE_COUNT)
formatter = logging.Formatter(
    "[%(asctime)s] %(name)s {%(pathname)s:%(lineno)d} %(levelname)s - %(message)s")
handler.setFormatter(formatter)
app.logger.addHandler(handler)
app.logger.setLevel(logging.INFO)

# sqlalchemy 的日志输出
sql_log = logging.getLogger("sqlalchemy")
sql_log.setLevel(logging.INFO)
sql_log.addHandler(handler)

# apscheduler 模块的日志输出
aps_log = logging.getLogger("apscheduler")
aps_log.setLevel(logging.INFO)
aps_log.addHandler(handler)

通过上面的办法，可以将三方模块的日志全部统一输出到app.log文件中。

参考资料：

https://docs.python.org/zh-cn/3/library/logging.handlers.html

https://docs.python.org/zh-cn/3/library/logging.html#logrecord-attributes