Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

How to determine which GC I use?

I didn't specify any GC, and I think my JVM have not any GC be enabled by default.

Of course I know that OpenJDK8 use ParallelGC by default, but I think it should can print by command line, like this:

java -XX:+PrintFlagsFinal|grep Use|grep GC

I expect that the output contains bool UseParallelOldGC = true {product} but it is no :

     bool ParGCUseLocalOverflow                     = false                               {product}
     bool UseAdaptiveGCBoundary                     = false                               {product}
     bool UseAdaptiveSizeDecayMajorGCCost           = true                                {product}
     bool UseAdaptiveSizePolicyWithSystemGC         = false                               {product}
     bool UseAutoGCSelectPolicy                     = false                               {product}
     bool UseConcMarkSweepGC                        = false                               {product}
     bool UseDynamicNumberOfGCThreads               = false                               {product}
     bool UseG1GC                                   = false                               {product}
     bool UseGCLogFileRotation                      = false                               {product}
     bool UseGCOverheadLimit                        = true                                {product}
     bool UseGCTaskAffinity                         = false                               {product}
     bool UseMaximumCompactionOnSystemGC            = true                                {product}
     bool UseParNewGC                               = false                               {product}
     bool UseParallelGC                             = false                               {product}
     bool UseParallelOldGC                          = false                               {product}
     bool UseSerialGC                               = false                               {product}

and

java -XX:+PrintCommandLineFlags -version

I expect that the output contains: XX:+UseParallelGC but it is no too:

-XX:InitialHeapSize=460493056 -XX:MaxHeapSize=7367888896 -XX:+PrintCommandLineFlags -XX:+UseCompressedClassPointers -XX:+UseCompressedOops 
.

My JVM options:

-XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintGCDateStamps -XX:+PrintHeapAtGC -verbose:gc -XX:+PrintTenuringDistribution -XX:+PrintGCApplicationStoppedTime
.

the above output show that no any GC be enabled(I think so), I am very confuse by this situation.

The GC logs output like:

OpenJDK 64-Bit Server VM (25.181-b13) for linux-amd64 JRE (1.8.0_181-b13), built on Oct 23 2018 11:39:12 by "buildozer" with gcc 6.4.0
Memory: 4k page, physical 28780816k(6283132k free), swap 0k(0k free)
CommandLine flags: -XX:InitialHeapSize=460493056 -XX:MaxHeapSize=7367888896 -XX:+PrintGC -XX:+PrintGCApplicationStoppedTime -XX:+PrintGCDateStamps -XX:+PrintGCDeta
ils -XX:+PrintGCTimeStamps -XX:+PrintHeapAtGC -XX:+PrintTenuringDistribution -XX:+UseCompressedClassPointers -XX:+UseCompressedOops 
{Heap before GC invocations=0 (full 0):
 def new generation   total 135168K, used 120192K [0x0000000608c00000, 0x0000000611ea0000, 0x000000069b2a0000)
  eden space 120192K, 100% used [0x0000000608c00000, 0x0000000610160000, 0x0000000610160000)
  from space 14976K,   0% used [0x0000000610160000, 0x0000000610160000, 0x0000000611000000)
  to   space 14976K,   0% used [0x0000000611000000, 0x0000000611000000, 0x0000000611ea0000)
 tenured generation   total 300416K, used 0K [0x000000069b2a0000, 0x00000006ad800000, 0x00000007c0000000)
   the space 300416K,   0% used [0x000000069b2a0000, 0x000000069b2a0000, 0x000000069b2a0200, 0x00000006ad800000)
 Metaspace       used 20532K, capacity 20780K, committed 20992K, reserved 1067008K
  class space    used 2628K, capacity 2726K, committed 2816K, reserved 1048576K
2019-02-25T06:29:46.105+0000: 2.890: [GC (Allocation Failure) 2019-02-25T06:29:46.105+0000: 2.890: [DefNew
Desired survivor size 7667712 bytes, new threshold 1 (max 15)
- age   1:   15335424 bytes,   15335424 total
: 120192K->14976K(135168K), 0.0238110 secs] 120192K->18041K(435584K), 0.0238765 secs] [Times: user=0.01 sys=0.01, real=0.02 secs] 
Heap after GC invocations=1 (full 0):
 def new generation   total 135168K, used 14976K [0x0000000608c00000, 0x0000000611ea0000, 0x000000069b2a0000)
  eden space 120192K,   0% used [0x0000000608c00000, 0x0000000608c00000, 0x0000000610160000)
  from space 14976K, 100% used [0x0000000611000000, 0x0000000611ea0000, 0x0000000611ea0000)
  to   space 14976K,   0% used [0x0000000610160000, 0x0000000610160000, 0x0000000611000000)
 tenured generation   total 300416K, used 3065K [0x000000069b2a0000, 0x00000006ad800000, 0x00000007c0000000)
   the space 300416K,   1% used [0x000000069b2a0000, 0x000000069b59e660, 0x000000069b59e800, 0x00000006ad800000)
 Metaspace       used 20532K, capacity 20780K, committed 20992K, reserved 1067008K
  class space    used 2628K, capacity 2726K, committed 2816K, reserved 1048576K
}
2019-02-25T06:29:46.129+0000: 2.914: Total time for which application threads were stopped: 0.0241189 seconds, Stopping threads took: 0.0000181 seconds
{Heap before GC invocations=1 (full 0):
 def new generation   total 135168K, used 21860K [0x0000000608c00000, 0x0000000611ea0000, 0x000000069b2a0000)
  eden space 120192K,   5% used [0x0000000608c00000, 0x00000006092b93f8, 0x0000000610160000)
  from space 14976K, 100% used [0x0000000611000000, 0x0000000611ea0000, 0x0000000611ea0000)
  to   space 14976K,   0% used [0x0000000610160000, 0x0000000610160000, 0x0000000611000000)
 tenured generation   total 300416K, used 3065K [0x000000069b2a0000, 0x00000006ad800000, 0x00000007c0000000)
   the space 300416K,   1% used [0x000000069b2a0000, 0x000000069b59e660, 0x000000069b59e800, 0x00000006ad800000)
 Metaspace       used 20982K, capacity 21132K, committed 21248K, reserved 1067008K
  class space    used 2667K, capacity 2758K, committed 2816K, reserved 1048576K
2019-02-25T06:29:46.187+0000: 2.972: [Full GC (Metadata GC Threshold) 2019-02-25T06:29:46.187+0000: 2.972: [Tenured: 3065K->9617K(300416K), 0.0270556 secs] 24926K-
>9617K(435584K), [Metaspace: 20982K->20982K(1067008K)], 0.0271334 secs] [Times: user=0.03 sys=0.00, real=0.03 secs] 
Heap after GC invocations=2 (full 1):
 def new generation   total 135296K, used 0K [0x0000000608c00000, 0x0000000611ec0000, 0x000000069b2a0000)
  eden space 120320K,   0% used [0x0000000608c00000, 0x0000000608c00000, 0x0000000610180000)
  from space 14976K,   0% used [0x0000000610180000, 0x0000000610180000, 0x0000000611020000)
  to   space 14976K,   0% used [0x0000000611020000, 0x0000000611020000, 0x0000000611ec0000)
 tenured generation   total 300416K, used 9617K [0x000000069b2a0000, 0x00000006ad800000, 0x00000007c0000000)
   the space 300416K,   3% used [0x000000069b2a0000, 0x000000069bc04698, 0x000000069bc04800, 0x00000006ad800000)
 Metaspace       used 20982K, capacity 21132K, committed 21248K, reserved 1067008K
  class space    used 2667K, capacity 2758K, committed 2816K, reserved 1048576K
}

(from app starting until first major GC)

The log show that JVM heap is divided into new and tenured, but without print GC type.

Sadly, I also cannot use jmap -heap {pid} to get the GC type because jmap without this option(-heap) in my env.

So I wanted knows that:

  1. Which GC is what I use really?
  2. Is the command line options(-XX:+PrintCommandLineFlags and -XX:+PrintFlagsFinal) output information correct?

My env: k8s+docker, Alpine OpenJKD8

like image 277
lianej Avatar asked Feb 25 '19 08:02

lianej


2 Answers

jcmd <pid> VM.flags should help.

E.g.

$ /usr/java/jdk1.8.0_202/bin/java Test
...
$ jcmd 28815 VM.flags
28815:
-XX:CICompilerCount=3 -XX:InitialHeapSize=266338304 -XX:MaxHeapSize=4257218560 -XX:MaxNewSize=1418723328 -XX:MinHeapDeltaBytes=524288 -XX:NewSize=88604672 -XX:OldSize=177733632 -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseParallelGC

The last printed flag is -XX:+UseParallelGC even though it hasn't been specified explicitly.

Then if I run JDK 11 which has G1 as the default collector, I will get the following output:

$ /usr/java/jdk11.0.2/bin/java Test
...
$ jcmd 28862 VM.flags
28862:
-XX:CICompilerCount=3 -XX:ConcGCThreads=1 -XX:G1ConcRefinementThreads=4 -XX:G1HeapRegionSize=1048576 -XX:GCDrainStackTargetSize=64 -XX:InitialHeapSize=266338304 -XX:MarkStackSize=4194304 -XX:MaxHeapSize=4257218560 -XX:MaxNewSize=2554331136 -XX:MinHeapDeltaBytes=1048576 -XX:NonNMethodCodeHeapSize=5830092 -XX:NonProfiledCodeHeapSize=122914074 -XX:ProfiledCodeHeapSize=122914074 -XX:ReservedCodeCacheSize=251658240 -XX:+SegmentedCodeCache -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseFastUnorderedTimeStamps -XX:+UseG1GC

Now the last printed option is -XX:+UseG1GC.

If for some reason you don't have jcmd available, you may try jattach which is the lightweight standalone alternative to jcmd:

$ jattach 28862 jcmd VM.flags

UPDATE

If no -XX:Use*GC flags are printed, it means that Serial GC is used. This happens only on JDK 8 and earlier. Since JDK 9, one of Use*GC flags is automatically set by the JVM. See JDK-8068582 for details.

like image 64
apangin Avatar answered Sep 18 '22 12:09

apangin


The problem is that you are looking at JVM options of type bool when you actually want a name. This is not your fault, the designers of the JVM decided to give the different garbage collectors names, but provide controls that look like boolean options.

So even if all these options are false, there is a garbage collector, but these options are not sufficient to get its name. But on the other hand, most of the names are insufficient for describing what these garbage collectors do, or how they differ from the other algorithms, anyway.

It’s not entirely correct that JDK8 uses ParallelGC by default; as this answer describes, the algorithm is selected by some heuristic, though, you’ll end up at ParallelGC in most cases.

Using the following code

Object flags = ManagementFactory.getPlatformMBeanServer().invoke(
    ObjectName.getInstance("com.sun.management:type=DiagnosticCommand"),
    "vmFlags", new Object[] { null }, new String[] { "[Ljava.lang.String;" });
for(String f: ((String)flags).split("\\s+"))
    if(f.contains("GC")) System.out.println(f);
for(GarbageCollectorMXBean gc: ManagementFactory.getGarbageCollectorMXBeans())
    System.out.printf("%-20s%s%n", gc.getName(), Arrays.toString(gc.getMemoryPoolNames()));

I get

> jdk1.8.0_162\bin\java ...
-XX:+UseParallelGC
PS Scavenge         [PS Eden Space, PS Survivor Space]
PS MarkSweep        [PS Eden Space, PS Survivor Space, PS Old Gen]

on my machine, so running without options did select ParallelGC in this environment. But note the reported names “PS Scavenge” and “PS MarkSweep”, which highlight another problem with the options and names: the typical configuration considers having two garbage collection algorithms, one for the minor gc and one for the major gc.

When I try to -XX:-UseParallelGC, I get

> jdk1.8.0_162\bin\java -XX:-UseParallelGC ...
-XX:+UseParallelGC
PS Scavenge         [PS Eden Space, PS Survivor Space]
PS MarkSweep        [PS Eden Space, PS Survivor Space, PS Old Gen]

which demonstrates the problem of the JVM options looking like boolean: I can’t turn them off, as the JVM needs an actual other garbage collector to select.
So to turn off parallel, you could use -XX:+UseSerialGC:

> jdk1.8.0_162\bin\java -XX:+UseSerialGC ...
-XX:+UseSerialGC
Copy                [Eden Space, Survivor Space]
MarkSweepCompact    [Eden Space, Survivor Space, Tenured Gen]

For comparison

> jdk1.8.0_162\bin\java -XX:+UseConcMarkSweepGC ...
-XX:+UseConcMarkSweepGC
-XX:+UseParNewGC
ParNew              [Par Eden Space, Par Survivor Space]
ConcurrentMarkSweep [Par Eden Space, Par Survivor Space, CMS Old Gen]

Note how each of the two algorithms can be associated with an option, but specifying one option can select two garbage collection algorithms.

> jdk-9.0.4\bin\java ...
-XX:ConcGCThreads=2
-XX:+UseG1GC
G1 Young Generation [G1 Eden Space, G1 Survivor Space]
G1 Old Generation   [G1 Eden Space, G1 Survivor Space, G1 Old Gen]

> jdk-11.0.1\bin\java ...
-XX:ConcGCThreads=2
-XX:GCDrainStackTargetSize=64
-XX:+UseG1GC
G1 Young Generation [G1 Eden Space, G1 Survivor Space, G1 Old Gen]
G1 Old Generation   [G1 Eden Space, G1 Survivor Space, G1 Old Gen]

> jdk-11.0.1\bin\java -XX:+UnlockExperimentalVMOptions -XX:+UseEpsilonGC ...
-XX:+UseEpsilonGC
Epsilon Heap        [Epsilon Heap]

So in case the code trying to get the associated Use…GC boolean option (i.e. the first part of the code above, using the nonstandard com.sun.management:type=DiagnosticCommand MBean) doesn’t find any, you can try to use the garbage collector names as reported by getGarbageCollectorMXBeans(), but as you can see, these names do not match the names of the JVM options, so you have to know, how these names are associated.

But in the end, none of these names is really descriptive, so they all are only helpful if you already know what’s behind these names…

like image 43
Holger Avatar answered Sep 18 '22 12:09

Holger