最開(kāi)始的時(shí)候,嚴(yán)重懷疑是內(nèi)存不足導(dǎo)致的,但是一直沒(méi)得排查,最近某個(gè)服務(wù)掛掉的幾率越來(lái)越高了不得不排查一下。

先從jar自己打印的debug,error查起,發(fā)現(xiàn)在掛掉之前沒(méi)有一點(diǎn)異常直接下一步(也沒(méi)想著這里能查到什么)畢竟“啟動(dòng)成功、運(yùn)行中突然掛，業(yè)務(wù)日志無(wú)異常”——99% 是進(jìn)程被操作系統(tǒng)干掉或者 JVM 自己 Abort

直接上排查 "三部曲"

• 確認(rèn)“是誰(shuí)”殺進(jìn)程
• 全局搜 JVM 崩潰日志
• 看 GC 日志有沒(méi)有“死循環(huán)”

1.確認(rèn)“是誰(shuí)”殺進(jìn)程,看看是不是OOM Kill

什么是 OOM Kill ?

內(nèi)核選擇性殺掉某個(gè)進(jìn)程來(lái)回收內(nèi)存，這個(gè)過(guò)程叫 OOM Kill

直接輸入下面的命令先查看

# 1. 系統(tǒng)日志里找 kill 記錄
sudo journalctl --since "1 hour ago" | egrep -i "killed process.*java|oom-killer"

這個(gè)指令的意思是:

在系統(tǒng)日志（journal）里，搜索最近 1 小時(shí)內(nèi)，涉及 Java 進(jìn)程被殺掉或觸發(fā) OOM Killer 的記錄。你可以通過(guò)修改journalctl --since "1 hour ago" 來(lái)實(shí)現(xiàn)查詢(xún)更久之前的,我這里掛了就馬上排查所有我只看1小時(shí)內(nèi)的免得有其它影響

通過(guò)命令可以看到系統(tǒng)返回給我們的信息

答案已經(jīng)呼之欲出了,警告信息:

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：就表示系統(tǒng)內(nèi)存不夠了

Killed process 1461612 (java)：內(nèi)核殺掉了 PID=1461612 的 Java 進(jìn)程

果然,oom kill了,系統(tǒng)主動(dòng)殺了一個(gè)占用內(nèi)存大的進(jìn)程,也就是掛掉的那個(gè)服務(wù)

所以 Java 應(yīng)用會(huì)莫名其妙掛掉，也不會(huì)生成 JVM hs_err_pid.log，因?yàn)檫@是 操作系統(tǒng)級(jí)別的強(qiáng)殺，JVM 根本沒(méi)機(jī)會(huì)寫(xiě)日志.

還有另一種方式,直接查看內(nèi)核緩沖區(qū)日志,跟上面那個(gè)方式差不多

# 2. 內(nèi)核環(huán)形緩沖區(qū)
dmesg -T | egrep -i "killed process|oom_reaper|segfault

從該指令返回的信息我們可以看到這幾個(gè)時(shí)間都發(fā)生了 OOM Kill 都因?yàn)閮?nèi)存不足導(dǎo)致的

使用命令查看我們內(nèi)存使用情況

free -h

逐項(xiàng)分析:(但是著重看 used 和 available)

total 3.6Gi

物理內(nèi)存總?cè)萘浚捍蠹s 3.6 GB（可能是 4GB 物理內(nèi)存減去一些保留給內(nèi)核/顯存的空間）。

used 3.5Gi

當(dāng)前已使用的內(nèi)存（包含應(yīng)用、緩存等）。

free 120Mi

完全空閑、未分配的內(nèi)存（非常少）。

shared 3.4Mi

共享內(nèi)存占用（主要是 tmpfs、shm）。

buff/cache 157Mi

文件緩存、緩沖區(qū)（可被回收）。

available 81Mi

系統(tǒng)真正還能分配給應(yīng)用程序的內(nèi)存：只有 81MB，這個(gè)值低到隨時(shí)會(huì)觸發(fā) OOM。

我們還可以通過(guò)下面的指令查看是誰(shuí)吃的內(nèi)存這么多,我這里是這幾個(gè)java服務(wù)吃最多,吃完了

# 按內(nèi)存占用排序
ps aux --sort=-%mem | head -20

-----------------------------------------------------------------------

這種情況加內(nèi)存是最有效的方式

但是,我還想掙扎一下,我決定做這兩步:

1.打開(kāi)Swap, 開(kāi) 2G 的swap

sudo fallocate -l 2G /swapfile
sudo chmod 600 /swapfile
sudo mkswap /swapfile
sudo swapon /swapfile

開(kāi)機(jī)自啟 swap

echo '/swapfile none swap sw 0 0' | sudo tee -a /etc/fstab

這樣你就會(huì)獲得2G內(nèi)存(消耗2G存儲(chǔ)空間)

2.限制開(kāi)銷(xiāo)不大的服務(wù)最大堆的空間

把512m 改成 256m

第一步排查就已經(jīng)查到問(wèn)題了,三部曲都沒(méi)走完,但是不是每一個(gè)人都是這種情況,下面兩部也簡(jiǎn)單說(shuō)一下

2.全局搜 JVM 崩潰日志

如果你不是 oom kill 導(dǎo)致的,那么jvm可能在"臨kill"前會(huì)給你留下線(xiàn)索

# 最近 7 天內(nèi)所有 hs_err 文件
sudo find / -type f -name "hs_err*.log" -mtime -7 2>/dev/null

• 文件名匹配模式，找類(lèi)似 hs_err_pid12345.log 這樣的文件。

• 這些一般是 Java 虛擬機(jī)（JVM）崩潰時(shí)生成的錯(cuò)誤日志，里面會(huì)有堆棧、CPU、內(nèi)存等信息。

然后分析這些日志排查一下

3.看 GC 日志有沒(méi)有“死循環(huán)”

如果你沒(méi)有打開(kāi)GC日志,那你得在jar包啟動(dòng)指令上面加上下面這個(gè)指令,下次復(fù)現(xiàn)時(shí)就能拿到日志了

JAVA_OPTS="$JAVA_OPTS -Xloggc:$APP_HOME/logs/gc_%t.log -XX:+PrintGCDetails -XX:+PrintGCDateStamps"

等下次復(fù)現(xiàn)之后就可以輸入下面的指令查看了

grep -c "Full GC" logs/gc_*.log

總結(jié)

到此這篇關(guān)于部署在linux上的java服務(wù)老是掛掉問(wèn)題排查日志的文章就介紹到這了,更多相關(guān)linux上java服務(wù)老是掛掉內(nèi)容請(qǐng)搜索腳本之家以前的文章或繼續(xù)瀏覽下面的相關(guān)文章希望大家以后多多支持腳本之家！