httpd-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Janne H <jannehso...@yahoo.com>
Subject Re: [users@httpd] What is %D in access log meassuring?
Date Thu, 31 Mar 2011 12:37:24 GMT
--- On Thu, 3/31/11, Mark Montague <mark@catseye.org> wrote:

> > In the access log, what is acctually meassured with
> the %D option?
> > 
> > %D The time taken to serve the request, in
> microseconds.
> > 
> > but what is included in this time? Is the stopwatch
> started when the last byte of the request is received and
> stoped when the first  byte of the response is ready to
> be sent?
> > 
> > Or is the stopwatch started when the first byte of the
> request is received and stoped when the last byte of the
> response has been sent? That is, it is including network
> sending time?
> From the source code for httpd-2.2.17,
> modules/loggers/mod_log_config.c, line 650, %D is:
> 
> apr_time_now() - r->request_time)
> 
> "now" in this context means "the time at which the log line
> is being written".  This is after all data has been
> sent to the client (logging the amount of data sent the the
> client is one of the things that can be logged).  Note
> that the connection may remain open past the last byte being
> sent to the client (keepalive, etc.).
> 
> r->request_time gets set in server/protocol.c, line 617,
> after the first non-blank line of the request (e.g., "GET /
> HTTP/1.1\r\n")
> made by the client is completely received.  This is
> close to, but a little bit after (16 bytes after, in the
> example I just gave) the first byte of the request was
> received.  So the time to receive the first line of the
> request is not counted in %D, but the time to receive any
> subsequent lines of the same request are counted.
> 
> I hope this helps.
> 

Well, I'm still a little confused.
I'm trying to find out why the accesslog shows the line


ipA [31/Mar/2011] "GET /file.jpg HTTP/1.0" 200 42981 "-" "ApacheBench/2.3" 3560
ipB [31/Mar/2011] "GET /file.jpg HTTP/1.0" 200 42981 "-" "ApacheBench/2.3" 93574

(the ipA is much "closer" to the server than ipB).

i also tried a curl download with a limit on 1000 bytes/s but the time logged in access-log
many orders of magnitute away from the acctual time it took to receive the image (about 42
seconds) So I guess the time that is logged is "when apache has sent the final bytes to the
level below in the network stack?


---------------------------------------------------------------------
The official User-To-User support forum of the Apache HTTP Server Project.
See <URL:http://httpd.apache.org/userslist.html> for more info.
To unsubscribe, e-mail: users-unsubscribe@httpd.apache.org
   "   from the digest: users-digest-unsubscribe@httpd.apache.org
For additional commands, e-mail: users-help@httpd.apache.org


Mime
View raw message