14.3　为控制、调试、审计和安全创建专门的日志

    日志有很多不同种类，我们会关注下面的4种。

    • 错误和控制（Errors and Contrrol）：应用程序基本的错误和控制产生的主要日志用于帮助用户确认程序是否真的按他们所预期的结果运行。这种日志会包含足够的错误信息，用户可以用这些信息修正他们的问题然后重新运行应用程序。如果用户启用了详细日志，它会在这个主要的错误日志中记录更多的信息，并且为日志控制提供更多用户友好的细节。
    • 调试（Debugging）：程序员和运维工程师会使用这种日志，它可以包含更复杂的实现细节。我们几乎不会想要启用完整的调试日志，但是经常会针对特定的模块或者类启用调试日志。
    • 设计（Audit）：这种日志用于正式确认追踪的数据已经改变，这样我们就可以保证所有的处理过程都正确完成了。
    • 安全（Security）：这种日志可以被用来记录哪些用户通过了验证，还可以用来确认程序遵守了授权规则。它也能被用于检测某些涉及重复密码失败类型的攻击。

    对于这些不同种类的日志，我们常常会有不同的格式和处理的需求。同样地，这些日志中的一部分可以被随时启用或者禁用。主要的错误日志和控制日志通常只包含非调试信息。我们可能会有一个应用程序的结构类似下面的代码。

    from collections import Counter
    class Main:
    　　 def init( self ):
    　　 　　self.balance= Counter()
    　　 　　self.log= logging.getLogger( self.class.qualname )
    　　 def run( self ):
    　　 　　self.log.info( "Start" )

    　　 　　# Some processing
    　　 　　self.balance['count'] += 1
    　　 　　self.balance['balance'] += 3.14

    　　 　　self.log.info( "Counts {0}".format(self.balance) )

    　　 　　for k in self.balance:
    　　 　　　　self.log.info( "{0:.<16s} {1:n}".format(k, self.balance[k]) )

    我们创建了一个与类的全名（Main）匹配的日志记录器。我们已经往这个日志记录器中写入了提示性信息用于展示应用程序正常启动和停止。在本例中，我们用 Counter 收集余额的信息，这些信息可以用来确认已经处理过的数据的数量是正确的。

    在某些情况下，在处理结束时，我们会显示更正式的余额信息。我们可能会用类似下面这样的代码提供更容易阅读的信息。

    for k in balance:
    　　 self.log.info( "{0:.<16s} {1:n}".format(k, balance[k]) )

    这个版本会在日志中用独立的行显示键和值。错误和控制日志通常使用最简单的格式，这种日志中可能只会展示信息文本和少量其他文本，或者完全没有其他文本。我们可能会使用类似下面这样的方式来使用日志Formatter对象。

    formatters:
    　control:
    　style: "{"
    　format: "{levelname:s}:{message:s}"

    这样的配置让formatter展示日志级别名称（INFO、WARNING、ERROR、CRITICAL）和信息文本。这里忽略了大量的细节，只为用户提供了基本的好处。我们把这个格式化器称为control。

    在下面的代码中，我们将控制格式化器和命令行处理程序结合使用。

    handlers:
    　console:
    　　 class: logging.StreamHandler
    　　 stream: ext://sys.stderr
    　　 formatter: control

    这段代码将control formatter和console handler一起使用。

    14.3.1　创建调试日志

    通常，程序员会启用调试日志来监视开发中的程序。它通常是只关注特定的功能、模块或者类。因此，我们会经常通过名称启用或者禁用日志记录器。在配置文件中，我们可能只会将一些日志记录器的级别设为DEBUG，而其他的都是INFO甚至可能是WARNING级别。

    我们常常会将调试信息的设计作为类设计的一部分。事实上，我们可能会将调试能力作为类设计中一个特殊的质量功能。这可能意味着要接受大量的日志请求。例如，我们可能会基于基本的类状态信息执行复杂的计算。

    @logged
    class OneThreeTwoSix( BettingStrategy ):
    　　 def init( self ):
    　　 　　self.wins= 0
    　　 def state( self ):
    　　 　　return dict( wins= self.wins )
    　　 def bet( self ):
    　　 　　bet= { 0: 1, 1: 3, 2: 2, 3: 6 }[self.wins%4]
    　　 　　self.logger.debug( "Bet {1}; based on {0}".format(self.
    state(), bet) )
    　　 def record_win( self ):
    　　 　　self.wins += 1
    　　 　　self.logger.debug( "Win: {0}".format(self._state()) )
    　　 def record_loss( self ):
    　　 　　self.wins = 0
    　　 　　self.logger.debug( "Loss: {0}".format(self._state()) )

    在这个类定义中，我们创建了一个 state()方法用于暴露相关的内部状态，这个方法只是用来支持调试需要。我们禁止使用self. _ dict ，因为通常这样会包含太多无用的信息。然后，我们就可以在方法函数的不同位置追踪这个状态的变化。

    调试输出通常是通过修改配置文件中用于启用/禁用调试的配置选择性地启用，参照下面这个修改配置文件。

    loggers:
    　　betting.OneThreeTwoSix:
    　　　　handlers: [console]
    　　　　level: DEBUG
    　　　　propagate: False

    我们基于类的全名来标识特定类的日志记录器。本例中假设已经定义了一个名为console的处理程序，关闭日志传播，这样就可以避免调试信息被复制到根日志记录器中。

    这种设计的潜在想法是我们不希望简单地在命令行中通过-D选项或者—DEBUG选项就可以启用调试日志。为了进行高效的调试，我们通常希望可以通过配置文件选择性地启用日志记录器。我们会在第16章“使用命令行”中介绍命令行的问题。

    14.3.2　创建审计和安全日志

    审计和安全日志通常会在两个处理程序中重复：主控制处理程序和用来检查审计与安全的文件处理程序，这意味着我们需要做下面几件事情。

    • 为审计和安全定义额外的日志处理器。
    • 为这个日志处理器定义多个处理程序。
    • 可选地为审计处理程序定义不同的格式。

    正如前面所展示的，通常，我们会为审计或者安全日志创建独立的日志结构。为日志记录器创建独立的结构比尝试通过新的日志级别引入审计或者安全日志要简单得多。创建新的日志级别是很有挑战的，因为信息本质上属于INFO信息；它们不属于偏向WARNING方面的INFO，因为它们不是错误；同时它们也不属于DEBUG方面的INFO，因为它们不是可选的。

    下面是可以用来创建包含审计功能的类的装饰器。

    def audited( class ):
    　　 class    .logger= logging.getLogger( class.qualname )
    　　 class    .audit= logging.getLogger( "audit." + class.qualname )
    　　 return class

    这个装饰器创建了两个日志记录器。一个的名称和类的全名相同，另一个在类全名前加了 audit.前缀，这个日志记录器就属于审计日志层次体系。下面演示了如何使用这个装饰器。

    @audited
    class Table:
    　　 def bet( self, bet, amount ):
    　　　　　self.audit.info( "Bet {0} Amount {1}".format(bet, amount) )

    我们创建了一个会在 audit 层次结构的日志记录器中生成记录的类。我们可以配置日志系统处理这个日志记录器额外的层次结构，来看一下我们需要的两个处理程序。

    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: detailed

    console处理程序用basic格式记录面向用户的日志，aduit _ file处理程序使用更复杂的detailed格式化器。下面是这些handlers引用的formatters。

    formatters:
    　basic:
    　　 style: "{"
    　　 format: "{levelname:s}:{name:s}:{message:s}"
    　detailed:
    　　 style: "{"
    　　 format: "{levelname:s}:{name:s}:{asctime:s}:{message:s}"
    　　 datefmt: "%Y-%m-%d %H:%M:%S"

    basic格式只会显示信息的3个属性。detailed格式会复杂一些，因为日期的格式和信息的其他格式是用不同的方式完成的。我们用{风格格式化全局信息，下面是两个Logger的定义。

    loggers:
    　audit:
    　　 handlers: [console,audit_file]
    　　 level: INFO
    　　 propagate: True
    　root:
    　　 handlers: [console]
    　　 level: INFO

    我们为audit层次结构定义了一个日志记录器。audit的所有孩子都会将消息写入console Handler和audit _ file Handler中。根日志记录器会规定其他的日志记录器只能使用console。现在，我们将会看到两种审计消息。

    console可能包含下面这样的内容。

    INFO:audit.Table:Bet One Amount 1
    INFO:audit.Table:Bet Two Amount 2

    audit _ file看起来可能类似下面这样。

    INFO:audit.Table:2013-12-29 10:24:57:Bet One Amount 1
    INFO:audit.Table:2013-12-29 10:24:57:Bet Two Amount 2

    这种重复记录日志的方式不但为我们提供了主console日志上下文中的审计信息，同时也将重点的审计信息保存在单独的日志文件中以供日后分析使用。