Re: [PATCH] checking for failures encountered by core_output_filter

["William A. Rowe, Jr." <wr...@apache.org>]

At 10:07 AM 11/4/2002, Jeff Trawick wrote:
>Justin Erenkrantz <je...@apache.org> writes:
>
>> >> I don't buy that logic at all.  Why should we be returning
>> >> APR_SUCCESS here?  We want to signal an error, so that the filters
>> >> stop what they are doing and exit.
>> >
>> > Talk to Ryan :)
>> 
>> Well, he ain't here no more.  Just us folks.  Do you (or anyone else)
>> see a reason why we shouldn't change this?
>
>interpret "Talk to Ryan" as "I can't justify the current behavior" :)
>
>We should make the change to return an APR error code here.

Agreed.  If we really have to dig through and find ALL of the areas where
the current behavior disagrees, this seems like the time to do it.  Choose
one; return apr_status_t and pay attention only to r->status and c->aborted
for logging (the right decision IMHO) or return HTTP statuses (ick.)

Either way it's the same amount of work, no?

I'm discovering the same confusion in the SSL filter right now, which has
never paid attention to c->aborted within ssl_engine_io.c.


>> > I'm kinda stuck thinking that the philosophy should be that we log
>> > whatever was written to the client in the status line, but there are
>> > some implementation details with that one.
>> 
>> How do we differentiate between a 200 that all the data was sent for
>> and a 200 where the client aborted?  If someone looked at the access
>> logs, they would see that the transmitted length wasn't correct in the
>> aborted case.  Perhaps that was Ryan's initial motivation - did he
>> want the length to be what we wanted to send not what we actually
>> sent?  (mod_logio is bringing up some of these concerns as well.)
>> 
>> I guess I'd like to see some notation in access log that indicates,
>> "Hey, we know we didn't send everything, but that's because they left
>> in the middle."  Yes, it also might be noted in the error log, but I
>> gotta believe it's goodness to have tools looking at just the access
>> logs know that the client aborted.
>
>FWIW, this is what happens with 1.3 when the client drops the
>connection before reading the entire response.  In this case, the
>client read several bytes of a 1MB response (though the client TCP
>accepted a lot more).
>
>  [Mon Nov  4 10:31:22 2002] [info] [client 9.27.32.119] (32)Broken pipe: 
>  client stopped connection before send mmap completed
>
>  9.27.32.119 - - [04/Nov/2002:10:31:22 -0500] "GET /bigfile.html" 200 65536
>
>Even though Apache could have noticed that it sent only 64K out of
>1MB, it still logged 200.  The 64K isn't even an indication of how
>much the client really read.  It is simply how much TCP was willing to
>buffer.  Also, I suspect that we can hit the first indication of a
>dropped connection after the previous response has been noted in the
>log.

Right, and that's good behavior.  The REQUEST resulted in a 200.  What
the RESPONSE did while serving it is another matter.

>I'm not sure what promises we can make about what is in the access
>log.
>
>> > One issue with that is that the filter that encounters the error
>> > really should do the logging so that the most specific information
>> > is available.  If some other code also logs less-specific info,
>> > then it is all for naught.
>> 
>> Makes sense.  So, core_output_filter should be calling
>> ap_log_rerror. Hmm.  Does it have access to the request_rec?  Didn't
>> we change that? Or, was I vetoed on that?  -- justin
>
>I don't recall that conversation.  Regardless, I wonder how 
>core_output_filter could know the r associated with a particular
>bucket?

It shouldn't need to... the response should probably percolate back
to the handler, via r->status, but the connection filter shouldn't need
to be aware of it.  If you wanted to log the 'error' associated with the
request (e.g. transmission troubles), that would probably need to 
percolate with the bucket.

Bill