線上服務 CPU 又 100% 啦?一鍵定位 so easy!

  • 2019 年 11 月 14 日
  • 筆記

做積極的人,而不是積極廢人!

源碼精品專欄

來源:my.oschina.net/leejun2005/blog/1524687

  • 背景
  • 1、java 正則表達式回溯造成 CPU 100%
  • 2、線程死鎖,程序 hang 住
  • 3、免費實用的腳本工具大禮包
    • (1)show-duplicate-java-classes
    • (2)find-in-jars
    • (3)housemd pid [java_home]
    • (4)jvm pid
    • (5)greys[@IP:PORT]
    • (6)sjksjk –commands sjk –help

背景

經常做後端服務開發的同學,或多或少都遇到過 CPU 負載特別高的問題。尤其是在周末或大半夜,突然群里有人反饋線上機器負載特別高,不熟悉定位流程和思路的同學可能登上服務器一通手忙腳亂,定位過程百轉千回。

img

對此,也有不少同學曾經整理過相關流程或方法論,類似把大象放進冰箱要幾步,傳統的方案一般是4步

1. top oder by with P:1040 // 首先按進程負載排序找到  axLoad(pid)  2. top -Hp 進程PID:1073    // 找到相關負載 線程PID  3. printf 「0x%xn」線程PID: 0x431  // 將線程PID轉換為 16進制,為後面查找 jstack 日誌做準備  4. jstack  進程PID | vim +/十六進制線程PID -        // 例如:jstack 1040|vim +/0x431 -

但是對於線上問題定位來說,分秒必爭,上面的 4 步還是太繁瑣耗時了,有沒有可能封裝成為一個工具,在有問題的時候一鍵定位,秒級找到有問題的代碼行呢?

當然可以!工具鏈的成熟與否不僅體現了一個開發者的運維能力,也體現了開發者的效率意識。淘寶的oldratlee 同學就將上面的流程封裝為了一個工具:show-busy-java-threads.sh(https://github.com/oldratlee/useful-scripts),可以很方便的定位線上的這類問題,下面我會舉兩個例子來看實際的效果。

快速安裝使用:

source <(curl -fsSL https://raw.githubusercontent.com/oldratlee/useful-scripts/master/test-cases/self-installer.sh)

1、java 正則表達式回溯造成 CPU 100%

import java.util.ArrayList;  import java.util.List;  import java.util.regex.Matcher;  import java.util.regex.Pattern;      public class RegexLoad {      public static void main(String[] args) {          String[] patternMatch = {"([\w\s]+)+([+\-/*])+([\w\s]+)",                  "([\w\s]+)+([+\-/*])+([\w\s]+)+([+\-/*])+([\w\s]+)"};          List<String> patternList = new ArrayList<String>();            patternList.add("Avg Volume Units product A + Volume Units product A");          patternList.add("Avg Volume Units /  Volume Units product A");          patternList.add("Avg retailer On Hand / Volume Units Plan / Store Count");          patternList.add("Avg Hand Volume Units Plan Store Count");          patternList.add("1 - Avg merchant Volume Units");          patternList.add("Total retailer shipment Count");            for (String s :patternList ){                for(int i=0;i<patternMatch.length;i++){                  Pattern pattern = Pattern.compile(patternMatch[i]);                    Matcher matcher = pattern.matcher(s);                  System.out.println(s);                  if (matcher.matches()) {                        System.out.println("Passed");                  }else                      System.out.println("Failed;");              }            }      }  }

編譯、運行上述代碼之後,咱們就能觀察到服務器多了一個 100% CPU 的 java 進程:

img

怎麼使用呢?

show-busy-java-threads.sh  # 從 所有的 Java進程中找出最消耗CPU的線程(缺省5個),打印出其線程棧。    show-busy-java-threads.sh -c <要顯示的線程棧數>    show-busy-java-threads.sh -c <要顯示的線程棧數> -p <指定的Java Process>  # -F選項:執行jstack命令時加上-F選項(強制jstack),一般情況不需要使用  show-busy-java-threads.sh -p <指定的Java Process> -F    show-busy-java-threads.sh -s <指定jstack命令的全路徑>  # 對於sudo方式的運行,JAVA_HOME環境變量不能傳遞給root,  # 而root用戶往往沒有配置JAVA_HOME且不方便配置,  # 顯式指定jstack命令的路徑就反而顯得更方便了    show-busy-java-threads.sh -a <輸出記錄到的文件>    show-busy-java-threads.sh -t <重複執行的次數> -i <重複執行的間隔秒數>  # 缺省執行一次;執行間隔缺省是3秒    ##############################  # 注意:  ##############################  # 如果Java進程的用戶 與 執行腳本的當前用戶 不同,則jstack不了這個Java進程。  # 為了能切換到Java進程的用戶,需要加sudo來執行,即可以解決:  sudo show-busy-java-threads.sh

示例:

work@dev_zz_Master 10.48.186.32 23:45:50 ~/demo >  bash show-busy-java-threads.sh  [1] Busy(96.2%) thread(8577/0x2181) stack of java process(8576) under user(work):  "main" prio=10 tid=0x00007f0c64006800 nid=0x2181 runnable [0x00007f0c6a64a000]     java.lang.Thread.State: RUNNABLE          at java.util.regex.Pattern$GroupHead.match(Pattern.java:4168)          at java.util.regex.Pattern$Loop.match(Pattern.java:4295)          ...          at java.util.regex.Matcher.match(Matcher.java:1127)          at java.util.regex.Matcher.matches(Matcher.java:502)          at RegexLoad.main(RegexLoad.java:27)    [2] Busy(1.5%) thread(8591/0x218f) stack of java process(8576) under user(work):  "C2 CompilerThread1" daemon prio=10 tid=0x00007f0c64095800 nid=0x218f waiting on condition [0x0000000000000000]     java.lang.Thread.State: RUNNABLE    [3] Busy(0.8%) thread(8590/0x218e) stack of java process(8576) under user(work):  "C2 CompilerThread0" daemon prio=10 tid=0x00007f0c64093000 nid=0x218e waiting on condition [0x0000000000000000]     java.lang.Thread.State: RUNNABLE    [4] Busy(0.2%) thread(8593/0x2191) stack of java process(8576) under user(work):  "VM Periodic Task Thread" prio=10 tid=0x00007f0c640a2800 nid=0x2191 waiting on condition    [5] Busy(0.1%) thread(25159/0x6247) stack of java process(25137) under user(work):  "VM Periodic Task Thread" prio=10 tid=0x00007f13340b4000 nid=0x6247 waiting on condition  work@dev_zz_Master 10.48.186.32 23:46:04 ~/demo >

可以看到,一鍵直接定位異常代碼行,是不是很方便?

2、線程死鎖,程序 hang 住

import java.util.*;  public class SimpleDeadLock extends Thread {      public static Object l1 = new Object();      public static Object l2 = new Object();      private int index;      public static void main(String[] a) {          Thread t1 = new Thread1();          Thread t2 = new Thread2();          t1.start();          t2.start();      }      private static class Thread1 extends Thread {          public void run() {              synchronized (l1) {                  System.out.println("Thread 1: Holding lock 1...");                  try { Thread.sleep(10); }                  catch (InterruptedException e) {}                  System.out.println("Thread 1: Waiting for lock 2...");                  synchronized (l2) {                      System.out.println("Thread 2: Holding lock 1 & 2...");                  }              }          }      }      private static class Thread2 extends Thread {          public void run() {              synchronized (l2) {                  System.out.println("Thread 2: Holding lock 2...");                  try { Thread.sleep(10); }                  catch (InterruptedException e) {}                  System.out.println("Thread 2: Waiting for lock 1...");                  synchronized (l1) {                      System.out.println("Thread 2: Holding lock 2 & 1...");                  }              }          }      }  }

執行之後的效果:

img

如何用工具定位:

img

一鍵定位:可以清晰的看到線程互相鎖住了對方等待的資源,導致死鎖,直接定位到代碼行和具體原因。

通過上面兩個例子,我想各位同學應該對這個工具和工具能解決什麼問題有了比較深刻的了解了,遇到 CPU 100% 問題可以從此不再慌亂。但是更多的還是依賴大家自己去實踐,畢竟實踐出真知嘛~

3、免費實用的腳本工具大禮包

除了正文提到的 show-busy-java-threads.sh,oldratlee 同學還整合和不少常見的開發、運維過程中涉及到的腳本工具,覺得特別有用的我簡單列下:

(1)show-duplicate-java-classes

偶爾會遇到本地開發、測試都正常,上線後卻莫名其妙的 class 異常,歷經千辛萬苦找到的原因竟然是 Jar衝突!這個工具就可以找出Java Lib(Java庫,即Jar文件)或Class目錄(類目錄)中的重複類。

Java開發的一個麻煩的問題是Jar衝突(即多個版本的Jar),或者說重複類。會出NoSuchMethod等的問題,還不見得當時出問題。找出有重複類的Jar,可以防患未然。

# 查找當前目錄下所有Jar中的重複類  show-duplicate-java-classes    # 查找多個指定目錄下所有Jar中的重複類  show-duplicate-java-classes path/to/lib_dir1 /path/to/lib_dir2    # 查找多個指定Class目錄下的重複類。Class目錄 通過 -c 選項指定  show-duplicate-java-classes -c path/to/class_dir1 -c /path/to/class_dir2    # 查找指定Class目錄和指定目錄下所有Jar中的重複類的Jar  show-duplicate-java-classes path/to/lib_dir1 /path/to/lib_dir2 -c path/to/class_dir1 -c path/to/class_dir2

例如:

# 在war模塊目錄下執行,生成war文件  $ mvn install  ...  # 解壓war文件,war文件中包含了應用的依賴的Jar文件  $ unzip target/*.war -d target/war  ...  # 檢查重複類  $ show-duplicate-java-classes -c target/war/WEB-INF/classes target/war/WEB-INF/lib  ...

(2)find-in-jars

在當前目錄下所有jar文件里,查找類或資源文件。

用法:注意,後面Pattern是grep的 擴展正則表達式。

find-in-jars 'log4j.properties'  find-in-jars 'log4j.xml$' -d /path/to/find/directory  find-in-jars log4j\.xml  find-in-jars 'log4j.properties|log4j.xml'

示例:

$ ./find-in-jars 'Service.class$'  ./WEB-INF/libs/spring-2.5.6.SEC03.jar!org/springframework/stereotype/Service.class  ./rpc-benchmark-0.0.1-SNAPSHOT.jar!com/taobao/rpc/benchmark/service/HelloService.class

(3)housemd pid [java_home]

很早的時候,我們使用BTrace排查問題,在感嘆BTrace的強大之餘,也曾好幾次將線上系統折騰掛掉。2012年淘寶的聚石寫了HouseMD,將常用的幾個Btrace腳本整合在一起形成一個獨立風格的應用,其核心代碼用的是Scala,HouseMD是基於位元組碼技術的診斷工具, 因此除了Java以外, 任何最終以位元組碼形式運行於JVM之上的語言, HouseMD都支持對它們進行診斷, 如Clojure(感謝@Killme2008提供了它的使用入門), scala, Groovy, JRuby, Jython, kotlin等.

使用housemd對java程序進行運行時跟蹤,支持的操作有:

  • 查看加載類
  • 跟蹤方法
  • 查看環境變量
  • 查看對象屬性值
  • 詳細信息請參考: https://github.com/CSUG/HouseMD/wiki/UserGuideCN

(4)jvm pid

執行jvm debug工具,包含對java棧、堆、線程、gc等狀態的查看,支持的功能有:

========線程相關=======  1 : 查看佔用cpu最高的線程情況  2 : 打印所有線程  3 : 打印線程數  4 : 按線程狀態統計線程數  ========GC相關=======  5 : 垃圾收集統計(包含原因)可以指定間隔時間及執行次數,默認1秒, 10次  6 : 顯示堆中各代的空間可以指定間隔時間及執行次數,默認1秒,5次  7 : 垃圾收集統計。可以指定間隔時間及執行次數,默認1秒, 10次  8 : 打印perm區內存情況*會使程序暫停響應*  9 : 查看directbuffer情況  ========堆對象相關=======  10 : dump heap到文件*會使程序暫停響應*默認保存到`pwd`/dump.bin,可指定其它路徑  11 : 觸發full gc。*會使程序暫停響應*  12 : 打印jvm heap統計*會使程序暫停響應*  13 : 打印jvm heap中top20的對象。*會使程序暫停響應*參數:1:按實例數量排序,2:按內存佔用排序,默認為1  14 : 觸發full gc後打印jvm heap中top20的對象。*會使程序暫停響應*參數:1:按實例數量排序,2:按內存佔用排序,默認為1  15 : 輸出所有類裝載器在perm里產生的對象。可以指定間隔時間及執行次數  ========其它=======  16 : 打印finalzer隊列情況  17 : 顯示classloader統計  18 : 顯示jit編譯統計  19 : 死鎖檢測  20 : 等待X秒,默認為1  q : exit

進入jvm工具後可以輸入序號執行對應命令 可以一次執行多個命令,用分號";"分隔,如:1;3;4;5;6 每個命令可以帶參數,用冒號":"分隔,同一命令的參數之間用逗號分隔,如:

Enter command queue:1;5:1000,100;10:/data1/output.bin

(5)greys[@IP:PORT]

PS:目前Greys僅支持Linux/Unix/Mac上的Java6+,Windows暫時無法支持

Greys是一個JVM進程執行過程中的異常診斷工具,可以在不中斷程序執行的情況下輕鬆完成問題排查工作。和HouseMD一樣,Greys-Anatomy取名同名美劇「實習醫生格蕾」,目的是向前輩致敬。代碼編寫的時候參考了BTrace和HouseMD兩個前輩的思路。

使用greys對java程序進行運行時跟蹤(不傳參數,需要先greys -C pid,再greys)。支持的操作有:

  • 查看加載類,方法信息
  • 查看JVM當前基礎信息
  • 方法執行監控(調用量,失敗率,響應時間等)
  • 方法執行數據觀測、記錄與回放(參數,返回結果,異常信息等)
  • 方法調用追蹤渲染
  • 詳細信息請參考: https://github.com/oldmanpushcart/greys-anatomy/wiki

(6)sjksjk –commands sjk –help

使用sjk對Java診斷、性能排查、優化工具

  • ttop:監控指定jvm進程的各個線程的cpu使用情況
  • jps: 強化版
  • hh: jmap -histo強化版
  • gc: 實時報告垃圾回收信息
  • 更多信息請參考: https://github.com/aragozin/jvm-tools