问题
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()方法; 为什么这类文件会这么多, 在哪个地方引用的呢?
解决思路
- 去spark的web界面去查看该job执行时,是否发生大量的shuffle操作, 如果是可尝试去调整代码上或job运行参数, 以来减少数据的混洗
通过分析, 该job( application_1588204334324_0246 )其实早已经执行完了, 却还是一直触发gc的告警, hdfs上本地的shuffle文件也不存在了, 进一步推断是yarn缓存管理的问题
- 寻找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: 执行清理操作时同时清理缓存
Spark Issues
通过查看 Spark官方问题列表, 看到了类似的问题, 不过我的pr没被采纳已经关闭了
SPARK-33206
我的PR-SPARK-33710
查看hadoop的源码
堆中存在着大量路径信息, 所以可以尝试去搜索关键字如 appcache, 结合调用堆栈可找到相关类ResourceLocalizationService,YarnConfiguration,LocalCacheCleaner,查看源码得知yarn提供资源缓存的清理, 默认值10分钟执行一次,清理的阈值为10G
解决
- 调整Yarn NodeManager堆内存, 默认的1GB数值太小; 在有多个job运行时, executor的数量也会增加, 每个executor占用100m的index缓存, 很快就到达阈值
- 调整shuffle index大小或更改源码( 不推荐 );
参考
Apche贡献指南
Hadoop源码
Spark源码
Yarn ResourceManager内存泄漏
大数据运维日常-YARN 运维、巡检、监控、调优、排障
CDH文档
