Log unhandled ART::RoutingHandler exceptions (#470)

src/components/routing/spec/routing_handler_spec.cr

@@ -77,18 +77,24 @@ describe ART::RoutingHandler do
         handler = ART::RoutingHandler.new MockURLMatcher.new "foo", ART::Exception::ResourceNotFound.new "Missing"
         handler.add("foo", ART::Route.new("/foo")) { }
 
-        handler.call HTTP::Server::Context.new HTTP::Request.new("GET", "/foo"), resp = HTTP::Server::Response.new(IO::Memory.new)
+        Log.capture do |logs|
+          handler.call HTTP::Server::Context.new HTTP::Request.new("GET", "/foo"), resp = HTTP::Server::Response.new(IO::Memory.new)
+          resp.status.should eq HTTP::Status::NOT_FOUND
 
-        resp.status.should eq HTTP::Status::NOT_FOUND
+          logs.empty
+        end
       end
 
       it "unsupported method" do
         handler = ART::RoutingHandler.new MockURLMatcher.new "foo", ART::Exception::MethodNotAllowed.new ["PUT", "SEARCH"], "Not Allowed"
         handler.add("foo", ART::Route.new("/foo")) { }
 
-        handler.call HTTP::Server::Context.new HTTP::Request.new("GET", "/foo"), resp = HTTP::Server::Response.new(IO::Memory.new)
+        Log.capture do |logs|
+          handler.call HTTP::Server::Context.new HTTP::Request.new("GET", "/foo"), resp = HTTP::Server::Response.new(IO::Memory.new)
+          resp.status.should eq HTTP::Status::METHOD_NOT_ALLOWED
 
-        resp.status.should eq HTTP::Status::METHOD_NOT_ALLOWED
+          logs.empty
+        end
       end
 
       it "domain exception" do
@@ -100,9 +106,12 @@ describe ART::RoutingHandler do
           raise "Oh no!"
         end
 
-        handler.call HTTP::Server::Context.new HTTP::Request.new("GET", "/foo"), resp = HTTP::Server::Response.new(IO::Memory.new)
+        Log.capture do |logs|
+          handler.call HTTP::Server::Context.new HTTP::Request.new("GET", "/foo"), resp = HTTP::Server::Response.new(IO::Memory.new)
+          resp.status.should eq HTTP::Status::INTERNAL_SERVER_ERROR
 
-        resp.status.should eq HTTP::Status::INTERNAL_SERVER_ERROR
+          logs.check :error, "Unhandled exception"
+        end
       end
     end
 
@@ -152,9 +161,12 @@ describe ART::RoutingHandler do
           ctx.request.path.should eq "/foo"
           raise "Oh no!"
         end
+        Log.capture do |logs|
+          expect_raises ::Exception, "Oh no!" do
+            handler.call HTTP::Server::Context.new HTTP::Request.new("GET", "/foo"), HTTP::Server::Response.new(IO::Memory.new)
+          end
 
-        expect_raises ::Exception, "Oh no!" do
-          handler.call HTTP::Server::Context.new HTTP::Request.new("GET", "/foo"), HTTP::Server::Response.new(IO::Memory.new)
+          logs.empty
         end
       end
     end

src/components/routing/spec/spec_helper.cr

@@ -2,11 +2,15 @@ require "spec"
 require "athena-spec"
 require "../src/athena-routing"
 
+require "log/spec"
+
 ASPEC.run_all
 
 Spec.before_each do
   ART::RouteProvider.reset
 end
 
+Log.setup :none
+
 # FIXME: Refactor these specs to not depend on calling a protected method.
 include Athena::Routing

src/components/routing/src/routing_handler.cr

@@ -1,3 +1,5 @@
+require "log"
+
 # Provides basic routing functionality to an [HTTP::Server](https://crystal-lang.org/api/HTTP/Server.html).
 #
 # This type works as both a [HTTP::Handler](https://crystal-lang.org/api/HTTP/Handler.html) and
@@ -64,6 +66,8 @@
 class Athena::Routing::RoutingHandler
   include HTTP::Handler
 
+  private LOG = Log.for "athena.routing"
+
   # :nodoc:
   class RouteProvider < ::Athena::Routing::RouteProvider
   end
@@ -113,6 +117,7 @@ class Athena::Routing::RoutingHandler
       @handlers[parameters["_route"]].call context, parameters
     rescue ex : ::Exception
       raise ex if @bubble_exceptions
+      LOG.error(exception: ex) { "Unhandled exception" }
       context.response.respond_with_status(:internal_server_error)
     end
   end