Re: [Dancer-users] Runtime error having to do with hooks (which I don't use)
[CC'd list back in] On Thursday 09 June 2011 20:02:27 Brian E. Lozier wrote:
I'm using Dancer-1.3051. Did you try it under plackup?
Yeah, I tried it both by running bin/app.pl directly, and starting it by running plackup bin/app.pl - both worked.
I will try to repro it with a scaffolded app. In my app I have one before filter, one before_template filter, one after template filter.
Ah, OK - I'll add a before handler and an after_template to my test case and see if that changes anything.
It's odd that the first request works and every subsequent ones don't work.
Indeed. I suspect it's something like a side-effect of what one of the handlers returned being inadvertently set, or something. -- 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)
On Thu, Jun 9, 2011 at 12:11 PM, David Precious <davidp@preshweb.co.uk> wrote:
[CC'd list back in] On Thursday 09 June 2011 20:02:27 Brian E. Lozier wrote:
I'm using Dancer-1.3051. Did you try it under plackup?
Yeah, I tried it both by running bin/app.pl directly, and starting it by running plackup bin/app.pl - both worked.
I will try to repro it with a scaffolded app. In my app I have one before filter, one before_template filter, one after template filter.
My mistake, I have one before filter, one before_template filter and one after filter (not after template).
Ah, OK - I'll add a before handler and an after_template to my test case and see if that changes anything.
It's odd that the first request works and every subsequent ones don't work.
Indeed. I suspect it's something like a side-effect of what one of the handlers returned being inadvertently set, or something.
-- 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)
On Thu, Jun 9, 2011 at 12:12 PM, Brian E. Lozier <brian@massassi.com> wrote:
On Thu, Jun 9, 2011 at 12:11 PM, David Precious <davidp@preshweb.co.uk> wrote:
[CC'd list back in] On Thursday 09 June 2011 20:02:27 Brian E. Lozier wrote:
I'm using Dancer-1.3051. Did you try it under plackup?
Yeah, I tried it both by running bin/app.pl directly, and starting it by running plackup bin/app.pl - both worked.
I will try to repro it with a scaffolded app. In my app I have one before filter, one before_template filter, one after template filter.
My mistake, I have one before filter, one before_template filter and one after filter (not after template).
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: hook before_template => sub { # do something }; A bunch of the hook documentation is broken, here's a pasted portion that shows the error in the docs multiple times. 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). before This is an alias to before. This hook receives no arguments. before sub { ... }; is equivalent to hook before sub { ... }; before_template_render This is an alias to 'before_template'. This hook receives as argument a HashRef, containing the tokens. hook before_template_render sub { my $tokens = shift; delete $tokens->{user}; }; is equivalent to hook before_template sub { my $tokens = shift; delete $tokens->{user}; };
Ah, OK - I'll add a before handler and an after_template to my test case and see if that changes anything.
It's odd that the first request works and every subsequent ones don't work.
Indeed. I suspect it's something like a side-effect of what one of the handlers returned being inadvertently set, or something.
-- 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)
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. 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)
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.
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)
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)
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)
Hi, On Sat, Jun 11, 2011 at 1:14 AM, Brian E. Lozier <brian@massassi.com> wrote:
It looks like the way Dancer is executing hooks is dangerous, please see this thread on perlmonks.org:
good catch https://github.com/sukria/Dancer/issues/559 https://github.com/sukria/Dancer/pull/560 Bye, -- Pedro Melo @pedromelo http://www.simplicidade.org/ http://about.me/melo xmpp:melo@simplicidade.org mailto:melo@simplicidade.org
On Fri, Jun 10, 2011 at 11:30 PM, Pedro Melo <melo@simplicidade.org> wrote:
Hi,
On Sat, Jun 11, 2011 at 1:14 AM, Brian E. Lozier <brian@massassi.com> wrote:
It looks like the way Dancer is executing hooks is dangerous, please see this thread on perlmonks.org:
good catch
https://github.com/sukria/Dancer/issues/559 https://github.com/sukria/Dancer/pull/560
Thanks!
Bye, -- Pedro Melo @pedromelo http://www.simplicidade.org/ http://about.me/melo xmpp:melo@simplicidade.org mailto:melo@simplicidade.org
participants (3)
-
Brian E. Lozier -
David Precious -
Pedro Melo