RFR(XS): 8202415: Incorrect time logged for monitor deflation

[Daniel D. Daugherty]

Coleen,

Thanks for the review!

On 11/27/18 12:03 PM, coleen.phillimore at oracle.com wrote:
>
> This looks good.  It looked initially like 'counters' are updated by 
> unsafely by multiple threads, but I see there is a lock:
>
> http://cr.openjdk.java.net/~dcubed/8202415-webrev/1_for_jdk_jdk.full/src/hotspot/share/runtime/synchronizer.cpp.udiff.html 
>
>
>    Thread::muxAcquire(&gListLock, "scavenge - return");  <= locked here.

Yes. That muxAquire() was added when the deflation of per-thread monitor
lists was made potentially multi-threaded by worker threads (ZGC only,
I think).

Dan

>
>    // Adjust counters
>    counters->nInCirculation += thread->omInUseCount;
>    thread->omInUseCount -= deflated_count;
>    counters->nScavenged += deflated_count;
>    counters->nInuse += thread->omInUseCount;
> + // For now, we only care about cumulative per-thread deflation time.
> + counters->perThreadTimes += timer.seconds();
>
>
> Coleen
>
>
> On 11/27/18 10:28 AM, Daniel D. Daugherty wrote:
>> Greetings,
>>
>> I re-reviewed my webrev and verified that the only line that I messed
>> up is the one that David spotted. Thanks for the catch!
>>
>> Full webrev against jdk/jdk:
>>
>> http://cr.openjdk.java.net/~dcubed/8202415-webrev/1_for_jdk_jdk.full/
>>
>> Incremental webrev:
>>
>> http://cr.openjdk.java.net/~dcubed/8202415-webrev/1_for_jdk_jdk.inc/
>>
>> Sanity check build and retest is in process.
>>
>> Thanks, in advance, for any comments, questions or suggestions.
>>
>> Dan
>>
>> On 11/27/18 9:16 AM, Daniel D. Daugherty wrote:
>>> Hi David,
>>>
>>> Thanks for the review!More below.
>>>
>>> On 11/26/18 11:04 PM, David Holmes wrote:
>>>> Hi Dan,
>>>>
>>>> On 27/11/2018 5:36 am, Daniel D. Daugherty wrote:
>>>>> Greetings,
>>>>>
>>>>> I have an extra small fix for the following bug:
>>>>>
>>>>>      JDK-8202415 Incorrect time logged for monitor deflation
>>>>>      https://bugs.openjdk.java.net/browse/JDK-8202415
>>>>>
>>>>> Here's the webrev URL:
>>>>>
>>>>> http://cr.openjdk.java.net/~dcubed/8202415-webrev/0_for_jdk_jdk/
>>>>
>>>> Why is it that you only track the time for
>>>>
>>>> log_is_enabled(Debug, monitorinflation)
>>>
>>> Ouch. That's a cut-n-paste error from when I manually extracted
>>> the patch out of my monitor deflation repo into the current
>>> jdk/jdk baseline repo.
>>>
>>> This line:
>>>
>>>     L1695:   if (log_is_enabled(Debug, monitorinflation)) {
>>>
>>> should be:
>>>
>>>     L1695:   if (log_is_enabled(Info, safepoint, cleanup)) {
>>>
>>> I must have grabbed from the wrong diff when I did that part.
>>>
>>>
>>>> but you only report the time under:
>>>>
>>>> log_info(safepoint, cleanup)
>>>>
>>>> ?? Unless you explicitly know to enable monitorinflation enabling 
>>>> the safepoint-cleanup logging will just report zero. I would have 
>>>> expected to see the deflation time recorded and printed for both 
>>>> log settings
>>>
>>> The intent for the new "deflating per-thread idle monitors" log mesg
>>> is to match the existing "deflating global idle monitors" log mesg.
>>> Both should be controlled by: log_is_enabled(Info, safepoint, cleanup)
>>>
>>>
>>>>
>>>> And under what conditions is the existing "global deflation" time 
>>>> reported?
>>>
>>> That's done by this piece of code:
>>>
>>>     src/hotspot/share/runtime/safepoint.cpp:
>>>     L621:       TraceTime timer(name, TRACETIME_LOG(Info, safepoint, 
>>> cleanup));
>>>
>>> That helper object includes a call to:
>>>
>>>     log_is_enabled(Info, safepoint, cleanup)
>>>
>>> along with built-in timer support.
>>>
>>>
>>>>
>>>>> The fix has been tested with a Mach5 builds-tier1,hs-tier1,jdk-tier1,
>>>>> hs-tier2,hs-tier3 job. The modified SafepointCleanupTest.java has
>>>>> been verified to pass in all Mach5 configs.
>>>>
>>>> But the test doesn't enable monitorinflation logging so doesn't 
>>>> actually verify the logging works.
>>>
>>> It does when the right check is in place. :-(
>>>
>>>
>>>>
>>>>> This bug is currently targeted at jdk13, but I think it is safe
>>>>> enough to be pushed to jdk12 if the reviewers agree.
>>>>
>>>> No problem with fixing in 12.
>>>
>>> Thanks.
>>>
>>> Dan
>>>
>>>>
>>>> Thanks,
>>>> David
>>>>
>>>>> Thanks, in advance, for any comments, questions or suggestions.
>>>>>
>>>>> Dan
>>>
>>>
>>
>