使用arthas排查请求超时问题

现象

? ? ? ? 客户端调用服务时间出现偶尔超时现象

排查

? ? ? ? 因为服务已开启arthas，使用trace命令监控

$ trace com.lizz slowfun '#cost > 1000' -n 10

• ?监控com.lizz类中的slowfun方法，输出用时超过1000ms的记录，记录10条

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
    `---[1112.033735ms] com.lizz:slowfun()
        +---[0.006783ms] java.util.Random:nextInt()
        +---[1111.852594ms] com.lizz:go()
        `---[0.05447ms] com.lizz:print()

• ?记录到com.lizz:go方法用时超过1000ms，继续监控

$ trace com.lizz go '#cost > 1000' -n 10

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
    `---[1110.033735ms] com.lizz:go()
        `---[1110.852594ms] com.lizz.UserMapper:select()
        `---[0.05447ms] com.lizz:print()

• 可以看最终耗时在 com.lizz.UserMapper:select()方法中
• 初步确定为查询数据耗时

排查数据库负载发现，数据库负载存在突刺现象，每5分钟会出现高负载情况。

判断为数据库负载导致的的查询慢问题导致请求响应慢。

修复

解决数据库突刺问题后修复。

?