今天下午15:11-15:13間出現了類似“黑色30秒”的狀況,我們用強大的IIS日誌分析工具——Log Parser Studio進行了進一步的分析。
分析情況如下——
先看一下Windows效能監視器中的問題表現:
然後用Log Parser Studio分析07:11:55與07:13:55(GMT時間)之間的IIS日誌,看看這期間有多少time-taken超過1秒的請求。
在短短的2分鐘之內,竟然有315個請求的time-taken超過1秒。
而在這期間Request Execution Time只有1次達到999ms,多數都在200ms以下(見下圖)。
時間都去哪了?請求響應內容傳送給客戶端的TCP處理環節是最大的嫌疑。
再選一個沒有出問題的時間段(15:15:40-15:17:40)對比一下:
同樣是2分鐘內,卻只有4次time-taken超過1秒的請求。
再與同一個負載均衡中的另外1臺Web伺服器在同時間段內進行對比:
只有42個請求time-taken超過1秒,比出問題的那臺伺服器的315少很多。
由此我們可以得出這樣一個結論:在出問題的期間,有大量的請求在處理完成後將響應內容傳送給客戶端的環節出現延遲。