Steve Hay wrote:
I've attached the complete error_log from a successful run (error_log_ok) and from an unsuccessful run (error_log_nok). I'm not sure it'll tell you much either, to be honest -- there's very little difference :-(
At least it tells me a lot ;) According to your logs (both), the handler side finishes just fine and the client side is the one that has a problem to deal with the server stopping to read the data a client is trying to send. You still have this problem with LWP and Apache::TestClient, right?
Yes - I've tried running this test with APACHE_TEST_PRETEND_NO_LWP=0 (and obviously with LWP installed!) and with APACHE_TEST_PRETEND_NO_LWP=1. Either way it sometimes fails.
Does the patch below help at all? I'm not quite sure whether localization works, so just trying it that way.
Sadly not. Again I've tried it with and without the APACHE_TEST_PRETEND_NO_LWP=1 setting, and sometimes get failures as before.
I also didn't see the warn()'ing that your patch emits when the client gets a SIGPIPE anywhere, either - neither in the console window nor in the error_log.
The only shred of interesting behaviour that I've noticed is that I don't seem to be able to make it fail if I use the "-trace=debug" option as you suggested above. I just ran it 24 times on the trot without a single failure! If I take the "-trace=debug" option out then it typically fails at least 2 or 3 times out of 6.
Besides the difference is the size of the first bucket brigades
- read in: HEAP bucket with 8000 bytes (0x91d9d8) <= ok + read in: HEAP bucket with 7831 bytes (0x91d870) <= nok
which could change from run to run I believe, the two logs are indentical.
Probably unrelated but for some reason the debug messages that -trace=debug is supposed to enable don't make it to, e.g. on my system it's:
+==> FILTER READ: [*************] +==> FILTER READ: 13 (0 more to go) +==> HANDLER READ: 105 bytes
unless both logs were created without -trace=debug.
Yes - both logs were indeed created without -trace=debug because, as I said, I don't seem to be able to make the test fail if I use that option! I've attached the output from a *successful* run with -trace=debug to this e-mail, but it looks the same as before to me -- there's no sign of the extra lines that you mentioned above.
Just to double-check I'm doing this right: I've set MOD_PERL_TRACE=f in the environment, and then run "perl t/TEST -trace=debug -verbose t/filter/in_str_consume.t".
- Steve
Index: t/filter/in_str_consume.t =================================================================== RCS file: /home/cvs/modperl-2.0/t/filter/in_str_consume.t,v retrieving revision 1.3 diff -u -r1.3 in_str_consume.t --- t/filter/in_str_consume.t 27 Aug 2003 04:42:37 -0000 1.3 +++ t/filter/in_str_consume.t 23 Sep 2003 01:34:27 -0000 @@ -16,6 +16,9 @@
t_debug "sent " . length($data) . "B, expecting ${expected}B to make through";
+my $old_sigpipe = $SIG{PIPE};
+$SIG{PIPE} = sub { warn "That's right! I received SIGPIPE and ignored it\n" };
my $received = POST_BODY $location, content => $data;
+$SIG{PIPE} = $old_sigpipe if $old_sigpipe;
ok t_cmp($expected, $received, "input stream filter partial consume")
[Tue Sep 23 09:06:10 2003] [info] mod_perl: using Perl HASH_SEED: 1237595763 mod_perl trace flags dump:
c Off (configuration for directive handlers)
d Off (directive processing)
f On (filters)
g Off (Perl runtime interaction)
h Off (handlers)
i Off (interpreter pool management)
m Off (memory allocations)
o Off (I/O)
s Off (perl sections)
t Off (benchmark-ish timings)
applied FilterConnectionHandler attribute to ModPerl::TestFilterDebug handler
applied FilterRequestHandler attribute to ModPerl::TestFilterDebug handler
[Tue Sep 23 09:06:11 2003] [info] 23 Apache:: modules loaded
[Tue Sep 23 09:06:11 2003] [info] 5 APR:: modules loaded
[Tue Sep 23 09:06:11 2003] [info] base server + 11 vhosts ready to run tests
applied FilterRequestHandler attribute to TestFilter::in_bbs_body handler
applied FilterInitHandler attribute to TestFilter::in_init_basic handler
applied FilterRequestHandler attribute to TestFilter::in_init_basic handler
applied FilterHasInitHandler(\&transparent_init) attribute to
TestFilter::in_init_basic handler
applied FilterInitHandler attribute to TestFilter::in_init_basic handler
applied FilterHasInitHandler(\&suicide_init) attribute to TestFilter::in_init_basic
handler
applied FilterInitHandler attribute to TestFilter::out_init_basic handler
applied FilterRequestHandler attribute to TestFilter::out_init_basic handler
applied FilterHasInitHandler(get_pre_handler()) attribute to
TestFilter::out_init_basic handler
applied FilterConnectionHandler attribute to TestFilter::in_str_msg handler
applied FilterConnectionHandler attribute to TestFilter::in_bbs_msg handler
[Tue Sep 23 09:06:13 2003] [info] mod_perl: using Perl HASH_SEED: 1886540735
[Tue Sep 23 09:06:13 2003] [notice] Child 2856: Child process is running
[Tue Sep 23 09:06:13 2003] [notice] Child 2856: Acquired the start mutex.
[Tue Sep 23 09:06:13 2003] [notice] Child 2856: Starting 20 worker threads.
[Tue Sep 23 09:06:13 2003] [debug] child.c(695): Child 2856: Worker thread 0 starting.
[Tue Sep 23 09:06:13 2003] [debug] child.c(695): Child 2856: Worker thread 1 starting.
[Tue Sep 23 09:06:13 2003] [debug] child.c(695): Child 2856: Worker thread 2 starting.
[Tue Sep 23 09:06:13 2003] [debug] child.c(695): Child 2856: Worker thread 3 starting.
[Tue Sep 23 09:06:13 2003] [debug] child.c(695): Child 2856: Worker thread 4 starting.
[Tue Sep 23 09:06:13 2003] [debug] child.c(695): Child 2856: Worker thread 5 starting.
[Tue Sep 23 09:06:13 2003] [debug] child.c(695): Child 2856: Worker thread 6 starting.
[Tue Sep 23 09:06:13 2003] [debug] child.c(695): Child 2856: Worker thread 7 starting.
[Tue Sep 23 09:06:13 2003] [debug] child.c(695): Child 2856: Worker thread 8 starting.
[Tue Sep 23 09:06:13 2003] [debug] child.c(695): Child 2856: Worker thread 9 starting.
[Tue Sep 23 09:06:13 2003] [debug] child.c(695): Child 2856: Worker thread 10 starting.
[Tue Sep 23 09:06:13 2003] [debug] child.c(695): Child 2856: Worker thread 11 starting.
[Tue Sep 23 09:06:13 2003] [debug] child.c(695): Child 2856: Worker thread 12 starting.
[Tue Sep 23 09:06:13 2003] [debug] child.c(695): Child 2856: Worker thread 13 starting.
[Tue Sep 23 09:06:13 2003] [debug] child.c(695): Child 2856: Worker thread 14 starting.
[Tue Sep 23 09:06:13 2003] [debug] child.c(695): Child 2856: Worker thread 15 starting.
[Tue Sep 23 09:06:13 2003] [debug] child.c(695): Child 2856: Worker thread 16 starting.
[Tue Sep 23 09:06:13 2003] [debug] child.c(695): Child 2856: Worker thread 17 starting.
[Tue Sep 23 09:06:13 2003] [debug] child.c(695): Child 2856: Worker thread 18 starting.
[Tue Sep 23 09:06:13 2003] [debug] child.c(695): Child 2856: Worker thread 19 starting.
ModPerl::TestFilterDebug::snoop_request
new: request input filter (0x334b198)
TestFilter::in_str_consume::handler
new: request input filter (0x334e1d0)
TestFilter::in_str_consume::handler::read
ModPerl::TestFilterDebug::snoop_request
new: request input filter (0x3351208)
ModPerl::TestFilterDebug::snoop_request
return: 0
TestFilter::in_str_consume::handler
retrieving bb: 0x3350228
TestFilter::in_str_consume::handler
wanted: 23 bytes
TestFilter::in_str_consume::handler
read in: HEAP bucket with 7836 bytes (0x91d928)
TestFilter::in_str_consume::handler
return: 23 bytes from 1 bucket (7813 bytes leftover)
TestFilter::in_str_consume::handler
return: 0
ModPerl::TestFilterDebug::snoop_request
return: 0
ModPerl::TestFilterDebug::snoop_request
new: request input filter (0x3354240)
TestFilter::in_str_consume::handler
new: request input filter (0x3357278)
TestFilter::in_str_consume::handler::read
ModPerl::TestFilterDebug::snoop_request
new: request input filter (0x335a2b0)
ModPerl::TestFilterDebug::snoop_request
return: 0
TestFilter::in_str_consume::handler
retrieving bb: 0x33592d0
TestFilter::in_str_consume::handler
wanted: 23 bytes
TestFilter::in_str_consume::handler
read in: HEAP bucket with 8000 bytes (0x91d9e8)
TestFilter::in_str_consume::handler
return: 23 bytes from 1 bucket (7977 bytes leftover)
TestFilter::in_str_consume::handler
return: 0
ModPerl::TestFilterDebug::snoop_request
return: 0
ModPerl::TestFilterDebug::snoop_request
new: request input filter (0x335d2e8)
TestFilter::in_str_consume::handler
new: request input filter (0x3360320)
TestFilter::in_str_consume::handler::read
ModPerl::TestFilterDebug::snoop_request
new: request input filter (0x3363358)
ModPerl::TestFilterDebug::snoop_request
return: 0
TestFilter::in_str_consume::handler
retrieving bb: 0x3362378
TestFilter::in_str_consume::handler
wanted: 23 bytes
TestFilter::in_str_consume::handler
read in: HEAP bucket with 8000 bytes (0x91d988)
TestFilter::in_str_consume::handler
return: 23 bytes from 1 bucket (7977 bytes leftover)
TestFilter::in_str_consume::handler
return: 0
ModPerl::TestFilterDebug::snoop_request
return: 0
ModPerl::TestFilterDebug::snoop_request
new: request input filter (0x3366390)
TestFilter::in_str_consume::handler
new: request input filter (0x33693c8)
TestFilter::in_str_consume::handler::read
ModPerl::TestFilterDebug::snoop_request
new: request input filter (0x336c400)
ModPerl::TestFilterDebug::snoop_request
return: 0
TestFilter::in_str_consume::handler
retrieving bb: 0x336b420
TestFilter::in_str_consume::handler
wanted: 23 bytes
TestFilter::in_str_consume::handler
read in: HEAP bucket with 8000 bytes (0x91d928)
TestFilter::in_str_consume::handler
return: 23 bytes from 1 bucket (7977 bytes leftover)
TestFilter::in_str_consume::handler
return: 0
ModPerl::TestFilterDebug::snoop_request
return: 0
ModPerl::TestFilterDebug::snoop_request
new: request input filter (0x336f438)
TestFilter::in_str_consume::handler
new: request input filter (0x3372470)
TestFilter::in_str_consume::handler::read
ModPerl::TestFilterDebug::snoop_request
new: request input filter (0x33754a8)
ModPerl::TestFilterDebug::snoop_request
return: 0
TestFilter::in_str_consume::handler
retrieving bb: 0x33744c8
TestFilter::in_str_consume::handler
wanted: 13 bytes
TestFilter::in_str_consume::handler
read in: HEAP bucket with 8000 bytes (0x91d9e8)
TestFilter::in_str_consume::handler
return: 13 bytes from 1 bucket (7987 bytes leftover)
TestFilter::in_str_consume::handler::print
TestFilter::in_str_consume::handler
write out: 105 bytes:
TestFilter::in_str_consume::handler
write out: EOS bucket
TestFilter::in_str_consume::handler
return: 0
ModPerl::TestFilterDebug::snoop_request
return: 0
write out: 3 bytes
from response handler
to byterange filter handler
--------------------------------------------------------------------- To unsubscribe, e-mail: [EMAIL PROTECTED] For additional commands, e-mail: [EMAIL PROTECTED]
