github/arthas
4
0 Fork 0
mirror of https://github.com/alibaba/arthas.git synced 2026-11-12 22:41:26 +00:00
Code Issues Packages Projects Releases Wiki Activity

update doc

Browse Source
This commit is contained in:
hengyunabc committed 2020-09-23 00:41:01 +08:00
1 parent c1dcc8ff9e
commit f599c74408
133 files changed
+793 -617
Download Patch File Download Diff File Expand all files Collapse all files

No files matched your search

en/_sources/dashboard.md.txt
+53 -35
View File
@@ -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")
en/_sources/thread.md.txt
+80 -53
View File
@@ -13,11 +13,23 @@ thread
|`[n:]`|the top n busiest threads with stack traces printed|
|`[b]`|locate the thread blocking the others|
|[i `<value>`]|specify the interval to collect data to compute CPU ratios (ms)|
|[--all]|Show all matching threads|
> How the CPU ratios are calculated? <br/><br/>
> 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. <br/><br/>
> 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.<br/><br/>
> 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 <pid>`. 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.<br/>
> 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
```