RFR(S): 8221350 more monitor logging updates from Async Monitor Deflation project

[coleen.phillimore at oracle.com]

http://cr.openjdk.java.net/~dcubed/8221350-webrev/3-for-jdk13.more_monitor_logging/src/hotspot/share/runtime/synchronizer.cpp.frames.html

1750 LogStreamHandle(Debug, monitorinflation) lsh_debug;
1751 LogStreamHandle(Info, monitorinflation) lsh_info;
1752 LogStream * ls = NULL;
1753 if (log_is_enabled(Debug, monitorinflation)) {
1754 ls = &lsh_debug;
1755 } else if (deflated_count != 0 && log_is_enabled(Info, 
monitorinflation)) {
1756 ls = &lsh_info;
1757 }
1758 if (ls != NULL) {
1759 ls->print_cr("jt=" INTPTR_FORMAT ": deflating per-thread idle 
monitors, %3.7f secs, %d monitors", p2i(thread), timer.seconds(), 
deflated_count);
1760 }

This and the block above might be nicer as below, at risk of repeating 
the print string.

1755 if (deflated_count != 0) {
1759 log_info("jt=" INTPTR_FORMAT ": deflating per-thread idle monitors, 
%3.7f secs, %d monitors", p2i(thread), timer.seconds(), deflated_count);
1760 } else { 1759 log_debug("jt=" INTPTR_FORMAT ": deflating per-thread 
idle monitors, %3.7f secs, %d monitors", p2i(thread), timer.seconds(), 
deflated_count);
        }


You can decide if you want to change this or not, though.

Coleen


On 3/25/19 8:45 PM, Daniel D. Daugherty wrote:
> Thanks! Don't think this one qualifies as trivial so I'll
> wait for another reviewer...
>
> Dan
>
>
> On 3/25/19 6:30 PM, David Holmes wrote:
>> Hi Dan,
>>
>> Your tweak looks good.
>>
>> Thanks,
>> David
>>
>> On 26/03/2019 7:25 am, Daniel D. Daugherty wrote:
>>> On 3/24/19 10:02 PM, David Holmes wrote:
>>>> Hi Dan,
>>>>
>>>> On 23/03/2019 6:23 am, Daniel D. Daugherty wrote:
>>>>> Greetings,
>>>>>
>>>>> I have a (S)mall patch extracted from the Async Monitor Deflation 
>>>>> project
>>>>> that is ready for code review.
>>>>>
>>>>> The short version of what this patch is about:
>>>>>
>>>>>      More monitor logging updates.
>>>>>
>>>>> The details are in the bug report:
>>>>>
>>>>>      JDK-8221350  monitor logging updates from Async Monitor 
>>>>> Deflation project
>>>>> https://bugs.openjdk.java.net/browse/JDK-8221350
>>>>>
>>>>> Here's the webrev:
>>>>>
>>>>> http://cr.openjdk.java.net/~dcubed/8221350-webrev/3-for-jdk13.more_monitor_logging/ 
>>>>
>>>>
>>>>
>>>>
>>>>
>>>> This mostly seems okay.
>>>
>>> Thanks.
>>>
>>>
>>>> One comment on the timer changes in synchronizer.cpp. Why not just 
>>>> change this:
>>>>
>>>> 1711   timer.stop();
>>>> 1712
>>>> 1713   Thread::muxAcquire(&gListLock, 
>>>> "deflate_thread_local_monitors");
>>>> 1714
>>>> 1715   // Adjust counters
>>>> 1716   counters->nInCirculation += thread->omInUseCount;
>>>> 1717   thread->omInUseCount -= deflated_count;
>>>> 1718   counters->nScavenged += deflated_count;
>>>> 1719   counters->nInuse += thread->omInUseCount;
>>>> 1720   counters->perThreadScavenged += deflated_count;
>>>> 1721   // For now, we only care about cumulative per-thread 
>>>> deflation time.
>>>> 1722   counters->perThreadTimes += timer.seconds();
>>>>
>>>> to move the timer.stop() to after line 1720, rather than moving 
>>>> outside the mux-block and reacquiring the mux again?
>>>
>>> How about a slight tweak to that:
>>>
>>> We'll move the timer.stop() and the perThreadTimes to just
>>> before the muxRelease():
>>>
>>> Diff relative to the baseline:
>>>
>>> ***************
>>> *** 1708,1715 ****
>>>
>>>      int deflated_count = 
>>> deflate_monitor_list(thread->omInUseList_addr(), &freeHeadp, 
>>> &freeTailp);
>>>
>>> -   timer.stop();
>>> -
>>>      Thread::muxAcquire(&gListLock, "deflate_thread_local_monitors");
>>>
>>>      // Adjust counters
>>> --- 1717,1722 ----
>>> ***************
>>> *** 1718,1725 ****
>>>      counters->nScavenged += deflated_count;
>>>      counters->nInuse += thread->omInUseCount;
>>>      counters->perThreadScavenged += deflated_count;
>>> -   // For now, we only care about cumulative per-thread deflation 
>>> time.
>>> -   counters->perThreadTimes += timer.seconds();
>>>
>>>      // Move the scavenged monitors back to the global free list.
>>>      if (freeHeadp != NULL) {
>>> --- 1725,1730 ----
>>> ***************
>>> *** 1730,1736 ****
>>> --- 1735,1760 ----
>>>        freeTailp->FreeNext = gFreeList;
>>>        gFreeList = freeHeadp;
>>>      }
>>> +
>>> +   timer.stop();
>>> +   // Safepoint logging cares about cumulative perThreadTimes and
>>> +   // we'll capture most of the cost, but not the muxRelease() which
>>> +   // should be cheap.
>>> +   counters->perThreadTimes += timer.seconds();
>>> +
>>>      Thread::muxRelease(&gListLock);
>>>
>>>
>>> What do you think?
>>>
>>> Dan
>>>
>>>
>>>>
>>>> Thanks,
>>>> David
>>>> -----
>>>>
>>>>>
>>>>> This patch along with the current patch for Async Monitor Deflation
>>>>> project have been through Mach5 tier[1-8] testing.
>>>>>
>>>>> I have been actively using this new logging code while debugging and
>>>>> analyzing my port of the Async Monitor Deflation project code.
>>>>>
>>>>> Thanks, in advance, for any questions, comments or suggestions.
>>>>>
>>>>> Dan
>>>
>