Administrator
发布于 2026-08-30 / 118 阅读
0
0

Log 体系与线上问题定位闭环:结构化日志、三支柱关联与 ANR 定位实战

系列文章《客户端可观测性进阶实战》第 3 篇
推荐阅读时间:10 分钟

前言

前两篇讲了 Trace 和 Metric。Trace 还原时间线,Metric 反映全局趋势,但线上排障时最常用的还是 Log。用户反馈一个问题,你打开后台面板,第一件事就是搜日志。

问题是,大多数团队的日志体系是这样的:几十个模块各打各的,格式不统一,没有关联 ID,搜索时只能靠肉眼一页页翻。一个 ANR 问题的定位可能要从 20 万条日志里捞线索,耗时半天。

这篇收尾,讲三个话题:

  • 结构化日志怎么设计,怎么分级

  • Trace ID 如何把 Log、Metric、Trace 三支柱打通

  • 一个线上 ANR 的完整定位过程

一、结构化日志设计

1.1 为什么不能用纯文本日志

纯文本日志最大的问题是不可查询。你打了一条 Log.d("Net", "request failed: timeout, url=/api/user/profile, retry=3"),搜索时只能做模糊匹配。如果要统计"所有 timeout 的请求按 URL 聚合",纯文本做不到。

结构化日志的核心思路:每条日志是一个 JSON 对象,字段固定,值可枚举。服务端收到后可以直接做聚合查询。

data class StructuredLog(
    val timestamp: Long,
    val level: LogLevel,
    val module: String,         // 来源模块
    val event: String,          // 事件名,枚举值
    val traceId: String?,       // 关联 Trace ID
    val message: String,        // 人类可读描述
    val fields: Map<String, String>, // 结构化附加字段
    val throwable: Throwable?   // 异常信息
)

1.2 日志级别体系

很多团队的日志级别形同虚设——全用 Log.d,或者全用 Log.e。一个可用的级别体系应该和线上策略绑定:

级别

使用场景

线上策略

VERBOSE

方法进出、状态机变化

仅本地调试,线上不采集

DEBUG

关键分支判断、中间状态

灰度采集 10%

INFO

用户行为、业务节点

全量采集

WARN

降级、重试、兼容处理

全量采集 + 告警

ERROR

异常、失败、不可恢复

全量采集 + P1 告警

关键点:VERBOSE 在线上完全不采集。端侧日志缓冲区有限,如果全量采集 VERBOSE 级别,真正有价值的 ERROR 会被淹没。

1.3 日志采集器实现

一个生产可用的结构化日志采集器:

class StructuredLogger(
    private val buffer: LogBuffer,
    private val config: LogConfig
) {

    fun log(
        level: LogLevel,
        module: String,
        event: String,
        message: String = "",
        fields: Map<String, String> = emptyMap(),
        throwable: Throwable? = null
    ) {
        // 级别过滤
        if (level.priority < config.minLevel(module).priority) return

        val entry = StructuredLog(
            timestamp = System.currentTimeMillis(),
            level = level,
            module = module,
            event = event,
            traceId = TraceContextHolder.currentTraceId(),
            message = message,
            fields = sanitizeFields(fields),
            throwable = throwable
        )

        buffer.add(entry)

        // ERROR 级别立即上报
        if (level == LogLevel.ERROR) {
            buffer.flush()
        }
    }

    private fun sanitizeFields(fields: Map<String, String>): Map<String, String> {
        val sanitized = LinkedHashMap<String, String>(fields.size)
        for ((key, value) in fields) {
            // 脱敏:移除可能包含用户信息的字段
            if (key in config.sensitiveKeys) {
                sanitized[key] = "***"
            } else {
                sanitized[key] = value
            }
        }
        return sanitized
    }
}

sanitizeFields 负责脱敏。哪些字段需要脱敏通过远程配置下发,可以根据隐私政策调整。常见的敏感 key 包括 phone、idCard、token、password 等。

1.4 日志缓冲与上报

日志缓冲区和 Metric 的聚合桶思路类似,但有两个特殊点:

  1. ERROR 级别需要立即上报,不能等时间窗口

  2. 日志不能在崩溃时丢失——如果 App 崩溃了,最后几条日志是定位问题的关键

class LogBuffer(
    private val maxEntries: Int = 2000,
    private val flushIntervalMs: Long = 60_000L
) {
    // 环形缓冲区,保留最近 N 条日志
    private val ringBuffer = ArrayDeque<StructuredLog>(maxEntries)
    private val lock = ReentrantLock()

    fun add(entry: StructuredLog) {
        lock.withLock {
            if (ringBuffer.size >= maxEntries) {
                ringBuffer.removeFirst()
            }
            ringBuffer.addLast(entry)
        }
    }

    fun snapshot(): List<StructuredLog> {
        lock.withLock {
            return ringBuffer.toList()
        }
    }

    // 崩溃时调用:把缓冲区内容写入文件
    fun crashFlush() {
        val entries = snapshot()
        val json = entries.joinToString("\n") { it.toJson() }
        // 写入 crash-specific 日志文件
        crashLogWriter.write(json)
    }
}

在 Thread.UncaughtExceptionHandler 里调用 crashFlush,保证崩溃前的日志不会丢:

class CrashHandler(private val logBuffer: LogBuffer) : Thread.UncaughtExceptionHandler {
    private val defaultHandler = Thread.getDefaultUncaughtExceptionHandler()

    override fun uncaughtException(t: Thread, e: Throwable) {
        // 先把日志落盘
        logBuffer.crashFlush()
        // 再上报崩溃
        CrashReporter.report(e, logBuffer.snapshot().takeLast(100))
        // 交给默认处理器
        defaultHandler?.uncaughtException(t, e)
    }
}

二、三支柱关联打通

2.1 Trace ID 是纽带

上一篇讲了 Trace ID 的生成和传递。这里的关键是让 Trace ID 出现在所有三支柱的数据里:

用户操作 → 生成 Trace ID
   ├── Trace slice 带 Trace ID
   ├── Metric record 带 Trace ID
   └── Log entry 带 Trace ID

这样排查问题时,用一个 Trace ID 可以同时拉出 trace 时间线、metric 指标快照和日志明细。三支柱从独立的数据孤岛变成可关联的整体。

2.2 Log 关联 Trace

在 StructuredLogger 的实现里,每条日志自动从 TraceContextHolder 取当前 Trace ID:

object TraceContextHolder {
    private val threadLocal = ThreadLocal<String?>()

    fun setTraceId(id: String?) {
        threadLocal.set(id)
    }

    fun currentTraceId(): String? = threadLocal.get()

    fun clear() {
        threadLocal.remove()
    }
}

在业务入口设置 Trace ID:

fun onUserAction(action: UserAction) {
    val traceId = TraceIdGenerator.generate()
    TraceContextHolder.setTraceId(traceId)

    logger.log(LogLevel.INFO, "user", "action_start",
        message = "user triggered ${action.name}",
        fields = mapOf("action" to action.name)
    )

    TraceUtil.traceSync("UserAction:${action.name}") {
        actionHandler.handle(action)
    }

    TraceContextHolder.clear()
}

所有在这期间产生的日志和 Trace 都带同一个 Trace ID。

2.3 Metric 关联 Trace

Metric 的 tags 里也带上 Trace ID,这样从指标看板发现异常后,可以下钻到具体的 trace:

fun recordTimingWithTrace(name: String, durationMs: Long, tags: Map<String, String>) {
    val traceId = TraceContextHolder.currentTraceId()
    val fullTags = if (traceId != null) {
        tags + ("trace_id" to traceId)
    } else {
        tags
    }
    metricCollector.recordTiming(name, durationMs, fullTags)
}

2.4 查询联动

三支柱打通后,排查一个问题的标准流程变成:

  1. 看 Metric 看板,发现某指标突增(如冷启动 P99 涨了 1 秒)

  2. 查 Metric 数据,取出突增时间窗口的异常 Trace ID 列表

  3. 用 Trace ID 查日志,看那个时间窗口的日志明细

  4. 用 Trace ID 拉 Perfetto trace(如果该设备有采样),看时间线

  5. 定位到具体原因,修复

以前是"翻日志"——在 20 万条日志里找线索。现在是"查 ID"——一个 Trace ID 串联所有数据。

三、线上问题定位实战

3.1 案例背景

某天下午,线上监控告警:Android 端 ANR 率从 0.02% 突增到 0.15%。同时收到用户反馈:“首页打开后白屏几秒,然后弹无响应弹窗。”

3.2 第一步:Metric 看板定位范围

打开 ANR 看板,按维度分桶:

维度

值

ANR 率

机型

Xiaomi 12

0.45%

机型

Huawei P50

0.08%

机型

其他

0.03%

版本

v3.2.1

0.15%

版本

v3.2.0

0.02%

场景

首页

0.12%

场景

详情页

0.03%

结论:v3.2.1 版本 + Xiaomi 12 机型 + 首页场景是重灾区。

3.3 第二步:Trace ID 查日志

从 ANR 上报里取出几个 Xiaomi 12 上的 ANR trace ID。用其中一个查日志:

SELECT * FROM logs
WHERE trace_id = '18f3a2b4-1c2d-4e3f'
ORDER BY timestamp ASC

返回结果里关键几条:

14:32:01.234  INFO  home  page_init      用户进入首页
14:32:01.567  INFO  net   request_start  请求首页推荐列表
14:32:01.568  INFO  net   request_start  请求首页 Banner
14:32:01.569  INFO  db    query_start     查询本地缓存
14:32:04.231  WARN  db    query_timeout   缓存查询超时 2600ms
14:32:04.232  ERROR net   request_error   推荐列表请求失败: timeout
14:32:05.100  ANR   system  anr_detected  主线程阻塞超过 5s

时间线很清楚:14:32:01 发起请求和 DB 查询,14:32:04 DB 查询超时 2.6 秒,14:32:05 触发 ANR。

3.4 第三步:Trace 看时间线

如果该设备恰好命中 Trace 采样(0.1%),可以拉到 Perfetto trace。在 trace 里搜索这个 Trace ID 对应的 slice:

Home:loadData (3800ms)
├── Net:recommend (3200ms)     ← 推荐列表请求,超时
│   ├── DNS (45ms)
│   ├── TCP connect (120ms)
│   └── request wait (3035ms)  ← 服务端或网络层慢
└── DB:cache:query (2600ms)    ← DB 查询也很慢
    └── SQLite query (2600ms)

两条线索并行出现:网络请求超时 3 秒,同时 DB 查询耗时 2.6 秒。两者在主线程串行执行,总耗时接近 4 秒。

3.5 第四步:根因定位

查 DB 查询的代码,发现首页的本地缓存查询用了 Room,但没加索引:

@Query("SELECT * FROM home_cache WHERE page_type = :pageType ORDER BY update_time DESC")
fun queryCache(pageType: String): HomeCache?

page_type 字段没有建索引。数据量小时查询很快,但 Xiaomi 12 上的缓存表有 12 万条记录(用户是重度用户),全表扫描需要 2.6 秒。

网络请求超时是因为 DNS 解析到了一个慢节点。但这不是根因——正常情况下即使网络慢,DB 查询应该先返回数据让用户看到内容,网络请求在后台刷新。问题是 DB 查询也卡在主线程,导致两者串行阻塞。

3.6 第五步:修复

两处修复:

  1. DB 查询加索引:

@Entity(tableName = "home_cache", indices = [Index("page_type")])
data class HomeCache(
    @PrimaryKey val id: Long,
    val page_type: String,
    val update_time: Long,
    val data: String
)
  1. 网络请求移到 IO 线程,DB 查询用 Flow 异步返回:

fun loadHomeData(): Flow<HomeData> = flow {
    // 先从 DB 读,快速展示
    val cache = withContext(Dispatchers.IO) {
        cacheDao.queryCache("home")
    }
    if (cache != null) {
        emit(HomeData.fromCache(cache))
    }

    // 后台请求网络,拿到后更新
    val fresh = withContext(Dispatchers.IO) {
        api.fetchHomeRecommend()
    }
    emit(fresh)
    cacheDao.insert(HomeCache.from(fresh))
}.flowOn(Dispatchers.IO)

修复后,ANR 率回到 0.02%。整个定位过程从告警到修复不到 2 小时。

四、平台化建议

4.1 三支柱统一入口

三个支柱最终应该收敛到一个查询入口。用户输入一个 Trace ID,平台同时返回:

数据源

展示内容

Trace

方法时间线,含耗时和嵌套

Metric

该 Trace ID 相关的指标快照

Log

该 Trace ID 的全部日志明细

Crash

如果有崩溃,崩溃堆栈和上下文

4.2 自动归因

下一步是自动归因。当 Metric 告警触发后,平台自动做:

  1. 取告警窗口的异常 Trace ID 列表

  2. 对异常 Trace 做聚类,找出共同模式(如"都卡在 DB 查询")

  3. 和历史正常 Trace 对比,定位差异 slice

  4. 自动生成归因报告,推送到告警群

这个流程目前需要人工分析,但基础设施(统一 Trace ID + 结构化日志 + Metric 关联)是自动化的前提。

小结

三篇文章构成了客户端可观测性进阶的完整图景:

  • 第一篇 Trace:还原时间线,定位"什么导致什么"

  • 第二篇 Metric:量化全局趋势,发现"多少次、多久"

  • 第三篇 Log:记录细节,配合 Trace ID 实现三支柱关联

三支柱不是三个独立工具,而是通过 Trace ID 打通的统一体系。建设顺序上,建议先做 Log(成本最低、收益最直接),再做 Metric(需要服务端配合),最后做 Trace(需要 Perfetto 采集和采样策略)。

线上问题定位的效率,取决于这三条线的关联程度。一个 Trace ID 串联全部数据,从"翻日志"变成"查 ID",这才是可观测性体系的价值。

参考阅读


评论