最近负责的项目中,有一定制客户频繁的抱怨设备在安装一些客户的app组件后,云端采集到的CPU占用率信息一直维持在78%以上,甚至还会出现90%的情况,与此同时,用户也反映了卡顿、耗电快等现象。
为了解决客户这个痛点问题,拿了一台复现设备来分析此CPU高的问题,以下是分析思路和过程,mark一下。
-
问题现象
设备在刷入原生软件版本时,后台收集到的CPU占用信息大约在27%,正常现象。
而在客户定制版本上,CPU至少在78%,对比两个版本区别,发现定制客户在原生软件版本上多安装了6个APP组件,此类app属于客户自研app,重启机器静置5分钟后,观察CPU信息,占用率没有降低,对这么高cpu占用率吓到了。
-
CPU问题分析过程
1. 抓Log分析
在客户上报问题后,不管反馈的问题是什么(重启\crash\卡顿等),一旦设备有问题出现,对于研发人员来说,在了解到问题现象后,接下来就是需要一份Log,不能无的放矢。
上图Log信息,发现后台一直在重复打印如上信息,第一直觉告诉我,会不会截图中log频繁输出导致cpu居高不下的。
于是乎,根据这个怀疑点,首先将以上日志信息注释掉,不让其打印出来,然后对比一下cpu前后使用情况,事实证明我的直觉一向不准,cpu使用率没有什么改善。
2. Android Profiler工具,实时说明CPU使用情况
Android Profiler这个工具就不多说了,简而言之,就是Android Studio自带的分析性能(包括cpu/memory/network)工具。
将现场设备连上USB后,用Android Profiler工具查看CPU使用情况,发现system_process进程的cpu一直维持在80%左右,如下图:
利用工具对system_server进程单独采样一段时间,具体看看这段时间内system_server进程在进行什么样的操作,采样信息如图所示:
两张图结合起来可以看出,system进程中,十几个binder线程都在轮询工作,即占用cpu,而正是这些线程不断执行任务,才导致system整个进程cpu占用高,那么这些binder线程具体在进行什么操作呢,还需要看单个线程的堆栈信息,如图所示(这里只贴出其中一个线程的堆栈,因为其他线程都是类似的堆栈信息):
根据堆栈调用信息,system进程在不断地dump meminfo信息,多个binder线程不断被请求dump meminfo信息,这才引起了cpu一直占用高。
竟然binder线程被请求dump meminfo信息,那么客户端是哪些进程呢,在IPC中,服务端被调用,肯定是有个对端--客户进程发起请求的。
所以还需要排查是哪个客户进程频繁发起服务请求的,查看system进程的binder调用情况,如下图所示:
根据system进程的binder请求信息,可以看到是进程号为4886、5207、5006这几个客户端进程不断在请求获取么meminfo内存信息的,而这几个进程号对应的包名为:
这几个应用,正是客户在设备上安装的app,所以基本确认是客户app代码不断请求获取meminfo内存信息导致的,需要优化客户app的代码逻辑,不要不停的获取内存信息,这样频繁请求meminfo信息,导致cpu负载很高,一直居高不下。
-
问题确认
为了再次确认上述分析的原因,修改接口getMemoryInfo的逻辑,使其直接return返回,不再真正地执行dump meminfo内存信息,重启机器后,cpu占用直接降到40%,正如所料。
现场 | 未屏蔽 | 已屏蔽 |
---|---|---|
CPU占用 | 80%以上 | 45% |
-
问题总结
有果比有因,需要具体分析到cpu占用高具体是在执行什么操作,打印出问题进程的堆栈信息,才能从代码端解决问题,找到root cause。