JDK-8269522 : serviceability/sa tests failed with "ArrayIndexOutOfBoundsException: Index 1 out of bounds for length 1"
  • Type: Bug
  • Component: hotspot
  • Sub-Component: svc-agent
  • Affected Version: 17,18
  • Priority: P4
  • Status: Closed
  • Resolution: Duplicate
  • Submitted: 2021-06-28
  • Updated: 2021-07-09
  • Resolved: 2021-07-09
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 :  
Relates :  
Relates :  
Relates :  
Description
The following test failed in the JDK18 CI:

serviceability/sa/ClhsdbPrintAs.java

Here's a snippet from the log file:

----------System.err:(16/1150)----------
java.lang.RuntimeException: Test ERROR java.lang.ArrayIndexOutOfBoundsException: Index 1 out of bounds for length 1
	at ClhsdbPrintAs.main(ClhsdbPrintAs.java:118)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:568)
	at com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:127)
	at java.base/java.lang.Thread.run(Thread.java:833)
Caused by: java.lang.ArrayIndexOutOfBoundsException: Index 1 out of bounds for length 1
	at ClhsdbPrintAs.main(ClhsdbPrintAs.java:61)
	... 6 more

JavaTest Message: Test threw exception: java.lang.RuntimeException: Test ERROR java.lang.ArrayIndexOutOfBoundsException: Index 1 out of bounds for length 1
JavaTest Message: shutting down test

Failure modes like this one were previously addressed via:

    JDK-8243455 Many SA tests can fail due to trying to get the stack trace of an active method
Comments
Closing as dup of JDK-8269830
09-07-2021

I filed JDK-8269830 to track this issue.
02-07-2021

Ok. I think I know what is happening. It is an SA bug. Above I showed you the VirtualConstructor mappings, and mentioned that instantiateWrapperFor(addr) iterates through these mappings, trying to find the one whose vtable matches the vtable of the object at the specified address. BasicTypeDataBase.addressTypeIsEqualToType(addr, type) is called for each of these mappings until a match is found. The problem is the code in addressTypeIsEqualToType() tries to be platform independent and search all possible locations for the vtableptr, not just the first word of the object. // 1. The first word of the object (should handle MSVC++ as // well as the solstudio compilers with compatibility set to // v5.0 or greater) // 2. and 3. The last two Address-aligned words of the part of // the object defined by its topmost polymorphic superclass. // This should handle the solstudio compilers, v4.2 or // earlier, as well as any other compilers which place the vptr // at the end of the user-defined fields of the first base // class with virtual functions. So if the first word does not point to the vtable of the specified type, then we also look at the last two words of the object. But the last two words aren't known with certainty since we don't know the actual type of the object yet (we are trying to figure out if it matches the specified type). So the code starts with the size of the specified type (this is known from vmstructs), adds that to the specified address, and then looks at the two words before it. This could very well be beyond the end of the object if it is not actually of the type we are trying to match it to, and could very well point to the address where the vtableptr of the next object in memory is stored. So if we have a pointer to an JavaThread and check to see if it is CompilerThread before checking if it is a JavaThread, the check for the vtableptr at address 0 will always fail, and we then look at the two words before addr + sizeof(CompilerThread). Since a CompilerThread is bigger than a JavaThread, we end up looking at words after the JavaThread, and likely we end up looking at the start of an CompilerThread that is right after the JavaThread. A vtable match is found there, causing SA to think the JavaThread is a CompilerThread. But... Even if the above does not result in SA thinking the JavaThread is a CompilerThread after looking for the vtableptr at the 3 addresses mentioned above, we have the following to deal with (this comment is right after the above comment): // Unfortunately this algorithm did not work properly for the // specific case of the ThreadShadow/Thread inheritance situation, // because the Solaris compiler seems to cleverly eliminate the // vtbl for ThreadShadow since the only virtual is empty. (We // should get rid of the ThreadShadow and fix the include // databases, but need to postpone this for the present.) The // current solution performs the three-location check for this // class and all of its known superclasses rather than just the // topmost polymorphic one. So if there is no match on the first pass, we then get the superclass type of the specified type, and see if the object type matches it. So this means if we failed to match using the CompilerThread type, we then try to match on the JavaThread type (the superclass of JavaThread). Since the object is a JavaThread, this match should succeed, and BasicTypeDataBase.addressTypeIsEqualToType(addr, type) would return true. But it seems like a bug to do this since this implies that the object is of type CompilerThread even though the vtable match was actually done using the JavaThread type. I don't know why this polymorphic superclass checking is even done. It just seems wrong. It would cause a mismatch if you ever lookup using the subclasses type before the base class type. Since Solaris isn't supported anymore, I think I'm going to just remove support for looking at the 2 addresses at the end of the object, and remove the superclass retries. If this works, I'll probably file a new CR to fix this under and dup out these 4 CRs that are failing because of it.
02-07-2021

Not quite what I'm saying. I'm saying that memory location might have once been a CompilerThread, but is now a plain JavaThread. Which means its current vtable should match that of a JavaThread. Are you caching the state of these memory pointers?
02-07-2021

A regular JavaThread having a CompilerThread vtable doesn't mess up hotspot all? What happens when you call something like thread->is_Compiler_thread()? Wouldn't it return true when it should return false.
02-07-2021

If I have a JavaThread that exits and I launch another JavaThread, then it is entirely normal for the new JavaThread data structure to occupy the same VM address as the old JavaThread data structure. I imagine that if a CompilerThread exits, then it would be entirely possible for a new JavaThread to occupy that same address.
02-07-2021

The problem is that jstack thinks the SteadyStateThread JavaThread is actually an instance of CompilerThread. jstack purposefully does not include CompilerThreads in its output. You do see the thread if you use the "clhsdb threads" command, which includes all threads. It's unclear to me how this can happen. SA determines the type of a VMObject by looking at the symbol name that the vtable address maps too. This is very core functionality for SA, and it would quickly fail just about any functionality if this wasn't working right. SA fetches the ThreadList found at ThreadsSMRSupport._java_thread_list, and gets the address of each thread in the list (actually an array). It determines the type of this VMObject stored at this address, and instantiate the equivalent SA wrapper for it: virtualConstructor = new VirtualConstructor(db); // Add mappings for all known thread types virtualConstructor.addMapping("JavaThread", JavaThread.class); virtualConstructor.addMapping("CompilerThread", CompilerThread.class); virtualConstructor.addMapping("CodeCacheSweeperThread", CodeCacheSweeperThread.class); virtualConstructor.addMapping("JvmtiAgentThread", JvmtiAgentThread.class); virtualConstructor.addMapping("ServiceThread", ServiceThread.class); virtualConstructor.addMapping("MonitorDeflationThread", MonitorDeflationThread.class); virtualConstructor.addMapping("NotificationThread", NotificationThread.class); public JavaThread createJavaThreadWrapper(Address threadAddr) { ... JavaThread thread = (JavaThread)virtualConstructor.instantiateWrapperFor(threadAddr); ... return thread; ... } instantiateWrapperFor(addr) finds the VM type of the VMObject stored at the address by getting the native symbol for the vtable of the C++ object at that address, from which it parses out the native type name (such as "JavaThread"). With the name of the VM type in hand, it can look it up in the virtualConstructor mapping to find the SA class to instantiate. For this bug to occur, we would have to have what is suppose to be a JavaThread VMObject (and not a subclass of JavaThread), but for some reason has a CompilerThread vtable. If this really is the case, it seems like a hotspot bug, but maybe goes unnoticed. Is there re-use of JavaThread objects that are deleted? In other words, we had a CompilerThread object, it was freed and put on a list for re-use, and later the same object was use for a new JavaThread object.
02-07-2021

I wonder if this might be the same issue as JDK-8257998 ('Signal Dispatcher' thread missing) and/or JDK-8244980 (Common-cleaner thread missing).
01-07-2021

Hmm. This again is because the SteadyState thread is not appearing in the output. That support was added by JDK-8243455 almost 4 months ago, and seemed to be working well. Now we suddenly have 2 failures to dump the thread, both on OSX. I'm pretty sure it has to have been created by the time we do the jstack thread dump. Has anything changed in the underlying hotspot thread management recently that might be causing SA to miss the thread? Or maybe I got something wrong with synchronization code in LingeredApp the creates the SteadyState thread.
01-07-2021

Here's a log file snippet from the jdk-18+5-130-tier3 sighting: serviceability/sa/ClhsdbJdis.java ----------System.err:(19/1307)---------- java version "18-ea" 2022-03-15 Java(TM) SE Runtime Environment (fastdebug build 18-ea+5-130) Java HotSpot(TM) 64-Bit Server VM (fastdebug build 18-ea+5-130, mixed mode) java.lang.RuntimeException: Test ERROR java.lang.ArrayIndexOutOfBoundsException: Index 1 out of bounds for length 1 at ClhsdbJdis.main(ClhsdbJdis.java:89) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:568) at com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:127) at java.base/java.lang.Thread.run(Thread.java:833) Caused by: java.lang.ArrayIndexOutOfBoundsException: Index 1 out of bounds for length 1 at ClhsdbJdis.main(ClhsdbJdis.java:62) ... 6 more JavaTest Message: Test threw exception: java.lang.RuntimeException: Test ERROR java.lang.ArrayIndexOutOfBoundsException: Index 1 out of bounds for length 1 JavaTest Message: shutting down test STATUS:Failed.`main' threw exception: java.lang.RuntimeException: Test ERROR java.lang.ArrayIndexOutOfBoundsException: Index 1 out of bounds for length 1 ----------rerun:(34/7129)*---------- The log file doesn't show the SteadyStateThread for this test either.
01-07-2021

The SteadyStateThread, which was added by JDK-8243455 to fix similar failures, is missing from the jstack output. We should see the following, but don't: "SteadyStateThread" #14 prio=5 tid=0x00007f93f427d2c0 nid=0x7a60 waiting for monitor entry [0x00007f91c5320000] java.lang.Thread.State: BLOCKED (on object monitor) JavaThread state: _thread_blocked - jdk.test.lib.apps.LingeredApp.steadyState(java.lang.Object) @bci=8, line=537, pc=0x00007f93dd78ba15, Method*=0x00007f91c6403530 (Interpreted frame) - waiting to lock <0x00001000000d8718> (a java.lang.Object) - jdk.test.lib.apps.LingeredApp$1.run() @bci=4, line=543, pc=0x00007f93dd7713be, Method*=0x00007f91c6403d78 (Interpreted frame) The main thread is there as expected: "main" #1 prio=5 tid=0x00007fedfb008e20 nid=0x1703 waiting on condition [0x0000700004475000] java.lang.Thread.State: TIMED_WAITING (sleeping) JavaThread state: _thread_blocked - java.lang.Thread.sleep(long) @bci=0, pc=0x00000001161925c0, Method*=0x0000000800427600 (Compiled frame; information may be imprecise) - jdk.test.lib.apps.LingeredApp.main(java.lang.String[]) @bci=158, line=599, pc=0x0000000115e945ab, Method*=0x0000000173c03818 (Interpreted frame) - locked <0x0000000138e67ed8> (a java.lang.Object) synchronized(steadyStateObj) { startSteadyStateThread(steadyStateObj); if (forceCrash) { System.loadLibrary("LingeredApp"); // location of native crash() method crash(); } while (Files.exists(path)) { // Touch the lock to indicate our readiness setLastModified(theLockFileName, epoch()); Thread.sleep(spinDelay); <--- Line 599 } } So we have called startSteadyStateThread() and are still synchronized on steadyStateObj, which should cause SteadyStateThread to remain blocked. So my conclusion is that SteadyStateThread is still running, but for some reason it was missed in the thread dump, although I'm not sure how that can happen either. Even if the thread is in a bad state and we can't walk its stack, it should at least be found and listed in the jstack output. I wonder if this has to do with other threads that are starting up, such as Common-Cleaner. Maybe we are in the middle of updating the hotspot thread list for one of these other threads, and this causes SteadyStateThread to temporarily not be visible.
28-06-2021