4 Troubleshoot Performance Issues Using Flight Recorder
To learn more about creating a recording with Flight Recorder in Java Mission Control (JMC), see Start a Flight Recording.
The data provided by Flight Recorder helps you investigate performance issues. No other tool gives as much profiling data without skewing the results with its own performance overhead. This chapter provides information about performance issues that you can identify and debug using data from Flight Recorder.
This chapter contains the following sections:
Flight Recorder Overhead
When you measure performance, it is important to consider any performance overhead added by Flight Recorder. The overhead will differ depending on the application. If you have any performance tests set up, you can measure if there is any noticeable overhead on your application.
The overhead for recording a standard time fixed recording (profiling recording) using the default settings is less than two percent for most applications. Running with a standard continuous recording generally has no measurable performance effect.
Using Heap Statistics, which is disabled by default, can cause significant performance overhead. This is because enabling Heap Statistics triggers an old garbage collection at the beginning and the at end of the test run. These old GCs give some extra pause times to the application, so if you are measuring latency or if your environment is sensitive to pause times, do not run with Heap Statistics enabled. The Heap Statistics feature is useful when debugging memory leaks or when investigating the live set of the application. For more information, see The jfr tool.
Note:
For performance profiling use cases, heap statistics may not be necessary.Find Bottlenecks
Different applications have different bottlenecks. Waiting for I/O or networking, synchronization between threads, CPU usage or garbage collection times can cause bottlenecks in an application. It is possible that an application has more than one bottleneck.
Find Bottlenecks
Different applications have different bottlenecks. For some applications, a bottleneck may be waiting for I/O or networking, it may be synchronization between threads, or it may be actual CPU usage. For others, a bottleneck may be garbage collection times. It is possible that an application has more than one bottleneck.
One way to find the application bottlenecks is to look at the following events in your flight recording. Make sure that all of these events are enabled in the recording template that you are using:
-
jdk.FileRead jdk.FileWritejdk.SocketReadjdk.SocketWritejdk.JavaErrorThrowjdk.JavaExceptionThrowjdk.JavaMonitorEnterjdk.JavaMonitorWaitjdk.ThreadStartjdk.ThreadEndjdk.ThreadSleepjdk.ThreadPark
The selected Java Application events all have the important property that they are all thread-stalling events. Thread stalling indicates that the thread was not running your application during the event, and they are all duration events. The duration event measures the duration the application was not running.
Use the jfr tool to print the events that were recorded and look for the following information:
jdk.JavaMonitorWaitevents show how much time a thread spends waiting for a monitor.jdk.ThreadSleepandjdk.ThreadParkevents show when a thread is sleeping or parked.- Read and write events show how much time is spent in I/O.
If your Java application's important threads spend a lot of time being blocked, then that means that a critical section of the application is single threaded, which is a bottleneck. If the Java application spends a lot of time waiting for sockets, then the main bottleneck may be in the network or with the other machines that the application communicates with. If your Java application's important threads are spending a lot of time without generating any application events, then the bottleneck in the application is the time spent executing code or the CPU itself. Each of these bottlenecks can be further investigated within the flight recording.
Note:
For most Java Application event types, only events longer than 20 ms are recorded. (This threshold can be modified when starting the flight recording.) To summarize, the areas may not have recorded events because the application is doing a lot of short tasks, such as writing to a file (a small part at a time) or spending time in synchronization for very short amounts of time.Use the jfr Tool to Find Bottlenecks
Different applications have different bottlenecks. For some applications, a bottleneck may be waiting for I/O or networking, it may be synchronization between threads, or it may be actual CPU usage. For others, a bottleneck may be garbage collection times. It is possible that an application has more than one bottleneck.
One way to find the application bottlenecks is to look at the following events in your flight recording. Make sure that all of these events are enabled in the recording template that you are using:
-
jdk.FileRead jdk.FileWritejdk.SocketReadjdk.SocketWritejdk.JavaErrorThrowjdk.JavaExceptionThrowjdk.JavaMonitorEnterjdk.JavaMonitorWaitjdk.ThreadStartjdk.ThreadEndjdk.ThreadSleepjdk.ThreadPark
The selected Java Application events all have the important property that they are all thread-stalling events. Thread stalling indicates that the thread was not running your application during the event, and they are all duration events. The duration event measures the duration the application was not running.
Use the jfr tool to print the events that were recorded and look for the following information:
jdk.JavaMonitorWaitevents show how much time a thread spends waiting for a monitor.jdk.ThreadSleepandjdk.ThreadParkevents show when a thread is sleeping or parked.- Read and write events show how much time is spent in I/O.
If your Java application's important threads spend a lot of time being blocked, then that means that a critical section of the application is single threaded, which is a bottleneck. If the Java application spends a lot of time waiting for sockets, then the main bottleneck may be in the network or with the other machines that the application communicates with. If your Java application's important threads are spending a lot of time without generating any application events, then the bottleneck in the application is the time spent executing code or the CPU itself. Each of these bottlenecks can be further investigated within the flight recording.
Note:
For most Java Application event types, only events longer than 20 ms are recorded. (This threshold can be modified when starting the flight recording.) To summarize, the areas may not have recorded events because the application is doing a lot of short tasks, such as writing to a file (a small part at a time) or spending time in synchronization for very short amounts of time.Garbage Collection Performance
Flight recordings can help you diagnose garbage collection issues in Java application.
Use JDK Mission Control to Debug Garbage Collection Issues
You can use JMC to debug garbage collections (GC) issues.
Tuning the HotSpot Garbage Collector can have a big effect on performance. See Garbage Collection Tuning Guide for general information.
Take a profiling flight recording of your running application. Do not include the heap statistics, as that will trigger additional old garbage collections. To get a good sample, take a longer recording, for example one hour.
Open the recording in JMC. Look at the Garbage Collections section in the Automated Analysis Results page. Here is a sample figure of a recording, which provides a snapshot of garbage collection performance during runtime.
Figure 4-1 Automated Analysis Results - Garbage Collections
Description of "Figure 4-1 Automated Analysis Results - Garbage Collections "
You can observe from the figure that there is a Full GC event. This is indicative of the fact that application needs more memory than what you have allocated.
For further analysis, open the Garbage Collections page under the JVM Internals page to investigate the overall performance impact of the GC. Here is a sample figure of a recording, which shows a graph with GC pauses.
Figure 4-2 Garbage Collection Performance - GC Pauses
Description of "Figure 4-2 Garbage Collection Performance - GC Pauses"
From the graph look at the Sum of Pauses from the recording. The Sum of Pauses is the total amount of time that the application was paused during a GC. Many GCs do most of their work in the background. In those cases, the length of the GC does not matter and what matters is how long the application actually had to stop. Therefore, the Sum of Pauses is a good measure for the GC effect.
The main performance problems with garbage collections are usually either that individual GCs take too long, or that too much time is spent in paused GCs (total GC pauses).
When an individual GC takes too long, you may need to change the GC strategy. Different GCs have different trade-offs when it comes to pause times verses throughput performance. See Behavior-Based Tuning in Java Platform, Standard Edition HotSpot Virtual Machine Garbage Collection Tuning Guide.
In addition, you may also need to fix your application so that it makes less use of finalizers or semireferences. See Monitoring the Objects Pending Finalization and Finalization and Weak, Soft, and Phantom References in Java Platform, Standard Edition HotSpot Virtual Machine Garbage Collection Tuning Guide for information about detecting and migrating from finalization.
If the application spends too much time paused, you can look into different
ways to overcome this. One way is to increase the Java heap size. Look at the GC
Configuration page to estimate the heap size used by the application, and change the
initial heap size and maximum heap size to a higher value. The bigger the heap, the longer
time it is between GCs. Watch out for any memory leaks in the Java application, because that
may cause more frequent GCs until an OutOfMemoryError is thrown. For more
information, see The jfr tool. Another way to reduce the GC cycles is to allocate fewer temporary objects.
In the TLAB Allocations page, look at how much memory is allocated over the course of
the recording. Small objects are allocated in a Thread Local Area Buffer (TLAB). TLAB is a
small memory area where new objects are allocated. Once a TLAB is full, the thread gets a
new one. Larger objects are allocated outside a TLAB. Often, the majority of allocations
happen inside a TLAB. Lastly, to reduce the need of GCs, decrease the allocation rate.
Select the TLAB Allocations page and then look at the allocation sites that have the
most memory pressure. You can either view it per class or thread to see which one consumes
the most allocation.
Some other settings may also increase GC performance of the Java application. See Garbage Collection Tuning Guide in Java Platform, Standard Edition HotSpot Virtual Machine Garbage Collection Tuning Guide for more information about GC performance.
Use the jfr Tool to Debug Garbage Collection Issues
Recordings from Flight Recorder can help diagnose Java application issues with garbage collections.
Tuning the HotSpot Garbage Collector can have a big effect on performance. See Introduction to Garbage Collection Tuning in Java Platform, Standard Edition HotSpot Virtual Machine Garbage Collection Tuning Guide for more information.
To investigate garbage collection issues, take a profiling flight recording of your application while it is running. Do not include the heap statistics, because that triggers extra old collections. To get a good sample, take a longer recording, for example, 1 hour.
Use the jfr tool to print the jdk.GCPhasePause events that were recorded. The following example shows the information contained in the event:
c:\Program Files\Java\jdk-15\bin>jfr print --events jdk.GCPhasePause \
gctest.jfr
jdk.GCPhasePause {
startTime = 11:19:13.779
duration = 3.419 ms
gcId = 1
name = "GC Pause"
eventThread = "VM Thread" (osThreadId = 17528)
}Using the information from the jdk.GCPhasePause events, you can calculate the average sum of pauses for each GC, the maximum sum of pauses, and the total pause time. The sum of pauses is the total amount of time that the application was paused during a GC. Many GCs do most of their work in the background. In those cases, the length of the GC does not matter and what matters is how long the application actually had to stop. Therefore, the sum of pauses is a good measure for the GC effect.
The main performance problems with garbage collections are usually either that individual GCs take too long, or that too much time is spent in paused GCs (total GC pauses).
When an individual GC takes too long, you may need to change the GC strategy. Different GCs have different trade-offs when it comes to pause times versus throughput performance. See Behavior-Based Tuning in Java Platform, Standard Edition HotSpot Virtual Machine Garbage Collection Tuning Guide.
In addition, you may also need to fix your application so that it makes less use of finalizers or semireferences. See Monitoring the Objects Pending Finalization and Finalization and Weak, Soft, and Phantom References in Java Platform, Standard Edition HotSpot Virtual Machine Garbage Collection Tuning Guide for information about detecting and migrating from finalization.
When the application spends too much time paused, there are different ways to work around that:
-
Increase the Java heap size. The bigger the Java heap, the longer time it is between GCs. Watch out for any memory leaks in the Java application, because that may cause more and more frequent GCs until an
OutOfMemoryErroris thrown. For more information, see The jfr tool. -
To reduce the number of GCs, allocate fewer temporary objects. Small objects are allocated in a Thread Local Area Buffer (TLAB). TLAB is a small memory area where new objects are allocated. Once a TLAB is full, the thread gets a new one. Larger objects are allocated outside a TLAB. Often, the majority of allocations happen inside a TLAB. The
jdk.ObjectAllocationInNewTLABandjdk.ObjectAllocationOutsideTLABevents provide information about the allocation of temporary objects. -
To reduce the need of GCs, decrease the allocation rate. The
jdk.ThreadAllocationStatisticsevent provides information about the allocations per thread.
Some other settings may also increase GC performance of the Java application. See Garbage-First Garbage Collection in Java Platform, Standard Edition HotSpot Virtual Machine Garbage Collection Tuning Guide for more information about GC performance.
Synchronization Performance
Java applications encounter synchronization issues when the application threads spend a lot of time waiting to enter a monitor.
Synchronization Performance
To debug Java Application synchronization issues, which is where the application threads spend a lot of time waiting to enter a monitor, look at the jdk.JavaMonitorWait events in a recording from Flight Recorder.
Look at the locks that are contended the most and the stack trace of the threads waiting to acquire the lock. Typically, look for contention that you did not think would be an issue. Logging is a common area that can be an unexpected bottleneck in some applications.
When you see performance degradation after a program update or at any specific times in the Java application, take a flight recording when things are good, and take another one when things are bad to look for a synchronization site that increases a lot.
Note:
By default, contention events with a duration longer than 20 ms are recorded. This threshold can be modified when starting the flight recording. Shorter thresholds give more events and also potentially more overhead. If you believe contention is an issue, then you could take a shorter recording with a very low threshold of only a few milliseconds. When this is done on a live application, make sure to start with a very short recording, and monitor the performance overhead.Use jdk.JavaMonitorWait Events to Debug Synchronization Issues
To debug Java Application synchronization issues, which is where the application threads spend a lot of time waiting to enter a monitor, look at the jdk.JavaMonitorWait events in a recording from Flight Recorder.
Look at the locks that are contended the most and the stack trace of the threads waiting to acquire the lock. Typically, look for contention that you did not think would be an issue. Logging is a common area that can be an unexpected bottleneck in some applications.
When you see performance degradation after a program update or at any specific times in the Java application, take a flight recording when things are good, and take another one when things are bad to look for a synchronization site that increases a lot.
Note:
By default, contention events with a duration longer than 20 ms are recorded. This threshold can be modified when starting the flight recording. Shorter thresholds give more events and also potentially more overhead. If you believe contention is an issue, then you could take a shorter recording with a very low threshold of only a few milliseconds. When this is done on a live application, make sure to start with a very short recording, and monitor the performance overhead.I/O Performance
Flight recordings can help you diagnose I/O performance issues in Java application.
I/O Performance
When a Java application spends a lot of time reading or writing sockets or files, then I/O or networking may be the bottleneck. Recordings from Flight Recorder can help identify problem areas.
To diagnose I/O issues in applications, look at the following events in your flight recording. Make sure that all of these events are enabled in the recording template that you are using:
jdk.SocketWritejdk.SocketReadjdk.FileWritejdk.FileRead
Use the socket read and write information in your flight recording to calculate the number of reads from a specific remote address, the total number of bytes read, and the total time spent waiting. Look at each event to analyze the time spent and data read.
File or networking I/O issues are diagnosed in a similar fashion. Look at the files read to or written to the most, then see each file read/write and the time spent on I/O.
By default, only events with a duration longer than 20 ms are recorded. When starting a flight recording, you can lower the file I/O threshold or the socket I/O threshold to gather more data, potentially with a higher performance effect.
Use the Socket Read and Write Events to Debug I/O Issues
When a Java application spends a lot of time reading or writing sockets or files, then I/O or networking may be the bottleneck. Recordings from Flight Recorder can help identify problem areas.
To diagnose I/O issues in applications, look at the following events in your flight recording. Make sure that all of these events are enabled in the recording template that you are using:
jdk.SocketWritejdk.SocketReadjdk.FileWritejdk.FileRead
Use the socket read and write information in your flight recording to calculate the number of reads from a specific remote address, the total number of bytes read, and the total time spent waiting. Look at each event to analyze the time spent and data read.
File or networking I/O issues are diagnosed in a similar fashion. Look at the files read to or written to the most, then see each file read/write and the time spent on I/O.
By default, only events with a duration longer than 20 ms are recorded. When starting a flight recording, you can lower the file I/O threshold or the socket I/O threshold to gather more data, potentially with a higher performance effect.
Code Execution Performance
Flight recordings can help you diagnose code execution performance issues in Java application.
Code Execution Performance
When there are not a lot of Java Application events, it could be that the main bottleneck of your application is the running code. Recordings from Flight Recorder can help identify problem areas.
Look at the jdk.CPULoad events and review the CPU usage over time. This shows the CPU usage of the JVM being recorded and the total CPU usage on the machine. If the JVM CPU usage is low, but the CPU usage of the machine is high, then some other application is likely taking a lot of CPU. In that case, look at the other applications running on the system using OS tools such as Top or the task manager to find out which processes are using a lot of CPU.
In case your application is using a lot of CPU time, look at jdk.ThreadCPULoad events and identify the threads that use the most CPU time. This information is based on method sampling, so it may not be 100% accurate if the sample count is low. When a recording is running, the JVM samples the threads. By default, a continuous recording does only some method sampling, while a profiling recording does as much as possible. The method sampling gathers data from only those threads running code. The threads waiting for I/O, sleeping, waiting for locks, and so on are not sampled. Therefore, threads with a lot of method samples are the ones using the most CPU time; however, how much CPU is used by each thread is not known.
The Hot Methods tab in the Code tab group helps find out where your application spends most of the execution time. This tab shows all the samples grouped by top method in the stack. Use the Call Tree tab to start with the lowest method in the stack traces and then move upward. starts with Thread.run, and then looks at the calls that have been most sampled.
Use jdk.CPULoad and jdk.ThreadCPULoad Events to Monitor Code Execution Performance
When there are not a lot of Java Application events, it could be that the main bottleneck of your application is the running code. Recordings from Flight Recorder can help identify problem areas.
Look at the jdk.CPULoad events and review the CPU usage over time. This shows the CPU usage of the JVM being recorded and the total CPU usage on the machine. If the JVM CPU usage is low, but the CPU usage of the machine is high, then some other application is likely taking a lot of CPU. In that case, look at the other applications running on the system using OS tools such as Top or the task manager to find out which processes are using a lot of CPU.
In case your application is using a lot of CPU time, look at jdk.ThreadCPULoad events and identify the threads that use the most CPU time. This information is based on method sampling, so it may not be 100% accurate if the sample count is low. When a recording is running, the JVM samples the threads. By default, a continuous recording does only some method sampling, while a profiling recording does as much as possible. The method sampling gathers data from only those threads running code. The threads waiting for I/O, sleeping, waiting for locks, and so on are not sampled. Therefore, threads with a lot of method samples are the ones using the most CPU time; however, how much CPU is used by each thread is not known.
The Hot Methods tab in the Code tab group helps find out where your application spends most of the execution time. This tab shows all the samples grouped by top method in the stack. Use the Call Tree tab to start with the lowest method in the stack traces and then move upward. starts with Thread.run, and then looks at the calls that have been most sampled.