AppFreeze(应用冻屏)检测

简介

用户在使用应用时,如果出现点击无反应或应用无响应等情况,并且持续时间超过一定限制,就会被定义为应用冻屏(AppFreeze),即应用无响应。系统会检测应用无响应,并生成AppFreeze日志,供应用开发者分析。

说明:

本文仅适用于Stage模型下的应用。在根据本文分析日志前,开发者需要具备JS在系统中运行情况、C++程序堆栈信息的相关基础知识,并对应用相关的子系统有一定了解。

检测原理

目前应用冻屏检测从以下三个维度检测,了解其原理有助于应用开发者定位和分析AppFreeze故障。

注意:

AppFreeze检测仅对release版本应用生效,对debug版本应用不生效。

故障类型 说明
THREAD_BLOCK_6S 应用主线程卡死超时
APP_INPUT_BLOCK 用户输入响应超时

当应用发生上述故障时,为了保证可恢复,会杀死应用。并上报应用冻屏事件,可通过HiAppEvent订阅应用冻屏事件

THREAD_BLOCK_6S 应用主线程卡死超时

概述:发生该故障,表示当前应用主线程有卡死或者执行任务过多的情况,影响应用的流畅度和体验。

检测原理:应用的watchdog线程定期向主线程插入判活检测任务。如果判活检测超过3s未被执行,将上报THREAD_BLOCK_3S告警事件;如果超过6s仍未被执行,将上报THREAD_BLOCK_6S主线程卡死事件。两个事件匹配生成THREAD_BLOCK的应用无响应日志。

检测原理如下图:

图1

thread_block

APP_INPUT_BLOCK 用户输入响应超时

概述:该故障是指点击事件超过5s未得到响应。

检测原理:用户点击应用时,输入系统会向应用侧发送点击事件;应用侧的响应反馈回执超时,则上报该故障。

检测原理如下图:

图2

app_input_block

日志获取

应用冻屏日志和进程崩溃日志一致,都是由Faultlogger模块进行管理,可通过以下方式获取:

方式一:通过DevEco Studio获取日志

DevEco Studio会收集设备/data/log/faultlog/faultlogger/路径下的进程崩溃故障日志到FaultLog下,根据进程名和故障时间分类显示。获取日志的方法参见:DevEco Studio使用指南-FaultLog

方式二:通过HiAppEvent接口订阅

HiAppEvent给开发者提供了故障订阅接口,详见HiAppEvent介绍。参考订阅应用冻屏事件(ArkTS)订阅应用冻屏事件(C/C++)完成应用冻屏事件订阅,并通过事件的external_log字段读取故障日志文件内容。

方式三:通过hdc获取日志,需打开开发者选项

在开发者选项打开的情况下,开发者可以通过hdc file recv /data/log/faultlog/faultlogger D:\命令导出故障日志到本地,故障日志文件名格式为appfreeze-进程名-进程UID-毫秒级时间.log。

日志规格

应用冻屏(AppFreeze)问题需要结合应用冻屏日志和hilog流水日志进行分析。

当前提供一个故障分析示例,请开发者根据具体问题具体分析。

应用冻屏日志主要分以下几个模块信息:

日志头部信息

Generated by HiviewDFX@OpenHarmony
================================================================
Device info:HUAWEI Mate 60 Pro
Build info:ALN-AL00 6.0.0.328(C00E1R4P3DEVDUlog)
DeviceDebuggable:No
Fingerprint:e18a33c12e1361173ec9ac1c93f2bd0c2daa88f03c7f76b228cca14bdc6a21b1
Module name:com.samples.freezedebug
ReleaseType:Release
CpuAbi:arm64-v8a
Version:1.0.0
VersionCode:1000000
IsSystemApp:No
PreInstalled:No
Foreground:Yes
Pid:13680
Uid:20020177
Process life time:18s
Process Memory(kB):163819(Rss)
Device Memory(kB):Total 11679272, Free 3697424, Available 5814272
Reason:THREAD_BLOCK_6S
appfreeze: com.samples.freezedebug THREAD_BLOCK_6S at 20250628140837
DisplayPowerInfo:powerState:UNKNOWN
HitraceIdInfo: hitrace_id: a92ab27238f409a, span_id: 1cd61c9, parent_span_id: 3072e, trace_flag: 0
Page switch history:
  14:08:30:327 /ets/pages/Index:Appfreeze
  14:08:28:986 /ets/pages/Index
  14:08:26:502 :enters foreground
  14:08:07:606 :leaves foreground
  14:08:06:246 /ets/pages/Index:Appfreeze
  14:08:01:955 :enters foreground
>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
DOMAIN:AAFWK
STRINGID:THREAD_BLOCK_6S
TIMESTAMP:2025/06/28-14:08:37:360
PID:13680
UID:20020177
PACKAGE_NAME:com.samples.freezedebug
PROCESS_NAME:com.samples.freezedebug
NOTE: Current fault may be caused by the system's low memory or thermal throttling, you may ignore it and analysis other faults.
***

从API version 20开始,当整机资源告警(如整机低内存或热限频)时,会输出NOTE行。出现此行时,开发者可以忽略应用冻屏故障。在之前的API版本中,无论整机资源状态如何,均无此行输出。

从API version 20开始,发生THREAD_BLOCK_6S故障时,日志中新增HiTraceId信息打印。HitraceId是HiTraceChain提供的唯一跟踪标识,用于跟踪业务流程调用链。可以协助开发者查看故障时间段内,故障流程的hilog日志,分析日志查看应用的执行状态。

三种AppFreeze事件都包含以下几部分信息,具体解释如下:

字段 说明
DeviceDebuggable 设备是否可调试。
说明:从API 23开始支持。
ReleaseType 标识应用打包时使用的SDK的发布类型。仅在应用进程提供,具体说明详见ApplicationInfo中的releaseType。
说明:从API 23开始支持。
CpuAbi 二进制接口类型。
说明:从API 23开始支持。
IsSystemApp 应用是否为系统应用。
说明:从API 23开始支持。
Reason 应用无响应原因,与应用无响应检测能力点对应。
PID 发生故障时的pid。
PACKAGE_NAME 应用进程包名。
Page switch history 从API 20开始,维测进程会记录应用切换历史。应用发生故障后,生成的故障文件将包含页面切换历史轨迹。如果维测服务进程出现故障或未缓存切换轨迹,则不包含此字段。
Process life time 故障进程存活时间。单位:s。
说明:从API 22开始支持。
Process Memory(kB) 故障进程内存占用。
说明:从API 22开始支持。
Device Memory(kB) 整机内存状态。
说明:从API 22开始支持。

日志主干通用信息

start time: 2025/06/28-14:08:34:318
DOMAIN = AAFWK
EVENTNAME = THREAD_BLOCK_3S
TIMESTAMP = 2025/06/28-14:08:34:310
PID = 13680
UID = 20020177
TID = 13680
PACKAGE_NAME = com.samples.freezedebug
PROCESS_NAME = com.samples.freezedebug
eventLog_action = ffrt,t,GpuStack,cmd:m,hot
eventLog_interval = 10
MSG =
Fault time:2025/06/28-14:08:34
App main thread is not response!
Main handler dump start time: 2025-06-28 14:08:34.067
mainHandler dump is:
 EventHandler dump begin curTime: 2025-06-28 14:08:34.067
 Event runner (Thread name = , Thread ID = 13680) is running
 Current Running: start at 2025-06-28 14:08:27.354, Event { send thread = 13680, send time = 2025-06-28 14:08:22.353, handle time = 2025-06-28 14:08:27.353, trigger time = 2025-06-28 14:08:27.354, task name = uv_timer_task, caller = [ohos_loop_handler.cpp(OnTriggered:72)] }
 History event queue information:
 No. 0 : Event { send thread = 13856, send time = 2025-06-28 14:08:22.336, handle time = 2025-06-28 14:08:22.336, trigger time = 2025-06-28 14:08:22.336, completeTime time = 2025-06-28 14:08:22.337, priority = VIP, task name = MMITask, caller = [deamon_io_waiter.cpp(HandleFileDescriptorEvent:225)] }
...
 No. 31 : Event { send thread = 13856, send time = 2025-06-28 14:08:22.330, handle time = 2025-06-28 14:08:22.380, trigger time = 2025-06-28 14:08:22.330, completeTime time = 2025-06-28 14:08:22.331, priority = VIP, task name = vSyncTask, caller = [deamon_io_waiter.cpp(PostTaskForVsync:159)] }
 VIP priority event queue information:
 No.1 : Event { send thread = 13843, send time = 2025-06-28 14:08:31.066, handle time = 2025-06-28 14:08:31.066, id = 1, caller = [watchdog.cpp(Timer:233)] }
 No.2 : Event { send thread = 13843, send time = 2025-06-28 14:08:34.067, handle time = 2025-06-28 14:08:34.067, id = 1, caller = [watchdog.cpp(Timer:233)] }
 Total size of VIP events : 2
 Immediate priority event queue information:
 Total size of Immediate events : 0
 High priority event queue information:
 Total size of High events : 0
 Low priority event queue information:
 Total size of Low events : 0
 Idle priority event queue information:
 Total size of Idle events : 0
 Total event size : 2

三种AppFreeze事件都包含以下几部分信息,具体解释如下:

主要信息字段 说明
EVENTNAME 组成卡死检测事件。
TIMESTAMP 发生故障时上报事件的时刻,可以根据应用无响应检测能力点中说明的超时时间,在相应hilog流水日志中缩小查看日志的时间范围。
PID 发生故障时候的pid。
UID 故障进程UID。
TID 发生故障时候的tid。
PACKAGE_NAME 应用进程包名。
PROCESS_NAME 应用进程名。
MSG 发生故障时间及EventHandler信息。

EventHandler信息,具体解释如下:

dump信息组成结构:

主要信息字段 说明
EventHandler dump begin curTime 获取dump信息时间。
Event runner EventHandler对应的线程名和线程号。
Current Running 当前正在执行的完整任务信息。
History event queue information 历史执行任务信息。
VIP priority event queue information VIP级任务队列信息。
Immediate priority event queue information 立即执行任务队列信息。
High priority event queue information 高优先级任务队列信息。
Low priority event queue information 低优先级任务队列信息。
Idle priority event queue information 挂起任务队列信息。

任务组成部分:

主要信息字段 说明
send thread 提交任务线程号。
send time 提交任务时间。
task name 任务队列中的任务名。
priority 任务优先级。
caller 任务提交方法。
handle time 任务预期执行时间。与实际的任务执行时间(trigger time)可能存在偏差
trigger time 任务执行时间。
completeTime time 任务执行完成时间(如果没有打印则表示该任务未执行完成)。

说明:

EventHandler信息中,开发者只需重点关注EventHandler dump begin curTime,trigger time和completeTime time时间即可。

EventHandler信息详细指导可参考:查看eventHandler信息

堆栈信息

显示故障进程堆栈信息。

Tid:13680, Name:les.freezedebug
state=S, utime=0, stime=0, priority=0, nice=-20, clk=100
#00 pc 000000000000186c [shmm](__kernel_gettimeofday+72)
#01 pc 00000000001d887c /system/lib/ld-musl-aarch64.so.1(gettimeofday+40)(f1a940981720250b920ee26d2d76af5b)
#02 pc 000000000058fb5c /system/lib64/platformsdk/libark_jsruntime.so(panda::ecmascript::builtins::BuiltinsDate::Now(panda::ecmascript::EcmaRuntimeCallInfo*)+48)(0f1928b77d36d27edb5512bd89806a6f)
#03 pc 0000000000cff5dc /system/lib64/module/arkcompiler/stub.an(RTStub_PushCallArgsAndDispatchNative+40)
#04 pc 000000000036aaf4 /system/lib64/module/arkcompiler/stub.an(BCStub_HandleCallthis0Imm8V8StwCopy+380)
#05 at wait15s (entry/src/main/ets/pages/Index.ets:16:10)
#06 pc 000000000026b1dc /system/lib64/platformsdk/libark_jsruntime.so(panda::ecmascript::InterpreterAssembly::Execute(panda::ecmascript::EcmaRuntimeCallInfo*)+536)(0f1928b77d36d27edb5512bd89806a6f)
#07 pc 000000000096b188 /system/lib64/platformsdk/libark_jsruntime.so(panda::FunctionRef::CallForNapi(panda::ecmascript::EcmaVM const*, panda::JSValueRef*, panda::JSValueRef* const*, int)+1432)(0f1928b77d36d27edb5512bd89806a6f)
#08 pc 000000000006b7a4 /system/lib64/platformsdk/libace_napi.z.so(napi_call_function+212)(eaa639519e67e8495ca596293a0d33cd)
#09 pc 000000000000b17c /system/lib64/platformsdk/libtimer.z.so(OHOS::JsSysModule::Timer::TimerCallback(uv_timer_s*) (.cfi)+528)(764291289e89523cdbe9c3c78c1cca35)
#10 pc 0000000000013ea8 /system/lib64/platformsdk/libuv.so(uv__run_timers+68)(9e7eb59ca1a45f4230b641a7c940a20b)
#11 pc 000000000001a344 /system/lib64/platformsdk/libuv.so(uv_run+376)(9e7eb59ca1a45f4230b641a7c940a20b)
#12 pc 00000000000895a8 /system/lib64/platformsdk/libruntime.z.so(OHOS::AbilityRuntime::OHOSLoopHandler::OnTriggered()+140)(daf29e377c47e3e26282e745dd1b3488)
#13 pc 0000000000089b4c /system/lib64/platformsdk/libruntime.z.so(std::__h::__function::__func<OHOS::AbilityRuntime::OHOSLoopHandler::OnTriggered()::$_0, std::__h::allocator<OHOS::AbilityRuntime::OHOSLoopHandler::OnTriggered()::$_0>, void ()>::operator()() (.9efded9864dc55830f61b3b92d59beab)+52)(daf29e377c47e3e26282e745dd1b3488)
#14 pc 000000000001ff6c /system/lib64/chipset-sdk-sp/libeventhandler.z.so(OHOS::AppExecFwk::(anonymous namespace)::EventRunnerImpl::ExecuteEventHandler(std::__h::unique_ptr<OHOS::AppExecFwk::InnerEvent, void (*)(OHOS::AppExecFwk::InnerEvent*)>&)+2228)(475713336c2720d372d5aeb99dda5f9f)
#15 pc 000000000001a7d8 /system/lib64/chipset-sdk-sp/libeventhandler.z.so(OHOS::AppExecFwk::(anonymous namespace)::EventRunnerImpl::Run()+648)(475713336c2720d372d5aeb99dda5f9f)
#16 pc 000000000003f5f4 /system/lib64/chipset-sdk-sp/libeventhandler.z.so(OHOS::AppExecFwk::EventRunner::Run()+404)(475713336c2720d372d5aeb99dda5f9f)
#17 pc 00000000000a50f0 /system/lib64/platformsdk/libappkit_native.z.so(OHOS::AppExecFwk::MainThread::Start()+504)(e794b687fdf46631ae5144eba250f8c0)
#18 pc 0000000000005278 /system/lib64/appspawn/appspawn/libappspawn_ace.z.so(RunChildProcessor(AppSpawnContent*, AppSpawnClient*)+568)(143c05087e9460f0fd794b9dce5dec29)
#19 pc 000000000000baa8 /system/bin/appspawn(AppSpawnChild+648)(25ab88f6e04b1d2c8feb5d3eebfb4664)
#20 pc 0000000000016478 /system/bin/appspawn(ProcessSpawnReqMsg+3260)(25ab88f6e04b1d2c8feb5d3eebfb4664)
#21 pc 0000000000013aac /system/bin/appspawn(OnReceiveRequest+724)(25ab88f6e04b1d2c8feb5d3eebfb4664)
#22 pc 0000000000017844 /system/lib64/chipset-sdk-sp/libbegetutil.z.so(HandleRecvMsg_+384)(a9ddb8b84cc09183cc6bd2e5bb875f30)
#23 pc 000000000001715c /system/lib64/chipset-sdk-sp/libbegetutil.z.so(HandleStreamEvent_+152)(a9ddb8b84cc09183cc6bd2e5bb875f30)
#24 pc 000000000001444c /system/lib64/chipset-sdk-sp/libbegetutil.z.so(ProcessEvent+380)(a9ddb8b84cc09183cc6bd2e5bb875f30)
#25 pc 0000000000013edc /system/lib64/chipset-sdk-sp/libbegetutil.z.so(RunLoop_.llvm.16927440879641410339+656)(a9ddb8b84cc09183cc6bd2e5bb875f30)
#26 pc 0000000000010dcc /system/bin/appspawn(AppSpawnRun+212)(25ab88f6e04b1d2c8feb5d3eebfb4664)
#27 pc 000000000000eb90 /system/bin/appspawn(main+728)(25ab88f6e04b1d2c8feb5d3eebfb4664)
#28 pc 00000000000a9804 /system/lib/ld-musl-aarch64.so.1(libc_start_main_stage2+84)(f1a940981720250b920ee26d2d76af5b)

大部分情况下,THREAD_BLOCK_6S、APP_INPUT_BLOCK故障的堆栈信息,可以协助开发者定位到异常代码。

其他情况下(比如瞬时栈场景),由于主线程繁忙等问题,导致获取堆栈信息延迟,无法及时捕获到异常代码段,堆栈的栈顶信息并非开发者期望获取的结果。

为解决上述问题,从API version 21开始,支持获取AppFreeze的增强日志。协助开发者定位问题,详见AppFreeze(应用冻屏)增强日志实现原理

说明:

在整机高负载情况(如CPU高负载)下,采用低开销方式获取调用栈时,可能损失函数名信息。

从API version 21开始,出现'Failed to dump normal stacktrace'字样时,系统采取轻量化的frame pointer回溯模式。栈回溯可能中断在非使能frame pointer的库(在GCC编译使用 -fomit-frame-pointer 选项时,编译产物会非使能frame pointer),以及受轻量化的限制,单个线程的回栈层数不会超过50层。

从API version 23开始,在线程号下新增线程状态等信息,用于判断是否是系统卡顿导致的问题。其中,state表示当前线程的运行状态,priority和nice表示当前线程的调度优先级,stime和utime表示当前线程运行的时间。对比3S和6S的堆栈运行时间没有发生改变,说明进程未被调度。通过分析业务代码无阻塞调用后,可判断为系统调度问题。线程状态信息在故障日志中具体格式如下:

state=S, utime=0, priority=0, nice=-20, clk=100

字段信息具体解释如下:

字段 说明
state 线程运行状态。读取自/proc/pid/stat的state的值。
utime 线程在用户态下消耗的CPU的嘀嗒数。读取自/proc/pid/stat的utime的值。
stime 线程在内核态下消耗的CPU的嘀嗒数。读取自/proc/pid/stat的stime的值。
priority 实时优先级。读取自/proc/pid/stat的priority的值。
nice 静态优先级。读取自/proc/pid/stat的nice的值。
clk 每秒的时钟嘀嗒次数。使用sysconf(_SC_CLK_TCK)获取,获取失败时使用默认值100。通过嘀嗒数除以该值可以计算得到运行时间(单位:秒)。

对端信息(与当前故障进程通信的进程信息)

(1)BinderCatcher:显示进程间通信的调用信息及等待时间过长的情况。

PeerBinderCatcher -- pid==13680
BinderCatcher --
    13840:14102 to 901:4079 code 16 wait:0.25653125 s frz_state:3,  ns:-1:-1 to -1:-1, debug:13840:14102 to 901:4079, active_code:0, active_thread=0, pending_async_proc=0
    3712:3712 to 13967:14076 code d2 wait:0.703385417 s frz_state:3,  ns:-1:-1 to -1:-1, debug:3712:3712 to 13967:14076, active_code:0, active_thread=0, pending_async_proc=0
    1733:2285 to 3712:3712 code b wait:1.365925521 s frz_state:3,  ns:-1:-1 to -1:-1, debug:1733:2285 to 3712:3712, active_code:0, active_thread=0, pending_async_proc=0
...
pid context     request started max ready   free_async_space
14072   binder  0   2   16  3   520192
14103   binder  0   4   16  6   520192
13967   binder  0   3   16  3   520192
13878   binder  0   2   16  3   520192
13840   binder  0   2   16  3   520192
13863   binder  0   1   16  3   520192
13680   binder  0   2   16  3   520192
13770   binder  0   3   16  5   520192
13749   binder  0   3   16  5   520192
...

进程间通信调用信息解释如下:

主要信息字段 说明
xxx:xxx to xxx:xxx 客户端进程号、线程号 to 服务端进程号、线程号。其中async表示异步,无async表示同步。
code 客户端和服务端达成一致约束的业务码。
wait 通信等待时长。
frz_state 进程冻结状态。
-1 未知
1 默认
2 正在向用户态发送binder状态信息
3 走到了binder接收线程。
ns 客户端进程号、线程号 to 服务端进程号、线程号(非卓易通内进程显示-1)。
debug IPC通信双方的信息补充。
active_code 正在处理的异步消息code。
active_thread 处理这个异步消息的线程。
pending_async_proc 被这个异步消息阻塞的进程。
pid 进程PID。
context 通信方式。
request 请求申请的IPC线程数量。
started 已经申请启动的IPC线程数量。
max 可以申请的最大IPC线程数量。
ready 空闲IPC线程。
free_async_space 空闲异步空间,用于观测异步信息阻塞。

(2)PeerBinder Stacktrace:故障进程相关的对端进程有卡死,会抓取对端的进程堆栈,即与当前进程通信的进程堆栈

Tid:48841, Name:xxx
#00 pc 000000000016adf4 /system/lib/ld-musl-aarch64.so.1
#01 pc 000000000001c0d4 /system/lib64/chipset-sdk-sp/libeventhandler.z.so
#02 pc 000000000001a7f4 /system/lib64/chipset-sdk-sp/libeventhandler.z.so
#03 pc 000000000003f5f4 /system/lib64/chipset-sdk-sp/libeventhandler.z.so
#04 pc 00000000000a50f0 /system/lib64/platformsdk/libappkit_native.z.so
#05 pc 0000000000005278 /system/lib64/appspawn/appspawn/libappspawn_ace.z.so
#06 pc 000000000000baa8 /system/bin/appspawn
#07 pc 0000000000016478 /system/bin/appspawn
#08 pc 0000000000013aac /system/bin/appspawn
#09 pc 0000000000017844 /system/lib64/chipset-sdk-sp/libbegetutil.z.so
#10 pc 000000000001715c /system/lib64/chipset-sdk-sp/libbegetutil.z.so
#11 pc 000000000001444c /system/lib64/chipset-sdk-sp/libbegetutil.z.so
#12 pc 0000000000013edc /system/lib64/chipset-sdk-sp/libbegetutil.z.so
#13 pc 0000000000010dcc /system/bin/appspawn
#14 pc 000000000000eb90 /system/bin/appspawn
#15 pc 00000000000a9804 /system/lib/ld-musl-aarch64.so.1
#16 pc 000000000000b754 /system/bin/appspawn

CPU信息

整机CPU信息及解释如下:

Load average: 14.3 / 12.9 / 11.4; the cpu load average in 1 min, 5 min and 15 min
CPU usage from 2025-06-28 14:08:36 to 2025-06-28 14:08:37
Total: 22.45%; User Space: 13.64%; Kernel Space: 8.81%; iowait: 0.33%; irq: 0.07%; idle: 77.15%
Details of Processes:
    PID   Total Usage      User Space    Kernel Space    Page Fault Minor    Page Fault Major    Name
    13680      8.86%           8.31%          0.55%            4711                6637            com.samples.freezedebug
    644        2.55%           1.40%          1.15%          210104                7391            hiview
    600        0.89%           0.78%          0.10%           60192                 514            hilogd
    1685       0.53%           0.31%          0.22%          879838               59636            foundation
主要信息字段 说明
PID 进程PID。
Total Usage CPU使用率,Total Usage = User Space+Kernel Space。
User Space 用户态使用率。
Kernel Space 内核态使用率。
Page Fault Minor 次要缺页错误。
Page Fault Major 主要缺页错误。
Name 进程名。

内存信息

Get freeze memory start time: 2025-06-28 14:08:37.112
some avg10=56.81 avg60=56.81 avg300=56.81 total=56
full avg10=56.81 avg60=56.81 avg300=56.81 total=56
...
ReclaimAvailBuffer:                    4676608 kB
...

整机内存信息如上所示,其中ReclaimAvailBuffer为整机剩余可用内存,主要用于确认是否是低内存问题。

日志差异性信息

APP_INPUT_BLOCK 用户输入响应超时

Generated by HiviewDFX@OpenHarmony
================================================================
...
Reason:APP_INPUT_BLOCK
appfreeze: com.samples.freezedebug APP_INPUT_BLOCK at 20251129123745
Wait Event(430) to be marked exceed 8000ms, lastDispatchEvent(430), lastProcessEvent(429), lastMarkedEvent(428)
DisplayPowerInfo:powerState:AWAKE
...

从API version 22开始,发生APP_INPUT_BLOCK故障时,日志中会同步输出多模点击输入(包含鼠标、键盘、触控板及触屏等输入方式)超时事件(Wait Event)。该事件信息中包含事件id,事件检测超时阈值,及前置事件id。

事件检测超时阈值:log版本为8000毫秒,nolog版本为5000毫秒。

前置事件中包含:lastDispatchEvent为上次分发的事件;lastProcessEvent为上次处理的事件;lastMarkedEvent为上次标记的事件。

在上述示例中,上次分发的事件是430,上次处理的事件是429,上次标记的事件是428,表明430事件已分发完毕,在处理环节,已超时8000毫秒。此日志可以用于APP_INPUT_BLOCK事件的简单定界,帮助问题分析。

AppFreeze(应用冻屏)增强日志信息

从API version 21开始,支持获取AppFreeze的增强日志。该日志通过采集整机及主线程的运行负载,并抓取多份主线程调用栈,帮助开发者分析问题根源。相比原有日志,AppFreeze的增强日志主要解决了以下两个不足:

  1. 难以定位故障期间的主线程热点。

  2. 缺乏对主线程繁忙或阻塞的资源层面分析。

实现原理

生成AppFreeze增强日志的流程分为以下两个阶段,具体如下:

  1. 应用进程在运行时发生THREAD_BLOCK_3S时,会开启采集主线程调用栈流程,记录当前时刻的一些CPU信息。

  2. 应用进程在运行时发生THREAD_BLOCK_6S或APP_INPUT_BLOCK时,会停止上述流程的采集主线程调用栈流程,并计算周期内的CPU信息。一般情况下,会抓取1~10次堆栈日志。

    说明:

    由于应用冻屏事件的采样栈会与MAIN_THREAD_JANK冲突,如果应用接入MAIN_THREAD_JANK的setEventConfig接口自定义配置采集堆栈的个数,应用冻屏事件的采集堆栈的会与应用当前配置的采集堆栈的个数一致。

    APP_INPUT_BLOCK故障有增强日志的前提是:先发生THREAD_BLOCK_3S。

日志获取

开发者可通过以下方式获取Appfreeze增强日志路径:

方式一:通过HiAppEvent接口订阅

应用需要在AppScope/app.json5文件中配置如下环境变量:

"appEnvironments": [
  {
    "name": "DFX_APPFREEZE_LOG_OPTIONS",
    "value": "mainthread_sampling:enable"
  }
]

HiAppEvent给开发者提供了故障订阅接口,开发者可以使用HiAppEvent监听应用冻屏事件,获取文件内容,详见应用冻屏事件介绍。参考订阅应用冻屏事件(ArkTS)订阅应用冻屏事件(C/C++)完成应用冻屏事件订阅。

开发者可以通过事件的external_log字段读取应用冻屏事件生成的故障文件和应用冻屏事件的增强日志文件。增强日志文件的命名与应用冻屏事件生成的故障文件名称格式相同。

external_log是字符串数组,第一个元素为应用冻屏事件生成的故障文件路径;第二个元素为应用冻屏事件生成的增强日志文件路径。

方式二:通过hdc获取日志,需打开开发者选项

在开发者选项打开的情况下,开发者可以通过“hdc file recv /data/log/faultlog/freeze_ext D:\”命令导出故障日志到本地,故障日志文件名格式为:freeze-cpuinfo-ext-进程名-进程UID-毫秒级时间。

日志规格

增强日志的信息头字段如下:

字段 描述 起始API版本
TimeStamp 日志生成时间。 21
Module name 故障模块名。 21

增强日志的CPU总体耗时信息字段如下:

字段 描述 起始API版本
ProcessCpuTime 统计周期内,进程运行时间。 21
DeviceRuntime 统计周期内,设备所有CPU的运行时间。 21
Tid 线程号。 21
StartTime 统计开始时间。 21
EndTime 统计结束时间。 21
StaticsDuration 统计持续时间。 21
CpuTime 统计周期内,主线程运行时间。 21
SyncWaitTime 主线程等待时间。 21
OptimalCpuTime 统计周期内,主线程最优负载运行时间(使用最大核的最高算力运行)。 21
SupplyAvailableTime 调度可优化时间。如果值较小,说明主线程繁忙,需要开发者考虑优化主线程的任务。 21

增强日志的堆栈信息字段如下:

字段 描述 起始API版本
SnapshotTime 本次抓取主线程堆栈的时间。 21
ThreadInfos Tid 线程号。 21
Name 线程名。 21
Stack 主线程调用栈。 21
SubmitterStacktrace 任务提交者调用栈。 21

增强日志规格

本节主要介绍增强日志的一般日志规格,以下是一份Appfreeze增强日志的核心内容。可以使用聚类脚本提取主线程堆栈关键信息,提高问题定位效率及准确性。

Generated by HiviewDFX @OpenHarmony
===============================================================
TimeStamp: 2021-01-01 20:06:01.175  <- 日志生成时间
Module name: com.example.freeze   <- 模块名

#Basic Concepts   <- CPU时间注释
T1:  StaticsDuration, EndTime - StartTime.
T2:  CpuTime              --Time that spend on CPU.
T3:  SyncWaitTime         --SleepingTime + Runnable Time, etc.
T4:  OptimalCpuTime       --run the thread at the max Core's max cpu capacity.
T5:  SupplyAvailableTime  --T2 - T4. Time can be optimized by scheduling.
Equation:  T1 = T2 + T3. T2 = T4 + T5.
|-----------------------------------StaticsDuration-----------------------------------|.
|-------------------------CpuTime----------------------|--------SyncWaitTime----------|.
|----OptimalCpuTime----|------SupplyAvailableTime------|--------SyncWaitTime----------|.

#Basic Statistical Infomation  <- CPU基本统计信息
ProcessCpuTime: 0 ms  <- 统计周期内,进程运行时间
DeviceRuntime: 0 ms  <- 统计周期内,设备所有CPU的运行时间
Tid: 2320  <- 故障主线程号
StartTime: 2021-01-01 20:05:58:177  <- 统计开始时间
EndTime: 2021-01-01 20:06:01:172  <- 统计结束时间
StaticsDuration: 2995 ms  <- 统计持续时间
CpuTime: 0 ms  <- 统计周期内,主线程运行时间
SyncWaitTime: 2995 ms  <- 主线程等待时间
OptimalCpuTime: 0 ms  <- 统计周期内,主线程最优负载运行时间(使用最大核的最高算力运行)
SupplyAvailableTime: 0 ms  <- 调度可优化时间

#CpuFreq Usage (usage >=1%)  <- 当CPU单个频点使用率>=1%时,这些频点及频点的使用率就会被列出来。
start time: 2021-01-01 20:06:00:888  <- 计算CPU使用率开始时间
cpu0 Usage 23.5%, 1430MHZ 21.04%  <- cpu0的总使用率,cpu0单个频点的使用率(在1430MHZ频点下的使用率)
cpu1 Usage 23.5%, 1430MHZ 21.04%
cpu2 Usage 23.5%, 1430MHZ 21.04%
cpu3 Usage 23.5%, 1430MHZ 21.04%
.......
end time: 2021-01-01 20:06:00:888  <- 计算CPU使用率结束时间
#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)(f8a0616c89b184992d0e8883cc78f638)
#02 pc 00000000001d9f20 /system/lib64/ld-musl-aarck64.so.1(time+32)(f8a0616c89b184992d0e8883cc78f638)
#03 pc 0000000000007e2c /data/storage/el1/bundle/libs/arm64/libsample.so(WaitSomeTime()+76)(8b74cdc906ea6b2eba95d891bc91c72a)
#04 pc 0000000000009b2c /data/storage/el1/bundle/libs/arm64/libsample.so(8b74cdc906ea6b2eba95d891bc91c72a)
#05 pc 00000000000a0500 /system/lib64/platformsdk/libruntime.z.so(c2f75213ee12fdf08da323fe546923ff)
#06 pc 0000000000017b04 /system/lib64/chipset-sdk-sp/libeventhandler.z.so(366b4d7f2eba693ad06f14469b08943b)
#07 pc 0000000000016f38 /system/lib64/chipset-sdk-sp/libeventhandler.z.so(366b4d7f2eba693ad06f14469b08943b)
#08 pc 000000000003e160 /system/lib64/chipset-sdk-sp/libeventhandler.z.so(OHOS::AppExecFwk::EventRunner::Run()+396)(366b4d7f2eba693ad06f14469b08943b)
.......
========SubmitterStacktrace======== <- 任务提交者调用栈(最多抓取16层调用栈)
#00 pc 0000000000013108 /system/lib64/platformsdk/libuv.so(uv_queue_work+292)(366b4d7f2eba693ad06f14469b08943b)
#01 pc 0000000000008cdc /data/storage/el1bundle/libs/arm64/libsample.so(8b74cdc906ea6b2eba95d891bc91c72a)
#02 pc 000000000005ae00 /system/lib64/platformsdk/libace_napi.z.so(panda::JSValueRef ArkNativeFunctionCallBack<true>(panda::JsiRuntimeCallInfo*)+272)(bc1c64aabbe5c7d4db2282a6137443e1)
#03 pc 0000000000de3efc /system/lib64/module/arkcompiler/stub.an(RTStub_PushCallArgsAndDispatchNative+44)
#04 pc 0000000000448dd4 /system/lib64/module/arkcompiler/stub.an(BCStub_HandleCallthis0Imm8V8StwCopy+372)
#05 at anonymous (sample|sample|1.0.0|src/main/ets/pages/Index.ts:381:36)
#06 pc 00000000001e5c8c /system/lib64/platformsdk/libark_jsruntime.so(ce0b05d90b9fae02e7abf8e9f1e5a0f3)
.......

SnapshotTime: 2021-01-01-20-05-58.549685
#00 pc 00000000000015b8 [shmm](__kernel_gettimeofday+72)
#01 pc 00000000001d7e44 /system/lib64/ld-musl-aarck64.so.1(clock_gettime+48)(f8a0616c89b184992d0e8883cc78f638)
#02 pc 00000000001d9f20 /system/lib64/ld-musl-aarck64.so.1(time+32)(f8a0616c89b184992d0e8883cc78f638)
#03 pc 0000000000007e2c /data/storage/el1/bundle/libs/arm64/libsample.so(WaitSomeTime()+76)(8b74cdc906ea6b2eba95d891bc91c72a)
#04 pc 0000000000009b2c /data/storage/el1/bundle/libs/arm64/libsample.so(8b74cdc906ea6b2eba95d891bc91c72a)
#05 pc 00000000000a0500 /system/lib64/platformsdk/libruntime.z.so(c2f75213ee12fdf08da323fe546923ff)
.......
========SubmitterStacktrace========
#00 pc 0000000000013108 /system/lib64/platformsdk/libuv.so(uv_queue_work+292)(366b4d7f2eba693ad06f14469b08943b)
#01 pc 0000000000008cdc /data/storage/el1bundle/libs/arm64/libsample.so(8b74cdc906ea6b2eba95d891bc91c72a)
#02 pc 000000000005ae00 /system/lib64/platformsdk/libace_napi.z.so(panda::JSValueRef ArkNativeFunctionCallBack<true>(panda::JsiRuntimeCallInfo*)+272)(bc1c64aabbe5c7d4db2282a6137443e1)
#03 pc 0000000000de3efc /system/lib64/module/arkcompiler/stub.an(RTStub_PushCallArgsAndDispatchNative+44)
#04 pc 0000000000448dd4 /system/lib64/module/arkcompiler/stub.an(BCStub_HandleCallthis0Imm8V8StwCopy+372)
#05 at anonymous (sample|sample|1.0.0|src/main/ets/pages/Index.ts:381:36)
.......

Native栈帧内容说明

详细说明见Cpp Crash一般故障场景日志规格中的调用栈帧内容说明。

JS混合栈帧内容说明

详细说明见JS Crash异常代码调用栈格式

增强日志聚类规则

聚类规则说明

在一份包含多个应用主线程堆栈(如10份)的日志中,对每份采样栈执行以下操作。

1.过滤系统栈

如需过滤掉系统栈帧(如 /system/lib/...ld-musl 等)。系统栈帧格式示例:

# 00 pc 000e8400 /system/lib/ld-musl-arm.so.1(raise+176)(a40044d0acb68107cfc4adb5049c0725)

2.保留业务栈

如需保留业务栈帧(以“at”为起始字符,或包含“/data/storage”子串,JS 栈帧默认视为业务栈帧(来自应用代码)。业务栈帧格式示例:

at onPageShow har1 (har1/src/main/ets/pages/Index.ets:7:13)

3.标准化栈帧

定义标准化栈帧的内容,自行去除易变信息(如行号、字节偏移、BuildID),根据实际聚类需求保留聚类的关键信息。 对每一帧业务栈帧,执行以下清洗操作:

(1)Native栈帧标准化

原始栈帧内容 标准化后栈帧内容
# 01 pc 00006e95 /data/crasher_cpp(DfxCrasher::RaiseSegmentFaultException()+92)(d6cead5be17c9bb7eee2a9b4df4b7626) /data/crasher_cpp(DfxCrasher::RaiseSegmentFaultException()+92)

按以下步骤处理:

a. 提取函数签名部分(括号内的内容,含类名、函数名、参数);

b. 忽略PC偏移和BuildID;

c. 保留函数完整签名(包括 const、参数类型等,若日志中已解析)。

(2)JS栈帧标准化

原始栈帧内容 标准化后栈帧内容
# 00 at onPageShow (entry|har1|1.0.0|src/main/ets/pages/Index.ts:7:13) onPageShow (entry|har1|1.0.0|src/main/ets/pages/Index.ts:7:13)

按以下步骤处理:

a. 去除行号;

b. 保留函数名(如 onPageShow);

c. 保留文件路径(如 src/main/ets/pages/Index.ts);

d. 最终生成一个标准化的业务调用栈序列,用于后续聚类分析。

4.生成聚类特征

原始采样栈 最终聚类特征(调用顺序从上到下)
# 00 pc 000e8400 /system/lib/ld-musl-arm.so.1(raise+176)(a40044d0...)
# 01 pc 00006e95 /data/crasher_cpp(DfxCrasher::RaiseSegmentFaultException()+92)(d6ce...)
# 02 pc 00008909 /data/crasher_cpp(DfxCrasher::ParseAndDoCrash(char const*) const+612)(d6ce...)
# 03 at onPageShow (entry|har1|1.0.0|src/main/ets/pages/Index.ts:7:13)
/data/crasher_cpp(DfxCrasher::RaiseSegmentFaultException()+92)
/data/crasher_cpp(DfxCrasher::ParseAndDoCrash(char const*) const+612)
at onPageShow (entry|har1|1.0.0|src/main/ets/pages/Index.ts:7:13)

根据聚类特征直接聚类所有采样栈。

聚类脚本说明

该脚本的使用仅限于appfreeze增强日志。当日志内容过长、主线程堆栈存在多次重复时,用于提取业务栈聚类信息(业务栈内容、总出现次数及代表性完整堆栈等),更快定位问题。

1.脚本功能

该脚本用于批量处理指定文件夹中的.zip日志文件。按以下步骤处理:

(1)从输入文件夹中读取所有.zip文件中采样栈文件;

(2)自动逐一解压,解析及转换;

(3)将处理结果输出到指定文件夹中。

2.运行方式

get_all_result(input_dir: str, output_dir: str)
参数名 是否必填 类型 说明
input_dir 必填 字符串 输入文件夹路径,需包含若干.zip日志文件。
output_dir 必填 字符串 输出文件夹路径,脚本会将处理后的结果写入该目录。

示例:

get_all_result(r"D:\log\input", r"D:\log\output")

3.输入要求

input_dir目录下应为若干.zip文件。

不限制文件名,可为嵌套结构(脚本可拓展支持.zip内还有.zip)。

zip文件中必须带采样栈日志文件。

4.输出说明

脚本会在output_dir中生成处理结果(例如):

output_dir/
├─stack_summary.txt
├─ 业务栈聚类.txt
└─ 业务栈聚类.xlsx

实际输出类型依脚本逻辑而定(解压文件/转换文件/汇总文本/JSON/CSV等)。

5.运行前准备

确保本机或部署环境满足以下条件:

(1)已安装Python 3.x。

(2)已安装脚本依赖(如 os/zipfile/pandas 等)。

(3)output_dir不存在时脚本会自动创建(若脚本未实现自动创建,请提前建好目录)。

(4)该脚本不支持在DevEco Studio中执行,请在已按照的python环境下运行该脚本。

6.聚类脚本源码

import re
from collections import Counter, defaultdict
import os
import pandas as pd
import zipfile
import glob
from pathlib import Path

# 日志目录
log_dir = r"D:\log\input"  # 改成你日志目录
# 输出结果
output_file = r"D:\log\stack_summary.txt"
# 匹配堆栈行
stack_line_pattern = re.compile(r'^\s*(#\d+\s+pc\s+[0-9a-f]+.*|#?\d*\s*at .+)$')


# 判断是否是业务栈
def is_business_stack(line):
    line = line.strip()
    return re.match(r'^(#\d+\s+)?at .+\(.+\)$', line) is not None


def process_log_file(path):
    with open(path, "r", encoding="utf-8", errors='ignore') as f:
        lines = f.readlines()

    all_stacks = []
    current_stack = []
    for line in lines:
        if line.startswith("SnapshotTime:"):
            if current_stack:
                all_stacks.append(current_stack)
                current_stack = []
        elif stack_line_pattern.match(line):
            # 忽略无关紧要的系统行
            if re.match(r'#\d+\s+pc\s+[0-9a-f]+$', line.strip()):
                continue
            current_stack.append(line.strip())
    if current_stack:
        all_stacks.append(current_stack)

    # 对同一日志的堆栈进行计数
    stack_counter = Counter()
    for stack in all_stacks:
        business_lines = [line for line in stack if is_business_stack(line)]
        if business_lines:
            key = "\n".join(business_lines[0:5])
        else:
            key = "\n".join(stack)
        stack_counter[key] += 1

    # 只保留出现次数大于5的
    result = {k: v for k, v in stack_counter.items() if v >= 1}
    return result


def remove_lineno(line):
    return re.sub(r'^#\d+\s+', '', line.strip())


def normalize_frame(line: str) -> str:
    """
    去掉无关信息,提取业务栈的关键部分
    """
    line = line.strip()
    # 去掉 "#数字 pc 地址" 或 "#数字 at"
    line = re.sub(r'^#\d+\s+(pc\s+[0-9a-f]+\s+)?', '', line)
    # 去掉行号 (:123:1)
    line = re.sub(r':\d+(:\d+)?', '', line)
    return line


def is_business_frame(line: str) -> bool:
    """
    判断是否是业务栈
    """
    return (
            line.startswith("at ") or
            "/data/storage/" in line
    )


def unzip_all(src_dir, dest_dir):
    # 确保目标目录存在
    os.makedirs(dest_dir, exist_ok=True)

    # 找到所有 zip 文件
    zip_files = glob.glob(os.path.join(src_dir, "*.zip"))

    for zip_path in zip_files:
        # 以 zip 文件名(去掉扩展名)作为子目录
        base_name = os.path.splitext(os.path.basename(zip_path))[0]
        extract_path = os.path.join(dest_dir, base_name)

        os.makedirs(extract_path, exist_ok=True)

        # 解压
        with zipfile.ZipFile(zip_path, "r") as zip_ref:
            zip_ref.extractall(extract_path)

        print(f"✅ 解压完成: {zip_path}{extract_path}")

    print(f"\n全部解压完成,共 {len(zip_files)} 个 zip 文件。")


def get_cluster(input_dir):
    input_file = os.path.join(input_dir, 'stack_summary.txt')
    # 统计次数和代表性堆栈
    cluster_count = defaultdict(int)
    cluster_sample = {}  # 片段 key -> 代表性完整堆栈

    current_stack = []
    current_count = 0

    with open(input_file, "r", encoding="utf-8") as f:
        for line in f:
            line = line.rstrip()
            if line.startswith("出现次数:"):
                current_count = int(re.search(r'\d+', line).group())
                current_stack = []
            elif line.startswith("=" * 10) or line == "":
                if current_stack:
                    # 找第一个业务栈
                    business_frame = None
                    for frame in current_stack:
                        norm = normalize_frame(frame)
                        if is_business_frame(norm):
                            business_frame = norm
                            break
                    if business_frame:
                        cluster_count[business_frame] += 1
                        if business_frame not in cluster_sample:  # 保存代表性堆栈
                            cluster_sample[business_frame] = "\n".join(current_stack)
                current_stack = []
            else:
                current_stack.append(line)
    output_file = os.path.join(input_dir, '业务栈聚类.txt')
    # 输出到txt
    with open(output_file, "w", encoding="utf-8") as f:
        for top_line, total_count in sorted(cluster_count.items(), key=lambda x: x[1], reverse=True):
            f.write(f"业务栈: {top_line}\n")
            f.write(f"总出现次数: {total_count}\n")
            f.write("代表性完整堆栈:\n")
            f.write(cluster_sample[top_line] + "\n")
            f.write("-" * 80 + "\n")

    print(f"业务栈聚类完成,结果输出到 {output_file}")

    # 输出到excel
    rows = []
    for key, count in sorted(cluster_count.items(), key=lambda x: x[1], reverse=True):
        rows.append({
            "业务栈片段": key,
            "总出现次数": count,
            "代表性完整堆栈": cluster_sample[key]
        })
    output_excel = os.path.join(input_dir, '业务栈聚类.xlsx')
    df = pd.DataFrame(rows)
    df.to_excel(output_excel, index=False)
    print(f"业务栈聚类已导出到 {output_excel}")


def get_stack_summary(log_dir, output_dir):
    all_results = {}
    for root, dirs, files in os.walk(log_dir):
        for filename in files:
            if "freeze-cpuinfo-ext" in filename:
                path = os.path.join(root, filename)
                result = process_log_file(path)
                if result:
                    all_results[path] = result
    folder = Path(output_dir)  #统一转成 Path
    output_file = folder / 'stack_summary.txt'  #自动拼路径
    folder.mkdir(parents=True, exist_ok=True)
    # 输出结果
    with open(output_file, "w", encoding="utf-8") as f:
        for log_file, stacks in all_results.items():
            f.write(f"日志文件: {log_file}\n")
            for stack_text, count in stacks.items():
                f.write(f"出现次数: {count}\n")
                f.write(stack_text + "\n")
                f.write("=" * 80 + "\n")
    print(f"处理完成,结果输出到 {output_file}")


def get_all_result(log_dir, output_dir):
    unzip_all(log_dir, log_dir)
    get_stack_summary(log_dir, output_dir)
    get_cluster(output_dir)


if __name__ == "__main__":
    get_all_result(r"D:\log\input", r"D:\log\output")