关于android:systrace-统计方法耗时

本文作者：Fangx3

Android 是单线程模型，用户的按键事件、屏幕触摸及 UI 绘制都在 UI 线程中解决。单线程意味着串行执行，如果某一个操作耗时了就会导致后续的操作都得期待，这个时候用户的第一感知就是卡了。所以在排查卡顿的时候有一个最简略的方法就是找出耗时长的办法。

如何统计办法耗时？

在开发的时候想统计一个办法的耗时最简略的办法就是在办法的开始和完结地位打个工夫戳，两个工夫戳相减就是这个办法的耗时。

fun take() {val start = System.currentTimeMillis()
  //..
  service.take();
  //...
  val end = System.currentTimeMillis()
  val const = end - start
}

下面的办法能统计到咱们利用代码的耗时，然而无奈统计到 Android 的零碎办法耗时。
其实 Android 零碎曾经在一些要害链路上曾经埋入了一些点位，然而它的实现不是像咱们这样埋入工夫戳，而是通过 Trace 类 来实现的，而 Trace 类也反对咱们应用层调用插入自定义的点位，在通过 Android 提供的 systrace 工具，抓取解决 Trace 类打的点位信息。最终生成一个 Html 文件，通过 Chrome 能够直观的查看一个残缺链路的耗时状况。

systrace 在开发阶段的确是一个调优的利器，然而它有两个显著的限度导致这个利器无奈在线上应用：

• 须要连贯 PC 端，通过执行命令的形式开启 Trace 性能，
• 须要开发者手动退出 Trace.beginSection 和Trace.endSection，这就变成了须要开发预判耗时地位手动退出 Trace 函数，然而线上环境无奈预判哪里会耗时。

所以如果可能解决下面两个问题就能将 systrace 这个利器用于线上问题排查了。

脱离 PC 端运行 systrace

这里简略画下 systrace 的工作原理：

从下面的图上能够看到 systrace 抓的数据能够分为两类：

• Java 层和 Native 层产生的函数调用信息
• 内核态的事件信息

其中 Java 层和 Native 层的函数调用信息就是咱们通过调用 Trace 类的办法收集起来的信息 (也是这次咱们须要关怀的数据)，数据信息会记录到trace_marker 中；
而内核态的工夫信息是通过 Linux 提供的 ftrace 性能，通过激活不同的事件节点，在内核运行时依据节点使能状态，会往 ftrace 缓冲中打点记录事件。
最终 systrace 通过回捞上述两个数据整合生成一份 Html 文件。

从上图中能够看到 systrace 通过 Atrace 来设置 Tag，如果可能找到须要抓取的类型信息的对应 Tag，并且间接在端上进行设置，在将 trace_marker 中的数据捞取进去，就能够解脱 PC 端的限度。

端上设置 Tag

public static void beginSection(@NonNull String sectionName) {if (isTagEnabled(TRACE_TAG_APP)) {if (sectionName.length() > MAX_SECTION_NAME_LEN) {throw new IllegalArgumentException("sectionName is too long");
    }
    nativeTraceBegin(TRACE_TAG_APP, sectionName);
  }
}

下面是零碎 Trace 类中的 beginSecion 办法，首先会判断对应的 Tag 是否可用，可用时才会调用 native 层的 TraceBegin 办法写入数据。
而 isTagEnabled 的实现如下：

public static boolean isTagEnabled(long traceTag) {
  long tags = sEnabledTags;
  if (tags == TRACE_TAG_NOT_READY) {tags = cacheEnabledTags();
  }
  return (tags & traceTag) != 0;
}

private static long cacheEnabledTags() {long tags = nativeGetEnabledTags();
  sEnabledTags = tags;
  return tags;
}

看到这里在想是不是通过反射批改 sEnabledTags 的值就能够开启 Trace 性能了呢？
通过实际能够发现，仅批改 sEnabledTags 还是无奈开启 Trace 性能，因而能够大略猜想在 native 层应该也是有相似的判断，具体的 native 代码在 /system/core/libcutils/trace-dev.c(Android O 版本代码) 文件下

static inline void atrace_begin(uint64_t tag, const char* name)
{if (CC_UNLIKELY(atrace_is_tag_enabled(tag))) {void atrace_begin_body(const char*);
        atrace_begin_body(name);
    }
}

能够看到这里逻辑和 Java 中的解决相似，也是先判断 Tag 是否可用，如果可用才执行写入数据逻辑，持续看下 atrace_is_tag_enabled 的实现，

static inline uint64_t atrace_is_tag_enabled(uint64_t tag)
{return atrace_get_enabled_tags() & tag;
}
static inline uint64_t atrace_get_enabled_tags()
{atrace_init();
    return atrace_enabled_tags;
}

能够看到这里是获取了 atrace_enabled_tags 字段的值在进行与操作，而 Trace 类中的 sEnabledTags 也是通过 nativeGetEnabledTags 办法获取到的这个值。因而咱们应该批改下 native 层的这个值就能够开启 Trace 性能了。

这里参考了 Facebook 的 profilo 的计划，通过 dlopen 获取 libcuitls.so 对应的句柄，通过从对应 symbol 中找到 atrace_enabled_tags 的指针，从而设置 atrace_enabled_tags 来关上 Trace 性能。

std::string lib_name("libcutils.so");
std::string enabled_tags_sym("atrace_enabled_tags");

if (sdk < 18) {
  lib_name = "libutils.so";
  enabled_tags_sym = "_ZN7android6Tracer12sEnabledTagsE";
}
if (sdk < 21) {handle = dlopen(lib_name.c_str(), RTLD_LOCAL);
} else {handle = dlopen(nullptr, RTLD_GLOBAL);
}

atrace_enabled_tags = reinterpret_cast<std::atomic<uint64_t> *>(dlsym(handle, enabled_tags_sym.c_str()));

atrace_enabled_tags 在不同版本上其符号名不一样，所以这里须要作下版本辨别。
查问具体的符号名称能够通过 objdump 工具查看，在 Mac 上能够应用 binutils 工具提供的 gobjdump 工具来查看。
像下面的 atrace_enabled_tags 的符号在 Android 版本 18 以下，咱们就能够间接通过 gobjdump 工具查看取得：

然而有时候一个符号名称可能会被 mangle，在查看时不是太直观和确认是否是咱们须要的符号名称，能够在通过 c++filt 工具 demangle 这个符号从而失去一个比拟直观的符号名称，不便咱们确认。

到这里咱们就拿到了 atrace_enabled_tags 符号对应的指针，在批改成具体的对应的 Tag 值，同时通过反射同步批改 Trace 类中的 sEnabledTags 值，就开启了 Trace 性能。这里要设置的 Tag 能够具体看下零碎提供的 Trace 类，外面具体定义了所有的 Tag 值，咱们能够通过对这些 Tag 值的或操作来失去一个最终须要设置的 int 类型的值。

数据回捞

通过下面的步骤咱们能够不必在 PC 端执行 systrace 脚本的形式开启 Trace 性能，然而从下面的实现原理图上能够看到数据最终是写在 trace_marker 中，而这个是在内核态中，应用层是无奈间接读取的。在查找 Trace 开启对应的 Tag 的过程中能够看到在 native 代码中还有定义了：

int  atrace_marker_fd     = -1;

通过查看代码能够发现这个字段就是对应的 trace_marker 的文件描述符。
而咱们在调用 Trace.beginSection 写入的时候最终是会调用到 native 层的 atrace_begin_body 办法

void atrace_begin_body(const char* name)
{char buf[ATRACE_MESSAGE_LENGTH];

    int len = snprintf(buf, sizeof(buf), "B|%d|%s", getpid(), name);
    if (len >= (int) sizeof(buf)) {ALOGW("Truncated name in %s: %s\n", __FUNCTION__, name);
        len = sizeof(buf) - 1;
    }
    write(atrace_marker_fd, buf, len);
}

能够看到最终的写入过程其实就是调用了 write 办法实现的。

咱们能够和下面获取 atrace_enabled_tags 一样的形式拿到 trace_marker 的文件描述符对应的指针，这样有了文件描述符，在通过 hook 零碎的 write 办法，在 write 办法中通过文件描述符判断是否是往 trace_marker 中写入内容，如果是的话能够将内容间接保留到咱们自定义的一个文件中，实现数据回捞。

然而从下面代码中能够看到最终写入到 trace_marker 中的内容是 “B|pid|name” 这样一串数据，如果只是这样一串内容的数据还是无奈被 systrace 工具辨认解析的，因而咱们还须要依照上面的格局进行数据补全。

< 线程名 > - < 线程 id>  [000] ...1 < 工夫 - 秒 >: tracing_mark_write: <B|E>|< 过程 id>|<TAG>

将数据保留文件导出后，能够通过 systrace 工具提供的 --from-file 参数将文件转为 Html 文件，就能够通过 Chrome 关上查看了。
最新的 SDK Platform Tools 曾经移除了 systrace 工具，这里能够间接通过 Perfetto 间接关上导出的文件，不须要在将文件进行转换。
通过端上开启 Trace 之后抓的数据成果最终如下，能够看到 Android 零碎中埋的点和咱们本人增加的点的数据都能抓取到。

预判耗时？

systrace 的另一个痛点是须要开发手动插入 Trace.beginSection 和 Trace.endSection 办法，这就意味着须要开发预判哪里的函数耗时。然而大部分状况下可能并不知道哪里可能会产生耗时，特地是线上环境，根本无法判断哪里会产生耗时。既然无奈预判，那就全副减少，然而这个对一个大我的项目来说工作量微小，没有实操性。因而这里通过函数插桩的形式在每个办法中退出 Trace 的办法。

在插桩时如果只是设置办法名称，最终生成的文件可读性较差，不利于进行数据分析，然而如果插入方法的全限定名称 Trace.beginSection 办法中对 sectionName 的长度有限度，因而这里参考了腾讯的 martix 的实现生成 methodId，插入的时候插入一个 methodId，这样能够防止 beginSection 办法的长度限度。

最终的成果如上图。

操作几次后会发现最初生成的文件中会有一些 Did not Finish 的数据

前后数据分析之后，发现是这些中央抛了异样走了异样流程导致 Trace 数据没有闭合。因而在插桩的时候还须要在抛异样的 catch 代码块中也插入 Trace.endSection，实现数据闭合。

总结

借助零碎提供的 Trace 性能帮咱们生成一个残缺的调用链路信息，利于开发进行问题排除；在端上开启 systrace 性能解脱了 PC 的限度，不便咱们在各种环境下进行数据抓取，能帮忙咱们发现一些偶现或暗藏的耗时卡顿问题。

参考资料

• https://github.com/facebookin…
• https://github.com/Tencent/ma…
• https://linux.cn/article-9838…
• https://segmentfault.com/a/11…

本文公布自网易云音乐技术团队，文章未经受权禁止任何模式的转载。咱们长年招收各类技术岗位，如果你筹备换工作，又恰好喜爱云音乐，那就退出咱们 grp.music-fe(at)corp.netease.com！