Jump to content
Wikitech

Data Platform/Systems/Java

From Wikitech

Thread Dump

A thread dump will provide a state of all active threads within the java process at that particular point of time.

Each thread is displayed with it's stack trace.

It is written in plain text that can be saved in file for later analysis.

It is useful for diagnosing different issues (deadlock, thread contention, performance issues...)

How to take a java thread dump

Thread dumps from most Java processes

  • Connect as the user running the java process
  • Run the below command
jstack-l$(pgrep-ajava|grep<arg_to_identify_process>|awk'{print 1ドル}')

It is usually interesting to get multiple thread dump in a row (for ex. one thread dump taken every 1/10 second 5/30 times)

foriin{1..30};dojstack-l$(pgrep-ajava|greppresto|awk'{print 1ドル}')>/tmp/threaddump-$(date+%s).txt;sleep1;done

Having multiple thread dumps permits to check how the threads are evolving.

For ex. it can help detect threads waiting for a lock during multiple thread dump and identify which thread is taking that lock (from which part of the code the lock is taken)

Thread dumps from Apache Spark

Apache Spark provides a built-in thread dump facility in its User Interface:

  1. Go to https://yarn.wikimedia.org/, login, and figure out the Spark job you're interested in. Click on it. Now click on the 'Application Master' link to proxy into the Spark job's UI.
  2. You can now click on the 'executors' tab. You will be shown a table with a row for each executor and for the driver. For each row, you will see at the far right a link aptly named 'Thread Dump'. Each time you click on the link a new thread dump for that java process is made, and you are redirected to a UI facility where you can explore and analyze the dump right there.

Analyzing the thread dump

Spotify provide an interesting online thread dump analyzer

Threads are group per stack to facilitate reading it.

It provide a view of object locks with the thread holding them and the threads waiting for it:

Another solution to analyze thread dump.

Locks between threads are easy to identify.

It provide comparative view between to thread dump to identify threads stuck from one dump to another

GC analysis

Enabling GC logs

When the JVM is facing long pause duration tuning the GC es needed.

If the JVM is facing OutOfMemory tuning the GC won't help.

In order to know how to tune the JVM gc logs must be enabled.

Depending to were time is spend multiple specific tag can be added to get more details. Those tags also depends on the garbage collector used by the java process: https://newrelic.com/blog/best-practices/java-garbage-collection#toc-what-garbage-collectors-are-available-for-java-

Ex. of basic GC logs configuration:

  • Java 8
-XX:-PrintCommandLineFlags-XX:+PrintGCDetails-XX:+PrintGCTimeStamps-XX:+PrintGCDateStamps-XX:+PrintGCApplicationStoppedTime-XX:+PrintAdaptiveSizePolicy-XX:+PrintTenuringDistribution-XX:+UseGCLogFileRotation-Xloggc:/tmp/gc.log-XX:NumberOfGCLogFiles=10-XX:GCLogFileSize=10m
  • java 11 and greater
-Xlog:gc=debug:file=/tmp/gc.log:time,uptime,level,tags:filecount=10,filesize=10m

Analyzing GC logs

Analyzing the GC logs file need to understand the behavior of the garbage collector used on the java process.

Then you should be able to know which step is slow and what potential tuning can be done.

Some tools like this website can provide good insight on root cause of slow GC: https://gceasy.io/

OutOfMemory/HeapDump

When facing OOM or bad memory usage it is possible to generate heap dump in order to understand which objects are using the memory.

Enabling HeapDump on OutOfMemmory

Add below java option to your java process

-XX:+HeapDumpOnOutOfMemoryError-XX:HeapDumpPath=/tmp/heapdump.bin

Ensure you have enough space on the HeapDumpPath to store it (it can take up to the Xmx size)

Generating HeapDump manually

As the user running the java process run below command

jmap-dump:format=b,file=/tmp/heapdump.bin<pid>

Ensure you have enough space on the HeapDumpPath to store it (it can take up to the Xmx size)

Analyzing it

Analyzing a Heap Dump is a memory intensive. It could require same amount of memory to do parse it than the max memory configured on the java process.

MAT comes with a ParseHeapDump.sh script to do the parsing in cli which can be interesting to run it on a server having enough memory.

Once parsing done MAT can look at memory leak or let you browse the list of objects within the heap and links between them.

Jcmd

Utility to send diagnostic command request to the JVM

Running below command will provide a live view of the heap usage

>jcmd<pid>GC.class_histogram|more
<pid>:
num#instances #bytes class name (module)
-------------------------------------------------------
1:143966143151864[B(java.base@13.0.14)
2:1629249532104[I(java.base@13.0.14)
3:1230932954232java.lang.String(java.base@13.0.14)
4:327142878832java.lang.reflect.Method(java.base@13.0.14)
5:381512168912[Ljava.lang.Object;(java.base@13.0.14)
6:156381836280java.lang.Class(java.base@13.0.14)
7:418031672120java.util.LinkedHashMap$Entry(java.base@13.0.14)
8:192211471400[Ljava.util.HashMap$Node;(java.base@13.0.14)
9:322841033088java.util.concurrent.ConcurrentHashMap$Node(java.base@13.0.14)
10:732994672[C(java.base@13.0.14)
11:17012952672java.util.LinkedHashMap(java.base@13.0.14)
12:25410813120java.util.HashMap$Node(java.base@13.0.14)
13:22785729120javax.management.MBeanAttributeInfo(java.management@13.0.14)
14:27168630520[Ljava.lang.Class;(java.base@13.0.14)
15:22974551376org.glassfish.jersey.server.internal.routing.CombinedMediaType$EffectiveMediaType
16:22583541992java.util.ArrayList(java.base@13.0.14)
17:12096483840java.util.TreeMap$Entry(java.base@13.0.14)
18:15491371784java.util.LinkedList$Node(java.base@13.0.14)
19:15311367464java.util.Collections$UnmodifiableRandomAccessList(java.base@13.0.14)
20:11543336336[Ljava.lang.String;(java.base@13.0.14)
21:20831333296java.lang.Object(java.base@13.0.14)
22:13733329592org.weakref.jmx.NestedMBeanAttribute
23:849317408[Ljava.util.concurrent.ConcurrentHashMap$Node;(java.base@13.0.14)
24:6146295008java.util.HashMap(java.base@13.0.14)
25:3683294640java.lang.reflect.Constructor(java.base@13.0.14)
26:4539290496java.net.URL(java.base@13.0.14)
27:4001288072java.lang.reflect.Field(java.base@13.0.14)
28:2236286208sun.nio.fs.UnixFileAttributes(java.base@13.0.14)

It can also help to do memory allocation profiling with tool like async-profiler in order to map the instances usage with the methods call

Profile Analysis

When facing some bad CPU usage or huge memory allocation rate preforming some profiling can help

async-profiler

https://github.com/async-profiler/async-profiler

They are multiple profiling tool but this one is providing good set of feature and is fully open source.

It is a low overhead sampling profiler. It can be attached to any running JVM, no need to start the JVM with a specific java agent.

How to use it

As of now this profiler is not automatically installed on servers running java based process

You will have first to download it locally and then to scp it on the server running the java instance to profile: https://github.com/async-profiler/async-profiler/releases/download/v2.9/async-profiler-2.9-linux-x64.tar.gz

Then run below command to get a flamegraph:

# Profile for 30s cpu usage
sudo./profiler.sh--fdtransfer-ecpu-oflamegraph-d30-f/tmp/test.html<pid>
# Profile for 30s memory allocation usage
sudo./profiler.sh--fdtransfer-ealloc-oflamegraph-d30-f/tmp/test.html<pid>

Ex. of CPU profiling Flamegraph from one presto node

From that flamegraph you can see that 22% of the cpu usage is done doing some kerberos authenticate action.

AltStyle によって変換されたページ (->オリジナル) /