CDH yarn集群GC告警内存泄漏, 结合源码排查分析

问题

我的简书主页

GC超阈值

在之前的5分钟内，垃圾收集花费的平均时间为每分钟36.4秒。临界阈值60%
NODE_MANAGER_GC_DURATION has become bad: Avgrage time spent in garbage collection was 36.4 seconds(s) per minute over the prevoies 5 minute(s). Critical threshold: 60%

The healthy test result for YARN_RESOURCEMANAGERS_HEALTH has become concerning

排查

查看NodeManage日志

日志中每隔几秒就会发生gc且老年代回收( CMS )的时间比较久

官网问题查询
关键字: NODE_MANAGER_GC_DURATION

从社区的答复来看, 大多数的建议是调整NodeManager的堆大小和监控值, 但是并没说到问题的原因, 接着继续排查吧

点击图标库, 查看进程使用情况

发现最近时间段堆内存一直接近最大值, 且每次回收掉的内存非常少; 查看7天数据gc和堆内存的占用处于持续上升的状态, 初步定位是内存泄漏


查看30天发现29号的时候内存突降, 之后又开始持续上升至峰值徘徊, 其实29号的前几天也是不正常的

查看日志和进程信息, 29号的9点确有异常, 触发了yarn节点重启机制 , 发生内存溢出生成了dump文件

内存泄漏

yarn默认没有开启gc的打印, 需要自己在cdh进行配置, 搜索JAVA_GC_ARGS,在对应位置填上-Xloggc:gc.log -XX:+PrintGCTimeStamps -XX:+PrintGCDetails, 配置生效需要重启该节点( 可选项 )

1. 查看gc详情

jstat -gcutil 25678 3000 100
从图中来看明显是有问题的;YGC和FGC代表新生代和老年代gc的次数, 每隔几秒次数就会递增, 且老年代的空间一直没有回收掉

2. 分析在堆中对象的数量和占用字节

执行su -s /bin/bash -c ''/usr/java/jdkl.8.0_202-amd64/bin/jmap -histo:live 20886" yarn | more

• 如果提示jdk版本的报错, jmap前加上运行参数的全路径;
• 如果报Unable to open socket file: target process not responding or HotSport VM not loaded, 则切换到进程的用户;
• 如果切换时报This account is currently not available, 则可用root用户su -s指定用户去执行命令

从命令结果来看, 占用最多的是字符串和byte数组, 但是不知道里面的内容是什么, 所以需要mat去分析堆中对象的详情

3. 将dump文件导入到mat中

su -s /bin/bash -c '/usr/java/jdkl.8.0_202-amd64/bin/jmap -dump:format=b,file=/tmp/nnm.dump 20886' yarn, 如果已经发生了内存溢出生成了dump文件, 则不需要执行这一步

点击Histogram->右键对象List objects->with outgoing references

发现缓存大量spark job的shuffle索引文件路径, 但实际上appcache下并没有文件, 所以推断这个是shuffle的临时文件, 查阅源码证明推断正确, ExternalShuffleService的executorRemoved()和applicationRemoved()方法; 为什么这类文件会这么多, 在哪个地方引用的呢?

解决思路

1. 去spark的web界面去查看该job执行时,是否发生大量的shuffle操作, 如果是可尝试去调整代码上或job运行参数, 以来减少数据的混洗

通过分析, 该job( application_1588204334324_0246 )其实早已经执行完了, 却还是一直触发gc的告警, hdfs上本地的shuffle文件也不存在了, 进一步推断是yarn缓存管理的问题

2. 寻找spark yarn中控制shuffle缓存的配置并修改
   ###排查spark源码
   根据调用堆栈搜索shuffleIndexCache,ShuffleIndexInformation,CacheBuilder, 在源码中找到关键类ExternalShuffleBlockResolver
   
   

 String indexCacheSize = conf.get("spark.shuffle.service.index.cache.size", "100m");
    CacheLoader<File, ShuffleIndexInformation> indexCacheLoader =
        new CacheLoader<File, ShuffleIndexInformation>() {
          public ShuffleIndexInformation load(File file) throws IOException {
            return new ShuffleIndexInformation(file);
          }
        };
    shuffleIndexCache = CacheBuilder.newBuilder()
      .maximumWeight(JavaUtils.byteStringAsBytes(indexCacheSize))
      .weigher(new Weigher<File, ShuffleIndexInformation>() {
        public int weigh(File file, ShuffleIndexInformation indexInfo) {
          return indexInfo.getSize();
        }
      }).build(indexCacheLoader);

查看源码得知缓存的统计是根据索引文件大小叠加的, 即ShuffleIndexInformation的size相加; 根据上面的缓存键值分布图做空间推测

• ShuffleIndexInformation的size平均为152字节, 则100mb可存放的对象数为
  689852 个 = 100(mb) * 1024 * 1024 / 152
• key是File类型的, 每个对象占用920字节, 则缓存中key占用的空间为
  605 mb = 689852 * 920 / 1024 / 1024

结合mat的总览图, 缓存对象占用817mb, 那么和推断的值705mb = 605+100基本是吻合的; spark管理这一块的缓存只累加了value的文件容量, 而忽略了key占用的内存, 个人感觉这一块会有隐患, 如果ShuffleIndexInformation的size值很小, 那么key的数量会非常的多, 如果内存配置不够大那么发生内存溢出的概率比较大

更改源码

在github上查看这个类的提交记录没有找到相关的修复, 提下issue或pr看官方有什么答复; 有个要注意的小点, 源码中缓存使用的是LocalCache.LocalLoadingCache, 调用get方法的时候会同时load进缓存中, 且ExternalShuffleBlockResolver中有提供清理过期文件的操作

• 方案1: CacheLoader构造时重写weigher()方法中加入key的容量统计
• 方案2: 执行清理操作时同时清理缓存
  30672 PR

查看hadoop的源码

堆中存在着大量路径信息, 所以可以尝试去搜索关键字如 appcache, 结合调用堆栈可找到相关类ResourceLocalizationService,YarnConfiguration,LocalCacheCleaner,查看源码得知yarn提供资源缓存的清理, 默认值10分钟执行一次,清理的阈值为10G

解决

调整堆内存, 调整shuffle index大小或更改源码( 不推荐 )

参考

Apche贡献指南
Hadoop源码
Spark源码
Yarn ResourceManager内存泄漏
大数据运维日常-YARN 运维、巡检、监控、调优、排障
CDH文档