-
Notifications
You must be signed in to change notification settings - Fork 937
Description
Hi, and thanks so much for the async-profiler!
I'm trying to use the async-profiler to profile a short-lived JVM from start-to-finish.
I couldn't figure out a way to send a stop
command during JVM shutdown, so I have been using this agent string to approximate a full profile:
-agentpath:/path/to/libasyncProfiler.so=start,event=wall,loop=1s,jfr,file=/tmp/output/%n.jfr
This generates multiple JFR files that I then concatenate together, and pass through jfr2flame
. But the output isn't what I expect. Here's a repro case:
export PROFILER="/path/to/async/profiler"
echo "Thread.sleep(3000)" | jshell "-J-agentpath:$PROFILER/build/libasyncProfiler.so=start,event=wall,loop=1s,jfr,file=/tmp/output/%n.jfr"
cat /tmp/output/* > /tmp/combined.jfr
java -cp "$PROFILER/converter.jar" jfr2flame /tmp/combined.jfr /tmp/out.html --threads
Open the output HTML, click on the "main" thread, and search for "JShell.eval". For me on 2.9, it looks like this:
The stacktrace with the most samples appears to be the correct one, the ones on the right side show JShell.eval without a parent frame, or show JShell.eval eventually calling itself, which isn't happening in reality.
I checked the output of the jfr
tool for the combined.jfr
, and it looks to generate reasonable stacktraces:
jfr print --stack-depth 1000 /tmp/combined.jfr | grep -A 1 JShell.eval
The output looks like this:
jdk.jshell.JShell.eval(String) line: 513
jdk.internal.jshell.tool.JShellTool.processSource(String) line: 3633
--
jdk.jshell.JShell.eval(String) line: 513
jdk.internal.jshell.tool.JShellTool.processSource(String) line: 3633
--
<snipped>
The jfr
tool shows stack frame above JShell.eval is always JShellTool.processSource, where the flame graph does not make this clear. I checked other discrepancies in the flamegraph against the jfr tool, and they sometimes disagree, as if the end of one stacktrace got appended to the other.
I would expect that after profiling a program that only calls a method once, that method would only appear once in the flamegraph with a consistent stacktrace. This should happen whether or not the profile is performed in one JFR file or across multiple JFR files with loop
.
- The jshell usage is just a concise example, I am profiling a non-trivial program and seeing similar behavior.
- I don't see the corruption when running jfr2flame on the individual JFR files generated by the loop.
- I tried using the
jfr
tool to assemble the JFR files and got the same result as plain concatenation - Changing the order of concatenation appears to change the resulting flame graph, but doesn't fix it.
Thanks!