RFR (S): JDK-8027428: Different conditions for printing taskqueue statistics for parallel gc, parNew and G1

[Jesper Wilhelmsson]

> 2 okt 2014 kl. 09:05 skrev Bengt Rutisson <bengt.rutisson at oracle.com>:
>
>
>> On 2014-10-02 09:06, Jesper Wilhelmsson wrote:
>>
>> Bengt Rutisson skrev 2/10/14 08:54:
>>>
>>>> On 2014-10-01 19:45, Sangheon Kim wrote:
>>>> Hi ,
>>>>
>>>>> On 10/01/2014 10:29 AM, Sangheon Kim wrote:
>>>>> Hi,
>>>>>
>>>>>>> On 10/01/2014 03:51 AM, Jesper Wilhelmsson wrote:
>>>>>>> Thomas Schatzl skrev 1/10/14 10:12:
>>>>>>> Hi,
>>>>>>>
>>>>>>>> On Tue, 2014-09-30 at 22:58 +0200, Jesper Wilhelmsson wrote:
>>>>>>>> Hi,
>>>>>>>>
>>>>>>>> Sangheon Kim skrev 30/9/14 19:41:
>>>>>>>>> Hi Bengt,
>>>>>>>>>
>>>>>>>>> Thank you for looking at this change.
>>>>>>>>>
>>>>>>>>>> On 09/30/2014 01:36 AM, Bengt Rutisson wrote:
>>>>>>>>>>
>>>>>>>>>> Hi Sangheon,
>>>>>>>>>>
>>>>>>>>>>> On 2014-09-30 01:30, Sangheon Kim wrote:
>>>>>>>>>>> Hi all,
>>>>>>>>>>>
>>>>>>>>>>> can I have reviews for the following small change to print taskqueue statistics
>>>>>>>>>>> for parallel gc, parNew and G1?
>>>>>>>>>>> Main changes are:
>>>>>>>>>>> 1) printing by 'ParallelGCVerbose' flag, not 'PrintGCDetails &&
>>>>>>>>>>> ParallelGCVerbose'.
>>>>>>>>>>> 2) printing logs via 'gclog_or_tty', not 'tty'.
>>>>>>>>>>> 3) adding 'totals' row to sums up.
>>>>>>>>>>>
>>>>>>>>>>> CR:
>>>>>>>>>>> https://bugs.openjdk.java.net/browse/JDK-8027428
>>>>>>>>>>>
>>>>>>>>>>> Webrev:
>>>>>>>>>>> http://cr.openjdk.java.net/~jwilhelm/8027428/
>>>>>>>
>>>>>>> [...]
>>>>>>>
>>>>>>>>>> But there is a lot of logging that has to do with parallel work (at least in
>>>>>>>>>> G1) that is not controlled by this flag. It seems to me that the flag actually
>>>>>>>>>> only controls the task queue statistics. Ideally we could change the name of
>>>>>>>>>> the flag, but that will be too much overhead I guess. But we can maybe updated
>>>>>>>>>> the description to indicate more what it actually controls.
>>>>>>>>> After applying this patch, I see this flag in 4 routines (3 files).
>>>>>>>>> And as all of them are stats for 'taskqueue' and 'termination', I changed the
>>>>>>>>> description as a statistics related flag.
>>>>>>>>> But if it's not enough, may I ask your opinion?
>>>>>>>>
>>>>>>>> I don't like that this flag controls some, but not all logging for parallel
>>>>>>>> Stuff. I think we should do one of the following:
>>>>>>>>
>>>>>>>> A. Use ParallelGCVerbose for all verbose logging related to parallel stuff in
>>>>>>>> all GCs, or
>>>>>>>>
>>>>>>>> B. Only use ParallelGCVerbose in ParallelGC.
>>>>>>>>
>>>>>>>> There aren't that many occurrences of the flag so at least B doesn't seem to be
>>>>>>>> too much work. A is trickier since it involves finding all verbose logging
>>>>>>>> related to parallel stuff.
>>>>>>>
>>>>>>> The question is, what how do we intend to print the task queue
>>>>>>> statistics then, consistently across all collectors? This seems to be
>>>>>>> the only purpose of ParallelGCVerbose right now.
>>>>>>> Sometimes (actually in very specific cases) this information is
>>>>>>> interesting.
>>>>>>>
>>>>>>> There could be an option C) that just adds a new experimental or
>>>>>>> diagnostic flag with a proper name that prints task queue statistics,
>>>>>>> and let ParallelGCVerbose do nothing and start retiring the flag.
>>>>>>>
>>>>>>> If the task queue statistics are not compiled in, ParallelGCVerbose
>>>>>>> prints nothing at all. So this would not be a change in behavior too.
>>>>>>
>>>>>> Thomas, you always have the best suggestions! :)
>>>>>> If task queue is all it verboses about today, can't we simply rename the flag to describe that? It would take a CCC, but I doubt that would meet any objections.
>>>>>> I vote for PrintTaskQueue to get it into the Print<Stuff> convention.
>>>>>> /Jesper
>>>>> I agree to Jesper's suggestion.
>>>>> If retiring ParallelGCVerbose is preferred, it would be better just renaming it.
>>>>> And a new one would be an experimental flag to print taskqueue stats.
>>>> Sorry for sending again.
>>>> I forgot that ParallelGCVerbose prints not only taskqueue stats but also termination stats(G1ParScanThreadState::print_termination_stats).
>>>> So the new flag name shouldn't be PrintTaskqueue.
>>>
>>> Flags names are always difficult. :)
>>>
>>>>
>>>> How about leave the flag name as is?
>>>> i.e. ParallelGCVerbose can be used widely and for now it will print two stats information.
>>>
>>> I still think we have lots of logging that concerns parallel work that we don't want to guard with ParallelGCVerbose.
>>>
>>> How about doing a first change that separates out the termination stat printing to be guarded by a separate flag (Maybe PrintTerminationStats) and then rename ParallelGCVerbose to PrintTaskqueue?
>>
>> Yes, I think this is good.
>>
>>>
>>> If we do that I think both new flags, PrintTerminationStats and PrintTaskqueue, should be diagnostic rather than experiemental.
>>
>> I'm curious, what is the rationale to make the flag diagnostic rather than product? We have had requests in the past to make more verbose information available in product. Is there any reason in particular to make the flags something else than product?
>
> Diagnostic options are available in product builds.
>
> Making it diagnostic is just an indication that it is a flag if for diagnosing the VM as opposed to tuning it. We don't use that in any strict way so I don't have strong opinions about it. I just figured that experimental does not seem to be the right category for these flags.

Agreed that experimental is not the right category.

My take on the product vs diagnostic is that since diagnostic flags require the 
additional XX:+UnlockDiagnosticVMOptions they should be used for stuff that is 
not supposed to be enabled per default in production systems. That could be 
logging that affects performance too much or other diagnostic stuff that is only 
enabled when debugging or testing a production system. Logging that is expected 
to be enabled by default out there should be product imho.

The risk when setting verbose flags that people are likely to use in production 
systems as diagnostic are that they start enabling UnlockDiagnosticVMOptions per 
default, and suddenly they are running with various really expensive logging and 
verification code enabled without realizing it affects performance.

I don't know if anyone out there is likely to use either flags discussed here 
per default in a running production system, but unless they are bad for 
performance I would prefer to have them be product flags and leave it to the 
user to decide.

/Jesper

>
> Bengt
>
>> /Jesper
>>
>>>
>>> Thanks,
>>> Bengt
>>>
>>>>
>>>> Thanks,
>>>> Sangheon
>>>>
>>>>>
>>>>> Thanks,
>>>>> Sangheon
>>>>>>
>>>>>>
>>>>>>>
>>>>>>> Thanks,
>>>>>>>  Thomas
>