安装
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.