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

Thu Nov 12 18:36:36 UTC 2015


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.

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