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

[Ioi Lam]

On 4/10/20 3:05 PM, Lois Foltan wrote:
>
>> On 4/9/20 8: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.
>>>
>>> First the change in compileTask.cpp seems wrong: you should get the 
>>> timestamp from the specified stream not the tty.
>>>
>>> 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 */.
>>>
>>> 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. :(
>>>
>>
>> Hi Lois,
>
> Hi Ioi,
>
> Thanks for the review!
>
>>
>>
>> LinkResolver::lookup_polymorphic_method()
>> +  ResourceMark rm(THREAD);
>>
>> Is this ResourceMark used only for logging?
>
> Yes.  As a matter of fact specifying -XX:+TraceMethodHandles or 
> -XX:+TraceInvokeDynamic currently on my sample test case results today 
> in crashes concerning the lack of allocating without a ResourceMark.
>
>>
>> =================
>> For code like this in ConstantPool::resolve_constant_at_impl:
>>
>>     if (log_is_enabled(Debug, methodhandles, condy)) {
>>       LogTarget(Debug, methodhandles, condy) lt;
>>       LogStream ls(lt);
>>       bootstrap_specifier.print_msg_on(&ls, "resolve_constant_at_impl");
>>     }
>>
>> The second set of tags can be avoided by declaring LogTarget(Debug, 
>> methodhandles, condy) first. There's an example of this style in 
>> FileMapInfo::log_paths().
>>
>>     LogTarget(Debug, methodhandles, condy) lt;
>>     if (lt.is_enabled()) {
>>       LogStream ls(lt);
>>       bootstrap_specifier.print_msg_on(&ls, "resolve_constant_at_impl");
>>     }
>
> Fixed, I have changed all checks in this webrev to consistently use 
> this form of checking if LogTarget is enabled.
>
>>
>> =================
>>
>> unpack_method_and_appendix() {
>>
>>       if (log_develop_is_enabled(Info, methodhandles)) {
>>         ResourceMark rm(THREAD);
>>         LogTarget(Info, methodhandles) lt;
>>         LogStream ls(lt);
>>         ls->print_on(.....);
>>
>> This can be fixed similarly, if we add a new function to LogTargetImpl:
>>
>>    class LogTargetImpl {
>>      static bool develop_is_enabled() {
>>        NOT_PRODUCT(return LogImpl<T0, T1, T2, T3, T4, 
>> GuardTag>::is_level(level));
>>        PRODUCT_ONLY(return false);
>>      }
>>      ...
>>    }
>>
>>       LogTarget(Info, methodhandles) lt;
>>       if (lt.develop_is_enabled()) {
>>         ResourceMark rm(THREAD);
>>         LogStream ls(lt);
>>         ls->print_on(.....);
>
> Fixed. Added the method "develop_is_enabled()" to class 
> LogTargetImpl.  However my method looks more like this:
>
> static bool develop_is_enabled() {
>   NOT_PRODUCT(return is_enabled();)
>   PRODUCT_ONLY(return false);
> }
>
>>
>> =================
>> void ConstantPoolCacheEntry::set_method_handle_common()
>>
>>   LogStreamHandle(Debug, methodhandles, indy) lsh;
>>   if (log_is_enabled(Debug, methodhandles, indy)) {
>>
>> Maybe we should add a new function LogStream::is_enabled so we can:
>>
>>   LogStreamHandle(Debug, methodhandles, indy) lsh;
>>   if (lsh.is_enabled()) {
>
> Fixed. Turns out that a LogTargetHandle already has an "is_enabled()" 
> method.  So I added an "is_enabled()" method to class LogStream to 
> check if its field, _log_handle, whose type is LogTargetHandle, is 
> enabled.
>
>>
>>
>> =================
>> Not a comment about this patch, but in general, I am not happy with 
>> the verbosity when a ResourceMark is needed in logging.
>>
>> I think the best way to avoid the verbosity would be to use C++ 
>> lambda expressions (are we allowed??), or (oh gosh!) maybe a macro? 
>> (Probably in a separate RFE).
>>
>>     LOG_WITH_RESOURCE_MARK((Info, methodhandles), THREAD,ls, {
>>         ls->print_on(.....);
>>       });
>
> Good idea, but will create an RFE for this.
>
> New webrev at: 
> http://cr.openjdk.java.net/~lfoltan/bug_jdk8210012.1/webrev/index.html
>

Hi Lois,

This new version looks good to me.

Thanks
- Ioi


> Thanks,
> Lois
>
>>
>>
>> Thanks
>> - Ioi
>>
>>
>>> Thanks,
>>> David
>>>
>>>> Testing: hs-tier1-5
>>>>
>>>> Thanks,
>>>> Lois
>>
>