Tuesday, October 4, 2011

JavaOne 2011: Are Your Garbage Collection Logs Speaking to You?

"Are Your Garbage Collection Logs Speaking to You?" (24466) was the last session I attended on the second day (Tuesday, October 4) of JavaOne 2011. This "BOF" was held in Hilton San Francisco's Plaza A/B. It looked like it might get a little ugly when attendees were congregating outside the door waiting for the previous session to end, but there appears to have been enough room albeit for a well-attended presentation. Kirk Pepperdine's title slide called the presentation "Do Your GC Logs Speak to You: Using Measurements to Tune Java Memory Management."

Pepperdine stated that "GUI tools are human scalable and logs are machine scalable." He added that "GC logs contain key performance indicators." He showed a slide with several command-line options that can be used for logging garbage collection events. Pepperdine also told us that they have not yet provided information on G1 because they have not had the necessary access to it. He said it took a couple years to evaluate the tuning steps for CMS.

Pepperdine said that all explicitly provided switches should be used with particular intent or should not be specified at all on the command line. He talked about abnormal situations due to memory leaks and high rates of object creation or characterized by long pause times and other symptoms. Pepperdine said to prefer "live object harvesting" from young generation memory.

"Weak Generational Hypothesis" (also defined by Pepperdine in his Fasterj column The Garbage First Collector) states that objects will die very quickly or they will live a very long time. You can either work with this hypothesis (narrowly scoped local variables) or fight it (static variables).

Pepperdine showed an example where a full garbage collection was occurring as evidenced in the garbage collection log. It was clear from his log example that no thresholds were being hit at which full garbage collection should be kicked off. The only conclusion is that the code was invoking explicit System.gc(). Pepperdine stated that it's rarely a good idea to explicitly do this because of the cost. When it's done as part of the natural garbage collection process, costs are amortized better across the overall garbage collection effort.

Pepperdine used some tools to help analyze the logs. He used his own censum application, but said one could do similar things with parsing of log files and populating an Excel spreadsheet. He also showed an HP tool (HP jTune?). Update (6 October 2011): JZ pointed out that this tool is HPjmeter in a comment below.

Pepperdine's slides would make a nice reference because he has portions of garbage collection logs marked with annotations as to what they mean. These color coded ovals would be helpful in more easily understanding what the somewhat cryptic log format is trying to tell one. The only disadvantage to these slides for reference is that Pepperdine added significant verbal description to what the slide was showing in text and graphics. It would be more difficult to see what these slides are communicating without the verbal accompaniment.


JZ said...

The HP tool would be HPjmeter. It can read GC logs, heap dumps, and profiling data.

@DustinMarx said...

Thanks JZ,

I have updated the post to reflect the tool as HPjmeter.