RFR: 8020875 java/lang/management/ThreadMXBean/ResetPeakThreadCount.java fails intermittently

[Mandy Chung]

On 7/23/2013 5:54 PM, David Holmes wrote:
> On 23/07/2013 7:53 PM, Daniel Fuchs wrote:
>> On 7/23/13 11:45 AM, David Holmes wrote:
>>> On 23/07/2013 7:24 PM, Jaroslav Bachorik wrote:
>>>  > The result is that the offender is j.u.l.LogManager$Cleaner 
>>> thread. I
>>>  > am attaching the profiler snapshot (can be opened in eg. jvisualvm)
>>>
>>> That doesn't quite make sense. The Cleaner thread is a shutdownhook, it
>>> should not be starting unless the VM is shutting down!
>>
>> Hummm... Right: the javadoc says "Returns the peak live thread count
>> since the Java virtual machine started or peak was reset." so the
>> Cleaner thread should not be counted.
>
> Not sure why you say that. It is a live Java thread - if you happen to 
> query the MXBean during VM shutdown then it should be in the count.
>

I am catching up on this thread....

The thread count counts Java threads that are not hidden.  I believe all 
VM internal threads are hidden from external API.   This test runs in 
othervm mode and AFAICT the thread count is expected to be 
deterministic.  I don't expect the VM will start and terminate any 
thread any time.

I agree with David that we should diagnose why there is one additional 
thread started before the reset.  If it is the LogManager$Cleaner 
thread, like David said, the VM is shutting down while the test is still 
running which doesn't quite make sense.

Mandy

>> If it is actually counted it might indicate a real problem in the
>> implementation of the ThreadMXBean.
>
> My point is: why is the VM apparently shutting down while this test is 
> running???
>
> David
>
>> -- daniel.
>>
>>
>>>
>>> David
>>> -----
>>>
>>>> On Tue 23 Jul 2013 11:19:13 AM CEST, David Holmes wrote:
>>>>> On 23/07/2013 6:29 PM, Jaroslav Bachorik wrote:
>>>>>> On 07/23/2013 10:19 AM, David Holmes wrote:
>>>>>>> Hi Jaroslav,
>>>>>>>
>>>>>>> On 22/07/2013 9:55 PM, Jaroslav Bachorik wrote:
>>>>>>>> The java/lang/management/ThreadMXBean/ResetPeakThreadCount.java 
>>>>>>>> test
>>>>>>>> seems to be failing intermittently.
>>>>>>>>
>>>>>>>> The test checks the functionality of the
>>>>>>>> j.l.m.ThreadMXBean.resetPeakThreadCount() method. It does so by
>>>>>>>> capturing the current value of "getPeakThreadCount()", starting a
>>>>>>>> predefined number of the user threads, stopping them and resetting
>>>>>>>> the
>>>>>>>> stored peak value and making sure the new peak equals to the
>>>>>>>> number of
>>>>>>>> the actually running threads.
>>>>>>>>
>>>>>>>> The main problem is that it is not possible to prevent JVM to
>>>>>>>> start/stop
>>>>>>>> arbitrary system threads while executing the test. This might
>>>>>>>> lead to
>>>>>>>> small variations of the reported peak (a short-lived system
>>>>>>>> thread is
>>>>>>>> started while the batch of the user threads is running) or the
>>>>>>>> expected
>>>>>>>> number of running threads (again, a short-lived system thread is
>>>>>>>> started
>>>>>>>> at the moment the test asks for the number of running threads).
>>>>>>>
>>>>>>> Do you know what "system threads" these are? I would not expect VM
>>>>>>> internal threads to be counted in getPeakThreadCount(), but even if
>>>>>>> they
>>>>>>> are I can't think of any short-lived threads that get created other
>>>>>>> than
>>>>>>> the Signal handling thread.
>>>>>>
>>>>>> Unfortunatelly I don't. Capturing the thread dump at the moment of
>>>>>> discovering the discrepancy seems to to be too late. I tried
>>>>>> monitoring
>>>>>> the JVM under the test from external tools but it just brings more
>>>>>> entropy to the result.
>>>>>
>>>>> We'd need to instrument the thread creation logic to keep a separate
>>>>> record. Dtrace probes could probably do it - but the problem is
>>>>> getting the test to fail.
>>>>
>>>> Well, while responding to the previous email I thought about yet
>>>> another way to try to pinpoint the mysterious thread - I've tried NB
>>>> profiler. It filters out it's own threads and can do thread monitoring
>>>> at the same time as tracking the call tree.
>>>>
>>>> The result is that the offender is j.u.l.LogManager$Cleaner thread. I
>>>> am attaching the profiler snapshot (can be opened in eg. jvisualvm)
>>>>
>>>>>
>>>>>> I am completely relying on the JVM native thread accounting to be
>>>>>> correct and accurate - that it reports the thread count peak 
>>>>>> based on
>>>>>> the real data.
>>>>>
>>>>> The spec isn't clear but I would only expect these counters to apply
>>>>> to Java threads not VM internal threads (compiler, gc etc). So I'd
>>>>> really like to know what thread is messing up this count.
>>>>
>>>> I hope my previous finding makes this clearer.
>>>>
>>>> -JB-
>>>>
>>>>>
>>>>> David
>>>>>
>>>>>> -JB-
>>>>>>
>>>>>>>
>>>>>>>> The patch does not fix those shortcomings as it is not really
>>>>>>>> possible
>>>>>>>> to do given the nature of the JVM threading system. It rather
>>>>>>>> tries to
>>>>>>>> relax the conditions while still maintaining the ability to detect
>>>>>>>> functional problems - eg. decreasing peak without explicitly
>>>>>>>> resetting
>>>>>>>> it and reporting false number of threads.
>>>>>>>>
>>>>>>>> The webrev is at:
>>>>>>>> http://cr.openjdk.java.net/~jbachorik/8020875/webrev.00
>>>>>>>
>>>>>>> Seems reasonable.
>>>>>>>
>>>>>>> David
>>>>>>> -----
>>>>>>>
>>>>>>>> Thanks,
>>>>>>>>
>>>>>>>> -JB-
>>>>>>>>
>>>>>>
>>>>
>>