Troubleshooting GC Problems in Jenkins

Java garbage collection should work quietly in the background, making sure memory is always available for new tasks. When all is well, it’s unseen and unnoticed.

Until it goes wrong.

Garbage collection (GC) is a complex and resource-hungry process. Marking unused resources, removing them, and reorganizing memory is a highly CPU-intensive process. While some of this work can be done in the background while other threads continue to work, critical phases require a “Stop-the-World” event, where all productive work is temporarily paused. An overloaded garbage collector therefore kills application performance.

When Jenkins suffers from GC pressure, build queues stall, GUI responsiveness drops, and latency spikes. Severe GC bottlenecks trigger java.lang.OutOfMemoryError exceptions across worker threads, abruptly terminating running pipelines and dropping active tasks without saving state..

In this article, we’ll look at how to identify, troubleshoot, fix and prevent GC issues in Jenkins.

Common Symptoms of Jenkins Garbage Collection Problems

We should suspect GC overload if we experience any of the following in Jenkins:

• Slow builds;
• Scheduled jobs failing to start on time;
• Intermittent stalls;
• A sluggish GUI response;
• Other applications running on the same machine, such as Docker, are experiencing CPU starvation.

If we look at diagnostics, we’ll see that Jenkins CPU time is excessive, throughput is poor and latency is high. If the problem is acute, the Jenkins logs may show OutOfMemoryErrors.

Understanding the Root Causes of Jenkins GC Issues

Since the first release of Java, seven GC algorithms common to most JVM platforms have been developed, each suitable for a different scenario.

All of them have several things in common:

• Working from GC roots, they identify and mark live objects; i.e. objects that still have valid references pointing to them;
• Unmarked objects are then cleared from memory, releasing space for new allocations;
• From time to time, the heap may need to be compacted to avoid fragmentation;
• During critical phases of GC, all other threads are paused in a stop-the-world event;
• Minor GC events are short and frequent; full GC events take longer and only occur when minor GCs can’t clear enough space.

Most modern versions of Java at the time of writing default to using the G1GC algorithm. This splits the memory into regions, which it cleans individually. It’s capable of doing much of its work concurrently, while other application threads continue to work. In almost all Jenkins installations, G1GC is the best algorithm to use. In exceptional cases where the heap size is greater than 32GB, we may get better performance from either the ZGC or Shenandoah algorithms.

Factors that can cause the GC to lose efficiency include:

• Memory leaks: Memory retained by the application beyond the time where it’s actually needed;
• Under-configured Heap: The heap is too small for the workload;
• Object churn:  A large number of objects are created and released very quickly, and the GC struggles to keep up;
• Wastage: Plugins or Groovy scripts follow poor coding practices.
• Metaspace issues: Either too many classes are created by complex Groovy scripts, or the metaspace is under-configured. Jenkins’ plugin architecture, as well as dynamic Groovy class creation, often means the metaspace needs to be configured fairly high.
• Poor GC Tuning: While most applications work well with the default GC settings, these may not be suitable for all workloads.  We can often improve performance drastically with a few simple JVM arguments.
• Humongous Objects: G1GC splits the heap into regions for faster collection. Any object that occupies more than 50% of a region is classed as ‘humongous’, and must have its own dedicated region or set of regions. Adding a humongous object to the heap often results in the GC having to reshuffle other data to make enough contiguous space. This is sometimes the result of poor coding choices in Groovy pipelines, such as loading large files into memory instead of using streams.

In Jenkins, Groovy scripts often load large amounts of data into memory, for example, reading large files or storing test results into memory. Additionally, when Jenkins loads build history, this can be enormous. 

If we encounter GC problems as Jenkins administrators, we need to look at:

• The JVM configuration;
• GC tuning;
• Pipelines and history to identify areas of memory overload.

How to Diagnose Jenkins Garbage Collection Problems

When we suspect GC problems, the first thing to look at are GC logs. We should always have these enabled in live systems, since they use very little overhead and contain valuable diagnostic information. Although the logs are in readable text format, they’re likely to be very long, and analyzing them manually would take too much time. A GC log analyzer is therefore the most important tool for investigating GC behavior.

Depending on what we find in the logs, we may need to dig deeper by capturing a heap dump. This is a file containing a snapshot of the heap’s contents at a given moment. Since the file is in binary, we need a heap dump analyzer tool to explore its contents.

Note: While a heap dump is being captured, it adds significant overhead to the system. 
In a situation where performance problems are already critical, taking a heap dump has been known to crash the system.
In these situations, an alternative is to use the non-intrusive yc-360 script. This captures a wide range of diagnostics with little overhead, including a heap dump substitute.
The free open-source script is available from yc-360 on Github.

For the diagnostics in this article, we used GCeasy for log analysis and HeapHero to analyze the heap dump. Both of these tools are part of the yCrash suite.

1. GC Log Analysis

GCeasy produces an interactive report from the GC logs. It contains several useful sections. Let’s look at a few of them.

Recommendations: 

The report starts with a high-level machine learning analysis of the log. If GCeasy notices any problems, it highlights them. It then makes recommendations of changes that are likely to improve GC performance. The diagram below shows a sample recommendation section. Often, this leads us directly to the problem. As with all ML-generated solutions, however, we should fact-check by examining the detailed report, as well as testing and monitoring any configuration changes.

Fig: Sample GCeasy Recommendations

Key Performance Indicators:

Key performance indicators allow us to form an overall picture of how efficiently the GC is behaving. They include:

• Throughput. This is the percentage of CPU time spent running application tasks, as opposed to GC tasks. Throughput should be at least 95%, but healthy applications generally run at 98 – 99%.
• Latency. This represents the times when application threads are paused while GC carries out stop-the-world tasks. Maximum, average and percentile data are all important indicators of GC health. Different types of applications have different latency requirements. In batch tasks, high latency is tolerable, and throughput is more important. In online applications, latency requirements are more strict, whereas in real-time applications, low latency is critical. In Jenkins, a good balance between throughput and latency is the target.
• CPU Time. This is the actual amount of CPU time spent in GC. If this is high, performance drops.

See the image below for a sample KPI report.

Fig: KPI Chart by GCeasy

When trying out solutions to GC problems in Jenkins, the KPI are the best indicators of whether or not the changes have improved the situation.

Heap Usage Patterns:

Heap usage patterns let us see at a glance what the problem is likely to be. GCeasy plots heap usage over time, showing full GC events as red markers. Let’s look at the graphs of a few applications.

Healthy Pattern

Fig: Healthy GC Pattern

In a healthy application, objects are created as tasks are carried out, and the heap may even almost reach its maximum size. However, GC is always able to clear it back to a consistent level. The pattern may not always be as clear as this, but the most important thing is that the bottom line is fairly stable.

Memory Leak Pattern

Fig: Memory Leak Pattern

If the application has a memory leak, the GC still regularly clears the heap, but it never goes back to a stable bottom line. The bottom line slopes upwards as leaked objects accumulate over time. GC events happen more and more frequently, and eventually they run back to back before the application crashes with an OutOfMemoryError.

In Jenkins, since it is multithreaded, it’s often only one thread that crashes. If this happens, the GC log shows the memory leak pattern escalating to back-to-back GC events, then an abrupt drop in memory usage as the thread terminates.

For more information, see Resolving Memory Leaks in Java.

Under-configuration or Wasted Memory:

Fig: Under-configuration or Wastage Pattern

The symptoms are the same for under-configured memory and wasted memory. The heap continually remains close to the maximum, although GC is clearing it regularly. If the configured heap size looks too small, try increasing it; otherwise, check for memory wastage. In Jenkins, this may be due to a plugin, large Groovy variables or excessive build history.

The heap requirements of individual installations vary widely, since the nature of the workload will never be exactly the same. You can use the table of suggested heap sizes below as a starting point, but adjust the heap size as needed after monitoring performance over time. Accurate heap sizing is usually a case of trying different settings and monitoring the result.

Object Churn Pattern:

Fig: Object Churn GC Pattern

When an application is experiencing object churn, it’s because it’s creating objects and releasing them faster than the GC is able to easily clean them. Minor GCs run frequently, resulting in a spiky pattern as in the diagram above. In Jenkins, the problem is likely to be either within plugins or within Groovy scripts. The solution is usually to adjust the code to make objects re-usable where possible.

Metaspace Issues Pattern:

Fig: Metaspace Issues GC Pattern

If the Metaspace fills up, it can trigger back-to-back GC events, even though the heap is nowhere near full. This application had a healthy GC pattern, suddenly switching to frequent full GCs that did not make any difference to the heap size. Since GCs are running continually, no other tasks were active, so the heap usage remained the same. This is likely to result in the system crashing with the error: java.lang.OutOfMemoryError: Metaspace.

This can be caused by:

• Too many dynamic classes, for example, classes created by Groovy scripts. Simplifying or splitting Groovy pipelines may solve the problem.
• An under-configured metaspace. This is fairly common in Jenkins, since Jenkins deals with several plugins and complex Groovy scripts. 
• A classloader leak. This is rare in Jenkins, but can sometimes happens if there’s a glitch when updating plugins. Restarting Jenkins usually solves this problem.

For more information, see this article on Solving OutOfMemoryErrors in the Metaspace.

Object Stats

This section is particularly useful when monitoring whether or not object churn and GC tuning solutions are working. Comparing this section of the report to the original tells us whether object churn has been reduced.

Fig: Object Creation Statistics

GC Causes

Another useful section is an analysis of GC events by triggers. See the sample GCeasy chart below.

Fig: GCeasy Analysis of GC Events by Cause

These are important clues as to what may be causing the GC to overwork.

Here is a table of some of the most common causes of GC events.

2. Analyzing the Heap Dump

A heap dump lets us dig deeper to find what objects are actually responsible for memory leaks, object churn, humongous objects and memory wastage. It can also be useful for diagnosing metaspace issues, as it includes a class histogram.

Note: In Jenkins, the most important thing to look for is the package names of problematic objects. This tells us what area of Jenkins is likely to be the cause of the problem. At a high level, we can categorise Jenkins packages as shown below.
For more details of a particular package, see the Jenkins Javadoc page.

You can use tools such as HeapHero or Eclipse MAT to analyze the dump. The sample charts are taken from HeapHero. See this video for a quick lesson on How to Analyze Heap Dumps Fast.

For memory leaks, humongous objects and wastage, the best place to start is the Largest Object report, as shown below.

Fig: Heaphero Largest Object Report

From this, you can follow the dominator tree to find out what’s actually using the space, as shown in the recommended video.

For metaspace issues, the Class Histogram is the most useful section of the report. 

Fig: Class Histogram

This gives us insights into what classes are currently loaded.

If we suspect object churn, we should look at the Unreachable Objects report to see objects that have been released by the application but have not yet been garbage collected. 

Let’s look at a short program that deliberately causes object churn by creating and releasing objects very rapidly.

public class BuggyProg19 {
// Creates big arrays, which then go out of scope
// when each iteration of the loop terminates,
// causing object churn
// ==============================================
    public static void main(String[] args) {
       while(true) {
             String[] bigArray = new String[30000];
             for (int i=0;i<30000;i++)
                 bigArray[i]=""+i;
 
             try{Thread.sleep(1);} catch (Exception e){}
       }
    }

This loops indefinitely, creating and releasing a large variable on each iteration.

The image below shows the Unreachable Object report for this application when a dump is loaded into HeapHero.

Fig: Unreachable Object Report

The HeapHero report also contains an interactive breakdown of memory wastage, allowing us to explore wasted memory by category. The categories include duplicate strings, inefficient collections and boxed numbers.

The image below shows details of duplicate strings, which is one of the charts in the memory wastage section.

Fig: Duplicate Strings Report

How to fix GC Problems in Jenkins

Once we’ve diagnosed the cause, we can look for an appropriate fix.

It’s often worth looking at GC tuning first, since this is likely to give us performance gains very quickly. We can then look further for other causes. JVM tuning and configuration is beyond the scope of this article, so we recommend working through the G1GC Tuning guide to optimize garbage collection.

The table below lists common causes of Java garbage collection problems, what we might expect to see in the diagnostics for each, and suggested fixes for Jenkins.

Can Jenkins Garbage Collection Problems be Predicted and Prevented?

Jenkins GC problems seldom develop overnight, unless a newly-implemented plugin or pipeline has an acute memory leak.

By monitoring micrometrics , it’s nearly always possible to predict GC performance issues long before they’re noticeable to the users. As soon as throughput drops or latency increases, we can look for solutions proactively and without being in a panic situation.

We should make a practice of running the GC logs through a log analyzer such as GCeasy regularly, comparing the current log report to the previous one.

Look for the danger signals:

• Reduced throughput.
• Increased latency.
• Unhealthy patterns on the heap usage/ time graph.
• Sudden increase in object creation rate.
• Changes in the type of events triggering GC cycles.
• Increase in full GC frequency.

Alternatively, we can set up continuous monitoring with tools such as yCrash. This software samples JVM performance statistics regularly. If it detects any developing problems, it raises an alert while capturing full diagnostic information related to both the JVM and its environment.

Conclusion

GC overload is one of the most common  performance killers in Java applications.

In Jenkins, performance is critical, and outages can’t be tolerated.

Jenkins garbage collection problems cause unacceptable delays in releasing critical software upgrades and getting new applications production-ready.

System administrators should monitor GC behavior regularly, and be familiar with diagnostic tools to solve problems quickly.