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

[Stefan Karlsson]

Looks good.

StefanK

On 2017-08-28 22:37, sangheon.kim wrote:
> Hi all,
> 
> I had another round of chat with Stefan and here's updated webrev:
> 1. To use regex group when searching pattern in a log.
> 2. Improve readability.
>      - Remove colon from strings.
>      - Replace indent strings and add converting method for indent.
> 
> webrev:
> http://cr.openjdk.java.net/~sangheki/8186465/webrev.3
> http://cr.openjdk.java.net/~sangheki/8186465/webrev.3_to_2
> 
> Thanks,
> Sangheon
> 
> 
> On 08/24/2017 09:41 PM, sangheon.kim wrote:
>> 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
>>>>
>>>>
>>>
>>
>