[Gc] Understanding why GC'ing increases to the double in time?

Boehm, Hans hans.boehm at hp.com
Mon Jan 30 11:32:03 PST 2006


This looks somewhat mysterious to me.

The first (very) expensive collection overflows and then grows the mark
stack.  That is expected to be expensive, but shouldn't affect later
collections.  This should go away if you increase
INITIAL_MARK_STACK_SIZE (in mark.c).  It would be interesting to see if
that changes later GC times as well.  If so, I would suspect a GC bug.
If you can easily rebuild the collector, I think that would be a
worthwhile experiment.  The fact that the mark stack overflow occurs
exactly at the transition is suspicious.

Based on a quick look at the heap block dumps, I think it should be
unusually cheap to trace your heaps.  They seem to consist mostly of
large pointer-free objects.  The GC doesn't even touch those pages
during tracing.

The two things that are likely to make garbage collection expensive here
are:

1) Scanning the 3 MB root set.  The collector does have to read those at
every GC.  That's really a gcj issue that should get fixed there.  It
looks to me like there is more data here than there is
pointer-containing data in the heap, and thus most of the scan time
would probably go here.  (I usually assume that trace time depends to a
significant extent on the amount of memory that needs to be moved into
the cache.  That's probably less true on your platform.  I assume the
miss penalty is only 10 or 20 cycles?  Are cache lines large enough that
sequential reads perform well?)

2) Processing of finalizable objects may be an issue.  There are more of
them than I would have expected.  It would be nice to understand where
they're coming from.  If you can set a breakpoint in
GC_register_finalizer_inner, and sample every few hundred calls to see
where they are coming from, that might be interesting.  I'm not sure
whether finalizable objects are a major factor here, but I can't really
preclude it either.

If you have some way of getting an execution profile for the time spent
in the "long" GCs that might help to track things down.


Hans


> -----Original Message-----
> From: gc-bounces at napali.hpl.hp.com 
> [mailto:gc-bounces at napali.hpl.hp.com] On Behalf Of Martin 
> Egholm Nielsen
> Sent: Saturday, January 28, 2006 1:03 AM
> To: gc at napali.hpl.hp.com
> Subject: [Gc] Understanding why GC'ing increases to the 
> double in time?
> 
> 
> Hi,
> 
> Didn't quite know whether I should have kept this on the GCJ 
> list, but here goes anyway:
> 
> Prehistory - in short: I have "GC world stopped" times of 
> ~400 ms on my embedded PPC 133 Mhz platform running GCJ 
> compiled code. I would like to decrease that time...
> 
> Now, I have noticed that before "activating/touching" certain 
> parts of my application (different parts may do it), the 
> world stop times suddenly "doubles".
> 
> I would like to know/understand why. I've attached some dumps 
> from the same "session" showing that I start with world stop 
> times off ~200 ms, and ending up with ~360 ms. I notice the 
> log files are bigger - due to the increased amount of blocks. 
> Is that the same reason the world-stop times are increased?
> 
> Best regards,
>    Martin Egholm
> 
> 



More information about the Gc mailing list