Android Perfetto实战_分析系统花屏问题

前两天遇到了个系统花屏的问题，基本上是必现，只要设备一开机，前三分钟就经常出现花屏。界面正常显示着就开突然花屏一下，然后又重新正常显示内容。花屏的现象如下图：

经过对现象归纳总结发现，在开机的bootlogo阶段从未出现过花屏，基本上是播放完开机动画进入系统之后才出现的问题。 并且判定认为是软件层面的问题，然后就开始怀疑是不是显示驱动有问题，在期间和驱动层的同事扯皮很久，双方都觉得不是自己这边的问题。花屏这种东西一般不太像是framework层出问题能出来的现象，自己同时也在看hwcomposer和SurfaceFlinger方面的一些概念。期间做过一些小的尝试，包括开发者选项中禁用硬件叠加层。

在此期间为了说服驱动层同事，抓了好多dmesg的日志，一直在分析，看不懂的时候就交给AI进行分析。最开始的时候一直认为是显示管线这个流程中的一些问题，所以看日志的时候都会着重看和显示驱动流程这块的关键词。分析到最后也看不出来到底是啥问题，只能从代码块中看到mtk显示驱动这块有个error级别的日志，搜索日志关键词查看源码也没啥头绪。

[  486.931526] rtcwake: [name:mediatek_drm&][DISP]CRTC0 release input fence
[  486.931571] rtcwake: [name:mediatek_drm&][DISP]CRTC0 release wakelock mtk_drm_crtc_suspend 10769
[  486.931620] rtcwake: [name:mediatek_drm&][DISP][E]mtk_atomic_doze_finish connector has no crtc

后面请教一位大佬之后，建议使用Perfetto抓个trace看看。因为这个问题基本算是必现的，所以很快就抓到了有效的trace素材。不得不感慨把性能日志图形化之后真的是非常的直观，我是看到花屏现象一出现之后就立马停止了抓trace。因此这里可以非常明显的看到在图形化日志的结尾部分CPU占用率这块有个很明显的空缺，说明花屏现象出现的时候可以认为CPU是闲着的。

随后用两棵旗帜对这片时间做起止标记，然后放大这块区域继续观察，发现有个很明显的英文单词suspend，这个dpm_suspend占据了很长的一片时间，随后点击这个dpm_suspend事件，屏幕下方出现了更详细的信息。

这里显示了这个事件的开始时间，持续时间，哪个线程发起的，运行在哪个CPU核心上。

这个信息翻译下来就是：名为 rtcwake，ID 为 3220 的线程在系统上触发或参与了一个主内核挂起事件（Main Kernel Suspend Event）。 这个事件发生在 00:00:19.182556078 时间点，持续了大约 273 毫秒，并在 CPU 7 上执行。 其实发现没有，到这里就已经能和之前的日志呼应上了，还记得之前日志中的关键词吗？这句日志中，主语不是mediatek_drm，而是冒号左边的rtcwake。事后看恍然大悟，其实就说明了这是rtcwake打印的，真正根本原因不是出在mtkdrm。

[  486.931571] rtcwake: [name:mediatek_drm&][DISP]CRTC0 release wakelock mtk_drm_crtc_suspend 10769

而后继续在dmesg日志和adb logcat日志中去搜索关键词rtcwake，然后弄清楚了具体是哪个程序在调用rtcwake，细节日志不方便透露，总结下来就是安卓不太兼容Linux的这种原生休眠机制，不能用这种方式在安卓系统上实践，应该走安卓自己原生的AlarmService，然后通过它的代理，去和底层来进行交互。在adb shell通过执行rtcwake命令能稳定复现该bug，确认就是它引起的。

出于学习了解的目的继续顺藤摸瓜,点击rtcwake这个跳转链接。查看它的具体信息：