You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@perl.apache.org by Steve Hay <st...@uk.radan.com> on 2003/09/17 09:51:55 UTC
[mp2] t/filter/in_str_consume.t failure
Hi Stas,
As requested, here's a report of the t/filter/in_str_consume.t test
failure that I'm getting using Apache 2.0.47, perl@21233 and mp2 (from
CVS on 16 Sep) on Win32.
=====
C:\Temp\modperl-2.0>perl t/TEST -verbose t/filter/in_str_consume.t
C:\apache2/bin/Apache.exe -d C:/Temp/modperl-2.0/t -f
C:/Temp/modperl-2.0/t/conf/httpd.conf -DAPACHE2 -DPERL_USEITHREADS
using Apache/2.0.47 (winnt MPM)
waiting for server to start: .[Wed Sep 17 08:38:38 2003] [info] 23
Apache:: modules loaded
[Wed Sep 17 08:38:38 2003] [info] 5 APR:: modules loaded
[Wed Sep 17 08:38:38 2003] [info] base server + 11 vhosts ready to run tests
.............
waiting for server to start: ok (waited 13 secs)
server localhost:8529 started
server localhost:8530 listening (TestProtocol::echo)
server localhost:8531 listening (TestProtocol::echo_filter)
server localhost:8532 listening (TestProtocol::eliza)
server localhost:8533 listening (TestPreConnection::note)
server localhost:8534 listening (TestHooks::stacked_handlers2)
server localhost:8535 listening (TestFilter::both_str_con_add)
server localhost:8536 listening (TestFilter::in_bbs_msg)
server localhost:8537 listening (TestFilter::in_str_msg)
server localhost:8538 listening (TestDirective::perlmodule)
server localhost:8539 listening (TestDirective::perlrequire)
server localhost:8540 listening (TestPerl::ithreads)
server localhost:8541 listening (TestDirective::perlloadmodule3)
server localhost:8542 listening (TestDirective::perlloadmodule4)
server localhost:8543 listening (TestDirective::perlloadmodule5)
server localhost:8544 listening (TestDirective::perlloadmodule6)
filter/in_str_consume....1..1
# Running under perl version 5.008001 for MSWin32
# Current time local: Wed Sep 17 08:38:52 2003
# Current time GMT: Wed Sep 17 07:38:52 2003
# Using Test.pm version 1.24
# sent 80000B, expecting 105B to make through
malformed response at
C:/Temp/modperl-2.0/Apache-Test/lib/Apache/TestClient.pm line 86.
# Failed test 1 in filter/in_str_consume.t at line 21
# testing : input stream filter partial consume
# expected: 105
# received:
not ok 1
FAILED test 1
Failed 1/1 tests, 0.00% okay
Failed Test Stat Wstat Total Fail Failed List of Failed
-------------------------------------------------------------------------------
filter/in_str_consume.t 1 1 100.00% 1
!!! error running tests (please examine t\logs\error_log)
=====
Sadly the error_log contains nothing of interest (the last 20 messages
were regarding worker threads starting).
Inserting some debug shows that $res->{headers_as_string} is the null
string at the point where the "malformed response" warning appears.
- Steve
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@perl.apache.org
For additional commands, e-mail: dev-help@perl.apache.org
Re: [mp2] t/filter/in_str_consume.t failure
Posted by Stas Bekman <st...@stason.org>.
Steve Hay wrote:
>> is it still the problem with leading / in the path? Can you please
>> submit this issue as a separate thread?
>
>
> Sorry - I must have confused you there. I was reporting the fact that
> the new APACHE_TEST_PRETEND_NO_LWP option is indeed working, which I
> established by running the test suite with the *old* (broken) cookie
> tests in place. (They should, and do, break when we pretend not to have
> LWP, even though LWP is really installed.)
>
> All is well when running with the *new* (fixed) cookie tests, whether we
> pretend not to have LWP or not.
ok, the cookie tests issue is now officially closed on win32 ;) (I do have
problems with the cookie test on linux but for a totally different reason,
will take care of it soonish).
>>> Unfortunately that crash actually takes the Apache server down
>>> causing all subsequent tests to fail (I generally just stop the
>>> testsuite there). How do I have "nmake test" skip one test script so
>>> that I can see what the rest do without having to run each one manually?
>>
>>
>>
>> http://perl.apache.org/docs/general/testing/testing.html#Skipping_Numerous_Tests
>>
>>
>> or you can change the test to skip, by changing its plan to 'plan =>
>> tests, 0;'
>> http://perl.apache.org/docs/general/testing/testing.html#Skipping_a_Whole_Test
>>
>>
>> probably the former is a better approach.
>
>
> Groovy. I've added a SKIP file containing initially just "filter" and
> this enables me to get further. Sadly there are further failures:
>
> hooks/stacked_handlers2.t
> modules/include.t
>
> I'll report these in separate threads.
>
> BTW, The SKIP file is not as easy to use on Win32 as it could be. I
> find that if I put in a line like "hooks/stacked_handlers2" then the
> test is *not* skipped. Neither is it skipped if I write
> "hooks\stacked_handlers2". It turns out that I have to write
> "hooks\\stacked_handlers2". Yuck!
>
> I only realised this when I added "modules\include" and got this error:
>
> ===
> Unrecognized escape \i passed through in regex; marked by <-- HERE in
> m/(?:modul
> es\i <-- HERE nclude)/ at
> C:\Temp\modperl-2.0\Apache-Test\lib/Apache/TestHarness
> .pm line 138.
> ===
>
> (Writing "hooks\stacked_handlers2" doesn't trigger this error because \s
> is recognised!)
>
> I can hack TestHarness.pm so that it works OK for me on Win32, but doing
> it so that it works portably on any OS it rather trickier. I haven't
> got time for it now.
Actually I believe it should be trivial to make it portable. Just use
File::Spec tools to split the path into its componenent and then construct it
back? Probably Doug was using that feature on unix and didn't test on win32 ;)
__________________________________________________________________
Stas Bekman JAm_pH ------> Just Another mod_perl Hacker
http://stason.org/ mod_perl Guide ---> http://perl.apache.org
mailto:stas@stason.org http://use.perl.org http://apacheweek.com
http://modperlbook.org http://apache.org http://ticketmaster.com
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@perl.apache.org
For additional commands, e-mail: dev-help@perl.apache.org
Re: [mp2] t/filter/in_str_consume.t failure
Posted by Steve Hay <st...@uk.radan.com>.
Stas Bekman wrote:
> Steve Hay wrote:
>
>>> please run the test suite twice:
>>>
>>> env APACHE_TEST_PRETEND_NO_LWP=1 make test ;
>>> make test
>>>
>>> the former will emulate the situation when LWP is missing. See if
>>> you have any problems besides the perlio test
>>
>>
>>
>> (The APACHE_TEST_PRETEND_NO_LWP setting seems to work OK: I
>> re-instated the old version of the cookie tests that broke without
>> LWP, and (with LWP installed) they still break when that flag is set,
>> and pass when it isn't.)
>
>
> is it still the problem with leading / in the path? Can you please
> submit this issue as a separate thread?
Sorry - I must have confused you there. I was reporting the fact that
the new APACHE_TEST_PRETEND_NO_LWP option is indeed working, which I
established by running the test suite with the *old* (broken) cookie
tests in place. (They should, and do, break when we pretend not to have
LWP, even though LWP is really installed.)
All is well when running with the *new* (fixed) cookie tests, whether we
pretend not to have LWP or not.
>
>> Unfortunately that crash actually takes the Apache server down
>> causing all subsequent tests to fail (I generally just stop the
>> testsuite there). How do I have "nmake test" skip one test script so
>> that I can see what the rest do without having to run each one manually?
>
>
> http://perl.apache.org/docs/general/testing/testing.html#Skipping_Numerous_Tests
>
>
> or you can change the test to skip, by changing its plan to 'plan =>
> tests, 0;'
> http://perl.apache.org/docs/general/testing/testing.html#Skipping_a_Whole_Test
>
>
> probably the former is a better approach.
Groovy. I've added a SKIP file containing initially just "filter" and
this enables me to get further. Sadly there are further failures:
hooks/stacked_handlers2.t
modules/include.t
I'll report these in separate threads.
BTW, The SKIP file is not as easy to use on Win32 as it could be. I
find that if I put in a line like "hooks/stacked_handlers2" then the
test is *not* skipped. Neither is it skipped if I write
"hooks\stacked_handlers2". It turns out that I have to write
"hooks\\stacked_handlers2". Yuck!
I only realised this when I added "modules\include" and got this error:
===
Unrecognized escape \i passed through in regex; marked by <-- HERE in
m/(?:modul
es\i <-- HERE nclude)/ at
C:\Temp\modperl-2.0\Apache-Test\lib/Apache/TestHarness
.pm line 138.
===
(Writing "hooks\stacked_handlers2" doesn't trigger this error because \s
is recognised!)
I can hack TestHarness.pm so that it works OK for me on Win32, but doing
it so that it works portably on any OS it rather trickier. I haven't
got time for it now.
- Steve
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@perl.apache.org
For additional commands, e-mail: dev-help@perl.apache.org
Re: [RESOLVED] Re: [mp2] t/filter/in_str_consume.t failure
Posted by Stas Bekman <st...@stason.org>.
Steve Hay wrote:
> Stas Bekman wrote:
>
>> Steve, I still want you to followup on the suggestions I made in the
>> previous post, however this should fix the problem. Thanks.
>
>
> Hurrah! I've just done 12 runs each with and without
> APACHE_TEST_PRETEND_NO_LWP set, and all 24 ran OK.
>
> I think you've cracked it at last. Well done!
Thanks Steve, even though this is not what I wanted but it makes the test safe
and I've documented what should the filter writer should do in this situation
(consume all the data).
>> +
>> + # tell Apache to get rid of the rest of the request body
>> + # if we don't a client will get a broken pipe and may fail to
>> + # handle this situation gracefully
>> + $r->discard_request_body;
>> +
>> my $len = length $data;
>> debug "HANDLER READ: $len bytes\n";
>> $r->print($len);
__________________________________________________________________
Stas Bekman JAm_pH ------> Just Another mod_perl Hacker
http://stason.org/ mod_perl Guide ---> http://perl.apache.org
mailto:stas@stason.org http://use.perl.org http://apacheweek.com
http://modperlbook.org http://apache.org http://ticketmaster.com
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@perl.apache.org
For additional commands, e-mail: dev-help@perl.apache.org
[RESOLVED] Re: [mp2] t/filter/in_str_consume.t failure
Posted by Steve Hay <st...@uk.radan.com>.
Stas Bekman wrote:
> Steve, I still want you to followup on the suggestions I made in the
> previous post, however this should fix the problem. Thanks.
Hurrah! I've just done 12 runs each with and without
APACHE_TEST_PRETEND_NO_LWP set, and all 24 ran OK.
I think you've cracked it at last. Well done!
- Steve
>
>
> Index: t/filter/TestFilter/in_str_consume.pm
> ===================================================================
> RCS file: /home/cvs/modperl-2.0/t/filter/TestFilter/in_str_consume.pm,v
> retrieving revision 1.9
> diff -u -r1.9 in_str_consume.pm
> --- t/filter/TestFilter/in_str_consume.pm 18 Sep 2003 08:10:32
> -0000 1.9
> +++ t/filter/TestFilter/in_str_consume.pm 23 Sep 2003 02:20:10
> -0000
> @@ -106,6 +106,12 @@
>
> if ($r->method_number == Apache::M_POST) {
> my $data = ModPerl::Test::read_post($r);
> +
> + # tell Apache to get rid of the rest of the request body
> + # if we don't a client will get a broken pipe and may fail to
> + # handle this situation gracefully
> + $r->discard_request_body;
> +
> my $len = length $data;
> debug "HANDLER READ: $len bytes\n";
> $r->print($len);
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@perl.apache.org
For additional commands, e-mail: dev-help@perl.apache.org
Re: [mp2] t/filter/in_str_consume.t failure
Posted by Stas Bekman <st...@stason.org>.
Steve, I still want you to followup on the suggestions I made in the previous
post, however this should fix the problem. Thanks.
Index: t/filter/TestFilter/in_str_consume.pm
===================================================================
RCS file: /home/cvs/modperl-2.0/t/filter/TestFilter/in_str_consume.pm,v
retrieving revision 1.9
diff -u -r1.9 in_str_consume.pm
--- t/filter/TestFilter/in_str_consume.pm 18 Sep 2003 08:10:32 -0000
1.9
+++ t/filter/TestFilter/in_str_consume.pm 23 Sep 2003 02:20:10 -0000
@@ -106,6 +106,12 @@
if ($r->method_number == Apache::M_POST) {
my $data = ModPerl::Test::read_post($r);
+
+ # tell Apache to get rid of the rest of the request body
+ # if we don't a client will get a broken pipe and may fail to
+ # handle this situation gracefully
+ $r->discard_request_body;
+
my $len = length $data;
debug "HANDLER READ: $len bytes\n";
$r->print($len);
__________________________________________________________________
Stas Bekman JAm_pH ------> Just Another mod_perl Hacker
http://stason.org/ mod_perl Guide ---> http://perl.apache.org
mailto:stas@stason.org http://use.perl.org http://apacheweek.com
http://modperlbook.org http://apache.org http://ticketmaster.com
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@perl.apache.org
For additional commands, e-mail: dev-help@perl.apache.org
Re: [mp2] t/filter/in_str_consume.t failure
Posted by Stas Bekman <st...@stason.org>.
Steve Hay wrote:
> Stas Bekman wrote:
>
>> Steve Hay wrote:
>>
>>>> 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.
>>
>>
>>
>> May be it's different on win32, when the socket is closed on the
>> reading client. I was getting the SIGPIPE on linux only when the print
>> was in Apache::TestClient, not with $s->send(), which was failing
>> silently without die'ing or throwing any signals. I wasn't getting any
>> problems when using LWP. Perhaps this is something that needs to be
>> fixed in perl. You can try the test case that I have posted to p5p:
>> http://www.xray.mpe.mpg.de/mailing-lists/perl5-porters/2003-09/msg01112.html
>
>
> I tried out your test case (using perl-5.8.1-RC5) and my client doesn't
> get the SIGPIPE - it just says "done", and the server has read 10 "x"s.
> (I tried perl-5.8.0 too, with the same result.)
>
> Is that good or bad? Nick I-S and yourself seem to agree in follow-ups
> to that mail that the SIGPIPE was a good thing.
But you don't get it on win32. I was trying to emulate the situation that we
were struggling with before, trying to make the client gracefully resolve a
closed socket. That test case seems to represent quite well what was happening
on linux, may be on win32 the server behaves differently and that's why this
test doesn't reproduce the problem. Oh well, let's put this case to rest then.
Thank you for testing it, Steve.
__________________________________________________________________
Stas Bekman JAm_pH ------> Just Another mod_perl Hacker
http://stason.org/ mod_perl Guide ---> http://perl.apache.org
mailto:stas@stason.org http://use.perl.org http://apacheweek.com
http://modperlbook.org http://apache.org http://ticketmaster.com
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@perl.apache.org
For additional commands, e-mail: dev-help@perl.apache.org
Re: [mp2] t/filter/in_str_consume.t failure
Posted by Steve Hay <st...@uk.radan.com>.
Stas Bekman wrote:
> Steve Hay wrote:
>
>>> 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.
>
>
> May be it's different on win32, when the socket is closed on the
> reading client. I was getting the SIGPIPE on linux only when the print
> was in Apache::TestClient, not with $s->send(), which was failing
> silently without die'ing or throwing any signals. I wasn't getting any
> problems when using LWP. Perhaps this is something that needs to be
> fixed in perl. You can try the test case that I have posted to p5p:
> http://www.xray.mpe.mpg.de/mailing-lists/perl5-porters/2003-09/msg01112.html
I tried out your test case (using perl-5.8.1-RC5) and my client doesn't
get the SIGPIPE - it just says "done", and the server has read 10 "x"s.
(I tried perl-5.8.0 too, with the same result.)
Is that good or bad? Nick I-S and yourself seem to agree in follow-ups
to that mail that the SIGPIPE was a good thing.
- Steve
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@perl.apache.org
For additional commands, e-mail: dev-help@perl.apache.org
Re: [mp2] t/filter/in_str_consume.t failure
Posted by Stas Bekman <st...@stason.org>.
Steve Hay wrote:
>> 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.
May be it's different on win32, when the socket is closed on the reading
client. I was getting the SIGPIPE on linux only when the print was in
Apache::TestClient, not with $s->send(), which was failing silently without
die'ing or throwing any signals. I wasn't getting any problems when using LWP.
Perhaps this is something that needs to be fixed in perl. You can try the test
case that I have posted to p5p:
http://www.xray.mpe.mpg.de/mailing-lists/perl5-porters/2003-09/msg01112.html
>> +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")
__________________________________________________________________
Stas Bekman JAm_pH ------> Just Another mod_perl Hacker
http://stason.org/ mod_perl Guide ---> http://perl.apache.org
mailto:stas@stason.org http://use.perl.org http://apacheweek.com
http://modperlbook.org http://apache.org http://ticketmaster.com
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@perl.apache.org
For additional commands, e-mail: dev-help@perl.apache.org
Re: [mp2] t/filter/in_str_consume.t failure
Posted by Steve Hay <st...@uk.radan.com>.
Stas Bekman wrote:
> 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")
Re: [mp2] t/filter/in_str_consume.t failure
Posted by Stas Bekman <st...@stason.org>.
Steve Hay wrote:
> Stas Bekman wrote:
>
>> Steve Hay wrote:
>> [...]
>>
>> OK, so you have t/filter/in_str_consume.t failing with and without LWP
>> and it happens randomly and it's not affected by the PERL_HASH_SEED
>> variable. You didn't tell me what's the error that you get. Or do you
>> get that silent failure as before? If so try with -v and look for
>> error message on the client side, not error_log. This test is special,
>> since the server underreads data sent by the client, it's possible
>> that neither LWP nor TestClient are good at handling that condition.
>
>
> Here's what I (sometimes!) get running "perl t/TEST -verbose
> t/filter/in_str_consume.t":
>
> =====
> filter/in_str_consume....1..1
> # Running under perl version 5.008001 for MSWin32
> # Current time local: Mon Sep 22 11:23:46 2003
> # Current time GMT: Mon Sep 22 10:23:46 2003
> # Using Test.pm version 1.24
> # sent 80000B, expecting 105B to make through
> # Failed test 1 in filter/in_str_consume.t at line 21
> # testing : input stream filter partial consume
> # expected: 105
> # received:
> not ok 1
> FAILED test 1
> Failed 1/1 tests, 0.00% okay
> Failed Test Stat Wstat Total Fail Failed List of Failed
> -------------------------------------------------------------------------------
>
> filter/in_str_consume.t 1 1 100.00% 1
> =====
>
> The error_log contains nothing of interest (only the stuff about the
> server starting up).
I've seen that with Apache::TestClient (when LWP is not available). The
problem is that it may fail to deal with the broken pipe to the server.
>> Another thing that will help debuggiing is looking at the trace with
>> MOD_PERL_TRACE=f and -trace=debug. I bet that it fails the moment the
>> filter stops its reading:
>>
>> env MOD_PERL_TRACE=f t/TEST -verbose -trace=debug
>> t/filter/in_str_consume.t
>>
>> This should tell you all the story.
>
>
> It doesn't tell me anything, I'm afraid.
>
> 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? Does the patch
below help at all? I'm not quite sure whether localization works, so just
trying it that way.
> 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.
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")
__________________________________________________________________
Stas Bekman JAm_pH ------> Just Another mod_perl Hacker
http://stason.org/ mod_perl Guide ---> http://perl.apache.org
mailto:stas@stason.org http://use.perl.org http://apacheweek.com
http://modperlbook.org http://apache.org http://ticketmaster.com
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@perl.apache.org
For additional commands, e-mail: dev-help@perl.apache.org
Re: [mp2] t/filter/in_str_consume.t failure
Posted by Steve Hay <st...@uk.radan.com>.
Stas Bekman wrote:
> Steve Hay wrote:
> [...]
>
> OK, so you have t/filter/in_str_consume.t failing with and without LWP
> and it happens randomly and it's not affected by the PERL_HASH_SEED
> variable. You didn't tell me what's the error that you get. Or do you
> get that silent failure as before? If so try with -v and look for
> error message on the client side, not error_log. This test is special,
> since the server underreads data sent by the client, it's possible
> that neither LWP nor TestClient are good at handling that condition.
Here's what I (sometimes!) get running "perl t/TEST -verbose
t/filter/in_str_consume.t":
=====
filter/in_str_consume....1..1
# Running under perl version 5.008001 for MSWin32
# Current time local: Mon Sep 22 11:23:46 2003
# Current time GMT: Mon Sep 22 10:23:46 2003
# Using Test.pm version 1.24
# sent 80000B, expecting 105B to make through
# Failed test 1 in filter/in_str_consume.t at line 21
# testing : input stream filter partial consume
# expected: 105
# received:
not ok 1
FAILED test 1
Failed 1/1 tests, 0.00% okay
Failed Test Stat Wstat Total Fail Failed List of Failed
-------------------------------------------------------------------------------
filter/in_str_consume.t 1 1 100.00% 1
=====
The error_log contains nothing of interest (only the stuff about the
server starting up).
>
>
> Another thing that will help debuggiing is looking at the trace with
> MOD_PERL_TRACE=f and -trace=debug. I bet that it fails the moment the
> filter stops its reading:
>
> env MOD_PERL_TRACE=f t/TEST -verbose -trace=debug
> t/filter/in_str_consume.t
>
> This should tell you all the story.
It doesn't tell me anything, I'm afraid.
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 :-(
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.
- Steve
Re: [mp2] t/filter/in_str_consume.t failure
Posted by Stas Bekman <st...@stason.org>.
Steve Hay wrote:
[...]
OK, so you have t/filter/in_str_consume.t failing with and without LWP and it
happens randomly and it's not affected by the PERL_HASH_SEED variable. You
didn't tell me what's the error that you get. Or do you get that silent
failure as before? If so try with -v and look for error message on the client
side, not error_log. This test is special, since the server underreads data
sent by the client, it's possible that neither LWP nor TestClient are good at
handling that condition.
Another thing that will help debuggiing is looking at the trace with
MOD_PERL_TRACE=f and -trace=debug. I bet that it fails the moment the filter
stops its reading:
env MOD_PERL_TRACE=f t/TEST -verbose -trace=debug t/filter/in_str_consume.t
This should tell you all the story.
__________________________________________________________________
Stas Bekman JAm_pH ------> Just Another mod_perl Hacker
http://stason.org/ mod_perl Guide ---> http://perl.apache.org
mailto:stas@stason.org http://use.perl.org http://apacheweek.com
http://modperlbook.org http://apache.org http://ticketmaster.com
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@perl.apache.org
For additional commands, e-mail: dev-help@perl.apache.org
Re: [mp2] t/filter/in_str_consume.t failure
Posted by Steve Hay <st...@uk.radan.com>.
Stas Bekman wrote:
> Randy Kobes wrote:
>
>> On Thu, 18 Sep 2003, Stas Bekman wrote:
>>
>>
>>> Steve Hay wrote:
>>
>>
>> [ .. ]
>>
>>>> Damn. I've just discovered that this isn't actually fixed --
>>>> sometimes
>>>> it works, sometimes not.
>>>>
>>>> I just ran "perl t/TEST t/filter/in_str_consume.t" six times and got
>>>> these results:
>>>>
>>>> FAIL
>>>> PASS
>>>> FAIL
>>>> PASS
>>>> PASS
>>>> FAIL
>>>
>>>
>>> What's the failure? All the same? A silent die? This is only with
>>> APACHE_TEST_PRETEND_NO_LWP=1, right?
>>
>>
>>
>> I get the same failure, without APACHE_TEST_PREPEND_NO_LWP,
>> but not consistently (occasionally it'll pass). When it
>> fails the test returns nothing. I wasn't too worried about
>> it at the time, as all the filter tests have problems when
>> run from 'nmake test', and so this may ultimately get
>> resolved when that problem is fixed (maybe).
>
I didn't see it like that: This test fails intermittently, and doesn't
require any special combination of prior tests to make it fail - it even
fails when run on its own. The other filter test that we're looking at
(both_str_con_add.t) only fails when run after certain other tests
(t/api + t/apr), and does so every time under those circumstances, but
it never fails when run on its own.
They sound like different problems to me, but who knows...
>>
>
> Man, people are going to have so much fun with this random thing when
> 5.8.1 hits the streets. If you run your tests with env
> PERL_HASH_SEED_DEBUG=1 you will be able to re-use the HASH_SEED it
> reported when you had a failure to reliable reproduce the problem if
> this has anything to do with the hash randomness. it's possible that
> it's not the issue, but I'd try that first. To tell perl to use a
> specific seed just run the test with:
>
> env PERL_HASH_SEED=9879434 t/TEST ... (and the seed comes from the
> mod_perl report
>
> it error_log)
It's nothing to do with hash seed randomisation: I grabbed the hash seed
from a "successful" run from the error_log and ran a few times with that
set in the env and got some failures. Conversely, running with a hash
seed from a "failed" run, I got some successes.
>
>
> You say: without APACHE_TEST_PREPEND_NO_LWP, so you do have LWP, right
> and it doesn't use Apache::TestClient, so the problem is elsewhere and
> not in the broken pipe issue that is now fixed.
I also have LWP. I've tried running this test with and without
APACHE_TEST_PREPEND_NO_LWP set and get a mix of successes/failures
either way.
>
>
> also do you have this problem when running standalone, or with other
> tests?
This one fails when run on its own (perl t/TEST
t/filter/in_str_consume.t), or when run with other tests.
- Steve
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@perl.apache.org
For additional commands, e-mail: dev-help@perl.apache.org
Re: [mp2] t/filter/in_str_consume.t failure
Posted by Stas Bekman <st...@stason.org>.
Randy Kobes wrote:
> On Thu, 18 Sep 2003, Stas Bekman wrote:
>
>
>>Steve Hay wrote:
>
> [ .. ]
>
>>>Damn. I've just discovered that this isn't actually fixed -- sometimes
>>>it works, sometimes not.
>>>
>>>I just ran "perl t/TEST t/filter/in_str_consume.t" six times and got
>>>these results:
>>>
>>>FAIL
>>>PASS
>>>FAIL
>>>PASS
>>>PASS
>>>FAIL
>>
>>What's the failure? All the same? A silent die? This is only with
>>APACHE_TEST_PRETEND_NO_LWP=1, right?
>
>
> I get the same failure, without APACHE_TEST_PREPEND_NO_LWP,
> but not consistently (occasionally it'll pass). When it
> fails the test returns nothing. I wasn't too worried about
> it at the time, as all the filter tests have problems when
> run from 'nmake test', and so this may ultimately get
> resolved when that problem is fixed (maybe).
Man, people are going to have so much fun with this random thing when 5.8.1
hits the streets. If you run your tests with env PERL_HASH_SEED_DEBUG=1 you
will be able to re-use the HASH_SEED it reported when you had a failure to
reliable reproduce the problem if this has anything to do with the hash
randomness. it's possible that it's not the issue, but I'd try that first. To
tell perl to use a specific seed just run the test with:
env PERL_HASH_SEED=9879434 t/TEST ... (and the seed comes from the mod_perl
report
it error_log)
You say: without APACHE_TEST_PREPEND_NO_LWP, so you do have LWP, right and it
doesn't use Apache::TestClient, so the problem is elsewhere and not in the
broken pipe issue that is now fixed.
also do you have this problem when running standalone, or with other tests?
__________________________________________________________________
Stas Bekman JAm_pH ------> Just Another mod_perl Hacker
http://stason.org/ mod_perl Guide ---> http://perl.apache.org
mailto:stas@stason.org http://use.perl.org http://apacheweek.com
http://modperlbook.org http://apache.org http://ticketmaster.com
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@perl.apache.org
For additional commands, e-mail: dev-help@perl.apache.org
Re: [mp2] t/filter/in_str_consume.t failure
Posted by Randy Kobes <ra...@theoryx5.uwinnipeg.ca>.
On Thu, 18 Sep 2003, Stas Bekman wrote:
> Steve Hay wrote:
[ .. ]
> > Damn. I've just discovered that this isn't actually fixed -- sometimes
> > it works, sometimes not.
> >
> > I just ran "perl t/TEST t/filter/in_str_consume.t" six times and got
> > these results:
> >
> > FAIL
> > PASS
> > FAIL
> > PASS
> > PASS
> > FAIL
>
> What's the failure? All the same? A silent die? This is only with
> APACHE_TEST_PRETEND_NO_LWP=1, right?
I get the same failure, without APACHE_TEST_PREPEND_NO_LWP,
but not consistently (occasionally it'll pass). When it
fails the test returns nothing. I wasn't too worried about
it at the time, as all the filter tests have problems when
run from 'nmake test', and so this may ultimately get
resolved when that problem is fixed (maybe).
--
best regards,
randy
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@perl.apache.org
For additional commands, e-mail: dev-help@perl.apache.org
Re: [mp2] t/filter/in_str_consume.t failure
Posted by Stas Bekman <st...@stason.org>.
Steve Hay wrote:
> Stas Bekman wrote:
>
>> Steve Hay wrote:
>> [...]
>>
>>>>> filter/in_str_consume.t 1 1 100.00% 1
>>>>> !!! error running tests (please examine t\logs\error_log)
>>>>
>>>>
>>>>
>>>>
>>>>
>>>> That proved to be a bug in Apache::TestClient, which couldn't handle
>>>> situations where the server won't read all the data the client tries
>>>> to send. Now fixed.
>>>
>>>
>>>
>>>
>>> Yep - mine passes OK now.
>>
>>
>>
>> Great
>
>
> Damn. I've just discovered that this isn't actually fixed -- sometimes
> it works, sometimes not.
>
> I just ran "perl t/TEST t/filter/in_str_consume.t" six times and got
> these results:
>
> FAIL
> PASS
> FAIL
> PASS
> PASS
> FAIL
What's the failure? All the same? A silent die? This is only with
APACHE_TEST_PRETEND_NO_LWP=1, right?
__________________________________________________________________
Stas Bekman JAm_pH ------> Just Another mod_perl Hacker
http://stason.org/ mod_perl Guide ---> http://perl.apache.org
mailto:stas@stason.org http://use.perl.org http://apacheweek.com
http://modperlbook.org http://apache.org http://ticketmaster.com
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@perl.apache.org
For additional commands, e-mail: dev-help@perl.apache.org
Re: [mp2] t/filter/in_str_consume.t failure
Posted by Steve Hay <st...@uk.radan.com>.
Stas Bekman wrote:
> Steve Hay wrote:
> [...]
>
>>>> filter/in_str_consume.t 1 1 100.00% 1
>>>> !!! error running tests (please examine t\logs\error_log)
>>>
>>>
>>>
>>>
>>> That proved to be a bug in Apache::TestClient, which couldn't handle
>>> situations where the server won't read all the data the client tries
>>> to send. Now fixed.
>>
>>
>>
>> Yep - mine passes OK now.
>
>
> Great
Damn. I've just discovered that this isn't actually fixed -- sometimes
it works, sometimes not.
I just ran "perl t/TEST t/filter/in_str_consume.t" six times and got
these results:
FAIL
PASS
FAIL
PASS
PASS
FAIL
Grrr.
- Steve
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@perl.apache.org
For additional commands, e-mail: dev-help@perl.apache.org
Re: [mp2] t/filter/in_str_consume.t failure
Posted by Stas Bekman <st...@stason.org>.
Steve Hay wrote:
[...]
>>> filter/in_str_consume.t 1 1 100.00% 1
>>> !!! error running tests (please examine t\logs\error_log)
>>
>>
>>
>> That proved to be a bug in Apache::TestClient, which couldn't handle
>> situations where the server won't read all the data the client tries
>> to send. Now fixed.
>
>
> Yep - mine passes OK now.
Great
>> please run the test suite twice:
>>
>> env APACHE_TEST_PRETEND_NO_LWP=1 make test ;
>> make test
>>
>> the former will emulate the situation when LWP is missing. See if you
>> have any problems besides the perlio test
>
>
> (The APACHE_TEST_PRETEND_NO_LWP setting seems to work OK: I re-instated
> the old version of the cookie tests that broke without LWP, and (with
> LWP installed) they still break when that flag is set, and pass when it
> isn't.)
is it still the problem with leading / in the path? Can you please submit this
issue as a separate thread?
> There is, of course, one other problem besides the perlio test -- the
> filter/both_str_con_add segfault.
Yup, I posted this reply before I got to filter/both_str_con_add
> Unfortunately that crash actually
> takes the Apache server down causing all subsequent tests to fail (I
> generally just stop the testsuite there). How do I have "nmake test"
> skip one test script so that I can see what the rest do without having
> to run each one manually?
http://perl.apache.org/docs/general/testing/testing.html#Skipping_Numerous_Tests
or you can change the test to skip, by changing its plan to 'plan => tests, 0;'
http://perl.apache.org/docs/general/testing/testing.html#Skipping_a_Whole_Test
probably the former is a better approach.
>> because of the failure of that test, make test won't descend into
>> ModPerl-Registry, so please do so manually and run the two again:
>>
>> cd ModPerl-Registry
>> env APACHE_TEST_PRETEND_NO_LWP=1 make test ;
>> make test
>
>
> These all pass OK, with and "without" LWP.
Cool.
time to go to sleep... thank you for doing this debugging, Steve!
__________________________________________________________________
Stas Bekman JAm_pH ------> Just Another mod_perl Hacker
http://stason.org/ mod_perl Guide ---> http://perl.apache.org
mailto:stas@stason.org http://use.perl.org http://apacheweek.com
http://modperlbook.org http://apache.org http://ticketmaster.com
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@perl.apache.org
For additional commands, e-mail: dev-help@perl.apache.org
Re: [mp2] t/filter/in_str_consume.t failure
Posted by Steve Hay <st...@uk.radan.com>.
Stas Bekman wrote:
> Steve,
>
>> As requested, here's a report of the t/filter/in_str_consume.t test
>> failure that I'm getting using Apache 2.0.47, perl@21233 and mp2
>> (from CVS on 16 Sep) on Win32.
>
> [...]
>
>> filter/in_str_consume....1..1
>> # Running under perl version 5.008001 for MSWin32
>> # Current time local: Wed Sep 17 08:38:52 2003
>> # Current time GMT: Wed Sep 17 07:38:52 2003
>> # Using Test.pm version 1.24
>> # sent 80000B, expecting 105B to make through
>> malformed response at
>> C:/Temp/modperl-2.0/Apache-Test/lib/Apache/TestClient.pm line 86.
>> # Failed test 1 in filter/in_str_consume.t at line 21
>> # testing : input stream filter partial consume
>> # expected: 105
>> # received:
>> not ok 1
>> FAILED test 1
>> Failed 1/1 tests, 0.00% okay
>> Failed Test Stat Wstat Total Fail Failed List of Failed
>> -------------------------------------------------------------------------------
>>
>> filter/in_str_consume.t 1 1 100.00% 1
>> !!! error running tests (please examine t\logs\error_log)
>
>
> That proved to be a bug in Apache::TestClient, which couldn't handle
> situations where the server won't read all the data the client tries
> to send. Now fixed.
Yep - mine passes OK now.
>
>
> please run the test suite twice:
>
> env APACHE_TEST_PRETEND_NO_LWP=1 make test ;
> make test
>
> the former will emulate the situation when LWP is missing. See if you
> have any problems besides the perlio test
(The APACHE_TEST_PRETEND_NO_LWP setting seems to work OK: I re-instated
the old version of the cookie tests that broke without LWP, and (with
LWP installed) they still break when that flag is set, and pass when it
isn't.)
There is, of course, one other problem besides the perlio test -- the
filter/both_str_con_add segfault. Unfortunately that crash actually
takes the Apache server down causing all subsequent tests to fail (I
generally just stop the testsuite there). How do I have "nmake test"
skip one test script so that I can see what the rest do without having
to run each one manually?
>
>
> because of the failure of that test, make test won't descend into
> ModPerl-Registry, so please do so manually and run the two again:
>
> cd ModPerl-Registry
> env APACHE_TEST_PRETEND_NO_LWP=1 make test ;
> make test
These all pass OK, with and "without" LWP.
- Steve
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@perl.apache.org
For additional commands, e-mail: dev-help@perl.apache.org
Re: [mp2] t/filter/in_str_consume.t failure
Posted by Stas Bekman <st...@stason.org>.
Steve,
> As requested, here's a report of the t/filter/in_str_consume.t test
> failure that I'm getting using Apache 2.0.47, perl@21233 and mp2 (from
> CVS on 16 Sep) on Win32.
[...]
> filter/in_str_consume....1..1
> # Running under perl version 5.008001 for MSWin32
> # Current time local: Wed Sep 17 08:38:52 2003
> # Current time GMT: Wed Sep 17 07:38:52 2003
> # Using Test.pm version 1.24
> # sent 80000B, expecting 105B to make through
> malformed response at
> C:/Temp/modperl-2.0/Apache-Test/lib/Apache/TestClient.pm line 86.
> # Failed test 1 in filter/in_str_consume.t at line 21
> # testing : input stream filter partial consume
> # expected: 105
> # received:
> not ok 1
> FAILED test 1
> Failed 1/1 tests, 0.00% okay
> Failed Test Stat Wstat Total Fail Failed List of Failed
> -------------------------------------------------------------------------------
>
> filter/in_str_consume.t 1 1 100.00% 1
> !!! error running tests (please examine t\logs\error_log)
That proved to be a bug in Apache::TestClient, which couldn't handle
situations where the server won't read all the data the client tries to send.
Now fixed.
please run the test suite twice:
env APACHE_TEST_PRETEND_NO_LWP=1 make test ;
make test
the former will emulate the situation when LWP is missing. See if you have any
problems besides the perlio test
because of the failure of that test, make test won't descend into
ModPerl-Registry, so please do so manually and run the two again:
cd ModPerl-Registry
env APACHE_TEST_PRETEND_NO_LWP=1 make test ;
make test
thanks.
__________________________________________________________________
Stas Bekman JAm_pH ------> Just Another mod_perl Hacker
http://stason.org/ mod_perl Guide ---> http://perl.apache.org
mailto:stas@stason.org http://use.perl.org http://apacheweek.com
http://modperlbook.org http://apache.org http://ticketmaster.com
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@perl.apache.org
For additional commands, e-mail: dev-help@perl.apache.org