Search code examples
javajvmjvm-hotspotjvm-arguments

JVM G1 GC logs analyze

Please help check why my GC logs failed to generate, or is there anything wrong with it.

My java start parameter is 

-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

I've set a rotation to generate JVM G1 GC logs. It's my first time use the G1 GC. But it always create a single log "gc.0.current" with very few contents, "gc" is the name of the log. The content is as below. 

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

No other logs created. Do you know why is that? I've run a lot of tasks on the server, suppose it should generate some GC logs.

Can you see anything abnormal with the above log content?

Is there any other way to view the GC activities on the Linux server ?

Thanks,

Solution

  • Heap layout printed at the bottom of GC log indicates that your Java process has terminated.

    Heap layout is printed in two situations: before/after GC, if -XX:+PrintHeapAtGC is specified, and before JVM exits. In your case it is obviously the latter.

    JVM exited almost immediately after start (it was running only for 281 milliseconds). Most likely, it either failed to start an application (check the VM output), or it did something very simple, i.e. just launched a new subprocess.

    Note that a new JVM process overwrites the previosly written log file.