some nonblocking examples/testing

bump Mojolicious version requirement to 8.00, add nonblocking example to
ExampleApp, document caveats with using async code with profiling

note the change of the post_hook to after_dispatch in the ExampleApp,
which is the reversion of 5ec7b18 (only
for the example, not in the actual plugin config itself) to get the
async code covered by the profiler in this example:

    [2019-06-28 09:05:54.12481] [71327] [debug] GET "/nonblock" (91158226)
    [2019-06-28 09:05:54.12496] [71327] [debug] starting NYTProf
    [2019-06-28 09:05:54.12589] [71327] [debug] Routing to controller "ExampleApp::ExampleController" and action "nonblock"
    [2019-06-28 09:05:54.12603] [71327] [info] starting request, first sleep
    [2019-06-28 09:05:55.13080] [71327] [info] about to wait
    [2019-06-28 09:05:55.13093] [71327] [info] returning from controller
    [2019-06-28 09:05:55.13123] [71327] [debug] Template "example_controller/nonblock.html.ep" not found
    [2019-06-28 09:05:55.13138] [71327] [debug] Nothing has been rendered, expecting delayed response
    [2019-06-28 09:05:55.13157] [71327] [info] in first callback
    [2019-06-28 09:05:56.13444] [71327] [info] in second callback
    [2019-06-28 09:05:57.13883] [71327] [debug] 200 OK (3.01398s, 0.332/s)
    [2019-06-28 09:05:57.13964] [71327] [debug] finished NYTProf

clicking through i see all the async code in ExampleController.pm is
covered. in "real world" examples the after_dispatch hook can fire
out of order as per the aforementioned commit so it's "not that simple"

the only other option i can think here is to tweak the way the plugin
runs to add routes that allow manual switching on/off of the profiling
as required and not trying to do this through the mojo hooks:

    /nytprof/start - start the profiler
    /nytprof/stop  - stop the profiler

not sure how well that would work, and could lead to large profiles, so
i'm going to mark that as a TODO

Changes

@@ -1,5 +1,10 @@
 Revision history for Mojolicious-Plugin-NYTProf
 
+0.22     2019-07-01
+        - Bump Mojolicious version requirement to 8.00
+        - Add nonblocking example to ExampleApp
+        - Document caveats with using async code with profiling
+
 0.21     2018-10-01
         - Bump Devel::NYTProf version requirement to 6.06 for recent fixes
 

Makefile.PL

@@ -14,7 +14,7 @@ WriteMakefile(
   LICENSE       => 'perl',
   PREREQ_PM => {
     'Devel::NYTProf'        => '6.06',
-    'Mojolicious'           => '6.00',
+    'Mojolicious'           => '8.00',
     'File::Which'           => '1.09',
     'File::Temp'            => '0.22',
     'Time::HiRes'           => '1.9719',

README.md

@@ -10,7 +10,7 @@ Mojolicious::Plugin::NYTProf - Auto handling of Devel::NYTProf in your Mojolicio
 
 # VERSION
 
-0.21
+0.22
 
 # DESCRIPTION
 
@@ -65,6 +65,10 @@ is started using a before\_routes hook and the stopped with an around\_dispatch
 The consequence of this is that you should see profiling only for your routes and
 rendering code and will not see most of the actual Mojolicious framework detail.
 
+The caveat with the use of hooks is that some hooks can fire out of order, and when
+asynchronous code is used in your controllers you may see incomplete/odd profiling
+behaviour - you can play around with the hook configuration to try to fix this.
+
 You can override the hooks used to control when the profiling runs, see the
 CONFIGURATION section below.
 

lib/Mojolicious/Plugin/NYTProf.pm

@@ -10,7 +10,7 @@ Mojolicious::Plugin::NYTProf - Auto handling of Devel::NYTProf in your Mojolicio
 
 =head1 VERSION
 
-0.21
+0.22
 
 =head1 DESCRIPTION
 
@@ -59,7 +59,7 @@ use File::Temp;
 use File::Which;
 use File::Spec::Functions qw/catfile catdir/;
 
-our $VERSION = '0.21';
+our $VERSION = '0.22';
 
 =head1 METHODS
 
@@ -78,6 +78,10 @@ is started using a before_routes hook and the stopped with an around_dispatch ho
 The consequence of this is that you should see profiling only for your routes and
 rendering code and will not see most of the actual Mojolicious framework detail.
 
+The caveat with the use of hooks is that some hooks can fire out of order, and when
+asynchronous code is used in your controllers you may see incomplete/odd profiling
+behaviour - you can play around with the hook configuration to try to fix this.
+
 You can override the hooks used to control when the profiling runs, see the
 CONFIGURATION section below.
 

t/lib/ExampleApp.pm

@@ -11,7 +11,7 @@ sub startup {
             trace => 1,
             log => '/tmp/nytprof.log',
             pre_hook  => 'before_routes',
-            post_hook => 'around_dispatch',
+            post_hook => 'after_dispatch',
         },
     });
 
@@ -20,6 +20,8 @@ sub startup {
     $self->routes->any('/t3')->to('ExampleController#t3');
     $self->routes->any('/t4')->to('ExampleController#t4');
     $self->routes->any('/t5')->to('ExampleController#t5');
+
+	$self->routes->any('/nonblock')->to('ExampleController#nonblock');
 }
 
 1;

t/lib/ExampleApp/ExampleController.pm

@@ -18,4 +18,43 @@ sub t4 {
     $self->render(template=>'t3');
 }
 
+sub nonblock {
+    my $self=shift;
+
+    my $delay = Mojo::IOLoop::Delay->new;
+
+    $self->app->log->info("starting request, first sleep");
+
+    sleeping_before_any_callbacks();
+
+    $delay->steps(
+        sub {
+            my $end = $delay->begin;
+            $self->app->log->info("in first callback");
+            sleeping_in_first_callback();
+            $end->();
+        },
+        sub {
+            my $end = $delay->begin;
+            $self->app->log->info("in second callback");
+            sleeping_in_second_callback();
+            $end->();
+            $self->render(text=>"Done with second callback, returning this response\n");
+        },
+    );
+    $self->app->log->info("about to wait");
+    $delay->wait unless Mojo::IOLoop->is_running;
+
+    $self->app->log->info("returning from controller");
+}
+
+sub sleeping_before_any_callbacks {
+       sleep 1;
+}
+sub sleeping_in_first_callback {
+       sleep 1;
+}
+sub sleeping_in_second_callback {
+       sleep 1;
+}
 1;