e038606385f37578383036f40c797ed5bcb54708
Arthas-guide.md
... | ... | @@ -1,714 +0,0 @@ |
1 | -Arthas - Java 线上问题定位处理的终极利器 |
|
2 | -最后更新日期:2019-11-06 | 显示目录 | 字体 ➕ ➖ |
|
3 | - |
|
4 | -Arthas logo |
|
5 | - |
|
6 | -前言 |
|
7 | -在使用 Arthas 之前,当遇到 Java 线上问题时,如 CPU 飙升、负载突高、内存溢出等问题,你需要查命令,查网络,然后 jps、jstack、jmap、jhat、jstat、hprof 等一通操作。最终焦头烂额,还不一定能查出问题所在。而现在,大多数的常见问题你都可以使用 Arthas 轻松定位,迅速解决,及时止损,准时下班。 |
|
8 | - |
|
9 | - |
|
10 | - |
|
11 | -1、Arthas 介绍 |
|
12 | -Arthas 是 Alibaba 在 2018 年 9 月开源的 Java 诊断工具。支持 JDK6+, 采用命令行交互模式,提供 Tab 自动补全,可以方便的定位和诊断线上程序运行问题。截至本篇文章编写时,已经收获 Star 17000+。 |
|
13 | - |
|
14 | -Arthas 官方文档十分详细,本文也参考了官方文档内容,同时在开源在的 Github 的项目里的 Issues 里不仅有问题反馈,更有大量的使用案例,也可以进行学习参考。 |
|
15 | - |
|
16 | -开源地址:https://github.com/alibaba/arthas |
|
17 | - |
|
18 | -官方文档:https://alibaba.github.io/arthas |
|
19 | - |
|
20 | -2、Arthas 使用场景 |
|
21 | -得益于 Arthas 强大且丰富的功能,让 Arthas 能做的事情超乎想象。下面仅仅列举几项常见的使用情况,更多的使用场景可以在熟悉了 Arthas 之后自行探索。 |
|
22 | - |
|
23 | -是否有一个全局视角来查看系统的运行状况? |
|
24 | -为什么 CPU 又升高了,到底是哪里占用了 CPU ? |
|
25 | -运行的多线程有死锁吗?有阻塞吗? |
|
26 | -程序运行耗时很长,是哪里耗时比较长呢?如何监测呢? |
|
27 | -这个类从哪个 jar 包加载的?为什么会报各种类相关的 Exception? |
|
28 | -我改的代码为什么没有执行到?难道是我没 commit?分支搞错了? |
|
29 | -遇到问题无法在线上 debug,难道只能通过加日志再重新发布吗? |
|
30 | -有什么办法可以监控到 JVM 的实时运行状态? |
|
31 | -3、Arthas 怎么用 |
|
32 | -前文已经提到,Arthas 是一款命令行交互模式的 Java 诊断工具,由于是 Java 编写,所以可以直接下载相应 的 jar 包运行。 |
|
33 | - |
|
34 | -3.1 安装 |
|
35 | -可以在官方 Github 上进行下载,如果速度较慢,可以尝试国内的码云 Gitee 下载。 |
|
36 | - |
|
37 | -# github下载 |
|
38 | -wget https://alibaba.github.io/arthas/arthas-boot.jar |
|
39 | -# 或者 Gitee 下载 |
|
40 | -wget https://arthas.gitee.io/arthas-boot.jar |
|
41 | -# 打印帮助信息 |
|
42 | -java -jar arthas-boot.jar -h |
|
43 | -3.2 运行 |
|
44 | -Arthas 只是一个 java 程序,所以可以直接用 java -jar 运行。运行时或者运行之后要选择要监测的 Java 进程。 |
|
45 | - |
|
46 | -# 运行方式1,先运行,在选择 Java 进程 PID |
|
47 | -java -jar arthas-boot.jar |
|
48 | -# 选择进程(输入[]内编号(不是PID)回车) |
|
49 | -[INFO] arthas-boot version: 3.1.4 |
|
50 | -[INFO] Found existing java process, please choose one and hit RETURN. |
|
51 | -* [1]: 11616 com.Arthas |
|
52 | - [2]: 8676 |
|
53 | - [3]: 16200 org.jetbrains.jps.cmdline.Launcher |
|
54 | - [4]: 21032 org.jetbrains.idea.maven.server.RemoteMavenServer |
|
55 | - |
|
56 | -# 运行方式2,运行时选择 Java 进程 PID |
|
57 | -java -jar arthas-boot.jar [PID] |
|
58 | -查看 PID 的方式可以通过 ps 命令,也可以通过 JDK 提供的 jps 命令。 |
|
59 | - |
|
60 | -# 查看运行的 java 进程信息 |
|
61 | -$ jps -mlvV |
|
62 | -# 筛选 java 进程信息 |
|
63 | -$ jps -mlvV | grep [xxx] |
|
64 | -jps 筛选想要的进程方式。 |
|
65 | - |
|
66 | -jps 筛选进程 |
|
67 | - |
|
68 | -在出现 Arthas Logo 之后就可以使用命令进行问题诊断了。下面会详细介绍。 |
|
69 | - |
|
70 | -Arthas 启动 |
|
71 | - |
|
72 | -更多的启动方式可以参考 help 帮助命令。 |
|
73 | - |
|
74 | -# 其他用法 |
|
75 | -EXAMPLES: |
|
76 | - java -jar arthas-boot.jar <pid> |
|
77 | - java -jar arthas-boot.jar --target-ip 0.0.0.0 |
|
78 | - java -jar arthas-boot.jar --telnet-port 9999 --http-port -1 |
|
79 | - java -jar arthas-boot.jar --tunnel-server 'ws://192.168.10.11:7777/ws' |
|
80 | - java -jar arthas-boot.jar --tunnel-server 'ws://192.168.10.11:7777/ws' |
|
81 | ---agent-id bvDOe8XbTM2pQWjF4cfw |
|
82 | - java -jar arthas-boot.jar --stat-url 'http://192.168.10.11:8080/api/stat' |
|
83 | - java -jar arthas-boot.jar -c 'sysprop; thread' <pid> |
|
84 | - java -jar arthas-boot.jar -f batch.as <pid> |
|
85 | - java -jar arthas-boot.jar --use-version 3.1.4 |
|
86 | - java -jar arthas-boot.jar --versions |
|
87 | - java -jar arthas-boot.jar --session-timeout 3600 |
|
88 | - java -jar arthas-boot.jar --attach-only |
|
89 | - java -jar arthas-boot.jar --repo-mirror aliyun --use-http |
|
90 | -3.3 web console |
|
91 | -Arthas 目前支持 Web Console,在成功启动连接进程之后就已经自动启动,可以直接访问 http://127.0.0.1:8563/ 访问,页面上的操作模式和控制台完全一样。 |
|
92 | - |
|
93 | -1570979937637 |
|
94 | - |
|
95 | -3.4 常用命令 |
|
96 | -下面列举一些 Arthas 的常用命令,看到这里你可能还不知道怎么使用,别急,后面会一一介绍。 |
|
97 | - |
|
98 | -命令 介绍 |
|
99 | -dashboard 当前系统的实时数据面板 |
|
100 | -thread 查看当前 JVM 的线程堆栈信息 |
|
101 | -watch 方法执行数据观测 |
|
102 | -trace 方法内部调用路径,并输出方法路径上的每个节点上耗时 |
|
103 | -stack 输出当前方法被调用的调用路径 |
|
104 | -tt 方法执行数据的时空隧道,记录下指定方法每次调用的入参和返回信息,并能对这些不同的时间下调用进行观测 |
|
105 | -monitor 方法执行监控 |
|
106 | -jvm 查看当前 JVM 信息 |
|
107 | -vmoption 查看,更新 JVM 诊断相关的参数 |
|
108 | -sc 查看 JVM 已加载的类信息 |
|
109 | -sm 查看已加载类的方法信息 |
|
110 | -jad 反编译指定已加载类的源码 |
|
111 | -classloader 查看 classloader 的继承树,urls,类加载信息 |
|
112 | -heapdump 类似 jmap 命令的 heap dump 功能 |
|
113 | -3.5 退出 |
|
114 | -使用 shutdown 退出时 Arthas 同时自动重置所有增强过的类 。 |
|
115 | - |
|
116 | -4、Arthas 常用操作 |
|
117 | -上面已经了解了什么是 Arthas,以及 Arthas 的启动方式,下面会依据一些情况,详细说一说 Arthas 的使用方式。在使用命令的过程中如果有问题,每个命令都可以是 -h 查看帮助信息。 |
|
118 | - |
|
119 | -首先编写一个有各种情况的测试类运行起来,再使用 Arthas 进行问题定位, |
|
120 | - |
|
121 | -import java.util.HashSet; |
|
122 | -import java.util.concurrent.ExecutorService; |
|
123 | -import java.util.concurrent.Executors; |
|
124 | -import lombok.extern.slf4j.Slf4j; |
|
125 | - |
|
126 | -/** |
|
127 | - * <p> |
|
128 | - * Arthas Demo |
|
129 | - * 公众号:程序猿阿朗 |
|
130 | - * |
|
131 | - * @Author niujinpeng |
|
132 | - */ |
|
133 | -@Slf4j |
|
134 | -public class Arthas { |
|
135 | - |
|
136 | - private static HashSet hashSet = new HashSet(); |
|
137 | - /** 线程池,大小1*/ |
|
138 | - private static ExecutorService executorService = Executors.newFixedThreadPool(1); |
|
139 | - |
|
140 | - public static void main(String[] args) { |
|
141 | - // 模拟 CPU 过高,这里注释掉了,测试时可以打开 |
|
142 | - // cpu(); |
|
143 | - // 模拟线程阻塞 |
|
144 | - thread(); |
|
145 | - // 模拟线程死锁 |
|
146 | - deadThread(); |
|
147 | - // 不断的向 hashSet 集合增加数据 |
|
148 | - addHashSetThread(); |
|
149 | - } |
|
150 | - |
|
151 | - /** |
|
152 | - * 不断的向 hashSet 集合添加数据 |
|
153 | - */ |
|
154 | - public static void addHashSetThread() { |
|
155 | - // 初始化常量 |
|
156 | - new Thread(() -> { |
|
157 | - int count = 0; |
|
158 | - while (true) { |
|
159 | - try { |
|
160 | - hashSet.add("count" + count); |
|
161 | - Thread.sleep(10000); |
|
162 | - count++; |
|
163 | - } catch (InterruptedException e) { |
|
164 | - e.printStackTrace(); |
|
165 | - } |
|
166 | - } |
|
167 | - }).start(); |
|
168 | - } |
|
169 | - |
|
170 | - public static void cpu() { |
|
171 | - cpuHigh(); |
|
172 | - cpuNormal(); |
|
173 | - } |
|
174 | - |
|
175 | - /** |
|
176 | - * 极度消耗CPU的线程 |
|
177 | - */ |
|
178 | - private static void cpuHigh() { |
|
179 | - Thread thread = new Thread(() -> { |
|
180 | - while (true) { |
|
181 | - log.info("cpu start 100"); |
|
182 | - } |
|
183 | - }); |
|
184 | - // 添加到线程 |
|
185 | - executorService.submit(thread); |
|
186 | - } |
|
187 | - |
|
188 | - /** |
|
189 | - * 普通消耗CPU的线程 |
|
190 | - */ |
|
191 | - private static void cpuNormal() { |
|
192 | - for (int i = 0; i < 10; i++) { |
|
193 | - new Thread(() -> { |
|
194 | - while (true) { |
|
195 | - log.info("cpu start"); |
|
196 | - try { |
|
197 | - Thread.sleep(3000); |
|
198 | - } catch (InterruptedException e) { |
|
199 | - e.printStackTrace(); |
|
200 | - } |
|
201 | - } |
|
202 | - }).start(); |
|
203 | - } |
|
204 | - } |
|
205 | - |
|
206 | - /** |
|
207 | - * 模拟线程阻塞,向已经满了的线程池提交线程 |
|
208 | - */ |
|
209 | - private static void thread() { |
|
210 | - Thread thread = new Thread(() -> { |
|
211 | - while (true) { |
|
212 | - log.debug("thread start"); |
|
213 | - try { |
|
214 | - Thread.sleep(3000); |
|
215 | - } catch (InterruptedException e) { |
|
216 | - e.printStackTrace(); |
|
217 | - } |
|
218 | - } |
|
219 | - }); |
|
220 | - // 添加到线程 |
|
221 | - executorService.submit(thread); |
|
222 | - } |
|
223 | - |
|
224 | - /** |
|
225 | - * 死锁 |
|
226 | - */ |
|
227 | - private static void deadThread() { |
|
228 | - /** 创建资源 */ |
|
229 | - Object resourceA = new Object(); |
|
230 | - Object resourceB = new Object(); |
|
231 | - // 创建线程 |
|
232 | - Thread threadA = new Thread(() -> { |
|
233 | - synchronized (resourceA) { |
|
234 | - log.info(Thread.currentThread() + " get ResourceA"); |
|
235 | - try { |
|
236 | - Thread.sleep(1000); |
|
237 | - } catch (InterruptedException e) { |
|
238 | - e.printStackTrace(); |
|
239 | - } |
|
240 | - log.info(Thread.currentThread() + "waiting get resourceB"); |
|
241 | - synchronized (resourceB) { |
|
242 | - log.info(Thread.currentThread() + " get resourceB"); |
|
243 | - } |
|
244 | - } |
|
245 | - }); |
|
246 | - |
|
247 | - Thread threadB = new Thread(() -> { |
|
248 | - synchronized (resourceB) { |
|
249 | - log.info(Thread.currentThread() + " get ResourceB"); |
|
250 | - try { |
|
251 | - Thread.sleep(1000); |
|
252 | - } catch (InterruptedException e) { |
|
253 | - e.printStackTrace(); |
|
254 | - } |
|
255 | - log.info(Thread.currentThread() + "waiting get resourceA"); |
|
256 | - synchronized (resourceA) { |
|
257 | - log.info(Thread.currentThread() + " get resourceA"); |
|
258 | - } |
|
259 | - } |
|
260 | - }); |
|
261 | - threadA.start(); |
|
262 | - threadB.start(); |
|
263 | - } |
|
264 | -} |
|
265 | -4.1 全局监控 |
|
266 | -使用 dashboard 命令可以概览程序的 线程、内存、GC、运行环境信息。 |
|
267 | - |
|
268 | -dashboard |
|
269 | - |
|
270 | -4.2 CPU 为什么起飞了 |
|
271 | -上面的代码例子有一个 CPU 空转的死循环,非常的消耗 CPU性能,那么怎么找出来呢? |
|
272 | - |
|
273 | -使用 thread 查看所有线程信息,同时会列出每个线程的 CPU 使用率,可以看到图里 ID 为 12 的线程 CPU 使用 100%。 |
|
274 | - |
|
275 | -使用命令 thread 12 查看 CPU 消耗较高的 12 号线程信息,可以看到 CPU 使用较高的方法和行数(这里的行数可能和上面代码里的行数有区别,因为上面的代码在我写文章时候重新排过版了)。 |
|
276 | - |
|
277 | - |
|
278 | - |
|
279 | -上面是先通过观察总体的线程信息,然后查看具体的线程运行情况。如果只是为了寻找 CPU 使用较高的线程,可以直接使用命令 thread -n [显示的线程个数] ,就可以排列出 CPU 使用率 Top N 的线程。 |
|
280 | - |
|
281 | - |
|
282 | - |
|
283 | -定位到的 CPU 使用最高的方法。 |
|
284 | - |
|
285 | - |
|
286 | - |
|
287 | -4.3 线程池线程状态 |
|
288 | -定位线程问题之前,先回顾一下线程的几种常见状态: |
|
289 | - |
|
290 | -RUNNABLE 运行中 |
|
291 | -TIMED_WAITIN 调用了以下方法的线程会进入 TIMED_WAITING: |
|
292 | -Thread#sleep() |
|
293 | -Object#wait () 并加了超时参数 |
|
294 | -Thread#join () 并加了超时参数 |
|
295 | -LockSupport#parkNanos() |
|
296 | -LockSupport#parkUntil() |
|
297 | -WAITING 当线程调用以下方法时会进入 WAITING 状态: |
|
298 | -Object#wait () 而且不加超时参数 |
|
299 | -Thread#join () 而且不加超时参数 |
|
300 | -LockSupport#park() |
|
301 | -BLOCKED 阻塞,等待锁 |
|
302 | -上面的模拟代码里,定义了线程池大小为 1 的线程池,然后在 cpuHigh 方法里提交了一个线程,在 thread 方法再次提交了一个线程,后面的这个线程因为线程池已满,会阻塞下来。 |
|
303 | - |
|
304 | -使用 thread | grep pool 命令查看线程池里线程信息。 |
|
305 | - |
|
306 | - |
|
307 | - |
|
308 | -可以看到线程池有 WAITING 的线程。 |
|
309 | - |
|
310 | - |
|
311 | - |
|
312 | -4.4 线程死锁 |
|
313 | -上面的模拟代码里 deadThread 方法实现了一个死锁,使用 thread -b 命令查看直接定位到死锁信息。 |
|
314 | - |
|
315 | -/** |
|
316 | - * 死锁 |
|
317 | - */ |
|
318 | -private static void deadThread() { |
|
319 | - /** 创建资源 */ |
|
320 | - Object resourceA = new Object(); |
|
321 | - Object resourceB = new Object(); |
|
322 | - // 创建线程 |
|
323 | - Thread threadA = new Thread(() -> { |
|
324 | - synchronized (resourceA) { |
|
325 | - log.info(Thread.currentThread() + " get ResourceA"); |
|
326 | - try { |
|
327 | - Thread.sleep(1000); |
|
328 | - } catch (InterruptedException e) { |
|
329 | - e.printStackTrace(); |
|
330 | - } |
|
331 | - log.info(Thread.currentThread() + "waiting get resourceB"); |
|
332 | - synchronized (resourceB) { |
|
333 | - log.info(Thread.currentThread() + " get resourceB"); |
|
334 | - } |
|
335 | - } |
|
336 | - }); |
|
337 | - |
|
338 | - Thread threadB = new Thread(() -> { |
|
339 | - synchronized (resourceB) { |
|
340 | - log.info(Thread.currentThread() + " get ResourceB"); |
|
341 | - try { |
|
342 | - Thread.sleep(1000); |
|
343 | - } catch (InterruptedException e) { |
|
344 | - e.printStackTrace(); |
|
345 | - } |
|
346 | - log.info(Thread.currentThread() + "waiting get resourceA"); |
|
347 | - synchronized (resourceA) { |
|
348 | - log.info(Thread.currentThread() + " get resourceA"); |
|
349 | - } |
|
350 | - } |
|
351 | - }); |
|
352 | - threadA.start(); |
|
353 | - threadB.start(); |
|
354 | -} |
|
355 | -检查到的死锁信息。 |
|
356 | - |
|
357 | - |
|
358 | - |
|
359 | -4.5 反编译 |
|
360 | -上面的代码放到了包 com 下,假设这是一个线程环境,当怀疑当前运行的代码不是自己想要的代码时,可以直接反编译出代码,也可以选择性的查看类的字段或方法信息。 |
|
361 | - |
|
362 | -如果怀疑不是自己的代码,可以使用 jad 命令直接反编译 class。 |
|
363 | - |
|
364 | -jad |
|
365 | - |
|
366 | -jad 命令还提供了一些其他参数: |
|
367 | - |
|
368 | -# 反编译只显示源码 |
|
369 | -jad --source-only com.Arthas |
|
370 | -# 反编译某个类的某个方法 |
|
371 | -jad --source-only com.Arthas mysql |
|
372 | -4.6 查看字段信息 |
|
373 | -使用 **sc -d -f ** 命令查看类的字段信息。 |
|
374 | - |
|
375 | -[arthas@20252]$ sc -d -f com.Arthas |
|
376 | -sc -d -f com.Arthas |
|
377 | - class-info com.Arthas |
|
378 | - code-source /C:/Users/Niu/Desktop/arthas/target/classes/ |
|
379 | - name com.Arthas |
|
380 | - isInterface false |
|
381 | - isAnnotation false |
|
382 | - isEnum false |
|
383 | - isAnonymousClass false |
|
384 | - isArray false |
|
385 | - isLocalClass false |
|
386 | - isMemberClass false |
|
387 | - isPrimitive false |
|
388 | - isSynthetic false |
|
389 | - simple-name Arthas |
|
390 | - modifier public |
|
391 | - annotation |
|
392 | - interfaces |
|
393 | - super-class +-java.lang.Object |
|
394 | - class-loader +-sun.misc.Launcher$AppClassLoader@18b4aac2 |
|
395 | - +-sun.misc.Launcher$ExtClassLoader@2ef1e4fa |
|
396 | - classLoaderHash 18b4aac2 |
|
397 | - fields modifierfinal,private,static |
|
398 | - type org.slf4j.Logger |
|
399 | - name log |
|
400 | - value Logger[com.Arthas] |
|
401 | - |
|
402 | - modifierprivate,static |
|
403 | - type java.util.HashSet |
|
404 | - name hashSet |
|
405 | - value [count1, count2] |
|
406 | - |
|
407 | - modifierprivate,static |
|
408 | - type java.util.concurrent.ExecutorService |
|
409 | - name executorService |
|
410 | - value java.util.concurrent.ThreadPoolExecutor@71c03156[Ru |
|
411 | - nning, pool size = 1, active threads = 1, queued ta |
|
412 | - sks = 0, completed tasks = 0] |
|
413 | - |
|
414 | - |
|
415 | -Affect(row-cnt:1) cost in 9 ms. |
|
416 | -4.7 查看方法信息 |
|
417 | -使用 sm 命令查看类的方法信息。 |
|
418 | - |
|
419 | -[arthas@22180]$ sm com.Arthas |
|
420 | -com.Arthas <init>()V |
|
421 | -com.Arthas start()V |
|
422 | -com.Arthas thread()V |
|
423 | -com.Arthas deadThread()V |
|
424 | -com.Arthas lambda$cpuHigh$1()V |
|
425 | -com.Arthas cpuHigh()V |
|
426 | -com.Arthas lambda$thread$3()V |
|
427 | -com.Arthas addHashSetThread()V |
|
428 | -com.Arthas cpuNormal()V |
|
429 | -com.Arthas cpu()V |
|
430 | -com.Arthas lambda$addHashSetThread$0()V |
|
431 | -com.Arthas lambda$deadThread$4(Ljava/lang/Object;Ljava/lang/Object;)V |
|
432 | -com.Arthas lambda$deadThread$5(Ljava/lang/Object;Ljava/lang/Object;)V |
|
433 | -com.Arthas lambda$cpuNormal$2()V |
|
434 | -Affect(row-cnt:16) cost in 6 ms. |
|
435 | -4.8 对变量的值很是好奇 |
|
436 | -使用 ognl 命令,ognl 表达式可以轻松操作想要的信息。 |
|
437 | - |
|
438 | -代码还是上面的示例代码,我们查看变量 hashSet 中的数据: |
|
439 | - |
|
440 | - |
|
441 | - |
|
442 | -查看静态变量 hashSet 信息。 |
|
443 | - |
|
444 | -[arthas@19856]$ ognl '@com.Arthas@hashSet' |
|
445 | -@HashSet[ |
|
446 | - @String[count1], |
|
447 | - @String[count2], |
|
448 | - @String[count29], |
|
449 | - @String[count28], |
|
450 | - @String[count0], |
|
451 | - @String[count27], |
|
452 | - @String[count5], |
|
453 | - @String[count26], |
|
454 | - @String[count6], |
|
455 | - @String[count25], |
|
456 | - @String[count3], |
|
457 | - @String[count24], |
|
458 | -查看静态变量 hashSet 大小。 |
|
459 | - |
|
460 | -[arthas@19856]$ ognl '@com.Arthas@hashSet.size()' |
|
461 | - @Integer[57] |
|
462 | -甚至可以进行操作。 |
|
463 | - |
|
464 | -[arthas@19856]$ ognl '@com.Arthas@hashSet.add("test")' |
|
465 | - @Boolean[true] |
|
466 | -[arthas@19856]$ |
|
467 | -# 查看添加的字符 |
|
468 | -[arthas@19856]$ ognl '@com.Arthas@hashSet' | grep test |
|
469 | - @String[test], |
|
470 | -[arthas@19856]$ |
|
471 | -ognl 可以做很多事情,可以参考 ognl 表达式特殊用法 (https://github.com/alibaba/arthas/issues/71)。 |
|
472 | - |
|
473 | -4.9 程序有没有问题 |
|
474 | -4.9.1 运行较慢、耗时较长 |
|
475 | -使用 trace 命令可以跟踪统计方法耗时 |
|
476 | - |
|
477 | -这次换一个模拟代码。一个最基础的 Springboot 项目(当然,不想 Springboot 的话,你也可以直接在 UserController 里 main 方法启动)控制层 getUser 方法调用了 userService.get(uid);,这个方法中分别进行 check、service、redis、mysql 操作。 |
|
478 | - |
|
479 | -@RestController |
|
480 | -@Slf4j |
|
481 | -public class UserController { |
|
482 | - |
|
483 | - @Autowired |
|
484 | - private UserServiceImpl userService; |
|
485 | - |
|
486 | - @GetMapping(value = "/user") |
|
487 | - public HashMap<String, Object> getUser(Integer uid) throws Exception { |
|
488 | - // 模拟用户查询 |
|
489 | - userService.get(uid); |
|
490 | - HashMap<String, Object> hashMap = new HashMap<>(); |
|
491 | - hashMap.put("uid", uid); |
|
492 | - hashMap.put("name", "name" + uid); |
|
493 | - return hashMap; |
|
494 | - } |
|
495 | -} |
|
496 | -模拟代码 Service: |
|
497 | - |
|
498 | -@Service |
|
499 | -@Slf4j |
|
500 | -public class UserServiceImpl { |
|
501 | - |
|
502 | - public void get(Integer uid) throws Exception { |
|
503 | - check(uid); |
|
504 | - service(uid); |
|
505 | - redis(uid); |
|
506 | - mysql(uid); |
|
507 | - } |
|
508 | - |
|
509 | - public void service(Integer uid) throws Exception { |
|
510 | - int count = 0; |
|
511 | - for (int i = 0; i < 10; i++) { |
|
512 | - count += i; |
|
513 | - } |
|
514 | - log.info("service end {}", count); |
|
515 | - } |
|
516 | - |
|
517 | - public void redis(Integer uid) throws Exception { |
|
518 | - int count = 0; |
|
519 | - for (int i = 0; i < 10000; i++) { |
|
520 | - count += i; |
|
521 | - } |
|
522 | - log.info("redis end {}", count); |
|
523 | - } |
|
524 | - |
|
525 | - public void mysql(Integer uid) throws Exception { |
|
526 | - long count = 0; |
|
527 | - for (int i = 0; i < 10000000; i++) { |
|
528 | - count += i; |
|
529 | - } |
|
530 | - log.info("mysql end {}", count); |
|
531 | - } |
|
532 | - |
|
533 | - public boolean check(Integer uid) throws Exception { |
|
534 | - if (uid == null || uid < 0) { |
|
535 | - log.error("uid不正确,uid:{}", uid); |
|
536 | - throw new Exception("uid不正确"); |
|
537 | - } |
|
538 | - return true; |
|
539 | - } |
|
540 | -} |
|
541 | - |
|
542 | -运行 Springboot 之后,使用 **trace== ** 命令开始检测耗时情况。 |
|
543 | - |
|
544 | -[arthas@6592]$ trace com.UserController getUser |
|
545 | -访问接口 /getUser ,可以看到耗时信息,看到 com.UserServiceImpl:get() 方法耗时较高。 |
|
546 | - |
|
547 | -继续跟踪耗时高的方法,然后再次访问。 |
|
548 | - |
|
549 | -[arthas@6592]$ trace com.UserServiceImpl get |
|
550 | - |
|
551 | - |
|
552 | -很清楚的看到是 com.UserServiceImpl 的 mysql 方法耗时是最高的。 |
|
553 | - |
|
554 | -Affect(class-cnt:1 , method-cnt:1) cost in 31 ms. |
|
555 | -`---ts=2019-10-16 14:40:10;thread_name=http-nio-8080-exec-8;id=1f;is_daemon=true;priority=5;TCCL=org.springframework.boot.web.embedded.tomcat.TomcatEmbeddedWebappClassLoader@23a918c7 |
|
556 | - `---[6.792201ms] com.UserServiceImpl:get() |
|
557 | - +---[0.008ms] com.UserServiceImpl:check() #17 |
|
558 | - +---[0.076ms] com.UserServiceImpl:service() #18 |
|
559 | - +---[0.1089ms] com.UserServiceImpl:redis() #19 |
|
560 | - `---[6.528899ms] com.UserServiceImpl:mysql() #20 |
|
561 | -4.9.2 统计方法耗时 |
|
562 | -使用 monitor 命令监控统计方法的执行情况。 |
|
563 | - |
|
564 | -每 5 秒统计一次 com.UserServiceImpl 类的 get 方法执行情况。 |
|
565 | - |
|
566 | -monitor -c 5 com.UserServiceImpl get |
|
567 | - |
|
568 | - |
|
569 | -4.10 想观察方法信息 |
|
570 | -下面的示例用到了文章的前两个模拟代码。 |
|
571 | - |
|
572 | -4.10.1 观察方法的入参出参信息 |
|
573 | -使用 watch 命令轻松查看输入输出参数以及异常等信息。 |
|
574 | - |
|
575 | - USAGE: |
|
576 | - watch [-b] [-e] [-x <value>] [-f] [-h] [-n <value>] [-E] [-M <value>] [-s] class-pattern method-pattern express [condition-express] |
|
577 | - |
|
578 | - SUMMARY: |
|
579 | - Display the input/output parameter, return object, and thrown exception of specified method invocation |
|
580 | - The express may be one of the following expression (evaluated dynamically): |
|
581 | - target : the object |
|
582 | - clazz : the object's class |
|
583 | - method : the constructor or method |
|
584 | - params : the parameters array of method |
|
585 | - params[0..n] : the element of parameters array |
|
586 | - returnObj : the returned object of method |
|
587 | - throwExp : the throw exception of method |
|
588 | - isReturn : the method ended by return |
|
589 | - isThrow : the method ended by throwing exception |
|
590 | - #cost : the execution time in ms of method invocation |
|
591 | - Examples: |
|
592 | - watch -b org.apache.commons.lang.StringUtils isBlank params |
|
593 | - watch -f org.apache.commons.lang.StringUtils isBlank returnObj |
|
594 | - watch org.apache.commons.lang.StringUtils isBlank '{params, target, returnObj}' -x 2 |
|
595 | - watch -bf *StringUtils isBlank params |
|
596 | - watch *StringUtils isBlank params[0] |
|
597 | - watch *StringUtils isBlank params[0] params[0].length==1 |
|
598 | - watch *StringUtils isBlank params '#cost>100' |
|
599 | - watch -E -b org\.apache\.commons\.lang\.StringUtils isBlank params[0] |
|
600 | - |
|
601 | - WIKI: |
|
602 | - https://alibaba.github.io/arthas/watch |
|
603 | -常用操作: |
|
604 | - |
|
605 | -# 查看入参和出参 |
|
606 | -$ watch com.Arthas addHashSet '{params[0],returnObj}' |
|
607 | -# 查看入参和出参大小 |
|
608 | -$ watch com.Arthas addHashSet '{params[0],returnObj.size}' |
|
609 | -# 查看入参和出参中是否包含 'count10' |
|
610 | -$ watch com.Arthas addHashSet '{params[0],returnObj.contains("count10")}' |
|
611 | -# 查看入参和出参,出参 toString |
|
612 | -$ watch com.Arthas addHashSet '{params[0],returnObj.toString()}' |
|
613 | -查看入参出参。 |
|
614 | - |
|
615 | - |
|
616 | - |
|
617 | -查看返回的异常信息。 |
|
618 | - |
|
619 | -4.10.2 观察方法的调用路径 |
|
620 | -使用 stack 命令查看方法的调用信息。 |
|
621 | - |
|
622 | -# 观察 类com.UserServiceImpl的 mysql 方法调用路径 |
|
623 | -stack com.UserServiceImpl mysql |
|
624 | - |
|
625 | - |
|
626 | -4.10.3 方法调用时空隧道 |
|
627 | -使用 tt 命令记录方法执行的详细情况。 |
|
628 | - |
|
629 | -tt 命令方法执行数据的时空隧道,记录下指定方法每次调用的入参和返回信息,并能对这些不同的时间下调用进行观测 。 |
|
630 | - |
|
631 | -常用操作: |
|
632 | - |
|
633 | -开始记录方法调用信息:tt -t com.UserServiceImpl check |
|
634 | - |
|
635 | - |
|
636 | - |
|
637 | -可以看到记录中 INDEX=1001 的记录的 IS-EXP = true ,说明这次调用出现异常。 |
|
638 | - |
|
639 | -查看记录的方法调用信息: tt -l |
|
640 | - |
|
641 | - |
|
642 | - |
|
643 | -查看调用记录的详细信息(-i 指定 INDEX): tt -i 1001 |
|
644 | - |
|
645 | - |
|
646 | - |
|
647 | -可以看到 INDEX=1001 的记录的异常信息。 |
|
648 | - |
|
649 | -重新发起调用,使用指定记录,使用 -p 重新调用。 |
|
650 | - |
|
651 | -tt -i 1001 -p |
|
652 | - |
|
653 | - |
|
654 | -4.5. 火焰图分析 |
|
655 | -最近 Arthas 性能分析工具上线了火焰图分析功能,Arthas 使用 async-profiler 生成 CPU / 内存火焰图进行性能分析,弥补了之前内存分析的不足。在 Arthas 上使用还是比较方便的。 |
|
656 | - |
|
657 | -profiler 命令支持生成应用热点的火焰图。本质上是通过不断的采样,然后把收集到的采样结果生成火焰图。 |
|
658 | - |
|
659 | -profiler 命令基本运行结构是 profiler action [actionArg] |
|
660 | - |
|
661 | -4.5.1. 使用案例 |
|
662 | -开启 prifilter |
|
663 | - |
|
664 | -默认情况下,生成的是 cpu 的火焰图,即 event 为 cpu。可以用 --event 参数来指定,使用 start 命令开始捕获信息。 |
|
665 | - |
|
666 | -$ profiler start |
|
667 | -Started [cpu] profiling |
|
668 | -获取已采集的 sample 的数量 |
|
669 | - |
|
670 | -$ profiler getSamples |
|
671 | -23 |
|
672 | -查看 profiler 状态,可以查看当前 profiler 在采样哪种 event 和进行的采样时间。 |
|
673 | - |
|
674 | -$ profiler status |
|
675 | - |
|
676 | -[cpu] profiling is running for 4 seconds |
|
677 | -停止 profiler |
|
678 | - |
|
679 | -生成 svg 格式火焰图 |
|
680 | - |
|
681 | -$ profiler stop |
|
682 | -profiler output file: /tmp/demo/arthas-output/20191125-135546.svg |
|
683 | -OK |
|
684 | -默认情况下,生成的结果保存到应用的工作目录下的 arthas-output 目录。可以通过 --file 参数来指定输出结果路径。 |
|
685 | - |
|
686 | -比如: |
|
687 | - |
|
688 | -$ profiler stop --file /tmp/output.svg |
|
689 | -HTML 格式输出 |
|
690 | - |
|
691 | -默认情况下,结果文件是 svg 格式,如果想生成 html 格式,可以用 --format 参数指定:$ profiler stop --format html |
|
692 | - |
|
693 | -查看 profilter |
|
694 | - |
|
695 | -默认情况下,arthas 使用 3658 端口,则可以打开: http://localhost:3658/arthas-output/ 查看到 arthas-output 目录下面的 profiler 结果: |
|
696 | - |
|
697 | - |
|
698 | - |
|
699 | -点击可以查看具体的结果:火焰图里,横条越长,代表使用的越多,从下到上是调用堆栈信息 |
|
700 | - |
|
701 | - |
|
702 | - |
|
703 | -**profilter 自持多种分析方式,** 常见的有 event: cpu|alloc|lock|cache-misses etc. 比如要分析内存使用情况。 |
|
704 | - |
|
705 | -$ profiler start --event alloc |
|
706 | - |
|
707 | -4.5.2. 复杂命令 |
|
708 | -比如开始采样: |
|
709 | - |
|
710 | -profiler execute 'start' |
|
711 | -停止采样,并保存到指定文件里: |
|
712 | - |
|
713 | -profiler execute 'stop,file=/tmp/result.svg' |
|
714 | -文中代码已经上传到 Github。 |
|
... | ... | \ No newline at end of file |
Arthas-guide.mediawiki
... | ... | @@ -0,0 +1,744 @@ |
1 | +<div> |
|
2 | + <h1> <a class="home" href="/">程序猿阿朗</a> </h1> |
|
3 | +</div> |
|
4 | +<div class="main" id="main"> |
|
5 | + <div class="post-title"><h1>Arthas - Java 线上问题定位处理的终极利器</h1></div> |
|
6 | + <div class="post-time" style="font-size: .9em;"> |
|
7 | + <p><i class="fa fa-calendar"></i> 最后更新日期:<span>2019-11-06</span> | <a href="#" onclick="showToc()" id="tocBtn"><i class="fa fa-pencil"></i> 显示目录</a> | |
|
8 | + 字体 <a href="#" onclick="changeFontSize(1)" title="增大字体" style="background: white">➕</a> |
|
9 | + <a href="#" onclick="changeFontSize(-1)" title="减小字体" style="background: white">➖</a> |
|
10 | + </p> |
|
11 | + </div> |
|
12 | + <div class="post-toc" id="toc"> |
|
13 | + <div><b>目录</b></div> |
|
14 | + <div><a style="margin: 0px;" href="#前言">前言</a></div> |
|
15 | + <div><a style="margin: 0px;" href="#1arthas--介绍">1、Arthas 介绍</a></div> |
|
16 | + <div><a style="margin: 0px;" href="#2arthas--使用场景">2、Arthas 使用场景</a></div> |
|
17 | + <div><a style="margin: 0px;" href="#3arthas--怎么用">3、Arthas 怎么用</a></div> |
|
18 | + <div><a style="margin: 20px;" href="#31-安装">3.1 安装</a></div> |
|
19 | + <div><a style="margin: 20px;" href="#32-运行">3.2 运行</a></div> |
|
20 | + <div><a style="margin: 20px;" href="#33-web-console">3.3 web console</a></div> |
|
21 | + <div><a style="margin: 20px;" href="#34-常用命令">3.4 常用命令</a></div> |
|
22 | + <div><a style="margin: 20px;" href="#35-退出">3.5 退出</a></div> |
|
23 | + <div><a style="margin: 0px;" href="#4arthas-常用操作">4、Arthas 常用操作</a></div> |
|
24 | + <div><a style="margin: 20px;" href="#41-全局监控">4.1 全局监控</a></div> |
|
25 | + <div><a style="margin: 20px;" href="#42-cpu-为什么起飞了">4.2 CPU 为什么起飞了</a></div> |
|
26 | + <div><a style="margin: 20px;" href="#43-线程池线程状态">4.3 线程池线程状态</a></div> |
|
27 | + <div><a style="margin: 20px;" href="#44-线程死锁">4.4 线程死锁</a></div> |
|
28 | + <div><a style="margin: 20px;" href="#45-反编译">4.5 反编译</a></div> |
|
29 | + <div><a style="margin: 20px;" href="#46-查看字段信息">4.6 查看字段信息</a></div> |
|
30 | + <div><a style="margin: 20px;" href="#47-查看方法信息">4.7 查看方法信息</a></div> |
|
31 | + <div><a style="margin: 20px;" href="#48-对变量的值很是好奇">4.8 对变量的值很是好奇</a></div> |
|
32 | + <div><a style="margin: 20px;" href="#49-程序有没有问题">4.9 程序有没有问题</a></div> |
|
33 | + <div><a style="margin: 40px;" href="#491-运行较慢耗时较长">4.9.1 运行较慢、耗时较长</a></div> |
|
34 | + <div><a style="margin: 40px;" href="#492-统计方法耗时">4.9.2 统计方法耗时</a></div> |
|
35 | + <div><a style="margin: 20px;" href="#410-想观察方法信息">4.10 想观察方法信息</a></div> |
|
36 | + <div><a style="margin: 40px;" href="#4101-观察方法的入参出参信息">4.10.1 观察方法的入参出参信息</a></div> |
|
37 | + <div><a style="margin: 40px;" href="#4102-观察方法的调用路径">4.10.2 观察方法的调用路径</a></div> |
|
38 | + <div><a style="margin: 40px;" href="#4103-方法调用时空隧道">4.10.3 方法调用时空隧道</a></div> |
|
39 | + <div><a style="margin: 20px;" href="#45-火焰图分析">4.5. 火焰图分析</a></div> |
|
40 | + <div><a style="margin: 40px;" href="#451使用案例">4.5.1.使用案例</a></div> |
|
41 | + <div><a style="margin: 40px;" href="#452-复杂命令">4.5.2. 复杂命令</a></div> |
|
42 | + </div> |
|
43 | + <div class="post-content"><p><img src="https://cdn.debug.group/git/2019/arthas-1572972116473.png" alt="Arthas logo" /></p> |
|
44 | +<h1 id="前言">前言</h1> |
|
45 | +<p>在使用 <strong>Arthas</strong> 之前,当遇到 Java 线上问题时,如 CPU 飙升、负载突高、内存溢出等问题,你需要查命令,查网络,然后 jps、jstack、jmap、jhat、jstat、hprof 等一通操作。最终焦头烂额,还不一定能查出问题所在。而现在,大多数的常见问题你都可以使用 <strong>Arthas</strong> 轻松定位,迅速解决,及时止损,准时下班。</p> |
|
46 | +<p><img src="https://cdn.debug.group/img/23/02/Xnip2023-02-21_21-19-50.jpeg" alt="" /></p> |
|
47 | +<h1 id="1arthas--介绍">1、Arthas 介绍</h1> |
|
48 | +<p><strong>Arthas</strong> 是 <code>Alibaba</code> 在 2018 年 9 月开源的 <strong>Java 诊断</strong>工具。支持 <code>JDK6+</code>, 采用命令行交互模式,提供 <code>Tab</code> 自动补全,可以方便的定位和诊断线上程序运行问题。截至本篇文章编写时,已经收获 <code>Star</code> 17000+。</p> |
|
49 | +<p><strong>Arthas</strong> 官方文档十分详细,本文也参考了官方文档内容,同时在开源在的 <code>Github</code> 的项目里的 <code>Issues</code> 里不仅有问题反馈,更有大量的使用案例,也可以进行学习参考。</p> |
|
50 | +<p>开源地址:<em>https://github.com/alibaba/arthas</em></p> |
|
51 | +<p>官方文档:<em>https://alibaba.github.io/arthas</em></p> |
|
52 | +<!-- more --> |
|
53 | +<h1 id="2arthas--使用场景">2、Arthas 使用场景</h1> |
|
54 | +<p>得益于 <strong>Arthas</strong> 强大且丰富的功能,让 <strong>Arthas</strong> 能做的事情超乎想象。下面仅仅列举几项常见的使用情况,更多的使用场景可以在熟悉了 <strong>Arthas</strong> 之后自行探索。</p> |
|
55 | +<ol> |
|
56 | +<li>是否有一个全局视角来查看系统的运行状况?</li> |
|
57 | +<li>为什么 CPU 又升高了,到底是哪里占用了 CPU ?</li> |
|
58 | +<li>运行的多线程有死锁吗?有阻塞吗?</li> |
|
59 | +<li>程序运行耗时很长,是哪里耗时比较长呢?如何监测呢?</li> |
|
60 | +<li>这个类从哪个 jar 包加载的?为什么会报各种类相关的 Exception?</li> |
|
61 | +<li>我改的代码为什么没有执行到?难道是我没 commit?分支搞错了?</li> |
|
62 | +<li>遇到问题无法在线上 debug,难道只能通过加日志再重新发布吗?</li> |
|
63 | +<li>有什么办法可以监控到 JVM 的实时运行状态?</li> |
|
64 | +</ol> |
|
65 | +<h1 id="3arthas--怎么用">3、Arthas 怎么用</h1> |
|
66 | +<p>前文已经提到,<strong>Arthas</strong> 是一款命令行交互模式的 Java 诊断工具,由于是 Java 编写,所以可以直接下载相应 的 jar 包运行。</p> |
|
67 | +<h2 id="31-安装">3.1 安装</h2> |
|
68 | +<p>可以在官方 Github 上进行下载,如果速度较慢,可以尝试国内的码云 Gitee 下载。</p> |
|
69 | +<pre><code class="language-shell"># github下载 |
|
70 | +wget https://alibaba.github.io/arthas/arthas-boot.jar |
|
71 | +# 或者 Gitee 下载 |
|
72 | +wget https://arthas.gitee.io/arthas-boot.jar |
|
73 | +# 打印帮助信息 |
|
74 | +java -jar arthas-boot.jar -h |
|
75 | +</code></pre> |
|
76 | +<h2 id="32-运行">3.2 运行</h2> |
|
77 | +<p><strong>Arthas</strong> 只是一个 java 程序,所以可以直接用 <code>java -jar</code> 运行。运行时或者运行之后要选择要监测的 Java 进程。</p> |
|
78 | +<pre><code class="language-shell"># 运行方式1,先运行,在选择 Java 进程 PID |
|
79 | +java -jar arthas-boot.jar |
|
80 | +# 选择进程(输入[]内编号(不是PID)回车) |
|
81 | +[INFO] arthas-boot version: 3.1.4 |
|
82 | +[INFO] Found existing java process, please choose one and hit RETURN. |
|
83 | +* [1]: 11616 com.Arthas |
|
84 | + [2]: 8676 |
|
85 | + [3]: 16200 org.jetbrains.jps.cmdline.Launcher |
|
86 | + [4]: 21032 org.jetbrains.idea.maven.server.RemoteMavenServer |
|
87 | + |
|
88 | +# 运行方式2,运行时选择 Java 进程 PID |
|
89 | +java -jar arthas-boot.jar [PID] |
|
90 | +</code></pre> |
|
91 | +<p>查看 PID 的方式可以通过 <code>ps</code> 命令,也可以通过 JDK 提供的 <code>jps</code>命令。</p> |
|
92 | +<pre><code class="language-shell"># 查看运行的 java 进程信息 |
|
93 | +$ jps -mlvV |
|
94 | +# 筛选 java 进程信息 |
|
95 | +$ jps -mlvV | grep [xxx] |
|
96 | +</code></pre> |
|
97 | +<p><code>jps</code> 筛选想要的进程方式。</p> |
|
98 | +<p><img src="https://cdn.debug.group/git/2019/1570979767404.png" alt="jps 筛选进程" /></p> |
|
99 | +<p>在出现 <strong>Arthas</strong> Logo 之后就可以使用命令进行问题诊断了。下面会详细介绍。</p> |
|
100 | +<p><img src="https://cdn.debug.group/git/2019/image-20191106003512451.png" alt="Arthas 启动" /></p> |
|
101 | +<p>更多的启动方式可以参考 help 帮助命令。</p> |
|
102 | +<pre><code class="language-shell"># 其他用法 |
|
103 | +EXAMPLES: |
|
104 | + java -jar arthas-boot.jar <pid> |
|
105 | + java -jar arthas-boot.jar --target-ip 0.0.0.0 |
|
106 | + java -jar arthas-boot.jar --telnet-port 9999 --http-port -1 |
|
107 | + java -jar arthas-boot.jar --tunnel-server 'ws://192.168.10.11:7777/ws' |
|
108 | + java -jar arthas-boot.jar --tunnel-server 'ws://192.168.10.11:7777/ws' |
|
109 | +--agent-id bvDOe8XbTM2pQWjF4cfw |
|
110 | + java -jar arthas-boot.jar --stat-url 'http://192.168.10.11:8080/api/stat' |
|
111 | + java -jar arthas-boot.jar -c 'sysprop; thread' <pid> |
|
112 | + java -jar arthas-boot.jar -f batch.as <pid> |
|
113 | + java -jar arthas-boot.jar --use-version 3.1.4 |
|
114 | + java -jar arthas-boot.jar --versions |
|
115 | + java -jar arthas-boot.jar --session-timeout 3600 |
|
116 | + java -jar arthas-boot.jar --attach-only |
|
117 | + java -jar arthas-boot.jar --repo-mirror aliyun --use-http |
|
118 | +</code></pre> |
|
119 | +<h2 id="33-web-console">3.3 web console</h2> |
|
120 | +<p><strong>Arthas</strong> 目前支持 <code>Web Console</code>,在成功启动连接进程之后就已经自动启动,可以直接访问 http://127.0.0.1:8563/ 访问,页面上的操作模式和控制台完全一样。</p> |
|
121 | +<p><img src="https://cdn.debug.group/git/2019/1570979937637.png" alt="1570979937637" /></p> |
|
122 | +<h2 id="34-常用命令">3.4 常用命令</h2> |
|
123 | +<p>下面列举一些 <a href="https://www.wdbyte.com/2019/11/arthas/" target="_blank"><strong>Arthas</strong></a> 的常用命令,看到这里你可能还不知道怎么使用,别急,后面会一一介绍。</p> |
|
124 | +<table class="ui celled table"> |
|
125 | +<thead> |
|
126 | +<tr> |
|
127 | +<th>命令</th> |
|
128 | +<th>介绍</th> |
|
129 | +</tr> |
|
130 | +</thead> |
|
131 | +<tbody> |
|
132 | +<tr> |
|
133 | +<td><a href="https://alibaba.github.io/arthas/dashboard.html" target="_blank">dashboard</a></td> |
|
134 | +<td>当前系统的实时数据面板</td> |
|
135 | +</tr> |
|
136 | +<tr> |
|
137 | +<td><a href="https://alibaba.github.io/arthas/thread.html" target="_blank"><strong>thread</strong></a></td> |
|
138 | +<td>查看当前 JVM 的线程堆栈信息</td> |
|
139 | +</tr> |
|
140 | +<tr> |
|
141 | +<td><a href="https://alibaba.github.io/arthas/watch.html" target="_blank"><strong>watch</strong></a></td> |
|
142 | +<td>方法执行数据观测</td> |
|
143 | +</tr> |
|
144 | +<tr> |
|
145 | +<td><strong><a href="https://alibaba.github.io/arthas/trace.html" target="_blank">trace</a></strong></td> |
|
146 | +<td>方法内部调用路径,并输出方法路径上的每个节点上耗时</td> |
|
147 | +</tr> |
|
148 | +<tr> |
|
149 | +<td><a href="https://alibaba.github.io/arthas/stack.html" target="_blank"><strong>stack</strong></a></td> |
|
150 | +<td>输出当前方法被调用的调用路径</td> |
|
151 | +</tr> |
|
152 | +<tr> |
|
153 | +<td><a href="https://alibaba.github.io/arthas/tt.html" target="_blank"><strong>tt</strong></a></td> |
|
154 | +<td>方法执行数据的时空隧道,记录下指定方法每次调用的入参和返回信息,并能对这些不同的时间下调用进行观测</td> |
|
155 | +</tr> |
|
156 | +<tr> |
|
157 | +<td><a href="https://alibaba.github.io/arthas/monitor.html" target="_blank">monitor</a></td> |
|
158 | +<td>方法执行监控</td> |
|
159 | +</tr> |
|
160 | +<tr> |
|
161 | +<td><a href="https://alibaba.github.io/arthas/jvm.html" target="_blank">jvm</a></td> |
|
162 | +<td>查看当前 JVM 信息</td> |
|
163 | +</tr> |
|
164 | +<tr> |
|
165 | +<td><a href="https://alibaba.github.io/arthas/vmoption.html" target="_blank">vmoption</a></td> |
|
166 | +<td>查看,更新 JVM 诊断相关的参数</td> |
|
167 | +</tr> |
|
168 | +<tr> |
|
169 | +<td><a href="https://alibaba.github.io/arthas/sc.html" target="_blank">sc</a></td> |
|
170 | +<td>查看 JVM 已加载的类信息</td> |
|
171 | +</tr> |
|
172 | +<tr> |
|
173 | +<td><a href="https://alibaba.github.io/arthas/sm.html" target="_blank">sm</a></td> |
|
174 | +<td>查看已加载类的方法信息</td> |
|
175 | +</tr> |
|
176 | +<tr> |
|
177 | +<td><a href="https://alibaba.github.io/arthas/jad.html" target="_blank">jad</a></td> |
|
178 | +<td>反编译指定已加载类的源码</td> |
|
179 | +</tr> |
|
180 | +<tr> |
|
181 | +<td><a href="https://alibaba.github.io/arthas/classloader.html" target="_blank">classloader</a></td> |
|
182 | +<td>查看 classloader 的继承树,urls,类加载信息</td> |
|
183 | +</tr> |
|
184 | +<tr> |
|
185 | +<td><a href="https://alibaba.github.io/arthas/heapdump.html" target="_blank">heapdump</a></td> |
|
186 | +<td>类似 jmap 命令的 heap dump 功能</td> |
|
187 | +</tr> |
|
188 | +</tbody> |
|
189 | +</table> |
|
190 | +<h2 id="35-退出">3.5 退出</h2> |
|
191 | +<p>使用 shutdown 退出时 <strong>Arthas</strong> 同时自动重置所有增强过的类 。</p> |
|
192 | +<h1 id="4arthas-常用操作">4、Arthas 常用操作</h1> |
|
193 | +<p>上面已经了解了什么是 <strong>Arthas</strong>,以及 <strong>Arthas</strong> 的启动方式,下面会依据一些情况,详细说一说 <strong>Arthas</strong> 的使用方式。在使用命令的过程中如果有问题,每个命令都可以是 <code>-h</code> 查看帮助信息。</p> |
|
194 | +<p>首先编写一个有各种情况的测试类运行起来,再使用 <strong>Arthas</strong> 进行问题定位,</p> |
|
195 | +<pre><code class="language-java">import java.util.HashSet; |
|
196 | +import java.util.concurrent.ExecutorService; |
|
197 | +import java.util.concurrent.Executors; |
|
198 | +import lombok.extern.slf4j.Slf4j; |
|
199 | + |
|
200 | +/** |
|
201 | + * <p> |
|
202 | + * Arthas Demo |
|
203 | + * 公众号:程序猿阿朗 |
|
204 | + * |
|
205 | + * @Author niujinpeng |
|
206 | + */ |
|
207 | +@Slf4j |
|
208 | +public class Arthas { |
|
209 | + |
|
210 | + private static HashSet hashSet = new HashSet(); |
|
211 | + /** 线程池,大小1*/ |
|
212 | + private static ExecutorService executorService = Executors.newFixedThreadPool(1); |
|
213 | + |
|
214 | + public static void main(String[] args) { |
|
215 | + // 模拟 CPU 过高,这里注释掉了,测试时可以打开 |
|
216 | + // cpu(); |
|
217 | + // 模拟线程阻塞 |
|
218 | + thread(); |
|
219 | + // 模拟线程死锁 |
|
220 | + deadThread(); |
|
221 | + // 不断的向 hashSet 集合增加数据 |
|
222 | + addHashSetThread(); |
|
223 | + } |
|
224 | + |
|
225 | + /** |
|
226 | + * 不断的向 hashSet 集合添加数据 |
|
227 | + */ |
|
228 | + public static void addHashSetThread() { |
|
229 | + // 初始化常量 |
|
230 | + new Thread(() -> { |
|
231 | + int count = 0; |
|
232 | + while (true) { |
|
233 | + try { |
|
234 | + hashSet.add("count" + count); |
|
235 | + Thread.sleep(10000); |
|
236 | + count++; |
|
237 | + } catch (InterruptedException e) { |
|
238 | + e.printStackTrace(); |
|
239 | + } |
|
240 | + } |
|
241 | + }).start(); |
|
242 | + } |
|
243 | + |
|
244 | + public static void cpu() { |
|
245 | + cpuHigh(); |
|
246 | + cpuNormal(); |
|
247 | + } |
|
248 | + |
|
249 | + /** |
|
250 | + * 极度消耗CPU的线程 |
|
251 | + */ |
|
252 | + private static void cpuHigh() { |
|
253 | + Thread thread = new Thread(() -> { |
|
254 | + while (true) { |
|
255 | + log.info("cpu start 100"); |
|
256 | + } |
|
257 | + }); |
|
258 | + // 添加到线程 |
|
259 | + executorService.submit(thread); |
|
260 | + } |
|
261 | + |
|
262 | + /** |
|
263 | + * 普通消耗CPU的线程 |
|
264 | + */ |
|
265 | + private static void cpuNormal() { |
|
266 | + for (int i = 0; i < 10; i++) { |
|
267 | + new Thread(() -> { |
|
268 | + while (true) { |
|
269 | + log.info("cpu start"); |
|
270 | + try { |
|
271 | + Thread.sleep(3000); |
|
272 | + } catch (InterruptedException e) { |
|
273 | + e.printStackTrace(); |
|
274 | + } |
|
275 | + } |
|
276 | + }).start(); |
|
277 | + } |
|
278 | + } |
|
279 | + |
|
280 | + /** |
|
281 | + * 模拟线程阻塞,向已经满了的线程池提交线程 |
|
282 | + */ |
|
283 | + private static void thread() { |
|
284 | + Thread thread = new Thread(() -> { |
|
285 | + while (true) { |
|
286 | + log.debug("thread start"); |
|
287 | + try { |
|
288 | + Thread.sleep(3000); |
|
289 | + } catch (InterruptedException e) { |
|
290 | + e.printStackTrace(); |
|
291 | + } |
|
292 | + } |
|
293 | + }); |
|
294 | + // 添加到线程 |
|
295 | + executorService.submit(thread); |
|
296 | + } |
|
297 | + |
|
298 | + /** |
|
299 | + * 死锁 |
|
300 | + */ |
|
301 | + private static void deadThread() { |
|
302 | + /** 创建资源 */ |
|
303 | + Object resourceA = new Object(); |
|
304 | + Object resourceB = new Object(); |
|
305 | + // 创建线程 |
|
306 | + Thread threadA = new Thread(() -> { |
|
307 | + synchronized (resourceA) { |
|
308 | + log.info(Thread.currentThread() + " get ResourceA"); |
|
309 | + try { |
|
310 | + Thread.sleep(1000); |
|
311 | + } catch (InterruptedException e) { |
|
312 | + e.printStackTrace(); |
|
313 | + } |
|
314 | + log.info(Thread.currentThread() + "waiting get resourceB"); |
|
315 | + synchronized (resourceB) { |
|
316 | + log.info(Thread.currentThread() + " get resourceB"); |
|
317 | + } |
|
318 | + } |
|
319 | + }); |
|
320 | + |
|
321 | + Thread threadB = new Thread(() -> { |
|
322 | + synchronized (resourceB) { |
|
323 | + log.info(Thread.currentThread() + " get ResourceB"); |
|
324 | + try { |
|
325 | + Thread.sleep(1000); |
|
326 | + } catch (InterruptedException e) { |
|
327 | + e.printStackTrace(); |
|
328 | + } |
|
329 | + log.info(Thread.currentThread() + "waiting get resourceA"); |
|
330 | + synchronized (resourceA) { |
|
331 | + log.info(Thread.currentThread() + " get resourceA"); |
|
332 | + } |
|
333 | + } |
|
334 | + }); |
|
335 | + threadA.start(); |
|
336 | + threadB.start(); |
|
337 | + } |
|
338 | +} |
|
339 | +</code></pre> |
|
340 | +<h2 id="41-全局监控">4.1 全局监控</h2> |
|
341 | +<p>使用 <strong>dashboard</strong> 命令可以概览程序的 线程、内存、GC、运行环境信息。</p> |
|
342 | +<p><img src="https://cdn.debug.group/git/2019/1571212470373.png" alt="dashboard" /></p> |
|
343 | +<h2 id="42-cpu-为什么起飞了">4.2 CPU 为什么起飞了</h2> |
|
344 | +<p>上面的代码例子有一个 <code>CPU</code> 空转的死循环,非常的消耗 <code>CPU性能</code>,那么怎么找出来呢?</p> |
|
345 | +<p>使用 <strong>thread</strong>查看<strong>所有</strong>线程信息,同时会列出每个线程的 <code>CPU</code> 使用率,可以看到图里 ID 为12 的线程 CPU 使用100%。 |
|
346 | +<img src="https://cdn.debug.group/git/2019/1570983440457.png" alt="" /></p> |
|
347 | +<p>使用命令 <strong>thread 12</strong> 查看 CPU 消耗较高的 12 号线程信息,可以看到 CPU 使用较高的方法和行数(这里的行数可能和上面代码里的行数有区别,因为上面的代码在我写文章时候重新排过版了)。</p> |
|
348 | +<p><img src="https://cdn.debug.group/git/2019/1570983401254.png" alt="" /></p> |
|
349 | +<p>上面是先通过观察总体的线程信息,然后查看具体的线程运行情况。如果只是为了寻找 CPU 使用较高的线程,可以直接使用命令 <strong>thread -n [显示的线程个数]</strong> ,就可以排列出 CPU 使用率 <strong>Top N</strong> 的线程。</p> |
|
350 | +<p><img src="https://cdn.debug.group/git/2019/1570983061047.png" alt="" /></p> |
|
351 | +<p>定位到的 CPU 使用最高的方法。</p> |
|
352 | +<p><img src="https://cdn.debug.group/git/2019/1571016675083.png" alt="" /></p> |
|
353 | +<h2 id="43-线程池线程状态">4.3 线程池线程状态</h2> |
|
354 | +<p>定位线程问题之前,先回顾一下线程的几种常见状态:</p> |
|
355 | +<ul> |
|
356 | +<li><strong>RUNNABLE</strong> 运行中</li> |
|
357 | +<li><strong>TIMED_WAITIN</strong> 调用了以下方法的线程会进入<strong>TIMED_WAITING</strong>: |
|
358 | +<ol> |
|
359 | +<li>Thread#sleep()</li> |
|
360 | +<li>Object#wait() 并加了超时参数</li> |
|
361 | +<li>Thread#join() 并加了超时参数</li> |
|
362 | +<li>LockSupport#parkNanos()</li> |
|
363 | +<li>LockSupport#parkUntil()</li> |
|
364 | +</ol> |
|
365 | +</li> |
|
366 | +<li><strong>WAITING</strong> 当线程调用以下方法时会进入WAITING状态: |
|
367 | +<ol> |
|
368 | +<li>Object#wait() 而且不加超时参数</li> |
|
369 | +<li>Thread#join() 而且不加超时参数</li> |
|
370 | +<li>LockSupport#park()</li> |
|
371 | +</ol> |
|
372 | +</li> |
|
373 | +<li><strong>BLOCKED</strong> 阻塞,等待锁</li> |
|
374 | +</ul> |
|
375 | +<p>上面的模拟代码里,定义了线程池大小为1 的线程池,然后在 <code>cpuHigh</code> 方法里提交了一个线程,在 <code>thread</code>方法再次提交了一个线程,后面的这个线程因为线程池已满,会阻塞下来。</p> |
|
376 | +<p>使用 <strong>thread | grep pool</strong> 命令查看线程池里线程信息。</p> |
|
377 | +<p><img src="https://cdn.debug.group/git/2019/1571020871537.png" alt="" /></p> |
|
378 | +<p>可以看到线程池有 <strong>WAITING</strong> 的线程。</p> |
|
379 | +<p><img src="https://cdn.debug.group/git/2019/1571021838323.png" alt="" /></p> |
|
380 | +<h2 id="44-线程死锁">4.4 线程死锁</h2> |
|
381 | +<p>上面的模拟代码里 <code>deadThread </code>方法实现了一个死锁,使用 <strong>thread -b</strong> 命令查看直接定位到死锁信息。</p> |
|
382 | +<pre><code class="language-java">/** |
|
383 | + * 死锁 |
|
384 | + */ |
|
385 | +private static void deadThread() { |
|
386 | + /** 创建资源 */ |
|
387 | + Object resourceA = new Object(); |
|
388 | + Object resourceB = new Object(); |
|
389 | + // 创建线程 |
|
390 | + Thread threadA = new Thread(() -> { |
|
391 | + synchronized (resourceA) { |
|
392 | + log.info(Thread.currentThread() + " get ResourceA"); |
|
393 | + try { |
|
394 | + Thread.sleep(1000); |
|
395 | + } catch (InterruptedException e) { |
|
396 | + e.printStackTrace(); |
|
397 | + } |
|
398 | + log.info(Thread.currentThread() + "waiting get resourceB"); |
|
399 | + synchronized (resourceB) { |
|
400 | + log.info(Thread.currentThread() + " get resourceB"); |
|
401 | + } |
|
402 | + } |
|
403 | + }); |
|
404 | + |
|
405 | + Thread threadB = new Thread(() -> { |
|
406 | + synchronized (resourceB) { |
|
407 | + log.info(Thread.currentThread() + " get ResourceB"); |
|
408 | + try { |
|
409 | + Thread.sleep(1000); |
|
410 | + } catch (InterruptedException e) { |
|
411 | + e.printStackTrace(); |
|
412 | + } |
|
413 | + log.info(Thread.currentThread() + "waiting get resourceA"); |
|
414 | + synchronized (resourceA) { |
|
415 | + log.info(Thread.currentThread() + " get resourceA"); |
|
416 | + } |
|
417 | + } |
|
418 | + }); |
|
419 | + threadA.start(); |
|
420 | + threadB.start(); |
|
421 | +} |
|
422 | +</code></pre> |
|
423 | +<p>检查到的死锁信息。</p> |
|
424 | +<p><img src="https://cdn.debug.group/git/2019/1571206638142.png" alt="" /></p> |
|
425 | +<h2 id="45-反编译">4.5 反编译</h2> |
|
426 | +<p>上面的代码放到了包 <code>com</code>下,假设这是一个线程环境,当怀疑当前运行的代码不是自己想要的代码时,可以直接反编译出代码,也可以选择性的查看类的字段或方法信息。</p> |
|
427 | +<p>如果怀疑不是自己的代码,可以使用 <strong>jad</strong> 命令直接反编译 class。</p> |
|
428 | +<p><img src="https://cdn.debug.group/git/2019/image-20191106012005747.png" alt="jad" /></p> |
|
429 | +<p><code>jad</code> 命令还提供了一些其他参数:</p> |
|
430 | +<pre><code class="language-shell"># 反编译只显示源码 |
|
431 | +jad --source-only com.Arthas |
|
432 | +# 反编译某个类的某个方法 |
|
433 | +jad --source-only com.Arthas mysql |
|
434 | +</code></pre> |
|
435 | +<h2 id="46-查看字段信息">4.6 查看字段信息</h2> |
|
436 | +<p>使用 **sc -d -f ** 命令查看类的字段信息。</p> |
|
437 | +<pre><code class="language-shell">[arthas@20252]$ sc -d -f com.Arthas |
|
438 | +sc -d -f com.Arthas |
|
439 | + class-info com.Arthas |
|
440 | + code-source /C:/Users/Niu/Desktop/arthas/target/classes/ |
|
441 | + name com.Arthas |
|
442 | + isInterface false |
|
443 | + isAnnotation false |
|
444 | + isEnum false |
|
445 | + isAnonymousClass false |
|
446 | + isArray false |
|
447 | + isLocalClass false |
|
448 | + isMemberClass false |
|
449 | + isPrimitive false |
|
450 | + isSynthetic false |
|
451 | + simple-name Arthas |
|
452 | + modifier public |
|
453 | + annotation |
|
454 | + interfaces |
|
455 | + super-class +-java.lang.Object |
|
456 | + class-loader +-sun.misc.Launcher$AppClassLoader@18b4aac2 |
|
457 | + +-sun.misc.Launcher$ExtClassLoader@2ef1e4fa |
|
458 | + classLoaderHash 18b4aac2 |
|
459 | + fields modifierfinal,private,static |
|
460 | + type org.slf4j.Logger |
|
461 | + name log |
|
462 | + value Logger[com.Arthas] |
|
463 | + |
|
464 | + modifierprivate,static |
|
465 | + type java.util.HashSet |
|
466 | + name hashSet |
|
467 | + value [count1, count2] |
|
468 | + |
|
469 | + modifierprivate,static |
|
470 | + type java.util.concurrent.ExecutorService |
|
471 | + name executorService |
|
472 | + value java.util.concurrent.ThreadPoolExecutor@71c03156[Ru |
|
473 | + nning, pool size = 1, active threads = 1, queued ta |
|
474 | + sks = 0, completed tasks = 0] |
|
475 | + |
|
476 | + |
|
477 | +Affect(row-cnt:1) cost in 9 ms. |
|
478 | +</code></pre> |
|
479 | +<h2 id="47-查看方法信息">4.7 查看方法信息</h2> |
|
480 | +<p>使用 <strong>sm</strong> 命令查看类的方法信息。</p> |
|
481 | +<pre><code class="language-shell">[arthas@22180]$ sm com.Arthas |
|
482 | +com.Arthas <init>()V |
|
483 | +com.Arthas start()V |
|
484 | +com.Arthas thread()V |
|
485 | +com.Arthas deadThread()V |
|
486 | +com.Arthas lambda$cpuHigh$1()V |
|
487 | +com.Arthas cpuHigh()V |
|
488 | +com.Arthas lambda$thread$3()V |
|
489 | +com.Arthas addHashSetThread()V |
|
490 | +com.Arthas cpuNormal()V |
|
491 | +com.Arthas cpu()V |
|
492 | +com.Arthas lambda$addHashSetThread$0()V |
|
493 | +com.Arthas lambda$deadThread$4(Ljava/lang/Object;Ljava/lang/Object;)V |
|
494 | +com.Arthas lambda$deadThread$5(Ljava/lang/Object;Ljava/lang/Object;)V |
|
495 | +com.Arthas lambda$cpuNormal$2()V |
|
496 | +Affect(row-cnt:16) cost in 6 ms. |
|
497 | +</code></pre> |
|
498 | +<h2 id="48-对变量的值很是好奇">4.8 对变量的值很是好奇</h2> |
|
499 | +<p>使用 <strong>ognl</strong> 命令,ognl 表达式可以轻松操作想要的信息。</p> |
|
500 | +<p>代码还是上面的示例代码,我们查看变量 <code>hashSet</code> 中的数据:</p> |
|
501 | +<p><img src="https://cdn.debug.group/git/2019/1571196786678.png" alt="" /></p> |
|
502 | +<p>查看静态变量 <code>hashSet</code> 信息。</p> |
|
503 | +<pre><code class="language-shell">[arthas@19856]$ ognl '@com.Arthas@hashSet' |
|
504 | +@HashSet[ |
|
505 | + @String[count1], |
|
506 | + @String[count2], |
|
507 | + @String[count29], |
|
508 | + @String[count28], |
|
509 | + @String[count0], |
|
510 | + @String[count27], |
|
511 | + @String[count5], |
|
512 | + @String[count26], |
|
513 | + @String[count6], |
|
514 | + @String[count25], |
|
515 | + @String[count3], |
|
516 | + @String[count24], |
|
517 | +</code></pre> |
|
518 | +<p>查看静态变量 hashSet 大小。</p> |
|
519 | +<pre><code class="language-shell">[arthas@19856]$ ognl '@<a href="/cdn-cgi/l/email-protection" class="__cf_email__" data-cfemail="dfbcb0b2f19eadabb7beac9fb7beacb78cbaabf1acb6a5ba">[email protected]</a>()' |
|
520 | + @Integer[57] |
|
521 | +</code></pre> |
|
522 | +<p>甚至可以进行操作。</p> |
|
523 | +<pre><code class="language-shell">[arthas@19856]$ ognl '@<a href="/cdn-cgi/l/email-protection" class="__cf_email__" data-cfemail="01626e6c2f40737569607241696072695264752f606565">[email protected]</a>("test")' |
|
524 | + @Boolean[true] |
|
525 | +[arthas@19856]$ |
|
526 | +# 查看添加的字符 |
|
527 | +[arthas@19856]$ ognl '@com.Arthas@hashSet' | grep test |
|
528 | + @String[test], |
|
529 | +[arthas@19856]$ |
|
530 | +</code></pre> |
|
531 | +<p><code>ognl</code> 可以做很多事情,可以参考 <a href="https://github.com/alibaba/arthas/issues/71" target="_blank">ognl 表达式特殊用法( https://github.com/alibaba/arthas/issues/71 )</a>。</p> |
|
532 | +<h2 id="49-程序有没有问题">4.9 程序有没有问题</h2> |
|
533 | +<h3 id="491-运行较慢耗时较长">4.9.1 运行较慢、耗时较长</h3> |
|
534 | +<p>使用 <strong>trace</strong> 命令可以跟踪统计方法耗时</p> |
|
535 | +<p>这次换一个模拟代码。一个最基础的 Springboot 项目(当然,不想 Springboot 的话,你也可以直接在 UserController 里 main 方法启动)控制层 <code>getUser</code> 方法调用了 <code>userService.get(uid);</code>,这个方法中分别进行<code>check</code>、<code>service</code>、<code>redis</code>、<code>mysql</code>操作。</p> |
|
536 | +<pre><code class="language-java">@RestController |
|
537 | +@Slf4j |
|
538 | +public class UserController { |
|
539 | + |
|
540 | + @Autowired |
|
541 | + private UserServiceImpl userService; |
|
542 | + |
|
543 | + @GetMapping(value = "/user") |
|
544 | + public HashMap<String, Object> getUser(Integer uid) throws Exception { |
|
545 | + // 模拟用户查询 |
|
546 | + userService.get(uid); |
|
547 | + HashMap<String, Object> hashMap = new HashMap<>(); |
|
548 | + hashMap.put("uid", uid); |
|
549 | + hashMap.put("name", "name" + uid); |
|
550 | + return hashMap; |
|
551 | + } |
|
552 | +} |
|
553 | +</code></pre> |
|
554 | +<p>模拟代码 Service:</p> |
|
555 | +<pre><code class="language-java">@Service |
|
556 | +@Slf4j |
|
557 | +public class UserServiceImpl { |
|
558 | + |
|
559 | + public void get(Integer uid) throws Exception { |
|
560 | + check(uid); |
|
561 | + service(uid); |
|
562 | + redis(uid); |
|
563 | + mysql(uid); |
|
564 | + } |
|
565 | + |
|
566 | + public void service(Integer uid) throws Exception { |
|
567 | + int count = 0; |
|
568 | + for (int i = 0; i < 10; i++) { |
|
569 | + count += i; |
|
570 | + } |
|
571 | + log.info("service end {}", count); |
|
572 | + } |
|
573 | + |
|
574 | + public void redis(Integer uid) throws Exception { |
|
575 | + int count = 0; |
|
576 | + for (int i = 0; i < 10000; i++) { |
|
577 | + count += i; |
|
578 | + } |
|
579 | + log.info("redis end {}", count); |
|
580 | + } |
|
581 | + |
|
582 | + public void mysql(Integer uid) throws Exception { |
|
583 | + long count = 0; |
|
584 | + for (int i = 0; i < 10000000; i++) { |
|
585 | + count += i; |
|
586 | + } |
|
587 | + log.info("mysql end {}", count); |
|
588 | + } |
|
589 | + |
|
590 | + public boolean check(Integer uid) throws Exception { |
|
591 | + if (uid == null || uid < 0) { |
|
592 | + log.error("uid不正确,uid:{}", uid); |
|
593 | + throw new Exception("uid不正确"); |
|
594 | + } |
|
595 | + return true; |
|
596 | + } |
|
597 | +} |
|
598 | + |
|
599 | +</code></pre> |
|
600 | +<p>运行 Springboot 之后,使用 **trace== ** 命令开始检测耗时情况。</p> |
|
601 | +<pre><code class="language-shell">[arthas@6592]$ trace com.UserController getUser |
|
602 | +</code></pre> |
|
603 | +<p>访问接口 <code>/getUser</code> ,可以看到耗时信息,看到 <code>com.UserServiceImpl:get() </code>方法耗时较高。 |
|
604 | +<img src="https://cdn.debug.group/git/2019/1571208153793.png" alt="" /></p> |
|
605 | +<p>继续跟踪耗时高的方法,然后再次访问。</p> |
|
606 | +<pre><code class="language-shell">[arthas@6592]$ trace com.UserServiceImpl get |
|
607 | +</code></pre> |
|
608 | +<p><img src="https://cdn.debug.group/git/2019/1571208245597.png" alt="" /></p> |
|
609 | +<p>很清楚的看到是 <code>com.UserServiceImpl </code>的 <code>mysql </code>方法耗时是最高的。</p> |
|
610 | +<pre><code class="language-java">Affect(class-cnt:1 , method-cnt:1) cost in 31 ms. |
|
611 | +`---ts=2019-10-16 14:40:10;thread_name=http-nio-8080-exec-8;id=1f;is_daemon=true;priority=5;TCCL=org.springframework.boot.web.embedded.tomcat.TomcatEmbeddedWebappClassLoader@23a918c7 |
|
612 | + `---[6.792201ms] com.UserServiceImpl:get() |
|
613 | + +---[0.008ms] com.UserServiceImpl:check() #17 |
|
614 | + +---[0.076ms] com.UserServiceImpl:service() #18 |
|
615 | + +---[0.1089ms] com.UserServiceImpl:redis() #19 |
|
616 | + `---[6.528899ms] com.UserServiceImpl:mysql() #20 |
|
617 | +</code></pre> |
|
618 | +<h3 id="492-统计方法耗时">4.9.2 统计方法耗时</h3> |
|
619 | +<p>使用 <strong>monitor</strong> 命令监控统计方法的执行情况。</p> |
|
620 | +<p>每5秒统计一次 <code>com.UserServiceImpl</code> 类的 <code>get</code> 方法执行情况。</p> |
|
621 | +<pre><code class="language-shell">monitor -c 5 com.UserServiceImpl get |
|
622 | +</code></pre> |
|
623 | +<p><img src="https://cdn.debug.group/git/2019/1571210158018.png" alt="" /></p> |
|
624 | +<h2 id="410-想观察方法信息">4.10 想观察方法信息</h2> |
|
625 | +<p>下面的示例用到了文章的前两个模拟代码。</p> |
|
626 | +<h3 id="4101-观察方法的入参出参信息">4.10.1 观察方法的入参出参信息</h3> |
|
627 | +<p>使用 <strong>watch</strong> 命令轻松查看输入输出参数以及异常等信息。</p> |
|
628 | +<pre><code class="language-shell"> USAGE: |
|
629 | + watch [-b] [-e] [-x <value>] [-f] [-h] [-n <value>] [-E] [-M <value>] [-s] class-pattern method-pattern express [condition-express] |
|
630 | + |
|
631 | + SUMMARY: |
|
632 | + Display the input/output parameter, return object, and thrown exception of specified method invocation |
|
633 | + The express may be one of the following expression (evaluated dynamically): |
|
634 | + target : the object |
|
635 | + clazz : the object's class |
|
636 | + method : the constructor or method |
|
637 | + params : the parameters array of method |
|
638 | + params[0..n] : the element of parameters array |
|
639 | + returnObj : the returned object of method |
|
640 | + throwExp : the throw exception of method |
|
641 | + isReturn : the method ended by return |
|
642 | + isThrow : the method ended by throwing exception |
|
643 | + #cost : the execution time in ms of method invocation |
|
644 | + Examples: |
|
645 | + watch -b org.apache.commons.lang.StringUtils isBlank params |
|
646 | + watch -f org.apache.commons.lang.StringUtils isBlank returnObj |
|
647 | + watch org.apache.commons.lang.StringUtils isBlank '{params, target, returnObj}' -x 2 |
|
648 | + watch -bf *StringUtils isBlank params |
|
649 | + watch *StringUtils isBlank params[0] |
|
650 | + watch *StringUtils isBlank params[0] params[0].length==1 |
|
651 | + watch *StringUtils isBlank params '#cost>100' |
|
652 | + watch -E -b org\.apache\.commons\.lang\.StringUtils isBlank params[0] |
|
653 | + |
|
654 | + WIKI: |
|
655 | + https://alibaba.github.io/arthas/watch |
|
656 | +</code></pre> |
|
657 | +<p>常用操作:</p> |
|
658 | +<pre><code class="language-shell"># 查看入参和出参 |
|
659 | +$ watch com.Arthas addHashSet '{params[0],returnObj}' |
|
660 | +# 查看入参和出参大小 |
|
661 | +$ watch com.Arthas addHashSet '{params[0],returnObj.size}' |
|
662 | +# 查看入参和出参中是否包含 'count10' |
|
663 | +$ watch com.Arthas addHashSet '{params[0],returnObj.contains("count10")}' |
|
664 | +# 查看入参和出参,出参 toString |
|
665 | +$ watch com.Arthas addHashSet '{params[0],returnObj.toString()}' |
|
666 | +</code></pre> |
|
667 | +<p>查看入参出参。</p> |
|
668 | +<p><img src="https://cdn.debug.group/git/2019/1571196483469.png" alt="" /></p> |
|
669 | +<p>查看返回的异常信息。</p> |
|
670 | +<h3 id="4102-观察方法的调用路径">4.10.2 观察方法的调用路径</h3> |
|
671 | +<p>使用 <strong>stack</strong>命令查看方法的调用信息。</p> |
|
672 | +<pre><code class="language-shell"># 观察 类com.UserServiceImpl的 mysql 方法调用路径 |
|
673 | +stack com.UserServiceImpl mysql |
|
674 | +</code></pre> |
|
675 | +<p><img src="https://cdn.debug.group/git/2019/1571210706602.png" alt="" /></p> |
|
676 | +<h3 id="4103-方法调用时空隧道">4.10.3 方法调用时空隧道</h3> |
|
677 | +<p>使用 <strong>tt</strong> 命令记录方法执行的详细情况。</p> |
|
678 | +<blockquote> |
|
679 | +<p><strong>tt</strong> 命令方法执行数据的时空隧道,记录下指定方法每次调用的入参和返回信息,并能对这些不同的时间下调用进行观测 。</p> |
|
680 | +</blockquote> |
|
681 | +<p>常用操作:</p> |
|
682 | +<p>开始记录方法调用信息:tt -t com.UserServiceImpl check</p> |
|
683 | +<p><img src="https://cdn.debug.group/git/2019/1571212007249.png" alt="" /></p> |
|
684 | +<p>可以看到记录中 INDEX=1001 的记录的 IS-EXP = true ,说明这次调用出现异常。</p> |
|
685 | +<p>查看记录的方法调用信息: tt -l</p> |
|
686 | +<p><img src="https://cdn.debug.group/git/2019/1571212080071.png" alt="" /></p> |
|
687 | +<p>查看调用记录的详细信息(-i 指定 INDEX): tt -i 1001</p> |
|
688 | +<p><img src="https://cdn.debug.group/git/2019/1571212151064.png" alt="" /></p> |
|
689 | +<p>可以看到 INDEX=1001 的记录的异常信息。</p> |
|
690 | +<p>重新发起调用,使用指定记录,使用 -p 重新调用。</p> |
|
691 | +<pre><code class="language-java">tt -i 1001 -p |
|
692 | +</code></pre> |
|
693 | +<p><img src="https://cdn.debug.group/git/2019/1571212227058.png" alt="" /></p> |
|
694 | +<h2 id="45-火焰图分析">4.5. 火焰图分析</h2> |
|
695 | +<p>最近 Arthas 性能分析工具上线了<strong>火焰图</strong>分析功能,Arthas 使用 <strong>async-profiler</strong> 生成 CPU/内存火焰图进行性能分析,弥补了之前内存分析的不足。在 Arthas 上使用还是比较方便的。</p> |
|
696 | +<p><strong><code>profiler</code></strong> 命令支持生成应用热点的火焰图。本质上是通过不断的采样,然后把收集到的采样结果生成火焰图。</p> |
|
697 | +<p><strong><code>profiler</code></strong> 命令基本运行结构是 <strong><code>profiler action [actionArg]</code></strong></p> |
|
698 | +<h3 id="451使用案例"><strong>4.5.1.使用案例</strong></h3> |
|
699 | +<p><strong>开启 prifilter</strong></p> |
|
700 | +<p>默认情况下,生成的是cpu的火焰图,即event为<code>cpu</code>。可以用<code>--event</code>参数来指定,使用 start 命令开始捕获信息。</p> |
|
701 | +<pre><code class="language-shell">$ profiler start |
|
702 | +Started [cpu] profiling |
|
703 | +</code></pre> |
|
704 | +<p>获取已采集的sample的数量</p> |
|
705 | +<pre><code class="language-shell">$ profiler getSamples |
|
706 | +23 |
|
707 | +</code></pre> |
|
708 | +<p>查看 profiler状态,可以查看当前 profiler 在采样哪种 <code>event </code>和进行的采样时间。</p> |
|
709 | +<pre><code class="language-shell">$ profiler status |
|
710 | + |
|
711 | +[cpu] profiling is running for 4 seconds |
|
712 | +</code></pre> |
|
713 | +<p><strong>停止profiler</strong></p> |
|
714 | +<p>生成svg格式火焰图</p> |
|
715 | +<pre><code class="language-shell">$ profiler stop |
|
716 | +profiler output file: /tmp/demo/arthas-output/20191125-135546.svg |
|
717 | +OK |
|
718 | +</code></pre> |
|
719 | +<p>默认情况下,生成的结果保存到应用的<code>工作目录</code>下的<code>arthas-output</code>目录。可以通过 <code>--file</code>参数来指定输出结果路径。</p> |
|
720 | +<p>比如:</p> |
|
721 | +<pre><code class="language-shell">$ profiler stop --file /tmp/output.svg |
|
722 | +</code></pre> |
|
723 | +<p><strong>HTML 格式输出</strong></p> |
|
724 | +<p>默认情况下,结果文件是<code>svg</code>格式,如果想生成<code>html</code>格式,可以用<code>--format</code>参数指定:$ profiler stop --format html</p> |
|
725 | +<p><strong>查看 profilter</strong></p> |
|
726 | +<p>默认情况下,arthas使用3658端口,则可以打开: http://localhost:3658/arthas-output/ 查看到<code>arthas-output</code>目录下面的profiler结果:</p> |
|
727 | +<p><img src="https://cdn.debug.group/img/23/10/151226645.webp" alt="" /></p> |
|
728 | +<p>点击可以查看具体的结果:<strong>火焰图里,横条越长,代表使用的越多,从下到上是调用堆栈信息</strong></p> |
|
729 | +<p><img src="https://cdn.debug.group/img/23/10/151303153.webp" alt="" /></p> |
|
730 | +<p>**profilter 自持多种分析方式,**常见的有 event: cpu|alloc|lock|cache-misses etc. 比如要分析内存使用情况。</p> |
|
731 | +<p>$ profiler start --event alloc</p> |
|
732 | +<h3 id="452-复杂命令">4.5.2. 复杂命令</h3> |
|
733 | +<p>比如开始采样:</p> |
|
734 | +<pre><code class="language-shell">profiler execute 'start' |
|
735 | +</code></pre> |
|
736 | +<p>停止采样,并保存到指定文件里:</p> |
|
737 | +<pre><code class="language-shell">profiler execute 'stop,file=/tmp/result.svg' |
|
738 | +</code></pre> |
|
739 | +<p>文中代码已经上传到 <a href="https://github.com/niumoo/lab-notes/" target="_blank">Github</a>。</p> |
|
740 | + |
|
741 | + </div> |
|
742 | +</div> |
|
743 | + |
|
744 | +</html> |
|
... | ... | \ No newline at end of file |