今天下午訪問高峰的時候,主站的Web服務器出現奇怪的問題,開始是2台8核8G的雲服務器(ECS),后來又加了1台8核8G的雲服務器,問題依舊。
而且3台服務器特地使用了不同的配置:1台是禁用了虛擬內存的臨時磁盤雲服務器,1台是啟用了虛擬內存的臨時磁盤雲服務器,1台是禁用了虛擬內存的雲盤雲服務器。這樣排除了磁盤IO與虛擬內存的原因。
問題的表現是這樣的(以下監視截圖來自Windows性能監控器Performance Monitor):
1. ASP.NET請求執行時間(Request Execution Time)變慢

通常請求執行時間在100ms以下,而出問題時竟然達到了近1.5s,發生時間為15:18:09。
2. IIS當前連接數(Current Connections)突增

IIS當前連接數通常在10左右,出現問題時先跳高至67,后跳高至270多,說明IIS處理請求的能力下降,開始發生的時間點是15:18:06。
可見IIS當前連接數突增早於ASP.NET請求執行時間變慢。
3. CPU占用下降


CPU在15:18:07到達高點之后,一直往下掉,在15:18:14掉至最低點。
CPU下降發生於IIS當前連接數突增之后。
4. 請求出現排隊現象(Requests Queued)

Requests Queued正常情況下是0,只有在請求處理不過來的時候才會出現排隊現象。請求排隊開始於15:18:05,早於IIS當前連接數突增。
5. ASP.NET請求處理能力下降(Requests/Sec)

15:18:05開始,ASP.NET的請求處理能力下降,與請求排隊開始於同一時間。
我們給上面的5個現象排個序:請求處理能力下降(Requests/Sec)-> 請求排隊(Requests Queued)-> 當前連接數突增(Current Connections)-> CPU占用下降 -> 請求執行時間變慢(Request Execution Time)
然后再來看另外一次問題發生時的現象:
1. Requests/Sec下降(棕色)與Requests Queued出現(藍色)

Requests Queued在高點達1007。
2. Request Execution Time變慢(紫色)與Current Connections突增(綠色)

Current Connections在高點達1586。
3. 加上CPU占用率,5個指標疊在一起

【分析】
Requests/Sec下降、Requests Queued上升、Request Execution Time變慢、Current Connections突增,這些說明在什么地方卡住了;而CPU占用下降說明不是因為負載高CPU處理不過來,而是卡在了其他環節,比如IO。
之前遇到比這還奇怪的“黑色10秒鍾”(詳見雲計算之路-阿里雲上:超級奇怪的“黑色10秒鍾”),現象有點類似,但有2個地方不同:
1. 這次持續時間是30秒(所以把這次問題命名為“黑色30秒”)。
2. “黑色10秒鍾”期間Requests/Sec會下降為0;而“黑色30秒”期間Requests/Sec只是下降,沒有為0,也就是說還在處理請求,只是因為某些資源出現瓶頸,請求處理能力下降。
之前的“黑色10秒鍾”是因為虛擬化對spinlock的支持問題引起的,改用Windows Server 2012解決了問題。
這次呢?應用的問題,Windows的問題,還是阿里雲的問題?這是個問題!目前還不知道從何處下手。
期待您的寶貴建議!
