12.7　日志

日志是让程序员爱恨交织的事情之一。每当有人问为什么某个程序运行这么糟时，我首先要做的就是拿到任何可用的日志，希望在应用生成的日志中找到线索，以了解应用的状况。而每当有人让我审查工作代码的性能时，我又会立即建议把所有的日志语句关掉。

日志有很多种。GC 会生成自己的日志语句（参见第 6 章）。日志可以定向到一个单独的文件中，其大小可以由 JVM 管理。即便在生产代码中，GC 日志（使用 -XX:+PrintGCDetails 标志开启）的开销也是非常低的，而当出现问题时，它们的好处非常大，所以 GC 日志应该一直打开。

Java EE 应用服务器会生成一个访问日志，每当有请求时都会更新。这类日志的影响通常比较明显：不管在应用服务器上运行的是何种测试，关闭这类日志可以明显改进性能。根据我的经验，从诊断角度看，当出现问题时这些日志的帮助不是很大。不过在业务需求方面，这类日志往往非常关键，此时必须开启。

很多应用服务器都支持 Apache 的 mod_log_config 标准，尽管它并非一个 Java EE 标准。它可以针对每个请求精确地指定想要记录的信息（不支持 mod_log_config 语法的服务器通常也会支持某种形式的定制）。这里的关键是，记录的信息应该尽可能少，同时仍要满足业务需求。日志的性能会受所写数据量的影响。

特别是在 HTTP 访问日志中（或者笼统地说，在任何种类的日志中），记录下所有的数字信息是个不错的主意：记录 IP 地址而不是主机名，记录时间戳（比如从 Unix 纪元到现在所经过的秒数）而不是字符串数据（比如“Monday, June 3, 2013 17:23:00 -0600”），诸如此类。尽量减少需要花时间和内存去计算的任何数据转换，以便使日志对系统的影响将至最低。转换后的数据总是可以通过对日志做后续处理来获得。

对于应用日志，需要记住 3 个基本原则。第一，协调好要打日志的数据和所选级别（Level）之间的关系。JDK 中有 7 个标准的日志级别，而且 Logger 实例一般默认配置为输出其中的 3 个级别（INFO 及更高级别）。在项目中，这往往会导致混淆：INFO 级别听上去好像应该非常常见，而且应该提供与应用流程相关的描述（“现在正在处理 A 任务”，“现在正在做 B 任务”，等等）。特别是对于存在大量线程的可扩展应用（包括 Java EE 应用服务器）而言，这类日志多了会给性能带来不利影响（更不用说太多没什么用的日志信息带来的风险了）。要学会使用更低级别的日志语句。

类似地，当把代码签入到组库中时，应该考虑的是项目使用者的需求，而不是我们作为开发者的需求。在将自己的代码集成到一个更大的系统中之后，这些代码运行状况如何呢？我们都希望获得与此相关的大量积极反馈，另外还会运行一连串的测试。但如果消息对最终用户或系统管理员没什么意义，那默认开启这些日志就没什么帮助。它们的“作用”不过是拖慢了系统（还会让最终用户迷惑不解）。

第二个原则是使用细粒度的 Logger 实例。对每个类的 Logger 实例进行配置可能会很繁琐，但这么做是值得的，因为能够更好地控制日志输出。在一个较小的模块中，让一组类共享一个 Logger 实例，是个不错的折中办法。要记住的关键一点是，如果生产环境变化很大，有些问题（特别是那些在高负载情况下出现的问题，或者是其他与性能有关的问题）很难重现。打开太多日志往往会改变环境，导致原来的问题不再复现。

因此，我们必须能够做到仅打开一小组代码的日志（至少最初能控制一小组 FINE 级别的日志语句，然后是控制更多 FINER 和 FINEST 级别的），这样就不会影响代码的性能了。

在这两个原则之间，应该能够支持在生产环境中生成信息的小子集，前提是不影响系统性能。无论如何这都是应该考虑的，原因在于：如果日志会让生产系统变慢，其管理员很可能不会开启日志；在这种情况下，如果系统确实变慢了，重现问题的可能性也小了。

第三个原则是，在向代码引入日志时，应该注意，很容易编写出带来意想不到的副作用的日志代码，即使这个日志并没有开启。这是可以说明“过早的优化”很不错的又一种情况：如第 1 章的例子所示，每当要打日志的信息包含方法调用、字符串连接或者其他任何形式的资源分配（比如为 MessageFormat 参数分配一个 Object 数组）时，记得使用 isLoggable() 方法。

　快速小结

1. 为帮助用户找出问题，代码应该包含大量日志，但是这些日志默认都应该是关闭的。

2. 如果 Logger 实例的参数需要调用方法或者分配对象，那么在调用该实例之前，不要忘了测试日志级别。