Find out latency increase issue while performance test, take java thread dump and analyze it
Hello Friends in this blog we will be learning how to analyze thread saturation. if your application facing latency issue on load/performance test you should read this article.
Background of the Problem Statement
In a large complex java application, it happens many times that few operations run well when running in isolation. But the Latency of the calls increases during performance/load test. This might be happening due to the poor design of the multithreaded system. Below are the few signs which might cause slowness/increase latency to your application calls & this may vary depending on the system. am listing out the generic problem which everyone might encounter.
- Excessive use of synchronization with improper lock objects
- Connect to an external system, where the external system does not guarantee immediate response
- Executing expensive SQL Queries / Using non-indexed columns on the OLTP system
- Configuring the low number of thread pool & request incoming rate is too high, we can say as thread tuning is not well
How Multithreaded system works
Before we understand the problem in depth, let us understand how multi-threaded system work. Let us take an example of apache tomcat web server. each application server has a thread pool. it has a finite number of threads are defined like 50 or 80 or 100. whenever a request comes into the system, a corresponding job is added to the queue. job scheduler/thread manager check for free thread & assign the job to the thread for execution. and in this way, the job gets on to his journey of serving your request. Here below image depict the picture of what we discussed just now
Ultimately now the job for fetching employee details of id 1234, will assign to thread "Thread #1" as it is an ideal state & ready to work. remaining threads are currently working on another task. so they cannot take other tasks they get freed.
Let's get back to our problem statement
So now you have understood, how the multithreaded system works, you can imagine what can happen if all threads are currently working/running state & constantly new jobs are coming into the system. what will happen in this case? All new job will be queued up. as in when thread frees from their existing task, it will pick up a job from the waiting queue. this will impact the execution time of the request. so now the caller will have to wait till the job was in queue + actual job execution time. in this way, latency gets increased. So now we have understood that queuing up jobs will cause latency increase. Thread execution time should be finitely based on what type of system you are designing & what level of TPS you want to archive from your system. let us see some scenario that one should avoid, which cause the long-running operation execution on the thread.
So now you have aware of what to do and what not. But how will you identify the problem the in the large complex application if you face increasing latency, slowness problem under load or performance test?
Just to simulate the latency, I have developed the sample spring boot application which we will be used to identify the problem. I have developed this application just to simulate the thread saturation. It is having "thread.sleep()" statement to simulate latency by external calls or heavy database query.
We run the demo application, & hit the load test using SOAP UI tool. In below screenshot, you can see the which operation is in progress & how many time it is taking.
Here is the statics of SOAP UI Load test. You can see the latency of the request min, max, and average.
So at this point, we are ready to take the thread dump. Our performance test is already running & in SOAP UI test we have already seen that our threads are getting saturated & latency is increasing for the REST calls. I will show how we can take thread dump on Windows & Linux operating systems.
How to take a thread dump and analyze it
1. For taking a thread dump of the java process, JDK has provided few commands in the bin directory. make sure you have updated the PATH variable to include java bin directory. otherwise you are in the bin directory of JDK.
2. For taking thread dump, you should know for which java process you want to take a thread dump. JDK has provided "jps" command to list the java process. below is the sample execution of the command. am executing command -v option which will give me more verbose details about the process. and anyone can distinguish between the different Java process running simultaneously under one JVM. If you are on Linux you can use ps -ef | grep "java" to list all java process. in below screenshot, you can see sample java application is running with process id PID 31684.
3. Now we have found the java process for which we have to take the thread dump. You can use "jstack" command with process id and redirect the output to the file. if you are the linux user you can use kill -3 <<PID>> command to send the signal to java process which will dump the thread dump on stdout.
4. Now you have a thread dump file. a Thread dump file is a simple text file in which state of each thread is dumped with its call stack. there is various information associated with it like thread name, is it a demon thread, thread priority in JVM, thread priority in os, os transaction id, thread state, monitor. below is the screenshot of the thread dump file.
5. Now you have a thread dump file. there are many free tools which can analyze your thread dump and tell you what's wrong with your application. you can google for thread dump analyzer you will get a bunch of results which can analyze your thread dump. One of my favorites is fastthread.io. This website will give you the graphical representation of your thread dump. Let's analyze the result.
6. Open up the website and upload your dump file there. hit the analyze button. You can upload multiple thread dump file here.
7. Once processing is complete. you will see the report in the format of graphs and text. below is the sample report. Here in the below report, it is mention that analyzer has found the problem.
Below 9 threads were blocked. you will get a nice description of the problematic scenario
Above image indicate that thread-8 has obtained a lock and did not release and due to this other threads are waiting. you can click on each thread to check in the call stack at what point they are blocked.
