You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@httpd.apache.org by Doug MacEachern <do...@covalent.net> on 2001/11/21 00:23:47 UTC

core output filter buffering

can someone explain how the core output buffering is supposed to work?
if you look at
httpd-test/perl-framework/c-modules/test_pass_brigade/mod_test_pass_brigade.c
this intentionally creates a brigade with just one bucket and calls
ap_pass_brigade with that bucket.  you can make a request like so:
http://localhost:8529/test_pass_brigade?1024,500000
which means use a buffer size of 1024 bytes and send 500k total.
with the patch below for tracing i see this in the error_log:
writev 15543 bytes
writev 16384 bytes
writev 10240 bytes
writev 8192 bytes
... a bunch of 8192's ...
writev 7456 bytes
writev 0 bytes

then with 8192,500000:
writev 41143 bytes
writev 8192 bytes
... a bunch of 8192's ...
writev 288 bytes
writev 0 bytes

is this the expected behavior?  reason i am asking is that mod_ssl pretty
much does what mod_test_pass_brigade.c does with 8192 size buffers.  i
have a patch in the works to optimize that, but want to make sure core
output filter is behaving as expected first.  i thought it would buffer
until it could fill AP_MIN_BYTES_TO_WRITE * MAX_IOVEC_TO_WRITE.  but then
again, i guess there is a reason it doesn't, since the OLD_WRITE filter
does its own buffering.  insight greatly appreciated, thanks.

p.s.
i realize the answer is probably buried in the archives, maybe somebody
wants to write a documented summary?

--- server/core.c       2001/11/19 22:36:20     1.100
+++ server/core.c       2001/11/20 22:52:56
@@ -3201,7 +3201,7 @@
         }
         else {
             apr_size_t unused_bytes_sent;
-
+            fprintf(stderr, "writev %d bytes\n", nbytes);
             rv = writev_it_all(net->client_socket, 
                                vec, nvec, 
                                nbytes, &unused_bytes_sent);



Re: core output filter buffering

Posted by Ryan Bloom <rb...@covalent.net>.
On Tuesday 20 November 2001 07:48 pm, Doug MacEachern wrote:
> On Tue, 20 Nov 2001, Bill Stoddard wrote:
> > What is the source of the bytes being written? Is it a pipe? Or a file?
>
> a heap bucket.  i guess my question should be:
> when using memory (heap,transient,pool,etc) buckets, what is the optimal
> apr_brigade_length() to build up before passing to core_output_filter?

It shouldn't matter.  I looked at your module, and the behavior you are
describing looks like a bug.  I am hoping to look at this later tonight.  I should
be able to report about what is happening in the next hour or two.  

Kelly is making dinner, or I would do it sooner.  If I'm working on the computer
when she is ready to eat, she get's upset, because I spend all of my time on
the computer.  :-)

Ryan
______________________________________________________________
Ryan Bloom				rbb@apache.org
Covalent Technologies			rbb@covalent.net
--------------------------------------------------------------

Re: core output filter buffering

Posted by Doug MacEachern <do...@covalent.net>.
On Tue, 20 Nov 2001, Bill Stoddard wrote:

> What is the source of the bytes being written? Is it a pipe? Or a file?

a heap bucket.  i guess my question should be:
when using memory (heap,transient,pool,etc) buckets, what is the optimal
apr_brigade_length() to build up before passing to core_output_filter? 



Re: core output filter buffering

Posted by Bill Stoddard <bi...@wstoddard.com>.
What is the source of the bytes being written? Is it a pipe? Or a file?

If it is a pipe, you can experience these suboptimal packets because of code in the
content_length filter. The idea is to read bytes from the pipe in non blocking mode. If
the pipe is empty, then flush what you have already read to the network and go back to the
pipe for more.

1.3 behaviour is slightly different. In 1.3, only the first read from the pipe is
nonblocking. If a pipe read returns EWOULDBLOCK, you flush what you have to the net then
all subsequent pipe reads are blocking. We can change this to more closely resemble 1.3
behaviour quite easily although I sort of like the 2.0 behaviour as it is now; you don't
hold bytes up in the server if you don't have to which can be useful for some apps.  The
first pipe read definitely needs to be non blocking though.

Bill

----- Original Message -----
From: "Doug MacEachern" <do...@covalent.net>
To: <de...@httpd.apache.org>
Sent: Tuesday, November 20, 2001 6:23 PM
Subject: core output filter buffering


> can someone explain how the core output buffering is supposed to work?
> if you look at
> httpd-test/perl-framework/c-modules/test_pass_brigade/mod_test_pass_brigade.c
> this intentionally creates a brigade with just one bucket and calls
> ap_pass_brigade with that bucket.  you can make a request like so:
> http://localhost:8529/test_pass_brigade?1024,500000
> which means use a buffer size of 1024 bytes and send 500k total.
> with the patch below for tracing i see this in the error_log:
> writev 15543 bytes
> writev 16384 bytes
> writev 10240 bytes
> writev 8192 bytes
> ... a bunch of 8192's ...
> writev 7456 bytes
> writev 0 bytes
>
> then with 8192,500000:
> writev 41143 bytes
> writev 8192 bytes
> ... a bunch of 8192's ...
> writev 288 bytes
> writev 0 bytes
>
> is this the expected behavior?  reason i am asking is that mod_ssl pretty
> much does what mod_test_pass_brigade.c does with 8192 size buffers.  i
> have a patch in the works to optimize that, but want to make sure core
> output filter is behaving as expected first.  i thought it would buffer
> until it could fill AP_MIN_BYTES_TO_WRITE * MAX_IOVEC_TO_WRITE.  but then
> again, i guess there is a reason it doesn't, since the OLD_WRITE filter
> does its own buffering.  insight greatly appreciated, thanks.
>
> p.s.
> i realize the answer is probably buried in the archives, maybe somebody
> wants to write a documented summary?
>
> --- server/core.c       2001/11/19 22:36:20     1.100
> +++ server/core.c       2001/11/20 22:52:56
> @@ -3201,7 +3201,7 @@
>          }
>          else {
>              apr_size_t unused_bytes_sent;
> -
> +            fprintf(stderr, "writev %d bytes\n", nbytes);
>              rv = writev_it_all(net->client_socket,
>                                 vec, nvec,
>                                 nbytes, &unused_bytes_sent);
>
>


Re: core output filter buffering

Posted by Ryan Bloom <rb...@covalent.net>.
On Wednesday 21 November 2001 10:29 am, Ian Holsman wrote:
> On Wed, 2001-11-21 at 10:14, Ryan Bloom wrote:
> > On Tuesday 20 November 2001 03:23 pm, Doug MacEachern wrote:
> >
> > Okay, I have looked at this again.  I have a patch, but it is doing too
> > much buffering now.  :-(  I'm hoping to fix this soon.  However, there is
> > a misunderstanding in the question below that I want to clear up.  We try
> > to buffer up to AP_MIN_BYTES_TO_WRITE in the core, never more than that. 
> > With that logic, the behavior you are seeing is correct.  However, you
> > are seeing the correct behavior because of the values that you chose.
> >
> > :-)
>
> Hey Ryan.
> while your looking at buffering
> is there any way to buffer the stuff up over brigades?
> mod-include creates a seperate brigade per virtual include and you can
> get lots of small packets being sent

The core should be doing this for you.  I think you are seeing the problem
I described above.  Namely, your SSI files are creating more than 16 brigades
that combine to less than 8192 bytes.  This is what causes the core to send
the data too soon.  I am about to commit a patch that stops that behavior.  Can
you test with the patch and let me know if it solves your problem too?

If not, could you send me a test case?

Ryan

______________________________________________________________
Ryan Bloom				rbb@apache.org
Covalent Technologies			rbb@covalent.net
--------------------------------------------------------------

Re: core output filter buffering

Posted by Ian Holsman <ia...@cnet.com>.
On Wed, 2001-11-21 at 10:14, Ryan Bloom wrote:
> On Tuesday 20 November 2001 03:23 pm, Doug MacEachern wrote:
> 
> Okay, I have looked at this again.  I have a patch, but it is doing too much
> buffering now.  :-(  I'm hoping to fix this soon.  However, there is a 
> misunderstanding in the question below that I want to clear up.  We try
> to buffer up to AP_MIN_BYTES_TO_WRITE in the core, never more than
> that.  With that logic, the behavior you are seeing is correct.  However,
> you are seeing the correct behavior because of the values that you chose.
> :-)
> 
Hey Ryan.
while your looking at buffering 
is there any way to buffer the stuff up over brigades?
mod-include creates a seperate brigade per virtual include and you can
get lots of small packets being sent 

> If you use
> 
> GET /test?20,500
> 
> You will see two writes, one for 476, and one for 200.  That is incorrect.
> 
> Ryan
> 
> > can someone explain how the core output buffering is supposed to work?
> > if you look at
> > httpd-test/perl-framework/c-modules/test_pass_brigade/mod_test_pass_brigade
> >.c this intentionally creates a brigade with just one bucket and calls
> > ap_pass_brigade with that bucket.  you can make a request like so:
> > http://localhost:8529/test_pass_brigade?1024,500000
> > which means use a buffer size of 1024 bytes and send 500k total.
> > with the patch below for tracing i see this in the error_log:
> > writev 15543 bytes
> > writev 16384 bytes
> > writev 10240 bytes
> > writev 8192 bytes
> > ... a bunch of 8192's ...
> > writev 7456 bytes
> > writev 0 bytes
> >
> > then with 8192,500000:
> > writev 41143 bytes
> > writev 8192 bytes
> > ... a bunch of 8192's ...
> > writev 288 bytes
> > writev 0 bytes
> >
> > is this the expected behavior?  reason i am asking is that mod_ssl pretty
> > much does what mod_test_pass_brigade.c does with 8192 size buffers.  i
> > have a patch in the works to optimize that, but want to make sure core
> > output filter is behaving as expected first.  i thought it would buffer
> > until it could fill AP_MIN_BYTES_TO_WRITE * MAX_IOVEC_TO_WRITE.  but then
> > again, i guess there is a reason it doesn't, since the OLD_WRITE filter
> > does its own buffering.  insight greatly appreciated, thanks.
> >
> > p.s.
> > i realize the answer is probably buried in the archives, maybe somebody
> > wants to write a documented summary?
> >
> > --- server/core.c       2001/11/19 22:36:20     1.100
> > +++ server/core.c       2001/11/20 22:52:56
> > @@ -3201,7 +3201,7 @@
> >          }
> >          else {
> >              apr_size_t unused_bytes_sent;
> > -
> > +            fprintf(stderr, "writev %d bytes\n", nbytes);
> >              rv = writev_it_all(net->client_socket,
> >                                 vec, nvec,
> >                                 nbytes, &unused_bytes_sent);
> 
> -- 
> 
> ______________________________________________________________
> Ryan Bloom				rbb@apache.org
> Covalent Technologies			rbb@covalent.net
> --------------------------------------------------------------
-- 
Ian Holsman          IanH@cnet.com
Performance Measurement & Analysis
CNET Networks   -   (415) 344-2608


Re: core output filter buffering

Posted by Ryan Bloom <rb...@covalent.net>.
On Tuesday 20 November 2001 03:23 pm, Doug MacEachern wrote:

Okay, I have looked at this again.  I have a patch, but it is doing too much
buffering now.  :-(  I'm hoping to fix this soon.  However, there is a 
misunderstanding in the question below that I want to clear up.  We try
to buffer up to AP_MIN_BYTES_TO_WRITE in the core, never more than
that.  With that logic, the behavior you are seeing is correct.  However,
you are seeing the correct behavior because of the values that you chose.
:-)

If you use

GET /test?20,500

You will see two writes, one for 476, and one for 200.  That is incorrect.

Ryan

> can someone explain how the core output buffering is supposed to work?
> if you look at
> httpd-test/perl-framework/c-modules/test_pass_brigade/mod_test_pass_brigade
>.c this intentionally creates a brigade with just one bucket and calls
> ap_pass_brigade with that bucket.  you can make a request like so:
> http://localhost:8529/test_pass_brigade?1024,500000
> which means use a buffer size of 1024 bytes and send 500k total.
> with the patch below for tracing i see this in the error_log:
> writev 15543 bytes
> writev 16384 bytes
> writev 10240 bytes
> writev 8192 bytes
> ... a bunch of 8192's ...
> writev 7456 bytes
> writev 0 bytes
>
> then with 8192,500000:
> writev 41143 bytes
> writev 8192 bytes
> ... a bunch of 8192's ...
> writev 288 bytes
> writev 0 bytes
>
> is this the expected behavior?  reason i am asking is that mod_ssl pretty
> much does what mod_test_pass_brigade.c does with 8192 size buffers.  i
> have a patch in the works to optimize that, but want to make sure core
> output filter is behaving as expected first.  i thought it would buffer
> until it could fill AP_MIN_BYTES_TO_WRITE * MAX_IOVEC_TO_WRITE.  but then
> again, i guess there is a reason it doesn't, since the OLD_WRITE filter
> does its own buffering.  insight greatly appreciated, thanks.
>
> p.s.
> i realize the answer is probably buried in the archives, maybe somebody
> wants to write a documented summary?
>
> --- server/core.c       2001/11/19 22:36:20     1.100
> +++ server/core.c       2001/11/20 22:52:56
> @@ -3201,7 +3201,7 @@
>          }
>          else {
>              apr_size_t unused_bytes_sent;
> -
> +            fprintf(stderr, "writev %d bytes\n", nbytes);
>              rv = writev_it_all(net->client_socket,
>                                 vec, nvec,
>                                 nbytes, &unused_bytes_sent);

-- 

______________________________________________________________
Ryan Bloom				rbb@apache.org
Covalent Technologies			rbb@covalent.net
--------------------------------------------------------------

Re: core output filter buffering

Posted by Ryan Bloom <rb...@covalent.net>.
On Tuesday 20 November 2001 03:23 pm, Doug MacEachern wrote:

This is a bug!  A big one at that.  The problem is that you are writing very
small sets of data at one time.  The code tries very hard to use writev if at
all possible, because that will improve our performance.

The problem that we are having in this case, is that once we see 16 buckets,
we send the data no matter how much data we have.  This is just plain wrong.
If we don't have AP_MIN_BYTES_TO_WRITE, we should buffer until we do or
until we get a FLUSH or EOS bucket.

I am looking at this now, expect a patch either late tonight or early tomorrow.
I don't know how extensive the bug is, I need to really look at the core output
filter in detail to fix this.

Ryan

> can someone explain how the core output buffering is supposed to work?
> if you look at
> httpd-test/perl-framework/c-modules/test_pass_brigade/mod_test_pass_brigade
>.c this intentionally creates a brigade with just one bucket and calls
> ap_pass_brigade with that bucket.  you can make a request like so:
> http://localhost:8529/test_pass_brigade?1024,500000
> which means use a buffer size of 1024 bytes and send 500k total.
> with the patch below for tracing i see this in the error_log:
> writev 15543 bytes
> writev 16384 bytes
> writev 10240 bytes
> writev 8192 bytes
> ... a bunch of 8192's ...
> writev 7456 bytes
> writev 0 bytes
>
> then with 8192,500000:
> writev 41143 bytes
> writev 8192 bytes
> ... a bunch of 8192's ...
> writev 288 bytes
> writev 0 bytes
>
> is this the expected behavior?  reason i am asking is that mod_ssl pretty
> much does what mod_test_pass_brigade.c does with 8192 size buffers.  i
> have a patch in the works to optimize that, but want to make sure core
> output filter is behaving as expected first.  i thought it would buffer
> until it could fill AP_MIN_BYTES_TO_WRITE * MAX_IOVEC_TO_WRITE.  but then
> again, i guess there is a reason it doesn't, since the OLD_WRITE filter
> does its own buffering.  insight greatly appreciated, thanks.
>
> p.s.
> i realize the answer is probably buried in the archives, maybe somebody
> wants to write a documented summary?
>
> --- server/core.c       2001/11/19 22:36:20     1.100
> +++ server/core.c       2001/11/20 22:52:56
> @@ -3201,7 +3201,7 @@
>          }
>          else {
>              apr_size_t unused_bytes_sent;
> -
> +            fprintf(stderr, "writev %d bytes\n", nbytes);
>              rv = writev_it_all(net->client_socket,
>                                 vec, nvec,
>                                 nbytes, &unused_bytes_sent);

-- 

______________________________________________________________
Ryan Bloom				rbb@apache.org
Covalent Technologies			rbb@covalent.net
--------------------------------------------------------------