From 8f3a97b18eedb0f919594a54bff818e86e34ee07 Mon Sep 17 00:00:00 2001 From: Christopher Layne Date: Thu, 25 Jul 2019 13:27:33 -0700 Subject: [PATCH] execute_hook: Improve logging * Provide *per*-hook entry and exit logging around each hook called. This came out of a debugging experience where client code was adding the same hook twice at different stages of execution but it wasn't immediately apparent from debugging output to even look in that direction. Example output: core @2019-07-25 17:04:06> Entering hook core.app.before_request [CODE(0x55f96d8dbac0)] in (eval 221) l. 1 core @2019-07-25 17:04:06> Exited hook core.app.before_request [CODE(0x55f96d8dbac0)] in (eval 221) l. 1 --- lib/Dancer2/Core/Role/Hookable.pm | 9 ++++++--- 1 file changed, 6 insertions(+), 3 deletions(-) diff --git a/lib/Dancer2/Core/Role/Hookable.pm b/lib/Dancer2/Core/Role/Hookable.pm index 652ab5adb..6a1499df0 100644 --- a/lib/Dancer2/Core/Role/Hookable.pm +++ b/lib/Dancer2/Core/Role/Hookable.pm @@ -108,11 +108,14 @@ sub execute_hook { croak "Hook '$name' does not exist" if !$self->has_hook($name); - $self->$_isa('Dancer2::Core::App') && - $self->log( core => "Entering hook $name" ); - for my $hook ( @{ $self->hooks->{$name} } ) { + $self->$_isa('Dancer2::Core::App') && + $self->log( core => "Entering hook $name [$hook]" ); + $hook->(@_); + + $self->$_isa('Dancer2::Core::App') && + $self->log( core => "Exited hook $name [$hook]" ); } }