今天我来分享一个关于日志的问题和解法。
问题
没有界面的后端程序在实际运行中发生了什么事,通常是通过日志来探查。所以日志非常重要。数据库记录了程序运行的结果,日志记录了程序运行的过程。但是日志经常出现一个问题,日志量太多,以至于把重要的日志淹没在里面。未能及时地发现问题,或者当有问题出现的时候,在日志中找原因真的是很痛苦。
对于这个问题,第1招就是把日志进行分级,差不多是每一种日志工具都提供了这个功能。常见的有info、warn、error这些级别。当使用级别进行过滤之后,往往发现日志还是太多。就需要进一步分析原因了。
在实际项目中发现有这么几种情况:
1. 有大量的日志,内容基本相同,只是有一两个值不同。如“发现无法转成long类型的字符串:xxx”
2. 还有一类日志是内容完全相同,如“意外发现xxx属性的值是null”
至于为什么会有大量的这种日志,大概率是它在循环内部,甚至是多重循环的内部。
解法
解法一:少写日志
怕日志多而在写日志代码时犹豫,甚至就不写了。当出问题后找不到日志,无法为定位问题提供帮助。此法不可取。
解法二:硬编码控制日志数量
设置一些标志或计数器来使循环内的同一类日志只打印一条或少数几条,那么日志的逻辑跟业务的逻辑会混在一起,程序的整体逻辑变得复杂。此法是下策。
如何让程序员大胆写日志,而又不会出现日志太多,同时日志的逻辑也很少掺杂到业务逻辑中呢?
解法三:日志工具类
我写了一个日志的实用类来解决这个问题。
1. 拼接
它是将多条日志拼接为一条来输出。采用“前缀+主体+后缀”的形式,在初始化时设置好前缀和后缀,在接收日志条目时拼接条目,最后的输出形式是“前缀+条目1, 条目2, …+后缀”。如果条目数为0,则前后缀都不会输出。所以,“发现无法转成long类型的字符串:aaa”,“发现无法转成long类型的字符串:bbb”“发现无法转成long类型的字符串:ccc”,会拼接这样一条:“发现无法转成long类型的字符串:aaa,bbb,ccc”。合成后的内容长度就大大减少。
2. 条目数限制
假如类似的情况发生1000次,拼接后的日志还是很长。作为人来讲,只需要看到前面的若干条目,就了解了这个问题,通常是没必要看到全部的值。所以这个日志工具提供了条目数的限制,对于超过限制的条目,则不会输出。比如条目数的限制是2,那输出的结果就是“发现无法转成long类型的字符串:aaa,bbb”
3. 同值合并
对于内容完全相同的日志,就会直接进行合并,并记录一个次数,不相邻的除外。原本是好几屏幕的“意外发现xxx的值是null”。合并成一条:“[1000*]意外发现xxx的值是null”。(此法是向浏览器的控制台学习)
4. 长度限制
除此之外,还提供了总长度的限制,即是对“前缀+条目1, 条目2, …+后缀”的总长度的限制。如果某个条目加进去之后整体长度超过这个限制了,那么这个条目就会被丢弃。前缀后缀是不会被丢弃的,但如果“前缀+后缀”已经超出限制了,根据“如果条目数为0,则前后缀都不会输出”最终没有输出。
5. 异常
此日志类实现特定的接口(Closable),做到了即使在业务代码发生异常的情况下,也不会漏了输出优化后日志。用法:
try (LogUtil log = LogUtil.builder().logger(LOGGER).build()) {
// ...A
log.write(“any message”);
// ...B
}
如果A处发生异常,自然没有任何输出。如果B处发生异常,则不影响前面的“any message”的输出。
以上的条目数限制、同值合并、总长度限制等功能可单独使用,也可组合使用。所以可能会看到这样的结果:
“发现无法转成long类型的字符串:aaa,bbb,[99*]aaa,[56*]ccc”
这个日志实用工具是对现有日志组件的封装,而现有的日志组件是log4j。不管使用哪个日志组件,都可以加上这种封装。我并没有修改日志组件,只是给他套了一层“壳”。
实际投入使用后,在我们的项目中发现,有一种相同的日志产生了947条,在过去是刷了好多屏,而且还不知道他多少条,现在合成之后就是一条,并且打上了“[947*]”,不仅没有刷屏,还很清晰的看到了条数。
干净,舒服。