14.1　创建基本日志

创建日志有两个必要的步骤。

• 通过logging.getLogger()函数获得logging.Logger实例。
• 用获得的Logger创建消息。有许多用于创建不同重要性级别消息的方法，例如warn()、info()、debug()、error()和fatal()。

但是，这两个步骤不足以给我们提供任何输出。只有当我们需要查看输出的时候，才会使用第3个步骤。有一些日志是为调试准备的，所以我们并不总是希望看到这种日志。还有一个可选的步骤是配置logging模块的handlers、filters和formatters，可以用logging.basicConfig()函数完成这些配置。

就技术上而言，甚至可能可以跳过第1步。我们可以用logging模块顶层函数默认的日志记录器。在第8章“装饰器和mixin——横切方面”中，介绍过这种日志记录器，但是由于当时主要关注的是装饰而不是日志，因此没有深入讲解它。建议你不要使用默认的根记录器。为了弄清楚为什么最好不要使用根记录器，我们需要先介绍一点背景知识。

Logger的实例是通过名称标识的。名称中用“.-”分别的字符串组成了一个层次结构。根记录器的名称是“”——空字符串。所有其他的Loggers都是这个根Logger的孩子。

由于这棵树的名称是Loggers，因此我们通常会用根Logger来配置整棵树。当找不到正确的Logger时，我们也会使用它。如果把根Logger也作为某个模块的一等日志，那么只会制造混乱。

除了名称之外，可以在Handlers列表中配置Logger确定要将消息写到哪里，也可以在Filters列表中配置Logger确定哪种消息可以通过以及需要拒绝哪种消息。日志记录器是记录日志的基本API：我们用日志记录器创建LogRecords。然后，这些记录会被发送给Filters和Handlers，之后，被接受的记录会被格式化并保存在本地文件中或者通过网络传输到其他地方。

最佳实践是为每个类或者模块都定义一个单独的日志记录器。由于Logger的名称是由“.-”分隔的字符串，因此 Logger 的名称不会与类或者模块名冲突，我们还会为日志记录器定义一个与应用程序的层次结构类似的结构。我们可能会有一个以下面的代码作为开始的类。

import logging
class Player:
　　 def init( self, bet, strategy, stake ):
　　 　　self.logger= logging.getLogger( self.class.qualname )
　　 　　self.logger.debug( "init bet {0}, strategy {1}, stake {2}".
format(
　　 　　　　bet, strategy, stake) )

这段代码会确保这个类使用的Logger对象的名称与当前类的全名匹配。

14.1.1　创建共享的类级记录器

正如我们在第8章“装饰器和mixin——横切方面”中看到的，通过在类的外部创建日志记录器的装饰器，可以让定义类级的日志记录器变得更清晰一些。下面是我们定义的装饰器。

def logged( class ):
　　 class.logger= logging.getLogger( class.qualname )
　　 return class

这段代码将logger创建为类的一个属性，所有的实例都可以使用这个属性。现在，可以像下面这样定义类。

@logged
class Player:
　　 def init( self, bet, strategy, stake ):
　　 　　self.logger.debug( "init bet {0}, strategy {1}, stake {2}".format(
　　 　　　　bet, strategy, stake) )

这段代码可以确保类中日志记录器的名称和我们预期的一致。然后，就可以在各个方法中使用self.logger，并且对于它是正确的logging.Logger实例充满信心。

当我们创建Player实例时，会想要尝试使用一下日志记录器。默认情况下，我们不会看到任何输出。logging模块的初始配置没有包含任何能够生成输出的hanlder或者日志级别。为了看到一些输出，我们需要修改logging的配置。

使用logging模块的最大好处是可以在类和模块中使用日志记录的功能，而不用担心全局的配置问题。默认的行为是无声的，并且只会带来一点点开销。基于这个原因，我们可以在每个类中都包含日志记录的功能。

14.1.2　配置日志记录器

为了能够在日志中看到输出，我们需要提供两个配置信息。

• 把我们使用的日志记录器与一个可以生成明显输出的handler关联起来。
• 这个handler需要一个用于传递日志信息的日志级别。

Logging模块包含了许多配置方法，我们会在这里向你展示logging.basicConfig()。稍后，会单独介绍logging.config.dictConfig()。

logging.basicConfig()方法根据一些参数来创建一个用于记录输出日志的logging.handlers.StreamHandler。在许多情况下，我们需要的就是下面的代码。

import logging
import sys
logging.basicConfig( stream=sys.stderr, level=logging.DEBUG )

这段代码会配置一个用于向sys.stderr写入信息的StreamHandler实例。它会传递日志级别大于等于给定日志级别的信息。可以用logging.DEBUG来确保能够看到所有的信息。默认的级别是logging.WARN。

完成了这个配置之后，就可以看到调试信息了。

>>> p= Player( 1, 2, 3 )
DEBUG:Player:init bet 1, strategy 2, stake 3

默认的格式会显示日志级别（DEBUG）、日志记录器的名称（Player）和生成的字符串。LogRecord中还包含其他的一些可以显示的属性。通常，这个默认格式就足够了。

14.1.3　开始和关闭日志记录系统

logging模块禁止手动地修改全局的状态信息。全局的状态在logging模块内部处理。我们可以将应用程序写成独立的部分，然后通过logging接口确保这些部分之间可以正常交互。例如，可以在一些模块中包含logging，而在其他的模块中完全不用包含它，不用担心兼容性有问题或者配置有缺失。

更重要的是，我们可以记录应用程序的所有请求而不需要配置任何的 handlers。顶层的主要脚本完全可以不用 import logging。在本例中，日志代码中不会产生错误或者问题。

由于日志天生就是松耦合的，因此在应用程序的顶层只配置一次是很容易做到的。我们只应该在应用程序的if name == " main ":中配置logging。我们会在第16章“使用命令行”中详细讲解这点。

大多数的handler都包含缓冲区。大多数情况下，缓冲区将正常刷新。尽管不用在意日志系统是如何关闭的，但是用 logging.shutdown()确保所有的缓冲区都被刷新了会更可靠一些。

当处理顶层的错误和异常时，我们有两种明确的技术用于确保所有的缓冲区都被写入，其中一种技术是在try:代码块中使用finally语句。

import sys
if name == "main":
　　logging.config.dictConfig( yaml.load("log_config.yaml") )
　　try:
　　　　application= Main()
　　　　status= application.run()
　　except Exception as e:
　　　　logging.exception( e )
　　　　status= 2
　　finally:
　　　　logging.shutdown()
　　sys.exit(status)

这个例子展示了我们是如何尽早配置logging以及尽可能晚地关闭logging的。这就确保了尽可能多的程序可以使用已经配置好的日志记录器。这段代码还包括了一个异常处理的日志记录器，但是，在一些程序中，所有的异常都在main()函数中处理，使得except语句显得多余了。

另外一种方法是用atexit handler来关闭logging。

import atexit
import sys
if name == "main":
　　logging.config.dictConfig( yaml.load("log_config.yaml") )
　　atexit.register(logging.shutdown)
　　try:
　　　　 application= Main()
　　　　 status= application.run()
　　except Exception as e:
　　　　 logging.exception( e )
　　　　 status= 2
　　sys.exit(status)

这个版本的代码向我们展示了如何用atexit handler调用logging.shutdown()。当应用程序退出时，会调用给定的函数。如果main()函数中已经正确地处理了异常，那么可以用简单得多的status= main(); sys.exit(status)替代try:块。

还有第3种技术是用上下文管理器来控制日志记录。我们会在第16章“使用命令行”中介绍这种方法。

14.1.4　使用命名的日志记录器

有4种常见的需要用logging.getLogger()为Loggers命名的情况，我们通常会选择和应用程序结构一致的名称。

• 模块名：当模块包含大量的小函数或者创建大量对象的类时，我们可能会声明一个模块级的全局Logger实例。例如，当扩展tuple时，我们不希望每个实例中都包含一个Logger的引用。通常会定义一个全局的Logger，而且通常这个创建过程在模块的头部完成。在本例中，就在imports之后。

　　import logging
　　logger= logging.getLogger( name )

• 对象实例：在前面的代码中，当我们在 init ()方法中创建Logger时，展示过在对象实例中使用Logger的例子。这里，每个对象中的Logger都是唯一的，想单纯通过全名来区分可能会导致一些令人误解的情况，因为一个类可以有多个实例。一个更好的设计是在日志记录器的名称中包含一个唯一的实例标识符。

　　def init( self, playername )
　　　　self.name= playername
　　　　self.logger= logging.getLogger( "{0}.{1}".format(
　　　　　　self.class.__qualname, player_name ) )

• 类名：之前我们定义简单的装饰器时，演示过如何在类中使用Logger。我们可以用 class . qualname 作为Logger的名字并且将Logger作为一个整体赋值给类。该类的所有实例会共享这个Logger。
• 函数名：对于经常使用的小函数，经常会使用前面展示的模块级日志。对于很少使用的大型函数，可能会在函数中创建日志。

　　def main():
　　　　log= logging.getLogger("main")

这里最重要的是确保Logger的名称与软件架构相符，这为我们提供了最透明的日志，简化了调试过程。

但是，在一些情况下，我们可能会创建一个更复杂的Logger集合。有可能来自于同一个类但属于不同种类的信息。两个常见的例子是财务审计日志和安全访问日志。我们可能希望Loggers具有一些平行的结构：一个以audit.作为名称的前缀，另一个以 security.作为名称的前缀。一个类可能会包含更特定的 Loggers，例如，以audit.module.Class或者security.module.Class为名的Loggers。

self.auditlog= logging.getLogger( "audit." + self.class._qualname )

一个类中包含多个日志对象允许我们更精细地控制输出的类型。我们可以为每个Logger配置不同的handlers。在下面的部分中，我们会使用更高级的配置将输出重定向到不同的目标位置。

14.1.5　扩展日志等级

logging模块预定义了5个重要性级别。每个级别都有一个（或者两个）带有级别号码的全局变量。重要性级别代表的是从调试信息（很少重要到需要显示出来）到关键的或是致命的错误（总是非常重要）的一个可选范围。

如果需要更精细地控制哪些信息可以用，哪些信息需要拒绝，我们可以添加额外的级别。例如，一些应用程序支持多个详细级别。类似地，一些应用程序包含了不同级别的调试信息。对于不需要太多信息的普通日志，我们可能会将日志级别设置为logging. WARNING，这样只有警告和错误信息会被输出。对于详细程度的第1个级别，为了查看提示性信息，我们可以将级别设为logging.INFO。对于详细程度的第2个级别，我们会希望添加一个值是15的级别，并且让根日志记录器包含这个新级别。

我们可以像下面这样定义详细信息的新级别。

logging.addLevelName(15, "VERBOSE")
logging.VERBOSE= 15

可以通过Logger.log()方法使用新级别，这个方法接受一个级别数字作为参数。

self.logger.log( logging.VERBOSE, "Some Message" )

由于添加一个像这样的级别不会带来什么额外的开销，因此它们经常被滥用。这里的关键是，一个级别将很多概念合并进了一个单独的数字代码中——可见性和错误行为。级别应该被局限于用来表示一个简单的可见性或者错误范围。任何更复杂的部分都应该通过Logger名称或者Filter对象来完成。

14.1.6　定义指向多个目标输出的handler

有些情况下，我们需要将日志发送到多个不同的目标，如下所示。

• 可能希望有两份日志，这样可以提高运营的可靠性。
• 可能希望使用复杂的Filter对象为不同的消息创建子集。
• 可能希望为不同的目标定义不同的级别，通过这种方式分离调试信息和指示性信息。
• 可能希望基于Loggers的名称定义不同的handlers来代表不同的日志源。

当然，我们也能把这些合并起来用于十分复杂的情况。为了创建多个目标输出，必须创建多个Handlers。每个Handler可能包含一个自定义的Formatter、一个可选的级别和一个可选的Filters对象的列表。

一旦定义好了多个Handlers，我们就可以将Loggers与对应的Handlers绑定起来。Loggers 会创建一种适当的层次结构，这意味着我们可以用高层或者低层的名称将Loggers绑定到Handlers。由于Handlers中包含了一个级别过滤器，我们可以让不同的Handlers基于级别输出不同类型的信息。同样地，如果需要更复杂的过滤操作，我们可以显式地使用Filter对象。

尽管我们可以通过logging模块的API配置目标输出，但是，更清晰一些的通常做法是将日志细节定义在配置文件中。一个优雅的解决方案是用YAML标记作为配置字典。可以用一种相对直接的方法加载字典——使用logging.config.dictConfig(yaml.load(somefile))。

YAML 标记 configparser 作为默认标记显得更简洁一些。Python 标准库中关于logging. config的文档就使用了 YAML 作为范例，因为这种标记法非常简洁，所以我们会遵循这个模式。

下面是包含了两个handlers和两个loggers配置文件的范例。

version: 1
handlers:
　console:
　　 class: logging.StreamHandler
　　 stream: ext://sys.stderr
　　 formatter: basic
　audit_file:
　　 class: logging.FileHandler
　　 filename: p3_c14_audit.log
　　 encoding: utf-8
　　 formatter: basic
　formatters:
　　 basic:
　　　 style: "{"
　　　 format: "{levelname:s}:{name:s}:{message:s}"
　loggers:
　　 verbose:
　　　 handlers: [console]
　　　 level: INFO
　　 audit:
　　　 handlers: [audit_file]
　　　 level: INFO

我们定义了两个处理程序：console和adudit file。console是发送到sys.stderr的 StreamHandler。请注意，我们必须以 URI 风格语法中的 ext://sys.stderr 来命名外部的Python资源。在当前上下文中，外部的意思是配置文件的外部。这个假设是当前的值是一个简单的字符串，而不是一个指向某个对象的引用。audit file是一个会写入指定文件中的FileHandler。默认情况下，会用a模式打开文件，向文件末尾添加内容。

我们还定义了一个格式化器，命名为basic，它根据我们从basicConfig()中获得的格式来生成日志格式。如果我们不使用它，我们的信息会使用一个有些不同的默认格式，这种默认格式只包含信息文本。

最后，我们定义了两个顶层的日志记录器：verbose和audit。所有顶层名称为verbose的日志记录器都会使用verbose实例。然后，我们就能用类似verbose.example. SomeClass这样的Logger名称来创建verbose的子实例。每个日志记录器中都可以包含多个处理程序，在本例中，只包含了一个。另外，我们为每个日志记录器都指定了日志级别。

下面代码演示了如何加载这个配置文件。

import logging.config
import yaml
config_dict= yaml.load(config)
logging.config.dictConfig(config_dict)

我们将YAML文本转化为dict，然后用dictConfig()函数使用指定的字典配置日志。下面是一些获取日志记录器并且输出消息的例子。

verbose= logging.getLogger( "verbose.example.SomeClass" )
audit= logging.getLogger( "audit.example.SomeClass" )
verbose.info( "Verbose information" )
audit.info( "Audit record with before and after" )

我们创建了两个Logger对象，一个属于verbose家族树，另一个属于audit家族树。当我们写入verbose日志记录器时，会在命令行中看到输出。但是，当我们写入 audit 日志记录器时，我们在命令行中什么都看不到，记录会写到一个文件中，文件的名称保存在配置文件中。

当我们仔细查看logging.handlers模块时，可以看到有大量的处理程序供我们使用。默认情况下，logging 模块会使用老式的%风格的格式化说明。这些格式化说明与str.format()方法的不同。当我们定义格式化参数时，使用{风格的格式化说明，这和str.format()是一致的。

14.1.7　管理传播规则

Loggers的默认行为会将一条日志记录从命名的Logger一直往上经过所有的父级Loggers传到根Logger。我们可以在更低层的Loggers中包含一些特殊的行为，但是需要在根Logger中定义所有Loggers的默认行为。

由于日志记录的传播性，根日志记录器也需要处理来自我们定义的低层Loggers的日志记录。如果子日志记录器定义了输出并且允许传播，这会导致重复的输出：第1个输出来自子日志记录，然后又从父日志记录器输出了一次。当子日志记录器生成输出时，如果我们想要避免重复，我们必须关闭低层日志记录器的传播特性。

我们前面的例子中没有配置根级别的Logger。如果我们应用程序中的某些部分没有以audit.或者verbose.作为名称前缀创建日志记录器，那么这个额外的日志记录器不会与Handler关联。我们可以配置一个更高层的名称或者配置一个可以捕获全部信息的根级别的日志记录器。

如果我们需要添加一个根级别的日志记录器来捕获这些其他名称，那么我们要注意传播法则。下面是对配置文件的修改。

loggers:
　verbose:
　　 handlers: [console]
　　 level: INFO
　　 propagate: False # Added
　audit:
　　 handlers: [audit_file]
　　 level: INFO
　　 propagate: False # Added
　root: # Added
　　 handlers: [console]
　　 level: INFO

我们关闭了两个低层的日志记录器的传播功能：verbose和audit，添加了一个新的根级别的日志记录器。由于这个日志记录器没有名称，所以我们声明了一个与loggers:平行的顶层字典root:。

如果我们不关心这两个低层日志记录器的传播功能，那么verbose或者audit的每条记录都会被处理两次。在audit的例子中，处理两次可能正好是我们所预期的。审计数据会在命令行输出一次，同时也会写入审计文件中。

关于logging模块的重点是不用修改现有的应用程序就可以改进和控制日志记录。通过配置文件，我们几乎可以完成任何需求。由于 YAML 是一种相对比较优雅的标记法，因此我们可以很简单地编码许多功能。