java虚拟机调优_Java虚拟机性能调优（二）

学习JavaGuide性能调优时，场景模拟。(基础环境JDK1.8、SpringBoot)

一、模拟CPU占满场景

controller代码如下：

/*** 模拟CPU占满*/@GetMapping("/test/cpuLoop")public void testCPULoop() throwsInterruptedException {

System.out.println("请求cpu死循环");

Thread.currentThread().setName("loop-thread-cpu");int num = 0;while (true) {

num++;if (num ==Integer.MAX_VALUE) {

System.out.println("reset");

num= 0;

}//num = 0;

}

}

启动Jar包：

①java -jar -Xms256m -Xmx512m -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=./heapump.hprof -XX:+PrintGCTimeStamps -XX:+PrintGCDetails -Xloggc:./log.log ptDemo.jar&

②查看Linux进程：

jps -mlVv

11862 sun.tools.jps.Jps -mlVv -Dapplication.home=/usr/local/java/jdk1.8.0_144 -Xms8m

10319 ptDemo.jar

请求接口/test/cpuLoop。

1、查看Java进程10319的线程

[root@docker wangymd]# top -Hp 10319top- 00:35:51 up 4:05, 1 user, load average: 1.00, 1.00, 1.04Threads:29 total, 1 running, 28 sleeping, 0 stopped, 0zombie%Cpu(s): 50.4 us, 0.3 sy, 0.0 ni, 49.2 id, 0.0 wa, 0.0 hi, 0.0 si, 0.0st

KiB Mem :1863236 total, 396196 free, 493100 used, 973940 buff/cache

KiB Swap:2097148 total, 2097148 free, 0 used. 1166776avail Mem

PID USER PR NI VIRT RES SHR S%CPU %MEM TIME+COMMAND10339 root 20 0 2990792 290080 13588 R 99.7 15.6 239:05.43java10338 root 20 0 2990792 290080 13588 S 0.3 15.6 0:43.63java10341 root 20 0 2990792 290080 13588 S 0.3 15.6 0:43.91java10319 root 20 0 2990792 290080 13588 S 0.0 15.6 0:00.00java10320 root 20 0 2990792 290080 13588 S 0.0 15.6 0:14.85java10321 root 20 0 2990792 290080 13588 S 0.0 15.6 0:06.14java10322 root 20 0 2990792 290080 13588 S 0.0 15.6 0:06.12java10323 root 20 0 2990792 290080 13588 S 0.0 15.6 0:12.28java10324 root 20 0 2990792 290080 13588 S 0.0 15.6 0:00.03java10325 root 20 0 2990792 290080 13588 S 0.0 15.6 0:00.04 java

系统进程10319中线程PID10339使用CPU99.7%。

2、执行 printf '%x' 10339 转换为16进制的线程id，用于dump信息查询，结果为2863。最后我们执行jstack 10339 |grep -A 20 2863来查看下详细的dump信息。

[root@docker wangymd]# printf '%x' 10339

2863

[root@docker wangymd]# jstack 10319 |grep -A 20 2863

"loop-thread-cpu" #17 daemon prio=5 os_prio=0 tid=0x00007f7be09ec000 nid=0x2863 runnable [0x00007f7bc9222000]

java.lang.Thread.State: RUNNABLE

at com.javaguide.pt.Application.testCPULoop(Application.java:45)

at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)

at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)

at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)

at java.lang.reflect.Method.invoke(Method.java:498)

at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:190)

at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:138)

at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:105)

at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:879)

at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:793)

at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87)

at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1040)

at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:943)

at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1006)

at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:898)

at javax.servlet.http.HttpServlet.service(HttpServlet.java:634)

at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:883)

at javax.servlet.http.HttpServlet.service(HttpServlet.java:741)

at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231)

定位到问题，标红位置！

二、模拟内存泄漏场景

内存泄漏(Memory Leak)是指程序中己动态分配的堆内存由于某种原因程序未释放或无法释放，造成系统内存的浪费，导致程序运行速度减慢甚至系统崩溃等严重后果。

模拟内存泄漏借助了ThreadLocal对象来完成，ThreadLocal是一个线程私有变量，可以绑定到线程上，在整个线程的生命周期都会存在，但是由于ThreadLocal的特殊性，ThreadLocal是基于ThreadLocalMap实现的，ThreadLocalMap的Entry继承WeakReference，而Entry的Key是WeakReference的封装，换句话说Key就是弱引用，弱引用在下次GC之后就会被回收，如果ThreadLocal在set之后不进行后续的操作，因为GC会把Key清除掉，但是Value由于线程还在存活，所以Value一直不会被回收，最后就会发生内存泄漏。

1、controller代码如下：

1 /**

2 * 模拟内存泄漏3 */

4 @GetMapping(value = "/test/memoryLeak")5 publicString memoryLeak() {6 System.out.println("模拟内存泄漏");7 ThreadLocal localVariable = new ThreadLocal();8 localVariable.set(new Byte[4096 * 1024]);//为线程添加变量

9 return "ok";10 }

2、调用100次

for i in {1..100}; do curl localhost:8080/test/memoryLeak;done

调用未结束发生接口500错误。

3、日志错误信息：

java.lang.OutOfMemoryError: Java heap space

at com.javaguide.pt.Application.memoryLeak(Application.java:57) ~[classes!/:0.0.1-SNAPSHOT]

at sun.reflect.GeneratedMethodAccessor20.invoke(Unknown Source)~[na:na]

at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_144]

at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_144]

4、jstat命令查看GC情况

[root@docker wangymd]# jstat -gc 10956S0C S1C S0U S1U EC EU OC OU MC MU CCSC CCSU YGC YGCT FGC FGCT GCT12288.0 11776.0 0.0 0.0 150528.0 21923.8 349696.0 255003.2 35456.0 33371.2 4480.0 4110.0 9 0.715 32 7.000 7.715[root@docker wangymd]# jstat-gcutil 10956S0 S1 E O M CCS YGC YGCT FGC FGCT GCT0.00 0.00 22.34 72.92 94.12 91.74 9 0.715 32 7.000 7.715

Full GC发生32次，GC总耗时7.715秒。此时发生内存溢出，堆内存中的对象未被回收。堆内存中的对象被引用，不能进行回收，可能是内存泄漏导致。通过使用MAT工具进一步进行分析。

5、内存分析

内存分析-概述：

内存分析-内存泄漏(存在4个可疑问题)：

内存分析-内存泄漏-怀疑问题1：

这里已经指出了内存被线程占用了接近50M的内存，占用的对象就是ThreadLocal。如果想详细的通过手动去分析的话，可以点击Histogram,查看最大的对象占用是谁，然后再分析它的引用关系，即可确定是谁导致的内存溢出。

内存分析-内存泄漏-怀疑问题1-Histogram：

上图发现占用内存最大的对象是一个Byte数组，我们看看它到底被那个GC Root引用导致没有被回收。按照上图红框操作指引，结果如下图：

发现Byte数组是被线程对象引用的，Byte数组对像的GC Root是线程，所以它是不会被回收的；展开详细信息，发现最终的内存占用对象是被ThreadLocal对象占据了。

这也和MAT工具自动帮我们分析的结果一致。

三、模拟死锁场景

死锁会导致耗尽线程资源，占用内存，表现就是内存占用升高，CPU不一定会飙升(看场景决定)，如果是直接new线程，会导致JVM内存被耗尽，报无法创建线程的错误，这也是体现了使用线程池的好处。

//线程池

ExecutorService service = new ThreadPoolExecutor(4, 10, 0, TimeUnit.SECONDS,new LinkedBlockingQueue(1024), Executors.defaultThreadFactory(),newThreadPoolExecutor.AbortPolicy());/*** 模拟死锁*/@GetMapping("/test/deadlock")public String deadlock() throwsInterruptedException {

System.out.println("请求cpu");

Object lock1= newObject();

Object lock2= newObject();

service.submit(new DeadLockThread(lock1, lock2), "deadLookThread-" + newRandom().nextInt());

service.submit(new DeadLockThread(lock2, lock1), "deadLookThread-" + newRandom().nextInt());return "ok";

}public class DeadLockThread implementsRunnable {privateObject lock1;privateObject lock2;publicDeadLockThread(Object lock1, Object lock2) {this.lock1 =lock1;this.lock2 =lock2;

}

@Overridepublic voidrun() {synchronized(lock2) {

System.out.println(Thread.currentThread().getName()+ "get lock2 and wait lock1");try{

TimeUnit.MILLISECONDS.sleep(2000);

}catch(InterruptedException e) {

e.printStackTrace();

}synchronized(lock1) {

System.out.println(Thread.currentThread().getName()+ "get lock1 and lock2 ");

}

}

}

}

请求接口：/test/deadlock

循环调用1000次接口：for i in {1..1000}; do curl localhost:8080/test/deadlock; done。接口报500错误详细信息如下：

{"timestamp":"2020-05-18T06:30:14.046+0000","status":500,"error":"Internal Server Error","message":"Task java.util.concurrent.FutureTask@4c8896c2 rejected from java.util.concurrent.ThreadPoolExecutor@50d9e1b6[Running, pool size = 10, active threads = 10, queued tasks = 1024, completed tasks = 0]","path":"/test/deadlock"}

线程池和队列都满了,由于选择拒绝策略，所以系统直接抛出异常。

通过jstack 10956查看线程堆栈跟踪信息，发现5个死锁，下面列出第一个。

"pool-1-thread-2":

at com.javaguide.pt.Application$DeadLockThread.run(Application.java:97)- waiting to lock <0x00000000ec987e80> (a java.lang.Object)

- locked <0x00000000ec987e90>(a java.lang.Object)

at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)

at java.util.concurrent.FutureTask.run(FutureTask.java:266)

at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)

at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)

at java.lang.Thread.run(Thread.java:748)"pool-1-thread-1":

at com.javaguide.pt.Application$DeadLockThread.run(Application.java:97)- waiting to lock <0x00000000ec987e90> (a java.lang.Object)

- locked <0x00000000ec987e80>(a java.lang.Object)

at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)

at java.util.concurrent.FutureTask.run(FutureTask.java:266)

at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)

at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)

at java.lang.Thread.run(Thread.java:748)

Found5 deadlocks.

线程pool-1-thread-2锁定0x00000000ec987e80，等待0x00000000ec987e90锁；线程pool-1-thread-1锁定0x00000000ec987e90，等待锁0x00000000ec987e80,从而产生死锁。

四、线程频繁切换场景

重新启动服务，新的进程Id是14084。

上下文切换会导致将大量CPU时间浪费在寄存器、内核栈以及虚拟内存的保存和恢复上，导致系统整体性能下降。当你发现系统的性能出现明显的下降时候，需要考虑是否发生了大量的线程上下文切换。

@GetMapping(value = "/test/threadSwap")public String theadSwap(intnum) {

System.out.println("模拟线程切换");for (int i = 0; i < num; i++) {new Thread(new ThreadSwap1(new AtomicInteger(0)), "thread-swap" +i).start();

}return "ok";

}public class ThreadSwap1 implementsRunnable {privateAtomicInteger integer;publicThreadSwap1(AtomicInteger integer) {this.integer =integer;

}

@Overridepublic voidrun() {while (true) {

integer.addAndGet(1);

Thread.yield();//让出CPU资源

}

}

}

1、创建多个线程去执行基础的原子+1操作，然后让出 CPU 资源，理论上 CPU 就会去调度别的线程，我们请求接口创建100个线程看看效果如何，curl localhost:8080/thread/swap?num=100。接口请求成功后，我们执行`vmstat 1 10，表示每1秒打印一次，打印10次，线程切换采集结果如下：

procs -----------memory---------- ---swap-- -----io---- -system-- ------cpu-----r b swpd free buff cache si so bi bo in cs us sy id wa st5 0 1544 769336 316 559656 0 0 52 76 391 502 3 5 91 1 0

101 0 1544 769328 316 559664 0 0 0 0 2081 344337 30 70 0 0 0

103 0 1544 769328 316 559668 0 0 0 0 2096 390859 25 76 0 0 0

102 0 1544 769328 316 559668 0 0 0 0 794 462564 25 75 0 0 0

104 0 1544 769328 316 559672 0 0 0 0 773 461674 24 76 0 0 0

101 0 1544 769328 316 559672 0 0 0 0 1515 443980 24 76 0 0 0

101 0 1544 769328 316 559676 0 0 0 0 1712 441115 28 72 0 0 0

101 0 1544 769328 316 559676 0 0 0 0 1681 461222 24 75 1 0 0

101 0 1544 769204 316 559680 0 0 0 0 1966 404770 22 78 0 0 0

101 0 1544 769204 316 559680 0 0 0 0 2051 397209 24 77 0 0 0

r：进程数100；cs：每秒上线文及切换近40万；us：用户占用CPU24%的时间片；sy：系统占用CPU76%的时间片。

2、top命令：

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+COMMAND14084 root 20 0 3152276 314796 13444 S 190.7 16.9 9:28.02 java

3、top -Hp 14084命令：

14138 root 20 0 3152276 335072 13444 R 2.3 18.0 0:07.14java14092 root 20 0 3152276 335072 13444 R 2.0 18.0 0:33.05java14131 root 20 0 3152276 335072 13444 R 2.0 18.0 0:07.09java14134 root 20 0 3152276 335072 13444 R 2.0 18.0 0:07.15java14136 root 20 0 3152276 335072 13444 R 2.0 18.0 0:07.14java14140 root 20 0 3152276 335072 13444 R 2.0 18.0 0:07.10java14144 root 20 0 3152276 335072 13444 R 2.0 18.0 0:07.03java14149 root 20 0 3152276 335072 13444 R 2.0 18.0 0:07.05java14153 root 20 0 3152276 335072 13444 R 2.0 18.0 0:07.03java14154 root 20 0 3152276 335072 13444 R 2.0 18.0 0:06.88java14158 root 20 0 3152276 335072 13444 R 2.0 18.0 0:07.00java14159 root 20 0 3152276 335072 13444 R 2.0 18.0 0:06.92java14160 root 20 0 3152276 335072 13444 R 2.0 18.0 0:06.89java14161 root 20 0 3152276 335072 13444 R 2.0 18.0 0:06.93java14162 root 20 0 3152276 335072 13444 R 2.0 18.0 0:06.87java14163 root 20 0 3152276 335072 13444 R 2.0 18.0 0:06.87java14164 root 20 0 3152276 335072 13444 R 2.0 18.0 0:06.86java14165 root 20 0 3152276 335072 13444 R 2.0 18.0 0:06.84java14166 root 20 0 3152276 335072 13444 R 2.0 18.0 0:06.88java14167 root 20 0 3152276 335072 13444 R 2.0 18.0 0:06.83java14170 root 20 0 3152276 335072 13444 R 2.0 18.0 0:06.90java14182 root 20 0 3152276 335072 13444 R 2.0 18.0 0:06.71java14185 root 20 0 3152276 335072 13444 R 2.0 18.0 0:06.65java14186 root 20 0 3152276 335072 13444 R 2.0 18.0 0:06.66java14187 root 20 0 3152276 335072 13444 R 2.0 18.0 0:06.75java14194 root 20 0 3152276 335072 13444 R 2.0 18.0 0:06.60java14195 root 20 0 3152276 335072 13444 R 2.0 18.0 0:06.55java14199 root 20 0 3152276 335072 13444 R 2.0 18.0 0:06.47java14202 root 20 0 3152276 335072 13444 R 2.0 18.0 0:06.52java14205 root 20 0 3152276 335072 13444 R 2.0 18.0 0:06.54java14208 root 20 0 3152276 335072 13444 R 2.0 18.0 0:06.45java14213 root 20 0 3152276 335072 13444 R 2.0 18.0 0:06.38java14216 root 20 0 3152276 335072 13444 R 2.0 18.0 0:06.35 java

Java进程将CPU占满，但是线程使用CPU很平均。

结合上面用户态CPU只使用了24%，内核态CPU占用了76%，可以基本判断是Java程序线程上下文切换导致性能问题。

4、使用pidstat命令来看看Java进程内部的线程切换数据，执行pidstat -p 14084 -w 1 10：

深入理解Linux的CPU上下文切换