IIS Log Time column: Start or End Time?

On Oct 18, 4:02 pm, "Ken Schaefer" <kenREM....RemoveThis@THISadOpenStatic.com>
wrote:
> I believe this is correct. The log entry is one of the last thing performed
> for each request
>
> Cheers
> Ken
>
> "JimLad" <jamesdbi....RemoveThis@yahoo.co.uk> wrote in message
>
> news:1192712226.033895.124230@y27g2000pre.googlegroups.com...
>
>
>
> > Hi,
>
> > In IIS 6.0 Log, does Time represent the end time or the start time?
> > Doesn't matter much normally, but I have some time-out entries where
> > time-taken is 6 minutes where it makes a huge difference.
>
> > I think the time in the log is the end time, and that to get a rough
> > approximation of the start time I need to subtract the time-taken. Am
> > I correct?
>
> > Cheers,
>
> > James- Hide quoted text -
>
> - Show quoted text -

Thanks.

Also just to clarify, when you get a new set of headers in the log,
that indicates a website restart or an idle timeout on the worker
process. Is that correct? Could anything else cause new headers to be
written?

Cheers,

James
 >> Stay informed about: IIS Log Time column: Start or End Time? 

On Oct 19, 2:48 am, JimLad <jamesdbi....TakeThisOut@yahoo.co.uk> wrote:
> On Oct 18, 4:02 pm, "Ken Schaefer" <kenREM....TakeThisOut@THISadOpenStatic.com>
> wrote:
>
>
>
>
>
> > I believe this is correct. The log entry is one of the last thing performed
> > for each request
>
> > Cheers
> > Ken
>
> > "JimLad" <jamesdbi....TakeThisOut@yahoo.co.uk> wrote in message
>
> >news:1192712226.033895.124230@y27g2000pre.googlegroups.com...
>
> > > Hi,
>
> > > In IIS 6.0 Log, does Time represent the end time or the start time?
> > > Doesn't matter much normally, but I have some time-out entries where
> > > time-taken is 6 minutes where it makes a huge difference.
>
> > > I think the time in the log is the end time, and that to get a rough
> > > approximation of the start time I need to subtract the time-taken. Am
> > > I correct?
>
> > > Cheers,
>
> > > James- Hide quoted text -
>
> > - Show quoted text -
>
> Thanks.
>
> Also just to clarify, when you get a new set of headers in the log,
> that indicates a website restart or an idle timeout on the worker
> process. Is that correct? Could anything else cause new headers to be
> written?
>
> Cheers,
>
> James- Hide quoted text -
>
> - Show quoted text -


You get a new set of headers whenever HTTP.SYS has to open the log
file to start writing a log entry to it.

What you have mentioned is a subset of possible actions that can cause
new headers to be written. There are others, but without a context, it
is not useful to list them.


//David
http://w3-4u.blogspot.com
http://blogs.msdn.com/David.Wang
//
 >> Stay informed about: IIS Log Time column: Start or End Time? 

On Oct 19, 7:46 pm, David Wang <w3.4....TakeThisOut@gmail.com> wrote:
> On Oct 19, 2:48 am, JimLad <jamesdbi....TakeThisOut@yahoo.co.uk> wrote:
>
>
>
>
>
> > On Oct 18, 4:02 pm, "Ken Schaefer" <kenREM....TakeThisOut@THISadOpenStatic.com>
> > wrote:
>
> > > I believe this is correct. The log entry is one of the last thing performed
> > > for each request
>
> > > Cheers
> > > Ken
>
> > > "JimLad" <jamesdbi....TakeThisOut@yahoo.co.uk> wrote in message
>
> > >news:1192712226.033895.124230@y27g2000pre.googlegroups.com...
>
> > > > Hi,
>
> > > > In IIS 6.0 Log, does Time represent the end time or the start time?
> > > > Doesn't matter much normally, but I have some time-out entries where
> > > > time-taken is 6 minutes where it makes a huge difference.
>
> > > > I think the time in the log is the end time, and that to get a rough
> > > > approximation of the start time I need to subtract the time-taken. Am
> > > > I correct?
>
> > > > Cheers,
>
> > > > James- Hide quoted text -
>
> > > - Show quoted text -
>
> > Thanks.
>
> > Also just to clarify, when you get a new set of headers in the log,
> > that indicates a website restart or an idle timeout on the worker
> > process. Is that correct? Could anything else cause new headers to be
> > written?
>
> > Cheers,
>
> > James- Hide quoted text -
>
> > - Show quoted text -
>
> You get a new set of headers whenever HTTP.SYS has to open the log
> file to start writing a log entry to it.
>
> What you have mentioned is a subset of possible actions that can cause
> new headers to be written. There are others, but without a context, it
> is not useful to list them.
>
> //Davidhttp://w3-4u.blogspot.comhttp://blogs.msdn.com/David.Wang
> //- Hide quoted text -
>
> - Show quoted text -

Well, I've been looking at a problem, which from the IIS log file
looks like a db server problem (very slow or timeout on data access
via SQLXML virtual directory, fine when just accessing files on web
server). But there is a set of headers at about the same time. I
suspect that this is a manual website restart in an attempt to solve
the problem, but I'd like to be able to confirm that. As far as I am
aware this isn't logged anywhere? There's nothing in the event log,
although get the following about quarter of an hour later (but I think
it's a red herring as the problem had resolved by then):

Application popup: w3wp.exe - Application Error : The instruction at
"0x4bc4ce39" referenced memory at "0x4bc4ce39". The memory could not
be "read".
 >> Stay informed about: IIS Log Time column: Start or End Time? 

On Oct 22, 2:47 am, JimLad <jamesdbi....TakeThisOut@yahoo.co.uk> wrote:
> On Oct 19, 7:46 pm, David Wang <w3.4....TakeThisOut@gmail.com> wrote:
>
>
>
>
>
> > On Oct 19, 2:48 am, JimLad <jamesdbi....TakeThisOut@yahoo.co.uk> wrote:
>
> > > On Oct 18, 4:02 pm, "Ken Schaefer" <kenREM....TakeThisOut@THISadOpenStatic.com>
> > > wrote:
>
> > > > I believe this is correct. The log entry is one of the last thing performed
> > > > for each request
>
> > > > Cheers
> > > > Ken
>
> > > > "JimLad" <jamesdbi....TakeThisOut@yahoo.co.uk> wrote in message
>
> > > >news:1192712226.033895.124230@y27g2000pre.googlegroups.com...
>
> > > > > Hi,
>
> > > > > In IIS 6.0 Log, does Time represent the end time or the start time?
> > > > > Doesn't matter much normally, but I have some time-out entries where
> > > > > time-taken is 6 minutes where it makes a huge difference.
>
> > > > > I think the time in the log is the end time, and that to get a rough
> > > > > approximation of the start time I need to subtract the time-taken. Am
> > > > > I correct?
>
> > > > > Cheers,
>
> > > > > James- Hide quoted text -
>
> > > > - Show quoted text -
>
> > > Thanks.
>
> > > Also just to clarify, when you get a new set of headers in the log,
> > > that indicates a website restart or an idle timeout on the worker
> > > process. Is that correct? Could anything else cause new headers to be
> > > written?
>
> > > Cheers,
>
> > > James- Hide quoted text -
>
> > > - Show quoted text -
>
> > You get a new set of headers whenever HTTP.SYS has to open the log
> > file to start writing a log entry to it.
>
> > What you have mentioned is a subset of possible actions that can cause
> > new headers to be written. There are others, but without a context, it
> > is not useful to list them.
>
> > //Davidhttp://w3-4u.blogspot.comhttp://blogs.msdn.com/David.Wang
> > //- Hide quoted text -
>
> > - Show quoted text -
>
> Well, I've been looking at a problem, which from the IIS log file
> looks like a db server problem (very slow or timeout on data access
> via SQLXML virtual directory, fine when just accessing files on web
> server). But there is a set of headers at about the same time. I
> suspect that this is a manual website restart in an attempt to solve
> the problem, but I'd like to be able to confirm that. As far as I am
> aware this isn't logged anywhere? There's nothing in the event log,
> although get the following about quarter of an hour later (but I think
> it's a red herring as the problem had resolved by then):
>
> Application popup: w3wp.exe - Application Error : The instruction at
> "0x4bc4ce39" referenced memory at "0x4bc4ce39". The memory could not
> be "read".- Hide quoted text -
>
> - Show quoted text -


A manual website restart can look like that in the log file.

By default, IIS only logs unexpected recycling of worker processes,
such as when it crashes. You can instruct IIS to log *all* (or
selected subset, based on bit-flags) recycling of worker processes.

This is special flag not exposed in the UI (in fact, the UI does not
expose ALL IIS functionality -- only the subset we think most people
will reasonably use. Thus, all the debugging features are not in the
UI). You set it on the Application Pool of interest, or globally
across all Application Pools.

LogEventOnRecycle

http://www.microsoft.com/technet/prodtechnol/WindowsServer2003/Library...S/6f43d

CSCRIPT %SYSTEMDRIVE%\Inetpub\AdminScripts\ADSUTIL.VBS SET W3SVC/
AppPools/MyAppPool/LogEventOnRecycle 255

Your event log entry indicates SOMETHING in the worker process
crashed. I recommend following the following procedures to track it
down and get it resolved. Until you resolve crashes/hangs, strange
things like timeouts can always mysteriously happen.

http://blogs.msdn.com/david.wang/archive/2005/08/29/HOWTO_Understand_a...Diagnos


//David
http://w3-4u.blogspot.com
http://blogs.msdn.com/David.Wang
//
 >> Stay informed about: IIS Log Time column: Start or End Time? 

On Oct 22, 11:11 am, David Wang <w3.4....DeleteThis@gmail.com> wrote:
> On Oct 22, 2:47 am, JimLad <jamesdbi....DeleteThis@yahoo.co.uk> wrote:
>
>
>
>
>
> > On Oct 19, 7:46 pm, David Wang <w3.4....DeleteThis@gmail.com> wrote:
>
> > > On Oct 19, 2:48 am, JimLad <jamesdbi....DeleteThis@yahoo.co.uk> wrote:
>
> > > > On Oct 18, 4:02 pm, "Ken Schaefer" <kenREM....DeleteThis@THISadOpenStatic.com>
> > > > wrote:
>
> > > > > I believe this is correct. The log entry is one of the last thing performed
> > > > > for each request
>
> > > > > Cheers
> > > > > Ken
>
> > > > > "JimLad" <jamesdbi....DeleteThis@yahoo.co.uk> wrote in message
>
> > > > >news:1192712226.033895.124230@y27g2000pre.googlegroups.com...
>
> > > > > > Hi,
>
> > > > > > In IIS 6.0 Log, does Time represent the end time or the start time?
> > > > > > Doesn't matter much normally, but I have some time-out entries where
> > > > > > time-taken is 6 minutes where it makes a huge difference.
>
> > > > > > I think the time in the log is the end time, and that to get a rough
> > > > > > approximation of the start time I need to subtract the time-taken. Am
> > > > > > I correct?
>
> > > > > > Cheers,
>
> > > > > > James- Hide quoted text -
>
> > > > > - Show quoted text -
>
> > > > Thanks.
>
> > > > Also just to clarify, when you get a new set of headers in the log,
> > > > that indicates a website restart or an idle timeout on the worker
> > > > process. Is that correct? Could anything else cause new headers to be
> > > > written?
>
> > > > Cheers,
>
> > > > James- Hide quoted text -
>
> > > > - Show quoted text -
>
> > > You get a new set of headers whenever HTTP.SYS has to open the log
> > > file to start writing a log entry to it.
>
> > > What you have mentioned is a subset of possible actions that can cause
> > > new headers to be written. There are others, but without a context, it
> > > is not useful to list them.
>
> > > //Davidhttp://w3-4u.blogspot.comhttp://blogs.msdn.com/David.Wang
> > > //- Hide quoted text -
>
> > > - Show quoted text -
>
> > Well, I've been looking at a problem, which from the IIS log file
> > looks like a db server problem (very slow or timeout on data access
> > via SQLXML virtual directory, fine when just accessing files on web
> > server). But there is a set of headers at about the same time. I
> > suspect that this is a manual website restart in an attempt to solve
> > the problem, but I'd like to be able to confirm that. As far as I am
> > aware this isn't logged anywhere? There's nothing in the event log,
> > although get the following about quarter of an hour later (but I think
> > it's a red herring as the problem had resolved by then):
>
> > Application popup: w3wp.exe - Application Error : The instruction at
> > "0x4bc4ce39" referenced memory at "0x4bc4ce39". The memory could not
> > be "read".- Hide quoted text -
>
> > - Show quoted text -
>
> A manual website restart can look like that in the log file.
>
> By default, IIS only logs unexpected recycling of worker processes,
> such as when it crashes. You can instruct IIS to log *all* (or
> selected subset, based on bit-flags) recycling of worker processes.
>
> This is special flag not exposed in the UI (in fact, the UI does not
> expose ALL IIS functionality -- only the subset we think most people
> will reasonably use. Thus, all the debugging features are not in the
> UI). You set it on the Application Pool of interest, or globally
> across all Application Pools.
>
> LogEventOnRecycle
>
> http://www.microsoft.com/technet/prodtechnol/WindowsServer2003/Librar...
>
> CSCRIPT %SYSTEMDRIVE%\Inetpub\AdminScripts\ADSUTIL.VBS SET W3SVC/
> AppPools/MyAppPool/LogEventOnRecycle 255
>
> Your event log entry indicates SOMETHING in the worker process
> crashed. I recommend following the following procedures to track it
> down and get it resolved. Until you resolve crashes/hangs, strange
> things like timeouts can always mysteriously happen.
>
> http://blogs.msdn.com/david.wang/archive/2005/08/29/HOWTO_Understand_...
>
> //Davidhttp://w3-4u.blogspot.comhttp://blogs.msdn.com/David.Wang
> //- Hide quoted text -
>
> - Show quoted text -

Thanks David. Very helpful.

Cheers,

James
 >> Stay informed about: IIS Log Time column: Start or End Time?