IIS – Causes of High Time-Taken Values for Small Static Data

iis

Below is an excerpt of the IIS logs, showing only the time and time-taken fields. Sometimes we have requests that seem to be taking more than 5 minutes. These slow requests include dynamic data (ASP.NET) as well as static files, served from the local disk, like in the case below that took 336134 milliseconds.

time      time-taken 
00:06:32         109 
00:06:33          46 
00:06:33          15 
00:06:33          78 
00:06:33          31 
00:06:33          31 
00:06:33          31 
00:06:33          31 
00:06:33          62 
00:06:36      336134 
00:06:38          15 
00:06:39          62 
00:06:39          31 
00:06:39          46 
00:06:39          62 
00:06:39          31 
00:06:39          15 
00:06:39          15 
00:06:39          31 
00:06:41          31 
00:06:44        2203 
00:06:44          31 
00:06:44          31 
00:06:44          62 
00:06:44          31 
00:06:44          15

As the log snippet shows, the server isn't generally overwhelmed at that time.

Any idea how to get to the bottom of this?

I wonder if those long times are in fact not due to the server being slow, but because the client – which may be on some terrible and disconnecting wireless connection – is not receiving the full TCP data in time. Because here it says:

Beginning in IIS 6.0, the time-taken field typically includes network
time. Before HTTP.sys logs the value in the time-taken field, HTTP.sys
usually waits for the client to acknowledge the last response packet
send operation or HTTP.sys waits for the client to reset the
underlying TCP connection.

Best Answer

TL;DR

The time up to the client's ack of the last TCP packet from the server's response is included in time-taken, so a slow client, say due to an unstable mobile connection, can increase time-taken arbitrarily, making your server look bad. Unless of course you know that time-taken is not the time the server took to fully process the request.

I could verify using the following command

curl --limit-rate 1000 http://...

that I can increase time-taken as recorded by IIS as far as my patience allowed my to try, which was over 3 minutes, by adjusting the limit-rate.

So considering the rather quick other responses at the very time of that horribly slow one, that particular client was likely the problem here.

N.B. If you want to try this, make sure to use a file that's big enough that it needs several IP packets to be transferred completely, i.e. a couple kilobytes at least, otherwise time-taken will be close to zero.

Related Topic