RFR (M) JDK-8210012: Implement Unified Logging Option for -XX:+TraceMethodHandles and -XX:+TraceInvokeDynamic

[Lois Foltan]

On 4/10/2020 10:57 PM, David Holmes wrote:
> Hi Lois,
>
> On 11/04/2020 7:55 am, Lois Foltan wrote:
>> On 4/9/2020 11:12 PM, David Holmes wrote:
>>> Hi Lois,
>>>
>>> On 10/04/2020 4:42 am, Lois Foltan wrote:
>>>> Please review the following change to implement unified logging 
>>>> options for -XX:+TraceMethodHandles and -XX:+TraceInvokeDynamic. 
>>>> The new options map as follows:
>>>>
>>>> -XX:+TraceMethodHandles --> -Xlog:methodhandles=info
>>>> -XX:+TraceInvokeDynamic --> -Xlog:methodhandles+indy=debug
>>>>
>>>> and in addition dynamic constants can now be viewed under their own 
>>>> option via -Xlog:methodhandles+condy=debug
>>>>
>>>> open webrev at: 
>>>> http://cr.openjdk.java.net/~lfoltan/bug_jdk8210012.0/webrev/
>>>> bug link: https://bugs.openjdk.java.net/browse/JDK-8210012
>>>
>>> Generally looks good. A couple of things.
>>
>> Thanks David for the review!
>>
>>>
>>> First the change in compileTask.cpp seems wrong: you should get the 
>>> timestamp from the specified stream not the tty.
>>
>> At first it looked wrong to me as well, but I was receiving an assert 
>> about the TimeStamp associated with the outputStream being cleared, 
>> (the first assert in TimeStamp::milliseconds). After investigation it 
>> turns out that CompileTask::print_impl() has never been called with 
>> any outputStream other than tty.  And 3-or 4 levels up when I call it 
>> with a LogStream (which inherits from outputStream and constructs 
>> with a default ctor that does not set a time stamp), it seems odd at 
>> that point that I have to determine a timestamp, one that does not 
>> seem relevant to CompileTask.  What I believe CompileTask wants, and 
>> what it seems other calls in the compiler directory use is the time 
>> since the vm was started.  See the support for PrintCompilation in 
>> compiler/compileBroker.cpp for the use of tty->timestamp() vs. 
>> CompileBroker's _time* timestamps.  Thus I think my change to use tty 
>> in CompileTask::print_impl() is correct.
>
> So we have an outputStream API for timestamps, but in practice it is 
> enabled on a per-instance basis (only the tty?) and we have whole 
> subclasses (stringStream, LogStream) that don't support it. Yet we 
> have code that claims to generically operate on any outputstream but 
> calls timestamp() which may assert if not called on a supporting 
> instance! What a mess. :(
>
> We also have two notions of "uptime" in the VM:
> - one is the timestamp held within the tty
> - the other is os::elapsedTime()  (which is used by UL)
>
> Probably some scope for some cleanup here ... like get rid of 
> timestamp from the tty/outputStream as it is barely used and used 
> incorrectly in a couple of places. Further, it's main use was 
> consistency across all the logging output to the tty, but now very 
> little is logged to the tty so we have inconsistencies across 
> different log output anyway.
>
> But not for this RFE.

Exactly and when I stated that my use of tty is correct, I meant correct 
for this current situation but hopefully not long term.

>
>>>
>>> Second the changes to wrap_dynamic_exception seem rather awkward, 
>>> both in terms of having to remember what the initial boolean arg 
>>> represents at the call site, and more so in the logic to determine 
>>> which log stream to use. I was wondering if it might be better to 
>>> add wrap_dynamic_exception_for_indy to keep the call sites clean? 
>>> Otherwise perhaps document like "true /* indy */" and "false /* not 
>>> indy */.
>>
>> I would rather not break wrap_dynamic_exception into 2 methods since 
>> this is a JVMS behavior to wrap certain exceptions into a 
>> BootstrapMethodError for both indy and condy.  So I have instead 
>> opted for your suggestion of using comments when calling 
>> wrap_dynamic_exception.
>>
>> New webrev at: 
>> http://cr.openjdk.java.net/~lfoltan/bug_jdk8210012.1/webrev/index.html
>
> Updates look fine.

Thanks again for the review!
Lois

>
> Thanks,
> David
>
>> Thanks,
>> Lois
>>
>>>
>>> For the log stream logic I was assuming there must be a 
>>> better/simpler way, but after looking at it in some detail it seems 
>>> not. :(
>>>
>>> Thanks,
>>> David
>>>
>>>> Testing: hs-tier1-5
>>>>
>>>> Thanks,
>>>> Lois
>>