Request for review 7141200: log some interesting information in ring buffers for crashes

[Jon Masamitsu]

Tom,

I only looked at the files from

src/share/vm/services/memoryManager.*
src/share/vm/utilities/debug.*
|| src/share/vm/utilities/events.*
src/share/vm/utilities/exceptions.cpp
src/share/vm/utilities/vmError.cpp*

*In events.hpp if the variable _filled maybe would be
better named _entries to indicate the number of entries
written.  I initially thought with _filled you were trying
to record the number of times the buffer wrapped.

Copyrights need updating.

These are supposed to be start and end times?

| Time: 0.000000.3 - 0.000000.3


Jon


On 01/30/12 23:50, Tom Rodriguez wrote:
> http://cr.openjdk.java.net/~never/7141200
> 664 lines changed: 389 ins; 185 del; 90 mod; 37188 unchg
>
> 7141200: log some interesting information in ring buffers for crashes
> Reviewed-by:
>
> 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 running some benchmarks.  Tested with JCK vm and lang, and
> the nsk tests.
>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://mail.openjdk.java.net/pipermail/hotspot-dev/attachments/20120131/819b1c6e/attachment.html