RFR: 8142506: Reimplement TraceClassUnloading with Unified Logging.

[Coleen Phillimore]

For classload and classunload we should use levels info and debug.

The info level was chosen for classload because it's good general 
information (ie we're not really debugging anything by seeing which 
classes are loaded), and it was a product flag so wasn't originally 
intended for developer debugging.

I think that was in our initial proposal.  I think classunload should be 
the same.  Max's change for classinit also starts at the 'info' level.

Coleen

On 11/30/15 5:46 AM, Ioi Lam wrote:
> On 11/13/15 7:31 AM, Staffan Larsen wrote:
>>> On 13 nov. 2015, at 14:57, David Holmes <david.holmes at oracle.com> 
>>> wrote:
>>>
>>> On 13/11/2015 11:42 PM, Max Ockner wrote:
>>>> David,
>>>>
>>>> We chose Trace* and Print* options to convert to Unified Logging 
>>>> because
>>>> those options do most of the logging.  Trace level logging is 
>>>> basically
>>>> the new WizardMode/Verbose. Flags that could once be called either 
>>>> alone
>>>> or with WizardMode can now be logged with different levels. For 
>>>> example,
>>>>
>>>> "-XX:+TraceClassUnloading" will hit code guarded by "if
>>>> (TraceClassUnloading)", but not "if (TraceClassUnloading &&
>>>> WizardMode)". To see logging contained in the WizardMode statement, 
>>>> you
>>>> must specify WizardMode as well.  When This all gets converted to
>>>> Unified Logging,  logging that was once guarded by "if
>>>> (TraceClassUnloading)" will now be accessible with
>>>> "-Xlog:classunload=debug", and logging that was guarded by "if
>>>> (TraceClassUnloading && WizardMode)" will be accessible through
>>>> "-Xlog:classunload=trace".
>>> It is that mapping that I am questioning: why should it not be 
>>> classunload=info as it is the initial level of logging.
>> +1: classunload=info seems the more natural mapping for UL.
>
> Currently, my "classload" patch and Max's "classunload" patch use 
> these levels"
>
> [some output] = debug
> [more output] = trace
>
> Are you saying we should use the following instead?
>
> [some output] = info
> [more output] = debug
>
> Thanks
> - Ioi
>
>>
>>>> For this particular case, I could also imagine using the Info level 
>>>> for
>>>> the majority of the logging to make it accessible with
>>>> "-Xlog:classunload", and if we wanted to keep the WizardMode output 
>>>> out
>>>> of product, we could either (1) use #ifndef PRODUCT or (2) change to
>>>> develop level for those outputs. However, I don't see a problem with
>>>> allowing the WizardMode output in product builds.  This output is
>>>> currently blocked from product builds by WizardMode, which is a 
>>>> product
>>>> only flag. There are no #ifdefs that we'd have to remove, so I don't
>>>> expect any kind of performance or size issues with this change.
>>> Including non-product code in a product build will affect both size 
>>> and performance, though to what exact extent we can't say a-priori. 
>>> A develop flag in a product build is a constant and so code guarded 
>>> by eg WizardMode can be elided in a product build.
>>>
>>> Cheers,
>>> David
>>>
>>>> Thanks,
>>>> Max
>>>>
>>>> On 11/13/2015 12:31 AM, David Holmes wrote:
>>>>> Hi Max,
>>>>>
>>>>> I have not looked at the code :) This is more a meta-commentary on 
>>>>> the
>>>>> general approach to conversion ...
>>>>>
>>>>> On 12/11/2015 6:23 AM, Max Ockner wrote:
>>>>>> Hello,
>>>>>> Please review my change.
>>>>>>
>>>>>> Bug:  https://bugs.openjdk.java.net/browse/JDK-8142506
>>>>>> Webrev: http://cr.openjdk.java.net/~mockner/classunload/
>>>>>>
>>>>>> Testing:
>>>>>> Hotspot jtreg tests with and without "-Xlog:classunload=trace"
>>>>>> runthese tests with "-Xlog:classunload=trace"
>>>>>> new jtreg test for classunload output.
>>>>>>
>>>>>> Summary:
>>>>>>
>>>>>> There are two parts to this fix.
>>>>>>
>>>>>> (1) Existing logic for TraceClassUnloading has been replaced with
>>>>>> commands from Unified Logging.
>>>>>>
>>>>>> (2) Logging Alias Table. "-XX:+TraceClassUnloading" is now mapped to
>>>>>> "-Xlog:classunload=debug" in the new logging alias table in
>>>>>> arguments.cpp. Arguments are checked in the beginning of
>>>>>> parse_each_vm_init_arg and if an argument (such as
>>>>>> -XX:+TraceClassUnloading") is found in the alias table, the 
>>>>>> optionString
>>>>>> is substituted for the value found in the logging alias table.
>>>>>>
>>>>>> I had to make a few decisions along that might raise questions, so I
>>>>>> will knock a few of them out now.
>>>>>>
>>>>>> Why didn't I use the existing alias table?
>>>>>> - Existing alias table only stores the flag name 
>>>>>> (TraceClassUnloading)
>>>>>> and is meant for substituting one "-XX:" argument for another. 
>>>>>> This does
>>>>>> not solve our problem.
>>>>>>
>>>>>> Why didn't I process the logging aliases later in
>>>>>> parse_each_vm_init_arg, next to the rest of the "-XX:" argument
>>>>>> processing?
>>>>>> - The main processing for "-XX:" options happens after processing of
>>>>>> "-Xlog" options. If we want the unified logging alias to be 
>>>>>> handled, it
>>>>>> needs to be substituted in before "-Xlog:" is handled.
>>>>>>
>>>>>> Why does "-XX:+TraceClassUnloading" get aliased to
>>>>>> "-Xlog:classunload=debug" and not "-Xlog:classunload=trace"?
>>>>>> - logging statements that contained the develop-only flag 
>>>>>> "WizardMode"
>>>>>> were converted to "-Xlog:classunload=trace". The logging 
>>>>>> statements that
>>>>> I'm again having trouble reconciling the conversion of non-product
>>>>> logging into product logging. Really not sure it is desirable or 
>>>>> useful.
>>>>>
>>>>> More generally although most of our "tracing" flags start with Trace
>>>>> (some start with Print), that should be read simply as "log" or
>>>>> "report" in my opinion. So in the sense that the UL framework 
>>>>> defines:
>>>>> info, debug, trace; it is certainly not the case that our "trace"
>>>>> flags should automatically map to a "trace" log level in the first
>>>>> instance. For something like classloading/unloading I would still
>>>>> expect to see basic information at the info level, more detailed info
>>>>> at the debug level, and so forth. So why are we not doing the basic
>>>>> class-unloading logging at the info level?
>>>>>
>>>>> Thanks,
>>>>> David
>>>>>
>>>>>
>>>>>> could have been previously been triggered in Product mode are all 
>>>>>> now
>>>>>> accessed by "-Xlog:classunload=debug". (We are updating logging, 
>>>>>> but we
>>>>>> are not updating the functionality of the old logging options. Old
>>>>>> options such as TraceClassUnloading are being aliased so they may
>>>>>> continue to work in *exactly* the way they did before.)
>>>>>>
>>>>>> Thanks,
>>>>>> Max
>>>>>>
>