Eclipse
/
jetty.project
mirror of https://github.com/jetty/jetty.project.git
1
0
Fork 0
Code Issues Packages Projects Releases Wiki Activity

352684 Rewrote thread monitor code, removed deadlock detection, removed spin analyzer that was slow

This commit is contained in:
Michael Gorovoy 2011-08-10 17:28:27 -04:00
parent 599d7f92c9
commit f01c8f7ebf
3 changed files with 66 additions and 311 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

193
jetty-monitor/src/main/java/org/eclipse/jetty/monitor/ThreadMonitor.java
View File

@ -15,9 +15,7 @@
package org.eclipse.jetty.monitor;
import java.lang.management.ManagementFactory;
import java.lang.management.ThreadInfo;
import java.lang.management.ThreadMXBean;
import java.lang.reflect.Method;
import java.util.ArrayList;
import java.util.Collections;
import java.util.Comparator;
@ -35,14 +33,11 @@ public class ThreadMonitor extends AbstractLifeCycle implements Runnable
{
private int _scanInterval;
private int _logInterval;
private int _detectInterval;
private int _detectPeriod;
private int _busyThreshold;
private int _logThreshold;
private int _stackDepth;
private ThreadMXBean _threadBean;
private Method findDeadlockedThreadsMethod;
private Thread _runner;
private Logger _logger;
@ -106,30 +101,6 @@ public class ThreadMonitor extends AbstractLifeCycle implements Runnable
_logInterval = ms;
}
/* ------------------------------------------------------------ */
public int getDetectInterval()
{
return _detectInterval;
}
/* ------------------------------------------------------------ */
public void setDetectInterval(int ms)
{
_detectInterval = ms;
}
/* ------------------------------------------------------------ */
public int getDetectPeriod()
{
return _detectPeriod;
}
/* ------------------------------------------------------------ */
public void setDetectPeriod(int ms)
{
_detectPeriod = ms;
}
/* ------------------------------------------------------------ */
public int getBusyThreshold()
{
@ -167,19 +138,12 @@ public class ThreadMonitor extends AbstractLifeCycle implements Runnable
}
/* ------------------------------------------------------------ */
public void logCpuUsage(int ms, int percent)
public void logCpuUsage(int frequencyMs, int thresholdPercent)
{
setLogInterval(ms);
setLogThreshold(percent);
setLogInterval(frequencyMs);
setLogThreshold(thresholdPercent);
}
/* ------------------------------------------------------------ */
public void logSpinInfo(int periodMs, int intervalMs)
{
setDetectPeriod(periodMs);
setDetectInterval(intervalMs);
}
/* ------------------------------------------------------------ */
/**
* @see org.eclipse.jetty.util.component.AbstractLifeCycle#doStart()
@ -189,6 +153,7 @@ public class ThreadMonitor extends AbstractLifeCycle implements Runnable
_done = false;
_runner = new Thread(this);
_runner.setDaemon(true);
_runner.start();
Log.info("Thread Monitor started successfully");
@ -211,25 +176,6 @@ public class ThreadMonitor extends AbstractLifeCycle implements Runnable
}
}
/* ------------------------------------------------------------ */
/**
* Find deadlocked threads.
*
* @return array of the deadlocked thread ids
*/
protected long[] findDeadlockedThreads()
{
try
{
return (long[])findDeadlockedThreadsMethod.invoke(_threadBean,(Object[])null);
}
catch (Exception ex)
{
Log.debug(ex);
return new long[0];
}
}
/* ------------------------------------------------------------ */
/**
* Retrieve all avaliable thread ids
@ -253,19 +199,6 @@ public class ThreadMonitor extends AbstractLifeCycle implements Runnable
return _threadBean.getThreadCpuTime(id);
}
/* ------------------------------------------------------------ */
/**
* Retrieve thread info.
*
* @param id thread id
* @param maxDepth maximum stack depth
* @return thread info
*/
protected ThreadInfo getThreadInfo(long id, int maxDepth)
{
return _threadBean.getThreadInfo(id,maxDepth);
}
/* ------------------------------------------------------------ */
/**
* Initialize JMX objects.
@ -277,24 +210,6 @@ public class ThreadMonitor extends AbstractLifeCycle implements Runnable
{
_threadBean.setThreadCpuTimeEnabled(true);
}
String versionStr = System.getProperty("java.version");
float version = Float.valueOf(versionStr.substring(0,versionStr.lastIndexOf('.')));
try
{
if (version < 1.6)
{
findDeadlockedThreadsMethod = ThreadMXBean.class.getMethod("findMonitorDeadlockedThreads");
}
else
{
findDeadlockedThreadsMethod = ThreadMXBean.class.getMethod("findDeadlockedThreads");
}
}
catch (Exception ex)
{
Log.debug(ex);
}
}
/* ------------------------------------------------------------ */
@ -343,43 +258,41 @@ public class ThreadMonitor extends AbstractLifeCycle implements Runnable
{
try
{
long[] allThreadId = getAllThreadIds();
for (int idx=0; idx < allThreadId.length; idx++)
Map<Thread,StackTraceElement[]> all = Thread.getAllStackTraces();
for (Map.Entry<Thread,StackTraceElement[]> entry : all.entrySet())
{
long currId = allThreadId[idx];
Thread thread = entry.getKey();
long threadId = thread.getId();
if (currId == _runner.getId())
if (threadId == _runner.getId())
{
continue;
}
ThreadMonitorInfo currMonitorInfo = _monitorInfo.get(Long.valueOf(currId));
ThreadMonitorInfo currMonitorInfo = _monitorInfo.get(Long.valueOf(threadId));
if (currMonitorInfo == null)
{
currMonitorInfo = new ThreadMonitorInfo(getThreadInfo(currId,0));
currMonitorInfo.setCpuTime(getThreadCpuTime(currId));
currMonitorInfo = new ThreadMonitorInfo(thread);
currMonitorInfo.setStackTrace(entry.getValue());
currMonitorInfo.setCpuTime(getThreadCpuTime(threadId));
currMonitorInfo.setSampleTime(System.nanoTime());
_monitorInfo.put(Long.valueOf(currId), currMonitorInfo);
_monitorInfo.put(Long.valueOf(threadId), currMonitorInfo);
}
else
{
currMonitorInfo.setCpuTime(getThreadCpuTime(currId));
currMonitorInfo.setStackTrace(entry.getValue());
currMonitorInfo.setCpuTime(getThreadCpuTime(threadId));
currMonitorInfo.setSampleTime(System.nanoTime());
if (currMonitorInfo.getCpuUtilization() < _busyThreshold)
currMonitorInfo.setSpinning(false);
if (currMonitorInfo.getCpuUtilization() > _busyThreshold)
{
currMonitorInfo.setInfo(getThreadInfo(currId,0));
}
else
{
ThreadInfo threadInfo = getThreadInfo(currId,Integer.MAX_VALUE);
StackTraceElement[] lastStackTrace = currMonitorInfo.getStackTrace();
currMonitorInfo.setInfo(threadInfo);
if (lastStackTrace != null
&& matchStackTraces(lastStackTrace, threadInfo.getStackTrace()))
&& matchStackTraces(lastStackTrace, entry.getValue()))
{
spinAnalyzer(currMonitorInfo);
currMonitorInfo.setSpinning(true);
}
}
}
@ -391,38 +304,6 @@ public class ThreadMonitor extends AbstractLifeCycle implements Runnable
}
}
/* ------------------------------------------------------------ */
/**
* Collect spin info.
*
* @param threadId the thread id
*/
protected void spinAnalyzer(ThreadMonitorInfo info)
{
info.setSpinning(true);
if (_detectPeriod > 0 && _detectInterval > 0)
{
long threadId = info.getThreadId();
long sampleTime = info.getSampleTime() / 1000000;
long endTime = System.currentTimeMillis() + _detectPeriod;
do
{
if (sampleTime + _detectInterval < System.currentTimeMillis())
{
ThreadInfo threadInfo = getThreadInfo(threadId,Integer.MAX_VALUE);
if (threadInfo != null)
{
info.addStackTrace(threadInfo.getStackTrace());
sampleTime = System.currentTimeMillis();
}
}
}
while(System.currentTimeMillis() < endTime);
}
}
/* ------------------------------------------------------------ */
protected void logCpuUsage()
{
@ -471,47 +352,17 @@ public class ThreadMonitor extends AbstractLifeCycle implements Runnable
{
if (_monitorInfo.size() > 0)
{
String format = "Thread %1$s[id:%2$d,%3$s] is SPINNING";
long[] all = getAllThreadIds();
for (int idx=0; idx<all.length; idx++)
{
ThreadMonitorInfo info = _monitorInfo.get(all[idx]);
if (info != null && info.isSpinning())
{
String message = String.format(format, info.getThreadName(),
info.getThreadId(), info.getThreadState());
String message = String.format("%1$s[id:%2$d,%3$s] is SPINNING",
info.getThreadName(), info.getThreadId(), info.getThreadState());
_logger.warn(new ThreadMonitorException(message, info.getStackTrace()));
// log extra stack traces from spin analyzer
List<StackTraceElement[]> stackTraces = info.getStackTraces();
int size = stackTraces.size();
for (int sti=1; sti<size; sti++)
{
message = String.format("Stack Trace %d", sti);
_logger.warn(new ThreadMonitorException(message, stackTraces.get(sti)));
}
}
}
long[] locked = findDeadlockedThreads();
if (locked != null && locked.length > 0)
{
for (int idx=0; idx<locked.length; idx++)
{
ThreadMonitorInfo info = _monitorInfo.get(locked[idx]);
if (info != null && info.getLockOwnerId() >=0 )
{
StringBuilder builder = new StringBuilder();
builder.append(String.format("Thread %s[id:%d,%s] is DEADLOCKED",
info.getThreadName(), info.getThreadId(), info.getThreadState()));
builder.append(String.format(" on %s owned by %s[id:%d]",
info.getLockName(), info.getLockOwnerName(), info.getLockOwnerId()));
StackTraceElement[] stackTrace = getThreadInfo(locked[idx],Integer.MAX_VALUE).getStackTrace();
_logger.warn(new ThreadMonitorException(builder.toString(), stackTrace));
}
}
}
}
}

135
jetty-monitor/src/main/java/org/eclipse/jetty/monitor/ThreadMonitorInfo.java
View File

@ -14,9 +14,6 @@
package org.eclipse.jetty.monitor;
import java.lang.management.ThreadInfo;
import java.util.ArrayList;
import java.util.List;
/* ------------------------------------------------------------ */
@ -24,57 +21,26 @@ import java.util.List;
*/
public class ThreadMonitorInfo
{
private long _threadId;
private String _threadName;
private String _threadState;
private Thread _thread;
private long _lockOwnerId;
private String _lockOwnerName;
private String _lockName;
private List<StackTraceElement[]> _stackTraces;
private StackTraceElement[] _stackTrace;
private boolean _threadSpinning;
private long _prevCpuTime;
private long _prevSampleTime;
private long _currCpuTime;
private long _currSampleTime;
private boolean _threadSpinning;
/* ------------------------------------------------------------ */
/**
* Instantiates a new thread monitor info.
*
* @param threadInfo the thread info
*/
public ThreadMonitorInfo(ThreadInfo threadInfo)
public ThreadMonitorInfo(Thread thread)
{
_stackTraces = new ArrayList<StackTraceElement[]>();
setInfo(threadInfo);
}
/* ------------------------------------------------------------ */
/**
* Sets the thread info.
*
* @param threadInfo the new thread info
*/
public void setInfo(ThreadInfo threadInfo)
{
_threadId = threadInfo.getThreadId();
_threadName = threadInfo.getThreadName();
_threadState = threadInfo.isInNative() ? "IN_NATIVE" :
threadInfo.getThreadState().toString();
_lockOwnerId = threadInfo.getLockOwnerId();
_lockOwnerName = threadInfo.getLockOwnerName();
_lockName = threadInfo.getLockName();
_stackTraces.clear();
addStackTrace(threadInfo.getStackTrace());
_threadSpinning = false;
_thread = thread;
}
/* ------------------------------------------------------------ */
@ -83,7 +49,7 @@ public class ThreadMonitorInfo
*/
public long getThreadId()
{
return _threadId;
return _thread.getId();
}
/* ------------------------------------------------------------ */
@ -94,7 +60,7 @@ public class ThreadMonitorInfo
*/
public String getThreadName()
{
return _threadName;
return _thread.getName();
}
/* ------------------------------------------------------------ */
@ -105,52 +71,51 @@ public class ThreadMonitorInfo
*/
public String getThreadState()
{
return _threadState;
return _thread.getState().toString();
}
/* ------------------------------------------------------------ */
/** Get the lockOwnerId.
* @return the lockOwnerId
/**
* Gets the stack trace.
*
* @return the stack trace
*/
public long getLockOwnerId()
{
return _lockOwnerId;
}
/* ------------------------------------------------------------ */
/** Get the lockOwnerName.
* @return the lockOwnerName
*/
public String getLockOwnerName()
{
return _lockOwnerName;
}
/* ------------------------------------------------------------ */
/** Get the lockName.
* @return the lockName
*/
public String getLockName()
{
return _lockName;
}
public List<StackTraceElement[]> getStackTraces()
{
return _stackTraces;
}
public StackTraceElement[] getStackTrace()
{
return _stackTraces.size() == 0 ? null : _stackTraces.get(0);
return _stackTrace;
}
/* ------------------------------------------------------------ */
/**
* Sets the stack trace.
*
* @param stackTrace the new stack trace
*/
public void setStackTrace(StackTraceElement[] stackTrace)
{
_stackTrace = stackTrace;
}
public void addStackTrace(StackTraceElement[] stackTrace)
/* ------------------------------------------------------------ */
/**
* Checks if is spinning.
*
* @return true, if is spinning
*/
public boolean isSpinning()
{
if (stackTrace != null && stackTrace.length > 0)
{
_stackTraces.add(stackTrace);
}
return _threadSpinning;
}
/* ------------------------------------------------------------ */
/**
* Sets the spinning flag.
*
* @param value the new value
*/
public void setSpinning(boolean value)
{
_threadSpinning = value;
}
/* ------------------------------------------------------------ */
@ -208,16 +173,4 @@ public class ThreadMonitorInfo
return elapsedNanoTime > 0 ? Math.min((elapsedCpuTime * 100.0f) / elapsedNanoTime, 100.0f) : 0;
}
/* ------------------------------------------------------------ */
public void setSpinning(boolean value)
{
_threadSpinning = value;
}
/* ------------------------------------------------------------ */
public boolean isSpinning()
{
return _threadSpinning;
}
}

49
jetty-monitor/src/test/java/org/eclipse/jetty/monitor/ThreadMonitorTest.java
View File

@ -31,18 +31,11 @@ public class ThreadMonitorTest
@Test
public void monitorTest() throws Exception
{
final AtomicInteger countSpins=new AtomicInteger(0);
final AtomicInteger countCpuLogs=new AtomicInteger(0);
final AtomicInteger countStateLogs=new AtomicInteger(0);
ThreadMonitor monitor = new ThreadMonitor(1000,50,1)
{
@Override
protected void spinAnalyzer(ThreadMonitorInfo info)
{
countSpins.incrementAndGet();
super.spinAnalyzer(info);
}
@Override
protected void logCpuUsage()
{
@ -57,30 +50,17 @@ public class ThreadMonitorTest
}
};
monitor.logCpuUsage(2000,1);
monitor.logSpinInfo(100,20);
monitor.start();
Spinner spinner = new Spinner();
Thread runner = new Thread(spinner);
runner.start();
Locker locker1 = new Locker();
Locker locker2 = new Locker();
locker1.setLock(locker2);
locker2.setLock(locker1);
Thread runner1 = new Thread(locker1);
Thread runner2 = new Thread(locker2);
runner1.start();
runner2.start();
Thread.sleep(DURATION);
spinner.setDone();
monitor.stop();
runner1.interrupt();
runner2.interrupt();
assertTrue(countSpins.get() >= 1);
assertTrue(countCpuLogs.get() >= 1);
assertTrue(countStateLogs.get() >= 1);
}
@ -119,33 +99,4 @@ public class ThreadMonitorTest
System.err.println("Bingo!");
}
}
private class Locker implements Runnable
{
private Object _lock;
public void setLock(Object lock)
{
_lock = lock;
}
public void run()
{
try
{
lockOn();
}
catch (InterruptedException ex) {}
}
public synchronized void lockOn() throws InterruptedException
{
Thread.sleep(100);
synchronized (_lock)
{
Thread.sleep(100);
}
}
}
}