Java 日志管理最佳实践

概述

对于如今的应用程序来讲，日志的重要性是不言而喻的。很难想象没有任何日志记录功能的应用程序运行在生产环境中。日志所能提供的功能是多种多样的，包括记录程序运行时产生的错误信息、状态信息、调试信息和执行时间信息等。在生产环境中，日志是查找问题来源的重要依据。应用程序运行时的产生的各类信息，都应该经过日志 API 来进行记录。不少开发人员习惯于使用 System.out.println、System.err.println 以及异常对象的 printStrackTrace 方法来输出相关信息。这些使用方式虽然简便，可是所产生的信息在出现问题时并不能提供有效的帮助。这些使用方式都应该改成使用日志 API。使用日志 API 并无增长不少复杂度，可是所提供的好处是显著的。

尽管记录日志是应用开发中并不可少的功能，在 JDK 的最第一版本中并不包含日志记录相关的 API 和实现。相关的 API（java.util.logging 包，JUL）和实现，直到 JDK 1.4 才被加入。所以在日志记录这一个领域，社区贡献了不少开源的实现。其中比较流行的包括 log4j 及其后继者 logback。除了真正的日志记录实现以外，还有一类与日志记录相关的封装 API，如 Apache Commons Logging 和 SLF4J。这类库的做用是在日志记录实现的基础上提供一个封装的 API 层次，对日志记录 API 的使用者提供一个统一的接口，使得能够自由切换不一样的日志记录实现。好比从 JDK 的默认日志记录实现 JUL 切换到 log4j。这类封装 API 库在框架的实现中比较经常使用，由于须要考虑到框架使用者的不一样需求。在实际的项目开发中则使用得比较少，由于不多有项目会在开发中切换不一样的日志记录实现。本文对于这两类库都会进行具体的介绍。

记录日志只是有效地利用日志的第一步，更重要的是如何对程序运行时产生的日志进行处理和分析。典型的情景包括当日志中包含知足特定条件的记录时，触发相应的通知机制，好比邮件或短信通知；还能够在程序运行出现错误时，快速地定位潜在的问题源。这样的处理和分析的能力对于实际系统的维护尤为重要。当运行系统中包含的组件过多时，日志对于错误的诊断就显得格外重要。

本文首先介绍关于日志 API 的基本内容。

Java 日志 API

从功能上来讲，日志 API 自己所需求的功能很是简单，只须要可以记录一段文本便可。API 的使用者在须要进行记录时，根据当前的上下文信息构造出相应的文本信息，调用 API 完成记录。通常来讲，日志 API 由下面几个部分组成：

• 记录器（Logger）：日志 API 的使用者经过记录器来发出日志记录请求，并提供日志的内容。在记录日志时，须要指定日志的严重性级别。
• 格式化器（Formatter）：对记录器所记录的文本进行格式化，并添加额外的元数据。
• 处理器（Handler）：把通过格式化以后的日志记录输出到不一样的地方。常见的日志输出目标包括控制台、文件和数据库等。

记录器

当程序中须要记录日志时，首先须要获取一个日志记录器对象。通常的日志记录 API 都提供相应的工厂方法来建立记录器对象。每一个记录器对象都是有名称的。通常的作法是使用当前的 Java 类的名称或所在包的名称做为记录器对象的名称。记录器的名称一般是具备层次结构的，与 Java 包的层次结构相对应。好比 Java 类“com.myapp.web.IndexController”中使用的日志记录器的名称通常是“com.myapp.web.IndexController”或“com.myapp.web”。除了使用类名或包名以外，还能够根据日志记录所对应的功能来进行划分，从而选择不一样的名称。好比用“security”做为全部与安全相关的日志记录器的名称。这样的命名方式对于某些横切的功能比较实用。开发人员通常习惯于使用当前的类名做为日志记录器的名称，这样能够快速在日志记录中定位到产生日志的 Java 类。使用有意义的其余名称在不少状况下也是一个不错的选择。

在经过日志记录器对象记录日志时，须要指定日志的严重性级别。根据每一个记录器对象的不一样配置，低于某个级别的日志消息可能不会被记录下来。该级别是日志 API 的使用者根据日志记录中所包含的信息来自行决定的。不一样的日志记录 API 所定义的级别也不尽相同。日志记录封装 API 也会定义本身的级别并映射到底层实现中相对应的实际级别。好比 JDK 标准的日志 API 使用的级别包括 OFF、SEVERE、WARNING、INFO、CONFIG、FINE、FINER、FINEST 和 ALL 等，Log4j 使用的级别则包括 OFF、FATAL、ERROR、WARN、INFO、DEBUG、TRACE 和 ALL 等。通常状况下，使用得比较多的级别是 FATAL、ERROR、WARN、INFO、DEBUG 和 TRACE 等。这 6 个级别所对应的状况也有所不一样：

• FATAL：致使程序提早结束的严重错误。
• ERROR：运行时异常以及预期以外的错误。
• WARN：预期以外的运行时情况，不必定是错误的状况。
• INFO：运行时产生的事件。
• DEBUG：与程序运行时的流程相关的详细信息。
• TRACE：更加具体的详细信息。

在这 6 个级别中，以 ERROR、WARN、INFO 和 DEBUG 做为经常使用。

日志记录 API 的使用者经过记录器来记录日志消息。日志消息在记录下来以后只能以文本的形式保存。不过有的实现（如 Log4j）容许在记录日志时使用任何 Java 对象。非 String 类型的对象会被转换成 String 类型。因为日志记录一般在出现异常时使用，记录器在记录消息时能够把产生的异常（Throwable 类的对象）也记录下来。

每一个记录器对象都有一个运行时对应的严重性级别。该级别能够经过配置文件或代码的方式来进行设置。若是没有显式指定严重性级别，则会根据记录器名称的层次结构关系往上进行查找，直到找到一个设置了严重性级别的名称为止。好比名称为“com.myapp.web.IndexController”的记录器对象，若是没有显式指定其严重性级别，则会依次查找是否有为名称“com.myapp.web”、“com.myapp”和“com”指定的严重性级别。若是仍然没有找到，则使用根记录器配置的值。

经过记录器对象来记录日志时，只是发出一个日志记录请求。该请求是否会完成取决于请求和记录器对象的严重性级别。记录器使用者产生的低于记录器对象严重性级别的日志消息不会被记录下来。这样的记录请求会被忽略。除了基于严重性级别的过滤方式以外，日志记录框架还支持其余自定义的过滤方式。好比 JUL 能够经过实现 java.util.logging.Filter 接口的方式来进行过滤。Log4j 能够经过继承 org.apache.log4j.spi.Filter 类的方式来过滤。

格式化器

实际记录的日志中除了使用记录器对象时提供的消息以外，还包括一些元数据。这些元数据由日志记录框架来提供。经常使用的信息包括记录器的名称、时间戳、线程名等。格式化器用来肯定全部这些信息在日志记录中的展现方式。不一样的日志记录实现提供各自默认的格式化方式和自定义支持。

JUL 中经过继承 java.util.logging.Formatter 类来自定义格式化的方式，并提供了两个标准实现 SimpleFormatter 类和 XMLFormatter 类。清单 1 中给出了 JUL 中自定义格式化器的实现方式，只须要继承自 Formatter 类并实现 format 方法便可。参数 LogRecord 类的对象中包含了日志记录中的所有信息。

清单 1. JUL 中自定义格式化器的实现

public class CustomFormatter extends Formatter {
    public String format(LogRecord record) {
        return String.format("<%s> [%s] : %s", new Date(record.getMillis()), record.getLoggerName(), record.getMessage());
    }
}

清单 2. 在 JUL 配置文件中指定自定义的格式化器类

java.util.logging.ConsoleHandler.formatter = logging.jul.CustomFormatter

Log4j 在格式化器的实现上要简单一些，由 org.apache.log4j.PatternLayout 类来负责完成日志记录的格式化。在自定义时不须要建立新的 Java 类，而是经过配置文件指定所需的格式化模式。在格式化模式中，不一样的占位符表示不一样类型的信息。好比“%c”表示记录器的名称，“%d”表示日期，“%m”表示日志的消息文本，“%p”表示严重性级别，“%t”表示线程的名称。清单 3 给出了 Log4j 配置文件中日志记录的自定义方式。

清单 3. Log4j 中日志记录的自定义方式

log4j.appender.stdout.layout.ConversionPattern=%d{yyyy-MM-dd HH:mm:ss} [%p] %c - %m%n

日志处理器

日志记录通过格式化以后，由不一样的处理器来进行处理。不一样的处理器有各自不一样的处理方式。好比控制台处理器会把日志输出到控制台中，文件处理器把日志写入到文件中。除了这些以外，还有写入到数据库、经过邮件发送、写入到 JMS 队列等各类不一样的处理方式。

日志处理器也能够配置所处理日志信息的最低严重性级别。低于该级别的日志不会被处理。这样能够控制所处理的日志记录数量。好比控制台处理器的级别通常设置为 INFO，而文件处理器则通常设置为 DEBUG。

日志记录框架通常提供了比较多的日志处理器实现。开发人员也能够建立自定义的实现。

Java 日志封装 API

除了 JUL 和 log4j 这样的日志记录库以外，还有一类库用来封装不一样的日志记录库。这样的封装库中一开始以 Apache Commons Logging 框架最为流行，如今比较流行的是 SLF4J。这样封装库的 API 都比较简单，只是在日志记录库的 API 基础上作了一层简单的封装，屏蔽不一样实现之间的区别。因为日志记录实现所提供的 API 大体上比较类似，封装库的做用更多的是达到语法上的一致性。

在 Apache Commons Logging 库中，核心的 API 是 org.apache.commons.logging.LogFactory 类和 org.apache.commons.logging.Log 接口。LogFactory 类提供了工厂方法用来建立 Log 接口的实现对象。好比 LogFactory.getLog 能够根据 Java 类或名称来建立 Log 接口的实现对象。Log 接口中为 6 个不一样的严重性级别分别定义了一组方法。好比对 DEBUG 级别，定义了 isDebugEnabled()、debug(Object message) 和 debug(Object message, Throwable t) 三个方法。从这个层次来讲，Log 接口简化了对于日志记录器的使用。

SLF4J 库的使用方式与 Apache Commons Logging 库比较相似。SLF4J 库中核心的 API 是提供工厂方法的 org.slf4j.LoggerFactory 类和记录日志的 org.slf4j.Logger 接口。经过 LoggerFactory 类的 getLogger 方法来获取日志记录器对象。与 Apache Commons Logging 库中的 Log 接口相似，Logger 接口中的方法也是按照不一样的严重性级别来进行分组的。Logger 接口中有一样 isDebugEnabled 方法。不过 Logger 接口中发出日志记录请求的 debug 等方法使用 String 类型来表示消息，同时可使用包含参数的消息，如清单 4 所示。

清单 4. SLF4J 的使用方式

public class Slf4jBasic { 
    private static final Logger LOGGER = LoggerFactory.getLogger(Slf4jBasic.class); 
    public void logBasic() { 
        if (LOGGER.isInfoEnabled()) { 
            LOGGER.info("My log message for %s", "Alex"); 
        } 
    } 
 }

MDC

MDC（Mapped Diagnostic Context，映射调试上下文）是 log4j 和 logback 提供的一种方便在多线程条件下记录日志的功能。某些应用程序采用多线程的方式来处理多个用户的请求。在一个用户的使用过程当中，可能有多个不一样的线程来进行处理。典型的例子是 Web 应用服务器。当用户访问某个页面时，应用服务器可能会建立一个新的线程来处理该请求，也可能从线程池中复用已有的线程。在一个用户的会话存续期间，可能有多个线程处理过该用户的请求。这使得比较难以区分不一样用户所对应的日志。当须要追踪某个用户在系统中的相关日志记录时，就会变得很麻烦。

一种解决的办法是采用自定义的日志格式，把用户的信息采用某种方式编码在日志记录中。这种方式的问题在于要求在每一个使用日志记录器的类中，均可以访问到用户相关的信息。这样才可能在记录日志时使用。这样的条件一般是比较难以知足的。MDC 的做用是解决这个问题。

MDC 能够当作是一个与当前线程绑定的哈希表，能够往其中添加键值对。MDC 中包含的内容能够被同一线程中执行的代码所访问。当前线程的子线程会继承其父线程中的 MDC 的内容。当须要记录日志时，只须要从 MDC 中获取所需的信息便可。MDC 的内容则由程序在适当的时候保存进去。对于一个 Web 应用来讲，一般是在请求被处理的最开始保存这些数据。清单 5 中给出了 MDC 的使用示例。

清单 5. MDC 使用示例

public class MdcSample { 
    private static final Logger LOGGER = Logger.getLogger("mdc"); 
    public void log() { 
        MDC.put("username", "Alex"); 
        if (LOGGER.isInfoEnabled()) { 
            LOGGER.info("This is a message."); 
        } 
    } 
 }

清单 5 中，在记录日志前，首先在 MDC 中保存了名称为“username”的数据。其中包含的数据能够在格式化日志记录时直接引用，如清单 6 所示，“%X{username}”表示引用 MDC 中“username”的值。

清单 6. 使用 MDC 中记录的数据

log4j.appender.stdout.layout.ConversionPattern=%X{username} %d{yyyy-MM-dd HH:mm:ss} [%p] %c - %m%n

日志记录最佳实践

下面主要介绍一些在记录日志时的比较好的实践。

检查日志是否能够被记录

当日志记录器收到一个日志记录请求时，若是请求的严重性级别低于记录器对象的实际有效级别，则该请求会被忽略。在日志记录方法的实现中会首先进行这样的检查。不过推荐的作法是在调用 API 进行记录以前，首先进行相应的检查，这样能够避免没必要要的性能问题，如清单 7 所示。

清单 7. 检查日志是否能够被记录

if (LOGGER.isDebugEnabled()) { 
    LOGGER.debug("This is a message."); 
 }

清单 7 中的作法的做用在于避免了构造日志记录消息所带来的开销。日志消息中一般包含与当前上下文相关的信息。为了获取这些信息并构造相应的消息文本，不可避免会产生额外的开销。尤为对于 DEBUG 和 TRACE 级别的日志消息来讲，它们所出现的频率很高，累加起来的开销比较大。所以在记录 INFO、DEBUG 和 TRACE 级别的日志时，首先进行相应的检查是一个好的实践。而 WARN 及其以上级别的日志则通常不须要进行检查。

日志中包含充分的信息

日志中所包含的信息应该是充分的。在记录日志消息时应该尽量多的包含当前上下文中的各类信息，以方便在遇到问题时能够快速的获取到所需的信息。好比在网上支付功能中，与支付相关的日志应该完整的包含当前用户、订单以及支付方式等所有信息。一种比较常见的作法是把相关的日志记录分散在由不一样日志记录器所记录的日志中。当出现问题以后，须要手工查找并匹配相关的日志来定位问题，所花费的时间和精力会更多。所以，应该尽量在一条日志记录中包含足够多的信息。

使用合适的日志记录器名称

通常的日志记录实践是使用当前 Java 类的全名做为其使用的日志记录器的名称。这样作能够获得一个与 Java 类和包的层次结构相对应的日志记录器的层次结构。能够很方便的按照不一样的模块来设置相应的日志记录级别。不过对于某些全局的或是横切的功能，如安全和性能等，则推荐使用功能相关的名称。好比程序中可能包含用来提供性能剖析信息的日志记录。对于这样的日志记录，应该使用同一名称的日志记录器，如相似“performance”或“performance.web”。这样当须要启用和禁用性能剖析时，只须要配置这些名称的记录器便可。

使用半结构化的日志消息

在介绍日志记录 API 中的格式化器时提到过，日志记录中除了基本的日志消息以外，还包括由日志框架提供的其余元数据。这些数据按照给定的格式出如今日志记录中。这些半结构化的格式使得能够经过工具提取日志记录中的相关信息进行分析。在使用日志 API 进行记录时，对于日志消息自己，也推荐使用半结构化的方式来组织。

好比一个电子商务的网站，当用户登陆以后，该用户所产生的不一样操做所对应的日志记录中均可以包含该用户的用户名，并以固定的格式出如今日志记录中，如清单 8 所示。

清单 8. 使用半结构化的日志消息

[user1] 用户登陆成功。
 [user1] 用户成功购买产品 A。
 [user2] 订单 003 付款失败。

当须要经过日志记录来排查某个用户所遇到的问题时，只须要经过正则表达就能够很快地查询到用户相关的日志记录。

日志聚合与分析

在程序中正确的地方输出合适的日志消息，只是合理使用日志的第一步。日志记录的真正做用在于当有问题发生时，可以帮助开发人员很快的定位问题所在。不过一个实用的系统一般由不少个不一样的部分组成。这其中包括所开发的程序自己，也包括所依赖的第三方应用程序。以一个典型的电子商务网站为例，除了程序自己，还包括所依赖的底层操做系统、应用服务器、数据库、HTTP 服务器和代理服务器和缓存等。当一个问题发生时，真正的缘由可能来自程序自己，也可能来自所依赖的第三方程序。这就意味着开发人员可能须要检查不一样服务器上不一样应用程序的日志来肯定真正的缘由。

日志聚合的做用就在于能够把来自不一样服务器上不一样应用程序产生的日志聚合起来，存放在单一的服务器上，方便进行搜索和分析。在日志聚合方面，已经有很多成熟的开源软件能够很好的知足需求。本文中要介绍的是 logstash，一个流行的事件和日志管理开源软件。logstash 采用了一种简单的处理模式：输入 -> 过滤器 -> 输出。logstash 能够做为代理程序安装到每台须要收集日志的机器上。logstash 提供了很是多的插件来处理不一样类型的数据输入。典型的包括控制台、文件和 syslog 等；对于输入的数据，可使用过滤器来进行处理。典型的处理方式是把日志消息转换成结构化的字段；过滤以后的结果能够被输出到不一样的目的地，好比 ElasticSearch、文件、电子邮件和数据库等。

Logstash 在使用起来很简单。从官方网站下载 jar 包并运行便可。在运行时须要指定一个配置文件。配置文件中定义了输入、过滤器和输出的相关配置。清单 9 给出了一个简单的 logstash 配置文件的示例。

清单 9. logstash 配置文件示例

input { 
  file { 
    path => [ "/var/log/*.log", "/var/log/messages", "/var/log/syslog" ] 
    type => 'syslog'
  } 
 } 

 output { 
  stdout { 
 debug => true 
 debug_format => "json" 
  } 
 }

清单 9 中定义了 logstash 收集日志时的输入（input）和输出（output）的相关配置。输入类型是文件（file）。每种类型输入都有相应的配置。对于文件来讲，须要配置的是文件的路径。对每种类型的输入，都须要指定一个类型（type）。该类型用来区分来自不一样输入的记录。代码中使用的输出是控制台。配置文件完成以后，经过“java -jar logstash-1.1.13-flatjar.jar agent -f logstash-simple.conf”就能够启动 logstash。

在日志分析中，比较重要的是结构化的信息。而日志信息一般只是一段文本，其中的不一样字段表示不一样的含义。不一样的应用程序产生的日志的格式并不相同。在分析时须要关注的是其中包含的不一样字段。好比 Apache 服务器会产生与用户访问请求相关的日志。在日志中包含了访问者的各类信息，包括 IP 地址、时间、HTTP 状态码、响应内容的长度和 User Agent 字符串等信息。在 logstash 收集到日志信息以后，能够根据必定的规则把日志信息中包含的数据提取出来并命名。logstash 提供了 grok 插件能够完成这样的功能。grok 基于正则表达式来工做，同时提供了很是多的经常使用类型数据的提取模式，如清单 10 所示。

清单 10. 使用 grok 提取日志记录中的内容

//Apache 访问日志
49.50.214.136 GET /index.html 200 1150 "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.17 (KHTML, like Gecko) Chrome/24.0.1312.57 Safari/537.17"
 
//grok 提取模式
%{IP:client} %{WORD:method} %{URIPATHPARAM:request} %{NUMBER:status} %{NUMBER:bytes} %{QS:useragent}

清单 10. 使用 grok 提取日志记录中的内容

//Apache 访问日志
 49.50.214.136 GET /index.html 200 1150 "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.17 (KHTML, like Gecko) Chrome/24.0.1312.57 Safari/537.17"

 //grok 提取模式
 %{IP:client} %{WORD:method} %{URIPATHPARAM:request} %{NUMBER:status} %{NUMBER:bytes} %{QS:useragent}

在通过上面 grok 插件的提取以后，Apache 访问日志被转换成包含字段 client、method、request、status、bytes 和 useragent 的格式化数据。能够根据这些字段来进行搜索。这对于分析问题和进行统计都是颇有帮助的。

当日志记录经过 logstash 进行收集和处理以后，一般会把这些日志记录保存到数据库中进行分析和处理。目前比较流行的方式是保存到 ElasticSearch 中，从而能够利用 ElasticSearch 提供的索引和搜索能力来分析日志。已经有很多的开源软件在 ElasticSearch 基础之上开发出相应的日志管理功能，能够很方便的进行搜索和分析。本文中介绍的是 Graylog2。

Graylog2 由服务器和 Web 界面两部分组成。服务器负责接收日志记录并保存到 ElasticSearch 之中。Web 界面则能够查看和搜索日志，并提供其余的辅助功能。logstash 提供了插件 gelf，能够把 logstash 收集和处理过的日志记录发送到 Graylog2 的服务器。这样就能够利用 Graylog2 的 Web 界面来进行查询和分析。只须要把清单 9 中的 logstash 的配置文件中的 output 部分改为清单 11 中所示便可。

清单 11. 配置 logstash 输出到 Graylog2

output { 
  gelf { 
    host => '127.0.0.1'
  } 
 }

在安装 Graylog2 时须要注意，必定要安装与 Graylog2 的版本相对应的版本的 ElasticSearch，不然会出现日志记录没法保存到 ElasticSearch 的问题。本文中使用的是 Graylog2 服务器 0.11.0 版本和 ElasticSearch 0.20.4 版本。

除了 Graylog2 以外，另一个开源软件 Kibana 也比较流行。Kibana 能够当作是 logstash 和 ElasticSearch 的 Web 界面。Kibana 提供了更加丰富的功能来显示和分析日志记录。与代码清单中的 logstash 的配置类似，只须要把输出改成 elasticsearch 就能够了。Kibana 能够自动读取 ElasticSearch 中包含的日志记录并显示。

小结

日 志记录是应用程序开发中的重要一环。不过这一环比较容易被开发人员忽视，由于它所产生的影响在程序运行和维护时。对于一个生产系统来讲，日志记录的重要性 是不言而喻的。本文首先以 java.util.logging 包和 log4j 为例介绍了 Java 日志 API 的主要组成部分和使用方式，同时也介绍了 Apache Commons Logging 和 SLF4J 两种日志封装 API。本文也给出了一些记录日志时应该采用的最佳实践。最后介绍了如何使用开源工具对日志进行聚合和分析。经过本文，开发人员能够了解如何在开发中有效 的使用日志。