On March 31, 2011 4:28 , Janne H <jannehson51@xxxxxxxxx> wrote:
In the access log, what is acctually meassured with the %D option? The docs say: %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. -- Mark Montague mark@xxxxxxxxxxx --------------------------------------------------------------------- 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@xxxxxxxxxxxxxxxx " from the digest: users-digest-unsubscribe@xxxxxxxxxxxxxxxx For additional commands, e-mail: users-help@xxxxxxxxxxxxxxxx
|