性能压测问题分析
2019-07-20 17:13 清风软件测试开发 阅读(1126) 评论(0) 编辑 收藏 举报
记一次生产环境性能压测优化的经历
对线上服务进行性能压力测试的一次优化过程。
项目背景:
1.服务器的硬件配置(48核120G内存2T硬盘);
2.网络部署结构,用户请求报文首先进入负载均衡Nginx,Nginx后端负载两台Tomcat。
现象描述:
对线上的两台服务器做性能压测时,发现单台Tomcat的QPS达到600左右处理业务就明显变慢,一次请求处理时间大约上升到七秒左右(正常情况下一秒内就处理完成),给人的感觉就是Tomcat跑不动。
优化过程:
1.查看Tomcat和Nginx各自的log日志,发现Nginx的日志中有大量的“worker_connections are not enough while connecting to upstream”,错误信息已明确给出了提示,因此修改配置文件nginx.conf,修改为:
worker_processes auto; events { worker_connections 10240; }
2.继续压测时,当QPS达到600时,发现Tomcat处理业务仍然很慢,查看ngxin的日志一切正常并无任何线索,因此,把重心转向Tomcat,查看Tomcat日志,发现日志打印的非常慢,特别是定位到两条相隔很近的日志间所需时间都在2秒左右,而且这两条日志在代码层面相隔很近,中间也无耗时的业务逻辑。
此时的第一反应是jvm的参数设置的不合理,于是就去查看gc的日志,并改动JVM的参数,但是多次调优JVM后QPS仍然未有明显提升。修改后的jvm参数:
JAVA_OPTS="-server -Xmx32g -Xms32g -Xmn12g -Xss256k -XX:SurvivorRatio=6 -XX:+UseConcMarkSweepGC -XX:+UseParNewGC -XX:MaxGCPauseMillis=n -XX:CMSInitiatingOccupancyFraction=60 -XX:CMSTriggerRatio=70 -XX:+PrintGCDateStamps -XX:+PrintGCDetails -Xloggc:/home/xiaoju/logs/stargate-service/gc/gc_${DT}.log -XX:+PrintHeapAtGC"
3.既然排除JVM和业务代码的原因,把目标又锁定在了日志框架上,我们的业务代码中引用了log4j(版本1.12.7)框架进行日志操作,在log4j的官网上找到了对性能影响的因素,见官网Performance菜单下的如下章节所示
Asynchronous Logging with Caller Location Information
也就是说如果在日志信息中打印location信息(例如:包名、类名、函数名称和行号)(即:在log4j的配置文件中,配置了%C or $class, %F or %file, %l or %location, %L or %line, %M or %method),会严重影响log4j的性能。
跟踪log4j源码后发现,log4j为了拿到函数名称和行号信息,利用了异常机制,首先抛出一个异常,之后捕获异常并打印出异常信息的堆栈内容,再从堆栈内容中解析出行号,代码截取如下:
/** Set the location information for this logging event. The collected information is cached for future use. */ public LocationInfo getLocationInformation() { if(locationInfo == null) { locationInfo = new LocationInfo(new Throwable(), fqnOfCategoryClass); } return locationInfo; }
我们知道,Java的异常机制很耗性能(注意:如果单纯的是new异常并抛出并未耗性能,如果对异常栈进行操作,如打印输出则很耗性能),因此我们将log4j的配置文件去掉了函数名称和行号打印后,性能QPS立马提升到了2500。
4.在log4j的配置文件中去掉log4j的location信息后,继续压力测试,待QPS达到2500后服务器又会报服务超时的错误,通过看log4j官网文档中的性能章节,发现console对性能的影响也会非常大,因此在log4j的配置文件中又将console关闭了,继续压测后QPS性能达到8000左右了。
5.在log4j的配置文件中关闭location信息和关闭console后,继续压力测试进行优化,发现日志文件的大小也会影响到性能,建议控制日志文件的大小或者采用日志追加的方式;同时将日志改为异步打印也会有性能提升有所帮助。(在我们测试的过程中,日志文件大小和异步打印,对性能的提升有限,不如去掉location信息和关闭console那么明显)。
总结:
1.Java语言不像C语言或PHP语言,对于行号获取有宏定义__LINE__,可以很方便的获取到行号信息,而Java语言中并未有这样的宏定义,因此为了获取到行号信息,Java只能从线程池栈或异常栈中获取,为了获得异常栈信息,又只能构造异常并抛异常,依次来拿到栈信息。即:在Java语言中,凡是涉及到行号信息的获取,只能通过构造异常new Throwable()抛出,之后在函数内部通过异常或上层捕获异常来拿到栈信息,从栈信息中解析出行号信息,因此在Java中凡是涉及到行号信息的获取操作,都非常的耗性能,这一点尤其要注意。
2.log4j影响性能的程度依次为:日志的location信息(如:行号函数名) > console(关闭日志输出到控制台) > 异步打印 > 日志文件的大小(日志追加模式)。线上环境如果对性能有一定要求的话,建议关闭location和console控制台。
附录:
JVM的优化,JVM调优一般来说都是出问题或告警的时候注意进行优化,这块可谓”水无常形 兵无常势”,具体问题具体分析。
回收器的选择:
- CMS
- G1
关键参数
– 决定Heap大小:-xms(最小) -xmx(最大) –xmn(年轻代大小)(建议-xms=-xmx) ,初始堆的大小==可调堆最大值,避免堆动荡
● 取决与操作系统位数和CPU能力
● 过小则GC频繁,过大则GC中断时间过长,注意GC发生时业务代码会出现暂停一会,即:Stop the world。
– Eden/From/To:决定YounGC,如:-XX:SurvivorRatio
– 新生代存活周期:决定FullGC,如:–XX:MaxTenuringThreshold
新生代/旧生代
– 避免新生代设置过小
● 频繁YoungGC
● 大对象,From/To不足拿Old增长快,FullGC
– 避免新生代设置过大
● 旧生代变小,频繁FullGC
● 新生代变大,YoungGC更耗时
– 对于我们组大部分系统,可以分配 : 新生代:Heap=33%,即Young:Old=1:2
-XX:NewRatio=4:设置年轻代(包括Eden和两个Survivor区)与年老代的比值(除去持久代),设置为4,则年轻代与年老代所占比值为1:4,年轻代占整个堆栈的1/5。
-XX:SurvivorRatio=4:设置年轻代中Eden区与Survivor区的大小比值,设置为4,则两个Survivor区与一个Eden区的比值为2:4,一个Survivor区占整个年轻代的1/6,Eden区占整个年轻代的4/6。
供参考:
1.GC专家系列3-GC调优 https://segmentfault.com/a/1190000004303843
2.JVM GC中Stop the world案例实战 https://blog.csdn.net/sinat_25306771/article/details/52374498
3.从实际案例聊聊Java应用的GC优化 https://tech.meituan.com/2017/12/29/jvm-optimize.html
4.垃圾回收算法 https://blog.csdn.net/d6619309/article/details/53358250
5.关于Jvm知识看这一篇就够了https://zhuanlan.zhihu.com/p/34426768?group_id=956114978579750912