JDK-6454193 : JTREG test bug: 'com/sun/jdi/RunToExit.java' fails with timeout
  • Type: Bug
  • Component: core-svc
  • Sub-Component: debugger
  • Affected Version: 5.0u22,6,6u5
  • Priority: P4
  • Status: Closed
  • Resolution: Fixed
  • OS: generic,linux
  • CPU: generic,x86
  • Submitted: 2006-07-28
  • Updated: 2011-04-19
  • Resolved: 2011-04-19
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 6 JDK 7
6u10Fixed 7 b22Fixed
Related Reports
Duplicate :  
JDK-6613408 - com/sun/jdi/RunToExit.java fails with timeout
Relates :  
JDK-6489232 - VM crashes after class class redefining (VM_Operation: change breakpoints)
Description
To reproduce:
ssh jtg-linux17.sfbay
cd /net/vmsqe.sfbay/export/weekly/mustang/results/1.6.0-rc-b92/ServerVM/RHAT4.0AS/comp/VM4/JDI_REGRESSION-27-WEEKLYmtg-VM4-ServerVM-comp-RHAT4.0AS-2006-07-27-15-27-49
sh rerun.sh
Test 
	'com/sun/jdi/RunToExit.java'
can't finish because of debuggee VM hangs, this is main thread dump obtained with jstack for debugeer VM: 

"MainThread" prio=10 tid=0x0812f000 nid=0x4d32 in Object.wait() [0xac6b7000..0xac6b7ea0]
   java.lang.Thread.State: WAITING (on object monitor)
        at java.lang.Object.wait(Native Method)
        - waiting on <0xad588870> (a java.lang.UNIXProcess)
        at java.lang.Object.wait(Object.java:485)
        at java.lang.UNIXProcess.waitFor(UNIXProcess.java:165)
        - locked <0xad588870> (a java.lang.UNIXProcess)
        at RunToExit.main(RunToExit.java:149)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:597)
        at com.sun.javatest.regtest.MainWrapper$MainThread.run(MainWrapper.java:82)
        at java.lang.Thread.run(Thread.java:619)

Thread dump for hanging debuggee VM:
JVM version is 1.6.0-rc-b93
Deadlock Detection:

No deadlocks found.

Thread 19771: (state = BLOCKED)


Thread 19770: (state = BLOCKED)
 - java.lang.Object.wait(long) @bci=0 (Interpreted frame)
 - java.lang.ref.ReferenceQueue.remove(long) @bci=44, line=116 (Interpreted frame)
 - java.lang.ref.ReferenceQueue.remove() @bci=2, line=132 (Interpreted frame)
 - java.lang.ref.Finalizer$FinalizerThread.run() @bci=3, line=159 (Interpreted frame)


Thread 19769: (state = BLOCKED)
 - java.lang.Object.wait(long) @bci=0 (Interpreted frame)
 - java.lang.Object.wait() @bci=2, line=485 (Interpreted frame)
 - java.lang.ref.Reference$ReferenceHandler.run() @bci=46, line=116 (Interpreted frame)


Thread 19767: (state = BLOCKED)
This test is also known as:

    closed/com/sun/jdi/RunToExit.java
Test 
    com/sun/jdi/BadHandshakeTest.java

fails intermittently in the same way.
Comments
EVALUATION In addition, the synch between the main thread and the IO reader thread isn't right which can cause the IO reader thread to read the first line of output from the debuggee and then do a notify() before the main thread has done a corresponding wait(). This leaves the test hung in the wait().
19-09-2007
SUGGESTED FIX See attached webrev for complete fix.
19-09-2007
SUGGESTED FIX For the test in 6489232, I made the following changes: ------- RetransformStress_Test.java ------- *** /tmp/geta22617 Tue Apr 10 23:08:24 2007 --- /tmp/getb22617 Tue Apr 10 23:08:24 2007 *************** *** 266,271 **** --- 266,272 ---- static class EventListener extends Thread { Event receivedEvent; + static volatile boolean vmStarted; public void run() { try { *************** *** 278,283 **** --- 279,288 ---- Event event = iterator.next(); receivedEvent = event; System.out.println("Event: " + event); + if (event instanceof VMStartEvent) { + vmStarted = true; + break; + } if (event instanceof VMDisconnectEvent) { vmDisconnected = true; break; *************** *** 348,353 **** --- 353,371 ---- ServerIOPipe pipe = new ServerIOPipe(); + // wait for VMStartEvent before resuming the debuggee VM + final int delay = 100; + int retryCount = (120 * 1000) / delay; // two minutes at most + while (!listener.vmStarted && retryCount > 0) { + try { + Thread.sleep(delay); + } catch (InterruptedException ie) { + } + retryCount--; + } + if (!listener.vmStarted) { + throw new Error("debuggee never issued VMStartEvent"); + } vm.resume(); String command = pipe.readln(); Similar changes should be made to RunToExit.java and any other JDI_REGRESSION or nsk.jdi test that makes a similar assumption about the first vm.resume() call.
11-04-2007
SUGGESTED FIX Fix the testcase to wait for the VMStart before doing a resume.
01-08-2006
EVALUATION It is a simple test bug. The test debugger does a resume independently of receiving a VMStart. Sometimes the debuggee gets the resume before it suspends itself for the VMStart,SUSPEND_ALL, leaving itself hung.
01-08-2006
EVALUATION This is a regression in b79. b78 works ok. b79 works ok if a b78 hotspot is used so it is probably not a hotspot problem. The timeout doesn't happen if the fix for 6401245: Small JDWP packets with the socket transport causes slow debugging on linux 2.6.15 kernel and newer is undone.
01-08-2006
EVALUATION The test hangs when the init thread, after having put the VMStart event on the queue, attempts to get the CommandCompleteLock so it can wait for the command thread to notifiy it that the command has been completed, AND the the command thread has already done this notification. IE, the init thread tries to lock the CommandCompleteLock and it never returns, no it never returns. When this hang occurs, the JDWP trace in the front-end shows the VMStart event coming in after the resume command has been sent out.
01-08-2006
EVALUATION linux-i586: b78 and earlier: test passes b79 and later: test usually fails solsparc32: b79: test passes
29-07-2006
EVALUATION The testcase debugger: - launches a debuggee with server=y,suspend=y,address=<some port> - starts a thread watching for stdout to appear from the debuggee. - waits for a notification from that thread that a msg from the debuggee has appeared - when this notification occurs: - attaches to the port - does a 'resume' on the debuggee - waits for the debuggee to die with a process.waitFor(). The debuggee - starts - starts listening on the specified port - writes the msg to stdout that the debugger is waiting for - when the debugger resumes the debuggee, the debuggee does a System.exit(0) This should cause the debuggee process to exit which should cause the debugger to finish the process.waitFor() which causes the test to pass. The test is failing because the process.waitFor() never returns - see the stack in the description. The stack shown for the debuggee doesn't show native frames so we can't tell just where the debuggee is. However, I have been able to repro this using the rerun.sh script shown and b92. Here is the jstack -m output: /net/koori.sfbay/onestop/jdk/6/promoted/rc/b93/binaries/linux-i586/bin/jstack -m 15143 Attaching to process ID 15143, please wait... Debugger attached successfully. Client compiler detected. JVM version is 1.6.0-rc-b92 Deadlock Detection: No deadlocks found. ----------------- 15146 ----------------- 0x008457a2 _dl_sysinfo_int80 + 0x2 0x062efc56 _ZN7Monitor4waitEbl + 0x76 0x063008a6 _ZN2os22pd_self_suspend_threadEP6Thread + 0x16 0x0637b55b _ZN10JavaThread17java_suspend_selfEv + 0xbb 0x0635a4fa _ZN13ObjectMonitor9raw_enterEP6Threadb + 0x2da 0x062ac7a6 _ZN8JvmtiEnv15RawMonitorEnterEP15JvmtiRawMonitor + 0x86 0x062a117e jvmti_RawMonitorEnter + 0x5e 0xb7f6f659 debugMonitorEnter + 0x39 0xb7f5d727 enqueueCommand + 0xe7 0xb7f54606 initialize + 0x376 0xb7f535cd cbEarlyVMInit + 0xad 0x062b3b7a _ZN11JvmtiExport19post_vm_initializedEv + 0xfa 0x0637d624 _ZN7Threads9create_vmEP14JavaVMInitArgsPb + 0x894 0x0622f300 JNI_CreateJavaVM + 0x60 0x0804afcc InitializeJVM + 0x5c 0x08049942 JavaMain + 0x72 0x00ab1371 start_thread + 0x81 ----------------- 15147 ----------------- 0x008457a2 _dl_sysinfo_int80 + 0x2 java.lang.NullPointerException at sun.jvm.hotspot.tools.PStack.printUnknown(PStack.java:207) at sun.jvm.hotspot.tools.PStack.run(PStack.java:130) at sun.jvm.hotspot.tools.PStack.run(PStack.java:36) at sun.jvm.hotspot.tools.PStack.run(PStack.java:31) at sun.jvm.hotspot.tools.JStack.run(JStack.java:43) at sun.jvm.hotspot.tools.Tool.start(Tool.java:204) at sun.jvm.hotspot.tools.JStack.main(JStack.java:69) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:597) at sun.tools.jstack.JStack.runJStackTool(JStack.java:118) at sun.tools.jstack.JStack.main(JStack.java:84) ----------------- 15148 ----------------- 0x008457a2 _dl_sysinfo_int80 + 0x2 0x06301379 _ZN2os13PlatformEvent4parkEv + 0xb9 0x06359565 _ZN13ObjectMonitor4waitExbP6Thread + 0x615 0x06356dcf _ZN18ObjectSynchronizer4waitE6HandlexP6Thread + 0x3f 0x062588ea JVM_MonitorWait + 0x1da 0xb5ce55ae * java.lang.Object.wait(long) bci:0 (Interpreted frame) 0xb5cd8e9d * java.lang.Object.wait() bci:2 line:485 (Interpreted frame) 0xb5cd8e9d * java.lang.ref.Reference$ReferenceHandler.run() bci:46 line:116 (Interpreted frame) 0xb5cd6207 <StubRoutines> 0x062066bd _ZN9JavaCalls11call_helperEP9JavaValueP12methodHandleP17JavaCallArgumentsP6Thread + 0x15d 0x063008c8 _ZN2os20os_exception_wrapperEPFvP9JavaValueP12methodHandleP17JavaCallArgumentsP6ThreadES1_S3_S5_S7_ + 0x18 0x06205fd0 _ZN9JavaCalls12call_virtualEP9JavaValue11KlassHandle12symbolHandleS3_P17JavaCallArgumentsP6Thread + 0xa0 0x0620605d _ZN9JavaCalls12call_virtualEP9JavaValue6Handle11KlassHandle12symbolHandleS4_P6Thread + 0x5d 0x06276215 _Z12thread_entryP10JavaThreadP6Thread + 0x75 0x0637a13f _ZN10JavaThread3runEv + 0x10f 0x063017a3 _Z10java_startP6Thread + 0x123 0x00ab1371 start_thread + 0x81 ----------------- 15149 ----------------- 0x008457a2 _dl_sysinfo_int80 + 0x2 0x06301379 _ZN2os13PlatformEvent4parkEv + 0xb9 0x06359565 _ZN13ObjectMonitor4waitExbP6Thread + 0x615 0x06356dcf _ZN18ObjectSynchronizer4waitE6HandlexP6Thread + 0x3f 0x062588ea JVM_MonitorWait + 0x1da 0xb5ce55ae * java.lang.Object.wait(long) bci:0 (Interpreted frame) 0xb5cd8e9d * java.lang.ref.ReferenceQueue.remove(long) bci:44 line:116 (Interpreted frame) 0xb5cd8d37 * java.lang.ref.ReferenceQueue.remove() bci:2 line:132 (Interpreted frame) 0xb5cd8d37 * java.lang.ref.Finalizer$FinalizerThread.run() bci:3 line:159 (Interpreted frame) 0xb5cd6207 <StubRoutines> 0x062066bd _ZN9JavaCalls11call_helperEP9JavaValueP12methodHandleP17JavaCallArgumentsP6Thread + 0x15d 0x063008c8 _ZN2os20os_exception_wrapperEPFvP9JavaValueP12methodHandleP17JavaCallArgumentsP6ThreadES1_S3_S5_S7_ + 0x18 0x06205fd0 _ZN9JavaCalls12call_virtualEP9JavaValue11KlassHandle12symbolHandleS3_P17JavaCallArgumentsP6Thread + 0xa0 0x0620605d _ZN9JavaCalls12call_virtualEP9JavaValue6Handle11KlassHandle12symbolHandleS4_P6Thread + 0x5d 0x06276215 _Z12thread_entryP10JavaThreadP6Thread + 0x75 0x0637a13f _ZN10JavaThread3runEv + 0x10f 0x063017a3 _Z10java_startP6Thread + 0x123 0x00ab1371 start_thread + 0x81 ----------------- 15150 ----------------- 0x008457a2 _dl_sysinfo_int80 + 0x2 0x062efc56 _ZN7Monitor4waitEbl + 0x76 0x063008a6 _ZN2os22pd_self_suspend_threadEP6Thread + 0x16 0x0637b55b _ZN10JavaThread17java_suspend_selfEv + 0xbb 0x06301b3b _Z21check_pending_signalsb + 0x12b 0x062ff13d _ZN2os11signal_waitEv + 0xd 0x062fc4b8 _Z19signal_thread_entryP10JavaThreadP6Thread + 0x28 0x0637a13f _ZN10JavaThread3runEv + 0x10f 0x063017a3 _Z10java_startP6Thread + 0x123 0x00ab1371 start_thread + 0x81 ----------------- 15151 ----------------- 0x008457a2 _dl_sysinfo_int80 + 0x2 0x06301379 _ZN2os13PlatformEvent4parkEv + 0xb9 0x0635a0ff _ZN13ObjectMonitor10SimpleWaitEP6Threadx + 0x24f 0x0635a68e _ZN13ObjectMonitor8raw_waitExbP6Thread + 0xce 0x062ac945 _ZN8JvmtiEnv14RawMonitorWaitEP15JvmtiRawMonitorx + 0x55 0x062a1313 jvmti_RawMonitorWait + 0x73 0xb7f6f816 debugMonitorWait + 0x46 0xb7f56362 dequeue + 0x92 0xb7f55e08 debugLoop_run + 0x78 0xb7f6ac65 connectionInitiated + 0x75 0xb7f6aef0 acceptThread + 0x170 0x062bb83f _ZN16JvmtiAgentThread22start_function_wrapperEP10JavaThreadP6Thread + 0x5f 0x0637a13f _ZN10JavaThread3runEv + 0x10f 0x063017a3 _Z10java_startP6Thread + 0x123 0x00ab1371 start_thread + 0x81 ----------------- 15152 ----------------- 0x008457a2 _dl_sysinfo_int80 + 0x2 0x06301379 _ZN2os13PlatformEvent4parkEv + 0xb9 0x0635a0ff _ZN13ObjectMonitor10SimpleWaitEP6Threadx + 0x24f 0x0635a68e _ZN13ObjectMonitor8raw_waitExbP6Thread + 0xce 0x062ac945 _ZN8JvmtiEnv14RawMonitorWaitEP15JvmtiRawMonitorx + 0x55 0x062a1313 jvmti_RawMonitorWait + 0x73 0xb7f6f816 debugMonitorWait + 0x46 0xb7f5d8fe dequeueCommand + 0x4e 0xb7f5ea85 commandLoop + 0x65 0x062bb83f _ZN16JvmtiAgentThread22start_function_wrapperEP10JavaThreadP6Thread + 0x5f 0x0637a13f _ZN10JavaThread3runEv + 0x10f 0x063017a3 _Z10java_startP6Thread + 0x123 0x00ab1371 start_thread + 0x81 ----------------- 15155 ----------------- 0x008457a2 _dl_sysinfo_int80 + 0x2 0xad8b1f34 recv_fully + 0x54 0xad8b1f92 socketTransport_readPacket + 0x42 0xb7f6b6df transport_receivePacket + 0x2f 0xb7f56078 reader + 0x38 0x062bb83f _ZN16JvmtiAgentThread22start_function_wrapperEP10JavaThreadP6Thread + 0x5f 0x0637a13f _ZN10JavaThread3runEv + 0x10f 0x063017a3 _Z10java_startP6Thread + 0x123 0x00ab1371 start_thread + 0x81 ----------------- 15143 ----------------- 0x008457a2 _dl_sysinfo_int80 + 0x2 0x0804dce8 ContinueInNewThread + 0x88 0x080497f6 main + 0x276 0x00876e23 __libc_start_main + 0xd3
28-07-2006