jvm调优工具详解及调优实战

只有不断努力,你才能走向成功。不要因为一时的挫折而放弃,相信自己的潜力是无限的。

不了解jvm内存结构和垃圾回收机制的可以查看我上篇文章jvm内存模型及垃圾回收机制

前置工作

首先本地启动一个java项目

jps查看进程

dongfengfan@dongfengdeMacBook-Pro ~/Desktop> jps
27377 Jps
27080 DemoApplication
26862 RemoteMavenServer
26783

27080 DemoApplication 这个是我刚启动的springboot项目。

jmap

jmap 可以查看内存信息,实例个数以及占用内存大小。

jmap -histo 27080 > ./log.txt

打开log.txt查看内容

num #instances #bytes class name
----------------------------------------------
1: 4463 9008256 [I
2: 10554 7602216 [B
3: 43130 5308888 [C
4: 11036 971168 java.lang.reflect.Method
5: 39181 940344 java.lang.String
6: 6514 718992 java.lang.Class
7: 14863 475616 java.util.concurrent.ConcurrentHashMap$Node
8: 7641 398064 [Ljava.lang.Object;
9: 4328 355696 [Ljava.util.HashMap$Node;
10: 8130 325200 java.util.LinkedHashMap$Entry
11: 8023 256736 java.util.HashMap$Node

中间省略

2966: 1 16 sun.util.locale.provider.AuxLocaleProviderAdapter$NullProvider
2967: 1 16 sun.util.locale.provider.CalendarDataUtility$CalendarWeekParameterGetter
2968: 1 16 sun.util.locale.provider.SPILocaleProviderAdapter
2969: 1 16 sun.util.locale.provider.TimeZoneNameUtility$TimeZoneNameGetter
2970: 1 16 sun.util.resources.LocaleData
2971: 1 16 sun.util.resources.LocaleData$LocaleDataResourceBundleControl
Total 287011 30963480
  • num: 序号

  • instances: 实例数量

  • bytes: 占用空间大小

  • class name: 类名称,C is a char[]],S is a short[],I is a int[], B is a byte[]

堆信息

dongfengfan@dongfengdeMacBook-Pro ~/Desktop> jmap -heap 27080
Attaching to process ID 27080, please wait...
Debugger attached successfully.
Server compiler detected.
JVM version is 25.141-b15

using thread-local object allocation.
Parallel GC with 8 thread(s)

#堆配置
Heap Configuration:
MinHeapFreeRatio = 0
MaxHeapFreeRatio = 100
#最大堆内存空间
MaxHeapSize = 2147483648 (2048.0MB)
#新生代容量
NewSize = 44564480 (42.5MB)
#新生代最大容量
MaxNewSize = 715653120 (682.5MB)
#老年代
OldSize = 89653248 (85.5MB)
NewRatio = 2
SurvivorRatio = 8
MetaspaceSize = 21807104 (20.796875MB)
CompressedClassSpaceSize = 1073741824 (1024.0MB)
MaxMetaspaceSize = 17592186044415 MB
G1HeapRegionSize = 0 (0.0MB)

#堆使用情况
Heap Usage:
PS Young Generation
Eden Space:
capacity = 99614720 (95.0MB)
used = 11697456 (11.155563354492188MB)
free = 87917264 (83.84443664550781MB)
11.742698267886514% used
From Space:
capacity = 9437184 (9.0MB)
used = 9421384 (8.984931945800781MB)
free = 15800 (0.01506805419921875MB)
99.83257717556424% used
To Space:
capacity = 10485760 (10.0MB)
used = 0 (0.0MB)
free = 10485760 (10.0MB)
0.0% used
PS Old Generation
capacity = 62914560 (60.0MB)
used = 9844640 (9.388580322265625MB)
free = 53069920 (50.611419677734375MB)
15.647633870442709% used

13089 interned Strings occupying 1106208 bytes.
dongfengfan@dongfengdeMacBook-Pro ~/Desktop>

堆内存dump

dongfengfan@dongfengdeMacBook-Pro ~/Desktop> jmap -dump:format=b,file=./demo.hprof 27080
Dumping heap to /Users/dongfengfan/Desktop/demo.hprof ...
Heap dump file created
dongfengfan@dongfengdeMacBook-Pro ~/Desktop>

可以使用jdk自带的jvisualvm查看

dongfengfan@dongfengdeMacBook-Pro ~/Desktop> jvisualvm
2023-03-05 21:52:25.158 java[27781:892733] *** WARNING: Textured window <AWTWindow_Normal: 0x7fb86403f670> is getting an implicitly transparent titlebar. This will break when linking against newer SDKs. Use NSWindow's -titlebarAppearsTransparent=YES instead.

也可以使用JProfiler查看


jvm调优工具详解及调优实战

OK,我们现在来模拟一个OOM的场景

@Data
@AllArgsConstructor
public class User {

private int id;
private String name;

}
public class OOMTest {

/**
* 静态变量,保存在堆中,防止被回收
*/
public static List<Object> list = new ArrayList<>();

/**
* JVM设置, -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=G:dump.hprof 内存溢出前导出文件
* -Xms5M -Xmx5M -XX:+PrintGCDetails -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=G:dump.hprof
*/
public static void main(String[] args) {
int a = 0;
int b = 0;
while (true) {
list.add(new User(a++, UUID.randomUUID().toString()));
new User(b--, UUID.randomUUID().toString());
}
}
}

启动后运行几秒钟后出现OOM异常,并将堆栈信息打印到G盘

java -jar -Xms5M -Xmx5M -XX:+PrintGCDetails -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=G:dump.hprof test-1.0.0.jar

报错信息如下

···省略部分日志
[Full GC (Ergonomics) [PSYoungGen: 1024K->1023K(1536K)] [ParOldGen: 4093K->4093K(4096K)] 5117K->5117K(5632K), [Metaspace: 19310K->19310K(1067008K)], 0.0114855 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]
[Full GC (Allocation Failure) [PSYoungGen: 1023K->987K(1536K)] [ParOldGen: 4093K->4093K(4096K)] 5117K->5081K(5632K), [Metaspace: 19310K->19310K(1067008K)], 0.0098486 secs] [Times: user=0.09 sys=0.00, real=0.01 secs]
[Full GC (Ergonomics) [PSYoungGen: 1017K->1001K(1536K)] [ParOldGen: 4093K->4093K(4096K)] 5111K->5095K(5632K), [Metaspace: 19310K->19310K(1067008K)], 0.0101730 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]
[Full GC (Allocation Failure) [PSYoungGen: 1001K->1001K(1536K)] [ParOldGen: 4093K->4093K(4096K)] 5095K->5095K(5632K), [Metaspace: 19310K->19310K(1067008K)], 0.0116407 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]
java.lang.OutOfMemoryError: Java heap space
Dumping heap to G:dump.hprof ...
Heap dump file created [10757468 bytes in 0.040 secs]
[Full GC (Ergonomics) [PSYoungGen: 1024K->943K(1536K)] [ParOldGen: 4095K->4080K(4096K)] 5119K->5023K(5632K), [Metaspace: 19311K->19311K(1067008K)], 0.0109664 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]
2023-03-20 11:47:57.206 WARN 14204 --- [ main] ConfigServletWebServerApplicationContext : Exception encountered during context initialization - cancelling refresh attempt: org.springframework.beans.factory.BeanDefinitionStoreException: Failed to process import candidates for configuration class [com.fandf.test.Application]; nested exception is java.lang.OutOfMemoryError: Java heap space
[Full GC (Ergonomics) [PSYoungGen: 1024K->412K(1536K)] [ParOldGen: 4080K->3936K(4096K)] 5104K->4349K(5632K), [Metaspace: 19383K->19381K(1067008K)], 0.0414265 secs] [Times: user=0.02 sys=0.00, real=0.04 secs]
2023-03-20 11:47:57.285 INFO 14204 --- [ main] ConditionEvaluationReportLoggingListener :

Error starting ApplicationContext. To display the conditions report re-run your application with 'debug' enabled.
[GC (Allocation Failure) [PSYoungGen: 1024K->512K(1536K)] 4960K->4552K(5632K), 0.0035359 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
[Full GC (Ergonomics) [PSYoungGen: 512K->463K(1536K)] [ParOldGen: 4040K->3968K(4096K)] 4552K->4431K(5632K), [Metaspace: 19488K->19488K(1067008K)], 0.0593039 secs] [Times: user=0.16 sys=0.00, real=0.06 secs]
[Full GC (Ergonomics) [PSYoungGen: 1487K->457K(1536K)] [ParOldGen: 3968K->4054K(4096K)] 5455K->4511K(5632K), [Metaspace: 19548K->19548K(1067008K)], 0.0231957 secs] [Times: user=0.16 sys=0.00, real=0.02 secs]
[Full GC (Ergonomics) [PSYoungGen: 1481K->448K(1536K)] [ParOldGen: 4054K->4073K(4096K)] 5535K->4522K(5632K), [Metaspace: 19654K->19654K(1067008K)], 0.0156454 secs] [Times: user=0.00 sys=0.00, real=0.02 secs]
[Full GC (Ergonomics) [PSYoungGen: 1466K->569K(1536K)] [ParOldGen: 4073K->4062K(4096K)] 5540K->4632K(5632K), [Metaspace: 19715K->19715K(1067008K)], 0.0260354 secs] [Times: user=0.06 sys=0.00, real=0.03 secs]
2023-03-20 11:47:57.417 ERROR 14204 --- [ main] o.s.boot.SpringApplication : Application run failed

org.springframework.beans.factory.BeanDefinitionStoreException: Failed to process import candidates for configuration class [com.fandf.test.Application]; nested exception is java.lang.OutOfMemoryError: Java heap space
at org.springframework.context.annotation.ConfigurationClassParser.processImports(ConfigurationClassParser.java:610) ~[spring-context-5.3.14.jar!/:5.3.14]
at org.springframework.context.annotation.ConfigurationClassParser.access$800(ConfigurationClassParser.java:111) ~[spring-context-5.3.14.jar!/:5.3.14]
at org.springframework.context.annotation.ConfigurationClassParser$DeferredImportSelectorGroupingHandler.lambda$processGroupImports$1(ConfigurationClassParser.java:812) ~[spring-context-5.3.14.jar!/:5.3.14]
at java.util.ArrayList.forEach(Unknown Source) ~[na:1.8.0_181]
at org.springframework.context.annotation.ConfigurationClassParser$DeferredImportSelectorGroupingHandler.processGroupImports(ConfigurationClassParser.java:809) ~[spring-context-5.3.14.jar!/:5.3.14]
at org.springframework.context.annotation.ConfigurationClassParser$DeferredImportSelectorHandler.process(ConfigurationClassParser.java:780) ~[spring-context-5.3.14.jar!/:5.3.14]
at org.springframework.context.annotation.ConfigurationClassParser.parse(ConfigurationClassParser.java:193) ~[spring-context-5.3.14.jar!/:5.3.14]
at org.springframework.context.annotation.ConfigurationClassPostProcessor.processConfigBeanDefinitions(ConfigurationClassPostProcessor.java:331) ~[spring-context-5.3.14.jar!/:5.3.14]
at org.springframework.context.annotation.ConfigurationClassPostProcessor.postProcessBeanDefinitionRegistry(ConfigurationClassPostProcessor.java:247) ~[spring-context-5.3.14.jar!/:5.3.14]
at org.springframework.context.support.PostProcessorRegistrationDelegate.invokeBeanDefinitionRegistryPostProcessors(PostProcessorRegistrationDelegate.java:311) ~[spring-context-5.3.14.jar!/:5.3.14]
at org.springframework.context.support.PostProcessorRegistrationDelegate.invokeBeanFactoryPostProcessors(PostProcessorRegistrationDelegate.java:112) ~[spring-context-5.3.14.jar!/:5.3.14]
at org.springframework.context.support.AbstractApplicationContext.invokeBeanFactoryPostProcessors(AbstractApplicationContext.java:746) ~[spring-context-5.3.14.jar!/:5.3.14]
at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:564) ~[spring-context-5.3.14.jar!/:5.3.14]
at org.springframework.boot.web.servlet.context.ServletWebServerApplicationContext.refresh(ServletWebServerApplicationContext.java:145) ~[spring-boot-2.5.8.jar!/:2.5.8]
at org.springframework.boot.SpringApplication.refresh(SpringApplication.java:765) [spring-boot-2.5.8.jar!/:2.5.8]
at org.springframework.boot.SpringApplication.refreshContext(SpringApplication.java:445) [spring-boot-2.5.8.jar!/:2.5.8]
at org.springframework.boot.SpringApplication.run(SpringApplication.java:338) [spring-boot-2.5.8.jar!/:2.5.8]
at org.springframework.boot.SpringApplication.run(SpringApplication.java:1354) [spring-boot-2.5.8.jar!/:2.5.8]
at org.springframework.boot.SpringApplication.run(SpringApplication.java:1343) [spring-boot-2.5.8.jar!/:2.5.8]
at com.fandf.test.Application.main(Application.java:18) [classes!/:na]
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_181]
at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source) ~[na:1.8.0_181]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) ~[na:1.8.0_181]
at java.lang.reflect.Method.invoke(Unknown Source) ~[na:1.8.0_181]
at org.springframework.boot.loader.MainMethodRunner.run(MainMethodRunner.java:49) [test-1.0.0.jar:na]
at org.springframework.boot.loader.Launcher.launch(Launcher.java:108) [test-1.0.0.jar:na]
at org.springframework.boot.loader.Launcher.launch(Launcher.java:58) [test-1.0.0.jar:na]
at org.springframework.boot.loader.JarLauncher.main(JarLauncher.java:88) [test-1.0.0.jar:na]
Caused by: java.lang.OutOfMemoryError: Java heap space
at java.util.Properties$LineReader.readLine(Unknown Source) ~[na:1.8.0_181]
at java.util.Properties.load0(Unknown Source) ~[na:1.8.0_181]
at java.util.Properties.load(Unknown Source) ~[na:1.8.0_181]
at org.springframework.core.io.support.PropertiesLoaderUtils.fillProperties(PropertiesLoaderUtils.java:153) ~[spring-core-5.3.14.jar!/:5.3.14]
at org.springframework.core.io.support.PropertiesLoaderUtils.loadProperties(PropertiesLoaderUtils.java:133) ~[spring-core-5.3.14.jar!/:5.3.14]
at org.springframework.core.io.support.SpringFactoriesLoader.loadSpringFactories(SpringFactoriesLoader.java:147) ~[spring-core-5.3.14.jar!/:5.3.14]
at org.springframework.core.io.support.SpringFactoriesLoader.loadFactoryNames(SpringFactoriesLoader.java:132) ~[spring-core-5.3.14.jar!/:5.3.14]
at org.springframework.core.io.support.SpringFactoriesLoader.loadFactories(SpringFactoriesLoader.java:101) ~[spring-core-5.3.14.jar!/:5.3.14]
at org.springframework.boot.autoconfigure.template.TemplateAvailabilityProviders.<init>(TemplateAvailabilityProviders.java:86) ~[spring-boot-autoconfigure-2.5.8.jar!/:2.5.8]
at org.springframework.boot.autoconfigure.web.servlet.error.ErrorMvcAutoConfiguration$ErrorTemplateMissingCondition.getMatchOutcome(ErrorMvcAutoConfiguration.java:185) ~[spring-boot-autoconfigure-2.5.8.jar!/:2.5.8]
at org.springframework.boot.autoconfigure.condition.SpringBootCondition.matches(SpringBootCondition.java:47) ~[spring-boot-autoconfigure-2.5.8.jar!/:2.5.8]
at org.springframework.context.annotation.ConditionEvaluator.shouldSkip(ConditionEvaluator.java:108) ~[spring-context-5.3.14.jar!/:5.3.14]
at org.springframework.context.annotation.ConfigurationClassParser.processConfigurationClass(ConfigurationClassParser.java:226) ~[spring-context-5.3.14.jar!/:5.3.14]
at org.springframework.context.annotation.ConfigurationClassParser.processMemberClasses(ConfigurationClassParser.java:372) ~[spring-context-5.3.14.jar!/:5.3.14]
at org.springframework.context.annotation.ConfigurationClassParser.doProcessConfigurationClass(ConfigurationClassParser.java:272) ~[spring-context-5.3.14.jar!/:5.3.14]
at org.springframework.context.annotation.ConfigurationClassParser.processConfigurationClass(ConfigurationClassParser.java:250) ~[spring-context-5.3.14.jar!/:5.3.14]
at org.springframework.context.annotation.ConfigurationClassParser.processImports(ConfigurationClassParser.java:600) ~[spring-context-5.3.14.jar!/:5.3.14]
at org.springframework.context.annotation.ConfigurationClassParser.access$800(ConfigurationClassParser.java:111) ~[spring-context-5.3.14.jar!/:5.3.14]
at org.springframework.context.annotation.ConfigurationClassParser$DeferredImportSelectorGroupingHandler.lambda$processGroupImports$1(ConfigurationClassParser.java:812) ~[spring-context-5.3.14.jar!/:5.3.14]
at org.springframework.context.annotation.ConfigurationClassParser$DeferredImportSelectorGroupingHandler$$Lambda$249/712256162.accept(Unknown Source) ~[na:na]
at java.util.ArrayList.forEach(Unknown Source) ~[na:1.8.0_181]
at org.springframework.context.annotation.ConfigurationClassParser$DeferredImportSelectorGroupingHandler.processGroupImports(ConfigurationClassParser.java:809) ~[spring-context-5.3.14.jar!/:5.3.14]
at org.springframework.context.annotation.ConfigurationClassParser$DeferredImportSelectorHandler.process(ConfigurationClassParser.java:780) ~[spring-context-5.3.14.jar!/:5.3.14]
at org.springframework.context.annotation.ConfigurationClassParser.parse(ConfigurationClassParser.java:193) ~[spring-context-5.3.14.jar!/:5.3.14]
at org.springframework.context.annotation.ConfigurationClassPostProcessor.processConfigBeanDefinitions(ConfigurationClassPostProcessor.java:331) ~[spring-context-5.3.14.jar!/:5.3.14]
at org.springframework.context.annotation.ConfigurationClassPostProcessor.postProcessBeanDefinitionRegistry(ConfigurationClassPostProcessor.java:247) ~[spring-context-5.3.14.jar!/:5.3.14]
at org.springframework.context.support.PostProcessorRegistrationDelegate.invokeBeanDefinitionRegistryPostProcessors(PostProcessorRegistrationDelegate.java:311) ~[spring-context-5.3.14.jar!/:5.3.14]
at org.springframework.context.support.PostProcessorRegistrationDelegate.invokeBeanFactoryPostProcessors(PostProcessorRegistrationDelegate.java:112) ~[spring-context-5.3.14.jar!/:5.3.14]
at org.springframework.context.support.AbstractApplicationContext.invokeBeanFactoryPostProcessors(AbstractApplicationContext.java:746) ~[spring-context-5.3.14.jar!/:5.3.14]
at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:564) ~[spring-context-5.3.14.jar!/:5.3.14]
at org.springframework.boot.web.servlet.context.ServletWebServerApplicationContext.refresh(ServletWebServerApplicationContext.java:145) ~[spring-boot-2.5.8.jar!/:2.5.8]
at org.springframework.boot.SpringApplication.refresh(SpringApplication.java:765) [spring-boot-2.5.8.jar!/:2.5.8]

Heap
PSYoungGen total 1536K, used 887K [0x00000000ffe00000, 0x0000000100000000, 0x0000000100000000)
eden space 1024K, 86% used [0x00000000ffe00000,0x00000000ffeddda0,0x00000000fff00000)
from space 512K, 0% used [0x00000000fff00000,0x00000000fff00000,0x00000000fff80000)
to space 512K, 0% used [0x00000000fff80000,0x00000000fff80000,0x0000000100000000)
ParOldGen total 4096K, used 4062K [0x00000000ffa00000, 0x00000000ffe00000, 0x00000000ffe00000)
object space 4096K, 99% used [0x00000000ffa00000,0x00000000ffdf7bd8,0x00000000ffe00000)
Metaspace used 19739K, capacity 20760K, committed 20992K, reserved 1067008K
class space used 2491K, capacity 2710K, committed 2816K, reserved 1048576K

使用jProfiler导入dump文件分析


jvm调优工具详解及调优实战

jstack

模拟死锁,使用jstack排查

public class DeadLockTest {

private static Object lock1 = new Object();
private static Object lock2 = new Object();


public static void main(String[] args) {
new Thread(() -> {
synchronized (lock1) {
try {
System.out.println("thread1 begin");
Thread.sleep(5000);
} catch (InterruptedException e) {

}
synchronized (lock2) {
System.out.println("thread1 end");
}
}
}).start();

new Thread(() -> {
synchronized (lock2) {
try {
System.out.println("thread2 begin");
Thread.sleep(5000);
} catch (InterruptedException e) {

}
synchronized (lock1) {
System.out.println("thread2 end");
}
}
}).start();
System.out.println("main thread end");
}

}

主线程结束,但是一直阻塞,未结束


jvm调优工具详解及调优实战

线程0和线程1都阻塞住了

jvm调优工具详解及调优实战

jvm调优工具详解及调优实战

“Thread-1” 线程名 

prio=5 优先级=5 

tid=0x000000001df63000 线程id 

nid=0x5528 线程对应的本地线程标识nid 

java.lang.Thread.State: BLOCKED 线程状态


使用jstack排查

☺ jps
1204 DeadLockTest
1285 Jps
1129 Launcher
830 RemoteMavenServer
591

~
☺ jstack 1204
2023-03-21 06:32:54
Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.141-b15 mixed mode):

"Attach Listener" #13 daemon prio=9 os_prio=31 tid=0x00007f9423009000 nid=0x3607 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE

"DestroyJavaVM" #12 prio=5 os_prio=31 tid=0x00007f942389a800 nid=0xe03 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE

"Thread-1" #11 prio=5 os_prio=31 tid=0x00007f942286c800 nid=0x5503 waiting for monitor entry [0x000070000b658000]
java.lang.Thread.State: BLOCKED (on object monitor)
at com.fandf.test.deadlock.DeadLockTest.lambda$main$1(DeadLockTest.java:33)
- waiting to lock <0x00000007955eb628> (a java.lang.Object)
- locked <0x00000007955eb638> (a java.lang.Object)
at com.fandf.test.deadlock.DeadLockTest$$Lambda$2/1418481495.run(Unknown Source)
at java.lang.Thread.run(Thread.java:748)

"Thread-0" #10 prio=5 os_prio=31 tid=0x00007f942286c000 nid=0x3c03 waiting for monitor entry [0x000070000b555000]
java.lang.Thread.State: BLOCKED (on object monitor)
at com.fandf.test.deadlock.DeadLockTest.lambda$main$0(DeadLockTest.java:19)
- waiting to lock <0x00000007955eb638> (a java.lang.Object)
- locked <0x00000007955eb628> (a java.lang.Object)
at com.fandf.test.deadlock.DeadLockTest$$Lambda$1/834600351.run(Unknown Source)
at java.lang.Thread.run(Thread.java:748)

"Service Thread" #9 daemon prio=9 os_prio=31 tid=0x00007f942404e800 nid=0x4003 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE

"C1 CompilerThread3" #8 daemon prio=9 os_prio=31 tid=0x00007f9423050800 nid=0x4203 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE

"C2 CompilerThread2" #7 daemon prio=9 os_prio=31 tid=0x00007f9423050000 nid=0x3a03 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE

"C2 CompilerThread1" #6 daemon prio=9 os_prio=31 tid=0x00007f942401d800 nid=0x4503 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE

"C2 CompilerThread0" #5 daemon prio=9 os_prio=31 tid=0x00007f942304e800 nid=0x4703 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE

"Signal Dispatcher" #4 daemon prio=9 os_prio=31 tid=0x00007f942304e000 nid=0x4803 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE

"Finalizer" #3 daemon prio=8 os_prio=31 tid=0x00007f9427008800 nid=0x3403 in Object.wait() [0x000070000ac37000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x0000000795588ec8> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:143)
- locked <0x0000000795588ec8> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:164)
at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:209)

"Reference Handler" #2 daemon prio=10 os_prio=31 tid=0x00007f942480a800 nid=0x3203 in Object.wait() [0x000070000ab34000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x0000000795586b68> (a java.lang.ref.Reference$Lock)
at java.lang.Object.wait(Object.java:502)
at java.lang.ref.Reference.tryHandlePending(Reference.java:191)
- locked <0x0000000795586b68> (a java.lang.ref.Reference$Lock)
at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:153)

"VM Thread" os_prio=31 tid=0x00007f9421829000 nid=0x3103 runnable

"GC task thread#0 (ParallelGC)" os_prio=31 tid=0x00007f942400b800 nid=0x1f07 runnable

"GC task thread#1 (ParallelGC)" os_prio=31 tid=0x00007f942180d000 nid=0x1a03 runnable

"GC task thread#2 (ParallelGC)" os_prio=31 tid=0x00007f942180f800 nid=0x1c03 runnable

"GC task thread#3 (ParallelGC)" os_prio=31 tid=0x00007f9421810000 nid=0x2a03 runnable

"GC task thread#4 (ParallelGC)" os_prio=31 tid=0x00007f9422809800 nid=0x5403 runnable

"GC task thread#5 (ParallelGC)" os_prio=31 tid=0x00007f942280d800 nid=0x2d03 runnable

"GC task thread#6 (ParallelGC)" os_prio=31 tid=0x00007f942280e800 nid=0x2e03 runnable

"GC task thread#7 (ParallelGC)" os_prio=31 tid=0x00007f942400c000 nid=0x2f03 runnable

"VM Periodic Task Thread" os_prio=31 tid=0x00007f942280b800 nid=0x3e03 waiting on condition

JNI global references: 309


Found one Java-level deadlock:
=============================
"Thread-1":
waiting to lock monitor 0x00007f94228142a8 (object 0x00000007955eb628, a java.lang.Object),
which is held by "Thread-0"
"Thread-0":
waiting to lock monitor 0x00007f9422811a18 (object 0x00000007955eb638, a java.lang.Object),
which is held by "Thread-1"

Java stack information for the threads listed above:
===================================================
"Thread-1":
at com.fandf.test.deadlock.DeadLockTest.lambda$main$1(DeadLockTest.java:33)
- waiting to lock <0x00000007955eb628> (a java.lang.Object)
- locked <0x00000007955eb638> (a java.lang.Object)
at com.fandf.test.deadlock.DeadLockTest$$Lambda$2/1418481495.run(Unknown Source)
at java.lang.Thread.run(Thread.java:748)
"Thread-0":
at com.fandf.test.deadlock.DeadLockTest.lambda$main$0(DeadLockTest.java:19)
- waiting to lock <0x00000007955eb638> (a java.lang.Object)
- locked <0x00000007955eb628> (a java.lang.Object)
at com.fandf.test.deadlock.DeadLockTest$$Lambda$1/834600351.run(Unknown Source)
at java.lang.Thread.run(Thread.java:748)

Found 1 deadlock.

使用jvisualvm也可以排查死锁问题

jvm调优工具详解及调优实战

也可以使用jprofiler进入线程查看

jvm调优工具详解及调优实战

系统CPU经常100%,怎么调优?

jstack找出占用cpu最高的线程堆栈信息

模拟cpu占用

public class CpuTest {

public int compute(){
int a = 11;
int b = 22;
return a*b;
}

public static void main(String[] args) {
CpuTest test = new CpuTest();
while (true) {
test.compute();
}
}


}

1,使用命令top -p pid

top



Processes: 440 total, 4 running, 436 sleeping, 2116 threads 06:36:38
Load Avg: 7.96, 12.05, 10.29 CPU usage: 54.60% user, 10.63% sys, 34.75% idle
SharedLibs: 225M resident, 33M data, 14M linkedit.
MemRegions: 158381 total, 1996M resident, 65M private, 698M shared.
PhysMem: 7374M used (2227M wired), 816M unused.
VM: 24T vsize, 3141M framework vsize, 477750(64) swapins, 788663(0) swapouts.
Networks: packets: 79717/32M in, 78904/23M out. Disks: 652013/12G read, 145200/7294M written.

PID COMMAND %CPU TIME #TH #WQ #PORT MEM PURG CMPRS PGRP PPID STATE
1821 java 216.6 00:09.41 29 2 94+ 190M+ 0B 0B 591 591 sleeping
279 mds_stores 33.8 14:02.26 13/7 11/8 118 60M- 0B 19M- 279 1 running
155 WindowServer 17.7 01:42.96 16 6 1451+ 315M- 2688K 69M- 155 1 sleeping
1678 mdworker_sha 14.1 00:00.20 5 2 52+ 1432K+ 0B 0B 1678 1 sleeping
591 idea 11.8 10:34.65 97 3 571 2671M 0B 1586M- 591 1 sleeping
1123 iTerm2 11.5 00:08.73 11 8 366+ 86M+ 2708K 26M- 1123 1 sleeping
1669 mdworker_sha 10.4 00:00.24 5 2 53+ 1428K+ 0B 0B 1669 1 sleeping
113 mds 7.0 00:40.25 15 12 329+ 23M- 0B 13M 113 1 sleeping
1593 top 4.4 00:02.64 1/1 0 36+ 4272K+ 0B 648K- 1593 1139 running
0 kernel_task 3.7 01:22.23 203/8 0 0 708M- 0B 0B 0 0 running
1 launchd 3.6 00:09.37 4 3 2085+ 18M+ 0B 9004K 1 0 sleeping
393 cfprefsd 3.4 00:05.14 7 6 450+ 1664K+ 4096B 188K 393 1 sleeping
124 opendirector 2.4 00:08.52 10 9 1131+ 6268K+ 0B 2892K 124 1 sleeping
321 com.apple.Ap 2.1 00:07.72 4 3 255 1632K 0B 1080K 321 1 sleeping
154 cfprefsd 1.9 00:02.66 7 6 658+ 1492K 0B 164K 154 1 sleeping

##Linux top -p
top -pid 1821

Processes: 448 total, 8 running, 440 sleeping, 2127 threads 06:41:18
Load Avg: 3.37, 6.85, 8.42 CPU usage: 27.25% user, 9.60% sys, 63.14% idle
SharedLibs: 246M resident, 37M data, 15M linkedit.
MemRegions: 160485 total, 2232M resident, 75M private, 705M shared.
PhysMem: 7674M used (2153M wired), 516M unused.
VM: 24T vsize, 3140M framework vsize, 583905(316) swapins, 1069939(0) swapouts.
Networks: packets: 81711/32M in, 81846/24M out. Disks: 677646/13G read, 155187/8563M written.

PID COMMAND %CPU TIME #TH #WQ #POR MEM PURG CMPR PGRP PPID STATE BOOSTS %CPU_ME
1821 java 98.5 03:28.85 22/1 1 81 9232K 0B 0B 591 1782 running *0[1] 0.00000

2,按H,获取每个线程的内存情况

jvm调优工具详解及调优实战
image.png

3,找到内存和cpu占用最高的线程tid,比如19664

4,转为十六进制得到 0x4cd0,此为线程id的十六进制表示

5,执行 jstack 19663|grep -A 10 4cd0,得到线程堆栈信息中 4cd0 这个线程所在行的后面10行,从堆栈中可以发现导致cpu飙高的调 用方法

jvm调优工具详解及调优实战

6,查看对应的堆栈信息找出可能存在问题的代码

Jinfo

查看正在运行的Java应用程序的扩展参数
查看jvm的参数

☺ jinfo -flags 2489
Attaching to process ID 2489, please wait...
Debugger attached successfully.
Server compiler detected.
JVM version is 25.141-b15
Non-default VM flags: -XX:CICompilerCount=4 -XX:InitialHeapSize=134217728 -XX:MaxHeapSize=2147483648 -XX:MaxNewSize=715653120 -XX:MinHeapDeltaBytes=524288 -XX:NewSize=44564480 -XX:OldSize=89653248 -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseFastUnorderedTimeStamps -XX:+UseParallelGC
Command line:

查看java系统参数

☺ jinfo -sysprops 2489
Attaching to process ID 2489, please wait...
Debugger attached successfully.
Server compiler detected.
JVM version is 25.141-b15
java.runtime.name = Java(TM) SE Runtime Environment
java.vm.version = 25.141-b15
sun.boot.library.path = /Library/Java/JavaVirtualMachines/jdk1.8.0_141.jdk/Contents/Home/jre/lib
gopherProxySet = false
java.vendor.url = http://java.oracle.com/
java.vm.vendor = Oracle Corporation
path.separator = :
file.encoding.pkg = sun.io
java.vm.name = Java HotSpot(TM) 64-Bit Server VM
sun.os.patch.level = unknown
sun.java.launcher = SUN_STANDARD
user.country = CN
user.dir = /Users/dongfengfan/IdeaProjects/SpringCloudLearning
java.vm.specification.name = Java Virtual Machine Specification
java.runtime.version = 1.8.0_141-b15
java.awt.graphicsenv = sun.awt.CGraphicsEnvironment
os.arch = x86_64
java.endorsed.dirs = /Library/Java/JavaVirtualMachines/jdk1.8.0_141.jdk/Contents/Home/jre/lib/endorsed
line.separator =

java.io.tmpdir = /var/folders/l4/j6t_zhxj5s34nzxb30rz9vcc0000gn/T/
java.vm.specification.vendor = Oracle Corporation
os.name = Mac OS X
sun.jnu.encoding = UTF-8
java.library.path = /Users/dongfengfan/Library/Java/Extensions:/Library/Java/Extensions:/Network/Library/Java/Extensions:/System/Library/Java/Extensions:/usr/lib/java:.
java.specification.name = Java Platform API Specification
java.class.version = 52.0
sun.management.compiler = HotSpot 64-Bit Tiered Compilers
os.version = 10.16
http.nonProxyHosts = local|*.local|169.254/16|*.169.254/16
user.home = /Users/dongfengfan
user.timezone =
java.awt.printerjob = sun.lwawt.macosx.CPrinterJob
file.encoding = UTF-8
java.specification.version = 1.8
user.name = dongfengfan
java.class.path = /Users/dongfengfan/IdeaProjects/SpringCloudLearning/fdf-test/target/classes:/Users/dongfengfan/Downloads/soft/mavenRepository/commons-beanutils/commons-beanutils/1.9.4/commons-beanutils-1.9.4.jar:/Users/dongfengfan/Downloads/soft/mavenRepository/commons-logging/commons-logging/1.2/commons-logging-1.2.jar:/Users/dongfengfan/Downloads/soft/mavenRepository/commons-collections/commons-collections/3.2.2/commons-collections-3.2.2.jar
java.vm.specification.version = 1.8
sun.arch.data.model = 64
sun.java.command = com.fandf.test.deadlock.DeadLockTest
java.home = /Library/Java/JavaVirtualMachines/jdk1.8.0_141.jdk/Contents/Home/jre
user.language = zh
java.specification.vendor = Oracle Corporation
awt.toolkit = sun.lwawt.macosx.LWCToolkit
java.vm.info = mixed mode
java.version = 1.8.0_141
java.ext.dirs = /Users/dongfengfan/Library/Java/Extensions:/Library/Java/JavaVirtualMachines/jdk1.8.0_141.jdk/Contents/Home/jre/lib/ext:/Library/Java/Extensions:/Network/Library/Java/Extensions:/System/Library/Java/Extensions:/usr/lib/java
sun.boot.class.path = /Library/Java/JavaVirtualMachines/jdk1.8.0_141.jdk/Contents/Home/jre/lib/resources.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_141.jdk/Contents/Home/jre/lib/rt.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_141.jdk/Contents/Home/jre/lib/sunrsasign.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_141.jdk/Contents/Home/jre/lib/jsse.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_141.jdk/Contents/Home/jre/lib/jce.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_141.jdk/Contents/Home/jre/lib/charsets.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_141.jdk/Contents/Home/jre/lib/jfr.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_141.jdk/Contents/Home/jre/classes
java.vendor = Oracle Corporation
file.separator = /
java.vendor.url.bug = http://bugreport.sun.com/bugreport/
sun.io.unicode.encoding = UnicodeBig
sun.cpu.endian = little
socksNonProxyHosts = local|*.local|169.254/16|*.169.254/16
ftp.nonProxyHosts = local|*.local|169.254/16|*.169.254/16
sun.cpu.isalist =

Jstat

jstat命令可以查看堆内存各部分的使用量,以及加载类的数量。

#jdk8
jstat [-命令选项] [vmid] [间隔时间(毫秒)] [查询次数]

垃圾回收统计

☺ jstat -gc 2742
S0C S1C S0U S1U EC EU OC OU MC MU CCSC CCSU YGC YGCT FGC FGCT GCT
5120.0 5120.0 0.0 0.0 33280.0 1996.8 87552.0 0.0 4480.0 774.5 384.0 75.9 0 0.000 0 0.000 0.000

S0C:第一个幸存区的大小,单位KB
S1C:第二个幸存区的大小
S0U:第一个幸存区的使用大小S1U:第二个幸存区的使用大小
EC:伊甸园区的大小
EU:伊甸园区的使用大小
OC:老年代大小
OU:老年代使用大小
MC:方法区大小(元空间)
MU:方法区使用大小
CCSC:压缩类空间大小
CCSU:压缩类空间使用大小
YGC:年轻代垃圾回收次数
YGCT:年轻代垃圾回收消耗时间,单位s
FGC:老年代垃圾回收次数
FGCT:老年代垃圾回收消耗时间,单位s
GCT:垃圾回收消耗总时间,单位s

堆内存统计

☺ jstat -gccapacity 2742
NGCMN NGCMX NGC S0C S1C EC OGCMN OGCMX OGC OC MCMN MCMX MC CCSMN CCSMX CCSC YGC FGC
43520.0 698880.0 43520.0 5120.0 5120.0 33280.0 87552.0 1398272.0 87552.0 87552.0 0.0 1056768.0 4480.0 0.0 1048576.0 384.0 0 0

~

NGCMN:新生代最小容量
NGCMX:新生代最大容量
NGC:当前新生代容量
S0C:第一个幸存区大小
S1C:第二个幸存区的大小
EC:伊甸园区的大小
OGCMN:老年代最小容量
OGCMX:老年代最大容量
OGC:当前老年代大小
OC:当前老年代大小
MCMN:最小元数据容量
MCMX:最大元数据容量
MC:当前元数据空间大小
CCSMN:最小压缩类空间大小
CCSMX:最大压缩类空间大小
CCSC:当前压缩类空间大小
YGC:年轻代gc次数
FGC:老年代GC次数

新生代垃圾回收统计

☺ jstat -gcnew 2742
S0C S1C S0U S1U TT MTT DSS EC EU YGC YGCT
5120.0 5120.0 0.0 0.0 15 15 0.0 33280.0 3328.0 0 0.000

S0C:第一个幸存区的大小
S1C:第二个幸存区的大小
S0U:第一个幸存区的使用大小
S1U:第二个幸存区的使用大小
TT:对象在新生代存活的次数
MTT:对象在新生代存活的最大次数
DSS:期望的幸存区大小
EC:伊甸园区的大小
EU:伊甸园区的使用大小
YGC:年轻代垃圾回收次数
YGCT:年轻代垃圾回收消耗时间

新生代内存统计

☺ jstat -gcnewcapacity 2742
NGCMN NGCMX NGC S0CMX S0C S1CMX S1C ECMX EC YGC FGC
43520.0 698880.0 43520.0 232960.0 5120.0 232960.0 5120.0 697856.0 33280.0 0 0

NGCMN:新生代最小容量
NGCMX:新生代最大容量
NGC:当前新生代容量
S0CMX:最大幸存1区大小
S0C:当前幸存1区大小
S1CMX:最大幸存2区大小
S1C:当前幸存2区大小
ECMX:最大伊甸园区大小
EC:当前伊甸园区大小
YGC:年轻代垃圾回收次数
FGC:老年代回收次数

老年代垃圾回收统计

☺ jstat -gcold 2742
MC MU CCSC CCSU OC OU YGC FGC FGCT GCT
4480.0 774.5 384.0 75.9 87552.0 0.0 0 0 0.000 0.000

MC:方法区大小
MU:方法区使用大小
CCSC:压缩类空间大小
CCSU:压缩类空间使用大小
OC:老年代大小
OU:老年代使用大小
YGC:年轻代垃圾回收次数
FGC:老年代垃圾回收次数
FGCT:老年代垃圾回收消耗时间
GCT:垃圾回收消耗总时间

老年代内存统计

☺ jstat -gcoldcapacity 2742
OGCMN OGCMX OGC OC YGC FGC FGCT GCT
87552.0 1398272.0 87552.0 87552.0 0 0 0.000 0.000

OGCMN:老年代最小容量
OGCMX:老年代最大容量
OGC:当前老年代大小
OC:老年代大小
YGC:年轻代垃圾回收次数
FGC:老年代垃圾回收次数
FGCT:老年代垃圾回收消耗时间
GCT:垃圾回收消耗总时间

元数据空间统计

☺ jstat -gcmetacapacity 2742
MCMN MCMX MC CCSMN CCSMX CCSC YGC FGC FGCT GCT
0.0 1056768.0 4480.0 0.0 1048576.0 384.0 0 0 0.000 0.000

MCMN:最小元数据容量
MCMX:最大元数据容量
MC:当前元数据空间大小
CCSMN:最小压缩类空间大小
CCSMX:最大压缩类空间大小
CCSC:当前压缩类空间大小
YGC:年轻代垃圾回收次数
FGC:老年代垃圾回收次数
FGCT:老年代垃圾回收消耗时间
GCT:垃圾回收消耗总时间

总结垃圾回收统计 gcutil

☺ jstat -gcutil 2742
S0 S1 E O M CCS YGC YGCT FGC FGCT GCT
0.00 0.00 16.00 0.00 17.29 19.76 0 0.000 0 0.000 0.000

S0:幸存1区当前使用比例
S1:幸存2区当前使用比例
E:伊甸园区使用比例
O:老年代使用比例
M:元数据区使用比例
CCS:压缩使用比例
YGC:年轻代垃圾回收次数
FGC:老年代垃圾回收次数
FGCT:老年代垃圾回收消耗时间
GCT:垃圾回收消耗总时间

JVM运行情况预估

用 jstat gc -pid 命令可以查看一些关键数据,有了这些数据就可以先给自己的系统设置一些初始性的 JVM参数,比如堆内存大小,年轻代大小,Eden和Survivor的比例,老年代的大小,大对象的阈值,大龄对象进入老年代的阈值等。

年轻代对象增长的速率

可以执行命令 jstat -gc pid 2000 10 (每隔2秒执行1次命令,共执行10次),通过观察EU(eden区的使用)来估算每秒eden大概新增多少对象,如果系统负载不高,可以把频率2秒换成1分钟,甚至5分钟来观察整体情况。这里需要注意的是,正常系统可能有高峰期和日常期,所以需要在不同的时间点分别估算不同情况下对象增长速率。

Young GC的触发频率和每次耗时

知道年轻代对象增长速率我们就能推根据eden区的大小推算出Young GC大概多久触发一次,Young GC的平均耗时可以通过 YGCT/YGC公式算出,根据结果我们大概就能知道系统大概多久会因为Young GC的执行而卡顿多久。

每次Young GC后有多少对象存活和进入老年代

因为之前已经大概知道Young GC的频率,假设是每5分钟一次,那么可以执行命令 jstat -gc pid 300000 10 ,观察每次结果eden,survivor和老年代使用的变化情况,在每次gc后eden区使用一般会大幅减少,survivor和老年代都有可能增长,这些增长的对象就是每次Young GC后存活的对象,同时还可以看出每次Young GC后进去老年代大概多少对象,从而可以推算出老年代对象增长速率。

Full GC的触发频率和每次耗时

知道了老年代对象的增长速率就可以推算出Full GC的触发频率了,Full GC的每次耗时可以用公式 FGCT/FGC 计算得出。

优化思路其实简单来说就是尽量让每次Young GC后的存活对象小于Survivor区域的50%,都留存在年轻代里。尽量别让对象进入老年代。尽量减少Full GC的频率,避免频繁Full GC对JVM性能的影响。

系统频繁Full GC导致系统卡顿是怎么回事

思路还是和上面排查问题一样,主要考虑以下几点
1.数据太多,频繁GC,stw时间长
2.内存越大,FGC时间越久
3.内存超过16G,也可以考虑使用G1或者PN+cms垃圾回收算法

内存泄露问题

再来讨论一种情况,很多时候我们在系统中都会使用多级缓存架构,就是redis加上JVM级缓存,有时候可能为了图方便,JVM级缓存就简单使用一个hashmap,于是不断往里面放缓存数据,但是很少考虑这个map的容量问题,结果这个缓存map越来越大,一直占用着老年代的很多空间,时间长了就会导致full gc非常频繁,这就是一种内存泄漏,对于一些老旧数据没有及时清理导致一直占用着宝贵的内存资源,时间长了除了导致full gc,还有可能导致OOM。

这种情况其实可以考虑使用一些成熟的JVM级缓存框架,比如Guava Cache、Caffeine等一些自带LRU数据淘汰算法的框架来作为JVM级的缓存。



原文始发于微信公众号(好好学技术):jvm调优工具详解及调优实战

版权声明:本文内容由互联网用户自发贡献,该文观点仅代表作者本人。本站仅提供信息存储空间服务,不拥有所有权,不承担相关法律责任。如发现本站有涉嫌侵权/违法违规的内容, 请发送邮件至 举报,一经查实,本站将立刻删除。

文章由极客之音整理,本文链接:https://www.bmabk.com/index.php/post/219613.html

(0)
小半的头像小半

相关推荐

发表回复

登录后才能评论
极客之音——专业性很强的中文编程技术网站,欢迎收藏到浏览器,订阅我们!