JDK-8202975 : src/jdk/nashorn/internal/runtime/doubleconv/test/BignumTest.java failed with Agent communication error
  • Type: Bug
  • Component: core-libs
  • Sub-Component: jdk.nashorn
  • Affected Version: 11
  • Priority: P4
  • Status: Resolved
  • Resolution: Won't Fix
  • OS: solaris
  • CPU: sparc_64
  • Submitted: 2018-05-11
  • Updated: 2024-02-12
  • Resolved: 2019-01-15
Related Reports
Relates :  
Relates :  
Description
src/jdk/nashorn/internal/runtime/doubleconv/test/BignumTest.java failed, error message in testlog:
result: Error. Agent communication error: java.net.SocketTimeoutException: Read timed out; check console log for any additional details

stdout and stderr from task workdir are attached.

There's nothing in test workdir.
Comments
Nashorn is deprecated.
15-01-2019

Here's a snippet of the log file (still running with -Xcomp): #section:testng ----------messages:(6/343)---------- command: testng jdk.nashorn.internal.runtime.doubleconv.test.BignumTest reason: User specified action: run testng jdk.nashorn.internal.runtime.doubleconv.test.BignumTest Mode: agentvm Agent id: 19 Additional opens to unnamed modules from @modules: jdk.scripting.nashorn/jdk.nashorn.internal.runtime.doubleconv elapsed time (seconds): 383.318 ----------configuration:(12/1235)---------- Boot Layer class path: /scratch/opt/mach5/mesos/work_dir/jib-master/install/java/re/jtreg/4.2/promoted/all/b12/bundles/jtreg_bin-4.2.zip/jtreg/lib/testng.jar /scratch/opt/mach5/mesos/work_dir/jib-master/install/java/re/jtreg/4.2/promoted/all/b12/bundles/jtreg_bin-4.2.zip/jtreg/lib/javatest.jar /scratch/opt/mach5/mesos/work_dir/jib-master/install/java/re/jtreg/4.2/promoted/all/b12/bundles/jtreg_bin-4.2.zip/jtreg/lib/jtreg.jar patch: java.base /scratch/opt/mach5/mesos/work_dir/4382bb2f-3a1d-4aeb-b340-ecabc9bb47bb/testoutput/jtreg/JTwork/patches/java.base Test Layer add opens: jdk.scripting.nashorn/jdk.nashorn.internal.runtime.doubleconv ALL-UNNAMED class path: /scratch/opt/mach5/mesos/work_dir/4382bb2f-3a1d-4aeb-b340-ecabc9bb47bb/testoutput/jtreg/JTwork/classes/4/src/jdk/nashorn/internal/runtime/doubleconv/test/BignumTest.d /scratch/opt/mach5/mesos/work_dir/jib-master/install/jdk11-jdk.1156/src.full/open/test/nashorn/src/jdk/nashorn/internal/runtime/doubleconv/test /scratch/opt/mach5/mesos/work_dir/jib-master/install/com/oracle/java/jib/jib/3.0-SNAPSHOT/jib-3.0-SNAPSHOT-distribution.zip/jib-3.0-SNAPSHOT-distribution/lib/jib-3.0-SNAPSHOT.jar ----------rerun:(30/3929)*---------- cd /scratch/opt/mach5/mesos/work_dir/4382bb2f-3a1d-4aeb-b340-ecabc9bb47bb/testoutput/jtreg/JTwork/scratch/11 && \\ CPAPPEND=/scratch/opt/mach5/mesos/work_dir/jib-master/install/com/oracle/java/jib/jib/3.0-SNAPSHOT/jib-3.0-SNAPSHOT-distribution.zip/jib-3.0-SNAPSHOT-distribution/lib/jib-3.0-SNAPSHOT.jar \\ HOME=/var/tmp/sparky-temp-home-5860292827172113949/user_home \\ JDK8_HOME=/scratch/opt/mach5/mesos/work_dir/jib-master/install/jdk/10/46/bundles/solaris-sparcv9/jdk-10_solaris-sparcv9_bin.tar.gz/jdk-10 \\ JIB_DATA_DIR=/scratch/opt/mach5/mesos/work_dir/jib-master \\ JTREG_SHOWAGENT=true \\ JTREG_TIMEOUT_OPTION=-timeoutFactor:10 \\ JTREG_VERBOSE=fail,error,time \\ LANG=en_US.UTF-8 \\ LC_ALL= \\ LC_CTYPE= \\ PATH=/bin:/usr/bin \\ TEST_IMAGE_GRAAL_DIR=/scratch/opt/mach5/mesos/work_dir/jib-master/install/jdk11-jdk.1156/solaris-sparcv9-debug.test/hotspot/jtreg/graal \\ TZ=UTC \\ /scratch/opt/mach5/mesos/work_dir/jib-master/install/jdk11-jdk.1156/solaris-sparcv9-debug.jdk/jdk-11/fastdebug/bin/java \\ -Dtest.class.path.prefix=/scratch/opt/mach5/mesos/work_dir/4382bb2f-3a1d-4aeb-b340-ecabc9bb47bb/testoutput/jtreg/JTwork/classes/4/src/jdk/nashorn/internal/runtime/doubleconv/test/BignumTest.d:/scratch/opt/mach5/mesos/work_dir/jib-master/install/jdk11-jdk.1156/src.full/open/test/nashorn/src/jdk/nashorn/internal/runtime/doubleconv/test \\ -Dtest.src=/scratch/opt/mach5/mesos/work_dir/jib-master/install/jdk11-jdk.1156/src.full/open/test/nashorn/src/jdk/nashorn/internal/runtime/doubleconv/test \\ -Dtest.src.path=/scratch/opt/mach5/mesos/work_dir/jib-master/install/jdk11-jdk.1156/src.full/open/test/nashorn/src/jdk/nashorn/internal/runtime/doubleconv/test \\ -Dtest.classes=/scratch/opt/mach5/mesos/work_dir/4382bb2f-3a1d-4aeb-b340-ecabc9bb47bb/testoutput/jtreg/JTwork/classes/4/src/jdk/nashorn/internal/runtime/doubleconv/test/BignumTest.d \\ -Dtest.class.path=/scratch/opt/mach5/mesos/work_dir/4382bb2f-3a1d-4aeb-b340-ecabc9bb47bb/testoutput/jtreg/JTwork/classes/4/src/jdk/nashorn/internal/runtime/doubleconv/test/BignumTest.d \\ -Dtest.vm.opts='-XX:MaxRAMPercentage=2 -ea -esa -Xmx512m' \\ -Dtest.tool.vm.opts='-J-XX:MaxRAMPercentage=2 -J-ea -J-esa -J-Xmx512m' \\ -Dtest.compiler.opts= \\ -Dtest.java.opts='-Xcomp -XX:+CreateCoredumpOnCrash -ea -esa -XX:CompileThreshold=100 -XX:+UnlockExperimentalVMOptions -server -XX:+TieredCompilation' \\ -Dtest.jdk=/scratch/opt/mach5/mesos/work_dir/jib-master/install/jdk11-jdk.1156/solaris-sparcv9-debug.jdk/jdk-11/fastdebug \\ -Dcompile.jdk=/scratch/opt/mach5/mesos/work_dir/jib-master/install/jdk11-jdk.1156/solaris-sparcv9-debug.jdk/jdk-11/fastdebug \\ -Dtest.timeout.factor=10.0 \\ -Dtest.modules=jdk.scripting.nashorn/jdk.nashorn.internal.runtime.doubleconv:open \\ -classpath /scratch/opt/mach5/mesos/work_dir/4382bb2f-3a1d-4aeb-b340-ecabc9bb47bb/testoutput/jtreg/JTwork/classes/4/src/jdk/nashorn/internal/runtime/doubleconv/test/BignumTest.d:/scratch/opt/mach5/mesos/work_dir/jib-master/install/jdk11-jdk.1156/src.full/open/test/nashorn/src/jdk/nashorn/internal/runtime/doubleconv/test:/scratch/opt/mach5/mesos/work_dir/jib-master/install/java/re/jtreg/4.2/promoted/all/b12/bundles/jtreg_bin-4.2.zip/jtreg/lib/testng.jar:/scratch/opt/mach5/mesos/work_dir/jib-master/install/com/oracle/java/jib/jib/3.0-SNAPSHOT/jib-3.0-SNAPSHOT-distribution.zip/jib-3.0-SNAPSHOT-distribution/lib/jib-3.0-SNAPSHOT.jar:/scratch/opt/mach5/mesos/work_dir/jib-master/install/java/re/jtreg/4.2/promoted/all/b12/bundles/jtreg_bin-4.2.zip/jtreg/lib/javatest.jar:/scratch/opt/mach5/mesos/work_dir/jib-master/install/java/re/jtreg/4.2/promoted/all/b12/bundles/jtreg_bin-4.2.zip/jtreg/lib/jtreg.jar \\ com.sun.javatest.regtest.agent.TestNGRunner src/jdk/nashorn/internal/runtime/doubleconv/test/BignumTest.java false jdk.nashorn.internal.runtime.doubleconv.test.BignumTest result: Error. Agent communication error: java.net.SocketTimeoutException: Read timed out; check console log for any additional details test result: Error. Agent communication error: java.net.SocketTimeoutException: Read timed out; check console log for any additional details
07-08-2018

Another observation with -Xint -ea -esa (instead of -Xcomp) test passed in 3 sec on SPARC and about the same number of initialized classes: [3.639s][info][class,init] 1213 Initializing 'org/testng/SuiteResultCounts'(no method) (0x00000007c0118298) =============================================== src/jdk/nashorn/internal/runtime/doubleconv/test/BignumTest.java Total tests run: 13, Failures: 0, Skips: 0 May be we should not run it with -Xcomp indeed.
10-07-2018

ON SPARC test initialize 300 more classes: [128.504s][info][class,init] 1235 Initializing 'org/testng/SuiteResultCounts'(no method) (0x00000007c0120868) =============================================== src/jdk/nashorn/internal/runtime/doubleconv/test/BignumTest.java Total tests run: 13, Failures: 0, Skips: 0 On x86" [26.215s][info][class,init] 946 Initializing 'org/testng/SuiteResultCounts'(no method) (0x00000001000d8868) =============================================== src/jdk/nashorn/internal/runtime/doubleconv/test/BignumTest.java Total tests run: 13, Failures: 0, Skips: 0
10-07-2018

Note, SunPKCS11 is used only on Solaris. On Intel other provider is used. That may be why we see the issue only on SPARC.
10-07-2018

Uncommon trap is generated for next bytecode which access static field 'descriptors' because it compiler think that SunPKCS11 is not initialized? 23 getstatic 158 <sun/security/pkcs11/SunPKCS11.descriptors/Ljava/util/Map;> I waited until test successfully finished and uncommon trap was never removed. Interestingly looking on sun.security.pkcs11.SunPKCS11 <clinit> compilation and after 70 sec it is still not loaded. What?
10-07-2018

Also test passed when I added /timeout=600
10-07-2018

May be we should not run these tests with -Xcomp.
10-07-2018

I see next method deoptimized at the same BCI (23) and recompiled a lot : <jvms bci='23' method='sun.security.pkcs11.SunPKCS11 register (Lsun/security/pkcs11/SunPKCS11$Descriptor;)V' bytes='79' count='1' backedge_count='4' iicount='36' decompiles='46' unloaded_traps='1' uninitialized_traps='45'/> But it is normal that we have a lot of deoptimizations when we compile with -Xcomp on first invocation when code is not executed before.
10-07-2018

Seems we are filing a lot of bugs for this timeout issue when it occurs during different tests. We also have JDK-8205389, JDK-8205532, and JDK-8205463. There's also other tests failing besides BignumTest.java and ExceptionTests.java. This is a query for finding CI test failures that failed with "Read timed out" http://java.se.oracle.com:10065/mdash/testHistory?page=11&search=status%3Afailed+AND+reasons.details%3A%2ARead%3Ftimed%3Fout%2A+AND+task%3A%28jobId%3Amach5-one-jdk11-%2A%29 All of them are on solaris-sparc.
26-06-2018

Is this a one-time failure or does it fail consistently? The SocketTimeoutException looks very much like a problem in the testing framework/infrastructure.
14-05-2018