stas 2003/04/02 22:21:43
Modified: xs modperl_xs_util.h xs/Apache/Filter Apache__Filter.h src/modules/perl modperl_filter.c Log: - filters tracing readability is now mucho improved - a small bug fix with eos bucket Revision Changes Path 1.14 +4 -1 modperl-2.0/xs/modperl_xs_util.h Index: modperl_xs_util.h =================================================================== RCS file: /home/cvs/modperl-2.0/xs/modperl_xs_util.h,v retrieving revision 1.13 retrieving revision 1.14 diff -u -r1.13 -r1.14 --- modperl_xs_util.h 17 Jan 2003 03:08:31 -0000 1.13 +++ modperl_xs_util.h 3 Apr 2003 06:21:42 -0000 1.14 @@ -80,10 +80,13 @@ arg = *MARK++ /* XXX: we probably shouldn't croak here */ -#define mpxs_write_loop(func,obj) \ +#define mpxs_write_loop(func, obj) \ while (MARK <= SP) { \ apr_ssize_t wlen; \ char *buf = SvPV(*MARK, wlen); \ + MP_TRACE_f(MP_FUNC, " %s\n\n\tbuffer out: %d bytes\n", \ + ((modperl_filter_ctx_t *)obj->f->ctx)->handler->name, \ + wlen); \ apr_status_t rv = func(aTHX_ obj, buf, &wlen); \ if (rv != APR_SUCCESS) { \ Perl_croak(aTHX_ modperl_apr_strerror(rv)); \ 1.27 +2 -6 modperl-2.0/xs/Apache/Filter/Apache__Filter.h Index: Apache__Filter.h =================================================================== RCS file: /home/cvs/modperl-2.0/xs/Apache/Filter/Apache__Filter.h,v retrieving revision 1.26 retrieving revision 1.27 diff -u -r1.26 -r1.27 --- Apache__Filter.h 1 Apr 2003 05:20:50 -0000 1.26 +++ Apache__Filter.h 3 Apr 2003 06:21:43 -0000 1.27 @@ -193,12 +193,8 @@ mpxs_usage_va_1(modperl_filter, "$filter->remove()"); f = modperl_filter->f; -#ifdef MP_TRACE - { - modperl_filter_ctx_t *ctx = (modperl_filter_ctx_t *)(f->ctx); - MP_TRACE_f(MP_FUNC, "removing filter %s\n", ctx->handler->name); - } -#endif + MP_TRACE_f(MP_FUNC, " %s\n\n\tfilter removes itself\n", + ((modperl_filter_ctx_t *)f->ctx)->handler->name); if (modperl_filter->mode == MP_INPUT_FILTER_MODE) { ap_remove_input_filter(f); 1.57 +100 -37 modperl-2.0/src/modules/perl/modperl_filter.c Index: modperl_filter.c =================================================================== RCS file: /home/cvs/modperl-2.0/src/modules/perl/modperl_filter.c,v retrieving revision 1.56 retrieving revision 1.57 diff -u -r1.56 -r1.57 --- modperl_filter.c 14 Mar 2003 05:33:18 -0000 1.56 +++ modperl_filter.c 3 Apr 2003 06:21:43 -0000 1.57 @@ -2,8 +2,37 @@ /* helper funcs */ +#define MP_FILTER_NAME_FORMAT " %s\n\n\t" + +#define MP_FILTER_NAME(f) \ + ((modperl_filter_ctx_t *)f->ctx)->handler->name + +#define MP_FILTER_TYPE(filter) \ + ((modperl_filter_ctx_t *)filter->f->ctx)->handler->attrs & \ + MP_FILTER_CONNECTION_HANDLER ? "connection" : "request" + +#define MP_FILTER_MODE(filter) \ + (filter->mode == MP_INPUT_FILTER_MODE ? "input" : "output") + #define MP_FILTER_POOL(f) f->r ? f->r->pool : f->c->pool +/* this function is for tracing only, it's not optimized for performance */ +static const char* next_filter_name(ap_filter_t *f) +{ + const char *name = f->frec->name; + + /* frec->name is always lowercased */ + if (ap_strcasecmp_match(name, MP_FILTER_CONNECTION_INPUT_NAME) || + ap_strcasecmp_match(name, MP_FILTER_CONNECTION_OUTPUT_NAME) || + ap_strcasecmp_match(name, MP_FILTER_REQUEST_INPUT_NAME) || + ap_strcasecmp_match(name, MP_FILTER_REQUEST_OUTPUT_NAME) ) { + return ((modperl_filter_ctx_t *)f->ctx)->handler->name; + } + else { + return name; + } +} + MP_INLINE static apr_status_t send_input_eos(modperl_filter_t *filter) { apr_bucket_alloc_t *ba = filter->f->c->bucket_alloc; @@ -29,8 +58,9 @@ apr_bucket *b = apr_bucket_eos_create(ba); APR_BRIGADE_INSERT_TAIL(bb, b); ((modperl_filter_ctx_t *)f->ctx)->sent_eos = 1; - MP_TRACE_f(MP_FUNC, "sending EOS bucket in separate bb\n"); - return ap_pass_brigade(f, bb); + MP_TRACE_f(MP_FUNC, MP_FILTER_NAME_FORMAT + "write out: EOS bucket in separate bb\n", MP_FILTER_NAME(f)); + return ap_pass_brigade(f->next, bb); } MP_INLINE static apr_status_t send_output_flush(ap_filter_t *f) @@ -40,7 +70,8 @@ ba); apr_bucket *b = apr_bucket_flush_create(ba); APR_BRIGADE_INSERT_TAIL(bb, b); - MP_TRACE_f(MP_FUNC, "sending FLUSH bucket in separate bb\n"); + MP_TRACE_f(MP_FUNC, MP_FILTER_NAME_FORMAT + "write out: FLUSH bucket in separate bb\n", MP_FILTER_NAME(f)); return ap_pass_brigade(f, bb); } @@ -109,7 +140,12 @@ APR_BRIGADE_INSERT_TAIL(bb, bucket); } - MP_TRACE_f(MP_FUNC, "buffer length=%d\n", len); + MP_TRACE_f(MP_FUNC, "\n\n\twrite out: %d bytes\n" + "\t\tfrom %s\n\t\tto %s filter handler\n", + len, + (wb->r && wb->filters == &wb->r->output_filters) + ? "response handler" : "current filter handler", + next_filter_name(*(wb->filters))); return ap_pass_brigade(*(wb->filters), bb); } @@ -193,10 +229,12 @@ filter->bb_in = bb; filter->bb_out = NULL; } - - MP_TRACE_f(MP_FUNC, "filter=0x%lx, mode=%s\n", - (unsigned long)filter, - mode == MP_INPUT_FILTER_MODE ? "input" : "output"); + + MP_TRACE_f(MP_FUNC, MP_FILTER_NAME_FORMAT + "new: %s %s filter (0x%lx)\n", + MP_FILTER_NAME(f), + MP_FILTER_TYPE(filter), MP_FILTER_MODE(filter), + (unsigned long)filter); return filter; } @@ -249,8 +287,6 @@ SvREFCNT_dec((SV*)args); - MP_TRACE_f(MP_FUNC, "%s returned %d\n", handler->name, status); - /* when the streaming filter is invoked it should be able to send * extra data, after the read in a while() loop is finished. * Therefore we need to postpone propogating the EOS bucket, up @@ -277,6 +313,9 @@ MP_FAILURE_CROAK(modperl_output_filter_flush(filter)); } + MP_TRACE_f(MP_FUNC, MP_FILTER_NAME_FORMAT + "return: %d\n", handler->name, status); + return status; } @@ -304,8 +343,9 @@ MP_INLINE static int get_bucket(modperl_filter_t *filter) { if (!filter->bb_in || MP_FILTER_EMPTY(filter)) { - MP_TRACE_f(MP_FUNC, "%s filter bucket brigade is empty\n", - (filter->mode == MP_INPUT_FILTER_MODE ? "input" : "output")); + MP_TRACE_f(MP_FUNC, MP_FILTER_NAME_FORMAT + "read in: bucket brigade is empty\n", + MP_FILTER_NAME(filter->f)); return 0; } @@ -325,9 +365,9 @@ } if (MP_FILTER_IS_EOS(filter)) { - MP_TRACE_f(MP_FUNC, "%s filter received EOS bucket\n", - (filter->mode == MP_INPUT_FILTER_MODE - ? "input" : "output")); + MP_TRACE_f(MP_FUNC, MP_FILTER_NAME_FORMAT + "read in: EOS bucket\n", + MP_FILTER_NAME(filter->f)); filter->seen_eos = 1; /* there should be only one EOS sent, modperl_filter_read will @@ -336,10 +376,9 @@ return 0; } else if (MP_FILTER_IS_FLUSH(filter)) { - MP_TRACE_f(MP_FUNC, "%s filter received FLUSH bucket\n", - (filter->mode == MP_INPUT_FILTER_MODE - ? "input" : "output")); - + MP_TRACE_f(MP_FUNC, MP_FILTER_NAME_FORMAT + "read in: FLUSH bucket\n", + MP_FILTER_NAME(filter->f)); filter->flush = 1; return 0; } @@ -372,14 +411,17 @@ /*modperl_brigade_dump(filter->bb_in, stderr);*/ - MP_TRACE_f(MP_FUNC, "%s filter wants %d bytes\n", - (filter->mode == MP_INPUT_FILTER_MODE ? "input" : "output"), + MP_TRACE_f(MP_FUNC, MP_FILTER_NAME_FORMAT + "wanted: %d bytes\n", + MP_FILTER_NAME(filter->f), wanted); if (filter->remaining) { if (filter->remaining >= wanted) { - MP_TRACE_f(MP_FUNC, - "eating/returning %d of remaining %d leftover bytes\n", + MP_TRACE_f(MP_FUNC, MP_FILTER_NAME_FORMAT + "eating and returning %d of " + "remaining %d leftover bytes\n", + MP_FILTER_NAME(filter->f), wanted, filter->remaining); sv_catpvn(buffer, filter->leftover, wanted); filter->leftover += wanted; @@ -387,7 +429,9 @@ return wanted; } else { - MP_TRACE_f(MP_FUNC, "eating remaining %d leftover bytes\n", + MP_TRACE_f(MP_FUNC, MP_FILTER_NAME_FORMAT + "eating remaining %d leftover bytes\n", + MP_FILTER_NAME(filter->f), filter->remaining); sv_catpvn(buffer, filter->leftover, filter->remaining); len = filter->remaining; @@ -410,14 +454,18 @@ if (filter->rc == APR_SUCCESS) { MP_TRACE_f(MP_FUNC, - "bucket=%s(0x%lx) read returned %d bytes\n", + MP_FILTER_NAME_FORMAT + "read in: %s bucket with %d bytes (0x%lx)\n", + MP_FILTER_NAME(filter->f), filter->bucket->type->name, - (unsigned long)filter->bucket, - buf_len); + buf_len, + (unsigned long)filter->bucket); } else { MP_TRACE_f(MP_FUNC, - "apr_bucket_read error: %s\n", + MP_FILTER_NAME_FORMAT + "read in: apr_bucket_read error: %s\n", + MP_FILTER_NAME(filter->f), modperl_apr_strerror(filter->rc)); return len; } @@ -439,8 +487,9 @@ } MP_TRACE_f(MP_FUNC, - "returning %d bytes from %d bucket%s " - "(%d bytes leftover)\n", + MP_FILTER_NAME_FORMAT + "return: %d bytes from %d bucket%s (%d bytes leftover)\n", + MP_FILTER_NAME(filter->f), len, num_buckets, ((num_buckets == 1) ? "" : "s"), filter->remaining); @@ -460,7 +509,9 @@ filter->f->c->bucket_alloc); ap_get_brigade(filter->f->next, filter->bb_in, filter->input_mode, filter->block, filter->readbytes); - MP_TRACE_f(MP_FUNC, "retrieving bb: 0x%lx\n", + MP_TRACE_f(MP_FUNC, MP_FILTER_NAME_FORMAT + "retrieving bb: 0x%lx\n", + MP_FILTER_NAME(filter->f), (unsigned long)(filter->bb_in)); } @@ -505,7 +556,9 @@ } if (filter->eos || filter->flush) { - MP_TRACE_f(MP_FUNC, "sending %s bucket\n", + MP_TRACE_f(MP_FUNC, MP_FILTER_NAME_FORMAT + "write out: %s bucket\n", + MP_FILTER_NAME(filter->f), filter->eos ? "EOS" : "FLUSH"); filter->rc = filter->eos ? send_input_eos(filter) : send_input_flush(filter); @@ -536,7 +589,7 @@ } if (filter->eos) { - filter->rc = send_output_eos(filter->f->next); + filter->rc = send_output_eos(filter->f); if (filter->bb_in) { apr_brigade_destroy(filter->bb_in); filter->bb_in = NULL; @@ -556,7 +609,10 @@ char *copy = apr_pstrndup(filter->pool, buf, *len); apr_bucket *bucket = apr_bucket_transient_create(copy, *len, ba); /* MP_TRACE_f(MP_FUNC, "writing %d bytes: %s\n", *len, copy); */ - MP_TRACE_f(MP_FUNC, "writing %d bytes:\n", *len); + MP_TRACE_f(MP_FUNC, MP_FILTER_NAME_FORMAT + "write out: %d bytes:\n", + MP_FILTER_NAME(filter->f), + *len); APR_BRIGADE_INSERT_TAIL(filter->bb_out, bucket); /* modperl_brigade_dump(filter->bb_out, stderr); */ return APR_SUCCESS; @@ -578,7 +634,10 @@ if (((modperl_filter_ctx_t *)f->ctx)->sent_eos) { MP_TRACE_f(MP_FUNC, - "EOS was already sent, passing through the brigade\n"); + MP_FILTER_NAME_FORMAT + "write_out: EOS was already sent, " + "passing through the brigade\n", + MP_FILTER_NAME(f)); return ap_pass_brigade(f->next, bb); } else { @@ -608,7 +667,10 @@ if (((modperl_filter_ctx_t *)f->ctx)->sent_eos) { MP_TRACE_f(MP_FUNC, - "EOS was already sent, passing through the brigade\n"); + MP_FILTER_NAME_FORMAT + "write out: EOS was already sent, " + "passing through the brigade\n", + MP_FILTER_NAME(f)); return ap_get_brigade(f->next, bb, input_mode, block, readbytes); } else { @@ -690,6 +752,8 @@ while (f) { const char *fname = f->frec->name; + /* XXX: I think this won't work as f->frec->name gets + * lowercased when added to the chain */ if (*fname == 'M' && strEQ(fname, name)) { modperl_handler_t *ctx_handler = ((modperl_filter_ctx_t *)f->ctx)->handler; @@ -793,7 +857,6 @@ Perl_croak(aTHX_ "unable to resolve handler 0x%lx\n", (unsigned long)callback); } - void modperl_brigade_dump(apr_bucket_brigade *bb, FILE *fp) {