现象

在对catboost模型(大小1g)做切换测试的时候,出现Java进程异常退出的情况。

JVM监控:
内存稳定,且没有出现FullGC,没有发生oom

catboost1
catboost1

MDC监控:
cpu使用率接近70%,内存使用率接近100%

catboost2
catboost2

怀疑使用了堆外内存,导致容器内存打满。
排查加载catboost模型代码,发现catboost提供sdk中loadModel方法调用了JNI,推测在native方法中申请了内存。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
public static CatBoostModel loadModel(InputStream in) throws CatBoostError, IOException {
long[] handles = new long[1];
byte[] copyBuffer = new byte[4096];
ByteArrayOutputStream out = new ByteArrayOutputStream();

int bytesRead;
while((bytesRead = in.read(copyBuffer)) != -1) {
out.write(copyBuffer, 0, bytesRead);
}

implLibrary.catBoostLoadModelFromArray(out.toByteArray(), handles);
return new CatBoostModel(handles[0]);
}

final void catBoostLoadModelFromArray(@NotNull byte[] data, @NotNull long[] handle) throws CatBoostError {
CatBoostJNIImpl.checkCall(CatBoostJNIImpl.catBoostLoadModelFromArray(data, handle));
}

调整堆外内存大小调整机器配置

8c12g -> 8c16g
JVM堆内存参数配置不变(即堆外内存增大4g)
-Xms9632M
-Xmx9632M

JVM监控:

catboost3
catboost3

MDC监控:

catboost4
catboost4

模型切换次数由原来的1、2次,提升到7次才出现Java进程异常退出的情况,基本可以确定堆外内存搞的鬼了。

主动释放模型资源

在CatBoostModel对象被回收的时候,finalize方法中会自己调用dispose方法,释放资源

1
2
3
4
5
6
7
8
9
10
11
12
13
14
protected void finalize() throws Throwable {
try {
this.dispose();
} finally {
super.finalize();
}
}

private synchronized void dispose() throws CatBoostError {
if (this.handle != 0L) {
implLibrary.catBoostFreeModel(this.handle);
this.handle = 0L;
}
}

不过我们还是在加载新模型后,尝试主动调用释放旧模型,即增加oldModel.close()代码

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
public void convert(String modelKey, InputStream inputStream) {
try {
CatBoostModel catBoostModel = CatBoostModel.loadModel(inputStream);
CatBoostModel oldModel = modelMap.get(modelKey);
modelMap.put(modelKey, catBoostModel);
if(Objects.nonNull(oldModel)){
log.info("释放catboost资源");
oldModel.close();
}
log.info("CatBoost init model :{} success!", modelKey);
} catch (Exception e) {
log.error("CatBoost init model :{} fail! exception :", modelKey, e);
throw new BusinessException("CatBoost模型加载失败");
}
}

public void close() throws CatBoostError {
this.dispose();
}

JVM监控

catboost5
catboost5

MDC监控

catboost6
catboost6

还是一样存在内存泄漏的问题。

NMT定位内存区域

可以展示堆内内存、Code区域或者使用unsafe.allocateMemory和DirectByteBuffer申请的堆外内存
JVM启动参数增加:-XX:NativeMemoryTracking=detail

查看命令:jcmd pid VM.native_memory detail

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
[admin@host-11-68-72-16 ~]$ jcmd 217 VM.native_memory detail
217:

Native Memory Tracking:

Total: reserved=11242880KB, committed=9746476KB
- Java Heap (reserved=8839168KB, committed=8839168KB)
(mmap: reserved=8839168KB, committed=8839168KB)

- Class (reserved=1176337KB, committed=143121KB)
(classes #23536)
(malloc=2833KB #43400)
(mmap: reserved=1173504KB, committed=140288KB)

- Thread (reserved=437769KB, committed=437769KB)
(thread #425)
(stack: reserved=435872KB, committed=435872KB)
(malloc=1400KB #2133)
(arena=498KB #849)

- Code (reserved=548090KB, committed=84902KB)
(malloc=15610KB #19166)
(mmap: reserved=532480KB, committed=69292KB)

- GC (reserved=62053KB, committed=62053KB)
(malloc=36149KB #493)
(mmap: reserved=25904KB, committed=25904KB)

- Compiler (reserved=1664KB, committed=1664KB)
(malloc=1533KB #2248)
(arena=131KB #3)

- Internal (reserved=38055KB, committed=38055KB)
(malloc=38023KB #89946)
(mmap: reserved=32KB, committed=32KB)

- Symbol (reserved=29710KB, committed=29710KB)
(malloc=27017KB #264972)
(arena=2693KB #1)

- Native Memory Tracking (reserved=6936KB, committed=6936KB)
(malloc=261KB #3929)
(tracking overhead=6675KB)

- Arena Chunk (reserved=190KB, committed=190KB)
(malloc=190KB)

- Unknown (reserved=102908KB, committed=102908KB)
(mmap: reserved=102908KB, committed=102908KB)

可以发现Native Memory Tracking中,只分配了6m的空间,我们更加相信是Native Code(C代码)申请的堆外内存导致的问题。

系统层面的工具定位堆外内存

pmap

显示进程的地址空间的相关信息

切换前

catboost7
catboost7

切换后

catboost8
catboost8

对比切换前后进程分配的内存空间,可以看到每次loadModel会增加700m的内存,而且旧模型申请的空间也没有释放。

strace

我们可以用它来监控用户空间进程和内核的交互。如对应用程序的系统调用、信号传递与进程状态变更等进行跟踪与分析,以达到解决问题的目的。

catboost9
catboost9

通过strace监控,切换模型过程中申请内存的命令,可以看到申请了差不多700m内存,可以与上面pmap对应上。

/proc/pid/smaps

我们通过pmap已经发现了可疑的内存区间,在/proc/pid/smaps可以找到分配内存块的起始地址和结束地址

catboost10
catboost10

gdb

通过gdb对可疑内存区间进行dump

catboost11
catboost11

编码可视化其内容,进行分析,可以看到是模型相关的

catboost12
catboost12
catboost13
catboost13
catboost14
catboost14

github相似issue

https://github.com/catboost/catboost/issues/1979