Schedule your own Java thread dumps

So, if you ever tried to figure out what a Java program that appears to be hung is doing you are probably very familiar with the Java thread dump feature. Basically you send a signal to the JVM which responds by, essentially, writing a stack trace of each thread in the JVM to the standard output device. In fact, a thread dump contains more useful information that just a stack trace, it also show the state of each thread (i.e. runnable, waiting, etc) and which Java monitors (synchronized locks) are owned and/or being waited on.

Here is a sample snippet of a thread dump:

Full thread dump Java HotSpot(TM) Client VM (1.5.0_07-b03 mixed mode):

"Timer-5" daemon prio=10 tid=0x092d5720 nid=0x73 in Object.wait() [0x9b52f000..0x9b52fd38]
at java.lang.Object.wait(Native Method) - waiting on <0xa2a4b978> (a java.util.TaskQueue)
at java.util.TimerThread.mainLoop(Timer.java:509) - locked <0xa2a4b978> (a java.util.TaskQueue)
at java.util.TimerThread.run(Timer.java:462)

"Timer-4" prio=10 tid=0x0925d418 nid=0x72 in Object.wait() [0x9b4ed000..0x9b4edab8]
at java.lang.Object.wait(Native Method) - waiting on <0xa2a49570> (a java.util.TaskQueue)
at java.util.TimerThread.mainLoop(Timer.java:509) - locked <0xa2a49570> (a java.util.TaskQueue)
at java.util.TimerThread.run(Timer.java:462)

As you can see a thread dump contains a lot of very useful information.

The method used to “request” a thread dump is to send a signal to the running JVM. In Unix this is the SIGQUIT signal which may be generated via either:

kill -3 <pid>

or

kill -QUIT <pid>

where <pid> is the process id the the JVM. You can also enter Ctrl-\ in the window where the JVM is running.

On Windows a thread dump is requested by sending a Ctrl-Break to the JVM process. This is pretty simple for foreground windows but requires a program (akin to Unix kill) to be used for JVMs running in the background (i.e. services).

The problem with requesting a thread dump is that it requires manual intervention, i.e. someone has to enter the kill command or press the Ctrl-Break keys to generate a thread dump. If you are having problems with your production site in the wee hours of the morning your support staff probably won’t appreciate getting out of bed to capture a few dumps for you. In addition, a single thread dump is not as useful as a series of dumps taken over a period of time. With a single dump you only get a snapshot of what is happening. You might see a thread holding a monitor that is causing others thread to block but you have no idea how long that condition has existed. The lock might have been released a millisecond after the dump was taken. If you have, say, 5 dumps taken over 20 minutes and the same thread is holding the monitor in all of them then you know you’ve got a problem to investigate.

The solution I’m going to propose makes use of JNI to request a thread dump of the current JVM and capture that output to a file which may be time stamped. This allows dump output to be segregated from everything else the JVM is sending to STDOUT.

Before you invest any more time in this article let me state that the solution I’m going to present here only partially works for windows. It is possible to programmatically request a thread dump under Windows but due to a limitation in Win32, the Microsoft C runtime, or both the capture to a separate file does not work. Even though Win32 provides APIs for changing the file handles used for STDOUT/STDERR, changing them after a process has started executing does not seem to make any difference. If you do all your Java work on Windows, you’ve been warned – don’t read to the end and then send me a nasty email saying I wasted your time!

Ok, the first thing we need to do is create a Java class that will serve as an interface to our native routine that captures thread dumps:

package com.utils.threaddump;

public class ThreadDumpUtil
{
public static int performThreadDump(final String fileName)
{
return(threadDumpJvm(fileName));
}

private static native int threadDumpJvm(final String fileName);

static
{
System.loadLibrary("libthreaddump");
}
}

This class loads a native library called libthreaddump when it is loaded and then exposes a static method to request a thread dump from Java code specifying the name of the file that should contain the captured dump.

Running this file through the javah tool generates a C header named com_utils_threaddump_ThreadDumpUtil.h which is used to help build our native routine.

The C code for the Unix variant follows:

#include <signal.h>
#include <unistd.h>
#include <fcntl.h>
#include <sys/stat.h>
#include <string.h>
#include <errno.h>
#include "com_utils_threaddump_ThreadDumpUtil.h"

#define FILE_STDOUT             1
#define FILE_STDERR             2

JNIEXPORT jint JNICALL
Java_com_nm_utils_threaddump_ThreadDumpUtil_threadDumpJvm(JNIEnv *env, jclass clazz, jstring fileName)
{
    /* get my process id */
    pid_t pid = getpid();

    /* open the file where we want the thread dump written */
    char* fName = (char*) (*env)->GetStringUTFChars(env, fileName, NULL);
    if (NULL == fName)
    {
        printf("threadDumpJvm: Out of memory converting filename");
        return((jint) -1L);
    }

    int fd = open(fName, O_WRONLY | O_CREAT, S_IRUSR | S_IWUSR | S_IRGRP | S_IROTH);
    if (-1 == fd)
    {
        printf("threadDumpJvm: Open of file %s failed: %d[%s]\n", fName, errno, strerror(errno));
	    (*env)->ReleaseStringUTFChars(env, fileName, fName);
        return((jint) -2L);
    }

    /* redirect stdout and stderr to our thread dump file */
    int fdOut = dup(FILE_STDOUT);
    int fdErr = dup(FILE_STDERR);
    dup2(fd, FILE_STDOUT);
    dup2(fd, FILE_STDERR);
    close(fd);
    (*env)->ReleaseStringUTFChars(env, fileName, fName);

    /* send signal requesting JVM to perform a thread dump */
    kill(pid, SIGQUIT);

    /* this is kind of hokey but we have to wait for the dump to complete - 10 secs should be ok */
    sleep(10);

    /* replace the original stdout and stderr file handles */
    dup2(fdOut, FILE_STDOUT);
    dup2(fdErr, FILE_STDERR);
    return((jint) 0L);
}

Following are the compile command lines I’ve used on a couple of Unix systems to build this dynamic library:

Mac OSX:
gcc -o liblibthreaddump.dylib -dynamiclib -I. -I$JAVA_HOME/include -L/usr/lib -lc libthreaddump_unix.c

Solaris:
gcc -o liblibthreaddump.so -G -I/$JAVA_HOME/include -I/$JAVA_HOME/include/solaris libthreaddump_unix.c -lc

Here is the C code for the Windows version of the native library:

#define WIN32_LEAN_AND_MEAN
#include <windows.h>
#include "com_nm_utils_threaddump_ThreadDumpUtil.h"

#define FILE_STDOUT             1
#define FILE_STDERR             2

JNIEXPORT jint JNICALL
Java_com_nm_utils_threaddump_ThreadDumpUtil_threadDumpJvm(JNIEnv *env, jclass clazz, jstring fileName)
{
	auto	HANDLE		fd;
	auto	HANDLE 		fdOut;
	auto	HANDLE		fdErr;
	auto	long		retValue = 0L;
	auto	char* 		errText = "";
	auto	DWORD 		pid = GetCurrentProcessId();

    /* open the file where we want the thread dump written */
    char* fName = (char*) (*env)->GetStringUTFChars(env, fileName, NULL);
    if (NULL == fName)
    {
        printf("threadDumpJvm: Out of memory converting filename");
        return((jint) -1L);
    }

	fd = CreateFile((LPCTSTR) fName, GENERIC_WRITE, FILE_SHARE_WRITE,
					NULL, CREATE_ALWAYS, FILE_ATTRIBUTE_NORMAL, NULL);
    if (INVALID_HANDLE_VALUE == fd)
    {
        printf("threadDumpJvm: Open of file %s failed: %ld\n", fName, (long) GetLastError());
	    (*env)->ReleaseStringUTFChars(env, fileName, fName);
        return((jint) -2L);
    }

    /* redirect stdout and stderr to our thread dump file */
    fdOut = GetStdHandle(STD_OUTPUT_HANDLE);
    fdErr = GetStdHandle(STD_ERROR_HANDLE);
    printf("fdOut=%ld fdErr=%ld\n", (long) GetStdHandle(STD_OUTPUT_HANDLE), (long) GetStdHandle(STD_ERROR_HANDLE));
    if (!SetStdHandle(STD_OUTPUT_HANDLE, fd))
    	printf("SetStdHandle failed: %ld\n", (long) GetLastError());

    SetStdHandle(STD_ERROR_HANDLE, fd);

    printf("fdOut=%ld fdErr=%ld\n", (long) GetStdHandle(STD_OUTPUT_HANDLE), (long) GetStdHandle(STD_ERROR_HANDLE));
    if (0 == GenerateConsoleCtrlEvent(CTRL_BREAK_EVENT, 0))  // pid fails here????
    {
    	retValue = (long) GetLastError();
    	errText = "Generate CTRL-BREAK event failed";
   	}
	else
	{
	    /* this is kind of hokey but we have to wait for the dump to complete - 10 secs should be ok */
    	Sleep(10000L);
    }

    printf("This is a test message\n");

    /* replace the original stdout and stderr file handles */
    SetStdHandle(STD_OUTPUT_HANDLE, fdOut);
    SetStdHandle(STD_ERROR_HANDLE, fdErr);
	CloseHandle(fd);
    (*env)->ReleaseStringUTFChars(env, fileName, fName);

    if (0L != retValue)
    {
    	printf("threadDumpJvm: Error generating thread dump: %s\n", errText);
    }

	return((jint) retValue);
}

Remember – the file capture will not work here, it simply creates an empty file and the thread dump goes to the original STDOUT device.

Here is the command I used to create a Windows DLL using Microsoft Visual C++ 6.0:

cl -I. -I%JAVA_HOME%\include -I%JAVA_HOME%/include/win32 -LD libthreaddump_win32.c -Felibthreaddump.dll

That’s it. All the tools needed to request a thread dump any time you like. I used these tools to diagnose problems with an ATG application cluster to research problems being reported by the ATG ServerMonitor component. The ATG ServerMonitor issues warning and error log message for various reasons like the JVM being low on memory or a application request thread executing for an extended period of time. In a future post I’ll discuss how I extended the ATG ServerMonitor to capture thread dumps under these conditions.

4 Responses to “Schedule your own Java thread dumps”

  1. namsplayels Says:

    Hi,

    I am new on this fantastic forum bwithers.wordpress.com
    and just want to inttoduce mygself here.

    namsplayels

    ____________________________________________
    car In That Spain Built Had EngineSports Sports Car Buick 60s During V8

  2. ClearlyPro Says:

    When I tried to log on to ours dekstop, a message saying “there are not sufficient resources to load” my account with the default something-or-other came up. The message had a timer that was going to close the box, and then when it closed it would not log me on. I couldn’t turn it off normally so I cut the power. When I turned it back on I logged on fine?
    I read here Worcester PC Repair but couldnt make sense?

     

  3. Debug java in JVM Diagnostics Tools « When IE meets SE… Says:

    [...] Traces 2. JDB Example: Generating a Thread Dump 3. How to debug a multithreaded java program 4. Schedule your own Java thread dumps 5. JDK Debugging Tools 6. JDK Tools and Utilities 7. Exercise basic command line debugging tools 8. [...]

  4. Hydrolyze Says:

    Just wanted to say hello all. This is my first post.

    I expect to learn alot here.

Leave a Reply