器異常斷電排查:看內(nèi)核日志與文件系統(tǒng)證據(jù))
凌晨兩點收到告警機器人狂轟亂炸的短信打開手機一看云服務(wù)器上的服務(wù)全掛了。登錄控制臺實例狀態(tài)倒是運行中可 SSH 一進去uptime 顯示系統(tǒng)剛啟動三分鐘nginx 進程一個都沒有數(shù)據(jù)庫也只剩半條命。你第一反應(yīng)肯定是昨晚是不是異常斷電了對于物理機這種問題看一眼機房配電柜就完了。但這是云服務(wù)器你連電源插頭都摸不著更別說去看排插。好在 Linux 系統(tǒng)自己會把異常斷電這件事記在好幾個地方而且證據(jù)比物理機還清晰——內(nèi)核日志、系統(tǒng)重啟履歷、文件系統(tǒng)狀態(tài)甚至是云平臺的事件記錄都可能在替你留存現(xiàn)場。這篇文章就把我排查這類問題用的完整思路寫下來。不管你手上是阿里云、騰訊云、華為云還是自建的 OpenStack 虛擬機這套方法基本通用。內(nèi)容面向運維、后端開發(fā)以及所有手頭有臺服務(wù)器又怕它半夜出事的人。1. 內(nèi)核日志的時間斷崖異常斷電留下的第一現(xiàn)場為什么會把看日志放在第一位因為正常關(guān)機和異常斷電在系統(tǒng)日志里留下的形態(tài)是完全不同的。普通操作者不需要理解 systemd 的細節(jié)只要學(xué)會辨認正常收尾和突然斷片的差別就已經(jīng)能鎖定 80% 的情況。1.1 正常關(guān)機時內(nèi)核會留下什么日志一臺 Linux 在收到正常的關(guān)機指令后會走一條非常標準的流程systemd 通知所有進程結(jié)束同步文件系統(tǒng)卸載各個掛載點關(guān)閉網(wǎng)絡(luò)設(shè)備最后才真正切斷電源。這個過程里的每一步都會往內(nèi)核日志里寫東西。正常關(guān)機時日志最后幾行通常長這樣Jan 14 03:47:01 myhost systemd-shutdown[1]: Sending SIGTERM to remaining processes... Jan 14 03:47:02 myhost systemd[1]: Unmounting /data. Jan 14 03:47:03 myhost systemd[1]: Unmounting /boot. Jan 14 03:47:05 myhost systemd[1]: All filesystems unmounted. Jan 14 03:47:05 myhost systemd[1]: Powering off.看到這類日志說明內(nèi)核是被有禮貌地關(guān)掉的——先告訴所有人要下班了然后收拾東西、鎖門、關(guān)燈。日志是收束的狀態(tài)最后一句會明確落到 shutdown、poweroff 或 reboot 上。也就是說正常關(guān)機會給出一條完整的告別記錄。而有異常斷電時這條告別記錄根本沒有機會被執(zhí)行內(nèi)核日志會像一篇文章被撕掉了后半段。1.2 斷電后的日志斷崖長什么樣異常斷電的瞬間CPU 直接失去電源內(nèi)核連一個字節(jié)的機會都沒有。此時內(nèi)核環(huán)形緩沖區(qū)里最后幾條日志可能還沒來得及寫進磁盤所以你能看到的是已持久化的最后一條日志與重啟后第一條日志之間出現(xiàn)一段明顯的空白。舉個例子斷電前系統(tǒng)還在正常運行網(wǎng)絡(luò)驅(qū)動可能是最后印出來的線索Jan 12 22:14:36 myhost kernel: 8021q: adding VLAN 0 to HW filter on device eth0然后戛然而止。下一次再有日志已經(jīng)是 22:20:11 系統(tǒng)重新上電、內(nèi)核開始引導(dǎo)時的輸出。中間那 6 分鐘左右的空白基本就是斷電時段加上少量啟動時間。這就是我常說的時間斷崖——日志不是慢慢變少、一步一步降級而是直接硬切。只要你在/var/log/journal或/var/log/messages里找到這種硬切痕跡異常斷電的概率就非常高了。這里要提醒一點dmesg本身讀的是內(nèi)核內(nèi)存里的環(huán)形緩沖區(qū)斷電重啟后早期日志其實看不全真正可靠的是已經(jīng)落盤的持久化日志。1.3 journalctl 怎么看上一次啟動的結(jié)局systemd 環(huán)境的判斷非常直接先用journalctl --list-boots列出歷次啟動記錄journalctl --list-boots輸出通常是這樣的結(jié)構(gòu)-1 31e2d9b... Jan 12 21:08:42 2024 Jan 12 22:14:36 2024 0 8ac7f34a... Jan 12 22:20:11 2024 now最后一行是當(dāng)前啟動倒數(shù)第一條-1是上一次啟動。如果上一次啟動的結(jié)束時間明顯晚于它自己的啟動時間并且和本次啟動時間之間隔了一段距離那就是一個值得注意的信號。再看上一次啟動的結(jié)尾journalctl -b -1 -e --no-pager | tail -30如果日志結(jié)尾停在某個普通內(nèi)核消息上后面什么都沒有也沒有 Powering off、沒有 reboot: Powering down、Reached target Unmount All File Systems 這類收尾行說明這個系統(tǒng)根本不是正常關(guān)機的。我習(xí)慣把這條命令放在整個排查流程的第一位因為它最快也最直觀。哪怕只執(zhí)行這一條都能給后續(xù)判斷提供明確方向。2. last 命令里的關(guān)機履歷從 wtmp 讀出非正常關(guān)機日志有斷崖算是一條線索但日志可能被輪轉(zhuǎn)、被清空或者 journald 因為存儲配置問題根本沒留下上一次的記錄。這時候就得看另一份記錄/var/log/wtmp。2.1 reboot 和 shutdown 記錄為什么重要Linux 有個專門記錄用戶登錄、退出、系統(tǒng)重啟和關(guān)機的二進制文件就是 wtmp。它不在文本日志里而是結(jié)構(gòu)化的二進制數(shù)據(jù)普通cat讀不了需要用last命令解析。正常關(guān)機時系統(tǒng)會在 wtmp 里寫一條 shutdown 類型的記錄正常重啟時也會寫一條 reboot 記錄。關(guān)鍵就在這里這兩條記錄應(yīng)該是成對出現(xiàn)的。一次完整、正常的重啟會先寫一條 shutdown 記錄再寫一條 reboot 記錄。而異常斷電時系統(tǒng)根本來不及寫 shutdown 記錄。等你重新開機wtmp 里只有一條 reboot 記錄對應(yīng)的 shutdown 記錄缺失。這個特征非常清晰基本可以用是不是成對出現(xiàn)來快速判斷。2.2 三條命令讀出關(guān)停時間線我這幾年排查最常用的就是下面三條last -x | head -40 last -x | grep -E shutdown|reboot who -blast -x會把系統(tǒng)事件翻出來重點看 shutdown 和 reboot。一次正常重啟的輸出大概是這樣reboot system boot 6.1.0-18-amd64 Mon Jan 13 03:48 still running shutdown system down 6.1.0-18-amd64 Mon Jan 13 03:47 - Mon Jan 13你看到了嗎先有 shutdown緊接著就有 reboot時間相差不過一分鐘。而異常斷電的情況通常只有孤零零一條reboot system boot 6.1.0-18-amd64 Sat Jan 12 22:20 still running沒有對應(yīng)的 shutdown 記錄。這條 reboot 記錄的時間就是斷電后系統(tǒng)重新起來的時刻。who -b可以顯示本次系統(tǒng)啟動時間。uptime或者/proc/uptime則告訴你系統(tǒng)已經(jīng)連續(xù)運行多久。如果 uptime 顯示只有十幾分鐘而你上次登錄是在幾天前說明中間發(fā)生過一次重啟接下來就該判斷重啟性質(zhì)了。還有個細節(jié)容易被忽略wtmp 會被 logrotate 輪轉(zhuǎn)。如果當(dāng)前 wtmp 里看不到足夠多的歷史可以加上-f參數(shù)讀歷史文件last -f /var/log/wtmp.1 -x | head -402.3 最容易誤判的情況人為重啟與內(nèi)核 panic不是說沒有 shutdown 記錄就一定是斷電。系統(tǒng)也可能是因為內(nèi)核 panic、硬件錯誤、云平臺強制重啟等原因而非正常重啟。人為執(zhí)行shutdown -r now或reboot是正常流程會留下 shutdown。真正容易混淆的是兩類第一類是內(nèi)核崩潰后自動重啟。內(nèi)核在 panic 后如果配置了panicN會自動重啟此時的系統(tǒng)沒有機會收尾日志也沒有 shutdown 記錄。但這種情況往往能在日志里找到 panic 關(guān)鍵字比如Kernel panic - not syncing、Oops、硬件報錯等。第二類是云平臺控制臺里的強制重啟。從操作系統(tǒng)視角看強制重啟就是突然斷電再上電幾乎不可能在系統(tǒng)內(nèi)部把它和物理斷電區(qū)分開。遇到這種情況得去控制臺事件里找操作記錄。所以判斷邏輯應(yīng)該是日志斷崖 無 shutdown 記錄 沒有 panic 痕跡這條線索才更接近異常斷電。3. 文件系統(tǒng)的賬本狀態(tài)clean 標志如何指認異常關(guān)機如果說日志和 wtmp 都是文檔型證據(jù)那文件系統(tǒng)這塊就是實物證據(jù)。因為它不在軟件層面而是直接寫在磁盤的元數(shù)據(jù)里斷電之后依然存在。3.1 ext4 superblock 里的 filesystem stateext4 文件系統(tǒng)在格式化時會有一塊存儲元數(shù)據(jù)的區(qū)域叫超級塊superblock。里面有一個字段叫 filesystem state表示文件系統(tǒng)當(dāng)前是干凈狀態(tài)還是臟狀態(tài)。正常關(guān)機時內(nèi)核會先同步文件系統(tǒng)數(shù)據(jù)然后把這個狀態(tài)標記為clean相當(dāng)于合上賬本并寫上已結(jié)清。這樣下次掛載時內(nèi)核就知道這個文件系統(tǒng)是干凈的可以直接用。異常斷電則完全來不及合賬。磁盤上的標記就停留在not clean狀態(tài)等系統(tǒng)再次開機掛載文件系統(tǒng)時內(nèi)核會發(fā)現(xiàn)這個賬本沒結(jié)清從而執(zhí)行日志重放把數(shù)據(jù)恢復(fù)到一致狀態(tài)。這種機制很像你家樓下的便利店營業(yè)員每天關(guān)門前都會把賬本合上鎖進抽屜月底結(jié)賬時一目了然。而停電時賬本攤在桌上第二天開店第一件事就是先算清楚昨天的賬。3.2 tune2fs 實操與取證時機查看 superblock 狀態(tài)用tune2fs比如tune2fs -l /dev/vda1 | grep -iE Filesystem state|Mount count|Last mount|Last checked正常輸出會是這樣Filesystem state: clean Mount count: 23 Last checked: ...如果斷電后系統(tǒng)還沒有做過一次正常關(guān)機你看到的狀態(tài)很可能是Filesystem state: not clean這就直接證明了上一次文件系統(tǒng)沒有正常卸載。配合日志和 wtmp證據(jù)鏈基本就閉合了。但這里有一個關(guān)鍵時機會講清楚如果系統(tǒng)斷電后開機又經(jīng)歷了一次正常的 reboot文件系統(tǒng)會被再次標記為 clean之前不干凈的證據(jù)就被覆蓋了。所以這個命令的檢測窗口其實是斷電后的第一次啟動這個階段。那過了窗口怎么辦看下一節(jié)。另外要確認磁盤設(shè)備名不要想當(dāng)然寫 /dev/vda1。先跑lsblk -f看看你的根分區(qū)和各個數(shù)據(jù)盤分別是什么設(shè)備、什么文件系統(tǒng)。有些實例的根分區(qū)位于 LVM 上路徑可能類似/dev/mapper/centos-root設(shè)備名寫錯了什么也查不到。3.3 斷電后首次掛載的 EXT4-fs recovery 信號相比 clean 標志日志重放的證據(jù)在時間上更持久。ext4 默認帶 journal斷電后文件系統(tǒng)處于 not clean 狀態(tài)內(nèi)核在掛載時其實會做一次日志回放recovery把未完成的事務(wù)恢復(fù)掉。而這個過程會寫進本次啟動的內(nèi)核日志。排查命令dmesg -T | grep -i ext4 journalctl -b | grep -i ext4如果看到類似這樣的輸出EXT4-fs (vda2): recovery complete EXT4-fs (vda2): mounted filesystem with ordered data mode. Quota mode: none.第一行recovery complete就是證據(jù)上一次掛載是被突然打斷的。這個信號通常只出現(xiàn)在斷電或強制重啟后的首次啟動日志里。只要你沒把日志清掉即使文件系統(tǒng)后來又正常重啟過這條歷史記錄依然存在。對于非 ext4 的分區(qū)比如 XFS檢修我先說一下思路不建議在運行中的系統(tǒng)上直接對根分區(qū)做檢查風(fēng)險太高。XFS 可以看內(nèi)核日志里有沒有recovery相關(guān)輸出或者用xfs_repair -n只讀檢查給數(shù)據(jù)盤做診斷。但日常場景里云服務(wù)器數(shù)據(jù)盤最常見還是 ext4先把上面的排查方法吃透就已經(jīng)能覆蓋大多數(shù)情況了。4. 云監(jiān)控斷點、實例事件與 NTP 跳變?nèi)菖宰C系統(tǒng)內(nèi)部的證據(jù)再充足也只能證明這臺機器不是正常關(guān)機的。至于斷電到底發(fā)生在物理層面還是虛擬化層面就得借助云平臺側(cè)的信息了。反過來也一樣如果你先在控制臺看到異常事件再回到系統(tǒng)里驗證效率會高很多。4.1 云服務(wù)器斷電的物理真相云服務(wù)器不是插著電源線的物理機你的 Linux 運行在一個虛擬機里。真正的主機電源在物理宿主機上由虛擬化平臺統(tǒng)一管理。云上異常斷電通常有兩種形態(tài)。第一種是宿主機本身出問題物理機器斷電、宿主機內(nèi)核崩潰、底層存儲網(wǎng)絡(luò)異常。此時虛擬機會一下子失去 CPU 和內(nèi)存和直接拔電源沒有任何區(qū)別。第二種是虛擬化層面強制干預(yù)比如熱遷移失敗、宿主機維護、資源調(diào)度異常導(dǎo)致虛擬機直接被強制停止。對你而言其實并不需要準確區(qū)分這兩種因為它們在系統(tǒng)內(nèi)留下的痕跡幾乎一致日志斷崖、沒有 shutdown 記錄、文件系統(tǒng) not clean。你需要關(guān)注的是控制臺記錄里是否有一條非你發(fā)起的停止或重啟事件。4.2 控制臺事件與監(jiān)控曲線的斷崖歸零幾乎所有主流云平臺都有事件或操作記錄模塊。打開控制臺找到實例的操作記錄事件中心或生命周期頁簽看斷電時間點前后有沒有以下類型的事件異常重啟宿主機維護/遷移電源操作不同平臺的叫法不同但基本都會記錄誰在什么時間對實例做了什么操作。如果事件里顯示這段時間有宿主機異?;蜃詣又貑⒛腔揪褪谴鸢噶?。如果事件記錄空空如也也別急看監(jiān)控曲線。云平臺的監(jiān)控頁面里CPU 使用率、內(nèi)存使用率、網(wǎng)絡(luò)出入帶寬都會有歷史曲線。正常關(guān)機會有一個負載逐步下降的過程曲線先下降后歸零像一段緩坡。異常斷電則是某個時間點數(shù)據(jù)直接消失曲線呈現(xiàn)斷崖式歸零沒有任何過渡。如果你發(fā)現(xiàn)實例的 CPU、內(nèi)存、網(wǎng)絡(luò)三項指標在同一時間點同時歸零并且之后又重新開始那基本可以確定這段時間實例處于斷電狀態(tài)。這里再留個心眼如果平臺開啟了自動恢復(fù)斷電后實例可能被自動拉起但你并不知情這正是監(jiān)控斷點幫你識別出來的關(guān)鍵場景。4.3 時鐘跳變與網(wǎng)絡(luò)閃斷的旁證作用斷電期間虛擬機的時鐘是停走的?;謴?fù)供電后系統(tǒng)剛起來的那幾十秒里時間往往是不準的之后才通過 NTP 或 systemd-timesyncd 校準。這個大幅校時的過程會留下痕跡。journalctl -b | grep -iE chronyd|ntpd|systemd-timesyncd如果看到類似 System clock was off by 165345 seconds 或者 Step time 165345 的輸出說明開機時系統(tǒng)時間與實際時間偏差很大而這種偏差往往就是因為機器停過一段不短的時間。注意這只能算旁證因為有些人手動改時間也會留下類似記錄必須結(jié)合前面幾條證據(jù)綜合判斷。網(wǎng)絡(luò)閃斷也可以順帶看一眼。如果業(yè)務(wù)日志里出現(xiàn)大量 TCP 連接超時、WebSocket 掉線、重連記錄且時間集中在同一個時間點說明有大量進程在同一瞬間失去網(wǎng)絡(luò)能力這與斷電后統(tǒng)一恢復(fù)是吻合的。當(dāng)然這條證據(jù)的效力更弱主要是幫你確定出事時間點而不是確定出事原因。5. 六條命令拼出完整證據(jù)鏈從篩查到定案線索都齊了現(xiàn)在把這些零散證據(jù)串起來。實際操作中我建議按固定順序來30 秒先出初步結(jié)論再決定要不要深入查。5.1 30 秒快速篩查先跑這六條命令# 1. 系統(tǒng)已運行多久誰啟動的 uptime who -b cat /proc/uptime # 2. 歷次啟動履歷 journalctl --list-boots # 3. 上一次啟動的最后日志 journalctl -b -1 -e --no-pager | tail -30 # 4. 歷史關(guān)停記錄 last -x | head -30 # 5. 文件系統(tǒng)是否干凈卸載 lsblk -f tune2fs -l /dev/vda1 | grep -iE Filesystem state|Mount count # 6. 文件系統(tǒng)是否做過日志重放 dmesg -T | grep -iE ext4.*recovery|EXT4-fs.*clean這套命令跑完你大概已經(jīng)能判斷事件性質(zhì)了。如果第 2 條的 boot 列表里上一次結(jié)束時間與本次開始時間有間隔第 3 條結(jié)尾沒有收尾日志第 4 條只有 reboot 沒有 shutdown第 5 條顯示 not clean基本可以直接告訴客戶或同事沒有正常關(guān)機記錄大概率斷電或強制重啟。5.2 證據(jù)權(quán)重表與交叉驗證邏輯證據(jù)也有輕重之分不能單憑一條下結(jié)論。我平時用大概這樣一張權(quán)重表證據(jù)來源檢查方式權(quán)重說明內(nèi)核日志斷崖journalctl -b -1 -e高上一次啟動無正常收尾日志關(guān)停記錄缺失last -x高reboot 與 shutdown 不成對文件系統(tǒng) not cleantune2fs -l高斷電后首次啟動時觀察最佳recovery 日志dmesg / journalctl高文件系統(tǒng)執(zhí)行過日志重放控制臺異常事件云平臺事件中心高宿主機異?;驈娭浦貑⒂涗洷O(jiān)控斷崖歸零云監(jiān)控平臺中CPU/內(nèi)存/帶寬同時歸零NTP 大幅校時journalctl低僅輔助定位斷點時間我的判斷原則三條以上高權(quán)重證據(jù)命中基本可以定案兩條高權(quán)重再加上監(jiān)控斷點或控制臺事件也可以定案如果只有低權(quán)重證據(jù)我不會急著下結(jié)論會先去做故障復(fù)盤和繼續(xù)觀察。還有一種情況要特別提醒你在控制臺看到有人執(zhí)行了強制重啟那從系統(tǒng)內(nèi)排查出來的特征和斷電完全一樣。別因為在系統(tǒng)里看到了非正常跡象就一口咬定是異常斷電有時候不過是有人手滑點了強制重啟或者云平臺自動恢復(fù)了故障實例。5.3 定案后的加固清單確認服務(wù)器確實發(fā)生過異常斷電后不能只停留在查明白了這一步。斷電最怕的不是系統(tǒng)重啟而是數(shù)據(jù)不一致和業(yè)務(wù)中斷時間過長。以下加固項是我每次操作完都會順手做的把 journald 設(shè)為持久化存儲。檢查/etc/systemd/journald.conf里的Storagepersistent同時給SystemMaxUse設(shè)個幾百兆的上限防止日志把磁盤撐爆。很多云鏡像默認是 volatile重啟后上一份 boot 日志直接蒸發(fā)。系統(tǒng)日志異地集中。配 rsyslog 或 syslog-ng 把關(guān)鍵日志發(fā)到遠程日志服務(wù)器這樣宿主機斷電日志也不會丟。云平臺自帶日志服務(wù)的話直接用也行。數(shù)據(jù)庫類的服務(wù)必須有高可用。異常斷電之后單機數(shù)據(jù)庫即使靠日志恢復(fù)也可能丟最近幾秒的事務(wù)這是最容易被業(yè)務(wù)方追問的地方。提前做主從至少能保證一個可切換的副本。關(guān)鍵進程設(shè)置自動拉起。systemd 服務(wù)設(shè)置Restarton-failure容器服務(wù)設(shè)置restart: unless-stopped這樣斷電重啟后服務(wù)能自愈一部分。定期檢查文件系統(tǒng)健康。云服務(wù)器根分區(qū)一般不強制要求定期 fsck但數(shù)據(jù)盤還是建議在維護窗口跑一下避免磁盤因多次異常斷電累積壞塊。最后給云平臺開好健康檢查。很多公有云支持實例自動恢復(fù)把健康檢查打開實例異常后平臺能自動幫你把機器重新拉起來比我半夜爬起來手動開機靠譜得多。很多人查到這里就結(jié)束了但我還有一個習(xí)慣不管確認與否都會把這次排查的結(jié)論、支撐日志的截圖、時間線整理成一頁文檔放到當(dāng)時的故障記錄里。下次如果再出現(xiàn)類似事件直接翻舊文檔對照能省下至少一半時間。遇到拿不準的情況也別硬扛。云平臺一般都有宿主機側(cè)的證據(jù)用戶自己在系統(tǒng)內(nèi)看不到。直接工單把時間點發(fā)給客服讓他們查一下宿主機電源事件和維護記錄往往比你自己在系統(tǒng)里猜一整天還準。