RFR: 8149064: Convert TraceProtectionDomainVerification to Unified Logging

[Max Ockner]

Another round of changes. In addition to completing the changes 
suggested by Coleen,  I have made the test case more thorough to test 
for the distinction between debug level and trace level output.

webrev: http://cr.openjdk.java.net/~mockner/protectiondomain.04/

More comments below.

Thanks,
Max

On 2/25/2016 6:22 PM, Coleen Phillimore wrote:
>
>
> On 2/25/16 4:56 PM, Max Ockner wrote:
>> Hello ,
>>
>> There do not seem to be too many opinions on this one, so I have just 
>> responded to Coleen's suggestions (comments inline).
>> Webrev: http://cr.openjdk.java.net/~mockner/protectiondomain.03/
>
> You missed changing the message:
>
> *!      _st_->print_cr("pd set = #%d", count);*
>
> to
>
> *!      _st_->print_cr("pd set = #%d", count);*
>

I originally didn't see the suggested change in this line ( I thought 
you were suggesting that the old output simply be the output of a new 
function named print_count). I have changed this to

*!      _st_->print_cr("pd set count = #%d", count);*


> You can shorten this to:
>
> *!    if (TraceProtectionDomainVerification) {*
> *!    if (_log_is_enabled(Debug, protectiondomain)_) {*
> *+     ResourceMark rm;*
> *+     outputStream* log = LogHandle(protectiondomain)::debug_stream();*
>        if (HAS_PENDING_EXCEPTION) {
> *!        tty->print_cr(" ->DENIED !!!!!!!!!!!!!!!!!!!!!");*
> *!        _log->print_cr("_DENIED !!!!!!!!!!!!!!!!!!!!!");*
>        } else {
> *!       tty->print_cr(" ->granted");*
> *!       _log->print_cr("_granted");*
>        }
> *       tty->cr();*
>      }
>
> to
>
>
>        if (HAS_PENDING_EXCEPTION) {
> *!        tty->print_cr(" ->DENIED !!!!!!!!!!!!!!!!!!!!!");*
> *!        _log__debug(protectiondomain)_("_DENIED !!!!!!!!!!!!!!!!!!!!!");*
>        } else {
> *!       tty->print_cr(" ->granted");*
> *!       __log_debug(protectiondomain)_("_granted");*
>        }
> *       tty->cr();*
>      }
Yes, now that the cr() is gone there is no need to explicitly call the 
log streams. Fantastic.
This has been fixed.

> http://cr.openjdk.java.net/~mockner/protectiondomain.03/test/runtime/logging/Hello.java.html 
> Needs a copyright. Do you still get the messages if Hello is an 
> internal class? Thanks, Coleen 

Yes. I have moved Hello into ProtectionDomainVerificationTest.java as an 
inner class.
>> Thanks, Max On 2/24/2016 10:57 AM, Coleen Phillimore wrote:
>>> On 2/22/16 6:04 PM, Coleen Phillimore wrote:
>>>> Hi Max, I think this looks fine.  A couple of comments though: 
>>>> http://cr.openjdk.java.net/~mockner/protectiondomain.02/src/share/vm/classfile/dictionary.hpp.udiff.html 
>>>> This is preexisting code, which is apparently giving the number of 
>>>> pd set.  Not sure what the use is, but could you rename the 
>>>> function print_count() and make the output *!_st_->print_cr("pd set 
>>>> count = #%d", count);* 
>> This has been fixed.
>>>> Maybe it wouldn't look so strange in the log. 
>>>> http://cr.openjdk.java.net/~mockner/protectiondomain.02/test/runtime/logging/ProtectionDomainVerificationTest.java.html 
>>>> The test looks like it's missing "Hello.java" but maybe you can use 
>>>> Empty.class from ClassLoadUnloadTest.java. 
>> Added Hello.java
>>>> http://cr.openjdk.java.net/~mockner/protectiondomain.02/src/share/vm/classfile/systemDictionary.cpp.udiff.html 
>>>> You're right, I have a vote for the format - it seems like a more 
>>>> compact log would be better: [0.138s][debug][protectiondomain]  - 
>>>> class loader: a 'sun/misc/Launcher$AppClassLoader' protection 
>>>> domain: a 'java/security/ProtectionDomain'  loading: 
>>>> 'java/lang/Object' -> granted 
>> These messages have been condensed to a single line.
>>> I should point out that I 've never used this logging for anything 
>>> so my opinion in favor of brevity can be easily countered if anyone 
>>> has a different opinion. Coleen
>>>> Or at least remove the blank line in the log. 
>> The blank line has been removed.
>>>> thanks, Coleen On 2/22/16 12:17 PM, Max Ockner wrote:
>>>>> Please review this conversion of TraceProtectionDomainverification 
>>>>> to Unified Logging. Theres some output that I think should be 
>>>>> changed, but I want to see what others think first. Bug: 
>>>>> https://bugs.openjdk.java.net/browse/JDK-8149064 Webrev: 
>>>>> http://cr.openjdk.java.net/~mockner/protectiondomain.02/ 
>>>>> TraceProtectionDomainVerification is a non-product flag, but the 
>>>>> output will now be available in product builds through 
>>>>> -Xlog:protectiondomain=debug.  - The output is concise. "-version" 
>>>>> produces no output, and "Hello.java" produces 27 lines (if 
>>>>> level=trace) or fewer. See below.  - This change doesn't rely on 
>>>>> "#ifndef PRODUCT" and is smaller than most logging changes that 
>>>>> we've seen so far.  - refworkload shows now significant 
>>>>> performance changes. Tested with jtreg hotspot tests and 
>>>>> refworkload. Here is sample output for a run of Hello.java: 
>>>>> [0.138s][debug][protectiondomain]  - class loader:      a 
>>>>> 'sun/misc/Launcher$AppClassLoader' 
>>>>> [0.138s][debug][protectiondomain]  - protection domain: a 
>>>>> 'java/security/ProtectionDomain' 
>>>>> [0.138s][debug][protectiondomain]  - loading: 'java/lang/Object' 
>>>>> [0.139s][debug][protectiondomain] -> granted 
>>>>> [0.139s][debug][protectiondomain] 
>>>>> [0.139s][trace][protectiondomain] pd set = #1 
>>>>> [0.139s][debug][protectiondomain] Checking package access 
>>>>> [0.139s][debug][protectiondomain]  - class loader:      a 
>>>>> 'sun/misc/Launcher$AppClassLoader' 
>>>>> [0.139s][debug][protectiondomain]  - protection domain: a 
>>>>> 'java/security/ProtectionDomain' 
>>>>> [0.139s][debug][protectiondomain]  - loading: 'java/lang/String' 
>>>>> [0.139s][debug][protectiondomain] -> granted 
>>>>> [0.139s][debug][protectiondomain] 
>>>>> [0.139s][trace][protectiondomain] pd set = #1 
>>>>> [0.139s][debug][protectiondomain] Checking package access 
>>>>> [0.139s][debug][protectiondomain]  - class loader:      a 
>>>>> 'sun/misc/Launcher$AppClassLoader' 
>>>>> [0.139s][debug][protectiondomain]  - protection domain: a 
>>>>> 'java/security/ProtectionDomain' 
>>>>> [0.139s][debug][protectiondomain]  - loading: 'java/lang/System' 
>>>>> [0.139s][debug][protectiondomain] -> granted 
>>>>> [0.139s][debug][protectiondomain] 
>>>>> [0.139s][trace][protectiondomain] pd set = #1 
>>>>> [0.140s][debug][protectiondomain] Checking package access 
>>>>> [0.140s][debug][protectiondomain]  - class loader:      a 
>>>>> 'sun/misc/Launcher$AppClassLoader' 
>>>>> [0.140s][debug][protectiondomain]  - protection domain: a 
>>>>> 'java/security/ProtectionDomain' 
>>>>> [0.140s][debug][protectiondomain]  - loading: 
>>>>> 'java/io/PrintStream' [0.140s][debug][protectiondomain] -> granted 
>>>>> [0.140s][debug][protectiondomain] 
>>>>> [0.140s][trace][protectiondomain] pd set = #1 I am anticipating 
>>>>> several comments and suggestions, but I believe there are only 
>>>>> minor changes remaining. I would like to remove the empty space, 
>>>>> though I believe this was present in the 
>>>>> TraceProtectionDomainVerification output to make the output more 
>>>>> readable. I also anticipate that you may want me to remove the "-" 
>>>>> from in front of some of the lines.  Again, I would like input 
>>>>> since output seems like it was designed to look a certain way. 
>>>>> Thanks, Max