ZGC: Fix an incorrect column in GC statistics
Erik Österlund
erik.osterlund at oracle.com
Mon Aug 12 08:50:49 UTC 2019
Hi,
Looks good to me too.
/Erik
On 2019-08-11 11:07, Per Liden wrote:
> Hi,
>
> Nice catch! Change looks good. As far as I can tell there's no JIRA
> entry for this yet, so I'll create one and sponsor your fix.
>
> thanks,
> Per
>
> On 2019-08-11 02:16, Hao Tang wrote:
>> Hi, I found that column "total" of ZGC log's statistics always reports
>> obviously incorrect average values after running program with ZGC for
>> over 10 hours (36000s). See the GC log below.
>>
>> [36000.080s][info][gc,stats ] === Garbage Collection Statistics
>> =======================================================================================================================
>>
>> [36000.080s][info][gc,stats
>> ] Last
>> 10s Last 10m Last 10h Total
>> [36000.080s][info][gc,stats
>> ] Avg /
>> Max Avg / Max Avg / Max Avg / Max
>> [36000.080s][info][gc,stats ] Collector: Garbage Collection
>> Cycle 33.269 / 34.686 32.699 / 36.862
>> 32.938 / 60.703 0.000 / 60.703 ms
>> [36000.080s][info][gc,stats ] Contention: Mark Segment Reset
>> Contention 0 / 0 0 /
>> 0 0 / 0 1 / 0 ops/s
>> [36000.080s][info][gc,stats ] Contention: Mark SeqNum Reset
>> Contention 0 / 0 0 /
>> 0 0 / 0 1 / 0 ops/s
>> [36000.080s][info][gc,stats ] Contention: Relocation
>> Contention 0 / 0 0 /
>> 0 0 / 2277 1 / 2277 ops/s
>> [36000.080s][info][gc,stats ] Critical: Allocation
>> Stall 0.000 / 0.000 0.000 /
>> 0.000 0.000 / 0.000 0.000 / 0.000 ms
>> [36000.080s][info][gc,stats ] Critical: Allocation
>> Stall 0 / 0 0 /
>> 0 0 / 0 1 / 0 ops/s
>> [36000.080s][info][gc,stats ] Critical: GC Locker
>> Stall 0.000 / 0.000 0.000 /
>> 0.000 0.000 / 0.000 0.000 / 0.000 ms
>> [36000.080s][info][gc,stats ] Critical: GC Locker
>> Stall 0 / 0 0 /
>> 0 0 / 0 1 / 0 ops/s
>> [36000.080s][info][gc,stats ] Memory: Allocation
>> Rate 45 / 48 45 /
>> 48 45 / 90 0 / 90 MB/s
>> [36000.080s][info][gc,stats ] Memory: Heap Used After
>> Mark 126 / 130 125 /
>> 140 125 / 164 0 / 164 MB
>> [36000.080s][info][gc,stats ] Memory: Heap Used After
>> Relocation 48 / 52 47 /
>> 52 47 / 54 0 / 54 MB
>> [36000.080s][info][gc,stats ] Memory: Heap Used Before
>> Mark 124 / 130 123 /
>> 138 124 / 158 0 / 158 MB
>> [36000.080s][info][gc,stats ] Memory: Heap Used Before
>> Relocation 54 / 58 53 /
>> 60 53 / 60 0 / 60 MB
>>
>> The bug is caused by mistakenly adding "nsamples" to
>> ZStatSamplerData::_sum. I am applying the patch below to fix the bug.
>> Please give advice on this fix.
>> diff -r 8f067351c370 src/hotspot/share/gc/z/zStat.cpp
>> --- a/src/hotspot/share/gc/z/zStat.cpp Mon Aug 05 16:27:30 2019 -0700
>> +++ b/src/hotspot/share/gc/z/zStat.cpp Fri Aug 09 11:22:58 2019 +0800
>> @@ -63,7 +63,7 @@
>> void add(const ZStatSamplerData& new_sample) {
>> _nsamples += new_sample._nsamples;
>> - _sum += new_sample._nsamples;
>> + _sum += new_sample._sum;
>> _max = MAX2(_max, new_sample._max);
>> }
>> };
>> This patch can enable ZGC to print correct statistics after 10 hours.
>>
>> [36000.080s][info][gc,stats ] === Garbage Collection Statistics
>> =======================================================================================================================
>>
>> [36000.080s][info][gc,stats
>> ] Last
>> 10s Last 10m Last 10h Total
>> [36000.080s][info][gc,stats
>> ] Avg /
>> Max Avg / Max Avg / Max Avg / Max
>> [36000.080s][info][gc,stats ] Collector: Garbage Collection
>> Cycle 32.794 / 32.985 32.865 / 38.454
>> 33.212 / 80.477 33.212 / 80.477 ms
>> [36000.080s][info][gc,stats ] Contention: Mark Segment Reset
>> Contention 0 / 0 0 /
>> 0 0 / 0 0 / 0 ops/s
>> [36000.080s][info][gc,stats ] Contention: Mark SeqNum Reset
>> Contention 0 / 0 0 /
>> 0 0 / 0 0 / 0 ops/s
>> [36000.080s][info][gc,stats ] Contention: Relocation
>> Contention 0 / 0 0 /
>> 0 0 / 5978 0 / 5978 ops/s
>> [36000.080s][info][gc,stats ] Critical: Allocation
>> Stall 0.000 / 0.000 0.000 /
>> 0.000 0.000 / 0.000 0.000 / 0.000 ms
>> [36000.080s][info][gc,stats ] Critical: Allocation
>> Stall 0 / 0 0 /
>> 0 0 / 0 0 / 0 ops/s
>> [36000.080s][info][gc,stats ] Critical: GC Locker
>> Stall 0.000 / 0.000 0.000 /
>> 0.000 0.000 / 0.000 0.000 / 0.000 ms
>> [36000.080s][info][gc,stats ] Critical: GC Locker
>> Stall 0 / 0 0 /
>> 0 0 / 0 0 / 0 ops/s
>> [36000.080s][info][gc,stats ] Memory: Allocation
>> Rate 45 / 46 45 /
>> 48 45 / 92 45 / 92 MB/s
>> [36000.080s][info][gc,stats ] Memory: Heap Used After
>> Mark 124 / 126 125 /
>> 148 126 / 164 126 / 164 MB
>> [36000.080s][info][gc,stats ] Memory: Heap Used After
>> Relocation 48 / 52 48 /
>> 52 47 / 54 47 / 54 MB
>> [36000.080s][info][gc,stats ] Memory: Heap Used Before
>> Mark 122 / 124 123 /
>> 148 124 / 158 124 / 158 MB
>> [36000.080s][info][gc,stats ] Memory: Heap Used Before
>> Relocation 54 / 58 54 /
>> 60 53 / 60 53 / 60 MB
>>
>>
>> Best regards,
>> Hao Tang
>>
More information about the hotspot-gc-dev
mailing list