Android Systrace 基础知识 -- 分析 Systrace 预备知识

Word count: 3.1kReading time: 11 min

 2019/07/23

本文是 Systrace 系列文章的第二篇，主要是讲解一些分析 Systrace 的预备知识, 有了这些预备知识, 分析 Systrace 才会事半功倍, 更快也更有效率地找到问题点.

本文介绍了如何查看 Systrace 中的线程状态, 如何对线程的唤醒信息进行分析, 如何解读信息区的数据, 以及介绍了常用的快捷键. 通过本篇文章的学习, 相信你可以掌握进程和线程相关的一些信息, 也知道如何查看复杂的 Systrace 中包含的关键信息

系列文章目录

正文

用 Perfetto 阅读本文

本文讲的是分析 Trace 前需要建立的几个基础能力：线程状态、唤醒关系、信息区字段和快捷操作。旧 Systrace UI 和新 Perfetto UI 的界面不一样，但这几个能力仍然是同一套分析基础。

旧流程里，线程状态通过 Systrace HTML 里的颜色直接展示，点击 Slice 后在下方信息区看 Duration、Thread、Process、唤醒关系等字段；新流程里，Perfetto 会把这些信息拆到线程轨道、CPU 调度轨道、选择面板、搜索结果和 SQL 表中。读法要从“看一张 HTML 图”变成“先看轨道，再用搜索/SQL 收敛证据”。

对应到 Perfetto 系列，可以这样读：

本文知识点	Perfetto 中的对应入口
打开、缩放、搜索、选中 Slice	Perfetto 3：熟悉 Perfetto View
Running、Runnable、Sleep 等线程状态	Perfetto 9：CPU 信息解读
主线程等待、RenderThread 等待、Binder 等待	Perfetto 7：MainThread 和 RenderThread / Perfetto 10：Binder 调度与锁竞争

线程状态查看

Systrace 会用不同的颜色来标识不同的线程状态, 在每个方法上面都会有对应的线程状态来标识目前线程所处的状态，通过查看线程状态我们可以知道目前的瓶颈是什么, 是 cpu 执行慢还是因为 Binder 调用, 又或是进行 io 操作, 又或是拿不到 cpu 时间片

如果现在用 Perfetto 看同类问题，不要只找和 Systrace 完全一样的颜色。更稳定的做法是同时看三类信息：线程轨道上的 Slice，CPU 轨道上的实际 Running 区间，以及调度状态里的 Runnable/Sleep/Uninterruptible Sleep。这样才能区分“函数自己执行慢”“线程醒了但没抢到 CPU”“线程在等 Binder/锁/IO”这几类完全不同的问题。

线程状态主要有下面几个

绿色 : 运行中（Running）

只有在该状态的线程才可能在 cpu 上运行。而同一时刻可能有多个线程处于可执行状态，这些线程的 task_struct 结构被放入对应 cpu 的可执行队列中（一个线程最多只能出现在一个 cpu 的可执行队列中）。调度器的任务就是从各个 cpu 的可执行队列中分别选择一个线程在该cpu 上运行

作用：我们经常会查看 Running 状态的线程，查看其运行的时间，与竞品做对比，分析快或者慢的原因：

是否频率不够？
是否跑在了小核上？
是否频繁在 Running 和 Runnable 之间切换？为什么？
是否频繁在 Running 和 Sleep 之间切换？为什么？
是否跑在了不该跑的核上面？比如不重要的线程占用了超大核

蓝色 : 可运行（Runnable）

线程可以运行但当前没有安排，在等待 cpu 调度

作用：Runnable 状态的线程状态持续时间越长，则表示 cpu 的调度越忙，没有及时处理到这个任务：

是否后台有太多的任务在跑？
没有及时处理是因为频率太低？
没有及时处理是因为被限制到某个 cpuset 里面，但是 cpu 很满？
此时 Running 的任务是什么？为什么？

白色 : 休眠中（Sleep）

线程没有工作要做，可能是因为线程在互斥锁上被阻塞。

作用：这里一般是在等事件驱动

橘色 : 不可中断的睡眠态（Uninterruptible Sleep - IO Block）

线程在I / O上被阻塞或等待磁盘操作完成，一般底线都会标识出此时的 callsite ：wait_on_page_locked_killable

作用：这个一般是标示 io 操作慢，如果有大量的橘色不可中断的睡眠态出现，那么一般是由于进入了低内存状态，申请内存的时候触发 pageFault, linux 系统的 page cache 链表中有时会出现一些还没准备好的 page(即还没把磁盘中的内容完全地读出来), 而正好此时用户在访问这个 page 时就会出现 wait_on_page_locked_killable 阻塞了. 只有系统当 io 操作很繁忙时, 每笔的 io 操作都需要等待排队时, 极其容易出现且阻塞的时间往往会比较长.

紫色 : 不可中断的睡眠态（Uninterruptible Sleep）

线程在另一个内核操作（通常是内存管理）上被阻塞。

作用：一般是陷入了内核态，有些情况下是正常的，有些情况下是不正常的，需要按照具体的情况去分析

线程唤醒信息分析

Systrace 会标识出一个非常有用的信息，可以帮助我们进行线程调用等待相关的分析。

一个线程被唤醒的信息往往比较重要，知道他被谁唤醒，那么我们也就知道了他们之间的调用等待关系，如果一个线程出现一段比较长的 sleep 情况，然后被唤醒，那么我们就可以去看是谁唤醒了这个线程，对应的就可以查看唤醒者的信息，看看为什么唤醒者这么晚才唤醒。

一个常见的情况是：应用主线程程使用 Binder 与 SystemServer 的 AMS 进行通信，但是恰好 AMS 的这个函数正在等待锁释放（或者这个函数本身执行时间很长），那么应用主线程就需要等待比较长的时间，那么就会出现性能问题，比如响应慢或者卡顿，这就是为什么后台有大量的进程在运行，或者跑完 Monkey 之后，整机性能会下降的一个主要原因

另外一个场景的情况是：应用主线程在等待此应用的其他线程执行的结果，这时候线程唤醒信息就可以用来分析主线程到底被哪个线程 Block 住了，比如下面这个场景，这一帧 doFrame 执行了 152ms，有明显的异常，但是大部分时间是在 sleep

这时候放大来看，可以看到是一段一段被唤醒的，这时候点击图中的 runnable ，下面的信息区就会出现唤醒信息，可以顺着看这个线程到底在做什么。换到 Perfetto 后，分析思路不变：先定位主线程或目标线程的长 Sleep/Runnable 区间，再回看唤醒相关事件和当时正在 CPU 上运行的线程；如果肉眼看不清，就用 sched/thread_state 相关数据做 SQL 查询，把等待时间和唤醒来源列出来。

20424 线程是 RenderHeartbeat，这就牵扯到了 App 自身的代码逻辑，需要 App 自己去分析 RenderHeartbeat 到底做了什么事情

Systrace 可以标示出这个的一个原因是，一个任务在进入 Running 状态之前，会先进入 Runnable 状态进行等待，而 Systrace 会把这个状态也标示在 Systrace 上（非常短，需要放大进行看）

拉到最上面查看对应的 cpu 上的 taks 信息，会标识这个 task 在被唤醒之前的状态：

顺便贴一下 Linux 常见的进程状态

D 无法中断的休眠状态（通常 IO 的进程）；
R 正在可运行队列中等待被调度的；
S 处于休眠状态；
T 停止或被追踪；
W 进入内存交换（从内核2.6开始无效）；
X 死掉的进程（基本很少見）；
Z 僵尸进程；
< 优先级高的进程
N 优先级较低的进程
L 有些页被锁进内存
s 进程的领导者（在它之下有子进程）
l 多进程的（使用 CLONE_THREAD, 类似 NPTL pthreads）
+ 位于后台的进程组

信息区数据解析

线程状态信息解析

函数 Slice 信息解析

Counter Sample 信息解析

Async Slice 信息解析

CPU Slice 信息解析

User Expectation 信息解析

位于整个 Systrace 最上面的部分,标识了 Rendering Response 和 Input Response

快捷键使用

快捷键的使用可以加快查看 Systrace 的速度,下面是一些常用的快捷键

W : 放大 Systrace, 放大可以更好地看清局部细节
S : 缩小 Systrace, 缩小以查看整体
A : 左移
D : 右移
M : 高亮选中当前鼠标点击的段(这个比较常用,可以快速标识出这个方法的左右边界和执行时间,方便上下查看)

鼠标模式快捷切换 : 主要是针对鼠标的工作模式进行切换, 默认是 1,也就是选择模式,查看 Systrace 的时候,需要经常在各个模式之间切换, 所以点击切换模式效率比较低,直接用快捷键切换效率要高很多

数字键1 : 切换到 Selection 模式, 这个模式下鼠标可以点击某一个段查看其详细信息, 一般打开 Systrace 默认就是这个模式, 也是最常用的一个模式 , 配合 M 和 ASDW 可以做基本的操作
数字键2 : 切换到 Pan 模式, 这个模式下长按鼠标可以左右拖动, 有时候会用到
数字键3 : 切换到 Zoom 模式, 这个模式下长按鼠标可以放大和缩小, 有时候会用到
数字键4 : 切换到 Timing 模式, 这个模式下主要是用来衡量时间的,比如选择一个起点, 选择一个终点, 查看起点和终点这中间的操作所花费的时间.