一次内存泄露问题排查

背景提要

深度召回服务在浏览器个性化推荐召回阶段占着重要作用。现在基线上有n路深度召回;

深度召回服务流程主要分为两大阶段:用户特征过模型得到用户向量;用户向量调用annoy获取相似资讯;

我们发现当前的深度召回服务存在内存泄漏问题,服务进程占用的内存总是缓慢增长,直至触发阈值告警。

image1.png

问题定位

深度召回服务内部需要加载模型和加载annoy向量文件,初步怀疑内存泄漏与这两个部分有关系。

仔细观察增长图像,发现内存增长的速率和请求量成正比,白天涨的快,晚上涨的慢;所以内存泄漏点与在线处理流程关系更加密切,与模型加载替换部分没有关系。

在线处理流程中,涉及到的内存有Java堆内存和堆外内存。其中堆内存大小我们通过JVM启动参数已经控制,而泄漏的内存大小,远远大于我们设置的堆内存大小。我们通过调整堆内存大小,观察堆内存使用情况和GC回收情况,确定不是堆内存泄漏导致的;


image2.png

深度召回堆外内存的使用主要有两个方面,一个是通过推理SDK调用模型推理,计算用户向量;另外一个是通过调用Native方法封装Annoy接口,查询相似文章。这两个方面都有可能存在内存泄漏。
排查堆外内存泄漏,这里我们使用jdk8提供的一些命令辅助:

1. JVM启动参数,设置对堆外内存的追踪:“ -XX:NativeMemoryTracking=detail ”
2. 服务启动后,设置baseline:
   jcmd 228156 VM.native_memory baseline

经过一段时间后,对比不同块内存的增长情况,找出问题所在;(命令:jcmd 228156 VM.native_memory detail.diff scale=mb)

 $ jcmd 228156 VM.native_memory detail.diff scale=mb
 228156:
 
 Native Memory Tracking:
 
 Total: reserved=17563MB +3831MB, committed=16346MB +3843MB
 
 -                 Java Heap (reserved=10240MB, committed=10240MB)
                             (mmap: reserved=10240MB, committed=10240MB)
  
 -                     Class (reserved=1112MB +2MB, committed=100MB +3MB)
                             (classes #16112 +69)
                             (malloc=2MB #28287 +3993)
                             (mmap: reserved=1110MB +2MB, committed=98MB +3MB)
  
 -                    Thread (reserved=342MB -5MB, committed=342MB -5MB)
                             (thread #340 -5)
                             (stack: reserved=340MB -5MB, committed=340MB -5MB)
                             (malloc=1MB #1726 -25)
  
 -                      Code (reserved=255MB +2MB, committed=71MB +14MB)
                             (malloc=11MB +2MB #16481 +3047)
                             (mmap: reserved=244MB, committed=60MB +12MB)
  
 -                        GC (reserved=546MB +1MB, committed=546MB +1MB)
                             (malloc=134MB +1MB #118554 +5894)
                             (mmap: reserved=412MB, committed=412MB)
  
 -                  Compiler (reserved=1MB, committed=1MB)
                             (malloc=1MB #2189 +56)
  
 -                  Internal (reserved=4793MB +3605MB, committed=4793MB +3605MB)
                             (malloc=4793MB +3605MB #14922900 +14749710)
  
 -                    Symbol (reserved=21MB, committed=21MB)
                             (malloc=16MB #170771 +218)
                             (arena=4MB #1)
  
 -    Native Memory Tracking (reserved=234MB +225MB, committed=234MB +225MB)
                             (malloc=1MB #8349 +2466)
                             (tracking overhead=233MB +225MB)
  
 -                   Unknown (reserved=20MB, committed=0MB)
                             (mmap: reserved=20MB, committed=0MB)
  
 [0x00007f6e8818d654] ElfSymbolTable::ElfSymbolTable(_IO_FILE*, Elf64_Shdr)+0x64
 [0x00007f6e8818ce60] ElfFile::load_tables()+0x1d0
 [0x00007f6e88113975] ElfDecoder::decode(unsigned char*, char*, int, int*, char const*)+0xa5
 [0x00007f6e881131ea] Decoder::decode(unsigned char*, char*, int, int*, char const*)+0xea
                              (malloc=1MB type=Internal +1MB #2 +2)
 
 [0x00007f6e882f3165] jni_GetFloatArrayElements+0x155
 [0x00007f6bb81ec618] Java_com_spotify_annoy_jni_base_AnnoyIndexImpl_cppGetNearestByVector+0x28
 [0x00007f6e6d05418a]
                              (malloc=3621MB type=Internal +3601MB #14830743 +14748680)
 
 [0x00007f6e88083dcd] CodeBlob::set_oop_maps(OopMapSet*) [clone .part.5]+0xed
 [0x00007f6e880841c3] CodeBlob::CodeBlob(char const*, CodeBuffer*, int, int, int, int, OopMapSet*)+0xe3
 [0x00007f6e8850a42d] nmethod::nmethod(Method*, int, int, int, CodeOffsets*, int, DebugInformationRecorder*, Dependencies*, CodeBuffer*, int, OopMapSet*, ExceptionHandlerTable*, ImplicitExceptionTable*, AbstractCompiler*, int)+0x4d
 [0x00007f6e8850adb9] nmethod::new_nmethod(methodHandle, int, int, CodeOffsets*, int, DebugInformationRecorder*, Dependencies*, CodeBuffer*, int, OopMapSet*, ExceptionHandlerTable*, ImplicitExceptionTable*, AbstractCompiler*, int)+0x219
                              (malloc=11MB type=Code +2MB #15348 +2963)
 
 [0x00007f6e8818d3da] ElfStringTable::ElfStringTable(_IO_FILE*, Elf64_Shdr, int)+0x4a
 [0x00007f6e8818cde5] ElfFile::load_tables()+0x155
 [0x00007f6e88113975] ElfDecoder::decode(unsigned char*, char*, int, int*, char const*)+0xa5
 [0x00007f6e881131ea] Decoder::decode(unsigned char*, char*, int, int*, char const*)+0xea
                              (malloc=2MB type=Internal +2MB #3 +3)
 
 [0x00007f6e886fb11d] ReservedSpace::ReservedSpace(unsigned long, unsigned long, bool, char*, unsigned long)+0x1ad
 [0x00007f6e884b125e] VirtualSpaceNode::VirtualSpaceNode(unsigned long)+0x16e
 [0x00007f6e884b6ccb] VirtualSpaceList::create_new_virtual_space(unsigned long) [clone .part.64]+0x3b
 [0x00007f6e884b7443] VirtualSpaceList::get_new_chunk(unsigned long, unsigned long)+0x2f3
                              (mmap: reserved=78MB +2MB, committed=78MB +3MB)
 
 [0x00007f6e8853b8b2] java_start(Thread*)+0x102
                              (mmap: reserved=283MB -5MB, committed=283MB -5MB)
 
 [0x00007f6e886fc1c7] ReservedCodeSpace::ReservedCodeSpace(unsigned long, unsigned long, bool)+0x77
 [0x00007f6e8823a3b1] CodeHeap::reserve(unsigned long, unsigned long, unsigned long)+0xd1
 [0x00007f6e8808b7aa] codeCache_init()+0x7a
 [0x00007f6e88260b2c] init_globals()+0x3c
                              (mmap: reserved=240MB, committed=59MB +12MB)

可以看出经过一整子运行,进程所占内存增长了:3831MB,其中绝大部分内存是Internal区域增长的;

进一步分析,Internal内存增长注意是:


zz.png

这部分内存增长导致的。

Java_com_spotify_annoy_jni_base_AnnoyIndexImpl_cppGetNearestByVector 这个方法是公司自己封装的annoy库接口,使用native的方法提供接口,供Java线上服务调用;传入向量,返回相似资讯的id;对应召回资讯的步骤。

3.png

进一步,进入annoy库内部C++代码,排查问题


4.png

这个方法,是native JNI 方法的具体实现,在方法体的第一行,可以看到,C++代码向env申请了内存;查看资料发现“GetFloatArrayElements”方法是Java提供给native方法,申请数组内存的方法。这个方法对应的有一个对应的释放内存的方法,“ReleaseFloatArrayElements”,而这里,只有申请内存,没有释放内存;导致了内存泄露。

此外,从上述命令行中也能看出一些蛛丝马迹,这里也提到了内存申请的方法。

5.png

加上内存释放的代码,重新编译打包成so文件,上线测试,内存平稳,相比对照组,不再有增加。

6.png
VC20210928-175559.png

再次重新执行堆外内存追踪,相应的指标,不再明显增加


8.png
最后编辑于
©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 220,884评论 6 513
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 94,212评论 3 395
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 167,351评论 0 360
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 59,412评论 1 294
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 68,438评论 6 397
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 52,127评论 1 308
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 40,714评论 3 420
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 39,636评论 0 276
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 46,173评论 1 319
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 38,264评论 3 339
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 40,402评论 1 352
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 36,073评论 5 347
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 41,763评论 3 332
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 32,253评论 0 23
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 33,382评论 1 271
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 48,749评论 3 375
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 45,403评论 2 358

推荐阅读更多精彩内容