Vim 一下日志文件,Java 进程没了?

一次端口告警,发现 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   

Vim 一下日志文件,Java 进程没了?

       

收到告警之后,登陆机器发现 java 进程消失了,第一反应是先摘流容器,然后再排查问题。

15:23 摘掉容器流量。

15:24 开始重建容器。

15:26 重建容器成功并上线。

Vim 一下日志文件,Java 进程没了?

       

请求成功率恢复,端口恢复。

Vim 一下日志文件,Java 进程没了?

排查路径

线上告警解除,业务恢复正常后,开始排查问题。首先排除日常发布的因素,先查看容器性能相关的监控,是否存在异常。查看 odin 用户内存使用率的监控,发现有异常:在 15:19 内存使用率突然飙升,然后极速下跌。看着内存使用率有问题,第一反应是否有 FullGC 的问题?

Vim 一下日志文件,Java 进程没了?


奇怪的是,在告警发生前后,居然一直没有 FullGC。

Vim 一下日志文件,Java 进程没了?

 

YGC 在问题发生点没有异常,15:25 YGC 较高,但很快恢复,应该和应用刚启动有关。

Vim 一下日志文件,Java 进程没了?


此时顺便查看 cpu 使用率有无问题。线上性能问题,往往是内存、cpu、io 这些情况。cpu 使用率没有明显的波动,15:25有短暂升高,原因是容器重建,java 代码即时编译。

Vim 一下日志文件,Java 进程没了?


既然性能层面监控没有头绪,试着查看应用监控和日志。成功率下跌是基于 nginx 的灭火图监控,查看应用层面接口的成功率监控,发现在告警发生期间,应用接口成功率并没有下跌。

Vim 一下日志文件,Java 进程没了?

根因定位

没有 FullGC,应用监控和应用日志都没有明显异常,为什么 java 进程无缘无故没有了?难道被 Linux 杀掉了,这时只能抱着试试的心态,看看是不是这个原因。

dmesg -T | grep java。

Vim 一下日志文件,Java 进程没了?


发现 java 进程1155805在15:17时候被 linux 操作系统杀掉了,原因是发生了out of memory。再看看端口异常的告警配置,在12个周期(12*10s=2min)端口均不通会触发告警。到此,时间点串起来了。15:17 linux oom killer 杀掉了 java 进程,15:19 触发了端口异常告警。       

Vim 一下日志文件,Java 进程没了?


奇怪的是,java 进程并没有 FullGC,为啥会触发 linux 系统 OOM 呢?就在排查原因陷入困境时,有同事反馈他刚才在问题机器看过日志,是使用 vim 查看 nginx 日志,打开文件过程中,vim 程序报错。

Vim 一下日志文件,Java 进程没了?

有资料反馈 oom killer 有 case 和 vim 操作有关


vim 查看日志为什么会干掉 java 进程呢?看一下日志大小,居然有37G,而我们的容器规格仅有8G。 

Vim 一下日志文件,Java 进程没了?


至此,问题原因基本定位:使用 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 进程没了?

版权声明:admin 发表于 2023年11月23日 下午8:59。
转载请注明:Vim 一下日志文件,Java 进程没了? | CTF导航

相关文章

暂无评论

您必须登录才能参与评论!
立即登录
暂无评论...