RFR: 8149383: Convert TraceBiasedLocking to Unified Logging

Daniel D. Daugherty daniel.daugherty at oracle.com
Tue Feb 16 21:16:33 UTC 2016


On 2/15/16 3:37 PM, Rachel Protacio wrote:
> Thanks for the review, David! I've fixed those issues. New webrev: 
> http://cr.openjdk.java.net/~rprotacio/8149383.01

src/share/vm/logging/logTag.hpp
     No comments.

src/share/vm/runtime/arguments.cpp
     No comments.

src/share/vm/runtime/biasedLocking.cpp
     (old) L165     tty->print_cr("Revoking bias of object " 
INTPTR_FORMAT " , mark " INTPTR_FORMAT " , type %s , prototype header " 
INTPTR_FORMAT " , allow rebias %d , requesting thread " INTPTR_FORMAT,
     (old) L166                   p2i((void *)obj), (intptr_t) mark, 
obj->klass()->external_name(), (intptr_t) 
obj->klass()->prototype_header(), (allow_rebias ? 1 : 0), (intptr_t) 
requesting_thread);

     (new)
  163   if (!is_bulk) {
  164     ResourceMark rm;
  165     log_info(biasedlocking)("Revoking bias of object " 
INTPTR_FORMAT " , mark "
  166                             INTPTR_FORMAT " , type %s , prototype 
header " INTPTR_FORMAT
  167                             " , allow rebias %d , requesting 
thread " INTPTR_FORMAT,
  168                             p2i((void *)obj),
  169                             (intptr_t) mark,
  170 obj->klass()->external_name(),
  171                             (intptr_t) 
obj->klass()->prototype_header(),
  172                             (allow_rebias ? 1 : 0),
  173                             (intptr_t) requesting_thread);
  174   } else {
  175     ResourceMark rm;
  176     log_trace(biasedlocking)("Revoking bias of object " 
INTPTR_FORMAT " , mark "
  177                              INTPTR_FORMAT " , type %s , prototype 
header " INTPTR_FORMAT
  178                              " , allow rebias %d , requesting 
thread " INTPTR_FORMAT,
  179                              p2i((void *)obj),
  180                              (intptr_t) mark,
  181 obj->klass()->external_name(),
  182                              (intptr_t) 
obj->klass()->prototype_header(),
  183                              (allow_rebias ? 1 : 0),
  184                              (intptr_t) requesting_thread);
  185   }
         Originally I missed the difference between "log_info" and
         "log_trace". So "log_trace" is taking the place of the
         Verbose option in this logging situation. Wow!

         I really don't like the duplication, but if I remember correctly
         these are macros so we really can't do something like function
         pointers or some other trick here. Ouch! This duplication pattern
         is repeated in several places where the old logging was conditional
         on two different option variables and a biased locking operational
         state variable (is_bulk).

         I suppose the logging framework doesn't have an API that says
         to log at different levels based on a parameter. Something like:

         log_info_or_trace(log_to /* true logs at 'info' level and
                                     false logs at 'trace' level */, ...);

         would do it, but it's an API nightmare. Sigh...

src/share/vm/runtime/globals.hpp
     No comments.

src/share/vm/runtime/thread.cpp
     No comments.

test/runtime/logging/BiasedLockingTest.java
     L75:             System.out.println("Bias test");
         nit: should be "Biased Locking test".

Thumbs up!


Dan


>
> Rachel
>
> On 2/15/2016 1:51 AM, David Holmes wrote:
>> Hi Rachel,
>>
>> On 13/02/2016 6:37 AM, Rachel Protacio wrote:
>>> Hello,
>>>
>>> Please review this change converting TraceBiasedLocking to UL, i.e.
>>> -Xlog:biasedlocking. *This* flag is product-level (sorry about the
>>> confusion on the last one!) so the existing option has been aliased to
>>> the logging tag.
>>>
>>> Bug: https://bugs.openjdk.java.net/browse/JDK-8149383
>>> Open webrev: http://cr.openjdk.java.net/~rprotacio/8149383/
>>>
>>> Passes JPRT and RBT quick and non-colo tests.
>>>
>>> Sample of previous output (with ellipses in place of many lines of
>>> "Aligned thread"):
>>>
>>>     $ java -XX:+TraceBiasedLocking -XX:BiasedLockingStartupDelay=0 
>>> -version
>>>     Aligned thread 0x00007fe9480192c0 to 0x00007fe948019800
>>>     Aligned thread 0x00007fe94803a850 to 0x00007fe94803b000
>>>     Aligned thread 0x00007fe94803c390 to 0x00007fe94803c800
>>>     ...
>>>     Aligned thread 0x00007fe948400180 to 0x00007fe948400800
>>>     Aligned thread 0x00007fe94840ef00 to 0x00007fe94840f000
>>>     Biased locking enabled
>>>     Aligned thread 0x00007fe948410a20 to 0x00007fe948411000
>>>     java version "9-internal"
>>>     Java(TM) SE Runtime Environment (fastdebug build
>>>     9-internal+0-2016-02-08-180545.rprotaci.clean)
>>>     Java HotSpot(TM) 64-Bit Server VM (fastdebug build
>>>     9-internal+0-2016-02-08-180545.rprotaci.clean, mixed mode)
>>>     Aligned thread 0x00007fe9480192c0 to 0x00007fe948019800
>>>
>>> Sample of new output (with ellipses in place of many lines of "Aligned
>>> thread"):
>>>
>>>     $ java -Xlog:biasedlocking -XX:BiasedLockingStartupDelay=0 -version
>>>     [0.026s][info][biasedlocking] Aligned thread 0x00007fa194019480 to
>>>     0x00007fa194019800
>>>     [0.056s][info][biasedlocking] Aligned thread 0x00007fa19403aa80 to
>>>     0x00007fa19403b000
>>>     [0.056s][info][biasedlocking] Aligned thread 0x00007fa19403c5c0 to
>>>     0x00007fa19403c800
>>>     ...
>>>     [0.362s][info][biasedlocking] Aligned thread 0x00007fa194400430 to
>>>     0x00007fa194400800
>>>     [0.367s][info][biasedlocking] Aligned thread 0x00007fa194417160 to
>>>     0x00007fa194417800
>>>     [0.383s][info][biasedlocking] Biased locking enabled
>>>     [0.384s][info][biasedlocking] Aligned thread 0x00007fa194418d60 to
>>>     0x00007fa194419000
>>>     java version "9-internal"
>>>     Java(TM) SE Runtime Environment (fastdebug build
>>>     9-internal+0-2016-02-09-124441.rprotaci.biasedlocking)
>>>     Java HotSpot(TM) 64-Bit Server VM (fastdebug build
>>>     9-internal+0-2016-02-09-124441.rprotaci.biasedlocking, mixed mode)
>>>     [0.389s][info][biasedlocking] Aligned thread 0x00007fa194019480 to
>>>     0x00007fa194019800
>>>
>>> A comment on the code: in order to maintain the existing functionality
>>> of the "(TraceBiasedLocking && (Verbose || !is_bulk))" portions of 
>>> code,
>>> it was necessary to create two separate cases in the conversion, one
>>> each for the info (regular) and trace (verbose) levels. It has been
>>> asked that the functionality be maintained. The logging statements in
>>> these chunks do not necessarily have to stay equal to each other in the
>>> future, which this would facilitate.
>>
>> You missed the ResourceMark when you did this split at line #163.
>>
>> Otherwise all seems accurate - the test needs the copyright line 
>> modified to use a single year.
>>
>> Thanks,
>> David
>>
>>
>>>
>>> Thank you,
>>> Rachel
>



More information about the hotspot-runtime-dev mailing list