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

[Ioi Lam]

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,


LinkResolver::lookup_polymorphic_method()
+  ResourceMark rm(THREAD);

Is this ResourceMark used only for logging?

=================
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");
     }

=================

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(.....);

=================
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()) {


=================
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(.....);
       });


Thanks
- Ioi


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