首页 > 其他分享 >arthas定位接口的耗时排查问题

arthas定位接口的耗时排查问题

时间:2024-05-14 16:22:41浏览次数:28  
标签:xxxx 排查 0.00% cashier 耗时 +--- ms arthas com

下载Arthas的jar包

https://arthas.aliyun.com/

image

上传jar包到你的服务器启动

启动 arthas
在命令行下面执行(使用和目标进程一致的用户启动,否则可能 attach 失败):


curl -O https://arthas.aliyun.com/arthas-boot.jar
java -jar arthas-boot.jar

执行该程序的用户需要和目标进程具有相同的权限。比如以admin用户来执行:sudo su admin && java -jar arthas-boot.jar 或 sudo -u admin -EH java -jar arthas-boot.jar。
如果 attach 不上目标进程,可以查看~/logs/arthas/ 目录下的日志。
如果下载速度比较慢,可以使用 aliyun 的镜像:java -jar arthas-boot.jar --repo-mirror aliyun --use-http
java -jar arthas-boot.jar -h 打印更多参数信息。

选择你要排查的JAVA运行的服务

image

监控成功就进入

image

找到你代码里面的耗时比较慢的接口

例如:
 @PostMapping("/createOrder")
    @Override
    public Result<Object> createOrder(@RequestBody PreOrderBusinessOrderRequest requestBody) 

image

执行Arthas的监控命令--监控这个接口

监控方法-----整体耗时 monitor命令

monitor -c 5 com.xxxx.cashier.payment.interfaces.service.PaymentServiceController create

监控方法-----整体耗时 monitor命令得到结果

Press Q or Ctrl+C to abort.
Affect(class count: 1 , method count: 1) cost in 835 ms, listenerId: 1
 timestamp                           class                                                method                                                total             success          fail              avg-rt(ms)        fail-rate        
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
 2024-05-14 10:50:06                 com.xxxx.cashier.payment.interfaces.serv  create                                                1                 1                0                 5732.03           0.00%            
                                     ice.PaymentServiceController                                                                                                                                                                       

 timestamp                           class                                                method                                                total             success          fail              avg-rt(ms)        fail-rate        
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
 2024-05-14 10:50:15                 com.xxxx.cashier.payment.interfaces.serv  create                                                0                 0                0                 0.00              0.00%            
                                     ice.PaymentServiceController                                                                                                                                             

监控方法-----每行执行结果耗时 trace 命令

trace  com.xxxxx.cashier.payment.interfaces.service.PaymentServiceController create

监控方法-----每行执行结果耗时 trace 命令执行结果

Press Q or Ctrl+C to abort.
Affect(class count: 1 , method count: 1) cost in 178 ms, listenerId: 2
---ts=2024-05-14 10:52:27;thread_name=http-nio-8291-exec-19;id=74;is_daemon=true;priority=5;TCCL=org.springframework.boot.web.embedded.tomcat.TomcatEmbeddedWebappClassLoader@592cb470 ---[6373.19803ms] com.xxxx.platform.cashier.payment.interfaces.service.PaymentServiceController:create()
+---[0.00% 0.155539ms ] com.xxxx.platform.cashier.domain.model.CashierPayment:setStateId() #38
+---[0.00% 0.020813ms ] com.xxxx.platform.cashier.domain.model.CashierPayment:getPhoneNo() #39
+---[0.00% 0.020437ms ] com.xxxx.platform.cashier.domain.model.CashierPayment:setCreator() #39
+---[0.00% 0.021332ms ] com.xxxx.platform.cashier.domain.model.CashierPayment:getUserId() #40
+---[0.00% 0.019115ms ] com.xxxx.platform.cashier.domain.model.CashierPayment:setCreatorId() #40
+---[99.99% 6372.41672ms ]com.xxxx.platform.cashier.payment.application.PaymentService:order() #43
+---[0.00% 0.027684ms ] com.xxxx.common.domain.model.Result:ok() #48
`---[0.00% 0.01374ms ] com.xxxx.common.domain.model.Result:setResponse() #49

得到结果:-[99.99% 6372.41672ms ]com.xxxx.platform.cashier.payment.application.PaymentService:order()

方法里面嵌套的这个方法调取耗时---继续追踪

[arthas@1711210]$ trace com.xxxx.platform.cashier.payment.application.impl.PaymentServiceImpl order

PaymentServiceImpl order 的耗时追踪

Press Q or Ctrl+C to abort.
Affect(class count: 2 , method count: 2) cost in 453 ms, listenerId: 3
`---ts=2024-05-14 10:54:32;thread_name=http-nio-8291-exec-22;id=77;is_daemon=true;priority=5;TCCL=org.springframework.boot.web.embedded.tomcat.TomcatEmbeddedWebappClassLoader@592cb470
    `---[5546.383883ms] com.xxxx.platform.cashier.payment.application.impl.PaymentServiceImpl$$EnhancerBySpringCGLIB$$5fc9f056:order()
        `---[100.00% 5546.162384ms ] org.springframework.cglib.proxy.MethodInterceptor:intercept()
            `---[99.95% 5543.406012ms ] com.xxxx.platform.cashier.payment.application.impl.PaymentServiceImpl:order()
                +---[0.00% 0.037904ms ] com.xxxx.platform.cashier.domain.model.CashierPayment:getPayChannel() #83
                +---[0.00% 0.01964ms ] com.xxxx.platform.cashier.domain.model.PayTypeEnum:getDesc() #85
                +---[0.00% 0.030665ms ] com.xxxx.platform.cashier.payment.application.CheckCommonService:payOrderCreateCheck() #89
                +---[0.00% 0.01448ms ] com.xxxx.platform.cashier.domain.model.CashierPayment:getMerchantId() #94
                +---[0.05% 2.768826ms ] com.xxxx.platform.cashier.merchant.application.MerchantService:getThatMerchantNo() #96
                +---[0.00% 0.03542ms ] com.xxxx.platform.cashier.merchant.domain.model.Merchant:getStatus() #98
                +---[0.00% 0.014544ms ] com.xxxx.platform.cashier.merchant.domain.model.Merchant:getFee() #102
                +---[0.00% 0.015929ms ] com.xxxx.platform.cashier.domain.model.CashierPayment:getAmount() #104
                +---[0.00% 0.017196ms ] com.xxxx.platform.cashier.domain.model.CashierPayment:setMerchantFee() #105
                +---[0.00% 0.014196ms ] com.xxxx.platform.cashier.domain.model.PaymentStatusEnum:code() #107
                +---[0.00% 0.015284ms ] com.xxxx.platform.cashier.domain.model.CashierPayment:setStatus() #107
                +---[0.00% 0.013615ms ] com.xxxx.platform.cashier.domain.model.CashierPayment:getUserId() #109
                +---[0.00% 0.015292ms ] com.xxxx.platform.cashier.domain.model.CashierPayment:setPayerId() #109
                +---[0.00% 0.017296ms ] com.xxxx.platform.cashier.domain.model.CashierPayment:getPhoneNo() #110
                +---[0.00% 0.014007ms ] com.xxxx.platform.cashier.domain.model.CashierPayment:setPayerName() #110
                +---[0.00% 0.011935ms ] com.xxxx.platform.cashier.domain.model.CashierPayment:getMerchantId() #112
                +---[0.00% 0.013289ms ] com.xxxx.platform.cashier.domain.model.CashierPayment:getOrderNo() #112
                +---[0.03% 1.53837ms ] com.xxxx.platform.cashier.common.RedisLockUtils:lock() #112
                +---[0.00% 0.019698ms ] com.xxxx.platform.cashier.domain.model.TransactionTypeEnum:code() #117
                +---[0.00% 0.019657ms ] com.xxxx.platform.cashier.domain.model.CashierPayment:setTransactionType() #117
                +---[0.00% 0.014411ms ] com.xxxx.platform.cashier.domain.model.CashierPayment:getCurrencyType() #120
                +---[0.00% 0.055756ms ] org.apache.commons.lang3.StringUtils:isEmpty() #120
                +---[0.00% 0.016267ms ] com.xxxx.platform.cashier.domain.model.CashierPayment:setCurrencyType() #120
                +---[0.00% 0.053548ms ] com.xxxx.platform.cashier.common.RuleCommonUilt:getOrderNoNextValue() #123
                +---[0.00% 0.014304ms ] com.xxxx.platform.cashier.domain.model.CashierPayment:setPaymentNo() #123
                +---[99.64% 5523.18862ms ] com.xxxx.platform.cashier.payChannel.application.WxPayService:unifiedOrderV3() #126
                +---[0.00% 0.031283ms ] com.xxxx.platform.cashier.payChannel.callback.vo.WxPayRespDto:getPrepayId() #129
                +---[0.00% 0.019875ms ] com.xxxx.platform.cashier.domain.model.CashierPayment:setChannelFlowNo() #130
                +---[0.00% 0.014413ms ] com.xxxx.platform.cashier.payChannel.callback.vo.WxPayRespDto:getCodeUrl() #132
                +---[0.00% 0.015808ms ] com.xxxx.platform.cashier.domain.model.CashierPayment:setCodeUrl() #132
                +---[0.00% 0.014376ms ] com.xxxx.platform.cashier.domain.model.CashierPayment:getExpireTime() #134
                +---[0.19% 10.32507ms ] com.xxxx.platform.cashier.payment.infra.persistent.PaymentRepository:save() #137
                +---[0.00% 0.013414ms ] com.xxxx.platform.cashier.domain.model.CashierPayment:getMerchantId() #139
                +---[0.00% 0.0138ms ] com.xxxx.platform.cashier.domain.model.CashierPayment:getOrderNo() #139
                +---[0.05% 2.851317ms ] com.xxxx.platform.cashier.common.RedisLockUtils:unlock() #139
                +---[0.00% 0.034698ms ] com.xxxx.platform.cashier.domain.dto.PayRespDto:<init>() #140
                +---[0.00% 0.017892ms ] com.xxxx.platform.cashier.payChannel.callback.vo.WxPayRespDto:getPaymentNo() #141
                +---[0.00% 0.01654ms ] com.xxxx.platform.cashier.domain.dto.PayRespDto:setPaymentNo() #141
                +---[0.00% 0.01323ms ] com.xxxx.platform.cashier.payChannel.callback.vo.WxPayRespDto:getNonceStr() #142
                +---[0.00% 0.0158ms ] com.xxxx.platform.cashier.domain.dto.PayRespDto:setNonceStr() #142
                +---[0.00% 0.012434ms ] com.xxxx.platform.cashier.payChannel.callback.vo.WxPayRespDto:getCodeUrl() #143
                +---[0.00% 0.01343ms ] com.xxxx.platform.cashier.domain.dto.PayRespDto:setCodeUrl() #143
                +---[0.00% 0.01348ms ] com.xxxx.platform.cashier.payChannel.callback.vo.WxPayRespDto:getTimeStamp() #144
                +---[0.00% 0.014787ms ] com.xxxx.platform.cashier.domain.dto.PayRespDto:setTimeStamp() #144
                +---[0.00% 0.01276ms ] com.xxxx.platform.cashier.payChannel.callback.vo.WxPayRespDto:getSignType() #145
                +---[0.00% 0.014926ms ] com.xxxx.platform.cashier.domain.dto.PayRespDto:setSignType() #145
                +---[0.00% 0.014566ms ] com.xxxx.platform.cashier.domain.dto.PayRespDto:setPrepayId() #146
                +---[0.00% 0.01013ms ] com.xxxx.platform.cashier.payChannel.callback.vo.WxPayRespDto:getPrepayId() #147
                +---[0.00% 0.013928ms ] com.xxxx.platform.cashier.domain.dto.PayRespDto:setPackgeVal() #147
                +---[0.00% 0.019242ms ] com.xxxx.platform.cashier.payChannel.callback.vo.WxPayRespDto:getPaySign() #148
                `---[0.00% 0.01396ms ] com.xxxx.platform.cashier.domain.dto.PayRespDto:setPaySign() #148

PaymentServiceImpl order 的耗时追踪结果

[99.64% 5523.18862ms ] com.xxxx.platform.cashier.payChannel.application.WxPayService:unifiedOrderV3() #126

WxPayService:unifiedOrderV3() 耗时比较高---继续追踪


trace com.xxxx.platform.cashier.payChannel.handler.JsapiPrepayHandler handlePrepay

WxPayService:unifiedOrderV3() 耗时比较高---继续追踪---结果

Press Q or Ctrl+C to abort.
Affect(class count: 1 , method count: 1) cost in 270 ms, listenerId: 6
`---ts=2024-05-14 11:06:59;thread_name=http-nio-8291-exec-34;id=83;is_daemon=true;priority=5;TCCL=org.springframework.boot.web.embedded.tomcat.TomcatEmbeddedWebappClassLoader@592cb470
    `---[5495.001335ms] com.xxxx.platform.cashier.payChannel.handler.JsapiPrepayHandler:handlePrepay()
        +---[0.00% 0.031287ms ] com.xxxx.platform.cashier.payChannel.application.WxConfigService:getWxConfig() #58
        +---[0.24% 12.980429ms ] com.xxxx.platform.cashier.payChannel.application.WxConfigService:getWxCallBackUrl() #59
        +---[0.00% 0.013296ms ] com.xxxx.platform.cashier.payChannel.application.WxConfigService:getPayChannel() #60
        +---[0.00% 0.051999ms ] com.xxxx.platform.cashier.payChannel.domain.model.PayChannel:getMid() #62
        +---[0.00% 0.014014ms ] com.xxxx.platform.cashier.domain.model.CashierPayment:setPayChannelId() #62
        +---[0.00% 0.01112ms ] com.wechat.pay.java.service.payments.jsapi.model.PrepayRequest:<init>() #66
        +---[0.00% 0.008355ms ] com.xxxx.platform.cashier.domain.model.CashierPayment:getAppId() #68
        +---[0.00% 0.007783ms ] com.wechat.pay.java.service.payments.jsapi.model.PrepayRequest:setAppid() #68
        +---[0.00% 0.032611ms ] com.wechat.pay.java.core.Config:createCredential() #70
        +---[0.00% 0.012989ms ] com.wechat.pay.java.core.auth.Credential:getMerchantId() #70
        +---[0.00% 0.007349ms ] com.wechat.pay.java.service.payments.jsapi.model.PrepayRequest:setMchid() #70
        +---[0.00% 0.007852ms ] com.xxxx.platform.cashier.domain.model.CashierPayment:getDescription() #72
        +---[0.00% 0.007496ms ] com.wechat.pay.java.service.payments.jsapi.model.PrepayRequest:setDescription() #72
        +---[0.00% 0.008485ms ] com.xxxx.platform.cashier.domain.model.CashierPayment:getExpireTime() #74
        +---[0.00% 0.014132ms ] com.wechat.pay.java.service.payments.jsapi.model.PrepayRequest:setTimeExpire() #80
        +---[0.00% 0.006621ms ] com.wechat.pay.java.service.payments.jsapi.model.PrepayRequest:setNotifyUrl() #87
        +---[0.00% 0.008656ms ] com.xxxx.platform.cashier.domain.model.CashierPayment:getPaymentNo() #89
        +---[0.00% 0.00741ms ] com.wechat.pay.java.service.payments.jsapi.model.PrepayRequest:setOutTradeNo() #89
        +---[0.00% 0.008734ms ] com.wechat.pay.java.service.payments.jsapi.model.Amount:<init>() #91
        +---[0.00% 0.007847ms ] com.xxxx.platform.cashier.domain.model.CashierPayment:getAmount() #92
        +---[0.00% 0.008955ms ] com.wechat.pay.java.service.payments.jsapi.model.Amount:setTotal() #92
        +---[0.00% 0.007979ms ] com.xxxx.platform.cashier.domain.model.CashierPayment:getCurrencyType() #93
        +---[0.00% 0.006736ms ] com.wechat.pay.java.service.payments.jsapi.model.Amount:setCurrency() #93
        +---[0.00% 0.008146ms ] com.wechat.pay.java.service.payments.jsapi.model.PrepayRequest:setAmount() #94
        +---[0.00% 0.005114ms ] com.xxxx.platform.cashier.domain.model.CashierPayment:getPaymentNo() #96
        +---[0.00% 0.008387ms ] com.xxxx.platform.cashier.domain.model.CashierPayment:getOrderNo() #96
        +---[0.00% 0.007641ms ] com.wechat.pay.java.service.payments.jsapi.model.PrepayRequest:setAttach() #96
        +---[0.00% 0.00908ms ] com.wechat.pay.java.service.payments.jsapi.model.Payer:<init>() #98
        +---[0.00% 0.007556ms ] com.xxxx.platform.cashier.domain.model.CashierPayment:getOpenId() #100
        +---[0.00% 0.007754ms ] com.wechat.pay.java.service.payments.jsapi.model.Payer:setOpenid() #100
        +---[0.00% 0.013363ms ] com.wechat.pay.java.service.payments.jsapi.model.PrepayRequest:setPayer() #101
        +---[0.00% 0.008127ms ] com.xxxx.platform.cashier.domain.model.CashierPayment:getClientIp() #103
        +---[0.00% 0.024896ms ] org.apache.commons.lang3.StringUtils:isNotBlank() #103
        +---[0.00% 0.00985ms ] com.wechat.pay.java.service.payments.jsapi.JsapiServiceExtension$Builder:<init>() #109
        +---[0.00% 0.008498ms ] com.wechat.pay.java.service.payments.jsapi.JsapiServiceExtension$Builder:config() #111
        +---[0.00% 0.008683ms ] com.wechat.pay.java.service.payments.jsapi.JsapiServiceExtension$Builder:signType() #112
        +---[0.00% 0.184347ms ] com.wechat.pay.java.service.payments.jsapi.JsapiServiceExtension$Builder:build() #113
        +---[99.73% 5480.296786ms ] com.wechat.pay.java.service.payments.jsapi.JsapiServiceExtension:prepayWithRequestPayment() #115
        +---[0.00% 0.031419ms ] com.wechat.pay.java.service.payments.jsapi.model.PrepayWithRequestPaymentResponse:getPackageVal() #116
        +---[0.00% 0.02185ms ] org.apache.commons.lang3.StringUtils:isEmpty() #116
        `---[0.00% 0.065744ms ] com.xxxx.platform.cashier.payChannel.handler.JsapiPrepayHandler:buildWxPayRespVo() #121

找到罪魁祸首 JsapiServiceExtension:prepayWithRequestPayment() 耗时全都是他

分析代码:甩锅了

image

标签:xxxx,排查,0.00%,cashier,耗时,+---,ms,arthas,com
From: https://www.cnblogs.com/gtnotgod/p/18191545

相关文章

  • Etcd开启grpc请求耗时监控
    针对各种类型grpc请求耗时统计场景,etcd提供监控数据。#etcd容器增加环境变量env:-name:ETCD_METRICSvalue:extensivecurl-shttp://127.0.0.1:2381/metrics|grepgrpc_server_handling_seconds_bucketgrpc_method包含了Alarm/AuthDisable/AuthEnable/Authenticate/......
  • arthas使用
    arthas中文文档https://github.com/alibaba/arthas/blob/master/README_CN.md1、下载并启动curl-Ohttps://arthas.aliyun.com/arthas-boot.jarjava-jararthas-boot.jar2、选择java进程[INFO]JAVA_HOME:/Library/Java/JavaVirtualMachines/jdk1.8.0_151.jdk/Contents/H......
  • 【java】问题排查-内存溢出(OOM)-汇总指南
    1、java.lang.OutOfMemoryError:Javaheapspace原因分析示例解决方案2、java.lang.OutOfMemoryError:GCoverheadlimitexceeded原因分析示例解决方案3、java.lang.OutOfMemoryError:Permgenspace原因分析示例解决方案4、java.lang.OutOfMemoryErr......
  • 日常Bug排查-连接突然全部关闭
    日常Bug排查-连接突然全部关闭前言日常Bug排查系列都是一些简单Bug的排查。笔者将在这里介绍一些排查Bug的简单技巧,同时顺便积累素材。Bug现场最近碰到一个问题,一台机器上的连接数在达到一定连接数(大概4.5W)连接数之后会突然急速下降到几百。在应用上的表现就是大量的连接报......
  • 抽丝剥茧:详述一次DevServer Proxy配置无效问题的细致排查过程
    事情的起因是这样的,在一个已上线的项目中,其中一个包含登录和获取菜单的接口因响应时间较长,后端让我尝试未经服务转发的另一域名下的新接口,旧接口允许跨域请求,但新接口不允许本地访问(只允许发布测试/生产的域名访问)。问题那么问题来了,本地环境该如何成功访问到新的接口并验证业务......
  • 揭秘网络故障的幕后黑手:流量探针如何助您快速排查网络问题
    网络故障就像潜藏在暗处的幽灵,时不时跳出来影响我们的工作和生活。面对突如其来的网络问题,我们常常手足无措,不知从何下手进行排查。而流量探针,就像侦探手中的放大镜,可以帮助我们洞悉网络流量的真相,快速定位并解决问题。流量探针:网络故障排查的利器流量探针是一种网络流量分析工......
  • 一次glide内存泄漏排查分析
    glide是一款非常优秀的图片加载框架,目前很多项目在使用。提供了非常方法,在此,笔者就不一一列举了,可以到官网查找。目前项目在做内存排查,因为是车机项目,之前开发的时候没有注意内存方面的问题(车机项目你懂的),现在ota期间系统提出让我们优化内存,说出现过应用内存一直增加的情况。一......
  • 瑞萨问题排查记录
    P1当把RFD28F添加进项目时,报错如下:参考链接:https://www.sekorm.com/news/73776172.html栈溢出.textE0562330:Relocationsizeoverflow:"DefaultBuild\sample_control_codeflash.obj"-".text"-00000b(1)右键Subproject的CC-RH——LinkOptionsTab——S......
  • stm32 出现 hard fault 的排查记录
    参考链接:https://blog.csdn.net/qq_43118572/article/details/1327596261、先验知识先验知识1:cortexm3在中断/异常时,会把8个寄存器(xPSR、PC、LR、R12以及R3-R0)的值压入栈。入栈顺序以及入栈后堆栈中的内容如下(CM4是从低地址到搞地质):地址寄存器被保存的顺序......
  • stm32 将外部 Flash挂载在 SPI 出现数据传输时好时不好的排查过程
    现象:将外部Flash挂载在SPI,在hardware_init()->read_jedec_id()里的result=spi->wr(spi,cmd_data,sizeof(cmd_data),recv_data,sizeof(recv_data))中,recv_data的值经常不一致,result的值偶尔为SFUD_SUCCESS,大部分会Error。备注:正常情况下,recv_data的值为......