Skip to main content

Java Garbage Collection Logging

Peter
Updated

This article summarizes Sonatype recommended settings to be used for capturing garbage collection (GC) activities in our server products.

Base Settings

-XX:+PrintGCDetails
-XX:+PrintGCDateStamps
-XX:+PrintGCApplicationStoppedTime
-XX:+PrintGCApplicationConcurrentTime
-XX:+UseGCLogFileRotation
-XX:NumberOfGCLogFiles=10
-XX:GCLogFileSize=200M
-Xloggc:./log/gc.%t.log

Why Monitor Garbage Collection

Collecting Java Hotspot Virtual Machine (JVM) garbage collection activities is an advanced diagnostic. The information may be helpful to diagnose performance issues related to memory optimization and application pauses.

Settings to enable garbage collection logging are non-standard options to a java program. Non-standard options are general purpose options that are specific to the Java HotSpot Virtual Machine, so they are not guaranteed to be supported by all JVM implementations, and are subject to change.

Is GC Logging Suitable for a Production Server?

Our experience is the overhead of GC logging is negligible compared with the performance issue that it can help diagnose. You are more likely to hit some other bottleneck long before GC logging causes a concern. Without GC monitoring, some performance problems are difficult to diagnose. You have the option to only enable GC logging after a performance issue is encountered that requires it. However enabling GC logging will require a server application restart.

GC Log Best Practices

  1. Log GC to an explicit file, not stderr.
  2. Use GC Log file rotation. Both the number of files to keep and the size of each file should be specified.
  3. Always log date/time. Without date stamps in the GC log it will be impossible to correlate GC activity with other application log files.
  4. Store logs in a predictable location that survives upgrades. The following are good default relative path locations:
    Nexus Repository Manager 3.x: ../sonatype-work/nexus3/log/
    Nexus Repository Manager 2.x: ../sonatype-work/nexus/logs/
    Nexus IQ Server: ./log/

Specifying GC Log File Name

The path to the GC log file is specified using the Oracle Java non-standard option -Xloggc:<path-to-file>. The path can be relative or absolute. If relative, it is relative to the directory from which java is executed which will also be the value of the JVM system property user.dir.

In practice the user.dir value is the same directory where the Nexus Repository Manager or Nexus IQ Server runtime files are installed ( installation dir - not a ./bin sub-directory, not the work directory ).

The GC log file name you specify will be used as the base file name template. If log rotation is not used, the GC log file name will be exactly as specified and grow without bounds, being appended to on subsequent java restarts.

Any directories specified in the log file name must already be created and writable by the java process owner before the JVM is started. The JVM will not create directories for you. If a directory does not exist or is not writable, there will be a single warning printed to stderr. For example:

>Java HotSpot(TM) 64-Bit Server VM warning: Cannot open file ../sonatype-work/nexus3/doesnotexist/gc.log due to No such file or directory

Not being able to open the file for writing will NOT prevent startup of the application - but will prevent capturing any GC log information. Therefore make sure there are no typos in your GC log file path.

GC Log File Naming Conventions

The file name portion of the log file must adhere to certain conventions which are enforced by java program. If the convention is violated you will see a message about this and the java process will exit. An example:

Invalid file name for use with -Xloggc: Filename can only contain the characters [A-Z][a-z][0-9]-_.%[p|t] but it has been ../sonatype-work/nexus3/log/gc.$$.%t.log
Note %p or %t can only be used once
Error: Could not create the Java Virtual Machine.
Error: A fatal exception has occurred. Program will exit.

Special Name Placeholder: %p

When %p is used in the gc log file name, it will be replaced with the text "pid" plus the process id.

For example this argument:

-Xloggc:../sonatype-work/nexus3/log/gc.%p.log

May generate an active log file named:

./sonatype-work/nexus3/log/gc.pid2680.log.0.current

or a rotated file name:

./sonatype-work/nexus3/log/gc.pid2680.log.0

Special Name Placeholder: %t

When %t is used in the gc log file name, it will be replaced with a timestamp representing the exact time the java program was started, in the timezone of the host JVM.

For example this argument:

-Xloggc:../sonatype-work/nexus3/log/gc.%t.log

May generate an active log file named:

./sonatype-work/nexus3/log/gc.2018-03-28_14-58-30.log.0.current

or a rotated file name:

./sonatype-work/nexus3/log/gc.2018-03-28_14-58-30.log.0

GC Log File Rotation

Log file rotation is activated by -XX:+UseGCLogFileRotation , but will also require setting the number of files and file size as well.

A period plus a zero based index number is appended to the base name. For example:

./sonatype-work/nexus3/log/gc.log.0

The active log file that is being written to will have a period plus the word "current" appended as well. For example:

./sonatype-work/nexus3/log/gc.log.0.current

Log file rotation is done in a round robin fashion. When the active log file has reached its size limit specified by -XX:GCLogFileSize and the total number of log files equals the value specified by -XX:NumberOfGCLogFiles, then the oldest/first log file is deleted and replaced with the base log name plus "0.current" .

External References

Advanced Garbage Collection Options ( Linux / Windows )

 

Related articles