JDK-8158272 : IncludeLocalesPluginTest.java fails with timeout
  • Type: Bug
  • Component: tools
  • Sub-Component: jlink
  • Affected Version: 9
  • Priority: P3
  • Status: Closed
  • Resolution: Fixed
  • Submitted: 2016-05-31
  • Updated: 2016-07-28
  • Resolved: 2016-06-17
The Version table provides details related to the release that this issue/RFE will be addressed.

Unresolved : Release in which this issue/RFE will be addressed.
Resolved: Release in which this issue/RFE has been resolved.
Fixed : Release in which this issue/RFE has been fixed. The release containing this fix may be available for download as an Early Access Release or a General Availability Release.

To download the current JDK release, click here.
JDK 9
9 b124Fixed
Related Reports
Duplicate :  
JDK-8158909 - $jdk/test/tools/jlink/plugins/IncludeLocalesPluginTest test fails on Windows consistently (timeout)
Relates :  
JDK-8158451 - Problem list IncludeLocalesPluginTest.java
Relates :  
JDK-8145136 - Upgrade CLDR locale data
Relates :  
JDK-8159418 - Extract hard-coded strings from test/tools/jlink/plugins/IncludeLocalesPluginTest.java
Description
tools/jlink/plugins/IncludeLocalesPluginTest.java

----------System.out:(49/4797)*----------
[0.012s][info][gc] Using Serial
[0.210s][info][gc] GC(0) Pause Young (Allocation Failure) 4M->1M(15M) (0.206s, 0.210s) 3.733ms
[0.241s][info][gc] GC(1) Pause Young (Allocation Failure) 5M->2M(15M) (0.239s, 0.241s) 2.114ms
[0.259s][info][gc] GC(2) Pause Young (Allocation Failure) 6M->2M(15M) (0.257s, 0.259s) 1.285ms
[0.270s][info][gc] GC(3) Pause Young (Allocation Failure) 6M->2M(15M) (0.268s, 0.270s) 1.283ms
[0.283s][info][gc] GC(4) Pause Young (Allocation Failure) 7M->3M(15M) (0.282s, 0.283s) 1.249ms
[0.317s][info][gc] GC(5) Pause Young (Allocation Failure) 7M->3M(15M) (0.315s, 0.317s) 1.980ms
[0.437s][info][gc] GC(6) Pause Young (Allocation Failure) 7M->4M(15M) (0.435s, 0.437s) 2.359ms
[0.645s][info][gc] GC(7) Pause Young (Allocation Failure) 8M->5M(15M) (0.641s, 0.645s) 3.872ms
[0.721s][info][gc] GC(8) Pause Young (Allocation Failure) 9M->9M(15M) (0.715s, 0.721s) 6.530ms
[0.823s][info][gc] GC(10) Pause Full (Allocation Failure) 12M->12M(17M) (0.807s, 0.823s) 15.594ms
[0.823s][info][gc] GC(9) Pause Young (Allocation Failure) 13M->12M(30M) (0.801s, 0.823s) 21.555ms
[1.015s][info][gc] GC(11) Pause Young (Allocation Failure) 21M->17M(30M) (1.003s, 1.015s) 12.084ms
[1.137s][info][gc] GC(12) Pause Young (Allocation Failure) 26M->19M(30M) (1.129s, 1.137s) 7.316ms
[1.430s][info][gc] GC(14) Pause Full (Allocation Failure) 24M->22M(33M) (1.401s, 1.430s) 29.003ms
[1.430s][info][gc] GC(13) Pause Young (Allocation Failure) 28M->22M(55M) (1.391s, 1.430s) 38.788ms
[1.652s][info][gc] GC(15) Pause Young (Allocation Failure) 38M->31M(55M) (1.636s, 1.652s) 15.254ms
[2.074s][info][gc] GC(17) Pause Full (Allocation Failure) 43M->29M(58M) (2.032s, 2.074s) 41.324ms
[2.074s][info][gc] GC(16) Pause Young (Allocation Failure) 46M->29M(71M) (2.014s, 2.074s) 60.110ms
[2.415s][info][gc] GC(18) Pause Young (Allocation Failure) 49M->40M(71M) (2.398s, 2.415s) 16.812ms
[2.800s][info][gc] GC(19) Pause Young (Allocation Failure) 60M->51M(71M) (2.780s, 2.800s) 19.774ms
[3.233s][info][gc] GC(21) Pause Full (Allocation Failure) 61M->41M(81M) (3.171s, 3.233s) 61.748ms
[3.233s][info][gc] GC(20) Pause Young (Allocation Failure) 71M->41M(100M) (3.152s, 3.233s) 80.785ms
[3.731s][info][gc] GC(22) Pause Young (Allocation Failure) 69M->59M(100M) (3.704s, 3.731s) 26.728ms
[4.348s][info][gc] GC(24) Pause Full (Allocation Failure) 77M->41M(105M) (4.275s, 4.348s) 72.742ms
[4.348s][info][gc] GC(23) Pause Young (Allocation Failure) 87M->41M(100M) (4.244s, 4.348s) 104.484ms
[4.882s][info][gc] GC(25) Pause Young (Allocation Failure) 69M->57M(100M) (4.858s, 4.882s) 23.567ms
[5.280s][info][gc] GC(26) Pause Young (Allocation Failure) 85M->65M(100M) (5.267s, 5.280s) 13.055ms
[5.424s][info][gc] GC(28) Pause Full (Allocation Failure) 74M->47M(102M) (5.363s, 5.424s) 61.115ms
[5.424s][info][gc] GC(27) Pause Young (Allocation Failure) 93M->47M(115M) (5.355s, 5.424s) 69.674ms
[5.479s][info][gc] GC(29) Pause Young (Allocation Failure) 79M->61M(115M) (5.474s, 5.479s) 5.207ms
[5.541s][info][gc] GC(30) Pause Young (Allocation Failure) 93M->72M(115M) (5.535s, 5.541s) 5.205ms
[5.615s][info][gc] GC(31) Pause Young (Allocation Failure) 104M->83M(115M) (5.607s, 5.615s) 8.294ms
[5.737s][info][gc] GC(33) Pause Full (Allocation Failure) 93M->65M(125M) (5.691s, 5.736s) 45.429ms
[5.737s][info][gc] GC(32) Pause Young (Allocation Failure) 115M->65M(159M) (5.682s, 5.737s) 54.380ms
[5.850s][info][gc] GC(34) Pause Young (Allocation Failure) 109M->80M(159M) (5.840s, 5.850s) 10.011ms
[6.017s][info][gc] GC(35) Pause Young (Allocation Failure) 124M->86M(159M) (5.998s, 6.017s) 19.207ms
[6.060s][info][gc] GC(36) Pause Young (Allocation Failure) 130M->95M(159M) (6.051s, 6.060s) 8.906ms
[6.086s][info][gc] GC(37) Pause Young (Allocation Failure) 139M->105M(159M) (6.080s, 6.086s) 6.113ms
[6.175s][info][gc] GC(39) Pause Full (Allocation Failure) 115M->87M(159M) (6.116s, 6.175s) 58.605ms
[6.175s][info][gc] GC(38) Pause Young (Allocation Failure) 149M->87M(211M) (6.110s, 6.175s) 64.843ms
[6.473s][info][gc] GC(40) Pause Young (Allocation Failure) 145M->91M(211M) (6.467s, 6.473s) 6.492ms
[6.618s][info][gc] GC(41) Pause Young (Allocation Failure) 150M->91M(211M) (6.615s, 6.618s) 2.893ms
[6.748s][info][gc] GC(42) Pause Young (Allocation Failure) 150M->91M(211M) (6.747s, 6.748s) 0.733ms
[6.875s][info][gc] GC(43) Pause Young (Allocation Failure) 149M->91M(211M) (6.874s, 6.875s) 0.798ms
[6.998s][info][gc] GC(44) Pause Young (Allocation Failure) 150M->91M(211M) (6.997s, 6.998s) 0.736ms
[7.094s][info][gc] GC(45) Pause Young (Allocation Failure) 149M->91M(211M) (7.093s, 7.094s) 0.890ms
Timeout signalled after 600 seconds
Comments
As this is test only fix, it should have "noreg-self" label with it.
24-06-2016
I was wrong about the memory usage of the test. The test itself doesn't require much memory, but jlink does? While I was trying to figure out what's going on in the child processes, I added a call to inheritIO() to the test. Then the symptom was no longer reproducible with the call.
03-06-2016
Actually, this test doesn't detect real test failures. JDK-8145136 added more locales and the golden data of the test needs to be updated. That's not related to this timeout issue, though.
02-06-2016
The test is written requiring tons of memory.
02-06-2016
The test seems to have started failing after JDK-8145136 was pushed.
01-06-2016
I don't know how to find this information for particular machine but when test passed, it finished within 1 minute.
01-06-2016
Do we have data on how long this test normally takes on this system? Just wondering if it's specific to Windows or this machine or maybe there is something else consuming CPU or I/O cycles on this system?
01-06-2016