在线界面响应时间过长，如何排除故障？

不知道你是否遇到过这种情况。写完界面业务逻辑后，我用postman来调整。我发现界面响应时间很长，所以必须对界面进行优化。但此时接口代码往往逻辑比较复杂，调用层次较多，很难定位耗时较长的代码块

这种情况下如何定位耗时的代码块呢？

我看到很多人直接用System.currentTimeMillis()来埋代码

公共 静态 void main（字符串[]参数） {
长startTime = System.currentTimeMillis ();
 exec();
 Long endTime = System.currentTimeMillis();
 www.sychzs.cn("exec 方法执行时间: {}ms", endTime - startTime ) ;
}

或者秒表打印方式比较耗时

public static void main（字符串[]参数） 抛出 InterruptedException {
 StopWatch stopWatch = new StopWatch();
 stopWatch.start("exec");
 exec();
 stop Watch.stop(); 
  System.out.println(stopWatch.prettyPrint());
}

两种方法本质上是一样的。他们都是手动在代码块中埋点并打印出耗时的方法。这种方法不仅费时费力，而且对代码有侵入性。解决问题后删除代码。还是一件麻烦事

下面介绍如何通过Arthas定位耗时的代码块

阿尔萨斯简介

Arthas是阿里巴巴开发的开源java诊断工具。它可以实时查看应用程序负载、内存、gc、线程等状态信息，而无需重新启动JVM。它还可以实时查看方法调用。参数、参数、方法调用时间等等

阿尔萨斯快速入门

直接下载Arthasjar包，然后用java -jar命令启动

$curl -O https://www.sychzs.cn/arthas-boot.jar
$java -jar arthas-boot.jar

Arthas启动时，会打印出当前运行的java进程

$ java -jar arthas-boot.jar
[INFO] JAVA_HOME：/Library/Java/JavaVirtualMachines/jdk1.8.0_351.jdk/Contents/Home/jre
[INFO] arthas-boot 版本： 3.6.9
[INFO] 找到已有的java进程，请选择一个并输入该进程的序号，例如：1.然后按ENTER键。
* [1]: 12512 com.huangxy。 springstudy.SpringStudyApplication
[2]：12511 org.jetbrains.jps.cmdline.Launcher

然后我们就可以选择我们需要附加的java进程了。这里我们选择1并按Enter键。 Arthas 将附加到目标进程并输出 log:

[INFO] arthas home:/Users/huangxiaoyu/.arthas/lib/3.6.9/arthas
[INFO]尝试附加进程12512
[INFO]附加进程12512成功。
[信息] arthas-client 连接 127.0.0.1 3658
，---。 ，------。 ,--------.,--。 ,--。 ,---。 ,---.
 /  O   | .--. ''--。 .--'| '--'  | /  O   '   .-'
| .-. || '--'。'   | | | .--. || .-. |`。 `-.
| | | || | | | | | | || | | |.-'    |
`--'`--'`--' '--'   `--'   ` --'  `--'`--' `--'`-----'

wiki       https://www.sychzs.cn/doc
教程  https://www.sychzs.cn/doc/arthas-tutorials.html
版本    3.6.9
main_class com.huangxy.springstudy.SpringStudyApplication
pid        12512
时间       2023-07 -25 09:14:22

到这里，Arthas已经附加到我们的目标进程了，我们尝试使用dashboad，查看进程的信息

$仪表板
ID   名称                           组          优先级  状态     %CPU      DELTA_TIME TIME      中断守护进程
36                  主要           5         可运行  0.0       0.000      0:1.748   假          false
-1   C1 编译器线程3 -              -1        -         0.0       0.000      0:0.761   假     真
- 1   VM 定期任务 线程        -              -1        -         0.0       0.000      0:0.237   false     真
24   http-nio-8081-exec-1           主要           5         正在等待   0.0       0.000      0:0.098   假     true
-1   虚拟机线程                     -              -1        -         0.0       0.000      0:0.07 1    false     true
25   http-nio-8081-exec-2           主要           5         等待   0.0       0.000      0 ：0.055   假     真
54   arthas-NettyHttpTelnetBootstra 系统         5         可运行  0.0       0.000      0:0.054   false     true
-1   GC任务线程#8 (ParallelGC)  -              -1        -         0.0       0.000      0:0.043   false     true
 -1   GC任务线程#1（并行GC）  -              -1        -         0.0       0.000      0:0.043   false     true
- 1   GC 任务线程#7 （并行 GC）  -              -1        -         0.0       0.000      0:0.042   false true
-1   GC 任务线程#6 （并行 GC）  -             -1        -         0.0       0.000      0:0.042   假     true 
-1   GC 任务线程#0 （并行 GC）  -             -1        -         0.0       0.000 0:0.042   假     true
-1   GC任务线程#9 （并行GC）  -              -1        -         0.0       0.000      0 0:0.042   false     true
-1   GC 任务线程#2（并行 GC）  -              - 1        -         0.0       0.000      0:0.042false     true
-1   GC 任务线程#3 （并行 GC）  -              -1        -         0.0       0.000      0:0.042   false     true
-1   GC 任务线程#5（并行 GC）  -              -1        -         0.0 0.000      0:0.042   假     true
-1   GC任务线程#4（并行GC）  -              -1        -         0.0       0.000      0:0.042   false     true
内存                    已用     总计    最大     使用量    GC
堆                       83M      432M     7282M   1.14 %    www.sychzs.cn_scavenge.count           4
ps_eden_space             72M      212M     2688M   2.69%    www.sychzs.cn_scavenge.time(ms)        24
ps_survivor_space         0K       21504K   21504K  0.00%    www.sychzs.cn_marksweep.count          2
ps_old_gen                10M      1 99M     5461M   0.20%    气相色谱.ps_marksweep.time(ms)       61
nonheap                   53M      56M      -1      94.71%
code_cache                6M       7M       240M    2.87%
元空间                 40M      43M      -1      94.45%
压缩_class_空间    5M       5M       1024M   0.53%
直接                    16K      16K      -       100.01%
映射                    0K       0K     0K       0K       -       0.00%
运行时
www.sychzs.cn Mac OS X
os.version                                                  13.0.1
java.version                                                           1.8.0_351
java.home                                                    /Library/Java/JavaVirtualMachines/jdk1.8.0_351. jdk/Contents/
                                                             首页/jre
systemload.average                                           3.80
处理器                                                             12

可以看到dashboad命令会展示一个实时的数据面板，列出了我们平时比较关心的数据指标，如内存使用量，gc状态等

更多命令的使用，可以参考官网的命令列表

使用Trace命令统计方法运行

trace命令可以主动搜索class-pattern/method-pattern对应的方法调用路径，渲染并统计整个调用链路上的所有性能开销，并跟踪调用链路

例如以下界面

@RestController
publicclassHelloController{

  @GetMapping("/测试"  ? ? ; private void 两个 () 抛出 InterruptedException {
                      三();
 } 

 私人 void 三() 抛出 InterruptedException {                     Thread.sleep(1000);                        私人 空 一个()  抛出 InterruptedException {
              Thread.sleep(100); 
 }

}

启动Arthas进程，并附加到我们的springboot 项目，然后使用trace命令跟踪方法

$ 跟踪 com.huangxy.springstudy.controller.HelloController 测试

trace方法的第一个参数是要附加的类的路径，第二个参数是方法名称。然后我们调用一次接口，就可以看到hello方法的调用栈以及耗时

来源：huangxy