xsl/face_sdk

Fork 0

Files

T

xsl fb434f09b8 添加调试日志

2026-04-23 11:29:18 +08:00

8.8 KiB

Raw Permalink Blame History

Face SDK 崩溃调试指南

本文档说明如何配合 AI 定位 libface_sdk.so 里的崩溃 / 异常。核心思路：把 Vulkan 每一次异常的上下文写进一个持久日志文件里，崩溃或画面卡住后把这份文件发给 AI 分析。

一、已经加好的东西（不需要你做什么）

1. `DebugLog` 模块（`app/src/main/cpp/DebugLog.{h,cpp}`）

线程安全；
每条日志带时间戳 + 线程 ID（tid）；
写到 App 私有目录下的文件 —— 不会被 logcat 自动清掉；
每写一行 fflush，进程挂了也不丢最后几行；
文件大小超过 2MB 自动滚动到 .old；
同步把日志镜像到 logcat，tag 是 FACE_DBG。

2. 打点位置

位置	打点内容	用途
`android_main` 启动	pid、tid、日志文件绝对路径	每次启动一条，作为分段锚点
渲染循环心跳	每 600 帧一条：`frame=X exceptions_so_far=Y`	判断启动多久后崩溃 / 异常持续性
`try/catch` 兜底	首 10 次异常每次都打，之后每 120 次打一次	Vulkan 异常不会再让进程硬崩，留住现场
`handle_cmd`	每个 `APP_CMD_*` 事件（尤其 `INIT_WINDOW`/`TERM_WINDOW`/`CONFIG_CHANGED`）	旋转 / 切后台 / 锁屏场景的时间线
`FaceApp::initVulkan` 入/出口	调用次数、`_applicationInited` / `_faceAppInited` / `_sceondInited` 状态	判断是否被多次重复调用
`processImageNative` / `passDataToNative`	每 300 次调用打一条 tid	验证"Java 两个回调在不同线程并发调 Vulkan"假设
`Application::drawFrame` 里的 4 次 Vulkan 调用	非 `VK_SUCCESS` 时打印数值 + 字符串名（例如 `-4 (VK_ERROR_DEVICE_LOST)`）	最关键的证据

3. 关键行为变化

⚠️ 现在 drawFrame 里 Vulkan 抛出的异常会被 try/catch 吃掉 —— App 不会再因为这类问题硬崩溃。

好处：你能继续跑、继续复现、日志一直在写；
代价：出问题时表现从"崩溃"变成"画面卡住 / 黑屏 / 不再更新"。
如果想暂时回到硬崩行为：把 app/src/main/cpp/main.cpp 里那段 try { g_Application->drawFrame(...); } catch (...) { ... } 改回直接 g_Application->drawFrame(frameTime); 即可。

二、怎么把日志文件取出来

方式 A：`run-as`（推荐，不需要 root）

adb shell "run-as com.inewme.uvmirror cat files/face_sdk_debug.log" > face_sdk_debug.log
adb shell "run-as com.inewme.uvmirror cat files/face_sdk_debug.log.old" > face_sdk_debug.log.old

.old 只有文件滚动过一次才存在，没有可以忽略错误。

方式 B：直接看 logcat（实时）

adb logcat -s FACE_DBG

和文件内容基本一致。跑较久的话还是文件更可靠。

方式 C：从 App 里拿路径

启动后 FACE_DBG 第一条日志长这样：

[10:12:03.041][tid=12345] android_main start, pid=23456 tid=12345, logPath=/data/user/0/com.inewme.uvmirror/files/face_sdk_debug.log

照这个路径走就对了。

三、你现在要做的事（B 方案：两种场景都复现一次）

场景 1：旋转崩溃（已确认必现）

打开 App，等初始化完成（画面能看到人脸渲染）。
旋转一次屏幕。
等 3~5 秒让日志写进去。
取 face_sdk_debug.log，不要清文件，继续场景 2。

期望看到的关键行：

>> handle_cmd APP_CMD_TERM_WINDOW(...)
>> handle_cmd APP_CMD_INIT_WINDOW(...)
FaceApp::initVulkan enter, call#2 ...
drawFrame[NNN] vkAcquireNextImageKHR -> ??? (...)
!!! drawFrame std::exception (frame=NNN count=M): failed to ...

注意里面那个 ??? —— 这是整件事的核心证据。

场景 2：长时间运行崩溃（之前那个 10 分钟左右的）

不要退出 App，接着跑。现在即使旋转触发了异常，进程没死，我们希望看后续会不会再出另一种 VkResult：

尽量不操作（不切后台、不旋转、不锁屏，让 App 持续渲染）。
连续跑 15~20 分钟，观察是否复现之前的"无外部事件崩溃"。
复现后（或稳定 20 分钟未复现也行），再取一次 face_sdk_debug.log（这次会覆盖场景 1 的那份，所以务必先把场景 1 的单独保存好）。

期望看到的关键行（如果真的是 DEVICE_LOST）：

drawFrame[NNN] vkQueueSubmit -> -4 (VK_ERROR_DEVICE_LOST) ...

或者某个 Vulkan 调用返回其他错误码。

辅助信息（手边有就顺便记一下）

项	为什么要
机型 + Android 版本	GPU 驱动差异；Adreno / Mali / Xclipse 表现差别大
复现时手机是不是很烫	排查 GPU 温控 / thermal throttling
旋转时是"横屏 → 竖屏"还是"竖屏 → 横屏" / 多次连续旋转？	某些机型一次 vs 多次触发行为不同
10 分钟崩溃时 App 在做什么（有在切换 motion 吗？）	帮助排除 `changeMotionList` 相关路径

四、发给 AI 的时候包含什么

最小集：

face_sdk_debug.log（场景 1 旋转那份）
face_sdk_debug.log（场景 2 长跑那份）
如果文件很大，完整发比截断发强（AI 主要关心最后几千行）
一句话说明这份日志对应场景 1 还是场景 2，是否复现了

不需要的：

logcat 完整 dump（体积太大且大多无关，除非 AI 主动问特定 tag）
录屏
源代码（AI 已经能看到仓库）

五、当前未解决的假设，等日志验证

假设	对应 VkResult	修法
旋转导致 surface 失效未处理	`VK_ERROR_OUT_OF_DATE_KHR` (-1000001004) 或 `VK_ERROR_SURFACE_LOST_KHR` (-1000000000) 或 `VK_SUBOPTIMAL_KHR` (1000001003)	实现 `APP_CMD_TERM_WINDOW` 销毁流程 + swapchain 重建
Java 多线程并发提交 graphicsQueue 导致 GPU 长时间后挂	`VK_ERROR_DEVICE_LOST` (-4)，且 `processImageNative` / `passDataToNative` 日志里 tid 不同	给所有 `vkQueueSubmit`/`vkQueuePresentKHR` 加全局 queue mutex
驱动 bug / 温度导致 GPU hang	`VK_ERROR_DEVICE_LOST` (-4)，单线程也出	捕获并尝试重建 device，或上报给机型厂商
资源累积泄漏	`VK_ERROR_OUT_OF_DEVICE_MEMORY` (-2) 或 `VK_ERROR_TOO_MANY_OBJECTS`	排查 `beginSingleTimeCommands`/`processWithVulkan` 路径

六、日志样例（便于你确认打印是否正常）

正常启动应该看到：

========== DebugLog opened @ 2026-04-23 14:05:12 (pid=12345) ==========
[14:05:12.019][tid=12345] android_main start, pid=12345 tid=12345, logPath=/data/user/0/com.inewme.uvmirror/files/face_sdk_debug.log
[14:05:12.155][tid=12345] >> handle_cmd APP_CMD_START(10) tid=12345
[14:05:12.155][tid=12345] << handle_cmd APP_CMD_START done
[14:05:12.210][tid=12345] >> handle_cmd APP_CMD_INIT_WINDOW(1) tid=12345
[14:05:12.210][tid=12345] handle_cmd APP_CMD_INIT_WINDOW: calling initVulkan()
[14:05:12.210][tid=12345] FaceApp::initVulkan enter, call#1 _applicationInited=0 _faceAppInited=0 _secondfaceAppInited=0
[14:05:13.420][tid=12345] FaceApp::initVulkan exit, call#1 _applicationInited=1 _faceAppInited=1 _secondfaceAppInited=1
[14:05:13.420][tid=12345] handle_cmd APP_CMD_INIT_WINDOW: initVulkan() returned, isInited=1
[14:05:13.421][tid=12345] << handle_cmd APP_CMD_INIT_WINDOW done
[14:05:14.005][tid=67890] processImageNative #1 tid=67890 w=480 h=480
[14:05:14.008][tid=67891] passDataToNative #1 tid=67891 point_count=468 w=480 h=480
[14:05:35.200][tid=12345] heartbeat: frame=600 exceptions_so_far=0

旋转时如果触发异常应该看到：

[14:06:10.112][tid=12345] >> handle_cmd APP_CMD_CONFIG_CHANGED(8) tid=12345
[14:06:10.113][tid=12345] >> handle_cmd APP_CMD_TERM_WINDOW(2) tid=12345
[14:06:10.113][tid=12345] handle_cmd APP_CMD_TERM_WINDOW: (no handler yet, ...)
[14:06:10.113][tid=12345] << handle_cmd APP_CMD_TERM_WINDOW done
[14:06:10.250][tid=12345] >> handle_cmd APP_CMD_INIT_WINDOW(1) tid=12345
[14:06:10.250][tid=12345] FaceApp::initVulkan enter, call#2 _applicationInited=1 _faceAppInited=1 _secondfaceAppInited=0
[14:06:10.250][tid=12345] FaceApp::initVulkan exit, call#2 _applicationInited=1 _faceAppInited=1 _secondfaceAppInited=1
[14:06:10.280][tid=12345] drawFrame[1234] vkAcquireNextImageKHR -> -1000001004 (VK_ERROR_OUT_OF_DATE_KHR) currentFrame=0
[14:06:10.280][tid=12345] !!! drawFrame std::exception (frame=1234 count=1): failed to acquire swap chain image!

只要日志里能看到 vkXxxKHR -> <数值> (<名字>) 这一行，诊断就成立了。

七、文件清单（仅供参考，日常不用动）

app/src/main/cpp/
  DebugLog.h        新增
  DebugLog.cpp      新增
  main.cpp          改：日志初始化 / 心跳 / try-catch / cmd 日志 / JNI tid
vulkan/
  Application.cpp   改：drawFrame 4 处 VkResult 日志 + VkResultStr
  FaceApp.cpp       改：initVulkan 入/出口日志
CMakeLists.txt      改：加入 DebugLog.cpp 到 Android 构建

8.8 KiB Raw Permalink Blame History Unescape Escape