SpringBoot项目调优及垃圾回收器的比较详解
时间：2020-10-28 16:54:51 | 栏目：JAVA代码 | 点击：次
一、SpringBoot项目在外部Tomcat启动时加载两次
如下所示，spring标志出现两次(截取部分代码)
. ____ _ __ _ _ /\\ / ___'_ __ _ _(_)_ __ __ _ \ \ \ \ ( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \ \\/ ___)| |_)| | | | | || (_| | ) ) ) ) ' |____| .__|_| |_|_| |_\__, | / / / / =========|_|==============|___/=/_/_/_/ :: Spring Boot :: (v1.5.7.RELEASE) 2020-04-02 16:57:29.505 INFO 19964 --- [ost-startStop-1] com.pitt.kill.server.MainApplication : Starting MainApplication on LAPTOP-1U9EARRO with PID 19964 (D:\apache-tomcat-8.5.42\apache-tomcat-8.5.42\webapps\kill-0.0.1-SNAPSHOT\WEB-INF\classes started by pitt in C:\Users\pitt\AppData\Local\MyEclipse 2017 CI) 2020-04-02 16:57:29.508 DEBUG 19964 --- [ost-startStop-1] com.pitt.kill.server.MainApplication : Running with Spring Boot v1.5.7.RELEASE, Spring v4.3.11.RELEASE 2020-04-02 16:57:29.509 INFO 19964 --- [ost-startStop-1] com.pitt.kill.server.MainApplication : No active profile set, falling back to default profiles: default 2020-04-02 16:57:29.539 INFO 19964 --- [ost-startStop-1] ationConfigEmbeddedWebApplicationContext : Refreshing org.springframework.boot.context.embedded.AnnotationConfigEmbeddedWebApplicationContext@1e20bc0d: startup date [Thu Apr 02 16:57:29 GMT+08:00 2020]; root of context hierarchy 2020-04-02 16:57:30.097 INFO 19964 --- [ost-startStop-1] o.s.b.f.xml.XmlBeanDefinitionReader : Loading XML bean definitions from class path resource [spring/spring-jdbc.xml] 2020-04-02 16:57:30.141 WARN 19964 --- [ost-startStop-1] o.m.s.mapper.ClassPathMapperScanner : No MyBatis mapper was found in '[com.pitt.kill.model.mapper]' package. Please check your configuration. 2020-04-02 16:57:30.258 WARN 19964 --- [ost-startStop-1] o.m.s.mapper.ClassPathMapperScanner : No MyBatis mapper was found in '[com.pitt.kill.server]' package. Please check your configuration. 2020-04-02 16:57:30.307 INFO 19964 --- [ost-startStop-1] .s.d.r.c.RepositoryConfigurationDelegate : Multiple Spring Data modules found, entering strict repository configuration mode! . ____ _ __ _ _ /\\ / ___'_ __ _ _(_)_ __ __ _ \ \ \ \ ( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \ \\/ ___)| |_)| | | | | || (_| | ) ) ) ) ' |____| .__|_| |_|_| |_\__, | / / / / =========|_|==============|___/=/_/_/_/ :: Spring Boot :: (v1.5.7.RELEASE) 2020-04-02 16:57:37.069 INFO 19964 --- [ost-startStop-1] com.pitt.kill.server.MainApplication : Starting MainApplication on LAPTOP-1U9EARRO with PID 19964 (D:\apache-tomcat-8.5.42\apache-tomcat-8.5.42\webapps\server\WEB-INF\classes started by pitt in C:\Users\pitt\AppData\Local\MyEclipse 2017 CI) 2020-04-02 16:57:37.072 DEBUG 19964 --- [ost-startStop-1] com.pitt.kill.server.MainApplication : Running with Spring Boot v1.5.7.RELEASE, Spring v4.3.11.RELEASE 2020-04-02 16:57:37.072 INFO 19964 --- [ost-startStop-1] com.pitt.kill.server.MainApplication : No active profile set, falling back to default profiles: default 2020-04-02 16:57:37.102 INFO 19964 --- [ost-startStop-1] ationConfigEmbeddedWebApplicationContext : Refreshing org.springframework.boot.context.embedded.AnnotationConfigEmbeddedWebApplicationContext@1565ae71: startup date [Thu Apr 02 16:57:37 GMT+08:00 2020]; root of context hierarchy 2020-04-02 16:57:37.675 INFO 19964 --- [ost-startStop-1] o.s.b.f.xml.XmlBeanDefinitionReader : Loading XML bean definitions from class path resource [spring/spring-jdbc.xml] 2020-04-02 16:57:37.863 INFO 19964 --- [ost-startStop-1] .s.d.r.c.RepositoryConfigurationDelegate : Multiple Spring Data modules found, entering strict repository configuration mode! 2020-04-02 16:57:38.422 INFO 19964 --- [ost-startStop-1] trationDelegate$BeanPostProcessorChecker : Bean 'org.springframework.amqp.rabbit.annotation.RabbitBootstrapConfiguration' of type [org.springframework.amqp.rabbit.annotation.RabbitBootstrapConfiguration$$EnhancerBySpringCGLIB$$6cdea02f] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying) 2020-04-02 16:57:38.456 INFO 19964 --- [ost-startStop-1] trationDelegate$BeanPostProcessorChecker : Bean 'shiroConfig' of type [com.pitt.kill.server.config.ShiroConfig$$EnhancerBySpringCGLIB$$4392bed0] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
加载时间30s
2020-04-02 16:57:42.825 INFO 19964 --- [ost-startStop-1] com.pitt.kill.server.MainApplication : Started MainApplication in 6.091 seconds (JVM running for 30.348) 2020-04-02 16:57:42.946 INFO 19964 --- [ main] org.apache.catalina.startup.Catalina : Server startup in 29361 ms
原因：打开配置文件server.xml，Tomcat在启动web项目时，会首先在Host标签中找webapps下的项目，进行加载后，又会在Context 标签中再次加载，导致加载两次
解决: 将appBase="webapps"替换为appBase = " "
<Host appBase="webapps" autoDeploy="true" name="localhost" unpackWARs="true">
<Context docBase="D:\apache-tomcat-8.5.42\apache-tomcat-8.5.42\webapps\server" path="" reloadable="true" source="org.eclipse.jst.jee.server:server"/>
加载一次时间为12s
2020-04-02 17:03:12.759 INFO 952 --- [ost-startStop-1] com.pitt.kill.server.MainApplication : Started MainApplication in 7.478 seconds (JVM running for 12.532) 2020-04-02 17:03:13.100 INFO 952 --- [ main] org.apache.catalina.startup.Catalina : Server startup in 11772 ms
二、禁用字节码验证过程
对类的加载时间进行优化，首先查看类的加载时间
C:\Program Files\Java\jdk1.8.0_211\bin>jps 16612 QuorumPeerMain 9172 Main 19416 MyEclipse 952 Bootstrap 19580 Jps C:\Program Files\Java\jdk1.8.0_211\bin>jstat -class 952 Loaded Bytes Unloaded Bytes Time 10533 20062.0 0 0.0 7.83
我们默认通过MyEclipse编译的代码是可靠的，不需要在加载的时候进行字节码验证，使用-Xverify:none参数将字节码验证过程禁用掉，来提升类的加载速度
C:\Program Files\Java\jdk1.8.0_211\bin>jstat -class 12308 Loaded Bytes Unloaded Bytes Time 9822 18874.2 0 0.0 6.70
提升效果一般，只减少了1s
此外由于HotSpot采用了JIT编译器可以提前加载热代码，1.8版本JVM的代码编译速度已经比较优秀，此处不做优化
三、调整内存设置控制垃圾收集频率
Java8默认的GC回收器为Parallel Scavenge + Parallel Old
用Jmeter发送请求作为辅助测试
可以看到，测试时间内，发起了103次Minor GC，耗时不到1s，其实时间停顿并不多，但是5次Full GC占用了很大部分的GC时间，主要针对这部分时间进行优化。通过-Xloggc:gc.log -XX:+PrintGCTimeStamps -XX:+PrintGCDetails参数打印GC日志，将Full GC挑出如下：
7.934: [Full GC (Metadata GC Threshold) [PSYoungGen: 926K->0K(647680K)] [ParOldGen: 54198K->15711K(65024K)] 55125K->15711K(712704K), [Metaspace: 20674K->20674K(1069056K)], 0.0303162 secs] [Times: user=0.03 sys=0.00, real=0.03 secs] 10.430: [Full GC (Metadata GC Threshold) [PSYoungGen: 3883K->0K(646656K)] [ParOldGen: 20986K->17184K(80896K)] 24870K->17184K(727552K), [Metaspace: 34377K->34377K(1081344K)], 0.0413074 secs] [Times: user=0.28 sys=0.00, real=0.04 secs] 379.971: [Full GC (Metadata GC Threshold) [PSYoungGen: 2528K->0K(93696K)] [ParOldGen: 65885K->58730K(132096K)] 68413K->58730K(225792K), [Metaspace: 57642K->57535K(1101824K)], 0.3908541 secs] [Times: user=0.97 sys=0.00, real=0.39 secs] 390.977: [Full GC (Ergonomics) [PSYoungGen: 8688K->0K(230400K)] [ParOldGen: 129221K->120704K(226304K)] 137909K->120704K(456704K), [Metaspace: 62151K->62115K(1105920K)], 0.1319683 secs] [Times: user=0.50 sys=0.02, real=0.13 secs] 553.770: [Full GC (Ergonomics) [PSYoungGen: 47104K->0K(513536K)] [ParOldGen: 228052K->120789K(249344K)] 275156K->120789K(762880K), [Metaspace: 62330K->62330K(1105920K)], 0.1344527 secs] [Times: user=0.27 sys=0.02, real=0.13 secs]
每一次Full GC都伴随着老年代的扩容，日志还显示有时候内存回收状况不理想，获取可用的内存主要通过空间的扩容。
查看运行期间的CPU使用情况，如下图：
垃圾回收的CPU使用率曲线几乎看不到，CPU资源还有可利用的余地，为此想到更换原有的垃圾回收器来进行GC优化
CMS:
相比于默认的Parallel GC明显改善了Full GC所消耗的时间，Stop The World时间减少，但是Minor GC大量增加，尝试调整新生代的大小来减少Minor GC的产生，在使用-XX:NewRatio=1 -XX:SurvivorRatio=3
-XX:+UseConcMarkSweepGC -XX:CMSInitiatingOccupancyFraction=85参数进行调整后，Minor GC数量下降，但是相比而言还是很多
G1:
G1为最新的垃圾回收算法，将新生代和老年代同时进行标记和回收，采用标记-整理算法，不会产生内存碎片，在时间消耗上表现的最好，平均每次回收占用的时间最短，并且最好在内存比较大的机器上使用G1算法进行回收
G1的优势在于:
作为CMS的长期替代品
1、G1是一个压缩收集器，提供足够强的压缩来完全避免狭小的内存分配
2、依赖Regions概念，大大简化收集器逻辑，大部分情况下规避潜在的内存碎片问题
3、比CMS的GC停顿时长更加可预测，并允许用户指定停顿时长
总结:
以上三种回收器都为多线程垃圾回收器，但是对于不同的环境，应该具体问题具体分析，而不是采用一刀切的方法，解决问题的过程即为寻找最优解的过程。