RFR: 8142366: Add develop_debug and develop_trace levels to Unified Logging

Staffan Larsen staffan.larsen at oracle.com
Fri Nov 13 13:36:42 UTC 2015 

I think what you are saying is that you want an additional classifier on a log statement that says whether it is a product or develop statement. I’m seeing this as an additional dimension from log-level and log-tags. It’s not about adding more log-levels, it’s about adding a dimension on top of the levels. 

So today you can specify {level, tags} for a statement. If we add another dimension you would specify {level, tags, product/develop} (where “product” would probably be the default). 

There would then have to be ways to configure this dimension from the command-line and including that as a decorator in the outputs. 

Am I on the right track?

/Staffan

> On 13 nov. 2015, at 08:53, David Lindholm <david.lindholm at oracle.com> wrote:
> 
> Hi,
> 
> What I'd like to see is the same levels for develop as for product, like Marcus original suggestion 2. Maybe this is what you are also proposing, but to avoid confusion I would like to clarify:
> 
> log_debug() will log to debug for all kind of builds.
> log_trace() will log to trace for all kind of builds.
> ... and so on.
> 
> log_debug_develop() will log to debug in develop builds and be silent in product builds.
> log_trace_develop() will log to trace in develop builds and be silent in product builds.
> ... and so on.
> 
> So this would be like having #ifdefs in the code, but will look nicer.
> 
> The drawback of this (as someone said) is that we will get different printouts for develop and product builds. However, I don't see that as much of a problem, develop logging should only be interesting in develop builds anyway.
> 
> Thanks,
> David
> 
> On 2015-11-13 06:19, David Holmes wrote:
>> I have to agree with Coleen and Rachel that the existing "develop" level as a monolithic non-product log-level is inadequate. Non-product logging can still be coarse, fine (verbose) or really noisy (or expensive - WizardMode) depending on what you are doing.
>> 
>> So having a similar classification as for product builds make sense to me. I don't see why we would have product options defined one way, and non-product options defined a different way.
>> 
>> David
>> 
>> On 13/11/2015 5:18 AM, Coleen Phillimore wrote:
>>> 
>>> 
>>> On 11/12/15 2:07 PM, Staffan Larsen wrote:
>>>>> On 12 nov. 2015, at 19:36, Coleen Phillimore
>>>>> <coleen.phillimore at oracle.com> wrote:
>>>>> 
>>>>> 
>>>>> 
>>>>> On 11/12/15 3:34 AM, Bengt Rutisson wrote:
>>>>>> Hi Rachel and Coleen,
>>>>>> 
>>>>>> Thanks for providing more background on this.
>>>>>> 
>>>>>> Would it be possible to use tags to give users the control you want
>>>>>> to give them?
>>>>>> 
>>>>>> Let's say you introduce a "verbose" tag. Then you could do something
>>>>>> like:
>>>>>> 
>>>>>> log_develop(vtables)("Main logging for vtables");
>>>>>> log_develop(vtables, verbose)("Very detailed logging for vtables");
>>>>> I think adding a verbose tag would be a huge mistake.  We have
>>>>> -XX:+Verbose and -XX:+WizardMode.   Having to add these for
>>>>> additional levels of development logging is something that the new
>>>>> logging framework makes much cleaner.
>>>> I think the Bengt meant the name “verbose” as an example. It could be
>>>> called “extra_vtables”, “vtables_details", or (preferably) something
>>>> else that makes semantic sense given what data it will produce.
>>> 
>>> We are already adding a LOT of tags for runtime logging as the existing
>>> logging is distinct from each other.  I don't think we want more tags to
>>> encapsulate the idea of levels.  We just need levels, as proposed.
>>> 
>>> Coleen
>>>> 
>>>> /S
>>>> 
>>>>> Coleen
>>>>>> Thanks,
>>>>>> Bengt
>>>>>> 
>>>>>> On 2015-11-11 21:32, Coleen Phillimore wrote:
>>>>>>> I agree with what Rachel has written.   Many of the runtime
>>>>>>> debug/tracing flags are not appropriate for product level logging.
>>>>>>> Should they not be converted?    If we can't have multiple Develop
>>>>>>> levels for TraceItables and PrintVtables, we can't convert them to
>>>>>>> UL.    It would have been nice to remove all of these command line
>>>>>>> flags and use UL tags though.
>>>>>>> 
>>>>>>> Coleen
>>>>>>> 
>>>>>>> On 11/11/15 3:05 PM, Rachel Protacio wrote:
>>>>>>>> Hi,
>>>>>>>> 
>>>>>>>> Thanks for the feedback. I appreciate the justification behind
>>>>>>>> wanting a single develop level, but our desire for multiple levels
>>>>>>>> I think comes again from letting the user have fine control over
>>>>>>>> the amount of output. In particular, I am working on TraceItables
>>>>>>>> and PrintVtables, which contain code that (before the change) has
>>>>>>>> regular and verbose output. This would translate to "debug" and
>>>>>>>> "trace" levels in the product mode, but I don't think anyone will
>>>>>>>> argue that the hundreds of lines that print out about itables and
>>>>>>>> vtables need to be in the product. So if we move all the code to a
>>>>>>>> single develop level, the user loses the ability to distinguish
>>>>>>>> between some extra information and tons of extra information. I
>>>>>>>> think it would be wrong to rob them of this amount of control,
>>>>>>>> when the existing non-product implementation allows them to have
>>>>>>>> it. I don't think, though, that the non-product levels should be
>>>>>>>> in a separate system; I think it is right for them to aggregate
>>>>>>>> below the product levels. As you and Marcus pointed out, it would
>>>>>>>> be confusing to have non-product and product logging appear
>>>>>>>> together as if it were the same level. The develop logging is more
>>>>>>>> detailed, so it should still be below. I just think we need to
>>>>>>>> have multiple levels below - ones that do not need to take up
>>>>>>>> space in the product release but should still allow users to
>>>>>>>> control their verbosity.
>>>>>>>> 
>>>>>>>> Does that make sense?
>>>>>>>> 
>>>>>>>> Thanks,
>>>>>>>> Rachel
>>>>>>>> 
>>>>>>>> On 11/11/2015 2:25 PM, Bengt Rutisson wrote:
>>>>>>>>> Hi all,
>>>>>>>>> 
>>>>>>>>> I agree with Marcus here. Adding more levels below the Trace
>>>>>>>>> level seems odd.
>>>>>>>>> 
>>>>>>>>> I interpret Marcus' suggestion 2) as that there would be for
>>>>>>>>> example a log_develop_trace() macro that does nothing in product
>>>>>>>>> builds and that calls log_trace() in debug builds. Similarly for
>>>>>>>>> info and debug.
>>>>>>>>> 
>>>>>>>>> To me that seems like a reasonable approach. But I do see the
>>>>>>>>> problem that Marcus mentions. That it will be hard to distinguish
>>>>>>>>> develop logging from normal logging in the output.
>>>>>>>>> 
>>>>>>>>> So far it's been enough for me with the single Develop level. Can
>>>>>>>>> you give an example of a use case where the different develop
>>>>>>>>> levels are needed?
>>>>>>>>> 
>>>>>>>>> Thanks,
>>>>>>>>> Bengt
>>>>>>>>> 
>>>>>>>>> On 2015-11-11 15:01, Marcus Larsson wrote:
>>>>>>>>>> Hi,
>>>>>>>>>> 
>>>>>>>>>> I don't think this is the right approach for this problem.
>>>>>>>>>> 
>>>>>>>>>> These new develop levels are introduced as even finer levels
>>>>>>>>>> than the trace, but have names that somewhat say otherwise.
>>>>>>>>>> For example, develop_info is finer than trace, but it isn't
>>>>>>>>>> unreasonable to expect that develop_info actually shares
>>>>>>>>>> verbosity with the regular info level.
>>>>>>>>>> 
>>>>>>>>>> 
>>>>>>>>>> I see two ways to look at this:
>>>>>>>>>> 
>>>>>>>>>> 1) develop is a level, which is so verbose/expensive that it is
>>>>>>>>>> not possible to include it in the product (current implementation).
>>>>>>>>>> The following levels are used: error, warning, info, debug,
>>>>>>>>>> trace and develop. There is no concept of levels for the develop
>>>>>>>>>> only logging (it IS the level).
>>>>>>>>>> Selecting/distinguishing different logging on develop level is
>>>>>>>>>> done by using tags.
>>>>>>>>>> 
>>>>>>>>>> 2) There is no concept of a develop level, either the logging is
>>>>>>>>>> included in product or it isn't (compare to using #ifdefs around
>>>>>>>>>> the logging calls).
>>>>>>>>>> Development-only logging is orthogonal to the regular log
>>>>>>>>>> levels, i.e. some log_info calls should only be made in
>>>>>>>>>> non-product builds (log_develop_info),
>>>>>>>>>> but should still follow the regular log level system (as all
>>>>>>>>>> other logging does) and use the info level.
>>>>>>>>>> The following levels are used: error, warning, info, debug,
>>>>>>>>>> trace, and convenience macros are used to strip develop-logging
>>>>>>>>>> from non-product builds.
>>>>>>>>>> 
>>>>>>>>>> The downside of this approach is that it becomes harder to
>>>>>>>>>> distinguish what is logged only in non-product builds and what
>>>>>>>>>> is always logged.
>>>>>>>>>> Depending on if the build is non-product or not one can get
>>>>>>>>>> different output for "-Xlog".
>>>>>>>>>> 
>>>>>>>>>> 
>>>>>>>>>> The current proposal mixes these two approaches and adds develop
>>>>>>>>>> "levels" that are all finer than trace, which is confusing.
>>>>>>>>>> 
>>>>>>>>>> In my opinion, there should be no reason to require multiple
>>>>>>>>>> levels for non-product logging. I would assume all develop level
>>>>>>>>>> logging to be very specific, i.e. have a very specific tagset,
>>>>>>>>>> and require no support for selection/separation using log
>>>>>>>>>> levels. If it does, then I would argue for that the logging is
>>>>>>>>>> missing some classifying log tag that could be used instead of a
>>>>>>>>>> level.
>>>>>>>>>> The logging has already been classified as verbose/expensive,
>>>>>>>>>> why classify it further on a level scale?
>>>>>>>>>> 
>>>>>>>>>> Thanks,
>>>>>>>>>> Marcus
>>>>>>>>>> 
>>>>>>>>>> 
>>>>>>>>>> On 2015-11-11 00:13, Coleen Phillimore wrote:
>>>>>>>>>>> I think this looks good. I added serviceability-dev to the
>>>>>>>>>>> mailing list.
>>>>>>>>>>> 
>>>>>>>>>>> Coleen
>>>>>>>>>>> 
>>>>>>>>>>> On 11/10/15 2:18 PM, Rachel Protacio wrote:
>>>>>>>>>>>> Good point. I have changed Develop to DevelopInfo. I think
>>>>>>>>>>>> it's better to maintain the same levels of levels on the
>>>>>>>>>>>> develop side so that the logging can just shift laterally to
>>>>>>>>>>>> non-product, as it were.
>>>>>>>>>>>> 
>>>>>>>>>>>> And yes, they are specified as -Xlog:<tag>=develop_debug
>>>>>>>>>>>> 
>>>>>>>>>>>> Updated webrev: http://cr.openjdk.java.net/~rprotacio/8142366.01/
>>>>>>>>>>>> I re-tested with logging jtreg tests and
>>>>>>>>>>>> ExecuteInternalVMTests test, and for anyone who was curious
>>>>>>>>>>>> (namely Max who had the good idea for me to check), the debug
>>>>>>>>>>>> levels do correctly "nest" with more verbose ones printing out
>>>>>>>>>>>> the less verbose and product mode logging as well.
>>>>>>>>>>>> 
>>>>>>>>>>>> Thanks,
>>>>>>>>>>>> Rachel
>>>>>>>>>>>> 
>>>>>>>>>>>> On 11/9/2015 6:05 PM, Coleen Phillimore wrote:
>>>>>>>>>>>>> Hi Rachel,
>>>>>>>>>>>>> 
>>>>>>>>>>>>> I sort of thought DevelopDebug would replace plain Develop,
>>>>>>>>>>>>> and DevelopTrace would be additional lower level.   Maybe
>>>>>>>>>>>>> plain Develop should be DevelopInfo then?
>>>>>>>>>>>>> 
>>>>>>>>>>>>> Another question - how do you specify these levels? Is it
>>>>>>>>>>>>> -Xlog:itables=develop_debug ?
>>>>>>>>>>>>> 
>>>>>>>>>>>>> Thanks,
>>>>>>>>>>>>> Coleen
>>>>>>>>>>>>> 
>>>>>>>>>>>>> On 11/9/15 5:55 PM, Rachel Protacio wrote:
>>>>>>>>>>>>>> Hello,
>>>>>>>>>>>>>> 
>>>>>>>>>>>>>> Please see my small changeset to add two develop levels to UL.
>>>>>>>>>>>>>> 
>>>>>>>>>>>>>> Summary: This adds develop (that is, non-product) logging
>>>>>>>>>>>>>> levels to the Unified Logging framework in order to support
>>>>>>>>>>>>>> performance, footprint, and usefulness-of-output
>>>>>>>>>>>>>> considerations while maintaining the ability for the user to
>>>>>>>>>>>>>> specify levels of verbosity, i.e. default, "debug," and
>>>>>>>>>>>>>> "trace" levels.
>>>>>>>>>>>>>> Open webrev: http://cr.openjdk.java.net/~rprotacio/8142366/
>>>>>>>>>>>>>> Bug: https://bugs.openjdk.java.net/browse/JDK-8142366
>>>>>>>>>>>>>> 
>>>>>>>>>>>>>> I tested the added levels locally with sample log messages
>>>>>>>>>>>>>> to ensure proper functioning. When I convert future tags to
>>>>>>>>>>>>>> logging with these levels, those tags will have their own
>>>>>>>>>>>>>> tests and inherently exercise the added levels.
>>>>>>>>>>>>>> 
>>>>>>>>>>>>>> Thank you,
>>>>>>>>>>>>>> Rachel
>>> 
>>> 
>

More information about the hotspot-runtime-dev mailing list