1. 概述Systrace 是一种基于 Ftrace 的性能追踪工具可直接用文本阅读器打开。输出文件记录了从设备启动以来的所有系统事件。Systrace里面主要有应用层事件以及内核层事件应用层事件图形显示的是原始记录的直接呈现没有信息损失所以应用层trace直接看图形解析就可以了内核事件图形显示的是选择性渲染可能有上下文信息缺失所以本章主要对内核事件文本格式进行讲解2. 应用层事件应用层事件通过tracing_mark_write写入有三种类型2.1 B/E 事件对Duration EventB:记录一个时间段的开始E:记录一个时间段的结束C:记录某个瞬时值ndroid.launcher-4422 ( 4422) [007] .... 172954.944301: tracing_mark_write: B|4422|Choreographer#onVsync 44147512ndroid.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 Overview3.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: dev2064 sector295269864 nr_sector8 bytes4096 rwbsR commkworker/X34:2 cmd Io完成 idle-0 (-----) [005] .... 172954.957732: block_rq_complete: dev2064 sector295269864 nr_sector8 rwbsR cmd error03.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事务 IDdest_node目标 Binder 节点dest_proc目标进程 PIDdest_thread目标线程 PIDreply线程是否主动发起flags事务标志code:操作码如果ID相同就能证明是同一事件ndroid.launcher-4422 ( 4422) [007] .... 172954.944474: binder_transaction: transaction84444601 dest_node49009 dest_proc1886 dest_thread0 reply0 flags0x11 code0x3binder:1886_1-2409 ( 1886) [000] .... 172954.955442: binder_transaction_received: transaction84444601┌─────────────────────────────────────────────────────────────────────────┐ │ 发送端进程 │ │ binder_transaction(transaction_id, dest_node, dest_proc, flags) │ └───────────────────────────┬─────────────────────────────────────────────┘ ↓ ┌─────────────────────────────────────────────────────────────────────────┐ │ Binder Driver │ │ │ │ binder_transaction_received(transaction_id) ← 目标线程收到 │ │ binder_transaction_reply(transaction_id) ← 目标处理完毕 │ └───────────────────────────┬─────────────────────────────────────────────┘ ↓ ┌─────────────────────────────────────────────────────────────────────────┐ │ 接收端进程 │ │ onTransact() 处理请求 │ └─────────────────────────────────────────────────────────────────────────┘重点讲解3.5 通过 raw 时间定位问题Systrace 中的时间戳是**系统启动以来的时间秒**也是raw时间可以在图形trace中直接获取然后通过raw时间定位到具体的trace事件。**示例**[T1] 172954.944474: 事件A开始[T2] 172954.957445: 事件B完成