通過jstack日志分析和問題排查


前段事件公司出現了一個嚴重故障(調用dubbo服務一直處於超時,整個服務系統發生雪崩,系統徹底訪問不了),一開始怎么都找不到問題的根源,日志的表現形式是dubbo線程池用完了,那么具體是什么導致的沒有找到,后然通過jstack日志分析才找到問題的根源,根源就是系統日志代碼寫有問題。通過這個故障我們來了解下如何通過jstack日志分析線上問題。首先了解下jstack

 

簡介

jstack用於生成java虛擬機當前時刻的線程快照。線程快照是當前java虛擬機內每一條線程正在執行的方法堆棧的集合,生成線程快照的主要目的是定位線程出現長時間停頓的原因,如線程間死鎖、死循環、請求外部資源導致的長時間等待等。 線程出現停頓的時候通過jstack來查看各個線程的調用堆棧,就可以知道沒有響應的線程到底在后台做什么事情,或者等待什么資源。 如果java程序崩潰生成core文件,jstack工具可以用來獲得core文件的java stack和native stack的信息,從而可以輕松地知道java程序是如何崩潰和在程序何處發生問題。另外,jstack工具還可以附屬到正在運行的java程序中,看到當時運行的java程序的java stack和native stack的信息, 如果現在運行的java程序呈現hung的狀態,jstack是非常有用的。

 

一:jstack

 

jstack命令的語法格式: jstack  <pid>。可以用jps查看java進程id。這里要注意的是:

1. 不同的 JAVA虛機的線程 DUMP的創建方法和文件格式是不一樣的,不同的 JVM版本, dump信息也有差別。

2. 在實際運行中,往往一次 dump的信息,還不足以確認問題。建議產生三次 dump信息,如果每次 dump都指向同一個問題,我們才確定問題的典型性。

 

二:jstack Dump 日志文件中的線程狀態

 

1:dump 文件里,值得關注的線程狀態有

 

死鎖, Deadlock(重點關注) 

執行中,Runnable   

等待資源, Waiting on condition(重點關注) 

等待獲取監視器, Waiting on monitor entry(重點關注)

暫停,Suspended

對象等待中,Object.wait() 或 TIMED_WAITING

阻塞, Blocked(重點關注)  

停止,Parked

 

2:Dump文件中的線程狀態含義及注意事項

 

Deadlock:死鎖線程,一般指多個線程調用間,進入相互資源占用,導致一直等待無法釋放的情況。

 

Runnable:一般指該線程正在執行狀態中,該線程占用了資源,正在處理某個請求,有可能正在傳遞SQL到數據庫執行,有可能在對某個文件操作,有可能進行數據類型等轉換。

 

Waiting on condition:該狀態出現在線程等待某個條件的發生。具體是什么原因,可以結合 stacktrace來分析。最常見的情況是線程在等待網絡的讀寫,比如當網絡數據沒有准備好讀時,線程處於這種等待狀態,而一旦有數據准備好讀之后,線程會重新激活,讀取並處理數據。在 Java引入 NewIO之前,對於每個網絡連接,都有一個對應的線程來處理網絡的讀寫操作,即使沒有可讀寫的數據,線程仍然阻塞在讀寫操作上,這樣有可能造成資源浪費,而且給操作系統的線程調度也帶來壓力。在 NewIO里采用了新的機制,編寫的服務器程序的性能和可擴展性都得到提高。

        如果發現有大量的線程都在處在 Wait on condition,從線程 stack看, 正等待網絡讀寫,這可能是一個網絡瓶頸的征兆。因為網絡阻塞導致線程無法執行。一種情況是網絡非常忙,幾 乎消耗了所有的帶寬,仍然有大量數據等待網絡讀 寫;另一種情況也可能是網絡空閑,但由於路由等問題,導致包無法正常的到達。所以要結合系統的一些性能觀察工具來綜合分析,比如 netstat統計單位時間的發送包的數目,如果很明顯超過了所在網絡帶寬的限制 ; 觀察 cpu的利用率,如果系統態的 CPU時間,相對於用戶態的 CPU時間比例較高;如果程序運行在 Solaris 10平台上,可以用 dtrace工具看系統調用的情況,如果觀察到 read/write的系統調用的次數或者運行時間遙遙領先;這些都指向由於網絡帶寬所限導致的網絡瓶頸。另外一種出現 Wait on condition的常見情況是該線程在 sleep,等待 sleep的時間到了時候,將被喚醒。

  

  

locked:線程阻塞,是指當前線程執行過程中,所需要的資源長時間等待卻一直未能獲取到,被容器的線程管理器標識為阻塞狀態,可以理解為等待資源超時的線程。

 

Waiting for monitor entry 和 in Object.wait():Monitor是 Java中用以實現線程之間的互斥與協作的主要手段,它可以看成是對象或者 Class的鎖。每一個對象都有,也僅有一個 monitor。

 

 

三:各種情況演示分享

 

   分享dump日志我們需要找到一個分析工具,一直沒找到好的分析工具后然我同事分享了我一個是IBM開發的工具叫

    "IBM Thread and Monitor Dump Analyzer for Java" 下載地址:https://www.ibm.com/developerworks/community/groups/service/html/communityview?communityUuid=2245aa39-fa5c-4475-b891-14c205f7333c

    

    1:Deadlock(死鎖)

    

    演示代碼

 

  1.  
       public class DiedsynchronizedTest {
  2.  
             public static void main(String[] args) {
  3.  
                Thread a =  new ThreadRunA();
  4.  
                Thread b =  new ThreadRunB();
  5.  
                a.start();
  6.  
                b.start();
  7.  
            }
  8.  
        }
  9.  
         class ThreadRunA extends Thread {
  10.  
             public void run() {
  11.  
                System.out.println( "================A===================");
  12.  
                 synchronized (A.A) {
  13.  
                    System.out.println( "我要開始執行任務A。。。。" + Thread.currentThread().getName());
  14.  
                     try {
  15.  
                        Thread.sleep( 5000);
  16.  
                    }  catch (InterruptedException e) {
  17.  
                        e.printStackTrace();
  18.  
                    }
  19.  
                     synchronized (B.B) {
  20.  
                    }
  21.  
                    System.out.println( "我在執行任務結束了A。。。。" + Thread.currentThread().getName() + ":" + B.B.hashCode() + ":"
  22.  
                                       + A.A.hashCode());
  23.  
                }
  24.  
            }
  25.  
        }
  26.  
         class ThreadRunB extends Thread {
  27.  
             public void run() {
  28.  
                System.out.println( "================B===================");
  29.  
                 synchronized (B.B) {
  30.  
                    System.out.println( "我要開始執行任務B。。。。" + Thread.currentThread().getName());
  31.  
                     try {
  32.  
                        Thread.sleep( 1000);
  33.  
                    }  catch (InterruptedException e) {
  34.  
                        e.printStackTrace();
  35.  
                    }
  36.  
                     synchronized (A.A) {
  37.  
                    }
  38.  
                    System.out.println( "我在執行任務結束了B。。。。" + Thread.currentThread().getName() + ":" + B.B + ":" + A.A);
  39.  
                }
  40.  
            }
  41.  
        }
  42.  
         class A {
  43.  
             static Integer A = new Integer(1);
  44.  
        }
  45.  
         class B {
  46.  
             static Integer B = new Integer(1);
  47.  
        }

    這是個簡單的死循環的代碼,我們用jstack命令dump他的信息導入分析工具如圖

    

    從圖上能清醒的看到Thread-1和Thread-0現實 Deadlock,而且還幫你定位到了具體的類和行數。

    所以我們在系統中實用鎖的時候,一定要考慮到多線程並發,避免出現交叉調用。

    

    2:Runnable 

 

    有時候我們發現CPU性能消耗很厲害,系統日志也看不出什么問題,那么這個時候我們要堅持運行中的線程有沒有出現異常,

    下面我們看下代碼

  1.  
       public class DumpWhileDemo {
  2.  
             public static void main(String[] args) {
  3.  
                 new Thread(new WhileThread()).start();
  4.  
                System.out.println();
  5.  
            }
  6.  
        }
  7.  
         class WhileThread implements Runnable {
  8.  
             @Override
  9.  
             public void run() {
  10.  
                 while (true) {
  11.  
                    System.out.println( "Thread");
  12.  
                }
  13.  
            }
  14.  
        }

    這段代碼我們可以看出new一個線程,線程里面是無線循環,執行main方法后,CPU會直線上升。可以通過linux的top命令看出來。

    我們jstack命令dump它的信息導入查看如下圖

    

    我們能看到線程Thread-0的Method方法列顯示的是我們的自己寫的類,其他兩個run的的都顯示NO JAVA STACK.

    如果我還是懷疑Thread-0方法那么我多dump幾次查看,如果依舊還是這樣那么可以說明此訪問有問題。

    因為我們使用jstack的時候打印的是當時的狀態,所以多打印幾次基本能確定是否是有異常方法.不要天真的認為Runnable狀態的就

    沒問,一切皆有可能。

     

    3:Waiting on monitor entry 和 in Object.wait()

 

    這個我就直接拿我們線上出的故障來和大家分享下,當時我們分析的時候吧dump日志下載到本地,然后導入到工具里面,看下圖

    

    

    線上我們可以清楚的看到DubboServerHandler有200的線程(dubbo服務默認線程池就200,這個了解dubbo的同學都應該清楚),

    我們再看右側報錯的內容backlog日志出問題了,后面我開發同學進一步分析是dubbo日志打印沒有控制線程數量。

    

 JAVA程序中,實現線程之間的同步,就要說說Monitor。Monitor是Java中用以實現線程之間的互斥與協作的主要手段,

 它可以看成是對象或者 Class的鎖。每一個對象都有,也僅有一個 monitor。下面這個圖,描述了線程和 Monitor之間關系,以及線程的狀態轉換圖:

 

 從圖中可以看出,每個 Monitor在某個時刻,只能被一個線程擁有,該線程就是 “Active Thread”,而其它線程都是 “Waiting Thread”,分別在兩個隊列 “ Entry Set”和 “Wait Set”里面等候。在 “Entry Set”中等待的線程狀態是 “Waiting for monitorentry”,而在 “Wait Set”中等待的線程狀態是“in Object.wait()”。 

 

    4、 Blocked  

    還是上面說的那個故障,這個時候線程已經阻塞了看下圖,導致阻塞的原因就是就是200個默認線程一直沒有釋放或者,

    等待進入的線程太多

    

    

 總結

 Java線程 DUMP的基本知識和分析的基本方法,並且解釋了如何利用線程的 DUMP信息,以及結合操作系統的各種資源使用情況,

分析程序的性能問題,從而達到改進程序,提高性能的目的。


免責聲明!

本站轉載的文章為個人學習借鑒使用,本站對版權不負任何法律責任。如果侵犯了您的隱私權益,請聯系本站郵箱yoyou2525@163.com刪除。



 
粵ICP備18138465號   © 2018-2025 CODEPRJ.COM