Bug in G1GC it performs Full GC when code cache is full resulting in overkill

[Thomas Schatzl]

Hi,

On Mon, 2013-06-10 at 15:22 +0300, Martin Makundi wrote:
> >> Regarding bytecode rewriting, I found
> >> https://code.google.com/p/java-allocation-instrumenter/ which on the
> >> front page already gives an example for almost what you want to achieve.
> >
> > Thanks, this seems to work, will try that to see how it impacts and
> > what we can find out. The first large object we found was a
> > stringbuilder from a logger that collects stacktraces to dump them
> > optionally after a certain timeout... need to redesign that up front
> > ;)
> 
> Interesting, my allocationrecorder did not catch the allocation:
> 
>[...]
>
>While gc log says:
> 
>  28787.582: [G1Ergonomics (Heap Sizing) attempt heap expansion,
> reason: humongous allocation request failed, allocation request:
> 58720272 bytes]
>  28787.582: [G1Ergonomics (Heap Sizing) expand the heap, requested
> expansion amount: 58720256 bytes, attempted expansion amount: 58720256
> bytes]
>  28787.582: [G1Ergonomics (Heap Sizing) did not expand the heap,
> reason: heap expansion operation failed]
>  28787.585: --""--
>  28787.585: --""--
>  28787.585: --""--
>  28787.585: --""--
>  28787.585: --""--
>  28787.585: --""--
>  [ gc executed message ]
> 
> Does this make sense?

To me, the log indicates that there are multiple threads trying to
allocate large objects, all of them failing to do so, only then
triggering the gc.

I assume you checked that the log messages are not possibly printed
after the gc? The instrumentation invokes the allocation sampler after
allocation. So in this case, the threads will block at the allocation,
wait for gc, and only after that print the expected messages. There may
also be a delay between the gc output and the allocation information.

This should not be a problem, as this does not influence a stack trace
in the AllocationSampler.

In very quick tests the correct amount of allocations were always
reported, also after full gc.

Maybe looking at the code for the instrumentation helps finding this
issue (this is the first one such bytecode rewriting tool that looked
simple to use that I found as example).

Thomas