Unified Garbage Collection Logging Recommendations
- Enabling Unified GC Logging
- Configuring Rotation of Large Log Files
- Concatenating Tags
- Configuring Multiple Logs
- Inspecting GC Performance
- Mapping Old and Unified GC Logging Options
Looking for Zing? The Azul Zing Virtual Machine is now Azul Zulu Prime Builds of OpenJDK and part of Azul Platform Prime. Learn more.
Starting with Java 9, the unified logging infrastructure in Java Virtual Machine (JVM) provides access to log messages from different subsystems (compiler, gc, classload, etc.). See JEP 158: Unified JVM Logging for more information.
The unified logging system for all JVM components includes reimplemented GC logging which is described in JEP 271: Unified GC Logging. Azul Platform Prime 20.09.0.0 introduces support for unified GC logging in Azul Platform Prime 8, 11, and 13. Both sets of GC logging options - old and unified - are supported.
For non-detailed GC logging, use unified
-Xlog:gc instead of old
-XX:+PrintGC. For detailed information, use unified
-Xlog:gc* instead of old
-XX:+PrintGCDetails. A unified log message has a tag and a level set associated with it. To quickly see examples of
-Xlog usage syntax, available tags, levels, decorators, and sample command lines with explanations, use:
-Xlog:gc is a command-line option to perform unified GC logging using the Azul Zulu Prime Builds of OpenJDK (Azul Zulu Prime JVM) unified logging framework.
Example 1. Syntax of the -Xlog option
gcis a tag to log GC related information.
<output>specifies the target location for GC log messages.
<decorators>are used to define information that log messages include.
<output_options>are varied output options for logging additional information.
Unified logging is performed at six different levels that correspond to the amount of details included. You can choose messages to log based on the preferred level. The levels are listed in increasing order of verbosity:
Enabling Unified GC Logging
-XX:+UseGCUnifiedLogging enables unified GC logging, and
-XX:-UseGCUnifiedLogging disables it in Azul Zulu Prime JVM. By default, unified GC logging is enabled in Azul Zulu Prime JVM.
To start unified GC logging, use:
This command-line option logs messages tagged with the
safepoint tags using
info level to
gc.log. By default, a GC log is written to
To get more detailed information, use:
Example 2. A sample unified GC log entry
[2.308s][info][gc] [Safepoint max times: safepoint 21.697 ms, time to safepoint 14.273 ms]
[2.308s]is the time since the start of the Azul Zulu Prime JVM
[info]is a default logging level
[gc]is the name of the GC-specific tag
[Safepoint max times: safepoint 21.697 ms, time to safepoint 14.273 ms]is a log message
Azul Zulu Prime JVM supports the following three output types:
To log GC messages to a file rather than to a console, use:
file= is optional and can be omitted.
Configuring Rotation of Large Log Files
To configure log files to handle file rotation based on file size and a number of files to rotate, use:
Example 3. A sample -Xlog:gc command for configuring log rotation
gcis a tag to log GC-specific information.
none specifies no decorations.
gc.logspecifies the file name for GC log messages.
filesize=10Msize of each file in the log file set
filecount=5specifies the number of files in a rotating set (current log + 5 archive files)
By default, that is when using
-Xlog:gc:gc.log, the size of a rotating file is 10 MB and the number of files in rotation is 5.
To turn off rotation, specify
0 in the
filecount, for example,
To include messages tagged with different tags in your GC log output, you can concatenate the tags with
+ as shown in Example 4.
Example 4. A sample -Xlog:gc command for concatenating tags
The resulting GC log contains all messages that feature the gc and phases tags:
[2.299s][info][gc] [SPS 0.000 0.000 0.001 0.178 0.005 0.000 0.008 0.087 0.142 0.420 NewGC_pause2 2.299078 [2.299s][info][gc, phases] [New GC cycle 3-2: concurrent ref processing]
Additionally, you can specify a logging level by adding
=<level> after the set of tags as follows:
This includes all messages with the gc, task, and stats tags at the debug logging level.
Configuring Multiple Logs
To simultaneously log messages from different subsystems to separate files, specify particular tags (or a combination of tags) and file names in the command line, for example:
This creates a
gc.log file with GC related messages and a
gcdetails.log file with detailed GC related messages.
Example 5. A sample log entry with a gc tag
[5.010s][info][gc] [VM has exited gracefully]
Example 6. A sample log entry with gc and details tags
[5.009s][info][gc,details] [Unmapping heap memory, 0 millis]
Inspecting GC Performance
With the safepoint tag, you can compare the performance of GC implementations over different JVMs as it produces similar log lines on all JVMs for pauses affecting application performance. The highest performance regarding latency is achieved when pauses are as short as possible.
Example 7. A sample output on Azul Zulu Prime JVM
[105.482s][info][safepoint] Total time for which application threads were stopped: 0.0003760 seconds, Stopping threads took: 0.0000014 seconds
The snippet above shows
-Xlog:gc,safepoint:gc.log output on Azul Zulu Prime JVM with a pause of 0.376 ms at 105 seconds after application start.
Example 8. A sample output on OpenJDK
[55.350s][info][safepoint] Safepoint "CollectForAllocation", Time since last: 553327366 ns, Reaching safepoint: 188921 ns, At safepoint: 94660058 ns, Total: 94848979 ns
The log entry above shows
-Xlog:gc,safepoint:gc.log output on OpenJDK with a pause of 94.848 ms at 55 seconds after application start.
To filter Azul Zulu Prime JVM and Hotspot logs to always select the total time, use the following script:
grep safepoint.*Total gc.log | sed -E 's/^\[([0-9\.s]+).*Total[a-z ]*: ([0-9\.]+ [a-z]+).*/\1 \2/'
Example 9. A sample regex output on Azul Zulu Prime JVM
109.288s 0.0003746 seconds
Example 10. A sample regex output on OpenJDK
103.339s 257668 ns
For Azul Zulu Prime JVM GC logs, you can also use Azul Zulu Prime JVM GCLogAnalyzer which displays performance-related metrics as graphs.
Mapping Old and Unified GC Logging Options
The table below contains a list of old GC logging command-line options and their unified GC logging equivalents.
|Old GC Logging Option||Unified GC Logging Configuration|