JDK-7141200 : log some interesting information in ring buffers for crashes
Type:Enhancement
Component:hotspot
Sub-Component:runtime
Affected Version:hs23
Priority:P3
Status:Closed
Resolution:Fixed
OS:solaris_10
CPU:x86
Submitted:2012-01-31
Updated:2014-03-12
Resolved:2012-02-21
The Version table provides details related to the release that this issue/RFE will be addressed.
Unresolved : Release in which this issue/RFE will be addressed. Resolved: Release in which this issue/RFE has been resolved. Fixed : Release in which this issue/RFE has been fixed. The release containing this fix may be available for download as an Early Access Release or a General Availability Release.
EVALUATION
7141200: log some interesting information in ring buffers for crashes
Reviewed-by: kvn, jrose, kevinw, brutisso, twisti, jmasa
As part of convergence with JRockit it was requested that Hotspot
capture some internal events in ring buffer so that they could be
dumped into the error log to provide more context at crash time. I
chose to make these logs be mostly text based for simplicity of
implementation. Eventually more of the flight recorder infrastructure
will be in place and the recording of this kind of data should be more
integrated the infrastructure for that. So my current implementation
is somewhat ad hoc since I expect it will be revisited.
This also doesn't include one of the more important features, dumping
crashing context when scanning the heap. Capturing that information
without impacting GC performance is difficult and would require broad
changes in the heap iteration code. That can possibly be address later.
I've chosen to tear out the existing Events class which was a debug
only feature of limited use and extend that into a collection of
product ring buffers. They are registered during JVM startup and
dumped into the hs_err log when the JVM crashes. There are a couple
different categories maintained: compilation, deopt, internal
exceptions, other uncategorized messages and GC events. Each ring
buffer has it's own mutex to reduce contention across different kinds
of events and generally logging is performed for relatively infrequent
or expensive events to minimize any performance penalty. I also chose
to maintain separate logs for the categories so that higher frequency
events one kind don't hide other kinds.
I eliminated some of the less useful Events::log calls as well and
move some others around.
The GC logging keeps track of GC history using GCStatInfos. This has
the benefit that it's GC independent and provides before and after
information. It could also or instead capture Universe::print_on
though that's pretty verbose output. The GC section is fairly long
and I'm not sure what the best output would be. Opinions would be
appreciated.
There are some EventMarks in GC code that I'm tempted to delete. Any
objections?
I put a couple example logs at:
http://cr.openjdk.java.net/~never/7141200/example1.log
http://cr.openjdk.java.net/~never/7141200/example2.log
I can produce others if needed.
Performance seems to be largely unchanged according to refworkload but
I'm still in process of running final results. Tested with JCK vm and
lang, and the nsk tests.