一次压测循环播放几个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%的是别人引起的。
完结,撒花
标签:泄漏,00,region,TEE,pa,内存,TC,size From: https://www.cnblogs.com/coversky/p/18220191