trace分析方法

    trace 格式化输出主要有两种类型：flow 和 format 。flow 输出包括后缀名为 version, flw, except, funcRecord.csv, error 的5个文件；format 输出包括后缀名为 version, fmt 的2个文件。下面具体介始各个文件的输出及各部分的具体含义。

    • 版本文件： 后缀名为 version，可以通过该文件了解引擎的版本号和 Release。
    • 流程文件： 后缀名为 flw，按线程执行流程进行组织输出，输出组成如下：
    • 异常文件：后缀名为 except，函数调用中，两处跟踪之间最大时间间隔大于3ms 时，该函数的跟踪记录会被输出到这个文件中。

    • 汇总统计文件：后缀名为 funcRecord.csv，这个属于汇总性质的文件，其中每一行由如下几个部分组成：

      • 函数名
      • 被调用次数
      • 平均开销
      • 最小开销
      • 最大总的开销
      • 最大自身开销
      • 最大时间间隔 top 5 的跟踪记录，top 5跟踪记录的格式为: 顺序号，函数调用总的开销，函数调用自身的开销，最大时间间隔

      函数自身的开销是把调用子函数的开销排除在外的，函数调用的总的开销是包含子函数调用的开销的，最大时间间隔一般是一个函数中最耗时的部分，所有开销的单位都微秒。

    • 错误文件：后缀名为 error，错误输出文件，主要是记录存在函数出口的跟踪记录，没有匹配到函数入口的跟踪记录。

    • 格式化文件： 后缀名为 fmt，按照 dump 出来的二进制文件直接格式化输出的结果，其中输出各部分如下表：

    结合 trace 分析问题

    trace 可以用来分析两类问题，常规问题和性能问题。分析常规问题时，主要关注 flw 文件，找到最开始报错的函数结合代码进行分析。

    • 创建集合空间，报 -133，重现问题
    1. db.createCS('example')
    • 导出跟踪记录为二进制文件
    1. db.traceOff("dbpath/11820.dump")
    • 格式化输出
    • 打开11820.flw，找到最初报 -133 的位置：
    1. 14502:  | | | | | sdbCatalogueCB::getAGroupRand Entry(650): 2019-04-28-17.26.49.916397
    2. 14503:  | | | | | | sdbCatalogueCB::getAGroupRand(653): 2019-04-28-17.26.49.916397
    3. 14504:  | | | | | sdbCatalogueCB::getAGroupRand Exit[retCode=-133](689): 2019-04-28-17.26.49.916397
    4. 14505:  | | | | catCatalogueManager::_assignGroup Exit[retCode=-133](1057): 2019-04-28-17.26.49.916398
    5. 14506:  | | | | pdLog Entry(431): 2019-04-28-17.26.49.916398
    • 显示 sdbCatalogueCB::getAGroupRand 最开始报 -133，结合代码是由于 grpMapId 为空导致报错：
    2. {
    3.    INT32 rc = SDB_CAT_NO_NODEGROUP_INFO ;
    4.    PD_TRACE_ENTRY ( SDB_CATALOGCB_GETAGROUPRAND ) ;
    5.    PD_TRACE1 ( SDB_CATALOGCB_GETAGROUPRAND,
    6.                   PD_PACK_UINT ( mapSize ) ) ;
    7.    if ( mapSize > 0 )
    8.    {
    10.    }
    11. done:
    12.    PD_TRACE_EXITRC ( SDB_CATALOGCB_GETAGROUPRAND, rc ) ;
    13.    return rc;
    14. }

    • 向 _grpIdMap 插入元素的方法是激活组，找到激活组的命令，确认客户端的操作激活组，定位到需要调用 group.start() 。

    • 分析性能问题，先通过 funcRecord.csv 文件找到执行次数( count )，平均开销( avgcost )或者是两者的乘积最大的跟踪记录。结合 except 找到该函数最耗时的部分定位到 flw 文件的调用栈进行分析。

    • 遇到一个操作长时间没有返回，可以通过会话快照找到执行当前操作的节点，连接到该节点并开启 trace：

    • 等待一定时间，关闭 trace ，dump 跟踪记录为二进制文件：
    1. db.traceOff('dbpath/11850.dump')
    • 格式化输出
      • 打开 funRecord.csv 文件，按照 count 或者 avgcost 或者 count * avgcost 列进行排序：

      用户从调用次数最多的函数入手，找到最大时间间隔 top 5 中的 first 里面的顺序号810062。如果从最大耗时入手，应先关联 except 文件，找到耗时最大的调用点，从调用次数入手的会直接通过顺序号去关联 flw 文件。以下是通过顺序号关联 flw 的结果：