More accurate logging of requests per connection

[Dan Poirier <po...@pobox.com>]

I recently contributed a new %k log format that is intended to log how 
many requests have been handled on the current connection.  It does this 
by logging the value of conn->keepalives.

However, conn->keepalives isn't, strictly speaking, the number of 
requests the connection has handled.  If keepalives are disabled, it's 
zero.  It's also not incremented when the request count reaches 
MaxKeepAliveRequests, so with e.g. MaxKeepAliveRequests 3, it logs 1,2,3,3.

The attached patch adjusts the value logged, so it's always 1 if 
keepalives are disabled, and if it's the last request (conn->keepalive 
== AP_CONN_CLOSE), we add one so the values logged are 1,2,3,4 instead 
of 1,2,3,3.

There's one remaining problem.  There are some error paths which set 
conn->keepalive to AP_CONN_CLOSE after conn->keepalives has already been 
incremented, and in that case, this logging code will log a value that's 
one too many.  I don't think that's a terrible problem, but I'd welcome 
suggestions on how to catch that case.

Thanks.
Dan Poirier
poirier@pobox.com

Re: More accurate logging of requests per connection

[Jim Jagielski <ji...@jaguNET.com>]

On Sep 19, 2008, at 11:33 AM, Dan Poirier wrote:

> On Fri, September 19, 2008 11:18 am, Jim Jagielski wrote:
>> A better interpretation would be, I think, the number of keepalive
>> requests on that connection. So a '1' would be the 1st keepalive
>> request, 2 would be the 2nd, etc... So a '0' would be the
>> initial request, and would be applicable whether keepalives
>> are enabled or not. This would make the logic simpler.
>
> That works.  The remaining issue, which is minor, is that since
> ap_set_keepalive() doesn't increment connection->keepalives on the
> last request, the value logged will be N-1 for both the N-1 and N'th
> keepalive request.  But I don't imagine most connections will ever
> see the N'th keepalive request.

Unless it is small, agreed... still, might be worthwhile to
handle it as you suggest anyway. :)

Re: More accurate logging of requests per connection

[Dan Poirier <po...@pobox.com>]

On Fri, September 19, 2008 11:18 am, Jim Jagielski wrote:
> A better interpretation would be, I think, the number of keepalive
> requests on that connection. So a '1' would be the 1st keepalive
> request, 2 would be the 2nd, etc... So a '0' would be the
> initial request, and would be applicable whether keepalives
> are enabled or not. This would make the logic simpler.

That works.  The remaining issue, which is minor, is that since
ap_set_keepalive() doesn't increment connection->keepalives on the
last request, the value logged will be N-1 for both the N-1 and N'th
keepalive request.  But I don't imagine most connections will ever
see the N'th keepalive request.

-- 
Dan Poirier <po...@pobox.com>

Re: More accurate logging of requests per connection

[Jim Jagielski <ji...@apache.org>]

A better interpretation would be, I think, the number of keepalive
requests on that connection. So a '1' would be the 1st keepalive
request, 2 would be the 2nd, etc... So a '0' would be the
initial request, and would be applicable whether keepalives
are enabled or not. This would make the logic simpler.

On Sep 16, 2008, at 1:56 PM, Dan Poirier wrote:

> I recently contributed a new %k log format that is intended to log  
> how many requests have been handled on the current connection.  It  
> does this by logging the value of conn->keepalives.
>
> However, conn->keepalives isn't, strictly speaking, the number of  
> requests the connection has handled.  If keepalives are disabled,  
> it's zero.  It's also not incremented when the request count reaches  
> MaxKeepAliveRequests, so with e.g. MaxKeepAliveRequests 3, it logs  
> 1,2,3,3.
>
> The attached patch adjusts the value logged, so it's always 1 if  
> keepalives are disabled, and if it's the last request (conn- 
> >keepalive == AP_CONN_CLOSE), we add one so the values logged are  
> 1,2,3,4 instead of 1,2,3,3.
>
> There's one remaining problem.  There are some error paths which set  
> conn->keepalive to AP_CONN_CLOSE after conn->keepalives has already  
> been incremented, and in that case, this logging code will log a  
> value that's one too many.  I don't think that's a terrible problem,  
> but I'd welcome suggestions on how to catch that case.
>
> Thanks.
> Dan Poirier
> poirier@pobox.com
>
>
>
> Index: modules/loggers/mod_log_config.c
> ===================================================================
> --- modules/loggers/mod_log_config.c	(revision 693854)
> +++ modules/loggers/mod_log_config.c	(working copy)
> @@ -697,7 +697,28 @@
>
> static const char *log_requests_on_connection(request_rec *r, char *a)
> {
> -    return apr_itoa(r->pool, r->connection->keepalives);
> +    int num_requests;
> +    if (!r->server->keep_alive) {
> +        num_requests = 1;
> +    } else if (r->connection->keepalive == AP_CONN_CLOSE) {
> +        num_requests = r->connection->keepalives + 1;
> +    } else {
> +        num_requests = r->connection->keepalives;
> +    }
> +    return apr_itoa(r->pool, num_requests);
> }
>
> /*****************************************************************