allow Mojo::Server::Daemon to log when a connection has been closed p…

…rematurely
mojolicious · Apr 21, 2016 · 5038a1b · 5038a1b
1 parent 5685407
commit 5038a1b
Show file tree

Hide file tree

Showing 4 changed files with 25 additions and 9 deletions.
diff --git a/Changes b/Changes
@@ -1,6 +1,8 @@
 
 6.59  2016-04-21
   - Improved HTML Living Standard compliance of Mojo::DOM::HTML.
+  - Improved Mojo::Server::Daemon to log when a connection has been closed
+    prematurely.
   - Improved Mojo::Server::Prefork to log when the manager process has been
     stopped.
   - Fixed a few tests to keep up with breaking changes in IO::Socket::SSL.

diff --git a/lib/Mojo/Server/Daemon.pm b/lib/Mojo/Server/Daemon.pm
@@ -118,7 +118,11 @@ sub _close {
   my ($self, $id) = @_;
 
   # Finish gracefully
-  if (my $tx = $self->{connections}{$id}{tx}) { $tx->closed }
+  if (my $tx = $self->{connections}{$id}{tx}) {
+    $tx->closed;
+    $self->_debug($id, 'Premature connection close')
+      unless $tx->is_websocket || $tx->res->is_finished;
+  }
 
   delete $self->{connections}{$id};
 }

diff --git a/lib/Mojolicious/Guides/FAQ.pod b/lib/Mojolicious/Guides/FAQ.pod
@@ -248,10 +248,18 @@ request.
 
 =head2 What does "Premature connection close" mean?
 
-This error message is often related to the one above, and means that the web
-server closed the connection before the user agent could receive the whole
-response or that the user agent got destroyed, which forces all connections to
-be closed immediately.
+On the I<client-side> this message is often related to the one above, and means
+that the web server closed the connection before the user agent could receive
+the whole response, or that the user agent got destroyed, which forces all
+connections to be closed immediately.
+
+On the I<server-side> this message means that the user agent closed the
+connection before the web server could send the whole response. While this is
+generally harmless in itself, special care must be taken for non-blocking
+operations that might still be active, because once the connection has been
+closed L<Mojolicious::Controller/"tx"> will no longer be available. In such
+cases you can use events like L<Mojolicious::Transaction/"finish"> for cleaning
+up, or keep an extra reference to the transaction object.
 
 =head2 What does "Worker 31842 has no heartbeat, restarting" mean?
 

diff --git a/t/mojolicious/longpolling_lite_app.t b/t/mojolicious/longpolling_lite_app.t
@@ -300,15 +300,17 @@ Mojo::IOLoop->one_tick until $stash->{destroyed};
 ok !$stash->{writing}, 'finish event timing is right';
 ok $stash->{destroyed}, 'controller has been destroyed';
 
-# Request timeout
-$tx = $t->ua->request_timeout(0.5)->get('/too_long');
+# Request and inactivity timeouts
+$log = '';
+$cb  = $t->app->log->on(message => sub { $log .= pop });
+$tx  = $t->ua->request_timeout(0.5)->get('/too_long');
 is $tx->error->{message}, 'Request timeout', 'right error';
 $t->ua->request_timeout(0);
-
-# Inactivity timeout
 $tx = $t->ua->inactivity_timeout(0.5)->get('/too_long');
 is $tx->error->{message}, 'Inactivity timeout', 'right error';
 $t->ua->inactivity_timeout(20);
+like $log, qr/Premature connection close/, 'right message';
+$t->app->log->unsubscribe(message => $cb);
 
 # Transaction is available after rendering early in steps
 $t->get_ok('/steps')->status_is(200)->content_is('second');