從應用到內核查接口超時（中）

應用復現

---

接着上文 從應用到內核查接口超時（上） 繼續排查致使接口超時的緣由。

轉載隨意，文章會持續修訂，請註明來源地址：https://zhenbianshu.github.io 。

Jdk 的 native 方法固然不是終點，雖然發現 Jdk、docker、操做系統 Bug 的可能性極小，但再往底層查卻極可能發現一些常見的配置錯誤。

爲了便於復現，我用 JMH 寫了一個簡單的 demo，控制速度不斷地經過 log4j2 寫入日誌。將項目打包成 jar 包，就能夠很方便地在各處運行了。

@BenchmarkMode(Mode.AverageTime) @OutputTimeUnit(TimeUnit.MICROSECONDS) @State(Scope.Benchmark) @Threads(5) public class LoggerRunner { public static void main(String[] args) throws RunnerException { Options options = new OptionsBuilder() .include(LoggerRunner.class.getName()) .warmupIterations(2) .forks(1) .measurementIterations(1000) .build(); new Runner(options).run(); } } 

我比較懷疑是 docker 的緣由。可是在 docker 內外運行了 jar 包卻發現都能很簡單地復現日誌停頓問題。而 jdk 版本衆多，我準備首先排查操做系統配置問題。

系統調用

---

strace 命令很早就使用過，不久前還用它分析過 shell 腳本執行慢的問題( 解決問題，別擴展問題)，但我仍是不太習慣把 Java 和它聯繫起來，幸虧有部門的老司機指點，因而就使用 strace 分析了一波 Java 應用。

命令跟分析普通腳本同樣， strace -T -ttt -f -o strace.log java -jar log.jar， -T 選項能夠將每個系統調用的耗時打印到系統調用的結尾。固然排查時使用 -p pid 附加到 tomcat 上也是能夠的，雖然會有不少容易混淆的系統調用。

對比 jmh 壓測用例輸出的 log4j2.info() 方法耗時，發現了下圖中的情況。

一次 write 系統調用居然消耗了 147ms，很明顯地，問題出在 write 系統調用上。

文件系統

---

結構

這時候就要好好回想一下操做系統的知識了。

在 linux 系統中，萬物皆文件，而爲了給不一樣的介質提供一種抽象的接口，在應用層和系統層之間，抽象了一個虛擬文件系統層（virtual file system, VFS）。上層的應用程序經過 系統調用 system call 操做虛擬文件系統，進而反饋到下層的硬件層。

因爲硬盤等介質操做速度與內存不在同一個數量級上，爲了平衡二者之間的速度，linux 便把文件映射到內存中，將硬盤單位塊(block)對應到內存中的一個 頁(page)上。這樣，當須要操做文件時，直接操做內存就能夠了。當緩衝區操做達到必定量或到達必定的時間後，再將變動統一刷到磁盤上。這樣便有效地減小了磁盤操做，應用也沒必要等待硬盤操做結束，響應速度獲得了提高。

而 write 系統調用會將數據寫到內存中的 page cache，將 page 標記爲 髒頁(dirty) 後返回。

linux 的 writeback 機制

對於將內存緩衝區的內容刷到磁盤上，則有兩種方式：

首先，應用程序在調用 write 系統調用寫入數據時，若是發現 page cache 的使用量大於了設定的大小，便會主動將內存中的髒頁刷到硬盤上。在此期間，全部的 write 系統調用都會被阻塞。

系統固然不會容忍不定時的 write 阻塞，linux 還會定時啓動 pdflush 線程，判斷內存頁達到必定的比例或髒頁存活時間達到設定的時間，將這些髒頁刷回到磁盤上，以免被動刷緩衝區，這種機制就是 linux 的 writeback 機制。

猜想

瞭解了以上基礎知識，那麼對於 write 系統調用爲何會被阻塞，提出了兩種可能：

• page cache 可用空間不足，致使觸發了主動的 flush，此時會阻塞全部對此 device 的 write。
• 寫入過程被其餘事務阻塞。

首先對於第一種可能： 查看系統配置 dirty_ratio 的大小： 20。此值是 page cache 佔用系統可用內存(real mem + swap)的最大百分比， 咱們的內存爲 32G，沒有啓用 swap，則實際可用的 page cache 大小約爲 6G。

另外，與 pdflush 相關的系統配置：系統會每 vm.dirty_writeback_centisecs (5s) 喚醒一次 pdflush 線程， 發現髒頁比例超過 vm.dirty_background_ratio (10%) 或 髒頁存活時間超過 vm.dirty_expire_centisecs(30s) 時，會將髒頁刷回硬盤。

查看 /proc/meminfo 內 Dirty/Writeback 項的變化，並對比服務的文件寫入速度，結論是數據會被 pdflush 刷回到硬盤，不會觸發被動 flush 以阻塞 write 系統調用。

ext4 的 journal 特性

---

write 被阻塞的緣由

繼續搜索資料，在一篇文章(Why buffered writes are sometimes stalled )中看到 write 系統調用被阻塞有如下可能：

• 要寫入的數據依賴讀取的結果時。但記錄日誌不依賴讀文件；
• wirte page 時有別的線程在調用 fsync() 等主動 flush 髒頁的方法。但因爲鎖的存在，log 在寫入時不會有其餘的線程操做；
• 格式爲 ext3/4 的文件系統在記錄 journal log 時會阻塞 write。而咱們的系統文件格式爲 ext4。維基百科上的一個條目（ https://en.wikipedia.org/wiki/Journaling_block_device ） 也描述了這種可能。

journal

journal 是 文件系統保證數據一致性的一種手段，在寫入數據前，將即將進行的各個操做步驟記錄下來，一旦系統掉電，恢復時讀取這些日誌繼續操做就能夠了。但批量的 journal commit 是一個事務，flush 時會阻塞 write 的提交。

咱們可使用 dumpe2fs /dev/disk | grep features 查看磁盤支持的特性，其中有 has_journal 表明文件系統支持 journal 特性。

ext4 格式的文件系統在掛載時能夠選擇 (jouranling、ordered、writeback) 三種之一的 journal 記錄模式。

三種模式分別有如下特性：

• journal： 在將數據寫入文件系統前，必須等待 metadata 和 journal 已經落盤了。
• ordered： 不記錄數據的 journal，只記錄 metadata 的 journal 日誌，且須要保證全部數據在其 metadata journal 被 commit 以前落盤。 ext4 在不添加掛載參數時使用此模式。
• writeback: 數據可能在 metadata journal 被提交以後落盤，可能致使舊數據在系統掉電後恢復到磁盤中。

固然，咱們也能夠選擇直接禁用 journal，使用 tune2fs -O ^has_journal /dev/disk，只能操做未被掛載的磁盤。

猜想由於 journal 觸發了髒頁落盤，而髒頁落盤致使 write 被阻塞，因此解決 journal 問題就能夠解決接口超時問題。

解決方案與壓測結果

---

如下是我總結的幾個接口超時問題的解決方案：

1. log4j2 日誌模式改異步。但有可能會在系統重啓時丟失日誌，另外在異步隊列 ringbuffer 被填滿未消費後，新日誌會自動使用同步模式。
2. 調整系統刷髒頁的配置，將檢查髒頁和髒頁過時時間設置得更短(1s 之內)。但理論上會略微提高系統負載（未明顯觀察到）。
3. 掛載硬盤時使用 data=writeback 選項修改 journal 模式。 但可能致使系統重啓後文件包含已刪除的內容。
4. 禁用 ext4 的 journal 特性。但可能會致使系統文件的不一致。
5. 把 ext4 的 journal 日誌遷移到更快的磁盤上，如 ssd、閃存等。操做複雜，不易維護。
6. 使用 xfs、fat 等 文件系統格式。特性不瞭解，影響不可知。

固然，對於這幾種方案，我也作了壓測，如下是壓測的結果。

 

	文件系統特性	接口超時比例
	ext4（同線上）	0.202%
	xfs文件系統	0.06%
	page過時時間和pdflush啓動時間都設置爲 0.8s	0.017%
	ext4 掛載時 journal 模式爲 writeback	0%
	禁用 ext4 的 journal 特性	0%
	log4j2 使用異步日誌	0%

小結

---

接口超時問題總算是告一段落，查了好久，不過解決它以後也很是有成就感。遺憾的是沒有在 linux 內核代碼中找到證據，160M 的代碼，分層也不熟悉，實在是無從查起，但願之後有機會能慢慢接觸吧。

程序員仍是要懂些操做系統知識的，不只幫咱們在應對這種詭異的問題時不至於一籌莫展，也能夠在作一些業務設計時能有所參考。

又熟悉了一些系統工具和命令，腳手架上又豐富了。

關於本文有什麼疑問能夠在下面留言交流，若是您以爲本文對您有幫助，歡迎關注個人 微博 或 GitHub 。您也能夠在個人 博客REPO 右上角點擊 Watch 並選擇 Releases only 項來 訂閱 個人博客，有新文章發佈會第一時間通知您。