RFR: 8142506: Reimplement TraceClassUnloading with Unified Logging. (original) (raw)

Coleen Phillimore coleen.phillimore at oracle.com
Mon Nov 30 18:47:31 UTC 2015

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 parseeachvminitarg 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 parseeachvminitarg, 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

More information about the hotspot-runtime-dev mailing list