RFR(xs): 8186465: Each j.l.Reference elapsed time log is incorrect

[sangheon.kim]

Hi all,

Stefan gave me some comments so here's updated webrev.

* Changed list
1. 165     static final int M = 512 * 1024;
     : M -> SIZE
2. 117     double result = 
Double.parseDouble(match.substring(match.lastIndexOf(” “) + 1, 
match.length()));
     : to use regex group
3. 128     String indent_2 = ”  “;
     : move to static same as other indent_x
4. Enhanced comparison of double type to allow tolerance. (not part of 
Stefan's comment)
     : during local tests, I faced a test failure because of this case. 
Reference logs are 1 decimal place (x.xms) of double so enclosing phase 
can be smaller than sum of printed values.
  137   // e.g. Actual value:  SoftReference(5.55) = phase1(1.85) + 
phase2(1.85) + phase3(1.85)
  138   //      Log value:     SoftReference(5.6) = phase1(1.9) + 
phase2(1.9) + phase3(1.9)
  139   //      When checked:  5.6 < 5.7 (sum of phase1~3)

webrev:
http://cr.openjdk.java.net/~sangheki/8186465/webrev.2
http://cr.openjdk.java.net/~sangheki/8186465/webrev.2_to_1

Testing: JPRT and manual test including #4 case. Without the fix, this 
new test fails, of course.

Thanks,
Sangheon


On 08/23/2017 10:09 PM, sangheon.kim wrote:
> Hi Stefan,
>
> Thank you for the review!
>
> On 08/23/2017 02:08 PM, Stefan Karlsson wrote:
>> Hi Sangheon,
>>
>> On 2017-08-23 23:04, sangheon.kim wrote:
>>> Hi all,
>>>
>>> Could I have some reviews for this tiny fix?
>>> The problem is each j.l.References has wrong time log as related 
>>> function is using wrong variable.
>>> Actually it should be using '_ref_proc_time_ms' but accidentally 
>>> using '_par_phase_time_ms'. Setter is using correct one but getter 
>>> is referring wrong one.
>>>
>>> CR: https://bugs.openjdk.java.net/browse/JDK-8186465
>>> webrev: http://cr.openjdk.java.net/~sangheki/8186465/webrev.0/
>>> Testing: manually checked log values
>>
>> Looks good, but I think you should add a regression test for this. 
>> Maybe the test could at least verify that the sub-phases are not 
>> larger than the enclosing phase?
> Sure, done!
>
> Added a new sub-test in TestPrintReferences.java to see:
> 1. Reference Processing time >= Soft + Weak + Final + Phantom 
> Reference processing time
> 2. Each References >= phase 1(for Soft) + phase 2 + phase 3
>
> webrev: http://cr.openjdk.java.net/~sangheki/8186465/webrev.0/
> Testing: JPRT, manual test to see sub-phases are not larger than the 
> enclosing phase.
>
> FYI, from my local run:
> Reference Processing: 115.6ms > 115.5 + 0 + 0 + 0
>    SoftReference: 115.5ms > 115.4 (36.5 + 37.2 + 41.7)
>      Phase1: 36.5ms
>      Phase2: 37.2ms
>      Phase3: 41.7ms
>      Discovered: 459095
>      Cleared: 0
>    WeakReference: 0.0ms
>      Phase2: 0.0ms
>      Phase3: 0.0ms
>      Discovered: 0
>      Cleared: 0
>   FinalReference: 0.0ms
>      Phase2: 0.0ms
>      Phase3: 0.0ms
>      Discovered: 1
>      Cleared: 1
>    PhantomReference: 0.0ms
>      Phase2: 0.0ms
>      Phase3: 0.0ms
>      Discovered: 0
>      Cleared: 0
>
> Thanks,
> Sangheon
>
>
>>
>> Thanks,
>> StefanK
>>
>>>
>>> Thanks,
>>> Sangheon
>>
>>
>