tt命令

方法执行数据的时空隧道，记录下指定方法每次调用的入参和返回信息，并能对这些不同的时间下调用进行观测

watch 虽然很方便和灵活，但需要提前想清楚观察表达式的拼写，这对排查问题而言要求太高，因为很多时候我们并不清楚问题出自于何方，只能靠蛛丝马迹进行猜测。

这个时候如果能记录下当时方法调用的所有入参和返回值、抛出的异常会对整个问题的思考与判断非常有帮助。

于是乎，TimeTunnel 命令就诞生了。

对于一个最基本的使用来说，就是记录下当前方法的每次调用环境现场。

 

参数说明

• -t

  tt 命令有很多个主参数，-t 就是其中之一。这个参数的表明希望记录下类 *Test 的 print 方法的每次执行情况。

• -n 3

  当你执行一个调用量不高的方法时可能你还能有足够的时间用 CTRL+C 中断 tt 命令记录的过程，但如果遇到调用量非常大的方法，瞬间就能将你的 JVM 内存撑爆。

  此时你可以通过 -n 参数指定你需要记录的次数，当达到记录次数时 Arthas 会主动中断tt命令的记录过程，避免人工操作无法停止的情况

 

使用参考

# 记录com.kq.springboot.controller包下的所有控制器的所有方法
tt -t com.kq.springboot.controller.*Controller *

 INDEX    TIMESTAMP            COST(ms)   IS-RET   IS-EXP   OBJECT          CLASS                           METHOD
--------------------------------------------------------------------------------------------------------------------------------------------
 1002     2019-08-28 13:07:09  0.661655   true     false    0x24ad77e9      IndexController                 register
 1003     2019-08-28 13:07:18  0.346577   true     false    0x24ad77e9      IndexController                 register
 1004     2019-08-28 13:07:21  0.228743   true     false    0x24ad77e9      IndexController                 path
 1005     2019-08-28 13:07:33  0.074181   true     false    0x24ad77e9      IndexController                 path
 1006     2019-08-28 13:07:34  0.068274   true     false    0x24ad77e9      IndexController                 path
 1007     2019-08-28 13:07:41  0.067423   true     false    0x24ad77e9      IndexController                 path
 1008     2019-08-28 13:07:42  0.064989   true     false    0x24ad77e9      IndexController                 path
 

• 表格字段说明

表格字段	字段解释
INDEX	时间片段记录编号，每一个编号代表着一次调用，后续tt还有很多命令都是基于此编号指定记录操作，非常重要。
TIMESTAMP	方法执行的本机时间，记录了这个时间片段所发生的本机时间
COST(ms)	方法执行的耗时
IS-RET	方法是否以正常返回的形式结束
IS-EXP	方法是否以抛异常的形式结束
OBJECT	执行对象的hashCode()，注意，曾经有人误认为是对象在JVM中的内存地址，但很遗憾他不是。但他能帮助你简单的标记当前执行方法的类实体
CLASS	执行的类名
METHOD	执行的方法名

• 条件表达式

• 解决方法重载

  tt -t *Test print params.length==1

  通过制定参数个数的形式解决不同的方法签名，如果参数个数一样，你还可以这样写

  tt -t *Test print 'params[1] instanceof Integer'

• 解决指定参数

  tt -t *Test print params[0].mobile=="13989838402"

 

# 列出记录
tt -l 

INDEX    TIMESTAMP            COST(ms)   IS-RET   IS-EXP   OBJECT          CLASS                           METHOD
--------------------------------------------------------------------------------------------------------------------------------------------
 1002     2019-08-28 13:07:09  0.661655   true     false    0x24ad77e9      IndexController                 register
 1003     2019-08-28 13:07:18  0.346577   true     false    0x24ad77e9      IndexController                 register
 1004     2019-08-28 13:07:21  0.228743   true     false    0x24ad77e9      IndexController                 path
 1005     2019-08-28 13:07:33  0.074181   true     false    0x24ad77e9      IndexController                 path
 1006     2019-08-28 13:07:34  0.068274   true     false    0x24ad77e9      IndexController                 path
 1007     2019-08-28 13:07:41  0.067423   true     false    0x24ad77e9      IndexController                 path
 1008     2019-08-28 13:07:42  0.064989   true     false    0x24ad77e9      IndexController                 path

# 根据方法名从记录中找
tt -s 'method.name=="register"'

INDEX    TIMESTAMP            COST(ms)   IS-RET   IS-EXP   OBJECT          CLASS                           METHOD
--------------------------------------------------------------------------------------------------------------------------------------------
 1000     2019-08-28 13:05:55  2.13737    true     false    0x24ad77e9      IndexController                 register
 1001     2019-08-28 13:06:08  0.258676   true     false    0x24ad77e9      IndexController                 register
 1002     2019-08-28 13:07:09  0.661655   true     false    0x24ad77e9      IndexController                 register
 1003     2019-08-28 13:07:18  0.346577   true     false    0x24ad77e9      IndexController                 register
Affect(row-cnt:4) cost in 403 ms.

查看调用信息

对于具体一个时间片的信息而言，你可以通过 -i 参数后边跟着对应的 INDEX 编号查看到他的详细信息

# -i 是INDEX
tt -i 1003

INDEX          1003
 GMT-CREATE     2019-08-28 13:07:18
 COST(ms)       0.346577
 OBJECT         0x24ad77e9
 CLASS          com.kq.springboot.controller.IndexController
 METHOD         register
 IS-RETURN      true
 IS-EXCEPTION   false
 PARAMETERS[0]  @RequestFacade[
                    request=@Request[org.apache.catalina.connector.Request@4cb09ba8],
                    sm=@StringManager[org.apache.tomcat.util.res.StringManager@7e0e2e44],
                ]
 RETURN-OBJ     @DtoResult[
                    code=@String[000000],
                    result=@String[king_3],
                ]
Affect(row-cnt:1) cost in 30 ms.
 

 

重做一次调用

当你稍稍做了一些调整之后，你可能需要前端系统重新触发一次你的调用，此时得求爷爷告奶奶的需要前端配合联调的同学再次发起一次调用。而有些场景下，这个调用不是这么好触发的。

tt 命令由于保存了当时调用的所有现场信息，所以我们可以自己主动对一个 INDEX 编号的时间片自主发起一次调用，从而解放你的沟通成本。此时你需要 -p 参数。通过 --replay-times 指定 调用次数，通过 --replay-interval 指定多次调用间隔(单位ms, 默认1000ms)

tt -i 1005 -p

你会发现结果虽然一样，但调用的路径发生了变化，有原来的程序发起变成了 Arthas 自己的内部线程发起的调用了。

• 需要强调的点

  1. ThreadLocal 信息丢失

     很多框架偷偷的将一些环境变量信息塞到了发起调用线程的 ThreadLocal 中，由于调用线程发生了变化，这些 ThreadLocal 线程信息无法通过 Arthas 保存，所以这些信息将会丢失。

     一些常见的 CASE 比如：鹰眼的 TraceId 等。

  2. 引用的对象

     需要强调的是，tt 命令是将当前环境的对象引用保存起来，但仅仅也只能保存一个引用而已。如果方法内部对入参进行了变更，或者返回的对象经过了后续的处理，那么在 tt 查看的时候将无法看到当时最准确的值。这也是为什么 watch 命令存在的意义。