RFR: JDK-8205508: hotspot/jtreg/vmTestbase/nsk/jdb/exclude/exclude001/exclude001.java fails with Prompt is not received during 300200 milliseconds.

Gary Adams gary.adams at oracle.com
Tue Jun 26 13:59:57 UTC 2018


As far as I can tell,
the default jtreg harness timeout is 5 minutes
and the RunTests.gmk or TestCommon.gmk
includes a default time factor 4.

So the jtreg harness/invoker is set up to timeout after 20 minutes,
and the vmTestbase wrapper is set to 5 minutes before
it times out internally.

The failure we see in JDK-8205508 is hitting the internal timeout
of the vmTestbase wrapper, not the external jtreg harness.


On 6/26/18, 8:58 AM, David Holmes wrote:
> On 26/06/2018 9:15 PM, Gary Adams wrote:
>> For the vmTestbase tests recently moved to the open repos,
>> see test/hotspot/jtreg/vmTestbase/nsk/share/TimeoutHandler.java.
>> It uses a simple wrapper around a test to ensure a single test completes
>> within a specific time window. The vmTestbase tests were only minimally
>> changed so they could be run with the jtreg test harness, but were not
>> fully ported to rely on features in the jtreg harness itself.
>>
>>      /**
>>       * Perform test execution in separate thread and wait for
>>       * thread finishes or timeout exceeds.
>>       */
>>      public void runTest(Thread testThread) {
>>          long millisec = waitTime * 60 * 1000;
>>          testThread.start();
>>          try {
>>              testThread.join(millisec);
>>          } catch (InterruptedException ex) {
>>              throw new Failure(ex);
>>          }
>>      }
>>
>> For the jtreg TimeoutHandlers,
>> see <jtreg-src>/build/images/jtreg/doc/jtreg/usage.txt.
>>
>> ...
>> Timeout Options
>>                  These options control the behavior when tests run 
>> longer than
>>                  their specified timeout value.
>>      -th:<classname> | -timeoutHandler:<classname>
>>                      Specifies the class to handle timeouts. The 
>> class must
>>                      extend com.sun.javatest.regtest.TimeoutHandler. 
>> E.g.
>>                      -th:MyHandler
>>      -thd:<path> | -timeoutHandlerDir:<path>
>>                      Specifies the pathname of a directory or .jar 
>> file in which
>>                      the timeout handler class is located. The given 
>> pathname is
>>                      simply appended to the CLASSPATH used for the 
>> tests, thus
>>                      care should be taken when naming an timeout 
>> handler not to
>>                      collide with the names of classes internal to 
>> the JavaTest
>>                      harness or the JRE, e.g., put the timeout 
>> handler class in
>>                      its own named package.
>>      -thtimeout:<#seconds> | -timeoutHandlerTimeout:<#seconds>
>>                      Specifies execution time limitation for the 
>> timeout handler.
>>                      If the timeout handler does not finish its 
>> actions within
>>                      the specified period of time, it will be 
>> interrupted.
>>                      Non-positive values mean no limitation. The 
>> default value is
>>                      5 minutes (300 seconds).
>>      -timeout:<number> | -timeoutFactor:<number>
>>                      A scaling factor to extend the default timeout 
>> of all tests.
>>                      Typically used when running tests on slow 
>> systems or systems
>>                      with slow file systems.
>>      -tl:<#seconds> | -timelimit:<#seconds>
>>                      Do not run tests which specify a timeout longer 
>> than a given
>>                      value. The comparison is done against any values 
>> specified
>>                      in the test, before any timeout factor is applied.
>>
>> Which would you prefer at this point in time :
>>    - increase the timeout so it can run on the slower platforms
>>    - problem list the test so it is bypassed completely
>
> I simply wanted to understand how the waitTime related to the jtreg 
> timeout mechanism. There's no point, afterall, in adding an extra 
> minute or two internally to the test if jtreg would time it out before 
> then.
>
> David
> -----
>
>
>> On 6/26/18, 1:45 AM, David Holmes wrote:
>>> Hi Gary,
>>>
>>> On 26/06/2018 4:27 AM, Gary Adams wrote:
>>>> The first time I looked into problems with exclude001 test,
>>>> we discovered a large number of new packages in the jdk.internal
>>>> classes that were introduced in jdk9. The test needed to add 
>>>> excludes for
>>>> any of the jdk.* methods or it could not finish in time.
>>>>
>>>> As a follow up I'll try a test run with unlimited time and no 
>>>> methods excluded to get
>>>> a specific count of methods that are being processed. Over time new 
>>>> features
>>>> have been added, e.g. string concatenation optimizations, lambda 
>>>> functions,
>>>> etc., etc., etc. For a test that does method tracing, each new 
>>>> method adds to the
>>>> collective time. If you can  not reduce the number of methods 
>>>> called, then the time
>>>> for the test needs to be increased.
>>>
>>> That sounds quite reasonable. I'm just wondering how the 
>>> "-waittime=7" interacts with the jtreg timeout handling?
>>>
>>> Thanks,
>>> David
>>>
>>>> ...
>>>>
>>>> On 6/25/18, 2:11 PM, Chris Plummer wrote:
>>>>> I'm also wondering how fast this test runs on other platforms and 
>>>>> when passing on solaris-sparc. 5 minutes already seems like a long 
>>>>> time for this test. There could be an underlying issue that needs 
>>>>> to be addressed.
>>>>>
>>>>> Chris
>>>>>
>>>>> On 6/25/18 11:00 AM, serguei.spitsyn at oracle.com wrote:
>>>>>> Hi Gary,
>>>>>>
>>>>>> It looks Okay.
>>>>>> But I'm curious when this started failing and what triggered it 
>>>>>> to fail?
>>>>>>
>>>>>> Thanks,
>>>>>> Serguei
>>>>>>
>>>>>>
>>>>>> On 6/25/18 10:20, Gary Adams wrote:
>>>>>>> The exclude001 test times out on solaris sparc debug builds.
>>>>>>>
>>>>>>> Basically, this test is all about tracing method calls and 
>>>>>>> introduces
>>>>>>> exclude filters to reduce the callbacks to a select set of 
>>>>>>> packages.
>>>>>>> The time spent tracing/filtering method callbacks is purely a 
>>>>>>> function
>>>>>>> of the number of methods that are processed. On this 
>>>>>>> particularly slow
>>>>>>> target platform, more time is needed before issuing a timeout.
>>>>>>>
>>>>>>>   Issue: https://bugs.openjdk.java.net/browse/JDK-8205508
>>>>>>>
>>>>>>> Proposed fix:
>>>>>>> diff --git 
>>>>>>> a/test/hotspot/jtreg/vmTestbase/nsk/jdb/exclude/exclude001/exclude001.javab/test/hotspot/jtreg/vmTestbase/nsk/jdb/exclude/exclude001/exclude001.java 
>>>>>>>
>>>>>>> --- 
>>>>>>> a/test/hotspot/jtreg/vmTestbase/nsk/jdb/exclude/exclude001/exclude001.java 
>>>>>>>
>>>>>>> +++ 
>>>>>>> b/test/hotspot/jtreg/vmTestbase/nsk/jdb/exclude/exclude001/exclude001.java 
>>>>>>>
>>>>>>> @@ -63,7 +63,7 @@
>>>>>>>   * nsk.jdb.exclude.exclude001.exclude001a
>>>>>>>   * @run main/othervm PropertyResolvingWrapper 
>>>>>>> nsk.jdb.exclude.exclude001.exclude001
>>>>>>>   * -arch=${os.family}-${os.simpleArch}
>>>>>>> - * -waittime=5
>>>>>>> + * -waittime=7
>>>>>>>   * -debugee.vmkind=java
>>>>>>>   * -transport.address=dynamic
>>>>>>>   * -jdb=${test.jdk}/bin/jdb
>>>>>>>
>>>>>>>
>>>>>>
>>>>>
>>>>
>>



More information about the serviceability-dev mailing list