从2021年10月开始服务于急速构建的Jenkins服务器基本每周都会由于以下原因挂一次。
给业务造成较大的影响。
上图反应出来的现象有两个:
1. 内存使用96%, 就快耗尽。
2. 很多threads 堆积,没法处理。
3. Jenkins GUI上的直接现象就是卡顿,非常卡顿,只有人工重启一条路。
分析
抓取HPROF
因为JVM启动的时候配置了dump Heap, 运维方提供了两次HPROF 快照供分析。
分析HPROF
使用MAT
如下,由于快照达到30G, 传统的MAT解析时报错。
使用JProfile
分析第一个快照
- 使用JProfile打开快照时,第一次会比较耗时, 这个30G快照大概20分钟左右,但第一次打开结束后,他的内部数据库已建立,后面打开就很快了,打开过程就不图片展示了,很简单。
- 左边Panel展示当前是在 “堆遍历器”, 中间view是 "类", 右边点击大小,以大小排序。
可以从下图看到结论:
a. byte []类有16万个实例对象,总大小15G左右。
b. char []类有200万个实例对象,总大小3G左右。 - 开始分析byte[]类的对象,双击后,弹出的对话,引用里面默认是outgoing reference, 这里改成incoming references
- 上步会生成一个对象集,同样,如果排序是乱序的,按大小排序
- 分析每一个对象
- 分析了25个泄露,所有对象都是由于访问同一次个人构建任务850772这次构建的Log时泄露的
- 我们原本就怀疑跟开发访问Jenkins log接口有关,但没有想到的是,其实泄露的是访问同一个build,而且来自同一个IP(同一个人), 换句话说就是99.9%的人访问log接口是没有问题的。
- 联系了对应的同学,他告诉说当时比较慢,没有反应他就连续点击了很多次,调用该REST API多次。
- 为什么就是这位同学点击时比较慢,诱导他连续点击很多次,最后把内存用完呢?
我猜测是因为他这次的Log大小比较大,从分配的对象可以看到,一次分配了598M, 这种大文件导致了反应慢,越没有反应,他越是着急,连接触发了多达25次,最后搞死了Jenkins. 我看了大多数构建的build阶段的Log最多150M, 所以接口能很快响应,是没有问题的。
分析第二个快照
- 事实是第二个快照就没有第一个快照那么好分析了。
可以从下图看到结论:
a. char []类有560万个实例对象,总大小10G左右。
b. byte []类有13万个实例对象,总大小9G左右。 - 打开char[]类的对象,可以看到对象都很小(就没有上面那次快照时一个598M那么幸运了),而对象很多,这怎么分析呢?
- 这里按如下方法对这几百万个对象进行分类,按引用数
- 结果如下:
- 分析里面的第一个对象
- 下图是展开的更详细的堆栈, 得到两个信息:
a. 跟Personal build Release job有关系
b. 里面有一句LoadStep, 可能跟Jeninsfile的DSL 的一个step- "Load" 有关 - 查看该job的实现,里面真的有load step的使用, 如下:
而且该对象的内容(如下),就跟上图中load的Jenkinsfile文件里的内容相同。 - 难道Load step有坑,上网查,真查到了
https://issues.jenkins.io/browse/JENKINS-32338?jql=text%20~%20%22leak%22 - 看一下,我们使用的Jenkins 插件的版本是否包含这个问题的fix, fix 是:
里面搜索 Merged:
从上图可以看到最老的包含该fix的版本是2.23 - 看一下我们的Jenins 版本, 我们使用的是2.2版本,workflow-cps-plugin在Jenkins里面的插件的名字就叫"Groovy",与这个fix完美错过, 我们用的版本这个问题还存在,没有fix:
结论和下一步
结论:
1. Jenkins 的 blueocean提供的看Log的接口当log大小非常大的时候,的确有问题, 所以当前将该接口对开发屏蔽是有必要的。
2. 个人构建里面使用Load等step 语法是会导致内存泄露的,但不代表导致最终OOM就是它,也许还有其他leak的原因。
下一步:
- 可以先将groovy插件升级到2.23, 不能升级跨度太大,免得跟当前Jenkins大版本不匹配。
- 如果解决了上面的泄露还有其他问题,最完美的方式是尽量升级Jenkins大版本,但也许升级了大版本后又有其他问题,风险同样高, 其实,我建议是一周能重启一次(周末维护窗口的时候)。