[TOC]
1. 使用合适的工具
有些程序员似乎忘记日志中记录应用程序的行为和它的当前状态是多么的重要。比如这样记录：
log.info("Happy and carefree logging");//快乐而无脑的打印日志
写在代码里非常开心，但他可能没有意识到应用程序的日志在运维，调优，故障定位中的重要性。低估好日志的价值是可怕的错误。
以笔者来看，SFL4J是可用的日志API中最好的，主要是因为支持一个好模式。
log.debug("Found {} records matching filter: '{}'", records, filter);
在Log4j中你只能这样用
log.debug("Found " + records + " records matching filter: '" + filter + "'");
这样不只是更长且较低的可读性，而且低效率，因为额外的字符串拼接操作。SLF4J增加了一个漂亮的{}子句特性。而且，当日志语句被过滤时，避免了字符串的拼接和不需调用toString()，不再需要isDebugEnabled()。另外，你注意到那个字符串参数外的单引号了吗?
译者注：第一个参数是数字，不需要加引号；第二个参数是字符串，加引号可以明确其中的空格，避免值的模糊性。
SLF4J仅是一个门面。做一个应用我推荐Logback框架，同样建议的，而不是更加知名的Log4J。 它有很多有趣的特性，并且相较于Log4J，它是积极在开发中。
最新的工具推荐Perf4J。它们的格言是：
Per4J是System.currentTimeMillis() 而Log4J是 System.out.println()
我曾经将Per4J加入一个已有应用，有大负载并且在实际中观察它。包括管理员和业务用户都被这个简单程序的漂亮图示所打动。同时，我们也能够及时发现性能缺陷。Perf4J有自身的文档，但是看他们的开发指南就可以了。
另外，请注意 Ceki Gülcü （ Log4J, SLF4J and Logback 项目的创建者）建议采用一个简单的方案来消除对 commons-logging的依赖。
2. 不要忘记，日志等级是可以为你所用的。
每次当你写下一个日志语句，你认真思考对这个事件应当选择哪种日志等级，是吗？基本上90%程序员从不注意日志等级，简单地把所有事件记录在同一等级，如INFO或DEBUG。为什么？日志框架相对于系统输出有两个主要好处，即类别（categories）和级别（level）。两者都允许您选择性地永久过滤日志记录语句，或者只在诊断期间。如果你不能看到区别，请打印下面这个表格，每次在ide打出"log.""时，检查一下它。
- ERROR - 一些可怕的错误发生了，这必须立即检查。任何系统都不能容忍此级别的日志。 例如：NPE，数据库不可用，关键用例无法继续。
- WARN - 程序可以继续下去，但应当格外注意。实际上，我总是想在这里有两个层级：
- 一个是明显的问题，但有补救方案（如：当前数据不可以用，使用缓存的值），
- 另一个是 ATTENTION 对优化问题或建议。如：应用是在开发模式运行，或管理员控制台没有密码。应用可以容忍warning消息，但它们应当是合理的并验证。
- INFO - 重要的业务步骤已经完成。在现实世界里，管理员或高级用户需要能理解 info消息，并快速的定位应用程序在做什么。如：如果应用程序是订购机票，每次订购时，应当只有一个info语句，记录 [Who] booked ticket from [Where] to [Where]。 其它info消息，明确改变应用状态的每个操作（数据更新，外部系统请求）
- DEBUG - 开发者的东西。我将在后面讨论哪类信息应当记录。
- TRACE - 非常细节的信息，只是为开发服务。你可以在开发后发布到生产环境后短期内跟踪消息，但这些日志是暂时的，最后应当被关闭。debug和trace是非常难区分的，但是如果你记录日志，并在某个特性完成开发和测试后移除它，它就应当是trace级。
上面的列表只是一种建议，你可以创建自己的方案去执行，但是总是应当有些规则。我的经验是，经常是所有的东西都记到日志里了，但是没有过滤（至少对应用代码来说），但是有能力快速地过滤日志，并且从正确的详细程度提炼信息，可能是救命稻草。
最后一件值得一提的事是，著名的is*Enabled()条件，有人把它写在每一个打印日志语句前面：
if(log.isDebugEnabled())
log.debug("Place for your commercial");
笔者认为这个短语只会带来混乱，应当避免使用。性能的提升（特别是当使用前面讨论过的SLF4J模式时），看起来与主题无关，而且像是过度优化。同时，你能指出重复吗？当这个显式条件被判断时，我们极少情况下，可以证明构造日志消息是昂贵的。在其它情况下，你只要打印日志，让日志框架来做过滤的工作。
3 你知道你在记录什么内容吗？
每次你执行一条打印日志语句，花一点时间，检查一下将打印进你的日志里的内容。阅读你的日志，并且指出难看的语句。首先，避免象这样的NPE
log.debug("Processing request with id: {}", request.getId());
你确认这个请求不是null吗？
另一个陷阱是打印集合。如果你使用Hibernate从数据库域对象中取得集合，并且不仔细校验就象这样打印日志：
log.debug("Returning users: {}", users);
SLF4J 只会在语句实际打印时，调用toString()，这样非常好。但是，如果它是内存溢出异常，N+1 select 问题，线程饥饿（打印日志是同步的！），懒汉初始化异常，日志存储空间被填满，这些都可能会发生。
这里是更好的打印日志方法，例如，只是域对象的id（或只是集合的大小）。但是在java中，从一个含有getId()方法的对象集合制作一个id的集合，非常麻烦并且繁琐。Groovy有一个非常快速的操作符(users*.id),在java中，我们可以使用通用对象Commons Beanutils库模仿它。
log.debug("Returning user ids: {}", collect(users, "id"));
这里的collect()方法可以这样实现：
public static Collection collect(Collection collection, String propertyName) {
return CollectionUtils.collect(collection, new BeanToPropertyValueTransformer(propertyName));
}
最后一个值得注意的事，不当的实现或使用toString()。
- 首先，为每个可能出现在打印日志语句中的类创建toString()，更好的应用ToStringBuilder(但是它不是可以反射的副本)，
- 其次，检查 arrays 和 非典型的collection。Arrays和一些少见的collections不具有toString()实现，对它们的每一个项调用toString()。使用jdk集成的方法Arrays.deepToString()。
- 然后，经常阅读你的日志找出没有正确格式化的消息。
4 避免副作用
日志打印语句应当没有或很少影响应用程序的行为。最近我的一个朋友给我提供了一个例子，一个系统抛出Hibernate的LazyInitializaionException,仅在某些特定的运行环境里。就如你根据前文猜到的那样，有些打印日志语句会引起懒汉式初始化集合的加载，当session被加载时。在这个环境里，打印日志的级别level被提升，并且集合不再被初始化。如果你没掌握前文所提示的内容，想想这样要花你多少时间找出这个bug.
另一种影响是降低系统运行速度。快速回复：如果你打印日志过多，或者不正确的使用toString()和（或）字符串连接，打印日志会造成性能影响。有多大呢？好吧，我曾经见过服务器第15分钟重启一次，因为过多的打印日志导致一个线程饥饿。现在这是一种副作用！以笔者的经验，日志每小时存入磁盘几百MiB是合适的上限。
当然，如果打印日志语句本身错误或引起业务流程被异常中断，这也是一个大副作用。笔者见过这样一种结构来避免这些：
try {
log.trace("Id=" + request.getUser().getId() + " accesses " + manager.getPage().getUrl().toString())
} catch(NullPointerException e) {}
这是一个实用代码，但是请使这个世界成为一个有一点美好的地方，不要这样做。永远。
5 简明扼要
- 每个打印日志语句应当包含数据和描述。请考虑以下例子：
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");
在警告文字中，写明实际的type,messagid等内容非常困难吗？我知道有些问题，但是什么呢？什么时上下文？
- 第三种坏模式是，“魔法日志”。实际生活的例子：大多数程序员在一个团队里，知道3个&后面跟着感叹号，跟着hash,跟着伪随机字母数字串日志，如： “Message with XYZ id received”。没人费心去改变日志，只是有人按下键盘，并选择一些特别的“&&&!#”串，这样它可以被容易的找到。
做为结果，整个日志文件看来象是一些随机生成的字符串。有人甚至认为这些文件是一个有效的perl程序。但是，日志文件应当具有可阅读性，整洁的和有描述意义的。不要使用魔法值，日志变量，数字，ids和它们的上下文。展示数据被处理的过程，并显示它们的含义。展示程序实际上如何工作的。好的日志可以成为程序代码的最好说明文档。
我提到过，不要在日志里记录密码和任何个人信息。不要！
6调整你的格式
日志格式是一个非常棒的工具，可以在你的每个日志语句里添加有意义的上下文。但是你必须非常仔细地考虑，哪些信息包括在你的模式里。 例如，当你的日志每小时滚动时，记录日期是没有意义的，因为日期已经包含在文件名里了。与些相反，没有记录线程名，你将无法使用日志追踪任何过程，当两个线程都在工作时，这些日志会重叠。这在单线程应用中不是问题，但是现在基本不存在那种应用了。
依笔者的经验，理想的日志记录格式应当包括（引起异常自动记录消息）：当前时间（没有日期，毫秒级精度），日志等级level，线程名，简单的日志记录者名称（不是完整的路径）和消息。在Logback里，它是这样的：
<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
<encoder>
<pattern>%d{HH:mm:ss.SSS} %-5level [%thread][%logger{0}] %m%n</pattern>
</encoder>
</appender>
你永远也不用包含文件名，类名和行号，虽然它是非常吸引人的。我见过在代码里空的日志语句：
log.info("");
因为程序员假设行号将是日志格式的一部分，他认为，“如果空的日志语句出现在文件的67行（在authenticated()方法里），这意味着用户通过验证了。”。
然而，记录类名，方法名和或行号是严重的性能障碍。
一种更加高级的日志框架特性是定位诊断上下文Mapped Diagnostic Context。MDC简单的定位管理在本地线程基础上。你可以放任何关键字和值对在这些map里，并且每个日志语句在这个线程里执行时会将这些值 放入模式中。
7 日志记录方法参数和返回值
当你在开发中发现一个bug，你一般会运行debugger来跟踪到实际的原因。现在，假设过了一段时间，你不能使用dubugger。例如，由于bug几天后在客户的环境里发生了，而你只能得到日志。你能够找到问题吗？
如果你简单执行的记录每个方法和输出（参数和返回值），你不再需要debugger。当然，你必须有逻辑的，但是每个方法必须被 注意到，如：访问外部系统（包括数据库），块，等待等等。只要参照这个模式。
public String printDocument(Document doc, Mode mode) {
log.debug("Entering printDocument(doc={}, mode={})", doc, mode);
String id = //Lengthy printing operation
log.debug("Leaving printDocument(): {}", id);
return id;
}
因为你不仅记录开始也记录方法的结束，你可以手工的查找有影响的代码，甚至分析可能的块区和饥饿原因 - 只要看看entering后，而没有相应的leaving。如果你的方法有具有含义的名字，阅读日志将是愉快的。同时，分析出什么导致错误是非常容易的，因为每个你了解的步骤都被处理了。你甚至可以使用一个简单的AOP体，记录你的代码里广大范围的方法。这些降低代码冗余度，但是小心，因为它可以导致巨大数量的大型日志。
你需要把DEBUG和TRACE级别，做为最适合这类日志。并且，如果你发现有些方法被过于频繁调用，记录日志有害于性能，只要降低这些类的日志级别level，或者彻底移除日志（可能对整个方法调用只保留一条？）。但是通常来说过多总是比过少日志要好一些。要象对待单元测试一样对待日志打印语句- 你的代码应当象被单元测试覆盖一样被日志例程覆盖。没有系统的任何部分可以没有日志。记住，有时观察日志在滚动，是唯一手段可以说明你的程序是否正常工作中或者已经挂掉。
8 监视外部系统
这里是前面事项的特例：如果你与外部系统通信，应当考虑为每一段从你的系统输出和输入你的系统数据打印日志。曾经，集成是困难的工作，并且在两个系统之间诊断问题（两家供应商，环境，技术栈和团队）是特别难。最近，例如，我们已对对全部消息内容打印日志，包含SOAP HTTP头部在apache CXF web services，在集成和系统测试中是非常有用的。
这是一项巨大成本，而且如果性能是问题，你可经常关闭打印日志。但是，什么是关键点呢，拥有一个快速但是坏掉的应用，没人能够修复它？在集成外部系统时要特别小心，准备好支付这些成本。如果你是幸运的，而且，所有你的集成都是通过ESB，那么总线是合适的最佳地点，用来对每一个进入的请求和响应打印日志。看看，例如Mule的日志模块。
有时候与外部系统交互的信息数量，使得它看来无法对所有东西打印日志。在另一方面，在测试中和短暂的生产期间（例如当有些问题发生时），我们希望在日志里的所有记录，并且，准备好支付性能代价。这可以通过仔细地使用日志级别来归档。请看一下下面的短语：
Collection<Integer> requestIds = //...
if(log.isDebugEnabled())
log.debug("Processing ids: {}", requestIds);
else
log.info("Processing ids size: {}", requestIds.size());
如果特定的日志记录器被配置成打印debug日志消息，它将会打印整个requestIds集合的内容。但是如果它是配置成打印info日志消息，只打印集合的数量。如果你疑惑为什么我忘记isInfoEnabled()条件，请回到 #2。有一点需要提醒的是requestIds集合此时不能是null。虽然，它可以正确的记录日志的，在debug状态下null是可以正确打印的，但是如果配置成INFO时，会抛出一个大大的NullPointException.记得我在第4段副作用中的内容吗？
9 正确的打印异常日志
首先，应当避免打印异常，让你的框架或者容器（不管它是什么）来为你处理。在这条规则下有一个例外：如果你从某些远程服务抛出异常（如RMI,EJB远程会话对象，等等），那是一个可以序列化的异常，确保所有的异常对客户端是可用的（是api的一部分）。否则客户端将会收到NoClassDefFoundError: somefancyException 而不是真正的错误。
打印异常是所有打印日志中最重要的一项，但是很多程序员倾向于把打印日志看成一种处理异常的途径。他们有时返回默认值（典型的 null,0或空串），假装什么也没发生。其它时候他们首先把异常打印日志，然后封装它并抛出来。
log.error("IO exception", e);
throw new MyCustomException(e);
这种结构会在大部分时候打印相同的栈内容两次，因为某些地方会最终捕获MyCustomException，并且打印它的原因。打印日志，或者封装后抛出（这样更加可取），永远不要同时做两件，否则你的日志会被搞乱。
但是，如果你确实想在日志打印异常？由于某种原因（因为我们不想读apis和文档？），我认为大约半数日志语句是错误的。快速回答，下面哪个日志语句会正确记录npe?
try {
Integer x = null;
++x;
} catch (Exception e) {
log.error(e); //A
log.error(e, e); //B
log.error("" + e); //C
log.error(e.toString()); //D
log.error(e.getMessage()); //E
log.error(null, e); //F
log.error("", e); //G 正确的！
log.error("{}", e); //H
log.error("{}", e.getMessage()); //I
log.error("Error reading configuration file: " + e); //J
log.error("Error reading configuration file: " + e.getMessage()); //K
log.error("Error reading configuration file", e); //L 相对较好
}
令人惊奇的是，只有G和相对较好的L是正确的！A 和B 甚至在slf4j下不能正确编译，其它的抛弃堆栈跟踪信息，并且/或者打印了不正确的消息。例如，E不会打印任何内容，因为NPE通常不能提供任何异常消息，并且堆栈不能正确打印。记住，第一重要是文本消息，写下任何关于问题本质的内容。不要包含异常消息，因为它会在日志语句后自动记录，如前述的堆栈跟踪。但是为了做这件事，你必须将异常本身作为第二参数传递。
10 易读易查的日志
有两组接收者会对你的程序日志感兴趣：人类（你可能不同意，但是程序员也属于这组）和计算机（典型的是系统管理员编写的shell脚本）。日志应当同时适合这两组人群。如果有人从你的背后观察应用日志时发现（源自wikipedia）： 你可能没有遵守我的这些建议。日志应当具备可读性，并且就象代码一样易理解。
另一方面，如果你的应用程序每小时产生0.5GB日志，没有人和图形文本编辑器可以完整地阅读它们。这是老派grep、sed和awk派上用场的地方。如果有可能，尽量在写日志语句时，让它们可以既被人和机器阅读，例如，避免数字的格式化，使用可以被正则表达式容易识别的模式，等等。如果不可能，就用两种格式打印数据。
log.debug("Request TTL set to: {} ({})", new Date(ttl), ttl);
// Request TTL set to: Wed Apr 28 20:14:12 CEST 2010 (1272478452437)
final String duration = DurationFormatUtils.formatDurationWords(durationMillis, true, true);
log.info("Importing took: {}ms ({})", durationMillis, duration);
//Importing took: 123456789ms (1 day 10 hours 17 minutes 36 seconds)
计算机可以识别“ms after 1970 epoch” 时间格式，而人们可以清楚看到“1 day 10 hours 17 minutes 36 seconds”。顺便提一下，看一看DurationFormatUtils，很棒的工具。
这些朋友，我们的JCP合作者中的“日志要点极客”，Tomasz Nurkiewicz。不要忘记分享。
