问题描述
某天下午突然收到大量的企业微信告警提示CPU超阈值以及慢接口告警.半个小时内,很多客户反馈小程序,APP各种系统异常
应急过程
首先进行初步的分析以及保留现场相关信息,确认初步的恢复系统可用方案(进行分工)
- 对应服务器节点查看cpu高的是哪些进程(top命令,查看监控等确认)
- 初步分析原因
确定是java进程导致,大多是2种情况.- 频繁gc
使用jdk自带工具查看gc情况: jstat gc $pid 1000 -1 或者使用arthas查看 - 死循环(长时间循环)
- 频繁gc
- 确认到对应进程有频繁gc情况.从线上dump内存快照和线程快照.使用MAT,TMDA等工具初步分析
- 为优先恢复系统可用先采取临时方案
确认到近期无版本变更,先紧急调整JVM启动参数,堆内存由原来的2G调整为3G
发现很快又出现CPU飚高情况 - 通过分析内存快照,线程快照,日志,监控数据等,追踪发现是由于运营人员进行多条配置触发了首页弹窗广告接口的历史遗留bug导致.优先迅速下线了该功能(代码临时写死接口返回空)
- 系统恢复正常
原因分析
- 弹窗广告配置分多种类型,所有商户/指定商户集合等类型.由于当时类型无代理商维度,因此当天运营人员导出60个左右代理商的商户列表,进行了多条弹窗广告的配置.每个代理商的商户列表数量大概在5K-2W个左右.平均1W
- 首页弹窗广告列表接口存在历史遗留bug.(具体可以看下面的复现过程)
在匹配商户的处理上,采取了获取所有广告配置,并获取对应广告的商户list匹配当前商户的不合理处理逻辑.每次接口要进行约60*1W=60W的数据过滤.且由于首页接口qps较高,近1000/s.导致内存消耗急剧增加,进而导致一系列问题.
复现过程
问题代码大致代码如下(本地模拟)
/**
* 获取首页配置项列表(弹窗/banner广告等)
*/
@GetMapping("/getConfigList")
public Object getConfigList(@RequestParam("merchantId") String merchantId) {
log.info("getConfigList start,merchantId->{}", merchantId);
// 获取所有在有效期内的配置项列表
List<ZcjConfig> configList = zcjConfigMapper.listEnable(new Date());
List<ZcjConfig> result = new ArrayList<>();
for (ZcjConfig config : configList) {
if ("MERCHANT_LIST".equals(config.getEnableType())) { // 生效类型为指定商户列表的需要匹配商户
List<ZcjConfigMerchant> configMerchantList = zcjConfigMerchantMapper.listByConfigId(config.getId());
boolean containMerchant = configMerchantList.stream().anyMatch(p -> merchantId.equals(p.getMerchantId()));
if (containMerchant) {
result.add(config);
}
} else {
result.add(config);
}
}
log.info("getConfigList end,result->{}", JSON.toJSONString(result));
return result;
}
对应进程28518 cpu占用率达到168%左右
可以通过 jps -lv | grep 28518 或者 ps -ef | grep 28518 查看对应进程对应的项目
image.png
对应进程存在频繁的gc
image.png
使用arthas也可以查看到频繁的gc以及gc线程占用cpu率高
使用top -Hp $pid也可以
image.png
image.png
arthas查看cpu占用率高的线程栈信息
image.png
应用日志出现OOM
image.png
MAT分析可以分析到大量的mybatis相关实例数据
image.png
image.png
image.png
image.png
查看线程栈详情可以定位到业务代码内容
image.png
定位代码,并结合应用日志,可以看到接口多次循环查表获取列表且返回结果集太大(线上更大)
image.png
事后改进措施
- 修复了代码bug.直接使用mysql匹配商户号方式优化代码处理逻辑.类似逻辑如下
SELECT
t.*
from
(
select
*
from
zcj_config
WHERE
start_time <= '2023-02-01 15:00:00'
AND end_time >= '2023-02-01 15:00:00'
) AS t
WHERE
case when t.enable_type = 'MERCHANT_LIST' then exists (
select
1
from
zcj_config_merchant zcm
where
zcm.config_id = t.id
and zcm.merchant_id = 'merchant_10013'
) ELSE 1 = 1 end
- 优先进行指定代理商列表类型的需求的开发.避免类似匹配代理商需要设置多条商户广告配置的操作
- 增加了redis缓存.减少对DB的访问
- 调整应用JVM大小,2G扩大到3G
- 该代码处理逻辑属于比较低级的错误.也进一步规范了相关的代码规范以及开发流程