LOG使用规范（整理）

在开发B/S系统时，对于LOG，需要关注：

1. 日志信息的集中采集、存储、信息检索：在WEB集群节点越来越多的情况下，让开发及系统维护人员能很方便的查看日志信息
2. 日志信息的输出策略：日志信息输出全而不乱，便于跟踪和分析问题
3. 关键业务的日志输出：基于度量数据采集、数据核查、系统安全等方面的考虑，关键业务系统对输出的日志信息有特殊的要求，需要做针对性的设计

本文主要从这3个方面进行说明，重点说明日志输出的使用

日志的采集和存储
对于目前存储日志，主要存在2种方式：

1. 本地日志：直接存放在本地磁盘上
2. 远程日志：发往日志平台，用作数据分析和日志处理并展现。如用户访问行为的记录，异常日志，性能统计日志等。

日志工具的选择
推荐使用SLF4J（Simple Logging Facade for Java）作为日志的api，SLF4J是一个用于日志系统的简单Facade，允许最终用户在部署其应用时使用其所希望的日志系统。与使用apache commons-logging和直接使用log4j相比，SLF4J提供了一个名为参数化日志的高级特性，可以显著提高在配置为关闭日志的情况下的日志语句性能

//slf4j
log.debug("Found {} records matching filter: '{}'", records, filter);

//log4j
log.debug("Found " + records + " records matching filter: '" + filter + "'");

可以看出SLF4J的方式一方面更简略易读，另一方面少了字符串拼接的开销,并且在日志级别达不到时（这里例子即为设置级别为debug以上），不会调用对象的toString方法。

日志输出级别（由高到低）

• ERROR：系统中发生了非常严重的问题，必须马上有人进行处理。没有系统可以忍受这个级别的问题的存在。比如：NPEs（空指针异常），数据库不可用，关键业务流程中断等等

• WARN：发生这个级别问题时，处理过程可以继续，但必须对这个问题给予额外关注。这个问题又可以细分成两种情况：一种是存在严重的问题但有应急措施（比如数据库不可用，使用Cache）；第二种是潜在问题及建议（ATTENTION），比如生产环境的应用运行在Development模式下、管理控制台没有密码保护等。系统可以允许这种错误的存在，但必须及时做跟踪检查

• INFO：重要的业务处理已经结束。在实际环境中，系统管理员或者高级用户要能理解INFO输出的信息并能很快的了解应用正在做什么。比如，一个和处理机票预订的系统，对每一张票要有且只有一条INFO信息描述 "[Who] booked ticket from [Where] to [Where]"。另外一种对INFO信息的定义是：记录显著改变应用状态的每一个action，比如：数据库更新、外部系统请求

• DEBUG：用于开发人员使用。将在TRACE章节中一起说明这个级别该输出什么信息

• TRACE：非常具体的信息，只能用于开发调试使用。部署到生产环境后，这个级别的信息只能保持很短的时间。这些信息只能临时存在，并将最终被关闭。要区分DEBUG和TRACE会比较困难，对一个在开发及测试完成后将被删除的LOG输出，可能会比较适合定义为TRACE级别

推荐使用debug，info，warn，error级别即可，对于不同的级别可以设置不同的输出路径,如debug，info输出到一个文件，warn，error输出到一个带error后缀的文件

日志API规范

• Log对象的声明和初始化，仅以下代码是符合规范的

// （推荐）
private static final Logger logger = LoggerFactory.getLogger(Xxx.class);

private final Logger logger = LoggerFactory.getLogger(getClass());

private  static  final Logger logger =  LoggerFactory.getLogger("loggerName");

private static Logger logger = LoggerFactory.getLogger(Xxx.class);

protected final Logger logger = LoggerFactory.getLogger(getClass());

private Logger logger = LoggerFactory.getLogger(getClass());

protected Logger logger = LoggerFactory.getLogger(getClass());

• 不得使用System.out, System.err进行日志记录，请改使用logger.debug、logger.error

• debug/info级别的信息，信息本身需要计算或合并的，必须加 isXxxEnabled() 判断在前，这样可以大大提高高并发下的效率。如：

if (logger.isDebugEnabled()) {
    logger.debug(test());
}

private String test(){
    int i = 0;
    while (i < 1000000) {
        i++;
    }

    return "";
}

如果不加 isXxxEnabled() 判断，test()在info级别下也会执行。

• 注意error和warn级别的区别，导致业务不正常服务的，用error级别；错误是预期会发生的，并且已经有了其他的处理流程，使用warn级别

• 正确的记录异常信息
  记录异常信息是“记录所有信息”中的一个重要组成，但很多开发人员只是把logging当做处理异常的一种方式。他们通常返回缺省值，然后当做什么都没发生。 其他时候，他们先log异常信息，然后再抛出包装过的异常。如：

log.error("IO exception", e);

throw new MyCustomException(e);

这种方法总是会打印两次相同的 stack trace信息，因为有些地方会捕捉MyCustomException异常，然后输出导致问题的日志信息。
但有时基于某些原因我们真的想log异常信息怎么办？很过见多的log语句有一半以上都是错的，
如：

try {    
    Integer x = null;
    ++x;
} catch (Exception e) {

    //A
    log.error(e);        

    //B
    log.error(e, e);        

    //C
    log.error(""+ e);        

    //D
    log.error(e.toString());        

    //E
    log.error(e.getMessage());        

    //F
    log.error(null, e);        

    //G
    log.error("", e);        

    //H
    log.error("{}", e);        

    //I
    log.error("{}", e.getMessage());      

     //J
     log.error("Error reading configuration file: " + e);        

    //K
    log.error("Error reading configuration file: "+ e.getMessage());        

    //L
    log.error("Error reading configuration file", e);        


}

上面只有G、L是对的，L的处理方式更好一些

注意：捕获异常后不处理也不输出log是一种非常不负责任的行为，这会造成问题很难被定位，极大地提高debug成本！

• 重要方法入口，业务流程前后及处理的结果等，推荐记录log，并使用debug级别，如：

public String printDocument(Document doc, Mode mode) {

    log.debug("Entering printDocument(doc={}, mode={})", doc, mode);

    //Lengthy printing operation
    String id = "Id";

    log.debug("Leaving printDocument(): {}", id);

    return id;

}

因为对于非开发人员掌控的环境（无法做DEBUG），记录方法调用、入参、返回值的方式对于排查问题会有很大帮助。

• Log的内容一定要确保不会因为Log语句的问题而抛出异常造成中断，如：

log.debug("Processing request with id: {}", request.getId());

你能确保request对象不是NULL吗？如果request为null，就会抛出NullPointerException。

• 避免拖慢应用系统
  输出太多日志信息：通常每小时输出到disk的数据量达到几百MiB就已经是上限了不正确使用toString() 或字符串拼接方法。

try {
    log.trace("Id=" + request.getUser().getId() + " accesses" + manager.getPage().getUrl().toString())
} catch(NullPointerException e) {
}

• 日志信息中尽量包含数据和描述：easy to read, easy to parse
  一些反模式的例子

log.debug("Message processed");

log.debug(message.getJMSMessageID());

log.debug("Message with id '{}' processed", message.getJMSMessageID());



if (message instanceof TextMessage)

//...
else {
    log.warn("Unknown message type");
}

为什么不包含 message type, message id, etc，包含个message content很难吗？另一个anti-pattern是magic-log。
有些开发人员为了自己查找信息方便，输出类似“&&&!#”的Log，而不是“Message with XYZ id received”。
最后，Log 不要涉及密码及个人信息（身份证、银行卡号etc）

• 关键业务系统日志的要求

  • 用户浏览日志
    使用WEB服务器或应用服务器实现日志输出，关键信息包括：访问时间、用户IP、访问的URL、用户浏览器信息、HTTP状态码、请求处理时间

  • 用户登录日志
    用于记录用户的Login、Logout、CheckLogin请求情况，关键信息如下：
    Login：请求时间、用户IP、用户名、渠道信息、用户浏览器信息、登录处理结果、请求花费时间、tokenId、sessionid
Logout：请求时间、用户IP、用户名、渠道信息、用户浏览器信息、登出结果、请求花费时间、tokenid、sessionid
CheckLogin：请求时间、用户IP、用户名、渠道信息、用户浏览器信息、检查结果、检查花费时间、tokenid、sessionId

  • 服务接口调用日志
    所有外部接口的调用需要记录接口访问信息，关键信息如下：
    请求时间、接口URL、接口方法、调用结果、执行时间

---

配置规范

• 统一使用log4j.xml、log4j2.xml、logback配置。

• 所有的jar包中不推荐包含log4j.xml、log4j.properties、logback.xml文件，避免干扰实际的业务系统。

• 注意Logger间的继承关系，如：

  • log4j的继承是通过命名来实现的。
  • 子logger会默认继承父logger的appender，将它们加入到自己的Appender中；除非加上了additivity="false"，则不再继承父logger的appender。
  • 子logger只在自己未定义输出级别的情况下，才会继承父logger的输出级别。

• Log文件位置和命名，目前Log文件的位置统一放在相同目录下面，Log名字通常以业务名开头，如xxx.log.2015-11-19等。

• 日志格式：必选打印数据项: 发生时间、日志级别、日志内容,可选文件和行号。

• 远程日志的输出需要注意host和port，区分cagegory。

---

参考

• SLF4J ：http://www.slf4j.org/docs.html
• Log4j：http://logging.apache.org/
• Log4j2：http://logging.apache.org/log4j/2.x/