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

[David Holmes]

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.

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

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());
>>>>>
>>>
>