Analyzing hung Java process

This post focuses on jdk command line tool jhsdb

Posted by Vipin Sharma on Saturday, May 29, 2021 Tags: OpenJDK tools   11 minute read

This is a draft post, work in progress:

jhsdb is a Serviceability Agent (SA) tool. Serviceability Agent (SA) is a JDK component used to provide snapshot debugging, performance analysis and to get an in-depth understanding of the Hotspot JVM, and the Java application executed by the Hotspot JVM.

Even though native debuggers like gdb are available for examining the JVM, unlike jhsdb, these native debuggers do not have an inbuilt understanding of the data structures in Hotspot and hence, are not able to throw insights on the Java application being executed. jhsdb knows about the locations and address ranges of crucial components of the JVM like the Java heap, heap generations, regions, code cache, etc.

We use the jhsdb tool to attach to a hanged Java process or to a core dump from a crashed Java Virtual Machine (JVM).


Troubleshooting a Java Application with jhsdb

jhsdb modes

Following are 7 modes available in jhsdb

jhsdb clhsdb    Starts the interactive command-line debugger.
jhsdb debugd    Starts the remote debug server.
jhsdb hsdb      Starts the interactive GUI debugger.
jhsdb jstack    Prints stack and locks information.
jhsdb jmap      Prints heap information.
jhsdb jinfo     Prints basic JVM information.
jhsdb jsnap     Prints performance counter information.

Structure of commands

Following is structure of commands to use with jhsdb.

jhsdb clhsdb [--pid pid | --exe executable --core coredump]

jhsdb debugd [options] (pid | executable coredump) [--serverid]

jhsdb hsdb [--pid pid | --exe executable --core coredump]

jhsdb jstack [--pid pid | --exe executable --core coredump] [options]

jhsdb jmap [--pid pid | --exe executable --core coredump] [options]

jhsdb jinfo [--pid pid | --exe executable --core coredump] [options]

jhsdb jsnap [options] [--pid pid | --exe executable --core coredump]

--pid

The process ID to which the jhsdb tool should attach. 

--serverid

An optional unique ID to use when multiple debug servers are running on the same remote host.

--exe

The Java executable file from which the core dump was produced.

--core

The core dump file to which the jhsdb tool should attach.

options

Each mode has its separate list of options, which we can see using help (e.g. jhsdb jstack --help)


Java program we will be debugging in this post

Following is the java class we are going to run and try to understand different features available in jhsdb.

import java.util.concurrent.*;
import java.util.concurrent.locks.*;

public class DeadlockAOS
{
    private static Lock lock1 = new ReentrantLock();
    private static Lock lock2 = new ReentrantLock();
    private static int number_of_threads=2;

    public static void main(String args[])
    {
        ExecutorService executorService = Executors.newFixedThreadPool(number_of_threads);
        for (int i=0; i<number_of_threads/2; i++)
        {
            executorService.execute(new Task1());
            executorService.execute(new Task2());
        }

        executorService.shutdown();

    }

    static class Task1 implements Runnable
    {
        @Override
        public void run()
        {
            while(true)
            {
                try
                {
                    lock1.lock();
                    lock2.lock();
                }
                catch(Exception e)
                {
                    System.out.println(e.getMessage());
                }

                finally
                {
                    lock1.unlock();
                    lock2.unlock();
                }
            }

        }

    }

    static class Task2 implements Runnable
    {
        @Override
        public void run()
        {
            while(true)
            {
                try
                {
                    lock2.lock();
                    lock1.lock();
                }
                catch(Exception e)
                {
                    System.out.println(e.getMessage());
                }

                finally
                {
                    lock2.unlock();
                    lock1.unlock();
                }

            }
        }

    }

}


For all our examples we will be using Java 17, as of writing this post it is built using JDK master branch. This post explains how to build JDK from the source.

java -version
openjdk version "17-internal" 2021-09-14
OpenJDK Runtime Environment (build 17-internal+0-adhoc.vipin.jdk)
OpenJDK 64-Bit Server VM (build 17-internal+0-adhoc.vipin.jdk, mixed mode)


Connecting jhsdb with Java process

Following are three ways to connect jhsdb with a Java process:

  1. –pid option: Provide process id to connect with process (e.g. jhsdb jstack –pid 1234)
  2. –core option: Use core dump file to connect with process (e.g. jhsdb jstack –core ./core.1234 –exe ./myexe)
  3. –connect option: Start debug server using jhsdb debugd and use connect option (e.g. jhsdb jstack –connect id@debugserver:1234)


Using pid to connect with a hanged process

It is important to note we are trying to connect with a hanged process, if process is running it may get hang after we connect with jhsdb. Following command connects jhsdb with a java process and executes it in jstack mode to get thread dump:

jhsdb jstack --pid 26697

Following are some command showing clhsdb mode.

This is command to connect jhsdb with pid 26697

jhsdb clhsdb --pid 26697
Attaching to process 26697, please wait...

After attaching jhsdb threads command fetches list of threads along with thread ids.

hsdb> threads
...
26758 pool-1-thread-2
State: BLOCKED
Stack in use by Java: 0x00007f92ca8835a0 .. 0x00007f92ca883a78
Base of Stack: 0x00007f92ca885000
Last_Java_SP: 0x00007f92ca8835a0
Last_Java_FP: 0x00007f92ca883610
Last_Java_PC: 0x00007f930900d84b
Thread id: 26758
...

In this following command we are trying to get stack trace for thread id 26758

hsdb> where 26758
Thread 26758 Address: 0x00007f93183ec510

Java Stack Trace for pool-1-thread-2
Thread state = BLOCKED
- public native void park(boolean, long) @0x00007f92cb8c7f58 @bci = 0, pc = 0x00007f930900d87a (Interpreted)
    - parking to wait for <0x0000000452e9c678> (a java/util/concurrent/locks/ReentrantLock$NonfairSync)
- public static void park(java.lang.Object) @0x00007f92cb9a1e50 @bci = 14, line = 211, pc = 0x00007f930900924a (Interpreted)
- final int acquire(java.util.concurrent.locks.AbstractQueuedSynchronizer$Node, int, boolean, boolean, boolean, long) @0x00007f92cbbdc218 @bci = 347, line = 715, pc = 0x00007f930900924a, oop = 0x0000000452e9c678 (Interpreted)
- public final void acquire(int) @0x00007f92cbbdc8d0 @bci = 15, line = 938, pc = 0x00007f930900935e, oop = 0x0000000452e9c678 (Interpreted)
- final void lock() @0x00007f92cbce6cc0 @bci = 9, line = 153, pc = 0x00007f930900924a, oop = 0x0000000452e9c678 (Interpreted)
- public void lock() @0x00007f92cb99f778 @bci = 4, line = 322, pc = 0x00007f930900924a, oop = 0x0000000452e9c528 (Interpreted)
- public void run() @0x00007f92cbc0e978 @bci = 11, line = 61, pc = 0x00007f93090096ba, oop = 0x0000000452e9fd88 (Interpreted)
- final void runWorker(java.util.concurrent.ThreadPoolExecutor$Worker) @0x00007f92cbcec6d8 @bci = 92, line = 1135, pc = 0x00007f93090096ba, oop = 0x0000000452e9cc30 (Interpreted)
- public void run() @0x00007f92cbc40680 @bci = 5, line = 635, pc = 0x00007f930900924a, oop = 0x0000000452e9fd98 (Interpreted)
- public void run() @0x00007f92cb844170 @bci = 11, line = 831, pc = 0x00007f93090096ba, oop = 0x0000000452e9fdc8 (Interpreted)


Connecting jhsdb with core dump file

When Java process has generated core dump file, we can connect this with jhsdb and do further analysis e.g. take thread dump, heap dump.

First command to connect jhsdb with core dump file, filename: core

jhsdb clhsdb --core ./core --exe /home/vipin/githubprojects/jdk/build/linux-x86_64-server-fastdebug/jdk/bin/java
Opening core file, please wait...
hsdb>

This is command to get list of threads along with thread ids.

hsdb> threads
...
37825 pool-1-thread-2
State: BLOCKED
Stack in use by Java: 0x00007f24e78f65a0 .. 0x00007f24e78f6a78
Base of Stack: 0x00007f24e78f8000
Last_Java_SP: 0x00007f24e78f65a0
Last_Java_FP: 0x00007f24e78f6610
Last_Java_PC: 0x00007f254500d84b
Thread id: 37825
...

In this following command we are trying to get stack trace for thread id 37825

hsdb> where 37825
Thread 37825 Address: 0x00007f25543dc1f0

Java Stack Trace for pool-1-thread-2
Thread state = BLOCKED
- public native void park(boolean, long) @0x00007f251ccc7f58 @bci = 0, pc = 0x00007f254500d87a (Interpreted)
    - parking to wait for <0x0000000452e9c670> (a java/util/concurrent/locks/ReentrantLock$NonfairSync)
- public static void park(java.lang.Object) @0x00007f251cda1e50 @bci = 14, line = 211, pc = 0x00007f254500924a (Interpreted)
- final int acquire(java.util.concurrent.locks.AbstractQueuedSynchronizer$Node, int, boolean, boolean, boolean, long) @0x00007f251cfdc218 @bci = 347, line = 715, pc = 0x00007f254500924a, oop = 0x0000000452e9c670 (Interpreted)
- public final void acquire(int) @0x00007f251cfdc8d0 @bci = 15, line = 938, pc = 0x00007f254500935e, oop = 0x0000000452e9c670 (Interpreted)
- final void lock() @0x00007f251d0e6cc0 @bci = 9, line = 153, pc = 0x00007f254500924a, oop = 0x0000000452e9c670 (Interpreted)
- public void lock() @0x00007f251cd9f778 @bci = 4, line = 322, pc = 0x00007f254500924a, oop = 0x0000000452e9c520 (Interpreted)
- public void run() @0x00007f251d00e978 @bci = 11, line = 61, pc = 0x00007f25450096ba, oop = 0x0000000452e9fd80 (Interpreted)
- final void runWorker(java.util.concurrent.ThreadPoolExecutor$Worker) @0x00007f251d0ec6d8 @bci = 92, line = 1135, pc = 0x00007f25450096ba, oop = 0x0000000452e9cc28 (Interpreted)
- public void run() @0x00007f251d040680 @bci = 5, line = 635, pc = 0x00007f254500924a, oop = 0x0000000452e9fd90 (Interpreted)
- public void run() @0x00007f251cc44170 @bci = 11, line = 831, pc = 0x00007f25450096ba, oop = 0x0000000452e9fdc0 (Interpreted)


Starting debugd server and connecting using –connect option

Following is command to start debug server:

jhsdb debugd --pid 5069 --serverid test

This is command to connect with the server we started in above thread:

jhsdb jstack --connect test@localhost

Following is command to connect jhsdb in clhsdb mode, after this we can use all the clhsdb specific commands.

jhsdb clhsdb --pid 48584


Conclusion

Utilities like this are very useful in a situation when we need to analyze and resolve problems in production Java application quickly. jhsdb is an amazing utility part of JDK itself, no need to install any third party software.

If you want to get amazing Java jobs, I wrote an ebook 5 steps to Best Java Jobs. You can download this step-by-step guide for free!


Resources

  1. Java tools reference