gc log entry format

[Y. Srinivas Ramakrishna]

Jon Masamitsu wrote:
> I think you're seeing a mix of the ParNew collection experiencing a
> promotion failure and resulting in a full collection - this part
> 
> 41.599: [CMS
> 
> and at the same time a CMS concurrent phase starting
> 
> 41.600: [CMS-concurrent-abortable-preclean:

That's the concurrent phase _ending_. It turns out that because
of historical reasons, we have to _end_ an ongoing concurrent
phase before the foreground collection can take over and
do a full gc as done here. So, yes, each concurrent mode failure
will likely have such a report of the "interrupted" concurrent
phase reporting its end before the foreground compacting
collection occures.

> 
> Yah, we hate it too.  We're not doing any piecemeal fixing
> of the logging since we're trying to overhaul the whole thing.
>

Right, and as we've remarked on occasion, our approach in the
interim is to post-process the logs so as to separate out such
interleaving so that our existing parsers can grok the data.
Perhaps that approach can work for Kirk too in the interim...

-- ramki

> 
> 
> On 5/26/10 12:58 PM, Kirk Pepperdine wrote:
>> Hi all,
>>
>> In build 1.6.0_17-b04-248-9M3125 I've been running into log entries 
>> that look like this.
>>
>> 41.597: [GC 41.597: [ParNew (promotion failed)
>> Desired survivor size 1343488 bytes, new threshold 4 (max 4)
>> - age   1:     744120 bytes,     744120 total
>> - age   2:     529152 bytes,    1273272 total
>> - age   3:      32392 bytes,    1305664 total
>> : 17486K->17249K(18624K), 0.0021027 secs]41.599: [CMS41.600: 
>> [CMS-concurrent-abortable-preclean: 0.028/0.632 secs] [Times: 
>> user=1.00 sys=0.04, real=0.63 secs]
>>  (concurrent mode failure): 63809K->8087K(64768K), 0.0860671 secs] 
>> 81202K->8087K(83392K), [CMS Perm : 10707K->10707K(21248K)], 0.0883203 
>> secs] [Times: user=0.09 sys=0.00, real=0.09 secs]
>>
>> Looks like ParNew is mixed with the invocation of the CMS instead of 
>> that record being on a new line. The format is consistent but not so 
>> nice to parse ;-)
>>
>> Regards,
>> Kirk
>