维测典型案例分析1 —— 内存泄漏
在系统运行的过程中,内存泄漏是较为常见但是很难复现的现象,一般的内存泄漏点都是比较隐蔽的,每次几十个字节的泄漏,往往需要压测很久才能复现问题。本节案例分析,我们从一个已经压测出来的问题出发,通过维测工具的使用,来看一次内存泄漏的分析。
1. 问题现象:
xx平台压测反复断AP电源第488次连接通道时出现dump机现象
**
2. 重现步骤:
- 设备认证连接,并保持在线状态(维持心跳)
b. .待连接稳定后,断开网络(断AP电源)
c .5分钟后恢复AP电源
d .查看设备端日志判断设备是否上线
3. 问题初步分析
从压测过程看,是设备和路由器循环断开重连的操作,没有连云,也没有起业务。这部分仅仅是调用厂商的wifi 驱动库。
从问题出现的log来看,发生了系统crash,并且出现了典型了内存不足的打印,如下:
(这个Log是我们维测体系中的设备端能力之一,将发生内存出错时候的内存使用情况全部输出,方便定位)
这是由于内存不足,无法从系统内存池中mallo出动态内存,出现这种现象一般有2种原因:
- 某组件在运行中持续分配了较大内存,并且一直还没释放。这种情况可能性不大
- 内存泄漏了,根据压测描述,压测了几天才出现,发生了缓慢泄漏。
初步分析到此,我们先用PC端维测工具对这个设备端log解析一把,看看有什么有价值的信息出现。维测工具的使用参加另一篇文章介绍。这里直接使用
python core_dump.py log xx.elf
维测工具输出了对设备端log的解析,打印出了上图中内存泄漏时的系统内存使用情况的一次统计,如下图:
这里对系统crash时所有动态内存分配情况进行了统计,按照内存分配size 从小到大的顺序进行了排列,每一行都包含着内存malloc出来的地址,谁申请了内存,申请的次数,申请的size大小,申请者在代码中的位置等,一目了然。
我们一下就从图中的最后一行(也就是占据系统内存最多的组件)发现了异常点:此时系统中还存在着982个timer,占据着70K+ 的系统内存,这个肯定是有问题的!
4. 快速问题复现
快速复现问题是bug定位过程中非常重要的的一步。
由于压测过程是每5分钟断开路由器,时间较长,我们尝试重现构造测试用例来复现这一现象。由前面分析可知,这一压测过程只跟厂商wifi 驱动有关。我们找到了2个通用接口来模拟这一过程:
hal_wifi_suspend_station ---- 断开路由器操作,会调用厂商底层的wifi disconnect
netmgr_reconnect_wifi ---- 连接路由器操作,会调用厂商底层的wifi connect
我们构建的测试case代码如下:
while (1) {krhino_mm_overview(NULL); /*重点关注这一行*/aos_msleep(5000);hal_wifi_suspend_station(NULL);netmgr_reconnect_wifi();}
即:在系统上电启动必要的网络初始化后,开始以5s为周期循环压测 suspend 和 reconnect
请注意while循环里的第一行:
krhino_mm_overview(NULL);
这个接口是维测对外API 调试接口之一,会打印堆的相关统计。
维测调试API接口是debug的时候的重要手段之一,加上这些接口出版本,往往可以快速定位问题
详见 https://yuque.antfin-inc.com/aliosthings/mr5i1t/wupvbn#994230b2
这个接口打印如下所示(举例):
========== Heap Info ==========
-----------------------------------------------------------
[HEAP]| TotalSz | FreeSz | UsedSz | MinFreeSz || 0x0004A838 | 0x00047E50 | 0x000029E8 | 0x00047E50 |
-----------------------------------------------------------
[POOL]| PoolSz | FreeSz | UsedSz | BlkSz || 0x00002000 | 0x00001E00 | 0x00000200 | 0x00000020 |
-----------------------------------------------------------
上面统计分成两部分,HEAP与POOL。HEAP是总的统计,POOL是HEAP的一部分。
HEAP与POOL的区别是,当用户使用
aos_malloc(size)
来分配内存的时候,size若小于32字节(由RHINO_CONFIG_MM_BLK_SIZE宏指定,在k_config.h中定义),malloc会在POOL上固定分配32字节内存,反之则在HEAP上分配用户定义size的内存。
HEAP中的内容含义:
- TotalSz,堆的总大小。
- FreeSz,当前堆的空闲大小。
- UsedSz,当前堆的使用量,即UsedSz = TotalSz – FreeSz。
- MinFreeSz,堆空闲历史最小值,即TotalSz – MinFreeSz 便是堆历史使用量峰值。
出异常时,可以利用该信息大致判断堆是否出现空闲内存不足的问题。
回到问题中来,测试case跑起来后,循环输出了每次网络连接后的系统内存使用情况,如图:
5. 问题定位
可见系统系内存经过每次suspend 和 connect后,都会减少,并且减少的大小是固定的。这种情况是发生了稳定的内存泄漏,厂商的WIFI驱动中存在着connect时 malloc的内存,在suspend时没有free的情况,导致了内存池泄漏,早晚会发生内存耗尽。
由最早的log可知,系统crach的时候(也就是内存耗尽的时候),系统中存在着982个timer没有释放,所以我们重点关注timer的使用。由于厂商不提供源码(这也是每次定位问题异常痛苦的原因之一),没法在上层代码处直接加打印调试。在kernel timer处加上打印,结果如下:connect:
suspend:
可以非常明显的看出,connect时timer create了5次,但是suspend的时候,只delete了4次!
问题定位到这里,已经明确了问题根因:timer少释放了一次。反馈给厂商后,迅速解决。
6. 总结
这里结合使用了AliOS Things维测能力的几个方面:
- 在设备端对接了内存异常的处理,作为crash的第一现场打印出来
- PC端维测工具,对设备端的crash log进行解析,降低使用门槛
- 维测API接口的使用,是出版本进行debug的利器。
原文链接
本文为云栖社区原创内容,未经允许不得转载。