Bug #47929 for Template-Toolkit: XS stash crashes with string eval in stash.

Wed Jul 15 21:13:50 2009 TJC [...] cpan.org - Ticket created

Subject:

XS stash crashes with DateTime::TimeZone::Local

The attached file calls DateTime::TimeZone::Local->TimeZone() from inside a callback function in a template stash. This has the surprising result of neatly exiting Perl upon return from the callback function, rather than returning to the template processing. This was tested with Template Toolkit 2.20 and 2.21, and DateTime::TimeZone 0.91 on Perl 5.10.0 on Linux and MacOSX. (I will also report this bug against DateTime::TimeZone as I'm unsure which module is at fault.)

Subject:

crash.pl

#!/usr/bin/perl use strict; use warnings; use DateTime::TimeZone::Local; use Template; use Template::Stash::XS; print "DateTime::TimeZone version: " . $DateTime::TimeZone::VERSION . "\n"; print "Template version: " . $Template::VERSION . "\n"; my $status = 'FAILED'; my $template = '[% crasher() %]'; my $output; # Note that only the XS stash fails.. my $tt2 = Template->new( STASH => Template::Stash::XS->new ); $tt2->process(\$template, { crasher => \&crasher }, \$output); print "Generated output: $output\n"; $status = 'SUCCESS'; sub crasher { DateTime::TimeZone::Local->TimeZone; warn "** In crasher(), about to return.."; return 'foo'; } sub END { print "Status: $status\n"; }

Wed Jul 15 21:18:21 2009 TJC [...] cpan.org - Reference to ticket #47930 added

Wed Jul 15 21:58:43 2009 TJC [...] cpan.org - Subject changed from 'XS stash crashes with DateTime::TimeZone::Local' to 'XS stash crashes with string eval in stash.'

Wed Jul 15 22:01:41 2009 TJC [...] cpan.org - Correspondence added

I have eliminated DateTime::TimeZone from the test, and narrowed down the cause of the problem to using a string eval inside the template stash callback. See attached file for details.

#!/usr/bin/perl use strict; use warnings; use Template; use Template::Stash::XS; print "Template version: " . $Template::VERSION . "\n"; my $status = 'FAILED'; my $template = '[% crasher() %]'; my $output; # Note that only the XS stash fails.. my $tt2 = Template->new( STASH => Template::Stash::XS->new ); $tt2->process(\$template, { crasher => \&load_subclass }, \$output) or warn "Failed to process..\n"; $status = 'SUCCESS'; sub END { print "Status: $status\n"; } sub load_subclass { eval "use Nonexistent::Class"; if ($@) { warn "Caught expected failure to use Nonexistent::Class"; } }

Wed Jul 15 22:01:44 2009 TJC [...] cpan.org - Status changed from 'new' to 'open'

Tue Jul 21 09:10:09 2009 cpan [...] wardley.org - Correspondence added 240 min

RT-Send-CC:

robin [...] smidsrod.no

I've closed bug #48020 as it looks like it's a manifestation of the same bug. https://rt.cpan.org/Ticket/Display.html?id=48020 Based on the code that Robin produced to demonstrate bug #48020, I've created a stripped down version of the XS Stash to try and narrow down the problem. http://github.com/abw/TT-XS-Stash-DateTime/tree/master I've added your string eval test and can confirm that it fails on my machine. Interestingly, the string eval test fails on my Macbook, but the DateTime tests pass. On a Fedora 64 bit machine all the tests fail. So although I'm no closer to finding and fixing the problem, it is at least reproducible and there's a minimal version of the XS Stash in the above git repo which demonstrates the problem.

Tue Jul 21 10:06:00 2009 robin [...] smidsrod.no - Correspondence added

Subject:	Re: [rt.cpan.org #47929] XS stash crashes with string eval in stash.
Date:	Tue, 21 Jul 2009 16:04:41 +0200
To:	bug-Template-Toolkit [...] rt.cpan.org
From:	Robin Smidsrød <robin [...] smidsrod.no>

-----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1 Andy Wardley via RT wrote: Show quoted text

> I've added your string eval test and can confirm that it fails on my > machine. Interestingly, the string eval test fails on my Macbook, but > the DateTime tests pass. On a Fedora 64 bit machine all the tests fail.

Running on Strawberry perl 5.10.0.5 on a Vista x64 machine: As you can see the datetime seems to work, but the string eval seems to fail: (TT 2.22 and DateTime 0.50 from CPAN was used) C:\Users\robin\perl\TT-XS-Stash-DateTime>dmake test C:\strawberry\perl\bin\perl.exe "-MExtUtils::Command::MM" "-e" "test_harness(0, 'blib\lib', 'blib\arch')" t/datetime.t t/string_eval.t t/datetime.t ..... - dotop(date_time) - - fetch item: date_time - - fetching hash item - - got value, triggering any tied magic - - TT_RET_OK - - dotop(date_time_sub) - - fetch item: date_time_sub - - fetching hash item - - got value, triggering any tied magic - - calling coderef t/datetime.t ..... 1/2 in call_coderef() - - about to push args - - pushed args - - calling call_sv() # Creating DateTime object # Created DateTime object, returning - - called call_sv() - - called coderef, returning result - - TT_RET_CODEREF t/datetime.t ..... ok t/string_eval.t .. - dotop(eval_fail) - - fetch item: eval_fail - - fetching hash item - - got value, triggering any tied magic - - calling coderef - - in call_coderef() - - about to push args - - pushed args - - calling call_sv() # About to use NonExistantClass # Caught expected failure to use Nonexistent::Class at t/string_eval.t line 24. # No tests run! t/string_eval.t .. Dubious, test returned 255 (wstat 65280, 0xff00) Failed 1/1 subtests Test Summary Report - ------------------- t/string_eval.t (Wstat: 65280 Tests: 0 Failed: 0) Non-zero exit status: 255 Parse errors: Bad plan. You planned 1 tests but ran 0. Files=2, Tests=2, 1 wallclock secs ( 0.05 usr + 0.00 sys = 0.05 CPU) Result: FAIL Failed 1/2 test programs. 0/2 subtests failed. dmake: Error code 255, while making 'test_dynamic' C:\Users\robin\perl\TT-XS-Stash-DateTime> C:\Users\robin\perl\TT-XS-Stash-DateTime>perl t/string_eval.t 1..1 - - dotop(eval_fail) - - fetch item: eval_fail - - fetching hash item - - got value, triggering any tied magic - - calling coderef - - in call_coderef() - - about to push args - - pushed args - - calling call_sv() # About to use NonExistantClass # Caught expected failure to use Nonexistent::Class at t/string_eval.t line 24. # No tests run! C:\Users\robin\perl\TT-XS-Stash-DateTime> Maybe this can help you to get one step closer to the problem. - -- Robin -----BEGIN PGP SIGNATURE----- Version: GnuPG v1.4.9 (MingW32) Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org/ iEYEARECAAYFAkplyvgACgkQHAwEVD/in27biACfar+XRWh6LPu0sC7o0iGGkWhd bhYAn1aY9zttW9yKu29My4I8FSLOnozm =dbD1 -----END PGP SIGNATURE-----

Tue Jul 21 10:08:35 2009 robin [...] smidsrod.no - Correspondence added

Subject:	Re: [rt.cpan.org #47929] XS stash crashes with string eval in stash.
Date:	Tue, 21 Jul 2009 16:07:17 +0200
To:	bug-Template-Toolkit [...] rt.cpan.org
From:	Robin Smidsrød <robin [...] smidsrod.no>

-----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1 Andy Wardley via RT wrote: Show quoted text

> I've added your string eval test and can confirm that it fails on my > machine. Interestingly, the string eval test fails on my Macbook, but > the DateTime tests pass. On a Fedora 64 bit machine all the tests fail.

Forgot to mention that my tests where run from: commit f9c9ca2ba2c68fc8772e73aedd36a794e503c639 - -- Robin -----BEGIN PGP SIGNATURE----- Version: GnuPG v1.4.9 (MingW32) Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org/ iEYEARECAAYFAkply5UACgkQHAwEVD/in27lDQCfXUZFRZKewO5R1BSRydo0x6r0 MvkAnA1/XjO7ZYB2Hyuy3HVyX5TcCgek =NybL -----END PGP SIGNATURE-----

Tue Jul 21 20:59:09 2009 TJC [...] cpan.org - Correspondence added

Hi, I think I can at least explain why the datetime test passes on the mac. The older versions of datetime did not use the string eval method to load further modules. (I hit this bug after an upgrade of datetime occurred, and then narrowed it down to the eval which failed and caused the problem. I initially reported it against datetime because downgrading datetime fixed the high level crash)

Fri Aug 14 15:30:55 2009 ROBINS [...] cpan.org - Requestor ROBINS added

Mon Aug 17 22:13:38 2009 TJC [...] cpan.org - Correspondence added

I tried git bisecting* the source history of TT2 with the XS stash (from version 2.06 to 2.22) with the attached files, and it seems like every revision fails against the test! (ie. git bisect run ./runtest.sh)

Download runtest.sh
application/x-shellscript 155b

Message body not shown because it is not plain text.

#!/usr/bin/perl use strict; use warnings; use Test::More tests => 3; use_ok('Template'); use_ok('Template::Stash::XS'); diag("Template version: $Template::VERSION"); # Note that only the XS stash fails.. my $tt2 = Template->new( STASH => Template::Stash::XS->new ); $tt2->process( \'[% crasher() %]', { crasher => sub { eval "use Nonexistent::Class" } }, ) or warn "Failed to process..\n"; ok(1, 'Reached end of test without crashing');

Mon Aug 17 22:14:37 2009 TJC [...] cpan.org - Broken in 2.06 added

Mon Aug 17 22:14:37 2009 TJC [...] cpan.org - Broken in 2.07 added

Mon Aug 17 22:14:37 2009 TJC [...] cpan.org - Broken in 2.08 added

Mon Aug 17 22:14:37 2009 TJC [...] cpan.org - Broken in 2.09 added

Mon Aug 17 22:14:37 2009 TJC [...] cpan.org - Broken in 2.10 added

Mon Aug 17 22:14:38 2009 TJC [...] cpan.org - Broken in 2.11 added

Mon Aug 17 22:14:38 2009 TJC [...] cpan.org - Broken in 2.12 added

Mon Aug 17 22:14:38 2009 TJC [...] cpan.org - Broken in 2.13 added

Mon Aug 17 22:14:38 2009 TJC [...] cpan.org - Broken in 2.14 added

Mon Aug 17 22:14:38 2009 TJC [...] cpan.org - Broken in 2.15 added

Mon Aug 17 22:14:38 2009 TJC [...] cpan.org - Broken in 2.16 added

Mon Aug 17 22:14:38 2009 TJC [...] cpan.org - Broken in 2.17 added

Mon Aug 17 22:14:38 2009 TJC [...] cpan.org - Broken in 2.18 added

Mon Aug 17 22:14:38 2009 TJC [...] cpan.org - Broken in 2.19 added

Mon Aug 17 22:14:38 2009 TJC [...] cpan.org - Broken in 2.20 added

Mon Aug 17 22:14:38 2009 TJC [...] cpan.org - Broken in 2.22 added

Fri Feb 12 02:17:16 2010 mkanat [...] cpan.org - Correspondence added

Any hope of a resolution on this? I just hit this while working on some code for Bugzilla, and I spent about five or six hours tracing this down.

Fri Feb 12 02:25:12 2010 TJC [...] cpan.org - Correspondence added

On Fri Feb 12 02:17:16 2010, MKANAT wrote: Show quoted text

> Any hope of a resolution on this? I just hit this while working on some > code for Bugzilla, and I spent about five or six hours tracing this

down. I ported my code to Template::Alloy; wasn't too painful, and decent performance. (But avoid Template::Alloy::XS, it's totally broken.)

Fri Feb 12 11:22:41 2010 ROBINS [...] cpan.org - Correspondence added

On Fri Feb 12 08:25:12 2010, TJC wrote: Show quoted text

> On Fri Feb 12 02:17:16 2010, MKANAT wrote:

> > Any hope of a resolution on this? I just hit this while working on some > > code for Bugzilla, and I spent about five or six hours tracing this

> down. > > I ported my code to Template::Alloy; wasn't too painful, and decent > performance. (But avoid Template::Alloy::XS, it's totally broken.)

There is a simple workaround available. Disable the XS stash and take the performance penalty.

Tue Mar 30 21:16:35 2010 mkanat [...] cpan.org - Correspondence added

Okay, so, again--any hope of an actual fix for this issue? Telling 10,000+ Bugzilla installations that they just have to suck up being slow to work around a critical but not-all-affecting bug would be pretty lame. I keep getting reports that this bug causes varying parts of Bugzilla to break for various people.

Fri Apr 16 01:21:12 2010 TJC [...] cpan.org - Correspondence added

On Fri Feb 12 11:22:41 2010, ROBINS wrote: Show quoted text

> On Fri Feb 12 08:25:12 2010, TJC wrote:

> > I ported my code to Template::Alloy; wasn't too painful, and decent > > performance. (But avoid Template::Alloy::XS, it's totally broken.)

> > There is a simple workaround available. Disable the XS stash and take > the performance penalty.

Template::Alloy was quicker than Template::Toolkit with non-XS stash though. (At least in the real-world benchmarks I was doing with our code.) I'd also suggest that the build-time question of "Do you want to use the XS stash by default?" should be forced to "No", until such time as this bug is fixed. People who actually need the performance of XS can then evaluate the risks, and then test and enable it on a selective basis. To leave a known-bad thing enabled by default simply because it is faster sounds like premature optimisation to me. Cheers, Toby

Tue Oct 05 10:08:29 2010 perl-cpan [...] bereft.net - Correspondence added

On Tue Jul 21 09:10:09 2009, ABW wrote: Show quoted text

> http://github.com/abw/TT-XS-Stash-DateTime/tree/master

I've looked into this some more and: eval "BEGIN { die 'compile time die' }" seems to reproduce the issue also: http://github.com/bowman/TT-XS-Stash-DateTime (I should mention that from here on I'm just stumbling around and don't have much of a clue) Using call_pv (a call_sv wrapper) from a little C program in the same way as the XS Stash results in a crash, although it does have a message "panic: top_env" error. "panic" is bad. (see call.c & call.pl attached) Adding the G_EVAL flag (describe in perlcall) to the call_{pv,sv} calls seems to trap these errors and prevent the code bombing out. I tried adding G_EVAL to TT2 version 2.22 but it did cause some test failures related to exception handling. This seems to be more of a work-around than a fix, as the error should already have been contained by the string eval, right? I'm not certain my test really does reflect what is happening in TT2, does it look right? Where does it look like the bug is? I'm starting to think Perl, but it could easily be something else. What versions of Perl are effected? 5.10.1 for me, but I'll try others. Is this really is a 64bit issue only? There's been some very recent commits that look like they may be relevant: http://www.nntp.perl.org/group/perl.perl5.changes/2010/10/msg27575.html http://github.com/greerga/perl/commit/4aca2f62efca883199d7975f34b7fb876c280366 I'm going to keep looking at this on and off, but wanted to post what I have so far, Brad

Subject:

call.pl

# see call.c use strict; use warnings; sub test_use_fail { warn __FILE__, ": ", __LINE__, "\n"; eval "use NonExistent;"; warn " \$@ is <$@>\n"; } sub test_eval_begin_die { warn __FILE__, ": ", __LINE__, "\n"; eval "BEGIN { die 'compile time die' }"; warn " \$@ is <$@>\n"; } sub test_eval_syntax { warn __FILE__, ": ", __LINE__, "\n"; eval "/syntax"; warn " \$@ is <$@>\n"; } # the following are all ok sub test_eval_begin_eval_die { warn __FILE__, ": ", __LINE__, "\n"; eval "BEGIN { eval { die 'compile time die' } }"; warn " \$@ is <$@>\n"; } sub test_eval_end_die { warn __FILE__, ": ", __LINE__, "\n"; eval "END { die 'end time die' }"; warn " \$@ is <$@>\n"; } sub test_eval_die { warn __FILE__, ": ", __LINE__, "\n"; eval "die 'run time die'"; warn " \$@ is <$@>\n"; }

Subject:

call.c

/* cc `perl -MExtUtils::Embed -e ccopts -e ldopts` -g call.c -o call && ./call for s in `perl -nle 'print $1 if /sub (\w+)/' call.pl`; \ do if ./call $s 2> /dev/null; then echo "$s PASS"; else echo "$s FAIL"; fi;\ done test_use_fail FAIL test_eval_begin_die FAIL test_eval_syntax FAIL test_eval_begin_eval_die PASS test_eval_end_die PASS test_eval_die PASS */ #include <stdio.h> #include <EXTERN.h> #include <perl.h> static PerlInterpreter *my_perl; main (int argc, char **argv, char **env) { char *embedding[] = { "", "call.pl" }; char *default_sub = "test_eval_begin_die"; char *call_sub = (argc > 1) ? argv[1] : default_sub; fprintf(stderr, "Hello (successful end is Goodbye)\n"); PERL_SYS_INIT3(&argc,&argv,&env); my_perl = perl_alloc(); perl_construct( my_perl ); perl_parse(my_perl, NULL, 3, embedding, NULL); PL_exit_flags |= PERL_EXIT_DESTRUCT_END; perl_run(my_perl); fprintf(stderr, "calling %s with G_EVAL | G_KEEPERR\n", call_sub); call_pv(call_sub, G_DISCARD | G_NOARGS | G_EVAL | G_KEEPERR); fprintf(stderr, " $@ = %s\n\n", SvPV_nolen(ERRSV)); fprintf(stderr, "calling %s with no G*\n", call_sub); call_pv(call_sub, G_DISCARD | G_NOARGS); fprintf(stderr, " $@ = %s\n\n", SvPV_nolen(ERRSV)); perl_destruct(my_perl); perl_free(my_perl); PERL_SYS_TERM(); fprintf(stderr, "Goodbye\n"); exit(0); }

Tue Oct 05 10:25:58 2010 perl-cpan [...] bereft.net - Correspondence added

On Tue Oct 05 10:08:29 2010, BOWMANBS wrote: Show quoted text

> There's been some very recent commits that look like they may be > relevant: > > http://www.nntp.perl.org/group/perl.perl5.changes/2010/10/msg27575.html >

http://github.com/greerga/perl/commit/4aca2f62efca883199d7975f34b7fb876c280366 Looks like my call.* tests work in blead perl, although I haven't tried the TT2 test yet (I need to work out how to). $ for s in `perl -nle 'print $1 if /sub (\w+)/' call.pl`; do if ./call $s 2> /dev/null; then echo "$s PASS"; else echo "$s FAIL"; fi; done test_use_fail PASS test_eval_begin_die PASS test_eval_syntax PASS test_eval_begin_eval_die PASS test_eval_end_die PASS test_eval_die PASS Brad

Tue Oct 05 19:11:33 2010 perl-cpan [...] bereft.net - Requestor BOWMANBS added

Tue Oct 05 20:57:03 2010 TJC [...] cpan.org - Correspondence added

On Tue Oct 05 10:08:29 2010, BOWMANBS wrote: Show quoted text

> What versions of Perl are effected? 5.10.1 for me, but I'll try > others. > Is this really is a 64bit issue only?

I have reproduced my original bug on several combinations of perl and 32/64bit architectures: Perl 5.8.8 i386 Perl 5.10.1 i386 Perl 5.10.1 AMD64 Perl 5.12.1 AMD64 -Toby

Wed Mar 02 00:34:55 2011 TJC [...] cpan.org - Correspondence added

I note that the bug is still present in Perl 5.12.2. Will test in 5.12.3 shortly..

Wed Mar 02 00:43:40 2011 TJC [...] cpan.org - Correspondence added

Tested on Perl 5.12.3, test still crashes out.

Fri Jan 13 11:27:51 2012 cpan [...] wardley.org - Correspondence added

I believe this is now fixed. https://github.com/abw/Template2/commit/cb1d793924ac105c188c2a573b7233621a6c5e24 Tested on Perl 5.10.0 and Perl 5.12.3. All test pass, including a new test in t/stash-xs.t which tickles the bug. The test fails without the patch and passes with it.

Fri Jan 13 11:27:52 2012 cpan [...] wardley.org - Status changed from 'open' to 'resolved'