It looks like the way Dancer is executing hooks is dangerous, please see this thread on perlmonks.org: http://perlmonks.org/?node_id=909229 On Fri, Jun 10, 2011 at 8:00 AM, Brian E. Lozier <brian@massassi.com> wrote:
On Fri, Jun 10, 2011 at 7:49 AM, Brian E. Lozier <brian@massassi.com> wrote:
On Fri, Jun 10, 2011 at 2:29 AM, David Precious <davidp@preshweb.co.uk> wrote:
On Friday 10 June 2011 00:30:57 Brian E. Lozier wrote:
Well I tracked down one bug that turns out may be a documentation bug. I haven't had time to look really really carefully but I was able to reproduce a crash when just starting app.pl if the "hook" syntax is wrong. The docs say you can do this:
hook before_template sub { # do something };
But you really need to do it like this: 8d50158 hook before_template => sub { # do something };
A bunch of the hook documentation is broken, [...]
You're absolutely right, thanks! Documentation fixed in 8d50158 which will be in the next release.
hook before_template sub {...} is of course wrong, as there's no comma (fat or otherwise) between two params to hook() (and without the fat comma, 'before_template' doesn't get auto-quoted, so it's an unknown bareword, too).
I'm still trying to find out the root cause of my original issue (which is why I tried using the "hook" syntax instead of declaring the before_template directly).
Hopefully I'll get a chance to dig further after $work; so far, I've not been able to reproduce the issue you're having. I think the machine I tested on is still on 1.3050, though, so it may be something that changed in 1.3051. I'll try 1.3051 and/or devel and see what happens.
I haven't been able to get this to reproduce outside the app I'm working on. However, I think I traced down the problem. In Dancer/Factory/Hook.pm there's a line that looks like this:
$_->(@args) foreach @{$self->get_hooks_for($hook_name)};
I did this before and after that line:
warn Dumper($self->get_hooks_for($hook_name));
And I noticed that the arrayref of hooks before it was executed the first time looked like this:
$VAR1 = [ sub { "DUMMY" } ];
But after it ran the first time it returned this:
$VAR1 = [ undef ];
So somehow the subroutine ref held for my before_template_render hook would be turned to undef with no warnings or anything on the console. I haven't been able to figure out why this is but I found if I changed the line to be a foreach with a localized var instead of using $_ the crash completely went away:
foreach my $hook (@{ $self->get_hooks_for($hook_name) }) { $hook->(@args); }
It seems like a scoping issue with $_ or @_ or something. I only have an hour or so a day to work on this project so I don't have time to dig much deeper today but maybe this will help you reproduce it somehow. I tried explicitly calling "die" inside a hook to try to reproduce this and I noticed that nothing dies, no errors get printed to the logs, no errors are shown in the browser either. This is really, really dangerous that something can completely swallow death and pretend nothing happened. I suspect this behavior is contributing to making this specific bug difficult to reproduce.
I tried to find somewhere in Dancer where die was being trapped but came up with nothing so far.
In Dancer/Hook.pm:
eval { $code->(@_) };
if ($@) { my $err = Dancer::Error->new( code => 500, title => $hook_name . ' filter error', message => "An error occured while executing the filter named $hook_name: $@" ); return Dancer::halt( $err->render ); } };
Returning Dancer::halt from here doesn't result in the app actually returning an error or exiting. I reproduced this on a simple test app by creating a before_template_render hook and just dying inside of it. The page renders normally but in the logs I see this:
[761] core @0.013301> [hit #3]response: 500 in /usr/local/lib/perl5/site_perl/5.12.2/Dancer/Handler.pm l. 159 127.0.0.1 - - [10/Jun/2011 07:58:41] "GET / HTTP/1.0" 500 4885 "-" "Mozilla/5.0 (Macintosh; U; Intel Mac OS X 10.6; en-US; rv:1.9.2.17) Gecko/20110420 Firefox/3.6.17"
I don't know how I can get a 500 (server error) in the logs but the page renders normally. This part at least should be easy to repro. Still can't figure out how the code ref can become undef after a single view but my previous message fixed that. I'm not totally comfortable because I don't understand WHY it fixed it.
Cheers
Dave P
-- David Precious ("bigpresh") http://www.preshweb.co.uk/
"Programming is like sex. One mistake and you have to support it for the rest of your life". (Michael Sinz)