为什么要使用logger

不知道ai时代的到来，还会不会有人再看博客来学习代码知识了，但对我来说，多记录是让我自己需要的时候多翻看吧😋

我们在编写程序时，难免会遇到错误，而我们在排查错误的时候，可以使用print语句来打印出来我们需要的信息，但是当我们排查完错误时，则需要将print语句删掉，不然人则会打印出来很多不必要的信息，而耽误我们看真正需要的信息。

而logger可以帮助我们控制日志是否输出，使用一个语句的开关来决定是否要输出需要的日志。

用法示例

1
2
3
4
5
6
7
8
9
10
11
12
import logging

logger = logging.getLogger(__name__)
logging.basicConfig(
		level=logging.INFO,
		format="%(asctime)s | %(levelname)s | %(name)s | %(message)s")

logging.debug("调试信息")
logging.info("程序正常运行")
logging.warning("可能存在问题")
logging.error("发生错误")
logging.critical("严重错误")

这里面日志的级别为DEBUG < INFO < WARNING < ERROR < CRITICAL

logging.getLogger(__name__)是什么意思

我们在刚开始使用时，可以用logger = logging.getLogger(__name__)来获取一个Logger，括号里传的是这个Logger的名字。而__name__是Python自动提供的特殊变量，不需要定义，它表示当前Python模块的名字。

例如项目结构是：

1
2
3
4
Project/
	app/
		user/
			service.py

那么__name__可能是：app.user.service。即文件被直接执行：__name__ == "__main__"，文件被其他文件导入：__name__ 通常是它的模块名。

basicConfig()是做什么的

它是用来配置日志系统的，可以理解为从现在开始，日志最低显示到什么级别，以及每条日志按照什么格式打印。例如logging.basicConfig(level=logging.INFO)表示该日志的级别为INFO，它不是在定义某一条日志为INFO，而是在设置一个过滤门槛，只输出级别大于等于INFO的日志。

format中的asctime, levelname, name, message分别是什么

这个不是我们定义的，是由logging自动生成的。每当我们写logger.info("服务启动成功")，logging都会在内部创建一条日志记录，其中自动包含时间、日志级别、Logger名字和消息等信息，这就是这四个字段所表示的含义。

需要注意的事项

推荐使用参数占位

如logger.info("用户 %s 登录，尝试次数：%d", username, count)，而不是f-string。虽然这样写也可以运行：logger.info(f"用户 {username} 登录")，但占位符写法只有日志真正需要输出时才会格式化，性能更好。

记录异常

  1. 先使用try...except来收集错误例如result = 10 / 0，而除数不能是0，所以Python会产生一个ZeroDivisionError异常。

  2. 如果使用诸如一下的用法：

    1
    2
    3
    4
    try:
    	result = 10 / 0
    except ZeroDivisionError:
    	logger.exception("计算失败", exc_info=True)

    而logger.exception()的本质是一条ERROR级别的日志。它相当于logger.error("计算失败", exc_info=True)

  3. logger.error()和logger.exception()的区别在于，不仅会输出消息，还会自动输出异常类型、错误原因和错误发生的位置。exc_info=True的意思是把当前捕获到的异常信息也打印出来。

  4. 它和level=logging.INFO不会冲突，假如配置是：logging.basicConfig(level=logging.INFO)，它表示输出INFO以及更高级别的日志，由于logger.exception()输入ERROR级别，而ERROR > INFO，所以它会输出。

可以将日志输送到不同地方并设置不同的日志门槛

例如，我们先创建Logger：

1
2
logger = logging.getLogger("typhoon_analysis") # 先创建一个名为typhoon_analysis的Logger,所以日志格式中的%(name)%会显示typhoon_analysis
logger.setLevel(logging.DEBUG) # 设置Logger的最低处理级别是DEBUG

然后我们创建日志格式：

1
2
3
formatter = logging.Formatter(
    "%(asctime)s | %(levelname)s | %(name)s | %(message)s"
)

这里规定每条日志的显示方式是时间｜日志级别｜Logger名字｜日志内容。

接下来我们创建一个终端Handler：

1
2
console_handler = logging.StreamHandler() # StreamHandler通常负责将日志输出到终端
console_handler.setLevel(logging.INFO) # 设置终端的最低日志级别为INFO

然后我们把刚刚创建的格式交给终端Handler:

1
console_handler.setFormatter(formatter) # 终端输出日志时，按照formatter规定的格式显示

然后我们再创建一个文件Handler:

1
file_handler = logging.FileHandler("ty-track.log", encoding="utf-8") # 这表示创建一个文件输出器,将日志写入ty-track

如果文件ty-track.log不存在，程序会自动创建它。

接下来，我们设置文件的最低日志级别是DEBUG：

1
file_handler.setLevel(logging.DEBUG)

设置文件中的日志格式：

1
file_handler.setFormatter(formatter)

最后关键的一步，我们刚开始设置的Logger还没有用到，所以现在我们把两个Handler安装到Logger上：

1
2
logger.addHandler(console_handler)
logger.addHandler(file_handler)

现在我们的一条日志会同时被交给两个 Handler，然后两个 Handler 分别按照自己的级别决定是否输出。🥳

当我们添加多个Handler时，导致一条日志打印多次，我们应该怎么办？

如果初始化函数可能执行多次，重复添加Handler可能会导致一条日志打印很多次，或者说我们同一个Logger被重复添加了多个Handler，日志又被传递给了根Logger，再打印一次

添加多个Handler的情况

首先，我们先考虑一下，为什么重复添加Handler会重复输出？假如我们写一个创建Logger的函数：

1
2
3
4
5
6
7
8
def create_logger():
    logger = logging.getLogger("typhoon_analysis")
    logger.setLevel(logging.INFO)

    handler = logging.StreamHandler()
    logger.addHandler(handler)

    return logger

然后调用两次：

1
2
3
4
logger1 = create_logger()
logger2 = create_logger()

logger2.info("程序启动")

这里虽然调用了两次函数，但是实际上logging.getLogger("typhoon_analysis")每次使用都是相同的名字，获取的都是同一个Logger对象。

而我们在第一次调用create_logger()时，给它添加了一个Handler，第二次调用时，又添加了一个，所以当我们执行logger.info("程序启动")，两个Handler都会输出这条日志，终端就会出现两遍：

1
2
程序启动
程序启动

那我们应该怎么解决呢？当我们改成如下情况：

1
2
3
4
5
6
7
8
9
def create_logger():
    logger = logging.getLogger("typhoon_analysis")
    logger.setLevel(logging.INFO)

    if not logger.handlers:
        handler = logging.StreamHandler()
        logger.addHandler(handler)

    return logger

当我们判断if not logger.handlers的时候，这里logger.handlers是当前Logger已经拥有的Handler列表。请注意，if not logger.handlers: 相当于if len(logger.handlers) == 0:它的意思是如果这个Logger一个Handler都没有，就执行下面的代码。

当我们第一次调用的时候，列表是空的，logger.handlers == []，所以：not logger.handlers结果是True，程序将会添加Handler：

1
2
handler = logging.StreamHandler()
logger.addHandler(handler)

当我们第二次调用的时候，Logger已经有Handler了：logger.handlers == [某个Handler]，此时：not logger.handlers结果是False，所以不会再次添加。

“向上传播”的情况

OK，我们目前已经学习了这种日志会重复的情况，在Logger学习中，还有一种情况是“向上传播”导致的日志重复打印。

在Python的日志系统中，有一个特殊的Logger，叫做根Logger，也叫做root logger。在我们之前使用logging.basicConfig(...)，就是在配置根Logger。

假设我们先配置了根Logger：logging.basicConfig(level=logging.INFO)，然后又给自己typhoon_analysis添加了一个Handler：

1
2
3
4
5
logger = logging.getLogger("typhoon_analysis")
logger.setLevel(logging.INFO)

handler = logging.StreamHandler()
logger.addHandler(handler)

现在我们执行：logger.info("程序启动")，这条日志会先经过自己的Handler，即typhoon_analysis，再继续传给root Logger，于是我们在终端可能会看到：

1
2
程序启动
INFO:typhoon_analysis:程序启动

内容格式虽然不同，但是这是同一条日志。这是因为**Logger默认会把日志继续向上交给它的父Logger，最终到达根Logger。**这个过程叫做“传播”，对应属性是logger.propagate。

如果我们设置：logger.propagate=False，这个意思表明，这条日志由typhoon_analysis处理完以后，不会再上传给上层Logger。

许可协议

本文采用 署名-非商业性使用-相同方式共享 4.0 国际 许可协议，转载请注明出处。