工欲善其事,必先利其器
很多程序员可能都忘了记录应用程序的行为是一件多么重要的事,当遇到多线程环境下高压力导致的并发bug时,你就能体会到记录log的重要性。
有的人很高兴的就在代码里加上了这么句:
log.info("Happy and carefree logging");
他可能都没有意识到应用程序的日志在维护,调优和故障识别中的重要性。
我认为slf4j是非常好的日志API,主要是因为它支持一个很棒的模式注入的方式:
log.debug("Found {} records matching filter: '{}'", records, filter);
log4j的话你只能这样:
log.debug("Found " + records + " recordsmatching filter: '" + filter + "'");
这样写不仅更啰嗦和可读性差,而且字符串拼接影响效率(当这个级别并不需要输出的时候)。
slf4j引入了{}注入特性,并且由于避免了每次都进行字符串拼接,toString方法不会被调用,也不再需要加上isDebugEnabled了。
slf4j是外观模式的一种应用,它只是一个门面。具体实现的话我推荐logback框架,之前已经做过一次广告了,而不是已经很完备的log4j。它有许多很有意思的特性,和log4j不同的是,它还在积极的开发完善中。
还有一个要推荐的工具是perf4j:
Perf4J is to System.currentTimeMillis() as log4j is to System.out.println()
就好比log4j是System.out.println的一种更好的替换方式一样,perf4j更像是System.currentTimeMillis()的替代。
我已经在一个项目中引入了perf4j,并在高负载的情况下观察它的表现。管理员和企业用户都被这个小工具提供的漂亮的图表惊呆了。
我们可以随时查看性能问题。perf4j应该专门开一篇文章来讲,现在的话可以先看下它的开发者指南。
还有一个Ceki Gülcü(log4j,slf4j和logback工程的创建者)提供了一个简单的方法供我们移除对commons-logging的依赖。
不要忘了日志级别
每次你要加一行日志的时候,你都会想,这里该用哪种日志级别?大概有90%的程序员都不太注意这个问题,都是用一个级别来记录日志,通常不是INFO就是DEBUG。为什么?
日志框架和System.out相比有两大优势:分类和级别。两者可以让你可以选择性的过滤日志,永久的或者只是在排查错误的时候。
1.ERROR 发生了严重的错误,必须马上处理。这种级别的错误是任何系统都无法容忍的。比如:空指针异常,数据库不可用,关键路径的用例无法继续执行。
2.RN 还会继续执行后面的流程,但应该引起重视。其实在这里我希望有两种级别:一个是存在解决方案的明显的问题(比如,”当前数据不可用,使用缓存数据”),另一个是潜在的问题和建议(比如“程序运行在开发模式下”或者“管理控制台的密码不够安全”)。应用程序可以容忍这些信息,不过它们应该被检查及修整。
3.BUG 开发人员关注的事。后面我会讲到什么样的东西应该记录到这个级别。
4.ACE 更为详尽的信息,只是开发阶段使用。在产品上线之后的一小段时间内你可能还需要关注下这些信息,不过这些日志记录只是临时性的,应该关掉。DEBUG和TRACE的区别很难区分,不过如果你加了一行日志,在开发测试完后又删了它的话,这条日志就应该是TRACE级别的。
上面的列表只是一个建议,你可以根据自己的规则来记录日志,但应该要有一定的规则。我个人的经验是:在代码层面不要进行日志过滤,而是用正确的日志级别能够快速的过滤出想要的信息,这样能节省你很多时间。
最后要说的就是这个臭名昭著的is*Enabled的条件语句了。有的人喜欢把每次日志前加上这个:
if(log.isDebugEnabled())
log.debug("Place for your commercial");
个人认为,应该避免在代码里加入这个乱哄哄的东西。性能看起来没有什么提升(尤其是用了slf4j之后),更像是过早的优化。还有,没发现这么做有点多余么?很少有时候是明确需要这种显式的判断语句的,除非我们证明构造日志消息本身开销太大。不然的话,该怎么记就怎么记,让日志框架去操心这个吧。
你清楚你在记录什么吗?
每次你写下一行日志,花点时间看看你到底在日志文件里打印了些什么。读一遍你的日志,找出异常的地方。首先,至少要避免空指针异常:
log.debug("Processing request with id: {}", request.getId());
你确认过request不是null了吗?
记录集合也是一个大坑。如果你用Hibernate从数据库里获取领域对象的集合的时候,不小心写成了这样:
log.debug("Returning users: {}", users);
slf4j只会在这条语句确实会打印的时候调用toString方法,当然这个很酷。不过如果内存溢出了,N+1选择问题,线程饿死,延迟初始化异常,日志存储空间用完了…这些都有可能发生。
更好的方式是只记录对象的ID(或者只记录集合的大小)。不过收集ID需要对每个对象调用getId方法,这个在Java里可真不是件简单的事。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来生成(不过不是它的反射实现的那个版本)。
第二,注意数组和非典型的集合。数组和一些另类的集合的toString实现可能没有挨个调用每个元素的toString方法。可以使用JDK提供的Arrays#deepToString方法。经常检查一下你自己打印的日志,看有没有格式异常的一些信息。
更多,Java视频,Java教程尽在极悦Java培训,关注极悦官方微信,获得一手Java全新知识。