故障分析 | 讓top命令直接顯示Java執行緒名?-- 解析OpenJDK的一個bug修復

愛可生雲資料庫發表於2021-09-30

作者:閻虎青

DBLE 開源專案負責人,負責分散式資料庫中介軟體研發工作;持續專注於資料庫方面的技術,始終在一線從事開發;對資料複製、讀寫分離、分庫分表有深入的理解和實踐。

本文來源:原創投稿

*愛可生開源社群出品,原創內容未經授權不得隨意使用,轉載請聯絡小編並註明來源。


話說有一天,dble 團隊的測試小夥伴要做效能方面的調優,需要了解調優 dble 的原理與方法,於是我就丟給他一份文件讓他好好學習一下:

https://actiontech.github.io/...

測試同學充滿鄙夷的看完了文件,然後問我,圖中這個命令的目的是做什麼的?

用 Linux 原生的 top 命令不就行了麼?你費那事幹啥?

表現的機會來了,於是我很耐心的告訴他,原生 top 命令雖然對 cpu 統計的更加準確,但是對 Java 執行緒並不友好,執行緒名都顯示 java ,和應用實際的執行緒名對不起來,需要通過 jstack 來核對一下,就像這樣的,一邊說著,我一邊開始了演示。

首先,top 命令提供了一個正在執行的動態實時檢視。它可以顯示系統摘要資訊以及當前由 Linux 核心 管理的程式或執行緒列表。顯示的這些資訊的型別、順序是可配置並且持久化。。。(“說重點,別湊字數”,測試同學打斷了滔滔不覺的我)。

好的,說重點,預設 top 顯示的是單個程式中所有執行緒的指標的總和,我們可以通過引數 -H 來指定顯示執行緒的資訊,另外引數 -p 還可以指定具體的程式 id 。

執行看看 :

top -H -p `pidof java`

結果大概是這樣的:

這個結果有什麼用呢?還得通過 jstack 命令來列印一份堆疊(當然,如果線上環境可能要承擔一定的風險)

jstack -l `pidof java` > /tmp/dble_jstack.log

有了這兩個結果,我們就可以看某個執行緒號在應用中具體對應哪個執行緒。

具體怎麼做呢?比如我們拿著10849這樣一個執行緒號,把它轉為16進位制的數字

printf "%x\n" 10849
2a61

然後,再在 jstack 的結果中查詢執行緒的名字。

cat  /tmp/dble_jstack.log | grep "nid=0x2a61"
"BusinessExecutor0" #23 daemon prio=5 os_prio=0 tid=0x00007f95dc620800 nid=0x2a61 waiting on condition [0x00007f96281f6000]

當然,如果只需要執行緒名字,這就足夠了,兩行命令也可以拼接在一起。如果還需要更多的上下文資訊,可以檢視 grep 手冊找響應的引數比如-A還有-B,甚至可以開啟檔案查詢。

我還告訴他,實際運維工作中,如果發現 java 程式的 CPU 飆高了,怎麼排查呢?也是同樣的方法,先通過 top 命令找到 CPU 高的執行緒,然後通過 jstack 知道這個執行緒在做什麼,嘗試解決 CPU 高的問題, 並且據我經驗,絕大部分是因為 gc 問題,另外還遇到過 nio 的 epoll bug 。

測試同學靜靜地聽我說完後半程的介紹以及演示,在他自己的 Ubuntu 終端上敲了同樣的一行命令:

top -H -p `pidof java`

然後指著結果問我:這不是有執行緒名麼?

這。。。大寫的尷尬加打臉現場,滿頭問號我只好乖乖認慫,並去研究下到底是為什麼 top 命令在他的機器上比我的機器上聽話。

經過幾個晝夜不眠不休的調查(並沒有),我終於查出了是否顯示執行緒名的原因。原來早在遙遠的2011年就有人提出了疑問(參見 JDK-7102541 ),並且在 JDK-8179011 給出了更加簡單的描述。修復也早在2019年就有人做了,並且 openjdk 把它 backport 到 8u222 版本上,也就是說從那之後的 openjdk 版本就已經修復了這個問題,然而到我這篇文章書寫的時候,oracle jdk 的 8u301 仍然沒有修復這個問題。所以讀者們知道該怎麼選擇 jdk 了吧。

既然 bug 已經修了,就忍不住就想看看具體是怎麼實現的。這裡我們主要關心一下 Linux 平臺的實現。這裡還有個有意思的事情,我們其實可以看見這是一位來自 SAP 的大牛在2014年就已經實現的功能。

我們來具體看程式碼,首先線上程實現的層面將執行緒的名字 set 進去:

然後是對 set_native_thread_name 方法的具體實現,在 Linux 平臺下程式碼如下:

可以看到,這裡擷取了執行緒名的前15個字元,然後呼叫了 Linux::_pthread_setname_np 方法。在看下這個方法做了什麼:

可以看出,這裡其實是通過 dlsym 呼叫作業系統的 pthread_setname_np 方法。

至此,調查結束。我們總結以下幾點內容:

  1. 如果使用 Oracle jdk8 或者更早的 jdk ,那麼還得通過 jstack 或者其他方法來對應執行緒號和邏輯執行緒名稱。
  2. 如果使用 openjdk8 ,建議升級到222之後,這樣可以通過top命令直接看到執行緒的名稱,加快診斷。
  3. 建議應用在設定執行緒名時,儘量在15個字元內表達出唯一的含義,便於觀察和分析,當然,這一點 dble 做得不好,會在之後進行調整和修改
  4. 當然,社群還有一些其他工具,比如阿里的 Arthas 應該也能實現執行緒 id 和名字對應的功能,不過引入第三方總是件麻煩的事情,還是原生的更香。

參考文件:

http://hg.openjdk.java.net/jd...
https://bugs.openjdk.java.net...
https://bugs.openjdk.java.net...
https://bugs.openjdk.java.net...
https://man7.org/linux/man-pa...
https://man7.org/linux/man-pa...

相關文章