RFR: 8149383: Convert TraceBiasedLocking to Unified Logging

Rachel Protacio rachel.protacio at oracle.com
Wed Feb 17 15:10:43 UTC 2016


On 2/16/2016 4:16 PM, Daniel D. Daugherty wrote:
> 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...
Agreed. That would be awesome.
>
> 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".
Will fix.
>
> Thumbs up!
>
Thank you for the review, Dan!
Rachel
>
> 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