diff --git a/core/src/main/java/com/taobao/arthas/core/command/model/BusyThreadInfo.java b/core/src/main/java/com/taobao/arthas/core/command/model/BusyThreadInfo.java new file mode 100644 index 000000000..9466cb35a --- /dev/null +++ b/core/src/main/java/com/taobao/arthas/core/command/model/BusyThreadInfo.java @@ -0,0 +1,163 @@ +package com.taobao.arthas.core.command.model; + +import java.lang.management.LockInfo; +import java.lang.management.MonitorInfo; +import java.lang.management.ThreadInfo; + +/** + * Busy thread info, include ThreadInfo fields + * + * @author gongdewei 2020/4/26 + */ +public class BusyThreadInfo extends ThreadVO { + + private long blockedTime; + private long blockedCount; + private long waitedTime; + private long waitedCount; + private LockInfo lockInfo; + private String lockName; + private long lockOwnerId; + private String lockOwnerName; + private boolean inNative; + private boolean suspended; + private StackTraceElement[] stackTrace; + private MonitorInfo[] lockedMonitors; + private LockInfo[] lockedSynchronizers; + + + public BusyThreadInfo(ThreadVO thread, ThreadInfo threadInfo) { + this.setId(thread.getId()); + this.setName(thread.getName()); + this.setDaemon(thread.isDaemon()); + this.setInterrupted(thread.isInterrupted()); + this.setPriority(thread.getPriority()); + this.setGroup(thread.getGroup()); + this.setState(thread.getState()); + this.setCpu(thread.getCpu()); + this.setDeltaTime(thread.getDeltaTime()); + this.setTime(thread.getTime()); + + //thread info + if (threadInfo != null) { + this.setLockInfo(threadInfo.getLockInfo()); + this.setLockedMonitors(threadInfo.getLockedMonitors()); + this.setLockedSynchronizers(threadInfo.getLockedSynchronizers()); + this.setLockName(threadInfo.getLockName()); + this.setLockOwnerId(threadInfo.getLockOwnerId()); + this.setLockOwnerName(threadInfo.getLockOwnerName()); + this.setStackTrace(threadInfo.getStackTrace()); + this.setBlockedCount(threadInfo.getBlockedCount()); + this.setBlockedTime(threadInfo.getBlockedTime()); + this.setInNative(threadInfo.isInNative()); + this.setSuspended(threadInfo.isSuspended()); + this.setWaitedCount(threadInfo.getWaitedCount()); + this.setWaitedTime(threadInfo.getWaitedTime()); + } + + } + + public long getBlockedTime() { + return blockedTime; + } + + public void setBlockedTime(long blockedTime) { + this.blockedTime = blockedTime; + } + + public long getBlockedCount() { + return blockedCount; + } + + public void setBlockedCount(long blockedCount) { + this.blockedCount = blockedCount; + } + + public long getWaitedTime() { + return waitedTime; + } + + public void setWaitedTime(long waitedTime) { + this.waitedTime = waitedTime; + } + + public long getWaitedCount() { + return waitedCount; + } + + public void setWaitedCount(long waitedCount) { + this.waitedCount = waitedCount; + } + + public LockInfo getLockInfo() { + return lockInfo; + } + + public void setLockInfo(LockInfo lockInfo) { + this.lockInfo = lockInfo; + } + + public String getLockName() { + return lockName; + } + + public void setLockName(String lockName) { + this.lockName = lockName; + } + + public long getLockOwnerId() { + return lockOwnerId; + } + + public void setLockOwnerId(long lockOwnerId) { + this.lockOwnerId = lockOwnerId; + } + + public String getLockOwnerName() { + return lockOwnerName; + } + + public void setLockOwnerName(String lockOwnerName) { + this.lockOwnerName = lockOwnerName; + } + + public boolean isInNative() { + return inNative; + } + + public void setInNative(boolean inNative) { + this.inNative = inNative; + } + + public boolean isSuspended() { + return suspended; + } + + public void setSuspended(boolean suspended) { + this.suspended = suspended; + } + + public StackTraceElement[] getStackTrace() { + return stackTrace; + } + + public void setStackTrace(StackTraceElement[] stackTrace) { + this.stackTrace = stackTrace; + } + + public MonitorInfo[] getLockedMonitors() { + return lockedMonitors; + } + + public void setLockedMonitors(MonitorInfo[] lockedMonitors) { + this.lockedMonitors = lockedMonitors; + } + + public LockInfo[] getLockedSynchronizers() { + return lockedSynchronizers; + } + + public void setLockedSynchronizers(LockInfo[] lockedSynchronizers) { + this.lockedSynchronizers = lockedSynchronizers; + } +} diff --git a/core/src/main/java/com/taobao/arthas/core/command/model/ThreadCpuInfo.java b/core/src/main/java/com/taobao/arthas/core/command/model/ThreadCpuInfo.java deleted file mode 100644 index 83c45c3f2..000000000 --- a/core/src/main/java/com/taobao/arthas/core/command/model/ThreadCpuInfo.java +++ /dev/null @@ -1,36 +0,0 @@ -package com.taobao.arthas.core.command.model; - -import java.lang.management.ThreadInfo; - -/** - * ThreadInfo with cpuUsage - * - * @author gongdewei 2020/4/26 - */ -public class ThreadCpuInfo { - - private ThreadInfo threadInfo; - - private long cpuUsage; - - public ThreadCpuInfo(ThreadInfo threadInfo, long cpuUsage) { - this.threadInfo = threadInfo; - this.cpuUsage = cpuUsage; - } - - public long getCpuUsage() { - return cpuUsage; - } - - public void setCpuUsage(long cpuUsage) { - this.cpuUsage = cpuUsage; - } - - public ThreadInfo threadInfo() { - return threadInfo; - } - - public void setThreadInfo(ThreadInfo threadInfo) { - this.threadInfo = threadInfo; - } -} diff --git a/core/src/main/java/com/taobao/arthas/core/command/model/ThreadModel.java b/core/src/main/java/com/taobao/arthas/core/command/model/ThreadModel.java index 18c59bf68..57e72903a 100644 --- a/core/src/main/java/com/taobao/arthas/core/command/model/ThreadModel.java +++ b/core/src/main/java/com/taobao/arthas/core/command/model/ThreadModel.java @@ -18,11 +18,12 @@ public class ThreadModel extends ResultModel { private BlockingLockInfo blockingLockInfo; //thread -n 5 - private ThreadCpuInfo[] busyThreads; + private List busyThreads; //thread stats private List threadStats; private Map threadStateCount; + private boolean all; public ThreadModel() { } @@ -35,13 +36,14 @@ public class ThreadModel extends ResultModel { this.blockingLockInfo = blockingLockInfo; } - public ThreadModel(ThreadCpuInfo[] busyThreads) { + public ThreadModel(List busyThreads) { this.busyThreads = busyThreads; } - public ThreadModel(List threadStats, Map threadStateCount) { + public ThreadModel(List threadStats, Map threadStateCount, boolean all) { this.threadStats = threadStats; this.threadStateCount = threadStateCount; + this.all = all; } @Override @@ -65,11 +67,11 @@ public class ThreadModel extends ResultModel { this.blockingLockInfo = blockingLockInfo; } - public ThreadCpuInfo[] getBusyThreads() { + public List getBusyThreads() { return busyThreads; } - public void setBusyThreads(ThreadCpuInfo[] busyThreads) { + public void setBusyThreads(List busyThreads) { this.busyThreads = busyThreads; } @@ -88,4 +90,12 @@ public class ThreadModel extends ResultModel { public void setThreadStateCount(Map threadStateCount) { this.threadStateCount = threadStateCount; } + + public boolean isAll() { + return all; + } + + public void setAll(boolean all) { + this.all = all; + } } diff --git a/core/src/main/java/com/taobao/arthas/core/command/model/ThreadVO.java b/core/src/main/java/com/taobao/arthas/core/command/model/ThreadVO.java index 42a7b8db4..00f05ab07 100644 --- a/core/src/main/java/com/taobao/arthas/core/command/model/ThreadVO.java +++ b/core/src/main/java/com/taobao/arthas/core/command/model/ThreadVO.java @@ -13,7 +13,8 @@ public class ThreadVO { private String group; private int priority; private State state; - private long cpu; + private double cpu; + private long deltaTime; private long time; private boolean interrupted; private boolean daemon; @@ -61,14 +62,22 @@ public class ThreadVO { this.state = state; } - public long getCpu() { + public double getCpu() { return cpu; } - public void setCpu(long cpu) { + public void setCpu(double cpu) { this.cpu = cpu; } + public long getDeltaTime() { + return deltaTime; + } + + public void setDeltaTime(long deltaTime) { + this.deltaTime = deltaTime; + } + public long getTime() { return time; } @@ -92,4 +101,22 @@ public class ThreadVO { public void setDaemon(boolean daemon) { this.daemon = daemon; } + + @Override + public boolean equals(Object o) { + if (this == o) return true; + if (o == null || getClass() != o.getClass()) return false; + + ThreadVO threadVO = (ThreadVO) o; + + if (id != threadVO.id) return false; + return name != null ? name.equals(threadVO.name) : threadVO.name == null; + } + + @Override + public int hashCode() { + int result = (int) (id ^ (id >>> 32)); + result = 31 * result + (name != null ? name.hashCode() : 0); + return result; + } } diff --git a/core/src/main/java/com/taobao/arthas/core/command/monitor200/DashboardCommand.java b/core/src/main/java/com/taobao/arthas/core/command/monitor200/DashboardCommand.java index 796d7bec2..f8be83e1e 100644 --- a/core/src/main/java/com/taobao/arthas/core/command/monitor200/DashboardCommand.java +++ b/core/src/main/java/com/taobao/arthas/core/command/monitor200/DashboardCommand.java @@ -9,6 +9,7 @@ import com.taobao.arthas.core.command.model.DashboardModel; import com.taobao.arthas.core.command.model.GcInfoVO; import com.taobao.arthas.core.command.model.MemoryEntryVO; import com.taobao.arthas.core.command.model.RuntimeInfoVO; +import com.taobao.arthas.core.command.model.ThreadVO; import com.taobao.arthas.core.command.model.TomcatInfoVO; import com.taobao.arthas.core.shell.command.AnnotatedCommand; import com.taobao.arthas.core.shell.command.CommandProcess; @@ -305,7 +306,7 @@ public class DashboardCommand extends AnnotatedCommand { DashboardModel dashboardModel = new DashboardModel(); //thread sample - Map threads = ThreadUtil.getThreads(); + Map threads = ThreadUtil.getThreads(); dashboardModel.setThreads(threadSampler.sample(threads.values())); //memory diff --git a/core/src/main/java/com/taobao/arthas/core/command/monitor200/ThreadCommand.java b/core/src/main/java/com/taobao/arthas/core/command/monitor200/ThreadCommand.java index 2d02ac1b1..21321ecde 100755 --- a/core/src/main/java/com/taobao/arthas/core/command/monitor200/ThreadCommand.java +++ b/core/src/main/java/com/taobao/arthas/core/command/monitor200/ThreadCommand.java @@ -2,7 +2,7 @@ package com.taobao.arthas.core.command.monitor200; import com.taobao.arthas.core.command.Constants; import com.taobao.arthas.core.command.model.BlockingLockInfo; -import com.taobao.arthas.core.command.model.ThreadCpuInfo; +import com.taobao.arthas.core.command.model.BusyThreadInfo; import com.taobao.arthas.core.command.model.ThreadModel; import com.taobao.arthas.core.command.model.ThreadVO; import com.taobao.arthas.core.shell.command.AnnotatedCommand; @@ -51,11 +51,12 @@ public class ThreadCommand extends AnnotatedCommand { private long id = -1; private Integer topNBusy = null; private boolean findMostBlockingThread = false; - private int sampleInterval = 100; + private int sampleInterval = 200; private String state; private boolean lockedMonitors = false; private boolean lockedSynchronizers = false; + private boolean all = false; static { states = new HashSet(State.values().length); @@ -70,6 +71,12 @@ public class ThreadCommand extends AnnotatedCommand { this.id = id; } + @Option(longName = "all", flag = true) + @Description("Display all thread results instead of the first page") + public void setAll(boolean all) { + this.all = all; + } + @Option(shortName = "n", longName = "top-n-threads") @Description("The number of thread(s) to show, ordered by cpu utilization, -1 to show all.") public void setTopNBusy(Integer topNBusy) { @@ -122,7 +129,7 @@ public class ThreadCommand extends AnnotatedCommand { } private ExitStatus processAllThreads(CommandProcess process) { - Map threads = ThreadUtil.getThreads(); + Map threads = ThreadUtil.getThreads(); // 统计各种线程状态 Map stateCountMap = new LinkedHashMap(); @@ -130,18 +137,20 @@ public class ThreadCommand extends AnnotatedCommand { stateCountMap.put(s, 0); } - for (Thread thread : threads.values()) { + for (ThreadVO thread : threads.values()) { State threadState = thread.getState(); Integer count = stateCountMap.get(threadState); stateCountMap.put(threadState, count + 1); } - Collection resultThreads = new ArrayList(); + boolean includeInternalThreads = true; + Collection resultThreads = new ArrayList(); if (!StringUtils.isEmpty(this.state)) { this.state = this.state.toUpperCase(); if (states.contains(this.state)) { - for (Thread thread : threads.values()) { - if (state.equals(thread.getState().name())) { + includeInternalThreads = false; + for (ThreadVO thread : threads.values()) { + if (thread.getState() != null && state.equals(thread.getState().name())) { resultThreads.add(thread); } } @@ -154,10 +163,12 @@ public class ThreadCommand extends AnnotatedCommand { //thread stats ThreadSampler threadSampler = new ThreadSampler(); - threadSampler.setSampleInterval(sampleInterval); + threadSampler.setIncludeInternalThreads(includeInternalThreads); + threadSampler.sample(resultThreads); + threadSampler.pause(sampleInterval); List threadStats = threadSampler.sample(resultThreads); - process.appendResult(new ThreadModel(threadStats, stateCountMap)); + process.appendResult(new ThreadModel(threadStats, stateCountMap, all)); return ExitStatus.success(); } @@ -171,21 +182,44 @@ public class ThreadCommand extends AnnotatedCommand { } private ExitStatus processTopBusyThreads(CommandProcess process) { - Map topNThreads = ThreadUtil.getTopNThreads(sampleInterval, topNBusy); - Long[] tids = topNThreads.keySet().toArray(new Long[0]); - ThreadInfo[] threadInfos = threadMXBean.getThreadInfo(ArrayUtils.toPrimitive(tids), lockedMonitors, lockedSynchronizers); - if (threadInfos == null) { + ThreadSampler threadSampler = new ThreadSampler(); + threadSampler.sample(ThreadUtil.getThreads().values()); + threadSampler.pause(sampleInterval); + List threadStats = threadSampler.sample(ThreadUtil.getThreads().values()); + + int limit = Math.min(threadStats.size(), topNBusy); + List topNThreads = threadStats.subList(0, limit); + List tids = new ArrayList(topNThreads.size()); + for (ThreadVO thread : topNThreads) { + if (thread.getId() > 0) { + tids.add(thread.getId()); + } + } + + ThreadInfo[] threadInfos = threadMXBean.getThreadInfo(ArrayUtils.toPrimitive(tids.toArray(new Long[0])), lockedMonitors, lockedSynchronizers); + if (tids.size()> 0 && threadInfos == null) { return ExitStatus.failure(1, "get top busy threads failed"); } //threadInfo with cpuUsage - ThreadCpuInfo[] threadCpuInfos = new ThreadCpuInfo[threadInfos.length]; + List busyThreadInfos = new ArrayList(topNThreads.size()); + for (ThreadVO thread : topNThreads) { + ThreadInfo threadInfo = findThreadInfoById(threadInfos, thread.getId()); + BusyThreadInfo busyThread = new BusyThreadInfo(thread, threadInfo); + busyThreadInfos.add(busyThread); + } + process.appendResult(new ThreadModel(busyThreadInfos)); + return ExitStatus.success(); + } + + private ThreadInfo findThreadInfoById(ThreadInfo[] threadInfos, long id) { for (int i = 0; i < threadInfos.length; i++) { ThreadInfo threadInfo = threadInfos[i]; - threadCpuInfos[i] = new ThreadCpuInfo(threadInfo, topNThreads.get(threadInfo.getThreadId())); + if ( threadInfo.getThreadId() == id) { + return threadInfo; + } } - process.appendResult(new ThreadModel(threadCpuInfos)); - return ExitStatus.success(); + return null; } private ExitStatus processThread(CommandProcess process) { diff --git a/core/src/main/java/com/taobao/arthas/core/command/monitor200/ThreadSampler.java b/core/src/main/java/com/taobao/arthas/core/command/monitor200/ThreadSampler.java index 3fadf6f75..da414d00f 100644 --- a/core/src/main/java/com/taobao/arthas/core/command/monitor200/ThreadSampler.java +++ b/core/src/main/java/com/taobao/arthas/core/command/monitor200/ThreadSampler.java @@ -1,10 +1,18 @@ package com.taobao.arthas.core.command.monitor200; import com.taobao.arthas.core.command.model.ThreadVO; +import sun.management.HotspotThreadMBean; +import sun.management.ManagementFactoryHelper; import java.lang.management.ManagementFactory; import java.lang.management.ThreadMXBean; -import java.util.*; +import java.util.ArrayList; +import java.util.Collection; +import java.util.Collections; +import java.util.Comparator; +import java.util.HashMap; +import java.util.List; +import java.util.Map; /** * Thread cpu sampler @@ -13,61 +21,112 @@ import java.util.*; */ public class ThreadSampler { - private long sampleInterval = 100; + private static ThreadMXBean threadMXBean = ManagementFactory.getThreadMXBean(); + private static HotspotThreadMBean hotspotThreadMBean; + private static boolean hotspotThreadMBeanEnable = true; - public List sample(Collection originThreads) { + private Map lastCpuTimes = new HashMap(); - List threads = new ArrayList(originThreads); - ThreadMXBean threadMXBean = ManagementFactory.getThreadMXBean(); + private long lastSampleTimeNanos; + private boolean includeInternalThreads = true; + + + public List sample(Collection originThreads) { + + List threads = new ArrayList(originThreads); // Sample CPU - Map times1 = new HashMap(); - for (Thread thread : threads) { - long cpu = threadMXBean.getThreadCpuTime(thread.getId()); - times1.put(thread.getId(), cpu); - } + if (lastCpuTimes.isEmpty()) { + lastSampleTimeNanos = System.nanoTime(); + for (ThreadVO thread : threads) { + if (thread.getId() > 0) { + long cpu = threadMXBean.getThreadCpuTime(thread.getId()); + lastCpuTimes.put(thread, cpu); + thread.setTime(cpu / 1000000); + } + } - try { - Thread.sleep(sampleInterval); - } catch (InterruptedException e) { - Thread.currentThread().interrupt(); + // add internal threads + Map internalThreadCpuTimes = getInternalThreadCpuTimes(); + if (internalThreadCpuTimes != null) { + for (Map.Entry entry : internalThreadCpuTimes.entrySet()) { + String key = entry.getKey(); + ThreadVO thread = createThreadVO(key); + thread.setTime(entry.getValue() / 1000000); + threads.add(thread); + lastCpuTimes.put(thread, entry.getValue()); + } + } + + //sort by time + Collections.sort(threads, new Comparator() { + @Override + public int compare(ThreadVO o1, ThreadVO o2) { + long l1 = o1.getTime(); + long l2 = o2.getTime(); + if (l1 < l2) { + return 1; + } else if (l1 > l2) { + return -1; + } else { + return 0; + } + } + }); + return threads; } // Resample - Map times2 = new HashMap(threads.size()); - for (Thread thread : threads) { - long cpu = threadMXBean.getThreadCpuTime(thread.getId()); - times2.put(thread.getId(), cpu); + long newSampleTimeNanos = System.nanoTime(); + Map newCpuTimes = new HashMap(threads.size()); + for (ThreadVO thread : threads) { + if (thread.getId() > 0) { + long cpu = threadMXBean.getThreadCpuTime(thread.getId()); + newCpuTimes.put(thread, cpu); + } + } + // internal threads + Map newInternalThreadCpuTimes = getInternalThreadCpuTimes(); + if (newInternalThreadCpuTimes != null) { + for (Map.Entry entry : newInternalThreadCpuTimes.entrySet()) { + ThreadVO threadVO = createThreadVO(entry.getKey()); + threads.add(threadVO); + newCpuTimes.put(threadVO, entry.getValue()); + } } - // Compute delta map and total time - long total = 0; - Map deltas = new HashMap(threads.size()); - for (Long id : times2.keySet()) { - long time1 = times2.get(id); - long time2 = times1.get(id); + // Compute delta time + final Map deltas = new HashMap(threads.size()); + for (ThreadVO thread : newCpuTimes.keySet()) { + Long t = lastCpuTimes.get(thread); + if (t == null) { + t = 0L; + } + long time1 = t; + long time2 = newCpuTimes.get(thread); if (time1 == -1) { time1 = time2; } else if (time2 == -1) { time2 = time1; } long delta = time2 - time1; - deltas.put(id, delta); - total += delta; + deltas.put(thread, delta); } - // Compute cpu - final HashMap cpus = new HashMap(threads.size()); - for (Thread thread : threads) { - long cpu = total == 0 ? 0 : Math.round((deltas.get(thread.getId()) * 100) / total); - cpus.put(thread, cpu); + long sampleIntervalNanos = newSampleTimeNanos - lastSampleTimeNanos; + + // Compute cpu usage + final HashMap cpuUsages = new HashMap(threads.size()); + for (ThreadVO thread : threads) { + double cpu = sampleIntervalNanos == 0 ? 0 : (deltas.get(thread) * 10000 / sampleIntervalNanos / 100.0); + cpuUsages.put(thread, cpu); } // Sort by CPU time : should be a rendering hint... - Collections.sort(threads, new Comparator() { - public int compare(Thread o1, Thread o2) { - long l1 = cpus.get(o1); - long l2 = cpus.get(o2); + Collections.sort(threads, new Comparator() { + public int compare(ThreadVO o1, ThreadVO o2) { + long l1 = deltas.get(o1); + long l2 = deltas.get(o2); if (l1 < l2) { return 1; } else if (l1 > l2) { @@ -78,34 +137,61 @@ public class ThreadSampler { } }); - List threadVOList = new ArrayList(threads.size()); - for (Thread thread : threads) { - ThreadGroup group = thread.getThreadGroup(); - long seconds = times2.get(thread.getId()) / 1000000000; - //long min = seconds / 60; - //String time = min + ":" + (seconds % 60); - long cpu = cpus.get(thread); + for (ThreadVO thread : threads) { + //nanos to mills + long timeMills = newCpuTimes.get(thread) / 1000000; + long deltaTime = deltas.get(thread) / 1000000; + double cpu = cpuUsages.get(thread); - ThreadVO threadVO = new ThreadVO(); - threadVO.setId(thread.getId()); - threadVO.setName(thread.getName()); - threadVO.setGroup(group == null ? "" : group.getName()); - threadVO.setPriority(thread.getPriority()); - threadVO.setState(thread.getState()); - threadVO.setCpu(cpu); - threadVO.setTime(seconds); - threadVO.setInterrupted(thread.isInterrupted()); - threadVO.setDaemon(thread.isDaemon()); - threadVOList.add(threadVO); + thread.setCpu(cpu); + thread.setTime(timeMills); + thread.setDeltaTime(deltaTime); } - return threadVOList; + lastCpuTimes = newCpuTimes; + lastSampleTimeNanos = newSampleTimeNanos; + + return threads; } - public long getSampleInterval() { - return sampleInterval; + private Map getInternalThreadCpuTimes() { + if (hotspotThreadMBeanEnable && includeInternalThreads) { + try { + if (hotspotThreadMBean == null) { + hotspotThreadMBean = ManagementFactoryHelper.getHotspotThreadMBean(); + } + return hotspotThreadMBean.getInternalThreadCpuTimes(); + } catch (Throwable e) { + //ignore ex + hotspotThreadMBeanEnable = false; + } + } + return null; } - public void setSampleInterval(long sampleInterval) { - this.sampleInterval = sampleInterval; + private ThreadVO createThreadVO(String name) { + ThreadVO threadVO = new ThreadVO(); + threadVO.setId(-1); + threadVO.setName(name); + threadVO.setPriority(-1); + threadVO.setDaemon(true); + threadVO.setInterrupted(false); + return threadVO; } + + public void pause(long mills) { + try { + Thread.sleep(mills); + } catch (InterruptedException e) { + // ignore + } + } + + public boolean isIncludeInternalThreads() { + return includeInternalThreads; + } + + public void setIncludeInternalThreads(boolean includeInternalThreads) { + this.includeInternalThreads = includeInternalThreads; + } + } diff --git a/core/src/main/java/com/taobao/arthas/core/command/view/DashboardView.java b/core/src/main/java/com/taobao/arthas/core/command/view/DashboardView.java index 684115cc6..7a9efa295 100644 --- a/core/src/main/java/com/taobao/arthas/core/command/view/DashboardView.java +++ b/core/src/main/java/com/taobao/arthas/core/command/view/DashboardView.java @@ -28,37 +28,61 @@ public class DashboardView extends ResultView { // 上半部分放thread top。下半部分再切分为田字格，其中上面两格放memory, gc的信息。下面两格放tomcat, // runtime的信息 int totalHeight = height - 1; - int threadTopHeight = totalHeight / 2; + int threadTopHeight; + if (totalHeight <= 24) { + //总高度较小时取1/2 + threadTopHeight = totalHeight / 2; + } else { + //总高度较大时取1/3，但不少于上面的值(24/2=12) + threadTopHeight = totalHeight / 3; + if (threadTopHeight < 12) { + threadTopHeight = 12; + } + } int lowerHalf = totalHeight - threadTopHeight; - int runtimeInfoHeight = lowerHalf / 2; - int heapInfoHeight = lowerHalf - runtimeInfoHeight; + //Memory至少保留8行, 显示metaspace信息 + int memoryInfoHeight = lowerHalf / 2; + if (memoryInfoHeight < 8) { + memoryInfoHeight = Math.min(8, lowerHalf); + } + + //runtime + TableElement runtimeInfoTable = drawRuntimeInfo(result.getRuntimeInfo()); + //tomcat + TableElement tomcatInfoTable = drawTomcatInfo(result.getTomcatInfo()); + int runtimeInfoHeight = Math.max(runtimeInfoTable.getRows().size(), tomcatInfoTable == null ? 0 : tomcatInfoTable.getRows().size()); + if (runtimeInfoHeight < lowerHalf - memoryInfoHeight) { + //如果runtimeInfo高度有剩余，则增大MemoryInfo的高度 + memoryInfoHeight = lowerHalf - runtimeInfoHeight; + } else { + runtimeInfoHeight = lowerHalf - memoryInfoHeight; + } + + //如果MemoryInfo高度有剩余，则增大ThreadHeight + int maxMemoryInfoHeight = getMemoryInfoHeight(result.getMemoryInfo()); + memoryInfoHeight = Math.min(memoryInfoHeight, maxMemoryInfoHeight); + threadTopHeight = totalHeight - memoryInfoHeight - runtimeInfoHeight; String threadInfo = ViewRenderUtil.drawThreadInfo(result.getThreads(), width, threadTopHeight); - String memoryAndGc = drawMemoryInfoAndGcInfo(result.getMemoryInfo(), result.getGcInfos(), width, runtimeInfoHeight); - String runTimeAndTomcat = drawRuntimeInfoAndTomcatInfo(result.getRuntimeInfo(), result.getTomcatInfo(), width, heapInfoHeight); + String memoryAndGc = drawMemoryInfoAndGcInfo(result.getMemoryInfo(), result.getGcInfos(), width, memoryInfoHeight); + String runTimeAndTomcat = drawRuntimeInfoAndTomcatInfo(runtimeInfoTable, tomcatInfoTable, width, runtimeInfoHeight); process.write(threadInfo + memoryAndGc + runTimeAndTomcat); } static String drawMemoryInfoAndGcInfo(Map> memoryInfo, List gcInfos, int width, int height) { TableElement table = new TableElement(1, 1); - - TableElement memoryInfoTable = new TableElement(3, 1, 1, 1, 1).rightCellPadding(1); - memoryInfoTable.add(new RowElement().style(Decoration.bold.fg(Color.black).bg(Color.white)).add("Memory", - "used", "total", "max", "usage")); - - drawMemoryInfo(memoryInfoTable, memoryInfo); - - TableElement gcInfoTable = new TableElement(1, 1).rightCellPadding(1); - gcInfoTable.add(new RowElement().style(Decoration.bold.fg(Color.black).bg(Color.white)).add("GC", "")); - drawGcInfo(gcInfoTable, gcInfos); - + TableElement memoryInfoTable = drawMemoryInfo(memoryInfo); + TableElement gcInfoTable = drawGcInfo(gcInfos); table.row(memoryInfoTable, gcInfoTable); return RenderUtil.render(table, width, height); } - private static void drawMemoryInfo(TableElement table, Map> memoryInfo) { + private static TableElement drawMemoryInfo(Map> memoryInfo) { + TableElement table = new TableElement(3, 1, 1, 1, 1).rightCellPadding(1); + table.add(new RowElement().style(Decoration.bold.fg(Color.black).bg(Color.white)).add("Memory", + "used", "total", "max", "usage")); List heapMemoryEntries = memoryInfo.get(MemoryEntryVO.TYPE_HEAP); //heap memory for (MemoryEntryVO memoryEntryVO : heapMemoryEntries) { @@ -81,26 +105,38 @@ public class DashboardView extends ResultView { //buffer-pool List bufferPoolMemoryEntries = memoryInfo.get(MemoryEntryVO.TYPE_BUFFER_POOL); - for (MemoryEntryVO memoryEntryVO : bufferPoolMemoryEntries) { - new MemoryEntry(memoryEntryVO).addTableRow(table); + if (bufferPoolMemoryEntries != null) { + for (MemoryEntryVO memoryEntryVO : bufferPoolMemoryEntries) { + new MemoryEntry(memoryEntryVO).addTableRow(table); + } } + return table; } - private static void drawGcInfo(TableElement table, List gcInfos) { + private static int getMemoryInfoHeight(Map> memoryInfo) { + int height = 1; + for (List memoryEntryVOS : memoryInfo.values()) { + height += memoryEntryVOS.size(); + } + return height; + } + + private static TableElement drawGcInfo(List gcInfos) { + TableElement table = new TableElement(1, 1).rightCellPadding(1); + table.add(new RowElement().style(Decoration.bold.fg(Color.black).bg(Color.white)).add("GC", "")); for (GcInfoVO gcInfo : gcInfos) { table.add(new RowElement().style(Decoration.bold.bold()).add("gc." + gcInfo.getName() + ".count", "" + gcInfo.getCollectionCount())); table.row("gc." + gcInfo.getName() + ".time(ms)", "" + gcInfo.getCollectionTime()); } + return table; } - String drawRuntimeInfoAndTomcatInfo(RuntimeInfoVO runtimeInfo, TomcatInfoVO tomcatInfo, int width, int height) { + String drawRuntimeInfoAndTomcatInfo(TableElement runtimeInfoTable, TableElement tomcatInfoTable, int width, int height) { + if (height <= 0) { + return ""; + } TableElement resultTable = new TableElement(1, 1); - //runtime - TableElement runtimeInfoTable = drawRuntimeInfo(runtimeInfo); - //tomcat - TableElement tomcatInfoTable = drawTomcatInfo(tomcatInfo); - if (tomcatInfoTable != null) { resultTable.row(runtimeInfoTable, tomcatInfoTable); } else { @@ -211,13 +247,17 @@ public class DashboardView extends ResultView { public void addTableRow(TableElement table) { double usage = used / (double) (max == -1 || max == Long.MIN_VALUE ? total : max) * 100; - + if (Double.isNaN(usage) || Double.isInfinite(usage)) { + usage = 0; + } table.row(name, format(used), format(total), format(max), String.format("%.2f%%", usage)); } public void addTableRow(TableElement table, Style.Composite style) { double usage = used / (double) (max == -1 || max == Long.MIN_VALUE ? total : max) * 100; - + if (Double.isNaN(usage) || Double.isInfinite(usage)) { + usage = 0; + } table.add(new RowElement().style(style).add(name, format(used), format(total), format(max), String.format("%.2f%%", usage))); } diff --git a/core/src/main/java/com/taobao/arthas/core/command/view/ThreadView.java b/core/src/main/java/com/taobao/arthas/core/command/view/ThreadView.java index ca18e8322..b1d2ca362 100644 --- a/core/src/main/java/com/taobao/arthas/core/command/view/ThreadView.java +++ b/core/src/main/java/com/taobao/arthas/core/command/view/ThreadView.java @@ -1,6 +1,6 @@ package com.taobao.arthas.core.command.view; -import com.taobao.arthas.core.command.model.ThreadCpuInfo; +import com.taobao.arthas.core.command.model.BusyThreadInfo; import com.taobao.arthas.core.command.model.ThreadModel; import com.taobao.arthas.core.command.model.ThreadVO; import com.taobao.arthas.core.shell.command.CommandProcess; @@ -23,12 +23,12 @@ public class ThreadView extends ResultView { public void draw(CommandProcess process, ThreadModel result) { if (result.getThreadInfo() != null) { // no cpu usage info - String content = ThreadUtil.getFullStacktrace(result.getThreadInfo(), -1); + String content = ThreadUtil.getFullStacktrace(result.getThreadInfo()); process.write(content); } else if (result.getBusyThreads() != null) { - ThreadCpuInfo[] threadInfos = result.getBusyThreads(); - for (ThreadCpuInfo info : threadInfos) { - String stacktrace = ThreadUtil.getFullStacktrace(info.threadInfo(), info.getCpuUsage()); + List threadInfos = result.getBusyThreads(); + for (BusyThreadInfo info : threadInfos) { + String stacktrace = ThreadUtil.getFullStacktrace(info, -1, -1); process.write(stacktrace).write("\n"); } } else if (result.getBlockingLockInfo() != null) { @@ -44,6 +44,15 @@ public class ThreadView extends ResultView { for (Integer value : threadStateCount.values()) { total += value; } + + int internalThreadCount = 0; + for (ThreadVO thread : threadStats) { + if (thread.getId() <= 0) { + internalThreadCount += 1; + } + } + total += internalThreadCount; + StringBuilder threadStat = new StringBuilder(); threadStat.append("Threads Total: ").append(total); @@ -51,12 +60,20 @@ public class ThreadView extends ResultView { Integer count = threadStateCount.get(s); threadStat.append(", ").append(s.name()).append(": ").append(count); } + if (internalThreadCount > 0) { + threadStat.append(", Internal threads: ").append(internalThreadCount); + } String stat = RenderUtil.render(new LabelElement(threadStat), process.width()); //thread stats - int height = Math.max(5, process.height() - 2); - //remove blank lines - height = Math.min(height, threadStats.size() + 2); + int height; + if (result.isAll()) { + height = threadStats.size() + 1; + } else { + height = Math.max(5, process.height() - 2); + //remove blank lines + height = Math.min(height, threadStats.size() + 2); + } String content = ViewRenderUtil.drawThreadInfo(threadStats, process.width(), height); process.write(stat + content); } diff --git a/core/src/main/java/com/taobao/arthas/core/command/view/ViewRenderUtil.java b/core/src/main/java/com/taobao/arthas/core/command/view/ViewRenderUtil.java index 4e7201576..55e5b9743 100644 --- a/core/src/main/java/com/taobao/arthas/core/command/view/ViewRenderUtil.java +++ b/core/src/main/java/com/taobao/arthas/core/command/view/ViewRenderUtil.java @@ -105,7 +105,7 @@ public class ViewRenderUtil { } public static String drawThreadInfo(List threads, int width, int height) { - TableElement table = new TableElement(1, 3, 2, 1, 1, 1, 1, 1, 1).overflow(Overflow.HIDDEN).rightCellPadding(1); + TableElement table = new TableElement(1, 6, 3, 2, 2, 2, 2, 2, 2, 2).overflow(Overflow.HIDDEN).rightCellPadding(1); // Header table.add( @@ -116,6 +116,7 @@ public class ViewRenderUtil { "PRIORITY", "STATE", "%CPU", + "DELTA_TIME", "TIME", "INTERRUPTED", "DAEMON" @@ -124,22 +125,28 @@ public class ViewRenderUtil { for (ThreadVO thread : threads) { Color color = colorMapping.get(thread.getState()); - long seconds = thread.getTime(); - long min = seconds / 60; - String time = min + ":" + (seconds % 60); - long cpu = thread.getCpu(); + String time = formatTimeMills(thread.getTime()); + String deltaTime = formatTimeMillsToSeconds(thread.getDeltaTime()); + double cpu = thread.getCpu(); LabelElement daemonLabel = new LabelElement(thread.isDaemon()); if (!thread.isDaemon()) { daemonLabel.setStyle(Style.style(Color.magenta)); } + LabelElement stateElement; + if (thread.getState() != null) { + stateElement = new LabelElement(thread.getState()).style(color.fg()); + } else { + stateElement = new LabelElement("-"); + } table.row( new LabelElement(thread.getId()), new LabelElement(thread.getName()), - new LabelElement(thread.getGroup()), + new LabelElement(thread.getGroup() != null ? thread.getGroup() : "-"), new LabelElement(thread.getPriority()), - new LabelElement(thread.getState()).style(color.fg()), + stateElement, new LabelElement(cpu), + new LabelElement(deltaTime), new LabelElement(time), new LabelElement(thread.isInterrupted()), daemonLabel @@ -147,4 +154,18 @@ public class ViewRenderUtil { } return RenderUtil.render(table, width, height); } + + private static String formatTimeMills(long timeMills) { + long seconds = timeMills / 1000; + long mills = timeMills % 1000; + long min = seconds / 60; + //return min + ":" + (seconds % 60); + return String.format("%d:%d.%03d", min, seconds, mills); + } + + private static String formatTimeMillsToSeconds(long timeMills) { + long seconds = timeMills / 1000; + long mills = timeMills % 1000; + return String.format("%d.%03d", seconds, mills); + } } diff --git a/core/src/main/java/com/taobao/arthas/core/util/ThreadUtil.java b/core/src/main/java/com/taobao/arthas/core/util/ThreadUtil.java index 633297775..1556516ff 100644 --- a/core/src/main/java/com/taobao/arthas/core/util/ThreadUtil.java +++ b/core/src/main/java/com/taobao/arthas/core/util/ThreadUtil.java @@ -1,8 +1,10 @@ package com.taobao.arthas.core.util; import com.taobao.arthas.core.command.model.BlockingLockInfo; +import com.taobao.arthas.core.command.model.BusyThreadInfo; import com.taobao.arthas.core.command.model.StackModel; import com.taobao.arthas.core.command.model.ThreadNode; +import com.taobao.arthas.core.command.model.ThreadVO; import com.taobao.arthas.core.view.Ansi; import java.arthas.SpyAPI; @@ -38,13 +40,13 @@ abstract public class ThreadUtil { * * @return */ - public static Map getThreads() { + public static Map getThreads() { ThreadGroup root = getRoot(); Thread[] threads = new Thread[root.activeCount()]; while (root.enumerate(threads, true) == threads.length) { threads = new Thread[threads.length * 2]; } - SortedMap map = new TreeMap(new Comparator() { + SortedMap map = new TreeMap(new Comparator() { @Override public int compare(String o1, String o2) { return o1.compareTo(o2); @@ -52,12 +54,26 @@ abstract public class ThreadUtil { }); for (Thread thread : threads) { if (thread != null) { - map.put(thread.getName() + "-" + thread.getId(), thread); + ThreadVO threadVO = createThreadVO(thread); + map.put(thread.getName() + "-" + thread.getId(), threadVO); } } return map; } + private static ThreadVO createThreadVO(Thread thread) { + ThreadGroup group = thread.getThreadGroup(); + ThreadVO threadVO = new ThreadVO(); + threadVO.setId(thread.getId()); + threadVO.setName(thread.getName()); + threadVO.setGroup(group == null ? "" : group.getName()); + threadVO.setPriority(thread.getPriority()); + threadVO.setState(thread.getState()); + threadVO.setInterrupted(thread.isInterrupted()); + threadVO.setDaemon(thread.isDaemon()); + return threadVO; + } + /** * 获取所有线程List * @@ -78,89 +94,6 @@ abstract public class ThreadUtil { return result; } - /** - * get the top N busy thread - * @param sampleInterval the interval between two samples - * @param topN the number of thread - * @return a Map representing - */ - public static Map getTopNThreads(int sampleInterval, int topN) { - List threads = getThreadList(); - - // Sample CPU - Map times1 = new HashMap(); - for (Thread thread : threads) { - long cpu = threadMXBean.getThreadCpuTime(thread.getId()); - times1.put(thread.getId(), cpu); - } - - try { - // Sleep for some time - Thread.sleep(sampleInterval); - } - catch (InterruptedException e) { - Thread.currentThread().interrupt(); - } - - // Resample - Map times2 = new HashMap(threads.size()); - for (Thread thread : threads) { - long cpu = threadMXBean.getThreadCpuTime(thread.getId()); - times2.put(thread.getId(), cpu); - } - - // Compute delta map and total time - long total = 0; - Map deltas = new HashMap(threads.size()); - for (Long id : times2.keySet()) { - long time1 = times2.get(id); - long time2 = times1.get(id); - if (time1 == -1) { - time1 = time2; - } else if (time2 == -1) { - time2 = time1; - } - long delta = time2 - time1; - deltas.put(id, delta); - total += delta; - } - - // Compute cpu - final HashMap cpus = new HashMap(threads.size()); - for (Thread thread : threads) { - long cpu = total == 0 ? 0 : Math.round((deltas.get(thread.getId()) * 100) / total); - cpus.put(thread, cpu); - } - - // Sort by CPU time : should be a rendering hint... - Collections.sort(threads, new Comparator() { - public int compare(Thread o1, Thread o2) { - long l1 = cpus.get(o1); - long l2 = cpus.get(o2); - if (l1 < l2) { - return 1; - } else if (l1 > l2) { - return -1; - } else { - return 0; - } - } - }); - - // use LinkedHashMap to preserve insert order - Map topNThreads = new LinkedHashMap(); - - List topThreads = topN > 0 && topN <= threads.size() - ? threads.subList(0, topN) : threads; - - for (Thread thread: topThreads) { - // Compute cpu usage - topNThreads.put(thread.getId(), cpus.get(thread)); - } - - return topNThreads; - } - /** * Find the thread and lock that is blocking the most other threads. @@ -233,13 +166,12 @@ abstract public class ThreadUtil { } - public static String getFullStacktrace(ThreadInfo threadInfo, long cpuUsage) { - return getFullStacktrace(threadInfo, cpuUsage, 0, 0); + public static String getFullStacktrace(ThreadInfo threadInfo) { + return getFullStacktrace(threadInfo, -1, -1, -1, 0, 0); } - public static String getFullStacktrace(BlockingLockInfo blockingLockInfo) { - return getFullStacktrace(blockingLockInfo.getThreadInfo(), -1, blockingLockInfo.getLockIdentityHashCode(), + return getFullStacktrace(blockingLockInfo.getThreadInfo(), -1, -1, -1, blockingLockInfo.getLockIdentityHashCode(), blockingLockInfo.getBlockingThreadCount()); } @@ -252,7 +184,7 @@ abstract public class ThreadUtil { * @param blockingThreadCount 阻塞了其他线程的数量 * @return the string representation of the thread stack */ - public static String getFullStacktrace(ThreadInfo threadInfo, long cpuUsage, int lockIdentityHashCode, + public static String getFullStacktrace(ThreadInfo threadInfo, double cpuUsage, long deltaTime, long time, int lockIdentityHashCode, int blockingThreadCount) { StringBuilder sb = new StringBuilder("\"" + threadInfo.getThreadName() + "\"" + " Id=" + threadInfo.getThreadId()); @@ -260,6 +192,12 @@ abstract public class ThreadUtil { if (cpuUsage >= 0 && cpuUsage <= 100) { sb.append(" cpuUsage=").append(cpuUsage).append("%"); } + if (deltaTime >= 0 ) { + sb.append(" deltaTime=").append(deltaTime).append("ms"); + } + if (time >= 0 ) { + sb.append(" time=").append(time).append("ms"); + } sb.append(" ").append(threadInfo.getThreadState()); @@ -334,6 +272,102 @@ abstract public class ThreadUtil { return sb.toString().replace("\t", " "); } + public static String getFullStacktrace(BusyThreadInfo threadInfo, int lockIdentityHashCode, int blockingThreadCount) { + StringBuilder sb = new StringBuilder("\"" + threadInfo.getName() + "\""); + if (threadInfo.getId() > 0) { + sb.append(" Id=").append(threadInfo.getId()); + } else { + sb.append(" [Internal]"); + } + double cpuUsage = threadInfo.getCpu(); + if (cpuUsage >= 0 && cpuUsage <= 100) { + sb.append(" cpuUsage=").append(cpuUsage).append("%"); + } + if (threadInfo.getDeltaTime() >= 0 ) { + sb.append(" deltaTime=").append(threadInfo.getDeltaTime()).append("ms"); + } + if (threadInfo.getTime() >= 0 ) { + sb.append(" time=").append(threadInfo.getTime()).append("ms"); + } + + if (threadInfo.getState() == null) { + sb.append("\n\n"); + return sb.toString(); + } + + sb.append(" ").append(threadInfo.getState()); + + if (threadInfo.getLockName() != null) { + sb.append(" on ").append(threadInfo.getLockName()); + } + if (threadInfo.getLockOwnerName() != null) { + sb.append(" owned by \"").append(threadInfo.getLockOwnerName()).append("\" Id=").append(threadInfo.getLockOwnerId()); + } + if (threadInfo.isSuspended()) { + sb.append(" (suspended)"); + } + if (threadInfo.isInNative()) { + sb.append(" (in native)"); + } + sb.append('\n'); + int i = 0; + for (; i < threadInfo.getStackTrace().length; i++) { + StackTraceElement ste = threadInfo.getStackTrace()[i]; + sb.append("\tat ").append(ste.toString()); + sb.append('\n'); + if (i == 0 && threadInfo.getLockInfo() != null) { + Thread.State ts = threadInfo.getState(); + switch (ts) { + case BLOCKED: + sb.append("\t- blocked on ").append(threadInfo.getLockInfo()); + sb.append('\n'); + break; + case WAITING: + sb.append("\t- waiting on ").append(threadInfo.getLockInfo()); + sb.append('\n'); + break; + case TIMED_WAITING: + sb.append("\t- waiting on ").append(threadInfo.getLockInfo()); + sb.append('\n'); + break; + default: + } + } + + for (MonitorInfo mi : threadInfo.getLockedMonitors()) { + if (mi.getLockedStackDepth() == i) { + sb.append("\t- locked ").append(mi); + if (mi.getIdentityHashCode() == lockIdentityHashCode) { + Ansi highlighted = Ansi.ansi().fg(Ansi.Color.RED); + highlighted.a(" <---- but blocks ").a(blockingThreadCount).a(" other threads!"); + sb.append(highlighted.reset().toString()); + } + sb.append('\n'); + } + } + } + if (i < threadInfo.getStackTrace().length) { + sb.append("\t..."); + sb.append('\n'); + } + + LockInfo[] locks = threadInfo.getLockedSynchronizers(); + if (locks.length > 0) { + sb.append("\n\tNumber of locked synchronizers = ").append(locks.length); + sb.append('\n'); + for (LockInfo li : locks) { + sb.append("\t- ").append(li); + if (li.getIdentityHashCode() == lockIdentityHashCode) { + sb.append(" <---- but blocks ").append(blockingThreadCount); + sb.append(" other threads!"); + } + sb.append('\n'); + } + } + sb.append('\n'); + return sb.toString().replace("\t", " "); + } + /** * * java.lang.Thread.getStackTrace(Thread.java:1559), diff --git a/site/src/site/sphinx/_static/dashboard.png b/site/src/site/sphinx/_static/dashboard.png index 3ed6ec760..7eddc17d6 100644 Binary files a/site/src/site/sphinx/_static/dashboard.png and b/site/src/site/sphinx/_static/dashboard.png differ diff --git a/site/src/site/sphinx/dashboard.md b/site/src/site/sphinx/dashboard.md index b3c3738a1..fff004078 100644 --- a/site/src/site/sphinx/dashboard.md +++ b/site/src/site/sphinx/dashboard.md @@ -18,53 +18,65 @@ dashboard ``` $ dashboard -ID NAME GROUP PRIORITY STATE %CPU TIME INTERRUPTED DAEMON -889 RMI TCP Connection(15)-30.10.166. RMI Runtime 9 RUNNABLE 48 0:5 false true -1077 Timer-for-arthas-dashboard-0 system 9 RUNNABLE 24 0:0 false true -1074 as-selector-daemon system 9 RUNNABLE 12 0:0 false true -284 JMX server connection timeout 284 RMI Runtime 9 TIMED_WAITI 8 0:3 false true -16 Timer-1 main 5 TIMED_WAITI 5 0:9 false true -47 Pandora pandora-qos-reporter Pool main 5 TIMED_WAITI 0 0:0 false true -48 JmonitorClient-CheckThread Pool [ main 5 TIMED_WAITI 0 0:0 false true -49 JmonitorClient-HeartBeat Pool [Th main 5 TIMED_WAITI 0 0:0 false true -50 JmonitorClient-ReaderThread Pool main 5 TIMED_WAITI 0 0:0 false true -957 RMI TCP Connection(16)-30.10.166. RMI Runtime 9 RUNNABLE 0 0:2 false true -51 JmonitorClient-WriterThread Pool main 5 TIMED_WAITI 0 0:0 false true -52 ContainerBackgroundProcessor[Stan main 5 TIMED_WAITI 0 0:0 false true -53 http-bio-8080-Acceptor-0 main 5 RUNNABLE 0 0:2 false true -54 http-bio-8080-AsyncTimeout main 5 TIMED_WAITI 0 0:0 false true -11 GC Daemon system 2 TIMED_WAITI 0 0:0 false true -Memory used total max usage GC -heap 59M 223M 1820M 3.26% gc.ps_scavenge.count 118 -ps_eden_space 14M 114M 668M 2.11% gc.ps_scavenge.time(ms) 1890 -ps_survivor_space 6M 6M 6M 96.08% gc.ps_marksweep.count 5 -ps_old_gen 39M 103M 1365M 2.86% gc.ps_marksweep.time(ms) 1140 -nonheap 234M 240M 0M 97.46% -code_cache 46M 47M 240M 19.49% -metaspace 167M 172M 0M 97.36% -Runtime Tomcat -os.name Mac OS X connector http-bio-8080 -os.version 10.10.5 QPS 0.00 -java.version 1.8.0_60 RT(ms) 1.13 -java.home error/s 0.00 - received/s 0B -systemload.average 3.44 sent/s 0B -processors 4 threadpool http-bio-8080 -uptime 16020s busy 0 +ID NAME GROUP PRIORITY STATE %CPU DELTA_TIME TIME INTERRUPTE DAEMON +-1 C2 CompilerThread0 - -1 - 1.55 0.077 0:8.684 false true +53 Timer-for-arthas-dashboard-07b system 5 RUNNABLE 0.08 0.004 0:0.004 false true +22 scheduling-1 main 5 TIMED_WAI 0.06 0.003 0:0.287 false false +-1 C1 CompilerThread0 - -1 - 0.06 0.003 0:2.171 false true +-1 VM Periodic Task Thread - -1 - 0.03 0.001 0:0.092 false true +49 arthas-NettyHttpTelnetBootstra system 5 RUNNABLE 0.02 0.001 0:0.156 false true +16 Catalina-utility-1 main 1 TIMED_WAI 0.0 0.000 0:0.029 false false +-1 G1 Young RemSet Sampling - -1 - 0.0 0.000 0:0.019 false true +17 Catalina-utility-2 main 1 WAITING 0.0 0.000 0:0.025 false false +34 http-nio-8080-ClientPoller main 5 RUNNABLE 0.0 0.000 0:0.016 false true +23 http-nio-8080-BlockPoller main 5 RUNNABLE 0.0 0.000 0:0.011 false true +-1 VM Thread - -1 - 0.0 0.000 0:0.032 false true +-1 Service Thread - -1 - 0.0 0.000 0:0.006 false true +-1 GC Thread#5 - -1 - 0.0 0.000 0:0.043 false true +Memory used total max usage GC +heap 36M 70M 4096M 0.90% gc.g1_young_generation.count 12 +g1_eden_space 6M 18M -1 33.33% 86 +g1_old_gen 30M 50M 4096M 0.74% gc.g1_old_generation.count 0 +g1_survivor_space 491K 2048K -1 24.01% gc.g1_old_generation.time(ms) 0 +nonheap 66M 69M -1 96.56% +codeheap_'non-nmethods' 1M 2M 5M 22.39% +metaspace 46M 47M -1 98.01% +Runtime +os.name Mac OS X +os.version 10.15.4 +java.version 15 +java.home /Library/Java/JavaVirtualMachines/jdk-15.jdk/Contents/Home +systemload.average 10.68 +processors 8 +uptime 272s ``` ### 数据说明 -* ID: Java级别的线程ID，注意这个ID不能跟jstack中的nativeID一一对应 +* ID: Java级别的线程ID，注意这个ID不能跟jstack中的nativeID一一对应。 * NAME: 线程名 * GROUP: 线程组名 * PRIORITY: 线程优先级, 1~10之间的数字，越大表示优先级越高 * STATE: 线程的状态 -* CPU%: 线程消耗的cpu占比，采样100ms，将所有线程在这100ms内的cpu使用量求和，再算出每个线程的cpu使用占比。 -* TIME: 线程运行总时间，数据格式为`分：秒` +* CPU%: 线程的cpu使用率。比如采样间隔1000ms，某个线程的增量cpu时间为100ms，则cpu使用率=100/1000=10% +* DELTA_TIME: 上次采样之后线程运行增量CPU时间，数据格式为`秒` +* TIME: 线程运行总CPU时间，数据格式为`分:秒` * INTERRUPTED: 线程当前的中断位状态 * DAEMON: 是否是daemon线程 +#### JVM内部线程 +Java 8之后支持获取JVM内部线程CPU时间，这些线程只有名称和CPU时间，没有ID及状态等信息（显示ID为-1）。 +通过内部线程可以观测到JVM活动，如GC、JIT编译等占用CPU情况，方便了解JVM整体运行状况。 + +* 当JVM 堆(heap)/元数据(metaspace)空间不足或OOM时，可以看到GC线程的CPU占用率明显高于其他的线程。 +* 当执行`trace/watch/tt/redefine`等命令后，可以看到JIT线程活动变得更频繁。因为JVM热更新class字节码时清除了此class相关的JIT编译结果，需要重新编译。 + +JVM内部线程包括下面几种： +* JIT编译线程: 如 `C1 CompilerThread0`, `C2 CompilerThread0` +* GC线程: 如`GC Thread0`, `G1 Young RemSet Sampling` +* 其它内部线程: 如`VM Periodic Task Thread`, `VM Thread`, `Service Thread` + + ### 截图展示 -![](_static/dashboard.png "dashboard") +![](_static/dashboard.png "dashboard") \ No newline at end of file diff --git a/site/src/site/sphinx/en/dashboard.md b/site/src/site/sphinx/en/dashboard.md index c1888c601..84589cefa 100644 --- a/site/src/site/sphinx/en/dashboard.md +++ b/site/src/site/sphinx/en/dashboard.md @@ -18,39 +18,37 @@ When running in Apache Tomcat Alibaba edition, the dashboard will also present t ``` $ dashboard -ID NAME GROUP PRIORITY STATE %CPU TIME INTERRUPTED DAEMON -889 RMI TCP Connection(15)-30.10.166. RMI Runtime 9 RUNNABLE 48 0:5 false true -1077 Timer-for-arthas-dashboard-0 system 9 RUNNABLE 24 0:0 false true -1074 as-selector-daemon system 9 RUNNABLE 12 0:0 false true -284 JMX server connection timeout 284 RMI Runtime 9 TIMED_WAITI 8 0:3 false true -16 Timer-1 main 5 TIMED_WAITI 5 0:9 false true -47 Pandora pandora-qos-reporter Pool main 5 TIMED_WAITI 0 0:0 false true -48 JmonitorClient-CheckThread Pool [ main 5 TIMED_WAITI 0 0:0 false true -49 JmonitorClient-HeartBeat Pool [Th main 5 TIMED_WAITI 0 0:0 false true -50 JmonitorClient-ReaderThread Pool main 5 TIMED_WAITI 0 0:0 false true -957 RMI TCP Connection(16)-30.10.166. RMI Runtime 9 RUNNABLE 0 0:2 false true -51 JmonitorClient-WriterThread Pool main 5 TIMED_WAITI 0 0:0 false true -52 ContainerBackgroundProcessor[Stan main 5 TIMED_WAITI 0 0:0 false true -53 http-bio-8080-Acceptor-0 main 5 RUNNABLE 0 0:2 false true -54 http-bio-8080-AsyncTimeout main 5 TIMED_WAITI 0 0:0 false true -11 GC Daemon system 2 TIMED_WAITI 0 0:0 false true -Memory used total max usage GC -heap 59M 223M 1820M 3.26% gc.ps_scavenge.count 118 -ps_eden_space 14M 114M 668M 2.11% gc.ps_scavenge.time(ms) 1890 -ps_survivor_space 6M 6M 6M 96.08% gc.ps_marksweep.count 5 -ps_old_gen 39M 103M 1365M 2.86% gc.ps_marksweep.time(ms) 1140 -nonheap 234M 240M 0M 97.46% -code_cache 46M 47M 240M 19.49% -metaspace 167M 172M 0M 97.36% -Runtime Tomcat -os.name Mac OS X connector http-bio-8080 -os.version 10.10.5 QPS 0.00 -java.version 1.8.0_60 RT(ms) 1.13 -java.home error/s 0.00 - received/s 0B -systemload.average 3.44 sent/s 0B -processors 4 threadpool http-bio-8080 -uptime 16020s busy 0 +ID NAME GROUP PRIORITY STATE %CPU DELTA_TIME TIME INTERRUPTE DAEMON +-1 C2 CompilerThread0 - -1 - 1.55 0.077 0:8.684 false true +53 Timer-for-arthas-dashboard-07b system 5 RUNNABLE 0.08 0.004 0:0.004 false true +22 scheduling-1 main 5 TIMED_WAI 0.06 0.003 0:0.287 false false +-1 C1 CompilerThread0 - -1 - 0.06 0.003 0:2.171 false true +-1 VM Periodic Task Thread - -1 - 0.03 0.001 0:0.092 false true +49 arthas-NettyHttpTelnetBootstra system 5 RUNNABLE 0.02 0.001 0:0.156 false true +16 Catalina-utility-1 main 1 TIMED_WAI 0.0 0.000 0:0.029 false false +-1 G1 Young RemSet Sampling - -1 - 0.0 0.000 0:0.019 false true +17 Catalina-utility-2 main 1 WAITING 0.0 0.000 0:0.025 false false +34 http-nio-8080-ClientPoller main 5 RUNNABLE 0.0 0.000 0:0.016 false true +23 http-nio-8080-BlockPoller main 5 RUNNABLE 0.0 0.000 0:0.011 false true +-1 VM Thread - -1 - 0.0 0.000 0:0.032 false true +-1 Service Thread - -1 - 0.0 0.000 0:0.006 false true +-1 GC Thread#5 - -1 - 0.0 0.000 0:0.043 false true +Memory used total max usage GC +heap 36M 70M 4096M 0.90% gc.g1_young_generation.count 12 +g1_eden_space 6M 18M -1 33.33% 86 +g1_old_gen 30M 50M 4096M 0.74% gc.g1_old_generation.count 0 +g1_survivor_space 491K 2048K -1 24.01% gc.g1_old_generation.time(ms) 0 +nonheap 66M 69M -1 96.56% +codeheap_'non-nmethods' 1M 2M 5M 22.39% +metaspace 46M 47M -1 98.01% +Runtime +os.name Mac OS X +os.version 10.15.4 +java.version 15 +java.home /Library/Java/JavaVirtualMachines/jdk-15.jdk/Contents/Home +systemload.average 10.68 +processors 8 +uptime 272s ``` ### Notes on column headers @@ -60,11 +58,31 @@ uptime 16020s busy * GROUP: thread group name * PRIORITY: thread priority, ranged from 1 to 10. The greater number, the higher priority * STATE: thread state -* CPU%: the ratio of CPU usage for the thread, sampled every 100ms -* TIME: total running time in `minute:second` format +* CPU%: the ratio of CPU usage for the thread. For example, the sampling interval is 1000ms, and the incremental cpu time + of a thread is 100ms, then the cpu usage rate=100/1000=10% +* DELTA_TIME: incremental CPU time of thread running after the last sampling in `second` format +* TIME: total CPU time of the thread in `minute:second` format * INTERRUPTED: the thread interruption state * DAEMON: daemon thread or not + +#### JVM internal threads +After Java 8, it is supported to obtain the CPU time of JVM internal threads. These threads only have the name and CPU time, + without ID and status information (display ID is -1). + +JVM activities can be observed through internal threads, such as GC, JIT compilation, etc., to perceive the overall status of JVM. + +* When the JVM heap/metaspace space is insufficient or OOM, it can be seen that the CPU usage of the GC threads is + significantly higher than other threads. +* After executing commands such as `trace/watch/tt/redefine`, you can see that JIT threads activities become more frequent. + Because the JIT compilation data related to this class is cleared when the JVM hot update the class bytecode, it needs to be recompiled. + +JVM internal threads include the following: +* JIT compilation thread: such as `C1 CompilerThread0`, `C2 CompilerThread0` +* GC thread: such as `GC Thread0`, `G1 Young RemSet Sampling` +* Other internal threads: such as`VM Periodic Task Thread`, `VM Thread`, `Service Thread` + + ### Screenshot ![](../_static/dashboard.png "dashboard") diff --git a/site/src/site/sphinx/en/thread.md b/site/src/site/sphinx/en/thread.md index e998c6a4f..437c79757 100644 --- a/site/src/site/sphinx/en/thread.md +++ b/site/src/site/sphinx/en/thread.md @@ -13,11 +13,23 @@ thread |`[n:]`|the top n busiest threads with stack traces printed| |`[b]`|locate the thread blocking the others| |[i ``]|specify the interval to collect data to compute CPU ratios (ms)| +|[--all]|Show all matching threads| -> How the CPU ratios are calculated?

-> CPU ratio for a given thread is the CPU time it takes divided by the total CPU time within a specified interval period. It is calculated in the following way: sample CPU times for all the thread by calling `java.lang.management.ThreadMXBean#getThreadCpuTime` first, then sleep for a period (the default value is 100ms, which can be specified by `-i`), then sample CPU times again. By this, we can get the time cost for this period for each thread, then come up with the ratio.

-> Note: this operation consumes CPU time too (`getThreadCpuTime` is time-consuming), therefore it is possible to observe Arthas's thread appears in the list. To avoid this, try to increase sample interval, for example: 5000 ms.

-> If you'd like to check the CPU ratios from the very beginning of the Java process, [show-busy-java-threads](https://github.com/oldratlee/useful-scripts/blob/master/docs/java.md#-show-busy-java-threads) can come to help. +### How the CPU ratios are calculated? + +The cpu ratios here is similar to the thread `%CPU` of the linux command `top -H -p `. During a sampling interval, +the ratio of the incremental cpu time of each thread in the current JVM to the sampling interval time. + +> Working principle description: +* Do the first sampling, get the CPU time of all threads ( by calling `java.lang.management.ThreadMXBean#getThreadCpuTime()` and +`sun.management.HotspotThreadMBean.getInternalThreadCpuTimes()` ) +* Sleep and wait for an interval (the default is 200ms, the interval can be specified by `-i`) +* Do the second sampling, get the CPU time of all threads, compare the two sampling data, and calculate the incremental CPU time of each thread +* `Thread CPU usage ratio` = `Thread increment CPU time` / `Sampling interval time` * 100% + +> Note: this operation consumes CPU time too (`getThreadCpuTime` is time-consuming), therefore it is possible to observe Arthas's thread appears in the list. To avoid this, try to increase sample interval, for example: 5000 ms.
+ +> Another way to view the thread cpu usage of the Java process, [show-busy-java-threads](https://github.com/oldratlee/useful-scripts/blob/master/docs/java.md#-show-busy-java-threads) can come to help. ### Usage @@ -25,59 +37,72 @@ thread ```shell $ thread -n 3 -"as-command-execute-daemon" Id=29 cpuUsage=75% RUNNABLE - at sun.management.ThreadImpl.dumpThreads0(Native Method) - at sun.management.ThreadImpl.getThreadInfo(ThreadImpl.java:440) - at com.taobao.arthas.core.command.monitor200.ThreadCommand$1.action(ThreadCommand.java:58) - at com.taobao.arthas.core.command.handler.AbstractCommandHandler.execute(AbstractCommandHandler.java:238) - at com.taobao.arthas.core.command.handler.DefaultCommandHandler.handleCommand(DefaultCommandHandler.java:67) - at com.taobao.arthas.core.server.ArthasServer$4.run(ArthasServer.java:276) - at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) - at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) - at java.lang.Thread.run(Thread.java:745) - - Number of locked synchronizers = 1 - - java.util.concurrent.ThreadPoolExecutor$Worker@6cd0b6f8 +"C1 CompilerThread0" [Internal] cpuUsage=1.63% deltaTime=3ms time=1170ms - -"as-session-expire-daemon" Id=25 cpuUsage=24% TIMED_WAITING - at java.lang.Thread.sleep(Native Method) - at com.taobao.arthas.core.server.DefaultSessionManager$2.run(DefaultSessionManager.java:85) +"arthas-command-execute" Id=23 cpuUsage=0.11% deltaTime=0ms time=401ms RUNNABLE + at java.management@11.0.7/sun.management.ThreadImpl.dumpThreads0(Native Method) + at java.management@11.0.7/sun.management.ThreadImpl.getThreadInfo(ThreadImpl.java:466) + at com.taobao.arthas.core.command.monitor200.ThreadCommand.processTopBusyThreads(ThreadCommand.java:199) + at com.taobao.arthas.core.command.monitor200.ThreadCommand.process(ThreadCommand.java:122) + at com.taobao.arthas.core.shell.command.impl.AnnotatedCommandImpl.process(AnnotatedCommandImpl.java:82) + at com.taobao.arthas.core.shell.command.impl.AnnotatedCommandImpl.access$100(AnnotatedCommandImpl.java:18) + at com.taobao.arthas.core.shell.command.impl.AnnotatedCommandImpl$ProcessHandler.handle(AnnotatedCommandImpl.java:111) + at com.taobao.arthas.core.shell.command.impl.AnnotatedCommandImpl$ProcessHandler.handle(AnnotatedCommandImpl.java:108) + at com.taobao.arthas.core.shell.system.impl.ProcessImpl$CommandProcessTask.run(ProcessImpl.java:385) + at java.base@11.0.7/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) + at java.base@11.0.7/java.util.concurrent.FutureTask.run(FutureTask.java:264) + at java.base@11.0.7/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) + at java.base@11.0.7/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) + at java.base@11.0.7/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) + at java.base@11.0.7/java.lang.Thread.run(Thread.java:834) - -"Reference Handler" Id=2 cpuUsage=0% WAITING on java.lang.ref.Reference$Lock@69ba0f27 - at java.lang.Object.wait(Native Method) - - waiting on java.lang.ref.Reference$Lock@69ba0f27 - at java.lang.Object.wait(Object.java:503) - at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:133) +"VM Periodic Task Thread" [Internal] cpuUsage=0.07% deltaTime=0ms time=584ms ``` -#### List all threads' info when no options provided +* Without thread ID, including `[Internal]` means JVM internal thread, refer to the introduction of [dashboard](dashboard.md) command. +* `cpuUsage` is the CPU usage of the thread during the sampling interval, consistent with the data of the [dashboard](dashboard.md) command. +* `deltaTime` is the incremental CPU time of the thread during the sampling interval. If it is less than 1ms, it will be rounded and displayed as 0ms. +* `time` The total CPU time of thread. + +**Note:** The thread stack is acquired at the end of the second sampling, which does not indicate that the thread is +processing the same task during the sampling interval. It is recommended that the interval time should not be too long. +The larger the interval time, the more inaccurate. + +You can try to specify different intervals according to the specific situation and observe the output results. + + +#### List first page threads' info when no options provided + +By default, they are arranged in descending order of CPU increment time, and only the first page of data is displayed. ```shell $ thread -Threads Total: 16, NEW: 0, RUNNABLE: 7, BLOCKED: 0, WAITING: 5, TIMED_WAITING: 4, TERMINATED: 0 -ID NAME GROUP PRIORITY STATE %CPU TIME INTERRUPTE DAEMON -30 as-command-execute-daemon system 9 RUNNABLE 72 0:0 false true -23 as-session-expire-daemon system 9 TIMED_WAIT 27 0:0 false true -22 Attach Listener system 9 RUNNABLE 0 0:0 false true -11 pool-2-thread-1 main 5 TIMED_WAIT 0 0:0 false false -12 Thread-2 main 5 RUNNABLE 0 0:0 false true -13 pool-3-thread-1 main 5 TIMED_WAIT 0 0:0 false false -25 as-selector-daemon system 9 RUNNABLE 0 0:0 false true -14 Thread-3 main 5 TIMED_WAIT 0 0:0 false false -26 pool-5-thread-1 system 5 WAITING 0 0:0 false false -15 Thread-4 main 5 RUNNABLE 0 0:0 false false -1 main main 5 WAITING 0 0:2 false false -2 Reference Handler system 10 WAITING 0 0:0 false true -3 Finalizer system 8 WAITING 0 0:0 false true -4 Signal Dispatcher system 9 RUNNABLE 0 0:0 false true -20 NonBlockingInputStreamThread main 5 WAITING 0 0:0 false true -21 Thread-8 main 5 RUNNABLE 0 0:0 false true +Threads Total: 33, NEW: 0, RUNNABLE: 9, BLOCKED: 0, WAITING: 3, TIMED_WAITING: 4, TERMINATED: 0, Internal threads: 17 +ID NAME GROUP PRIORITY STATE %CPU DELTA_TIME TIME INTERRUPT DAEMON +-1 C2 CompilerThread0 - -1 - 5.06 0.010 0:0.973 false true +-1 C1 CompilerThread0 - -1 - 0.95 0.001 0:0.603 false true +23 arthas-command-execute system 5 RUNNABLE 0.17 0.000 0:0.226 false true +-1 VM Periodic Task Thread - -1 - 0.05 0.000 0:0.094 false true +-1 Sweeper thread - -1 - 0.04 0.000 0:0.011 false true +-1 G1 Young RemSet Sampling - -1 - 0.02 0.000 0:0.025 false true +12 Attach Listener system 9 RUNNABLE 0.0 0.000 0:0.022 false true +11 Common-Cleaner InnocuousThrea 8 TIMED_WAI 0.0 0.000 0:0.000 false true +3 Finalizer system 8 WAITING 0.0 0.000 0:0.000 false true +2 Reference Handler system 10 RUNNABLE 0.0 0.000 0:0.000 false true +4 Signal Dispatcher system 9 RUNNABLE 0.0 0.000 0:0.000 false true +15 arthas-NettyHttpTelnetBootstra system 5 RUNNABLE 0.0 0.000 0:0.029 false true +22 arthas-NettyHttpTelnetBootstra system 5 RUNNABLE 0.0 0.000 0:0.196 false true +24 arthas-NettyHttpTelnetBootstra system 5 RUNNABLE 0.0 0.000 0:0.038 false true +16 arthas-NettyWebsocketTtyBootst system 5 RUNNABLE 0.0 0.000 0:0.001 false true +17 arthas-NettyWebsocketTtyBootst system 5 RUNNABLE 0.0 0.000 0:0.001 false true ``` +#### thread --all, show all matching threads + +Display all matching threads. Sometimes it is necessary to obtain all the thread data of the JVM for analysis. + #### thread id, show the running stack for the target thread ```shell @@ -140,6 +165,10 @@ $ thread -b #### thread -i, specify the sampling interval +* `thread -i 1000`: Count the thread cpu time of the last 1000ms. + +* `thread -n 3 -i 1000`: List the 3 busiest thread stacks in 1000ms + ```bash $ thread -n 3 -i 1000 "as-command-execute-daemon" Id=4759 cpuUsage=23% RUNNABLE @@ -165,11 +194,9 @@ $ thread -n 3 -i 1000 ```bash [arthas@28114]$ thread --state WAITING -Threads Total: 15, NEW: 0, RUNNABLE: 7, BLOCKED: 0, WAITING: 5, TIMED_WAITING: 3, TERMINATED: 0 -ID NAME GROUP PRIORITY STATE %CPU TIME INTERRU DAEMON -198 AsyncAppender-Worker-arth system 9 WAITING 0 0:0 false true -3 Finalizer system 8 WAITING 0 0:0 false true -14 RMI Scheduler(0) system 9 WAITING 0 0:0 false true -2 Reference Handler system 10 WAITING 0 0:0 false true -204 pool-8-thread-1 system 5 WAITING 0 0:0 false false +Threads Total: 16, NEW: 0, RUNNABLE: 9, BLOCKED: 0, WAITING: 3, TIMED_WAITING: 4, TERMINATED: 0 +ID NAME GROUP PRIORITY STATE %CPU DELTA_TIME TIME INTERRUPTE DAEMON +3 Finalizer system 8 WAITING 0.0 0.000 0:0.000 false true +20 arthas-UserStat system 9 WAITING 0.0 0.000 0:0.001 false true +14 arthas-timer system 9 WAITING 0.0 0.000 0:0.000 false true ``` \ No newline at end of file diff --git a/site/src/site/sphinx/thread.md b/site/src/site/sphinx/thread.md index 546b58e01..7a35ecc10 100644 --- a/site/src/site/sphinx/thread.md +++ b/site/src/site/sphinx/thread.md @@ -13,16 +13,23 @@ thread |*id*|线程id| |[n:]|指定最忙的前N个线程并打印堆栈| |[b]|找出当前阻塞其他线程的线程| -|[i ``]|指定cpu占比统计的采样间隔，单位为毫秒| +|[i ``]|指定cpu使用率统计的采样间隔，单位为毫秒，默认值为200| +|[--all]|显示所有匹配的线程| -> cpu占比是如何统计出来的？ +### cpu使用率是如何统计出来的？ -> 这里的cpu统计的是，一段采样间隔内，当前JVM里各个线程所占用的cpu时间占总cpu时间的百分比。其计算方法为： -> 首先进行一次采样，获得所有线程的cpu的使用时间(调用的是`java.lang.management.ThreadMXBean#getThreadCpuTime`这个接口)，然后睡眠一段时间，默认100ms，可以通过`-i`参数指定，然后再采样一次，最后得出这段时间内各个线程消耗的cpu时间情况，最后算出百分比。 +这里的cpu使用率与linux 命令`top -H -p ` 的线程`%CPU`类似，一段采样间隔时间内，当前JVM里各个线程的增量cpu时间与采样间隔时间的比例。 + +#### 工作原理说明： + +* 首先第一次采样，获取所有线程的CPU时间(调用的是`java.lang.management.ThreadMXBean#getThreadCpuTime()`及`sun.management.HotspotThreadMBean.getInternalThreadCpuTimes()`接口) +* 然后睡眠等待一个间隔时间（默认为200ms，可以通过`-i`指定间隔时间） +* 再次第二次采样，获取所有线程的CPU时间，对比两次采样数据，计算出每个线程的增量CPU时间 +* 线程CPU使用率 = 线程增量CPU时间 / 采样间隔时间 * 100% > 注意： 这个统计也会产生一定的开销（JDK这个接口本身开销比较大），因此会看到as的线程占用一定的百分比，为了降低统计自身的开销带来的影响，可以把采样间隔拉长一些，比如5000毫秒。 -> 如果想看从Java进程启动开始到现在的cpu占比情况：可以使用[show-busy-java-threads](https://github.com/oldratlee/useful-scripts/blob/master/docs/java.md#-show-busy-java-threads)这个脚本 +> 另外一种查看Java进程的线程cpu使用率方法：可以使用[show-busy-java-threads](https://github.com/oldratlee/useful-scripts/blob/master/docs/java.md#-show-busy-java-threads)这个脚本 ### 使用参考 @@ -30,60 +37,70 @@ thread ```shell $ thread -n 3 -"as-command-execute-daemon" Id=29 cpuUsage=75% RUNNABLE - at sun.management.ThreadImpl.dumpThreads0(Native Method) - at sun.management.ThreadImpl.getThreadInfo(ThreadImpl.java:440) - at com.taobao.arthas.core.command.monitor200.ThreadCommand$1.action(ThreadCommand.java:58) - at com.taobao.arthas.core.command.handler.AbstractCommandHandler.execute(AbstractCommandHandler.java:238) - at com.taobao.arthas.core.command.handler.DefaultCommandHandler.handleCommand(DefaultCommandHandler.java:67) - at com.taobao.arthas.core.server.ArthasServer$4.run(ArthasServer.java:276) - at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) - at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) - at java.lang.Thread.run(Thread.java:745) - - Number of locked synchronizers = 1 - - java.util.concurrent.ThreadPoolExecutor$Worker@6cd0b6f8 +"C1 CompilerThread0" [Internal] cpuUsage=1.63% deltaTime=3ms time=1170ms - -"as-session-expire-daemon" Id=25 cpuUsage=24% TIMED_WAITING - at java.lang.Thread.sleep(Native Method) - at com.taobao.arthas.core.server.DefaultSessionManager$2.run(DefaultSessionManager.java:85) +"arthas-command-execute" Id=23 cpuUsage=0.11% deltaTime=0ms time=401ms RUNNABLE + at java.management@11.0.7/sun.management.ThreadImpl.dumpThreads0(Native Method) + at java.management@11.0.7/sun.management.ThreadImpl.getThreadInfo(ThreadImpl.java:466) + at com.taobao.arthas.core.command.monitor200.ThreadCommand.processTopBusyThreads(ThreadCommand.java:199) + at com.taobao.arthas.core.command.monitor200.ThreadCommand.process(ThreadCommand.java:122) + at com.taobao.arthas.core.shell.command.impl.AnnotatedCommandImpl.process(AnnotatedCommandImpl.java:82) + at com.taobao.arthas.core.shell.command.impl.AnnotatedCommandImpl.access$100(AnnotatedCommandImpl.java:18) + at com.taobao.arthas.core.shell.command.impl.AnnotatedCommandImpl$ProcessHandler.handle(AnnotatedCommandImpl.java:111) + at com.taobao.arthas.core.shell.command.impl.AnnotatedCommandImpl$ProcessHandler.handle(AnnotatedCommandImpl.java:108) + at com.taobao.arthas.core.shell.system.impl.ProcessImpl$CommandProcessTask.run(ProcessImpl.java:385) + at java.base@11.0.7/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) + at java.base@11.0.7/java.util.concurrent.FutureTask.run(FutureTask.java:264) + at java.base@11.0.7/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) + at java.base@11.0.7/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) + at java.base@11.0.7/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) + at java.base@11.0.7/java.lang.Thread.run(Thread.java:834) - -"Reference Handler" Id=2 cpuUsage=0% WAITING on java.lang.ref.Reference$Lock@69ba0f27 - at java.lang.Object.wait(Native Method) - - waiting on java.lang.ref.Reference$Lock@69ba0f27 - at java.lang.Object.wait(Object.java:503) - at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:133) +"VM Periodic Task Thread" [Internal] cpuUsage=0.07% deltaTime=0ms time=584ms ``` -#### 当没有参数时，显示所有线程的信息。 +* 没有线程ID，包含`[Internal]`表示为JVM内部线程，参考[dashboard](dashboard.md)命令的介绍。 +* `cpuUsage`为采样间隔时间内线程的CPU使用率，与[dashboard](dashboard.md)命令的数据一致。 +* `deltaTime`为采样间隔时间内线程的增量CPU时间，小于1ms时被取整显示为0ms。 +* `time` 线程运行总CPU时间。 + +注意：线程栈为第二采样结束时获取，不能表明采样间隔时间内该线程都是在处理相同的任务。建议间隔时间不要太长，可能间隔时间越大越不准确。 +可以根据具体情况尝试指定不同的间隔时间，观察输出结果。 + +#### 当没有参数时，显示第一页线程的信息 + +默认按照CPU增量时间降序排列，只显示第一页数据。 ```shell $ thread -Threads Total: 16, NEW: 0, RUNNABLE: 7, BLOCKED: 0, WAITING: 5, TIMED_WAITING: 4, TERMINATED: 0 -ID NAME GROUP PRIORITY STATE %CPU TIME INTERRUPTE DAEMON -30 as-command-execute-daemon system 9 RUNNABLE 72 0:0 false true -23 as-session-expire-daemon system 9 TIMED_WAIT 27 0:0 false true -22 Attach Listener system 9 RUNNABLE 0 0:0 false true -11 pool-2-thread-1 main 5 TIMED_WAIT 0 0:0 false false -12 Thread-2 main 5 RUNNABLE 0 0:0 false true -13 pool-3-thread-1 main 5 TIMED_WAIT 0 0:0 false false -25 as-selector-daemon system 9 RUNNABLE 0 0:0 false true -14 Thread-3 main 5 TIMED_WAIT 0 0:0 false false -26 pool-5-thread-1 system 5 WAITING 0 0:0 false false -15 Thread-4 main 5 RUNNABLE 0 0:0 false false -1 main main 5 WAITING 0 0:2 false false -2 Reference Handler system 10 WAITING 0 0:0 false true -3 Finalizer system 8 WAITING 0 0:0 false true -4 Signal Dispatcher system 9 RUNNABLE 0 0:0 false true -20 NonBlockingInputStreamThread main 5 WAITING 0 0:0 false true -21 Thread-8 main 5 RUNNABLE 0 0:0 false true +Threads Total: 33, NEW: 0, RUNNABLE: 9, BLOCKED: 0, WAITING: 3, TIMED_WAITING: 4, TERMINATED: 0, Internal threads: 17 +ID NAME GROUP PRIORITY STATE %CPU DELTA_TIME TIME INTERRUPT DAEMON +-1 C2 CompilerThread0 - -1 - 5.06 0.010 0:0.973 false true +-1 C1 CompilerThread0 - -1 - 0.95 0.001 0:0.603 false true +23 arthas-command-execute system 5 RUNNABLE 0.17 0.000 0:0.226 false true +-1 VM Periodic Task Thread - -1 - 0.05 0.000 0:0.094 false true +-1 Sweeper thread - -1 - 0.04 0.000 0:0.011 false true +-1 G1 Young RemSet Sampling - -1 - 0.02 0.000 0:0.025 false true +12 Attach Listener system 9 RUNNABLE 0.0 0.000 0:0.022 false true +11 Common-Cleaner InnocuousThrea 8 TIMED_WAI 0.0 0.000 0:0.000 false true +3 Finalizer system 8 WAITING 0.0 0.000 0:0.000 false true +2 Reference Handler system 10 RUNNABLE 0.0 0.000 0:0.000 false true +4 Signal Dispatcher system 9 RUNNABLE 0.0 0.000 0:0.000 false true +15 arthas-NettyHttpTelnetBootstra system 5 RUNNABLE 0.0 0.000 0:0.029 false true +22 arthas-NettyHttpTelnetBootstra system 5 RUNNABLE 0.0 0.000 0:0.196 false true +24 arthas-NettyHttpTelnetBootstra system 5 RUNNABLE 0.0 0.000 0:0.038 false true +16 arthas-NettyWebsocketTtyBootst system 5 RUNNABLE 0.0 0.000 0:0.001 false true +17 arthas-NettyWebsocketTtyBootst system 5 RUNNABLE 0.0 0.000 0:0.001 false true ``` -#### thread id， 显示指定线程的运行堆栈 +#### thread --all, 显示所有匹配的线程 + +显示所有匹配线程信息，有时需要获取全部JVM的线程数据进行分析。 + + +#### thread id, 显示指定线程的运行堆栈 ```shell $ thread 1 @@ -145,6 +162,10 @@ $ thread -b #### thread -i, 指定采样时间间隔 +* `thread -i 1000` : 统计最近1000ms内的线程CPU时间。 + +* `thread -n 3 -i 1000` : 列出1000ms内最忙的3个线程栈 + ```bash $ thread -n 3 -i 1000 "as-command-execute-daemon" Id=4759 cpuUsage=23% RUNNABLE @@ -170,11 +191,9 @@ $ thread -n 3 -i 1000 ```bash [arthas@28114]$ thread --state WAITING -Threads Total: 15, NEW: 0, RUNNABLE: 7, BLOCKED: 0, WAITING: 5, TIMED_WAITING: 3, TERMINATED: 0 -ID NAME GROUP PRIORITY STATE %CPU TIME INTERRU DAEMON -198 AsyncAppender-Worker-arth system 9 WAITING 0 0:0 false true -3 Finalizer system 8 WAITING 0 0:0 false true -14 RMI Scheduler(0) system 9 WAITING 0 0:0 false true -2 Reference Handler system 10 WAITING 0 0:0 false true -204 pool-8-thread-1 system 5 WAITING 0 0:0 false false +Threads Total: 16, NEW: 0, RUNNABLE: 9, BLOCKED: 0, WAITING: 3, TIMED_WAITING: 4, TERMINATED: 0 +ID NAME GROUP PRIORITY STATE %CPU DELTA_TIME TIME INTERRUPTE DAEMON +3 Finalizer system 8 WAITING 0.0 0.000 0:0.000 false true +20 arthas-UserStat system 9 WAITING 0.0 0.000 0:0.001 false true +14 arthas-timer system 9 WAITING 0.0 0.000 0:0.000 false true ``` diff --git a/tutorials/katacoda/command-dashboard-cn/dashboard.md b/tutorials/katacoda/command-dashboard-cn/dashboard.md index 8a6d79f2c..21908b672 100644 --- a/tutorials/katacoda/command-dashboard-cn/dashboard.md +++ b/tutorials/katacoda/command-dashboard-cn/dashboard.md @@ -4,41 +4,67 @@ 当运行在Ali-tomcat时，会显示当前tomcat的实时信息，如HTTP请求的qps, rt, 错误数, 线程池信息等等。 -```bash +``` $ dashboard -ID NAME GROUP PRIORITY STATE %CPU TIME INTERRUPTED DAEMON -889 RMI TCP Connection(15)-30.10.166. RMI Runtime 9 RUNNABLE 48 0:5 false true -1077 Timer-for-arthas-dashboard-0 system 9 RUNNABLE 24 0:0 false true -1074 as-selector-daemon system 9 RUNNABLE 12 0:0 false true -284 JMX server connection timeout 284 RMI Runtime 9 TIMED_WAITI 8 0:3 false true -16 Timer-1 main 5 TIMED_WAITI 5 0:9 false true -47 Pandora pandora-qos-reporter Pool main 5 TIMED_WAITI 0 0:0 false true -48 JmonitorClient-CheckThread Pool [ main 5 TIMED_WAITI 0 0:0 false true -49 JmonitorClient-HeartBeat Pool [Th main 5 TIMED_WAITI 0 0:0 false true -50 JmonitorClient-ReaderThread Pool main 5 TIMED_WAITI 0 0:0 false true -957 RMI TCP Connection(16)-30.10.166. RMI Runtime 9 RUNNABLE 0 0:2 false true -51 JmonitorClient-WriterThread Pool main 5 TIMED_WAITI 0 0:0 false true -52 ContainerBackgroundProcessor[Stan main 5 TIMED_WAITI 0 0:0 false true -53 http-bio-8080-Acceptor-0 main 5 RUNNABLE 0 0:2 false true -54 http-bio-8080-AsyncTimeout main 5 TIMED_WAITI 0 0:0 false true -11 GC Daemon system 2 TIMED_WAITI 0 0:0 false true -Memory used total max usage GC -heap 59M 223M 1820M 3.26% gc.ps_scavenge.count 118 -ps_eden_space 14M 114M 668M 2.11% gc.ps_scavenge.time(ms) 1890 -ps_survivor_space 6M 6M 6M 96.08% gc.ps_marksweep.count 5 -ps_old_gen 39M 103M 1365M 2.86% gc.ps_marksweep.time(ms) 1140 -nonheap 234M 240M 0M 97.46% -code_cache 46M 47M 240M 19.49% -metaspace 167M 172M 0M 97.36% -Runtime Tomcat -os.name Mac OS X connector http-bio-8080 -os.version 10.10.5 QPS 0.00 -java.version 1.8.0_60 RT(ms) 1.13 -java.home error/s 0.00 - received/s 0B -systemload.average 3.44 sent/s 0B -processors 4 threadpool http-bio-8080 -uptime 16020s busy 0 +ID NAME GROUP PRIORITY STATE %CPU DELTA_TIME TIME INTERRUPTE DAEMON +-1 C2 CompilerThread0 - -1 - 1.55 0.077 0:8.684 false true +53 Timer-for-arthas-dashboard-07b system 5 RUNNABLE 0.08 0.004 0:0.004 false true +22 scheduling-1 main 5 TIMED_WAI 0.06 0.003 0:0.287 false false +-1 C1 CompilerThread0 - -1 - 0.06 0.003 0:2.171 false true +-1 VM Periodic Task Thread - -1 - 0.03 0.001 0:0.092 false true +49 arthas-NettyHttpTelnetBootstra system 5 RUNNABLE 0.02 0.001 0:0.156 false true +16 Catalina-utility-1 main 1 TIMED_WAI 0.0 0.000 0:0.029 false false +-1 G1 Young RemSet Sampling - -1 - 0.0 0.000 0:0.019 false true +17 Catalina-utility-2 main 1 WAITING 0.0 0.000 0:0.025 false false +34 http-nio-8080-ClientPoller main 5 RUNNABLE 0.0 0.000 0:0.016 false true +23 http-nio-8080-BlockPoller main 5 RUNNABLE 0.0 0.000 0:0.011 false true +-1 VM Thread - -1 - 0.0 0.000 0:0.032 false true +-1 Service Thread - -1 - 0.0 0.000 0:0.006 false true +-1 GC Thread#5 - -1 - 0.0 0.000 0:0.043 false true +Memory used total max usage GC +heap 36M 70M 4096M 0.90% gc.g1_young_generation.count 12 +g1_eden_space 6M 18M -1 33.33% 86 +g1_old_gen 30M 50M 4096M 0.74% gc.g1_old_generation.count 0 +g1_survivor_space 491K 2048K -1 24.01% gc.g1_old_generation.time(ms) 0 +nonheap 66M 69M -1 96.56% +codeheap_'non-nmethods' 1M 2M 5M 22.39% +metaspace 46M 47M -1 98.01% +Runtime +os.name Mac OS X +os.version 10.15.4 +java.version 15 +java.home /Library/Java/JavaVirtualMachines/jdk-15.jdk/Contents/Home +systemload.average 10.68 +processors 8 +uptime 272s ``` 输入 `Q`{{execute T2}} 或者 `Ctrl+C` 可以退出dashboard命令。 + + + +### 数据说明 + +* ID: Java级别的线程ID，注意这个ID不能跟jstack中的nativeID一一对应。 +* NAME: 线程名 +* GROUP: 线程组名 +* PRIORITY: 线程优先级, 1~10之间的数字，越大表示优先级越高 +* STATE: 线程的状态 +* CPU%: 线程的cpu使用率。比如采样间隔1000ms，某个线程的增量cpu时间为100ms，则cpu使用率=100/1000=10% +* DELTA_TIME: 上次采样之后线程运行增量CPU时间，数据格式为`秒` +* TIME: 线程运行总CPU时间，数据格式为`分:秒` +* INTERRUPTED: 线程当前的中断位状态 +* DAEMON: 是否是daemon线程 + +#### JVM内部线程 +Java 8之后支持获取JVM内部线程CPU时间，这些线程只有名称和CPU时间，没有ID及状态等信息（显示ID为-1）。 +通过内部线程可以观测到JVM活动，如GC、JIT编译等占用CPU情况，方便了解JVM整体运行状况。 + +* 当JVM 堆(heap)/元数据(metaspace)空间不足或OOM时，可以看到GC线程的CPU占用率明显高于其他的线程。 +* 当执行`trace/watch/tt/redefine`等命令后，可以看到JIT线程活动变得更频繁。因为JVM热更新class字节码时清除了此class相关的JIT编译结果，需要重新编译。 + +JVM内部线程包括下面几种： +* JIT编译线程: 如 `C1 CompilerThread0`, `C2 CompilerThread0` +* GC线程: 如`GC Thread0`, `G1 Young RemSet Sampling` +* 其它内部线程: 如`VM Periodic Task Thread`, `VM Thread`, `Service Thread` + diff --git a/tutorials/katacoda/command-dashboard-en/dashboard.md b/tutorials/katacoda/command-dashboard-en/dashboard.md index 73514fdd7..576b095b8 100644 --- a/tutorials/katacoda/command-dashboard-en/dashboard.md +++ b/tutorials/katacoda/command-dashboard-en/dashboard.md @@ -4,41 +4,71 @@ The `dashboard`{{execute T2}} command allows you to view the real-time data pane When running in Apache Tomcat Alibaba edition, the dashboard will also present the real time statistics of the tomcat, including [QPS](https://en.wikipedia.org/wiki/Queries_per_second), RT, error counts, and thread pool, etc. -```bash +``` $ dashboard -ID NAME GROUP PRIORITY STATE %CPU TIME INTERRUPTED DAEMON -889 RMI TCP Connection(15)-30.10.166. RMI Runtime 9 RUNNABLE 48 0:5 false true -1077 Timer-for-arthas-dashboard-0 system 9 RUNNABLE 24 0:0 false true -1074 as-selector-daemon system 9 RUNNABLE 12 0:0 false true -284 JMX server connection timeout 284 RMI Runtime 9 TIMED_WAITI 8 0:3 false true -16 Timer-1 main 5 TIMED_WAITI 5 0:9 false true -47 Pandora pandora-qos-reporter Pool main 5 TIMED_WAITI 0 0:0 false true -48 JmonitorClient-CheckThread Pool [ main 5 TIMED_WAITI 0 0:0 false true -49 JmonitorClient-HeartBeat Pool [Th main 5 TIMED_WAITI 0 0:0 false true -50 JmonitorClient-ReaderThread Pool main 5 TIMED_WAITI 0 0:0 false true -957 RMI TCP Connection(16)-30.10.166. RMI Runtime 9 RUNNABLE 0 0:2 false true -51 JmonitorClient-WriterThread Pool main 5 TIMED_WAITI 0 0:0 false true -52 ContainerBackgroundProcessor[Stan main 5 TIMED_WAITI 0 0:0 false true -53 http-bio-8080-Acceptor-0 main 5 RUNNABLE 0 0:2 false true -54 http-bio-8080-AsyncTimeout main 5 TIMED_WAITI 0 0:0 false true -11 GC Daemon system 2 TIMED_WAITI 0 0:0 false true -Memory used total max usage GC -heap 59M 223M 1820M 3.26% gc.ps_scavenge.count 118 -ps_eden_space 14M 114M 668M 2.11% gc.ps_scavenge.time(ms) 1890 -ps_survivor_space 6M 6M 6M 96.08% gc.ps_marksweep.count 5 -ps_old_gen 39M 103M 1365M 2.86% gc.ps_marksweep.time(ms) 1140 -nonheap 234M 240M 0M 97.46% -code_cache 46M 47M 240M 19.49% -metaspace 167M 172M 0M 97.36% -Runtime Tomcat -os.name Mac OS X connector http-bio-8080 -os.version 10.10.5 QPS 0.00 -java.version 1.8.0_60 RT(ms) 1.13 -java.home error/s 0.00 - received/s 0B -systemload.average 3.44 sent/s 0B -processors 4 threadpool http-bio-8080 -uptime 16020s busy 0 +ID NAME GROUP PRIORITY STATE %CPU DELTA_TIME TIME INTERRUPTE DAEMON +-1 C2 CompilerThread0 - -1 - 1.55 0.077 0:8.684 false true +53 Timer-for-arthas-dashboard-07b system 5 RUNNABLE 0.08 0.004 0:0.004 false true +22 scheduling-1 main 5 TIMED_WAI 0.06 0.003 0:0.287 false false +-1 C1 CompilerThread0 - -1 - 0.06 0.003 0:2.171 false true +-1 VM Periodic Task Thread - -1 - 0.03 0.001 0:0.092 false true +49 arthas-NettyHttpTelnetBootstra system 5 RUNNABLE 0.02 0.001 0:0.156 false true +16 Catalina-utility-1 main 1 TIMED_WAI 0.0 0.000 0:0.029 false false +-1 G1 Young RemSet Sampling - -1 - 0.0 0.000 0:0.019 false true +17 Catalina-utility-2 main 1 WAITING 0.0 0.000 0:0.025 false false +34 http-nio-8080-ClientPoller main 5 RUNNABLE 0.0 0.000 0:0.016 false true +23 http-nio-8080-BlockPoller main 5 RUNNABLE 0.0 0.000 0:0.011 false true +-1 VM Thread - -1 - 0.0 0.000 0:0.032 false true +-1 Service Thread - -1 - 0.0 0.000 0:0.006 false true +-1 GC Thread#5 - -1 - 0.0 0.000 0:0.043 false true +Memory used total max usage GC +heap 36M 70M 4096M 0.90% gc.g1_young_generation.count 12 +g1_eden_space 6M 18M -1 33.33% 86 +g1_old_gen 30M 50M 4096M 0.74% gc.g1_old_generation.count 0 +g1_survivor_space 491K 2048K -1 24.01% gc.g1_old_generation.time(ms) 0 +nonheap 66M 69M -1 96.56% +codeheap_'non-nmethods' 1M 2M 5M 22.39% +metaspace 46M 47M -1 98.01% +Runtime +os.name Mac OS X +os.version 10.15.4 +java.version 15 +java.home /Library/Java/JavaVirtualMachines/jdk-15.jdk/Contents/Home +systemload.average 10.68 +processors 8 +uptime 272s ``` Enter `Q`{{execute T2}} or `Ctrl+C` to exit the dashboard command. + + +### Notes on column headers + +* ID: JVM thread ID, pls. note this ID is different from the nativeID in jstack +* NAME: thread name +* GROUP: thread group name +* PRIORITY: thread priority, ranged from 1 to 10. The greater number, the higher priority +* STATE: thread state +* CPU%: the ratio of CPU usage for the thread. For example, the sampling interval is 1000ms, and the incremental cpu time + of a thread is 100ms, then the cpu usage rate=100/1000=10% +* DELTA_TIME: incremental CPU time of thread running after the last sampling in `second` format +* TIME: total CPU time of the thread in `minute:second` format +* INTERRUPTED: the thread interruption state +* DAEMON: daemon thread or not + + +#### JVM internal threads +After Java 8, it is supported to obtain the CPU time of JVM internal threads. These threads only have the name and CPU time, + without ID and status information (display ID is -1). + +JVM activities can be observed through internal threads, such as GC, JIT compilation, etc., to perceive the overall status of JVM. + +* When the JVM heap/metaspace space is insufficient or OOM, it can be seen that the CPU usage of the GC threads is + significantly higher than other threads. +* After executing commands such as `trace/watch/tt/redefine`, you can see that JIT threads activities become more frequent. + Because the JIT compilation data related to this class is cleared when the JVM hot update the class bytecode, it needs to be recompiled. + +JVM internal threads include the following: +* JIT compilation thread: such as `C1 CompilerThread0`, `C2 CompilerThread0` +* GC thread: such as `GC Thread0`, `G1 Young RemSet Sampling` +* Other internal threads: such as`VM Periodic Task Thread`, `VM Thread`, `Service Thread` diff --git a/tutorials/katacoda/command-thread-cn/CPU-ratios-calculate.md b/tutorials/katacoda/command-thread-cn/CPU-ratios-calculate.md index 292d6b204..fc60c52a3 100644 --- a/tutorials/katacoda/command-thread-cn/CPU-ratios-calculate.md +++ b/tutorials/katacoda/command-thread-cn/CPU-ratios-calculate.md @@ -1,6 +1,15 @@ -这里的cpu统计的是，一段采样间隔内，当前JVM里各个线程所占用的cpu时间占总cpu时间的百分比。其计算方法为： 首先进行一次采样，获得所有线程的cpu的使用时间(调用的是`java.lang.management.ThreadMXBean#getThreadCpuTime`这个接口)，然后睡眠一段时间，默认100ms，可以通过`-i`参数指定，然后再采样一次，最后得出这段时间内各个线程消耗的cpu时间情况，最后算出百分比。 +### cpu使用率是如何统计出来的？ -注意： 这个统计也会产生一定的开销（JDK这个接口本身开销比较大），因此会看到as的线程占用一定的百分比，为了降低统计自身的开销带来的影响，可以把采样间隔拉长一些，比如5000毫秒。 +这里的cpu使用率与linux 命令`top -H -p ` 的线程`%CPU`类似，一段采样间隔时间内，当前JVM里各个线程的增量cpu时间与采样间隔时间的比例。 -如果想看从Java进程启动开始到现在的cpu占比情况：可以使用[`show-busy-java-threads`](https://github.com/oldratlee/useful-scripts/blob/master/docs/java.md#-show-busy-java-threads)这个脚本 +> 工作原理说明： + +* 首先第一次采样，获取所有线程的CPU时间(调用的是`java.lang.management.ThreadMXBean#getThreadCpuTime()`及`sun.management.HotspotThreadMBean.getInternalThreadCpuTimes()`接口) +* 然后睡眠等待一个间隔时间（默认为200ms，可以通过`-i`指定间隔时间） +* 再次第二次采样，获取所有线程的CPU时间，对比两次采样数据，计算出每个线程的增量CPU时间 +* 线程CPU使用率 = 线程增量CPU时间 / 采样间隔时间 * 100% + +> 注意： 这个统计也会产生一定的开销（JDK这个接口本身开销比较大），因此会看到as的线程占用一定的百分比，为了降低统计自身的开销带来的影响，可以把采样间隔拉长一些，比如5000毫秒。 + +> 另外一种查看Java进程的线程cpu使用率方法：可以使用[show-busy-java-threads](https://github.com/oldratlee/useful-scripts/blob/master/docs/java.md#-show-busy-java-threads)这个脚本 diff --git a/tutorials/katacoda/command-thread-cn/thread-usage.md b/tutorials/katacoda/command-thread-cn/thread-usage.md index 17fce7390..5b56eb478 100644 --- a/tutorials/katacoda/command-thread-cn/thread-usage.md +++ b/tutorials/katacoda/command-thread-cn/thread-usage.md @@ -5,57 +5,72 @@ ```bash $ thread -n 3 -"as-command-execute-daemon" Id=29 cpuUsage=75% RUNNABLE - at sun.management.ThreadImpl.dumpThreads0(Native Method) - at sun.management.ThreadImpl.getThreadInfo(ThreadImpl.java:440) - at com.taobao.arthas.core.command.monitor200.ThreadCommand$1.action(ThreadCommand.java:58) - at com.taobao.arthas.core.command.handler.AbstractCommandHandler.execute(AbstractCommandHandler.java:238) - at com.taobao.arthas.core.command.handler.DefaultCommandHandler.handleCommand(DefaultCommandHandler.java:67) - at com.taobao.arthas.core.server.ArthasServer$4.run(ArthasServer.java:276) - at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) - at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) - at java.lang.Thread.run(Thread.java:745) - - Number of locked synchronizers = 1 - - java.util.concurrent.ThreadPoolExecutor$Worker@6cd0b6f8 - -"as-session-expire-daemon" Id=25 cpuUsage=24% TIMED_WAITING - at java.lang.Thread.sleep(Native Method) - at com.taobao.arthas.core.server.DefaultSessionManager$2.run(DefaultSessionManager.java:85) - -"Reference Handler" Id=2 cpuUsage=0% WAITING on java.lang.ref.Reference$Lock@69ba0f27 - at java.lang.Object.wait(Native Method) - - waiting on java.lang.ref.Reference$Lock@69ba0f27 - at java.lang.Object.wait(Object.java:503) - at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:133) +"C1 CompilerThread0" [Internal] cpuUsage=1.63% deltaTime=3ms time=1170ms + + +"arthas-command-execute" Id=23 cpuUsage=0.11% deltaTime=0ms time=401ms RUNNABLE + at java.management@11.0.7/sun.management.ThreadImpl.dumpThreads0(Native Method) + at java.management@11.0.7/sun.management.ThreadImpl.getThreadInfo(ThreadImpl.java:466) + at com.taobao.arthas.core.command.monitor200.ThreadCommand.processTopBusyThreads(ThreadCommand.java:199) + at com.taobao.arthas.core.command.monitor200.ThreadCommand.process(ThreadCommand.java:122) + at com.taobao.arthas.core.shell.command.impl.AnnotatedCommandImpl.process(AnnotatedCommandImpl.java:82) + at com.taobao.arthas.core.shell.command.impl.AnnotatedCommandImpl.access$100(AnnotatedCommandImpl.java:18) + at com.taobao.arthas.core.shell.command.impl.AnnotatedCommandImpl$ProcessHandler.handle(AnnotatedCommandImpl.java:111) + at com.taobao.arthas.core.shell.command.impl.AnnotatedCommandImpl$ProcessHandler.handle(AnnotatedCommandImpl.java:108) + at com.taobao.arthas.core.shell.system.impl.ProcessImpl$CommandProcessTask.run(ProcessImpl.java:385) + at java.base@11.0.7/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) + at java.base@11.0.7/java.util.concurrent.FutureTask.run(FutureTask.java:264) + at java.base@11.0.7/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) + at java.base@11.0.7/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) + at java.base@11.0.7/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) + at java.base@11.0.7/java.lang.Thread.run(Thread.java:834) + + +"VM Periodic Task Thread" [Internal] cpuUsage=0.07% deltaTime=0ms time=584ms ``` -### 当没有参数时，显示所有线程的信息。 +* 没有线程ID，包含`[Internal]`表示为JVM内部线程，参考`dashboard`命令的介绍。 +* `cpuUsage`为采样间隔时间内线程的CPU使用率，与`dashboard`命令的数据一致。 +* `deltaTime`为采样间隔时间内线程的增量CPU时间，小于1ms时被取整显示为0ms。 +* `time` 线程运行总CPU时间。 + +注意：线程栈为第二采样结束时获取，不能表明采样间隔时间内该线程都是在处理相同的任务。建议间隔时间不要太长，可能间隔时间越大越不准确。 +可以根据具体情况尝试指定不同的间隔时间，观察输出结果。 + +### 当没有参数时，显示第一页线程信息 + +默认按照CPU增量时间降序排列，只显示第一页数据，避免滚屏。 `thread`{{execute T2}} ```bash $ thread -Threads Total: 16, NEW: 0, RUNNABLE: 7, BLOCKED: 0, WAITING: 5, TIMED_WAITING: 4, TERMINATED: 0 -ID NAME GROUP PRIORITY STATE %CPU TIME INTERRUPTE DAEMON -30 as-command-execute-daemon system 9 RUNNABLE 72 0:0 false true -23 as-session-expire-daemon system 9 TIMED_WAIT 27 0:0 false true -22 Attach Listener system 9 RUNNABLE 0 0:0 false true -11 pool-2-thread-1 main 5 TIMED_WAIT 0 0:0 false false -12 Thread-2 main 5 RUNNABLE 0 0:0 false true -13 pool-3-thread-1 main 5 TIMED_WAIT 0 0:0 false false -25 as-selector-daemon system 9 RUNNABLE 0 0:0 false true -14 Thread-3 main 5 TIMED_WAIT 0 0:0 false false -26 pool-5-thread-1 system 5 WAITING 0 0:0 false false -15 Thread-4 main 5 RUNNABLE 0 0:0 false false -1 main main 5 WAITING 0 0:2 false false -2 Reference Handler system 10 WAITING 0 0:0 false true -3 Finalizer system 8 WAITING 0 0:0 false true -4 Signal Dispatcher system 9 RUNNABLE 0 0:0 false true -20 NonBlockingInputStreamThread main 5 WAITING 0 0:0 false true -21 Thread-8 main 5 RUNNABLE 0 0:0 false true +Threads Total: 33, NEW: 0, RUNNABLE: 9, BLOCKED: 0, WAITING: 3, TIMED_WAITING: 4, TERMINATED: 0, Internal threads: 17 +ID NAME GROUP PRIORITY STATE %CPU DELTA_TIME TIME INTERRUPT DAEMON +-1 C2 CompilerThread0 - -1 - 5.06 0.010 0:0.973 false true +-1 C1 CompilerThread0 - -1 - 0.95 0.001 0:0.603 false true +23 arthas-command-execute system 5 RUNNABLE 0.17 0.000 0:0.226 false true +-1 VM Periodic Task Thread - -1 - 0.05 0.000 0:0.094 false true +-1 Sweeper thread - -1 - 0.04 0.000 0:0.011 false true +-1 G1 Young RemSet Sampling - -1 - 0.02 0.000 0:0.025 false true +12 Attach Listener system 9 RUNNABLE 0.0 0.000 0:0.022 false true +11 Common-Cleaner InnocuousThrea 8 TIMED_WAI 0.0 0.000 0:0.000 false true +3 Finalizer system 8 WAITING 0.0 0.000 0:0.000 false true +2 Reference Handler system 10 RUNNABLE 0.0 0.000 0:0.000 false true +4 Signal Dispatcher system 9 RUNNABLE 0.0 0.000 0:0.000 false true +15 arthas-NettyHttpTelnetBootstra system 5 RUNNABLE 0.0 0.000 0:0.029 false true +22 arthas-NettyHttpTelnetBootstra system 5 RUNNABLE 0.0 0.000 0:0.196 false true +24 arthas-NettyHttpTelnetBootstra system 5 RUNNABLE 0.0 0.000 0:0.038 false true +16 arthas-NettyWebsocketTtyBootst system 5 RUNNABLE 0.0 0.000 0:0.001 false true +17 arthas-NettyWebsocketTtyBootst system 5 RUNNABLE 0.0 0.000 0:0.001 false true ``` +### thread --all, 显示所有匹配的线程 + +显示所有匹配线程信息，有时需要获取全部JVM的线程数据进行分析。 + +`thread --all`{{execute T2}} + ### thread id， 显示指定线程的运行堆栈 查看线程ID 16的栈： @@ -122,8 +137,13 @@ $ thread -b **注意**， 目前只支持找出synchronized关键字阻塞住的线程， 如果是`java.util.concurrent.Lock`， 目前还不支持。 ### thread -i, 指定采样时间间隔 +* `thread -i 1000` : 统计最近1000ms内的线程CPU时间。 + +`thread -i 1000`{{execute T2}} -`thread -n 3 -i 5000`{{execute T2}} +* `thread -n 3 -i 1000` : 列出1000ms内最忙的3个线程栈 + +`thread -n 3 -i 1000`{{execute T2}} ```bash $ thread -n 3 -i 1000 @@ -152,11 +172,9 @@ $ thread -n 3 -i 1000 ```bash [arthas@28114]$ thread --state WAITING -Threads Total: 15, NEW: 0, RUNNABLE: 7, BLOCKED: 0, WAITING: 5, TIMED_WAITING: 3, TERMINATED: 0 -ID NAME GROUP PRIORITY STATE %CPU TIME INTERRU DAEMON -198 AsyncAppender-Worker-arth system 9 WAITING 0 0:0 false true -3 Finalizer system 8 WAITING 0 0:0 false true -14 RMI Scheduler(0) system 9 WAITING 0 0:0 false true -2 Reference Handler system 10 WAITING 0 0:0 false true -204 pool-8-thread-1 system 5 WAITING 0 0:0 false false +Threads Total: 16, NEW: 0, RUNNABLE: 9, BLOCKED: 0, WAITING: 3, TIMED_WAITING: 4, TERMINATED: 0 +ID NAME GROUP PRIORITY STATE %CPU DELTA_TIME TIME INTERRUPTE DAEMON +3 Finalizer system 8 WAITING 0.0 0.000 0:0.000 false true +20 arthas-UserStat system 9 WAITING 0.0 0.000 0:0.001 false true +14 arthas-timer system 9 WAITING 0.0 0.000 0:0.000 false true ``` diff --git a/tutorials/katacoda/command-thread-cn/thread.md b/tutorials/katacoda/command-thread-cn/thread.md index 2d369ae04..c552d9416 100644 --- a/tutorials/katacoda/command-thread-cn/thread.md +++ b/tutorials/katacoda/command-thread-cn/thread.md @@ -9,3 +9,4 @@ | [n:] | 指定最忙的前N个线程并打印堆栈 | | [b] | 找出当前阻塞其他线程的线程 | | [i ] | 指定cpu占比统计的采样间隔，单位为毫秒 | +|[--all]|显示所有匹配的线程| diff --git a/tutorials/katacoda/command-thread-en/CPU-ratios-calculate.md b/tutorials/katacoda/command-thread-en/CPU-ratios-calculate.md index 3a408eaf3..4e1953297 100644 --- a/tutorials/katacoda/command-thread-en/CPU-ratios-calculate.md +++ b/tutorials/katacoda/command-thread-en/CPU-ratios-calculate.md @@ -1,6 +1,15 @@ +### How the CPU ratios are calculated? -CPU ratio for a given thread is the CPU time it takes divided by the total CPU time within a specified interval period. It is calculated in the following way: sample CPU times for all the thread by calling `java.lang.management.ThreadMXBean#getThreadCpuTime` first, then sleep for a period (the default value is 100ms, which can be specified by `-i`), then sample CPU times again. By this, we can get the time cost for this period for each thread, then come up with the ratio. +The cpu ratios here is similar to the thread `%CPU` of the linux command `top -H -p `. During a sampling interval, +the ratio of the incremental cpu time of each thread in the current JVM to the sampling interval time. -**Note**: this operation consumes CPU time too (getThreadCpuTime is time-consuming), therefore it is possible to observe Arthas’s thread appears in the list. To avoid this, try to increase sample interval, for example: 5000 ms. +> Working principle description: +* Do the first sampling, get the CPU time of all threads ( by calling `java.lang.management.ThreadMXBean#getThreadCpuTime()` and +`sun.management.HotspotThreadMBean.getInternalThreadCpuTimes()` ) +* Sleep and wait for an interval (the default is 200ms, the interval can be specified by `-i`) +* Do the second sampling, get the CPU time of all threads, compare the two sampling data, and calculate the incremental CPU time of each thread +* `Thread CPU usage ratio` = `Thread increment CPU time` / `Sampling interval time` * 100% -If you’d like to check the CPU ratios from the very beginning of the Java process, [`show-busy-java-threads`](https://github.com/oldratlee/useful-scripts/blob/master/docs/java.md#-show-busy-java-threads) can come to help. +**Note:** this operation consumes CPU time too (`getThreadCpuTime` is time-consuming), therefore it is possible to observe Arthas's thread appears in the list. To avoid this, try to increase sample interval, for example: 5000 ms.
+ +> Another way to view the thread cpu usage of the Java process, [show-busy-java-threads](https://github.com/oldratlee/useful-scripts/blob/master/docs/java.md#-show-busy-java-threads) can come to help. diff --git a/tutorials/katacoda/command-thread-en/thread-usage.md b/tutorials/katacoda/command-thread-en/thread-usage.md index bb12c6797..4c938ebad 100644 --- a/tutorials/katacoda/command-thread-en/thread-usage.md +++ b/tutorials/katacoda/command-thread-en/thread-usage.md @@ -5,55 +5,68 @@ ```bash $ thread -n 3 -"as-command-execute-daemon" Id=29 cpuUsage=75% RUNNABLE - at sun.management.ThreadImpl.dumpThreads0(Native Method) - at sun.management.ThreadImpl.getThreadInfo(ThreadImpl.java:440) - at com.taobao.arthas.core.command.monitor200.ThreadCommand$1.action(ThreadCommand.java:58) - at com.taobao.arthas.core.command.handler.AbstractCommandHandler.execute(AbstractCommandHandler.java:238) - at com.taobao.arthas.core.command.handler.DefaultCommandHandler.handleCommand(DefaultCommandHandler.java:67) - at com.taobao.arthas.core.server.ArthasServer$4.run(ArthasServer.java:276) - at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) - at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) - at java.lang.Thread.run(Thread.java:745) - - Number of locked synchronizers = 1 - - java.util.concurrent.ThreadPoolExecutor$Worker@6cd0b6f8 - -"as-session-expire-daemon" Id=25 cpuUsage=24% TIMED_WAITING - at java.lang.Thread.sleep(Native Method) - at com.taobao.arthas.core.server.DefaultSessionManager$2.run(DefaultSessionManager.java:85) - -"Reference Handler" Id=2 cpuUsage=0% WAITING on java.lang.ref.Reference$Lock@69ba0f27 - at java.lang.Object.wait(Native Method) - - waiting on java.lang.ref.Reference$Lock@69ba0f27 - at java.lang.Object.wait(Object.java:503) - at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:133) +"C1 CompilerThread0" [Internal] cpuUsage=1.63% deltaTime=3ms time=1170ms + + +"arthas-command-execute" Id=23 cpuUsage=0.11% deltaTime=0ms time=401ms RUNNABLE + at java.management@11.0.7/sun.management.ThreadImpl.dumpThreads0(Native Method) + at java.management@11.0.7/sun.management.ThreadImpl.getThreadInfo(ThreadImpl.java:466) + at com.taobao.arthas.core.command.monitor200.ThreadCommand.processTopBusyThreads(ThreadCommand.java:199) + at com.taobao.arthas.core.command.monitor200.ThreadCommand.process(ThreadCommand.java:122) + at com.taobao.arthas.core.shell.command.impl.AnnotatedCommandImpl.process(AnnotatedCommandImpl.java:82) + at com.taobao.arthas.core.shell.command.impl.AnnotatedCommandImpl.access$100(AnnotatedCommandImpl.java:18) + at com.taobao.arthas.core.shell.command.impl.AnnotatedCommandImpl$ProcessHandler.handle(AnnotatedCommandImpl.java:111) + at com.taobao.arthas.core.shell.command.impl.AnnotatedCommandImpl$ProcessHandler.handle(AnnotatedCommandImpl.java:108) + at com.taobao.arthas.core.shell.system.impl.ProcessImpl$CommandProcessTask.run(ProcessImpl.java:385) + at java.base@11.0.7/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) + at java.base@11.0.7/java.util.concurrent.FutureTask.run(FutureTask.java:264) + at java.base@11.0.7/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) + at java.base@11.0.7/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) + at java.base@11.0.7/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) + at java.base@11.0.7/java.lang.Thread.run(Thread.java:834) + + +"VM Periodic Task Thread" [Internal] cpuUsage=0.07% deltaTime=0ms time=584ms ``` -### List all threads’ info when no options provided +* Without thread ID, including `[Internal]` means JVM internal thread, refer to the introduction of `dashboard` command. +* `cpuUsage` is the CPU usage of the thread during the sampling interval, consistent with the data of the `dashboard` command. +* `deltaTime` is the incremental CPU time of the thread during the sampling interval. If it is less than 1ms, it will be rounded and displayed as 0ms. +* `time` The total CPU time of thread. + +**Note:** The thread stack is acquired at the end of the second sampling, which does not indicate that the thread is +processing the same task during the sampling interval. It is recommended that the interval time should not be too long. +The larger the interval time, the more inaccurate. + +You can try to specify different intervals according to the specific situation and observe the output results. + + +#### List first page threads' info when no options provided + +By default, they are arranged in descending order of CPU increment time, and only the first page of data is displayed. `thread`{{execute T2}} ```bash $ thread -Threads Total: 16, NEW: 0, RUNNABLE: 7, BLOCKED: 0, WAITING: 5, TIMED_WAITING: 4, TERMINATED: 0 -ID NAME GROUP PRIORITY STATE %CPU TIME INTERRUPTE DAEMON -30 as-command-execute-daemon system 9 RUNNABLE 72 0:0 false true -23 as-session-expire-daemon system 9 TIMED_WAIT 27 0:0 false true -22 Attach Listener system 9 RUNNABLE 0 0:0 false true -11 pool-2-thread-1 main 5 TIMED_WAIT 0 0:0 false false -12 Thread-2 main 5 RUNNABLE 0 0:0 false true -13 pool-3-thread-1 main 5 TIMED_WAIT 0 0:0 false false -25 as-selector-daemon system 9 RUNNABLE 0 0:0 false true -14 Thread-3 main 5 TIMED_WAIT 0 0:0 false false -26 pool-5-thread-1 system 5 WAITING 0 0:0 false false -15 Thread-4 main 5 RUNNABLE 0 0:0 false false -1 main main 5 WAITING 0 0:2 false false -2 Reference Handler system 10 WAITING 0 0:0 false true -3 Finalizer system 8 WAITING 0 0:0 false true -4 Signal Dispatcher system 9 RUNNABLE 0 0:0 false true -20 NonBlockingInputStreamThread main 5 WAITING 0 0:0 false true -21 Thread-8 main 5 RUNNABLE 0 0:0 false true +Threads Total: 33, NEW: 0, RUNNABLE: 9, BLOCKED: 0, WAITING: 3, TIMED_WAITING: 4, TERMINATED: 0, Internal threads: 17 +ID NAME GROUP PRIORITY STATE %CPU DELTA_TIME TIME INTERRUPT DAEMON +-1 C2 CompilerThread0 - -1 - 5.06 0.010 0:0.973 false true +-1 C1 CompilerThread0 - -1 - 0.95 0.001 0:0.603 false true +23 arthas-command-execute system 5 RUNNABLE 0.17 0.000 0:0.226 false true +-1 VM Periodic Task Thread - -1 - 0.05 0.000 0:0.094 false true +-1 Sweeper thread - -1 - 0.04 0.000 0:0.011 false true +-1 G1 Young RemSet Sampling - -1 - 0.02 0.000 0:0.025 false true +12 Attach Listener system 9 RUNNABLE 0.0 0.000 0:0.022 false true +11 Common-Cleaner InnocuousThrea 8 TIMED_WAI 0.0 0.000 0:0.000 false true +3 Finalizer system 8 WAITING 0.0 0.000 0:0.000 false true +2 Reference Handler system 10 RUNNABLE 0.0 0.000 0:0.000 false true +4 Signal Dispatcher system 9 RUNNABLE 0.0 0.000 0:0.000 false true +15 arthas-NettyHttpTelnetBootstra system 5 RUNNABLE 0.0 0.000 0:0.029 false true +22 arthas-NettyHttpTelnetBootstra system 5 RUNNABLE 0.0 0.000 0:0.196 false true +24 arthas-NettyHttpTelnetBootstra system 5 RUNNABLE 0.0 0.000 0:0.038 false true +16 arthas-NettyWebsocketTtyBootst system 5 RUNNABLE 0.0 0.000 0:0.001 false true +17 arthas-NettyWebsocketTtyBootst system 5 RUNNABLE 0.0 0.000 0:0.001 false true ``` ### thread id, show the running stack for the target thread @@ -123,7 +136,13 @@ $ thread -b ### thread -i, specify the sampling interval -`thread -n 3 -i 5000`{{execute T2}} +* `thread -i 1000`: Count the thread cpu time of the last 1000ms. + +`thread -i 1000`{{execute T2}} + +* `thread -n 3 -i 1000`: List the 3 busiest thread stacks in 1000ms. + +`thread -n 3 -i 1000`{{execute T2}} ```bash $ thread -n 3 -i 1000 @@ -152,11 +171,9 @@ $ thread -n 3 -i 1000 ```bash [arthas@28114]$ thread --state WAITING -Threads Total: 15, NEW: 0, RUNNABLE: 7, BLOCKED: 0, WAITING: 5, TIMED_WAITING: 3, TERMINATED: 0 -ID NAME GROUP PRIORITY STATE %CPU TIME INTERRU DAEMON -198 AsyncAppender-Worker-arth system 9 WAITING 0 0:0 false true -3 Finalizer system 8 WAITING 0 0:0 false true -14 RMI Scheduler(0) system 9 WAITING 0 0:0 false true -2 Reference Handler system 10 WAITING 0 0:0 false true -204 pool-8-thread-1 system 5 WAITING 0 0:0 false false -``` +Threads Total: 16, NEW: 0, RUNNABLE: 9, BLOCKED: 0, WAITING: 3, TIMED_WAITING: 4, TERMINATED: 0 +ID NAME GROUP PRIORITY STATE %CPU DELTA_TIME TIME INTERRUPTE DAEMON +3 Finalizer system 8 WAITING 0.0 0.000 0:0.000 false true +20 arthas-UserStat system 9 WAITING 0.0 0.000 0:0.001 false true +14 arthas-timer system 9 WAITING 0.0 0.000 0:0.000 false true +``` \ No newline at end of file diff --git a/tutorials/katacoda/command-thread-en/thread.md b/tutorials/katacoda/command-thread-en/thread.md index 4c09defda..84ddf5228 100644 --- a/tutorials/katacoda/command-thread-en/thread.md +++ b/tutorials/katacoda/command-thread-en/thread.md @@ -12,3 +12,4 @@ Check the basic info and stack trace of the target thread. | [n:] | the top n busiest threads with stack traces printed | | [b] | locate the thread blocking the others | | [i ] | specify the interval to collect data to compute CPU ratios (ms) | +|[--all]|Show all matching threads|