JDK-6902121 : intermittent JdbMethodExitTest timeout
  • Type: Bug
  • Component: hotspot
  • Sub-Component: jvmti
  • Affected Version: hs17,hs24,9
  • Priority: P4
  • Status: Closed
  • Resolution: Cannot Reproduce
  • OS: solaris_10
  • CPU: x86
  • Submitted: 2009-11-17
  • Updated: 2023-12-13
  • Resolved: 2016-12-14
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.
Other
tbdResolved
Related Reports
Duplicate :  
Relates :  
Description
During my baseline testing of the following JDK promotion:

    java version "1.7.0-ea"
    Java(TM) SE Runtime Environment (build 1.7.0-ea-b76)
    Java HotSpot(TM) Server VM (build 17.0-b05, mixed mode)

the following JDI_REGRESSION test timed out:

RULE com/sun/jdi/JdbMethodExitTest.sh Timeout any

on my Solaris X86 test machine:

    % uname -a
    SunOS oliver-gs 5.10 Generic_137138-09 i86pc i386 i86pc
    % psrinfo -v
    Status of virtual processor 0 as of: 11/17/2009 10:19:53
      on-line since 10/03/2009 21:14:48.
      The i386 processor operates at 2800 MHz,
        and has an i387 compatible floating point processor.
    Status of virtual processor 1 as of: 11/17/2009 10:19:53
      on-line since 10/03/2009 21:15:03.
      The i386 processor operates at 2800 MHz,
        and has an i387 compatible floating point processor.

The .jtr timestamps show the previous tests and following
tests executed quickly:

-rw-rw-r--   1 dcubed   green       1628 Nov 13 18:20 JdbArgTest.jtr
-rw-rw-r--   1 dcubed   green       3347 Nov 13 18:20 JdbLockTest.jtr
drwxrwxr-x   2 dcubed   green        512 Nov 13 18:20 JdbMethodExitTest/
-rw-rw-r--   1 dcubed   green      25436 Nov 13 18:21 JdbMethodExitTest.jtr
-rw-rw-r--   1 dcubed   green       3335 Nov 13 18:21 JdbMissStep.jtr

/var/adm/messages showed no messages during this time frame.

Since these were product JDK and product VM bits, this test
shouldn't have timed out.

I've attached the complete .jtr file, but here are some
observations about the failure:

- the test was executing the following block in
  test/com/sun/jdi/JdbMethodExitTest.sh:

   268      cmd step            # step into traceExit()
   269      cmd trace method exit
   270      cmd cont
   271      jdbFailIfNotPresent "Method exited: return value = \"traceExit\""
   272      cmd untrace
   273      cmd step up
   274
   275
   276      cmd step
   277      cmd step           # skip over setting return value in caller :-(
   278      cmd trace go method exit
   279      cmd cont
   280      jdbFailIfNotPresent 'Method exited: .*JdbMethodExitTest.traceExit1'
   281      cmd quit

   The test had just finished the "traceExit" test and was starting
   on the "traceExit1" test which is the last test section. So the
   test had just finished line 276 and was starting line 277.

- the last few commands sent by the test script are:

  trace method exit
  cont
  untrace
  step up
  step

- the test output shows the results of the above commands:

  main[1] main[1] >
  Method exited: return value = "traceExit", "thread=main", JdbMethodExitTest.traceExit(), line=104 bci=2
  104            return "traceExit";

  main[1] main[1] >
  Step completed: "thread=main", JdbMethodExitTest.main(), line=139 bci=43
  139           traceExit();

  main[1]
  Step completed: "thread=main", JdbMethodExitTest.main(), line=142 bci=44
  142           traceExit1();

  main[1] > Input stream closed.

- the TestScaffold detected that the test was stuck; the jstack output
  shows something interesting:

----------------- t@2 -----------------
0xfeec9455      ___lwp_cond_wait + 0x15
0xfea3998e      void os::PlatformEvent::park() + 0xb2
0xfea20f39      int ParkCommon(ParkEvent*,long long) + 0x59
0xfea2148d      int Monitor::IWait(Thread*,long long) + 0xa5
0xfea21d3a      bool Monitor::wait(bool,long,bool) + 0x256
0xfeb2f004      int JavaThread::java_suspend_self() + 0xe0
0xfeb0fb78      int ObjectMonitor::raw_wait(long long,bool,Thread*) + 0x140
0xfe95669e      jvmtiError JvmtiEnv::RawMonitorWait(JvmtiRawMonitor*,long long)
+ 0xde
0xfe8f4531      jvmti_RawMonitorWait + 0x139
0xfe14972d      debugMonitorWait + 0x31
0xfe13959d      enqueueCommand + 0x14d
0xfe13acdc      eventHelper_reportEvents + 0xf0
0xfe135505      reportEvents + 0x131
0xfe135a35      event_callback + 0x345
0xfe135dbb      cbSingleStep + 0x11b
0xfe9661ca      void JvmtiExport::post_single_step(JavaThread*,methodOopDesc*,unsigned char*) + 0x67a
0xfe9619fd      void JvmtiExport::at_single_stepping_point(JavaThread*,methodOopDesc*,unsigned char*) + 0x195
0xfe5f4d68      void InterpreterRuntime::at_safepoint(JavaThread*) + 0x250
0xfb00b9ae      * JdbMethodExitTest.main(java.lang.String[]) bci:44 line:142 (Interpreted frame)
0xfb000348      <StubRoutines>
0xfe51ea36      void JavaCalls::call_helper(JavaValue*,methodHandle*,JavaCallArguments*,Thread*) + 0x1c2
0xfe51ece7      void os::os_exception_wrapper(void(*)(JavaValue*,methodHandle*,JavaCallArguments*,Thread*),JavaValue*,methodHandle*,JavaCallArguments*,Thread*)
+ 0x17
0xfe51ed1b      void JavaCalls::call(JavaValue*,methodHandle,JavaCallArguments*,Thread*) + 0x2f
0xfe5ab1cc      void jni_invoke_static(JNIEnv_*,JavaValue*,_jobject*,JNICallType,_jmethodID*,JNI_ArgumentPusher*,Thread*) + 0xe8
0xfe5b51bb      jni_CallStaticVoidMethod + 0x97
0xfef734af      JavaMain + 0x88f
0xfeec59b9      _thr_setup + 0x4e
0xfeec5ca0      _lwp_start

The thread that is posting a single step event has self suspended
due to a external suspend request. This might be part of the usual
single-step implementation and not an indication of a problem; I
have some vague memories that single stepping uses suspend/resume
combined with InterpreterRuntime::at_safepoint() in order to make
sure that each bytecode is stepped.

Comments
Have not been able to reproduce/no reproducer available, closing as CNR.
14-12-2016

RULE com/sun/jdi/JdbMethodExitTest.sh StatusError any
16-05-2013

The test is still failing with hs24, seen in PIT of hs24-b44 for jdk7u40-b25
14-05-2013