前言：成熟的软件开发不可避免的要进行日志记录，python内置模块logging提供了强大的日志记录能力，本文将从多个角度，由浅入深的介绍logging的常见使用方法和一些基本概念，本此系列文章分为两篇，本文为系列文章第一篇，介绍实用logging模块进行基本的日志记录操作。本文主要都是直接使用 logging.xxxx() 的方式，这是最简单初步的日志记录，不涉及任何复杂的类和对象，这些将会在下一篇文章中来说明。

一、什么是日志记录

所谓的日志记录就是对软件执行时所发生事件的一种追踪方式。软件开发人员对他们的代码添加日志调用，借此来指示某事件的发生。一个事件通过一些包含变量数据的描述信息来描述（比如：每个事件发生时的数据都是不同的）。开发者还会区分事件的重要性，重要性也被称为 等级 或 严重性

1.1 什么时候使用 Logging

对于简单的日志使用来说日志功能提供了一系列便利的函数。它们是 debug()，info()，warning()，error() 和 critical()。想要决定何时使用日志，请看下表，其中显示了对于每个通用任务集合来说最好的工具。

你想要执行的任务	此任务最好的工具
对于命令行或程序的应用，结果显示在控制台。	print()，这是我们自己常用的，显示某一些信息，直接打印结果，但是比较低级
在对程序的普通操作发生时提交事件报告(比如：状态监控和错误调查)	http://logging.info() 函数(当有诊断目的需要详细输出信息时使用 logging.debug() 函数)
提出一个警告信息基于一个特殊的运行时事件	warnings.warn() 位于代码库中，该事件是可以避免的，需要修改客户端应用以消除告警 logging.warning() 不需要修改客户端应用，但是该事件还是需要引起关注
对一个特殊的运行时事件报告错误	引发异常
报告错误而不引发异常(如在长时间运行中的服务端进程的错误处理)	logging.error(), logging.exception() 或 logging.critical() 分别适用于特定的错误及应用领域

1.2 日志记录的5个等级

日志功能应以所追踪事件级别或严重性而定。各级别适用性如下（以严重程度递增）：

级别	何时使用
DEBUG	细节信息，仅当诊断问题时适用。
INFO	确认程序按预期运行，但是要提示一些相关的信息，
WARNING	表明有已经或即将发生的意外（例如：磁盘空间不足）。程序仍按预期进行，但是会有警告，可能出现什么错误。
ERROR	由于严重的问题，程序的某些功能已经不能正常执行
CRITICAL	严重的错误，表明程序已不能继续执行

以及严重程度排序为：

debug<info<warning<error<critical

默认的级别是``WARNING``，意味着只会追踪该级别以及该级别以上的事件，当然我们可以更改日志配置，重新设置默认值。

另外，我们需要查看所记录的日志，一般日志输出会有两种形式，

所追踪事件可以以不同形式处理。最简单的方式是输出到控制台。另一种常用的方式是写入磁盘文件。默认情况下，日志输出信息会显示在控制台上。下面也会以这两种方式来加以说明。

1.3 logging模块初识

二、logging模块的常规基础操作

2.1 logging日志记录的基本配置

函数原型如下：

该函数支持以下关键字参数。

格式	描述
filename	使用指定的文件名而不是 StreamHandler 创建 FileHandler。在需要将日志写入到日志文件的时候使用
filemode	日志文件的写入模式.，默认的是"a"，默认是追加的方式，若要每一次都重新写入，则使用"w"
format	使用的指定格式字符串。
datefmt	时间格式的字符串
style	If format is specified, use this style for the format string. One of '%', '{' or '$' for printf-style, str.format() or string.Template respectively. Defaults to '%'. 字符串的格式化方式的选择，参考下面的style参数详解。
level	设置根记录器级别去指定 level.默认的是warning，可以重新指定，比如http://logging.INFO logging.DEBUG 等等，
stream	Use the specified stream to initialize the StreamHandler. Note that this argument is incompatible with filename - if both are present, a ValueError is raised.（后面用到了再说）
handlers	If specified, this should be an iterable of already created handlers to add to the root logger. Any handlers which don't already have a formatter set will be assigned the default formatter created in this function. Note that this argument is incompatible with filename or stream - if both are present, a ValueError is raised.（后面用到了再说）

对basicConfig的调用应该在 debug、info等函数的前面。因为它被设计为一次性的配置，只有第一次调用会进行操作，随后的调用不会产生有效操作。

2.2 将日志写入文件

2.3 多个模块中使用日志记录

如果你的程序包含多个模块，这里有一个如何组织日志记录的示例:

如果你运行 myapp.py ，你应该在 myapp.log 中看到：

我们发现，不同模块中所记录的日志信息都被保存到了同一个日志文件里面了。

2.4 格式化输出以及记录相关的变量值到日志文件

前面有文章专门介绍了python中的字符串格式化的几种方法，包括使用百分号%、str.format、string.Template模板等方法，可以参考前面的文章：

python字符串格式化深入详解（四种方法）

所以，要定义自己的字符串输出格式，要记录相关的变量到字符串中，我们可以这样做。

要记录变量数据，请使用格式字符串作为事件描述消息，并将变量数据作为参数附加。 例如:

如你所见，

logging日志记录的字符串格式化，将数据合并到字符串中所采用的方式是 百分号% 的形式，
但是如果我想要使用其他的字符串格式化的方法怎么办呢？就需要通过指定style参数来决定了，style的取值可以是三个，即

• '%':这是默认的，即默认使用百分号%格式的字符串格式化方法；
• '{'：表示使用str.format()的字符串格式化方法；
• '$':表示使用string.Template的格式化方法；

为什么是默认使用百分号 % 格式化工具呢？主要是因为logging的出现时间比这两种格式化方法要早一些，但是并不是说完全不支持，现在完全有其他的方法让logging支持str.format()和string.Template()这些格式，只需要设置不同的style参数值即可。

三、logging模块的格式化设置以及时间格式化

当我们看之前的记录日志的时候，我们发现，记录的日志总是下面的格式，如下：

即所谓的：

日志类别严重程度：root：message

这样的格式，那么能不能进行更改呢？这个自然是可以的，怎么更改呢，如下：

3.1 消息显示的格式设置——basicConfig的 format 参数

要更改用于显示消息的格式，你需要指定要使用的格式:

这将输出：

请注意，前面示例中出现的“root”已消失。

对于可以出现在格式字符串中的全部内容，你可以参考以下文档 LogRecord 属性 ，在后面的系列文章第二篇中，还会深入探讨日志记录的高级主题，来说明的。

下面是常见的格式设置的字段标识：

• %(asctime)s：日志创建时的普通时间；
• %(created)f：日志创建时的时间（由time.time()返回）；
• %(filename)s：文件名；
• %(funcName)s：调用日志记录的函数；
• %(levelname)s：日志消息的文本级别；
• %(levelno)s：日志消息的数字级别；
• %(lineno)d：调用日志消息的行号；
• %(msecs)d：创建时间的毫秒部分；
• %(message)s：日志消息；
• %(name)s：日志器的名称；
• %(pathname)s：记录日志的源文件的路径名；
• %(process)d：进程ID；
• %(processName)s：进程名；
• %(thread)d：线程ID；
• %(threadName)s：线程名；
• %(relativeCreated)d：创建日志记录的时间（以毫秒为单位）

借助于这些格式，我们可以自定义日志记录，比如显示时间：

这样，日志中除了记录消息等级、消息信息外，还会记录上消息创建的时间。

3.2 设置日志记录的时间显示的格式——basicConfig的datefmt参数

那我们可不可以更改时间显示的格式呢？这个自然是能的，

日期/时间显示的默认格式（如上所示）类似于 ISO8601 或 RFC 3339 。 如果你需要更多地控制日期/时间的格式，请为 basicConfig 提供 datefmt 参数，

需要格外注意的是：datefmt 参数的格式与 time.strftime() 支持的格式相同。

如下例所示:

那到底有哪一些格式呢？可以参考官网：https://docs.python.org/zh-cn/3.7/library/time.html#time.strftime

函数原型为：

转换一个元组或 struct_time 表示的由 gmtime() 或 localtime() 返回的时间到由 format 参数指定的字符串。如果未提供 t ，则使用由 localtime() 返回的当前时间。 format 必须是一个字符串。如果 t 中的任何字段超出允许范围，则引发 ValueError 。

0是时间元组中任何位置的合法参数；如果它通常是非法的，则该值被强制改为正确的值。

以下指令可以嵌入 format 字符串中。它们显示时没有可选的字段宽度和精度规范，并被 strftime() 结果中的指示字符替换：

指令	含义	注释
%a	本地化的缩写星期中每日的名称。
%A	本地化的星期中每日的完整名称。
%b	本地化的月缩写名称。
%B	本地化的月完整名称。
%c	本地化的适当日期和时间表示。
%d	十进制数 [01,31] 表示的月中日。
%H	十进制数 [00,23] 表示的小时（24小时制）。
%I	十进制数 [01,12] 表示的小时（12小时制）。
%j	十进制数 [001,366] 表示的年中日。
%m	十进制数 [01,12] 表示的月。
%M	十进制数 [00,59] 表示的分钟。
%p	本地化的 AM 或 PM 。	(1)
%S	十进制数 [00,61] 表示的秒。	(2)
%U	十进制数 [00,53] 表示的一年中的周数（星期日作为一周的第一天）作为。在第一个星期日之前的新年中的所有日子都被认为是在第0周。	(3)
%w	十进制数 [0(星期日),6] 表示的周中日。
%W	十进制数 [00,53] 表示的一年中的周数（星期一作为一周的第一天）作为。在第一个星期一之前的新年中的所有日子被认为是在第0周。	(3)
%x	本地化的适当日期表示。
%X	本地化的适当时间表示。
%y	十进制数 [00,99] 表示的没有世纪的年份。
%Y	十进制数表示的带世纪的年份。
%z	时区偏移以格式 +HHMM 或 -HHMM 形式的 UTC/GMT 的正或负时差指示，其中H表示十进制小时数字，M表示小数分钟数字 [-23:59, +23:59] 。
%Z	时区名称（如果不存在时区，则不包含字符）。
%%	字面的 '%' 字符。

注释:

1. 当与 strptime() 函数一起使用时，如果使用 %I 指令来解析小时， %p 指令只影响输出小时字段。
2. 范围真的是 0 到 61 ；值 60 在表示 leap seconds 的时间戳中有效，并且由于历史原因支持值 61 。
3. 当与 strptime() 函数一起使用时， %U 和 %W 仅用于指定星期几和年份的计算。

下面是一个示例，一个与 RFC 2822 Internet电子邮件标准以兼容的日期格式。

个人总结：

个人习惯使用的格式为，年月日，时分秒，星期数，如下：

四、日志记录的堆栈追踪

前面都是一些最简单的日志记录操作与格式设置，但是我们在编写python代码的时候，往往涉及到多个函数之间的调用，我们需要跟踪函数调用的堆栈信息，这样才能定位到到底是哪一个函数的哪一个位置出现了错误，这才更加合理。

再次回顾日志记录实际上是做一件什么事？

• 即当满足什么条件的时候、或者是当某一件事情发生的时候，开始记录日志，明白这思想很重要
• 现在我们要做的就是，在程序执行出发了异常的时候，就开始记录日志，并且记录程序的堆栈信息，思想是相通的，只不过条件现在变成了，在异常发生的时候。

首先其实我们发现，http://logging.xxx()的几个函数（info、debug、warning、error、critical）他们的参数格式是一样的，以error为例：

有两个非常关键的参数，它们是

• stack_info:
• exc_info:

下面将分别来说明这两个参数各自的作用

（1）exc_info=True——出现异常时记录堆栈调用信息

先从一个简单的函数调用例子来看

有一个math_func.py模块，实现了两个函数，如下：

然后有一个operation_func.py模块，再进一步对这两个函数进行包装，以便进行选择性的调用哪一个函数，如下：

最后再主模块main.py里面进行调用，如下：

运行之后，打开日志文件，得到如下的结果

从上面我们发现，错误信息以及堆栈信息全部清楚地记录在了里面。这对于程序调试是至关重要的。

以上就是出现错误的时候logging堆栈追踪的全部实现，一般的调用模板如下：

前面提到了由两个参数，那么这两个参数到底有什么区别呢？现总结如下：

• exe_info参数：在搜索异常处理程序时，跟踪异常而打开的堆栈帧的信息，这个是专门针对异常发生的时候记录日志的；
• stack_info参数：默认为 False。如果为 True，则将堆栈信息添加到日志消息中，包括实际的日志调用。请注意，这与通过指定 exc_info 显示的堆栈信息不同：他主要是从堆栈底部到当前线程中的日志记录调用的堆栈帧，什么意思呢？即使在未引发任何异常的情况下，也可以显示如何到达代码中的特定点。堆栈帧在标题行（即每一句日志记录行）之后打印：
• stack_info：简单来说就是，根据每一个日志记录语句所在的位置，打印出这一句日志记录信息，并且在后面显示这句日志记录所在的函数堆栈的位置是在哪里。

（2）stack_info=True——记录每一句日志记录语句所在代码中的堆栈信息

参考下面的例子：

调用b函数，b中有调用a函数，得到下面的日志信息：

从上面可以看出，stack_info它会详细记录每一条日志打印语句所在的位置，然后在日志信息后面加以显示，这跟exe_info是有显著区别的。

（3）补充参数说明——extra参数的说明

前面的3.1中在说明日志记录的格式的时候，给出了很多预先定义好的格式，比如

• %(asctime)s：日志创建时的普通时间；
• %(created)f：日志创建时的时间（由time.time()返回）；
• %(filename)s：文件名；

等等，有时候我们想定义自己的信息怎么办呢？可以采用下面的方式，extra参数接受的参数是一个字典类型，如下例子所示：

我们发现，自己定义的clientip、user、work都显示了出来！

实际上，上面的这种操作称之为，向日志输出中添加上下文信息

除了传递给日志记录函数的参数外，有时候我们还想在日志输出中包含一些额外的上下文信息。比如，在一个网络应用中，可能希望在日志中记录客户端的特定信息，如：远程客户端的IP地址和用户名。这里我们来介绍以下几种实现方式：

• 通过向日志记录函数传递一个extra参数引入上下文信息
• 使用LoggerAdapters引入上下文信息
• 使用Filters引入上下文信息

具体说明请参考博文 《Python之向日志输出中添加上下文信息》

关于Python logging的更多高级用法，请参考文档<< Logging CookBook >>。