/**
   * 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);
    }
  }
Esempio n. 2
0
  /**
   * 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");
    }
  }
Esempio n. 3
0
 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());
  }
Esempio n. 5
0
 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;
 }
Esempio n. 6
0
 /**
  * {@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());
   }
 }
Esempio n. 7
0
  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;
  }
Esempio n. 8
0
 /**
  * {@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);
     }
   }
 }
Esempio n. 9
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();
  }
Esempio n. 11
0
  /**
   * Return current (raw) list of thread info objects wrapped in ThreadRankInfo type.
   *
   * @return list of threads
   */
  protected List<ThreadRankInfo> rawList() {
    // Platform MBean Server startup might be suspended (eg. for JBoss AS);
    if (threadMXBean == null) {
      if (mBeanServerRegistry.lookup("java") != null) {
        threadMXBean = ManagementFactory.getThreadMXBean();
      } else {
        return new ArrayList<ThreadRankInfo>(1);
      }
    }

    ThreadInfo[] ati = threadMXBean.getThreadInfo(threadMXBean.getAllThreadIds());
    List<ThreadRankInfo> lst = new ArrayList<ThreadRankInfo>(ati.length);

    for (ThreadInfo ti : ati) {
      long tid = ti.getThreadId();
      long cpuTime = threadMXBean.getThreadCpuTime(tid);
      lst.add(new ThreadRankInfo(tid, ti.getThreadName(), cpuTime, ti.getBlockedTime()));
    }

    return lst;
  }
  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.");
    }
  }