JDK-8238717 : [macos] jpackage BasicTest.java fails due to timeout
  • Type: Bug
  • Component: tools
  • Sub-Component: jpackage
  • Affected Version: 15
  • Priority: P4
  • Status: Closed
  • Resolution: Duplicate
  • OS: os_x
  • CPU: x86_64
  • Submitted: 2020-02-08
  • Updated: 2020-05-30
  • Resolved: 2020-05-29
Related Reports
Duplicate :  
Relates :  
Relates :  
Relates :  
Description
The following test failed due to timeout in the JDK15 CI:

tools/jpackage/share/jdk/jpackage/tests/BasicTest.java

Here's a snippet from the log file:

#section:main
----------messages:(7/487)----------
command: main -Xmx512m jdk.jpackage.test.Main --jpt-run=jdk.jpackage.tests.BasicTest
reason: User specified action: run main/othervm/timeout=720 -Xmx512m jdk.jpackage.test.Main --jpt-run=jdk.jpackage.tests.BasicTest 
Mode: othervm [/othervm specified]
Additional options from @modules: --add-modules jdk.incubator.jpackage --add-exports jdk.incubator.jpackage/jdk.incubator.jpackage.internal=ALL-UNNAMED
Timeout information:
--- Timeout information end.
elapsed time (seconds): 2914.888
----------configuration:(4/165)----------
Boot Layer
  add modules: jdk.incubator.jpackage                                 
  add exports: jdk.incubator.jpackage/jdk.incubator.jpackage.internal ALL-UNNAMED

----------System.out:(1212/130839)*----------

<snip>

2020-02-07 21:48:55.208 diskimages-helper[53473:105655549] DIHelperHDID serveImage: connecting to myDrive 0x150F
2020-02-07 21:48:55.208 diskimages-helper[53473:105655549] DIHelperHDID serveImage: register _readBuffer 0x108f9d000
2020-02-07 21:48:55.208 diskimages-helper[53473:105655549] DIHelperHDID serveImage: activating drive port 19999
2020-02-07 21:48:55.209 diskimages-helper[53473:105655549] DIHelperHDID serveImage: set cache enabled=TRUE returned FAILURE.
2020-02-07 21:48:55.213 diskimages-helper[53473:105655549] DIHelperHDID serveImage: set on IO thread=TRUE returned SUCCESS.
2020-02-07 21:48:55.214 diskimages-helper[53473:105655549] -processKernelRequest: will sleep received
2020-02-07 21:48:57.007 diskimages-helper[53473:105655435] _mountDevEntries: disk1s1 aborting mountpoint postflight because disk image has no band size specified.
2020-02-07 21:48:57.051 diskimages-helper[53473:105655435] *useEffectiveIDs**** euid/egid changed to 10668,10668 (uid/gid is 10668,10668)
2020-02-07 21:48:57.118 diskimages-helper[53473:105655435] *useRealIDs******** euid/egid changed to 10668,10668 (uid/gid is 10668,10668)
Copying???
2020-02-07 21:48:57.119 diskimages-helper[53473:105655435] *useEffectiveIDs**** euid/egid changed to 10668,10668 (uid/gid is 10668,10668)
2020-02-07 21:48:57.198 copy-helper[53494:105655667] copying /scratch/mesos/slaves/7cfa21b9-afde-4338-a459-d3e0a13ec793-S790/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/37af9b83-2eee-4cee-97c0-1aa31df0883b/runs/7a7acaaa-9e4d-424a-95f3-1b98f5e91e86/testoutput/test-support/jtreg_open_test_jdk_tier2_part2/scratch/0/testTemp/temp-root/TempBasicTest-1.0.dmg/images/image-6443797179232148052 to /Volumes/TempBasicTest
2020-02-07 21:48:57.202 copy-helper[53494:105655667] About to copy "/scratch/mesos/slaves/7cfa21b9-afde-4338-a459-d3e0a13ec793-S790/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/37af9b83-2eee-4cee-97c0-1aa31df0883b/runs/7a7acaaa-9e4d-424a-95f3-1b98f5e91e86/testoutput/test-support/jtreg_open_test_jdk_tier2_part2/scratch/0/testTemp/temp-root/TempBasicTest-1.0.dmg/images/image-6443797179232148052".
2020-02-07 21:49:28.615 copy-helper[53494:105655667] Copy finished.
2020-02-07 21:49:33.840 diskimages-helper[53473:105655549] -processKernelRequest: flush received
2020-02-07 21:49:34.944 diskimages-helper[53473:105655435] *useRealIDs******** euid/egid changed to 10668,10668 (uid/gid is 10668,10668)
Finishing???
2020-02-07 21:49:37.139 diskimages-helper[53473:105655435] *useEffectiveIDs**** euid/egid changed to 10668,10668 (uid/gid is 10668,10668)
created: /scratch/mesos/slaves/7cfa21b9-afde-4338-a459-d3e0a13ec793-S790/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/37af9b83-2eee-4cee-97c0-1aa31df0883b/runs/7a7acaaa-9e4d-424a-95f3-1b98f5e91e86/testoutput/test-support/jtreg_open_test_jdk_tier2_part2/scratch/0/./testTemp/temp-root/TempBasicTest-1.0.dmg/images/TempBasicTest-tmp.dmghdiutil: create: returning 0

Running [/usr/bin/hdiutil, attach, /scratch/mesos/slaves/7cfa21b9-afde-4338-a459-d3e0a13ec793-S790/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/37af9b83-2eee-4cee-97c0-1aa31df0883b/runs/7a7acaaa-9e4d-424a-95f3-1b98f5e91e86/testoutput/test-support/jtreg_open_test_jdk_tier2_part2/scratch/0/./testTemp/temp-root/TempBasicTest-1.0.dmg/images/TempBasicTest-tmp.dmg, -verbose, -mountroot, /scratch/mesos/slaves/7cfa21b9-afde-4338-a459-d3e0a13ec793-S790/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/37af9b83-2eee-4cee-97c0-1aa31df0883b/runs/7a7acaaa-9e4d-424a-95f3-1b98f5e91e86/testoutput/test-support/jtreg_open_test_jdk_tier2_part2/scratch/0/./testTemp/temp-root/TempBasicTest-1.0.dmg/images]
Timeout refired 2880 times
----------System.err:(13/741)----------
WARNING: Using incubator modules: jdk.incubator.jpackage
WARNING: Using incubator modules: jdk.incubator.jpackage
WARNING: Using incubator modules: jdk.incubator.jpackage
WARNING: Using incubator modules: jdk.incubator.jpackage
WARNING: Using incubator modules: jdk.incubator.jpackage
WARNING: Using incubator modules: jdk.incubator.jpackage
WARNING: Using incubator modules: jdk.incubator.jpackage
WARNING: Using incubator modules: jdk.incubator.jpackage
WARNING: Using incubator modules: jdk.incubator.jpackage
WARNING: Using incubator modules: jdk.incubator.jpackage
WARNING: Using incubator modules: jdk.incubator.jpackage
WARNING: Using incubator modules: jdk.incubator.jpackage
WARNING: Using incubator modules: jdk.incubator.jpackage
----------rerun:(37/5840)*----------

<snip>

result: Error. Program `/scratch/mesos/jib-master/install/jdk-15+10-282/macosx-x64.jdk/jdk-15.jdk/Contents/Home/bin/java' timed out (timeout set to 2880000ms, elapsed time including timeout handling was 2914863ms).


test result: Error. Program `/scratch/mesos/jib-master/install/jdk-15+10-282/macosx-x64.jdk/jdk-15.jdk/Contents/Home/bin/java' timed out (timeout set to 2880000ms, elapsed time including timeout handling was 2914863ms).


So this test timed out at:

elapsed time (seconds): 2914.888

which is almost 49 minutes.

This is a Tier2 failure so I'm starting the bug as a P3.
Comments
intermittent and not obviously reproducible
27-05-2020