01 背景

針對在一些服務中會出現的cpu飆高、死鎖、執行緒假死等問題，總結和提煉排查問題的思路和解決方案非常重要。上述問題會涉及到執行緒堆疊，本文將結合實際案例來闡述一下執行緒堆疊的功能。

02 基本知識

2.1 什麼是執行緒堆疊

執行緒堆疊是系統當時某個時刻的執行緒執行狀態(即瞬間快照)。

執行緒堆疊的資訊包含

執行緒的名字、ID、執行緒的數量
執行緒的執行狀態、鎖的狀態(鎖被那個執行緒持有，哪個執行緒再等待鎖)

呼叫堆疊(即函式的呼叫層次關係)。呼叫堆疊包含完整的類名，所執行的方法，原始碼的行數

2.2 執行緒堆疊能分析問題型別

執行緒堆疊定位問題只能定位在當前執行緒上留下痕跡的問題

2.3 執行緒堆疊不能分析的問題

執行緒堆疊不能定位線上程堆疊上不留痕跡的問題：

併發bug導致的資料混亂，這種問題線上程堆疊中沒有任何航跡，所以這種問題執行緒堆疊無法提供任何幫助。
資料庫鎖表的問題，表被鎖，往往由於某個事務沒有提交/回滾，但這些資訊無法在堆疊中表現出現

線上程上不留痕跡的問題只能通過其他手段來進行定位。在實際的系統中，系統的問題分為幾種型別：

在堆疊中能夠表現出問題的，使用執行緒堆疊進行定位
無法線上程中留下痕跡的問題定位，需要依賴於一個好的日誌設計
非常隱蔽的問題，只能依賴於豐富的程式碼經驗，如多執行緒導致的資料混亂，以及後面提到的幽靈程式碼

2.4 如何輸出執行緒堆疊

kill -3 pid 命令只能列印那一瞬間java程式的堆疊資訊，適合在伺服器響應慢，cpu、記憶體快速飆升等異常情況下使用，可以方便地定位到導致異常發生的java類，解決如死鎖、連線超時等原因導致的系統異常問題。該命令不會殺死程式。

備註：

將螢幕輸出寫入到檔案中，重寫檔案內容
將螢幕輸出新增到檔案末尾

Linux常用命令

命令	描述
ps	查詢程式的pid
pstack	列印程式或者執行緒的棧資訊
strace	統計每一步系統呼叫花費的時間

2.5 分析執行緒堆疊-執行緒狀態的分析

2.5.1 概述

2.5.2 Runnable

從虛擬機器的角度來看，執行緒處於正在執行的狀態。

那麼處於RUNNABLE的執行緒是不是一定消耗CPU呢?實際上不一定。下面的執行緒堆疊表示該執行緒正在從網路讀取資料，儘管下面這個執行緒顯示為RUNNABLE狀態，但實際上網絡IO,執行緒絕大多數時間是被掛起，只有當資料到達之後，執行緒才被重新喚醒。掛起發生在本地程式碼(Native)中，虛擬機器根本不知道，不像顯式呼叫了Java的sleep()或者wait()等方法，虛擬機能知道執行緒的真正狀態，但對於原生程式碼中的掛起，虛擬機器無法真正地知道執行緒狀態，因此它一概顯示為RUNNABLE。像這種socket IO操作不會消耗大量的CPU,因為大多時間在等待，只有資料到來之後，才消耗一點點CPU.

Thread-39" daemon prio=1 tid=0x08646590 nid=0x666d runnable [5beb7000..5beb88b8]
      java.lang.Thread.State: RUNNABLE
        at java.net.SocketInputStream.socketRead0(Native Method)
        at java.net.SocketInputStream.read(SocketInputStream.java:129)
        at java.io.BufferedInputStream.fill(BufferedInputStream.java:183)
        at java.io.BufferedInputStream.read(BufferedInputStream.java:201)
        - locked <0x47bfb940> (a java.io.BufferedInputStream)
        at org.postgresql.PG_Stream.ReceiveChar(PG_Stream.java:141)
        at org.postgresql.core.QueryExecutor.execute(QueryExecutor.java:68)
        - locked <0x47bfb758> (a org.postgresql.PG_Stream)
        at org.postgresql.Connection.ExecSQL(Connection.java:398)

下面的執行緒正在執行純Java程式碼指令，實實在在是消耗CPU的執行緒。

"Thread-444" prio=1 tid=0xa4853568 nid=0x7ade runnable [0xafcf7000..0xafcf8680]
      java.lang.Thread.State: RUNNABLE
//實實在在再對應CPU運算指令
at org.apache.commons.collections.ReferenceMap.getEntry(Unknown Source) at org.apache.commons.collections.ReferenceMap.get(Unknown Source)
at org.hibernate.util.SoftLimitMRUCache.get(SoftLimitMRUCache.java:51) at org.hibernate.engine.query.QueryPlanCache.getNativeSQLQueryPlan()
at org.hibernate.impl.AbstractSessionImpl.getNativeSQLQueryPlan()
at org.hibernate.impl.AbstractSessionImpl.list()
at org.hibernate.impl.SQLQueryImpl.list(SQLQueryImpl.java:164)
at com.mogoko.struts.logic.user.LeaveMesManager.getCommentByShopId()
at com.mogoko.struts.action.shop.ShopIndexBaseInfoAction.execute() ......

下面的執行緒正在進行JNI本地方法呼叫，具體是否消耗CPU，要看TcpRecvExt的實現，如果TcpRecvExt 是純運算程式碼，那麼是實實在在消耗CPU,如果TcpRecvExt()中存在掛起的代碼，那麼該執行緒儘管顯示為RUNNABLE,但實際上也是不消耗CPU的。

 "ClientReceiveThread" daemon prio=1 tid=0x99dbacf8 nid=0x7988 runnable [...]
      java.lang.Thread.State: RUNNABLE
        at com.pangu.network.icdcomm.htcpapijni.TcpRecvExt(Native Method)
        at com.pangu.network.icdcomm.IcdComm.receive(IcdComm.java:60)
        at com.msp.client.MspFactory$ClientReceiveThread.task(MspFactory.java:333)
        at com.msp.system.TaskThread.run(TaskThread.java:94)

2.5.3 TIMED_WAITING(on object monitor)

表示當前執行緒被掛起一段時間,說明該執行緒正在執行obj.wait(int time)方法.

下面的執行緒堆疊表示當前執行緒正處於TIMED_WAITING狀態，當前正在被掛起，時長為引數中指定的時長，如obj.wait(2000)。因此該執行緒當前不消耗CPU。

 "JMX server" daemon prio=6 tid=0x0ad2c800 nid=0xdec in Object.wait() [...]
      java.lang.Thread.State: TIMED_WAITING (on  object  monitor)
       at java.lang.Object.wait(Native Method)
       - waiting on <0x03129da0> (a [I)
       at com.sun.jmx.remote.internal.ServerComm$Timeout.run(ServerComm.java:150)
       - locked <0x03129da0> (a [I)
       at java.lang.Thread.run(Thread.java:620)

2.5.4 TIMED_WAITING(sleeping)

表示當前執行緒被掛起一段時間,即正在執行Thread.sleep(int time)方法.

下面的執行緒正處於TIMED_WAITING狀態，表示當前被掛起一段時間，時長為引數中指定的時長，如Thread.sleep(100000)。因此該執行緒當前不消耗CPU。

 "Comm thread" daemon prio=10 tid=0x00002aaad4107400 nid=0x649f waiting on condition
    [0x000000004133b000..0x000000004133ba00]
       java.lang.Thread.State: TIMED_WAITING (sleeping)
            at java.lang.Thread.sleep(Native Method)
            at org.apache.hadoop.mapred.Task$1.run(Task.java:282)
            at java.lang.Thread.run(Thread.java:619)

2.5.5 TIMED_WAITING(parking)

當前執行緒被掛起一段時間,即正在執行Thread.sleep(int time)方法.

下面的執行緒正處於TIMED_WAITING狀態，表示當前被掛起一段時間，時長為引數中指定的時長，如LockSupport.parkNanos(blocker, l10000) 。因此該執行緒當前不消耗CPU。

"RMI TCP" daemon prio=6 tid=0x0ae3b800 nid=0x958 waiting on condition [0x17eff000..0x17effa94]
 java.lang.Thread.State: TIMED_WAITING (parking)
       at sun.misc.Unsafe.park(Native Method)
       - parking to wait for  <0x02f49f58> (a java.util.concurrent.SynchronousQueue$TransferStack)
       at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:179)
       at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:424)
       at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:323)
       at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:871)
       at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:495)
       at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:693)
       at java.lang.Thread.run(Thread.java:620)

2.5.6 WAINTING(on object monitor)

當前執行緒被掛起，即正在執行obj.wait()方法(無引數的wait()方法).

下面的執行緒正處於WAITING狀態，表示當前執行緒被掛起，如obj.wait()(只能通過notify()喚醒)。因此該執行緒當前不消耗CPU。

 "IPC Client" daemon prio=10 tid=0x00002aaad4129800 nid=0x649d in Object.wait() [0x039000..0x039d00]
       java.lang.Thread.State: WAITING (on object monitor)
            at java.lang.Object.wait(Native Method)
            - waiting on <0x00002aaab3acad18>; (aorg.apache.hadoop.ipc.Client$Connection)
            at java.lang.Object.wait(Object.java:485)
            at org.apache.hadoop.ipc.Client$Connection.waitForWork(Client.java:234)
            - locked <0x00002aaab3acad18> (aorg.apache.hadoop.ipc.Client$Connection)
            at org.apache.hadoop.ipc.Client$Connection.run(Client.java:273)

2.5.7 總結

處於TIMED_WAITING、WAITING狀態的執行緒一定不消耗CPU，處於Runable的執行緒，要結合當前執行緒程式碼的性質判斷，是否消耗CPU。

如果純java運算程式碼，則消耗CPU
如果是網路IO，很少消耗CPU
如果是原生程式碼，結合原生程式碼的性質判斷(可以通過pstack/gstack獲取本地執行緒堆疊)，如果是純運算程式碼，則消耗CPU，如果被掛起，則不消耗CPU，如果是IO，則不怎麼消耗CPU。

03 CPU飆高

3.1 概述

系統的CPU的飆高的原因有很多，下面羅列一下一些常見的場景：

3.2 死迴圈導致CPU飆高

死迴圈並不一定會導致CPU的100%利用率，如果死迴圈中的程式碼不是CPU密集型，而是像Socket或者資料庫IO操作，這些操作是不怎麼消耗CPU的。但如果迴圈程式碼中是CPU密集型操作，那這就是導致CPU利用率100%的可能原因。

定位問題的方法是：通過多次列印執行緒堆疊

主要流程如下：

獲取第一次堆疊資訊
等待一定的時間，再獲取第二次堆疊資訊。
預處理兩次堆疊資訊，首先去掉處於sleeping或者waiting狀態的執行緒，因為這種執行緒是不消耗CPU的
比較第一次堆疊和第二次堆疊預處理後的執行緒，找出這段時間一直活躍的執行緒，如果兩次堆疊中同一個執行緒處於同樣的呼叫上下文，那麼就應該列為重點懷疑物件。具體情況需要結合程式碼詳細分析。導致這種情況的可能原因猜測是：

猜測一：檢查該執行緒的執行上下所對應的程式碼是否屬於長期執行的程式碼。

猜測二：如果不屬於長期執行的程式碼，那麼這個執行緒為什麼長期執行不完那段程式碼，可能的原因是程式碼出現死迴圈了。

導致死迴圈出現的原因：

多執行緒：for,while迴圈中的退出條件永遠不滿足導致的死迴圈。
多執行緒：連結串列等資料結構首尾相接，導致遍歷永遠無法停止
其問題

3.3 非死迴圈導致CPU飆高

導致CPU飆高的可能原因：

純java程式碼導致的CPU過高，具體情況可以參考部落格： 【穩定性平臺】一次效能優化經驗分享
java程式碼中呼叫的JNI程式碼導致的CPU過高
虛擬機器自身的程式碼導致的CPU過高，比如GC的bug等

定位問題的方法是：通過列印執行緒堆疊

主要流程如下：

第一步：獲取目標程式id(pid)，使用命令可以獲取程式ID，jps -l 或 ps -ef ｜grep java

第二步：通過top -Hp pid 獲取該程式下最消耗CPU的本地執行緒ID。

第三步：列印執行緒堆疊，使用如下命令，jstack -l pid

第四步：將十進位制的本地執行緒ID換算成16進位制，採用如下命令：printf "0x%x\n" 53841(本地執行緒ID), 輸出Oxd251。

第五步：在java執行緒堆疊中查詢nid=<第一步獲取的最耗CPU時間的執行緒ID(十進位制換算成的十六進位制的本地執行緒ID)>，具體分析如下

如果在java執行緒堆疊中找到了對應的執行緒ID，並且該執行緒正在執行純java程式碼，說明是該java程式碼導致的CPU過高的。
如果在java執行緒堆疊中找到了對應的執行緒ID，並且該執行緒正在執行native code程式碼，說明是導致的CPU過高的問題程式碼在JNI呼叫中。
如果在java執行緒堆疊中找不到了對應的執行緒ID，有如下兩種可能：
- JNI呼叫中重新建立的執行緒來執行，那麼在java執行緒堆疊中就不存在該執行緒的資訊。
- 虛擬機器自身程式碼導致的CPU過高，如堆記憶體枯竭導致的頻繁Full GC，或者虛擬機器bug等
- 此時同樣可以通過pstack pid命令獲取所有的本地執行緒堆疊，根據之前獲取的最耗時CPU時間的執行緒ID，在本地執行緒堆疊中找到對應的執行緒，即為高消耗CPU的執行緒。藉助本地執行緒堆疊資訊，可以直接定位到原生程式碼找出問題。

04 系統假死

4.1 概述

系統假死只是一個表面現象。系統假死，從表面上看，是系統不處理響應。對於web系統來說，http請求無資料返回。總之來說，系統像死了一樣。導致系統假死的原因很多，具體的問題需要在特定的場景下進行分析，但總的歸結原因有如下幾種:

備註：特殊情況，系統假死，當一個服務即對外提供http和rpc服務時，兩者使用的不同的執行緒池，即使其中一個執行緒池中的執行緒產生死鎖，另外一個執行緒池仍然可以提供服務

4.2 執行緒死鎖

4.2.1 死鎖和定位方法

什麼死鎖

當兩個執行緒或多個執行緒正在等待被對方佔有的鎖，死鎖就會發生。死鎖會導致兩個執行緒無法繼續執行，被永遠掛起。

定位問題的方法是：列印執行緒堆疊。如出現死鎖時，在列印執行緒堆疊時虛擬機器會自動給出死鎖的提示。

4.2.2 背景

在2021.12.13 11:15 refund-interfaces 服務上這臺機器10.240.49.153 操作命令掛載沙箱，在11:32:19分在流量回放平臺操作錄製，此時返回操作失敗，對錄製失敗進行問題排查，在11:34 分，order服務有介面報服務超時，但是從refund-interface 監控上看，這臺10.240.49.153的監控不存在，其他都是正常的，11:59才發現這臺機器仍然在dubbo的註冊中心，當時情況沒有比較好手段儲存現場，只能將機器重啟，破會了現場。事後初步猜測是在高併發的情況下，操作平臺的錄製功能導致發生死鎖。而發生死鎖時，要想恢復系統，臨時也是唯一規避的辦法就是將系統重啟。

為保證服務的可用性，在發生異常情況下，降級方案和問題排查思路

通常的降級方案是：

【方案一】儲存現場法-摘除流量法，目前我司該方案並不完善

1.對於http，需要從閘道器摘除流量，即是consul

2.對於rpc，需要從dubbo的註冊中心摘除流量，即是nacos

3.對於mq，服務接入MQ的消費端摘除流量

【方案二】萬能法-機器重啟

通常的問題排查思路是：儘量儲存現場，便於事後問題排查！！！！

備註：對於死鎖的發生，如沒有保留現場，需要對其發現的手段是通過壓測的方式。因為程式碼如有發生死鎖的潛在可能並不意味照死鎖每次都發生，它只發生該發生的時候，當死鎖出現的時候，往往是遇到了最不幸的時候-在高負載的生產環境之下

4.2.3 通過壓測方式來複現死鎖

4.2.3.1 現象

在2021-12-27 11:58:15沒有監控，壓測是存在，服務程式是存在的，在12:02 dump執行緒堆疊進行觀察，如上

4.2.3.2 dump 執行緒堆疊

Found one Java-level deadlock:
=============================
"DubboServerHandler-10.246.144.236:20888-thread-200":
  waiting to lock monitor 0x00007faa6c00c128 (object 0x00000006bd2a0000, a com.pandora.jvm.sandbox.repeater.module.classloader.PluginClassLoader),
  which is held by "com.alibaba.nacos.client.naming.updater"
"com.alibaba.nacos.client.naming.updater":
  waiting to lock monitor 0x00007fa91c0568b8 (object 0x00000006bcf0de00, a com.alibaba.jvm.sandbox.core.classloader.ModuleJarClassLoader),
  which is held by "XNIO-1 task-44"
"XNIO-1 task-44":
  waiting to lock monitor 0x00007fa904004848 (object 0x0000000722c10c48, a java.lang.Object),
  which is held by "com.alibaba.nacos.client.naming.updater"

Java stack information for the threads listed above:
===================================================
"DubboServerHandler-10.246.144.236:20888-thread-200":
    at com.pandora.jvm.sandbox.repeater.plugin.dubbo.DubboProviderInvocationProcessor.assembleIdentity(DubboProviderInvocationProcessor.java:39)
    at com.pandora.jvm.sandbox.repeater.plugin.core.impl.api.DefaultEventListener.sample(DefaultEventListener.java:194)
    at com.pandora.jvm.sandbox.repeater.plugin.core.impl.api.DefaultEventListener.onEvent(DefaultEventListener.java:89)
    at com.alibaba.jvm.sandbox.core.enhance.weaver.EventListenerHandler.handleEvent(EventListenerHandler.java:117)
    at com.alibaba.jvm.sandbox.core.enhance.weaver.EventListenerHandler.handleOnBefore(EventListenerHandler.java:353)
    at java.com.alibaba.jvm.sandbox.spy.Spy.spyMethodOnBefore(Spy.java:164)
    at org.apache.dubbo.rpc.filter.ContextFilter.invoke(ContextFilter.java)
    at org.apache.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:81)
    at org.apache.dubbo.rpc.filter.GenericFilter.invoke(GenericFilter.java:147)
    at org.apache.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:81)
    at org.apache.dubbo.rpc.filter.ClassLoaderFilter.invoke(ClassLoaderFilter.java:38)
    at org.apache.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:81)
    at org.apache.dubbo.rpc.filter.EchoFilter.invoke(EchoFilter.java:41)
    at org.apache.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:81)
    at org.apache.dubbo.rpc.protocol.dubbo.DubboProtocol$1.reply(DubboProtocol.java:145)
    at org.apache.dubbo.remoting.exchange.support.header.HeaderExchangeHandler.handleRequest(HeaderExchangeHandler.java:100)
    at org.apache.dubbo.remoting.exchange.support.header.HeaderExchangeHandler.received(HeaderExchangeHandler.java:175)
    at org.apache.dubbo.remoting.transport.DecodeHandler.received(DecodeHandler.java:51)
    at org.apache.dubbo.remoting.transport.dispatcher.ChannelEventRunnable.run(ChannelEventRunnable.java:57)
    at com.alibaba.ttl.TtlRunnable.run(TtlRunnable.java:51)
    at com.alibaba.ttl.TtlRunnable.run(TtlRunnable.java:55)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at java.lang.Thread.run(Thread.java:775)
"com.alibaba.nacos.client.naming.updater":
    at java.lang.ClassLoader.checkCerts(ClassLoader.java:881)
    - waiting to lock <0x00000006bcf0de00> (a com.alibaba.jvm.sandbox.core.classloader.ModuleJarClassLoader)
    at java.lang.ClassLoader.preDefineClass(ClassLoader.java:662)
    at java.lang.ClassLoader.defineClass(ClassLoader.java:755)
    at java.security.SecureClassLoader.defineClass(SecureClassLoader.java:142)
    at java.net.URLClassLoader.defineClass(URLClassLoader.java:468)
    at java.net.URLClassLoader.access$100(URLClassLoader.java:74)
    at java.net.URLClassLoader$1.run(URLClassLoader.java:369)
    at java.net.URLClassLoader$1.run(URLClassLoader.java:363)
    at java.security.AccessController.doPrivileged(Native Method)
    at java.net.URLClassLoader.findClass(URLClassLoader.java:362)
    at com.alibaba.jvm.sandbox.core.classloader.RoutingURLClassLoader.access$400(RoutingURLClassLoader.java:22)
    at com.alibaba.jvm.sandbox.core.classloader.RoutingURLClassLoader$1.loadClass(RoutingURLClassLoader.java:91)
    at com.alibaba.jvm.sandbox.core.classloader.ClassLoadingLock.loadingInLock(ClassLoadingLock.java:55)
    - locked <0x0000000722c10c48> (a java.lang.Object)
    at com.alibaba.jvm.sandbox.core.classloader.RoutingURLClassLoader.loadClass(RoutingURLClassLoader.java:64)
    at java.lang.ClassLoader.loadClass(ClassLoader.java:406)
    - locked <0x00000006bd2a0000> (a com.pandora.jvm.sandbox.repeater.module.classloader.PluginClassLoader)
    at com.pandora.jvm.sandbox.repeater.module.classloader.PluginClassLoader.loadClass(PluginClassLoader.java:47)
    - locked <0x00000006bd2a0000> (a com.pandora.jvm.sandbox.repeater.module.classloader.PluginClassLoader)
    at java.lang.ClassLoader.loadClass(ClassLoader.java:352)
    at com.pandora.jvm.sandbox.repeater.plugin.exception.ExceptionEventListener.sample(ExceptionEventListener.java:34)
    at com.pandora.jvm.sandbox.repeater.plugin.core.impl.api.DefaultEventListener.onEvent(DefaultEventListener.java:89)
    at com.alibaba.jvm.sandbox.core.enhance.weaver.EventListenerHandler.handleEvent(EventListenerHandler.java:117)
    at com.alibaba.jvm.sandbox.core.enhance.weaver.EventListenerHandler.handleOnBefore(EventListenerHandler.java:353)
    at java.com.alibaba.jvm.sandbox.spy.Spy.spyMethodOnBefore(Spy.java:164)
    at java.lang.RuntimeException.<init>(RuntimeException.java:62)
    at java.lang.IllegalArgumentException.<init>(IllegalArgumentException.java:52)
    at java.lang.NumberFormatException.<init>(NumberFormatException.java:55)
    at java.lang.Long.parseLong(Long.java:552)
    at java.lang.Long.parseLong(Long.java:631)
    at sun.net.www.protocol.http.HttpURLConnection.getInputStream0(HttpURLConnection.java:1845)
    - locked <0x0000000722cc9928> (a sun.net.www.protocol.http.HttpURLConnection)
    at sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:1498)
    - locked <0x0000000722cc9928> (a sun.net.www.protocol.http.HttpURLConnection)
    at java.net.HttpURLConnection.getResponseCode(HttpURLConnection.java:480)
    at com.alibaba.nacos.common.http.client.response.JdkHttpClientResponse.getStatusCode(JdkHttpClientResponse.java:75)
    at com.alibaba.nacos.common.http.client.handler.AbstractResponseHandler.handle(AbstractResponseHandler.java:43)
    at com.alibaba.nacos.common.http.client.NacosRestTemplate.execute(NacosRestTemplate.java:483)
    at com.alibaba.nacos.common.http.client.NacosRestTemplate.exchangeForm(NacosRestTemplate.java:427)
    at com.alibaba.nacos.client.naming.net.NamingProxy.callServer(NamingProxy.java:599)
    at com.alibaba.nacos.client.naming.net.NamingProxy.reqApi(NamingProxy.java:524)
    at com.alibaba.nacos.client.naming.net.NamingProxy.reqApi(NamingProxy.java:491)
    at com.alibaba.nacos.client.naming.net.NamingProxy.reqApi(NamingProxy.java:486)
    at com.alibaba.nacos.client.naming.net.NamingProxy.queryList(NamingProxy.java:400)
    at com.alibaba.nacos.client.naming.core.HostReactor.updateService(HostReactor.java:339)
    at com.alibaba.nacos.client.naming.core.HostReactor$UpdateTask.run(HostReactor.java:420)
    at com.alibaba.ttl.TtlRunnable.run(TtlRunnable.java:51)
    at com.alibaba.ttl.TtlRunnable.run(TtlRunnable.java:55)
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at java.lang.Thread.run(Thread.java:775)
"XNIO-1 task-44":
    at com.alibaba.jvm.sandbox.core.classloader.ClassLoadingLock.loadingInLock(ClassLoadingLock.java:53)
    - waiting to lock <0x0000000722c10c48> (a java.lang.Object)
    at com.alibaba.jvm.sandbox.core.classloader.RoutingURLClassLoader.loadClass(RoutingURLClassLoader.java:64)
    at java.lang.ClassLoader.loadClass(ClassLoader.java:352)
    at com.pandora.jvm.sandbox.repeater.plugin.core.impl.dewuext.TraceExtension.dewuTrace(TraceExtension.java:51)
    at com.pandora.jvm.sandbox.repeater.plugin.core.impl.api.DefaultEventListener.onEvent(DefaultEventListener.java:76)
    at com.alibaba.jvm.sandbox.core.enhance.weaver.EventListenerHandler.handleEvent(EventListenerHandler.java:117)
    at com.alibaba.jvm.sandbox.core.enhance.weaver.EventListenerHandler.handleOnBefore(EventListenerHandler.java:353)
    at java.com.alibaba.jvm.sandbox.spy.Spy.spyMethodOnBefore(Spy.java:164)
    at io.jaegertracing.internal.JaegerSpan.finish(JaegerSpan.java)
    at com.poizon.fusion.monitor.instrument.jdbc.MonitorPreparedStatement.execute(MonitorPreparedStatement.java:97)
    at io.shardingsphere.shardingjdbc.jdbc.core.statement.MasterSlavePreparedStatement$3.executeSQL(MasterSlavePreparedStatement.java:152)
    at io.shardingsphere.shardingjdbc.jdbc.core.statement.MasterSlavePreparedStatement$3.executeSQL(MasterSlavePreparedStatement.java:149)
    at io.shardingsphere.spi.executor.MasterSlaveSQLExecuteCallback.execute0(MasterSlaveSQLExecuteCallback.java:17)
    at io.shardingsphere.shardingjdbc.jdbc.core.statement.MasterSlavePreparedStatement.execute(MasterSlavePreparedStatement.java:155)
    at com.poizon.fusion.monitor.instrument.jdbc.MonitorPreparedStatement.execute(MonitorPreparedStatement.java:89)
    at org.apache.ibatis.executor.statement.PreparedStatementHandler.query(PreparedStatementHandler.java:64)
    at org.apache.ibatis.executor.statement.RoutingStatementHandler.query(RoutingStatementHandler.java:79)
    at org.apache.ibatis.executor.SimpleExecutor.doQuery(SimpleExecutor.java:63)
    at org.apache.ibatis.executor.BaseExecutor.queryFromDatabase(BaseExecutor.java:324)
    at org.apache.ibatis.executor.BaseExecutor.query(BaseExecutor.java:156)
    at org.apache.ibatis.executor.CachingExecutor.query(CachingExecutor.java:109)
    at com.github.pagehelper.PageInterceptor.intercept(PageInterceptor.java:108)
    at org.apache.ibatis.plugin.Plugin.invoke(Plugin.java:61)
    at com.sun.proxy.$Proxy419.query(Unknown Source)
    at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:147)
    at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:140)
    at sun.reflect.GeneratedMethodAccessor490.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at org.mybatis.spring.SqlSessionTemplate$SqlSessionInterceptor.invoke(SqlSessionTemplate.java:426)
    at com.sun.proxy.$Proxy192.selectList(Unknown Source)
    at org.mybatis.spring.SqlSessionTemplate.selectList(SqlSessionTemplate.java:223)
    at org.apache.ibatis.binding.MapperMethod.executeForMany(MapperMethod.java:147)
    at org.apache.ibatis.binding.MapperMethod.execute(MapperMethod.java:80)
    at org.apache.ibatis.binding.MapperProxy.invoke(MapperProxy.java:93)
    at com.sun.proxy.$Proxy193.selectByExample(Unknown Source)
    at com.shizhuang.duapp.refund.infrastructure.db.dao.RefundOrderDao.getReturnBySubOrderNoList(RefundOrderDao.java:1049)
    at com.shizhuang.duapp.refund.infrastructure.db.dao.RefundOrderDao$$FastClassBySpringCGLIB$$41f7ca21.invoke(<generated>)
    at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218)
    at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:750)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
    at org.springframework.dao.support.PersistenceExceptionTranslationInterceptor.invoke(PersistenceExceptionTranslationInterceptor.java:139)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
    at org.springframework.aop.framework.adapter.MethodBeforeAdviceInterceptor.invoke(MethodBeforeAdviceInterceptor.java:56)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
    at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:93)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
    at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:689)
    at com.shizhuang.duapp.refund.infrastructure.db.dao.RefundOrderDao$$EnhancerBySpringCGLIB$$28f9b058.getReturnBySubOrderNoList(<generated>)
    at com.shizhuang.duapp.refund.application.service.refund.app.impl.QueryRefundDetailInBuyerOrderDetailService.hasRefund(QueryRefundDetailInBuyerOrderDetailService.java:147)
    at com.shizhuang.duapp.refund.interfaces.facade.refund.app.RefundOrderDesc2OldOrderDetailController.hasRefund(RefundOrderDesc2OldOrderDetailController.java:150)
    at com.shizhuang.duapp.refund.interfaces.facade.refund.app.RefundOrderDesc2OldOrderDetailController$$FastClassBySpringCGLIB$$da692b9e.invoke(<generated>)
    at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218)
    at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:750)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
    at org.springframework.aop.aspectj.MethodInvocationProceedingJoinPoint.proceed(MethodInvocationProceedingJoinPoint.java:88)
    at com.poizon.fusion.monitor.instrument.openfeign.aspect.FeignClientAspect.invoke(FeignClientAspect.java:109)
    at sun.reflect.GeneratedMethodAccessor486.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:644)
    at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:633)
    at org.springframework.aop.aspectj.AspectJAroundAdvice.invoke(AspectJAroundAdvice.java:70)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:175)
    at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:93)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
    at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:689)
    at com.shizhuang.duapp.refund.interfaces.facade.refund.app.RefundOrderDesc2OldOrderDetailController$$EnhancerBySpringCGLIB$$25d2f6d1.hasRefund(<generated>)
    at sun.reflect.GeneratedMethodAccessor497.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:190)
    at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:138)
    at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:105)
    at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:893)
    at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:798)
    at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87)
    at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1040)
    at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:943)
    at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1006)
    at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:909)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:665)
    at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:883)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:750)
    at io.undertow.servlet.handlers.ServletHandler.handleRequest(ServletHandler.java:74)
    at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:129)
    at com.shizhuang.duapp.dubbo.environment.ServletEnvironmentFilter.doFilter(ServletEnvironmentFilter.java:28)
    at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
    at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
    at com.alibaba.druid.support.http.WebStatFilter.doFilter(WebStatFilter.java:124)
    at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
    at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
    at org.springframework.boot.actuate.web.trace.servlet.HttpTraceFilter.doFilterInternal(HttpTraceFilter.java:88)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
    at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
    at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
    at com.shizhuang.duapp.sentinel.client.servlet.SentinelServletFilter.doFilter(SentinelServletFilter.java:90)
    at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
    at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
    at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:100)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
    at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
    at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
    at org.springframework.web.filter.FormContentFilter.doFilterInternal(FormContentFilter.java:93)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
    at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
    at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
    at org.springframework.web.filter.HiddenHttpMethodFilter.doFilterInternal(HiddenHttpMethodFilter.java:94)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
    at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
    at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
    at com.poizon.fusion.webmvc.logging.AccessLoggingFilter.doFilterInternal(AccessLoggingFilter.java:63)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
    at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
    at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
    at org.springframework.boot.actuate.metrics.web.servlet.WebMvcMetricsFilter.filterAndRecordMetrics(WebMvcMetricsFilter.java:114)
    at org.springframework.boot.actuate.metrics.web.servlet.WebMvcMetricsFilter.doFilterInternal(WebMvcMetricsFilter.java:104)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
    at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
    at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
    at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:201)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
    at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
    at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
    at com.poizon.fusion.monitor.instrument.spring.web.server.servlet.MonitorServletFilter.doFilter(MonitorServletFilter.java:170)
    at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
    at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
    at io.undertow.servlet.handlers.FilterHandler.handleRequest(FilterHandler.java:84)
    at io.undertow.servlet.handlers.security.ServletSecurityRoleHandler.handleRequest(ServletSecurityRoleHandler.java:62)
    at io.undertow.servlet.handlers.ServletChain$1.handleRequest(ServletChain.java:68)
    at io.undertow.servlet.handlers.ServletDispatchingHandler.handleRequest(ServletDispatchingHandler.java:36)
    at io.undertow.servlet.handlers.RedirectDirHandler.handleRequest(RedirectDirHandler.java:68)
    at io.undertow.servlet.handlers.security.SSLInformationAssociationHandler.handleRequest(SSLInformationAssociationHandler.java:132)
    at io.undertow.servlet.handlers.security.ServletAuthenticationCallHandler.handleRequest(ServletAuthenticationCallHandler.java:57)
    at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
    at io.undertow.security.handlers.AbstractConfidentialityHandler.handleRequest(AbstractConfidentialityHandler.java:46)
    at io.undertow.servlet.handlers.security.ServletConfidentialityConstraintHandler.handleRequest(ServletConfidentialityConstraintHandler.java:64)
    at io.undertow.security.handlers.AuthenticationMechanismsHandler.handleRequest(AuthenticationMechanismsHandler.java:60)
    at io.undertow.servlet.handlers.security.CachedAuthenticatedSessionHandler.handleRequest(CachedAuthenticatedSessionHandler.java:77)
    at io.undertow.security.handlers.AbstractSecurityContextAssociationHandler.handleRequest(AbstractSecurityContextAssociationHandler.java:43)
    at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
    at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
    at io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:269)
    at io.undertow.servlet.handlers.ServletInitialHandler.access$100(ServletInitialHandler.java:78)
    at io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:133)
    at io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:130)
    at io.undertow.servlet.core.ServletRequestContextThreadSetupAction$1.call(ServletRequestContextThreadSetupAction.java:48)
    at io.undertow.servlet.core.ContextClassLoaderSetupAction$1.call(ContextClassLoaderSetupAction.java:43)
    at io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:249)
    at io.undertow.servlet.handlers.ServletInitialHandler.access$000(ServletInitialHandler.java:78)
    at io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:99)
    at io.undertow.server.Connectors.executeRootHandler(Connectors.java:376)
    at io.uXNIO-1 task-44":
    at com.alibaba.jvm.sandbox.core.classloader.ClassLoadingLock.loadingInLock(ClassLoadingLock.java:53)
    - waiting to lock <0x0000000722c10c48> (a java.lang.Object)
    at com.alibaba.jvm.sandbox.core.classloader.RoutingURLClassLoader.loadClass(RoutingURLClassLoader.java:64)
    at java.lang.ClassLoader.loadClass(ClassLoader.java:352)
    at com.pandora.jvm.sandbox.repeater.plugin.core.impl.dewuext.TraceExtension.dewuTrace(TraceExtension.java:51)ndertow.server.HttpServerExchange$1.run(HttpServerExchange.java:830)
    at com.alibaba.ttl.TtlRunnable.run(TtlRunnable.java:51)
    at com.alibaba.ttl.TtlRunnable.run(TtlRunnable.java:55)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at java.lang.Thread.run(Thread.java:775)

Found 1 deadlock.

備註：

有一些令人頭疼的死鎖場景，比如類載入過程發生的死鎖，尤其是在框架大量使用自定義類載入時，因為往往不是在應用本身的程式碼庫中， jstack等工具也不見得能夠顯示全部鎖資訊。

4.2.3.3 dump檔案分析

執行緒XNIO-1

XNIO-1 task-44":
    at com.alibaba.jvm.sandbox.core.classloader.ClassLoadingLock.loadingInLock(ClassLoadingLock.java:53)
    - waiting to lock <0x0000000722c10c48> (a java.lang.Object)
    at com.alibaba.jvm.sandbox.core.classloader.RoutingURLClassLoader.loadClass(RoutingURLClassLoader.java:64)
    at java.lang.ClassLoader.loadClass(ClassLoader.java:352)
    at com.pandora.jvm.sandbox.repeater.plugin.core.impl.dewuext.TraceExtension.dewuTrace(TraceExtension.java:51)

執行緒com.alibaba.nacos.client.naming.updater

"com.alibaba.nacos.client.naming.updater":
    at java.lang.ClassLoader.checkCerts(ClassLoader.java:881)
    - waiting to lock <0x00000006bcf0de00> (a com.alibaba.jvm.sandbox.core.classloader.ModuleJarClassLoader)
    at java.lang.ClassLoader.preDefineClass(ClassLoader.java:662)
    at java.lang.ClassLoader.defineClass(ClassLoader.java:755)
    at java.security.SecureClassLoader.defineClass(SecureClassLoader.java:142)
    at java.net.URLClassLoader.defineClass(URLClassLoader.java:468)
    at java.net.URLClassLoader.access$100(URLClassLoader.java:74)
    at java.net.URLClassLoader$1.run(URLClassLoader.java:369)
    at java.net.URLClassLoader$1.run(URLClassLoader.java:363)
    at java.security.AccessController.doPrivileged(Native Method)
    at java.net.URLClassLoader.findClass(URLClassLoader.java:362)
    at com.alibaba.jvm.sandbox.core.classloader.RoutingURLClassLoader.access$400(RoutingURLClassLoader.java:22)
    at com.alibaba.jvm.sandbox.core.classloader.RoutingURLClassLoader$1.loadClass(RoutingURLClassLoader.java:91)
    at com.alibaba.jvm.sandbox.core.classloader.ClassLoadingLock.loadingInLock(ClassLoadingLock.java:55)
    - locked <0x0000000722c10c48> (a java.lang.Object)
    at com.alibaba.jvm.sandbox.core.classloader.RoutingURLClassLoader.loadClass(RoutingURLClassLoader.java:64)
    at java.lang.ClassLoader.loadClass(ClassLoader.java:406)
    - locked <0x00000006bd2a0000> (a com.pandora.jvm.sandbox.repeater.module.classloader.PluginClassLoader)
    at com.pandora.jvm.sandbox.repeater.module.classloader.PluginClassLoader.loadClass(PluginClassLoader.java:47)
    - locked <0x00000006bd2a0000> (a com.pandora.jvm.sandbox.repeater.module.classloader.PluginClassLoader)
    at java.lang.ClassLoader.loadClass(ClassLoader.java:352)
    at com.pandora.jvm.sandbox.repeater.plugin.exception.ExceptionEventListener.sample(ExceptionEventListener.java:34)

結合程式碼分析

執行緒XNIO-1

執行緒com.alibaba.nacos.client.naming.updater

4.2.3.4 結論

在高併發情況，類載入加鎖導致死鎖的

4.2.3.5 解決方案

提前載入RepeatCache和Tracer類

4.3 執行緒假死

執行緒假死是執行緒一直處於執行中，不退出。

定位問題的方法是：列印執行緒堆疊

業務中需要使用spark進行資料處理，因此將spark任務上傳到伺服器執行，但是main 執行緒一直hang住。通過列印執行緒堆疊，摘出其中的部分執行緒堆疊，如下：

"main" #1 prio=5 os_prio=0 tid=0x00007f0d98009800 nid=0x6240b runnable [0x00007f0d9ec49000]
   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:171)
    at java.net.SocketInputStream.read(SocketInputStream.java:141)
    at com.mysql.cj.protocol.ReadAheadInputStream.fill(ReadAheadInputStream.java:107)
    at com.mysql.cj.protocol.ReadAheadInputStream.readFromUnderlyingStreamIfNecessary(ReadAheadInputStream.java:150)
    at com.mysql.cj.protocol.ReadAheadInputStream.read(ReadAheadInputStream.java:180)
    - locked <0x000000072028a7b8> (a com.mysql.cj.protocol.ReadAheadInputStream)
    at java.io.FilterInputStream.read(FilterInputStream.java:133)
    at com.mysql.cj.protocol.FullReadInputStream.readFully(FullReadInputStream.java:64)
    at com.mysql.cj.protocol.a.SimplePacketReader.readHeaderLocal(SimplePacketReader.java:81)
    at com.mysql.cj.protocol.a.SimplePacketReader.readHeader(SimplePacketReader.java:63)
    at com.mysql.cj.protocol.a.SimplePacketReader.readHeader(SimplePacketReader.java:45)
    at com.mysql.cj.protocol.a.NativeProtocol.readMessage(NativeProtocol.java:514)
    at com.mysql.cj.protocol.a.NativeProtocol.readServerCapabilities(NativeProtocol.java:475)
    at com.mysql.cj.protocol.a.NativeProtocol.beforeHandshake(NativeProtocol.java:362)
    at com.mysql.cj.protocol.a.NativeProtocol.connect(NativeProtocol.java:1367)
    at com.mysql.cj.NativeSession.connect(NativeSession.java:133)
    at com.mysql.cj.jdbc.ConnectionImpl.connectWithRetries(ConnectionImpl.java:842)
    at com.mysql.cj.jdbc.ConnectionImpl.createNewIO(ConnectionImpl.java:823)
    - locked <0x0000000722c7fc40> (a com.mysql.cj.jdbc.ConnectionImpl)
    at com.mysql.cj.jdbc.ConnectionImpl.<init>(ConnectionImpl.java:448)
    at com.mysql.cj.jdbc.ConnectionImpl.getInstance(ConnectionImpl.java:241)
    at com.mysql.cj.jdbc.NonRegisteringDriver.connect(NonRegisteringDriver.java:198)
    at org.apache.spark.sql.execution.datasources.jdbc.connection.BasicConnectionProvider.getConnection(BasicConnectionProvider.scala:49)
    at org.apache.spark.sql.execution.datasources.jdbc.connection.ConnectionProvider$.create(ConnectionProvider.scala:68)
    - locked <0x0000000722c7fe18> (a org.apache.spark.security.SecurityConfigurationLock$)
    at org.apache.spark.sql.execution.datasources.jdbc.JdbcUtils$.$anonfun$createConnectionFactory$1(JdbcUtils.scala:62)
    at org.apache.spark.sql.execution.datasources.jdbc.JdbcUtils$$$Lambda$1606/936828380.apply(Unknown Source)
    at org.apache.spark.sql.execution.datasources.jdbc.JdbcRelationProvider.createRelation(JdbcRelationProvider.scala:48)
    at org.apache.spark.sql.execution.datasources.SaveIntoDataSourceCommand.run(SaveIntoDataSourceCommand.scala:46)
    at org.apache.spark.sql.execution.command.ExecutedCommandExec.sideEffectResult$lzycompute(commands.scala:70)
    - locked <0x0000000722c96c18> (a org.apache.spark.sql.execution.command.ExecutedCommandExec)
    at org.apache.spark.sql.execution.command.ExecutedCommandExec.sideEffectResult(commands.scala:68)
    at org.apache.spark.sql.execution.command.ExecutedCommandExec.doExecute(commands.scala:90)
    at org.apache.spark.sql.execution.SparkPlan.$anonfun$execute$1(SparkPlan.scala:180)
    at org.apache.spark.sql.execution.SparkPlan$$Lambda$1492/203829039.apply(Unknown Source)
    at org.apache.spark.sql.execution.SparkPlan.$anonfun$executeQuery$1(SparkPlan.scala:218)
    at org.apache.spark.sql.execution.SparkPlan$$Lambda$1516/376234567.apply(Unknown Source)
    at org.apache.spark.rdd.RDDOperationScope$.withScope(RDDOperationScope.scala:151)
    at org.apache.spark.sql.execution.SparkPlan.executeQuery(SparkPlan.scala:215)
    at org.apache.spark.sql.execution.SparkPlan.execute(SparkPlan.scala:176)
    at org.apache.spark.sql.execution.QueryExecution.toRdd$lzycompute(QueryExecution.scala:132)
    - locked <0x0000000722ca3c78> (a org.apache.spark.sql.execution.QueryExecution)
    at org.apache.spark.sql.execution.QueryExecution.toRdd(QueryExecution.scala:131)
    at org.apache.spark.sql.DataFrameWriter.$anonfun$runCommand$1(DataFrameWriter.scala:989)
    at org.apache.spark.sql.DataFrameWriter$$Lambda$1379/456240898.apply(Unknown Source)
    at org.apache.spark.sql.execution.SQLExecution$.$anonfun$withNewExecutionId$5(SQLExecution.scala:103)
    at org.apache.spark.sql.execution.SQLExecution$$$Lambda$1387/862090614.apply(Unknown Source)
    at org.apache.spark.sql.execution.SQLExecution$.withSQLConfPropagated(SQLExecution.scala:163)
    at org.apache.spark.sql.execution.SQLExecution$.$anonfun$withNewExecutionId$1(SQLExecution.scala:90)
    at org.apache.spark.sql.execution.SQLExecution$$$Lambda$1380/1008095885.apply(Unknown Source)
    at org.apache.spark.sql.SparkSession.withActive(SparkSession.scala:775)
    at org.apache.spark.sql.execution.SQLExecution$.withNewExecutionId(SQLExecution.scala:64)
    at org.apache.spark.sql.DataFrameWriter.runCommand(DataFrameWriter.scala:989)
    at org.apache.spark.sql.DataFrameWriter.saveToV1Source(DataFrameWriter.scala:438)
    at org.apache.spark.sql.DataFrameWriter.saveInternal(DataFrameWriter.scala:415)
    at org.apache.spark.sql.DataFrameWriter.save(DataFrameWriter.scala:301)
    at org.apache.spark.sql.DataFrameWriter.jdbc(DataFrameWriter.scala:817)
    at com.pandora.spark.task.job.EsSparkSqlRecordDataHandle.main(EsSparkSqlRecordDataHandle.java:111)

   Locked ownable synchronizers:
    - None

通過對上面的堆疊分析可以發現main執行緒的狀態為：RUNNABLE，且阻塞在方法

ReadAheadInputStream.fill(ReadAheadInputStream.java:107)，通過檢視配置發現沒有配置相關connectTimeout和socketTimeout等引數，通過配置上面超時引數之後，就出現其它的報錯。

05 系統執行越來越慢

5.1 概述

系統緩慢一般是由於如下幾個原因造成的:

堆記憶體洩漏造成的記憶體不足，導致系統越來越慢，直到停止。
Xmx設定太小造成的堆記憶體不足，導致系統越來越慢，直到停止。
系統出現死迴圈，消耗了過多的CPU。參考上一節的內容
資源不足導致性系統執行越來越慢。

5.2 記憶體洩漏

5.2.1 定位方式

判斷系統是否存在記憶體洩漏的依據是：如果系統存在記憶體洩漏，那麼在完成垃圾回收之後的記憶體值應該持續上升。如果在現場能觀察到這個現象，說明系統存在記憶體洩漏。當懷疑一個系統存在記憶體洩漏的時候，首先使用FULL GC資訊對記憶體洩漏進行一個初步確認，確認系統是否存在記憶體洩漏。只檢查完全垃圾回收後的可用記憶體值是否一直再增大，步驟如下:

首先擷取系統穩定執行以後的GC資訊(如初始化已經完成)，這個非常重要，非穩定執行期的資訊無分析價值，因為你無法確認記憶體的增長是正常的增長還是由於記憶體洩漏導致的非正常增長。
過濾出FULL GC的行。只有FULL GC的行才有分析價值。因為完成GC後的記憶體是當前Java物件真正使用的記憶體數量。一般系統會有兩種可能:
- 如果完成垃圾回收後的記憶體持續增長，大有一直增長到Xmx設定值的趨勢，那麼這個時候基本上就可以斷定系統存在記憶體洩漏。
- 如果當前完成垃圾回收後記憶體增長到一個值之後，又能回落，總體上處於一個動態平衡，那麼記憶體洩漏基本可以排除。

通過如上記憶體使用趨勢分析之後，基本上就能確定系統是否存在堆記憶體洩漏。當然這種GC資訊分析只能告訴你係統是否存在堆記憶體洩漏，但具體哪裡洩漏，它是無法告訴你的。記憶體洩漏的的精確定位，是要找到記憶體洩漏的具體位置，需要通過dump記憶體堆疊，通過其記憶體堆疊分析工具才能找到真正導致記憶體洩漏的類或者物件。

5.2.2 案例

jvm 監控：

記憶體堆疊分析：

通過記憶體堆疊，定位到如下程式碼

原因猜測：

1.通過jvm的記憶體監控上看，這個洩漏幾天，而且洩漏的速度是一條直線(近似勻速)，如果是業務呼叫導致記憶體洩漏應該會有起伏，猜測可能是定時任務呼叫dubbo的邏輯。

驗證

5.3 資源不足

5.3.1 特點和定位方法

特點：如資源不足，那麼會存在大量的執行緒在等待資源，列印的執行緒堆疊如果具有這個特徵，那麼就說明該系統資源是瓶頸。對於資源不足導致效能下降，列印出的執行緒堆疊中會存在大量的執行緒停在同樣的呼叫上下文中。

資源不足或者資源使用不恰當，表現出來往往是一個效能問題。系統越來越慢，並最終停止響應。遇到系統變慢等問題，定位問題的方法是列印執行緒堆疊。

5.3.2 可能的原因

5.3.3 案例

備註：當時沒有對服務列印執行緒堆疊。

從監控上看，資料庫的連線池已經打滿(連線池當時配置的60)。從客戶端角度來看，當時客戶端單機的cpu、memory都沒有使用滿，從服務端(mysql)來看，db沒有任何異常。因此可以看出瓶頸卡在資料庫連線上。

從具體的業務場景來分析，該問題有兩種解決方案：

方案一：資源隔離法。因為從該業務上看，只有流量上報和回放上報的介面的qps高，而平臺的其他介面qps低，並且都是平臺後臺的基本操作的方法。將流量上報和回放上報使用一個資料庫連線池，平臺的其他介面使用另外一個連線池。

方案二：提高資料庫的連線池，該方式有點缺點是會影響後臺的頁面操作, 出現頁面卡頓的情況。

06 效能分析

6.1 概述

執行緒堆疊進行效能分析使用場景：多執行緒場合下的效能瓶頸定位。特別是鎖的使用不當，導致的效能瓶頸。

改善效能意味著用更少的資源做更多的事。當執行緒的執行因某個特定資源受阻時，稱之為受限該資源：受限資料庫、受限對端的處理能力。

效能調優的終極目標是系統的CPU利用率接近100%。如果系統的CPU沒有被充分利用，那麼可能存在如下問題：施加的壓力不足，可能被測試的系統沒有被加入到足夠的壓力(負載)，這時候可以通過增加壓力，檢測系統的響應時間、服務失敗率和CPU使用率情況。如果增加壓力，系統開始出現部分服務失敗，系統的響應時間變慢，或者CPU的使用率無法再上升，那麼此時的壓力應該是系統的飽和壓力。即此時的能力是系統當前的最大能力。

系統存在瓶頸：當系統在飽和壓力下，如果CPU的使用率沒有接近100%，那麼說明這個系統效能的還有提升的空間。如果系統存在如下問題，那麼可以使用執行緒堆疊查詢效能瓶頸的方法進行問題定位。

持續執行緩慢。時常發現應用程式執行緩慢。通過改變環境因子(如資料庫連線數等)也無法有效提升整體響應時間
系統效能隨時間的增加逐漸下降。在負載穩定的情況下，系統執行時間越長速度越慢。可能是由於超出某個閾值範圍，系統執行頻繁出錯從而導致系統死鎖或崩潰。
系統效能隨負載的增加逐漸下降。隨著使用者數目的增多，應用程式的執行越發緩慢。若干使用者退出系統，應用程式便能夠恢復正常執行狀態。

6.2 常見的效能瓶頸

由於不恰當的同步導致的資源爭用
- 不相關的兩個函式，共用了一個鎖或者不同的共享變數共用了一個鎖，無謂地製造出了資源爭用
- 鎖的粒度過大，對共享資源訪問完成之後，沒有將後續的程式碼放在synchronized同步程式碼塊之外。
sleep 的濫用：sleep只適合用在等待固定時長的場合，如果輪詢程式碼中夾雜著sleep()呼叫，這種設計必然是一種糟糕的設計。這種設計在某些場合下會導致嚴重的效能瓶頸。
String + 濫用

不恰當的執行緒模型：在多執行緒場合下，如果執行緒模型不恰當，也會使效能低下。
效率低下的SQL語句或者不恰當的資料庫設計
執行緒數量不足：在使用執行緒池的場合，如果執行緒池的執行緒配置太少，也會導致效能低下。
記憶體洩漏導致的頻繁GC：記憶體洩漏會導致GC越來越頻繁，而GC操作是CPU密集型操作，頻繁GC會導致系統整體效能嚴重下降。

6.3 壓測發現效能瓶

效能瓶頸的特徵

當前的效能瓶頸只有一處，只有當解決的這一塊，才知道下一處。沒有解決當前的效能瓶頸，下一處效能瓶頸是不會出現的
效能瓶頸是動態的，低負載下不是瓶頸的地方，在高負載下可能成為瓶頸。

6.4 如何通過執行緒堆疊識別效能瓶頸

一個系統一旦出現效能瓶頸，從堆疊上分析，有如下三種最為典型的堆疊特徵:

絕大多數執行緒的堆疊都表現為在同一個呼叫上下文上，且只剩下非常少的空閒執行緒。可能的原因如下:

執行緒的數量過少
鎖的粒度過大導致的鎖競爭。
資源競爭(如資料庫連線池中連線不足，導致有些企圖獲取連線的執行緒被阻塞)
鎖範圍內有大量耗時操作(如大量的磁碟IO)，導致鎖爭用。
遠端通訊的對方處理緩慢(甚至導致socket緩衝區寫滿)，如資料庫側的SQL程式碼效能低下。

絕大多數執行緒處於等待狀態，只有幾個工作的執行緒，總體效能上不去。可能的原因是，系統存在關鍵路徑，在該關鍵路徑上沒有足夠的能力給下個階段輸送大量的任務，導致其它地方空閒。如在訊息分發系統，訊息分發一般是一個執行緒，而訊息處理是多個執行緒，這時候訊息分發是瓶頸的話，那麼從執行緒堆疊就會觀察到上面提到的現象:即該關鍵路徑沒有足夠的能力給下個階段輸送大量的任務，導致其它地方空閒。
執行緒總的數量很少。導致效能瓶頸的原因與上面的類似。這裡執行緒很少，是由於某些線程池實現使用另一種設計思路，當任務來了之後才new出執行緒來，這種實現方式下，執行緒的數量上不去，就意味有在某處關鍵路徑上沒有足夠的能力給下個階段輸送大量的任務，從而不需要更多的執行緒來處理。

6.5 執行緒堆疊進行效能分析總結

07 總結

本文是在閱讀《java問題定位技術》等相關書籍和文件，結合發生在生產環境下的真實案例下進行梳理和總結，一方面提升問題排查能力，同時也對其進行總結和提煉，另外一方面希望通過總結和提煉本文能夠幫助到大家提升問題排查能力和對執行緒堆疊的充分認識。

08 參考資料

《java問題定位技術》

文/小寶

關注得物技術，做最潮技術人

如何利用執行緒堆疊定位問題