Still celebrating National IT Professionals Day with 3 months of free Premium Membership. Use Code ITDAY17

x
?
Solved

IIS Log Timestamp Question

Posted on 2013-06-04
7
Medium Priority
?
963 Views
Last Modified: 2013-06-10
Using the extended log format in IIS we're given the wonderful "time-taken" field.

Given this entry:

2013-06-03 02:00:00 1.2.3.4 GET /file.htm - 443 - 5.6.7.8 (User Agent) 200 0 0 300000

The time-taken is 300000ms, or 5 minutes.

My question is.. did the request begin at 02:00, or did the request begin at 01:55 and end at 02:00?

A Followup question.. if the timestamp represents the end of the request, are there any log parsers that automatically adjust the timestamp to represent the origin of the request?
0
Comment
Question by:wegee2
[X]
Welcome to Experts Exchange

Add your voice to the tech community where 5M+ people just like you are talking about what matters.

  • Help others & share knowledge
  • Earn cash & points
  • Learn & ask questions
  • 4
  • 3
7 Comments
 
LVL 58

Expert Comment

by:Gary
ID: 39218950
The time the request was received
Not sure what you mean by
adjust the timestamp to represent the origin of the request
0
 

Author Comment

by:wegee2
ID: 39218970
I meant if the timestamp represented the end of the request, and in that sample the request instead started at 01:55, I wanted to convert it.

If the timestamp is already representing the beginning of the request, no conversion is needed and my followup question is moot.

I am now curious though if a request takes 5 minutes to process, how long does IIS buffer the information before writing to the log file.. since it can't write the "time-taken" until the request has finished.  I guess that's another question for another day.
0
 
LVL 58

Expert Comment

by:Gary
ID: 39219004
The time is when the request was received i.e. it is the start time. So in your example the request would have ended at 02:05:00
As for the second part, I'm not 100% sure.
0
Technology Partners: We Want Your Opinion!

We value your feedback.

Take our survey and automatically be enter to win anyone of the following:
Yeti Cooler, Amazon eGift Card, and Movie eGift Card!

 

Author Comment

by:wegee2
ID: 39219409
I did some testing to try and answer the second part, and in doing so I'm afraid I'm going to have to disagree with you on the first part.

Take this log entry from my test:

2013-06-04 15:21:15 ::1 GET /timeout.asp |-|ASP_0113|Script_timed_out 80 - ::1 (User Agent snipped) 500 0 0 194821

Open in new window


This test is a specific .asp script I wrote with an infinite loop and a 180 second timeout.  I started it as close to 15:18:00 as my mouse-clicking finger could get.

Notice the timestamp is 3 minutes, 15 seconds after when I started it.  And look at the time-taken.  194821 is a few ms shy of 3 minutes, 15 seconds.

So I believe the timestamp is the end of the request (and the time of writing to the log file), not the actual start of the request to IIS.

If you have any documentation to both explain this result and assert your idea, please share it, because I sure as heck couldn't find any before I posted the question.
0
 
LVL 58

Expert Comment

by:Gary
ID: 39219477
0
 

Accepted Solution

by:
wegee2 earned 0 total points
ID: 39219912
I read that, but it seems to be incorrect, or perhaps worded poorly.

http://blogs.msdn.com/b/mike/archive/2008/11/13/time-vs-time-taken-fields-in-iis-logging.aspx

Going from my real-world testing, and from this posting by a MS person, I am inclined to go with what he says about the log time being when the log entry itself is created (at the end of the response, not the beginning).  

Unfortunately, IIS logging by default doesn't include the time down to the millisecond, so I'm going to have some slight inaccuracy to my resultant forensics.
0
 

Author Closing Comment

by:wegee2
ID: 39234077
Having done more testing and finding the above blog by a MS employee on the subject, I'm content with this answer.
0

Featured Post

Industry Leaders: We Want Your Opinion!

We value your feedback.

Take our survey and automatically be enter to win anyone of the following:
Yeti Cooler, Amazon eGift Card, and Movie eGift Card!

Question has a verified solution.

If you are experiencing a similar issue, please ask a related question

Here are the symptoms: You start receiving calls from users that one of your legacy web apps isn't coming up, so you log into your IIS 5 server to check it out.  When you pull up the services, you notice that the WWW Publishing service isn't runn…
First of all, clustering IIS is something you should rarely consider doing. In almost all cases, Microsoft Network Load Balancing (NLB) (http://technet.microsoft.com/en-us/library/cc758834(WS.10).aspx) is a much better solution when you need to p…
In this video, Percona Director of Solution Engineering Jon Tobin discusses the function and features of Percona Server for MongoDB. How Percona can help Percona can help you determine if Percona Server for MongoDB is the right solution for …
Want to learn how to record your desktop screen without having to use an outside camera. Click on this video and learn how to use the cool google extension called "Screencastify"! Step 1: Open a new google tab Step 2: Go to the left hand upper corn…

722 members asked questions and received personalized solutions in the past 7 days.

Join the community of 500,000 technology professionals and ask your questions.

Join & Ask a Question