背景
在高并发的系统中,通常不会打印除参数校验失败或捕获异常之外的日志,防止对接口的性能产生影响。
那对于请求不符合预期的情况,我们如何快速找到是哪块逻辑影响的至关重要。
Pfinder提供的链路监控,更多的是性能层面的监控,无法满足我们上述的诉求。
下面我将通过自定义通用上下文,添加日志埋点,解决上述存在的问题。
通用上下文 CommonContext
作用
创建通用上下文的作用,是为了跟踪一个请求的生命周期,然后根据请求的特殊标识,决定是否记录关键日志,然后返回给调用方,以识别具体执行了什么逻辑,以便快速排查问题。
包含
一个通用上下文,除了要包含记录日志的字段,也可以存储一些通用参数,计算中间结果等等。
示例
使用
简单是使用如下:
说明:
- 当识别到指定的
uuid
,我们开启了上下文日志开关 - 对于单个入参的情况,
context.clearContext();
不执行也可以,但是对于批量接口,在遍历处理的时候,需要在每个循环体内执行context.clearContext();
,防止一些中间结果对后需循环的影响。 - 在关键的地方,我们可以通过
context.debug()
记录日志,然后设置到Response#message
随响应返回,进而快速识别问题。
存在的问题
在记录日志的时候,我打印了如下日志:
单从代码来看,好像没什么问题。
来看接口性能,如下:
tp99达到恐怖的35s!
CPU使用率居高不下!
通过分析,发现查询到的 activityList
个数较多,且单个对象较大,在执行上述日志打印逻辑的时候,消耗了较多的CPU资源,进而影响了接口性能。
注释该段代码,tp99降低至15ms左右。
但实际上,我还是存在打印该列表的诉求。
升级
上述问题的根本原因是:不论我是否开启日志打印,日志中的计算逻辑总会执行。
那有什么办法,只在开关开启的情况下,打印该日志呢?
借鉴log4j,使用lamba表达式延迟打印
Log4j存在如下API:
手动控制是否打印详情信息
将打印列表的诉求拆分如下:
- 对于特大的列表,不打印
- 对于较小的列表,打印
升级后的CommonContext
说明:
- 这里引入的
Supplier
是java.util
包的,更通用。 - 保留了对于简单的参数,不使用lambda的方式。
- lambda的延迟计算已验证,可放心使用。
升级后使用
需要注意: setDebugDetail()
需要在 setDebug
后执行,否则isDebug
标识会被覆盖。
将所有有计算逻辑的日志升级为 lamba表达式,下面来看升级前后接口性能变化:
以上。
作者:京东零售 张云鹏
来源:京东云开发者社区