Systrace 文本格式解析-平芜编程栈

1. 概述

Systrace 是一种基于 Ftrace 的性能追踪工具，可直接用文本阅读器打开。输出文件记录了从设备启动以来的所有系统事件。
Systrace里面主要有应用层事件以及内核层事件
应用层事件：图形显示的是原始记录的直接呈现，没有信息损失，所以应用层trace直接看图形解析就可以了
内核事件：图形显示的是选择性渲染，可能有上下文信息缺失，所以本章主要对内核事件文本格式进行讲解

2. 应用层事件

应用层事件通过tracing_mark_write写入，有三种类型：

2.1 B/E 事件对（Duration Event）

B:记录一个时间段的开始
E:记录一个时间段的结束
C:记录某个瞬时值
ndroid.launcher-4422 ( 4422) [007] .... 172954.944301: tracing_mark_write: B|4422|Choreographer#onVsync 44147512
ndroid.launcher-4422 ( 4422) [007] .... 172954.944319: tracing_mark_write: E|4422（执行doFeame函数）
pool_4_thread_1-23255 (23206) [007] .... 172954.895670: tracing_mark_write: C|23206|Heap size (KB)|77093

３. Kernel Events Overview

3.1 事件总表

3.2 关键参数详解

rwbs读写标识

**示例：**
(IO请求 dev：文件系统设备号，sector：起始扇区号，磁盘物理地址，nr_sector：本次IO操作的扇区数量，bytes：字节数，rwbs：读写标志组合，如果以上都相同，能证明IO请求与Io完成是一对)

> kworker/X34:2-28798 (28798) [002] .... 172954.957173:
> block_rq_issue: dev=2064 sector=295269864 nr_sector=8 bytes=4096
> rwbs=R comm=kworker/X34:2 cmd= （Io完成） <idle>-0 (-----) [005]
> .... 172954.957732: block_rq_complete: dev=2064 sector=295269864
> nr_sector=8 rwbs=R cmd= error=0

3.3 重点事件解析： Block IO 类事件 IO事件详解

Block IO 从应用到磁盘的完整路径：

┌─────────────────────────────────────────────────────────────────────────┐ │ 应用层（Application Layer） │ │ read() / write() │ │ （用户态读写接口，发起 IO 请求） │ └───────────────────────────┬─────────────────────────────────────────────┘ ↓ ┌─────────────────────────────────────────────────────────────────────────┐ │ VFS 层（虚拟文件系统层） │ │ sys_read() / sys_write() → vfs_read() / vfs_write() │ │ （系统调用入口，统一文件抽象，屏蔽底层差异） │ └───────────────────────────┬─────────────────────────────────────────────┘ ↓ ┌─────────────────────────────────────────────────────────────────────────┐ │ 文件系统层（File System Layer） │ │ ext4 / f2fs │ │ f2fs_sync_file_enter → submit_bio() → f2fs_sync_file_exit │ │ （具体文件系统实现，负责生成 bio 请求） │ └───────────────────────────┬─────────────────────────────────────────────┘ ↓ ┌─────────────────────────────────────────────────────────────────────────┐ │ Block 层（块设备层） │ │ │ │ ┌──────────────────┐ ┌──────────────────┐ ┌──────────────────┐ │ │ │ block_bio_queue │ ──▶ │ block_rq_issue │ ──▶ │ block_rq_insert │ │ │ │ （bio 入队列） │ │ （请求发出） │ │ （插入调度器） │ │ │ └──────────────────┘ └──────────────────┘ └──────────────────┘ │ │ │ │ │ │ │ │ ┌──────────────────┐ │ │ │ └──────────────────────────┴─▶ │ blk_mq_start_req │ ◀─┘ │ │ │ （多队列开始） │ │ │ └──────────────────┘ │ │ │ │ │ ┌────────────┴────────────┐ │ │ ↓ ↓ │ │ ┌──────────────────┐ ┌──────────────────┐ │ │ │ blk_mq_complete │ │ block softirq │ │ │ │ （多队列完成） │ │ （软中断处理） │ │ │ └──────────────────┘ └──────────────────┘ │ │ │ │ └────────────────────────────────────┼────────────────────────────────────┘ ↓ ┌─────────────────────────────────────────────────────────────────────────┐ │ 设备驱动层（Device Driver Layer） │ │ block_rq_complete ←── NVMe/eMMC 控制器中断 ──→ 硬件完成 │ │ （驱动层处理硬件中断，完成 IO 请求） │ └─────────────────────────────────────────────────────────────────────────┘

IO类事件完整的生命周期与状态

3.3.1 为什么 trace 中可能只有部分阶段？

**当前 trace 中只有 `block_rq_issue` 和 `block_rq_complete`**，原因：
1. **Ftrace 事件未完全启用**：Perfetto 默认配置可能只开启了部分 block 事件
2. **内核配置限制**：某些事件需要内核编译时启用
3. **性能开销**：开启更多事件会增加追踪开销

3.3.2 如何捕获完整的 IO 阶段？

**举例：使用 Perfetto 配置**

```json { "ftrace_config": { "ftrace_events": [ "block/block_bio_queue", "block/block_bio_frontmerge", "block/block_bio_backmerge", "block/block_rq_insert", "block/block_rq_issue", "block/block_rq_complete" ] } }

3.4 重点事件解析：Binder IPC 类事件

| 事件名 | 说明 |
|--------|------|
| `binder_transaction` | Binder 事务发起 |
| `binder_transaction_received` | Binder 事务接收 |

**示例：**
（transaction：事务 ID，dest_node：目标 Binder 节点，dest_proc：目标进程 PID，dest_thread：目标线程 PID，reply：线程是否主动发起，flags：事务标志，code:操作码，如果ID相同，就能证明是同一事件）

ndroid.launcher-4422 ( 4422) [007] .... 172954.944474: binder_transaction: transaction=84444601 dest_node=49009 dest_proc=1886 dest_thread=0 reply=0 flags=0x11 code=0x3
binder:1886_1-2409 ( 1886) [000] .... 172954.955442: binder_transaction_received: transaction=84444601

┌─────────────────────────────────────────────────────────────────────────┐ │ 发送端进程 │ │ binder_transaction(transaction_id, dest_node, dest_proc, flags) │ └───────────────────────────┬─────────────────────────────────────────────┘ ↓ ┌─────────────────────────────────────────────────────────────────────────┐ │ Binder Driver │ │ │ │ binder_transaction_received(transaction_id) ← 目标线程收到 │ │ binder_transaction_reply(transaction_id) ← 目标处理完毕 │ └───────────────────────────┬─────────────────────────────────────────────┘ ↓ ┌─────────────────────────────────────────────────────────────────────────┐ │ 接收端进程 │ │ onTransact() 处理请求 │ └─────────────────────────────────────────────────────────────────────────┘

重点讲解：