/** * 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; }
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()); } }
/** * {@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(); }
private void printThread() { long now = System.currentTimeMillis(); long diffLastThreadDump = now - lastThreadDump; logger.info("diffLastThreadDump:" + diffLastThreadDump); if (diffLastThreadDump > 60000) { logger.info("had not sent all threads for a while.. will do so now"); lastThreadDump = now; try { ThreadMXBean t = ManagementFactory.getThreadMXBean(); long threads[] = t.getAllThreadIds(); ThreadInfo[] tinfo = t.getThreadInfo(threads, 40); StringBuilder sb = new StringBuilder("All Threads"); for (int i = 0; i < tinfo.length; i++) { ThreadInfo e = tinfo[i]; try { StackTraceElement[] el = e.getStackTrace(); sb.append( "\n\n" + e.getThreadName() + "\n" + " " + " Thread id = " + e.getThreadId() + " " + e.getThreadState()); if (e.getThreadState().equals(State.BLOCKED)) { sb.append( "\n\nBlocked info: " + e.getBlockedCount() + ":" + e.getBlockedTime() + ":" + e.getLockName() + ":" + e.getLockOwnerId() + ":" + e.getLockOwnerName() + "\n" + " " + " Thread id = " + e.getThreadId() + " " + e.getThreadState()); ThreadInfo eBlockedThread = t.getThreadInfo(e.getLockOwnerId(), 40); StackTraceElement[] elBlockedThread = eBlockedThread.getStackTrace(); sb.append( "\n\n " + e.getThreadName() + "\n" + " " + " Thread id = " + eBlockedThread.getThreadId() + " " + eBlockedThread.getThreadState()); if (elBlockedThread == null || elBlockedThread.length == 0) { sb.append(" no stack trace available"); } else { for (int n = 0; n < elBlockedThread.length; n++) { if (n != 0) sb.append("\n"); StackTraceElement frame = elBlockedThread[n]; if (frame == null) { sb.append(" null stack frame"); continue; } sb.append(" "); sb.append(frame.toString()); } } } if (el == null || el.length == 0) { sb.append(" no stack trace available"); continue; } for (int n = 0; n < el.length; n++) { if (n != 0) sb.append("\n"); StackTraceElement frame = el[n]; if (frame == null) { sb.append(" null stack frame"); continue; } sb.append(" "); sb.append(frame.toString()); } } catch (Exception e2) { } } String warningEmailReceiver = CmsPropertyHandler.getWarningEmailReceiver(); if (warningEmailReceiver != null && !warningEmailReceiver.equals("") && warningEmailReceiver.indexOf("@warningEmailReceiver@") == -1) { try { logger.info("Mailing.."); MailServiceFactory.getService() .sendEmail( CmsPropertyHandler.getMailContentType(), warningEmailReceiver, warningEmailReceiver, null, null, null, null, message, sb.toString().replaceAll("\n", "<br/>"), "utf-8"); } catch (Exception e) { logger.error("Could not send mail:" + e.getMessage(), e); } } } catch (Throwable e) { logger.error("Error generating message:" + e.getMessage(), e); } } // Only sends if the last stack was sent more than 3 seconds ago. if ((now - lastSentTimer) > 10000) { lastSentTimer = System.currentTimeMillis(); StackTraceElement[] el = targetThread.getStackTrace(); ThreadMXBean threadMXBean = ManagementFactory.getThreadMXBean(); long stopTimeInNs = threadMXBean.getThreadUserTime(targetThread.getId()); long diff = (stopTimeInNs - startTimeInNs) / 1000000000; StringBuffer stackString = new StringBuffer("\n\n" + message + "\n\n"); stackString.append("ServerName: " + getServerName() + "\n"); stackString.append("Maximum memory (MB): " + (maxMemory / 1024 / 1024) + "\n"); stackString.append("Used memory (MB): " + ((totalMemory - freeMemory) / 1024 / 1024) + "\n"); stackString.append("Free memory (MB): " + (freeMemory / 1024 / 1024) + "\n"); stackString.append("Total memory (MB): " + (totalMemory / 1024 / 1024) + "\n"); stackString.append("Number of current requests: " + numberOfCurrentRequests + "\n"); stackString.append("Number of active requests: " + numberOfActiveRequests + "\n"); stackString.append("Number of long requests: " + longThreadMonitorsSize + "\n"); stackString.append("Current thread time: " + diff + " seconds\n"); stackString.append( "Average time: " + RequestAnalyser.getRequestAnalyser().getAverageElapsedTime() + "\n"); stackString.append( "Longest time: " + RequestAnalyser.getRequestAnalyser().getMaxElapsedTime() + "\n"); stackString.append("Original url: " + getOriginalFullURL() + "\n"); stackString.append("UserInfo: " + getUserInfo() + "\n"); stackString.append("--------------------------------------------\n\n"); stackString.append("Thread with id [" + targetThread.getId() + "] at report time:\n"); if (el != null && el.length != 0) { for (int j = 0; j < el.length; j++) { StackTraceElement frame = el[j]; if (frame == null) stackString.append(" null stack frame" + "\n"); else stackString.append(" ").append(frame.toString()).append("\n"); // if((stackString.indexOf("infoglue") > -1 && j > 20) || j > 35) // break; } } if (targetThread.getState().equals(State.BLOCKED)) { ThreadMXBean t = ManagementFactory.getThreadMXBean(); ThreadInfo e = t.getThreadInfo(targetThread.getId(), 40); stackString.append( "\n\nBlocked info: " + e.getBlockedCount() + ":" + e.getBlockedTime() + ":" + e.getLockName() + ":" + e.getLockOwnerId() + ":" + e.getLockOwnerName() + "\n" + " " + " Thread id = " + e.getThreadId() + " " + e.getThreadState()); ThreadInfo eBlockedThread = t.getThreadInfo(e.getLockOwnerId(), 40); StackTraceElement[] elBlockedThread = eBlockedThread.getStackTrace(); stackString.append( "\n\nBlocked thread: " + e.getThreadName() + "\n" + " " + " Thread id = " + eBlockedThread.getThreadId() + " " + eBlockedThread.getThreadState()); if (elBlockedThread == null || elBlockedThread.length == 0) { stackString.append(" no stack trace available"); } else { for (int n = 0; n < elBlockedThread.length; n++) { if (n != 0) stackString.append("\n"); StackTraceElement frame = elBlockedThread[n]; if (frame == null) { stackString.append(" null stack frame"); continue; } stackString.append(" "); stackString.append(frame.toString()); } } } stackString.append( "\n\n**********************************\nConcurrent long threads (Only an excerpt of all)\n**********************************"); ThreadMXBean t = ManagementFactory.getThreadMXBean(); List threadMonitors = RequestAnalyser.getLongThreadMonitors(); Iterator threadMonitorsIterator = threadMonitors.iterator(); int threadCount = 0; while (threadMonitorsIterator.hasNext() && threadCount < 5) { SimpleThreadMonitor tm = (SimpleThreadMonitor) threadMonitorsIterator.next(); if (targetThread.getId() == tm.getThreadId()) continue; long threads[] = {tm.getThreadId()}; ThreadInfo[] tinfo = t.getThreadInfo(threads, 40); stackString .append("\n\n---------------------------------\nConcurrent long thread [") .append(tm.getThreadId()) .append("]:\n"); stackString .append("Elapsed time:") .append(tm.getElapsedTime()) .append("\n Thread id: ") .append(tm.getThreadId()) .append("\n Original url: ") .append(tm.getOriginalFullURL()) .append(")"); for (int i = 0; i < tinfo.length; i++) { ThreadInfo e = tinfo[i]; el = e.getStackTrace(); if (el != null && el.length != 0) { for (int n = 0; n < el.length; n++) { StackTraceElement frame = el[n]; if (frame == null) stackString.append(" null stack frame\n"); else stackString.append(" null stack frame").append(frame.toString()).append("\n"); } } } threadCount++; } logger.warn(stackString); } else { logger.warn( "A thread took to long but the system seems to be really clogged so we don't send this one."); } }