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

[Lois Foltan]

> 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

Thanks,
Lois

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