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。