Iis – What does the different columns in IIS log mean

iis

I'm trying to figure out exactly what the different columns in the IIS log means. Especially the values in the time and time-taken

| date       | time     | s-port | sc-status | sc-win32-status | time-taken |
|------------|----------|--------|-----------|-----------------|------------|
| 15.03.2018 | 08:59:59 | 80     | 200       | 0               | 15         |
| 15.03.2018 | 08:59:59 | 80     | 200       | 0               | 0          |
| 15.03.2018 | 09:00:10 | 80     | 200       | 0               | 9921       |
| 15.03.2018 | 09:00:14 | 80     | 200       | 0               | 13687      |
| 15.03.2018 | 09:00:15 | 80     | 200       | 0               | 15000      |
| 15.03.2018 | 09:00:47 | 80     | 200       | 64              | 47000      |

It seems that the time-column actually says when the request was FINISHED, and the time-taken how long it took. So, to get an exactly measurment for when the request arrived, we have to take time – time-taken = request arrived. Is that correct?

Best Answer

The time-taken field shows the length of the time that it took for the request to be completely processed by HTTP.sys.

The client-request time stamp is initialized when HTTP.sys receives the first byte of the request (so network latency is included here). HTTP.sys is the kernel-mode component that is responsible for HTTP logging for IIS activity. The client-request time stamp is initialized before HTTP.sys begins parsing the request.

client-request is stopped when the last (HTTP-) response occurs.

So the answer is yes and no. Yes, it's the time when the request reaches HTTP.sys and no, it's not the time to measure if you want the time for IIS' reply. For example, a POST request with 2megs of payload will take a lot longer to reach your application (time-taken) than a short WebDAV keep-alive message. But both will have the same 'time' stamp. If you had subtractd one from the other, the long request would have "been there", even before it was sent.