VR玩游戏卡顿issue分析
issue描述:
使用VR以及手柄,玩切水果游戏。在挥砍时,击中水果时,手柄震动,并同时出现画面卡顿。卡顿较严重,帧率降至个位数,即遇到所谓的 jank。
基础背景知识:
1. 按照FPS60计算,那么每帧的间隔约为16ms,如果间隔超过16ms,就会出现掉帧,甚至卡顿。 而FPS30,则是33ms。
2. FPS对应了从sufacefliger中处理的数据间隔。即systrace中,surfacefliger线程的处理每帧数据间隔。
3. 游戏使用的引擎是Unity,所以在切水果游戏进程中,主要看unity的线程工作情况。
4. Vsync,也就是所谓的垂直同步。是帧缓冲(frame buffer)与后台缓冲(GPU处理后的数据缓冲区)之间的同步信号,能够解决tearing问题。
思路:
根据现象,推测Root Cause是:挥砍击中水果的软件反馈,或者与手柄的通信延迟导致。
工具:
Systrace
Android Studio - CPU Profiler
分析:
1、首先使用本地机器,进行复现。发现issue 100%复现。
2、分析测试提供的log,从device log中看到在卡顿时,FPS出现严重下降;
同时查看手柄震动马达的log,发现帧率下降时,trigger马达频繁,短时间内log较多:
FPS log:
08-16 16:38:11.214 12356 12433 I svr : FPS: 74.70
08-16 16:38:12.279 12356 12433 I svr : FPS: 18.78
08-16 16:38:13.286 12356 12433 I svr : FPS: 61.57
08-16 16:38:14.290 12356 12433 I svr : FPS: 74.70
08-16 16:38:15.293 12356 12433 I svr : FPS: 74.85
08-16 16:38:18.808 12356 12433 I svr : FPS: 70.93
08-16 16:38:19.813 12356 12433 I svr : FPS: 68.66
08-16 16:38:20.817 12356 12433 I svr : FPS: 74.78
08-16 16:38:21.820 12356 12433 I svr : FPS: 74.70
08-16 16:38:22.823 12356 12433 I svr : FPS: 74.78
08-16 16:38:23.828 12356 12433 I svr : FPS: 23.90
Vibrator timestamp:
08-16 16:38:12.064 2511 12309 D ChirpID0: triggerVibrator:16, 2000, -304865112
08-16 16:38:12.127 2511 12309 D ChirpID0: triggerVibrator:16, 2000, -304865112
08-16 16:38:12.169 2511 12309 D ChirpID0: triggerVibrator:16, 2000, -304865112
08-16 16:38:12.221 2511 12309 D ChirpID0: triggerVibrator:16, 2000, -304865112
08-16 16:38:12.281 2511 12309 D ChirpID0: triggerVibrator:16, 2000, -304865112
08-16 16:38:12.323 2511 12309 D ChirpID0: triggerVibrator:16, 2000, -304865112
08-16 16:38:12.383 2511 12309 D ChirpID0: triggerVibrator:16, 2000, -304865112
08-16 16:38:12.427 2511 12309 D ChirpID0: triggerVibrator:16, 2000, -304865112
08-16 16:38:22.882 2511 12309 D ChirpID0: triggerVibrator:16, 2000, -304865112
08-16 16:38:22.901 2511 12309 D ChirpID0: triggerVibrator:16, 2000, -304865112
08-16 16:38:22.952 2511 12309 D ChirpID0: triggerVibrator:16, 2000, -304865112
08-16 16:38:22.996 2511 12309 D ChirpID0: triggerVibrator:16, 2000, -304865112
1、抓取Systrace分析:
看到surfacefliger中,确实有3处明显掉帧。但从对应时间段内,看其他进程的工作情况,并没有发现有疑点。所以并未找到根源。
2、使用CPU Profiler抓取分析java 调用overhead。
抓取到的图中,当卡顿出现时,CPU占用会降低。我们仔细看下这段时间内,系统在干什么。
首先,发现Thread-4在此期间有活动,查看函数调用跟踪,这是com.htc.vr.ChirpControllerUart.ChirpControllerDevice进程,其主要的时间是耗在sleep()上。这是一个怀疑点。
另外,发现Thread-563也在此期间有活动,并查看函数调用跟踪。com.htc.vr.ChirpControllerUart.ChirpUsbWrapper进程的ubeaconUusb_set_xb_haptic()的耗时很长。这是第二个怀疑点。
3、让负责手柄的team分析
root cause:在手柄震动API set_haptic中耗时过长,从而导致该issue。之后修改验证fix。