• Arthas:线上问题排查工具


    安装

    下载

    java -jar arthas-boot.jar
    

    查看版本:

    D:Program Filesarthas
    $ java -jar arthas-boot.jar -version
    [INFO] arthas-boot version: 3.1.0
    Local versions:
     3.1.0
    Remote versions:
     3.1.0
     3.0.5
     3.0.4
     3.0.3
     3.0.0-RC
     3.0.5
    

    命令使用

    启动arthas

    E:BaiduYunDownloadarthas-packaging-3.1.0-bin                                           
    $ java -jar arthas-boot.jar                                                              
    [INFO] arthas-boot version: 3.1.0                                                        
    [INFO] Found existing java process, please choose one and hit RETURN.                    
    * [1]: 22596 org.jetbrains.idea.maven.server.RemoteMavenServer                           
      [2]: 20728 org.apache.catalina.startup.Bootstrap                                       
      [3]: 29752 com.shitou.Application                                                      
      [4]: 37144                                                                             
      [5]: 15660 org.jetbrains.jps.cmdline.Launcher                                          
    3                                                                                        
    [INFO] arthas home: E:BaiduYunDownloadarthas-packaging-3.1.0-bin                       
    [INFO] Try to attach process 29752                                                       
    [INFO] Found java home from System Env JAVA_HOME: D:Program FilesJavajdk1.8.0         
    [INFO] Attach process 29752 success.                                                     
    [INFO] arthas-client connect 127.0.0.1 3658                                              
      ,---.  ,------. ,--------.,--.  ,--.  ,---.   ,---.                                    
     /  O   |  .--. ''--.  .--'|  '--'  | /  O   '   .-'                                   
    |  .-.  ||  '--'.'   |  |   |  .--.  ||  .-.  |`.  `-.                                   
    |  | |  ||  |      |  |   |  |  |  ||  | |  |.-'    |                                  
    `--' `--'`--' '--'   `--'   `--'  `--'`--' `--'`-----'                                   
                                                                                             
                                                                                             
    wiki: https://alibaba.github.io/arthas                                                   
    version: 3.1.0                                                                           
    pid: 29752                                                                               
    time: 2019-03-20 18:21:26                                                                
    

    查看dashboard

    ID       NAME                      GROUP             PRIORIT STATE    %CPU     TIME     INTERRU DAEMON
    67       Abandoned connection clea main              5       TIMED_WA 0        0:0      false   true
    128      AsyncAppender-Worker-arth system            5       WAITING  0        0:0      false   true
    6        Attach Listener           system            5       RUNNABLE 0        0:0      false   true
    65       ContainerBackgroundProces main              5       TIMED_WA 0        0:0      false   true
    122      DestroyJavaVM             main              5       RUNNABLE 0        0:52     false   false
    68       Druid-ConnectionPool-Crea main              5       WAITING  0        0:0      false   true
    69       Druid-ConnectionPool-Dest main              5       TIMED_WA 0        0:0      false   true
    92       DubboClientReconnectTimer main              5       WAITING  0        0:0      false   true
    96       DubboClientReconnectTimer main              5       TIMED_WA 0        0:0      false   true
    79       DubboRegistryFailedRetryT main              5       TIMED_WA 0        0:0      false   true
    125      DubboResponseTimeoutScanT main              5       TIMED_WA 0        0:0      false   true
    83       DubboSaveRegistryCache-th main              5       WAITING  0        0:0      false   true
    Memory                 used   total   max    usage   GC
    heap                   160M   320M    4050M  3.96%   gc.parnew.count           155
    par_eden_space         5M     68M     266M   2.17%   gc.parnew.time(ms)        1154
    par_survivor_space     711K   8704K   34048K 2.09%   gc.concurrentmarksweep.co 7
    cms_old_gen            153M   243M    3751M  4.10%   unt
    nonheap                171M   180M    -1     94.88%  gc.concurrentmarksweep.ti 429
    code_cache             25M    25M     240M   10.77%  me(ms)
    Runtime
    os.name                    Windows 10
    os.version                 10.0
    java.version               1.8.0_201
    java.home                  D:Program FilesJavajdk
                               1.8.0jre
    systemload.average         -1.00
    

    数据说明

    • ID: Java级别的线程ID,注意这个ID不能跟jstack中的nativeID一一对应
    • NAME: 线程名
    • GROUP: 线程组名
    • PRIORITY: 线程优先级, 1~10之间的数字,越大表示优先级越高
    • STATE: 线程的状态
    • CPU%: 线程消耗的cpu占比,采样100ms,将所有线程在这100ms内的cpu使用量求和,再算出每个线程的cpu使用占比。
    • TIME: 线程运行总时间,数据格式为分:秒
    • INTERRUPTED: 线程当前的中断位状态
    • DAEMON: 是否是daemon线程

    thread:线程信息

    显示所有线程信息

    $ thread
    Threads Total: 80, NEW: 0, RUNNABLE: 23, BLOCKED: 0, WAITING: 33, TIMED_WAITING: 24, TERMINATED: 0
    ID       NAME                      GROUP             PRIORIT STATE    %CPU     TIME     INTERRU DAEMON
    67       Abandoned connection clea main              5       TIMED_WA 0        0:0      false   true
    128      AsyncAppender-Worker-arth system            5       WAITING  0        0:0      false   true
    6        Attach Listener           system            5       RUNNABLE 0        0:0      false   true
    65       ContainerBackgroundProces main              5       TIMED_WA 0        0:0      false   true
    122      DestroyJavaVM             main              5       RUNNABLE 0        0:52     false   false
    68       Druid-ConnectionPool-Crea main              5       WAITING  0        0:0      false   true
    69       Druid-ConnectionPool-Dest main              5       TIMED_WA 0        0:0      false   true
    92       DubboClientReconnectTimer main              5       WAITING  0        0:0      false   true
    96       DubboClientReconnectTimer main              5       TIMED_WA 0        0:0      false   true
    

    显示当前最忙的前n个线程,并打印出堆栈

    $ thread -n 3
    "Reference Handler" Id=2 cpuUsage=0% WAITING on java.lang.ref.Reference$Lock@5889e097
        at java.lang.Object.wait(Native Method)
        -  waiting on java.lang.ref.Reference$Lock@5889e097
        at java.lang.Object.wait(Object.java:502)
        at java.lang.ref.Reference.tryHandlePending(Reference.java:191)
        at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:153)
    
    
    "Finalizer" Id=3 cpuUsage=0% WAITING on java.lang.ref.ReferenceQueue$Lock@2c5e60e3
        at java.lang.Object.wait(Native Method)
        -  waiting on java.lang.ref.ReferenceQueue$Lock@2c5e60e3
        at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:144)
        at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:165)
        at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:216)
    
    
    "Signal Dispatcher" Id=5 cpuUsage=0% RUNNABLE
    

    查看指定线程的堆栈信息

    $ thread 2
    "Reference Handler" Id=2 WAITING on java.lang.ref.Reference$Lock@5889e097
        at java.lang.Object.wait(Native Method)
        -  waiting on java.lang.ref.Reference$Lock@5889e097
        at java.lang.Object.wait(Object.java:502)
        at java.lang.ref.Reference.tryHandlePending(Reference.java:191)
        at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:153)
    
    Affect(row-cnt:0) cost in 56 ms.
    

    找出当前阻塞其他线程的线程

    $ thread -b
    No most blocking thread found!
    Affect(row-cnt:0) cost in 68 ms.
    

    指定采样时间间隔

    $ thread -n 3 -i 10000
    "File Watcher" Id=101 cpuUsage=88% TIMED_WAITING
        at java.lang.Thread.sleep(Native Method)
        at org.springframework.boot.devtools.filewatch.FileSystemWatcher$Watcher.scan(FileSystemWatcher.java:249)
        at org.springframework.boot.devtools.filewatch.FileSystemWatcher$Watcher.run(FileSystemWatcher.java:239)
        at java.lang.Thread.run(Thread.java:748)
    
    
    "Hashed wheel timer #1" Id=89 cpuUsage=9% TIMED_WAITING
        at java.lang.Thread.sleep(Native Method)
        at org.jboss.netty.util.HashedWheelTimer$Worker.waitForNextTick(HashedWheelTimer.java:503)
        at org.jboss.netty.util.HashedWheelTimer$Worker.run(HashedWheelTimer.java:401)
        at org.jboss.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:108)
        at java.lang.Thread.run(Thread.java:748)
    
    
    "http-nio-18080-exec-7" Id=111 cpuUsage=1% WAITING on java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject@fefdf30
        at sun.misc.Unsafe.park(Native Method)
        -  waiting on java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject@fefdf30
        at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
        at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
        at org.apache.tomcat.util.threads.TaskQueue.take(TaskQueue.java:103)
        at org.apache.tomcat.util.threads.TaskQueue.take(TaskQueue.java:31)
        at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
        at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
        at java.lang.Thread.run(Thread.java:748)
    
    
    Affect(row-cnt:0) cost in 10062 ms.
    

    watch:查看方法的入参出参:

    $ watch com.shitou.huishi.contract.datacontract.service.web.OrderApplyInfoService readCreditDetailByLoanOrderId "{params[0],returnObj}"  -b -f
    Press Q or Ctrl+C to abort.
    Affect(class-cnt:2 , method-cnt:2) cost in 136 ms.
    ts=2019-03-21 16:10:14; [cost=0.01548ms] result=@ArrayList[
        @LoanOrderKeyReq[LoanOrderKeyReq(loanOrderId=PO119110867372605450)],
        null,
    ]
    ts=2019-03-21 16:10:14; [cost=0.011808ms] result=@ArrayList[
        @LoanOrderKeyReq[LoanOrderKeyReq(loanOrderId=PO119110867372605450)],
        null,
    ]
    ts=2019-03-21 16:10:15; [cost=56.043046ms] result=@ArrayList[
        @LoanOrderKeyReq[LoanOrderKeyReq(loanOrderId=PO119110867372605450)],
        @DataResponse[DataResponse(data=ApplyInfoDTO(loanOrderId=PO119110867372605450, orgSource=及时雨, productName=小微企业经营贷, lenderName=小米科技, lenderNo=544619676, lenderNoType=null, applyMoney=60000.00, applyPeriod=55, applyYearRate=63.0000, repaymentType=xxhb_rt, isCredit=0, loanUsage=gmsb_lu, loanUsageDesc=xxxxxxxxxxxxxx, ensureType=dy_bz_zy_et, isSmallLoan=null, showExpireTime=null, doorReview=tangy, conditionAdd=null, isXudai=null))],
    ]
    ts=2019-03-21 16:10:15; [cost=61.627293ms] result=@ArrayList[
        @LoanOrderKeyReq[LoanOrderKeyReq(loanOrderId=PO119110867372605450)],
        @DataResponse[DataResponse(data=ApplyInfoDTO(loanOrderId=PO119110867372605450, orgSource=及时雨, productName=小微企业经营贷, lenderName=小米科技, lenderNo=544619676, lenderNoType=null, applyMoney=60000.00, applyPeriod=55, applyYearRate=63.0000, repaymentType=xxhb_rt, isCredit=0, loanUsage=gmsb_lu, loanUsageDesc=xxxxxxxxxxxxxx, ensureType=dy_bz_zy_et, isSmallLoan=null, showExpireTime=null, doorReview=tangy, conditionAdd=null, isXudai=null))],
    ]
    

    前2个是请求参数

    后2段是返回参数

    对于上面的params,returnObj,具体请查看 表达式核心变量

    watch具体参数选项

    [b] 方法调用之前观察
    [e] 方法异常之后观察
    [s] 方法返回之后观察
    [f] 方法结束之后(正常返回和异常返回)观察
    [E] 开启正则表达式匹配,默认为通配符匹配
    [x:] 指定输出结果的属性遍历深度,默认为 1

    这里特别注意x,遍历深度

    深度为1:

    [arthas@22104]$ watch com.shitou.huishi.manager.impl.RefinanceManageImpl queryQYDHistoryRefinanceOrder "{params[0],returnObj }" -x 1 -b -f
    Press Q or Ctrl+C to abort.
    Affect(class-cnt:1 , method-cnt:1) cost in 153 ms.
    ts=2020-01-02 20:20:16; [cost=0.0103ms] result=@ArrayList[
        @String[PO119631178119643150],
        null,
    ]
    ts=2020-01-02 20:20:16; [cost=9.027673849411E8ms] result=@ArrayList[
        @String[PO119631178119643150],
        @ArrayList[isEmpty=false;size=2],
    ]
    

    深度为2:

    [arthas@22104]$ watch com.shitou.huishi.manager.impl.RefinanceManageImpl queryQYDHistoryRefinanceOrder "{params[0],returnObj }" -x 2 -b -f
    Press Q or Ctrl+C to abort.
    Affect(class-cnt:1 , method-cnt:1) cost in 152 ms.
    ts=2020-01-02 20:20:31; [cost=0.0106ms] result=@ArrayList[
        @String[PO119631178119643150],
        null,
    ]
    ts=2020-01-02 20:20:31; [cost=9.027829001319E8ms] result=@ArrayList[
        @String[PO119631178119643150],
        @ArrayList[
            @LoanOrderInfoDTO[LoanOrderInfoDTO(loanOrderId=BO119643577337905166, mainSubjectArchiveId=1000000162, borrowerArchiveId=1000000162, legalArchiveId=null, actualArchiveId=null, loanType=1)],
            @LoanOrderInfoDTO[LoanOrderInfoDTO(loanOrderId=BO119643622212763658, mainSubjectArchiveId=1000000125, borrowerArchiveId=1000000125, legalArchiveId=1000000099, actualArchiveId=1000000096, loanType=1)],
        ],
    ]
    java.net.SocketException: Connection reset
            at java.net.SocketInputStream.read(SocketInputStream.java:210)
            at java.net.SocketInputStream.read(SocketInputStream.java:141)
            at java.io.BufferedInputStream.read1(BufferedInputStream.java:284)
            at java.io.BufferedInputStream.read(BufferedInputStream.java:345)
            at java.io.BufferedInputStream.fill(BufferedInputStream.java:246)
            at java.io.BufferedInputStream.read(BufferedInputStream.java:265)
            at org.apache.commons.net.telnet.TelnetInputStream.__read(TelnetInputStream.java:132)
            at org.apache.commons.net.telnet.TelnetInputStream.run(TelnetInputStream.java:603)
            at java.lang.Thread.run(Thread.java:748)
    

    可以发现,原来的返回体数组的具体信息都可以看见了。

    trace:查看方法内部调用路径,并输出每个节点上面的耗时

    $ trace com.shitou.huishi.service.agency.AgencyOrderServiceImpl *
    Press Q or Ctrl+C to abort.
    Affect(class-cnt:2 , method-cnt:70) cost in 553 ms.
    `---ts=2020-04-21 14:47:05;thread_name=http-nio-18080-exec-6;id=1b0;is_daemon=true;priority=5;TCCL=org.springframework.boot.context.embedded.tomcat.TomcatEmbeddedWebappClassLoader@7bf74eb1
        `---[231.0472ms] com.shitou.huishi.service.agency.AgencyOrderServiceImpl$$EnhancerBySpringCGLIB$$b4405138:submitAgencyOrderInfo()
            `---[224.8126ms] org.springframework.cglib.proxy.MethodInterceptor:intercept()
                `---[137.4045ms] com.shitou.huishi.service.agency.AgencyOrderServiceImpl:submitAgencyOrderInfo()
                    +---[1.9188ms] java.lang.StringBuilder:<init>()
                    +---[min=0.0047ms,max=0.0584ms,total=0.0689ms,count=3] java.lang.StringBuilder:append()
                    +---[0.0137ms] com.shitou.huishi.contract.datacontract.request.agency.SubmitAgencyOrderInfoRequest:getAgencyToken()
                    +---[0.0153ms] java.lang.StringBuilder:toString()
                    +---[0.0409ms] org.apache.curator.framework.recipes.locks.InterProcessMutex:<init>()
                    +---[3.3824ms] org.apache.curator.framework.recipes.locks.InterProcessMutex:acquire()
                    +---[1.72ms] com.shitou.huishi.agency.helper.AgencyAuthHelper:getAgencyUser()
                    +---[0.0197ms] com.shitou.huishi.config.GlobalConfig:getIsHandXSAuth()
                    +---[0.02ms] java.lang.Boolean:booleanValue()
                    +---[19.3857ms] com.shitou.huishi.agency.manager.AgencyOrderManager:saveAgencyOrderInfo()
                    +---[27.697ms] com.shitou.huishi.agency.manager.AgencyOrderManager:submitAgencyOrderInfo()
                    +---[0.0188ms] com.shitou.huishi.domain.entity.AgencyOrderInfo:getLoanOrderId()
                    +---[61.3922ms] com.shitou.huishi.manager.LoanOrderManager:initOrderInfo()
                    +---[15.8171ms] com.shitou.huishi.agency.manager.AgencyLogManager:saveAgencyOrderInfoLog()
                    +---[0.0135ms] com.shitou.huishi.domain.entity.AgencyOrderInfo:getAgencyOrderId()
                    +---[0.0162ms] com.shitou.huishi.contract.datacontract.response.DataResponse:process()
                    +---[0.0095ms] org.apache.curator.framework.recipes.locks.InterProcessMutex:isAcquiredInThisProcess()
                    +---[0.5194ms] org.slf4j.Logger:info()
                    `---[1.7714ms] org.apache.curator.framework.recipes.locks.InterProcessMutex:release()
    

    命令 trace 类名 方法名

    trace只显示方法内方法的执行时间,但是再下一级的时间就需要自己再次手动调用

    $ trace com.shitou.huishi.manager.LoanOrderManager initOrderInfo
    Press Q or Ctrl+C to abort.
    Affect(class-cnt:2 , method-cnt:2) cost in 1031 ms.
    `---ts=2020-04-21 14:47:41;thread_name=http-nio-18080-exec-5;id=1af;is_daemon=true;priority=5;TCCL=org.springframework.boot.context.embedded.tomcat.TomcatEmbeddedWebappClassLoader@7bf74eb1
        `---[71.1404ms] com.shitou.huishi.manager.impl.LoanOrderManagerImpl$$EnhancerBySpringCGLIB$$a059faf9:initOrderInfo()
            `---[70.9246ms] org.springframework.cglib.proxy.MethodInterceptor:intercept()
                `---[69.8022ms] com.shitou.huishi.manager.impl.LoanOrderManagerImpl:initOrderInfo()
                    +---[4.3738ms] com.shitou.huishi.domain.LoanOrderBizFacade:selectByPrimaryKey()
                    +---[0.0173ms] com.shitou.huishi.domain.entity.ModifyLoanOrderInfo:<init>()
                    +---[0.01ms] com.shitou.huishi.domain.entity.ModifyLoanOrderInfo:setLoanOrderId()
                    +---[0.0122ms] com.shitou.huishi.domain.entity.LoanOrder:getBelongName()
                    +---[0.0084ms] com.shitou.huishi.domain.entity.ModifyLoanOrderInfo:setAfterBelongName()
                    +---[0.0083ms] com.shitou.huishi.domain.entity.LoanOrder:getBelongDisplayName()
                    +---[0.0077ms] com.shitou.huishi.domain.entity.ModifyLoanOrderInfo:setAfterBelongDisplayName()
                    +---[0.0069ms] com.shitou.huishi.domain.entity.LoanOrder:getBelongDeptName()
                    +---[0.0062ms] com.shitou.huishi.domain.entity.ModifyLoanOrderInfo:setAfterBelongDepartmentName()
                    +---[0.0102ms] com.shitou.huishi.domain.entity.LoanOrder:getCreateName()
                    +---[0.0068ms] com.shitou.huishi.domain.entity.ModifyLoanOrderInfo:setCreateName()
                    +---[0.0078ms] java.util.Date:<init>()
                    +---[0.0071ms] com.shitou.huishi.domain.entity.ModifyLoanOrderInfo:setChangeDate()
                    +---[2.5918ms] com.shitou.huishi.domain.ModifyLoanOrderInfoBizFacade:insertSelective()
                    +---[min=0.0058ms,max=0.0164ms,total=0.0317ms,count=3] com.shitou.huishi.domain.entity.LoanOrder:getMainSubjectArchiveId()
                    +---[0.0395ms] com.shitou.huishi.contract.datacontract.dto.assets.InitAssetsDto:<init>()
                    +---[min=0.0045ms,max=0.0064ms,total=0.0163ms,count=3] java.lang.Integer:<init>()
                    +---[min=0.0063ms,max=0.0074ms,total=0.0201ms,count=3] java.lang.reflect.Method:invoke()
                    +---[9.9859ms] com.shitou.huishi.manager.AssetsManager:initAssetsByNewest()
                    +---[0.0152ms] com.shitou.huishi.contract.datacontract.dto.assets.InitAssetsDebtDto:<init>()
                    +---[9.5382ms] com.shitou.huishi.manager.AssetsManager:initAssetsDebtByNewest()
                    +---[min=0.0059ms,max=0.0157ms,total=0.0216ms,count=2] com.shitou.huishi.domain.entity.LoanOrder:getLoanOrderId()
                    +---[0.0379ms] com.shitou.huishi.contract.datacontract.dto.assets.InitIncomeFeesDto:<init>()
                    +---[9.8176ms] com.shitou.huishi.manager.IncomeFeesManager:initIncomeFeesByNewest()
                    +---[min=0.0063ms,max=0.018ms,total=0.0243ms,count=2] com.shitou.huishi.domain.entity.LoanOrder:getLoanType()
                    +---[min=0.0068ms,max=0.0092ms,total=0.016ms,count=2] com.shitou.huishi.base.enums.LoanTypeEnum:getStatus()
                    +---[min=0.0046ms,max=0.022ms,total=0.0266ms,count=2] java.lang.Integer:valueOf()
                    +---[min=0.0054ms,max=0.0314ms,total=0.0368ms,count=2] java.lang.Integer:equals()
                    +---[0.0091ms] com.shitou.huishi.domain.entity.LoanOrder:getBorrowerArchiveId()
                    +---[0.0091ms] com.shitou.huishi.contract.datacontract.request.relation.OrderRelationQuery:<init>()
                    +---[6.5657ms] com.shitou.huishi.manager.RelationManage:sysnRelation()
                    `---[25.1437ms] com.shitou.huishi.manager.impl.LoanOrderManagerImpl:initLoanOrderDetail()
    
    $ trace com.shitou.huishi.manager.impl.LoanOrderManagerImpl initLoanOrderDetail
    Press Q or Ctrl+C to abort.
    Affect(class-cnt:2 , method-cnt:1) cost in 1045 ms.
    `---ts=2020-04-21 14:48:35;thread_name=http-nio-18080-exec-7;id=1b1;is_daemon=true;priority=5;TCCL=org.springframework.boot.context.embedded.tomcat.TomcatEmbeddedWebappClassLoader@7bf74eb1
        `---[21.0879ms] com.shitou.huishi.manager.impl.LoanOrderManagerImpl:initLoanOrderDetail()
            +---[0.0338ms] com.shitou.huishi.domain.entity.LoanOrder:getLoanOrderId()
            +---[3.4537ms] com.shitou.huishi.domain.LoanOrderDetailBizFacade:selectByPrimaryKey()
            +---[14.5324ms] com.shitou.huishi.manager.impl.RefinanceManageImpl:queryContinuedLoanOrderRelation()
            +---[0.0053ms] java.lang.Integer:<init>()
            +---[0.0052ms] java.lang.reflect.Method:invoke()
            +---[0.0231ms] java.util.List:isEmpty()
            +---[0.0215ms] java.lang.Boolean:valueOf()
            +---[0.0106ms] com.shitou.huishi.domain.entity.LoanOrderDetail:setIsSystemXudai()
            `---[2.6394ms] com.shitou.huishi.domain.LoanOrderDetailBizFacade:updateByPrimaryKeySelective()
    

    这样就可以一级一级查看具体执行时间

    可以调用业务实现类,也可以调用接口声明类,结果都一样

    也可以模糊匹配

     trace com.shitou.huishi.contract.datacontract.service.agency.AgencyOrderService *
     
     trace com.shitou.huishi.contract.datacontract.service.agency.AgencyOrderService submitAgencyOrderInfo
    

    stack:查看当前方法调用路径

    $ stack  com.shitou.huishi.contract.datacontract.service.web.OrderApplyInfoService readCreditDetailByLoanOrderId 
    Press Q or Ctrl+C to abort.
    Affect(class-cnt:2 , method-cnt:2) cost in 181 ms.
    ts=2019-03-21 16:19:04;thread_name=http-nio-8083-exec-8;id=3d;is_daemon=true;priority=5;TCCL=org.springframework.boot.context.embedded.tomcat.TomcatEmbeddedWebappClassLoader@34018c56
        @com.shitou.huishi.service.web.OrderApplyInfoServiceImpl$$FastClassBySpringCGLIB$$1213e5f9.invoke()
            at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204)
            at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:738)
            at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157)
            at org.springframework.aop.aspectj.MethodInvocationProceedingJoinPoint.proceed(MethodInvocationProceedingJoinPoint.java:85)
            at com.shitou.huishi.aop.ControllerAspect.aroundAdvice(ControllerAspect.java:61)
            at sun.reflect.GeneratedMethodAccessor161.invoke(null:-1)
            at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
            at java.lang.reflect.Method.invoke(Method.java:498)
            at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:629)
            at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:618)
            at org.springframework.aop.aspectj.AspectJAroundAdvice.invoke(AspectJAroundAdvice.java:70)
            at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
            at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92)
            at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
            at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:673)
            at com.shitou.huishi.service.web.OrderApplyInfoServiceImpl$$EnhancerBySpringCGLIB$$1a8938.readCreditDetailByLoanOrderId(<generated>:-1)
            at sun.reflect.NativeMethodAccessorImpl.invoke0(NativeMethodAccessorImpl.java:-2)
            at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
            at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
            at java.lang.reflect.Method.invoke(Method.java:498)
            at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:205)
            at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:133)
            at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:97)
            at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:827)
            at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:738)
            at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:85)
            at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:967)
            at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:901)
            at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:970)
            at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:872)
            at javax.servlet.http.HttpServlet.service(HttpServlet.java:707)
            at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:846)
            at javax.servlet.http.HttpServlet.service(HttpServlet.java:790)
            at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231)
            at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
            at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
            at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
            at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
            at org.springframework.boot.web.filter.ApplicationContextHeaderFilter.doFilterInternal(ApplicationContextHeaderFilter.java:55)
            at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
            at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
            at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
            at com.alibaba.druid.support.http.WebStatFilter.doFilter(WebStatFilter.java:123)
            at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
            at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
            at org.springframework.boot.actuate.trace.WebRequestTraceFilter.doFilterInternal(WebRequestTraceFilter.java:110)
            at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
            at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
            at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
            at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:99)
            at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
            at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
            at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
            at org.springframework.web.filter.HttpPutFormContentFilter.doFilterInternal(HttpPutFormContentFilter.java:105)
            at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
            at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
            at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
            at org.springframework.web.filter.HiddenHttpMethodFilter.doFilterInternal(HiddenHttpMethodFilter.java:81)
            at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
            at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
            at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
            at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:197)
            at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
            at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
            at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
            at org.springframework.boot.actuate.autoconfigure.MetricsFilter.doFilterInternal(MetricsFilter.java:106)
            at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
            at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
            at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
            at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:198)
            at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96)
            at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:478)
            at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:140)
            at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:80)
            at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:87)
            at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:342)
            at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:799)
            at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66)
            at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:861)
            at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1455)
            at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
            at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
            at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
            at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
            at java.lang.Thread.run(Thread.java:745)
    

    tt:记录下指定方法的调用,后续对其进行筛选,查看,重现等

    开始记录:

    $ tt -t com.shitou.huishi.contract.datacontract.service.web.OrderApplyInfoService readCreditDetailByLoanOrderId
    Press Q or Ctrl+C to abort.
    Affect(class-cnt:2 , method-cnt:2) cost in 160 ms.
     INDEX            TIMESTAMP                                 COST(ms)             IS-RET          IS-EXP           OBJECT                         CLASS                                                          METHOD                                                        
    ------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
     1000             2019-03-21 16:37:05                       62.710494            true            false            0x4adf3582                     OrderApplyInfoServiceImpl                                      readCreditDetailByLoanOrderId                                 
     1001             2019-03-21 16:37:05                       -0.022655            true            false            0x708c8fb                      OrderApplyInfoServiceImpl$$EnhancerBySpringCGLIB$$1a8938       readCreditDetailByLoanOrderId                                 
     1002             2019-03-21 16:37:14                       44.213677            true            false            0x4adf3582                     OrderApplyInfoServiceImpl                                      readCreditDetailByLoanOrderId                                 
     1003             2019-03-21 16:37:14                       -0.00271             true            false            0x708c8fb                      OrderApplyInfoServiceImpl$$EnhancerBySpringCGLIB$$1a8938       readCreditDetailByLoanOrderId                                 
     1004             2019-03-21 16:37:55                       59.234538            true            false            0x4adf3582                     OrderApplyInfoServiceImpl                                      readCreditDetailByLoanOrderId                                 
     1005             2019-03-21 16:37:55                       -0.00376             true            false            0x708c8fb                      OrderApplyInfoServiceImpl$$EnhancerBySpringCGLIB$$1a8938       readCreditDetailByLoanOrderId                                 
     1006             2019-03-21 16:38:01                       57.618517            true            false            0x4adf3582                     OrderApplyInfoServiceImpl                                      readCreditDetailByLoanOrderId                                 
     1007             2019-03-21 16:38:01                       -0.003653            true            false            0x708c8fb                      OrderApplyInfoServiceImpl$$EnhancerBySpringCGLIB$$1a8938       readCreditDetailByLoanOrderId   
    

    查看所有记录:

    $ tt -l
     INDEX            TIMESTAMP                                 COST(ms)             IS-RET          IS-EXP           OBJECT                         CLASS                                                          METHOD                                                        
    ------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
     1000             2019-03-21 16:37:05                       62.710494            true            false            0x4adf3582                     OrderApplyInfoServiceImpl                                      readCreditDetailByLoanOrderId                                 
     1001             2019-03-21 16:37:05                       -0.022655            true            false            0x708c8fb                      OrderApplyInfoServiceImpl$$EnhancerBySpringCGLIB$$1a8938       readCreditDetailByLoanOrderId                                 
     1002             2019-03-21 16:37:14                       44.213677            true            false            0x4adf3582                     OrderApplyInfoServiceImpl                                      readCreditDetailByLoanOrderId                                 
     1003             2019-03-21 16:37:14                       -0.00271             true            false            0x708c8fb                      OrderApplyInfoServiceImpl$$EnhancerBySpringCGLIB$$1a8938       readCreditDetailByLoanOrderId                                 
     1004             2019-03-21 16:37:55                       59.234538            true            false            0x4adf3582                     OrderApplyInfoServiceImpl                                      readCreditDetailByLoanOrderId                                 
     1005             2019-03-21 16:37:55                       -0.00376             true            false            0x708c8fb                      OrderApplyInfoServiceImpl$$EnhancerBySpringCGLIB$$1a8938       readCreditDetailByLoanOrderId                                 
     1006             2019-03-21 16:38:01                       57.618517            true            false            0x4adf3582                     OrderApplyInfoServiceImpl                                      readCreditDetailByLoanOrderId                                 
     1007             2019-03-21 16:38:01                       -0.003653            true            false            0x708c8fb                      OrderApplyInfoServiceImpl$$EnhancerBySpringCGLIB$$1a8938       readCreditDetailByLoanOrderId                                 
    Affect(row-cnt:8) cost in 11 ms.
    

    对记录进行筛选:

    比如对请求 参数进行筛选:

    $ tt -s "params[0].loanOrderId=='BO119643577337905166'"
     INDEX            TIMESTAMP                                 COST(ms)             IS-RET          IS-EXP           OBJECT                         CLASS                                                          METHOD                                                        
    ------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
     1006             2019-03-21 16:38:01                       57.618517            true            false            0x4adf3582                     OrderApplyInfoServiceImpl                                      readCreditDetailByLoanOrderId                                 
     1007             2019-03-21 16:38:01                       -0.003653            true            false            0x708c8fb                      OrderApplyInfoServiceImpl$$EnhancerBySpringCGLIB$$1a8938       readCreditDetailByLoanOrderId                                 
    Affect(row-cnt:2) cost in 21 ms.
    

    查看具体记录信息:

    $ tt -i 1006
     INDEX          1006                                                                                                                                                                                                                                                          
     GMT-CREATE     2019-03-21 16:38:01                                                                                                                                                                                                                                           
     COST(ms)       57.618517                                                                                                                                                                                                                                                     
     OBJECT         0x4adf3582                                                                                                                                                                                                                                                    
     CLASS          com.shitou.huishi.service.web.OrderApplyInfoServiceImpl                                                                                                                                                                                                       
     METHOD         readCreditDetailByLoanOrderId                                                                                                                                                                                                                                 
     IS-RETURN      true                                                                                                                                                                                                                                                          
     IS-EXCEPTION   false                                                                                                                                                                                                                                                         
     PARAMETERS[0]  @LoanOrderKeyReq[                                                                                                                                                                                                                                             
                        serialVersionUID=@Long[8109590394803201418],                                                                                                                                                                                                              
                        loanOrderId=@String[BO119643577337905166],                                                                                                                                                                                                                
                    ]                                                                                                                                                                                                                                                             
     RETURN-OBJ     @DataResponse[                                                                                                                                                                                                                                                
                        serialVersionUID=@Long[-2479705076778238646],                                                                                                                                                                                                             
                        data=@ApplyInfoDTO[ApplyInfoDTO(loanOrderId=BO119643577337905166, orgSource=及时雨, productName=小微企业经营贷, lenderName=张爱青, lenderNo=99988882, lenderNoType=null, applyMoney=5.00, applyPeriod=24, applyYearRate=63.0000, repaymentType=xxhb_rt, isCredit=0, lo 
                    anUsage=gmsb_lu, loanUsageDesc=xxxxxxxxxxxxxx, ensureType=dy_bz_zy_et, isSmallLoan=null, showExpireTime=null, doorReview=null, conditionAdd=null, isXudai=null)],                                                                                             
                    ]                                                                                                                                                                                                                                                             
    Affect(row-cnt:1) cost in 13 ms.
    

    重做一次调用:

    $ tt -i 1006 -p
     RE-INDEX       1006                                                                                                                                                                                                                                                          
     GMT-REPLAY     2019-03-21 16:45:20                                                                                                                                                                                                                                           
     OBJECT         0x4adf3582                                                                                                                                                                                                                                                    
     CLASS          com.shitou.huishi.service.web.OrderApplyInfoServiceImpl                                                                                                                                                                                                       
     METHOD         readCreditDetailByLoanOrderId                                                                                                                                                                                                                                 
     PARAMETERS[0]  @LoanOrderKeyReq[                                                                                                                                                                                                                                             
                        serialVersionUID=@Long[8109590394803201418],                                                                                                                                                                                                              
                        loanOrderId=@String[BO119643577337905166],                                                                                                                                                                                                                
                    ]                                                                                                                                                                                                                                                             
     IS-RETURN      true                                                                                                                                                                                                                                                          
     IS-EXCEPTION   false                                                                                                                                                                                                                                                         
     COST(ms)       50.881621                                                                                                                                                                                                                                                     
     RETURN-OBJ     @DataResponse[                                                                                                                                                                                                                                                
                        serialVersionUID=@Long[-2479705076778238646],                                                                                                                                                                                                             
                        data=@ApplyInfoDTO[ApplyInfoDTO(loanOrderId=BO119643577337905166, orgSource=及时雨, productName=小微企业经营贷, lenderName=张爱青, lenderNo=99988882, lenderNoType=null, applyMoney=5.00, applyPeriod=24, applyYearRate=63.0000, repaymentType=xxhb_rt, isCredit=0, lo 
                    anUsage=gmsb_lu, loanUsageDesc=xxxxxxxxxxxxxx, ensureType=dy_bz_zy_et, isSmallLoan=null, showExpireTime=null, doorReview=null, conditionAdd=null, isXudai=null)],                                                                                             
                    ]                                                                                                                                                                                                                                                             
    Time fragment[1006] successfully replayed.
    

    参考:

    Arthas 用户文档

  • 相关阅读:
    『转载』优秀ASP.NET程序员的修炼之路
    [转]给年轻工程师的十大忠告
    [转]谈谈技术原则,技术学习方法,代码阅读及其它
    【转贴】你必须知道的20个故事
    谈谈建站心得(转载)[精华]
    HTTP和SOAP完全就是两个不同的协议
    数据集的理解IDataset
    学习在 ArcEngine 中使用 Geoprocessing
    程序执行过程
    How to Run a Geoprocessing Tool
  • 原文地址:https://www.cnblogs.com/hongdada/p/10572776.html
Copyright © 2020-2023  润新知