執行緒池滿Thread pool exhausted排查和解決
發生{ThreadpoolisEXHAUSTED}時的伺服器日誌：
產生原因：
- 大併發導致配置的執行緒不夠用
在初始時候，dubbo協議配置，我是使用dubbo預設的引數，dubbo執行緒池預設是固定長度執行緒池，大小為200。一開始出現執行緒池滿的問題，本以為是併發量大導致的，沒做太多關注，運維也沒有把相應的日誌dump下來，直接重啟了。所以一開始只是優化了dubbo的配置。調大固定執行緒池數量為400，並且將dispatcher轉發由預設的配置"all"改為message。all表示所有訊息都派發到執行緒池，包括請求，連線事件，斷開事件，心跳等。message表示只有請求響應訊息派發到執行緒池，其他連線斷開事件，心跳等訊息，直接在IO執行緒上執行。同時開啟了訪問日誌記錄，觀察是不是有出現其他消費系統有短時間大併發呼叫介面的情況。
accesslog設為true，將向logger中輸出訪問日誌，也可填寫訪問日誌檔案路徑，直接把訪問日誌輸出到指定檔案
<dubbo:protocol name="dubbo" port="33112" accesslog="true" dispatcher="message" threads="500"/><!--開啟訪問日誌記錄 -->- 呼叫外部介面程式出現阻塞，等待時間過長
通過日誌觀察幾天下來，大概每天介面的呼叫量在60~70萬左右，瞬時併發呼叫量也就十幾，理論上不應該出現執行緒池滿的情況，所以這時候就懷疑是不是有出現執行緒Blocked的情況
定位方式：
- 通過運用統計發生異常時間段內的介面TPS/QPS，來定位是否大併發導致的執行緒配置不夠用
- 正常來說需要在程式在調外部介面時需要列印異常日誌，可以通過查詢log檔案的方式，定位是否是Blocked導致的
- 通過切面類日誌列印日誌來定位問題，具體如下：
import com.alibaba.dubbo.common.Constants; import com.alibaba.dubbo.common.extension.ExtensionLoader; import com.alibaba.dubbo.common.store.DataStore; import org.aspectj.lang.annotation.After; import org.aspectj.lang.annotation.Aspect; import org.aspectj.lang.annotation.Before; import org.aspectj.lang.annotation.Pointcut; import org.slf4j.Logger; import org.slf4j.LoggerFactory; import org.springframework.stereotype.Component; import java.util.Map; import java.util.concurrent.ExecutorService; import java.util.concurrent.ThreadPoolExecutor; /** * @ClassName DubboAOP * @Description * @Author libo * @Date 2019/7/25 11:46 * @Version 1.0 **/ @Component @Aspect public class DubboAOP { private static final Logger logger = LoggerFactory.getLogger(DubboAOP.class); @Pointcut("execution(* com.ncarzone.oa.biz.facade.EmployeeServiceFacadeImpl.*(..))") public void pointCut(){ } @Before("pointCut()") public void before(){ logger.info("======before()======"+Thread.currentThread().getName()); printDubboThreadInfo(); } @After("pointCut()") public void after(){ printDubboThreadInfo(); logger.info("======after()==="+Thread.currentThread().getName()); } private void printDubboThreadInfo(){ DataStore dataStore = ExtensionLoader.getExtensionLoader(DataStore.class).getDefaultExtension(); Map<String, Object> executors = dataStore.get(Constants.EXECUTOR_SERVICE_COMPONENT_KEY); for(Map.Entry<String,Object> entry : executors.entrySet()){ ExecutorService executor = (ExecutorService)entry.getValue(); if(executor instanceof ThreadPoolExecutor){ ThreadPoolExecutor tp = (ThreadPoolExecutor) executor; logger.info("===dubboThread======"+tp.toString()); } } } }
可以根據我們寫的切面的日誌列印資訊可以看到活躍執行緒一直在增加，即一個新的請求過來之後，就沒有下文了，執行緒沒有執行完，自然就無法被回收到執行緒池中。因而判斷極有可能是執行緒出現阻塞或者是一直在等待的情況。所以這次直接讓運維人員幫忙dump下執行緒日誌。 jstack + pid xxx.log
通過執行緒dump日誌，我們可以看到出現了大量執行緒的等待，dump中記錄了出問題的程式碼之處。通過分析，可知在獲取redis連線，去取redis資料的時候，由於沒有拿到redis的連線，即getResource方法執行卡住了，同時專案的redis配置又沒有設定獲取連線的最大超時時間，通過redis原始碼我們可知，如果沒有設定，則預設是-1，即可能會出現長時間等待獲取連線的情況。它會從空閒的連線佇列(private final LinkedBlockingDeque<PooledObject<T>> idleObjects)中取第一個，因為用的是takefirst()方法,即如果沒有空閒連線，則會一直等待。而pollFirst()，超時則會返回成功或失敗
因而我們需要在專案的jedis連線池配置中增加MaxWaitMillis配置，我這裡設定的是500毫秒
現在知道了是此種情況導致的，但是因為我專案裡配置的最大分配連線是600，而專案裡使用redis的地方並不多，理論上不應該出現redis連線池滿的情況，應該還是有其他問題。所以繼續看了thread dump日誌，發現了問題點所在，因為之前和釘釘的開放平臺對接，做了一個回撥介面，但偶爾會出現重複回撥的情況，所以就做了一個redis鎖，來避免這個問題。但是這邊程式碼有嚴重的問題，如果jedis設定快取不成功，則會進入執行緒休眠（Thread.sleep(1000)），執行緒休眠是不會釋放所持有的連線的，而這個地方就陷入了死迴圈。導致該連線被一直佔用，從而連線池中可用的連線越來越少，直到被佔滿
將此處程式碼做了修改.使用sleep雖然保證了執行緒安全，但是影響效能。修改為根據具有唯一性的欄位進行加鎖