一、背景

歷史原因，當前有一個服務專門用于處理mq消息，mq使用的阿里云rocketmq，sdk版本1.2.6（2016年）。隨著業務的發展，該應用上的consumer越來越多，接近200+，導致該應用所在的ecs長時間load高，頻繁報警。

二、現象分析

該應用所在的ecs服務器load長期飆高（該ecs上只有一個服務），但cpu、io、內存等資源利用率較低，系統負載參考下圖：

ECS配置：4核8G
物理cpu個數=4
單個物理CPU中核（core）的個數=1
單核多處理器
復制代碼

在系統負荷方面，多核CPU與多CPU效果類似，考慮系統負荷的時候，把系統負荷除以總的核心數，只要每個核心的負荷不超過1.0，就表明正常運行。通常，n核cpu時，load<n，系統負載都屬于正常情況。

套用以上規則：先觀察load_15m和load_5m，load基本保持在3-5之間，說明系統中長期負載保持在一個較高的量級。再觀察load_1m可以看出，波動很大，并且很多時間段內遠大于cpu核心數。短期內繁忙，中長期內緊張，很可能是一個擁塞的開始。

三、原因定位

排查導致load高的原因

tips：系統load高，不代表cpu資源不足。Load高只是代表需要運行的隊列累計過多。但隊列中的任務實際可能是耗cpu的，也可能是耗i/0及其他因素的
復制代碼

圖中load_15,load_5,load_1均大于核心數4，超負荷運行

用戶進程=8.6%
內核進程 =9.7%
空閑=80%
I/O等待所占用的cpu時間百分比=0.3%

通過上圖CPU、內存、IO使用情況，發現三者都不高， CPU使用率低負載高，排除cpu資源不足導致load高的可能性。

再通過vmstat查看進程、內存、I/O等系統整體運行狀態，如下圖：

從結果上看，io的block in和block out 并不頻繁，但是system的中斷數（in)、上下文切換（cs）特別頻繁，進程上下文切換次數較多的情況下，很容易導致CPU將大量的時間耗費在寄存器、內核棧、以及虛擬內存等資源的保存和恢復上，進而縮短了真正運行進程的時間造成load高。

CPU寄存器，是CPU內置的容量小、但速度極快的內存。程序計數器，則是用來存儲CPU正在執行的指令的位置，或者即將執行的下一條指令的位置。
他們都是CPU在運行任何任務前，必須依賴的環境，因此也被叫做CPU上下文。

CPU上下文切換，就是先把前一個任務的CPU上下文(也就是CPU寄存器和程序計數器)保存起來，然后加載新任務的上下文，到這些寄存器和程序計數器，
最后再跳轉到程序計數器所指的新位置，運行新任務。
復制代碼

排查大方向：頻繁的中斷以及線程切換（由于該臺ecs上只存在一個JAVA服務，主要排查該進程）

通過vmstate只能查看總的cpu上下文切換，可通過pidstat命令查看線程層面的上下文切換信息 pidstat -wt 1（下圖拉的是9s的數據，總共36w次，平均每秒4w次）

觀察上圖，很容易發現兩個現象：

第一個是java線程特別多
第二個是很有規律的出現每秒上下文切換100+次的線程。（具體原因后面分析）

確認一下這些java線程的來源,查看該應用進程下的線程數 cat /proc/17207/status

線程數9749（非高峰）

排查方向：

線程數過多
部分線程每秒上下文切換次數過高

先排查主要原因，即部分線程上下文切換次數過高拉一下線上該進程的堆棧信息，然后找到切換次數達到100+/每秒的線程id，把線程id轉成16進制后在堆棧日志中檢索

從上圖可以看到進程狀態TIME_WAITING,問題代碼，
com.alibaba.ons.open.trace.core.dispatch.impl.AsyncArrayDispatcher，多查幾個其他上下文切換頻繁的線程，堆棧信息基本相同。

再排查線程數過多的問題，分析堆棧信息會發現存在大量ConsumeMessageThread線程（通信、監聽、心跳等線程先忽略）

通過線程名稱，在rocketmq源碼中搜索基本能定位到下面這部分代碼

通過兩段代碼，基本可以定位到問題出現在mq consumer初始化以及啟動的流程，后續根據代碼進行分析。

四、代碼分析

線程數過多代碼層面排查，從上面代碼截圖可以看到，ConsumeMessageThread_由線程池進行管理，再看一下線程池的關鍵參數，核心線程數this.defaultMQPushConsumer.getConsumeThreadMin()、最大線程數this.defaultMQPushConsumer.getConsumeThreadMax()、無界隊列LinkedBlockingQueue

ps：由于線程池隊列用的LinkedBlockingQueue無界隊列，LinkedBlockingQueue的容量默認大小是Integer.Max，在任務沒有填滿這個容量之前不會創建新的工作線程，因此最大線程數沒有任何作用。
復制代碼

再看一下message-consumer對核心線程數以及最大線程數的配置，發現代碼層面沒有特殊配置，因此使用系統默認值，即下圖

至此，大致可以定位到線程數過多的原因：

由于未指定消費線程數量（ConsumeThreadNums），采用系統默認核心線程數20，最大線程數64.每個consumer初始化的時候都會創建一個核心線程數等于20的線程池，即大概率每個consumer都會存在20個線程消費消息，導致線程數飆升（20*consumer個數）,但發現這些消費線程大部分都處于sleep/wait狀態，對上下文切換影響不大。

線程上下文切換次數過高代碼層面排查：在rocketmq源碼中無法搜索到該段代碼，該應用使用阿里云sdk，在sdk中檢索，查看上下文以及調用鏈路，會發現這段代碼屬于軌跡回傳模塊。

結合代碼分析一下軌跡回傳模塊的流程（AsyncArrayDispatcher），總結如下：

在sdk源碼中定位線程堆棧日志中的代碼，如下：

從這段代碼以及堆棧信息可以看到問題出現在traceContextQueue.poll(5,TimeUnit.MILLISECONDS);其中traceContextQueue為有界阻塞隊列，poll時，如果隊列為空，會阻塞一定時間，因此會導致線程在running和time_wait之間進行頻繁切換。

至于為什么要用poll(5,TimeUnit.MILLISECONDS)而不是take()，個人認為可能是為了減少網絡io，5ms批量取一次丟到線程池批量上報，避免單個軌跡頻繁上報？

poll()方法會返回隊列的第一個元素，并刪除；如果隊列為空，則返回null，并不會阻塞當前線程；出隊的邏輯調用的是 dequeue()方法，此外，它還有一個重載的方法，poll(long timeout, TimeUnit unit)，如果隊列為空，則會等待一段時間
復制代碼

軌跡隊列traceContextQueue使用的是ArrayBlockingQueue，一個有界的阻塞隊列，內部使用一個數組來存放元素，通過鎖來實現并發訪問的，也是按照 FIFO 的原則對元素進行排列。

通過上面的代碼可以看到，其通過reentrantLock 來實現并發的控制，ReentrantLock 提供了公平鎖與非公平鎖的實現，但ArrayBlockingQueue默認情況下，使用的非公平鎖，不保證線程線程公平的訪問隊列。

所謂的公平是指阻塞的線程，按照阻塞的先后順序訪問隊列，非公平是指當隊列可用的時候，阻塞的線程都可以有爭奪線程訪問的資格，有可能先阻塞的線程最后才能訪問隊列。
復制代碼

由于每個consumer都只開了一個軌跡分發線程，所以這部分不存在競爭。

再看一下ArrayBlockingQueue的阻塞實現原理

通過上面這部分代碼可以看到阻塞最終是通過park方法實現，unsafe.park是個native方法

park這個方法會阻塞當前線程，當以下4種情況中的一種發生時，該方法才會返回

與park對應的unpark執行或已經執行時。
線程被中斷時
等待完time參數指定的毫秒數時
異?，F象發生

至此，系統線程切換以及中斷頻繁原因總結如下：

阿里云sdk中軌跡回發模塊，一個consumer有一個分發線程和一個軌跡隊列以及一個軌跡數據回發線程池，分發線程從軌跡隊列中取，取不到則阻塞5ms，取到塞到軌跡數據回發線程池，然后數據上報。過多的分發線程頻繁在running和time_wait狀態進行切換，導致系統load高。由于代碼層面未設置每個consumer消息消費的最大最小線程數，導致每個consumer都會開20個核心線程進程消息消費，導致線程數量過多消耗系統資源以及空跑。

五、優化方案

結合以上原因，進行針對性優化

代碼層面針對每個consumer設置線程數配置項，consumer可根據承載的業務等實際情況設置核心線程數，減少整體的線程數目，避免大量線程空跑。
以上分析用的是阿里云ons 1.2.6的版本，當前已經迭代到了1.8.5版本，通過分析1.8.5版本的軌跡回傳模塊的源碼，發現對軌跡回傳增加了開關，配置軌跡回傳使用單個線程（單例），即全部consumer使用一個分發線程、一個軌跡有界隊列、一個軌跡上報線程池來處理，可以考慮驗證通過后升版本。