Timelineserver进程挂掉原因排查

? ? 6月13号,凌晨 00:18分Zookeeper进程挂掉,查看zookeeper进程在挂掉时输出的JVM相关的错误文件hs_err_pid5829.log,可以看到zookeeper进程是因为内存溢出挂掉的,

????理论上,zookeeper里面没存什么东西,不应该会因为内存溢出挂掉,

????仔细查看该文件,在末尾,看到了当时服务器的内存的状态,发现该台物理内存为256G的服务器,在zookeeper挂掉的时候只有1.7G左右的空闲内存,感到很神奇,因为在分配该台服务器上的内存的时候是预留了50G左右,不应该只剩下那么少的内存

? ??通过查看谛听监控发现,该台服务器内存不断的升高,直到物理内存全部消耗完,然后内存直接降下来,然后又慢慢的上高到最大,如此重复,

????猜测该台服务器上有某个进程发生了内存泄露,消耗了服务器的所有内存,导致自己和别的进程(比如zookeeper进程和之前挂掉的JN进程)因为申请不到配置的内存资源,最终因为内存不足,导致报内存溢出挂掉,实际上不是真正的内存溢出,通过使用top命令,发现,yarn用户有一个进程,使用内存达到80%多,也就是将近190G的内存都被该进程占用,通过ps命令查找到这个进程ID最终定位该进程为timelineserver进程,但是很好奇的是,这个进程,我们分配了100G的堆内存+10G的堆外内存,理论上最多只会消耗110G左右的内存,但是实际上却消耗了200G内存,另外的80G内存消耗在哪了?(至于服务器内存的波动是因为crontab中有一个定时检测timelineserver的存活状态的脚本,会主动的将挂掉的timelineserver启动)

????最开始猜测是堆外内存泄露导致的,但是如何排查?

????通过在启动参数中加上 -XX:NativeMemoryTracking=detail 来追踪JVM堆外内存(该参数会带来5%~10%的性能消耗),通过命令

jcmd 22215 VM.native_memory summary scale=GB 来查看JVM的内存消耗(包括NMT内存),

????而使用linux的命令 ps -p 22215 -o rss,vsz是查看进程在linux中真实消耗的内存大小,如下图:

????通过图中发现,即便是追踪JVM的堆外内存,发现能够追踪到的内存消耗只有105G,这符合设置的110G内存,说明该进程没有发生堆内存泄露,也没有发生directory内存泄露,那么另外将近80G内存哪去了?

????通过对JVM内存分配模型发现,还有一部分JNI调用的内存,是不在JVM统计的范围之内的,因为JNI调用的是C或C++代码,C或C++代码内部自己的内存申请和释放是不受JVM管控的,不在JVM的统计范围之内,而timelineserver存储数据是使用leveldb,leveldb是使用C++ 语言实现的,因此现在确定是 JNI导致的堆外内存泄露,不会C++ 语言,更不会检测C++ 语言的内存泄露检测,如何排查?请教C++ 语言大牛,得到的结果,自己慢慢调试C++ 程序,找没有释放的内存的地方,找JVM大牛,得到的结果是看程序实现的地方,看能不能找到可疑的地方。

????一脸蒙圈,无从下手,JNI堆外内存泄露很难排查,最终选择查看最近修改的代码,看能不能找到什么蛛丝马迹,最终发现了一点问题,看如下的代码:

public TimelineEvents getEntityTimelines(String entityType,

??????SortedSet<String> entityIds, Long limit, Long windowStart,

??????Long windowEnd, Set<String> eventType) throws IOException {

????TimelineEvents events = new TimelineEvents();

????if (entityIds == null || entityIds.isEmpty()) {

??????return events;

????}

????// create a lexicographically-ordered map from start time to entities

????Map<byte[], List<EntityIdentifier>> startTimeMap =

????????new TreeMap<byte[], List<EntityIdentifier>>(

????????new Comparator<byte[]>() {

??????????@Override

??????????public int compare(byte[] o1, byte[] o2) {

????????????return WritableComparator.compareBytes(o1, 0, o1.length, o2, 0,

????????????????o2.length);

??????????}

????????});

????DBIterator iterator = null;

????try {

??????// look up start times for the specified entities

??????// skip entities with no start time

??????for (String entityId : entityIds) {

????????byte[] startTime = getStartTime(entityId, entityType);

????????if (startTime != null) {

??????????List<EntityIdentifier> entities = startTimeMap.get(startTime);

??????????if (entities == null) {

????????????entities = new ArrayList<EntityIdentifier>();

????????????startTimeMap.put(startTime, entities);

??????????}

??????????entities.add(new EntityIdentifier(entityId, entityType));

????????}

??????}

??????for (Entry<byte[], List<EntityIdentifier>> entry : startTimeMap

??????????.entrySet()) {

????????// look up the events matching the given parameters (limit,

????????// start time, end time, event types) for entities whose start times

????????// were found and add the entities to the return list

????????byte[] revStartTime = entry.getKey();

????????for (EntityIdentifier entityIdentifier : entry.getValue()) {

??????????EventsOfOneEntity entity = new EventsOfOneEntity();

??????????entity.setEntityId(entityIdentifier.getId());

??????????entity.setEntityType(entityType);

??????????events.addEvent(entity);

??????????KeyBuilder kb = KeyBuilder.newInstance().add(entityType)

??????????????.add(revStartTime).add(entityIdentifier.getId())

??????????????.add(EVENTS_COLUMN);

??????????byte[] prefix = kb.getBytesForLookup();

??????????if (windowEnd == null) {

????????????windowEnd = Long.MAX_VALUE;

??????????}

??????????byte[] revts = writeReverseOrderedLong(windowEnd);

??????????kb.add(revts);

??????????byte[] first = kb.getBytesForLookup();

??????????byte[] last = null;

??????????if (windowStart != null) {

????????????last = KeyBuilder.newInstance().add(prefix)

????????????????.add(writeReverseOrderedLong(windowStart)).getBytesForLookup();

??????????}

??????????if (limit == null) {

????????????limit = DEFAULT_LIMIT;

??????????}

??????????DB db = entitydb.getDBForStartTime(readReverseOrderedLong(

??????????????revStartTime, 0));

??????????if (db == null) {

????????????continue;

??????????}

??????????iterator = db.iterator();

??????????for (iterator.seek(first); entity.getEvents().size() < limit

??????????????&& iterator.hasNext(); iterator.next()) {

????????????byte[] key = iterator.peekNext().getKey();

????????????if (!prefixMatches(prefix, prefix.length, key)

????????????????|| (last != null && WritableComparator.compareBytes(key, 0,

????????????????????key.length, last, 0, last.length) > 0)) {

??????????????break;

????????????}

????????????TimelineEvent event = getEntityEvent(eventType, key, prefix.length,

????????????????iterator.peekNext().getValue());

????????????if (event != null) {

??????????????entity.addEvent(event);

????????????}

??????????}

????????}

??????}

????} finally {

??????IOUtils.cleanup(LOG, iterator);

????}

????return events;

??}


????主要看加粗的部分,看着iterator这个变量在finally中通过调用IOUtils.cleanup(LOG, iterator); 好像是被关闭了,但实际上finally中关闭的只是最后一个iterator指向的DBIterator对象,因为里面还有一层循环,不断的给iterator赋值别的变量,但是这些遍历途中的DBIterator对象却没有被调用close()方法,因此将上面的代码改成如下的方式:

??public TimelineEvents getEntityTimelines(String entityType,

??????SortedSet<String> entityIds, Long limit, Long windowStart,

??????Long windowEnd, Set<String> eventType) throws IOException {

????TimelineEvents events = new TimelineEvents();

????if (entityIds == null || entityIds.isEmpty()) {

??????return events;

????}

????// create a lexicographically-ordered map from start time to entities

????Map<byte[], List<EntityIdentifier>> startTimeMap =

????????new TreeMap<byte[], List<EntityIdentifier>>(

????????new Comparator<byte[]>() {

??????????@Override

??????????public int compare(byte[] o1, byte[] o2) {

????????????return WritableComparator.compareBytes(o1, 0, o1.length, o2, 0,

????????????????o2.length);

??????????}

????????});


??????// look up start times for the specified entities

??????// skip entities with no start time

????for (String entityId : entityIds) {

??????byte[] startTime = getStartTime(entityId, entityType);

??????if (startTime != null) {

????????List<EntityIdentifier> entities = startTimeMap.get(startTime);

????????if (entities == null) {

??????????entities = new ArrayList<EntityIdentifier>();

??????????startTimeMap.put(startTime, entities);

????????}

????????entities.add(new EntityIdentifier(entityId, entityType));

??????}

????}

????for (Entry<byte[], List<EntityIdentifier>> entry : startTimeMap

??????????.entrySet()) {

??????// look up the events matching the given parameters (limit,

??????// start time, end time, event types) for entities whose start times

??????// were found and add the entities to the return list

??????byte[] revStartTime = entry.getKey();

??????for (EntityIdentifier entityIdentifier : entry.getValue()) {

????????EventsOfOneEntity entity = new EventsOfOneEntity();

????????entity.setEntityId(entityIdentifier.getId());

????????entity.setEntityType(entityType);

????????events.addEvent(entity);

????????KeyBuilder kb = KeyBuilder.newInstance().add(entityType)

????????????.add(revStartTime).add(entityIdentifier.getId())

????????????.add(EVENTS_COLUMN);

????????byte[] prefix = kb.getBytesForLookup();

????????if (windowEnd == null) {

??????????windowEnd = Long.MAX_VALUE;

????????}

????????byte[] revts = writeReverseOrderedLong(windowEnd);

????????kb.add(revts);

????????byte[] first = kb.getBytesForLookup();

????????byte[] last = null;

????????if (windowStart != null) {

??????????last = KeyBuilder.newInstance().add(prefix)

??????????????.add(writeReverseOrderedLong(windowStart)).getBytesForLookup();

????????}

????????if (limit == null) {

??????????limit = DEFAULT_LIMIT;

????????}

????????DB db = entitydb.getDBForStartTime(readReverseOrderedLong(

????????????revStartTime, 0));

????????if (db == null) {

??????????continue;

????????}

????????try (DBIterator iterator = db.iterator()) {

??????????for (iterator.seek(first); entity.getEvents().size() < limit

??????????????&& iterator.hasNext(); iterator.next()) {

????????????byte[] key = iterator.peekNext().getKey();

????????????if (!prefixMatches(prefix, prefix.length, key)

????????????????|| (last != null && WritableComparator.compareBytes(key, 0,

????????????????key.length, last, 0, last.length) > 0)) {

??????????????break;

????????????}

????????????TimelineEvent event = getEntityEvent(eventType, key, prefix.length,

????????????????iterator.peekNext().getValue());

????????????if (event != null) {

??????????????entity.addEvent(event);

????????????}

??????????}

????????}

??????}

????}

????return events;

??}

????同样主要看加粗的部分,使用jdk8的写法,在最内部的每次循环结束之后,JVM都会主动调用iterator.close()方法(jdk8的写法,无需显示指明调用close()方法)将iterator引用的对象的close()方法执行关闭的操作,现在问题来了,为啥这个地方执行close()方法,就不会发生内存泄露了,

????通过分析DBIterator对象的close()方法

????public void close() {

????????iterator.delete();

????}

????里面调用的delete()方法如下:

????public void delete() {

????????assertAllocated();

????????IteratorJNI.delete(self);

????????self = 0;

????}

IteratorJNI.delete()方法如下:

????????@JniMethod(flags={CPP_DELETE})

????????public static final native void delete(long self);

????可以看到,最终通过jni调用了底层的C++的delete()方法,做释放的操作,这也就是说由于没有主动调用释放操作,导致底层C++的代码中申请的内存不能够释放,最终导致JNI内存泄露。

????通过修改代码后,观察几个小时,发现不在发生内存泄露现象了,至此问题解决。

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

推荐阅读更多精彩内容