1. 程式人生 > >ps -mp pid -o THREAD,tid,time;printf "%x\n" tid;jstack pid |grep tid -A 30;CPU佔用太高追查

ps -mp pid -o THREAD,tid,time;printf "%x\n" tid;jstack pid |grep tid -A 30;CPU佔用太高追查

http://datoumao.blogspot.com/2012/09/linuxcputhread.html

ps H -eo user,pid,ppid,tid,time,%cpu,cmd –sort=%cpu

來源地址:

http://www.blogjava.net/hankchen/archive/2012/08/09/377735.html

原文內容:

線上應用故障排查之一:高CPU佔用
一個應用佔用CPU很高,除了確實是計算密集型應用之外,通常原因都是出現了死迴圈。

(友情提示:本博文章歡迎轉載,但請註明出處:hankchen,http://www.blogjava.net/hankchen

以我們最近出現的一個實際故障為例,介紹怎麼定位和解決這類問題。
這裡寫圖片描述

clip_image002

根據top命令,發現PID為28555的Java程序佔用CPU高達200%,出現故障。

通過ps aux | grep PID命令,可以進一步確定是tomcat程序出現了問題。但是,怎麼定位到具體執行緒或者程式碼呢?

首先顯示執行緒列表:

ps -mp pid -o THREAD,tid,time
這裡寫圖片描述

1找到了耗時最高的執行緒28802,佔用CPU時間快兩個小時了!

其次將需要的執行緒ID轉換為16進位制格式:

printf “%x\n” tid
這裡寫圖片描述

2最後列印執行緒的堆疊資訊:

jstack pid |grep tid -A 30
這裡寫圖片描述

3找到出現問題的程式碼了!

現在來分析下具體的程式碼:ShortSocketIO.readBytes(ShortSocketIO.java:106)

ShortSocketIO是應用封裝的一個用短連線Socket通訊的工具類。readBytes函式的程式碼如下:

public byte[] readBytes(int length) throws IOException {

if ((this.socket == null) || (!this.socket.isConnected())) {

    throw new IOException("++++ attempting to read from closed socket");

}

byte[] result = null;

ByteArrayOutputStream bos = new ByteArrayOutputStream();

if (this.recIndex >= length) {

       bos.write(this.recBuf, 0, length);

       byte[] newBuf = new byte[this.recBufSize];

       if (this.recIndex > length) {

           System.arraycopy(this.recBuf, length, newBuf, 0, this.recIndex - length);

       }

       this.recBuf = newBuf;

       this.recIndex -= length;

} else {

       int totalread = length;

       if (this.recIndex > 0) {

            totalread -= this.recIndex;

            bos.write(this.recBuf, 0, this.recIndex);

            this.recBuf = new byte[this.recBufSize];

            this.recIndex = 0;

}

int readCount = 0;

while (totalread > 0) {

     if ((readCount = this.in.read(this.recBuf)) > 0) {

            if (totalread > readCount) {

                  bos.write(this.recBuf, 0, readCount);

                  this.recBuf = new byte[this.recBufSize];

                  this.recIndex = 0;

           } else {

                 bos.write(this.recBuf, 0, totalread);

                 byte[] newBuf = new byte[this.recBufSize];

                 System.arraycopy(this.recBuf, totalread, newBuf, 0, readCount - totalread);

                 this.recBuf = newBuf;

                 this.recIndex = (readCount - totalread);

         }

         totalread -= readCount;

    }

}

}

問題就出在標紅的程式碼部分。如果this.in.read()返回的資料小於等於0時,迴圈就一直進行下去了。而這種情況在網路擁塞的時候是可能發生的。

至於具體怎麼修改就看業務邏輯應該怎麼對待這種特殊情況了。

最後,總結下排查CPU故障的方法和技巧有哪些:

1、top命令:Linux命令。可以檢視實時的CPU使用情況。也可以檢視最近一段時間的CPU使用情況。

2、PS命令:Linux命令。強大的程序狀態監控命令。可以檢視程序以及程序中執行緒的當前CPU使用情況。屬於當前狀態的取樣資料。

3、jstack:Java提供的命令。可以檢視某個程序的當前執行緒棧執行情況。根據這個命令的輸出可以定位某個程序的所有執行緒的當前執行狀態、執行程式碼,以及是否死鎖等等。

4、pstack:Linux命令。可以檢視某個程序的當前執行緒棧執行情況。

(友情提示:本博文章歡迎轉載,但請註明出處:hankchen,http://www.blogjava.net/hankchen

http://binma85.iteye.com/blog/778986

開門見山,本文將簡述如何使用java thread dump來分析CPU高使用率以及執行緒死鎖問題。
一般java thread dump用於web開發中分析web容器或是應用伺服器的效能問題還是比較常用並有效的。常用的入門級web容器Tomcat,以及高級別的jboss、websphere、weblogic等的效能調優問題都可以使用java thread dump來分析。
首先,闡述一下thread dump常用來解決的是何種問題
(1)高CPU使用
(2)執行緒死鎖
其次,使用步驟[以JBOSS為例]
1..get thread dump log
(1)找到應用程式所在的程序號,命令如下

Java程式碼 收藏程式碼
ps aux |grep ‘jboss’ | grep ‘java’

獲取需要的PID
(2)執行sudo kill -3 PID獲取thread dump log(PID是第一步獲取)。
注意:在不同的linux環境下執行輸出的日誌的地方可能不同。在IBM的PowerPC小型機上的linux上執行kill -3 pid會在工作目錄下產生類似javacore.20100409.161739.7614.0001.txt的檔案。JBOSS預設環境下,thread dump log輸出到jboss console,所以thread dump資訊會輸出到個人定義的控制檯列印log中。
部分示例如下所以:

引用

2010-10-08 20:27:42
Full thread dump Java HotSpot(TM) Server VM (16.3-b01 mixed mode):

“http-182.50.0.138-8084-6” daemon prio=10 tid=0x08ce5000 nid=0x6a4c in Object.wait() [0x87b5c000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x95eb81b0> (a org.apache.tomcat.util.net.JIoEndpoint W o r k e r ) a t j a v a . l a n g . O b j e c t . w a i t ( O b j e c t . j a v a : 485 ) a t o r g . a p a c h e . t o m c a t . u t i l . n e t . J I o E n d p o i n t Worker.await(JIoEndpoint.java:415)
- locked <0x95eb81b0> (a org.apache.tomcat.util.net.JIoEndpoint W o r k e r ) a t o r g . a p a c h e . t o m c a t . u t i l . n e t . J I o E n d p o i n t Worker.run(JIoEndpoint.java:441)
at java.lang.Thread.run(Thread.java:619)

“http-182.50.0.138-8084-5” daemon prio=10 tid=0x08c2e000 nid=0x6a4b in Object.wait() [0x87bad000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x95ed0600> (a org.apache.tomcat.util.net.JIoEndpoint W o r k e r ) a t j a v a . l a n g . O b j e c t . w a i t ( O b j e c t . j a v a : 485 ) a t o r g . a p a c h e . t o m c a t . u t i l . n e t . J I o E n d p o i n t Worker.await(JIoEndpoint.java:415)
- locked <0x95ed0600> (a org.apache.tomcat.util.net.JIoEndpoint W o r k e r ) a t o r g . a p a c h e . t o m c a t . u t i l . n e t . J I o E n d p o i n t Worker.run(JIoEndpoint.java:441)
at java.lang.Thread.run(Thread.java:619)

“ajp-127.0.0.1-8009-Acceptor-0” daemon prio=10 tid=0x894de800 nid=0x6a45 runnable [0x881f3000]
java.lang.Thread.State: RUNNABLE
at java.net.PlainSocketImpl.socketAccept(Native Method)
at java.net.PlainSocketImpl.accept(PlainSocketImpl.java:390)
- locked <0x949c1288> (a java.net.SocksSocketImpl)
at java.net.ServerSocket.implAccept(ServerSocket.java:453)
at java.net.ServerSocket.accept(ServerSocket.java:421)
at org.apache.tomcat.util.net.DefaultServerSocketFactory.acceptSocket(DefaultServerSocketFactory.java:61)
at org.apache.tomcat.util.net.JIoEndpoint$Acceptor.run(JIoEndpoint.java:309)
at java.lang.Thread.run(Thread.java:619)

DefaultQuartzScheduler_QuartzSchedulerThread” prio=10 tid=0x8a460800 nid=0x6a38 sleeping[0x88818000]
java.lang.Thread.State: TIMED_WAITING (sleeping)
at java.lang.Thread.sleep(Native Method)
at org.quartz.core.QuartzSchedulerThread.run(QuartzSchedulerThread.java:394)

(3)獲取執行緒資訊
使用上面的ps或者使用top命令也可以。獲取的執行緒資訊如下所示:

引用

27143 root 20 0 780m 376m 11m S 17 11.5 2:56.48 java
4839 root 20 0 778m 162m 11m S 10 5.0 1717:03 java
5049 root 20 0 764m 147m 11m S 4 4.5 1744:06 java
1 root 20 0 2100 720 624 S 0 0.0 0:28.08 init
2 root 15 -5 0 0 0 S 0 0.0 0:00.00 kthreadd
3 root RT -5 0 0 0 S 0 0.0 0:00.44 migration/0

第一列是十進位制PID,需要轉化為16進位制後才能和thread dump資訊對應。
2.分析thread dump資訊[不在列舉示例,只講思想]
(1)分析高CPU使用執行緒的thread dump資訊,查詢那些程式碼導致高CPU使用。
(2)執行緒死鎖
a.為了發現執行緒動態變化,需要多次做thread dump,每次間隔10-30s為佳.
b.執行緒狀態用 runnable(正在執行)、waiting for monitor(主動等待)、waiting for monitor entry(死鎖)。所以我們最多的是關注runnable和entry型別的執行緒。
一種典型的死鎖是在server端多個應用同時使用同一個jboss資源,這時候需要將多個應用分不到不用的佇列中。

http://javag.iteye.com/blog/718243

參考文獻:

http://www.51testing.com/?uid-188107-action-viewspace-itemid-226468

1.分析記憶體的工具

Eclipse Memory Analyzer Tool(俗稱MAT),下載地址為: http://www.eclipse.org/mat/

使用Memory Analyzer tool(MAT)分析記憶體洩漏(一)

使用Memory Analyzer tool(MAT)分析記憶體洩漏(二) 使用前需要在linux上通過jmap -dump:format=b,file={ filename} {pid}方式將heap的記憶體快照檔案給dump出來,然後就可以通過上面的MAT進行分析了。注意dump出來的檔名要以bin作為字尾名不然可能識別不了哦.

例如: jmap -dump:format=b,file=a.bin 2298

2.執行緒狀態分析

“exec-613” Id=713 in BLOCKED on [email protected] owned by tomcatThreadPool-exec-553 Id=623

“exec-553” Id=623 in TIMED_WAITING on [email protected] at java.lang.Object.wait(Native Method)

“NioProcessor-1” Id=700 in RUNNABLE (running in native) at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method) at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:215) at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:65) at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:69) at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:80)

“RMI TCP Connection(8)-172.25.3.81” Id=698 in RUNNABLE at sun.management.ThreadImpl.getThreadInfo0(Native Method) at sun.management.ThreadImpl.getThreadInfo(ThreadImpl.java:145) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:597)

RUNNABLE(正在執行的,消耗cpu) TIMED_WAITING(等待被分配到cpu執行的,現在不消耗cpu) BLOCKED(被阻塞,在阻塞解除前不能被分配cpu執行,現在不消耗cpu)

exec-613佔用了鎖,exec-553需要的鎖被exec-613佔用無法執行處於blocked狀態.

NioProcessor-1正在執行,並且他的方法在呼叫native方法.

RMI TCP Connection(8)-172.25.3.81正在執行.

(一) jinfo   jinfo列印一個給定的Java程序或核心檔案或一個遠端除錯伺服器的Java配置資訊。配置資訊包括Java系統屬性和JVM命令列標誌(更多資訊,請參考《jinfo-Configuration Info》)。   (二) jmap   jmap:如果這個工具不使用任何選項(除了pid或core選項)執行,那麼它顯示類似於Solaris的pmap工具所輸出的資訊。這個工具支援針對Java堆可觀察性的若干其它選項。   在Java SE 6平臺中,新加入了一個-dump選項。這樣可以使jmap能夠把Java堆資訊複製到一個檔案中,然後我們可以使用新的jhat命令(見下面一節)來分析它。   jmap -dump選項並不使用Solaris libproc來實現實時處理;而是,它運行當前正執行的JVM中的一小段程式碼,由此來實現堆複製。既然這種堆複製程式碼運行於JVM內部,那麼其速度是比較快的。堆複製的效果大致相當於實現一次”完全的GC”(對整個堆的垃圾收集),再加上把該堆的內容寫入到檔案中。實現堆複製的另外一種可能的思路是使用 gcore來進行核心複製並且執行”jmap -dump”(這與以”離線”方式執行的核心複製形成對照)。 

可以輸出某個java程序記憶體內物件的情況,甚至可以將VM 中的heap,以二進位制輸出成文字。

[[email protected] ~]# jmap -histo 710 >mem.txt(可使用文字對比工具對比出GC回收了哪些物件) 該檔案中內容如: num #instances #bytes class name ———————————————- 4: 1202692 67350752 java.io.ObjectStreamClass