一场版本升级引发的性能血案的追凶过程

本是古典何须时尚 2022-05-24 08:27 169阅读 0赞

## 1. 故事的开始 ##

上周 ActFramework 推出 act-1.8.8-RC4 版本 后, 我兴致勃勃更新了 TFB 性能 PK 项目 到最新版, 经过漫长的 60 小时 ( TFB 的一次运行周期是 60 小时) 等待后终于等来了 .............................................. 噩耗: Act 这次的性能骤然下降, 不同测试的下降范围从 60% 到 90% 不等!

不多说了, 说起来都是泪啊. 先上图吧 (为了更加切合重点, 设置了测试过滤, 只显示 Java 全栈框架, 且排除掉了直接用 JDBC 的测试项目):

### 1.1 JSON 测试 ###

act-1.8.1

act-1.8.8-RC4

**JSON 测试性能下降: 74%**

### 1.2 单次数据库查询测试 ###

act-1.8.1

act-1.8.8-RC4

**单次数据库查询测试性能下降: 73%**

### 1.3 20 次数据库查询测试 ###

act-1.8.1

act-1.8.8-RC4

**20 次数据库更新测试性能下降: 76%**

### 1.4 数据查询带后台模板测试 ###

act-1.8.1

act-1.8.8-RC4

**数据查询带后台模板测试下降: 60%**

### 1.5 20 次数据库更新性能测试 ###

act-1.8.1

act-1.8.8-RC4

**20 次数据库更新测试下降: 50%**

### 1.5 返回 helloworld 字串性能测试 ###

act-1.8.1

act-1.8.8-RC4

**返回 helloworld 字串测试下降: 90%**

## 2. 追凶 ##

这个结果直接把 ActFramework 扔进 Spring 的朋友圈去了, 这分明就是叔叔可以忍, 婶婶不能忍啊. 立马拉响红色警报, 开始缉拿凶手.

### 2.1 从简单之处入手 ###

既然所有测试结果都有所下降, 那就从最简单的 Hello World 开始调查. 启动项目先:

先看能不能访问, 再拿出 wrk 压测一万年

### 2.2 被神器忽悠了 ###

现在祭出白试不爽神器 JVisualVM, 开始抽样 CPU

果然发现猫腻, `Router.getInvoker` 居然吃掉大部分 CPU, 这是種么回事? 创建一个 SNAPSHOT 来分析一把:

WTF! `binarySearch` 居然会是 bottleneck !!! 我读书虽少也不是随便相信鬼话的人, 不过还是查看一下代码先:

这里面的 `targetMethods` 是这样的:

并没有一万个东西需要 search 啊, 这个 JDK 的二分查询会是瓶颈, 打死老码农也不会相信啊. 追凶时间迅速从七七四十九分钟上升到了九九八十一分钟, 还是没有任何进展.

### 2.3 抓住头号凶手 ###

既然头号嫌疑犯搞不清楚, 那就追查二号嫌犯吧. 回到 CPU 抽样, 看到这个 `org.osgl.util.S$Buffer.<init>` 比较射眼睛:

是什么原因造成 Buffer 分配成为瓶颈的呢? 在创建一个 SNAPSHOT, 暂时掠过一号嫌疑, 从二号入手, 果然发现蹊跷之处:

每个请求进来都会创建 `ActionContext`, 毫无疑问这是兵家必争之地, 绝对绕不过去的, 跑回去看代码发现 `ActionContext` 的父类出现了这么一条语句:

的确是在 act-1.8.2 的时候整进去的, 目的是搞这么一个东西, 以后就不需要创建新的 `StringBuilder`了,可以降低 GC 压力. 可是当时不知道发什么神经, 居然一开始就给 buffer 初始化最大限额的空间, 话说这个默认空间大小是这样设定的:

而中间 `calc.calculate` 的过程是这样的:

用简单的话来讲就是默认大小是 JVM 可用内存大小的 128 分之一再除以线程数, 这个数字对于 TFB 测试 (给 JVM 分配了 2G) 来讲差不多是 512K. 也就是说每次请求进来先分配几百 k 的空间, 这个当然是不能忍受的. 当时的思路没有问题, 不过残酷的事实再次让老码农复习了 "理想是美好的 现实是骨感的" 这句箴言

立马干掉这个逻辑之后, 果然发现性能提升了至少 50%.

### 2.4 第二个凶犯暴露 ###

回过头来研究头号嫌犯依旧没有进展, 不过在整个过程中发现了第二个性能损耗的凶手, 在 act-1.8.8 中引入的新式武器, 允许开发人员使用 Query 参数来 overwrite HTTP Header, 比如直接在浏览器上模拟发起 JSON 类型请求可以这样写: `GET /url/?act_header_content_type=application%2Fjson&act_header_accept=application%2Fjson` 可以让 Act 将该请求的 `Content-Type` 和 `Accept` 头当作 `application/json` 处理. 这个过程需要做 Keyword 匹配, 单次消耗时间虽然可以忽略不及, 但是要上 TFB 这种残酷擂台, 这样的消耗都是不能忽略的. 所以立马发明了一个新的配置 `act.header.overwrite`, 当设置为 `true` 的时候上面的特性才会生效. 这样又能提高几个百分点了.

### 2.5 第三个凶犯 ###

折腾了一整天的 JVisualVM 还是不能搞清楚 Router 里面那个方法的问题. 最后老码农发飙了, 放弃了神器, 经过研究下载了 JProfiler 来帮助搞清楚这个事情. 需要花钱的东西和白给的东西之间的差距不用说了, JProfiler 立马把问题查的清清楚楚:

1.8.1 的情况:

1.8.8-RC4 的情况

非常明显的区别, 在 plaintext 的测试中 1.8.1 走了捷径, 没有调用 before after callback, 也因此没有设置 Content-Type 头, 经过继续追凶, 还发现 1.8.1 没有 clear ActionContext. 这里 1.8.8-RC4 并没有大的问题, 其实是修复了 1.8.1 的逻辑错误. 这部分性能损耗是应该的, 无法避免. 当然老码农也做了一些响应的优化, 比如允许开发人员指定某些请求处理器不参与 before, after 的 event trigger 过程. 这些都是题外话了.

## 3. 总结 ##

对于 Java 系统遇到性能问题时的应对方式:

1.  从简单情况入手
2.  学会使用 JVisualVM (JDK 自带, 免费免费免费)
3.  当 JVisualVM 开始忽悠的时候要请出真正的高手, 就像 JProfiler 这样的.

## 4. 题外话 ##

TFB (TechEmpower Framework Benchmark) 平台不仅仅是一个展示框架实力的 T 型台, 更重要的是能够帮助框架作者发现自己框架一些潜在的问题, 是一个极好的测试反馈工具. 对于框架用户来讲则是提供了一个相对客观的参考, 不仅框架性能可以通过 TFB 直接拿到 , 框架的易用性也可以通过参加框架的测试项目反映出来.

目前在国内已经有多个开源产品登陆 TFB, 包括 Java 阵营的 ActFramework, blade 和 redkale; Go 阵营的 beego, revel; D 语言阵营的 hunt 还有宇宙语言 PHP 阵营中的 swoole 最近也加入了 TFB, 而且表现出非常强劲的实力, 值得围观

**公众号推荐:**