容易忽视的细节：Log4j 配置导致的零点接口严重

一、问题发现

我所负责的商城活动系统用于承接公司线上官方商城的营销活动，最近突然收到凌晨0点的服务超时告警。

营销活动类的系统有如下特点：

1. 营销活动一般会0点开始，如红包雨、大额优惠券抢券等。
2. 日常营销活动的机会刷新，如每日任务，每日签到，每日抽奖机会的刷新等。

营销活动的利益刺激会吸引大量真实用户及黑产前来参与活动，所以流量在0点会迎来一波小高峰，也正因如此线上偶现的服务超时告警起初并未引起我的注意。但是接下来的几天，每天的凌晨0点都会收到服务超时告警，这引起了我的警惕，决定一探究竟。

二、问题排查

首先通过公司的应用监控系统查看了0点前后每分钟各接口的P95响应时间。如下图所示，接口响应时间在0点时刻最高达到了8s。继续查看锁定耗时最高的接口为商品列表接口，下面就针对这个接口展开具体的排查。

2.1 排查思路

正式排查之前，先和大家分享下我对接口超时问题的排查思路。下图是一个简化的请求流程。

1. 用户向应用发起请求
2. 应用服务进行逻辑处理
3. 应用服务通过RPC调用下游应用以及进行数据库的读写操作

服务超时可能是应用服务自身慢导致，也可能下游依赖响应慢导致。具体排查思路如下：

3.1.1下游依赖慢服务排查

（1）通过调用链技术定位下游依赖中的慢服务

调用链技术是实现系统可观测性的重要保障，常见的开源方案有ziplin、pinpoint等。完整的调用链可以按时间正序记录每一次下游依赖调用的耗时，如rpc服务调用、sql执行耗时、redis访问耗时等。因此使用调用链技术可以迅速定位到下游依赖的慢服务，如dubbo接口访问超时、慢SQL等。但理想很丰满，现实很骨感。由于调用链路信息的数量过大，想要收集全量的链路信息需要较高的存储成本和计算资源。因此在技术落地时，通常都会采用抽样的策略来收集链路信息。抽样带来的问题是请求链路信息的丢失或不完整。

（2）无调用链时的慢服务排查

如果调用链丢失或不完整，我们就要再结合其它手段进行综合定位了。