资讯动态

CPU Scheduling Events实战:从Perfetto trace中揪出启动卡顿的真凶

发布时间:2026/10/13 15:27:23 来源:尧图企业网站定制
真正让我把 CPU Scheduling events 当回事的是一次莫名其妙的 400ms 启动白屏。当时我在某个 Android 项目的性能优化里排查了大半天方法耗时、布局耗时、首帧渲染常规链路全都查了一遍始终没有看到异常。反倒是 Perfetto trace 里主线程的 CPU Scheduling events 一眼暴露了问题主线程被唤醒之后长时间处于 Runnable 状态却一直没有被调度到某个核心上运行。从那时候开始我把 Perfetto 官方文档中 CPU Scheduling events 的部分从头到尾啃了一遍发现这里面的门道比印象中要多得多。这篇文章就是我阅读这些文档和对 trace 的复盘记录适合刚接触 Perfetto、拿到 trace 却不知道从哪下手的人也适合已经会看线程切片、但面对一些奇怪调度现象时还找不到解释的开发者。我会按照官方文档给的结构来展开把事件格式、UI 上的呈现逻辑、以及更进阶的 Trace Processor SQL 查询都串起来尽量让读者读完以后能自己复现整套排查思路而不是只会点按钮。1. 为什么我先翻 Perfetto 官方文档的 Scheduling events1.1 一次启动卡顿排查让我看到调度时间线的价值先说回那 400ms 白屏。初查时我在 Method Trace 里看到主线程有段时间几乎没有任何操作但界面就是没出来。直觉告诉我这不是单纯的应用代码问题于是抓了一份 perfetto trace默认视图下只看到一堆 wakelock、binder 和 surfaceflinger 相关的轨道信息量很大但没法直接定位。把视图切到 CPU Scheduling 相关的轨道之后主线程那一行的表现非常清楚某段时间内主线程先是在 Running 状态跑了一段然后进入 Sleep过了很久才被某个后台线程唤醒醒来之后又变成 Runnable等待了约 300ms 才真正拿到 CPU。正是“唤醒后长时间等不到调度”这一点让我意识到问题不在方法耗时而在调度器本身。这一下就把排查方向从应用层拽到了内核调度层。所以如果你的目标是分析卡顿、启动慢、功耗异常而不是单纯看函数耗时那 CPU Scheduling events 几乎是必读的。Perfetto 官方文档把这一大块内容列在 Events 分节里大多数人看 UI 入门教程时都会略过原始格式但恰恰是这些原始格式才能解释 UI 上为什么会出现各种各样让人看不懂的 slice。1.2 官方文档这几页的结构与阅读路径Perfetto 官方文档里讲到 Linux kernel tracing 数据源时会列出 ftrace 支持的各个事件类别sched 相关事件是其中最常用的一块。文档通常不会直接手把手带你点 UI而是先告诉你每个事件的名称、字段、触发时机然后告诉你它在 UI 里会被如何可视化再往后是 Trace Processor 里对应的 SQL 表和查询方式。我的建议是读的时候不要只盯着 UI 截图。文档把原始事件格式讲清楚的部分才是整篇的钥匙。你知道了sched_switch是一条一条在 CPU 上实时发生的事件再回头看 UI 线程轨道上的那些色块就会明白那些色块不是凭空画出来的而是从事件里重建出来的区间。顺序可以是原始事件格式 - UI 呈现 - SQL 表查询这个三段式阅读路径能让你在任何一层卡住时都知道问题出在哪。2. sched_switch 背后那几行内核逻辑决定了你看到的一切2.1 sched_switch 时机与记录格式调度器的核心职责之一就是把某个 CPU 上正在运行的线程换下去再选一个新线程跑上去。每一次这样的切换内核里的 tracepoint 都会触发一条sched_switch事件。Perfetto 文档中给出的典型格式类似sched_switch: prev_commtelnetd prev_pid126 prev_prio120 prev_stateS next_commswapper/0 next_pid0 next_prio120这条事件看似简单其实信息量非常大。prev_comm和prev_pid是之前正在跑的线程prev_state表示它被换下去时的状态next_comm和next_pid是即将拿到 CPU 的线程。如果你把很多条这样的记录按时间排开就已经可以看到每个线程在哪个时刻让出了 CPU、又是在哪个时刻获得了 CPU。官方文档对字段来源解释得比较清楚这些值直接来自内核调度器在context_switch时保存的 task_struct 信息而不是用户态监控程序拍脑袋造的。所以它的可信度非常高几乎可以当作内核行为的直接观察窗口。这里有个容易被忽略的细节prev_state的值并不总是常见的 R 或者 S还有 D不可中断睡眠、T停止、Z僵尸等它们都来自内核线程状态标志。我在文档里特别留意过这一列因为排查 IO 卡顿时常常会看到 D 状态那是进程正在等不可中断的 IO既不能被信号打断也不能被正常调度换走。2.2 prev_comm 与 next_comm先读谁在让谁很多新手拿到 trace 后会有一个误区只看next_comm以为只要看到某个线程名字出现在 next 里它就是“被切换进来了”。其实理解一条sched_switch必须同时看前后两个线程。比如你在 100ms 处看到这样的记录prev_commBinder:12345_A next_commmain这意味着 Binder 线程被换下主线程被换上。真正的问题是Binder 线程为什么在这个时间点主动让出 CPU它是在等某个锁还是在等 IO还是时间片到了被抢占这三个原因在prev_state里会有不一样的体现。我通常的读法是把相邻几条sched_switch串成一个完整故事。举个例子如果主线程被换上去只跑了 2ms 又被换下来而换下来的下一跳又轮到另一个高优先级实时线程那就要警惕是不是存在优先级反转或者调度延迟。UI 上的切片虽然也能看出大概但缺少字段细节很多解释不了的坑最终都要回到原始事件上才能讲通。2.3 sched_wakeup 与 wakeup_new把“唤醒”和“切换”串起来prev_state能告诉你某个线程“当时为什么不在 CPU 上”但它解释不了“这个线程是怎么被从睡眠状态拉回来的”。恰恰是这个拉回来的过程隐藏了等待时间的大头。Perfetto 文档里专门讲了sched_wakeup事件当某个线程被另一个线程唤醒时内核会记录一条 wakeup里面包含唤醒者、被唤醒者的 pid、目标 CPU 等信息。还需要注意的是sched_wakeup_new它出现的主要场景是进程或线程刚被创建并首次唤醒。两者在文档中区分得非常清楚。排查冷启动问题时新创建的线程第一次被唤醒的时间点往往会直接影响后续任务的执行顺序所以这个事件也值得重点盯。在时间线上最常见的联动模式是某个线程先收到 wakeup接着过了一段时间才出现对应的sched_switch把那线程切换进来。从 wakeup 到 switch 之间的这段等待就是调度延迟也可以理解为排队时间。如果这段延迟很大说明目标线程不是立刻就能被调度很可能目标 CPU 正被高优任务占着或者整个 runqueue 都很长。3. Trace UI 时间线上同样一段运行用调度视角能看出什么3.1 线程切片内的着色规则Perfetto UI 打开后进程下会列出所有线程的轨道每个轨道上一段一段的色块就是该线程在一段时间内的调度状态。默认主题下面绿色一般是 Running蓝色属于 Runnable灰色或者深色是 Sleep 或 Uninterruptible Sleep 等非运行状态。颜色不是随便定的它本质上是sched_switch里prev_state的映射。你看到一个线程轨道上有大片灰色空白并不是说系统没有记录它而是这些时间片里线程不在 CPU 上调度器没有必要每次“睡眠”都反复记一条切换事件UI 就把两个切换之间的长时间空白合并成了一段 sleep 状态。我强烈建议不要只看主线程的轨道相邻的 CPU 轨道也要看。例如一个线程在 Core 0 上运行了很久它旁边的 CPU 轨道会有对应的频率和 idle 状态。如果这个核心大部分时间处于 idle而主线程却在另一个核心上排队那也许说明内核调度器的负载均衡没做好或者 CPU 亲和性设置让某个核心被闲置了。3.2 选择一条 slice 后右侧面板看什么选中某个线程的一个 Running slice 后右侧详情面板会列出 slice 名称、类别、起止时间、持续时间、线程名、pid、调度状态等一系列字段。这些字段大多直接来自sched_switch和sched_wakeup的组合。我最爱看的是“Scheduling State”和“Thread State”之间的区别很多文档读者在这里会被绕晕。切片本身的名称可能是Running但如果你展开查看属性能看到事件里记录的prev_state或者wakeup来源。换句话说一行切片只是“表象”真正决定它长短的是那一串事件时间戳。具体操作上我会先点击主线程上最长的 Running slice看看它落在哪个阶段。如果 slice 从第 1 秒持续到第 1.5 秒那大概率是主线程在纯计算或者同步等待某个资源而不是频繁被抢占。接着再点击主线程睡眠前的最后一个唤醒点看 wakeup 离 switch 隔了多远这样就能把“线程为什么慢”拆成“没在 CPU 上”和“在 CPU 上没干完”两部分。3.3 CPU Frequency 与空闲轨道另一条平行证据Perfetto UI 顶部或左侧轨道区通常会有单独的 CPU Frequency 轨道每个 CPU 核心的频率变化会以折线或色块显示。官方文档里频率采样和调度事件共享同一套 trace 数据源但在事件类型上是独立记的。读调度时间线时CPU 频率要当“辅助证据”用。假设你在某个 slice 上看到线程经常处于 Runnable但同时对应 CPU 的频率处在比较低的档位说明核心可能因为负载预测不足处于降频状态线程被唤醒后虽然排到了队却要等频率被拉上去才能快速跑完。相反如果线程切进来后立刻满频运行那问题可能更多在任务量本身。空闲状态轨道表达了 CPU 进入 C-state 和退出的情况。CPU 进入深空闲说明长时间没有可运行任务退出空闲到真正开始执行任务中间有一段延迟。这些都要和sched_wakeup一起看才能还原“一个线程从发起到跑起来”全过程的真实时间分布。4. 那些容易读错的事件cpu_idle、cpu_frequency、sched_wakeup 的边界4.1 cpu_idle 不代表某个线程在睡眠看名字很容易望文生义以为cpu_idle就是“CPU 上的线程睡眠了”。但准确地说它表达的是“CPU 这个物理资源进入了空闲状态”。比如 CPU 上所有任务都已经阻塞内核才会让该 CPU 进入 idle但这和某一个线程自己睡眠完全是两个层次的事情。一个很常见的困惑是主线程明明睡眠了为什么对应的 CPU Frequency 和 idle 轨道却没有太大变化因为主线程睡眠后CPU 调度器马上会从 runqueue 里挑下一个线程继续运行。只要 CPU 上还有任务CPU 就不会进入 idle。所以别拿着一根线程状态去推导核心的物理状态两者必须分开读。排查功耗问题时通常更关心 C-state 的深度和进入次数。官方文档里对 idle state 的定义通常和硬件相关在 ARM 平台和 x86 平台上字段含义会有差异。做跨设备对比时不要只看state数值相同就断言两种设备处于同样的省电状态因为不同 SoC 对 C-state 编号有自家定义。4.2 cpu_frequency 是采样记录不是连续精确的曲线Perfetto 里的 CPU 频率并不是每纳秒都采一个点一般是通过内核的cpu_frequencytracepoint 在频率变化时上报同时在特定周期也会通过定时器采样当前频率。因此在 UI 上看到的频率曲线本质上是“相邻采样点之间假设频率不变”的阶梯状数据。如果拿频率数据和sched_switch做精确对齐就会踩到一个坑你看到一个线程 slice 从 1.000ms 到 1.500ms而频率采样点只落在 1.010ms 和 1.490ms中间 1.490ms 到 1.500ms 的瞬时频率是无法确定的只能沿用上一个采样值。对一般的时序分析影响不大但如果要算“某个线程运行期间的精确功耗”就必须结合 CPU 的 P-state 转换模型而不能简单把 slice 起点和终点切到频率折线上做积分。4.3 通过一个案例比较 sched/wakeup 和 sched_switch 的先后用文档里的典型分析场景来说明假设有一个工作线程在等待网络包网络驱动在收包完成之后调用了 wake_up 之类的逻辑于是产生一条sched_wakeup事件目标线程从 sleep 状态变为 runnable。随后调度器在某个核心上发生切换sched_switch的 next_comm 正是这个线程此时它才真正获得 CPU。从 wakeup 到 switch 之间的这段就是排队等待时间。这个时间如果很短比如几十微秒说明系统负载轻调度很及时。如果达到几十毫秒甚至几百毫秒就要看看目标 CPU 上到底是谁在一直占着。这种问题在实时音视频场景尤其常见一个负责编码的线程被唤醒后迟迟上不了 CPU直接就表现为帧时间不稳定。我建议读者去尝试在 Perfetto UI 的 “Instants” 轨道里开启 sched/sched_wakeup 显示再把主线程切片和 CPU 切片叠在一起就能直观看到 wakeup 与 switch 之间的空白。这个空白在默认视图里往往被大段时间线淹没但只要放大到目标区间附近它是非常显眼的。5. 实战用 Trace Processor 把调度事件做成 SQL 输出5.1 把 trace 导入 trace_processor_shellPerfetto 除了图形界面还给了一整套命令行工具其中最核心的是 trace_processor_shell。官方文档把导入 trace 后的数据组织成关系表只要会用 SQL 就能把调度事件全部查出来。如果只想简单试一下可以在安装好 trace_processor_shell 后执行trace_processor_shell trace.pftrace这样会进入交互式 REPL可以直接输入 SQL。或者用-q参数执行单条查询并退出适合脚本化。还有更简单的办法Perfetto UI 自带 “Query” 页导入 trace 后可以直接在浏览器里执行 SQL日常排查完全够用。很多刚接触的人会问为什么非要 SQL因为 UI 上只能看到当前缩放窗口内的少部分内容而 SQL 可以一次性统计所有调度事件。比如把整个 trace 里主线程所有 Running slice 的总时长算出来或者找出某个时间里唤醒最频繁的线程这种操作在 UI 上人手点效率太低且容易出错。5.2 死等时刻的 SQL 查找表结构清单与调度事件相关的核心表在 Trace Processor 里主要这么分原始事件表sched重建后的切片表sched_slice线程状态表thread_state以及辅助的thread、process、cpu_freq_sched等。文档里每张表都有字段说明但平常最常打交道的还是sched_slice。一条典型查询是找某个线程耗时的 Running slice 最大值SELECT s.ts / 1e6 AS ts_ms, s.dur / 1e6 AS dur_ms, t.name AS thread_name, t.pid FROM sched_slice s JOIN thread t USING (utid) WHERE t.name my_thread ORDER BY s.dur DESC LIMIT 20;注意时间单位ts和dur默认都是纳秒。除以 1e6 转成毫秒后读起来更直观。这里用JOIN thread来拿到线程名因为sched_slice里存的是一串 internal thread id不是我们熟悉的 pid。如果想看某个瞬间谁占着 CPU可以用 SQL 直接列出所有核心上的当前线程。UI 上看似直观的视图到 SQL 里其实就是对sched_slice做时间过滤。掌握了这套思维很多 UI 上没法直接落盘看全的问题都能用查询方式一次解决。5.3 结合 sched slices 统计主线程 ON CPU 的时间占比启动优化中经常会问一个问题主线程真正在 CPU 上跑了多久答案是累加主线程所有 Running slice 的dur之和再除以总时间窗口。SQL 写法并不复杂SELECT SUM(s.dur) / 1e6 AS total_running_ms FROM sched_slice s JOIN thread t USING (utid) WHERE t.name my_main_thread AND s.dur 0如果这个值很小比如整个启动过程只有 300ms但界面直到 2s 才显示那主线程至少有 1.7s 处于等待状态要么在等 IO要么在等调度要么在等锁。这时候再细化查询把thread_state表里的状态分布按类型聚合就能知道睡眠、不可中断睡眠、可运行状态各自占了多少问题区域就会清晰很多。我还喜欢做另一个查询把主线程和它与sched_wakeup相关的事件按时间排序导出来做成 CSV然后放进表格里看唤醒源分布。看是哪个线程一直在唤醒主线程这比在 UI 上一个个点气泡直观得多。官方文档虽然没有直接给出这段 SQL但它给了表结构和字段含义照着就能组合出来。6. 我在读文档和查案时踩过的坑以及一些能帮你省时间的习惯6.1 读官方文档不要只看图要看它给的格式说明Perfetto 官方文档里每一类事件都会给一段类似内核 traceprintk 的输出示例。很多教程会直接跳过这些只教你怎么看 UI 色块其实这是最亏的。比如sched_switch的prev_state里有个标志S它和线程在睡眠状态中被打断、唤醒后状态不同。如果只看 UI你不会意识到这个标志会影响到后面 slice 的重建。而文档把那几行格式和字段讲得很清楚花十分钟看这段可以少走很多冤枉路。6.2 不要默认时间线里所有轨道都要看trace 一复杂轨道可能多达几十条。Perfetto UI 默认把进程、线程、CPU 频率、GPU 等全都展开这时候调度事件的细节反而不够突出。我一般会把不相关的轨道先折叠掉只保留进程的线程轨道、对应 CPU 轨道以及 wakeup instant。调整之后整个页面会干净很多主线程什么时候 Ready、什么时候 Running、什么时候 Sleep一目了然。不然时间线一缩窄所有色块挤在一起看不出任何问题。6.3 与日志、系统时间对表跨 trace 边界要小心排查真实业务问题时往往要把 perfetto trace 里的某段时间和业务日志里的时间戳对齐。Perfetto 的时间基准一般是机器启动后的单调时钟UI 展示时也会显示成可读的系统时间。但如果你同时拿了多台设备的 trace或者 trace 从半中间开始录跨 trace 计算时间差就很容易错位。依赖基站时间还是 monotonictime文档里都会说明。我在实际项目里会先找一个明显的全局事件比如某个带 pid 的日志或开机广播用它来确认不同数据源之间的时间偏移再开始做细粒度对比。这会避免很多“看起来像是 bug其实是时间基准没对齐”的乌龙。另外补充一个小习惯保存 trace 时顺手把当时的 dmesg 一并存下来。调度事件能告诉你“线程何时被切换”但解释不了“为什么这个时刻发生了 IO 卡顿”而 dmesg 里的驱动报错、电源状态变化、中断风暴往往就是那个原因。官方文档主推的是 trace 本身但实践里全链路证据组合起来才更可靠。CPU Scheduling events 这个主题字面上只是事件列表里的一个小节真正用起来却覆盖了从内核 tracepoint 到前端可视化、再到 SQL 聚合的完整链路。我刚接触时也曾经在 UI 上反复缩放却找不到重点后来是老老实实回到文档把每个事件的字段含义和产生时机弄明白才慢慢建立起从调度视角看问题的方法。如果你也在被一些莫名其妙的卡顿和延迟困扰不妨从今天这份文档开始把 trace 里的调度时间线当作第一现场。

读完文章,也想定制专属网站?

尧图设计师 24 小时内与您沟通定制方案

免费获取报价 →
↑