程序師世界是廣大編程愛好者互助、分享、學習的平台,程序師世界有你更精彩!
首頁
編程語言
C語言|JAVA編程
Python編程
網頁編程
ASP編程|PHP編程
JSP編程
數據庫知識
MYSQL數據庫|SqlServer數據庫
Oracle數據庫|DB2數據庫
 程式師世界 >> 編程語言 >> .NET網頁編程 >> ASP.NET >> ASP.NET基礎 >> 阿裡雲上從ASP.NET線程角度對“黑色30秒”問題的全新分析

阿裡雲上從ASP.NET線程角度對“黑色30秒”問題的全新分析

編輯:ASP.NET基礎

在這篇博文中,我們拋開對阿裡雲的懷疑,完全從ASP.NET的角度進行分析,看能不能找到針對問題現象的更合理的解釋。

“黑色30秒”問題現象的主要特征是:排隊的請求(Requests Queued)突增,到達HTTP.SYS的請求數(Arrival Rate)下降,QPS(Requests/Sec)下降,CPU消耗下降,Current Connections上升。

昨天晚上18:08左右發生了1次“黑色30秒”,正好借此案例分析一下。

黑色30秒

1、為什麼Requests Queued會突增?

最直接的原因是ASP.NET沒有可用的線程處理當前請求。為什麼會沒有可用的線程呢?ASP.NET可用的線程畢竟是有限的,可能是當時瞬間的並發請求太多,ASP.NET來不及創建足夠的線程處理這些請求。

我們來看一下ASP.NET中線程相關的設置——machine.config中的processModel(位於C:\Windows\Microsoft.NET\Framework64\v4.0.30319\Config)。

有4個相關設置:maxWorkerThreads(默認值是20), maxIoThreads(默認值是20), minWorkerThreads(默認值是1), minIoThreads(默認值是1)。(這些設置是針對每個CPU核)

我們用的就是默認設置,由於我們的Web服務器是8核的,於是實際的maxWorkerThreads是160,實際的maxIoThreads是160,實際的minWorkerThreads是8,實際的minIoThreads是8。

基於這樣的設置,是不是如果瞬間並發請求是169,就會出現排隊?不是的,ASP.NET沒這麼傻!因為CLR 1秒只能創建2個線程,等線程用完時才創建,黃花菜都涼了。我們猜測ASP.NET只是根據這個設置去預測線程池中的可用線程是不是緊張,是不是需要創建新的線程,以及創建多少線程。

那什麼情況下會出現“黑色30秒”期間那樣的大量請求排隊?假如並發請求數平時是300,突然某個瞬間並發請求數是600,超出了ASP.NET預估的所需的可用線程數,於是那些拿不到線程的請求只能排隊等待正在執行的請求釋放線程以及CLR創建新的線程。隨著時間的推移,釋放出來的線程+新創建的線程足以處理這些排隊的請求,就恢復了正常。

那如何驗證這個猜測呢? 修改maxWorkerThreads, maxIoThreads, minWorkerThreads, minIoThreads的設置,讓ASP.NET提供更多的可用線程,目前我們采用的設置如下:

<processModel enable="true" requestQueueLimit="5000" maxWorkerThreads="100" maxIoThreads="100" minWorkerThreads="50" minIoThreads="50"/>

如果采用這個設置之後,“黑色30秒”現象幾乎不出現,就能驗證問題出在這個地方。現在主站www.cnblogs.com已經使用了這個設置,需要觀察一段時間進行驗證。

【啟示】

1) 通過Windows性能監視器監視\ASP.NET\Requests Queued可以直觀地評估ASP.NET應用程序的吞吐能力(throughput)。

2) 通過ASP.NET異步編程(async/await)可以有效減少可用線程緊張造成的請求排隊問題。

2、為什麼Arrival Rate會下降?

(上圖中的橙色線條)

這是“黑色30秒”問題中最讓人不解的地方,ASP.NET中請求再怎麼排隊,怎麼會造成到達HTTP.SYS的請求數下降呢?一開始我們總是不相信是請求排隊引起的Arrival Rate下降,但是監視圖中卻鐵證如山。

寫這篇博客之前,我們突然想通了!之前忽略了一個地方——當你打這篇博文時,第1個請求是html頁面,如果這個請求得到正常響應,浏覽器在加載這個頁面時會發出多個ajax請求;如果第1個請求被排隊,浏覽器處於等待狀態,後續的ajax請求就不會發出,這樣到達HTTP.SYS的請求數就會下降。這也解釋了為什麼有時會在“黑色30秒”的中間階段Arrival Rate會飙高,正是因為當時被排隊的請求所對應的頁面中有很多ajax,當它結束排隊被執行後,後續的很多ajax請求(可能排隊的很多是這樣的請求)到達了HTTP.SYS。

於是,我們相信了是請求排隊引起的Arrival Rate下降。

【啟示】

不能把目光局限於當前看到的問題表現,而要綜合考慮,將諸多因素聯系起來理清各種現象之間的關系。

3、QPS下降

與Arrival Rate下降同理,QPS(Requests/Sec)與Arrival Rate是直接相關的,成正比關系。

於是,QPS下降也是因為請求排隊。

4、CPU消耗下降

也是同理,Arrival Rate與QPS下降,說明CPU要干的活少了,自然消耗就下降。

於是,CPU消耗下降也是因為請求排隊。

5、Current Connections上升

Current Connections是請求排隊的一個直接表現,請求還沒被執行,連接當然會保持著。

於是,Current Connection上升也是因為請求排隊。

6、看一個新指標Requests Executing

(上圖綠色的線條表示的是Requests Executing)

在請求排隊的期間,正在被ASP.NET執行的請求數(Requests Executing)在增加,說明隨著被釋放出來的線程增多以及更多的新線程被創建,排列中的請求正在被越來越多地執行。這從側面說明了執行中的線程可能是正常的,沒有被卡住。(接下來的IIS日志信息會進一步驗證這一點)

於是,Requests Executing在增加也是因為請求被排隊,而且說明這個排隊是正常的,沒有哪個地方卡住了。

7、再來看看IIS日志中請求的time-taken

日志分析工具Log Parser Studio

在“黑色30秒”階段,IIS日志中沒有time-taken超過1s的請求!這說明了什麼?說明了正在被執行的請求處理速度很快,沒有什麼地方被卡住。。。除了因為可用線程不夠,請求被排隊。

於是,IIS日志說明除了請求排隊,其他地方一切正常。

【總結】

如果把“黑色30秒”問題歸因於ASP.NET線程問題,除了30秒左右的這個時間,其他問題表現都得到了更合理的解釋。

寫這篇博客之前,我們當時覺得ASP.NET線程問題引起“黑色30秒”問題的可能性是80%,寫完這7點分析之後,我們覺得可能性是99%,除非這次分析的“黑色30秒”與之前的“黑色30秒”不是同一個問題。

現在還需要我們使用新設置(maxWorkerThreads="100", maxIoThreads="100", minWorkerThreads="50", minIoThreads="50")之後的驗證。

大結局即將來臨,重要的可能不是結局是什麼,而是其中的過程,我們分享的也是解決問題的過程。

  1. 上一頁:
  2. 下一頁:
Copyright © 程式師世界 All Rights Reserved