系列文章《客户端可观测性进阶实战》第 1 篇
推荐阅读时间：10 分钟
前言
之前《客户端质量与稳定性实战》系列讲过可观测性的基础概念，但那篇更多是"是什么"层面的科普。实际线上排障时，团队里问得最多的还是这种问题：
用户反馈"点了一下就卡了"，你能看到什么？
启动慢了 800 毫秒，到底慢在 Application 还是 ContentProvider？
一个网络请求从发起到回调用了 3 秒，中间经过了几层拦截器？
这些问题靠传统的日志打点很难回答。你需要的是时间线级别的因果关系——每一步做了什么，花了多久，串起来看是什么样。这就是 Trace 体系要解决的事。
这个系列三篇分别讲 Trace、Metric、Log 三条线，最后打通三支柱。第一篇先聊 Trace：
Android Trace API 底层是怎么工作的
Perfetto 怎么采集和分析 trace 文件
怎么写自定义 Trace 段，让业务链路在 trace 里可见
全链路 Trace ID 怎么从网络层贯穿到 DB 层
一、Android Trace API 原理
1.1 Trace API 不等于 Log
很多开发者第一次接触 android.os.Trace 时会困惑：它和打日志有什么区别？
区别在数据结构。Log 是离散的事件点，没有时间跨度概念。Trace 的核心数据结构是 slice（切片）：每一段都有 begin 和 end，自带耗时信息，可以被时间轴排列。
// 离散日志：只知道"发生了"，不知道多久
Log.d("App", "loadConfig start")
loadConfig()
Log.d("App", "loadConfig end")
// Trace slice：自带耗时，可在时间轴上排列
Trace.beginSection("loadConfig")
loadConfig()
Trace.endSection()
Trace.beginSection 在底层调用了 atrace 机制，往内核的 trace pipe 写入一条 tracing_mark_write 记录。Perfetto 或 systrace 工具读取这些记录后，能在时间轴上还原出每个 slice 的起止时间和嵌套关系。
1.2 beginSection 的限制
Trace.beginSection 有几个容易踩的限制：
单 slot 的限制意味着你不能这样写：
// 错误：第二个 begin 会覆盖第一个
Trace.beginSection("fetchToken")
fetchToken()
Trace.beginSection("parseResponse") // 第一个 slice 被截断
parseResponse()
Trace.endSection()
Trace.endSection()
正确做法是嵌套调用，保证 end 和 begin 严格配对：
Trace.beginSection("fetchToken")
try {
fetchToken()
Trace.beginSection("parseResponse")
try {
parseResponse()
} finally {
Trace.endSection()
}
} finally {
Trace.endSection()
}
1.3 API 29 引入的 Async Trace
Android 10（API 29）引入了 Trace.beginAsyncSection 和 Trace.endAsyncSection，解决了跨回调场景的 trace 问题：
private val traceCookie = Random.nextInt()
// 发起异步请求前打点
Trace.beginAsyncSection("networkRequest", traceCookie)
apiClient.request(url) { response ->
// 回调线程结束打点
Trace.endAsyncSection("networkRequest", traceCookie)
handleResponse(response)
}
cookie 是一个整数标识，用于匹配 begin 和 end。同一个 cookie 的 begin/end 会被 Perfetto 合并为一个完整的 slice，即使它们发生在不同线程。
二、Perfetto 采集与分析
2.1 Perfetto 是什么
Perfetto 是 Google 推出的统一 trace 采集和分析工具，取代了老的 systrace.py。它的架构分三层：
┌─────────────────────────────────────────────┐
│ Perfetto UI │
│ (https://ui.perfetto.dev) │
├─────────────────────────────────────────────┤
│ Trace Processor │
│ (SQL 查询引擎，WASM) │
├─────────────────────────────────────────────┤
│ Trace Config │
│ (数据源配置：ftrace、atrace、counter) │
└─────────────────────────────────────────────┘
Perfetto 可以同时采集内核 ftrace、应用层 atrace、系统服务 trace 和性能计数器，全部合并到一个 trace 文件里。这比老 systrace 的覆盖面大很多。
2.2 命令行采集
在 Android 10+ 设备上，Perfetto 已经内置于系统。通过 perfetto 命令行可以采集：
# 定义采集配置
cat > /data/misc/perfetto-config/trace_config.txt << EOF
buffers {
size_kb: 65536
fill_policy: RING_BUFFER
}
data_sources {
config {
name: "linux.ftrace"
ftrace_config {
ftrace_events: "sched/sched_switch"
ftrace_events: "sched/sched_waking"
atrace_categories: "view"
atrace_categories: "am"
atrace_categories: "sched"
atrace_apps: "*"
}
}
}
data_sources {
config {
name: "linux.process_stats"
}
}
duration_ms: 10000
EOF
# 执行采集
adb shell perfetto -c /data/misc/perfetto-config/trace_config.txt \
-o /data/misc/perfetto-traces/trace.perfetto-trace
# 拉取 trace 文件
adb pull /data/misc/perfetto-traces/trace.perfetto-trace .
关键配置项：
2.3 Perfetto SQL 分析
Perfetto UI 内置了一个 SQL 查询引擎，能直接对 trace 文件做结构化查询。这比在时间轴上手动找问题高效得多。
比如查找耗时超过 500 毫秒的 slice：
SELECT
name,
ts,
dur / 1000000.0 AS dur_ms,
thread_name,
process_name
FROM slice
JOIN thread_track ON slice.track_id = thread_track.id
JOIN thread USING (utid)
JOIN process USING (upid)
WHERE dur > 500000000
ORDER BY dur DESC
LIMIT 20
一个更实用的查询：统计某方法被调用的次数和平均耗时：
SELECT
name,
COUNT(*) AS call_count,
SUM(dur) / 1000000.0 AS total_ms,
AVG(dur) / 1000000.0 AS avg_ms,
MAX(dur) / 1000000.0 AS max_ms
FROM slice
WHERE name LIKE 'loadConfig%'
GROUP BY name
ORDER BY total_ms DESC
这种 SQL 查询可以在 CI 里自动化执行。把 trace 文件丢给 trace_processor_shell，跑一段 SQL，输出 JSON，就能在流水线上对性能做卡口检查。
三、自定义 Trace 段实战
3.1 业务链路可见性
系统自带的 atrace category 覆盖了 view 渲染、Activity 切换、GC 等系统行为，但业务代码在 trace 里是隐形的。如果不在关键路径上埋 Trace.beginSection，打开 Perfetto 只能看到一堆系统 slice，业务逻辑完全淹没在里面。
推荐在以下位置埋 Trace：
3.2 封装一个安全的 Trace 工具
直接用 Trace.beginSection 有两个问题：一是异常路径忘记 endSection 会导致 trace 污染，二是 API 29 以下不支持 async trace。封装一层：
object TraceUtil {
fun trace(name: String, block: () -> Unit) {
if (Build.VERSION.SDK_INT >= Build.VERSION_CODES.Q) {
val cookie = name.hashCode()
Trace.beginAsyncSection(name, cookie)
try {
block()
} finally {
Trace.endAsyncSection(name, cookie)
}
} else {
Trace.beginSection(name)
try {
block()
} finally {
Trace.endSection()
}
}
}
inline fun <T> traceSync(name: String, block: () -> T): T {
Trace.beginSection(name)
try {
return block()
} finally {
Trace.endSection()
}
}
}
使用方式：
// 同步场景
val config = TraceUtil.traceSync("loadConfig") {
repository.loadRemoteConfig()
}
// 异步场景（API 29+ 自动走 async）
TraceUtil.trace("fetchUserProfile") {
api.getUserProfile(userId) { profile ->
// 回调在 trace 内
}
}
3.3 Trace 采样策略
线上不应该对所有用户开启 Trace。atrace 本身有性能开销，每个 begin/end 都会往内核 buffer 写数据。推荐两级策略：
object TraceSampler {
// 采样比例，从远程配置下发
@Volatile var sampleRate = 0.0f
fun shouldTrace(tag: String): Boolean {
if (sampleRate <= 0.0f) return false
// 关键路径强制采样
if (tag.startsWith("App.onCreate") || tag.startsWith("Activity:firstFrame")) {
return true
}
return Random.nextFloat() < sampleRate
}
}
线上默认 sampleRate = 0.0，只在需要排查问题时通过远程配置调到 0.01（1% 采样）或更高。关键路径（启动、首帧）强制采样，确保每次都能采到。
四、全链路 Trace ID 贯穿
4.1 为什么需要 Trace ID
单机 trace 能回答"这个方法耗时多久"，但线上问题往往是跨进程、跨网络的。用户点了一个按钮，触发了网络请求，请求打到服务端，服务端查了缓存又查了 DB，最后返回数据渲染到页面上。这一整条链路如果只有一个端侧 trace，服务端的耗时就是黑洞。
全链路 Trace ID 的思路：在请求发起时生成一个唯一 ID，贯穿客户端到服务端的整条链路。所有日志、Metric、Trace 段都带上这个 ID，排查时用一个 ID 串联所有数据。
4.2 客户端生成 Trace ID
object TraceIdGenerator {
private val counter = AtomicLong(0)
fun generate(): String {
val ts = System.currentTimeMillis()
val seq = counter.incrementAndGet() and 0xFFFF
val pid = Process.myPid() and 0xFFFF
// 格式：时间戳-进程ID-序号，保证同设备内唯一
return String.format("%x-%04x-%04x", ts, pid, seq)
}
}
4.3 注入 HTTP 请求头
在 OkHttp Interceptor 里注入 Trace ID，同时把端侧的 trace 信息也带过去：
class TraceInterceptor : Interceptor {
override fun intercept(chain: Interceptor.Chain): Response {
val traceId = TraceIdGenerator.generate()
val parentSpanId = SpanContext.currentSpanId()
val request = chain.request().newBuilder()
.header("X-Trace-Id", traceId)
.header("X-Trace-Parent", parentSpanId)
.header("X-Trace-Source", "android")
.build()
Trace.beginSection("Net:${request.url.encodedPath}")
try {
val response = chain.proceed(request)
// 记录响应码到 trace 参数
Trace.setCounter("net_status", response.code.toFloat())
return response
} finally {
Trace.endSection()
}
}
}
服务端收到请求后，从 header 里取出 X-Trace-Id，在自己的 trace 体系里复用这个 ID。这样端侧和服务端的 trace 就能通过同一个 ID 关联起来。
4.4 Trace ID 贯穿到 DB 层
如果客户端有本地数据库操作，Trace ID 同样要贯穿：
class TraceRoomCallback(
private val traceIdProvider: () -> String
) : RoomDatabase.Callback() {
override fun onOpen(db: SupportSQLiteDatabase) {
val traceId = traceIdProvider()
// 用 PRAGMA 设置自定义参数，部分 SQLite 版本支持
db.execSQL("PRAGMA application_id = ${traceId.hashCode() and 0xFFFFFFFF}")
}
}
更实际的做法是在每次 DB 事务开始时，把 Trace ID 写入一张专门的 trace 表，后续查询日志时通过 trace ID 关联。
4.5 多线程传递
Trace ID 在多线程场景下需要通过 ThreadLocal 或 Kotlin Coroutines 的 CoroutineContext 传递：
class TraceContextElement(
val traceId: String
) : AbstractCoroutineContextElement(Key) {
companion object Key : CoroutineContext.Key<TraceContextElement>
}
// 发起协程时注入
suspend fun fetchWithTrace(url: String) = withContext(
TraceContextElement(TraceIdGenerator.generate()) + Dispatchers.IO
) {
val traceId = coroutineContext[TraceContextElement]?.traceId
Trace.beginSection("Net:${url.takeLast(30)}")
try {
val response = api.get(url, traceId)
handleResponse(response)
} finally {
Trace.endSection()
}
}
五、实战案例：启动慢 800 毫秒定位
这是一个真实场景。线上监控发现某机型冷启动 P95 从 2.1s 涨到 2.9s，但不知道慢在哪。团队用 Perfetto 采集了一次冷启动 trace：
App.onCreate (2100ms)
├── CP:init:bugly (45ms)
├── CP:init:tencent-push (180ms) ← 可疑
├── CP:init:third-pay-sdk (320ms) ← 可疑
├── initKoin (85ms)
├── initNetwork (120ms)
└── initDatabase (95ms)
在 Perfetto UI 里看到 CP:init:third-pay-sdk 占了 320ms，展开后发现其中 260ms 花在一个 init 方法内部的同步网络请求上。第三方 SDK 在 ContentProvider 里偷偷做了一次 HTTP 初始化。
定位后，把第三方 SDK 的初始化推迟到首页渲染完成后异步执行，冷启动回到 2.1s。
如果没有 Perfetto trace，靠日志打点很难发现 ContentProvider 里的隐藏网络请求——因为那不是你写的代码，你根本不知道该在哪打点。
小结
Trace 体系是可观测性三支柱里时间线最完整的一条。它和 Log、Metric 的区别在于：Log 回答"发生了什么"，Metric 回答"多少次、多久"，Trace 回答"什么导致了什么、串起来什么样子"。
这篇覆盖了 Trace API 原理、Perfetto 采集分析、自定义 trace 段和全链路 ID 贯穿。下一篇讲 Metric 体系——怎么把性能数据变成可量化的指标看板。
参考阅读
Perfetto 官方文档：https://perfetto.dev/docs/
Android Trace API：https://developer.android.com/reference/android/os/Trace
本系列第 2 篇：Metric 指标采集与监控看板