Why is garbage collection log Metaspace value different from provided flag?

Question

I am running a server app on Java 8 with the below flags:

-XX:GCLogFileSize=2097152 -XX:InitialBootClassLoaderMetaspaceSize=33554432 -XX:InitialHeapSize=1610612736 -XX:MaxHeapSize=1610612736 -XX:MaxMetaspaceSize=1073741824 -XX:MetaspaceSize=536870912 -XX:NumberOfGCLogFiles=5 -XX:+PrintGC -XX:+PrintGCApplicationConcurrentTime -XX:+PrintGCApplicationStoppedTime -XX:+PrintGCDateStamps -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintHeapAtGC -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseGCLogFileRotation -XX:-UseLargePagesIndividualAllocation -XX:+UseParallelGC

The metaspace start value is 512m and max value is 1gb.

In the GC logs I see different metaspace values than the above flag values. My log sample is below:

{Heap before GC invocations=1 (full 0):
 PSYoungGen      total 458752K, used 393216K [0x00000000e0000000, 0x0000000100000000, 0x0000000100000000)
  eden space 393216K, 100% used [0x00000000e0000000,0x00000000f8000000,0x00000000f8000000)
  from space 65536K, 0% used [0x00000000fc000000,0x00000000fc000000,0x0000000100000000)
  to   space 65536K, 0% used [0x00000000f8000000,0x00000000f8000000,0x00000000fc000000)
 ParOldGen       total 1048576K, used 0K [0x00000000a0000000, 0x00000000e0000000, 0x00000000e0000000)
  object space 1048576K, 0% used [0x00000000a0000000,0x00000000a00003a0,0x00000000e0000000)
 Metaspace       used 26975K, capacity 54120K, committed 54400K, reserved 1114112K
  class space    used 3346K, capacity 4426K, committed 4480K, reserved 1048576K
2016-12-21T16:41:10.569+0300: 1.423: [GC (GCLocker Initiated GC) [PSYoungGen: 393216K->29645K(458752K)] 393216K->29734K(1507328K), 0.0241803 secs] [Times: user=0.11 sys=0.00, real=0.02 secs] 
Heap after GC invocations=1 (full 0):
 PSYoungGen      total 458752K, used 29645K [0x00000000e0000000, 0x0000000100000000, 0x0000000100000000)
  eden space 393216K, 0% used [0x00000000e0000000,0x00000000e0000000,0x00000000f8000000)
  from space 65536K, 45% used [0x00000000f8000000,0x00000000f9cf3460,0x00000000fc000000)
  to   space 65536K, 0% used [0x00000000fc000000,0x00000000fc000000,0x0000000100000000)
 ParOldGen       total 1048576K, used 88K [0x00000000a0000000, 0x00000000e0000000, 0x00000000e0000000)
  object space 1048576K, 0% used [0x00000000a0000000,0x00000000a00163b0,0x00000000e0000000)
 Metaspace       used 26975K, capacity 54120K, committed 54400K, reserved 1114112K
  class space    used 3346K, capacity 4426K, committed 4480K, reserved 1048576K
}

So my question is: why don't I see the 512m and 1gb values for metaspace in the GC logs? Are the log values not directly related to flags?

I generally recommend developers to remove all options they don’t understand. The JVM has reasonable defaults and it makes no sense to assume to know a better value than the JVM, without even understanding the actual meaning of the option. — Holger, Dec 21 '16 at 17:05
The problem is, if i don't set the metaspace flags, server goes for many full gc in the startup. And i believe it is because metaspace becomes full, since it is something like 21mb as default for 64bit server. When i set the flag, full gc does not happen. My problem is solved. But i still want to understand the log and flag inconsistency. — oguz karakus, Dec 22 '16 at 07:15
The `-XX:MetaspaceSize` doesn’t specify an initial size, but the threshold at which a gc should be triggered. So as long as the actual metaspace size is smaller than that, it won’t trigger a gc. But this threshold isn’t constant. During the runtime, the JVM may choose new values based on the actual usage. But anyway, why is the *startup* time of a *server* so important? Wouldn’t it make more sense to tune the parameters for the long time performance? — Holger, Dec 22 '16 at 08:53
You are right about server start up time, it isn't that important, i was just tuning and wanted to get rid of full gc s at the start up and got curious at that point. Your last comment explains my misunderstanding of the flag, thank you for that. I can accept it if you can add it as answer. — oguz karakus, Dec 22 '16 at 09:33

score 2 · Accepted Answer · answered Dec 22 '16 at 10:01

As explained in “Advanced Garbage Collection Options”:

-XX:MetaspaceSize=size

Sets the size of the allocated class metadata space that will trigger a garbage collection the first time it is exceeded. This threshold for a garbage collection is increased or decreased depending on the amount of metadata used. The default size depends on the platform.

In other words, it doesn’t specify an initial size, but a first time gc threshold, so it matches your observed behavior of not having a full gc while the actual metaspace size is smaller than the specified size.

Once the threshold has been exceeded the first time, the JVM may choose a new threshold, based on the actual usage.

Why is garbage collection log Metaspace value different from provided flag?

1 Answers1

Linked