今天下午訪問高峰的時候,主站的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的問題,還是阿里雲的問題?這是個問題!目前還不知道從何處下手。
期待您的寶貴建議!