使用冻屏增强日志定位繁忙类问题

本原创文章帖发布在华为开发者联盟社区，欢迎开发者前往访问评论交流，更多与该内容相关讨论，请点击原帖查看：

使用冻屏增强日志定位繁忙类问题-华为开发者话题 | 华为开发者联盟

概述

用户在使用应用时，如果出现点击无反应或应用无响应等情况，并且持续时间超过一定限制，就会被定义为应用冻屏（AppFreeze），即应用无响应。系统会检测应用无响应，并生成AppFreeze日志，供应用开发者分析。从API 21开始，支持获取​AppFreeze的增强日志​。该日志通过采集整机及主线程的运行负载，并抓取多份主线程调用栈，帮助开发者知晓函数调用耗时。

日志获取及规格可以参考：AppFreeze（应用冻屏）检测-故障检测-Performance Analysis Kit（性能分析服务）-调测调优-系统 - 华为HarmonyOS开发者

冻屏的两种成因

传统方案的痛点

当 ThreadBlock3s 和 InputBlock 事件的调用栈出现以下情况时，传统日志难以定位问题：

• 系统栈 - 主线程全是系统栈

• 瞬时栈 - 栈指向的函数并非真正耗时，只是一个切面

此时只能看到瞬时的调用栈片段，无法确认具体哪个函数在耗时。

增强日志的核心能力

增强日志通过以下方式解决上述痛点：

1. 采集多份主线程调用栈 - 在采样周期内多次抓取调用栈

2. 记录整机及主线程运行负载 - 辅助判断线程是否真正获得CPU执行时间

3. 采样栈与耗时关联分析 - 从多次采样中识别耗时函数

增强日志用法（重点）

Step 1: 判断线程是否获得CPU执行

查看 CPU耗时统计 部分：

CpuTime: 0 ms <- 主线程实际运行时间 SyncWaitTime: 2995 ms <- 主线程等待时间 StaticsDuration: 2995 ms <- 统计总时间

判断逻辑：

Step 2: 分析CPU使用率

查看 CpuFreq Usage 部分：

cpu0 Usage 23.5%, 1430MHZ 21.04% cpu1 Usage 23.5%, 1430MHZ 21.04% cpu2 Usage 23.5%, 1430MHZ 21.04% cpu3 Usage 23.5%, 1430MHZ 21.04%

判断逻辑：
调用栈栈顶未阻塞，CPU趋近100%，考虑系统高负载类问题，可忽略本次故障。

Step 3: 解析采样栈

增强日志会采集 多份 主线程调用栈，查看 #ThreadInfos 部分：

#ThreadInfos Tid: 2204, Name: com.example.freeze SnapshotTime: 2021-01-01-20-05-58.292875 #00 pc 00000000000015b8 [shmm](__kernel_gettimeofday+72) #01 pc 00000000001d7e44 /system/lib64/ld-musl-aarck64.so.1(clock_gettime+48) #02 pc 00000000001d9f20 /system/lib64/ld-musl-aarck64.so.1(time+32) #03 pc 0000000000007e2c .../libsample.so(WaitSomeTime()+76) ... ========SubmitterStacktrace======== #00 pc 0000000000013108 /system/lib64/platformsdk/libuv.so(uv_queue_work+292) #01 pc 0000000000008cdc .../libsample.so #02 pc 000000000005ae00 .../libace_napi.z.so(...) ...

分析步骤：

• 统计调用路径出现次数 - 从多次采样中找到重复出现的函数调用

• 抽取最大公共路径 - 识别频繁执行的代码路径

• 估算耗时 - 根据采样次数估算函数累计耗时

示例：

假设从 ThreadBlock3s 到 InputBlock 期间有6次采样：

• 3次采样命中 Task3 → Task3 耗时至少 900ms

• 3次采样命中 Task4 → Task4 耗时至少 900ms

Step 4: 结合多种栈信息分析

可结合以下堆栈信息一同分析：

优化优先级：根据调用链路出现的次数来决定优化优先级。

与Android ANR日志的对比

在Android开发中，ANR（Application Not Responding）问题定位主要依赖traces.txt文件。以下是对比分析：

核心机制对比

Android ANR日志示例

"main" tid=1 Native #00 pc 0x00000000000015b8 [kernel] #01 pc 0x00000000001d7e44 libmusl.so (clock_gettime+48) #02 pc 0x00000000001d9f20 libmusl.so (time+32) #03 pc 0x0000000000007e2c libsample.so (WaitSomeTime+76) ...

问题：仅能看到一个时间点的调用栈，无法确认WaitSomeTime是瞬时执行还是持续阻塞。

HarmonyOS 增强日志示例

同样的场景，增强日志提供更多信息：

# CPU耗时分析 CpuTime: 1500 ms <- 线程实际运行了1500ms SyncWaitTime: 1500 ms <- 同时等待了1500ms StaticsDuration: 3000 ms <- 总统计时间3000ms

# 第一次采样 (T=0ms) SnapshotTime: 2021-01-01-20-05-58.292875 #00 WaitSomeTime()+76 #01 process()+200 #02 onInputEvent()+150 # 第二次采样 (T=300ms) SnapshotTime: 2021-01-01-20-05-58.592875 #00 WaitSomeTime()+76 #01 process()+200 #02 onInputEvent()+150 # 第三次采样 (T=600ms) SnapshotTime: 2021-01-01-20-05-58.892875 #00 WaitSomeTime()+76 #01 process()+200 #02 onInputEvent()+150

价值：3次采样都命中WaitSomeTime，证明该函数持续阻塞至少600ms。

采样栈的定位效果

场景1：系统栈无法定位问题

Android日志：

#00 [kernel] #01 EventHandler.process() #02 EventRunner.Run()

只能知道在process中，无法确认具体哪个子函数耗时。

HarmonyOS增强日志：

# 采样1: process() -> group_api() -> render() # 采样2: process() -> group_api() -> render() # 采样3: process() -> list_builder() -> item_create()

可明确group_api被多次采样命中，是耗时根因。

场景2：繁忙类问题定位

Android日志：1份栈只能看到瞬时状态。

HarmonyOS增强日志：

采样1: Task3 -> funcA -> funcB (命中) 采样2: Task3 -> funcA -> funcC (命中) 采样3: Task4 -> funcD -> funcE (命中) 采样4: Task4 -> funcD -> funcE (命中)

可确认Task3和Task4各执行2次，结合总耗时可估算单次执行时间。

场景3：异步任务溯源

当采样任务来源于uv_queue_work时，HarmonyOS增强日志会拼接完整的任务提交者调用栈：

========SubmitterStacktrace======== #00 uv_queue_work+292 #01 libsample.so #02 ArkNativeFunctionCallBack() #03 RTStub_PushCallArgsAndDispatchNative() #04 BCStub_HandleCallthis0Imm8V8StwCopy+372 #05 at Index.ts:381:36 <- 追溯到具体JS代码行

总结对比

核心优势：HarmonyOS增强日志的采样栈机制，将"瞬时切面"转化为"时间序列"，特别适合Android难以定位的繁忙类和系统栈密集类问题。如下图，可以完整的看出调用序列中的瓶颈在appfreeze_threadblock模拟函数中。

总结

冻屏增强日志的核心价值在于：将"瞬时切面"转化为"时间序列"，让开发者能够追踪主线程在一段时间内的完整执行轨迹，从而精准定位繁忙类冻屏的根因。

增强日志使用口诀：

• 先看CpuTime - 判断是阻塞还是繁忙

• 再看Cpu使用率 - 确认是否为调度问题

• 后解析采样栈 - 找出耗时函数

• 结合多栈分析 - 确定优化优先级