一次端口告警,发现 java 进程被异常杀掉,而根因竟然是因为在问题机器上 vim 查看了 nginx 日志。下面我将从时间维度详细回顾这次排查,希望读者在遇到相似问题时有些许启发。
时间线
15:19 收到端口异常 odin 告警。
状态:P1故障
名称:应用端口8989
指标:data-stream-openapi.port.8989
主机:data-stream-openapi-nmg-sf-a9457-1.docker.nmg01
节点:hbb-v.data-stream-openapi.data-stream.datadream.didi.com
当前值:0.00
说明:happen(data-stream-openapi.port.8989,#12,12) = 0
故障时间:2022-11-15 15:21:10
收到告警之后,登陆机器发现 java 进程消失了,第一反应是先摘流容器,然后再排查问题。
15:23 摘掉容器流量。
15:24 开始重建容器。
15:26 重建容器成功并上线。
请求成功率恢复,端口恢复。
排查路径
线上告警解除,业务恢复正常后,开始排查问题。首先排除日常发布的因素,先查看容器性能相关的监控,是否存在异常。查看 odin 用户内存使用率的监控,发现有异常:在 15:19 内存使用率突然飙升,然后极速下跌。看着内存使用率有问题,第一反应是否有 FullGC 的问题?
奇怪的是,在告警发生前后,居然一直没有 FullGC。
YGC 在问题发生点没有异常,15:25 YGC 较高,但很快恢复,应该和应用刚启动有关。
此时顺便查看 cpu 使用率有无问题。线上性能问题,往往是内存、cpu、io 这些情况。cpu 使用率没有明显的波动,15:25有短暂升高,原因是容器重建,java 代码即时编译。
既然性能层面监控没有头绪,试着查看应用监控和日志。成功率下跌是基于 nginx 的灭火图监控,查看应用层面接口的成功率监控,发现在告警发生期间,应用接口成功率并没有下跌。
根因定位
没有 FullGC,应用监控和应用日志都没有明显异常,为什么 java 进程无缘无故没有了?难道被 Linux 杀掉了,这时只能抱着试试的心态,看看是不是这个原因。
dmesg -T | grep java。
发现 java 进程1155805在15:17时候被 linux 操作系统杀掉了,原因是发生了out of memory。再看看端口异常的告警配置,在12个周期(12*10s=2min)端口均不通会触发告警。到此,时间点串起来了。15:17 linux oom killer 杀掉了 java 进程,15:19 触发了端口异常告警。
奇怪的是,java 进程并没有 FullGC,为啥会触发 linux 系统 OOM 呢?就在排查原因陷入困境时,有同事反馈他刚才在问题机器看过日志,是使用 vim 查看 nginx 日志,打开文件过程中,vim 程序报错。
有资料反馈 oom killer 有 case 和 vim 操作有关
vim 查看日志为什么会干掉 java 进程呢?看一下日志大小,居然有37G,而我们的容器规格仅有8G。
至此,问题原因基本定位:使用 vim 命令查看37G的的文件,文件在加载过程中耗尽了内存,触发了 linux oom killer 的机制,进而杀掉了 java 进程。
问题是,为什么不杀掉 vim 进程,而要杀掉 java 进程呢?
原理解析
这里有两个问题要验证:
-
vim 是不是要将文件全部加载到内存?
-
linux oom killer的机制是什么?
查阅资料吧,进入知识盲区了。有一篇不错的 vim 原理介绍 ,有兴趣可以阅读:《Linux 编辑器之神 vim 的 IO 存储原理》
归纳一下,vim 在加载文件时会调用 readfile 函数(readfile 内部在系统调用read),而 readfile 会读完文件。看来 vim 加载大文件确实会干爆内存。
划重点:readfile 会读完文件。这就是为什么当 vim 打开一个超大文件的时候,会非常慢的原因
那 linux oom killer 的机制又是什么?为什么不杀 vim 进程,杀掉 java 进程呢?核心原理是在内存快被耗尽的时候,linux 会尝试杀掉一些进程,不让系统变得更糟糕,具体杀掉哪个进程,有一个打分机制,得分高的进程容易被杀掉。具体原理可阅读《Linux 内核 OOM killer 机制》、《oom kill 内存源码》。
文章内容在此不赘述,分享两个核心:一个是 linux 内核源码注释
* If we run out of memory, we have the choice between either
* killing a random task (bad), letting the system crash (worse)
* OR try to be smart about which process to kill. Note that we
* don't have to be perfect here, we just have to be good.
一个是 oom killer 相关结论
你的进程被Linux杀掉几个可能的原因:
一种是内存泄露;
一种是你的进程所需要的内存资源太大,系统无法满足,应该在设计时对进程需要的资源有个最大限制,不能让他无限增长;
当然,也不一定全是你的问题,也有可能是同一主机的其他进程占用资源过多,但是Linux OOM选择“最坏“进程杀掉的算法是很简单粗暴的,就选中你的进程杀掉,也是有可能的
linux oom killer 会在系统内存耗尽的时候,触发杀掉糟糕进程的保护机制,但选择糟糕进程的机制不是很精准,存在误杀的可能。
运维规范
查看或者搜索日志有很多很好用的命令,比如 less、grep、tail。
vim 命令严禁用在查看日志的场景,如果需要用 vim 编辑文件,一定要先确认文件的大小。
原文始发于微信公众号(滴滴技术):Vim 一下日志文件,Java 进程没了?