Java Garbage Collection Logging: Difference between revisions

From NovaOrdis Knowledge Base
Jump to navigation Jump to search
 
(One intermediate revision by the same user not shown)
Line 5: Line 5:
=Java 9=
=Java 9=


=Java 8=
"-Xloggc:" becomes "-Xlog:gc:"


{{External|https://docs.oracle.com/javase/8/docs/technotes/tools/windows/java.html#BABFAFAE}}
'PrintGCDateStamps' was dropped.


==Overview==
=Java 8=
 
In Java 8, GC logging is enabled with the <tt>[[#-Xloggc:|-Xloggc:<file>]]</tt> (see below). The actual -XX values the JVM operates with are displayed at the top of the log file:
 
<pre>
...
CommandLine flags: -XX:InitialHeapSize=268435456 -XX:MaxHeapSize=4294967296 -XX:+PrintGC -XX:+PrintGCTimeStamps -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseParallelGC
...
</pre>
 
 
The recommended GC logging configuration is:
 
<pre>
-Xloggc:<absolute-path> -XX:+PrintGCDateStamps -XX:+PrintGCDetails
</pre>
 
In case the space of the filesystem logs are written onto is limited, [[#GC_Log_File_Rotation|log rotation]] can be enabled.
 
==Options==
 
===-Xloggc:===
 
Turns on GC logging and directs the output into the specified file. When used, <tt>[[#-verbose:gc|-verbose:gc]]</tt> becomes irrelevant.
 
<pre>
-Xloggc:<file>
</pre>
 
where <file> can be absolute or relative. In case of a relative path, it is relative to the current directory.
 
If used, the option automatically turns on the following: <tt>[[#-XX:.2BPrintGC|-XX:+PrintGC]]</tt>, <tt>[[#-XX:.2BPrintGCTimeStamps|-XX:+PrintGCTimeStamps]]</tt>.
 
===-XX:+PrintGC===
 
<pre>
-XX:+PrintGC
</pre>
 
Enables printing of messages at every GC. By default, this option is disabled, but <tt>[[#-Xloggc:|-Xloggc:<file>]]</tt> turns it on implicitly.
 
===-XX:+PrintGCTimeStamps===
 
<pre>
-XX:+PrintGCTimeStamps
</pre>
 
Enables printing of time stamps (time in seconds since the JVM started) at every GC. By default, this option is disabled. It is implicit turned on if <tt>[[#-Xloggc:|-Xloggc:<file>]]</tt> is used. Time stamps recorded this way provide a chronology relative to the time the JVM started, but additional calculation is needed to translate the timestamps to normal timestamps, and it is only possible if the JVM start time is also recorded. A better way to record timestamps is to use <tt>[[#-XX:.2BPrintGCDateStamps|-XX:+PrintGCDateStamps]]</tt>.
 
===-XX:+PrintGCDateStamps===
 
<pre>
-XX:+PrintGCDateStamps
</pre>
 
Records the GC event timestamps in the following format:
 
<pre>
2017-02-12T19:26:03.328+0800:
</pre>
 
===-XX:+PrintGCDetails===
 
Enables printing of detailed messages at every GC:
 
<pre>
-XX:+PrintGCDetails
</pre>
 
When used, each GC event contains information of how the event affected various heap areas such as the young generation, old generation and the metaspace. The default behavior is to report how the entire heap was modified as the result of the GC event. The difference in output is the following:
 
<pre>
2017-02-12T19:26:03.378+0800: 0.144: [Full GC (Ergonomics)  126674K->126513K(413696K), 0.0181008 secs]
</pre>
 
<pre>
2017-02-12T19:42:35.003+0800: 0.156: [Full GC (Ergonomics) [PSYoungGen: 10721K->0K(141824K)] [ParOldGen: 115952K->126513K(270848K)] 126674K->126513K(412672K), [Metaspace: 3447K->3447K(1056768K)], 0.0182535 secs] [Times: user=0.10 sys=0.03, real=0.02 secs]
</pre>
 
===-verbose:gc===
 
Displays GC log information at stdout. This option is rendered irrelevant by  <tt>[[#-Xloggc:|-Xloggc:<file>]]</tt>. When <tt>-Xloggc:<file></tt> is used, the GC log information is redirected into the specified file.
 
<pre>
-verbose:gc
</pre>
 
===GC Log File Rotation===
 
<pre>
-XX:+UseGCLogFileRotation
</pre>
 
<pre>
-XX:NumberOfGCLogFiles=5
</pre>
 
<pre>
-XX:GCLogFileSize=3M
</pre>
 
===-XX:+PrintGCApplicationConcurrentTime===
 
Enables printing of how much time elapsed since the last GC pause.
 
<pre>
-XX:+PrintGCApplicationConcurrentTime
</pre>
 
Output Example:
 
<pre>
2017-02-12T19:54:39.920+0800: 0.484: Application time: 0.0261502 seconds
</pre>
 
===-XX:+PrintGCApplicationStoppedTime===
 
Enables printing of how much time the GC pause lasted.
 
<pre>
-XX:+PrintGCApplicationStoppedTime
</pre>
 
Output Example:


<pre>
{{Internal|Java 8 Garbage Collection Logging#Overview|Java 8 Garbage Collection Logging}}
2017-02-12T19:57:57.170+0800: 0.116: Total time for which application threads were stopped: 0.0218238 seconds
</pre>


=Application Specific GC Logging=
=Application Specific GC Logging=

Latest revision as of 19:22, 28 December 2020

Internal

Java 9

"-Xloggc:" becomes "-Xlog:gc:"

'PrintGCDateStamps' was dropped.

Java 8

Java 8 Garbage Collection Logging

Application Specific GC Logging

WildFly GC Logging

WildFly GC Logging in Standalone Mode
WildFly GC Logging in Domain Mode
Retrieved from "https://kb.novaordis.com/index.php?title=Java_Garbage_Collection_Logging&oldid=74291"