aqa-tests icon indicating copy to clipboard operation
aqa-tests copied to clipboard

Published 20 hours ago • verified publisher icon adoptium

JFR TestCompilerCompile times out on Windows 32

Open karianna opened this issue 4 years ago • 7 comments

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

karianna avatar Oct 20 '21 12:10 karianna

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

smlambert avatar Oct 20 '21 14:10 smlambert

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

karianna avatar Oct 20 '21 14:10 karianna

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

smlambert avatar Apr 28 '22 00:04 smlambert

same on jdk8 linxu-aarch64

sophia-guo avatar May 16 '22 15:05 sophia-guo

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

sophia-guo avatar May 20 '22 14:05 sophia-guo

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.

roberttoyonaga avatar Feb 21 '24 19:02 roberttoyonaga

JDK PR suggesting fix: https://github.com/openjdk/jdk/pull/18010 JBS ticket for the problem: https://bugs.openjdk.org/browse/JDK-8326529

roberttoyonaga avatar Feb 26 '24 16:02 roberttoyonaga