I would like to ask the list for help with this mysterious error.
I consider myself pretty good at identifying and fixing bugs. But
this particular thing is hard. At it cocerns the error handling in
TT2.
I could go on with lots and lots of details. System set up, modules
and version numbers. mod_perl's /perl-status reports close to 150
loaded modules. Many of them uses Carp and confess. I now have *no*
confess in my own code.
The error has occured a couple of times per day. I can't remember
what I did at the time the errors started. Basicly the same system
has worked fine for maby a year.
I send information about the process ID and what is done to the error
log in such a way that I should see if all processes that produced
errors at some earlier point executed some specific code. No pattern
found there.
Some basic version info: I'm using perl, v5.6.1 built for i386-linux
with Template v2.07. And Apache mod_perl 1.26-2
with Apache 1.3.23-1. (Also currently using Apache::Reload 0.07.)
Most of the modules are loaded in the parent apache process. I
inserted two extra warn() in Template modules (without inserting any
newlines) to get som debug info. The errors was the same before those warn().
I wonder there the stack backtrace comes from and I wondering a bit
about if the Template::Exception as_string overload creates some
trouble. I haven't found a probable confess suspect in any of the
loaded modules. And nothing anywhere should be able to turn a
[% RETURN %] to a confession. That's not sane!!!
Here are my changes to TT:
A. In Template/Context.pm, row 492: warn $error;
B. In Template/Exception.pm, row 69: sub type {warn "type is $_[0]->[ TYPE ]";
Here is the debug output from an error instance: (first atatchment):
Uncaught exception from user code:
return error - at /usr/local/lib/perl/5.6.1/Template/Context.pm line 460
Template::Context::throw('Template::Context=HASH(0x85fd22c)', 'return', '',
'SCALAR(0x9ba05e0)') called at
/tmp/ttc/psidb1//var/www/paranormal.se/member/db/topic/view/index.ttc line 42
eval {...} called at
/tmp/ttc/psidb1//var/www/paranormal.se/member/db/topic/view/index.ttc line 19
Template::Provider::__ANON__('Template::Context=HASH(0x85fd22c)') called at
/usr/local/lib/perl/5.6.1/Template/Document.pm line 142
eval {...} called at /usr/local/lib/perl/5.6.1/Template/Document.pm line 140
Template::Document::process('Template::Document=HASH(0x9281154)',
'Template::Context=HASH(0x85fd22c)') called at
/usr/local/lib/perl/5.6.1/Template/Context.pm line 279
Template::Context::process('Template::Context=HASH(0x85fd22c)',
'Template::Document=HASH(0x9281154)') called at
/usr/local/lib/perl/5.6.1/Template/Service.pm line 90
eval {...} called at /usr/local/lib/perl/5.6.1/Template/Service.pm line 88
Template::Service::process('Template::Service=HASH(0x81efa90)',
'member/db/topic/view/index', 'HASH(0x9208868)') called at
/usr/local/lib/perl/5.6.1/Template.pm line 59
Template::process('Template=HASH(0x82e8fc0)', 'member/db/topic/view/index',
'HASH(0x9208868)', 'Apache=SCALAR(0x9a42694)') called at
/var/www/paranormal.se/cgi/Psi/Common.pm line 384
eval {...} called at /var/www/paranormal.se/cgi/Psi/Common.pm line 384
Psi::Common::handle_request('Apache=SCALAR(0x9a42694)') called at
/var/www/paranormal.se/cgi/Psi/Handler.pm line 18
Psi::Handler::handler('Apache=SCALAR(0x9a42694)') called at /dev/null line 0
eval {...} called at /dev/null line 0
type is undef at /usr/local/lib/perl/5.6.1/Template/Exception.pm line 69.
Uncaught exception from user code:
undef error - Uncaught exception from user code:
return error - at /usr/local/lib/perl/5.6.1/Template/Context.pm line 460
Template::Context::throw('Template::Context=HASH(0x85fd22c)', 'return', '',
'SCALAR(0x9ba05e0)') called at
/tmp/ttc/psidb1//var/www/paranormal.se/member/db/topic/view/index.ttc line 42
eval {...} called at
/tmp/ttc/psidb1//var/www/paranormal.se/member/db/topic/view/index.ttc line 19
Template::Provider::__ANON__('Template::Context=HASH(0x85fd22c)') called at
/usr/local/lib/perl/5.6.1/Template/Document.pm line 142
eval {...} called at /usr/local/lib/perl/5.6.1/Template/Document.pm line 140
Template::Document::process('Template::Document=HASH(0x9281154)',
'Template::Context=HASH(0x85fd22c)') called at
/usr/local/lib/perl/5.6.1/Template/Context.pm line 279
Template::Context::process('Template::Context=HASH(0x85fd22c)',
'Template::Document=HASH(0x9281154)') called at
/usr/local/lib/perl/5.6.1/Template/Service.pm line 90
eval {...} called at /usr/local/lib/perl/5.6.1/Template/Service.pm line 88
Template::Service::process('Template::Service=HASH(0x81efa90)',
'member/db/topic/view/index', 'HASH(0x9208868)') called at
/usr/local/lib/perl/5.6.1/Template.pm line 59
Template::process('Template=HASH(0x82e8fc0)', 'member/db/topic/view/index',
'HASH(0x9208868)', 'Apache=SCALAR(0x9a42694)') called at
/var/www/paranormal.se/cgi/Psi/Common.pm line 384
eval {...} called at /var/www/paranormal.se/cgi/Psi/Common.pm line 384
Psi::Common::handle_request('Apache=SCALAR(0x9a42694)') called at
/var/www/paranormal.se/cgi/Psi/Handler.pm line 18
Psi::Handler::handler('Apache=SCALAR(0x9a42694)') called at /dev/null line 0
eval {...} called at /dev/null line 0
Template::Provider::__ANON__('Template::Context=HASH(0x85fd22c)') called at
/usr/local/lib/perl/5.6.1/Template/Document.pm line 142
eval {...} called at /usr/local/lib/perl/5.6.1/Template/Document.pm line 140
Template::Document::process('Template::Document=HASH(0x9281154)',
'Template::Context=HASH(0x85fd22c)') called at
/usr/local/lib/perl/5.6.1/Template/Context.pm line 279
Template::Context::process('Template::Context=HASH(0x85fd22c)',
'Template::Document=HASH(0x9281154)') called at
/usr/local/lib/perl/5.6.1/Template/Service.pm line 90
eval {...} called at /usr/local/lib/perl/5.6.1/Template/Service.pm line 88
Template::Service::process('Template::Service=HASH(0x81efa90)',
'member/db/topic/view/index', 'HASH(0x9208868)') called at
/usr/local/lib/perl/5.6.1/Template.pm line 59
Template::process('Template=HASH(0x82e8fc0)', 'member/db/topic/view/index',
'HASH(0x9208868)', 'Apache=SCALAR(0x9a42694)') called at
/var/www/paranormal.se/cgi/Psi/Common.pm line 384
eval {...} called at /var/www/paranormal.se/cgi/Psi/Common.pm line 384
Psi::Common::handle_request('Apache=SCALAR(0x9a42694)') called at
/var/www/paranormal.se/cgi/Psi/Handler.pm line 18
Psi::Handler::handler('Apache=SCALAR(0x9a42694)') called at /dev/null line 0
eval {...} called at /dev/null line 0
FALLBACK!
This is as far as I can tell the result of output from (A), (B) and
then (A) again. The last word "FALLBACK!" is genereated after the
process call:
my $res = eval{ $Psi::th->process($Psi::handler, $params, $fh) };
if( $@ or not $res )
{
warn "FALLBACK!\n";
...
}
Notice that the second (A) consists of two stacktraces starting on
diffrent points but both ending at "eval {...} called at /dev/null
line 0".
Here is the content of $@ after the process:
Uncaught exception from user code:
undef error - Uncaught exception from user code:
undef error - Uncaught exception from user code:
return error - at /usr/local/lib/perl/5.6.1/Template/Context.pm line 460
Template::Context::throw('Template::Context=HASH(0x85fd22c)', 'return', '',
'SCALAR(0x9ba05e0)') called at
/tmp/ttc/psidb1//var/www/paranormal.se/member/db/topic/view/index.ttc line 42
eval {...} called at
/tmp/ttc/psidb1//var/www/paranormal.se/member/db/topic/view/index.ttc line 19
Template::Provider::__ANON__('Template::Context=HASH(0x85fd22c)') called at
/usr/local/lib/perl/5.6.1/Template/Document.pm line 142
eval {...} called at /usr/local/lib/perl/5.6.1/Template/Document.pm line 140
Template::Document::process('Template::Document=HASH(0x9281154)',
'Template::Context=HASH(0x85fd22c)') called at
/usr/local/lib/perl/5.6.1/Template/Context.pm line 279
Template::Context::process('Template::Context=HASH(0x85fd22c)',
'Template::Document=HASH(0x9281154)') called at
/usr/local/lib/perl/5.6.1/Template/Service.pm line 90
eval {...} called at /usr/local/lib/perl/5.6.1/Template/Service.pm line 88
Template::Service::process('Template::Service=HASH(0x81efa90)',
'member/db/topic/view/index', 'HASH(0x9208868)') called at
/usr/local/lib/perl/5.6.1/Template.pm line 59
Template::process('Template=HASH(0x82e8fc0)', 'member/db/topic/view/index',
'HASH(0x9208868)', 'Apache=SCALAR(0x9a42694)') called at
/var/www/paranormal.se/cgi/Psi/Common.pm line 384
eval {...} called at /var/www/paranormal.se/cgi/Psi/Common.pm line 384
Psi::Common::handle_request('Apache=SCALAR(0x9a42694)') called at
/var/www/paranormal.se/cgi/Psi/Handler.pm line 18
Psi::Handler::handler('Apache=SCALAR(0x9a42694)') called at /dev/null line 0
eval {...} called at /dev/null line 0
Template::Provider::__ANON__('Template::Context=HASH(0x85fd22c)') called at
/usr/local/lib/perl/5.6.1/Template/Document.pm line 142
eval {...} called at /usr/local/lib/perl/5.6.1/Template/Document.pm line 140
Template::Document::process('Template::Document=HASH(0x9281154)',
'Template::Context=HASH(0x85fd22c)') called at
/usr/local/lib/perl/5.6.1/Template/Context.pm line 279
Template::Context::process('Template::Context=HASH(0x85fd22c)',
'Template::Document=HASH(0x9281154)') called at
/usr/local/lib/perl/5.6.1/Template/Service.pm line 90
eval {...} called at /usr/local/lib/perl/5.6.1/Template/Service.pm line 88
Template::Service::process('Template::Service=HASH(0x81efa90)',
'member/db/topic/view/index', 'HASH(0x9208868)') called at
/usr/local/lib/perl/5.6.1/Template.pm line 59
Template::process('Template=HASH(0x82e8fc0)', 'member/db/topic/view/index',
'HASH(0x9208868)', 'Apache=SCALAR(0x9a42694)') called at
/var/www/paranormal.se/cgi/Psi/Common.pm line 384
eval {...} called at /var/www/paranormal.se/cgi/Psi/Common.pm line 384
Psi::Common::handle_request('Apache=SCALAR(0x9a42694)') called at
/var/www/paranormal.se/cgi/Psi/Handler.pm line 18
Psi::Handler::handler('Apache=SCALAR(0x9a42694)') called at /dev/null line 0
eval {...} called at /dev/null line 0
Template::Document::process('Template::Document=HASH(0x9281154)',
'Template::Context=HASH(0x85fd22c)') called at
/usr/local/lib/perl/5.6.1/Template/Context.pm line 279
Template::Context::process('Template::Context=HASH(0x85fd22c)',
'Template::Document=HASH(0x9281154)') called at
/usr/local/lib/perl/5.6.1/Template/Service.pm line 90
eval {...} called at /usr/local/lib/perl/5.6.1/Template/Service.pm line 88
Template::Service::process('Template::Service=HASH(0x81efa90)',
'member/db/topic/view/index', 'HASH(0x9208868)') called at
/usr/local/lib/perl/5.6.1/Template.pm line 59
Template::process('Template=HASH(0x82e8fc0)', 'member/db/topic/view/index',
'HASH(0x9208868)', 'Apache=SCALAR(0x9a42694)') called at
/var/www/paranormal.se/cgi/Psi/Common.pm line 384
eval {...} called at /var/www/paranormal.se/cgi/Psi/Common.pm line 384
Psi::Common::handle_request('Apache=SCALAR(0x9a42694)') called at
/var/www/paranormal.se/cgi/Psi/Handler.pm line 18
Psi::Handler::handler('Apache=SCALAR(0x9a42694)') called at /dev/null line 0
eval {...} called at /dev/null line 0
Notice that $@ has three(!) copies of the stacktrace. The content of
$@ is currently presented in the browser to the unfortunate visitor.
The involved template files are large. (Guilty. I'm in the process of
moving things to object methods.) Here is the part of the template
that say RETURN:
IF talias.search('^\d+$');
CALL q.param('t', talias);
ELSE;
PROCESS new_topic;
RETURN;
END;
Here is the corresponding compiled part:
Row 19: eval { BLOCK: {
Row 42: $context->throw('return', '', \$output);
And the last part catching the return:
if ($@) {
$error = $context->catch($@, \$output);
die $error unless $error->type eq 'return';
}
I have spent a couple of weeks looking at this now. Something is
generating a stack backtrace.
Similar errors are produced by other templates throwing exceptions or
using RETURN.
I'm using the XS stash.
Any idea of what I could do to fix this?
--
/ Jonas - http://jonas.liljegren.org/myself/en/index.html
