RFR 8227528: TestAbortVMOnSafepointTimeout.java failed due to "RuntimeException: 'Safepoint sync time longer than' missing from stdout/stderr"

David Holmes david.holmes at oracle.com
Tue Jul 30 02:18:42 UTC 2019


On 30/07/2019 6:26 am, Patricio Chilano wrote:
> 
> On 7/29/19 11:46 AM, Doerr, Martin wrote:
>> Hi everybody, just an additional remark: The test failure indicates 
>> that guaranteed safepoints are kind of broken. Using VM Operations 
>> resets the timer even if they don't use a real safepoint. Should we 
>> document that somehow?
> Just to add to that, the AbortVMOnSafepointTimeout flag now only aborts 
> if once the VMThread starts a safepoint, the time to actually reach it 
> exceeds the SafepointTimeoutDelay limit. If the 
> GuaranteedSafepointInterval flag is supposed to guarantee safepoints 
> every X amount of time, which the name seems to suggest, then yes it's 
> broken.

It's supposed to guarantee a minimum interval to initiate a safepoint. 
It can't guarantee that a safepoint will actually be reached - as 
happens in this test.

> As of now GuaranteedSafepointInterval is used as a parameter to 
> know when to check for pending safepoints (needed for cleanup), but the 
> actual safepoint could happen way after GuaranteedSafepointInterval time 
> since the last one. So, possibly the flag name needs to be changed. 
> Maybe somebody could give more context on the 
> GuaranteedSafepointInterval flag.

With Handshakes now added to the mix, yes the actual safepoint could 
happen even later than previously.

The intent is that the VMThread will wakeup at least every 
GuaranteedSafepointInterval and initiate a safepoint using a "no_op" VM 
operation (see VMThread::no_op_safepoint()). The main usecase is to run 
periodic cleanup operations (many of which no longer occur at safepoints 
anyway). If the VMThread wakes earlier because of a requested 
VMoperation, and that VMOperation is not a safepoint-VMOp, then we could 
go much longer between safepoints, depending on the length of time that 
VM-op takes. But once we've executed a VM-op we re-examine 
VMThread::no_op_safepoint() and force a safepoint if needed.

So the interval is more "best effort" than "guaranteed".

David
-----

> 
> Patricio
>> Best regards,
>> Martin
>>
>>
>>> -----Original Message-----
>>> From: hotspot-runtime-dev <hotspot-runtime-dev-
>>> bounces at openjdk.java.net> On Behalf Of Doerr, Martin
>>> Sent: Montag, 29. Juli 2019 16:14
>>> To: David Holmes <david.holmes at oracle.com>;
>>> daniel.daugherty at oracle.com; Patricio Chilano
>>> <patricio.chilano.mateo at oracle.com>; hotspot-runtime-
>>> dev at openjdk.java.net runtime <hotspot-runtime-dev at openjdk.java.net>
>>> Subject: [CAUTION] RE: RFR 8227528: TestAbortVMOnSafepointTimeout.java
>>> failed due to "RuntimeException: 'Safepoint sync time longer than' 
>>> missing
>>> from stdout/stderr"
>>>
>>> Hi Patricio,
>>>
>>> I have also already noticed this issue. Thank you for analyzing the 
>>> root cause.
>>> Fix looks good to me. I don't need to see another webrev for comment
>>> improvements, either.
>>> I've linked the bug to JDK-8191890 and JDK-8219584.
>>>
>>> Best regards,
>>> Martin
>>>
>>>
>>>> -----Original Message-----
>>>> From: hotspot-runtime-dev <hotspot-runtime-dev-
>>>> bounces at openjdk.java.net> On Behalf Of David Holmes
>>>> Sent: Samstag, 27. Juli 2019 00:28
>>>> To: daniel.daugherty at oracle.com; Patricio Chilano
>>>> <patricio.chilano.mateo at oracle.com>; hotspot-runtime-
>>>> dev at openjdk.java.net runtime <hotspot-runtime-
>>> dev at openjdk.java.net>
>>>> Subject: Re: RFR 8227528: TestAbortVMOnSafepointTimeout.java failed
>>> due
>>>> to "RuntimeException: 'Safepoint sync time longer than' missing from
>>>> stdout/stderr"
>>>>
>>>> On 27/07/2019 5:19 am, Daniel D. Daugherty wrote:
>>>>> On 7/26/19 2:46 PM, Patricio Chilano wrote:
>>>>>> Hi all,
>>>>>>
>>>>>> Could you review this small fix for test
>>>>>> TestAbortVMOnSafepointTimeout.java?
>>>>>>
>>>>>> The test has been failing intermittently since 8191890. As explained
>>>>>> in the bug comments, it turns out that a bias revocation handshake
>>>>>> could happen in between the start of the "for" loop without safepoint
>>>>>> polls and the safepoint where we want to timeout. That allows for the
>>>>>> long loop to actually finish and prevents the desired timeout in the
>>>>>> later safepoint. The simple solution is to just avoid using biased
>>>>>> locking in this test (and therefore prevent the revocation 
>>>>>> handshake),
>>>>>> since we just want to test the correct behavior of flag
>>>>>> AbortVMOnSafepointTimeout.
>>>>>>
>>>>>> Webrev:
>>> http://cr.openjdk.java.net/~pchilanomate/8227528/v01/webrev
>>>>> The change itself is trivial. However, the reasons behind the change
>>>>> aren't.
>>>>>
>>>>> This part of the description caught my eye:
>>>>>
>>>>>       the start of the "for" loop without safepoint polls
>>>>>
>>>>> and my brain did a "Say what?!?!" Of course, that was without 
>>>>> looking at
>>>>> the test which has a huge number of options, including these:
>>>>>
>>>>>       L70:                 "-XX:-UseCountedLoopSafepoints",
>>>>>       L71:                 "-XX:LoopStripMiningIter=0",
>>>>>       L72:                 "-XX:LoopUnrollLimit=0",
>>>>>
>>>>> Okay, now the world makes much more sense. We are intentionally
>>> telling
>>>>> the compiler to not emit safepoint polls in the counted loop and we're
>>>>> turning off other loop optimizations. Basically, we're telling the
>>>>> compiler we want to stall in that loop until we exceed the safepoint
>>>>> timeout limit. Got it...
>>>>>
>>>>> So the new biased locking handshake messes with the timeout that this
>>>>> test is trying to achieve. Disabling biased locking makes the test 
>>>>> more
>>>>> robust by allowing the safepoint sync timeout to happen.
>>>>>
>>>>> A couple of minor suggestions:
>>>>>
>>>>>
>>> test/hotspot/jtreg/runtime/Safepoint/TestAbortVMOnSafepointTimeout.ja
>>>> va
>>>>>       L30:  * @bug 8219584
>>>>>
>>>>>           You should add an @bug for this bug (8227528). I don't 
>>>>> know if
>>>>>           you can put more than one bug ID on an @bug line or if 
>>>>> you need
>>>>>           a separate @bug line.
>>>>>
>>>>>       L61:         ProcessBuilder pb =
>>>>> ProcessTools.createJavaProcessBuilder(
>>>>>           Please add a comment above this line:
>>>>>
>>>>>               // -XX:-UseBiasedLocking - is used to prevent biased 
>>>>> locking
>>>>>               // handshakes from changing the timing of this test.
>>>>>
>>>>> Thumbs up. I don't need to see another webrev if you choose to make
>>>>> the above changes.
>>>> I think some additional commentary on the other exotic options to 
>>>> ensure
>>>> the loop contains no safepoints and is not unrolled etc would also be
>>>> worthwhile.
>>>>
>>>> Change itself makes sense.
>>>>
>>>> Thanks,
>>>> David
>>>>
>>>>> Dan
>>>>>
>>>>>
>>>>>> Bugid: https://bugs.openjdk.java.net/browse/JDK-8227528
>>>>>>
>>>>>> Thanks!
>>>>>> Patricio
> 


More information about the hotspot-runtime-dev mailing list