RFR of 8194284: CheckRegisterInLog.java fails with java.lang.RuntimeException: CheckRegisterInLog got exception timeout 6480000ms out of range

[David Holmes]

On 18/01/2018 7:21 PM, Hamlin Li wrote:
> 
> 
> On 18/01/2018 5:07 PM, David Holmes wrote:
>> On 18/01/2018 6:05 PM, Hamlin Li wrote:
>>> On 18/01/2018 3:48 PM, David Holmes wrote:
>>>> On 18/01/2018 5:41 PM, Hamlin Li wrote:
>>>>> Hi David,
>>>>>
>>>>> Sometime we will run test by command "jtreg -timeoutFactor:xxx 
>>>>> ...", xxx 
>>>>
>>>> Yes but that controls how jtreg manages the execution of the test.
>>> right.
>>>> How is that then being used by the tests that call TestDriver?
>>> I assume you mean TestLibrary rather than TestDriver.
>>
>> Yes - sorry.
>>
>>> If you follow the code in RMID.java, you will find following code, it 
>>> calculates the timeout value by timeoutFactor value.
>>>
>>>          long waitTime = (long)(240_000 * 
>>> TestLibrary.getTimeoutFactor());
>>>          restartTimeout = (long)(waitTime * 0.9);
>>>> Further if TestDriver limits the timeout to a smaller value, then 
>>>> the increase in timeoutFactor won't help at all - people will see a 
>>>> timeout, increase the timeoutFactor and still see a timeout!
>>> No, by pass a large timeoutFactor value, I will get test passed 
>>> rather than get timeout exception.
>>
>> Sorry you are right - the timeout is limited before scaling by the 
>> timeout-factor, so it will increase. Though it's possible for the 
>> resulting scaled timeout to still be smaller than the original 
>> requested one.
>>
>> But the exception is telling you there is a mismatch between the 
>> timing expectations of the caller and the actual behaviour in 
>> TestLibrary. Simply placing a ceiling on the timeout value doesn't fix 
>> that mismatch.
> The patch is not to fix any mismatch, it's just let user to supply a 
> large enough value for timeoutFactor (if it's accepted by jtreg) and let 
> test pass, it's meaningless to throw an exception.

By dropping the exception you're trying to address the mismatch.

>> I don't see any point in computeDeadline imposing an arbitrary maximum 
>> timeout of 1 hour. (Though it concerns me that tests are trying to set 
>> timeouts even longer than an hour!)
> I neither, but it's history code, currently not necessary to touch it, 
> how do you think about it?

I think the max timeout is pointless. I think other code trying to set 
timeouts bigger than an hour is a real problem!

Let's what if anyone else has an opinion.

Thanks,
David

> Thank you
> -Hamlin
>>
>> David
>> -----
>>
>>>>
>>>> For that matter why is TestDriver even imposing a timeout of its own 
>>>> when jtreg imposes an overall timeout?
>>> It's a history topic, if it's necessary we could file another 
>>> enhancement or bug to track it.
>>>> In general we have been moving away from test initiated timeouts and 
>>>> letting the test harness handle it.
>>> Yes, I agree, that's the reason I refactor it to round down the 
>>> timeout to MAX_TIMEOUT_MS rather than throw an exception by test itself.
>>>
>>> Thank you
>>> -Hamlin
>>>>
>>>> Cheers,
>>>> David
>>>>
>>>>> may be a large number than usual, e.g. 100. The reason we supply a 
>>>>> large number for timeoutFactor is because we're running test on a 
>>>>> very slow machine, or we're running test on a docker environment 
>>>>> which has very limited resource, without a large timeoutFactor 
>>>>> value, the test will finally get timeout exception. At this 
>>>>> situation, it's NOT reasonable for user to know the exact 
>>>>> timeoutFactor by which the calculated result will be 
>>>>> MAX_TIMEOUT_MS, what's helpful is to let user supply a large enough 
>>>>> timeoutFactor value and round down the timeout value to 
>>>>> MAX_TIMEOUT_MS automatically, rather than throw an exception.
>>>>>
>>>>> Thank you
>>>>>
>>>>> -Hamlin
>>>>>
>>>>>
>>>>> On 18/01/2018 3:15 PM, David Holmes wrote:
>>>>>> Hi Hamlin,
>>>>>>
>>>>>> This should probably be reviewed on core-libs-dev. I don't think 
>>>>>> jdk-dev is intended for code reviews.
>>>>>>
>>>>>> On 18/01/2018 4:59 PM, Hamlin Li wrote:
>>>>>>> Would you please review the following patch?
>>>>>>>
>>>>>>> bug: https://bugs.openjdk.java.net/browse/JDK-8194284
>>>>>>>
>>>>>>> webrev as below.
>>>>>>
>>>>>> I don't agree with this. Whatever is passing the incorrect timeout 
>>>>>> to the TestLibrary should be fixed. The bug report needs more 
>>>>>> information about where the incorrect value is coming from and why.
>>>>>>
>>>>>> Cheers,
>>>>>> David
>>>>>>
>>>>>>>
>>>>>>> Thank you
>>>>>>>
>>>>>>> -Hamlin
>>>>>>>
>>>>>>> ------------------------------------------------------------------------ 
>>>>>>>
>>>>>>>
>>>>>>> diff -r 0dec8c41170c test/jdk/java/rmi/testlibrary/TestLibrary.java
>>>>>>> --- a/test/jdk/java/rmi/testlibrary/TestLibrary.java Wed Jan 17 
>>>>>>> 20:07:50 2018 -0800
>>>>>>> +++ b/test/jdk/java/rmi/testlibrary/TestLibrary.java Thu Jan 18 
>>>>>>> 14:54:50 2018 +0800
>>>>>>> @@ -188,8 +188,12 @@
>>>>>>>       public static long computeDeadline(long timestamp, long 
>>>>>>> timeout) {
>>>>>>>           final long MAX_TIMEOUT_MS = 3_600_000L;
>>>>>>>
>>>>>>> -        if (timeout < 0L || timeout > MAX_TIMEOUT_MS) {
>>>>>>> +        if (timeout < 0L) {
>>>>>>>               throw new IllegalArgumentException("timeout " + 
>>>>>>> timeout + "ms out of range");
>>>>>>> +        } else if (timeout > MAX_TIMEOUT_MS) {
>>>>>>> +            System.out.format("timeout value(%d) exceeds 
>>>>>>> MAX_TIMEOUT_MS(%d), "
>>>>>>> +                    + "use MAX_TIMEOUT_MS instead!%n", timeout, 
>>>>>>> MAX_TIMEOUT_MS);
>>>>>>> +            timeout = MAX_TIMEOUT_MS;
>>>>>>>           }
>>>>>>>
>>>>>>>           return timestamp + (long)(timeout * getTimeoutFactor());
>>>>>>>
>>>>>
>>>
>