As reported in other thread, I've seen mod_perl emit panic warnings such
as the following ever since 5.19.7:
panic: attempt to copy freed scalar 7fb2264ffde0 to 7fb2264ffd08 at
/Users/mschout/Sync/Apache-TryCatch/blib/lib/Apache/TryCatch.pm line 20.
I've also seen random segementation faults caused by innocent looking
"return" statements in a large code base.
I've created a test mod perl handler that demonstrates this behaviour:
------------------
package Apache::TryCatch;
use Apache2::Const -compile => qw(OK);
use TryCatch;
use CGI;
sub handler :method {
my ($self, $r) = @_;
$r->content_type('text/plain');
print $self->crash($r);
return Apache2::Const::OK;
}
sub crash {
my $cgi = CGI->new;
try { $cgi->param(x => 'x') }
return "Hello World!";
}
1;
------------------
configured in httpd.conf as:
PerlModule Apache::TryCatch
PerlSwitches -I@ServerRoot/../lib
<Location /crashme>
SetHandler perl-script
PerlResponseHandler Apache::TryCatch
</Location>
------------------
Simply accessing /crashme causes a 500 internal server error and the
panic warning in the httpd error log.
I bisected against perl git, using mod_perl 2.0.9 and apache 2.2.29 as
the mod_perl environment, and installing TryCatch from cpan, and
discovered that the following perl commit is the culprit:
> commit 437e3a7dac994ebace1195549170c81f474d9c20
> Author: Matthew Horsfall <WolfSage@gmail.com>
> Date: Wed Dec 11 18:28:21 2013 -0500
>
> Optimise out PUSHMARK/RETURN if return is the last statement in a sub.
>
> This makes:
>
> sub baz { return $cat; }
>
> Behave like:
>
> sub baz { $cat; }
>
> Which is notably faster.
>
> Unpatched:
>
> ./perl -Ilib/ ~/stuff/bench.pl
> Benchmark: timing 40000000 iterations of normal, ret...
> normal: 3 wallclock secs ( 1.60 usr + 0.01 sys = 1.61 CPU) @ 24844720.50/s (n=40000000)
> ret: 3 wallclock secs ( 2.08 usr + 0.00 sys = 2.08 CPU) @ 19230769.23/s (n=40000000)
>
> Patched:
>
> ./perl -Ilib ~/stuff/bench.pl
> Benchmark: timing 40000000 iterations of aret, normal...
> normal: 2 wallclock secs ( 1.72 usr + 0.00 sys = 1.72 CPU) @ 23255813.95/s (n=40000000)
> ret: 2 wallclock secs ( 1.72 usr + 0.00 sys = 1.72 CPU) @ 23255813.95/s (n=40000000)
>
> The difference in OP trees can be seen here:
>
> Unpatched:
>
> $ perl -MO=Concise,baz -e 'sub baz { return $cat }'
> main::baz:
> 5 <1> leavesub[1 ref] K/REFC,1 ->(end)
> - <@> lineseq KP ->5
> 1 <;> nextstate(main 1 -e:1) v ->2
> 4 <@> return K ->5
> 2 <0> pushmark s ->3
> - <1> ex-rv2sv sK/1 ->4
> 3 <#> gvsv[*cat] s ->4
> -e syntax OK
>
> Patched:
>
> $ ./perl -Ilib -MO=Concise,baz -e 'sub baz { return $cat }'
> main::baz:
> 3 <1> leavesub[1 ref] K/REFC,1 ->(end)
> - <@> lineseq KP ->3
> 1 <;> nextstate(main 1 -e:1) v ->2
> - <@> return K ->-
> - <0> pushmark s ->2
> - <1> ex-rv2sv sK/1 ->-
> 2 <$> gvsv(*cat) s ->3
> -e syntax OK
>
> (Includes some modifications from Steffen)
>
> ext/B/t/optree_samples.t | 18 +++++++++++++++++-
> op.c | 31 +++++++++++++++++++++++++++++++
> op.h | 6 ++++++
> 3 files changed, 54 insertions(+), 1 deletion(-)
Reverting the change to op.c completely fixes the problem. I cannot
reproduce the panic after this change, and I do not get any segmentation
faults either in a large codebase that I am also testing against.
This problem seems to be mod_perl specific as the try { $cgi->param() }
does not cause a panic when run outside of mod_perl.
In addition, not all try { } blocks cause the panic. It seems that
calling CGI.pm's param() method to set a value *does* cause it however.
If anyone has any ideas on what might be causing behaviour in mod_perl,
I'm all ears. I may try to dig into this, but I'm not familiar with
mod_perl internals so that may take quite some time. Admittedly,
TryCatch depends on Devel::Declare, which as I understand it makes
changes to the optree at runtime. I'm guessing there is some
interaction with the optree in mod_perl that TryCatch along with perl's
optimization that removes the "return" ops that is causing this.
I have put the test case as a module up on github so that anyone can
clone it to reproduce the bug. The repository is here:
https://github.com/mschout/modperl-trycatch-bug.git
The readme explains how to run it, but essentially its install a perl >=
5.19.7, install mod_perl, install TryCatch, and then the usual
"perl Makefile.PL && make test"
Regards,
Michael Schout
as the following ever since 5.19.7:
panic: attempt to copy freed scalar 7fb2264ffde0 to 7fb2264ffd08 at
/Users/mschout/Sync/Apache-TryCatch/blib/lib/Apache/TryCatch.pm line 20.
I've also seen random segementation faults caused by innocent looking
"return" statements in a large code base.
I've created a test mod perl handler that demonstrates this behaviour:
------------------
package Apache::TryCatch;
use Apache2::Const -compile => qw(OK);
use TryCatch;
use CGI;
sub handler :method {
my ($self, $r) = @_;
$r->content_type('text/plain');
print $self->crash($r);
return Apache2::Const::OK;
}
sub crash {
my $cgi = CGI->new;
try { $cgi->param(x => 'x') }
return "Hello World!";
}
1;
------------------
configured in httpd.conf as:
PerlModule Apache::TryCatch
PerlSwitches -I@ServerRoot/../lib
<Location /crashme>
SetHandler perl-script
PerlResponseHandler Apache::TryCatch
</Location>
------------------
Simply accessing /crashme causes a 500 internal server error and the
panic warning in the httpd error log.
I bisected against perl git, using mod_perl 2.0.9 and apache 2.2.29 as
the mod_perl environment, and installing TryCatch from cpan, and
discovered that the following perl commit is the culprit:
> commit 437e3a7dac994ebace1195549170c81f474d9c20
> Author: Matthew Horsfall <WolfSage@gmail.com>
> Date: Wed Dec 11 18:28:21 2013 -0500
>
> Optimise out PUSHMARK/RETURN if return is the last statement in a sub.
>
> This makes:
>
> sub baz { return $cat; }
>
> Behave like:
>
> sub baz { $cat; }
>
> Which is notably faster.
>
> Unpatched:
>
> ./perl -Ilib/ ~/stuff/bench.pl
> Benchmark: timing 40000000 iterations of normal, ret...
> normal: 3 wallclock secs ( 1.60 usr + 0.01 sys = 1.61 CPU) @ 24844720.50/s (n=40000000)
> ret: 3 wallclock secs ( 2.08 usr + 0.00 sys = 2.08 CPU) @ 19230769.23/s (n=40000000)
>
> Patched:
>
> ./perl -Ilib ~/stuff/bench.pl
> Benchmark: timing 40000000 iterations of aret, normal...
> normal: 2 wallclock secs ( 1.72 usr + 0.00 sys = 1.72 CPU) @ 23255813.95/s (n=40000000)
> ret: 2 wallclock secs ( 1.72 usr + 0.00 sys = 1.72 CPU) @ 23255813.95/s (n=40000000)
>
> The difference in OP trees can be seen here:
>
> Unpatched:
>
> $ perl -MO=Concise,baz -e 'sub baz { return $cat }'
> main::baz:
> 5 <1> leavesub[1 ref] K/REFC,1 ->(end)
> - <@> lineseq KP ->5
> 1 <;> nextstate(main 1 -e:1) v ->2
> 4 <@> return K ->5
> 2 <0> pushmark s ->3
> - <1> ex-rv2sv sK/1 ->4
> 3 <#> gvsv[*cat] s ->4
> -e syntax OK
>
> Patched:
>
> $ ./perl -Ilib -MO=Concise,baz -e 'sub baz { return $cat }'
> main::baz:
> 3 <1> leavesub[1 ref] K/REFC,1 ->(end)
> - <@> lineseq KP ->3
> 1 <;> nextstate(main 1 -e:1) v ->2
> - <@> return K ->-
> - <0> pushmark s ->2
> - <1> ex-rv2sv sK/1 ->-
> 2 <$> gvsv(*cat) s ->3
> -e syntax OK
>
> (Includes some modifications from Steffen)
>
> ext/B/t/optree_samples.t | 18 +++++++++++++++++-
> op.c | 31 +++++++++++++++++++++++++++++++
> op.h | 6 ++++++
> 3 files changed, 54 insertions(+), 1 deletion(-)
Reverting the change to op.c completely fixes the problem. I cannot
reproduce the panic after this change, and I do not get any segmentation
faults either in a large codebase that I am also testing against.
This problem seems to be mod_perl specific as the try { $cgi->param() }
does not cause a panic when run outside of mod_perl.
In addition, not all try { } blocks cause the panic. It seems that
calling CGI.pm's param() method to set a value *does* cause it however.
If anyone has any ideas on what might be causing behaviour in mod_perl,
I'm all ears. I may try to dig into this, but I'm not familiar with
mod_perl internals so that may take quite some time. Admittedly,
TryCatch depends on Devel::Declare, which as I understand it makes
changes to the optree at runtime. I'm guessing there is some
interaction with the optree in mod_perl that TryCatch along with perl's
optimization that removes the "return" ops that is causing this.
I have put the test case as a module up on github so that anyone can
clone it to reproduce the bug. The repository is here:
https://github.com/mschout/modperl-trycatch-bug.git
The readme explains how to run it, but essentially its install a perl >=
5.19.7, install mod_perl, install TryCatch, and then the usual
"perl Makefile.PL && make test"
Regards,
Michael Schout
