目錄：

創(chuàng)新互聯(lián)主營(yíng)肇東網(wǎng)站建設(shè)的網(wǎng)絡(luò)公司,主營(yíng)網(wǎng)站建設(shè)方案,app軟件開(kāi)發(fā)公司,肇東h5微信小程序開(kāi)發(fā)搭建,肇東網(wǎng)站營(yíng)銷(xiāo)推廣歡迎肇東等地區(qū)企業(yè)咨詢(xún)

1.環(huán)境介紹

2.癥狀

3.診斷

4.結(jié)論

5.解決

6.對(duì)比java實(shí)現(xiàn)

廢話(huà)就不多說(shuō)了，本文分享下博主在5.28大促壓測(cè)期間解決的一個(gè)性能問(wèn)題，覺(jué)得這個(gè)還是比較有意思的，值得總結(jié)拿出來(lái)分享下。

博主所服務(wù)的部門(mén)是作為公共業(yè)務(wù)平臺(tái)，公共業(yè)務(wù)平臺(tái)支持上層所有業(yè)務(wù)系統(tǒng)（2C、UGC、直播等）。平臺(tái)中核心之一的就是訂單域相關(guān)服務(wù)，下單服務(wù)、查單服務(wù)、支付回調(diào)服務(wù)，當(dāng)然結(jié)算頁(yè)暫時(shí)還是我們負(fù)責(zé)，結(jié)算頁(yè)負(fù)責(zé)承上啟下進(jìn)行下單、結(jié)算、跳支付中心。每次業(yè)務(wù)方進(jìn)行大促期間平臺(tái)都要進(jìn)行一次常規(guī)壓測(cè)，做到心里有底。

在壓測(cè)的上半場(chǎng)，陸續(xù)的解決一些不是太奇怪的問(wèn)題，定位到問(wèn)題時(shí)間都在計(jì)劃內(nèi)。下單服務(wù)、查單服務(wù)、結(jié)算頁(yè)都順利壓測(cè)通過(guò)。但是到了支付回調(diào)服務(wù)壓測(cè)的時(shí)候，有個(gè)奇怪的問(wèn)題出現(xiàn)了。

1.環(huán)境介紹

我們每年基本兩次大促，5.28、雙12。兩次大促期間相隔時(shí)間也就只有半年左右，所以每次大促壓測(cè)都會(huì)心里有點(diǎn)低，基本就是摸底檢查下。因?yàn)橹暗膲簻y(cè)性能在這半年期間一般不會(huì)出現(xiàn)太大的性能問(wèn)題。這前提是因?yàn)槲覀兠看伟l(fā)布重大的項(xiàng)目的時(shí)候都會(huì)進(jìn)行性能壓測(cè)，所以壓測(cè)慢慢變得常規(guī)化、自動(dòng)化，遺漏的性能問(wèn)題應(yīng)該不會(huì)太多。性能指標(biāo)其實(shí)在平時(shí)就關(guān)注了，而不是大促才來(lái)臨時(shí)抱佛腳，那樣其實(shí)為時(shí)已晚，只能拆東墻補(bǔ)西墻。

應(yīng)用服務(wù)器配置，物理機(jī)、32core 、168g、千兆網(wǎng)卡、壓測(cè)網(wǎng)絡(luò)帶寬千兆、IIS 7.5、.NET 4.0，這臺(tái)壓測(cè)服務(wù)器還是很強(qiáng)的。

我們本地會(huì)用JMeter進(jìn)行問(wèn)題排查。由于這篇文章不是講怎么做性能壓測(cè)的，所以其他跟本篇文章關(guān)系的不大的情況就不介紹了。包括壓測(cè)網(wǎng)絡(luò)隔離、壓測(cè)機(jī)器的配置和節(jié)點(diǎn)數(shù)等。

我們的要求，頂層服務(wù)在200并發(fā)下，平均響應(yīng)時(shí)間不能超過(guò)50毫秒，TPS要到3000左右。一級(jí)服務(wù)，也就是最底層服務(wù)的要求更高，商品系統(tǒng)、促銷(xiāo)系統(tǒng)、卡券系統(tǒng)平均響應(yīng)時(shí)間基本保持在20毫秒以?xún)?nèi)才能接受。因?yàn)橐患?jí)服務(wù)的響應(yīng)速度直接決定了上層服務(wù)的響應(yīng)速度，這里還要去掉一些其他的調(diào)用開(kāi)銷(xiāo)。 

2.癥狀

這個(gè)性能問(wèn)題的癥狀還是比較奇怪的，情況是這樣的：200并發(fā)、2000loop，40w的調(diào)用量。一開(kāi)始前幾秒速度是比較快的，基本上TPS到了2500左右。服務(wù)器的CPU也到了60左右，還是比較正常的，但是幾秒過(guò)后處理速度陡降，TPS慢慢在往下掉。從服務(wù)器的監(jiān)控中發(fā)現(xiàn)，服務(wù)器的CPU是0%消耗。這很?chē)樔?，怎么突然不處理了。TPS掉到100多了，顯然會(huì)一直掉下去。等了大概不到4分鐘，一下子CPU又上來(lái)了。TPS可以到2000左右。

我們仔細(xì)分析查看，首先JMeter的吞吐量的問(wèn)題，吞吐量是按照你的請(qǐng)求平均響應(yīng)時(shí)間計(jì)算的，所以這里看起來(lái)TPS是慢慢在減慢其實(shí)已經(jīng)基本停止了。如果你的平均響應(yīng)時(shí)間為20毫秒，那么在單位時(shí)間內(nèi)你的吞吐量是基本可以計(jì)算出來(lái)的。

癥狀主要就是這樣的，我們接下來(lái)對(duì)它進(jìn)行診斷。

3.診斷

開(kāi)始通過(guò)走查代碼，看能不能發(fā)現(xiàn)點(diǎn)什么。

這是支付回調(diào)服務(wù)，代碼的前后沒(méi)有太多的業(yè)務(wù)處理，鑒權(quán)檢查、訂單支付狀態(tài)修改、觸發(fā)支付完成事件、調(diào)用配送、周邊業(yè)務(wù)通知（這里有一部分需要兼容老代碼、老接口）。我們首先主要是查看對(duì)外依賴(lài)的部分，發(fā)現(xiàn)有redis讀寫(xiě)的代碼，就將redis的部分代碼注釋掉在進(jìn)行壓測(cè)試試看。結(jié)果一下子就正常了，這就比較奇怪了，redis是我們其他壓測(cè)服務(wù)共用的，之前壓測(cè)怎么沒(méi)有問(wèn)題。沒(méi)管那么多了，可能是代碼的執(zhí)行序列不同，在并發(fā)領(lǐng)域里面，這也說(shuō)得通。

我們?cè)偻ㄟ^(guò)打印redis執(zhí)行的時(shí)間，看處理需要多久。結(jié)果顯示，處理速度不均勻，前面的很快，后面的時(shí)間都在5-6秒，雖然不均勻但是很有規(guī)律。

所以我們都認(rèn)為是redis的相關(guān)問(wèn)題，就開(kāi)始一頭扎進(jìn)去檢查redis的問(wèn)題了。開(kāi)始對(duì)redis進(jìn)行檢查，首先是開(kāi)啟Wireshark TCP連接監(jiān)控，檢查鏈路、redis服務(wù)器的Slowlog查看處理時(shí)間。redis客戶(hù)端庫(kù)的源代碼查看（redis客戶(hù)端排除原生的StackExhange.Redis的有兩層封裝，一共三層），重點(diǎn)關(guān)注有鎖的地方和thread wait的地方。同時(shí)排查網(wǎng)絡(luò)問(wèn)題，再進(jìn)行壓測(cè)的時(shí)候ping redis服務(wù)器看是否有延遲。（此時(shí)是晚上21點(diǎn)左右，這個(gè)時(shí)候的大腦情況大家都懂的。）

就是這樣地毯式的搜查，以為是肯定能定位到問(wèn)題。但是我們卻忽視了代碼的層次結(jié)構(gòu)，一下子專(zhuān)到了太細(xì)節(jié)的地方，忽視了整體的架構(gòu)（指開(kāi)發(fā)架構(gòu)，因?yàn)榇a不是我們寫(xiě)的，對(duì)代碼周邊情況不是太了解）。

先看redis服務(wù)器的建立情況，tcp抓包查看，連接建立正常，沒(méi)有丟包，速度也很快。redis的處理速度也沒(méi)問(wèn)題，slowlog查看基本get key也就1毫秒不到。（這里需要注意，redis的處理時(shí)間還包括隊(duì)列里等待的時(shí)間。slowlog只能看到redis處理的時(shí)間，看不到blocking的時(shí)間，這里面還包括redis的command在客戶(hù)端隊(duì)列的時(shí)間。）

所以打印出來(lái)的redis處理時(shí)間很慢，不純粹是redis服務(wù)器的處理時(shí)間，中間有幾個(gè)環(huán)節(jié)需要排查的。

經(jīng)過(guò)一番折騰，排查，問(wèn)題沒(méi)定位到，已是深夜，精力嚴(yán)重不足了，也要到地鐵最后一班車(chē)發(fā)車(chē)時(shí)間了，再不走趕不上了，下班回家，上到最后一班地鐵沒(méi)耽誤三分鐘~~。

重整思路，第二天繼續(xù)排查。

我們定位到redis客戶(hù)端的連接是可以先預(yù)熱的，在global application_begin啟動(dòng)的時(shí)候先預(yù)熱好，然后性能一下子也正常了。

范圍進(jìn)一步縮小，問(wèn)題出在連接上，這里我們又反思了（一夜覺(jué)睡過(guò)了，腦子清醒了），那為什么我們之前的壓測(cè)沒(méi)出現(xiàn)過(guò)這個(gè)問(wèn)題。對(duì)技術(shù)狂熱愛(ài)好的我們，哪能善罷甘休。此時(shí)問(wèn)題算是解決了，但是背后所涉及到的相關(guān)線(xiàn)索穿不起來(lái)，總是不太舒服。（中場(chǎng)休息片刻，已是第二天的下午快傍晚了~~。）技術(shù)人員要有這種征服欲，必須搞清楚。

我們開(kāi)始還原現(xiàn)場(chǎng)，然后開(kāi)始出大招，開(kāi)始dump進(jìn)程文件，分不同的時(shí)間段，抓取了幾份dump文件down到本地進(jìn)行分析。

首先查看了線(xiàn)程情況，!runaway，發(fā)現(xiàn)大多數(shù)線(xiàn)程執(zhí)行時(shí)間都有點(diǎn)長(zhǎng)。接著切換到某個(gè)線(xiàn)程中~xxs，查看線(xiàn)程調(diào)用堆棧。發(fā)現(xiàn)在等一把monitor鎖。同時(shí)切換到其他幾個(gè)線(xiàn)程中查看下是不是都在等待這把鎖。結(jié)果確實(shí)都在等這把鎖。

結(jié)論，發(fā)現(xiàn)一半的線(xiàn)程都在等待moniter監(jiān)視器鎖，隨著時(shí)間增加，是不是都在等待這把鎖。這比較奇怪。

這把鎖是redis庫(kù)的第三層封裝的時(shí)候用來(lái)lock獲取redis connectioin時(shí)候用的。我們直接注釋掉這把鎖，繼續(xù)壓測(cè)繼續(xù)dump，然后又發(fā)現(xiàn)一把monitor，這把鎖是StackExchange.Redis中的，代碼一時(shí)半會(huì)無(wú)法消化，只查了主體代碼和周邊代碼情況，沒(méi)有時(shí)間查看全局情況。（因?yàn)闀r(shí)間緊迫）。暫且完全信任第三方庫(kù)，然后查看redis connection string 的各個(gè)參數(shù)，是不是可以調(diào)整超時(shí)時(shí)間、連接池大小等。但是還是未能解決。

回過(guò)頭繼續(xù)查看dump，查看了下CLR連接池，！ThreadPool，一下子看到問(wèn)題了。

繼續(xù)查看其他幾個(gè)dump文件，Idle都是0，也就是說(shuō)CLR線(xiàn)程池沒(méi)有線(xiàn)程來(lái)處理請(qǐng)求了，至少CLR線(xiàn)程池的創(chuàng)建速率和并發(fā)速率不匹配了。

CLR線(xiàn)程池的創(chuàng)建速率一般是1秒2個(gè)線(xiàn)程，線(xiàn)程池的創(chuàng)建速率是否存在滑動(dòng)時(shí)間不太清楚。線(xiàn)程池的大小可以通過(guò) C:\Windows\Microsoft.NET\Framework64\v4.0.30319\Config\machine.config 配置來(lái)設(shè)置，默認(rèn)是自動(dòng)配置的。最小的線(xiàn)程數(shù)一般是當(dāng)前機(jī)器的CPU 核數(shù)。當(dāng)然你也可以通過(guò)ThreadPool相關(guān)方法來(lái)設(shè)置，ThreadPool.SetMaxThreads(), ThreadPool.SetMinThreads()。

然后我們繼續(xù)排查代碼，發(fā)現(xiàn)代碼中有用Action的委托的地方，而這個(gè)Action是處理異步代碼的，上面說(shuō)的redis的讀寫(xiě)都在這個(gè)Action里面的。一下我們明白了，所有的線(xiàn)索都連起來(lái)了。

4.結(jié)論

.NET CLR線(xiàn)程池是共享線(xiàn)程池，也就是說(shuō)ASP.NET、委托、Task背后都是一個(gè)線(xiàn)程池在處理。線(xiàn)程池分為兩種，Request線(xiàn)程池、IOCP線(xiàn)程池（完成端口線(xiàn)程池）。

我們現(xiàn)在理下線(xiàn)索：

1.從最開(kāi)始的JMeter壓測(cè)吞吐量慢慢變低是個(gè)假象，而此時(shí)處理已經(jīng)全面停止，服務(wù)器的CPU處理為0%。肉眼看起來(lái)變慢是因?yàn)檎?qǐng)求延遲時(shí)間增加了。

2.redis的TCP鏈路沒(méi)問(wèn)題，Wireshark查看沒(méi)有任何異常、Slowlog沒(méi)有問(wèn)題、redis的key comnand慢是因?yàn)閎locking住了。

3.其他服務(wù)壓測(cè)之所有沒(méi)問(wèn)題是因?yàn)槲覀兪峭秸{(diào)用redis，當(dāng)首次TCP連接建立之后速度會(huì)上來(lái)。

4.Action看起來(lái)速度是上去了，但是所有的Action都是CLR線(xiàn)程池中的線(xiàn)程，看起來(lái)快是因?yàn)檫€沒(méi)有到CLR線(xiàn)程池的瓶頸。

Action asyncAction = () =>   
           {    
               //讀寫(xiě)redis    
               //發(fā)送郵件 
               //...
           };
asyncAction();

5.JMeter壓測(cè)的時(shí)候沒(méi)有延遲，在壓測(cè)的時(shí)候程序沒(méi)有預(yù)熱，導(dǎo)致所有的東西需要初始化，IIS、.NET等。這些都會(huì)讓第一次看起來(lái)很快，然后慢慢下降的錯(cuò)覺(jué)。

總結(jié)：首次建立TCP連接是需要時(shí)間的，此時(shí)并發(fā)過(guò)大，所有的線(xiàn)程在wait，wait之后CPU會(huì)將這些線(xiàn)程交換出去，此時(shí)是明顯的所線(xiàn)程上下文切換過(guò)程，是一部分開(kāi)銷(xiāo)。當(dāng)CLR線(xiàn)程池的線(xiàn)程全部耗光吞吐量開(kāi)始陡降。每次調(diào)用其實(shí)是開(kāi)啟力了兩個(gè)線(xiàn)程，一個(gè)處理請(qǐng)求的Request，還有一個(gè)是Action委托線(xiàn)程。當(dāng)你以為線(xiàn)程還夠的時(shí)候，其實(shí)線(xiàn)程池已經(jīng)滿(mǎn)了。

5.解決

針對(duì)這個(gè)問(wèn)題我們進(jìn)行了隊(duì)列化處理。相當(dāng)于在CLR線(xiàn)程池基礎(chǔ)上抽象一個(gè)工作隊(duì)列出來(lái)，然后隊(duì)列的消費(fèi)線(xiàn)程控制在一定數(shù)量之內(nèi)，初始化的時(shí)候默認(rèn)一個(gè)線(xiàn)程，會(huì)提供接口創(chuàng)建頂多6個(gè)線(xiàn)程。這樣當(dāng)隊(duì)列的處理速度跟不上的時(shí)候可以調(diào)用。大致代碼如下（已進(jìn)行適當(dāng)?shù)男薷模窃创a模樣，僅供參考）：

Service 部分：

private static readonly ConcurrentQueue AsyncNotifyPayQueue = new ConcurrentQueue();    
 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;    
            }
            //獲取訂單詳情
            //結(jié)轉(zhuǎn)分?jǐn)?nbsp;   
            //發(fā)短信    
            //發(fā)送消息    
            //配送    
        }    
        catch (Exception exception)    
        {    
            //log    
        }    
    }    
 }

原來(lái)調(diào)用的地方直接改成入隊(duì)列：

private void AsyncNotifyPayCompleted(NoticeParamEntity payNoticeParam)    
 {    
    AsyncNotifyPayQueue.Enqueue(payNoticeParam);    
 }

Controller 代碼：

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;    
        }    
    }

上述代碼是未經(jīng)過(guò)抽象封裝的，僅供參考。思路是不變的，將線(xiàn)程利用率最大化，延遲任務(wù)無(wú)需占用過(guò)多線(xiàn)程，將CPU密集型和IO密集型分開(kāi)。讓速度不匹配的動(dòng)作分開(kāi)。

優(yōu)化后的TPS可以到7000，比原來(lái)快近三倍。

6.對(duì)比JAVA實(shí)現(xiàn)

這個(gè)問(wèn)題其實(shí)如果在JAVA里也許不太容易出現(xiàn)，JAVA的線(xiàn)程池功能是比較強(qiáng)大的，并發(fā)庫(kù)比較豐富。在JAVA里兩行代碼就可以搞定了。

ExecutorService fiexdExecutorService = Executors.newFixedThreadPool(Thread_count);

直接構(gòu)造一個(gè)指定數(shù)量的線(xiàn)程池，當(dāng)然我們也可以設(shè)置線(xiàn)程池的隊(duì)列類(lèi)型、大小、包括隊(duì)列滿(mǎn)了之后、線(xiàn)程池滿(mǎn)了之后的拒絕策略。這些用起來(lái)還是比較方便的。