概述
最近公司项目要上线了,要求对项目做质量检测。毫无疑问,负载测试是其中很重要的一环。接下来分享下某个场景的性能优化的过程,希望能给研发兄弟们一点点参考价值。
当然这里不从架构上面考虑优化,仅仅只针对一些程序本身考虑(单个实例的情况),用最小的代价提高程序的性能。
工具及版本
工具 | 版本 | |
---|---|---|
Arthas | 3.5.2 | |
perf | 3.10.0-1160.31.1.el7.x86_64.debug | |
JDK | 1.8.0_221 |
性能这块监控工具有很多,特别是针对JAVA这块应用程序的监控的工具都做得非常棒。例如:visualvm,jprofiler,Arthas等。相比visualvm,jprofiler,这里我选择了Arthas做性能收集、性能参数等收集工具。为什么使用这个工具,基于以下几点:
- 因为有应用程序服务器权限,可以直接在服务器操作,不用远程连接。
- 微架构下的应用程序监控,Arthas能快速获取任何一个应用程序的请求的参数,不用启动网关服务等多个节点的应用服务去支撑联调。
- 快速使用内存反编译java代码,热更新到应用程序,从而提高了整体优化的效率。
调优步骤
1,通过编写简单地LR脚本压测这个场景,测试结果如下,关键接口的事务响应时长为3.5s~4s多。
![](https://img.haomeiwen.com/i26610136/bddbda43f323e150.png)
2,登录对应的微服务服务器,启动arthas进行性能数据采集。进入arthas控制台,选择对应微服务的序号 1,连接到这个微服务进行监控。
安装arthas:java -jar arthas-boot.jar --repo-mirror aliyun --use-http
![](https://img.haomeiwen.com/i26610136/199dd34b28222f52.png)
3,我们通过火焰图进行监控采集。执行profiler start,而后再去使用LR进行该场景压测。压测完,执行profiler stop。得到profiler output file的火焰图采集结果。
![](https://img.haomeiwen.com/i26610136/a36345a3e7c9861d.png)
4,使用浏览器打开火焰图,如下图所示。对性能进行分析,可以很明显看到ibatis这里出问题了。我们的程序使用了org/apache/ibatis/logging/stdout/StdOutImpl打印日志的功能。对于CPU密集型,返回字段多,字段内容复杂的情况下,这个地方导致性能问题会非常明显。
![](https://img.haomeiwen.com/i26610136/5326ddb978c83b7f.png)
![](https://img.haomeiwen.com/i26610136/6f3fbef0df7f9f63.png)
5,基于分析,我们在压测环境中关闭日志打印功能,这点也适用于生产环境。
mybatis-plus:
configuration:
log-impl: org.apache.ibatis.logging.nologging.NoLoggingImpl
6,重新使用LR进行压力测试,得到结果如下,基本满足此次性能优化的要求。
![](https://img.haomeiwen.com/i26610136/2c657fed1bd43e76.png)
观察
通过工具我们很快能分析到性能问题,以及产生的原因。那么,这个性能问题在JVM和操作系统层面又是一个怎样的现象?进一步挖掘,有利于今后在没有可视化工具或者不使用可视化工具的情况下快速定位问题并找到原因。
现在,我们借用perf和jstack工具来观察下优化之前的代码做压测运行时线程、系统情况:
perf安装:yum install -y perf
yum install -y sysstat
1,先找到对应JAVA进程12454
![](https://img.haomeiwen.com/i26610136/2d19048b2d8c6323.png)
2,执行jstack 12454 > ./jstack.log,并从JVM层面观察栈的情况,如下图所示,发现大量线程BLOCKED waiting to lock <0x00000000c005ff98>。而这里就是通过Arthas分析代码发现有问题的代码org/apache/ibatis/logging/jdbc/ResultSetLogger.printColumnValues。这里的代码使用了线程同步,阻塞线程并发。0x00000000c005ff98就是当前RUNNABLE状态的线程持有的锁。
![](https://img.haomeiwen.com/i26610136/2d4e54e82eb7d133.png)
![](https://img.haomeiwen.com/i26610136/5204c730b052cff5.png)
![](https://img.haomeiwen.com/i26610136/51ae9e8fc3cd5933.png)
3,在执行压测过程中,我们同样采用perf record -g -p 12454来记录这个过程,然后使用perf report展开结果如下图所示。看看操作系统层面能给我们怎么样的现象,可以看到object monitor 在操作系统层面反应出来的是complete monitor lock。那么以后见到了complete monitor lock ,是不是可以考虑下,程序有性能问题是不是因为有不合理使用线程同步的原因。
![](https://img.haomeiwen.com/i26610136/75ea58bf5532f3fa.png)
此外,我们还可以使用以下命令,观察下cpu、上下文切换、io等等操作系统的情况。
pidstat -u -p ALL | grep -E 'java|Command'
pidstat -p 12454 -t
vmstat 10 3
iostat 3 10
网友评论