記5.28大促壓測的效能優化—執行緒池相關問題----一下子專到了太細節的地方,忽視了整體的架構...

weixin_34037977發表於2017-06-05

目錄:

1.環境介紹

2.症狀

3.診斷

4.結論

5.解決

6.對比java實現

廢話就不多說了,本文分享下博主在5.28大促壓測期間解決的一個效能問題,覺得這個還是比較有意思的,值得總結拿出來分享下。

博主所服務的部門是作為公共業務平臺,公共業務平臺支援上層所有業務系統(2C、UGC、直播等)。平臺中核心之一的就是訂單域相關服務,下單服務、查單服務、支付回撥服務,當然結算頁暫時還是我們負責,結算頁負責承上啟下進行下單、結算、跳支付中心。每次業務方進行大促期間平臺都要進行一次常規壓測,做到心裡有底。

在壓測的上半場,陸續的解決一些不是太奇怪的問題,定位到問題時間都在計劃內。下單服務、查單服務、結算頁都順利壓測通過。但是到了支付回撥服務壓測的時候,有個奇怪的問題出現了。

1.環境介紹

我們每年基本兩次大促,5.28、雙12。兩次大促期間相隔時間也就只有半年左右,所以每次大促壓測都會心裡有點低,基本就是摸底檢查下。因為之前的壓測效能在這半年期間一般不會出現太大的效能問題。這前提是因為我們每次釋出重大的專案的時候都會進行效能壓測,所以壓測慢慢變得常規化、自動化,遺漏的效能問題應該不會太多。效能指標其實在平時就關注了,而不是大促才來臨時抱佛腳,那樣其實為時已晚,只能拆東牆補西牆。

應用伺服器配置,物理機、32core i7 64位、168g、千兆網路卡、壓測網路頻寬千兆、IIS 7.5、.NET 4.0,這臺壓測伺服器還是很強的。

我們本地會用JMeter進行問題排查。由於這篇文章不是講怎麼做效能壓測的,所以其他跟本篇文章關係的不大的情況就不介紹了。包括壓測網路隔離、壓測機器的配置和節點數等。

我們的要求,頂層服務在200併發下,平均響應時間不能超過50毫秒,TPS要到3000左右。一級服務,也就是最底層服務的要求更高,商品系統、促銷系統、卡券系統平均響應時間基本保持在20毫秒以內才能接受。因為一級服務的響應速度直接決定了上層服務的響應速度,這裡還要去掉一些其他的呼叫開銷。 

2.症狀

這個效能問題的症狀還是比較奇怪的,情況是這樣的:200併發、2000loop,40w的呼叫量。一開始前幾秒速度是比較快的,基本上TPS到了2500左右。伺服器的CPU也到了60左右,還是比較正常的,但是幾秒過後處理速度陡降,TPS慢慢在往下掉。從伺服器的監控中發現,伺服器的CPU是0%消耗。這很嚇人,怎麼突然不處理了。TPS掉到100多了,顯然會一直掉下去。等了大概不到4分鐘,一下子CPU又上來了。TPS可以到2000左右。

我們仔細分析檢視,首先JMeter的吞吐量的問題,吞吐量是按照你的請求平均響應時間計算的,所以這裡看起來TPS是慢慢在減慢其實已經基本停止了。如果你的平均響應時間為20毫秒,那麼在單位時間內你的吞吐量是基本可以計算出來的。

症狀主要就是這樣的,我們接下來對它進行診斷。

3.診斷

開始通過走查程式碼,看能不能發現點什麼。

這是支付回撥服務,程式碼的前後沒有太多的業務處理,鑑權檢查、訂單支付狀態修改、觸發支付完成事件、呼叫配送、周邊業務通知(這裡有一部分需要相容老程式碼、老介面)。我們首先主要是檢視對外依賴的部分,發現有redis讀寫的程式碼,就將redis的部分程式碼註釋掉在進行壓測試試看。結果一下子就正常了,這就比較奇怪了,redis是我們其他壓測服務共用的,之前壓測怎麼沒有問題。沒管那麼多了,可能是程式碼的執行序列不同,在併發領域裡面,這也說得通。

我們再通過列印redis執行的時間,看處理需要多久。結果顯示,處理速度不均勻,前面的很快,後面的時間都在5-6秒,雖然不均勻但是很有規律。

所以我們都認為是redis的相關問題,就開始一頭扎進去檢查redis的問題了。開始對redis進行檢查,首先是開啟Wireshark TCP連線監控,檢查鏈路、redis伺服器的Slowlog檢視處理時間。redis客戶端庫的原始碼檢視(redis客戶端排除原生的StackExhange.Redis的有兩層封裝,一共三層),重點關注有鎖的地方和thread wait的地方。同時排查網路問題,再進行壓測的時候ping redis伺服器看是否有延遲。(此時是晚上21點左右,這個時候的大腦情況大家都懂的。)

就是這樣地毯式的搜查,以為是肯定能定位到問題。但是我們卻忽視了程式碼的層次結構,一下子專到了太細節的地方,忽視了整體的架構(指開發架構,因為程式碼不是我們寫的,對程式碼周邊情況不是太瞭解)。

先看redis伺服器的建立情況,tcp抓包檢視,連線建立正常,沒有丟包,速度也很快。redis的處理速度也沒問題,slowlog檢視基本get key也就1毫秒不到。(這裡需要注意,redis的處理時間還包括佇列裡等待的時間。slowlog只能看到redis處理的時間,看不到blocking的時間,這裡面還包括redis的command在客戶端佇列的時間。)

所以列印出來的redis處理時間很慢,不純粹是redis伺服器的處理時間,中間有幾個環節需要排查的。

經過一番折騰,排查,問題沒定位到,已是深夜,精力嚴重不足了,也要到地鐵最後一班車發車時間了,再不走趕不上了,下班回家,上到最後一班地鐵沒耽誤三分鐘~~。

重整思路,第二天繼續排查。

我們定位到redis客戶端的連線是可以先預熱的,在global application_begin啟動的時候先預熱好,然後效能一下子也正常了。

範圍進一步縮小,問題出在連線上,這裡我們又反思了(一夜覺睡過了,腦子清醒了),那為什麼我們之前的壓測沒出現過這個問題。對技術狂熱愛好的我們,哪能善罷甘休。此時問題算是解決了,但是背後所涉及到的相關線索穿不起來,總是不太舒服。(中場休息片刻,已是第二天的下午快傍晚了~~。)技術人員要有這種征服欲,必須搞清楚。

我們開始還原現場,然後開始出大招,開始dump程式檔案,分不同的時間段,抓取了幾份dump檔案down到本地進行分析。

首先檢視了執行緒情況,!runaway,發現大多數執行緒執行時間都有點長。接著切換到某個執行緒中~xxs,檢視執行緒呼叫堆疊。發現在等一把monitor鎖。同時切換到其他幾個執行緒中檢視下是不是都在等待這把鎖。結果確實都在等這把鎖。

結論,發現一半的執行緒都在等待moniter監視器鎖,隨著時間增加,是不是都在等待這把鎖。這比較奇怪。

這把鎖是redis庫的第三層封裝的時候用來lock獲取redis connectioin時候用的。我們直接註釋掉這把鎖,繼續壓測繼續dump,然後又發現一把monitor,這把鎖是StackExchange.Redis中的,程式碼一時半會無法消化,只查了主體程式碼和周邊程式碼情況,沒有時間檢視全域性情況。(因為時間緊迫)。暫且完全信任第三方庫,然後檢視redis connection string 的各個引數,是不是可以調整超時時間、連線池大小等。但是還是未能解決。

回過頭繼續檢視dump,檢視了下CLR連線池,!ThreadPool,一下子看到問題了。

1

繼續檢視其他幾個dump檔案,Idle都是0,也就是說CLR執行緒池沒有執行緒來處理請求了,至少CLR執行緒池的建立速率和併發速率不匹配了。

CLR執行緒池的建立速率一般是1秒2個執行緒,執行緒池的建立速率是否存在滑動時間不太清楚。執行緒池的大小可以通過 C:\Windows\Microsoft.NET\Framework64\v4.0.30319\Config\machine.config 配置來設定,預設是自動配置的。最小的執行緒數一般是當前機器的CPU 核數。當然你也可以通過ThreadPool相關方法來設定,ThreadPool.SetMaxThreads(), ThreadPool.SetMinThreads()。

然後我們繼續排查程式碼,發現程式碼中有用Action的委託的地方,而這個Action是處理非同步程式碼的,上面說的redis的讀寫都在這個Action裡面的。一下我們明白了,所有的線索都連起來了。

4.結論

.NET CLR執行緒池是共享執行緒池,也就是說ASP.NET、委託、Task背後都是一個執行緒池在處理。執行緒池分為兩種,Request執行緒池、IOCP執行緒池(完成埠執行緒池)。

我們現在理下線索:

1.從最開始的JMeter壓測吞吐量慢慢變低是個假象,而此時處理已經全面停止,伺服器的CPU處理為0%。肉眼看起來變慢是因為請求延遲時間增加了。

2.redis的TCP鏈路沒問題,Wireshark檢視沒有任何異常、Slowlog沒有問題、redis的key comnand慢是因為blocking住了。

3.其他服務壓測之所有沒問題是因為我們是同步呼叫redis,當首次TCP連線建立之後速度會上來。

4.Action看起來速度是上去了,但是所有的Action都是CLR執行緒池中的執行緒,看起來快是因為還沒有到CLR執行緒池的瓶頸。

1
2
3
4
5
6
7
8
9
Action asyncAction = () =>
           {
               //讀寫redis
               //傳送郵件
               //...
 
           };
 
asyncAction();

5.JMeter壓測的時候沒有延遲,在壓測的時候程式沒有預熱,導致所有的東西需要初始化,IIS、.NET等。這些都會讓第一次看起來很快,然後慢慢下降的錯覺。

總結:首次建立TCP連線是需要時間的,此時併發過大,所有的執行緒在wait,wait之後CPU會將這些執行緒交換出去,此時是明顯的所執行緒上下文切換過程,是一部分開銷。當CLR執行緒池的執行緒全部耗光吞吐量開始陡降。每次呼叫其實是開啟力了兩個執行緒,一個處理請求的Request,還有一個是Action委託執行緒。當你以為執行緒還夠的時候,其實執行緒池已經滿了。

5.解決

針對這個問題我們進行了佇列化處理。相當於在CLR執行緒池基礎上抽象一個工作佇列出來,然後佇列的消費執行緒控制在一定數量之內,初始化的時候預設一個執行緒,會提供介面建立頂多6個執行緒。這樣當佇列的處理速度跟不上的時候可以呼叫。大致程式碼如下(已進行適當的修改,非原始碼模樣,僅供參考):

Service 部分:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
private static readonly ConcurrentQueue<NoticeParamEntity> AsyncNotifyPayQueue = new ConcurrentQueue<NoticeParamEntity>();
private static int _workThread;
 
static ChangeOrderService()
{
    StartWorkThread();
}
 
public static int GetPayNoticQueueCount()
{
    return AsyncNotifyPayQueue.Count;
}
 
public static int StartWorkThread()
{
    if (_workThread > 5) return _workThread;
 
    ThreadPool.QueueUserWorkItem(WaitCallbackImpl);
    _workThread += 1;
 
    return _workThread;;
}
 
public static void WaitCallbackImpl(object state)
{
    while (true)
    {
        try
         {
            PayNoticeParamEntity payParam;
            AsyncNotifyPayQueue.TryDequeue(out payParam);
 
            if (payParam == null)
            {
                Thread.Sleep(5000);
                continue;
            }
 
            //獲取訂單詳情
 
            //結轉分攤
 
            //發簡訊
 
            //傳送訊息
 
            //配送
        }
        catch (Exception exception)
        {
            //log
        }
    }
}

原來呼叫的地方直接改成入佇列:

1
2
3
4
private void AsyncNotifyPayCompleted(NoticeParamEntity payNoticeParam)
{
    AsyncNotifyPayQueue.Enqueue(payNoticeParam);
}

 

Controller 程式碼:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
public class WorkQueueController : ApiController
    {
        [Route("worker/server_work_queue")]
        [HttpGet]
        public HttpResponseMessage GetServerWorkQueue()
        {
            var payNoticCount = ChangeOrderService.GetPayNoticQueueCount();
 
            var result = new HttpResponseMessage()
            {
                Content = new StringContent(payNoticCount.ToString(), Encoding.UTF8, "application/json")
            };
 
            return result;
        }
 
        [Route("worker/start-work-thread")]
        [HttpGet]
        public HttpResponseMessage StartWorkThread()
        {
            var count = ChangeOrderService.StartWorkThread();
 
            var result = new HttpResponseMessage()
             {
                Content = new StringContent(count.ToString(), Encoding.UTF8, "application/json")
            };
 
            return result;
        }
    }

 

上述程式碼是未經過抽象封裝的,僅供參考。思路是不變的,將執行緒利用率最大化,延遲任務無需佔用過多執行緒,將CPU密集型和IO密集型分開。讓速度不匹配的動作分開。

優化後的TPS可以到7000,比原來快近三倍。

6.對比JAVA實現

這個問題其實如果在JAVA裡也許不太容易出現,JAVA的執行緒池功能是比較強大的,併發庫比較豐富。在JAVA裡兩行程式碼就可以搞定了。

ExecutorService fiexdExecutorService = Executors.newFixedThreadPool(Thread_count);

直接構造一個指定數量的執行緒池,當然我們也可以設定執行緒池的佇列型別、大小、包括佇列滿了之後、執行緒池滿了之後的拒絕策略。這些用起來還是比較方便的。

http://www.cnblogs.com/wangiqngpei557/p/6940721.html

 

相關文章