JAVA

JMX簡單定義

JMX（Java Management Extensions，即Java管理擴展）是Java平臺上為應用程序、設備、系統等植入管理功能的框架。用戶可以在任何Java應用程序中使用這些代理和服務實現管理。

JMX架構簡圖

JMX架構

JMX的結構一共分為三層：

• 基礎層：主要是MBean，被管理的資源。
• 適配層：MBeanServer，主要是提供對資源的註冊和管理。
• 接入層：提供遠程訪問的入口。

JMX堆棧分析

線程堆棧定義

線程堆棧也稱線程調用堆棧，是虛擬機中線程（包括鎖）狀態的一個瞬間快照，即系統在某一個時刻所有線程的運行狀態，包括每一個線程的調用堆棧，鎖的持有情況。雖然不同的虛擬機打印出來的格式有些不同，但是線程堆棧的信息都包含：

• 線程名字，id，線程的數量等。
• 線程的運行狀態，鎖的狀態（鎖被哪個線程持有，哪個線程在等待鎖等）
• 調用堆棧（即函數的調用層次關係）調用堆棧包含完整的類名，所執行的方法，源代碼的行數。

堆棧可以解決的問題

藉助堆棧信息可以幫助分析很多問題，如線程死鎖，鎖爭用，死循環，識別耗時操作等等。在多線程場合下的穩定性問題分析和性能問題分析，線程堆棧分析溼最有效的方法，在多數情況下，無需對系統瞭解就可以進行相應的分析。

由於線程堆棧是系統某個時刻的線程運行狀況（即瞬間快照），對於歷史痕跡無法追蹤。只能結合日誌分析。總的來說線程堆棧是多線程類應用程序非功能型問題定位的最有效手段，最善於分析如下類型問題：

• 系統無緣無故的cpu過高
• 系統掛起，無響應
• 系統運行越來越慢
• 性能瓶頸（如無法充分利用cpu等）
• 線程死鎖，死循環等
• 由於線程數量太多導致的內存溢出（如無法創建線程等）

死鎖定義

死鎖是線程競爭的一個特殊狀態，一個或是多個線程在等待其他線程完成它們的任務。

堆棧線程狀態

• NEW：線程剛被創建，但是還沒有被處理。
• RUNNABLE：當調用thread.start()後，線程變成為Runnable狀態。只要得到CPU，就可以執行
• Running：線程正在執行
• BLOCKED：該線程正在等待另外的不同的線程釋放鎖，阻塞狀態
• WAITING：該線程正在等待，通過使用了 wait, join 或者是 park 方法
• TIMED_WAITING：該線程正在等待，通過使用了 sleep, wait, join 或者是 park 方法，與Waiting的區別在於Timed_Waiting的等待有時間限制
• Dead：線程執行完畢，或者拋出了未捕獲的異常之後，會進入dead狀態，表示該線程結束

輸出堆棧信息

將堆棧信息重定向到文件中

$ jstack [option] pid >> 文件 

option參數:

-F:當正常輸出請求不響應時，強制輸出線程堆棧

-l:除堆棧外，顯示關於鎖的附加信息

-m:如果調用到本地方法的話，可以顯示C/C++堆棧

JMX堆棧信息解讀

RUNNABLE狀態示例

一般來講，我們只需要關注處於RUNNABLE狀態的線程並且包含com.xxx的一行(從下往上看，XXX為公司內部包)

堆棧示例：

"http-nio-40243-exec-9" #125 daemon prio=5 os_prio=0 tid=0x00007fd234d9f800 nid=0x7114 runnable [0x00007fd194e87000]
 java.lang.Thread.State: RUNNABLE
 at java.net.SocketInputStream.socketRead0(Native Method)
 at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
 at java.net.SocketInputStream.read(SocketInputStream.java:170)
 at java.net.SocketInputStream.read(SocketInputStream.java:141)
 at okio.Okio$2.read(Okio.java:139)
 at okio.AsyncTimeout$2.read(AsyncTimeout.java:237)
 at okio.RealBufferedSource.indexOf(RealBufferedSource.java:345)
 at okio.RealBufferedSource.readUtf8LineStrict(RealBufferedSource.java:217)
 at okio.RealBufferedSource.readUtf8LineStrict(RealBufferedSource.java:211)
 at okhttp3.internal.http1.Http1Codec.readResponseHeaders(Http1Codec.java:189)
 at okhttp3.internal.http.CallServerInterceptor.intercept(CallServerInterceptor.java:75) 

 at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:92)
 at okhttp3.internal.connection.ConnectInterceptor.intercept(ConnectInterceptor.java:45)
 at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:92)
 xxxxxxxxxxxxxxxx
 at feign.ReflectiveFeign$FeignInvocationHandler.invoke(ReflectiveFeign.java:103)
 at com.sun.proxy.$Proxy176.getCampaignShopCouponLimitRule(Unknown Source)
 at com.xxx.xxx.scan.dinner.service.impl.CouponsServiceImpl.queryCouponLimitRuleList(CouponsServiceImpl.java:478)
 at com.xxx.xxx.scan.dinner.controller.CouponsController.queryCouponLimitRuleList(CouponsController.java:115)
 at com.xxx.xxx.scan.dinner.controller.CouponsController$$FastClassBySpringCGLIB$$95e09cc2.invoke(<generated>)
 at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204)
 at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:738

/<generated>

線程解讀：

1. 線程名,“http-nio-40243-exec-10”
2. 線程屬性（如果是Daemon線程，會有Daemon標識，否則，什麼都沒有）
3. 線程優先級，prio
4. java線程對應的本地線程的優先級os_prio
5. java線程標識tid
6. java線程對應的本地線程標識nid
7. 線程狀態（運行中、等待等）
8. 線程的棧信息
9. 線程鎖信息

從線程的調用上下文可以看到從哪個函數調用到哪個函數，正執行到哪一類的哪一行。

方法

示例中基本可以定位到出現問題的方法為getCampaignShopCouponLimitRule

BLOCKED狀態示例

"http-nio-40243-exec-393" #1212 daemon prio=5 os_prio=0 tid=0x00007f4fdc3d9000 nid=0xe30 runnable [0x00007f4fc09d0000]
 java.lang.Thread.State: RUNNABLE
 at java.lang.Throwable.getStackTraceElement(Native Method)
 at java.lang.Throwable.getOurStackTrace(Throwable.java:827)
 - locked <0x00000000faf1f990> (a java.lang.Throwable)
 at java.lang.Throwable.getStackTrace(Throwable.java:816)
 at sun.reflect.GeneratedMethodAccessor2.invoke(Unknown Source)
 at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
 at java.lang.reflect.Method.invoke(Method.java:497) 

 at org.apache.log4j.spi.LocationInfo.<init>(LocationInfo.java:139)
 at org.apache.log4j.spi.LoggingEvent.getLocationInformation(LoggingEvent.java:253)
 at org.apache.log4j.pattern.LineLocationPatternConverter.format(LineLocationPatternConverter.java:58)
 at org.apache.log4j.pattern.BridgePatternConverter.format(BridgePatternConverter.java:119)
 at org.apache.log4j.EnhancedPatternLayout.format(EnhancedPatternLayout.java:546)
 at org.apache.log4j.WriterAppender.subAppend(WriterAppender.java:310)
 at org.apache.log4j.WriterAppender.append(WriterAppender.java:162)
 at org.apache.log4j.AppenderSkeleton.doAppend(AppenderSkeleton.java:251)
 - locked <0x00000000e00a2d40> (a org.apache.log4j.ConsoleAppender)
 at org.apache.log4j.helpers.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:66)
 at org.apache.log4j.Category.callAppenders(Category.java:206)
 - locked <0x00000000e009adf0> (a org.apache.log4j.Logger)
 at org.apache.log4j.Category.forcedLog(Category.java:391)
 at org.apache.log4j.Category.log(Category.java:856)
 XXXXXXXXXXXXXX
"http-nio-40243-exec-392" #1211 daemon prio=5 os_prio=0 tid=0x00007f4fd8095000 nid=0xe2f waiting for monitor entry [0x00007f4fc0dd4000]
 java.lang.Thread.State: BLOCKED (on object monitor)
 at org.apache.log4j.Category.callAppenders(Category.java:204)
 - waiting to lock <0x00000000e009adf0> (a org.apache.log4j.Logger)
 at org.apache.log4j.Category.forcedLog(Category.java:391)
 at org.apache.log4j.Category.log(Category.java:856)
 at org.slf4j.impl.Log4jLoggerAdapter.debug(Log4jLoggerAdapter.java:230)
 at com.navercorp.pinpoint.profiler.logging.Slf4jPLoggerAdapter.debug(Slf4jPLoggerAdapter.java:285)
 at com.navercorp.pinpoint.plugin.redis.interceptor.ProtocolSendCommandAndReadMethodInterceptor.before(ProtocolSendCommandAndReadMethodIntercept
or.java:71)

/<init>

上面的示例中，http-nio-40243-exec-393線程佔用了<0x00000000e009adf0>鎖，然而http-nio-40243-exec-392正在等待獲取鎖。

當一個線程佔有一個鎖的時候，線程堆棧會打印一個－locked

當一個線程正在等在其他線程釋放該鎖，線程堆棧會打印一個－waiting to lock

當一個線程佔有一個鎖，但又執行在該鎖的wait上，線程堆棧中首先打印locked,然後打印－waiting on

一般情況下，當一個或一些線程正在等待一個鎖的時候，應該有一個線程佔用了這個鎖，即如果有一個線程正在等待一個鎖，該鎖必然被另一個線程佔用，從線程堆棧中看，如果看到waiting to lock<0x22bffb60>,應該也應該有locked<0x22bffb60>,大多數情況下確實如此，但是有些情況下，會發現線程堆棧中可能根本沒有locked<0x22bffb60>,而只有waiting to ，這是什麼原因呢，實際上，在一個線程釋放鎖和另一個線程被喚醒之間有一個時間窗，如果這個期間，恰好打印堆棧信息，那麼只會找到waiting to ，但是找不到locked 該鎖的線程，當然不同的JAVA虛擬機有不同的實現策略，不一定會立刻響應請求，也許會等待正在執行的線程執行完成。

生產中的問題

實際環境中，我們通常會遇到兩類問題，一類是CPU高，程序響應慢，另一類是CPU正常，但是系統性能比較差，同時可能繁忙線程高。

CPU高，程序響應慢

1）top命令獲取佔用CPU最高的程序PID，此例為21382

top

2）找到此進程中消耗CPU較高的線程ID

top -Hp

3)將線程ID轉換為16進制

printf "%x\\n"

4）使用jstack打印堆棧信息

$ jstack -l 21382 >21382.log 

5）在堆棧結果中查詢16進制

堆棧結果

結果中可能會出現三種情況:

情況一：直接打印出代碼類名，這種情況就很好定位是代碼的問題，優化代碼即可

情況二："C2 CompilerThread*"開頭的堆棧信息，此信息表示java編譯的線程，說明java編譯器編譯過於頻繁，tomcat程序則加上參數 -XX:CICompilerCount=4 此設置表示改變編譯器線程為4線程並行處理

情況三："catalina-exec-***"開頭的堆棧信息，此信息表示程序正常處理的線程，則表示程序本身有待優化

基本思路只需要關注處於RUNNABLE狀態的線程並且包含com.xxx的一行即可(從下往上看)

注：由於環境並未出現問題，所以此處狀態正常，參考思路即可

CPU正常，但是系統性能比較差，同時可能繁忙線程高

這種情況，出現阻塞線程的可能性比較大，需要多次dump來抓取BLOCKED 狀態的線程列表。

後記

目前大部分公司開發語言還是以JAVA為主，多以瞭解下JVM對於解決問題還是很有幫助的。如果說系統慢，那麼要特別關注Blocked,Waiting on condition狀態的線程。如果說系統的cpu耗的高，那麼肯定是線程執行有死循環，那麼此時要關注下Runable狀態的線程。