TEE 严重内存泄漏事件

一次压测循环播放几个APK里面DRM视频1小时后会发生失败，现象是TA没有load 成功出错log如下

[ 2276.030861] [TEE] D/TC:? 00 tee_ta_init_session_with_context:583 Re-open TA 37eb0e02-c43d-48a8-a129-a95dd3d43929
[ 2276.030864] [TEE] E/TC:1 00 print_oom:200 Memory allocation failed: size 7689 context 0x24b62694
[ 2276.030868] [TEE] E/TC:1 00 TEE load address @ 0x24b00000
[ 2276.030871] [TEE] E/TC:1 00 Call stack:
[ 2276.030874] [TEE] E/TC:1 00  0x24b0a149
[ 2276.030876] [TEE] E/TC:1 00  0x24b3e2f7
[ 2276.030879] [TEE] E/TC:1 00  0x24b3e9c5
[ 2276.030882] [TEE] E/TC:1 00  0x24b1c8cb
[ 2276.030885] [TEE] E/TC:1 00  0x24b10c65
[ 2276.030887] [TEE] E/TC:1 00  0x24b0edc0
[ 2276.030891] [TEE] D/TC:? 00 tee_ta_close_session:490 csess 0x24b78bf8 id 5
[ 2276.030894] [TEE] D/TC:? 00 tee_ta_close_session:509 Destroy session

可以看到， print_oom 函数报错，这个函数调用一般是在malloc和calloc的时候，调用bget发现内存不足无法提供，于是报出这个错误。

最开始见到这个bug的时候我们并不认为很难解决，因为按照经验之谈，基本上是ta stack 或者 heap size 太大，又经过长时间的open close 导致ta ram 存在内存碎片，无法正常加载

以上情况，我们通常有2种解决方案：

禁止ta 频繁 open close，一旦open 成功就不让他关闭，一直占着这块内存.
增加CFG_RSV_SIZE 通过增大bl32 整体内存来扩大 ta ram, 这样可以在内存碎片比较多的情况下还能load ta.

但是事实证明我们想的太简单了，我们跟踪调用栈，发现这个print_oom 使用者仅仅想申请一块4byte的数据就失败了，就算有内存碎片也是影响申请大块内存，除非系统已经完全没有内存了才会导致4byte都无法成功申请。

我们制定了如下测试手段检查内存使用情况：

检查单个APK播放drm视频是否会有泄漏
检查单个APK切台播放drm视频是否有泄漏
一次完整循环两个APK播放drm视频是否会有泄漏

很幸运，我们在检查到第二个的时候，发现livetv 切台，每次切台泄漏内存固定28+32 byte

在这里分享一下 tee 的查内存泄漏的手段：

tee 内置了内存使用记录函数

void mdbg_check(int bufdump)
{       
        gen_mdbg_check(&malloc_ctx, bufdump);
}

我们仅仅需要再合适的时候调用tee执行 mdbg_check(1) ，就会列出来所有的执行过malloc ，calloc， realloc的函数

如下就是一部分dump出来的结果

[57288.043962@2]  [TEE] I/TC:3 00 gen_mdbg_check:639 count: 10, vaddr: 0x32efe1e8, buffer: 32 bytes core/arch/arm/mm/mobj.c:168
[57288.045380@2]  [TEE] I/TC:3 00 gen_mdbg_check:639 count: 11, vaddr: 0x32efe2d0, buffer: 32 bytes core/arch/arm/mm/mobj.c:168
[57288.046809@2]  [TEE] I/TC:3 00 gen_mdbg_check:639 count: 12, vaddr: 0x32efe310, buffer: 28 bytes core/arch/arm/mm/tee_mmu.c:368
[57288.048187@2]  [TEE] I/TC:3 00 gen_mdbg_check:639 count: 13, vaddr: 0x32efe348, buffer: 28 bytes core/arch/arm/mm/tee_mmu.c:257
[57288.049616@2]  [TEE] I/TC:3 00 gen_mdbg_check:639 count: 14, vaddr: 0x32efe3b8, buffer: 32 bytes core/arch/arm/mm/mobj.c:168
[57288.051035@2]  [TEE] I/TC:3 00 gen_mdbg_check:639 count: 15, vaddr: 0x32efe3f8, buffer: 32 bytes core/arch/arm/mm/mobj.c:168
[57288.052409@2]  [TEE] I/TC:3 00 gen_mdbg_check:639 count: 16, vaddr: 0x32efe4a0, buffer: 32 bytes core/arch/arm/mm/mobj.c:168
[57288.053806@2]  [TEE] I/TC:3 00 gen_mdbg_check:639 count: 17, vaddr: 0x32efe4e0, buffer: 32 bytes core/arch/arm/mm/mobj.c:168

我们就是根据count 值的增加来判断出来每次都是泄漏28+32 byte

于是根据每次增加的具体api ，去反推到具体的调用的api ，发现是mobj_phys_alloc api，那么再继续反推发现是tee_tvp_vdec_input_buf_map 函数，于是判断应该是tee_tvp_vdec_input_buf_unmap 调用次数和map的次数不匹配，导致这个 obj没有释放。

同时情形的是，我们在公版上一样复现到了这个bug，这就容易排查了，而且公版有个好处，就是debug手段比较多，还能打印出来每个ta的region信息，
user_mode_ctx_print_mappings 函数是tee提供的可以打印ta的region函数

大概如下

[57301.908865@1]  [TEE] E/TC:? 00 Status of user TA((null) 37eb0e02-c43d-48a8-a129-a95dd3d43929) (0x32f04e40)
[57301.910066@1]  [TEE] E/TC:? 00 Arch: arm
[57301.910586@1]  [TEE] E/TC:? 00 Flags: SINGLE_INSTANCE|MULTI_SESSION|CACHE_MAINTENANCE
[57301.911530@1]  [TEE] E/TC:? 00 Sessions List:
[57301.912071@1]  [TEE] E/TC:? 00 0x32f05080
[57301.912580@1]  [TEE] E/TC:? 00 Stack Ptr: 0x118800, Size: 0x9000, Free: 0x7e20
[57301.913479@1]  [TEE] E/TC:? 00 Memory Used: 0x402000
[57301.914096@1]  [TEE] E/TC:? 00 Memory List:
[57301.914662@1]  [TEE] E/TC:? 00  region  0: va 0x00100000 pa 0x05304000 size 0x002000 flags ---R-X
[57301.915722@1]  [TEE] E/TC:? 00  region  1: va 0x00103000 pa 0x05595000 size 0x002000 flags rw-RW-
[57301.916827@1]  [TEE] E/TC:? 00  region  2: va 0x00105000 pa 0x05597000 size 0x006000 flags r-x---
[57301.918324@1]  [TEE] E/TC:? 00  region  3: va 0x0010b000 pa 0x0559d000 size 0x001000 flags rw-RW-
[57301.919221@1]  [TEE] E/TC:? 00  region  4: va 0x0010c000 pa 0x0559e000 size 0x003000 flags rw-RW-
[57301.920744@1]  [TEE] E/TC:? 00  region  5: va 0x0010f000 pa 0x055a1000 size 0x001000 flags r--R--
[57301.921888@1]  [TEE] E/TC:? 00  region  6: va 0x00110000 pa 0x055a2000 size 0x009000 flags rw-RW-
[57301.922352@1]  [TEE] E/TC:? 00  region  7: va 0x00178000 pa 0x05ab5000 size 0x028000 flags r-xR--
[57301.923508@1]  [TEE] E/TC:? 00  region  8: va 0x001a0000 pa 0x05add000 size 0x3c4000 flags rw-RW-

一般来说一个ta的region 也就是在8个左右，当他去map别的地址的时候就会在region多增加一个region，那也是合理的数量，而且我们版本只能让ta去map一个段

那就是说ta 最多就是9个region。

但是我们发现了出问题的ta如下：在一次完整切换后，region增加几十个，这很不正常，甚至最后没有内存的时候 region达到了800多个。

不过我们松了一口气，这肯定不是我们tee的问题，而是上层忘了释放或者释放失败

[57299.745789@2]  [TEE] E/TC:? 00 Status of user TA((null) acbe4b66-6e40-46dc-a2fe-a576922cf170) (0x32f05560)
[57299.747022@2]  [TEE] E/TC:? 00 Arch: arm
[57299.747479@2]  [TEE] E/TC:? 00 Flags: SINGLE_INSTANCE|MULTI_SESSION|CACHE_MAINTENANCE
[57299.748463@2]  [TEE] E/TC:? 00 Sessions List:
[57299.749416@3]  [TEE] E/TC:? 00 0x32f05708
[57299.749505@3]  [TEE] E/TC:? 00 0x32f04928
[57299.750258@3]  [TEE] E/TC:? 00 Stack Ptr: 0x118800, Size: 0x9000, Free: 0x7b20
[57299.751000@3]  [TEE] E/TC:? 00 Memory Used: 0x4f0000
[57299.751532@3]  [TEE] E/TC:? 00 Memory List:
[57299.752050@3]  [TEE] E/TC:? 00  region  0: va 0x00100000 pa 0x05304000 size 0x002000 flags ---R-X
[57299.753156@3]  [TEE] E/TC:? 00  region  1: va 0x00103000 pa 0x05580000 size 0x002000 flags rw-RW-
[57299.754330@3]  [TEE] E/TC:? 00  region  2: va 0x00105000 pa 0x05582000 size 0x006000 flags r-x---
[57299.755452@3]  [TEE] E/TC:? 00  region  3: va 0x0010b000 pa 0x05588000 size 0x001000 flags rw-RW-
[57299.756472@3]  [TEE] E/TC:? 00  region  4: va 0x0010c000 pa 0x05589000 size 0x003000 flags rw-RW-
[57299.757637@3]  [TEE] E/TC:? 00  region  5: va 0x0010f000 pa 0x055af000 size 0x001000 flags r--R--
[57299.758748@3]  [TEE] E/TC:? 00  region  6: va 0x00110000 pa 0x0558c000 size 0x009000 flags rw-RW-
[57299.759787@3]  [TEE] E/TC:? 00  region  7: va 0x00119000 pa 0x5a399000 size 0x001000 flags rw-RW-
[57299.760938@3]  [TEE] E/TC:? 00  region  8: va 0x0011a000 pa 0x5a31a000 size 0x001000 flags rw-RW-
[57299.761997@3]  [TEE] E/TC:? 00  region  9: va 0x0011b000 pa 0x5a10c000 size 0x001000 flags rw-RW-
[57299.763184@3]  [TEE] E/TC:? 00  region 10: va 0x0011d000 pa 0x5a309000 size 0x001000 flags rw-RW-
[57299.764208@3]  [TEE] E/TC:? 00  region 11: va 0x0011e000 pa 0x5a10a000 size 0x001000 flags rw-RW-
[57299.765363@3]  [TEE] E/TC:? 00  region 12: va 0x0011f000 pa 0x5a0d5000 size 0x004000 flags rw-RW-
[57299.766417@3]  [TEE] E/TC:? 00  region 13: va 0x00123000 pa 0x5a308000 size 0x001000 flags rw-RW-
[57300.798649@3]  [TEE] E/TC:? 00  region 14: va 0x00124000 pa 0x5a31c000 size 0x001000 flags rw-RW-
[57300.799354@3]  [TEE] E/TC:? 00  region 15: va 0x00125000 pa 0x5a0b9000 size 0x001000 flags rw-RW-
[57300.801060@1]  [TEE] E/TC:? 00  region 16: va 0x00126000 pa 0x5a37e000 size 0x001000 flags rw-RW-
[57300.801554@1]  [TEE] E/TC:? 00  region 17: va 0x00129000 pa 0x5a380000 size 0x001000 flags rw-RW-
[57300.802700@1]  [TEE] E/TC:? 00  region 18: va 0x0012a000 pa 0x5a37c000 size 0x001000 flags rw-RW-
[57300.803817@1]  [TEE] E/TC:? 00  region 19: va 0x0012b000 pa 0x5a31b000 size 0x002000 flags rw-RW-
[57300.804868@1]  [TEE] E/TC:? 00  region 20: va 0x0012d000 pa 0x5a37f000 size 0x002000 flags rw-RW-
[57300.805973@1]  [TEE] E/TC:? 00  region 21: va 0x00132000 pa 0x5a2ee000 size 0x002000 flags rw-RW-

首先我们就把问题转出去，说明原因，让别的teams去排查，结果别的teams 好久找不到原因，甚至努力想把正常的情况的log截取出来，甩锅给我们，这个时候我们只能拼命反击

但是我们仅仅从region增加来看，有可能会被人反咬一口说我们unmap函数失败了，确实我们也奇怪这个事情，为何region会不断地增加。

我们在unmap加上了log，发现有出错提前返回了，但是原因让我们很奇怪，为何传入的pa 和 size 再已经map的list找不到呢，因为我们打印了所有的list 列表，没有发现能够和当前匹配的region

开始我们怀疑是不是上层传错了，结果我们在log里面向上翻找，发现map 函数确实返回成功，但是在下一次调用unmap 的时候，已经map的列表神奇的不见了。

确实这让我们瞬间以为bug又回到我们这边来了，压力巨大，然后突然leader一句话，正常的DRM调用流程应该是 open_channel -> map address -> unmap address -> close_channel .

会不会是上层调用顺序错了，open_channel -> map address ->close_channel -> unmap address . 这样就会导致channel丢失导致找不到了已经map 的region。从而导致unmap失败。

我们可以在open_channel 和 close_channel 加上log，看看是不是close_channel 顺序在unmap之前。

这个分析思路瞬间给我们一个巨大的希望，最后的实验结果果然证实了leader的猜测，由此真相大白。我们找出了铁证，断定是上层api 因为是多进程不能保证顺序调用导致我们tee内存泄露。

当然最后更狗血的是，其实后续的版本已经解决了这个问题，但是项目上面的人明知道ta更新过但是却没有合入，导致我们辛苦了这么久。更辛苦了QA同事连续抓了100多份log。

当然我们自一开始就预感到不是我们的问题导致的，因为tee 本身已经存在多年，经过无数的压力测试都不会有问题，只是我们苦于没有找到证据。

不过也通过了这个bug让我对tee ta的map机制有了更深的理解，为了分析这个bug，我们增强了debug的功能，这个对以后很有帮助。

注：世界上的bug，2%是自己引起的，98%的是别人引起的。

完结，撒花

posted @ 2024-05-29 14:14 颜小雀阅读(35) 评论(0) 编辑收藏举报

刷新页面返回顶部

CoverSky

让优秀成为一种习惯

TEE 严重内存泄漏事件

公告