[mp2] Problems with $r->bytes_sent and $r->status in log handler

[Markus Wichitill <ma...@gmx.de>]

Hi,

I have a log handler that is supposed to log whether certain 
HTTP-authenticated customers were able to completely download their digital 
deliveries. The mod_perl 1.x version works just fine.

Now under SuSE Linux 9.2/Apache 2.0.53/mod_perl 2.0 RC4, $r->bytes_sent 
seems to always contain the full size of the file resource, not the bytes 
really sent to the client on an interrupted download. Unless it's a byte 
range request, in which case it contains the full size of the range. Does 
anybody know whether this is perhaps expected behaviour under Apache2, maybe 
a result of its fancy filter architecture? Could it be a mod_perl bug,  or 
is mod_perl only a thin wrapper around the C structures in this case, and 
therefore most likely innocent?

If I add mod_ssl to the mix, $r->status acts wonky, too. When it should be 
200 (and $r->status_line contains the correct "200 OK"), it's the apparently 
nonsensical 104. When it should be 206 for a byte range request (and 
$r->status_line contains the correct "206 Partial Content"), it's 200. Other 
people with the same user agent managed to produce other combinations, 
though. Any ideas?

Somewhat simplified code (for mod_perl 2.0 RC4):

package MyClient::AuthLog2;
use strict;
use Apache::Const -compile => qw(OK);
use Apache::Util ();
use APR::Finfo ();

sub handler
{
   my $r = shift();

   my $user = $r->user;
   if ($user) {
     my $date = Apache::Util::ht_time(
       $r->pool, $r->request_time, "%Y-%m-%d %H:%M", 0);
     my $remote = $r->connection->get_remote_host();
     my $uri = $r->uri;
     my $status = $r->status;
     my $status_line = $r->status_line;
     my $bytes_file = $r->finfo->size;
     my $bytes_sent = $r->bytes_sent;
     my $result = "";

     if ($status == 200 && $bytes_sent == $bytes_file) {
       $result = 'complete'
     }
     elsif ($status == 200 && $bytes_sent != $bytes_file) {
       $result = 'incomplete'
     }
     elsif ($status == 206) {
       $result = 'partial'
     }

     open LOG, ">>/var/log/apache2/auth_log" or warn "Can't open auth log";
     print LOG "$date|$remote|$user|$uri|",
       "$status|$status_line|$bytes_file|$bytes_sent|$result\n";
     close LOG;
   }

   return Apache::OK;
}

Re: [mp2] Problems with $r->bytes_sent and $r->status in log handler

[Stas Bekman <st...@stason.org>]

Markus Wichitill wrote:
> Hi,
> 
> I have a log handler that is supposed to log whether certain 
> HTTP-authenticated customers were able to completely download their 
> digital deliveries. The mod_perl 1.x version works just fine.
> 
> Now under SuSE Linux 9.2/Apache 2.0.53/mod_perl 2.0 RC4, $r->bytes_sent 
> seems to always contain the full size of the file resource, not the 
> bytes really sent to the client on an interrupted download. Unless it's 
> a byte range request, in which case it contains the full size of the 
> range. Does anybody know whether this is perhaps expected behaviour 
> under Apache2, maybe a result of its fancy filter architecture? Could it 
> be a mod_perl bug,  or is mod_perl only a thin wrapper around the C 
> structures in this case, and therefore most likely innocent?

It's not even a wrapper in mp2, it's just an accessor to the r->bytes_sent 
record entry:

apr_off_t
bytes_sent(obj, val=0)
     Apache2::RequestRec obj
     apr_off_t val

     PREINIT:
     /*nada*/


     CODE:
     RETVAL = (apr_off_t) obj->bytes_sent;

     if (items > 1) {

          obj->bytes_sent = (apr_off_t) val;
     }

     OUTPUT:
     RETVAL

So you should probably ask at httpd-dev, Markus.

> If I add mod_ssl to the mix, $r->status acts wonky, too. When it should 
> be 200 (and $r->status_line contains the correct "200 OK"), it's the 
> apparently nonsensical 104. When it should be 206 for a byte range 
> request (and $r->status_line contains the correct "206 Partial 
> Content"), it's 200. Other people with the same user agent managed to 
> produce other combinations, though. Any ideas?

Same here:

int
status(obj, val=0)
     Apache2::RequestRec obj
     int val

     PREINIT:
     /*nada*/


     CODE:
     RETVAL = (int) obj->status;

     if (items > 1) {

          obj->status = (int) val;
     }

     OUTPUT:
     RETVAL


-- 
__________________________________________________________________
Stas Bekman            JAm_pH ------> Just Another mod_perl Hacker
http://stason.org/     mod_perl Guide ---> http://perl.apache.org
mailto:stas@stason.org http://use.perl.org http://apacheweek.com
http://modperlbook.org http://apache.org   http://ticketmaster.com

Re: [mp2] Problems with $r->bytes_sent and $r->status in log handler

[Joe Orton <jo...@redhat.com>]

On Mon, Apr 18, 2005 at 10:49:10PM +0200, Markus Wichitill wrote:
> Hi,
> 
> I have a log handler that is supposed to log whether certain 
> HTTP-authenticated customers were able to completely download their digital 
> deliveries. The mod_perl 1.x version works just fine.
> 
> Now under SuSE Linux 9.2/Apache 2.0.53/mod_perl 2.0 RC4, $r->bytes_sent 
> seems to always contain the full size of the file resource, not the bytes 
> really sent to the client on an interrupted download. Unless it's a byte 
> range request, in which case it contains the full size of the range. Does 
> anybody know whether this is perhaps expected behaviour under Apache2, 
> maybe a result of its fancy filter architecture? Could it be a mod_perl 
> bug,  or is mod_perl only a thin wrapper around the C structures in this 
> case, and therefore most likely innocent?

Yes, r->bytes_sent is a misnomer, it's just set to the size of the
response body in 2.0 as you surmise.  IIRC the issue is that buckets
from one request may get buffered and not sent during the lifetime of
the request, so it's not easy to give a truly accurate count of "bytes
sent to the network for this response".

I don't know about your r->status issue, if you think this is some
mod_ssl issue and can make a C module which reproduces it I'll take a
look, preferably filed in bugzilla.

Regards,

joe