JDK-8176567 : nsk/jdi/ReferenceType/instances/instances002: TestFailure: Unexpected size of referenceType.instances(nsk.share.jdi.TestInterfaceImplementer1): 11, expected: 10
  • Type: Bug
  • Component: core-svc
  • Sub-Component: debugger
  • Affected Version: 9,10,16,17,18,19
  • Priority: P4
  • Status: Resolved
  • Resolution: Fixed
  • Submitted: 2017-03-13
  • Updated: 2023-10-27
  • Resolved: 2022-01-18
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 17 JDK 19
17.0.10-oracleFixed 19 b06Fixed
Related Reports
Relates :  
JDK-8153711 - [REDO] JDWP: Memory Leak: GlobalRefs never deleted when processing invokeMethod command
Relates :  
JDK-8253073 - jdi/stress/serial/heapwalking002 failed with "ERROR: Unexpected size of referenceType.instances(java.lang.Thread): 11, expected: 10"
Relates :  
JDK-4858370 - JDWP: Memory Leak: GlobalRefs never deleted when processing invokeMethod command
Relates :  
JDK-8181419 - Race in jdwp invoker handling may lead to crashes or invalid results
Description
Looks similar to  JDK-8071677: nsk/jdi/ReferenceType/instances/instances003 Unexpected size of referenceType.instances
Seen in PIT on Linux 32/64 and Solaris-x64

[2017-03-12T17:40:55.85] # Actual: /export/home/aginfra/CommonData/TEST_JAVA_HOME/bin/java -d64 -server -Xcomp -server -Xcomp -XX:+TieredCompilation -Dsun.jvm.hotspot.runtime.VM.disableVersionCheck=1 nsk.jdi.ReferenceType.instances.instances002.instances002 -verbose -arch=solaris-amd64 -waittime=5 -debugee.vmkind=java -transport.address=dynamic "-debugee.vmkeys=-d64 -server -Xcomp -server -Xcomp -XX:+TieredCompilation"
[2017-03-12T17:40:55.85] 
[2017-03-12T17:41:10.83] binder> VirtualMachineManager: version 9.0
[2017-03-12T17:41:11.92] binder> Finding connector: default
[2017-03-12T17:41:12.02] binder> LaunchingConnector:
[2017-03-12T17:41:12.16] binder>     name: com.sun.jdi.CommandLineLaunch
[2017-03-12T17:41:12.17] binder>     description: Launches target using Sun Java VM command line and attaches to it
[2017-03-12T17:41:12.22] binder>     transport: com.sun.tools.jdi.SunCommandLineLauncher$2@20e2cbe0
[2017-03-12T17:41:13.44] binder> Connector arguments:
[2017-03-12T17:41:13.48] binder>     home=/export/home/aginfra/CommonData/TEST_JAVA_HOME
[2017-03-12T17:41:13.48] binder>     vmexec=java
[2017-03-12T17:41:13.48] binder>     options=-d64 -server -Xcomp -server -Xcomp -XX:+TieredCompilation
[2017-03-12T17:41:13.48] binder>     main=nsk.jdi.ReferenceType.instances.instances002.instances002a "-verbose" "-arch=solaris-amd64" "-waittime=5" "-debugee.vmkind=java" "-transport.address=dynamic" "-debugee.vmkeys=-d64 -server -Xcomp -server -Xcomp -XX:+TieredCompilation" "-pipe.port=63599"
[2017-03-12T17:41:13.48] binder>     quote="
[2017-03-12T17:41:13.48] binder>     suspend=true
[2017-03-12T17:41:13.48] binder> Launching debugee
[2017-03-12T17:41:22.45] binder> Waiting for VM initialized
[2017-03-12T17:41:22.60] Initial VMStartEvent received: VMStartEvent in thread main
[2017-03-12T17:41:33.68] debugee.stderr> Debuggee nsk.jdi.ReferenceType.instances.instances002.instances002a : sending the command: ready
[2017-03-12T17:41:40.59] binder> Breakpoint set:
[2017-03-12T17:41:40.59] 	breakpoint request nsk.share.jpda.AbstractDebuggeeTest:42 (disabled)
[2017-03-12T17:41:42.51] debugee.stderr> Debuggee: received the command: createInstances:nsk.share.jdi.TestClass1:10:1:STRONG
[2017-03-12T17:41:42.92] debugee.stderr> Debuggee nsk.jdi.ReferenceType.instances.instances002.instances002a : sending the command: ready
[2017-03-12T17:41:43.02] debugee.stderr> Debuggee: received the command: forceBreakpoint
[2017-03-12T17:41:43.10] binder> Waiting for event by request:
[2017-03-12T17:41:43.10] 	breakpoint request nsk.share.jpda.AbstractDebuggeeTest:42 (enabled)
[2017-03-12T17:41:43.52] binder> Got requested event:
[2017-03-12T17:41:43.52] 	BreakpointEvent@nsk.share.jpda.AbstractDebuggeeTest:42 in thread instances002a_MainThread
[2017-03-12T17:41:43.82] debugee.stderr> In breakpoint method: 'AbstractDebuggeeTest.breakpointMethod()'
[2017-03-12T17:41:43.82] debugee.stderr> Debuggee nsk.jdi.ReferenceType.instances.instances002.instances002a : sending the command: ready
[2017-03-12T17:41:43.83] debugee.stderr> Debuggee: received the command: deleteInstances:nsk.share.jdi.TestClass1:10
[2017-03-12T17:41:43.85] debugee.stderr> Debuggee nsk.jdi.ReferenceType.instances.instances002.instances002a : sending the command: ready
[2017-03-12T17:41:43.94] debugee.stderr> Debuggee: received the command: createInstances:nsk.share.jdi.TestInterfaceImplementer1:10:1:STRONG
[2017-03-12T17:41:44.02] debugee.stderr> Debuggee nsk.jdi.ReferenceType.instances.instances002.instances002a : sending the command: ready
[2017-03-12T17:41:44.08] binder> Waiting for event by request:
[2017-03-12T17:41:44.08] 	breakpoint request nsk.share.jpda.AbstractDebuggeeTest:42 (enabled)
[2017-03-12T17:41:44.09] debugee.stderr> Debuggee: received the command: forceBreakpoint
[2017-03-12T17:41:44.10] binder> Got requested event:
[2017-03-12T17:41:44.10] 	BreakpointEvent@nsk.share.jpda.AbstractDebuggeeTest:42 in thread instances002a_MainThread
[2017-03-12T17:41:44.49] # ERROR: Unexpected size of referenceType.instances(nsk.share.jdi.TestInterfaceImplementer1): 11, expected: 10
[2017-03-12T17:41:44.94] The following stacktrace is for Aurora. Used to create a RULE:
[2017-03-12T17:41:44.98] nsk.share.TestFailure: Unexpected size of referenceType.instances(nsk.share.jdi.TestInterfaceImplementer1): 11, expected: 10
[2017-03-12T17:41:45.00] 	at nsk.share.Log.logExceptionForAurora(Log.java:411)
[2017-03-12T17:41:45.00] 	at nsk.share.Log.complain(Log.java:380)
[2017-03-12T17:41:45.00] 	at nsk.share.jdi.HeapwalkingDebugger.checkDebugeeAnswer_instances(HeapwalkingDebugger.java:61)
[2017-03-12T17:41:45.00] 	at nsk.jdi.ReferenceType.instances.instances002.instances002.testClassType(instances002.java:122)
[2017-03-12T17:41:45.00] 	at nsk.jdi.ReferenceType.instances.instances002.instances002.doTest(instances002.java:153)
[2017-03-12T17:41:45.00] 	at nsk.share.jdi.TestDebuggerType2.runIt(TestDebuggerType2.java:196)
[2017-03-12T17:41:45.00] 	at nsk.jdi.ReferenceType.instances.instances002.instances002.run(instances002.java:24)
[2017-03-12T17:41:45.00] 	at nsk.jdi.ReferenceType.instances.instances002.instances002.main(instances002.java:20)
[2017-03-12T17:41:45.01] debugee.stderr> In breakpoint method: 'AbstractDebuggeeTest.breakpointMethod()'
[2017-03-12T17:41:45.01] debugee.stderr> Debuggee nsk.jdi.ReferenceType.instances.instances002.instances002a : sending the command: ready
[2017-03-12T17:41:45.01] debugee.stderr> Debuggee: received the command: deleteInstances:nsk.share.jdi.TestInterfaceImplementer1:10
[2017-03-12T17:41:45.01] debugee.stderr> Debuggee nsk.jdi.ReferenceType.instances.instances002.instances002a : sending the command: ready
[2017-03-12T17:41:45.09] # ERROR: Unexpected size of referenceType.instances(nsk.share.jdi.TestInterfaceImplementer1): 1, expected: 0
[2017-03-12T17:41:45.11] debugee.stderr> Debuggee: received the command: createInstances:byte[]:10:1:STRONG
[2017-03-12T17:41:45.11] debugee.stderr> Debuggee nsk.jdi.ReferenceType.instances.instances002.instances002a : sending the command: ready
[2017-03-12T17:41:45.76] debugee.stderr> Debuggee: received the command: createInstances:double[]:10:1:STRONG
[2017-03-12T17:41:45.76] debugee.stderr> Debuggee nsk.jdi.ReferenceType.instances.instances002.instances002a : sending the command: ready
[2017-03-12T17:41:45.93] debugee.stderr> Debuggee: received the command: createInstances:long[]:10:1:STRONG
[2017-03-12T17:41:45.93] debugee.stderr> Debuggee nsk.jdi.ReferenceType.instances.instances002.instances002a : sending the command: ready
[2017-03-12T17:41:46.12] debugee.stderr> Debuggee: received the command: createInstances:int[]:10:1:STRONG
[2017-03-12T17:41:46.12] debugee.stderr> Debuggee nsk.jdi.ReferenceType.instances.instances002.instances002a : sending the command: ready
[2017-03-12T17:41:46.30] debugee.stderr> Debuggee: received the command: createInstances:boolean[]:10:1:STRONG
[2017-03-12T17:41:46.30] debugee.stderr> Debuggee nsk.jdi.ReferenceType.instances.instances002.instances002a : sending the command: ready
[2017-03-12T17:41:46.48] debugee.stderr> Debuggee: received the command: createInstances:char[]:10:1:STRONG
[2017-03-12T17:41:46.48] debugee.stderr> Debuggee nsk.jdi.ReferenceType.instances.instances002.instances002a : sending the command: ready
[2017-03-12T17:41:46.75] debugee.stderr> Debuggee: received the command: createInstances:float[]:10:1:STRONG
[2017-03-12T17:41:46.75] debugee.stderr> Debuggee nsk.jdi.ReferenceType.instances.instances002.instances002a : sending the command: ready
[2017-03-12T17:41:46.92] debugee.stderr> Debuggee: received the command: quit
[2017-03-12T17:41:46.92] debugee.stderr> Debuggee: exiting
[2017-03-12T17:41:47.22] Debuggee's process finished with status: 95
[2017-03-12T17:41:47.22] TEST FAILED
Comments
A pull request was submitted for review. URL: https://git.openjdk.org/jdk17u-dev/pull/1901 Date: 2023-10-23 14:04:31 +0000
24-10-2023
Fix request [17u] I backport this for parity with 17.0.10-oracle. Low risk, simple change. Trivial resolve, probably recognized clean. SAP nightly testing passed.
24-10-2023
The fix for this bug is in jdk-19+6-269.
19-01-2022
Changeset: 46fd6838 Author: Chris Plummer <cjplummer@openjdk.org> Date: 2022-01-18 19:31:16 +0000 URL: https://git.openjdk.java.net/jdk/commit/46fd683820bb7149c0605a0ba03f59e76de69c16
18-01-2022
A pull request was submitted for review. URL: https://git.openjdk.java.net/jdk/pull/6943 Date: 2022-01-02 04:06:05 +0000
03-01-2022
This code has a bit of history. It’s starts with JDK-4858370 which noted that the some globalRefs, including returnValue, where not being freed. However, it was backed out due to a bunch of failures it introduced. The fix was redone as JDK-8153711. However, 7 months later someone noted: "Looks like this is a second attempt to fix the memory leak and earlier one has caused a regression and intermittent failures. Moreover, existing leak is not a regression and exist for a long time. Why is it critical now? “ There was no response or clarification of the failures, but a few weeks later Thomas Stuefe [~stuefe] filed and fixed JDK-8181419 “Race in jdwp invoker handling may lead to crashes or invalid results”. He noted that before sending the reply, we release the invokerLock. After the reply we re-enter the invokerLock and try to free InvokeRequest->returnValue. The problem is that once we leave the invokerLock, another invoke might get setup on the same thread. The end result is overwriting the InvokeRequest->returnValue we want to free, and then freeing the InvokeRequest->returnValue that was setup for the next invoke. The suggested fix was to move the InvokeRequest->returnValue to a local variable, which is what we have now. So the question is can we just move the tossGlobalRef(returnValue) up as I suggested. I think we can. The locking that is still in place was put there by JDK-8153711 to protect the InvokeRequest struct from being touched by other threads. But as already pointed out by Thomas, it’s not enough to just re-grab this lock after releasing it and sending the reply, thus his solution to move the relevant InvokeRequest fields into locals. Since the InvokeRequest fields are now in locals, that should mean the lock is no longer needed. I have a fix that seems to not only be fixing this issue, but also has passed extensive jdwp testing. I'll post a PR shortly.
03-01-2022
Ok, that's sort of the problem, though it's not related to weakenNode and strongCount. It looks like for a short period after the invoke, the debug agent still maintains a JNI global ref for the new instance. Every thread has a ThreadNode data structure, which has a InvokeRequest struct embedded in it. This struct has a "javalue returnValue" field, which holds the result of the invoke. If the result is an Object type, it is stored as a JNIGlboalRef. It is cleared eventually, but we have 3 threads in play here, and it may not be cleared out by the time the ReferenceType.instances() call comes in. The first thread we are dealing with is the event thread. It received a JVMTI breakpoint event, sent that to the debugger, and then did a suspendAll. Next the test sends a ClassType.newInstance() command. All commands are received on the JDWP Command Reader thread, our second thread. It configures the InvokeRequest for the ThreadNode of the event thread. It then resumes the event thread. When the event thread wakes up it sees the pending invoke request. It does the actual JNI NewObjectA call, and stores the result in InvokeRequest.returnValue as a JNI global ref. It then enqueues a command to send to the debugger that has the reply to the ClassType.newInstance() command. Lastly we have the JDWP Event Helper Thread. It reads the queued up reply to send to the debugger. The order it does things is: 1. suspends all threads 2. sends the reply 3. free the JNI global holding the return object The issue is with steps 2 and 3. Once the reply is sent, the debugger/test resumes and sends a VM.resume() command. This can come in before we get to step 3, especially since before doing step 3 the eventHandler_lock and invokerLock must be grabbed. The following is the relevant code: if (!detached) { outStream_initReply(&out, id); (void)outStream_writeValue(env, &out, tag, returnValue); (void)outStream_writeObjectTag(env, &out, exc); (void)outStream_writeObjectRef(env, &out, exc); outStream_sendReply(&out); } /* * Delete potentially saved global references of return value * and exception */ eventHandler_lock(); // for proper lock order debugMonitorEnter(invokerLock); if (mustReleaseReturnValue && returnValue.l != NULL) { tossGlobalRef(env, &returnValue.l); } if (exc != NULL) { tossGlobalRef(env, &exc); } debugMonitorExit(invokerLock); eventHandler_unlock(); I can make the test fail every time by adding a 1 second sleep after the block that sends the reply. Moving the tossGlobalRef() code to just after the outStream_writeValue() call that references returnValue value seems to fix the issue because it frees the global ref before the reply packet actually gets sent. However, I'm a bit unsure about doing that outside of the two locks being grabbed. On the other hand, I don't see why the locks are grabbed in the first place. tossGlobalRef() doesn't require any locking. I wonder if here was once other code in that block that did require it.
24-12-2021
I tried with 10 objects being created, and it failed only twice in my test runs (usually would see about 10). I then tried 3 objects and then just 1, and didn't see any failures. So it seems that too man or two few objects can make the issue go way, if not at least become very rare. I have a hypothesis, although it doesn't quite explain the above observation, it does explain why it's always that last object created that ends up being the extra one. weakenNode() only weakens the reference if strongCount == 1. If it is anything greater than that, it just decrements strongCount and moves on. I'm suspicious that for the last instance created, the debug agent implementation of ClassType.newInstance() is holding on to a strong reference that doesn't get released until some point after the VM.resumeAll is done. Keep in mind that ClassType.newInstance() uses the "invoke" mechanism to invoke java code (the constructor) on the debuggee side. This can only be done when handling an event, and the call has to be done on the (suspended) event thread. In this test case we are at a breakpoint. The "invoke" mechanism will resume the thread (actually all threads in this case) to allow the event thread to execute the invoke. When the invoke is done, the event thread becomes suspended again, just like it was before the invoke. This is done repeatedly for each ClassType.newInstance() call. Eventually the test does the VM.resume(), which allows the event thread to resume. The VM.resume on the debug agent side is handled by a special debug agent thread. Although the breakpoint thread gets resumed, it might not start executing right away. If it is still holding a strong ref to the last object created, then the weakenRef() call will not actually weaken the reference. Meanwhile the test calls ReferenceType.instances(), also handled by a special debug agent thread. It's possible that the event thread has still not resumed, and therefore the object still has a strong reference, so it is included in the ReferenceType.instances() result. Eventually the event thread does resume, releases its reference, which will trigger another weakenRef() call and allow the reference to be truly referenced. Now, I just need to find this reference to the object somewhere in the debug agent invoke support, which is an async bowl of spaghetti.
24-12-2021
Another odd observation. It seems that when it fails, it's always due to one extra reference, and that always seems to be the last ClassType.newInstance() object. Normally it tries creating 100 of them. I tried 1000 expecting more failures, but instead I got none. I tried 25 and it fails at about the same rate. Regarding resuming the VM, I don't see how that could be done in some async manner that allows the strong references to be in the process of being removed while ReferenceType.instances() is being called. The test calls VM.resume(), which will end up in threadControl_resumeAll(), which calls commonRef_unpinAll(), which replaces all the strong JNI references with weak ones by calling weakenNode(). By the time VM.resume() returns, all of this should be complete, and at that time ClassType.newInstance() is called. So it seems that maybe there is some delay in hotspot actually releasing the strong JNI reference of the last object released. Is there some JNI ref queue that gets processed async?
24-12-2021
This is quite a quagmire. I'm not clear which threads are involved here, but if we can be resuming the VM concurrently with the call to ReferenceType.instances then that is obviously a race. I'll butt out now and let you proceed with your investigation. :) Thanks.
24-12-2021
Part of the issue is what I brought up in JDK-8257921: https://bugs.openjdk.java.net/browse/JDK-8257921?focusedCommentId=14387118&page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#comment-14387118 > BTW, we talked a little about what instances() should return, but there are still some clarifications to make. instances() only returns the count of objects that are reachable via a strong reference (It's based on the JVMTI FollowReferences, which does the same). That means as you switch between VM.suspend() and VM.resume() (in either direction, and possibly repeatedly) the instance count may change, even if no collection was done. This is because VM.suspend() adds a strong reference to objects that the debug agent is tracking, and VM.resume() removes that strong reference. Note my "reachable via strong reference" comment was later corrected by Per: > "Weak references" is unfortunately an overloaded term, which might be causing the confusion here. Instances of java.lang.ref.WeakReference (and its referent) are indeed visited by JVMTI FollowReferences, but *weak roots* like JNIGlobalWeakRefs, StringTable, etc are not. However, that does not change my assertion. The these objects are reachable via a strong reference during VM.suspend() but only via a JNIGlobalWeakRefs when resumed, and therefore suspending and resuming the vm can change what ReferenceType.instances(0) returns. This is why when Per did his changes for JDK-8255987, he added the suspend/resume around the call to ReferenceType.instances(0): https://openjdk.github.io/cr/?repo=jdk&pr=1595&range=02#frames-5-test/hotspot/jtreg/vmTestbase/nsk/jdi/ReferenceType/instances/instances002/instances002.java This test change triggered the long discussion in https://github.com/openjdk/jdk/pull/1595, which led to the filing of JDK-8257921 to clarify the spec, which led to a lot more discussion and no resolution. BTW, this CR was originally filed 4 years ago with JDK 9, but with only one sighting. Then it started popping up again a month or two after Per's changes (almost a year ago). I suspect the original sighting had some other root caused and never reproduced again.
24-12-2021
And one more thing I just noticed is that id=945 would be the result of the last of the 100 ClassType.newInstance() calls, so it looks like the referenceType.instances(0) call was done too soon and must have been done on a different thread than the one that is cleaning up the instances due to the VM.resume(). I think that is because the breakpoint thread handling the referenceType.instances(0), but a debug agent thread is handling the VM.resume() and the cleaning up of the refs in commonRef.c
23-12-2021
Yes, I've already done that: REF: instance of nsk.share.jdi.TestClass1(id=836) REF: instance of nsk.share.jdi.TestClass1(id=945) REF: instance of nsk.share.jdi.TestClass1(id=837) REF: instance of nsk.share.jdi.TestClass1(id=838) REF: instance of nsk.share.jdi.TestClass1(id=839) REF: instance of nsk.share.jdi.TestClass1(id=840) REF: instance of nsk.share.jdi.TestClass1(id=841) REF: instance of nsk.share.jdi.TestClass1(id=842) REF: instance of nsk.share.jdi.TestClass1(id=843) REF: instance of nsk.share.jdi.TestClass1(id=844) REF: instance of nsk.share.jdi.TestClass1(id=845) id=945 is the odd one. Clearly a remnant from the 100 ClassType.newInstance() calls. Here's something I just noticed. The test code looks like: int instanceCounts = referenceType.instances(0).size(); if (strictCheck(className)) { if (referenceType.instances(0).size() != expectedCount) { setSuccess(false); log.complain("Unexpected size of referenceType.instances(" + className + "): " + instanceCounts + ", expected: " + expectedCount); } } else { This is where I added code to iterate over referenceType.instances(0) if there was an error. However, the first time I did this it only printed 10 objects even though the original referenceType.instances(0) result returned 11. I suspected my subsequent referenceType.instances(0) call got an updated list that only had the 10 objects. So I changed the code to only call referenceType.instances(0) once and base all the remaining code on that result, and now I see all 11 objects. List<ObjectReference> refs = referenceType.instances(0); int instanceCounts = refs.size(); if (strictCheck(className)) { if (instanceCounts != expectedCount) { setSuccess(false); log.complain("Unexpected size of referenceType.instances(" + className + "): " + instanceCounts + ", expected: " + expectedCount); for (ObjectReference ref : refs) { System.out.println("REF: " + ref); } } So there seems to be some sort of timing issue here with calling referenceType.instances(0) too soon. This is likely due to debug agent code in commonRef.c that is reacting to the VM.resume() call that the test is doing. The discussion regarding this test in https://github.com/openjdk/jdk/pull/1595 is worth a re-read (you were involved). I'm going to have to re-re-read it and also look a commonRef.c a bit more to see where this timing issue comes from.
23-12-2021
Is there a way to print out where the references were found so that the unexpected one can be identified?
23-12-2021
The debugger tells the debuggee to create 10 instances of TestClass1 and maintain references to them. Then debugger then uses JDI ClassType.newInstance() to create 100 more references. These will be weak references. After resuming the debugger and suspending it again via a breakpoint, the debugger then calls JDI ReferenceType.instances() to get all the instances to the TestClass1. It expects there to only be 10. I'm not sure why the 100 weak references are normally not included. I'm not seeing the test force a GC, but in any case normally the 100 weak references are not included and ReferenceType.instances() returns 10. However, once in a while there are 11 instances instead of 10, so I assume one of the weak references is lingering around still.
23-12-2021
ReferenceType.instances() is based on JVMTI FollowReferences, and it looks like FollowReferences does follow java.lang.ref.WeakReferences, but not weak roots, such JNIGlobalWeakRefs, which is what you get when creating instances using ClassType.newInstance(). To it would be expected that ReferenceType.instances() does not return any of these instances, even if there was no GC, yet it appears on occasion to return one of them. Either that or the debug agent code that uses FollowReferences is somehow counting the same object twice.
23-12-2021
This test is quite noisy - should we ProblemList it?
07-09-2021
Here's a log file snippet for the jdk-18+4-93-tier5 sighting: vmTestbase/nsk/jdi/ReferenceType/instances/instances002/instances002.java binder> Waiting for event by request: breakpoint request nsk.share.jpda.AbstractDebuggeeTest:63 (enabled) debugee.stderr> Debuggee: received the command: forceBreakpoint binder> Got requested event: BreakpointEvent@nsk.share.jpda.AbstractDebuggeeTest:63 in thread instances002a_MainThread debugee.stderr> In breakpoint method: 'AbstractDebuggeeTest.breakpointMethod()' debugee.stderr> Debuggee nsk.jdi.ReferenceType.instances.instances002.instances002a : sending the command: ready # ERROR: Unexpected size of referenceType.instances(nsk.share.jdi.TestInterfaceImplementer1): 11, expected: 10 The following stacktrace is for failure analysis. nsk.share.TestFailure: Unexpected size of referenceType.instances(nsk.share.jdi.TestInterfaceImplementer1): 11, expected: 10 at nsk.share.Log.logExceptionForFailureAnalysis(Log.java:432) at nsk.share.Log.complain(Log.java:403) at nsk.share.jdi.HeapwalkingDebugger.checkDebugeeAnswer_instances(HeapwalkingDebugger.java:116) at nsk.jdi.ReferenceType.instances.instances002.instances002.testClassType(instances002.java:193) at nsk.jdi.ReferenceType.instances.instances002.instances002.doTest(instances002.java:225) at nsk.share.jdi.TestDebuggerType2.runIt(TestDebuggerType2.java:214) at nsk.jdi.ReferenceType.instances.instances002.instances002.run(instances002.java:73) at nsk.jdi.ReferenceType.instances.instances002.instances002.main(instances002.java:69) 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) debugee.stderr> Debuggee: received the command: deleteInstances:nsk.share.jdi.TestInterfaceImplementer1:10 debugee.stderr> Debuggee nsk.jdi.ReferenceType.instances.instances002.instances002a : sending the command: ready debugee.stderr> Debuggee: received the command: createInstances:byte[]:10:1:STRONG debugee.stderr> Debuggee nsk.jdi.ReferenceType.instances.instances002.instances002a : sending the command: ready debugee.stderr> Debuggee: received the command: createInstances:double[]:10:1:STRONG debugee.stderr> Debuggee nsk.jdi.ReferenceType.instances.instances002.instances002a : sending the command: ready debugee.stderr> Debuggee: received the command: createInstances:long[]:10:1:STRONG debugee.stderr> Debuggee nsk.jdi.ReferenceType.instances.instances002.instances002a : sending the command: ready debugee.stderr> Debuggee: received the command: createInstances:int[]:10:1:STRONG debugee.stderr> Debuggee nsk.jdi.ReferenceType.instances.instances002.instances002a : sending the command: ready debugee.stderr> Debuggee: received the command: createInstances:boolean[]:10:1:STRONG debugee.stderr> Debuggee nsk.jdi.ReferenceType.instances.instances002.instances002a : sending the command: ready debugee.stderr> Debuggee: received the command: createInstances:char[]:10:1:STRONG debugee.stderr> Debuggee nsk.jdi.ReferenceType.instances.instances002.instances002a : sending the command: ready debugee.stderr> Debuggee: received the command: createInstances:float[]:10:1:STRONG debugee.stderr> Debuggee nsk.jdi.ReferenceType.instances.instances002.instances002a : sending the command: ready debugee.stderr> Debuggee: received the command: quit debugee.stderr> Debuggee: exiting Debuggee's process finished with status: 95 TEST FAILED #> #> SUMMARY: Following errors occured #> during test execution: #> # ERROR: Unexpected size of referenceType.instances(nsk.share.jdi.TestInterfaceImplementer1): 11, expected: 10 ----------System.err:(3/168)---------- java version "18-ea" 2022-03-15 Java(TM) SE Runtime Environment (fastdebug build 18-ea+4-93) Java HotSpot(TM) 64-Bit Server VM (fastdebug build 18-ea+4-93, mixed mode) ----------rerun:(35/8974)*----------
27-06-2021
[~cjplummer] and [~mwthomps] - Thanks for chiming in. Changed to non-confidential.
01-02-2021
Here's a snippet from the log file for the jdk-17+8-506-tier7 sighting: vmTestbase/nsk/jdi/ReferenceType/instances/instances002/instances002.java binder> Got requested event: BreakpointEvent@nsk.share.jpda.AbstractDebuggeeTest:63 in thread instances002a_MainThread debugee.stderr> In breakpoint method: 'AbstractDebuggeeTest.breakpointMethod()' debugee.stderr> Debuggee nsk.jdi.ReferenceType.instances.instances002.instances002a : sending the command: ready # ERROR: Unexpected size of referenceType.instances(nsk.share.jdi.TestClass1): 11, expected: 10 The following stacktrace is for failure analysis. nsk.share.TestFailure: Unexpected size of referenceType.instances(nsk.share.jdi.TestClass1): 11, expected: 10 at nsk.share.Log.logExceptionForFailureAnalysis(Log.java:428) at nsk.share.Log.complain(Log.java:399) at nsk.share.jdi.HeapwalkingDebugger.checkDebugeeAnswer_instances(HeapwalkingDebugger.java:116) at nsk.jdi.ReferenceType.instances.instances002.instances002.testClassType(instances002.java:193) at nsk.jdi.ReferenceType.instances.instances002.instances002.doTest(instances002.java:225) at nsk.share.jdi.TestDebuggerType2.runIt(TestDebuggerType2.java:214) at nsk.jdi.ReferenceType.instances.instances002.instances002.run(instances002.java:73) at nsk.jdi.ReferenceType.instances.instances002.instances002.main(instances002.java:69) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:78) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:566) at com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:127) at java.base/java.lang.Thread.run(Thread.java:831) debugee.stderr> Debuggee: received the command: deleteInstances:nsk.share.jdi.TestClass1:10 debugee.stderr> Debuggee nsk.jdi.ReferenceType.instances.instances002.instances002a : sending the command: ready debugee.stderr> Debuggee: received the command: createInstances:nsk.share.jdi.TestInterfaceImplementer1:10:1:STRONG debugee.stderr> Debuggee nsk.jdi.ReferenceType.instances.instances002.instances002a : sending the command: ready binder> Waiting for event by request: breakpoint request nsk.share.jpda.AbstractDebuggeeTest:63 (enabled) debugee.stderr> Debuggee: received the command: forceBreakpoint binder> Got requested event: BreakpointEvent@nsk.share.jpda.AbstractDebuggeeTest:63 in thread instances002a_MainThread debugee.stderr> In breakpoint method: 'AbstractDebuggeeTest.breakpointMethod()' debugee.stderr> Debuggee nsk.jdi.ReferenceType.instances.instances002.instances002a : sending the command: ready debugee.stderr> Debuggee: received the command: deleteInstances:nsk.share.jdi.TestInterfaceImplementer1:10 debugee.stderr> Debuggee nsk.jdi.ReferenceType.instances.instances002.instances002a : sending the command: ready debugee.stderr> Debuggee: received the command: createInstances:byte[]:10:1:STRONG debugee.stderr> Debuggee nsk.jdi.ReferenceType.instances.instances002.instances002a : sending the command: ready debugee.stderr> Debuggee: received the command: createInstances:double[]:10:1:STRONG debugee.stderr> Debuggee nsk.jdi.ReferenceType.instances.instances002.instances002a : sending the command: ready debugee.stderr> Debuggee: received the command: createInstances:long[]:10:1:STRONG debugee.stderr> Debuggee nsk.jdi.ReferenceType.instances.instances002.instances002a : sending the command: ready debugee.stderr> Debuggee: received the command: createInstances:int[]:10:1:STRONG debugee.stderr> Debuggee nsk.jdi.ReferenceType.instances.instances002.instances002a : sending the command: ready debugee.stderr> Debuggee: received the command: createInstances:boolean[]:10:1:STRONG debugee.stderr> Debuggee nsk.jdi.ReferenceType.instances.instances002.instances002a : sending the command: ready debugee.stderr> Debuggee: received the command: createInstances:char[]:10:1:STRONG debugee.stderr> Debuggee nsk.jdi.ReferenceType.instances.instances002.instances002a : sending the command: ready debugee.stderr> Debuggee: received the command: createInstances:float[]:10:1:STRONG debugee.stderr> Debuggee nsk.jdi.ReferenceType.instances.instances002.instances002a : sending the command: ready debugee.stderr> Debuggee: received the command: quit debugee.stderr> Debuggee: exiting Debuggee's process finished with status: 95 TEST FAILED #> #> SUMMARY: Following errors occured #> during test execution: #> # ERROR: Unexpected size of referenceType.instances(nsk.share.jdi.TestClass1): 11, expected: 10 ----------System.err:(0/0)---------- ----------rerun:(36/9113)*----------
31-01-2021
Here's a snippet from the log file for the jdk-16+32-2177-tier5 sighting: vmTestbase/nsk/jdi/ReferenceType/instances/instances002/instances002.java #section:main ----------messages:(4/877)---------- command: main nsk.jdi.ReferenceType.instances.instances002.instances002 -verbose -arch=linux-x64 -waittime=5 -debugee.vmkind=java -transport.address=dynamic -debugee.vmkeys="-XX:MaxRAMPercentage=6 -Djava.io.tmpdir=/opt/mach5/mesos/work_dir/slaves/983c483a-6907-44e0-ad29-98c7183575e2-S82317/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/08fa12b6-b771-423d-afb5-bb59da182798/runs/42245e55-6e77-4023-aa05-6e7b7584f012/testoutput/test-support/jtreg_open_test_hotspot_jtreg_vmTestbase_nsk_jdi_quick/tmp -Xshare:off -showversion" reason: User specified action: run main/othervm/native nsk.jdi.ReferenceType.instances.instances002.instances002 -verbose -arch=${os.family}-${os.simpleArch} -waittime=5 -debugee.vmkind=java -transport.address=dynamic -debugee.vmkeys="${test.vm.opts} ${test.java.opts}" Mode: othervm [/othervm specified] elapsed time (seconds): 7.74 ----------configuration:(0/0)---------- ----------System.out:(86/7041)*---------- binder> VirtualMachineManager: version 16.0 binder> Finding connector: default binder> LaunchingConnector: binder> name: com.sun.jdi.CommandLineLaunch binder> description: Launches target using Sun Java VM command line and attaches to it binder> transport: com.sun.tools.jdi.SunCommandLineLauncher$2@198bdf4b binder> Connector arguments: binder> home=/opt/mach5/mesos/work_dir/jib-master/install/jdk-16+32-2177/linux-x64-debug.jdk/jdk-16/fastdebug binder> vmexec=java binder> options=-XX:MaxRAMPercentage=6 -Djava.io.tmpdir=/opt/mach5/mesos/work_dir/slaves/983c483a-6907-44e0-ad29-98c7183575e2-S82317/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/08fa12b6-b771-423d-afb5-bb59da182798/runs/42245e55-6e77-4023-aa05-6e7b7584f012/testoutput/test-support/jtreg_open_test_hotspot_jtreg_vmTestbase_nsk_jdi_quick/tmp -Xshare:off -showversion binder> main=nsk.jdi.ReferenceType.instances.instances002.instances002a \u0000-verbose\u0000 \u0000-arch=linux-x64\u0000 \u0000-waittime=5\u0000 \u0000-debugee.vmkind=java\u0000 \u0000-transport.address=dynamic\u0000 \u0000-debugee.vmkeys="-XX:MaxRAMPercentage=6 -Djava.io.tmpdir=/opt/mach5/mesos/work_dir/slaves/983c483a-6907-44e0-ad29-98c7183575e2-S82317/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/08fa12b6-b771-423d-afb5-bb59da182798/runs/42245e55-6e77-4023-aa05-6e7b7584f012/testoutput/test-support/jtreg_open_test_hotspot_jtreg_vmTestbase_nsk_jdi_quick/tmp -Xshare:off -showversion"\u0000 \u0000-pipe.port=57321\u0000 binder> quote=\u0000 binder> suspend=true binder> Launching debugee binder> Waiting for VM initialized Initial VMStartEvent received: VMStartEvent in thread main debugee.stderr> java version "16-ea" 2021-03-16 debugee.stderr> Java(TM) SE Runtime Environment (fastdebug build 16-ea+32-2177) debugee.stderr> Java HotSpot(TM) 64-Bit Server VM (fastdebug build 16-ea+32-2177, mixed mode) debugee.stderr> Debuggee nsk.jdi.ReferenceType.instances.instances002.instances002a : sending the command: ready binder> Breakpoint set: breakpoint request nsk.share.jpda.AbstractDebuggeeTest:63 (disabled) debugee.stderr> Debuggee: received the command: createInstances:nsk.share.jdi.TestClass1:10:1:STRONG debugee.stderr> Debuggee nsk.jdi.ReferenceType.instances.instances002.instances002a : sending the command: ready binder> Waiting for event by request: breakpoint request nsk.share.jpda.AbstractDebuggeeTest:63 (enabled) debugee.stderr> Debuggee: received the command: forceBreakpoint binder> Got requested event: BreakpointEvent@nsk.share.jpda.AbstractDebuggeeTest:63 in thread instances002a_MainThread debugee.stderr> In breakpoint method: 'AbstractDebuggeeTest.breakpointMethod()' debugee.stderr> Debuggee nsk.jdi.ReferenceType.instances.instances002.instances002a : sending the command: ready # ERROR: Unexpected size of referenceType.instances(nsk.share.jdi.TestClass1): 11, expected: 10 The following stacktrace is for failure analysis. nsk.share.TestFailure: Unexpected size of referenceType.instances(nsk.share.jdi.TestClass1): 11, expected: 10 at nsk.share.Log.logExceptionForFailureAnalysis(Log.java:428) at nsk.share.Log.complain(Log.java:399) at nsk.share.jdi.HeapwalkingDebugger.checkDebugeeAnswer_instances(HeapwalkingDebugger.java:116) at nsk.jdi.ReferenceType.instances.instances002.instances002.testClassType(instances002.java:193) at nsk.jdi.ReferenceType.instances.instances002.instances002.doTest(instances002.java:225) at nsk.share.jdi.TestDebuggerType2.runIt(TestDebuggerType2.java:214) at nsk.jdi.ReferenceType.instances.instances002.instances002.run(instances002.java:73) at nsk.jdi.ReferenceType.instances.instances002.instances002.main(instances002.java:69) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:78) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:567) at com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:127) at java.base/java.lang.Thread.run(Thread.java:831) debugee.stderr> Debuggee: received the command: deleteInstances:nsk.share.jdi.TestClass1:10 debugee.stderr> Debuggee nsk.jdi.ReferenceType.instances.instances002.instances002a : sending the command: ready debugee.stderr> Debuggee: received the command: createInstances:nsk.share.jdi.TestInterfaceImplementer1:10:1:STRONG debugee.stderr> Debuggee nsk.jdi.ReferenceType.instances.instances002.instances002a : sending the command: ready binder> Waiting for event by request: breakpoint request nsk.share.jpda.AbstractDebuggeeTest:63 (enabled) debugee.stderr> Debuggee: received the command: forceBreakpoint binder> Got requested event: BreakpointEvent@nsk.share.jpda.AbstractDebuggeeTest:63 in thread instances002a_MainThread debugee.stderr> In breakpoint method: 'AbstractDebuggeeTest.breakpointMethod()' debugee.stderr> Debuggee nsk.jdi.ReferenceType.instances.instances002.instances002a : sending the command: ready debugee.stderr> Debuggee: received the command: deleteInstances:nsk.share.jdi.TestInterfaceImplementer1:10 debugee.stderr> Debuggee nsk.jdi.ReferenceType.instances.instances002.instances002a : sending the command: ready debugee.stderr> Debuggee: received the command: createInstances:byte[]:10:1:STRONG debugee.stderr> Debuggee nsk.jdi.ReferenceType.instances.instances002.instances002a : sending the command: ready debugee.stderr> Debuggee: received the command: createInstances:double[]:10:1:STRONG debugee.stderr> Debuggee nsk.jdi.ReferenceType.instances.instances002.instances002a : sending the command: ready debugee.stderr> Debuggee: received the command: createInstances:long[]:10:1:STRONG debugee.stderr> Debuggee nsk.jdi.ReferenceType.instances.instances002.instances002a : sending the command: ready debugee.stderr> Debuggee: received the command: createInstances:int[]:10:1:STRONG debugee.stderr> Debuggee nsk.jdi.ReferenceType.instances.instances002.instances002a : sending the command: ready debugee.stderr> Debuggee: received the command: createInstances:boolean[]:10:1:STRONG debugee.stderr> Debuggee nsk.jdi.ReferenceType.instances.instances002.instances002a : sending the command: ready debugee.stderr> Debuggee: received the command: createInstances:char[]:10:1:STRONG debugee.stderr> Debuggee nsk.jdi.ReferenceType.instances.instances002.instances002a : sending the command: ready debugee.stderr> Debuggee: received the command: createInstances:float[]:10:1:STRONG debugee.stderr> Debuggee nsk.jdi.ReferenceType.instances.instances002.instances002a : sending the command: ready debugee.stderr> Debuggee: received the command: quit debugee.stderr> Debuggee: exiting Debuggee's process finished with status: 95 TEST FAILED
12-01-2021