性能压测问题分析

系统管理员 2021-10-29 11:56 355阅读 0赞

![1034798-20190720170653106-1541459293.png][]

# 记一次生产环境性能压测优化的经历 #

对线上服务进行性能压力测试的一次优化过程。   
项目背景：   
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为了拿到函数名称和行号信息，利用了异常机制，首先抛出一个异常，之后捕获异常并打印出异常信息的堆栈内容，再从堆栈内容中解析出行号，代码截取如下：

![复制代码][copycode.gif]

/**
         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;
      }

![复制代码][copycode.gif]

我们知道，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][https_segmentfault.com_a_1190000004303843]  
2.JVM GC中Stop the world案例实战 [https://blog.csdn.net/sinat\_25306771/article/details/52374498][https_blog.csdn.net_sinat_25306771_article_details_52374498]  
3.从实际案例聊聊Java应用的GC优化 [https://tech.meituan.com/2017/12/29/jvm-optimize.html][https_tech.meituan.com_2017_12_29_jvm-optimize.html]  
4.垃圾回收算法 [https://blog.csdn.net/d6619309/article/details/53358250][https_blog.csdn.net_d6619309_article_details_53358250]  
5.**关于Jvm知识看这一篇就够了**[https://zhuanlan.zhihu.com/p/34426768?group\_id=956114978579750912][https_zhuanlan.zhihu.com_p_34426768_group_id_956114978579750912]

转载于:https://www.cnblogs.com/georgexu/p/11224133.html

[1034798-20190720170653106-1541459293.png]: /images/20211029/428faa4c8cde4149801edfa10887ba05.png
[copycode.gif]: /images/20211029/ea5f40bf5be84f1a8061580393eb627c.png
[https_segmentfault.com_a_1190000004303843]: https://segmentfault.com/a/1190000004303843
[https_blog.csdn.net_sinat_25306771_article_details_52374498]: https://blog.csdn.net/sinat_25306771/article/details/52374498
[https_tech.meituan.com_2017_12_29_jvm-optimize.html]: https://tech.meituan.com/2017/12/29/jvm-optimize.html
[https_blog.csdn.net_d6619309_article_details_53358250]: https://blog.csdn.net/d6619309/article/details/53358250
[https_zhuanlan.zhihu.com_p_34426768_group_id_956114978579750912]: https://zhuanlan.zhihu.com/p/34426768?group_id=956114978579750912