/**
* Update the information about completed thread that ran for runtime in milliseconds
*
* <p>This method updates all of the key timing and tracking information in the factory so that
* thread can be retired. After this call the factory shouldn't have a pointer to the thread any
* longer
*
* @param thread the thread whose information we are updating
*/
@Ensures({"getTotalTime() >= old(getTotalTime())"})
public synchronized void threadIsDone(final Thread thread) {
nThreadsAnalyzed++;
if (DEBUG) logger.warn("UpdateThreadInfo called");
final long threadID = thread.getId();
final ThreadInfo info = bean.getThreadInfo(thread.getId());
final long totalTimeNano = bean.getThreadCpuTime(threadID);
final long userTimeNano = bean.getThreadUserTime(threadID);
final long systemTimeNano = totalTimeNano - userTimeNano;
final long userTimeInMilliseconds = nanoToMilli(userTimeNano);
final long systemTimeInMilliseconds = nanoToMilli(systemTimeNano);
if (info != null) {
if (DEBUG)
logger.warn(
"Updating thread with user runtime "
+ userTimeInMilliseconds
+ " and system runtime "
+ systemTimeInMilliseconds
+ " of which blocked "
+ info.getBlockedTime()
+ " and waiting "
+ info.getWaitedTime());
incTimes(State.BLOCKING, info.getBlockedTime());
incTimes(State.WAITING, info.getWaitedTime());
incTimes(State.USER_CPU, userTimeInMilliseconds);
incTimes(State.WAITING_FOR_IO, systemTimeInMilliseconds);
}
}
/**
* Print all of the thread's information and stack traces.
*
* @param sb
* @param info
* @param indent
*/
public static void appendThreadInfo(StringBuilder sb, ThreadInfo info, String indent) {
boolean contention = threadBean.isThreadContentionMonitoringEnabled();
if (info == null) {
sb.append(indent).append("Inactive (perhaps exited while monitoring was done)\n");
return;
}
String taskName = getTaskName(info.getThreadId(), info.getThreadName());
sb.append(indent).append("Thread ").append(taskName).append(":\n");
Thread.State state = info.getThreadState();
sb.append(indent).append(" State: ").append(state).append("\n");
sb.append(indent).append(" Blocked count: ").append(info.getBlockedCount()).append("\n");
sb.append(indent).append(" Waited count: ").append(info.getWaitedCount()).append("\n");
if (contention) {
sb.append(indent).append(" Blocked time: " + info.getBlockedTime()).append("\n");
sb.append(indent).append(" Waited time: " + info.getWaitedTime()).append("\n");
}
if (state == Thread.State.WAITING) {
sb.append(indent).append(" Waiting on ").append(info.getLockName()).append("\n");
} else if (state == Thread.State.BLOCKED) {
sb.append(indent).append(" Blocked on ").append(info.getLockName()).append("\n");
sb.append(indent)
.append(" Blocked by ")
.append(getTaskName(info.getLockOwnerId(), info.getLockOwnerName()))
.append("\n");
}
sb.append(indent).append(" Stack:").append("\n");
for (StackTraceElement frame : info.getStackTrace()) {
sb.append(indent).append(" ").append(frame.toString()).append("\n");
}
}
MyThreadInfo(long cpuTime, ThreadInfo info) {
blockedCount = info.getBlockedCount();
blockedTime = info.getBlockedTime();
waitedCount = info.getWaitedCount();
waitedTime = info.getWaitedTime();
this.cpuTime = cpuTime;
this.info = info;
}
/**
* Update the information about completed thread that ran for runtime in milliseconds
*
* <p>This method updates all of the key timing and tracking information in the factory so that
* thread can be retired. After this call the factory shouldn't have a pointer to the thread any
* longer
*
* @param thread
* @param runtimeInMilliseconds
*/
@Ensures({
"activeThreads.size() < old(activeThreads.size())",
"! activeThreads.contains(thread)",
"getTotalTime() >= old(getTotalTime())",
"countDownLatch.getCount() < old(countDownLatch.getCount())"
})
private synchronized void threadIsDone(final Thread thread, final long runtimeInMilliseconds) {
if (DEBUG)
logger.warn(
" Countdown "
+ countDownLatch.getCount()
+ " in thread "
+ Thread.currentThread().getName());
if (DEBUG) logger.warn("UpdateThreadInfo called");
final ThreadInfo info = bean.getThreadInfo(thread.getId());
if (info != null) {
if (DEBUG)
logger.warn(
"Updating thread total runtime "
+ runtimeInMilliseconds
+ " of which blocked "
+ info.getBlockedTime()
+ " and waiting "
+ info.getWaitedTime());
incTimes(Thread.State.BLOCKED, info.getBlockedTime());
incTimes(Thread.State.WAITING, info.getWaitedTime());
incTimes(
Thread.State.RUNNABLE,
runtimeInMilliseconds - info.getWaitedTime() - info.getBlockedTime());
}
// remove the thread from the list of active activeThreads
if (!activeThreads.remove(thread))
throw new IllegalStateException("Thread " + thread + " not in list of active activeThreads");
// one less thread is live for those blocking on all activeThreads to be complete
countDownLatch.countDown();
if (DEBUG)
logger.warn(
" -> Countdown "
+ countDownLatch.getCount()
+ " in thread "
+ Thread.currentThread().getName());
}
void setDelta(long cpuTime, ThreadInfo info) {
if (deltaDone) throw new IllegalStateException("setDelta already called once");
blockedCount = info.getBlockedCount() - blockedCount;
blockedTime = info.getBlockedTime() - blockedTime;
waitedCount = info.getWaitedCount() - waitedCount;
waitedTime = info.getWaitedTime() - waitedTime;
this.cpuTime = cpuTime - this.cpuTime;
deltaDone = true;
this.info = info;
}
/**
* {@inheritDoc}
*
* @see com.wily.introscope.agent.trace.ITracer#ITracer_startTrace(int,
* com.wily.introscope.agent.trace.InvocationData)
*/
@Override
public void ITracer_startTrace(int tracerIndex, InvocationData data) {
final int currentIndex = reentrancyIndex.get().incrementAndGet();
final ThreadInfo ti = TMX.getThreadInfo(Thread.currentThread().getId());
waitCountBaselines.get().put(currentIndex, ti.getWaitedCount());
blockCountBaselines.get().put(currentIndex, ti.getBlockedCount());
if (timesEnabled) {
waitTimeBaselines.get().put(currentIndex, ti.getWaitedTime());
blockTimeBaselines.get().put(currentIndex, ti.getBlockedTime());
}
}
public static CharSequence getThreadStats(
boolean lockedMonitors, boolean lockedSynchronizers, boolean stackTrace) {
StringBuilder list = new StringBuilder();
int threadCount = threadMXbean.getThreadCount();
int daemonCount = threadMXbean.getThreadCount();
int nonDaemonCount = threadCount - daemonCount;
int peakCount = threadMXbean.getPeakThreadCount();
long totalCount = threadMXbean.getTotalStartedThreadCount();
list.append("Live: .................... ").append(threadCount).append(" threads").append("\n");
list.append(" Non-Daemon: ......... ")
.append(nonDaemonCount)
.append(" threads")
.append("\n");
list.append(" Daemon: ............. ").append(daemonCount).append(" threads").append("\n");
list.append("Peak: .................... ").append(peakCount).append(" threads").append("\n");
list.append("Total started: ........... ").append(totalCount).append(" threads").append("\n");
list.append("=================================================").append("\n");
for (ThreadInfo info : threadMXbean.dumpAllThreads(lockedMonitors, lockedSynchronizers)) {
list.append("Thread #")
.append(info.getThreadId())
.append(" (")
.append(info.getThreadName())
.append(")")
.append("\n");
list.append("=================================================\n");
list.append("\tgetThreadState: ...... ").append(info.getThreadState()).append("\n");
list.append("\tgetWaitedTime: ....... ").append(info.getWaitedTime()).append("\n");
list.append("\tgetBlockedTime: ...... ").append(info.getBlockedTime()).append("\n");
for (MonitorInfo monitorInfo : info.getLockedMonitors()) {
list.append("\tLocked monitor: ....... ").append(monitorInfo).append("\n");
list.append("\t\t[")
.append(monitorInfo.getLockedStackDepth())
.append(".]: at ")
.append(monitorInfo.getLockedStackFrame())
.append("\n");
}
for (LockInfo lockInfo : info.getLockedSynchronizers()) {
list.append("\tLocked synchronizer: ...").append(lockInfo).append("\n");
}
if (stackTrace) {
list.append("\tgetStackTace: ..........\n");
for (StackTraceElement trace : info.getStackTrace())
list.append("\t\tat ").append(trace).append("\n");
}
list.append("=================================================\n");
}
return list;
}
/**
* {@inheritDoc}
*
* @see com.wily.introscope.agent.trace.ITracer#ITracer_finishTrace(int,
* com.wily.introscope.agent.trace.InvocationData)
*/
@Override
public void ITracer_finishTrace(int tracerIndex, InvocationData data) {
final int currentIndex = reentrancyIndex.get().decrementAndGet();
try {
final int priorIndex = currentIndex + 1;
final ThreadInfo ti = TMX.getThreadInfo(Thread.currentThread().getId());
long newWaitCount = ti.getWaitedCount();
long newBlockCount = ti.getBlockedCount();
long priorWaitCount = waitCountBaselines.get().remove(priorIndex);
long priorBlockCount = blockCountBaselines.get().remove(priorIndex);
if (priorWaitCount != NO_ENTRY && !waitCountAcc.IDataAccumulator_isShutOff()) {
waitCountAcc.ILongAggregatingDataAccumulator_recordDataPoint(newWaitCount - priorWaitCount);
}
if (priorBlockCount != NO_ENTRY && !blockCountAcc.IDataAccumulator_isShutOff()) {
blockCountAcc.ILongAggregatingDataAccumulator_recordDataPoint(
newBlockCount - priorBlockCount);
}
if (timesEnabled) {
long newWaitTime = ti.getWaitedTime();
long newBlockTime = ti.getBlockedTime();
long priorWaitTime = waitTimeBaselines.get().remove(priorIndex);
long priorBlockTime = blockTimeBaselines.get().remove(priorIndex);
if (priorWaitTime != NO_ENTRY && !waitTimeAcc.IDataAccumulator_isShutOff()) {
waitTimeAcc.ILongAggregatingDataAccumulator_recordDataPoint(newWaitTime - priorWaitTime);
}
if (priorBlockTime != NO_ENTRY && !blockTimeAcc.IDataAccumulator_isShutOff()) {
blockTimeAcc.ILongAggregatingDataAccumulator_recordDataPoint(
newBlockTime - priorBlockTime);
}
}
} finally {
if (currentIndex < 1) {
waitCountBaselines.remove();
blockCountBaselines.remove();
if (timesEnabled) {
waitTimeBaselines.remove();
blockTimeBaselines.remove();
}
}
if (currentIndex < 0) {
log.warn("Reentrancy Index Underrun:", currentIndex);
reentrancyIndex.get().set(0);
}
}
}
/**
* Formats the thread dump header for one thread.
*
* @param ti the ThreadInfo describing the thread
* @return the formatted thread dump header
*/
private static String getThreadDumpHeader(ThreadInfo ti) {
StringBuilder sb = new StringBuilder("\"" + ti.getThreadName() + "\"");
sb.append(" Id=" + ti.getThreadId());
sb.append(" cpu=" + threadMXBean.getThreadCpuTime(ti.getThreadId()) + " ns");
sb.append(" usr="******" ns");
sb.append(" blocked " + ti.getBlockedCount() + " for " + ti.getBlockedTime() + " ms");
sb.append(" waited " + ti.getWaitedCount() + " for " + ti.getWaitedTime() + " ms");
if (ti.isSuspended()) {
sb.append(" (suspended)");
}
if (ti.isInNative()) {
sb.append(" (running in native)");
}
sb.append(CRLF);
sb.append(INDENT3 + "java.lang.Thread.State: " + ti.getThreadState());
sb.append(CRLF);
return sb.toString();
}
protected String generateThreadDump() {
StringBuilder dump = new StringBuilder();
ThreadMXBean threadMXBean = ManagementFactory.getThreadMXBean();
ThreadInfo[] threadInfos = threadMXBean.dumpAllThreads(true, true);
long currentThreadId = Thread.currentThread().getId();
for (ThreadInfo threadInfo : threadInfos) {
long threadId = threadInfo.getThreadId();
if (threadId == currentThreadId) {
continue;
}
dump.append('"');
dump.append(threadInfo.getThreadName());
dump.append("\" ");
Thread.State state = threadInfo.getThreadState();
dump.append("\n\tjava.lang.Thread.State: ");
dump.append(state);
if (threadInfo.getLockName() != null) {
dump.append(", on lock=").append(threadInfo.getLockName());
}
if (threadInfo.getLockOwnerName() != null) {
dump.append(", owned by ").append(threadInfo.getLockOwnerName());
dump.append(", id=").append(threadInfo.getLockOwnerId());
}
if (THREAD_CPU_TIME_INFO_AVAILABLE) {
dump.append(", cpu=").append(threadMXBean.getThreadCpuTime(threadId)).append(" nsecs");
dump.append(", usr="******" nsecs");
}
if (THREAD_CONTENTION_INFO_AVAILABLE) {
dump.append(", blocked=").append(threadInfo.getBlockedTime()).append(" msecs");
dump.append(", waited=").append(threadInfo.getWaitedTime()).append(" msecs");
}
StackTraceElement[] stackTraceElements = threadInfo.getStackTrace();
for (StackTraceElement stackTraceElement : stackTraceElements) {
dump.append("\n\t\tat ");
dump.append(stackTraceElement);
}
dump.append("\n\n");
}
return dump.toString();
}