Re: jdwp virtual threads dump?
Thanks Alan! for now there's no special support for virtual threads in IDEA, that's why I'm asking :) "Get Thread Dump" action gathers the information from the threads list provided by com.sun.jdi.VirtualMachine#allThreads. -Egor On 27.06.2023 18:24, Alan Bateman wrote: On 27/06/2023 16:58, Egor Ushakov wrote: Hi all, is there a way for a debugger to create a virtual threads dump via jdwp? Right now, the only way to do this via JDWP is use the ObjectReference/InvokeMethod command (or JDI invokeMethod at the API level) to invoke HotSpotDiagnosticMXBean dumpThreads to generate a thread dump to a file. So not terrible when the debugger and target VM are on the same system or at least have access to the same file system. In the future, JDWP + JDI will require updates to define new commands/methods to find threads, the VirtualMachine/AllThreads command is not the right solution for virtual threads. BTW: What does IDEA "Get Thread Dump" (camera icon) use? -Alan
jdwp virtual threads dump?
Hi all, is there a way for a debugger to create a virtual threads dump via jdwp? Thanks, Egor
Re: RFR: 8297638: Memory leak in case of many started-dead threads [v2]
On Thu, 19 Jan 2023 21:59:22 GMT, Chris Plummer wrote: >> Fix JDI leak when the debuggee creates a lot of threads, while at the same >> the debugger is not sending any commands. The lack of commands being sent >> results in code not being triggered that normally would clear out >> unreachable listeners and also clear out ObjectReferences queued for >> disposal. > > Chris Plummer has updated the pull request incrementally with one additional > commit since the last revision: > > Cleaned up removeUnreachableListeners(). looks good to me, thanks - Marked as reviewed by gor...@github.com (no known OpenJDK username). PR: https://git.openjdk.org/jdk/pull/12081
Re: RFR: 8297638: Memory leak in case of many started-dead threads [v2]
On Thu, 19 Jan 2023 21:59:22 GMT, Chris Plummer wrote: >> Fix JDI leak when the debuggee creates a lot of threads, while at the same >> the debugger is not sending any commands. The lack of commands being sent >> results in code not being triggered that normally would clear out >> unreachable listeners and also clear out ObjectReferences queued for >> disposal. > > Chris Plummer has updated the pull request incrementally with one additional > commit since the last revision: > > Cleaned up removeUnreachableListeners(). Looks good to me, thanks! - PR: https://git.openjdk.org/jdk/pull/12081
Re: [External] : Re: Grouped method entry events
threadControl_saveCLEInfo(env, thread, ei,
clazz, method, location);
}
Meanwhile the generated MethodEntry event sits in the thread's event
bag, and I guess gets added to when the next MethodEntry happens.
This goes on on a MethodExit event is generated, witch seems to push
out all pending events (there is actually no logic in the debug
agent to colocate MethodExit events, which seems odd).
So bottom line is that the CLE code is wrong when JVMTI single
stepping is enabled for the sake of supporting a JDWP STEP_OVER. I
think instead of checking if JVMTI single stepping is enabled, it
should be checking if the current StepDepth is INTO, although I
suspect there might be other factors to consider that will make the
check more complicated.
I'll look at this some more tomorrow.
Chris
On 8/7/22 11:50 PM, Chris Plummer wrote:
Hi Egor,
The reason only the last event prints location information is
because there is special logic in jdb that assumes if the suspend
type is not SUSPEND_NONE, then we will be stopping, and that will
result in the location info being printed.
if (me.request().suspendPolicy() !=
EventRequest.SUSPEND_NONE) {
// We are stopping; the name will be shown by the
normal mechanism
MessageOutput.lnprint("Method entered:");
} else {
// We aren't stopping, show the name
MessageOutput.print("Method entered:");
printLocationOfEvent(me);
}
The assumption here is wrong with co-located events, since there
could be more than one. However, normally it shouldn't matter since
all colocated events are suppose to be at the same location, and if
one is stopping then they all are. Yet clearly we are seeing that
they are not all at the same location. When I enable location
tracing for the first part of the "if" block, I get:
> Method entered: "thread=main", java.lang.ClassLoader.loadClass(),
line=521 bci=0
Method entered: "thread=main",
jdk.internal.loader.ClassLoaders$AppClassLoader.loadClass(),
line=180 bci=0
Method entered: "thread=main",
java.lang.System.getSecurityManager(), line=497 bci=0
Method entered: "thread=main",
java.lang.System.allowSecurityManager(), line=205 bci=0
Method exited: return value = false, "thread=main",
java.lang.System.allowSecurityManager(), line=205 bci=12
I also printed out the EventSet, which confirms the same:
event set, policy:2, count:5 =
{methodentryev...@java.lang.ClassLoader:521 in thread main,
MethodEntryEvent@jdk.internal.loader.ClassLoaders$AppClassLoader:180
in thread main, methodentryev...@java.lang.System:497 in thread
main, methodentryev...@java.lang.System:205 in thread main,
methodexitev...@java.lang.System:205 in thread main}
The JDWP spec says:
Several events may occur at a given time in the target VM. For
example, there may be more than one breakpoint request for a given
location or you might single step to the same location as a
breakpoint request. These events are delivered together as a
composite event.
...
The events that are grouped in a composite event are restricted in
the following ways:
...
� Only with other members of this group, at the same location and
in the same thread:
Breakpoint Event
Step Event
Method Entry Event
Method Exit Event
So there seems to be a debug agent bug that is grouping all the
MethodEntry events until a MethodExit is hit. But I don't think
this is new. I see the same thing in JDK11, but as Alan pointed
out, there are fewer method calls.
Chris
On 8/6/22 2:18 AM, Egor Ushakov wrote:
Hi Chris,
I was able to somewhat reproduce it with jdb:
compile any simple samle app like
public class A { public static void main(String[] args) {
System.out.println("A"); // line 3 } }
now debug with jdb:
% jdb A
Initializing jdb ...
> stop at A:3
Deferring breakpoint A:3.
It will be set after the class is loaded.
> run
run A
Set uncaught java.lang.Throwable
Set deferred uncaught java.lang.Throwable
>
VM Started: Set deferred breakpoint A:3
Breakpoint hit: "thread=main", A.main(), line=3 bci=0
main[1] exclude none
main[1] trace methods
main[1] next
>
*Method entered: **
**Method entered: **
**Method entered: **
**Method entered: *
Method exited: return value = false, "thread=main",
java.lang.System.allowSecurityManager(), line=198 bci=12
main[1] next
>
Method exited: return value = null, "thread=main",
java.lang.System.getSecurityManager(), line=493 bci=11
main[1] next
>
*Method entered: **
**Method entered: **
**Method entered: **
**Method entered:*
Method exited: return value = , "thread=main",
java.lang.Object.(), line=44 bci=0
main[1] next
>
*Method entered: **
**Method entered: **
**Method entered: **
**Method entered: *
Method exited: return value = true, &quo
Re: [External] : Re: Grouped method entry events
s hit. But I don't think this
is new. I see the same thing in JDK11, but as Alan pointed out, there
are fewer method calls.
Chris
On 8/6/22 2:18 AM, Egor Ushakov wrote:
Hi Chris,
I was able to somewhat reproduce it with jdb:
compile any simple samle app like
public class A { public static void main(String[] args) {
System.out.println("A"); // line 3 } }
now debug with jdb:
% jdb A
Initializing jdb ...
> stop at A:3
Deferring breakpoint A:3.
It will be set after the class is loaded.
> run
run A
Set uncaught java.lang.Throwable
Set deferred uncaught java.lang.Throwable
>
VM Started: Set deferred breakpoint A:3
Breakpoint hit: "thread=main", A.main(), line=3 bci=0
main[1] exclude none
main[1] trace methods
main[1] next
>
*Method entered: **
**Method entered: **
**Method entered: **
**Method entered: *
Method exited: return value = false, "thread=main",
java.lang.System.allowSecurityManager(), line=198 bci=12
main[1] next
>
Method exited: return value = null, "thread=main",
java.lang.System.getSecurityManager(), line=493 bci=11
main[1] next
>
*Method entered: **
**Method entered: **
**Method entered: **
**Method entered:*
Method exited: return value = , "thread=main",
java.lang.Object.(), line=44 bci=0
main[1] next
>
*Method entered: **
**Method entered: **
**Method entered: **
**Method entered: *
Method exited: return value = true, "thread=main",
java.lang.String.isLatin1(), line=4,546 bci=18
Unfortunately jdb does not show method description for the events
with suspend policy thread (except for the last one), but you can
see that there are 5 events in one set here.
Hope it helps,
Egor
On 05.08.2022 22:02, Chris Plummer wrote:
Hi Egor,
That is odd, and clearly wrong. It means that MethodEntryEvents are
being delivered when no longer even executing in the method. And
you are using the EVENT_THREAD suspend policy, so there should be a
suspend for each event. Offhand I can't think of any changes that
would have caused this. I also don't see how our testing would
passed with this behavior. I'm suspecting a faulty interaction with
the debug agent and IDEA (possibly the IDEA version of JDI).
Can you see where the thread is actually suspended at when you get
the event set?
Does this happen with 17 also? It would be nice to know what
version introduced this problem.
Can you create a JDI test case for this?
> Without the active step request it works in jdk 18 as in jdk 11:
I'm not sure what you mean by "active step". Do you mean single
stepping is enabled? The JDWP spec does allow BreakPoint,
SingleStep, MethodEntry, and MethodExit events to be combined into
the same composite event (which should translate to the same JDI
event set) if they occur at the same location and in the same
thread. So I can see enabling single stepping having an impact on
the behavior you are seeing.
Chris
On 8/5/22 9:59 AM, Egor Ushakov wrote:
Hi,
we're experiencing strange grouping of method entry/exit events,
is this a bug or a feature?
We have one method entry request active with suspend policy 1
(suspend thread).
important: we also have one active step request (step over)
In jdk 11 we have one composite event for each event, which is
what's expected:
event set, policy:1, count:1 =
{methodentryev...@java.lang.ClassLoader:522 in thread main}
event set, policy:1, count:1 =
{MethodEntryEvent@jdk.internal.loader.ClassLoaders$AppClassLoader:170
in thread main}
event set, policy:1, count:1 =
{methodentryev...@java.lang.System:375 in thread main}
event set, policy:1, count:1 =
{MethodEntryEvent@jdk.internal.loader.BuiltinClassLoader:579 in
thread main}
event set, policy:1, count:1 =
{MethodEntryEvent@jdk.internal.loader.BuiltinClassLoader:591 in
thread main}
event set, policy:1, count:1 =
{methodentryev...@java.lang.ClassLoader:665 in thread main}
event set, policy:1, count:1 =
{methodentryev...@java.lang.Object:50 in thread main}
event set, policy:1, count:1 =
{methodentryev...@java.util.concurrent.ConcurrentHashMap:1541 in
thread main}
event set, policy:1, count:1 =
{methodentryev...@java.util.concurrent.ConcurrentHashMap:1011 in
thread main}
event set, policy:1, count:1 =
{methodentryev...@java.lang.String:1502 in thread main}
event set, policy:1, count:1 =
{methodentryev...@java.lang.String:3266 in thread main}
event set, policy:1, count:1 =
{methodentryev...@java.lang.StringLatin1:194 in thread main}
...
In jdk 18 they are grouped now!
event set, policy:1, count:17 =
{methodentryev...@java.lang.ClassLoader:521 in thread main,
MethodEntryEvent@jdk.internal.loader.ClassLoaders$AppClassLoader:180
in thread main, methodentryev...@java.lang.System:490 in thread
main, methodentryev...@java.lang.System:198 in thread main,
MethodEntryEvent@jdk.internal.loader.BuiltinClassLoader:639 in
thread main,
MethodEntryEvent@jdk.internal.loader.BuiltinClassLoader:651 in
thread main
Re: Grouped method entry events
Hi Chris,
I was able to somewhat reproduce it with jdb:
compile any simple samle app like
public class A {
public static void main(String[] args) {
System.out.println("A"); // line 3
}
}
now debug with jdb:
% jdb A
Initializing jdb ...
> stop at A:3
Deferring breakpoint A:3.
It will be set after the class is loaded.
> run
run A
Set uncaught java.lang.Throwable
Set deferred uncaught java.lang.Throwable
>
VM Started: Set deferred breakpoint A:3
Breakpoint hit: "thread=main", A.main(), line=3 bci=0
main[1] exclude none
main[1] trace methods
main[1] next
>
*Method entered: **
**Method entered: **
**Method entered: **
**Method entered: *
Method exited: return value = false, "thread=main",
java.lang.System.allowSecurityManager(), line=198 bci=12
main[1] next
>
Method exited: return value = null, "thread=main",
java.lang.System.getSecurityManager(), line=493 bci=11
main[1] next
>
*Method entered: **
**Method entered: **
**Method entered: **
**Method entered:*
Method exited: return value = , "thread=main",
java.lang.Object.(), line=44 bci=0
main[1] next
>
*Method entered: **
**Method entered: **
**Method entered: **
**Method entered: *
Method exited: return value = true, "thread=main",
java.lang.String.isLatin1(), line=4,546 bci=18
Unfortunately jdb does not show method description for the events with
suspend policy thread (except for the last one), but you can see that
there are 5 events in one set here.
Hope it helps,
Egor
On 05.08.2022 22:02, Chris Plummer wrote:
Hi Egor,
That is odd, and clearly wrong. It means that MethodEntryEvents are
being delivered when no longer even executing in the method. And you
are using the EVENT_THREAD suspend policy, so there should be a
suspend for each event. Offhand I can't think of any changes that
would have caused this. I also don't see how our testing would passed
with this behavior. I'm suspecting a faulty interaction with the debug
agent and IDEA (possibly the IDEA version of JDI).
Can you see where the thread is actually suspended at when you get the
event set?
Does this happen with 17 also? It would be nice to know what version
introduced this problem.
Can you create a JDI test case for this?
> Without the active step request it works in jdk 18 as in jdk 11:
I'm not sure what you mean by "active step". Do you mean single
stepping is enabled? The JDWP spec does allow BreakPoint, SingleStep,
MethodEntry, and MethodExit events to be combined into the same
composite event (which should translate to the same JDI event set) if
they occur at the same location and in the same thread. So I can see
enabling single stepping having an impact on the behavior you are seeing.
Chris
On 8/5/22 9:59 AM, Egor Ushakov wrote:
Hi,
we're experiencing strange grouping of method entry/exit events, is
this a bug or a feature?
We have one method entry request active with suspend policy 1
(suspend thread).
important: we also have one active step request (step over)
In jdk 11 we have one composite event for each event, which is what's
expected:
event set, policy:1, count:1 =
{methodentryev...@java.lang.ClassLoader:522 in thread main}
event set, policy:1, count:1 =
{MethodEntryEvent@jdk.internal.loader.ClassLoaders$AppClassLoader:170
in thread main}
event set, policy:1, count:1 = {methodentryev...@java.lang.System:375
in thread main}
event set, policy:1, count:1 =
{MethodEntryEvent@jdk.internal.loader.BuiltinClassLoader:579 in
thread main}
event set, policy:1, count:1 =
{MethodEntryEvent@jdk.internal.loader.BuiltinClassLoader:591 in
thread main}
event set, policy:1, count:1 =
{methodentryev...@java.lang.ClassLoader:665 in thread main}
event set, policy:1, count:1 = {methodentryev...@java.lang.Object:50
in thread main}
event set, policy:1, count:1 =
{methodentryev...@java.util.concurrent.ConcurrentHashMap:1541 in
thread main}
event set, policy:1, count:1 =
{methodentryev...@java.util.concurrent.ConcurrentHashMap:1011 in
thread main}
event set, policy:1, count:1 =
{methodentryev...@java.lang.String:1502 in thread main}
event set, policy:1, count:1 =
{methodentryev...@java.lang.String:3266 in thread main}
event set, policy:1, count:1 =
{methodentryev...@java.lang.StringLatin1:194 in thread main}
...
In jdk 18 they are grouped now!
event set, policy:1, count:17 =
{methodentryev...@java.lang.ClassLoader:521 in thread main,
MethodEntryEvent@jdk.internal.loader.ClassLoaders$AppClassLoader:180
in thread main, methodentryev...@java.lang.System:490 in thread main,
methodentryev...@java.lang.System:198 in thread main,
MethodEntryEvent@jdk.internal.loader.BuiltinClassLoader:639 in thread
main, MethodEntryEvent@jdk.internal.loader.BuiltinClassLoader:651 in
thread main, methodentryev...@java.lang.ClassLoader:664 in thread
main, methodentryev...@java.lang.Object:44 in thread main,
Grouped method entry events
Hi,
we're experiencing strange grouping of method entry/exit events, is this
a bug or a feature?
We have one method entry request active with suspend policy 1 (suspend
thread).
important: we also have one active step request (step over)
In jdk 11 we have one composite event for each event, which is what's
expected:
event set, policy:1, count:1 =
{methodentryev...@java.lang.ClassLoader:522 in thread main}
event set, policy:1, count:1 =
{MethodEntryEvent@jdk.internal.loader.ClassLoaders$AppClassLoader:170 in
thread main}
event set, policy:1, count:1 = {methodentryev...@java.lang.System:375 in
thread main}
event set, policy:1, count:1 =
{MethodEntryEvent@jdk.internal.loader.BuiltinClassLoader:579 in thread main}
event set, policy:1, count:1 =
{MethodEntryEvent@jdk.internal.loader.BuiltinClassLoader:591 in thread main}
event set, policy:1, count:1 =
{methodentryev...@java.lang.ClassLoader:665 in thread main}
event set, policy:1, count:1 = {methodentryev...@java.lang.Object:50 in
thread main}
event set, policy:1, count:1 =
{methodentryev...@java.util.concurrent.ConcurrentHashMap:1541 in thread
main}
event set, policy:1, count:1 =
{methodentryev...@java.util.concurrent.ConcurrentHashMap:1011 in thread
main}
event set, policy:1, count:1 = {methodentryev...@java.lang.String:1502
in thread main}
event set, policy:1, count:1 = {methodentryev...@java.lang.String:3266
in thread main}
event set, policy:1, count:1 =
{methodentryev...@java.lang.StringLatin1:194 in thread main}
...
In jdk 18 they are grouped now!
event set, policy:1, count:17 =
{methodentryev...@java.lang.ClassLoader:521 in thread main,
MethodEntryEvent@jdk.internal.loader.ClassLoaders$AppClassLoader:180 in
thread main, methodentryev...@java.lang.System:490 in thread main,
methodentryev...@java.lang.System:198 in thread main,
MethodEntryEvent@jdk.internal.loader.BuiltinClassLoader:639 in thread
main, MethodEntryEvent@jdk.internal.loader.BuiltinClassLoader:651 in
thread main, methodentryev...@java.lang.ClassLoader:664 in thread main,
methodentryev...@java.lang.Object:44 in thread main,
methodentryev...@java.util.concurrent.ConcurrentHashMap:1541 in thread
main, methodentryev...@java.util.concurrent.ConcurrentHashMap:1011 in
thread main, methodentryev...@java.lang.String:2336 in thread main,
methodentryev...@java.lang.String:4546 in thread main,
methodentryev...@java.lang.StringLatin1:192 in thread main,
methodentryev...@java.util.concurrent.ConcurrentHashMap:697 in thread
main, methodentryev...@java.util.concurrent.ConcurrentHashMap:760 in
thread main, methodentryev...@jdk.internal.misc.Unsafe:2153 in thread
main,
methodentryev...@jdk.internal.misc.Unsafe.getReferenceVolatile(java.lang.Object,
long)+-1 in thread main}
event set, policy:1, count:4 =
{methodentryev...@java.util.concurrent.ConcurrentHashMap$Node:631 in
thread main, methodentryev...@java.lang.Object:44 in thread main,
methodentryev...@java.util.concurrent.ConcurrentHashMap:765 in thread
main,
methodentryev...@jdk.internal.misc.Unsafe.compareAndSetReference(java.lang.Object,
long, java.lang.Object, java.lang.Object)+-1 in thread main}
event set, policy:1, count:2 =
{methodentryev...@java.util.concurrent.ConcurrentHashMap:2326 in thread
main,
methodentryev...@jdk.internal.misc.Unsafe.compareAndSetLong(java.lang.Object,
long, long, long)+-1 in thread main}
Which is really strange and breaks some login in IDEA debugger.
Without the active step request it works in jdk 18 as in jdk 11:
event set, policy:1, count:1 =
{methodentryev...@java.lang.ClassLoader:521 in thread main}
event set, policy:1, count:1 =
{MethodEntryEvent@jdk.internal.loader.ClassLoaders$AppClassLoader:180 in
thread main}
event set, policy:1, count:1 = {methodentryev...@java.lang.System:490 in
thread main}
event set, policy:1, count:1 = {methodentryev...@java.lang.System:198 in
thread main}
event set, policy:1, count:1 =
{MethodEntryEvent@jdk.internal.loader.BuiltinClassLoader:639 in thread main}
event set, policy:1, count:1 =
{MethodEntryEvent@jdk.internal.loader.BuiltinClassLoader:651 in thread main}
event set, policy:1, count:1 =
{methodentryev...@java.lang.ClassLoader:664 in thread main}
event set, policy:1, count:1 = {methodentryev...@java.lang.Object:44 in
thread main}
event set, policy:1, count:1 =
{methodentryev...@java.util.concurrent.ConcurrentHashMap:1541 in thread
main}
event set, policy:1, count:1 =
{methodentryev...@java.util.concurrent.ConcurrentHashMap:1011 in thread
main}
event set, policy:1, count:1 = {methodentryev...@java.lang.String:2336
in thread main}
event set, policy:1, count:1 = {methodentryev...@java.lang.String:4546
in thread main}
event set, policy:1, count:1 =
{methodentryev...@java.lang.StringLatin1:192 in thread main}
Could anyone have a look please.
Thanks,
Egor
