背景:
项目代码中使用了Random来取得随机数,虽然是伪随机,一般情况下足够我们使用了;但是在sonar扫描中,会明确的告诉我们:
每次创建一个新的 Random 对象效率低下,并且可能会根据 JDK 生成非真正的随机数。并且给了我们例子,按照例子我们进行了代码修改,并且发到了线上;
线上事例代码:
private static Random random = null;
static {
try {
random = SecureRandom.getInstanceStrong();
} catch (NoSuchAlgorithmException e) {
log.error("NoSuchAlgorithmException",e);
}
}
//
//使用
//
xxx.setxxxx(random.nextInt(Integer.MAX_VALUE));
问题出现:
上午11点多,客服群中有人反馈订单支付完成之后状态没有立即变更成功。我们的支付流程是先走统一的交易平台,支付成功后会由交易平台发送MQ消息,业务线服务异步消费之后更改订单支付状态。正常来说,这个消费速度应该是毫秒级别的,但是当天的消费延迟达到了分钟级别,消息积压最高时120+条,好几分钟才能消费一条,导致用户支付后,很长时间内仍然是待支付的状态,重新发起支付提示: 已支付.
问题排查:
分别于12:44、16:03进行了线上两次dump,均未发现有线程阻塞的情况;
第一次怀疑是昨天上线的业务功能,因为也进行了MQ消费,大量的消息推送给mq造成了过大的压力所致,于是停掉了同步的服务,消息堆积的问题解决,在1小时后又再次出现消息堆积;
第二次发现此topic多个地方公用,使用不同的tag进行区分,并且是有序消费;修改配置文件orderly:false,消息堆积的问题解决,后续又再次出现;
16:12、19:05多次出现消息堆积,并且根据日志,发现程序在很长的一段时间内没有日志输出,怀疑线程被阻塞,再次进行线上dump;
根据dump信息发现,线上被阻塞在了读取文件(Random.nextInt()) 查看代码发现最近被修改为了sonar建议的方式获取随机数:
问题复现:
编写测试例子在服务器上进行复现:
public class Test {
private static Random random = null;
static {
try {
random = SecureRandom.getInstanceStrong();
} catch (NoSuchAlgorithmException e) {
e.printStackTrace();
}
}
public static void main(String[] args) {
for (; ; ) {
long startTime = System.currentTimeMillis();
System.out.println(random.nextInt(Integer.MAX_VALUE));
System.out.println("cost:" + (System.currentTimeMillis() - startTime));
}
}
}
复现结果: 第一次获取就消耗了将近3分钟
问题解决:
将获取随机数的代码替换回new Random的方式,发布上线,问题解决,消费速度正常.
事故复盘:
为什么从上午11点发现问题到晚上19点才发现问题?
- 业务迭代代码和sonar代码修改在一起上线,而且因时间跨度比较大,导致完全忽略了sonar代码改动,聚焦点都集中在业务代码上。
- 对于dump文件分析能力不够,不能从dump文件获取关键信息。
- 当问题出现而不能解决的时候,没有考虑代码回滚。这个是应该在第一时间考虑的。
- 对于rocket mq 不够熟悉,关键时刻不能熟练的使用和解决问题。
有哪些可以改进的地方?
- 业务代码和技术需求尽量不要发到一起上线,技术改造可以单独上线,避免因技术改造引起业务问题,而且发现问题也可以快速回滚。
- 对于dump文件分析能力不够,这个能力需要立即补足。
- 当上线后出现问题后,应该立即去解决问题,如果不能立即解决,应该考虑代码回滚。