JDK-8340548 : serviceability/sa/UniqueVtableTest.java timed out
  • Type: Bug
  • Component: hotspot
  • Sub-Component: svc-agent
  • Affected Version: 24
  • Priority: P4
  • Status: Open
  • Resolution: Unresolved
  • OS: windows
  • CPU: x86_64
  • Submitted: 2024-09-20
  • Updated: 2024-09-22
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
tbdUnresolved
Related Reports
Relates :  
JDK-8285729 - serviceability/sa/ClhsdbThreadContext.java timed out
Relates :  
JDK-8303921 - serviceability/sa/UniqueVtableTest.java timed out
Relates :  
JDK-8313814 - Test serviceability/sa/ClhsdbSymbol.java timed out after passing
Description
The following test timed out in the JDK24 CI:

serviceability/sa/UniqueVtableTest.java

Here's a snippet from the log file:

#section:driver
----------messages:(9/650)----------
command: driver UniqueVtableTest
reason: User specified action: run driver UniqueVtableTest 
started: Fri Sep 20 14:53:20 UTC 2024
Mode: othervm [test requires non-default system module]
Additional options from @modules: --add-modules jdk.hotspot.agent --add-exports jdk.hotspot.agent/sun.jvm.hotspot=ALL-UNNAMED --add-exports jdk.hotspot.agent/sun.jvm.hotspot.debugger=ALL-UNNAMED --add-exports jdk.hotspot.agent/sun.jvm.hotspot.types=ALL-UNNAMED --add-exports jdk.hotspot.agent/sun.jvm.hotspot.types.basic=ALL-UNNAMED
Timeout information:
--- Timeout information end.
finished: Fri Sep 20 15:06:42 UTC 2024
elapsed time (seconds): 802.624
----------configuration:(7/373)----------

<snip>

----------System.out:(210/12523)*----------
Command line: ['c:\\ade\\mesos\\work_dir\\jib-master\\install\\jdk-24+17-1839\\windows-x64-debug.jdk\\jdk-24\\fastdebug\\bin\\java.exe' '-XX:MaxRAMPercentage=4.16667' '-Dtest.boot.jdk=c:\\ade\\mesos\\work_dir\\jib-master\\install\\jdk\\22\\36\\bundles\\windows-x64\\jdk-22_windows-x64_bin.zip\\jdk-22' '-Djava.io.tmpdir=c:\\sb\\prod\\1726843264\\testoutput\\test-support\\jtreg_open_test_hotspot_jtreg_tier1_serviceability\\tmp' '-XX:+CreateCoredumpOnCrash' '-XX:+UnlockDiagnosticVMOptions' '-XX:+UseObjectMonitorTable' '-cp' 'C:\\sb\\prod\\1726843264\\testoutput\\test-support\\jtreg_open_test_hotspot_jtreg_tier1_serviceability\\classes\\4\\serviceability\\sa\\UniqueVtableTest.d;C:\\sb\\prod\\1726843264\\testoutput\\test-support\\jtreg_open_test_hotspot_jtreg_tier1_serviceability\\classes\\4\\test\\lib' 'jdk.test.lib.apps.LingeredApp' 'bb35e330-fb7b-48c3-b654-2f32295a44b7.lck']
LingeredApp startup took 1168ms
Check for hs_err_pid/core/mdmp files:
None.
Command line: [c:\\ade\\mesos\\work_dir\\jib-master\\install\\jdk-24+17-1839\\windows-x64-debug.jdk\\jdk-24\\fastdebug\\bin\\java.exe -cp C:\\sb\\prod\\1726843264\\testoutput\\test-support\\jtreg_open_test_hotspot_jtreg_tier1_serviceability\\classes\\4\\serviceability\\sa\\UniqueVtableTest.d;C:\\ade\\mesos\\work_dir\\jib-master\\install\\jdk-24+17-1839\\src.full\\open\\test\\hotspot\\jtreg\\serviceability\\sa;C:\\sb\\prod\\1726843264\\testoutput\\test-support\\jtreg_open_test_hotspot_jtreg_tier1_serviceability\\classes\\4\\test\\lib;C:\\ade\\mesos\\work_dir\\jib-master\\install\\jdk-24+17-1839\\src.full\\open\\test\\lib;C:\\ade\\mesos\\work_dir\\jib-master\\install\\jtreg\\7.4\\1\\bundles\\jtreg-7.4+1.zip\\jtreg\\lib\\jtreg.jar --add-modules=jdk.hotspot.agent --add-exports=jdk.hotspot.agent/sun.jvm.hotspot=ALL-UNNAMED --add-exports=jdk.hotspot.agent/sun.jvm.hotspot.debugger=ALL-UNNAMED --add-exports=jdk.hotspot.agent/sun.jvm.hotspot.types=ALL-UNNAMED --add-exports=jdk.hotspot.agent/sun.jvm.hotspot.types.basic=ALL-UNNAMED UniqueVtableTest 1068 ]
[2024-09-20T14:53:22.313274900Z] Gathering output for process 37460
[2024-09-20T14:53:22.403275800Z] Waiting for completion for process 37460
Timeout signalled after 480 seconds
[2024-09-20T15:06:05.459662200Z] Waiting for completion finished for process 37460
Output and diagnostic info for process 37460 was saved into 'pid-37460-output.log'
Attaching to process ID 1068...
Attached successfully.
vtable is null for G1HeapRegion (extends null)
vtable is null for JNIHandleBlock (extends null)
vtable is null for Abstract_VM_Version (extends null)
vtable is null for JVMState (extends null)
vtable is null for GrowableArray<InlineTree*> (extends null)
vtable is null for JvmtiExport (extends null)
vtable is null for CardTable*const (extends null)
vtable is null for ZAttachedArrayForForwarding (extends null)
vtable is null for CheckedExceptionElement (extends null)
vtable is null for MethodParametersElement (extends null)
vtable is null for address (extends null)
vtable is null for ClassLoaderDataGraph (extends null)
vtable is null for ZHeap (extends null)
vtable is null for ciField (extends null)
vtable is null for PerfMemory (extends null)
vtable is null for CompressedWriteStream (extends null)
vtable is null for XGranuleMapForPageTable (extends null)
vtable is null for PcDescCache (extends null)
vtable is null for ciObjectFactory (extends null)
vtable is null for Array<ResolvedIndyEntry> (extends MetaspaceObj)
vtable is null for FileMapInfo (extends CHeapObj<mtInternal>)
vtable is null for PerfDataEntry (extends null)
vtable is null for GrowableArray<CodeHeap*> (extends null)
vtable is null for ObjectSynchronizer (extends null)
vtable is null for LockStack (extends null)
vtable is null for SystemDictionary (extends null)
vtable is null for XForwarding (extends null)
vtable is null for HeapBlock::Header (extends null)
vtable is null for Threads (extends null)
vtable is null for Annotations (extends MetaspaceObj)
vtable is null for XGranuleMapForForwarding (extends null)
vtable is null for SATBMarkQueue (extends null)
vtable is null for MemRegion (extends null)
vtable is null for Arena (extends null)
vtable is null for StubRoutines (extends null)
vtable is null for volatile Metadata (extends null)
vtable is null for ExceptionTableElement (extends null)
vtable is null for ResolvedFieldEntry (extends null)
vtable is null for zoffset (extends null)
vtable is null for Array<ResolvedFieldEntry> (extends MetaspaceObj)
vtable is null for NegLNode (extends NegNode)
vtable is null for void (extends null)
vtable is null for CHeapObj<mtInternal> (extends null)
vtable is null for StubQueue (extends null)
vtable is null for XPageTable (extends null)
vtable is null for <opaque> (extends null)
vtable is null for Compile (extends null)
vtable is null for GrowableArray<int> (extends null)
vtable is null for MethodData::CompilerCounters (extends null)
vtable is null for SerialBlockOffsetTable (extends null)
vtable is null for ZPageTable (extends null)
vtable is null for JVMFlag (extends null)
vtable is null for PerfDataPrologue (extends null)
vtable is null for Block_Array (extends null)
vtable is null for OopMapValue (extends null)
vtable is null for LocalVariableTableElement (extends null)
vtable is null for VectorMaskWrapperNode (extends VectorNode)
vtable is null for XHeap (extends null)
vtable is null for XForwardingEntry (extends null)
vtable is null for ConstMethod (extends MetaspaceObj)
vtable is null for VMReg (extends null)
vtable is null for ZPageAllocator (extends null)
vtable is null for oopDesc (extends null)
vtable is null for Runtime1 (extends null)
vtable is null for AdapterHandlerEntry (extends null)
vtable is null for CompressedOops (extends null)
vtable is null for jniIdMapBase (extends null)
vtable is null for Array<u2> (extends MetaspaceObj)
vtable is null for PtrQueue (extends null)
vtable is null for XGlobalsForVMStructs (extends null)
vtable is null for XAttachedArrayForForwarding (extends null)
vtable is null for NegINode (extends NegNode)
vtable is null for Array<u1> (extends MetaspaceObj)
vtable is null for G1DirtyCardQueue (extends null)
vtable is null for ZForwardingEntry (extends null)
vtable is null for JNIid (extends null)
vtable is null for OSThread (extends null)
vtable is null for ImmutableOopMapSet (extends null)
vtable is null for CompressedStream (extends null)
vtable is null for G1HeapRegionManager (extends null)
vtable is null for BitMap (extends null)
vtable is null for JavaCallWrapper (extends null)
vtable is null for ImmutableOopMapPair (extends null)
vtable is null for XPageAllocator (extends null)
vtable is null for JavaFrameAnchor (extends null)
vtable is null for CompressedKlassPointers (extends null)
vtable is null for OopStorage (extends null)
vtable is null for Array<Klass*> (extends MetaspaceObj)
vtable is null for Array<InstanceKlass*> (extends null)
vtable is null for ThreadsList (extends null)
vtable is null for ciConstant (extends null)
vtable is null for OopHandle (extends null)
vtable is null for G1MonitoringSupport (extends null)
vtable is null for vtableEntry (extends null)
vtable is null for ClassLoaderData (extends null)
vtable is null for BasicLock (extends null)
vtable is null for HeapWord* volatile (extends null)
vtable is null for BasicObjectLock (extends null)
vtable is null for ZPhysicalMemoryManager (extends null)
vtable is null for ResolvedIndyEntry (extends null)
vtable is null for ExceptionCache (extends null)
vtable is null for HeapBlock (extends null)
vtable is null for XRelocate (extends null)
vtable is null for CDSFileMapRegion (extends null)
vtable is null for BarrierSet::Name (extends null)
vtable is null for frame (extends null)
vtable is null for UpcallStub::FrameData (extends null)
vtable is null for MetaspaceObj (extends null)
vtable is null for ContiguousSpace (extends null)
vtable is null for elapsedTimer (extends null)
vtable is null for Stub (extends null)
vtable is null for Universe (extends null)
vtable is null for AbstractInterpreter (extends null)
vtable is null for zoffset_end (extends null)
vtable is null for Mutex (extends null)
vtable is null for VMError (extends null)
vtable is null for SharedRuntime (extends null)
vtable is null for HeapWord (extends null)
vtable is null for ImmutableOopMap (extends null)
vtable is null for Array<int> (extends MetaspaceObj)
vtable is null for PcDesc (extends null)
vtable is null for FreeBlock (extends HeapBlock)
vtable is null for ZVirtualMemory (extends null)
vtable is null for BreakpointInfo (extends null)
vtable is null for XForwardingTable (extends null)
vtable is null for MonitorList (extends null)
vtable is null for ObjectMonitor (extends null)
vtable is null for CodeHeap (extends null)
vtable is null for ZForwarding (extends null)
vtable is null for GrowableArray<ciMetadata*> (extends null)
vtable is null for ZGranuleMapForPageTable (extends null)
vtable is null for VirtualSpace (extends null)
vtable is null for GrowableArray<ciSymbol*> (extends null)
vtable is null for Phase (extends null)
vtable is null for Symbol (extends null)
vtable is null for java_lang_Class (extends null)
vtable is null for JNIHandles (extends null)
vtable is null for jmethodID (extends null)
vtable is null for os (extends null)
vtable is null for vmClasses (extends null)
vtable is null for ThreadsSMRSupport (extends null)
vtable is null for OptoRegPair (extends null)
vtable is null for CompileTask (extends null)
vtable is null for Array<ResolvedMethodEntry> (extends MetaspaceObj)
vtable is null for instanceOopDesc (extends oopDesc)
vtable is null for ThreadLocalAllocBuffer (extends null)
vtable is null for ZRelocate (extends null)
vtable is null for Block_List (extends Block_Array)
vtable is null for vframeArray (extends null)
vtable is null for Array<Array<u1>*> (extends MetaspaceObj)
vtable is null for arrayOopDesc (extends oopDesc)
vtable is null for BitMapView (extends BitMap)
vtable is null for ZForwardingTable (extends null)
vtable is null for DataLayout (extends null)
vtable is null for JavaThread *const *const (extends null)
vtable is null for jobject (extends null)
vtable is null for Dependencies (extends null)
vtable is null for AtanDNode (extends Node)
vtable is null for vmSymbols (extends null)
vtable is null for Array<jushort> (extends null)
vtable is null for Options (extends null)
vtable is null for InterpreterCodelet (extends Stub)
vtable is null for PhaseCFG (extends Phase)
vtable is null for ResourceArea (extends Arena)
vtable is null for ciEnv (extends null)
vtable is null for ZPage (extends null)
vtable is null for Arguments (extends null)
vtable is null for objArrayOopDesc (extends arrayOopDesc)
vtable is null for volatile unsigned char (extends null)
vtable is null for Deoptimization::UnrollBlock (extends null)
vtable is null for OopMapCache (extends null)
vtable is null for BarrierSet::FakeRtti (extends null)
vtable is null for XVirtualMemory (extends null)
vtable is null for VMRegImpl (extends null)
vtable is null for ZGlobalsForVMStructs (extends null)
vtable is null for ResolvedMethodEntry (extends null)
vtable is null for Deoptimization (extends null)
vtable is null for XPhysicalMemoryManager (extends null)
vtable is null for Array<Method*> (extends MetaspaceObj)
vtable is null for FileMapHeader (extends null)
vtable is null for ConstantPoolCache (extends MetaspaceObj)
vtable is null for ZPageType (extends null)
vtable is null for CodeCache (extends null)
vtable is null for G1HeapRegionType (extends null)
vtable is null for AgeTable (extends null)
vtable is null for CardTable::CardValue (extends null)
vtable is null for ZGranuleMapForForwarding (extends null)
vtable is null for narrowKlass (extends null)
vtable is null for XPage (extends null)
vtable is null for vframeArrayElement (extends null)
total: 877, vm_classes_with_vtable: 497, vm_classes_without_vtable: 190

 LingeredApp stdout: [[764.313s][error][attach] could not open (2) pipe \\\\.\\pipe\\javatool-1774306128 to send result of operation jcmd
[764.314s][error][attach] could not open (2) pipe \\\\.\\pipe\\javatool-1988027181 to send result of operation jcmd
[764.315s][error][attach] could not open (2) pipe \\\\.\\pipe\\javatool-1213152738 to send result of operation jcmd
];
 LingeredApp stderr: []
 LingeredApp exitValue = 0
----------System.err:(1/16)----------
STATUS:Passed.
----------rerun:(46/6799)*----------


This timeout failure is pretty strange:

1) The timeout mesg happens while working with PID 37460:

Command line: [c:\\ade\\mesos\\work_dir\\jib-master\\install\\jdk-24+17-1839\\windows-x64-debug.jdk\\jdk-24\\fastdebug\\bin\\java.exe -cp C:\\sb\\prod\\1726843264\\testoutput\\test-support\\jtreg_open_test_hotspot_jtreg_tier1_serviceability\\classes\\4\\serviceability\\sa\\UniqueVtableTest.d;C:\\ade\\mesos\\work_dir\\jib-master\\install\\jdk-24+17-1839\\src.full\\open\\test\\hotspot\\jtreg\\serviceability\\sa;C:\\sb\\prod\\1726843264\\testoutput\\test-support\\jtreg_open_test_hotspot_jtreg_tier1_serviceability\\classes\\4\\test\\lib;C:\\ade\\mesos\\work_dir\\jib-master\\install\\jdk-24+17-1839\\src.full\\open\\test\\lib;C:\\ade\\mesos\\work_dir\\jib-master\\install\\jtreg\\7.4\\1\\bundles\\jtreg-7.4+1.zip\\jtreg\\lib\\jtreg.jar --add-modules=jdk.hotspot.agent --add-exports=jdk.hotspot.agent/sun.jvm.hotspot=ALL-UNNAMED --add-exports=jdk.hotspot.agent/sun.jvm.hotspot.debugger=ALL-UNNAMED --add-exports=jdk.hotspot.agent/sun.jvm.hotspot.types=ALL-UNNAMED --add-exports=jdk.hotspot.agent/sun.jvm.hotspot.types.basic=ALL-UNNAMED UniqueVtableTest 1068 ]
[2024-09-20T14:53:22.313274900Z] Gathering output for process 37460
[2024-09-20T14:53:22.403275800Z] Waiting for completion for process 37460
Timeout signalled after 480 seconds
[2024-09-20T15:06:05.459662200Z] Waiting for completion finished for process 37460
Output and diagnostic info for process 37460 was saved into 'pid-37460-output.log'
Attaching to process ID 1068...
Attached successfully.
vtable is null for G1HeapRegion (extends null)
vtable is null for JNIHandleBlock (extends null)
vtable is null for Abstract_VM_Version (extends null)

2) And then the test works with a new PID 1068 and generates a lot
    of output leading to:

vtable is null for narrowKlass (extends null)
vtable is null for XPage (extends null)
vtable is null for vframeArrayElement (extends null)
total: 877, vm_classes_with_vtable: 497, vm_classes_without_vtable: 190

 LingeredApp stdout: [[764.313s][error][attach] could not open (2) pipe \\\\.\\pipe\\javatool-1774306128 to send result of operation jcmd
[764.314s][error][attach] could not open (2) pipe \\\\.\\pipe\\javatool-1988027181 to send result of operation jcmd
[764.315s][error][attach] could not open (2) pipe \\\\.\\pipe\\javatool-1213152738 to send result of operation jcmd
];
 LingeredApp stderr: []
 LingeredApp exitValue = 0
----------System.err:(1/16)----------
STATUS:Passed.
----------rerun:(46/6799)*----------

where the test is reported as Passed.

3) There is also this LingeredApp stdout info:

LingeredApp stdout: [[764.313s][error][attach] could not open (2) pipe \\\\.\\pipe\\javatool-1774306128 to send result of operation jcmd
[764.314s][error][attach] could not open (2) pipe \\\\.\\pipe\\javatool-1988027181 to send result of operation jcmd
[764.315s][error][attach] could not open (2) pipe \\\\.\\pipe\\javatool-1213152738 to send result of operation jcmd
];

It seems like the test was stuck when dealing with PID 37460,
it then became unstuck and worked just fine with PID 1068.
Comments
Same issue with WindbgDebuggerLocal.lookupByName0() reported in JDK-8313814 and JDK-8285729, but with different tests. All 3 of these issues are likely dups.
21-09-2024
Process 1068 is a target LingeredApp. Process 37460 is a subprocess which attaches to the LingeredApp (1068) Thread dump shows that 37460 is stuck in "jdk.hotspot.agent\/sun.jvm.hotspot.debugger.windbg.WindbgDebuggerLocal.lookupByName0(Native Method)" call After timeout handler attaches to it several times (to get failure info) it finally unstuck and finishes. Then main test process logs output of 37460 subprocess, then stops LingeredApp, logs its stdout/stderr/exit code and exits normally (so we get "STATUS:Passed") Attach errors from LingeredApp are form "jcmd" command, looks like this were attach from timeout handler
21-09-2024