AliOS Things 维测典型案例分析 —— 内存泄漏

维测典型案例分析1 —— 内存泄漏

在系统运行的过程中,内存泄漏是较为常见但是很难复现的现象,一般的内存泄漏点都是比较隐蔽的,每次几十个字节的泄漏,往往需要压测很久才能复现问题。本节案例分析,我们从一个已经压测出来的问题出发,通过维测工具的使用,来看一次内存泄漏的分析。

1. 问题现象:

xx平台压测反复断AP电源第488次连接通道时出现dump机现象
**

2. 重现步骤: 

  1. 设备认证连接,并保持在线状态(维持心跳)
    b. .待连接稳定后,断开网络(断AP电源)
    c  .5分钟后恢复AP电源
    d .查看设备端日志判断设备是否上线

3. 问题初步分析

从压测过程看,是设备和路由器循环断开重连的操作,没有连云,也没有起业务。这部分仅仅是调用厂商的wifi 驱动库。
从问题出现的log来看,发生了系统crash,并且出现了典型了内存不足的打印,如下:
(这个Log是我们维测体系中的设备端能力之一,将发生内存出错时候的内存使用情况全部输出,方便定位)

AliOS Things 维测典型案例分析 —— 内存泄漏

这是由于内存不足,无法从系统内存池中mallo出动态内存,出现这种现象一般有2种原因:

  1. 某组件在运行中持续分配了较大内存,并且一直还没释放。这种情况可能性不大
  2. 内存泄漏了,根据压测描述,压测了几天才出现,发生了缓慢泄漏。

初步分析到此,我们先用PC端维测工具对这个设备端log解析一把,看看有什么有价值的信息出现。维测工具的使用参加另一篇文章介绍。这里直接使用

python  core_dump.py  log   xx.elf

维测工具输出了对设备端log的解析,打印出了上图中内存泄漏时的系统内存使用情况的一次统计,如下图:

AliOS Things 维测典型案例分析 —— 内存泄漏

这里对系统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://yq.aliyun.com/articles/693108?spm=a2c4e.11155435.0.0.6e4846abHIpnIX

这个接口打印如下所示(举例):

========== 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跑起来后,循环输出了每次网络连接后的系统内存使用情况,如图:

AliOS Things 维测典型案例分析 —— 内存泄漏
AliOS Things 维测典型案例分析 —— 内存泄漏
AliOS Things 维测典型案例分析 —— 内存泄漏

....

5. 问题定位

可见系统系内存经过每次suspend 和 connect后,都会减少,并且减少的大小是固定的。这种情况是发生了稳定的内存泄漏,厂商的WIFI驱动中存在着connect时 malloc的内存,在suspend时没有free的情况,导致了内存池泄漏,早晚会发生内存耗尽。

由最早的log可知,系统crach的时候(也就是内存耗尽的时候),系统中存在着982个timer没有释放,所以我们重点关注timer的使用。由于厂商不提供源码(这也是每次定位问题异常痛苦的原因之一),没法在上层代码处直接加打印调试。在kernel timer处加上打印,结果如下:connect:

AliOS Things 维测典型案例分析 —— 内存泄漏

suspend:

AliOS Things 维测典型案例分析 —— 内存泄漏

可以非常明显的看出,connect时timer create了5次,但是suspend的时候,只delete了4次!

问题定位到这里,已经明确了问题根因:timer少释放了一次。反馈给厂商后,迅速解决。

6. 总结

这里结合使用了AliOS Things维测能力的几个方面:

  1. 在设备端对接了内存异常的处理,作为crash的第一现场打印出来
  2. PC端维测工具,对设备端的crash log进行解析,降低使用门槛
  3. 维测API接口的使用,是出版本进行debug的利器。
上一篇:驱动程序测试问题


下一篇:BBED系列之编译安装(1)