Bug ID: JDK-8278233 [macos] tools/jpackage tests timeout due to /usr/bin/osascript

JDK-8278233 : [macos] tools/jpackage tests timeout due to /usr/bin/osascript

Type: Bug
Component: tools
Sub-Component: jpackage
Affected Version: 18

Priority: P3
Status: Resolved
Resolution: Fixed
OS: os_x
CPU: x86_64

Submitted: 2021-12-03
Updated: 2022-07-22
Resolved: 2021-12-15

Versions (Unresolved/Resolved/Fixed)

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 17	JDK 18	JDK 19
17.0.5-oracleFixed	18 b28Fixed	19Fixed

Related Reports

Relates :	JDK-8248248 - [macos] EmptyFolderPackageTest.java fails EmptyFolderPackageTest-dmg-setup.scpt exited with 134 code
Relates :	JDK-8276837 - [macos]: Error when signing the additional launcher

Sub Tasks

JDK-8278368 :	ProblemList tools/jpackage/share/MultiNameTwoPhaseTest.java on macosx-x64 - Resolved
JDK-8278445 :	ProblemList tools/jpackage/share/IconTest.java on macosx-x64 - Resolved

Description

The following test timed out in the JDK18 CI:

tools/jpackage/share/MultiNameTwoPhaseTest.java

The test run contains errors like this:

[11:45:37.245] Running /usr/bin/osascript
[11:51:07.189] Command [PID: 5566]:
    /usr/bin/osascript /var/folders/93/pf04s4c922qcyb7v8xr1y5h8000_dc/T/jdk.jpackage4183342526789260831/config/Hello-dmg-setup.scpt
[11:51:07.190] Output:
    /var/folders/93/pf04s4c922qcyb7v8xr1y5h8000_dc/T/jdk.jpackage4183342526789260831/config/Hello-dmg-setup.scpt:192:204: execution error: Finder got an error: AppleEvent timed out. (-1712)
[11:51:07.190] Returned: 1

[11:51:07.190] java.io.IOException: Command [/usr/bin/osascript, /var/folders/93/pf04s4c922qcyb7v8xr1y5h8000_dc/T/jdk.jpackage4183342526789260831/config/Hello-dmg-setup.scpt] exited with 1 code
	at jdk.jpackage/jdk.jpackage.internal.Executor.executeExpectSuccess(Executor.java:90)
	at jdk.jpackage/jdk.jpackage.internal.IOUtils.exec(IOUtils.java:215)
	at jdk.jpackage/jdk.jpackage.internal.IOUtils.exec(IOUtils.java:193)
	at jdk.jpackage/jdk.jpackage.internal.IOUtils.exec(IOUtils.java:172)
	at jdk.jpackage/jdk.jpackage.internal.MacDmgBundler.buildDMG(MacDmgBundler.java:404)
	at jdk.jpackage/jdk.jpackage.internal.MacDmgBundler.bundle(MacDmgBundler.java:90)
	at jdk.jpackage/jdk.jpackage.internal.MacDmgBundler.execute(MacDmgBundler.java:579)
	at jdk.jpackage/jdk.jpackage.internal.Arguments.generateBundle(Arguments.java:689)
	at jdk.jpackage/jdk.jpackage.internal.Arguments.processArguments(Arguments.java:561)
	at jdk.jpackage/jdk.jpackage.main.Main.execute(Main.java:91)
	at jdk.jpackage/jdk.jpackage.main.Main.main(Main.java:52)

There are five runs of /usr/bin/osascript and
all have similar errors. I suspect that the issues with
/usr/bin/osascript are what caused the test run to
take so long.

The test did PASS while the timeout handler was running:

[12:03:44.970] [       OK ] MultiNameTwoPhaseTest.test([MultiNameTest, ](length=2)); checks=36
[12:03:44.970] [==========] 5 tests ran
[12:03:44.971] [  PASSED  ] 5 tests
----------System.err:(1/15)----------
STATUS:Passed.
----------rerun:(39/8387)*----------

It could be that these /usr/bin/osascript errors are "normal"
and this test just needs a longer timeout.

Comments

Fix request [17u] I backport this for parity with 17.0.5-oracle. Clean backport except for ProblemList. SAP nightly testing passed.
22-07-2022
A pull request was submitted for review. URL: https://git.openjdk.org/jdk17u-dev/pull/577 Date: 2022-07-21 11:09:22 +0000
21-07-2022
Changeset: 918e3397 Author: Alexander Matveev <almatvee@openjdk.org> Date: 2021-12-14 23:59:11 +0000 URL: https://git.openjdk.java.net/jdk18/commit/918e3397858c425e9c3b82c9a918b7626603a59c
15-12-2021
so let's fix it in the forked 18.
09-12-2021
Looks like regression from JDK-8276837. JDK-8276837 introduced overwrite of IOUtils:exec() which passes Executor.INFINITE_TIMEOUT instead of actual timeout value and thus it disables timeouts.
09-12-2021
Here's a log file snippet from the 18+27-1846-tier2 sighting: tools/jpackage/share/IconTest.java [18:28:45.915] Running /usr/bin/osascript [18:45:54.213] Command [PID: 2998]: /usr/bin/osascript /var/folders/tl/0gwf6kb567s_1_q9jh8vh2v00000gp/T/jdk.jpackage186151433922985113/config/IconTest-dmg-setup.scpt [18:45:54.213] Output: /var/folders/tl/0gwf6kb567s_1_q9jh8vh2v00000gp/T/jdk.jpackage186151433922985113/config/IconTest-dmg-setup.scpt:194:206: execution error: Finder got an error: AppleEvent timed out. (-1712) [18:45:54.214] Returned: 1 [18:45:54.214] java.io.IOException: Command [/usr/bin/osascript, /var/folders/tl/0gwf6kb567s_1_q9jh8vh2v00000gp/T/jdk.jpackage186151433922985113/config/IconTest-dmg-setup.scpt] exited with 1 code at jdk.jpackage/jdk.jpackage.internal.Executor.executeExpectSuccess(Executor.java:90) at jdk.jpackage/jdk.jpackage.internal.IOUtils.exec(IOUtils.java:215) at jdk.jpackage/jdk.jpackage.internal.IOUtils.exec(IOUtils.java:193) at jdk.jpackage/jdk.jpackage.internal.IOUtils.exec(IOUtils.java:172) at jdk.jpackage/jdk.jpackage.internal.MacDmgBundler.buildDMG(MacDmgBundler.java:404) at jdk.jpackage/jdk.jpackage.internal.MacDmgBundler.bundle(MacDmgBundler.java:90) at jdk.jpackage/jdk.jpackage.internal.MacDmgBundler.execute(MacDmgBundler.java:579) at jdk.jpackage/jdk.jpackage.internal.Arguments.generateBundle(Arguments.java:689) at jdk.jpackage/jdk.jpackage.internal.Arguments.processArguments(Arguments.java:561) at jdk.jpackage/jdk.jpackage.main.Main.execute(Main.java:91) at jdk.jpackage/jdk.jpackage.main.Main.main(Main.java:52)
08-12-2021
tools/jpackage/share/IconTest.java has reach 4 timeouts in less than a week so I'm going to look at ProblemListing it on macosx-x64 to reduce the noise in the CI.
08-12-2021
This is an intermittent timeout in osascript that was supposed to be fixed by JDK-8248248
06-12-2021