当前位置：首页 > 科技 > 软件

接口响应慢该如何排查

来源：责编：时间：2023-10-23 17:05:59 261观看

导读不知道大家有没有遇到这种情况，接口业务逻辑写完后，用 postman 一调，发现接口响应时间好长，不得不对接口进行优化。但是此时接口的代码往往逻辑比较复杂，调用层次也比较多，很难定位到耗时较长的代码块。遇到这种情况大家都

不知道大家有没有遇到这种情况，接口业务逻辑写完后，用 postman 一调，发现接口响应时间好长，不得不对接口进行优化。但是此时接口的代码往往逻辑比较复杂，调用层次也比较多，很难定位到耗时较长的代码块。

遇到这种情况大家都是如何定位耗时代码块的呢？

我看到很多人都是直接用System.currentTimeMillis()对代码进行埋点：

public static void main(String[] args) {    Long startTime = System.currentTimeMillis();    exec();    Long endTime = System.currentTimeMillis();    log.info("exec 方法执行耗时:{}ms", endTime - startTime);}

或者用StopWatch打印方法耗时：

public static void main(String[] args) throws InterruptedException {    StopWatch stopWatch = new StopWatch();    stopWatch.start("exec");    exec();    stopWatch.stop();    System.out.println(stopWatch.prettyPrint());}

这两种方法本质上是一样的，都是通过手动在代码块上进行埋点，打印出方法的耗时，该方法不仅费时费力，而且对代码有侵入，修复问题后删掉代码还是一个麻烦事。

下面介绍如果通过Arthas定位耗时代码块。

Arthas 简介

Arthas是阿里开源的一款 Java 诊断工具，可以在无需重启 JVM 的情况下，实时查看应用 load、内存、gc、线程等状态信息，还能实时查看方法调用入参、出参、方法调用耗时等。

Arthas 快速开始

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

$ curl -O https://arthas.aliyun.com/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 version: 3.6.9[INFO] Found existing java process, please choose one and input the serial number of the process, eg : 1. Then hit ENTER.* [1]: 12512 com.huangxy.springstudy.SpringStudyApplication  [2]: 12511 org.jetbrains.jps.cmdline.Launcher

然后可以选择我们需要 attach 的 java 进程，这里我们选择 1，然后按回车。Arthas 会 attach 到目标进程上，并输出日志：

[INFO] arthas home: /Users/huangxiaoyu/.arthas/lib/3.6.9/arthas[INFO] Try to attach process 12512[INFO] Attach process 12512 success.[INFO] arthas-client connect 127.0.0.1 3658  ,---.  ,------. ,--------.,--.  ,--.  ,---.   ,---. /  O  / |  .--. ''--.  .--'|  '--'  | /  O  / '   .-'|  .-.  ||  '--'.'   |  |   |  .--.  ||  .-.  |`.  `-.|  | |  ||  |/  /    |  |   |  |  |  ||  | |  |.-'    |`--' `--'`--' '--'   `--'   `--'  `--'`--' `--'`-----'wiki       https://arthas.aliyun.com/doctutorials  https://arthas.aliyun.com/doc/arthas-tutorials.htmlversion    3.6.9main_class com.huangxy.springstudy.SpringStudyApplicationpid        12512time       2023-07-25 09:14:22

到这里，Arthas 已经 attach 到我们的目标进程上了，我们尝试使用dashboad命令，查看进程的信息：

$ dashboardID   NAME                           GROUP          PRIORITY  STATE     %CPU      DELTA_TIME TIME      INTERRUPT DAEMON36   DestroyJavaVM                  main           5         RUNNABLE  0.0       0.000      0:1.748   false     false-1   C1 CompilerThread3             -              -1        -         0.0       0.000      0:0.761   false     true-1   VM Periodic Task Thread        -              -1        -         0.0       0.000      0:0.237   false     true24   http-nio-8081-exec-1           main           5         WAITING   0.0       0.000      0:0.098   false     true-1   VM Thread                      -              -1        -         0.0       0.000      0:0.071   false     true25   http-nio-8081-exec-2           main           5         WAITING   0.0       0.000      0:0.055   false     true54   arthas-NettyHttpTelnetBootstra system         5         RUNNABLE  0.0       0.000      0:0.054   false     true-1   GC task thread#8 (ParallelGC)  -              -1        -         0.0       0.000      0:0.043   false     true-1   GC task thread#1 (ParallelGC)  -              -1        -         0.0       0.000      0:0.043   false     true-1   GC task thread#7 (ParallelGC)  -              -1        -         0.0       0.000      0:0.042   false     true-1   GC task thread#6 (ParallelGC)  -              -1        -         0.0       0.000      0:0.042   false     true-1   GC task thread#0 (ParallelGC)  -              -1        -         0.0       0.000      0:0.042   false     true-1   GC task thread#9 (ParallelGC)  -              -1        -         0.0       0.000      0:0.042   false     true-1   GC task thread#2 (ParallelGC)  -              -1        -         0.0       0.000      0:0.042   false     true-1   GC task thread#3 (ParallelGC)  -              -1        -         0.0       0.000      0:0.042   false     true-1   GC task thread#5 (ParallelGC)  -              -1        -         0.0       0.000      0:0.042   false     true-1   GC task thread#4 (ParallelGC)  -              -1        -         0.0       0.000      0:0.042   false     trueMemory                    used     total    max     usage    GCheap                      83M      432M     7282M   1.14%    gc.ps_scavenge.count           4ps_eden_space             72M      212M     2688M   2.69%    gc.ps_scavenge.time(ms)        24ps_survivor_space         0K       21504K   21504K  0.00%    gc.ps_marksweep.count          2ps_old_gen                10M      199M     5461M   0.20%    gc.ps_marksweep.time(ms)       61nonheap                   53M      56M      -1      94.71%code_cache                6M       7M       240M    2.87%metaspace                 40M      43M      -1      94.45%compressed_class_space    5M       5M       1024M   0.53%direct                    16K      16K      -       100.01%mapped                    0K       0K       -       0.00%Runtimeos.name                                                      Mac OS Xos.version                                                   13.0.1java.version                                                 1.8.0_351java.home                                                    /Library/Java/JavaVirtualMachines/jdk1.8.0_351.jdk/Contents/                                                             Home/jresystemload.average                                           3.80processors                                                   12

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

使用 Trace 命令统计方法耗时

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

比如下面接口：

@RestControllerpublic class HelloController {    @GetMapping("/test")    public String test() throws InterruptedException {       one();       two();       return "hello";    }    private void two() throws InterruptedException {        Thread.sleep(20);        three();    }    private void three() throws InterruptedException {        Thread.sleep(1000);    }    private void one() throws InterruptedException {        Thread.sleep(100);    }}

启动Arthas进程，并 attach 到我们的 springboot 项目上，接着使用trace命令跟踪方法的调用情况：

$ trace com.huangxy.springstudy.controller.HelloController test

trace方法第一个参数是要 attach 的类的路径，第二个参数是方法名称，接着我们调用一遍接口，就能看到 hello 方法的调用堆栈及其耗时

可以看到，这里耗时比较严重的是tow()方法，花了 1029ms，占了 90.73% 的比重。

不过需要注意的是，trace 命令只会 trace 匹配到的函数里的子调用，并不会向下 trace 多层，如果需要 trace 多层，可以用正则匹配多个函数，如：

$ trace -E com.huangxy.springstudy.controller.HelloController test|two

这下更清晰的定位到，导致耗时过长的方法是three()方法，定位到方法后，针对性的优化耗时代码块即可。

本文链接：http://www.28at.com/showinfo-26-14612-0.html接口响应慢该如何排查

声明：本网页内容旨在传播知识，若有侵权等问题请及时与本网联系，我们将在第一时间删除处理。邮件：2376512515@qq.com

上一篇： Fiber Golang：Golang中的强大Web框架

下一篇：当年很流行，现在已经淘汰的前端技术，请不要再继续学了！

标签：

热门焦点

帅气纯真少年！日本最帅初中生选美冠军出炉

日本第一帅哥初一生选美大赛冠军现已正式出炉，冠军是来自千叶县的宗田悠良。日本一直热衷于各种选美大赛，从“最美JK”起到“最美女星&r
Automa-通过连接块来自动化你的浏览器

1、前言通过浏览器插件可实现自动化脚本的录制与编写，具有代表性的工具就是：Selenium IDE、Katalon Recorder，对于简单的业务来说可快速实现自动化的上手工作。Selenium IDEKat
微信语音大揭秘：为什么禁止转发？

大家好，我是你们的小米。今天，我要和大家聊一个有趣的话题：为什么微信语音不可以转发？这是一个我们经常在日常使用中遇到的问题，也是一个让很多人好奇的问题。让我们一起来揭开这
WebRTC.Net库开发进阶，教你实现屏幕共享和多路复用！

WebRTC.Net库：让你的应用更亲民友好，实现视频通话无痛接入！除了基本用法外，还有一些进阶用法可以更好地利用该库。自定义 STUN/TURN 服务器配置WebRTC.Net 默认使用 Google 的
为什么你不应该使用Div作为可点击元素

按钮是为任何网络应用程序提供交互性的最常见方式。但我们经常倾向于使用其他HTML元素，如 div span 等作为 clickable 元素。但通过这样做，我们错过了许多内置浏览器的功能。
大厂卷向扁平化

来源：新熵作者丨南枝编辑丨月见大厂职级不香了。俗话说，兵无常势，水无常形，互联网企业调整职级体系并不稀奇。7月13日，淘宝天猫集团启动了近年来最大的人力制度改革，目前已形成一
超级标准版旗舰！iQOO 11S全球首发iQOO超算独显芯片

上半年已接近尾声，截至目前各大品牌旗下的顶级旗舰都已悉数亮相，而下半年即将推出的顶级旗舰已经成为了数码圈爆料的主流，其中就包括全新的iQOO 11S系
质感不错！OPPO K11渲染图曝光：旗舰IMX890传感器首次下放

一直以来，OPPO K系列机型都保持着较为均衡的产品体验，历来都是2K价位的明星机型，去年推出的OPPO K10和OPPO K10 Pro两款机型凭借各自的出色配置，堪称有
上海举办人工智能大会活动，建设人工智能新高地

人工智能大会在上海浦江两岸隆重拉开帷幕，人工智能新技术、新产品、新应用、新理念集中亮相。8月30日晚，作为大会的特色活动之一的上海人工智能发展盛典人工