Help with IIS 7 server logs

Original HTTP requests not shown?

[aakk9999]

We have noticed that the client's website too often returns HTTP 500 and have asked their development agency to provide us with the full set of IIS server logs for the last 7 days.

I have received server logs today and when looking at logs, I cannot see ANY request for friendly (rewritten) URL and can see very few requests for scripts not rewritten. I can however see many requests for supporting page elements (images, css etc). I can also see rewritten URLs being part of referrer string, clearly proving that that page was preceding the current request.

Other examples of IIS logs we have seen (other clients) do show acutal request sent to the server.

Before I question development agency on possibly removing some things from logs (perhaps to hide number of HTTP 500 errors), I would like IIS experts to let me know if what I am seeing is normal?

My understanding (and experience so far) of server logs is that they show all requests server received in the form it got them. If my assumption is correct then someone must have filtered logs out before sending us the data.

Alternatively, is it possible that there is something on IIS server (it is IIS 7) that has to be set up for the complete set of requests to be recorded, just on the off-chance they have "wrong" settings on server? In this case, could someone tell me what this setting is and how it should be set?

From what I do know is that friendly URLs are handled as a combination of IIS 7 Rewrite module + custom rewrite (most requests are forwarded via IIS 7 Rewrite module to custom rewrite module which then checks db for appropriate URL / action).

Many thanks

[dstiles]

If it's anything like IIS6 and previous, there is an option per site record in IIS Admin to define what is entered into the log (and where the log is saved and how often the name changes). There are very few features that are fixed. I turn on everything but some services leave as provided by MS (which isn't a bad set of options) and I'm sure other services turn off some options to reduce log space.

I'm not sure what you mean by "friendly urls" but IIS by default logs the IP of the web site and the IP of the visitor, not their rDNS (domain) values. That can save a lot of time serving up a site.

I have no idea about rewrite because I'm still using IIS6.

[aakk9999]

Thank you on your reply. Here is what I mean:

If the request (which I can see via Firefox Live HTTP headers) is

GET /some-pretty-url HTTP/1.1
which returns:
HTTP/1.1 200 OK

Then I expect (or better, I am used to) see in logs something alongside the following:

2010-12-03 15:00:47 sitename computername nnn.nnn.nnn.nnn GET /some-pretty-url 80 - nnn.nnn.nnn.nnn some-user-agent some-referer-url 200 0 0 450

and after that initial request, I am used to see all page elements being requested for this URL (eg. css, js, images, etc, whatever is not cached previously) that is, a number of lines in the log such as following:

2010-12-03 15:00:47 sitename computername nnn.nnn.nnn.nnn GET /some-css-file.css 80 - nnn.nnn.nnn.nnn some-user-agent some-referer-url 200 0 0 120
2010-12-03 15:00:47 sitename computername nnn.nnn.nnn.nnn GET /some-image.jpg 80 - nnn.nnn.nnn.nnn some-user-agent some-referer-url 200 0 0 98

I am not seeing the very first entry above. I am seeing only requests for page elements.

Secondly, if a dynamic URL has been redirected, then I would expect to see original request with 301 response followed a second request for rewritten (e.g. pretty) URL, for example if the request (which I can see via Firefox Live HTTP headers) is

GET /some-dynamic-url.aspx?parm=value HTTP/1.1
which returns response:
HTTP/1.1 301 Moved Permanently
Location /some-pretty-url
where the client now repeats the request for a new location:
GET /some-pretty-url HTTP/1.1
which returns:
HTTP/1.1 200 OK

Then again I am used to see in logs both requests with their responses (at the end of the request line):

2010-12-03 15:00:47 sitename computername nnn.nnn.nnn.nnn GET /some-dynamic-url.aspx parm=value 80 - nnn.nnn.nnn.nnn some-user-agent some-referer-url 301 0 0 450

2010-12-03 15:00:47 sitename computername nnn.nnn.nnn.nnn GET /some-pretty-url 80 - nnn.nnn.nnn.nnn some-user-agent some-referer-url 200 0 0 453

followed by requests for page elements (if not cached).

For this second example, what I am seeing in logs is a request for the script that handles custom rewrite/redirect with response 301 followed by a line showing dynamic URL that corresponds to URL that has been rewritten.

So looking at logs I cannot actually see what were original requests that have arrived at server.

I also know that there have been HTTP 500 errors generated in my browser that do not show in logs.

Hence I am wondering if something has been filtered out, either at IIS log setup level (hopefully not manually afterwards...)

Or could the use of memcache result in requests server accepts not being shown in logs? (but then again, the other client also uses memcache but all requests show in their logs...)

[dstiles]

It looks as if you have a fair number of fields in the log lines so I would say you've got at least the MS default.

I wonder how much difference the rewrite module has in all this. I THINK rewrite would occur before the site is accessed, so it could well be that the original request won't be in the logs, but I assume it would be in the rewrite log (if such exists). As I said, I don't use either IIS7 nor rewrite so I don't really KNOW.