首页 > 编程 > Effective Debug Logging (part 2)

Effective Debug Logging (part 2)

这是这个系列文章的第二部分,我们将关注如何过滤调试日志的问题,亦即索引当中“调试日志的分级和分类:提高日志的信噪比”一项。

调试日志的分级和分类

调试日志的分级和分类的目的在于能够更好的对大量的日志进行过滤,使得可以容易地从某个或某些方面分析日志。

日志的分级是已经广为接受的一种做法,例如Windows的事件日志就分为错误、警告、信息三种级别,而内核的DbgPrintEx函数也包含有日志分级的参数,并且给出了四种预设的级别。为调试日志实现分级的主要目的是过滤不必要的消息,以便能够让重要的调试信息不会淹没在大量的无用信息当中,同时在正常的使用过程当中,控制调试信息的输出也可以提高系统的效率。

在具有分级的调试日志实现当中,通常系统都会至少指定3种调试信息的级别,即错误、警告和信息。也有系统提供更加细致的级别,例如比错误更高级别的“致命错误”级别,或比信息级别更低的“调试”级别和“追踪”级别。通常情况下不同的级别使用一个正整数值来表示,一般的约定是使用较小的值表示优先级较高的调试信息,例如致命错误为0级,可恢复错误为1级等等。

通常具有调试日志分级的产品都会采用某种方式来指定需要打印的调试级别,这个可以通过命令行参数或者配置文件指定,通常接受一个正整数。在打印调试日志的地方,开发人员需要指定调试日志的级别,当这个级别高于或等于全局的调试级别时,这条调试日志便会输出。这种方式简单而且有效,因此得到了广泛的应用。

但是这里面隐含着一个实际当中需要面对的问题。虽然我们提供了不同的级别,四种或者五种,但是通常被用到的通常只有其中的两个极端的级别:在正常运行过程
当中,用户往往选择不打印任何的日志,或者只打印级别较高的日志;而当软件在客户处遇到了问题的时候,支持人员往往要求客户直接将调试日志级别调到最详细
的级别,然后搜集日志。因此,日志分级需要首要考虑的问题很多的时候并非为用户提供对于日志输出量的控制,而是为了开发人员拿到细致的日志的时候,能够快速的对其进行过滤,并在不同级别
上定位问题。因此调试级别不宜太多,分的过细没有太大的意义,而且容易使得在编写调试日志的时候难以确定正确的级别。我们比较倾向于五个级别:致命错误、可恢复错误、警告、信息、调试,有时候致命错误和可恢复错误不加区分,也就变成的四种级别。另外,应当在最终的日志文件当中记录每条日志的级别,以便于拿到日志之后可以根据级别过滤。

因此,我们有了Tip 3和Tip 4:

Tip 3:使用日志分级显示的机制,在正常运行当中控制日志的输出量,调试情况下输出尽可能细致。
Tip 4:在日志当中记录当前日志的级别,便于拿到日志之后的过滤和分析。

由于通常开发人员拿到的都是最详细的级别的调试日志,而在这个级别上面,各个模块通常都会打印出大量的日志,这种日志到了支持人员和开发人员手中之后,也往往由于数量巨大而难于处理和分析。因此如何可以更加细致的进行日志的分类,就是成了另一个需要解决的问题。

对于调试日志分类的设计有两个方面的考虑:一方面,对于日志分类倾向于尽可能的细致,以便拿到日志的开发人员能够在更加细致的级别上分析日志,另一方面,由于日志所从属的类别需要开发人员在写每一条日志的时候确定,因此,应该能够让开发人员能够快速的决定日志的类别,以便减少开发人员的工作,这就要求日志的分类不能过于细致。这两个方面相互矛盾,因此,设计良好分类方式,抛弃不必要的分类,使设计当中需要考虑的一个重要方面,否则开发人员花费在确定日志的类别上的时间比写代码的时间还多,就得不偿失了。

另外,由于调试日志的分类可以有几种不同的方式,例如基于模块进行分类,基于目的进行分类,等等,因此设计几个分类的维度也是一个需要仔细考虑的问题。因为开发人员在写日志的时候,需要考虑的问题目前至少有:什么级别,什么内容。我们每增加一个日志的分类维度,就使得开发人员增加了一个需要考虑的问题,这极大的增加了开发人员的工作,也可能是的开发人员因此开始不喜欢写调试日志,反而适得其反。因此,我们的经验是最多只添加一种分类的维度,这种通常就是基于模块的分类。

Tip 5:添加调试日志的工作越简单,开发人员越喜欢在代码当中添加调试日志。

基于模块的分类和过滤方案可以有多种方式实现。第一种是对于不同的模块使用不同的配置项控制其调试级别,之间互不影响。另一种使用全局的配置项控制调试级别,但是对于不同模块的日志文件使用不同的文件名前缀。例如按照第一部分的那种日志文件命名方案,使用不同的basename。第三种方案则使用类似于分级的方式实现,开发人员在代码当中加入调试日志的时候,指定一个模块的标识,而在程序运行的时候,通过某种方式如命令行和配置文件来指定需要显示的模块,来实现基于模块的过滤。

三种方案各有其优劣。

第一种方案的优势在于可以细致的控制各个模块的日志信息。这种在现场调试的时候比较有优势,但是在无法现场支持的时候就存在一定的操作难度。因为对于支持人员来说,往往倾向于拿到尽可能详细的日志,因此在搜集日志的时候,也往往要求用户将模块的调试级别都调到最详细。这样一来,一方面增加了用户的操作难度,另一方面对于最后分析日志的开发人员来说,这种方案并没有改变多少问题。因此,

Tip 6:即使需要对于每个模块分别控制日志级别,最好也能够提供一个全局的日志级别控制选项。

第二种方案则稍有改进,其优势在于便于搜集和浏览,因为每个文件都单纯的对应于一个模块,不存在模块之间互相穿插的问题,因此人阅读比较容易,也便于工具的处理。但是如果模块划分过细,会导致难于跟踪模块之间的互操作。比如模块A会在处理过程当中调用模块B,但是两者的日志分布在不同的日志文件当中,这样的结果往往是在察看日志的时候,需要在两个日志文件之间跳来跳去,反而使得分析变得麻烦。因此这种方案通常用在比较粗粒度的子系统级别。将不同子系统的日志输出到不同前缀的日志文件,可以在划分模块和便于分析之间找到一种折中。而且结合第一种方案,也可以对于不同的子系统提供不同的调试级别的控制。

Tip 7:在子系统级别上,让不同的子系统把日志输出到不同的日志文件

第三种方案则在第二种方案上面更进了一步,可以用来区分子系统当中不同的模块。这种方案当中对于模块标识的选择也有几种不同的设计。一种是使用短字符串作为模块的标识,例如main,server,client等字符串,而在配置文件当中,使用逗号或其他符号分割的字符串选择需要输出的模块。另一种方案是使用整数的位掩码(bit mask),每个模块对应于一个整数当中的一个位,而使用位AND操作来确定是否需要输出该模块的信息。表面看起来似乎前者更具有良好的可读性和可配置性,而后者则相对难于理解和配置。但实际当中,这种考虑应该放在相对较为次要的位置。因为用户对于模块的调试日志的控制往往也是两个极端:none或all,而如何让开发人员更加容易的添加调试日志,以及拿到所有模块都打开的日志的时候如何便于根据模块进行过滤和分析,才是设计调试日志方案的首要考虑。因此,我更倾向于使用第二种方案来实现,这样在最后的日志分析当中,更容易用脚本来进行辅助。与日志级别类似,在最终的日志文件当中,也应该记录该日志条目所从属的类别。

Tip 8:在子系统内部,对于不同的模块,使用不同的模块标识,便于开发人员进行分析和过滤。

实际当中,这三种方案放在一起实现是最为有效的。总结一下就是:提供一个全局的调试级别控制,在每个子系统上面提供一个该子系统的级别控制,该控制默认情况下使用全局控制,在特殊情况下可以覆盖全局控制;让不同子系统的日志输出到不同的日志文件当中;子系统内部的模块使用模块标识区分,并将其记录进最终的日志条目当中,便于开发人员使用人工或脚本过滤和区分。

如上Tip 5所述,我们希望添加的模块信息不会增加开发人员的工作,因此实现日志根据模块划分类别,可以采用了一些tricks来简化日志的添加工作。例如,每个源代码文件通常都只从属于一个模块,因此,我们可以在每个源代码文件的顶端添加它从属的模块的信息,而使用宏来自动的在每条日志当中添加模块信息。这样,开发人员其实并没有增加太多的工作要做。

而在实际当中,很多时候简单的根据日志从属的模块区分还不够,比如可能需要把所有的函数跟踪日志和路径跟踪日志作为两个单独的级别,这时也许我们就需要引入一些别的分类方式,但是即使有这种需求,我们也建议把他们并入到模块级别当中,因为任何一个增加的维度都是以增加开发人员的工作作为代价的。通常,我们建议使用宏来简化这些添加动作,而且,除非真的必要(很多时候这两种需求是可以由其他的日志代替的),我们不建议增加更多的日志分类方式。

Tip 9:使用一些tricks来简化调试日志的添加,减少开发人员在写调试日志时需要考虑的问题。

下面,我们开始探讨如何在正确的地方添加正确的日志,也就是“日志应该写些什么”的问题。

标签:
  1. 本文目前尚无任何评论.
  1. 本文目前尚无任何 trackbacks 和 pingbacks.