RFR (S): 8237857: LogDecorations::uptimenanos is implemented incorrectly

[David Holmes]

Thanks for the review Dan!

I updated one of my comments in the bug report to explicitly list the fix.

David

On 30/01/2020 4:29 am, Daniel D. Daugherty wrote:
> On 1/29/20 12:13 AM, David Holmes wrote:
>> Bug: https://bugs.openjdk.java.net/browse/JDK-8237857
>> Webrev: http://cr.openjdk.java.net/~dholmes/8237857/webrev/
> 
> src/hotspot/share/logging/logConfiguration.cpp
>      No comments.
> 
> src/hotspot/share/logging/logDecorations.hpp
>      No comments.
> 
> src/hotspot/share/logging/logDecorations.cpp
>      I was trying to figure out where you were going with this fix
>      and now I see. It would be good if you mentioned in the bug
>      report why you are using os::elapsedTime(). Perhaps even
>      mention your elapsed_time() helper
> 
> test/hotspot/gtest/logging/test_logDecorations.cpp
>      Thanks for adding this comment:
> 
>      L117:       // The sleep needs to be longer than the timer 
> resolution to ensure
>      L118:       // we see updates to 'timemillis'. Windows has the 
> lowest resolution
>      L119:       // at 15-16ms, so we use 20.
> 
> Thumbs up.
> 
> Dan
> 
> 
>>
>> After my changes in JDK-8235741 which changed uptimemillis to be the 
>> same as uptimenanos*1000000 the gtest for the logging time decorators 
>> started to fail intermittently on Windows where the uptimemillis 
>> values was not advancing sometimes after a 5ms sleep. It turned out 
>> this was actually a day one bug in the logging code that my change had 
>> exposed - the code uptimenanos was using os::elapsed_counter() but 
>> that isn't a time value it's just a counter value. On Linux/AIX/BSD it 
>> happens to count at 1ns resolution but not so on Solaris and in 
>> particular not so on Windows. When this counter value was truncated to 
>> "millis" there was no guarantee the value would increase as expected 
>> by the test.
>>
>> Changes:
>> - use os::elapsedTimer() not os::elapsed_counter() for uptimemillis 
>> and uptimenanos
>> - remove dead code that should have been removed in JDK-8235741
>> - update the test by:
>>   - adding diagnostic printouts of the time values read
>>   - fix a bug where the sleep time can be too short for Windows (see 
>> details in bug report)
>>
>> Testing:
>>   - gtests on all platforms with manual analysis of log files
>>
>> Thanks,
>> David
>> -----
>