RFR(S): 8000831: Heap verification output incorrect/incomplete

[John Cuthbertson]

Hi Bengt,

Thanks for looking at the code.

I honestly don't know the answer to your question. As I said in my 
earlier response to Ramki - I was surprised that all of the call sites 
were passing false for the silent parameter. I can't remember if that 
has always been the case. I'm also not sure if it always will be either. 
My guess is that no one thought of using a global flag, or if they did 
they reasoned that others may still want a finer grained control.

Regards,

JohnC

On 10/15/12 06:30, Bengt Rutisson wrote:

> Hi John,
>
> The changes look good to me.
>
> One kind of high level question. Why do we have a parameter and let 
> every caller decide whether or not to print verbose output instead of 
> having a flag to allow the user to turn it on and off on the command 
> line? Seems more consistent with other log output to have a flag like 
> PrintGCVerification or TraceGCVerification. A bit like the flag 
> TraceProtectionDomainVerification does now.
>
> Bengt
>
> On 2012-10-13 01:22, John Cuthbertson wrote:
>> Sending to the correct alias....
>>
>> Hi Everyone,
>>
>> Can I have a couple of volunteers review the fix for this CR - the 
>> webrev can be found at: 
>> http://cr.openjdk.java.net/~johnc/8000831/webrev.0/
>>
>> Summary:
>> An earlier change inadvertently turned off part of the output of heap 
>> verification:
>>
>> [Verifying threads syms strs zone dict hand C-heap code cache ]
>> VerifyBeforeGC:4.619: [GC [PSYoungGen: 16896K->416K(19712K)] 
>> 16896K->420K(62720K), 0.0170685 secs] [Times: user=0.02 sys=0.00, 
>> real=0.02 secs]
>> VerifyBeforeGC:5.013: [GC [PSYoungGen: 17312K->416K(19712K)] 
>> 17316K->424K(62720K), 0.0125283 secs] [Times: user=0.02 sys=0.00, 
>> real=0.01 secs]
>> VerifyBeforeGC:5.239: [GC [PSYoungGen: 17312K->400K(19712K)] 
>> 17320K->412K(62720K), 0.0586610 secs] [Times: user=0.04 sys=0.03, 
>> real=0.06 secs]
>> VerifyBeforeGC:5.439: [GC [PSYoungGen: 17296K->432K(36608K)] 
>> 17308K->448K(79616K), 0.0167533 secs] [Times: user=0.02 sys=0.00, 
>> real=0.02 secs]
>> VerifyBeforeGC:5.721: [GC [PSYoungGen: 34224K->392K(38144K)] 
>> 34240K->412K(81152K), 0.0909802 secs] [Times: user=0.05 sys=0.04, 
>> real=0.09 secs]
>> VerifyBeforeGC:6.034: [GC [PSYoungGen: 35720K->400K(69184K)] 
>> 35740K->424K(112192K), 0.0344226 secs] [Times: user=0.04 sys=0.00, 
>> real=0.03 secs]
>> VerifyBeforeGC:6.709: [GC [PSYoungGen: 69136K->64K(69184K)] 
>> 69160K->440K(112192K), 0.1976060 secs] [Times: user=0.10 sys=0.11, 
>> real=0.20 secs]
>>
>> Previously it was:
>>
>> [Verifying threads syms strs zone dict hand C-heap code cache ]
>> VerifyBeforeGC:[Verifying threads permanent tenured eden syms strs 
>> zone dict hand C-heap code cache ]
>> 4.818: [GC [PSYoungGen: 16896K->392K(19712K)] 16896K->396K(62720K), 
>> 0.0244147 secs] [Times: user=0.02 sys=0.00, real=0.02 secs]
>> VerifyBeforeGC:[Verifying threads permanent tenured eden syms strs 
>> zone dict hand C-heap code cache ]
>> 5.087: [GC [PSYoungGen: 17288K->392K(19712K)] 17292K->400K(62720K), 
>> 0.0597174 secs] [Times: user=0.04 sys=0.03, real=0.06 secs]
>> VerifyBeforeGC:[Verifying threads permanent tenured eden syms strs 
>> zone dict hand C-heap code cache ]
>> 5.410: [GC [PSYoungGen: 17288K->400K(19712K)] 17296K->412K(62720K), 
>> 0.0173056 secs] [Times: user=0.02 sys=0.00, real=0.02 secs]
>> VerifyBeforeGC:[Verifying threads permanent tenured eden syms strs 
>> zone dict hand C-heap code cache ]
>> 5.595: [GC [PSYoungGen: 17296K->400K(36608K)] 17308K->416K(79616K), 
>> 0.0134239 secs] [Times: user=0.02 sys=0.00, real=0.01 secs]
>>
>> The changes restore the previous output for the affected collectors.
>>
>> Testing:
>> GCBasher with VerifyBeforeGC, VerifyAfterGC, VerifyDuringGC with 
>> serial, parallel, concurrent, and G1 collectors.
>>
>> Thanks,
>>
>> JohnC
>