java - Thread Monitoring with Java SE 5
Thread Monitoring with Java SE 5
Last updated Mar 17, 2006.
Java SE 5 defined a host of new monitoring and management interfaces that interact directly with the JVM and exposed them through the java.lang.management package. Included in this package is a managed bean that exposes information about all threads running in the JVM, namely the ThreadMXBean.
Each JVM maintains a single instance of the ThreadMXBean, which can be obtained by calling the ManagementFactory.getThreadMXBean() method or through the platform MBean Server:
ThreadMXBean threads = ManagementFactory.getThreadMXBean();
This managed bean provides summary information about all threads running in the JVM as well as providing access to ThreadInfo class instances for each individual thread. The summary information includes the following:
The current number of threads
The current number of daemon threads
The peak number of live threads since the JVM started
The total number of threads that have been created since the JVM started
Find deadlocked threads
And then for individual threads is provides the following information:
The thread id
The thread name
The thread CPU time
The thread user time
The thread blocked count and blocked time
The thread waited count and waited time
A stack trace for the thread
If the thread is blocked, information about the owner thread that has the object lock that this thread is blocking on
The thread state: new, run-able, blocked, waiting, timed waiting, or terminated, defined by the java.lang.Thread.State enumeration
This threading information can be very useful in helping you debug problematic and potentially thread unsafe code as well as provide you with insight into the most CPU intensive threads in your application or application server. In a multithreaded and high-throughput environment, contention issues can arise that you might never discover in a unit test environment. The reason is that one thread, or even a dozen threads, can interact with shared resources without issue, but as soon as there are 50 or 100 threads, the probability of these threads colliding increases dramatically. These problems are therefore difficult to find and inconsistent to reproduce, so the strategies are:
Use a commercial profiler that will trace thread activities
Implement a hoard of logging and then sift through those logs when a problem does arise
Monitor JVM thread information
The latter is the least expensive option and provides a decent amount of detail about thread behavior. You may be able to solve your problems using the ThreadMXBean, but if not it will at least help you isolate problematic code that you can follow through with a commercial profiler.
To demonstrate how to obtain a ThreadMXBean and gather its associated ThreadInfo information, I decided to implement a Servlet that returns the information in XML that you can deploy to your application server. The reason is that application server thread information is plentiful and interesting to look at; a standalone application running three threads would be relatively uneventful. Listing 1 shows the source code for the MXBeanServlet class.
Listing 1. MXBeanServlet.java
package com.javasrc.management;
import javax.servlet.*;
import javax.servlet.http.*;
import java.io.*;
import java.lang.management.*;
import org.jdom.*;
import org.jdom.output.*;
public class MXBeanServlet extends HttpServlet
{
public void init() throws ServletException
{
ServletContext ctx = getServletContext();
}
public void service( HttpServletRequest req, HttpServletResponse res ) throws ServletException
{
try
{
System.out.println( "MXBeanServlet invoked..." );
Element root = new Element( "management-info" );
// Get runtime information
RuntimeMXBean runtime = ManagementFactory.getRuntimeMXBean();
// Handle thread info
ThreadMXBean threads = ManagementFactory.getThreadMXBean();
Element threadsElement = new Element( "threads" );
threadsElement.setAttribute( "thread-count", Long.toString( threads.getThreadCount() ) );
threadsElement.setAttribute( "total-started-thread-count", Long.toString( threads.getTotalStartedThreadCount() ) );
threadsElement.setAttribute( "daemon-thread-count", Long.toString( threads.getDaemonThreadCount() ) );
threadsElement.setAttribute( "peak-thread-count", Long.toString( threads.getPeakThreadCount() ) );
long totalCpuTime = 0l;
long totalUserTime = 0l;
// Parse each thread
ThreadInfo[] threadInfos = threads.getThreadInfo( threads.getAllThreadIds() );
for( int i=0; i<threadInfos.length; i++ )
{
Element threadElement = new Element( "thread" );
threadElement.setAttribute( "id", Long.toString( threadInfos[ i ].getThreadId() ) );
threadElement.setAttribute( "name", threadInfos[ i ].getThreadName() );
threadElement.setAttribute( "cpu-time-nano", Long.toString( threads.getThreadCpuTime( threadInfos[ i ].getThreadId() ) ) );
threadElement.setAttribute( "cpu-time-ms", Long.toString( threads.getThreadCpuTime( threadInfos[ i ].getThreadId() ) / 1000000l ) );
threadElement.setAttribute( "user-time-nano", Long.toString( threads.getThreadUserTime( threadInfos[ i ].getThreadId() ) ) );
threadElement.setAttribute( "user-time-ms", Long.toString( threads.getThreadUserTime( threadInfos[ i ].getThreadId() ) / 1000000l ) );
threadElement.setAttribute( "blocked-count", Long.toString( threadInfos[ i ].getBlockedCount() ) );
threadElement.setAttribute( "blocked-time", Long.toString( threadInfos[ i ].getBlockedTime() ) );
threadElement.setAttribute( "waited-count", Long.toString( threadInfos[ i ].getWaitedCount() ) );
threadElement.setAttribute( "waited-time", Long.toString( threadInfos[ i ].getWaitedTime() ) );
threadsElement.addContent( threadElement );
// Update our aggregate values
totalCpuTime += threads.getThreadCpuTime( threadInfos[ i ].getThreadId() );
totalUserTime += threads.getThreadUserTime( threadInfos[ i ].getThreadId() );
}
long totalCpuTimeMs = totalCpuTime / 1000000l;
long totalUserTimeMs = totalUserTime / 1000000l;
threadsElement.setAttribute( "total-cpu-time-nano", Long.toString( totalCpuTime ) );
threadsElement.setAttribute( "total-user-time-nano", Long.toString( totalUserTime ) );
threadsElement.setAttribute( "total-cpu-time-ms", Long.toString( totalCpuTimeMs ) );
threadsElement.setAttribute( "total-user-time-ms", Long.toString( totalUserTimeMs ) );
// root.addContent( threadsElement );
// Compute thread percentages
long uptime = runtime.getUptime();
threadsElement.setAttribute( "uptime", Long.toString( uptime ) );
double cpuPercentage = ( ( double )totalCpuTimeMs / ( double )uptime ) * 100.0;
double userPercentage = ( ( double )totalUserTimeMs / ( double )uptime ) * 100.0;
threadsElement.setAttribute( "total-cpu-percent", Double.toString( cpuPercentage ) );
threadsElement.setAttribute( "total-user-percent", Double.toString( userPercentage ) );
root.addContent( threadsElement );
// Output the XML to the caller
XMLOutputter outputter = new XMLOutputter( "\t", true );
outputter.output( root, res.getOutputStream() );
}
catch( Exception e )
{
e.printStackTrace();
throw new ServletException( e );
}
}
}
Listing 1 obtains a ThreadMXBean using the ManagementFactory.getThreadMXBean() method and extracts its summary information to populate an XML node. Next it obtains an array of ids for all threads running in the JVM by calling the ThreadMXBean.getAllThreadIds() method and passes that array of thread ids to getThreadInfo() to retrieve the associated ThreadInfo object. It iterates over all of the ThreadInfo objects and extracts their information to populate a "thread" XML element.
One additional MXBean that this Servlet interacts with is the RuntimeMXBean. This bean provides information about the JVM itself, such as the vendor and name, specification information, CLASSPATH, as well as start time and uptime. We use the uptime to compute the percentage of time the Servlet threads are actually using the CPU. This requires a conversion from nanoseconds to milliseconds because CPU time and User time are reported in nanoseconds while uptime is reported in milliseconds.
The code listing maintains a "management-info" root element because the intention is to someday add additional monitoring information in here, such as memory management and garbage collection behavior.
This Servlet makes use of JDOM to manage its XML documents, so in order to compile this class you need jdom.jar and xerces.jar in your CLASSPATH. You can read more about JDOM on their Web site.
Before building a Web Archive (WAR file), you need to construct an XML deployment descriptor that maps Web URL requests to the Servlet responsible for handling them. The Web deployment descriptor, web.xml, is shown in listing 2.
Listing 2. web.xml
<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE web-app PUBLIC ’-//Sun Microsystems, Inc.//DTD Web Application 2.2//EN’ ’http://java.sun.com/j2ee/dtds/web-app_2_2.dtd’>
<web-app>
<servlet>
<servlet-name>MXBeanServlet</servlet-name>
<servlet-class>com.javasrc.management.MXBeanServlet</servlet-class>
</servlet>
<servlet-mapping>
<servlet-name>MXBeanServlet</servlet-name>
<url-pattern>/mx/*</url-pattern>
</servlet-mapping>
<servlet-mapping>
<servlet-name>MXBeanServlet</servlet-name>
<url-pattern>/mx</url-pattern>
</servlet-mapping>
</web-app>
Listing 2 maps all requests passed to "/mx" directly as well as those prefixed with "/mx/" to the MXBean Servlet.
In order to build a Web Archive (WAR file) to host this Servlet, you need to include the following files in the specific location:
WEB-INF/classes/com/javasrc/management/MXBeanServlet.class
WEB-INF/lib/jdom.jar
WEB-INF/lib/xerces.jar
WEB-INF/web.xml
I named my WAR file mx.war. Deploy this to your application server and then invoke it through the following URL:
http://{machine}:{port}/mx/mx
For example, when I deploy this WAR file to JBoss running on my local machine, I use the following URL:
http://localhost:8080/mx/mx
And that yields an XML from which the following is an excerpt:
<management-info>
<threads thread-count="104"
total-started-thread-count="114"
daemon-thread-count="90"
peak-thread-count="105"
total-cpu-time-nano="1484375000"
total-user-time-nano="1093750000"
total-cpu-time-ms="1484"
total-user-time-ms="1093"
uptime="320813"
total-cpu-percent="0.462574770972498"
total-user-percent="0.34069691689551235">
<thread id="119"
name="http-0.0.0.0-8080-2"
cpu-time-nano="140625000"
cpu-time-ms="140"
user-time-nano="125000000"
user-time-ms="125"
blocked-count="0"
blocked-time="-1"
waited-count="1"
waited-time="-1" />
<thread id="83"
name="Thread-39"
cpu-time-nano="15625000"
cpu-time-ms="15"
user-time-nano="15625000"
user-time-ms="15"
blocked-count="0"
blocked-time="-1"
waited-count="0"
waited-time="-1" />
</threads>
</management-info>
In this environment there are currently 104 threads, 90 of which are daemon threads, and at its peak the threads grew to 105. The uptime of the JVM is 320 seconds, or a little over 5 minutes, and all threads combined for 1484 milliseconds -- which means that they were using the CPU time for 0.46% of the time. The two sample threads extracted from the output are an HTTP listener thread and a worker thread. In total there are 104 thread nodes for you to peruse.
Summary
Troubleshooting and debugging multithreaded applications in a high volume environment is a difficult task, but with the release of Java SE 5, the JVM provides a simple mechanism to obtain information about each thread running in the JVM. In addition it can identify threads that are deadlocked, from which you can extract the objects holding locks that these threads are waiting for and the stack trace (method calls) that led to the deadlock. While this level of granularity may or may not provide you with enough information to resolve your problems, it can greatly narrow down the scope of problematic code that you need to examine inside of a code profiler to resolve the issue.
[출처] Thread Monitoring with Java SE 5|작성자 슬레이어