案例分享 | 记一行MD5引发的超时问题

作者：京东零售 付伟

1. 前言

大家好，当你点开这篇文章的时候也许心想是哪个 XX 小编混到这里，先不要着急扔臭鸡蛋，本文是一篇标准（正经）的问题复盘文章。好了，一行 MD5 居然让小伙伴下不了班，到底是什么问题呢，让我们一起来看看吧。

2. 正文

2.1 需求是什么

这里不再介绍具体的业务。简而言之，有两个接口（查询、确认）对前端页面提供服务。

查询接口返回的数据依赖于本地数据与外部接口计算后的结果，也就是页面展示的是数据快照。确认接口是按照页面的展示结果请求外部接口。

考虑到用户打开展示页面时的数据与提交操作可能间隔很久，实际请求时结果已发生变化，而这种操作会影响业务结果。因此在提交时会进行一次 check，如果发现数据发生变化需要提示页面进行刷新。

为了方便大家理解，我简单的画了个图，毕竟上面太啰嗦了。

• 查询接口

• 确认接口

虽然这个图有点草率，但是相信看到这里的小伙伴（默认都是聪明的）都对需求了然于胸了。

2.2 我怎么搞得

掰扯了半天，我们的主角 MD5 还没有出场，别着急风雨总在彩虹后。

可以看出，这里需要前端将查询接口的返回值重新组装作为确认接口的入参。而后端需要再次走数据聚合的逻辑与前端传过来的业务值进行比较，如果不匹配则提示页面需要刷新。

一切看起来都顺理成章，那么小编遇到了什么问题呢？

简单来说有两点：

呵呵，机智的小编灵机一动，便想到了了MD5，看看百度百科怎么说

MD5 信息摘要算法（英语：MD5 Message-Digest Algorithm），一种被广泛使用的密码散列函数，可以产生出一个 128 位（16 字节）的散列值（hash value），用于确保信息传输完整一致。

一图胜千言

在工程，它差不多就是这么用。

String md5= Md5Utils.get(String source);

可能有聪明的小伙伴会说了，这是散列函数存在哈希碰撞，不同的字符串也有可能生成相同的哈希值。

是的没错，但是在小编的业务场景中，这种出现的概率微乎其微，忽略不计，解释权归小编所有。

那么具体怎么做的呢，还是看图说话：

• 改造后的查询接口

• 改造后的确认接口

我们需要对查询接口返回的业务集关键属性进行组合哈希，这样可以生成数据快照值。确认接口无需再传入业务集合，只需要传入数据快照值，后端进行对比即可知道是否发生变更。

一切都是那么的美好，接下来就到了动人心魄的编码环节。话不多说，小编的项目中引入了hutool包，什么你不知道糊涂包？

Hutool 是一个小而全的 Java 工具类库，通过静态方法封装，降低相关 API 的学习成本，提高工作效率，使 Java 拥有函数式语言般的优雅，让 Java 语言也可以“甜甜的”。Hutool 中的工具方法来自每个用户的精雕细琢，它涵盖了 Java 开发底层代码中的方方面面，它既是大型项目开发中解决小问题的利器，也是小型项目中的效率担当；

真不错，果然是效率担当，一行代码就搞定了。

	/**
	 * 生成数据哈希
	 */
	private String generateSnapShotHash(AcceptListQueryWrapResultDTO wrapResultDTO) {
		StringBuilder builder = new StringBuilder();
		for (AcceptListQueryResultDTO item : wrapResultDTO.getAllList()) {
			builder.append(item.getQuotationId()).append(item.getOperateType()).append(item.getPriceTypeCN());
		}
		return MD5.create().digestHex16(builder.toString());
	}

请各位看官记住这行代码

MD5.create().digestHex16(builder.toString());

毕竟它就是糊弄你点进来的罪魁祸首。

2.3 出了什么事

当小编开发完以后，开心的部署在了测试环境。和前端联调的时候，发现第一次请求总是超时 ？？？

一想可能是 mock 平台的问题，毕竟三方的查询接口还没开发完成，就不以为然。请注意，只是第一次超时。同样的请求参数第二次光速返回。呵呵，你说不是环境的问题，小编自己都不大信呢。

友方的接口开发完了，小编期待的换上了对方的接口。结果现实给了小编一记左勾拳，还是第一次超时。这不科学？于是小编对自身产生了怀疑？难道不是环境的问题?

于是连忙在本地测试了一下，居然是光速返回。作为自信的人一定不是代码的问题，那么这个锅往哪里甩呢？又臭又硬的小编狠狠的思考了一分钟，又将锅甩给了业务网关（统一接收HTTP请求）肯定是它的毛病，毕竟测试环境的网关出问题很常见。

于是开开心心的准备上预发了。上了预发绝对没问题！！！小编信誓旦旦的对QA说道。

上帝为你关上一扇门的同时也会为你关上一扇窗，预发环境第一次还是超时！！！小编觉得很惭愧对不起一起上线的小伙伴，毕竟大家都准备十点下机了。

小编陷入了沉思中。。。

2.4 怎么修好的

排查了预发环境的接口，友方的杰夫接口TP99只有几毫秒，网关也没有问题，也许是数据库的原因，排查发现也没有问题。顿时，小编又迷茫了。

山重水复疑无路柳暗花明又一村，机智的小编想到了国内知名厂商开源的一款java诊断工具Arthas，利用它可以查看方法详细耗时。点我查看 主动打开另一扇窗。

当你遇到以下类似问题而束手无策时，Arthas可以帮助你解决：

这个类从哪个 jar 包加载的？为什么会报各种类相关的 Exception？

我改的代码为什么没有执行到？难道是我没 commit？分支搞错了？

遇到问题无法在线上 debug，难道只能通过加日志再重新发布吗？

线上遇到某个用户的数据处理有问题，但线上同样无法 debug，线下无法重现！

是否有一个全局视角来查看系统的运行状况？

有什么办法可以监控到 JVM 的实时运行状态？

怎么快速定位应用的热点，生成火焰图？

怎样直接从 JVM 内查找某个类的实例？

由于预发环境还是比较麻烦，于是小编在测试环境准备好了arthas环境。

下面简单介绍下使用步骤：

当看到图标出现时，即启动成功。具体使用方法可以查看官网，此处不再赘述。

我们使用trace命令查看方法耗时，同时在页面请求该查询接口。

trace  --skipJDKMethod false com.jd.universal.inquiry.service.protocol.jsf.AcceptListWebErpServiceImpl queryList

可以看到这行生成数据快照的方法，耗时占整个接口的99.57%，紧接着我们继续监控generateSnapShotHash方法：

trace  --skipJDKMethod false com.jd.universal.inquiry.service.protocol.jsf.AcceptListWebErpServiceImpl generateSnapShotHash

可以看到方法的耗时都集中在

[99.99% 36562.318173ms ] cn.hutool.crypto.digest.MD5:create() #103

接着再次页面点击请求操作，出现以下情况：

可以看到后面多次请求cn.hutool.crypto.digest.MD5:create()方法耗时仅不到一毫秒。和我们之前遇到的状况一致。此时已确定是这行MD5导致的第一次加载很慢。

虽然原因找到了，但是还是得看下为什么这行代码只有在第一次时这么慢，于是我们进入该方法看看它到底搞什么幺蛾子。

可以看到初始化方法如下：

由于现象是程序第一次运行很慢，后续很快，根据小编多年的写/修BUG 经验怀疑是这段初始化中存在静态加载。

MessageDigest是JDK自带的类，为应用程序提供摘要算法的，这里我们关注点就落在了上面的一行。我们点进去看一下：

果然我们看到了他在尝试加载BouncyCastle库，我们来看一下这个库的介绍：

BouncyCastle（轻量级密码术包）是一种用于 Java 平台的开放源码的轻量级密码术包；Bouncycstle 包含了大量的密码算法，其支持椭圆曲线密码算法，并提供 JCE 1.2.1 的实现。

所以问题的答案就呼之欲出了，随着源码的深入，我们看到：

  private void setup()
   {
        loadAlgorithms(DIGEST_PACKAGE, DIGESTS);

        loadAlgorithms(SYMMETRIC_PACKAGE, SYMMETRIC_GENERIC);

        loadAlgorithms(SYMMETRIC_PACKAGE, SYMMETRIC_MACS);

        loadAlgorithms(SYMMETRIC_PACKAGE, SYMMETRIC_CIPHERS);

        loadAlgorithms(ASYMMETRIC_PACKAGE, ASYMMETRIC_GENERIC);

        loadAlgorithms(ASYMMETRIC_PACKAGE, ASYMMETRIC_CIPHERS);

        loadAlgorithms(KEYSTORE_PACKAGE, KEYSTORES);

        loadAlgorithms(SECURE_RANDOM_PACKAGE, SECURE_RANDOMS);

        loadPQCKeys();  // so we can handle certificates containing them.
     //省略。。。
    }

正是由于这些算法实现的加载，导致MD5.create()第一次调用时耗时超过数十秒。

好了，既然找到了问题。那么改动起来就很简单了，小编尝试寻找了糊涂包中提供的方法，发现并没有入参可以关闭该三方加密包的初始化。于是换用了Google提供的MD5的实现。重新打包，部署，一次成功，完美。

3. 后语

QA同学在测试环境测出了这个问题，而自信的本人不屑一顾，坚持自己愚昧的观点，先认为是Mock的问题，接着又说是网关的问题。由于小编的盲目自信，导致上线到很晚，表示非常的惭愧。总结失败的原因：

4. 参考

Bouncy Castle 加密算法包

arthas 官方文档

使用 Arthas 进行生产代码热修复

本文正在参加「金石计划」