Thread dump using jstack or jcmd Thread.print command with -l option sometimes takes long time.

Environment

• OpenJDK 8
• OpenJDK 11
• OpenJDK 17
• OpenJDK 21

Issue

• jstack -l <pid> or jcmd <pid> Thread.print -l command sometimes takes several seconds or tens of seconds.

Resolution

Run jstack or jcmd Thread.print command without giving -l option if you do not need information on java.util.concurrent locks output by -l option like (*1-1).

(*1) Example output by -l option

"IdleRemover" #119 daemon prio=5 os_prio=0 cpu=0.90ms elapsed=27.09s tid=0x000056439777e800 nid=0x44a30 waiting on condition  [0x00007fd26cec1000]
   java.lang.Thread.State: TIMED_WAITING (parking)
        at jdk.internal.misc.Unsafe.park(java.base@11.0.22/Native Method)
        - parking to wait for  <0x00000000f9c37c28> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
        at java.util.concurrent.locks.LockSupport.parkNanos(java.base@11.0.22/LockSupport.java:234)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(java.base@11.0.22/AbstractQueuedSynchronizer.java:2211)
        at org.jboss.jca.core.connectionmanager.pool.idle.IdleRemover$IdleRemoverRunner.run(IdleRemover.java:261)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@11.0.22/ThreadPoolExecutor.java:1128)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@11.0.22/ThreadPoolExecutor.java:628)
        at java.lang.Thread.run(java.base@11.0.22/Thread.java:829)

   Locked ownable synchronizers:                                                    <---------- (*1-1)
        - <0x00000000f9c37a40> (a java.util.concurrent.ThreadPoolExecutor$Worker)   <---------- (*1-1)

Regarding lock information by Java language's basic synchronization mechanism (synchronized method or synchronized block) like (*2-1), you can get it without giving -l option.

(*2) Example output when without -l option

"default I/O-1" #102 prio=5 os_prio=0 cpu=0.19ms elapsed=420.04s tid=0x0000564397a33800 nid=0x44a1f runnable  [0x00007fd26c15e000]
   java.lang.Thread.State: RUNNABLE
        at sun.nio.ch.EPoll.wait(java.base@11.0.22/Native Method)
        at sun.nio.ch.EPollSelectorImpl.doSelect(java.base@11.0.22/EPollSelectorImpl.java:120)
        at sun.nio.ch.SelectorImpl.lockAndDoSelect(java.base@11.0.22/SelectorImpl.java:124)
        - locked <0x00000000f9c00928> (a sun.nio.ch.Util$2)                         <---------- (*2-1)
        - locked <0x00000000f9c008d0> (a sun.nio.ch.EPollSelectorImpl)              <---------- (*2-1)
        at sun.nio.ch.SelectorImpl.select(java.base@11.0.22/SelectorImpl.java:141)
        at org.xnio.nio.WorkerThread.run(WorkerThread.java:532)

Root Cause

Both jstack and jcmd Thread.print commands request JVM operations for thread dump (PrintThreads, etc.) to the target Java process. Running these commands with -l option causes scan for the whole Java Heap space for finding all synchronizers (i.e. all AbstractOwnableSynchronizer objects used by some java.util.concurrent classes like ReentrantLock, ReentrantReadWriteLock, CountDownLatch, Semaphore or ThreadPoolExecutor) in the target Java process in order to get -l option specific information.

Therefore, if the target Java process has a large Java Heap space (e.g. tens of GB or more than 100 GB Java Heap) and quite many Java objects are allocated in it, jstack or jcmd with -l option may take long time depending on the total number of objects in the Java Heap.

This solution is part of Red Hat’s fast-track publication program, providing a huge library of solutions that Red Hat engineers have created while supporting our customers. To give you the knowledge you need the instant it becomes available, these articles may be presented in a raw and unedited form.