技术文章摘抄

✅线上接口如果响应很慢如何去排查定位问题呢？

典型回答

想要定位一个接口响应慢，有一个神器必备，那就是阿里巴巴推出的arthas，很快的就能定位到接口RT慢的问题，具体有一个案例，大家可以看下：

✅RT飙高问题排查过程

使用Arthas定位接口慢的步骤大致如下：

1、首先就是通过各种监控系统，发现慢的现象或者问题。我们明确的知道了具体是哪个接口慢了。然后才能开始分析。

2、安装arthas，arthas就是一个命令工具，他通过字节码插桩的方式来统计接口耗时的，很多公司的生产环境也都是可以用的，包括我司的生产环境都是可以用的，目前没发现什么副作用。

curl -L http://start.alibaba-inc.com/install.sh | sh

以上命令即可安装。

3、运行，比较简单，执行命令就行：

sh as.sh

4、查看接口耗时，这个就需要借助arthas的trace命令了，详见 https://arthas.aliyun.com/ 官网，trace命令的主要作用就是查看方法内部调用路径，并输出方法路径上的每个节点上耗时。

参数说明如下：

1686917575215-ab4d6089-ea23-4b4f-a887-c4dbf9104cf0.png

比如直接查看一次真实请求的耗时情况（例子来自官网，大家可以自己实践一下）：

$ trace demo.MathGame run
Press Q or Ctrl+C to abort.
Affect(class-cnt:1 , method-cnt:1) cost in 28 ms.
`---ts=2019-12-04 00:45:08;thread_name=main;id=1;is_daemon=false;priority=5;TCCL=sun.misc.Launcher$AppClassLoader@3d4eac69
    `---[0.617465ms] demo.MathGame:run()
        `---[0.078946ms] demo.MathGame:primeFactors() #24 [throws Exception]

`---ts=2019-12-04 00:45:09;thread_name=main;id=1;is_daemon=false;priority=5;TCCL=sun.misc.Launcher$AppClassLoader@3d4eac69
    `---[1.276874ms] demo.MathGame:run()
        `---[0.03752ms] demo.MathGame:primeFactors() #24 [throws Exception]

如果方法调用的次数很多，那么可以用-n参数指定捕捉结果的次数。比如下面的例子里，捕捉到一次调用就退出命令：

$ trace demo.MathGame run -n 1
Press Q or Ctrl+C to abort.
Affect(class-cnt:1 , method-cnt:1) cost in 20 ms.
`---ts=2019-12-04 00:45:53;thread_name=main;id=1;is_daemon=false;priority=5;TCCL=sun.misc.Launcher$AppClassLoader@3d4eac69
    `---[0.549379ms] demo.MathGame:run()
        +---[0.059839ms] demo.MathGame:primeFactors() #24
        `---[0.232887ms] demo.MathGame:print() #25

Command execution times exceed limit: 1, so command will exit. You can set it with -n option.

也可以做一些过滤，比如耗时超过一定时长的再进行观测：

$ trace demo.MathGame run '#cost > 1000'
Press Ctrl+C to abort.
Affect(class-cnt:1 , method-cnt:1) cost in 41 ms.
`---ts=2018-12-04 01:12:02;thread_name=main;id=1;is_daemon=false;priority=5;TCCL=sun.misc.Launcher$AppClassLoader@3d4eac69
    `---[12.033735ms] demo.MathGame:run()
        +---[0.006783ms] java.util.Random:nextInt()
        +---[11.852594ms] demo.MathGame:primeFactors()
        `---[0.05447ms] demo.MathGame:print()

以上就是只观测耗时超过1000Ms的请求。

5、分析耗时。

如下面一个trace的输出信息，可以看到，一个接口整体耗时在265ms左右，但是其中有221ms是耗时在com.alibaba.fin.pricing.*.ExercisePriceDomainService:queryMatchedEffectiveExercisePrice() #167 这里的，所以就可以直接去看代码，分析下这里为什么有耗时了。

[arthas@1658]$ trace com.alibaba.fin.pricing.**.PriceCalculateService trial '#cost > 50' -n 3
Press Q or Ctrl+C to abort.
Affect(class count: 1 , method count: 1) cost in 427 ms, listenerId: 6
`---ts=2021-11-08 15:10:24;thread_name=HSFBizProcessor-DEFAULT-8-thread-224;id=2d7c1;is_daemon=true;priority=10;TCCL=com.taobao.pandora.boot.loader.LaunchedURLClassLoader@783e6358;trace_id=2132e43116363554229592404e58b8;rpc_id=9.40.6
    `---[264.85838ms] com.alibaba.fin.pricing.**.service.PriceCalculateService:trial()
        +---[0.012009ms] com.alibaba.fin.pricing.**.request.PriceCalculateRequest:getTenant() #95
        +---[0.001564ms] com.alibaba.fin.pricing.**.request.PriceCalculateRequest:getProduct() #96
        ...
        ...
        ...
        +---[221.884809ms] com.alibaba.fin.pricing.*.ExercisePriceDomainService:queryMatchedEffectiveExercisePrice() #167
        +---[0.002242ms] com.alibaba.fin.pricing.**.service.PriceQueryRequest:<init>() #170
        `---[0.012586ms] com.alibaba.fin.pricing.**.service.PriceCalculateService:getTieredPrice() #170

6、耗时优化，在定位到具体耗时的代码时，就可以分析了，是请求执行慢了，还是SQL慢了，还是哪里慢了，然后就想办法优化：

https://www.yuque.com/hollis666/xkm7k3/ifuuagaqo3yd8vqb

https://www.yuque.com/hollis666/xkm7k3/mgpczmz7la99dkft

https://www.yuque.com/hollis666/xkm7k3/zhfa5g

原文: https://www.yuque.com/hollis666/xkm7k3/seg25uzc7ck89kkn