fix: throwing plug properly handled and returns 500 (#411)

* fix: throwing plug returns 500

* Keeps backwards compatibility for telemetry span exception event

* mix format

Author: grzuy

lib/bandit/pipeline.ex

@@ -46,12 +46,15 @@ defmodule Bandit.Pipeline do
             {:upgrade, adapter.transport, protocol, opts}
         end
       rescue
-        error -> handle_error(error, __STACKTRACE__, transport, span, opts)
+        exception -> handle_error(:error, exception, __STACKTRACE__, transport, span, opts)
+      catch
+        :throw, value ->
+          handle_error(:throw, value, __STACKTRACE__, transport, span, opts)
       end
     rescue
-      error ->
+      exception ->
         span = Bandit.Telemetry.start_span(:request, measurements, metadata)
-        handle_error(error, __STACKTRACE__, transport, span, opts)
+        handle_error(:error, exception, __STACKTRACE__, transport, span, opts)
     end
   end
 
@@ -194,13 +197,14 @@ defmodule Bandit.Pipeline do
   end
 
   @spec handle_error(
-          Exception.t(),
+          :error | :throw,
+          Exception.t() | term(),
           Exception.stacktrace(),
           Bandit.HTTPTransport.t(),
           Bandit.Telemetry.t(),
           map()
         ) :: {:ok, Bandit.HTTPTransport.t()} | {:error, term()}
-  defp handle_error(%type{} = error, stacktrace, transport, span, opts)
+  defp handle_error(:error, %type{} = error, stacktrace, transport, span, opts)
        when type in [
               Bandit.HTTPError,
               Bandit.HTTP2.Errors.StreamError,
@@ -216,21 +220,21 @@ defmodule Bandit.Pipeline do
     {:error, error}
   end
 
-  defp handle_error(error, stacktrace, transport, span, opts) do
-    Bandit.Telemetry.span_exception(span, :exit, error, stacktrace)
-    status = error |> Plug.Exception.status() |> Plug.Conn.Status.code()
+  defp handle_error(kind, reason, stacktrace, transport, span, opts) do
+    Bandit.Telemetry.span_exception(span, kind, reason, stacktrace)
+    status = reason |> Plug.Exception.status() |> Plug.Conn.Status.code()
 
     if status in Keyword.get(opts.http, :log_exceptions_with_status_codes, 500..599) do
       Logger.error(
-        Exception.format(:error, error, stacktrace),
+        Exception.format(kind, reason, stacktrace),
         domain: [:bandit],
-        crash_reason: {error, stacktrace}
+        crash_reason: crash_reason(kind, reason, stacktrace)
       )
 
-      Bandit.HTTPTransport.send_on_error(transport, error)
-      {:error, error}
+      Bandit.HTTPTransport.send_on_error(transport, reason)
+      {:error, reason}
     else
-      Bandit.HTTPTransport.send_on_error(transport, error)
+      Bandit.HTTPTransport.send_on_error(transport, reason)
       {:ok, transport}
     end
   end
@@ -252,4 +256,7 @@ defmodule Bandit.Pipeline do
   end
 
   defp do_maybe_log_error(_error, _stacktrace, false), do: :ok
+
+  defp crash_reason(:throw, reason, stacktrace), do: {{:nocatch, reason}, stacktrace}
+  defp crash_reason(_, reason, stacktrace), do: {reason, stacktrace}
 end

lib/bandit/telemetry.ex

@@ -188,18 +188,24 @@ defmodule Bandit.Telemetry do
     untimed_span_event(span, :stop, measurements, metadata)
   end
 
-  @spec span_exception(t(), Exception.kind(), Exception.t(), Exception.stacktrace()) :: :ok
-  def span_exception(span, kind, exception, stacktrace) do
+  @spec span_exception(t(), Exception.kind(), Exception.t() | term(), Exception.stacktrace()) ::
+          :ok
+  def span_exception(span, :error, reason, stacktrace) when is_exception(reason) do
     metadata =
       Map.merge(span.start_metadata, %{
-        kind: kind,
-        exception: exception,
+        # Using :exit for backwards-compatiblity with Bandit =< 1.5.7
+        kind: :exit,
+        exception: reason,
         stacktrace: stacktrace
       })
 
     span_event(span, :exception, %{}, metadata)
   end
 
+  def span_exception(_span, _kind, _reason, _stacktrace) do
+    :ok
+  end
+
   @doc false
   @spec span_event(t(), span_name(), :telemetry.event_measurements(), :telemetry.event_metadata()) ::
           :ok

test/bandit/http1/request_test.exs

@@ -1793,6 +1793,21 @@ defmodule HTTP1RequestTest do
       raise "boom"
     end
 
+    test "returns a 500 if the plug throws", context do
+      output =
+        capture_log(fn ->
+          response = Req.get!(context.req, url: "/throws")
+          assert response.status == 500
+          Process.sleep(100)
+        end)
+
+      assert output =~ "(throw) \"something\""
+    end
+
+    def throws(_conn) do
+      throw("something")
+    end
+
     test "does not send an error response if the plug has already sent one before raising",
          context do
       output =
@@ -2176,7 +2191,7 @@ defmodule HTTP1RequestTest do
       assert output =~ "(Bandit.HTTPError) Header read timeout"
     end
 
-    test "it should send `exception` events for erroring requests", context do
+    test "it should send `exception` events for raising requests", context do
       output =
         capture_log(fn ->
           {:ok, collector_pid} =
@@ -2202,6 +2217,26 @@ defmodule HTTP1RequestTest do
 
       assert output =~ "(RuntimeError) boom"
     end
+
+    test "it should not send `exception` events for throwing requests", context do
+      output =
+        capture_log(fn ->
+          {:ok, collector_pid} =
+            start_supervised({Bandit.TelemetryCollector, [[:bandit, :request, :exception]]})
+
+          Req.get!(context.req, url: "/uncaught_throw")
+
+          Process.sleep(100)
+
+          assert [] = Bandit.TelemetryCollector.get_events(collector_pid)
+        end)
+
+      assert output =~ "(throw) \"thrown\""
+    end
+
+    def uncaught_throw(_conn) do
+      throw("thrown")
+    end
   end
 
   describe "connection closure / error handling" do

test/bandit/http2/plug_test.exs

@@ -996,7 +996,7 @@ defmodule HTTP2PlugTest do
       assert output =~ "(Bandit.HTTP2.Errors.StreamError) Received uppercase header"
     end
 
-    test "it should send `exception` events for erroring requests", context do
+    test "it should send `exception` events for raising requests", context do
       output =
         capture_log(fn ->
           {:ok, collector_pid} =
@@ -1026,5 +1026,25 @@ defmodule HTTP2PlugTest do
     def raise_error(_conn) do
       raise "boom"
     end
+
+    test "it should not send `exception` events for throwing requests", context do
+      output =
+        capture_log(fn ->
+          {:ok, collector_pid} =
+            start_supervised({Bandit.TelemetryCollector, [[:bandit, :request, :exception]]})
+
+          Req.get!(context.req, url: "/uncaught_throw")
+
+          Process.sleep(100)
+
+          assert [] = Bandit.TelemetryCollector.get_events(collector_pid)
+        end)
+
+      assert output =~ "(throw) \"thrown\""
+    end
+
+    def uncaught_throw(_conn) do
+      throw("thrown")
+    end
   end
 end