关于日志打印的几点建议以及非最佳实践

　　日志的打印在软件开发过程中必不可少，一般分为两个大类：

操作日志
系统日志

　　操作日志，主要针对的是用户，例如在Photoshop软件中会记录自己操作的步骤，便于用户自己查看。

　　系统日志，主要针对的是软件开发人员（包括测试、维护人员），也就是说这部分的日志用户是看不到的，也就是我们通常所说的debug日志。

　　在大学中所谓的实践项目或者老师布置的作用中，通常是不会在意日志，除非在作业中有特别的需要，往往在开发过程中直接打印控制台语句来调试程序，这是极为不专业的调试开发过程。所以这也就导致了一个问题，大学毕业和工作时衔接不上最大的问题不在于技术上的难度，而是日志打印的问题。这个看似不起眼的问题对于应届生来说往往是“恶梦”，操作日志相对比较好理解，用户做了什么就记录什么；而打印系统日志则无从下手，往往一般有下面几个方面——3W：

Where：不清楚在何处打印日志
Who：不清楚打印什么级别的日志
What：不清楚日志应该包含什么内容

　　本篇着重讲解系统日志，所以以下“日志”均为“系统日志”的简称。我将针对这几个方面对系统日志的打印做一个简要的总结。另外对Java中常用的日志打印框架（log4j）的几种使用方式做一个示范。

WHERE

　　1.程序入口

　　在入口打印日志是因为这个时候传递进来的参数没有经过任何处理，将它打印在日志文件中能一眼就知道程序的原始数据是否符合我们的预期，是不是传递进来的原始数据就出现的问题。

　　2.异常捕获

　　在异常打印出详细的日志能让你快速定位错误在哪里，例如在程序抛出异常捕获时，在平时我们经常就是直接在控制台打印出堆栈信息e.printStackTrace()，但在实际的生产环境更加艰苦，更别说有IDE来让你查看控制台信息，此时就需要我们将堆栈信息记录在日志中，以便发生异常时我们能准确定位程序在哪里出错。

　　3.重要信息

　　这一点可能很宽泛，因为不同的业务逻辑重点可能并不一样，例如在有的重要参数不能为空，此时就需要判断是否为空，如果为空则记录到日志中；还有的例如传递进来的参数经过一系列的算法处理过后，此时也需要打印日志来查看是否计算正确。但切记，尽量不要直接在for循环中打印日志，特别是for循环特别大时，这样你的日志可能分分钟被冲得不见踪迹，甚至带来性能上的影响。

WHO

日志打印通常有四种级别，从高到底分别是：ERROR、WARN、INFO、DEBUG。应该选用哪种级别就是个很重要的问题。

首先明确日志级别中的优先级是什么意思，在你的系统中如果开启了某一级别的日志后，就不会打印比它级别低的日志。例如，程序如果开启了INFO级别日志，DEBUG日志就不会打印，但不打印不代表不产生，这在后面会提到。通常在生产环境中开启INFO日志。

那么应该打印什么级别的日志呢？首先我们应该明确谁在看日志。

通常来说，系统出了问题客户不会进到系统对着黑黢黢的控制台查看日志输出，所以日志所面对的主体对象必然是软件开发人员（包括测试测试、维护人员）。

下面我们假设几种场景来帮助我们理解日志级别。

首先，程序开发结束后交由给测试人员进行测试，测试人员根据测试用例发现某个用例的输出和预期不符，此时他的第一反应该是查看日志。此时的日志是INFO级别日志不会出现DEBUG级别的日志，现在就需要根据日志打印分为两种情况决定他下一步操作：

通过查看INFO日志发现是由于自己操作失误，造成了程序结果和预期不符合，这种情况不是程序出错，所以并不是bug，不需要开发人员到场。
通过查看INFO日志发现自己的操作正确，根据INFO日志查看并不是操作失误造成，这个时候就需要开发人员到场确认。
以上两种情况是理想情况，测试人员仅根据INFO级别的日志就能判断出程序的输出结果与预期不符是因为自己操作失误还是程序bug。更为现实的情况实际是测试人员并不能根据INFO级别的日志判断是否是自己失误还是程序bug。

　　综上，INFO级别的日志应该是能帮助测试人员判断这是否是一个真正的bug，而不是自己操作失误造成的。

　　假设测试人员现在已经初步判断这是一个bug，并且这个bug不那么明显，此时就需要开发人员到场确认。

　　开发人员到达现场后，第一步应该是查看INFO日志初步作初步判断验证测试人员的看法，接着如果不能判断出问题所在则应该是将日志级别调整至DEBUG级别，打印出DEBUG级别的日志，通过DEBUG日志来分析定位bug出在哪里。

　　所以，DEBUG级别的日志应该是能帮助开发人员分析定位bug所在的位置。

　　ERROR和WARN的级别都比INFO要高，所以在设定日志级别在INFO时，这两者的日志也会被打印。根据上面INFO和DEBUG级别的区别以及适用人员可以知道，ERROR和WARN是同时给测试和开发观察的。

　　WARN级别称之为“警告”，这个“警告”实际上就有点含糊了，它不算错，你可以选择忽视它，但也可以选择重视它。例如，现在一个WARN日志打出这么一条日志“系统有崩溃的风险”，这个时候就需要引起足够的重视，它代表现在不会崩溃，但是它有崩溃的风险。或者出现“某用户在短时间内将密码输出很多次过后才进入了系统”，这个时候是不是系统被暴力破解了呢？等等，这个级别日志如同它的字面含义，给你一个警告，你可以选择忽视，也可以重视，但至少它现在不会给系统带来其他影响。

　　ERROR级别称之为“错误”，这个含义就更明显了，就是系统出现了错误，需要处理。最为常见的就是捕获异常时所打印的日志。

　　上面我们介绍了四种日志级别的区别，特别需要注意的是INFO级别和DEBUG级别所适用的人员。那么我们该如何选择哪个级别的日志输出呢？

　　以下是我的个人理解：

INFO

程序入口，这能让开发人员确认参数是否为自己所为。
计算结果，测试关心的程序的输出结果是否符合预期，那么对于计算过程不应该关心，仅给出计算结果就能判断是否符合预期。

DEBUG

　　对于DEBUG级别，我认为更关心的是过程，以及更为具体的相关信息，因为帮助它的定位在于帮助开发人员定位bug，定位bug就需要较为详细的参数信息才能定位。例如对于某个具体的算法过程，可以使用DEBUG打印，开发人员不仅关心结果，同时在结果不正确时应该能根据DEBUG日志查询计算过程是否出现偏差

WARN

　　某个不常走到的分支，对于常规的操作是不应该打印WARN日志的，只有在满足某个条件才能走到的分支，且这个分支引起了“警觉”，此时就应该打印WARN日志。

ERROR

　　毫无疑问出现错误，程序不能继续运行下去就应该打印ERROR日志，这个错误并不是业务上的错误。例如，新增某个用户发现已经存在时，此时虽然新增失败，但不能说程序出现错误就打印ERROR日志；在删除某个用户发现用户已经被锁定时，此时也不能说因为程序不能按照删除的逻辑继续运行下去就应该打印ERROR日志。

WHAT

　　应该打印什么内容？打印的内容一定要从实际出发。也就是说如果在实际的生产环境中，你的用户量很大，日志在不停地刷新，如何定位某个用户的整个登录以及后续的操作呢？当然就是根据用户名来跟踪。所以打印内容的第一要素就是要能便于定位；定位过后也许用户在好几个模板中进行操作，还是定位，这个时候定的是模块的位；还有一点当然就是用户操作时的具体参数；最后一点就是用户干了什么。

　　总结就是，[id, module, params, content]（关键字，模块，参数，内容）。

　　以上就是对日志打印的几点建议，说的不全面，抛砖引玉。下面是对日志打印框架（log4j）的非最佳实践。

在Spring中使用log4j日志框架

　　Spring中使用log4j日志框架可以说是最为常见的应用场景了，我们将结合Spring对log4j做一个简单的示范。

　　在IDEA中创建一个Maven构建的Web项目，项目结构如下图所示：

　　pom.xml中的依赖如下：

<dependency>
  <groupId>org.slf4j</groupId>
  <artifactId>slf4j-api</artifactId>
  <version>1.6.6</version>
</dependency>
<dependency>
  <groupId>org.slf4j</groupId>
  <artifactId>slf4j-log4j12</artifactId>
  <version>1.6.6</version>
</dependency>
<dependency>
  <groupId>log4j</groupId>
  <artifactId>log4j</artifactId>
  <version>1.2.16</version>
</dependency>

　　在resources（IDEA中resources就是classpath路径）中新建一个log4j.properties文件，如下所示：

 1 log4j.rootLogger = INFO, stdout, logfile
 2 #日志输出到控制台
 3 log4j.appender.stdout = org.apache.log4j.ConsoleAppender
 4 log4j.appender.stdout.layout = org.apache.log4j.PatternLayout
 5 log4j.appender.stdout.ConversionLayout = %d [%t] %-5p %c - %m%n
 6 #日志输出到文件
 7 log4j.appender.logfile = org.apache.log4j.DailyRollingFileAppender
 8 log4j.appender.logfile.File = /Users/yulinfeng/Log/log
 9 log4j.appender.logfile.maxFileSize=10240KB     #日志的最大容量为10M
10 log4j.appender.logfile.Append = true    #是否追加写进文件
11 log4j.appender.logfile.Threshold = DEBUG    #输出DEBUG级别日志到文件中
12 log4j.appender.logfile.layout = org.apache.log4j.PatternLayout
13 log4j.appender.logfile.layout.ConversionPattern = %d [%t] %-5p %c - %m%n

　　第1行，log4j.rootLogger=INFO, stdout, logfile。这是log4j的根配置，第一个参数表示输出什么级别的日志，后面的参数表示输出的位置，位置可以是控制台，也可以是文件，语法为log4j.rootLogger=[level], appendername……，在这里定义了两个输出位置，名字无所谓取设么，有意义即可。日志级别从高到低分别是：OFF、FATAL、ERROR、WARN、INFO、DEBUG、ALL，log4j建议只使用ERROR、WARN、INFO、DEBUG四个级别，也就是也就是在上面提到过的。

　　第3、7行就分别指定了stdout和logfile日志的输出位置，log4j一共提供了5个。

　　org.apache.log4j.ConsoleAppender（控制台）

　　org.apache.log4j.FileAppender（文件）

　　org.apache.log4j.DailyRollingFileAppender（每天产生一个日志文件）

　　org.apache.log4j.RollingFileAppender（文件大小达到一定大小后产生一个新的文件）

　　org.apache.log4j.WriterAppender（将日志信息以流格式发送到任意位置）

第4行表示日志信息的格式，一共有以下几种。

org.apache.log4j.HTMLLayout（以HTML表格输出）

org.apache.log4j.PatternLayout（灵活的自定义格式输出）

org.apache.log4j.SimpleLayout（简单的格式输出，只包括日志级别和日志信息的字符串）

org.apache.log4j.TTCCLayout（包含线程、日志级别、日志所在类和日志信息的字符串）

通常为了更为灵活的打印日志，我们会选择PatternLayout布局的日志，同时通过ConversionPattern自定义输出格式。

　　按照上面的配置，我们就可以在代码中进行日志的输出了。由于是在Spring框架下使用log4j，所以就要使用Spring对log4j进行初始化，在web.xml中对log4j进行初始化。

<web-app>
    <display-name>log web</display-name>

    <context-param>
        <param-name>log4jConfigurationLocation</param-name>
        <param-value>classpath*:log4j.properties</param-value>
    </context-param>

    <!--每隔60s扫描log4j的配置文件，这里配置的log4jRefreshInterval参数表示能不用重启web服务器就能动态更改log4j日志级别，这也是和Spring整合的一大好处-->
    <context-param>
        <param-name>log4jRefreshInterval</param-name>
        <param-value>60000</param-value>
    </context-param>
    <listener>
        <!--从spring4.2.1开始Log4jConfigListener已经被废弃，最好使用log4j2对应的org.apache.logging.log4j.web.Log4jServletContextListener
.Log4jServletContextListener-->
        <listener-class>org.springframework.web.util.Log4jConfigListener</listener-class>
    </listener>
</web-app>

　　此时在代码逻辑中加入以下代码即可根据我们的配置输出系统日志。

private Logger log = Logger.getLogger(Test.class);
log.info(“test info”);

　　上面是所有日志文件都输出到一个文件的情况，在实际中我们很有可能针对不同的模块输出到不同到日志文件。

修改log4j.properties：

 1 log4j.rootLogger = INFO, module1, module2
 2 #输出到控制台
 3 log4j.appender.stdout = org.apache.log4j.ConsoleAppender
 4 log4j.appender.stdout.layout = org.apache.log4j.PatternLayout
 5 log4j.appender.stdout.ConversionLayout = %d [%t] %-5p %c - %m%n
 6 #模块1输出的日志文件
 7 log4j.appender.module1 = org.apache.log4j.DailyRollingFileAppender
 8 log4j.appender.module1.File = /Users/yulinfeng/Log/module1
 9 log4j.appender.module1.maxFileSize=10240KB     #日志的最大容量为10M
10 log4j.appender.module1.Append = true    #是否追加写进文件
11 log4j.appender.module1.Threshold = DEBUG    #输出DEBUG级别日志到文件中
12 log4j.appender.module1.layout = org.apache.log4j.PatternLayout
13 log4j.appender.module1.layout.ConversionPattern = %d [%t] %-5p %c - %m%n
14 #模块2输出的日志文件
15 log4j.appender.module2 = org.apache.log4j.DailyRollingFileAppender
16 log4j.appender.module2.File = /Users/yulinfeng/Log/module2
17 log4j.appender.module2.maxFileSize=10240KB     #日志的最大容量为10M
18 log4j.appender.module2.Append = true    #是否追加写进文件
19 log4j.appender.module2.Threshold = DEBUG    #输出DEBUG级别日志到文件中
20 log4j.appender.module2.layout = org.apache.log4j.PatternLayout
21 log4j.appender.module2.layout.ConversionPattern = %d [%t] %-5p %c - %m%n

　　在模块1中输出日志文件时其实就是参数不同而已：

private Logger log = Logger.getLogger(“module1”);
log.info(“test info”);

　　在模块2中：

private Logger log = Logger.getLogger(“module2”);
log.info(“test info”);

　　以上就是在Spring中使用log4j日志框架的非最佳实践。

　　最后，还要介绍另外一种打印日志的方式，上面的方式将会在每个类中都定义一个Logger对象，这样的代码相对于业务逻辑来说实际是不想关，此时就可以利用Spring中的AOP面向切面编程打印日志。这里可能不是所有的人都能接触到利用AOP来打印日志，这里暂时不做详细介绍。

这是一个能给程序员加buff的公众号

posted @ 2017-10-18 22:10 OKevin 阅读(12069) 评论(3) 编辑收藏举报

刷新页面返回顶部

CoderBuff

hellobug@outlook.com