JFR TestCompilerCompile times out on Windows 32

[karianna]

https://trss.adoptium.net/output/test?id=616f6997c6182d021789a649

[2021-10-19T23:12:48.473Z] rerun:
[2021-10-19T23:12:48.473Z] cd 'E:\workspace\Test_openjdk8_hs_extended.openjdk_x86-64_windows_testList_1\aqa-tests\TKG\output_16346820155578\jdk_jfr_1\work\scratch\2' &&
[2021-10-19T23:12:48.473Z] PATH='C:\cygwin64\bin;C:\Windows\system32;C:\Windows;C:\Windows\System32\Wbem;C:\Windows\System32\WindowsPowerShell\v1.0;C:\Program Files (x86)\Microsoft SQL Server\100\Tools\Binn;C:\Program Files\Microsoft SQL Server\100\Tools\Binn;C:\Program Files\Microsoft SQL Server\100\DTS\Binn;C:\Strawberry\perl\bin;C:\Program Files\Git\cmd;C:\openjdk\jdk-8\bin;C:\apache-ant\apache-ant-1.10.5\bin;C:\Program Files\Microsoft SQL Server\110\Tools\Binn;C:\Program Files (x86)\Microsoft SDKs\TypeScript\1.0;C:\Program Files\Microsoft SQL Server\120\Tools\Binn;C:\Program Files (x86)\IncrediBuild;C:\rust\bin;C:\Program Files\IcedTeaWEB\bin'
[2021-10-19T23:12:48.473Z] SystemDrive=C:
[2021-10-19T23:12:48.473Z] SystemRoot='C:\Windows'
[2021-10-19T23:12:48.473Z] TEMP='C:\Users\JENKIN~1.BLD\AppData\Local\Temp'
[2021-10-19T23:12:48.473Z] TMP='E:\jenkins\jenkinstmp'
[2021-10-19T23:12:48.473Z] windir='C:\Windows'
[2021-10-19T23:12:48.473Z] 'E:\workspace\Test_openjdk8_hs_extended.openjdk_x86-64_windows_testList_1\openjdkbinary\j2sdk-image\bin\javac'
[2021-10-19T23:12:48.473Z] -J-ea
[2021-10-19T23:12:48.473Z] -J-esa
[2021-10-19T23:12:48.473Z] -J-Xmx512m
[2021-10-19T23:12:48.473Z] -J-XX:-UseCompressedOops
[2021-10-19T23:12:48.473Z] -J-Djava.awt.headless=true
[2021-10-19T23:12:48.473Z] -J-Dtest.vm.opts='-ea -esa -Xmx512m -XX:-UseCompressedOops -Djava.awt.headless=true'
[2021-10-19T23:12:48.473Z] -J-Dtest.tool.vm.opts='-J-ea -J-esa -J-Xmx512m -J-XX:-UseCompressedOops -J-Djava.awt.headless=true'
[2021-10-19T23:12:48.473Z] -J-Dtest.compiler.opts=
[2021-10-19T23:12:48.473Z] -J-Dtest.java.opts=
[2021-10-19T23:12:48.473Z] -J-Dtest.jdk='E:\workspace\Test_openjdk8_hs_extended.openjdk_x86-64_windows_testList_1\openjdkbinary\j2sdk-image'
[2021-10-19T23:12:48.473Z] -J-Dcompile.jdk='E:\workspace\Test_openjdk8_hs_extended.openjdk_x86-64_windows_testList_1\openjdkbinary\j2sdk-image'
[2021-10-19T23:12:48.473Z] -J-Dtest.timeout.factor=8.0
[2021-10-19T23:12:48.473Z] -J-Dtest.root='E:\workspace\Test_openjdk8_hs_extended.openjdk_x86-64_windows_testList_1\aqa-tests\openjdk\openjdk-jdk\jdk\test'
[2021-10-19T23:12:48.473Z] -J-Dtest.name=jdk/jfr/event/compiler/TestCompilerCompile.java
[2021-10-19T23:12:48.473Z] -J-Dtest.file='E:\workspace\Test_openjdk8_hs_extended.openjdk_x86-64_windows_testList_1\aqa-tests\openjdk\openjdk-jdk\jdk\test\jdk\jfr\event\compiler\TestCompilerCompile.java'
[2021-10-19T23:12:48.473Z] -J-Dtest.src='E:\workspace\Test_openjdk8_hs_extended.openjdk_x86-64_windows_testList_1\aqa-tests\openjdk\openjdk-jdk\jdk\test\jdk\jfr\event\compiler'
[2021-10-19T23:12:48.473Z] -J-Dtest.src.path='E:\workspace\Test_openjdk8_hs_extended.openjdk_x86-64_windows_testList_1\aqa-tests\openjdk\openjdk-jdk\jdk\test\jdk\jfr\event\compiler;E:\workspace\Test_openjdk8_hs_extended.openjdk_x86-64_windows_testList_1\aqa-tests\openjdk\openjdk-jdk\jdk\test\lib;E:\workspace\Test_openjdk8_hs_extended.openjdk_x86-64_windows_testList_1\aqa-tests\openjdk\openjdk-jdk\jdk\test'
[2021-10-19T23:12:48.473Z] -J-Dtest.classes='E:\workspace\Test_openjdk8_hs_extended.openjdk_x86-64_windows_testList_1\aqa-tests\TKG\output_16346820155578\jdk_jfr_1\work\classes\2\jdk\jfr\event\compiler'
[2021-10-19T23:12:48.474Z] -J-Dtest.class.path='E:\workspace\Test_openjdk8_hs_extended.openjdk_x86-64_windows_testList_1\aqa-tests\TKG\output_16346820155578\jdk_jfr_1\work\classes\2\jdk\jfr\event\compiler;E:\workspace\Test_openjdk8_hs_extended.openjdk_x86-64_windows_testList_1\aqa-tests\TKG\output_16346820155578\jdk_jfr_1\work\classes\2\lib;E:\workspace\Test_openjdk8_hs_extended.openjdk_x86-64_windows_testList_1\aqa-tests\TKG\output_16346820155578\jdk_jfr_1\work\classes\2'
[2021-10-19T23:12:48.474Z] -J-Dtest.class.path.prefix='E:\workspace\Test_openjdk8_hs_extended.openjdk_x86-64_windows_testList_1\aqa-tests\TKG\output_16346820155578\jdk_jfr_1\work\classes\2\jdk\jfr\event\compiler;E:\workspace\Test_openjdk8_hs_extended.openjdk_x86-64_windows_testList_1\aqa-tests\openjdk\openjdk-jdk\jdk\test\jdk\jfr\event\compiler;E:\workspace\Test_openjdk8_hs_extended.openjdk_x86-64_windows_testList_1\aqa-tests\TKG\output_16346820155578\jdk_jfr_1\work\classes\2\lib;E:\workspace\Test_openjdk8_hs_extended.openjdk_x86-64_windows_testList_1\aqa-tests\TKG\output_16346820155578\jdk_jfr_1\work\classes\2'
[2021-10-19T23:12:48.474Z] -d 'E:\workspace\Test_openjdk8_hs_extended.openjdk_x86-64_windows_testList_1\aqa-tests\TKG\output_16346820155578\jdk_jfr_1\work\classes\2\jdk\jfr\event\compiler'
[2021-10-19T23:12:48.474Z] -sourcepath 'E:\workspace\Test_openjdk8_hs_extended.openjdk_x86-64_windows_testList_1\aqa-tests\openjdk\openjdk-jdk\jdk\test\jdk\jfr\event\compiler;E:\workspace\Test_openjdk8_hs_extended.openjdk_x86-64_windows_testList_1\aqa-tests\openjdk\openjdk-jdk\jdk\test\lib;E:\workspace\Test_openjdk8_hs_extended.openjdk_x86-64_windows_testList_1\aqa-tests\openjdk\openjdk-jdk\jdk\test'
[2021-10-19T23:12:48.474Z] -classpath 'E:\workspace\Test_openjdk8_hs_extended.openjdk_x86-64_windows_testList_1\aqa-tests\openjdk\openjdk-jdk\jdk\test\jdk\jfr\event\compiler;E:\workspace\Test_openjdk8_hs_extended.openjdk_x86-64_windows_testList_1\aqa-tests\TKG\output_16346820155578\jdk_jfr_1\work\classes\2\jdk\jfr\event\compiler;E:\workspace\Test_openjdk8_hs_extended.openjdk_x86-64_windows_testList_1\aqa-tests\TKG\output_16346820155578\jdk_jfr_1\work\classes\2\lib;E:\workspace\Test_openjdk8_hs_extended.openjdk_x86-64_windows_testList_1\aqa-tests\TKG\output_16346820155578\jdk_jfr_1\work\classes\2;E:\workspace\Test_openjdk8_hs_extended.openjdk_x86-64_windows_testList_1\openjdkbinary\j2sdk-image\lib\tools.jar'
[2021-10-19T23:12:48.474Z] -XDignore.symbol.file=true 'E:\workspace\Test_openjdk8_hs_extended.openjdk_x86-64_windows_testList_1\aqa-tests\openjdk\openjdk-jdk\jdk\test\jdk\jfr\event\compiler\TestCompilerCompile.java'
[2021-10-19T23:12:48.474Z] direct:
[2021-10-19T23:12:48.474Z] Note: E:\workspace\Test_openjdk8_hs_extended.openjdk_x86-64_windows_testList_1\aqa-tests\openjdk\openjdk-jdk\jdk\test\lib\jdk\test\lib\Utils.java uses unchecked or unsafe operations.
[2021-10-19T23:12:48.474Z] Note: Recompile with -Xlint:unchecked for details.
[2021-10-19T23:12:48.474Z]
[2021-10-19T23:12:48.474Z] ACTION: main -- Error. Program E:\workspace\Test_openjdk8_hs_extended.openjdk_x86-64_windows_testList_1\openjdkbinary\j2sdk-image\bin\java' timed out (timeout set to 960000ms, elapsed time including timeout handling was 960006ms). [2021-10-19T23:12:48.475Z] REASON: User specified action: run main/othervm -Xbootclasspath/a:. -XX:+UnlockDiagnosticVMOptions -XX:+WhiteBoxAPI jdk.jfr.event.compiler.TestCompilerCompile [2021-10-19T23:12:48.475Z] TIME: 960.009 seconds [2021-10-19T23:12:48.475Z] messages: [2021-10-19T23:12:48.475Z] command: main -Xbootclasspath/a:. -XX:+UnlockDiagnosticVMOptions -XX:+WhiteBoxAPI jdk.jfr.event.compiler.TestCompilerCompile [2021-10-19T23:12:48.475Z] reason: User specified action: run main/othervm -Xbootclasspath/a:. -XX:+UnlockDiagnosticVMOptions -XX:+WhiteBoxAPI jdk.jfr.event.compiler.TestCompilerCompile [2021-10-19T23:12:48.475Z] Mode: othervm [/othervm specified] [2021-10-19T23:12:48.475Z] Timeout information: [2021-10-19T23:12:48.475Z] Could not find process id for the process that timed out. [2021-10-19T23:12:48.475Z] Skipping timeout handling. [2021-10-19T23:12:48.475Z] elapsed time (seconds): 960.009 [2021-10-19T23:12:48.475Z] configuration: [2021-10-19T23:12:48.475Z] STDOUT: [2021-10-19T23:12:48.475Z] Warning: 'NoSuchMethodError' on register of sun.hotspot.WhiteBox::NMTNewArena(J)J [2021-10-19T23:12:48.475Z] Warning: 'NoSuchMethodError' on register of sun.hotspot.WhiteBox::NMTFreeArena(J)V [2021-10-19T23:12:48.475Z] Warning: 'NoSuchMethodError' on register of sun.hotspot.WhiteBox::NMTArenaMalloc(JJ)V [2021-10-19T23:12:48.475Z] Timeout refired 960 times [2021-10-19T23:12:48.475Z] STDERR: [2021-10-19T23:12:48.475Z] rerun: [2021-10-19T23:12:48.475Z] cd 'E:\workspace\Test_openjdk8_hs_extended.openjdk_x86-64_windows_testList_1\aqa-tests\TKG\output_16346820155578\jdk_jfr_1\work\scratch\2' && \ [2021-10-19T23:12:48.475Z] PATH='C:\cygwin64\bin;C:\Windows\system32;C:\Windows;C:\Windows\System32\Wbem;C:\Windows\System32\WindowsPowerShell\v1.0;C:\Program Files (x86)\Microsoft SQL Server\100\Tools\Binn;C:\Program Files\Microsoft SQL Server\100\Tools\Binn;C:\Program Files\Microsoft SQL Server\100\DTS\Binn;C:\Strawberry\perl\bin;C:\Program Files\Git\cmd;C:\openjdk\jdk-8\bin;C:\apache-ant\apache-ant-1.10.5\bin;C:\Program Files\Microsoft SQL Server\110\Tools\Binn;C:\Program Files (x86)\Microsoft SDKs\TypeScript\1.0;C:\Program Files\Microsoft SQL Server\120\Tools\Binn;C:\Program Files (x86)\IncrediBuild;C:\rust\bin;C:\Program Files\IcedTeaWEB\bin' \ [2021-10-19T23:12:48.475Z] SystemDrive=C: \ [2021-10-19T23:12:48.475Z] SystemRoot='C:\Windows' \ [2021-10-19T23:12:48.475Z] TEMP='C:\Users\JENKIN~1.BLD\AppData\Local\Temp' \ [2021-10-19T23:12:48.475Z] TMP='E:\jenkins\jenkinstmp' \ [2021-10-19T23:12:48.475Z] windir='C:\Windows' \ [2021-10-19T23:12:48.475Z] CLASSPATH='E:\workspace\Test_openjdk8_hs_extended.openjdk_x86-64_windows_testList_1\aqa-tests\TKG\output_16346820155578\jdk_jfr_1\work\classes\2\jdk\jfr\event\compiler;E:\workspace\Test_openjdk8_hs_extended.openjdk_x86-64_windows_testList_1\aqa-tests\openjdk\openjdk-jdk\jdk\test\jdk\jfr\event\compiler;E:\workspace\Test_openjdk8_hs_extended.openjdk_x86-64_windows_testList_1\aqa-tests\TKG\output_16346820155578\jdk_jfr_1\work\classes\2\lib;E:\workspace\Test_openjdk8_hs_extended.openjdk_x86-64_windows_testList_1\aqa-tests\openjdk\openjdk-jdk\jdk\test\lib;E:\workspace\Test_openjdk8_hs_extended.openjdk_x86-64_windows_testList_1\aqa-tests\TKG\output_16346820155578\jdk_jfr_1\work\classes\2;E:\workspace\Test_openjdk8_hs_extended.openjdk_x86-64_windows_testList_1\aqa-tests\openjdk\openjdk-jdk\jdk\test;E:\workspace\Test_openjdk8_hs_extended.openjdk_x86-64_windows_testList_1\openjdkbinary\j2sdk-image\lib\tools.jar;E:\workspace\Test_openjdk8_hs_extended.openjdk_x86-64_windows_testList_1\jvmtest\openjdk\jtreg\lib\javatest.jar;E:\workspace\Test_openjdk8_hs_extended.openjdk_x86-64_windows_testList_1\jvmtest\openjdk\jtreg\lib\jtreg.jar' \ [2021-10-19T23:12:48.475Z] 'E:\workspace\Test_openjdk8_hs_extended.openjdk_x86-64_windows_testList_1\openjdkbinary\j2sdk-image\bin\java' \ [2021-10-19T23:12:48.475Z] -Dtest.vm.opts='-ea -esa -Xmx512m -XX:-UseCompressedOops -Djava.awt.headless=true' \ [2021-10-19T23:12:48.475Z] -Dtest.tool.vm.opts='-J-ea -J-esa -J-Xmx512m -J-XX:-UseCompressedOops -J-Djava.awt.headless=true' \ [2021-10-19T23:12:48.475Z] -Dtest.compiler.opts= \ [2021-10-19T23:12:48.475Z] -Dtest.java.opts= \ [2021-10-19T23:12:48.475Z] -Dtest.jdk='E:\workspace\Test_openjdk8_hs_extended.openjdk_x86-64_windows_testList_1\openjdkbinary\j2sdk-image' \ [2021-10-19T23:12:48.475Z] -Dcompile.jdk='E:\workspace\Test_openjdk8_hs_extended.openjdk_x86-64_windows_testList_1\openjdkbinary\j2sdk-image' \ [2021-10-19T23:12:48.475Z] -Dtest.timeout.factor=8.0 \ [2021-10-19T23:12:48.475Z] -Dtest.root='E:\workspace\Test_openjdk8_hs_extended.openjdk_x86-64_windows_testList_1\aqa-tests\openjdk\openjdk-jdk\jdk\test' \ [2021-10-19T23:12:48.475Z] -Dtest.name=jdk/jfr/event/compiler/TestCompilerCompile.java \ [2021-10-19T23:12:48.475Z] -Dtest.file='E:\workspace\Test_openjdk8_hs_extended.openjdk_x86-64_windows_testList_1\aqa-tests\openjdk\openjdk-jdk\jdk\test\jdk\jfr\event\compiler\TestCompilerCompile.java' \ [2021-10-19T23:12:48.476Z] -Dtest.src='E:\workspace\Test_openjdk8_hs_extended.openjdk_x86-64_windows_testList_1\aqa-tests\openjdk\openjdk-jdk\jdk\test\jdk\jfr\event\compiler' \ [2021-10-19T23:12:48.476Z] -Dtest.src.path='E:\workspace\Test_openjdk8_hs_extended.openjdk_x86-64_windows_testList_1\aqa-tests\openjdk\openjdk-jdk\jdk\test\jdk\jfr\event\compiler;E:\workspace\Test_openjdk8_hs_extended.openjdk_x86-64_windows_testList_1\aqa-tests\openjdk\openjdk-jdk\jdk\test\lib;E:\workspace\Test_openjdk8_hs_extended.openjdk_x86-64_windows_testList_1\aqa-tests\openjdk\openjdk-jdk\jdk\test' \ [2021-10-19T23:12:48.476Z] -Dtest.classes='E:\workspace\Test_openjdk8_hs_extended.openjdk_x86-64_windows_testList_1\aqa-tests\TKG\output_16346820155578\jdk_jfr_1\work\classes\2\jdk\jfr\event\compiler' \ [2021-10-19T23:12:48.476Z] -Dtest.class.path='E:\workspace\Test_openjdk8_hs_extended.openjdk_x86-64_windows_testList_1\aqa-tests\TKG\output_16346820155578\jdk_jfr_1\work\classes\2\jdk\jfr\event\compiler;E:\workspace\Test_openjdk8_hs_extended.openjdk_x86-64_windows_testList_1\aqa-tests\TKG\output_16346820155578\jdk_jfr_1\work\classes\2\lib;E:\workspace\Test_openjdk8_hs_extended.openjdk_x86-64_windows_testList_1\aqa-tests\TKG\output_16346820155578\jdk_jfr_1\work\classes\2' \ [2021-10-19T23:12:48.476Z] -Dtest.class.path.prefix='E:\workspace\Test_openjdk8_hs_extended.openjdk_x86-64_windows_testList_1\aqa-tests\TKG\output_16346820155578\jdk_jfr_1\work\classes\2\jdk\jfr\event\compiler;E:\workspace\Test_openjdk8_hs_extended.openjdk_x86-64_windows_testList_1\aqa-tests\openjdk\openjdk-jdk\jdk\test\jdk\jfr\event\compiler;E:\workspace\Test_openjdk8_hs_extended.openjdk_x86-64_windows_testList_1\aqa-tests\TKG\output_16346820155578\jdk_jfr_1\work\classes\2\lib;E:\workspace\Test_openjdk8_hs_extended.openjdk_x86-64_windows_testList_1\aqa-tests\TKG\output_16346820155578\jdk_jfr_1\work\classes\2' \ [2021-10-19T23:12:48.476Z] -ea \ [2021-10-19T23:12:48.476Z] -esa \ [2021-10-19T23:12:48.476Z] -Xmx512m \ [2021-10-19T23:12:48.476Z] -XX:-UseCompressedOops \ [2021-10-19T23:12:48.476Z] -Djava.awt.headless=true \ [2021-10-19T23:12:48.476Z] -Xbootclasspath/a:. \ [2021-10-19T23:12:48.476Z] -XX:+UnlockDiagnosticVMOptions \ [2021-10-19T23:12:48.476Z] -XX:+WhiteBoxAPI \ [2021-10-19T23:12:48.476Z] com.sun.javatest.regtest.agent.MainWrapper 'E:\workspace\Test_openjdk8_hs_extended.openjdk_x86-64_windows_testList_1\aqa-tests\TKG\output_16346820155578\jdk_jfr_1\work\jdk\jfr\event\compiler\TestCompilerCompile.d\main.0.jta' [2021-10-19T23:12:48.476Z] [2021-10-19T23:12:48.476Z] TEST RESULT: Error. Program E:\workspace\Test_openjdk8_hs_extended.openjdk_x86-64_windows_testList_1\openjdkbinary\j2sdk-image\bin\java' timed out (timeout set to 960000ms, elapsed time including timeout handling was 960006ms).
[2021-10-19T23:12:48.476Z] --------------------------------------------------
[2021-10-19T23:12:48.476Z] Test results: passed: 430; error: 1
[2021-10-19T23:12:56.379Z] Report written to E:\workspace\Test_openjdk8_hs_extended.openjdk_x86-64_windows_testList_1\jvmtest\openjdk\report\html\report.html
[2021-10-19T23:12:56.379Z] Results written to E:\workspace\Test_openjdk8_hs_extended.openjdk_x86-64_windows_testList_1\aqa-tests\TKG\output_16346820155578\jdk_jfr_1\work
[2021-10-19T23:12:56.379Z] Error: Some tests failed or other problems occurred.
[2021-10-19T23:12:56.379Z]
[2021-10-19T23:12:56.379Z] jdk_jfr_1_FAILED

[smlambert]

Please also provide a link to test run or TRSS report to help whoever has to attempted to resolve this issue.

[karianna]

https://trss.adoptium.net/output/test?id=616f6997c6182d021789a649

[smlambert]

Also times out on win64 (TRSS link for April release run for jdk8 win64).

This seems to be the crux of the problem:

[2022-04-22T19:13:11.972Z] STDOUT:
[2022-04-22T19:13:11.972Z] Warning: 'NoSuchMethodError' on register of sun.hotspot.WhiteBox::NMTNewArena(J)J
[2022-04-22T19:13:11.972Z] Warning: 'NoSuchMethodError' on register of sun.hotspot.WhiteBox::NMTFreeArena(J)V
[2022-04-22T19:13:11.972Z] Warning: 'NoSuchMethodError' on register of sun.hotspot.WhiteBox::NMTArenaMalloc(JJ)V
[2022-04-22T19:13:11.972Z] Timeout refired 960 times

[sophia-guo]

same on jdk8 linxu-aarch64

[sophia-guo]

same jdk8 linux-x64 https://ci.adoptopenjdk.net/job/Test_openjdk8_hs_extended.openjdk_x86-64_linux_testList_2/40/

[roberttoyonaga]

The problem is that the test times-out waiting for the compilation of the test methods.
When I exclude all other methods from compilation, it passes fine.

-XX:CompileOnly=jdk.jfr.event.compiler.TestCompilerCompile::dummyMethod,jdk.jfr.event.compiler.TestCompilerCompile::doTest

I also tried reducing the compilation level to C1 only, and this also solved the problem. So basically it seems like the problem is that C2 is too slow in some configurations like Windows 32 bit.

I'll make a PR upstream to adjust the test case to focus on compiling only the methods it actually tests to avoid timing out.