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

[David Holmes]

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