1.分析程序
public class Application {
private static Map<String, String> stringContainer = new HashMap<>();
public static void main(String[] args) {
System.out.println("Start of program!");
String stringWithPrefix = "stringWithPrefix";
// Load Java Heap with 3 M java.lang.String instances
for (int i = 0; i < 3000000; i++) {
String newString = stringWithPrefix + i;
stringContainer.put(newString, newString);
}
System.out.println("MAP size: " + stringContainer.size());
// Explicit GC!
System.gc();
// Remove 2 M out of 3 M
for (int i = 0; i < 2000000; i++) {
String newString = stringWithPrefix + i;
stringContainer.remove(newString);
}
System.out.println("容量: " + stringContainer.size());
System.out.println("stop!");
}
}
2.添加 jvm 参数
java 8 -XX:+UseSerialGC -Xms1024m -Xmx1024m -verbose:gc -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintGCDateStamps
java 11 -XX:+UseSerialGC -Xms1024m -Xmx1024m -Xlog:gc=debug:file=gc.txt -Xlog:gc*::time
2.1java 8 输出
Start of program!
2021-07-10T16:52:46.317+0800: 1.632: [GC (Allocation Failure) 2021-07-10T16:52:46.317+0800: 1.632: [DefNew: 279616K->34944K(314560K), 1.1156542 secs] 279616K->229703K(1013632K), 1.1157999 secs] [Times: user=0.69 sys=0.17, real=1.12 secs]
MAP size: 3000000
2021-07-10T16:52:47.742+0800: 3.057: [Full GC (System.gc()) 2021-07-10T16:52:47.742+0800: 3.057: [Tenured: 194759K->368733K(699072K), 1.1881951 secs] 383157K->368733K(1013632K), [Metaspace: 3407K->3407K(1056768K)], 1.1882956 secs] [Times: user=1.06 sys=0.08, real=1.19 secs]
容量: 1000000
stop!
Heap
def new generation total 314560K, used 204437K [0x00000000c0000000, 0x00000000d5550000, 0x00000000d5550000)
eden space 279616K, 73% used [0x00000000c0000000, 0x00000000cc7a54c0, 0x00000000d1110000)
from space 34944K, 0% used [0x00000000d3330000, 0x00000000d3330000, 0x00000000d5550000)
to space 34944K, 0% used [0x00000000d1110000, 0x00000000d1110000, 0x00000000d3330000)
tenured generation total 699072K, used 368733K [0x00000000d5550000, 0x0000000100000000, 0x0000000100000000)
the space 699072K, 52% used [0x00000000d5550000, 0x00000000ebd674d8, 0x00000000ebd67600, 0x0000000100000000)
Metaspace used 3421K, capacity 4500K, committed 4864K, reserved 1056768K
class space used 371K, capacity 388K, committed 512K, reserved 1048576K
2021-07-10T16:52:46.317+0800: 1.632: GC发生时间
GC or Full GC – 垃圾收集器的类型 minor gc 和 full gc
Allocation Failure|System.gc() 产生垃圾收集原因
DefNew|Tenured 使用的垃圾收集器类型
279616K->34944K(314560K) gc前内存->gc后内存(该区域总内存)
1.1156542 secs gc所占用的时间
279616K->229703K(1013632K)java 堆gc前内存->java 堆gc后内存(Java堆总内存)
Times: user=0.69 sys=0.17, real=1.12 secs
user 垃圾收集器消耗的总 CPU 时间
sys花费在 操作系统调用或等待系统事件上的时间
real这是所有经过的时间,包括其他进程使用的时间片
2.2java 11输出
[2021-07-10T16:55:00.327+0800] -XX:+PrintGCDetails is deprecated. Will use -Xlog:gc* instead.
[2021-07-10T16:55:00.363+0800] Using Serial
[2021-07-10T16:55:00.363+0800] Heap address: 0x00000000c0000000, size: 1024 MB, Compressed Oops mode: 32-bit
Start of program!
[2021-07-10T16:55:02.383+0800] GC(0) Pause Young (Allocation Failure)
[2021-07-10T16:55:03.480+0800] GC(0) DefNew: 279616K->34944K(314560K)
[2021-07-10T16:55:03.480+0800] GC(0) Tenured: 0K->197430K(699072K)
[2021-07-10T16:55:03.480+0800] GC(0) Metaspace: 6578K->6578K(1056768K)
[2021-07-10T16:55:03.480+0800] GC(0) Pause Young (Allocation Failure) 273M->226M(989M) 1097.434ms
[2021-07-10T16:55:03.480+0800] GC(0) User=0.89s Sys=0.20s Real=1.10s
MAP size: 3000000
[2021-07-10T16:55:03.646+0800] GC(1) Pause Full (System.gc())
[2021-07-10T16:55:03.646+0800] GC(1) Phase 1: Mark live objects
[2021-07-10T16:55:04.067+0800] GC(1) Phase 1: Mark live objects 421.200ms
[2021-07-10T16:55:04.067+0800] GC(1) Phase 2: Compute new object addresses
[2021-07-10T16:55:04.264+0800] GC(1) Phase 2: Compute new object addresses 197.401ms
[2021-07-10T16:55:04.264+0800] GC(1) Phase 3: Adjust pointers
[2021-07-10T16:55:04.513+0800] GC(1) Phase 3: Adjust pointers 249.541ms
[2021-07-10T16:55:04.514+0800] GC(1) Phase 4: Move objects
[2021-07-10T16:55:04.635+0800] GC(1) Phase 4: Move objects 121.660ms
[2021-07-10T16:55:04.636+0800] GC(1) DefNew: 105460K->0K(314560K)
[2021-07-10T16:55:04.636+0800] GC(1) Tenured: 197430K->300246K(699072K)
[2021-07-10T16:55:04.636+0800] GC(1) Metaspace: 6578K->6578K(1056768K)
[2021-07-10T16:55:04.636+0800] GC(1) Pause Full (System.gc()) 295M->293M(989M) 990.440ms
[2021-07-10T16:55:04.636+0800] GC(1) User=0.94s Sys=0.03s Real=0.99s
容量: 1000000
stop!
[2021-07-10T16:55:05.863+0800] Heap
[2021-07-10T16:55:05.863+0800] def new generation total 314560K, used 149253K [0x00000000c0000000, 0x00000000d5550000, 0x00000000d5550000)
[2021-07-10T16:55:05.863+0800] eden space 279616K, 53% used [0x00000000c0000000, 0x00000000c91c1678, 0x00000000d1110000)
[2021-07-10T16:55:05.863+0800] from space 34944K, 0% used [0x00000000d3330000, 0x00000000d3330000, 0x00000000d5550000)
[2021-07-10T16:55:05.863+0800] to space 34944K, 0% used [0x00000000d1110000, 0x00000000d1110000, 0x00000000d3330000)
[2021-07-10T16:55:05.863+0800] tenured generation total 699072K, used 300246K [0x00000000d5550000, 0x0000000100000000, 0x0000000100000000)
[2021-07-10T16:55:05.863+0800] the space 699072K, 42% used [0x00000000d5550000, 0x00000000e7a85918, 0x00000000e7a85a00, 0x0000000100000000)
[2021-07-10T16:55:05.863+0800] Metaspace used 6602K, capacity 6671K, committed 6784K, reserved 1056768K
[2021-07-10T16:55:05.863+0800] class space used 578K, capacity 602K, committed 640K, reserved 1048576K
java11 gc日志内容和java8差不错,但是详细的列出的gc的每个步骤
3.GC分析工具
3.1 使用 GCeasy(https://gceasy.io/) 生成报告
2. 使用 GCViwer (https://github.com/chewiebug/GCViewer) 图线的说明可以查看github说明
mvn clean install -Dmaven.test.skip=true
java -jar gcviewer-1.37-SNAPSHOT.jar