今天下午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少很多。
由此我们可以得出这样一个结论:在出问题的期间,有大量的请求在处理完成后将响应内容发送给客户端的环节出现延迟。