0

I have a web application that is taking for longer than it should to perform a specific task. I place the web application under load using ab with a concurrency of one, and I see tomcat using 100% of one CPU. I want to drill down into the application and answer the question "what is this java code doing to cause the java code to burn 100% of a CPU?".

I have tried to use Java Flight Recorder as follows to record my application in full flight as follows:

-sh-4.1$ jcmd 115388 JFR.start duration=60s filename=/tmp/app-service-live.jfr settings=profile

Loading the resulting JFR file into VisualVM gives me the following:

Screenshot of VisualVM CPU samples tab

As can be seen in the screenshot, despite only one thread being red hot while recording, all threads are marked as red hot. Drilling down into one of the red hot threads, VisualVM reports us as burning hot inside the sun.misc.Unsafe.park() method. This method is not red hot, but stone cold.

With no way to tell the difference between hot code contributing to the 100% CPU figure, and stone cold code that is blocked waiting for an external event, there is no coherent picture that emerges.

What changes do I need to make to my jcmd command line to properly capture what the CPU is doing?

What alternative process do I need to follow inside VisualVM to find hot code, while eliminating cold code?

Graham Leggett
  • 911
  • 7
  • 20
  • I haven't done much with profiling, but it looks like most of your CPU times are pretty low compared to your total time. The total time doesn't mean anything at the top level. That's just how long that thread was alive, basically. The last thread is the interesting one. It pegged the CPU the whole time it ran, but it only ran for about 1/3 of the time of the other threads. Do you know what code is taking too long. Have you tried to see that code in the JFR results? Can that code run in any of the threads? – CryptoFool Oct 29 '20 at 23:18
  • I don't know the code that's taking too long, no - this is the question I am trying to get answered. It seems the tooling gives you very low resolution data, you can sort-of see what's happening, but can't see what's actually happening. – Graham Leggett Oct 31 '20 at 13:52

1 Answers1

0

I haven't seen the implementation of Visual VM, but the event that samples on CPU is called jdk.ExecutionSample.

There is also a jdk.NativeMethodSample event which can be used to find threads that are stuck in native, but it is not possible for the JVM to determine if they are running or not, so they should not be part of the visualization.

If it is, you can work around the bug by either using JDK Mission Control, or change the configuration so the event is not recorded. Look in the JAVA_HOME/lib/jfr directory and copy the default.jfc to a new file, i.e my.jfc, and then change into the file so the jdk.NativeMethodSample event has the setting:

<setting name="enabled">false</setting>

Then run it like this:

$ jcmd <pid> settings=my duration=60s ...

You can also copy the configuration to another directory, but then you must specify full path:

$ jcmd <pid> settings=/conf/my.jfc duration=60s ...
Kire Haglin
  • 6,569
  • 22
  • 27