Andreas Grabner About the Author

Andreas Grabner has been helping companies improve their application performance for 15+ years. He is a regular contributor within Web Performance and DevOps communities and a prolific speaker at user groups and conferences around the world. Reach him at @grabnerandi

Performance Analysis: How to identify “bad” methods messing up the GC

Whenever the Garbage Collector kicks in to free up memory - the runtime puts all currently executing threads on hold in order to do the cleanup. The GC runs when the application tries to allocate new objects and not enough free memory is available in the 1st Generation Heap. Putting the current execution on hold means that the overall performance of the system is affected. This is of course normal behavior and we are all glad that we have Garbage Collection because it makes our life easier when dealing with memory. Too high GC activity however indicates that memory might not be used wisely, e.g.: too many object allocations

Analyze GC Activity

First thing to do is that we need to identify how our GC activity looks like. I’ve covered this already in my previous blog post. There are different performance counters available – both in Java and .NET – that you can monitor. Following image shows the GC Activity of a .NET Application by looking at the % Time in GC

% in GC Time

% in GC Time

The graph shows that we definitely have a too active Garbage Collector. More than 50% of the time is actually spent by the GC between every GC cycle. The best practice here says that a value under 10% with occasional spikes is ok. Values above 50% are too high and need further investigation.

Identifying “bad” methods

So – who is responsible for this high activity?

One approach to identify those methods that cause a GC to kick in is to look at those methods that are executed when the GC actually starts running. Over a longer period of time, e.g: during a load-test – you will see those methods showing up that constantly allocate new objects causing the GC to clean up memory. dynaTrace provides a feature that shows those methods that were put on hold by the GC. The following image shows the so called Runtime Suspension View. It shows those methods that have been put on hold, how often it happend and how much time was actually spend in suspension mode.

Runtime Suspension Overview

Runtime Suspension Overview

It seems that – based on the view above - the method getOffers was suspended 4806 times for a total time of more than 92 seconds. It has a far higher count than all other methods that have been suspended in my test run. It is a good indication that this method is allocating many objects and should therefore be the starting point of my investigation.

Conclusion

Watch out for your Garbage Collector Activity. Allocating lots of objects cause the GC to suspend the runtime and therefore impacting the overall performance. Being smart with how you allocate objects decreases GC times and therefore improves overall performance.

Trackbacks

  1. [...] Louth made a good reference to one of his blog posts on my recent blog entry. He filters the captured performance data in a distributed Java application to focus on those [...]

Comments

*


9 − = eight