您的位置: 首页  >  文章  >  记一次Java调优，性能提高20倍

记一次Java调优，性能提高20倍

分类: 文章 • 2023-10-27 11:47:21

记一次Java调优，性能提高20倍

背景

最近我们接入网关OpenAccess服务增加了流量监控（阿里的Sentinel），进入测试环境，用20个线程并发测试后发现性能问题很严重，响应时间到达了1000+ms，这是完全不可以接受的数据。记一次Java调优，性能提高20倍

解决过程

添加挡板机
由于OpenAccess项目是一个接入网关，实际会调用后端服务来提供具体服务，因此初步怀疑是后端服务问题，
日志分析
经过检查日志发现“果然如此”。
在vim中通过正则表达式查找 耗时\d\d\d
查找到 调用用服务/utils/cert,耗时308

2019-03-27 09:19:05,240 [d90caafa9da696a5] [015e13ba96ca1fe9] [0a884e66a831ab40] [http-nio-8898-exec-138] [INFO ] [c.j.c.t.r.t.r.service.BaseRpcService] [getTTransport] [120] => 创建/auth/auth_server服务链接，服务地址为172.20.21.40:7000
2019-03-27 09:19:05,241 [94150341f8c2698e] [5ccc543994b1551a] [863f92af67bfc01a] [http-nio-8898-exec-150] [INFO ] [c.j.c.t.r.t.r.service.BaseRpcService] [invoke] [88] => 调用用服务/utils/cert,耗时308,返回内容为{"orgCode": "100024","merchNo": "JQ1000245100061","transId": "737848292845705","transTime": "2018-12-27 15:34:22","phoneNo": "13517198483","name": "关耳","certType": "01","certNo": "476da936e995408f99","sign": "GwWOFLfsBtj5oxfd/DsRdwnW3YkBUeiXyVfURuKEqF+rKkFTISnbNWBHUnbxc8SW1lp+p4CnPwXzgNi21Mg9UBZoduWhIXcjV1S12ZwUpAMZLnYFaZroRBttaAfThe9sCfV30bN3szG8okgyrRp7PB2kXvkg/38HYiMMllhUbG3rri5cUWT9m/n4btD6CAH/LWxKaHMDYeD1mbYSjru/QT/6qQ654fDtySvNpiWJPBpXlNceB4vfuIvpZmTkS8a6x8nJrSBIBlYy6m3sCtxdjZermuo/qhyrmfIr76/kskl6DCtRJkgNd+qSiXOr3+DqoaxGux8BD9rmupXsTHCG7w==","ret_code":"00","ret_msg":"验签成功"}

然后增加了挡板机，注册到rpc服务节点，当OpenAccess调用时直接返回，这样就可以直接测到OpenAccess自己的性能。

然而发现性能问题依然存在

替换挡板机
由于挡板机出现过几次宕机问题，加上日志分析就是rpc调用耗时过多，因此决定自己写了个挡板机来测试。
结果发现依然没有改善。

Java VisualVM性能分析

猜测宣告破产后决定还是稳扎稳打，用VisualVM性能分析工具。

应用开启jmx

首先应用启动的时候增加 jmx 参数 ，这样就会开启应用远程jmx，监听-Dcom.sun.management.jmxremote.port=1099 参数对应的端口了
start.sh脚本里面有如下内容

JAVA_JMX_OPTS=""
if [ "$1" = "jmx" ]; then
    JAVA_JMX_OPTS=" -Dcom.sun.management.jmxremote.port=1099 -Dcom.sun.management.jmxremote.ssl=false -Dcom.sun.management.jmxremote.authenticate=false "
fi

VisualVM远程连接到应用

这里配置需要监控应用的ip port即可连接成功
记一次Java调优，性能提高20倍

查看热点方法

连接成功后通过查找热点方法 ， 用jlpay 来搜索，发现时间主要是卡在com.jlpay.commons.tools.rpc.thrift.referer.service.BaseRpcService.getTTransport() 0.0 0.000 ms (0%) 0.000 ms 12,217 ms 209 ms
记一次Java调优，性能提高20倍

查看代码

查看上面getTTransport方法，看看里面都有些什么处理步骤。
每次调用rpc invoke的时候都会获取环境变量里面的连接超时参数，如为空则取默认值。设置到socket上面

		String connectTimeoutStr = SpringContextUtil.getPropertiesValue("thrift.connectTimeout","50000");
		socket.setConnectTimeout(Integer.parseInt(connectTimeoutStr));
		String socketTimeoutStr = SpringContextUtil.getPropertiesValue("thrift.socketTimeout","50000");
		socket.setSocketTimeout(Integer.parseInt(socketTimeoutStr));
		String timeoutStr = SpringContextUtil.getPropertiesValue("thrift.timeout","");

再到VisualVM里面查看SpringContextUtil.getPropertiesValue调用耗时200多ms
记一次Java调优，性能提高20倍

记一次Java调优，性能提高20倍

记一次Java调优，性能提高20倍

构造异常代价昂贵

然而这里取默认值的方式是抛异常，异常构造的话需要遍历当前线程的所有堆栈信息（类，方法，行号等），堆栈多的时候有几十个，这可是相当耗时的。
因为应用没有赋值，所有每次调用都会构造这三个异常。在高并发的时候就验证影响性能了。

public static String getPropertiesValue(String name,String defaultVal){
    if(!name.startsWith("${")){
        name = "${" + name + "}";
    }
    String val = null;
    try{
        val = STRINGVALUERESOLVER.resolveStringValue(name);
    }catch(Throwable e){
        logger.info("没有配置{" + name + "}属性，取默认值" + defaultVal);
    }

    return StringUtils.isNotEmpty(val)?val:defaultVal;
}

解决方案

问题是因为每次rpc调用去获取环境变量导致的。
因此我们可以事先将环境变量赋值给一个静态变量，这样就不需要每次都去Spring容器里面找环境变量而带来的开销了。
最后性能如图：（阿里的Sentinel监控性能）
记一次Java调优，性能提高20倍
优化后从1000+ms降到50ms 性能提升了20多倍

总结

当碰到性能问题是，一定要稳住。
通过日志，VisualVM，源码，测试等多维度分析问题。
一个个排除，验证。
剩下的就只是时间问题了。

感谢

感谢钟勇，刘明星给予测试支持，感谢陆建源提供帮助。

参考

Java虚拟机性能管理神器 - VisualVM

相关推荐