JVM G1 GC日志分析

Question

请帮助检查为什么我的GC日志无法生成，或者它有什么问题。

我的java start参数是

-Xms5G -Xmx5G -Xss1024K 
-XX:+UseG1GC -XX:MaxGCPauseMillis=200 -XX:G1HeapRegionSize=4m  

-verbose:gc -XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:+PrintGCTimeStamps 
-XX:+PrintGCApplicationStoppedTime -XX:+PrintGCApplicationConcurrentTime -XX:-PrintCommandLineFlags 
-XX:+PrintAdaptiveSizePolicy -XX:+PrintTenuringDistribution -XX:+PrintReferenceGC 
-Xloggc:/data/gclog/gc -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=5 -XX:GCLogFileSize=100M

我已经设置了一个旋转来生成JVM G1 GC日志。这是我第一次使用G1 GC。但是它总是创建一个日志"gc.0.current“，内容很少，"gc”是日志的名称。内容如下。

Java HotSpot(TM) 64-Bit Server VM (25.73-b02) for linux-amd64 JRE (1.8.0_73-b02), built on Jan 29 2016 17:39:45 by "java_re" with gcc 4.3.0 20080428 (Red Hat 4.3.0-8)
Memory: 4k page, physical 8056924k(5058272k free), swap 4194300k(4194300k free)
CommandLine flags: -XX:G1HeapRegionSize=4194304 -XX:GCLogFileSize=104857600 -XX:InitialHeapSize=5368709120 -XX:MaxGCPauseMillis=200 -XX:MaxHeapSize=5368709120 -XX:NumberOfGCLogFiles=5 -XX:+PrintAdaptiveSizePolicy -XX:-PrintCommandLineFlags -XX:+PrintGC -XX:+PrintGCApplicationConcurrentTime -XX:+PrintGCApplicationStoppedTime -XX:+PrintGCDateStamps -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintReferenceGC -XX:+PrintTenuringDistribution -XX:ThreadStackSize=1024 -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseG1GC -XX:+UseGCLogFileRotation
 0.012: [G1Ergonomics (Heap Sizing) expand the heap, requested expansion amount: 5368709120 bytes, attempted expansion amount: 5368709120 bytes]
2019-08-21T23:23:26.706-0500: 0.212: Application time: 0.1403261 seconds
2019-08-21T23:23:26.706-0500: 0.212: Total time for which application threads were stopped: 0.0001008 seconds, Stopping threads took: 0.0000202 seconds
Heap
 garbage-first heap   total 5242880K, used 8192K [0x0000000680000000, 0x0000000680402800, 0x00000007c0000000)
  region size 4096K, 3 young (12288K), 0 survivors (0K)
 Metaspace       used 7309K, capacity 7452K, committed 7552K, reserved 1056768K
  class space    used 853K, capacity 888K, committed 896K, reserved 1048576K
2019-08-21T23:23:26.775-0500: 0.281: Application time: 0.0686930 seconds

没有创建其他日志。你知道这是为什么吗？我在服务器上运行了很多任务，假设它应该生成一些GC日志。

您能看到上述日志内容有什么异常吗？

还有其他方式来查看Linux服务器上的GC活动吗？

谢谢,

Answer 1

在GC日志底部打印的堆布局表示您的Java进程已经结束。

堆布局是在两种情况下打印的: GC之前/之后，如果指定了-XX:+PrintHeapAtGC，则在JVM退出之前。在你的例子中，显然是后者。

JVM几乎在启动后立即退出(它仅运行281毫秒)。最有可能的是，它要么无法启动应用程序(检查VM输出)，要么做了一些非常简单的事情，即刚刚启动了一个新的子进程。

注意，一个新的JVM进程将覆盖先前编写的日志文件。

Answer 2

我在简单的CRUD服务上测试了所有参数，没有问题。但是当我在Hello应用程序上测试时，打印的日志与您的日志相同，因为GC没有触发。当我在Hello应用程序上用System.gc()手动触发GC时，打印GC日志。

总之，如果GC不采取任何行动，日志就不会打印。

Answer 3

可能是-XX:+UseGCLogFileRotation的一个问题。我以前也遇到过同样的问题，这对我来说是可行的：

-Xloggc:/data/gclog/gc

而不是

-Xloggc:/data/gclog/gc -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=5 -XX:GCLogFileSize=100M

下面是我在我的产品上调优G1GC时的注意事项，希望您能找到一些有用的信息：垃圾优先垃圾收集器(G1GC)对后端性能的影响。

此外，还有一个对避免-XX:+UseGCLogFileRotation的建议。一个GC日志文件将更容易导入到像GC查看器这样的分析工具中。