Re: svn commit: r1707087 - /httpd/httpd/trunk/modules/debugging/mod_bucketeer.c

[Jacob Champion]

On 05/02/2017 10:14 AM, Ruediger Pluem wrote> On 04/28/2017 10:50 PM, 
Jacob Champion wrote:

...why does the EOR bucket have memory ownership of a request_rec,
especially when its lifetime is not well defined? And why have we
put business logic into a finalizer? This is ringing all of my
memory management alarm bells.


This dates back to a long time ago
(http://svn.apache.org/viewvc?view=revision=327925) when we
started to add async processing to httpd. We had the issue that we
could not just destroy the request pool, once we "finished" the 
processing of a request, because we could still have buckets and data

created out of the request pool in the async processing of the
filters. Hence the idea was to sent a special final request bucket as
the very last bucket of a request that tells the filter that consumes
the bucket (usually the core output filter) that no data for the
request is coming down the filter stack and that it is now save to
destroy the request pool. And in order to prevent that logic to be
coded in the filter (when it just sees the bucket) it was put in the
"finalizer" code of the eor bucket. You might find this strange, but
IMHO we have this pattern to use cleanups for some business logic
quite often in httpd and we tie a lot of this logic to the lifecycle
of pools. So pools are not just a memory management tool, but also a
lifecycle management tool.


Hi Rüdiger,

I just realized I hadn't responded to this; sorry! Thanks for the 
background.


I have been trying (slowly) to learn enough about the async processing 
chain to participate meaningfully in this discussion, but so far I 
haven't had the time to really dig in. My intuition is that, if pieces 
of the request are disappearing out from under the thread, something is 
wrong with the lifecycle dependency chain (and I've never seen finalizer 
dependencies work out very well in practice). But it's just an idle 
guess without more research.


AFAIK, this is one of the final blockers (if not *the* final blocker, 
fingers crossed) for the trunk autotesting system; hence my interest.


--Jacob

Re: svn commit: r1707087 - /httpd/httpd/trunk/modules/debugging/mod_bucketeer.c

[Ruediger Pluem]

On 04/28/2017 10:50 PM, Jacob Champion wrote:
> On 04/27/2017 02:46 AM, Yann Ylavic wrote:
>> Jacob, does it work better?
> 
> Unfortunately not; now we have crashes in mod_case_filter.
> 
> If you're having trouble reproducing a crash, try using an APR with pool 
> debugging enabled. The poisoned-on-free memory
> is showing up really nicely.
> 
> I ask again, though... ;D
> 
> ...why does the EOR bucket have memory ownership of a request_rec, especially 
> when its lifetime is not well defined? And
> why have we put business logic into a finalizer? This is ringing all of my 
> memory management alarm bells.

This dates back to a long time ago 
(http://svn.apache.org/viewvc?view=revision=327925) when we started to 
add
async processing to httpd. We had the issue that we could not just destroy the 
request pool, once we "finished" the
processing of a request, because we could still have buckets and data created 
out of the request pool in the async
processing of the filters. Hence the idea was to sent a special final request 
bucket as the very last bucket of a
request that tells the filter that consumes the bucket (usually the core output 
filter) that no data for the request is
coming down the filter stack and that it is now save to destroy the request 
pool. And in order to prevent that logic to
be coded in the filter (when it just sees the bucket) it was put in the 
"finalizer" code of the eor bucket.
You might find this strange, but IMHO we have this pattern to use cleanups for 
some business logic quite often
in httpd and we tie a lot of this logic to the lifecycle of pools. So pools are 
not just a memory management tool, but
also a lifecycle management tool.


Regards

Rüdiger

Re: svn commit: r1707087 - /httpd/httpd/trunk/modules/debugging/mod_bucketeer.c

[Jacob Champion]

On 04/27/2017 02:46 AM, Yann Ylavic wrote:

Jacob, does it work better?


Unfortunately not; now we have crashes in mod_case_filter.

If you're having trouble reproducing a crash, try using an APR with pool 
debugging enabled. The poisoned-on-free memory is showing up really nicely.


I ask again, though... ;D

...why does the EOR bucket have memory ownership of a request_rec, 
especially when its lifetime is not well defined? And why have we put 
business logic into a finalizer? This is ringing all of my memory 
management alarm bells.


--Jacob

Re: svn commit: r1707087 - /httpd/httpd/trunk/modules/debugging/mod_bucketeer.c

[Yann Ylavic]

On Thu, Apr 27, 2017 at 2:45 PM, Plüm, Rüdiger, Vodafone Group
 wrote:
> Shouldn't we call apr_brigade_cleanup in any case after ap_pass_brigade?

We should yes, I first did this since we don't want possible r->pool's
buckets staying in bb.
I wanted to cleaning up tmp_bb too when rv != APR_SUCCESS && !eos,
actually that were both upcoming questions if the patch works and
looks reasonable otherwise ;)


Regards,
Yann.

AW: svn commit: r1707087 - /httpd/httpd/trunk/modules/debugging/mod_bucketeer.c

[Plüm , Rüdiger , Vodafone Group]

Shouldn't we call apr_brigade_cleanup in any case after ap_pass_brigade?

Regards

Rüdiger

> -Ursprüngliche Nachricht-
> Von: Yann Ylavic [mailto:ylavic@gmail.com]
> Gesendet: Donnerstag, 27. April 2017 11:47
> An: httpd-dev <dev@httpd.apache.org>
> Betreff: Re: svn commit: r1707087 -
> /httpd/httpd/trunk/modules/debugging/mod_bucketeer.c
> 
> On Wed, Apr 26, 2017 at 11:26 AM, Stefan Eissing
> <stefan.eiss...@greenbytes.de> wrote:
> >
> >> Am 26.04.2017 um 11:14 schrieb Plüm, Rüdiger, Vodafone Group
> <ruediger.pl...@vodafone.com>:
> >>
> >>
> >>
> >>> -Ursprüngliche Nachricht-
> >>> Von: Stefan Eissing [mailto:stefan.eiss...@greenbytes.de]
> >>> Gesendet: Mittwoch, 26. April 2017 10:55
> >>> An: dev@httpd.apache.org
> >>> Betreff: Re: svn commit: r1707087 -
> >>> /httpd/httpd/trunk/modules/debugging/mod_bucketeer.c
> >>>
> >>> Eh, not really into mod_bucketeer and its use cases, but some
> >>> observations after a quick scan:
> >>>
> >>> line 99:
> >>>rv = ap_pass_brigade(f->next, ctx->bb);
> >>>apr_brigade_cleanup(ctx->bb);
> >>>
> >>> line 146:
> >>>rv = ap_pass_brigade(f->next, ctx->bb);
> >>>if (rv) {
> >>>return rv;
> >>>}
> >>>apr_brigade_cleanup(ctx->bb);
> >>>
> >>> such things only work if an EOS always comes *before* an EOR
> >>> bucket (case 1) or of no DATA bucket of any kind follows an EOR.
> >>
> >> Correct, but with the BUCKETEER filter being a resource filter that
> >> should not happen.
> >
> > Because the implementations of everything else in the server do not
> > do it? Should we then add a filter that checks exactly that?
> 
> I don't think that EOR before EOS can happen in HTTP/1, because
> ap_finalize_request_protocol() is always called before
> ap_process_request_after_handler().
> 
> EOS is the signal for request filters to get out of the way, so this
> is probably what ap_request_core_filter() should do too, and the
> purpose of the attached patch.
> This patch could use EOR instead, but I find EOS more "semantically"
> correct for a request filter (we don't need to set aside anything
> after it), while EOR would be crash safe only...
> 
> Jacob, does it work better?
> 
> 
> Regards,
> Yann.

Re: svn commit: r1707087 - /httpd/httpd/trunk/modules/debugging/mod_bucketeer.c

[Yann Ylavic]

On Wed, Apr 26, 2017 at 11:26 AM, Stefan Eissing
<stefan.eiss...@greenbytes.de> wrote:
>
>> Am 26.04.2017 um 11:14 schrieb Plüm, Rüdiger, Vodafone Group 
>> <ruediger.pl...@vodafone.com>:
>>
>>
>>
>>> -Ursprüngliche Nachricht-
>>> Von: Stefan Eissing [mailto:stefan.eiss...@greenbytes.de]
>>> Gesendet: Mittwoch, 26. April 2017 10:55
>>> An: dev@httpd.apache.org
>>> Betreff: Re: svn commit: r1707087 -
>>> /httpd/httpd/trunk/modules/debugging/mod_bucketeer.c
>>>
>>> Eh, not really into mod_bucketeer and its use cases, but some
>>> observations after a quick scan:
>>>
>>> line 99:
>>>rv = ap_pass_brigade(f->next, ctx->bb);
>>>apr_brigade_cleanup(ctx->bb);
>>>
>>> line 146:
>>>rv = ap_pass_brigade(f->next, ctx->bb);
>>>if (rv) {
>>>return rv;
>>>}
>>>apr_brigade_cleanup(ctx->bb);
>>>
>>> such things only work if an EOS always comes *before* an EOR
>>> bucket (case 1) or of no DATA bucket of any kind follows an EOR.
>>
>> Correct, but with the BUCKETEER filter being a resource filter that
>> should not happen.
>
> Because the implementations of everything else in the server do not
> do it? Should we then add a filter that checks exactly that?

I don't think that EOR before EOS can happen in HTTP/1, because
ap_finalize_request_protocol() is always called before
ap_process_request_after_handler().

EOS is the signal for request filters to get out of the way, so this
is probably what ap_request_core_filter() should do too, and the
purpose of the attached patch.
This patch could use EOR instead, but I find EOS more "semantically"
correct for a request filter (we don't need to set aside anything
after it), while EOR would be crash safe only...

Jacob, does it work better?


Regards,
Yann.
Index: server/request.c
===
--- server/request.c	(revision 1791747)
+++ server/request.c	(working copy)
@@ -2057,12 +2057,27 @@ AP_CORE_DECLARE_NONSTD(apr_status_t) ap_request_co
 tmp_bb = f->ctx = apr_brigade_create(f->r->pool, f->c->bucket_alloc);
 }
 
+/* Use the given bb downstream (purposedly scoped), hence move the
+ * buckets into tmp_bb to walk through them locally.
+ */
+APR_BRIGADE_CONCAT(tmp_bb, bb);
+
 /* Reinstate any buffered content */
-ap_filter_reinstate_brigade(f, bb, _upto);
+ap_filter_reinstate_brigade(f, tmp_bb, _upto);
 
-while (!APR_BRIGADE_EMPTY(bb)) {
-apr_bucket *bucket = APR_BRIGADE_FIRST(bb);
+while (!APR_BRIGADE_EMPTY(tmp_bb)) {
+apr_bucket *bucket = APR_BRIGADE_FIRST(tmp_bb);
+int eos = APR_BUCKET_IS_EOS(bucket);
 
+if (eos) {
+/* pass everything down the chain, this request is over (and will
+ * possibly be destroyed before we leave, should the EOR be aside),
+ * not this filter's business anymore.
+ */
+APR_BRIGADE_CONCAT(bb, tmp_bb);
+ap_remove_output_filter(f);
+}
+else {
 /* if the core has set aside data, back off and try later */
 if (!flush_upto) {
 if (ap_filter_should_yield(f)) {
@@ -2088,20 +2103,19 @@ AP_CORE_DECLARE_NONSTD(apr_status_t) ap_request_co
 }
 }
 }
-
 /* pass each bucket down the chain */
 APR_BUCKET_REMOVE(bucket);
-APR_BRIGADE_INSERT_TAIL(tmp_bb, bucket);
+APR_BRIGADE_INSERT_TAIL(bb, bucket);
+}
 
-status = ap_pass_brigade(f->next, tmp_bb);
-if (!APR_STATUS_IS_EOF(status) && (status != APR_SUCCESS)) {
+status = ap_pass_brigade(f->next, bb);
+if (status != APR_SUCCESS || eos) {
 return status;
 }
-
+apr_brigade_cleanup(bb);
 }
 
-ap_filter_setaside_brigade(f, bb);
-return status;
+return ap_filter_setaside_brigade(f, tmp_bb);
 }
 
 extern APR_OPTIONAL_FN_TYPE(authz_some_auth_required) *ap__authz_ap_some_auth_required;

Re: svn commit: r1707087 - /httpd/httpd/trunk/modules/debugging/mod_bucketeer.c

[Stefan Eissing]

> Am 26.04.2017 um 11:14 schrieb Plüm, Rüdiger, Vodafone Group 
> <ruediger.pl...@vodafone.com>:
> 
> 
> 
>> -Ursprüngliche Nachricht-
>> Von: Stefan Eissing [mailto:stefan.eiss...@greenbytes.de]
>> Gesendet: Mittwoch, 26. April 2017 10:55
>> An: dev@httpd.apache.org
>> Betreff: Re: svn commit: r1707087 -
>> /httpd/httpd/trunk/modules/debugging/mod_bucketeer.c
>> 
>> Eh, not really into mod_bucketeer and its use cases, but some
>> observations after a quick scan:
>> 
>> line 99:
>>rv = ap_pass_brigade(f->next, ctx->bb);
>>apr_brigade_cleanup(ctx->bb);
>> 
>> line 146:
>>rv = ap_pass_brigade(f->next, ctx->bb);
>>if (rv) {
>>return rv;
>>}
>>apr_brigade_cleanup(ctx->bb);
>> 
>> such things only work if an EOS always comes *before* an EOR bucket
>> (case 1)
>> or of no DATA bucket of any kind follows an EOR.
> 
> Correct, but with the BUCKETEER filter being a resource filter that should
> not happen.

Because the implementations of everything else in the server do not do it? 
Should we then add a filter that checks exactly that? 

I am not saying this mockingly, but am serious. If we have such contracts 
implicit somewhere (and afaik not documented), would it not be better to make 
that explicit? The performance cost of a filter inspecting bucket orderings 
should be negligible, or?

-Stefan

AW: svn commit: r1707087 - /httpd/httpd/trunk/modules/debugging/mod_bucketeer.c

[Plüm , Rüdiger , Vodafone Group]

> -Ursprüngliche Nachricht-
> Von: Stefan Eissing [mailto:stefan.eiss...@greenbytes.de]
> Gesendet: Mittwoch, 26. April 2017 10:55
> An: dev@httpd.apache.org
> Betreff: Re: svn commit: r1707087 -
> /httpd/httpd/trunk/modules/debugging/mod_bucketeer.c
> 
> Eh, not really into mod_bucketeer and its use cases, but some
> observations after a quick scan:
> 
> line 99:
> rv = ap_pass_brigade(f->next, ctx->bb);
> apr_brigade_cleanup(ctx->bb);
> 
> line 146:
> rv = ap_pass_brigade(f->next, ctx->bb);
> if (rv) {
> return rv;
> }
> apr_brigade_cleanup(ctx->bb);
> 
> such things only work if an EOS always comes *before* an EOR bucket
> (case 1)
> or of no DATA bucket of any kind follows an EOR.

Correct, but with the BUCKETEER filter being a resource filter that should
not happen.

Regards

Rüdiger

Re: svn commit: r1707087 - /httpd/httpd/trunk/modules/debugging/mod_bucketeer.c

[Stefan Eissing]

Eh, not really into mod_bucketeer and its use cases, but some observations 
after a quick scan:

line 99:
rv = ap_pass_brigade(f->next, ctx->bb);
apr_brigade_cleanup(ctx->bb);

line 146:
rv = ap_pass_brigade(f->next, ctx->bb);
if (rv) {
return rv;
}
apr_brigade_cleanup(ctx->bb);
 
such things only work if an EOS always comes *before* an EOR bucket (case 1)
or of no DATA bucket of any kind follows an EOR.

I think, the code should check for EOR specifically and then get also out
of the way *without* a brigade cleanup afterwards.

As to EOR buckets and HTTP/2, the EOR buckets do not get forwarded to the main
connection. Instead there are H2EOS buckets as indicators that all stream data
has been sent. Destruction of those triggers the shutdown and dealloc of 
streams.

This can happen
a) after the request processing has finished and there is an EOR bucket on hold.
b) before the request is done and the EOR has yet to arrive (or the slave 
connection
   used in the request processing is aborted).
c) On a stream answered without ever generating a request_rec

As to crashes in http2: since 1.10.1 there are no crashes in HTTP/2 known to 
me. Stefan Priebe discovered deadlocks which I fixed in 1.10.2 and 1.10.3, but 
no more crashes. There is a reported assertion failure in mod_proxy_http2, but 
that's it.

Cheers,

Stefan

> Am 26.04.2017 um 01:04 schrieb Jacob Champion :
> 
> On 04/25/2017 04:02 PM, Yann Ylavic wrote:
>> Let me remind this a bit, it's been a long time :)
>> Will have a look at it tomorrow hopefully..
> 
> No problem; sorry for springing it on you again after two months of silence. 
> :D
> 
> --Jacob

AW: AW: svn commit: r1707087 - /httpd/httpd/trunk/modules/debugging/mod_bucketeer.c

[Plüm , Rüdiger , Vodafone Group]

> -Ursprüngliche Nachricht-
> Von: Jacob Champion [mailto:champio...@gmail.com]
> Gesendet: Mittwoch, 26. April 2017 00:23
> An: dev@httpd.apache.org; Plüm, Rüdiger, Vodafone Group
> <ruediger.pl...@vodafone.com>
> Betreff: Re: AW: svn commit: r1707087 -
> /httpd/httpd/trunk/modules/debugging/mod_bucketeer.c
> 
> On 02/15/2017 10:10 AM, Plüm, Rüdiger, Vodafone Group wrote:
> > How about creating it from c->pool and storing it in c->notes for the
> lifetime
> > of c?
> 
> Would that be unsafe for HTTP/2? Can multiple requests (that use
> ap_request_core_filter) be active on the same connection at once?

IMHO ap_request_core will use different slave connections then.
Stefan may prove me wrong, but we still won't have more than one request
in processing at the same time per slave connection

Regards

Rüdiger

Re: svn commit: r1707087 - /httpd/httpd/trunk/modules/debugging/mod_bucketeer.c

[Jacob Champion]

On 04/25/2017 04:02 PM, Yann Ylavic wrote:

Let me remind this a bit, it's been a long time :)
Will have a look at it tomorrow hopefully..


No problem; sorry for springing it on you again after two months of 
silence. :D


--Jacob

Re: svn commit: r1707087 - /httpd/httpd/trunk/modules/debugging/mod_bucketeer.c

[Yann Ylavic]

Hi Jacob,

On Tue, Apr 25, 2017 at 11:58 PM, Jacob Champion  wrote:
>
> Unfortunately the patch just moves the crash to another location. We can't
> call APR_BRIGADE_EMPTY() on a brigade that's pointing at junk. I think a
> bucket that cleans up the brigade it's a part of is just not a good idea. :)
> So moving to c->pool is an option for a quick fix, I suppose...
>
> ...but I'm more inclined to look at the whole EOR bucket situation --
> specifically eor_bucket_destroy() and its helpers. Why is the EOR bucket
> responsible for freeing the request's pool in the first place? It doesn't
> own the request. Surely we should be freeing the pool in the same code
> context in which we've allocated the pool?
>
> One of the comments in eor_bucket.c is "eor_bucket_destroy might be called
> at a point of time when the request pool had been already destroyed", which
> makes me incredibly suspicious of the whole thing. Finalizers are not a
> great place to put business logic.

Let me remind this a bit, it's been a long time :)
Will have a look at it tomorrow hopefully..


Regards,
Yann.

Re: AW: svn commit: r1707087 - /httpd/httpd/trunk/modules/debugging/mod_bucketeer.c

[Jacob Champion]

On 02/15/2017 10:10 AM, Plüm, Rüdiger, Vodafone Group wrote:

How about creating it from c->pool and storing it in c->notes for the lifetime
of c?


Would that be unsafe for HTTP/2? Can multiple requests (that use 
ap_request_core_filter) be active on the same connection at once?


--Jacob

Re: svn commit: r1707087 - /httpd/httpd/trunk/modules/debugging/mod_bucketeer.c

[Jacob Champion]

On 02/15/2017 05:08 AM, Yann Ylavic wrote:

[with the patch]

On Wed, Feb 15, 2017 at 2:07 PM, Yann Ylavic  wrote:

Does the attached patch work for you?
I don't like it too much (if ever relevent), we could also possibly
special case the EOR brigade (looks a bit hacky to me) or create
tmp_bb on c->pool (and leak a few bytes per request, like
ap_process_request_after_handler() already)...

Ideally we'd have c->tmp_bb...


Hi Yann, circling back to this crash at last...

Unfortunately the patch just moves the crash to another location. We 
can't call APR_BRIGADE_EMPTY() on a brigade that's pointing at junk. I 
think a bucket that cleans up the brigade it's a part of is just not a 
good idea. :) So moving to c->pool is an option for a quick fix, I 
suppose...


...but I'm more inclined to look at the whole EOR bucket situation -- 
specifically eor_bucket_destroy() and its helpers. Why is the EOR bucket 
responsible for freeing the request's pool in the first place? It 
doesn't own the request. Surely we should be freeing the pool in the 
same code context in which we've allocated the pool?


One of the comments in eor_bucket.c is "eor_bucket_destroy might be 
called at a point of time when the request pool had been already 
destroyed", which makes me incredibly suspicious of the whole thing. 
Finalizers are not a great place to put business logic.


--Jacob

AW: svn commit: r1707087 - /httpd/httpd/trunk/modules/debugging/mod_bucketeer.c

[Plüm , Rüdiger , Vodafone Group]

> -Ursprüngliche Nachricht-
> Von: Yann Ylavic [mailto:ylavic@gmail.com]
> Gesendet: Mittwoch, 15. Februar 2017 14:08
> An: httpd-dev <dev@httpd.apache.org>
> Betreff: Re: svn commit: r1707087 -
> /httpd/httpd/trunk/modules/debugging/mod_bucketeer.c
> 
> [with the patch]
> 
> On Wed, Feb 15, 2017 at 2:07 PM, Yann Ylavic <ylavic@gmail.com>
> wrote:
> > On Tue, Feb 14, 2017 at 10:21 PM, Jacob Champion
> <champio...@gmail.com> wrote:
> >>
> >
> > , hence the (default_)handler probably returned
> >>
> >>> Admittedly bucketeer_out_filter() is not very nice because it does
> not
> >>> "consume" its given brigade (nor does default_handler() clear it
> >>> afterward), but that shouldn't be an issue since anyway nothing
> should
> >>> use them once the request is destroyed.
> >>>
> >>> Do you have a backtrace of the crash (and/or a breakpoint in
> >>> bucketeer_out_filter() for the test)?
> >>
> >>
> >> Attached.
> >
> > Thanks, it shows the request being destroyed with the EOR bucket.
> > However the brigade containing the EOR is also allocated on r->pool,
> > hence remove_empty_buckets()'s loop crashes (AIUI).
> >
> > Here is the (reverse) backtrace:
> >
> > #17 0x00488070 in ap_process_request_after_handler
> > (r=0x7fa70980d0a0) at modules/http/http_request.c:366
> > #16 0x0043a4d6 in ap_pass_brigade (next=0x7fa70981b7d0,
> > bb=0x7fa7097fe088) at server/util_filter.c:610
> > [...]
> > #8  0x004554ca in ap_request_core_filter (f=0x7fa70980ea78,
> > bb=0x7fa7097fe088) at
> > #7  0x0043a4d6 in ap_pass_brigade (next=0x7fa709821cc0,
> > bb=0x7fa709821c80) at server/util_filter.c:610
> > [...]
> > #2  0x004579c0 in ap_core_output_filter (f=0x7fa7097fdcc8,
> > bb=0x7fa709821c80) at server/core_filters.c:467
> > #1  0x00457b32 in send_brigade_nonblocking (s=0x7fa7098250b0,
> > bb=0x7fa709821c80, bytes_written=0x7fa7097fe040, c=0x7fa709825348) at
> > server/core_filters.c:511
> > #0  0x00457f98 in remove_empty_buckets (bb=0x7fa709821c80) at
> > server/core_filters.c:604
> >
> > See how frame #8 changes "bb" to its own "tmp_bb" (allocated on r-
> >pool).
> > Since ap_request_core_filter() is trunk only (r1706669), it also
> > explains why it does not happen in 2.4.x.
> >
> > Does the attached patch work for you?
> > I don't like it too much (if ever relevent), we could also possibly
> > special case the EOR brigade (looks a bit hacky to me) or create
> > tmp_bb on c->pool (and leak a few bytes per request, like
> > ap_process_request_after_handler() already)...

How about creating it from c->pool and storing it in c->notes for the lifetime
of c?

Regards

Rüdiger

Re: svn commit: r1707087 - /httpd/httpd/trunk/modules/debugging/mod_bucketeer.c

[Yann Ylavic]

[with the patch]

On Wed, Feb 15, 2017 at 2:07 PM, Yann Ylavic  wrote:
> On Tue, Feb 14, 2017 at 10:21 PM, Jacob Champion  wrote:
>>
>
> , hence the (default_)handler probably returned
>>
>>> Admittedly bucketeer_out_filter() is not very nice because it does not
>>> "consume" its given brigade (nor does default_handler() clear it
>>> afterward), but that shouldn't be an issue since anyway nothing should
>>> use them once the request is destroyed.
>>>
>>> Do you have a backtrace of the crash (and/or a breakpoint in
>>> bucketeer_out_filter() for the test)?
>>
>>
>> Attached.
>
> Thanks, it shows the request being destroyed with the EOR bucket.
> However the brigade containing the EOR is also allocated on r->pool,
> hence remove_empty_buckets()'s loop crashes (AIUI).
>
> Here is the (reverse) backtrace:
>
> #17 0x00488070 in ap_process_request_after_handler
> (r=0x7fa70980d0a0) at modules/http/http_request.c:366
> #16 0x0043a4d6 in ap_pass_brigade (next=0x7fa70981b7d0,
> bb=0x7fa7097fe088) at server/util_filter.c:610
> [...]
> #8  0x004554ca in ap_request_core_filter (f=0x7fa70980ea78,
> bb=0x7fa7097fe088) at
> #7  0x0043a4d6 in ap_pass_brigade (next=0x7fa709821cc0,
> bb=0x7fa709821c80) at server/util_filter.c:610
> [...]
> #2  0x004579c0 in ap_core_output_filter (f=0x7fa7097fdcc8,
> bb=0x7fa709821c80) at server/core_filters.c:467
> #1  0x00457b32 in send_brigade_nonblocking (s=0x7fa7098250b0,
> bb=0x7fa709821c80, bytes_written=0x7fa7097fe040, c=0x7fa709825348) at
> server/core_filters.c:511
> #0  0x00457f98 in remove_empty_buckets (bb=0x7fa709821c80) at
> server/core_filters.c:604
>
> See how frame #8 changes "bb" to its own "tmp_bb" (allocated on r->pool).
> Since ap_request_core_filter() is trunk only (r1706669), it also
> explains why it does not happen in 2.4.x.
>
> Does the attached patch work for you?
> I don't like it too much (if ever relevent), we could also possibly
> special case the EOR brigade (looks a bit hacky to me) or create
> tmp_bb on c->pool (and leak a few bytes per request, like
> ap_process_request_after_handler() already)...
>
> Ideally we'd have c->tmp_bb...
>
> Graham/others, a better idea?
Index: server/request.c
===
--- server/request.c	(revision 1783088)
+++ server/request.c	(working copy)
@@ -2056,12 +2056,13 @@ AP_CORE_DECLARE_NONSTD(apr_status_t) ap_request_co
 if (!tmp_bb) {
 tmp_bb = f->ctx = apr_brigade_create(f->r->pool, f->c->bucket_alloc);
 }
+APR_BRIGADE_CONCAT(tmp_bb, bb);
 
 /* Reinstate any buffered content */
-ap_filter_reinstate_brigade(f, bb, _upto);
+ap_filter_reinstate_brigade(f, tmp_bb, _upto);
 
-while (!APR_BRIGADE_EMPTY(bb)) {
-apr_bucket *bucket = APR_BRIGADE_FIRST(bb);
+while (!APR_BRIGADE_EMPTY(tmp_bb)) {
+apr_bucket *bucket = APR_BRIGADE_FIRST(tmp_bb);
 
 /* if the core has set aside data, back off and try later */
 if (!flush_upto) {
@@ -2091,9 +2092,9 @@ AP_CORE_DECLARE_NONSTD(apr_status_t) ap_request_co
 
 /* pass each bucket down the chain */
 APR_BUCKET_REMOVE(bucket);
-APR_BRIGADE_INSERT_TAIL(tmp_bb, bucket);
+APR_BRIGADE_INSERT_TAIL(bb, bucket);
 
-status = ap_pass_brigade(f->next, tmp_bb);
+status = ap_pass_brigade(f->next, bb);
 if (!APR_STATUS_IS_EOF(status) && (status != APR_SUCCESS)) {
 return status;
 }
@@ -2100,7 +2101,7 @@ AP_CORE_DECLARE_NONSTD(apr_status_t) ap_request_co
 
 }
 
-ap_filter_setaside_brigade(f, bb);
+ap_filter_setaside_brigade(f, tmp_bb);
 return status;
 }
 

Re: svn commit: r1707087 - /httpd/httpd/trunk/modules/debugging/mod_bucketeer.c

[Yann Ylavic]

On Tue, Feb 14, 2017 at 10:21 PM, Jacob Champion  wrote:
>

, hence the (default_)handler probably returned
>
>> Admittedly bucketeer_out_filter() is not very nice because it does not
>> "consume" its given brigade (nor does default_handler() clear it
>> afterward), but that shouldn't be an issue since anyway nothing should
>> use them once the request is destroyed.
>>
>> Do you have a backtrace of the crash (and/or a breakpoint in
>> bucketeer_out_filter() for the test)?
>
>
> Attached.

Thanks, it shows the request being destroyed with the EOR bucket.
However the brigade containing the EOR is also allocated on r->pool,
hence remove_empty_buckets()'s loop crashes (AIUI).

Here is the (reverse) backtrace:

#17 0x00488070 in ap_process_request_after_handler
(r=0x7fa70980d0a0) at modules/http/http_request.c:366
#16 0x0043a4d6 in ap_pass_brigade (next=0x7fa70981b7d0,
bb=0x7fa7097fe088) at server/util_filter.c:610
[...]
#8  0x004554ca in ap_request_core_filter (f=0x7fa70980ea78,
bb=0x7fa7097fe088) at
#7  0x0043a4d6 in ap_pass_brigade (next=0x7fa709821cc0,
bb=0x7fa709821c80) at server/util_filter.c:610
[...]
#2  0x004579c0 in ap_core_output_filter (f=0x7fa7097fdcc8,
bb=0x7fa709821c80) at server/core_filters.c:467
#1  0x00457b32 in send_brigade_nonblocking (s=0x7fa7098250b0,
bb=0x7fa709821c80, bytes_written=0x7fa7097fe040, c=0x7fa709825348) at
server/core_filters.c:511
#0  0x00457f98 in remove_empty_buckets (bb=0x7fa709821c80) at
server/core_filters.c:604

See how frame #8 changes "bb" to its own "tmp_bb" (allocated on r->pool).
Since ap_request_core_filter() is trunk only (r1706669), it also
explains why it does not happen in 2.4.x.

Does the attached patch work for you?
I don't like it too much (if ever relevent), we could also possibly
special case the EOR brigade (looks a bit hacky to me) or create
tmp_bb on c->pool (and leak a few bytes per request, like
ap_process_request_after_handler() already)...

Ideally we'd have c->tmp_bb...

Graham/others, a better idea?

Re: svn commit: r1707087 - /httpd/httpd/trunk/modules/debugging/mod_bucketeer.c

[Jacob Champion]

On 02/14/2017 05:02 AM, Yann Ylavic wrote:

The previous test (mod_include) does use mod_bucketeer (including with
subrequests), possibly some remaining buckets (EOR?) from there
somewhere in the stack (core or some downstream filter's f->bb)?
That'd be very wrong too (but I can't see something like that with
gdb, though)...


Ah, it does seem to be related to mod_include, not mod_info. If I run 
the mod_include tests followed by mod_lua tests, the mod_lua tests 
report a segfault halfway through...


The crash looks like it's actually coming from a mod_include connection 
that, for some reason, takes a very long time to complete. 
mod_reqtimeout is also involved in the stack.



Admittedly bucketeer_out_filter() is not very nice because it does not
"consume" its given brigade (nor does default_handler() clear it
afterward), but that shouldn't be an issue since anyway nothing should
use them once the request is destroyed.

Do you have a backtrace of the crash (and/or a breakpoint in
bucketeer_out_filter() for the test)?


Attached.

--Jacob



backtrace
Description: application/info

Re: svn commit: r1707087 - /httpd/httpd/trunk/modules/debugging/mod_bucketeer.c

[Yann Ylavic]

Hi Jacob,

On Wed, Feb 8, 2017 at 2:16 AM, Jacob Champion  wrote:
> On 10/06/2015 09:30 AM, yla...@apache.org wrote:
>>
>> Author: ylavic
>> Date: Tue Oct  6 16:30:53 2015
>> New Revision: 1707087
>>
>> URL: http://svn.apache.org/viewvc?rev=1707087=rev
>> Log:
>> mod_bucketeer: cleanup properly on EOS and write.
>
>
> Hey Yann,
>
> I've started testing reallyall builds of trunk, which are currently
> segfaulting in the middle of mod_info tests.

Hmm, mod_bucketeer is not involved for me in mod_info's test, strange...

> A bisect points to this commit
> to mod_bucketeer, back in 2015. Reverting it makes everything run smoothly.

This commits looks good to me, once the buckets are passed down the
chain they can be normally be cleared (it's up to the next filters to
copy/setaside if they need to).
If this new "apr_brigade_cleanup(ctx->bb);" raises the crash
(indirectly?), there is something very wrong in the filter chain.

>
> Any idea what's going wrong? Seems like mod_bucketeer is messing with the
> brigade in a way mod_info doesn't expect.

I can't reproduce unfortunately, and my breakpoint(s) in mod_bucketeer
don't show up with mod_info test.

The previous test (mod_include) does use mod_bucketeer (including with
subrequests), possibly some remaining buckets (EOR?) from there
somewhere in the stack (core or some downstream filter's f->bb)?
That'd be very wrong too (but I can't see something like that with
gdb, though)...

Admittedly bucketeer_out_filter() is not very nice because it does not
"consume" its given brigade (nor does default_handler() clear it
afterward), but that shouldn't be an issue since anyway nothing should
use them once the request is destroyed.

Do you have a backtrace of the crash (and/or a breakpoint in
bucketeer_out_filter() for the test)?
It would be interesting to "dump_brigade bb" there before it happens,
which bucket(s) from where are involved/cleared...

We could probably patch some places to safely clear passed out
brigades, but it would be nice to determine first where this failure
comes from...


Thanks,
Yann.

Re: svn commit: r1707087 - /httpd/httpd/trunk/modules/debugging/mod_bucketeer.c

[Jacob Champion]

On 10/06/2015 09:30 AM, yla...@apache.org wrote:

Author: ylavic
Date: Tue Oct  6 16:30:53 2015
New Revision: 1707087

URL: http://svn.apache.org/viewvc?rev=1707087=rev
Log:
mod_bucketeer: cleanup properly on EOS and write.


Hey Yann,

I've started testing reallyall builds of trunk, which are currently 
segfaulting in the middle of mod_info tests. A bisect points to this 
commit to mod_bucketeer, back in 2015. Reverting it makes everything run 
smoothly.


Any idea what's going wrong? Seems like mod_bucketeer is messing with 
the brigade in a way mod_info doesn't expect.


--Jacob



Modified:
httpd/httpd/trunk/modules/debugging/mod_bucketeer.c

Modified: httpd/httpd/trunk/modules/debugging/mod_bucketeer.c
URL: 
http://svn.apache.org/viewvc/httpd/httpd/trunk/modules/debugging/mod_bucketeer.c?rev=1707087=1707086=1707087=diff
==
--- httpd/httpd/trunk/modules/debugging/mod_bucketeer.c (original)
+++ httpd/httpd/trunk/modules/debugging/mod_bucketeer.c Tue Oct  6 16:30:53 2015
@@ -95,6 +95,7 @@ static apr_status_t bucketeer_out_filter
 /* Okay, we've seen the EOS.
  * Time to pass it along down the chain.
  */
+ap_remove_output_filter(f);
 return ap_pass_brigade(f->next, ctx->bb);
 }

@@ -145,6 +146,7 @@ static apr_status_t bucketeer_out_filter
 if (rv) {
 return rv;
 }
+apr_brigade_cleanup(ctx->bb);
 }
 }
 }