I am investigating an ongoing CPU usage issue where it goes high after sometime of usage. I got an alert on one of the nodes that the load was high and I opened Java Mission Control and took a quick Flight Record.
I am attaching the output of what I see. I am not a developer so I need help understanding what I see.
I am looking at the thread locks and see that 3 threads are locked. I opened the stack trace and see a number Request/Response , Socket etc entries.
Any idea what it means ?
The image you've shown doesn't show three locked threads, but rather three objects which are the most contended locks. For a general developer-friendly description of what the pieces on the page you're looking at mean, see the doc on this page.
Now, since you've said you're not a developer, let me break things down for you a little:
What does it mean for an object to be a lock?
This is a java thing. Java has set up their multithreading locking scheme based around the concept of monitors. Basically any object in the language can be used as a lock so that when a thread executes code like:
synchronized(myObject){
//code
}
while //code is being executed, no other thread can be executing //other code in a block like:
synchronized(myObject){
//other code
}
(assuming myObject refers to the same actual object each time).
What does it mean for a lock to be contended?
Suppose thread A is currently executing //code from the example above (assume it takes some non-zero time), and thread B reaches a spot where it wants to try to execute //other code. Since the language is set up so that these two portions of code can't be executed at the same time (called mutual exclusion, thread b will have to sit and wait to execute //other code until //code is finished. When this happens, we say that the lock for myObject is contended.
What are the 3 classes I'm seeing?
These are the classes of the 3 objects acting as locks which caused the most delay by threads sitting an waiting for them.
What is the stack trace I'm seeing?
That is the stack trace to one of the spots where one of the threads spent the most time waiting.
And probably the question you care about most: Does the information in this profile indicate a performance problem?
It depends on how long your flight record was taken for, but my opinion (take it with a grain of salt given that I don't know any details of your application) is a rather underwhelming possibly, but not necessarily. The total amount of time waiting for the most contended lock was a little over 3 seconds, with an average wait time of a second and a half. This may not sound like a lot (and may not actually be a lot if the waiting happened on a relatively unimportant thread), but for code, 1.5 seconds of waiting can be a lot. Consider this, a guideline for user interface responsiveness is that an operation has to take less than 0.1 seconds for a user not to notice and less than 1 second for their train of thought to not be interrupted. If your waiting on that lock happened on the thread managing your user interface, the user would have noticed the delay.
My best recommendation to you as a non-developer would be to get the stack trace you receive by looking at the java.lang.ref.ReferenceQueue$Lock object and send it to a developer on your project to examine further.
Also, you mention that a CPU load issue prompted this investigation, so: Would contended locks cause a high CPU load?
No. When a lock is contended, one or more of the threads is sitting and waiting, which means they won't be using the CPU. As a matter of fact, one of the signs that lock contention could be causing problems is if your CPU load is abnormally low (particualrly on a multi-core machine). Your high CPU usage likely lies elsewhere to be found in your profiling results. To investigate high CPU usage you should try method hotspots or something like this. It will likely be enormously more productive if you have a trained developer looking at it with you.
Like many programs, they spend a significant portion of their time logging. In this case your program is spending a lot of time writing to it's console which I imagine is redirected to a file. The more you write the longer it takes. esp if you disk subsystem become a bottleneck. If the logs are going to a screen somewhere, it can slow down depending on what that computer is doing.
