On 7/7/23 1:00 PM, yla...@apache.org wrote: > Author: ylavic > Date: Fri Jul 7 11:00:34 2023 > New Revision: 1910846 > > URL: http://svn.apache.org/viewvc?rev=1910846&view=rev > Log: > util_filter: More useful logging for brigade setaside/reinstate/adopt. > > > Modified: > httpd/httpd/trunk/server/util_filter.c > > Modified: httpd/httpd/trunk/server/util_filter.c > URL: > http://svn.apache.org/viewvc/httpd/httpd/trunk/server/util_filter.c?rev=1910846&r1=1910845&r2=1910846&view=diff > ============================================================================== > --- httpd/httpd/trunk/server/util_filter.c (original) > +++ httpd/httpd/trunk/server/util_filter.c Fri Jul 7 11:00:34 2023 > @@ -949,12 +949,14 @@ AP_DECLARE(apr_status_t) ap_filter_setas > apr_status_t rv = APR_SUCCESS; > struct ap_filter_private *fp = f->priv; > > - ap_log_cerror(APLOG_MARK, APLOG_TRACE6, 0, f->c, > - "setaside %s brigade to %s brigade in '%s' %sput filter", > - APR_BRIGADE_EMPTY(bb) ? "empty" : "full", > - (!fp->bb || APR_BRIGADE_EMPTY(fp->bb)) ? "empty" : "full", > - f->frec->name, > - f->frec->direction == AP_FILTER_INPUT ? "in" : "out"); > + if (!APR_BRIGADE_EMPTY(bb) || (fp->bb && !APR_BRIGADE_EMPTY(fp->bb))) { > + ap_log_cerror(APLOG_MARK, APLOG_TRACE6, 0, f->c, > + "setaside %s brigade to %s brigade in '%s' %sput > filter", > + APR_BRIGADE_EMPTY(bb) ? "empty" : "full", > + (!fp->bb || APR_BRIGADE_EMPTY(fp->bb)) ? "empty" : > "full", > + f->frec->name, > + f->frec->direction == AP_FILTER_INPUT ? "in" : "out"); > + } > > /* This API is not suitable for request filters */ > if (f->frec->ftype < AP_FTYPE_CONNECTION) { > @@ -1049,12 +1051,14 @@ AP_DECLARE(void) ap_filter_adopt_brigade > { > struct ap_filter_private *fp = f->priv; > > - ap_log_cerror(APLOG_MARK, APLOG_TRACE6, 0, f->c, > - "adopt %s brigade to %s brigade in '%s' %sput filter", > - APR_BRIGADE_EMPTY(bb) ? "empty" : "full", > - (!fp->bb || APR_BRIGADE_EMPTY(fp->bb)) ? "empty" : "full", > - f->frec->name, > - f->frec->direction == AP_FILTER_INPUT ? "in" : "out"); > + if (!APR_BRIGADE_EMPTY(bb) || (fp->bb && !APR_BRIGADE_EMPTY(fp->bb))) { > + ap_log_cerror(APLOG_MARK, APLOG_TRACE6, 0, f->c, > + "adopt %s brigade to %s brigade in '%s' %sput filter", > + APR_BRIGADE_EMPTY(bb) ? "empty" : "full", > + (!fp->bb || APR_BRIGADE_EMPTY(fp->bb)) ? "empty" : > "full", > + f->frec->name, > + f->frec->direction == AP_FILTER_INPUT ? "in" : "out"); > + } > > if (!APR_BRIGADE_EMPTY(bb)) { > ap_filter_prepare_brigade(f); > @@ -1067,18 +1071,26 @@ AP_DECLARE(apr_status_t) ap_filter_reins > apr_bucket **flush_upto) > { > apr_bucket *bucket, *next; > + apr_size_t flush_max_threshold; > + apr_int32_t flush_max_pipelined; > apr_size_t bytes_in_brigade, memory_bytes_in_brigade; > int eor_buckets_in_brigade, opaque_buckets_in_brigade; > struct ap_filter_private *fp = f->priv; > core_server_config *conf; > int is_flush; > > - ap_log_cerror(APLOG_MARK, APLOG_TRACE6, 0, f->c, > - "reinstate %s brigade to %s brigade in '%s' %sput filter", > - (!fp->bb || APR_BRIGADE_EMPTY(fp->bb) ? "empty" : "full"), > - (APR_BRIGADE_EMPTY(bb) ? "empty" : "full"), > - f->frec->name, > - f->frec->direction == AP_FILTER_INPUT ? "in" : "out"); > + if (flush_upto) { > + *flush_upto = NULL; > + } > + > + if (!APR_BRIGADE_EMPTY(bb) || (fp->bb && !APR_BRIGADE_EMPTY(fp->bb))) { > + ap_log_cerror(APLOG_MARK, APLOG_TRACE6, 0, f->c, > + "reinstate %s brigade to %s brigade in '%s' %sput > filter", > + (!fp->bb || APR_BRIGADE_EMPTY(fp->bb) ? "empty" : > "full"), > + (APR_BRIGADE_EMPTY(bb) ? "empty" : "full"), > + f->frec->name, > + f->frec->direction == AP_FILTER_INPUT ? "in" : "out"); > + } > > /* This API is not suitable for request filters */ > if (f->frec->ftype < AP_FTYPE_CONNECTION) { > @@ -1086,17 +1098,15 @@ AP_DECLARE(apr_status_t) ap_filter_reins > } > > /* Buckets in fp->bb are leftover from previous call to setaside, so > - * they happen before anything added here in bb. > + * they happen before anything in bb already. > */ > if (fp->bb) { > APR_BRIGADE_PREPEND(bb, fp->bb); > } > - if (!flush_upto) { > - /* Just prepend all. */ > + if (!flush_upto || APR_BRIGADE_EMPTY(bb)) { > + /* Just prepend all, or nothing to do. */ > return APR_SUCCESS; > } > - > - *flush_upto = NULL; > > /* > * Determine if and up to which bucket the caller needs to do a blocking > @@ -1124,13 +1134,15 @@ AP_DECLARE(apr_status_t) ap_filter_reins > * reinstated by moving them from/to fp->bb to/from user bb. > */ > > + conf = ap_get_core_module_config(f->c->base_server->module_config); > + flush_max_threshold = conf->flush_max_threshold; > + flush_max_pipelined = conf->flush_max_pipelined; > + > bytes_in_brigade = 0; > memory_bytes_in_brigade = 0; > eor_buckets_in_brigade = 0; > opaque_buckets_in_brigade = 0; > > - conf = ap_get_core_module_config(f->c->base_server->module_config); > - > for (bucket = APR_BRIGADE_FIRST(bb); bucket != APR_BRIGADE_SENTINEL(bb); > bucket = next) { > next = APR_BUCKET_NEXT(bucket); > @@ -1157,9 +1169,9 @@ AP_DECLARE(apr_status_t) ap_filter_reins > } > > if (is_flush > - || (memory_bytes_in_brigade > conf->flush_max_threshold) > - || (conf->flush_max_pipelined >= 0 > - && eor_buckets_in_brigade > conf->flush_max_pipelined)) { > + || (memory_bytes_in_brigade > flush_max_threshold) > + || (flush_max_pipelined >= 0 > + && eor_buckets_in_brigade > flush_max_pipelined)) { > /* this segment of the brigade MUST be sent before returning. */ > > if (APLOGctrace6(f->c)) { > @@ -1170,11 +1182,9 @@ AP_DECLARE(apr_status_t) ap_filter_reins > ap_log_cerror(APLOG_MARK, APLOG_TRACE6, 0, f->c, > "will flush because of %s", reason); > ap_log_cerror(APLOG_MARK, APLOG_TRACE8, 0, f->c, > - "seen in brigade%s: bytes: %" APR_SIZE_T_FMT > + "seen in brigade so far: bytes: %" > APR_SIZE_T_FMT > ", memory bytes: %" APR_SIZE_T_FMT ", eor " > "buckets: %d, opaque buckets: %d", > - *flush_upto == NULL ? " so far" > - : " since last flush > point", > bytes_in_brigade, > memory_bytes_in_brigade, > eor_buckets_in_brigade, > @@ -1183,16 +1193,18 @@ AP_DECLARE(apr_status_t) ap_filter_reins > /* > * Defer the actual blocking write to avoid doing many writes. > */ > + if (memory_bytes_in_brigade > flush_max_threshold) { > + flush_max_threshold = APR_SIZE_MAX; > + } > + if (flush_max_pipelined >= 0 > + && eor_buckets_in_brigade > flush_max_pipelined) { > + flush_max_pipelined = APR_INT32_MAX; > + } > *flush_upto = next; > - > - bytes_in_brigade = 0; > - memory_bytes_in_brigade = 0; > - eor_buckets_in_brigade = 0; > - opaque_buckets_in_brigade = 0; Doesn't that change the logic? In the previous code the buckets beyond the flush_upto that the function returned are in sum below conf->flush_max_threshold and conf->flush_max_pipelined. Now we do not update *flush_upto any longer if after the first update we bypass conf->flush_max_threshold and conf->flush_max_pipelined again. Regards Rüdiger
