文档章节

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

罗格林
 罗格林
发布于 2018/05/21 13:28
字数 1689
阅读 2842
收藏 51

1. 故事的开始

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

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

1.1 JSON 测试

act-1.8.1

image

act-1.8.8-RC4

image

JSON 测试性能下降: 74%

1.2 单次数据库查询测试

act-1.8.1

image

act-1.8.8-RC4

image

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

1.3 20 次数据库查询测试

act-1.8.1

image

act-1.8.8-RC4

image

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

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

act-1.8.1

image

act-1.8.8-RC4

image

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

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

act-1.8.1

image

act-1.8.8-RC4

image

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

1.5 返回 helloworld 字串性能测试

act-1.8.1

image

act-1.8.8-RC4

image

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

2. 追凶

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

2.1 从简单之处入手

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

image

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

image

2.2 被神器忽悠了

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

image

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

image

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

image

这里面的 targetMethods 是这样的:

image

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

2.3 抓住头号凶手

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

image

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

image

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

image

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

image

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

image

用简单的话来讲就是默认大小是 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-TypeAccept 头当作 application/json 处理. 这个过程需要做 Keyword 匹配, 单次消耗时间虽然可以忽略不及, 但是要上 TFB 这种残酷擂台, 这样的消耗都是不能忽略的. 所以立马发明了一个新的配置 act.header.overwrite, 当设置为 true 的时候上面的特性才会生效. 这样又能提高几个百分点了.

2.5 第三个凶犯

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

1.8.1 的情况:

image

1.8.8-RC4 的情况

image

非常明显的区别, 在 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, bladeredkale; Go 阵营的 beego, revel; D 语言阵营的 hunt 还有宇宙语言 PHP 阵营中的 swoole 最近也加入了 TFB, 而且表现出非常强劲的实力, 值得围观

© 著作权归作者所有

罗格林

罗格林

粉丝 309
博文 46
码字总数 49389
作品 4
其他
架构师
私信 提问
加载中

评论(19)

talent-tan
talent-tan
为什么用抽样CPU?还不是Profiler?
木九天
木九天

引用来自“笔阁”的评论

引用来自“木九天”的评论

感觉抄袭的
已注明文章出处。

大神写个新版本的,哦哦,不好意思啊
Carvendy
Carvendy
膜拜
李嘉图
李嘉图
厉害,厉害,只要能debug,就没有不能解决的问题
罗格林
罗格林 博主
再给大家分享一个 .Net 团队如何利用 TFB 来发现其数据库驱动程序的性能问题的故事:
https://github.com/TechEmpower/FrameworkBenchmarks/issues/3769
m
magican
大神每次的分享都是干货,感谢
罗格林
罗格林 博主

引用来自“乌龟壳”的评论

JVisualVM是通过按某种频率采样得到函数运行时间的,这个只能用作参考,深度调试性能问题不好用,好处就是采样不太影响性能
对的对的. 我也尝试使用 JVisualVM 的 profiler 工具, 只是它这个 profiler 实在不能用, 等半天也出不来, 所以最后换成了 JProfiler, 分分钟搞定
罗格林
罗格林 博主

引用来自“闲大赋”的评论

性能问题,大部分还是代码问题,现在国内氛围很不对,一来就上虚拟机调优,还没有会走路,就想先飞。这个文章的解决思路可以扩展到任何项目和产品开发里
嗯, 出问题的时候通常来讲 99% 是自己代码的问题. 但作为程序员往往第一感觉是环境的问题, 拿本文这个情况来说, 发现问题的时候, 我第一感觉也是在想是不是 undertow-core 升级到 1.4.25 出问题了, 要不要换回 1.4.23 再提交个 PR 去测一下. 18 年的开发经验告诉我这个想法是不理智的, 错误绝对只会是在自己的代码里面. 当然最后的结果也是如此. 我这样讲并不是让大家对自己失去信心, 写代码的时候应该对自己抱有绝对的信心, 但出错的时候一定要先找自己的问题.
乌龟壳
乌龟壳
JVisualVM是通过按某种频率采样得到函数运行时间的,这个只能用作参考,深度调试性能问题不好用,好处就是采样不太影响性能
闲大赋
闲大赋
性能问题,大部分还是代码问题,现在国内氛围很不对,一来就上虚拟机调优,还没有会走路,就想先飞。这个文章的解决思路可以扩展到任何项目和产品开发里
一场版本升级引发的性能血案 - 王者归来

上次老码农在一场版本升级引发的性能血案 - 之数据历险一文中讲得口吐白沫, 最后还是没有一个结果, 反而被 OSCer 们各种吐槽: "看得我快快精尽人亡了""看着一头雾水""一脸懵逼进来,一脸懵逼...

罗格林
2018/06/04
0
0
Node.js 6.9.3 和 4.7.1 (LTS) 版本发布

Node.js 6.9.3 (LTS) 和 4.7.1 (LTS) 版本发布了。 更新内容: Node.js 6.9.3 显著变化: 构建:共享库现支持为 AIX 构建 deps: npm:升级到3.10.10 V8:通过计算属性解构箭头函数参数不再抛...

王练
2017/01/04
1K
4
携手追梦,从今起航 | INT Chain主网正式全球上线

致INT Chain全球社区成员: 世界上一切美好的事物,都值得用心去等待。终于,不负你们的耐心等待与守候,我们的播种和耕耘在今天结出了果实。 北京时间2019年1月16日18点30分,INT Chain主网...

INT奚子
04/04
0
0
Mybatis 错误Should be: #{propName,attr1=val1,attr2

Improper inline parameter map format. Should be: #{propName,attr1=val1,attr2; <update id="updateByPrimaryKeySelective" parameterType="com.wlyd.fmcgwms.persistence.beans.basic.W......

boonya
2016/04/22
50
0
伪静态化不正常,电脑打不开贴子,手机可以

其实可以叫是一个插件引起的血案,因为杀人的心都有了,事件起因是服务器http状态监控报警,说断网,一看还是真是占用资源极高,重启一下服务,当时可以,一会又不行,环境是phpstudy2014,到...

goodchina
2016/05/29
0
0

没有更多内容

加载失败,请刷新页面

加载更多

DevExpress-winform实现打印功能

创建Windows窗体,拖入richEdtControl(或者GridControl)+打印按钮(button) 双击打印,创建click事件,直接用richEdtControl1调用ShowPrintPreview()方法 private void btnPrint_Click(o...

元歌
51分钟前
2
0
Lucene

Lucene 简介: Lucene是apache下的一个开源的全文检索引擎工具 1.1.全文检索:先分词创建索引,再搜索(分词:就是将一个句子分成多个单词) 全文检索的流程分为两大部分:索引流程、搜索流程...

klmkom
52分钟前
2
0
SpringBoot2.0高级案例(03):集成 JavaMail ,实现异步发送邮件

本文源码码云地址:知了一笑https://gitee.com/cicadasmile/middle-ware-parent 一、JavaMail的核心API 1、API功能图解 2、API说明 (1)、Message 类: javax.mail.Message 类是创建和解析邮...

知了一笑
52分钟前
19
0
Andrew Ng 机器学习鸡尾酒音频分离算法解析

[w,s,v] = svd((repmat(sum(x.*x,1),size(x,1),1).*x)*x'); 在学习机器学习的课程过程中,ng用一行代码实现了音频分离的效果,这里对这行代码进行解析。 [x1, Fs1] = audioread('E:\sounds\f...

gdxz110
56分钟前
2
0
动漫人物阴影绘画技巧

动漫人物阴影绘画技巧?我们在上色的时候,对色彩的使用都大致了解,但是却不知道怎么画阴影。如果这是在现实日常生活中会看到的,但是要想画出来的话就很难了,下面就让我们一起来看看画阴影...

设绘嗨
57分钟前
2
0

没有更多内容

加载失败,请刷新页面

加载更多

返回顶部
顶部