JDK-8210220 : [AOT] jdwp test cases are failing with error # ERROR: TEST FAILED: Cought IOException while receiving event packet: # ERROR: java.net.SocketTimeoutException: Read timed out
  • Type: Bug
  • Component: hotspot
  • Sub-Component: compiler
  • Affected Version: 10,11,12
  • Priority: P3
  • Status: Resolved
  • Resolution: Fixed
  • Submitted: 2018-08-30
  • Updated: 2019-12-03
  • Resolved: 2018-09-13
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 11 JDK 12
11.0.7-oracleFixed 12 b12Fixed
Related Reports
Duplicate :  
Duplicate :  
Description
please check comments section for steps to reproduce
Comments
Fix request (11u) I would like to downport this for parity with 11.0.7-oracle. Applies clean
29-11-2019

Added NoSafepointVerifier to publish_aot() method: http://cr.openjdk.java.net/~kvn/8210220/webrev.01/
13-09-2018

http://cr.openjdk.java.net/~kvn/8210220/webrev.00/
12-09-2018

All listed tests passed with next fix: diff -r 1ddf9a99e4ad src/hotspot/share/aot/aotCodeHeap.cpp --- a/src/hotspot/share/aot/aotCodeHeap.cpp +++ b/src/hotspot/share/aot/aotCodeHeap.cpp @@ -298,7 +298,10 @@ void AOTCodeHeap::publish_aot(const methodHandle& mh, AOTMethodData* method_data, int code_id) { // The method may be explicitly excluded by the user. // Or Interpreter uses an intrinsic for this method. - if (CompilerOracle::should_exclude(mh) || !AbstractInterpreter::can_be_compiled(mh)) { + // Or method has breakpoints. + if (CompilerOracle::should_exclude(mh) || + !AbstractInterpreter::can_be_compiled(mh) || + (mh->number_of_breakpoints() > 0)) { return; }
12-09-2018

The issue is that we load AOT klasses and their methods only during klass initialization - just before it calls <clinit>. It seems it is allowed to set breakpoint before that - klass needs to be loaded only. The solution is to check method()->number_of_breakpoints() before registering AOT method for it.
12-09-2018

Test class indeed is loaded before breakpoint: [0.639s][info ][class,load ] javasoft.sqe.tests.vm.jdwp.ObjectReference.InvokeMethod.invokemeth001a$TestedObjectClass source: file:/export/kvn/jck_bugs/8210220/JCK-runtime-11/classes/ === called flush_dependents_on_method() === javasoft.sqe.tests.vm.jdwp.ObjectReference.InvokeMethod.invokemeth001a$TestedObjectClass::run
12-09-2018

We do deoptimize registerd (active) aot methods on the moment breakpoint is set. But for some reasons test class TestedObjectClass and its aot methods are loaded after that: [0.603s][trace][aot,class,load] found javasoft.sqe.tests.vm.jdwp.ObjectReference.InvokeMethod.invokemeth001a in solibs/libjcktestvm3.so for classloader 0x7febec64d840 tid=0x00007febec01d000 603 1 aot[ 1] javasoft.sqe.tests.vm.jdwp.ObjectReference.InvokeMethod.invokemeth001a.<init>()V 603 2 aot[ 1] javasoft.sqe.tests.vm.jdwp.ObjectReference.InvokeMethod.invokemeth001a.runIt([Ljava/lang/String;Ljava/io/PrintStream;)I 603 3 aot[ 1] javasoft.sqe.tests.vm.jdwp.ObjectReference.InvokeMethod.invokemeth001a.<clinit>()V 603 4 aot[ 1] javasoft.sqe.tests.vm.jdwp.ObjectReference.InvokeMethod.invokemeth001a.main([Ljava/lang/String;)V === called flush_dependents_on_method() === === found aot methods for deoptimization === 646 1 aot[ 1] javasoft.sqe.tests.vm.jdwp.ObjectReference.InvokeMethod.invokemeth001a.<init>()V made not entrant 646 2 aot[ 1] javasoft.sqe.tests.vm.jdwp.ObjectReference.InvokeMethod.invokemeth001a.runIt([Ljava/lang/String;Ljava/io/PrintStream;)I made not entrant 646 3 aot[ 1] javasoft.sqe.tests.vm.jdwp.ObjectReference.InvokeMethod.invokemeth001a.<clinit>()V made not entrant 646 4 aot[ 1] javasoft.sqe.tests.vm.jdwp.ObjectReference.InvokeMethod.invokemeth001a.main([Ljava/lang/String;)V made not entrant === exit flush_dependents_on_method() === [0.647s][trace][aot,class,load] found javasoft.sqe.tests.vm.jdwp.ObjectReference.InvokeMethod.invokemeth001a$TestedObjectClass in solibs/libjcktestvm3.so for classloader 0x7febec64d840 tid=0x00007febec01d000 647 5 aot[ 1] javasoft.sqe.tests.vm.jdwp.ObjectReference.InvokeMethod.invokemeth001a$TestedObjectClass.<init>()V 647 6 aot[ 1] javasoft.sqe.tests.vm.jdwp.ObjectReference.InvokeMethod.invokemeth001a$TestedObjectClass.pubm(I)I 647 7 aot[ 1] javasoft.sqe.tests.vm.jdwp.ObjectReference.InvokeMethod.invokemeth001a$TestedObjectClass.privm(I)I 647 8 aot[ 1] javasoft.sqe.tests.vm.jdwp.ObjectReference.InvokeMethod.invokemeth001a$TestedObjectClass.protm(I)I 647 9 aot[ 1] javasoft.sqe.tests.vm.jdwp.ObjectReference.InvokeMethod.invokemeth001a$TestedObjectClass.run()V 647 10 aot[ 1] javasoft.sqe.tests.vm.jdwp.ObjectReference.InvokeMethod.invokemeth001a$TestedObjectClass.m(I)I
12-09-2018

For some reasons we don't deoptimize aot methods when debugger sets break point in java methods.
12-09-2018

Looks like vm/jdwp/Method/IsObsolete/isobsolete002/ crash is covered by JDK-8210256. I will concentrate on hang in vm/jdwp/ClassType/NewInstance/newinst001 test.
11-09-2018

Main thread is waiting: "main" #1 prio=5 os_prio=0 cpu=570.15ms elapsed=723.45s allocated=2141K defined_classes=1067 tid=0x00007f2ba801c800 nid=0x4d726 in Object.wait() [0x00007f2bb18ba000] java.lang.Thread.State: TIMED_WAITING (on object monitor) JavaThread state: _thread_blocked Thread: 0x00007f2ba801c800 [0x4d726] State: _at_safepoint _has_called_back 0 _at_poll_safepoint 0 JavaThread state: _thread_blocked at java.lang.Object.wait(java.base@11-internal/Native Method) - waiting on <0x0000000457b844d8> (a java.util.Vector) at javasoft.sqe.jck.lib.jpda.common.MsgSwitchIOPipe.readHandledMsg(MsgSwitchIOPipe.java:86) - waiting to re-lock in wait() <0x0000000457b844d8> (a java.util.Vector) at javasoft.sqe.jck.lib.jpda.common.MsgSwitchIOPipe.readln(MsgSwitchIOPipe.java:76) at javasoft.sqe.jck.lib.jpda.common.DebugeeArgumentHandler.waitForDebuggerPrepared(DebugeeArgumentHandler.java:425) at javasoft.sqe.jck.lib.jpda.jdwp.DebuggeeLoader.createDebuggeeInstance(DebuggeeLoader.java:72) at javasoft.sqe.jck.lib.jpda.jdwp.DebuggeeLoader.run(DebuggeeLoader.java:30) at javasoft.sqe.jck.lib.jpda.jdwp.DebuggeeLoader.main(DebuggeeLoader.java:19)
11-09-2018

I only next thead (with 'jstack') which run: "MessageClient" #28 prio=5 os_prio=0 cpu=1.33ms elapsed=509.96s allocated=392B defined_classes=0 tid=0x00007f2ba8794000 nid=0x4d73d runnable [0x00007f2b4107a000] java.lang.Thread.State: RUNNABLE JavaThread state: _thread_in_native Thread: 0x00007f2ba8794000 [0x4d73d] State: _at_safepoint _has_called_back 0 _at_poll_safepoint 0 JavaThread state: _thread_in_native at java.net.SocketInputStream.socketRead0(java.base@11-internal/Native Method) at java.net.SocketInputStream.socketRead(java.base@11-internal/SocketInputStream.java:115) at java.net.SocketInputStream.read(java.base@11-internal/SocketInputStream.java:168) at java.net.SocketInputStream.read(java.base@11-internal/SocketInputStream.java:140) at java.io.BufferedInputStream.fill(java.base@11-internal/BufferedInputStream.java:252) at java.io.BufferedInputStream.read(java.base@11-internal/BufferedInputStream.java:271) - locked <0x000000045751dcd8> (a java.io.BufferedInputStream) at java.io.DataInputStream.readByte(java.base@11-internal/DataInputStream.java:270) at com.sun.jck.lib.MessageClient.run(MessageClient.java:114) at java.lang.Thread.run(java.base@11-internal/Thread.java:834)
11-09-2018

I tried to reproduce it and only next 2 tests were run: Passed: vm/jdwp/Method/IsObsolete/isobsolete002/isobsolete002.html Passed: vm/jdwp/ClassType/NewInstance/newinst001/newinst001.html They passed with one java.base AOT library (rameshbase.so). Tests failed with additional libjcktestvm3.so AOT lib: Test Method.IsObsolete.isobsolete002a crashed in AOT compiled method: A 6 javasoft.sqe.tests.vm.jdwp.Method.IsObsolete.isobsolete002b.testedMethod(I)V (11 bytes) @ 0x00007f88ddd19914 [0x00007f88ddd198a0+0x0000000000000074] j javasoft.sqe.tests.vm.jdwp.Method.IsObsolete.isobsolete002a.runIt([Ljava/lang/String;Ljava/io/PrintStream;)I+53 j javasoft.sqe.jck.lib.jpda.jdwp.DebuggeeTest.run([Ljava/lang/String;Ljava/io/PrintStream;)I+67 And ClassType.NewInstance.newinst001a hangs and I am still do not know where.
11-09-2018

Okay, thanks for verification. Vladimir, I'm assigning this to you. Please take a look or re-assign. Thanks!
31-08-2018

Hi Tobias, I have cross verified by re-running tests, there were no hs_err files. VM is still running root 130990 130869 4 15:55 pts/3 00:00:00 /scratch/export/home/aginfra/Desktop/ramesh/jdk-11/bin/java -XX:+UnlockDiagnosticVMOptions -XX:+UseAOTStrictLoading -XX:AOTLibrary=solibs/rameshbase.so,solibs/libjcktestvm3.so -XX:+PrintAOT --add-modules=java.base,java.datatransfer,java.instrument,java.logging,java.management,java.management.rmi,java.naming,java.prefs,java.rmi,java.scripting,java.se,java.security.jgss,java.security.sasl,java.xml,java.xml.crypto --add-exports=java.xml.crypto/org.jcp.xml.dsig.internal.dom=ALL-UNNAMED -Djdk.attach.allowAttachSelf=true -Xfuture -agentlib:jdwp=server=y,transport=dt_socket,address=llg00fyn.uk.oracle.com:54600,suspend=n -classpath /scratch/export/home/aginfra/Desktop/ramesh/JCK-runtime-11/classes::/scratch/export/home/aginfra/Desktop/ramesh/JCK-runtime-11/lib/extensions/JCK-extensions.jar:/scratch/export/home/aginfra/Desktop/ramesh/JCK-runtime-11/lib/extensions/JCK-extensions.jar -Djava.security.policy=/scratch/export/home/aginfra/Desktop/ramesh/JCK-runtime-11/lib/jck.policy javasoft.sqe.jck.lib.jpda.jdwp.DebuggeeLoader -waittime=1200 -msgSwitch=llg00fyn:26355 -componentName=ClassType.InvokeMethod.invokemeth001 -debuggeeName=ClassType.InvokeMethod.invokemeth001a root 130902 130869 6 15:55 pts/3 00:00:01 /scratch/export/home/aginfra/Desktop/ramesh/jdk-11/bin/java -Xss1m -Xms32m -Xmx512m -cp /scratch/export/home/aginfra/Desktop/ramesh/JCK-runtime-11/lib/javatest.jar:/scratch/export/home/aginfra/Desktop/ramesh/JCK-runtime-11/classes:/scratch/export/home/aginfra/Desktop/ramesh/JCK-runtime-11/lib/jtjck.jar:/scratch/export/home/aginfra/Desktop/ramesh/JCK-runtime-11/lib/extensions/JCK-extensions.jar -Djava.security.policy=/scratch/export/home/aginfra/Desktop/ramesh/JCK-runtime-11/lib/jck.policy -Djavatest.security.allowPropertiesAccess=true com.sun.javatest.agent.AgentMain -passivePort 17295 [root@llg00fyn ramesh]# netstat | grep 54600 tcp 0 0 llg00fyn.uk.oracl:54600 llg00fyn.uk.oracl:62338 ESTABLISHED tcp6 0 0 llg00fyn.uk.oracl:62338 llg00fyn.uk.oracl:54600 ESTABLISHED Also i can see log info DEBUGEE PASSED.
30-08-2018

Okay, thanks. Have you checked if the debuggee VM is still running (maybe there is even an hs_err file)? Maybe it crashed and that's why the debugger VM times out.
30-08-2018

Ramesh, could you please provide more information? Is the exception thrown because there is really a timeout (execution with AOT code is slower?) or is there another root cause hiding behind that exception (debuggee VM crashed)? Pre-ILW = Incorrect execution (exception thrown), with AOT compiled code, don't use AOT = HLM = P3
30-08-2018