部署在linux上的java服务老是挂掉[排查日志]
最开始的时候,严重怀疑是内存不足导致的,但是一直没得排查,最近某个服务挂掉的几率越来越高了不得不排查一下。
先从jar自己打印的debug,error查起,发现在挂掉之前没有一点异常直接下一步(也没想着这里能查到什么)毕竟“启动成功、运行中突然挂，业务日志无异常”——99% 是进程被操作系统干掉或者 JVM 自己 Abort
直接上排查 "三部曲"
- 确认“是谁”杀进程
- 全局搜 JVM 崩溃日志
- 看 GC 日志有没有“死循环”
1.确认“是谁”杀进程,看看是不是OOM Kill
什么是 OOM Kill ?
内核选择性杀掉某个进程来回收内存，这个过程叫 OOM Kill
直接输入下面的命令先查看
# 1. 系统日志里找 kill 记录
sudo journalctl --since "1 hour ago" | egrep -i "killed process.*java|oom-killer"
这个指令的意思是:
在系统日志（journal）里，搜索最近 1 小时内，涉及 Java 进程被杀掉或触发 OOM Killer 的记录。你可以通过修改journalctl --since "1 hour ago" 来实现查询更久之前的,我这里挂了就马上排查所有我只看1小时内的免得有其它影响
通过命令可以看到系统返回给我们的信息
答案已经呼之欲出了,警告信息:
Aug 13 14:21:32 VM-8-2-opencloudos kernel: sort invoked oom-killer: gfp_mask=0x140cca(GFP_HIGHUSER_MOVABLE|__GFP_COMP), order=0, oom_score_adj=0 Aug 13 14:21:32 VM-8-2-opencloudos kernel: Out of memory: Killed process 1461612 (java) total-vm:3390404kB, anon-rss:755084kB, file-rss:12044kB, shmem-rss:0kB, UID:0 pgtables:1964kB oom_score_adj:0
看到Out of memory：就表示系统内存不够了
Killed process 1461612 (java)：内核杀掉了 PID=1461612 的 Java 进程
果然,oom kill了,系统主动杀了一个占用内存大的进程,也就是挂掉的那个服务
所以 Java 应用会莫名其妙挂掉，也不会生成 JVM hs_err_pid.log，因为这是 操作系统级别的强杀，JVM 根本没机会写日志.
还有另一种方式,直接查看内核缓冲区日志,跟上面那个方式差不多
# 2. 内核环形缓冲区
dmesg -T | egrep -i "killed process|oom_reaper|segfault
从该指令返回的信息我们可以看到这几个时间都发生了 OOM Kill 都因为内存不足导致的
使用命令查看我们内存使用情况
free -h
逐项分析:(但是着重看 used 和 available)
total 3.6Gi
物理内存总容量：大约 3.6 GB（可能是 4GB 物理内存减去一些保留给内核/显存的空间）。
used 3.5Gi
当前已使用的内存（包含应用、缓存等）。
free 120Mi
完全空闲、未分配的内存（非常少）。
shared 3.4Mi
共享内存占用（主要是 tmpfs、shm）。
buff/cache 157Mi
文件缓存、缓冲区（可被回收）。
available 81Mi
系统真正还能分配给应用程序的内存：只有 81MB，这个值低到随时会触发 OOM。
我们还可以通过下面的指令查看是谁吃的内存这么多,我这里是这几个java服务吃最多,吃完了
# 按内存占用排序
ps aux --sort=-%mem | head -20
-----------------------------------------------------------------------
这种情况加内存是最有效的方式
但是,我还想挣扎一下,我决定做这两步:
1.打开Swap, 开 2G 的swap
sudo fallocate -l 2G /swapfile
sudo chmod 600 /swapfile
sudo mkswap /swapfile
sudo swapon /swapfile
开机自启 swap
echo '/swapfile none swap sw 0 0' | sudo tee -a /etc/fstab
2.限制开销不大的服务最大堆的空间
把512m 改成 256m
第一步排查就已经查到问题了,三部曲都没走完,但是不是每一个人都是这种情况,下面两部也简单说一下
2.全局搜 JVM 崩溃日志
如果你不是 oom kill 导致的,那么jvm可能在"临kill"前会给你留下线索
# 最近 7 天内所有 hs_err 文件
sudo find / -type f -name "hs_err*.log" -mtime -7 2>/dev/null
文件名匹配模式，找类似
hs_err_pid12345.log这样的文件。这些一般是 Java 虚拟机（JVM）崩溃时生成的错误日志，里面会有堆栈、CPU、内存等信息。
然后分析这些日志排查一下
3.看 GC 日志有没有“死循环”
如果你没有打开GC日志,那你得在jar包启动指令上面加上下面这个指令,下次复现时就能拿到日志了
JAVA_OPTS="$JAVA_OPTS -Xloggc:$APP_HOME/logs/gc_%t.log -XX:+PrintGCDetails -XX:+PrintGCDateStamps"
等下次复现之后就可以输入下面的指令查看了
grep -c "Full GC" logs/gc_*.log