Yesterday I learned an important lesson about IIS logs. They do not show you all of the requests hitting your server! Evidently the log does not show canceled requests.
Over the last couple of days I was receiving complaints about slow responses from our web site. By the time I would look at the CPU utilization it would be within the normal range. I looked in the IIS log file for timeouts but could not find any. So I ran a two hour trace on Thursday afternoon. Friday morning I crunched the trace with PAL and discovered several unaccountable CPU peaks attributable to w3wp.exe. An Internet search for “w3wp.exe high cpu usage†led me to this thread in which several people recommended using IISPeek to find the misbehaving request. So I installed a trial version of IISPeek and started watching the transactions coming in. Pretty soon I saw something I was not expecting. A shopping site was coming to our site and trying to retrieve a product advertising feed. What was surprising was not that the shopping site was retrieving the feed but there was no log of it in the IIS log file. This request had been consuming our CPU for several minutes and then disappearing without a trace. I knew this query had some serious performance issues but the IIS log indicated that it had been working on previous days. I did not know it was running so often. With IISPeek and Task Manager running together I could see the impact on the site. Evidently this particular shopping site would time out or cancel the query before our site either returned the data or timed out. It was at this moment that I figured out that IIS must have a “no harm, no foul†policy about canceled queries. My reliance on the IIS log was a mistake in this case. Since this shopping site was not getting the data, the shopping site would try again at a later time. When I was watching it with IISPeek I was seeing this request about every fifteen minutes. Fortunately I had already developed some web page caching code I could implement quickly and get us over this hump. Within an hour the shopping site had its data and our web site was back to normal. I have solved a lot of web site problems by looking at the IIS log but in this case it was not the right tool for the job. On Monday I am buying a copy of IISPeek!