5G变1G,线上日志瘦身方法论

一、背景
在日常开发中 , 通常为了方便调试、方便查问题 , 会打印很多INFO级别的日志 。
随着访问量越来越大 , 一不小心 , 某个日志文件一天的size就大于了某个阈值(如5G) , 于是 , 收到了优化日志大小的告警 , 一定时间内不优化反馈给你主管 , 囧...
日志过大容易导致一些运维操作消耗机器性能 , 如日志文件检索、数据采集、磁盘清理等 。
那么 , 日志瘦身哪些常见的思路呢?本文结合某个具体案例谈谈我的看法 。
二、日志瘦身方法论
5G变1G,线上日志瘦身方法论
文章图片
1、只打印必要的日志
有时候为了方便测试 , 临时打印很多INFO级别日志 。 对于这种日志 , 等项目上线前 , 可以将非必要的日志删除或者调整为DEBUG级别 。
但有些场景下有些日志可打印为DEBUG也可打印为INFO , 打印成INFO级别占空间 , 打印成DEBUG级别线上查问题的时候又需要用到 , 肿么办?
5G变1G,线上日志瘦身方法论
文章图片
我们可以对日志工具类进行改造 , 支持上下文传递某个开关时(正常调用没有这个开关 , 通过公司的Tracer或者RPC上下文传递) , 可以临时将DEBUG日志提升为INFO级别 。 伪代码如下:
if(log.isDebugEnable()){
log.debug(xxx);
}elseif(TracerUtils.openDebug2Info()){
log.info("【debug2info】"+xxx);
}
这样 , 可以将一些纠结是否要打印成INFO日志的log打印成DEBUG级别 , 查问题时自动提升为INFO日志 。 为了避免误会 , 区分DEBUG提升INFO的日志和普通INFO日志 , 加上类似【debug2info】日志前缀 。
5G变1G,线上日志瘦身方法论
文章图片
当然 , 你也可以搞一些其他骚操作 , 这里只是举个例子 , 请自行举一反三 。
2、合并打印
有些可以合并的日志 , 可以考虑合并 。
如在同一个方法前后都打印了INFO日志:
INFO[64位traceId]XXXService执行前size=10INFO[64位traceId]XXXService执行后size=4
可以合并成一条:
INFO[64位traceId]XXXService执行前size=10执行后size=4
3、简化&缩写&压缩
某个日志非常有必要 , 但是打印的对象有些大 , 如果可以满足问题排查需求的情况下 , 我们可以:选择只打印其ID 。 创建一个只保留关键字段的日志专用对象 , 转化为日志专用对象 , 再打印 。 可以用缩写 , 如write简化为w,read简化为r,execute简化为e等;比如pipeline中有20个核心bean , 打印日志时可以使用不同的编号替代bean全称 , 如S1,S2 , 虽然没那么直观 , 但既可以查问题 , 又降低了日志量 。
三、优化案例
1、场景描述
一个业务场景涉及很多bean , 为了复用一些通用逻辑 , 这些bean都继承自某个抽象类 。
在抽象类中 , 定义了执行bean前后的一些通用逻辑 , 如执行前后打印当前pipeline中item的数量 。 最后一个bean执行完结果转换后需要打印出结果 。
2、优化分析
1)只打印必要日志
由于当前bean执行前相当于前一个bean执行后 , 因此只打印执行后的日志就可以 , 执行前的INFO日志可以删除或者改为DEBUG(只打印必要日志)
通常问题只出现在执行前后size不一致的情况下 , 因此执行后打印日志前可以加个判断 , 如果执行前后size相同则不打印 。 (只打印必要日志)伪代码如下:
if(sizeBefore!=sizeAfter){
log.info("service:{},前size:{},后size:{}",getName(),sizeBefore,sizeAfter)
}
这招效果很明显 , 因为大多数bean的执行前后size是相同的 , 就不会打印这条日志 。 而假设之前有20个 , 这条日志就需要打印20次 , 改进后可能只需要打印2-3次 。