RFR(S): 8210514: Obsolete SyncVerbose

[Daniel D. Daugherty]

On 9/7/18 6:16 PM, coleen.phillimore at oracle.com wrote:
>
>
> On 9/7/18 6:00 PM, Daniel D. Daugherty wrote:
>> On 9/7/18 5:41 PM, coleen.phillimore at oracle.com wrote:
>>>
>>> I think this looks good. I think as a future RFE we should add 
>>> logging judiciously to this code and not preserve the logging that's 
>>> already there.  The new logging for this code should look like the 
>>> log_debug() etc calls and not with this distracting TEVENT macro.
>>
>> Just to clarify:
>>
>> That "distracting TEVENT macro" has an atomic event counter that is
>> part of the logging output so that the person doing the debugging
>> knows the sequence of TEVENT calls. When dealing with multi-threaded
>> output, the system doesn't always issue the output in the same order
>> in which the various threads generate it...
>
> It doesn't use Atomic::add though,

True. However, knowing Dice, I suspect that all the memory sync
operations in the Java monitor code take care of that for most
if not all of the TEVENT macro calls.


> and this looks like it supresses output or only prints output if 
> there's a collision in the increment?
>
> - if ((v & (v - 1)) == 0) { \

All these years and I never noticed that line of code
might be wrong. Because 'v' is a local copy of 'ctr'
that value will never change so that statement will
always be true.

I have always thought that what Dice was trying to do
here was avoid a collision between two calls to TEVENT
so that line should be this:

     if ((ctr & (v - 1)) == 0) {

Although I wonder why not use:

     if (ctr == v) {

Makes me wonder if the code generated for the original
statement is somehow more efficient... Dunno...

> And if you want to have logging in these places like this, I think you 
> could use the thread id or have the counter.

I thought I saw some change go by where thread id was available
in UL logging output for "free". In any case, thread_id tells
you "who" posted the events and the counter tells you "order" of
the events. Those are both useful when debugging.


> And rename TEVENT to something like: LOG_EVENT.

I have no idea why Dice called it TEVENT.


> And decide if these are the places that provide useful information to 
> log.  I think these would be a useful RFE.

I suspect that a majority of the places where TEVENT calls are
made are significant to Dice's algorithm that's in his paper.
There are a few that appear to be "debugging" in nature.

Of course, now that I've thought about this more, I'm wondering
whether we can safely use UL calls in such a low-level sub-system
like the Java monitoring implementation functions. I don't know
how UL handles avoiding collisions between multiple threads, but
if there's a sync mechanism in UL it might not interact well with
this code...

Mikael, I think converting these TEVENT macros to UL might be
risky from an interactions POV so I'm going to withdraw my request
that you do that...

Dan


>
> thanks,
> Coleen
>
>>
>> Dan
>>
>>>
>>> Thanks,
>>> Coleen
>>>
>>> On 9/7/18 5:14 PM, Mikael Vidstedt wrote:
>>>> Please review this change which obsoletes the SyncVerbose flag.
>>>>
>>>> Bug: https://bugs.openjdk.java.net/browse/JDK-8210514 
>>>> <https://bugs.openjdk.java.net/browse/JDK-8210514>
>>>> Webrev: 
>>>> http://cr.openjdk.java.net/~mikael/webrevs/8210514/webrev.00/open/webrev/ 
>>>> <http://cr.openjdk.java.net/~mikael/webrevs/8210514/webrev.00/open/webrev/> 
>>>>
>>>>
>>>> * Background (from bug)
>>>>
>>>> The experimental SyncVerbose flag can in theory be used to produce 
>>>> logging of some synchronization primitives. The flag was convenient 
>>>> when the synchronization implementation was implemented and tuned a 
>>>> long time ago.
>>>>
>>>> The SyncVerbose flag no longer serves the purpose it used to, and 
>>>> is "Unstable" (the documentation of the flag says so explicitly). 
>>>> It should be obsoleted and later removed.
>>>>
>>>>
>>>> Testing: I’m running the normal tier1 testing (still in progress).
>>>>
>>>> Cheers,
>>>> Mikael
>>>>
>>>
>>
>