United StatesChange Country, Oracle Worldwide Web Sites Communities I am a... I want to...
Bug ID: JDK-7141200 log some interesting information in ring buffers for crashes
JDK-7141200 : log some interesting information in ring buffers for crashes

Details
Type:
Enhancement
Submit Date:
2012-01-31
Status:
Closed
Updated Date:
2012-03-22
Project Name:
JDK
Resolved Date:
2012-02-21
Component:
hotspot
OS:
solaris_10
Sub-Component:
runtime
CPU:
x86
Priority:
P3
Resolution:
Fixed
Affected Versions:
hs23
Fixed Versions:
hs23 (b13)

Related Reports
Backport:
Backport:

Sub Tasks

Description
There is interest in capturing more information about what the JVM was doing in the recent history before a crash.

                                    

Comments
EVALUATION

http://hg.openjdk.java.net/hsx/hotspot-comp/hotspot/rev/aa3d708d67c4
                                     
2012-02-01
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.
                                     
2012-02-06
EVALUATION

http://hg.openjdk.java.net/lambda/lambda/hotspot/rev/aa3d708d67c4
                                     
2012-03-22



Hardware and Software, Engineered to Work Together