Taking ThreadDump from Java Code

Copied from HERE with some code modification.

import java.io.ByteArrayOutputStream;
import java.io.UnsupportedEncodingException;
import java.lang.management.ManagementFactory;
import java.util.Scanner;
import java.util.concurrent.Executors;
import java.util.concurrent.ScheduledExecutorService;
import java.util.concurrent.TimeUnit;
import java.util.concurrent.atomic.LongAdder;

public class StackTraceUtils {
	private static final char PID_SEPERATOR = '@';
	private static String pathToJStack = "jstack";


	private static String acquirePid()
	{
		String mxName = ManagementFactory.getRuntimeMXBean().getName();

		int index = mxName.indexOf(PID_SEPERATOR);

		String result;

		if (index != -1) {
			result = mxName.substring(0, index);
		} else {
			throw new IllegalStateException("Could not acquire pid using " + mxName);
		}

		return result;
	}


	public static String executeJstack()
	{
		ProcessInterface pi = new ProcessInterface();

		int exitCode;

		ByteArrayOutputStream byteArrayOutputStream = new ByteArrayOutputStream();

		try {
			exitCode = pi.run(new String[] { pathToJStack, "-l", acquirePid(),}, byteArrayOutputStream);
		} catch (Exception e) {
			throw new IllegalStateException("Error invoking jstack", e);
		}

		if (exitCode != 0) {
			throw new IllegalStateException("Bad jstack exit code " + exitCode);
		}


		try {
			String str = new String(byteArrayOutputStream.toByteArray(), "UTF-8");
			return str;
		} catch (UnsupportedEncodingException e) {
			throw new RuntimeException(e);
		}

	}

	public static void main(String[] args) {

		final String s = executeJstack();
		System.out.println("s = " + s);
	}
}




import java.io.BufferedReader;
import java.io.BufferedWriter;
import java.io.File;
import java.io.IOException;
import java.io.InputStream;
import java.io.InputStreamReader;
import java.io.OutputStream;
import java.io.OutputStreamWriter;
import java.util.HashMap;
import java.util.HashSet;
import java.util.Map;
import java.util.Map.Entry;
import java.util.Set;

public class ProcessInterface
{	
	private final Map<String, String> addModifyEnv;
	private final Set<String> removeEnv;
	
	static class StreamGobbler extends Thread
	{
		private static int gobblerNumber = 0;
		
		private final InputStream is;
		private final OutputStream os;
		
		private static synchronized int getNextGobblerNumber()
		{
			return gobblerNumber++;
		}
		
		public StreamGobbler(InputStream is, OutputStream os)
		{
			super("StreamGobblerThread-" + getNextGobblerNumber());
			
			this.is = is;
			this.os = os;
		}
		
		@Override
		public void run()
		{
			try
			{
				OutputStreamWriter osw = new OutputStreamWriter(os);
				BufferedWriter bw = new BufferedWriter(osw);
				
				InputStreamReader isr = new InputStreamReader(is);
				BufferedReader br = new BufferedReader(isr);
				
				String line = null;
				
				while ((line = br.readLine()) != null)
				{
					bw.write(line);
					bw.newLine();
				}
				
				bw.flush();
				osw.flush();
			}
			catch (IOException ioe)
			{
				throw new IllegalStateException(ioe);
			}
		}
	}
	
	public ProcessInterface()
	{
		this.addModifyEnv = new HashMap<String, String>();
		this.removeEnv = new HashSet<String>();
	}
	
	public void removeEnv(String name)
	{
		if (addModifyEnv.containsKey(name))
		{
			addModifyEnv.remove(name);
		}
		
		removeEnv.add(name);
	}
	
	public void addEnv(String name, String value)
	{
		if (removeEnv.contains(name))
		{
			removeEnv.remove(name);
		}
		
		addModifyEnv.put(name, value);
	}
	
	public int run(String[] command) throws InterruptedException, IOException
	{
		return run(command, null, null, null);
	}
	
	public int run(String[] command, File workingDir) throws InterruptedException, IOException
	{
		return run(command, null, null, workingDir);
	}
	
	public int run(String[] command, OutputStream os) throws InterruptedException, IOException
	{
		return run(command, os, os, null);
	}
	
	public int run(String[] command, OutputStream os, File workingDir) throws InterruptedException, IOException
	{
		return run(command, os, os, workingDir);
	}
	
	public int run(String[] command, OutputStream std, OutputStream err, File workingDir)
			throws InterruptedException, IOException
	{
		StringBuilder sb = new StringBuilder();
		
		for (String s : command)
		{
			sb.append(s);
			sb.append(" ");
		}
		
		ProcessBuilder builder = new ProcessBuilder();
		
		if (workingDir != null)
		{
			builder.directory(workingDir);
		}
		
		Map<String, String> env = builder.environment();
		
		for (String name : removeEnv)
		{
			env.remove(name);
		}
		
		for (Entry<String, String> entry : addModifyEnv.entrySet())
		{
			env.put(entry.getKey(), entry.getValue());
		}
		
		builder.command(command);
		
		Process process = builder.start();
		
		OutputStream outStream = ((std == null) ? System.out : std);
		OutputStream errStream = ((err == null) ? System.err : err);
		
		StreamGobbler outputGobbler = new StreamGobbler(process.getInputStream(), outStream);
		StreamGobbler errorGobbler = new StreamGobbler(process.getErrorStream(), errStream);
		
		outputGobbler.start();
		errorGobbler.start();
		
		int exitVal = process.waitFor();
		
		return exitVal;
	}
}


This can be very helpful, for example in a code block you suspect there is a deadlock, for Example timeout from connection pool , you can log the stacktrace so you can come back later and run a ThreadDump analysis tool on it. Add it to your code before the Operations guy restart your problematic server and report an issue in your name !

Finding the Bad Apple in JVM

If you run into situation where you have to troubleshoot a JVM that consumes high CPU and you have absolutely no idea whats causing it, here are some very useful tricks that saved my life countless time.

top:
Most of us use Top often but there are some handy params that can be even more helpful.

First Do a top to get the Cpu Hungry process id.

#top
top - 14:33:22 up 42 days, 7:11, 2 users, load average: 1.60, 1.62, 1.56
Tasks: 154 total, 1 running, 153 sleeping, 0 stopped, 0 zombie
Cpu(s): 77.8%us, 0.8%sy, 0.0%ni, 21.5%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Mem: 8061328k total, 7545548k used, 515780k free, 134776k buffers
Swap: 2097148k total, 162800k used, 1934348k free, 798096k cached</code>

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
12058 root 20 0 13.3g 4.7g 21m S 302.0 61.5 41219:31 java
18205 root 20 0 4273m 948m 6244 S 11.3 12.0 1704:03 java
12056 root 20 0 22032 1080 920 S 0.7 0.0 62:33.48 wrapper-linux-x
1 root 20 0 19356 1244 1052 S 0.0 0.0 0:03.22 init
2 root 20 0 0 0 0 S 0.0 0.0 0:00.00 kthreadd

Ok, clearly, the process with PID 12058 isn’t behaving properly.

Lets ask ‘top’ to list the child-process (one to one binding with each thread in JVM) for PID 12058

-H Flags turns on the Threads Toggle
-H : Threads toggle
Starts top with the last remembered ’H’ state reversed. When this toggle is On, all individual threads will be displayed. Other-
wise, top displays a summation of all threads in a process.

## top -p 12058 -H (-p only lists child process for 12058 )

&nbsp;

[mule@FSASYDESBPROD02 ~]# top -p $PID -H
top - 15:09:49 up 42 days, 7:48, 2 users, load average: 1.34, 1.50, 1.54
Tasks: 5359 total, 3 running, 5356 sleeping, 0 stopped, 0 zombie
Cpu(s): 77.8%us, 1.2%sy, 0.0%ni, 20.9%id, 0.0%wa, 0.0%hi, 0.1%si, 0.0%st
Mem: 8061328k total, 7740576k used, 320752k free, 135436k buffers
Swap: 2097148k total, 162652k used, 1934496k free, 833864k cached

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
28255 root 20 0 13.3g 4.9g 21m R 98.3 63.3 10163:33 java
14064 root 20 0 13.3g 4.9g 21m R 97.7 63.3 14089:00 java
14062 root 20 0 13.3g 4.9g 21m R 97.4 63.3 14073:55 java
925 root 20 0 13.3g 4.9g 21m S 1.9 63.3 279:22.62 java
12060 root 20 0 13.3g 4.9g 21m S 0.6 63.3 108:39.51 java

Ok, so Thread $28255 & $14064 is doing a lot of stuff. How do we know what they are doing??

jstack in rescue !

"AsyncLoggerConfig-1" daemon prio=10 tid=0x00007f45ec2ab000 nid=0x2f27 waiting on condition [0x00007f45e1e22000]
java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043)
at com.lmax.disruptor.BlockingWaitStrategy.waitFor(BlockingWaitStrategy.java:45)
at com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:55)
at com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:123)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)

In the jstack trace, the nid=0x2f27 is the hex of the pid we received before. So lets awk it!

bash# PID=12058
bash# NID=28255
bash# jstack $PID | awk '/ nid='"$(printf '%#x' $NID)"' /,/^$/'</code>

"pool-1140-thread-1" prio=10 tid=0x00007f45706b4000 nid=0x6e5f runnable [0x00007f453247a000]
java.lang.Thread.State: RUNNABLE
at sun.reflect.Reflection.getCallerClass0(Native Method)
at sun.reflect.Reflection.getCallerClass(Reflection.java:69)
at sun.reflect.GeneratedMethodAccessor1.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.apache.logging.log4j.util.ReflectionUtil.getCallerClass(ReflectionUtil.java:123)
at org.apache.logging.log4j.util.ReflectionUtil.getCallerClass(ReflectionUtil.java:230)
at org.apache.logging.log4j.jul.AbstractLoggerAdapter.getContext(AbstractLoggerAdapter.java:34)
at org.apache.logging.log4j.spi.AbstractLoggerAdapter.getLogger(AbstractLoggerAdapter.java:42)
at org.apache.logging.log4j.jul.LogManager.getLogger(LogManager.java:89)
at java.util.logging.LogManager.demandLogger(LogManager.java:430)
at java.util.logging.Logger.demandLogger(Logger.java:346)
at java.util.logging.Logger.getLogger(Logger.java:393)
at com.orientechnologies.common.log.OLogManager.log(OLogManager.java:103)
at com.orientechnologies.common.log.OLogManager.debug(OLogManager.java:128)
at com.orientechnologies.orient.client.remote.OStorageRemote.useNewServerURL(OStorageRemote.java:1703)
- locked (a java.util.ArrayList)
at com.orientechnologies.orient.client.remote.OStorageRemote.getAvailableNetwork(OStorageRemote.java:1866)
at com.orientechnologies.orient.client.remote.OStorageRemote.openRemoteDatabase(OStorageRemote.java:1608)
at com.orientechnologies.orient.client.remote.OStorageRemote.open(OStorageRemote.java:216)
at com.orientechnologies.orient.client.remote.OStorageRemoteThread.open(OStorageRemoteThread.java:87)
at com.orientechnologies.orient.core.db.document.ODatabaseDocumentTx.open(ODatabaseDocumentTx.java:244)
at com.orientechnologies.orient.core.db.OPartitionedDatabasePool$DatabaseDocumentTxPolled.internalOpen(OPartitionedDatabasePool.java:137)
at com.orientechnologies.orient.core.db.OPartitionedDatabasePool.openDatabase(OPartitionedDatabasePool.java:331)
at com.orientechnologies.orient.core.db.OPartitionedDatabasePool.acquire(OPartitionedDatabasePool.java:304)
at com.tinkerpop.blueprints.impls.orient.OrientBaseGraph.(OrientBaseGraph.java:166)
at com.tinkerpop.blueprints.impls.orient.OrientGraphNoTx.(OrientGraphNoTx.java:54)
at com.tinkerpop.blueprints.impls.orient.OrientGraphFactory.getNoTx(OrientGraphFactory.java:93)
at au.com.foxsports.subscription.service.SubscriptionServiceImpl.getSubscribersWithRetry(SubscriptionServiceImpl.java:760)
at au.com.foxsports.subscription.service.SubscriptionServiceImpl.getSubscribers(SubscriptionServiceImpl.java:739)
at au.com.foxsports.subscription.service.SubscriptionServiceImpl$1.call(SubscriptionServiceImpl.java:945)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)

There you go! You can see the 3rd party system eating up the CPU ! In my case its Orientdb. Yes, we faced a lot of issue trying to implement a graph model in orientdb, but thats a story for another day.