Refine acceptor behaviour on abnormal conditions (#103)

* Fix case where acceptors shut down forever after max_connections is hit

* Don't exit the acceptor process when handling an econnaborted error

Author: mtrudel

lib/thousand_island/acceptor.ex

@@ -28,8 +28,13 @@ defmodule ThousandIsland.Acceptor do
     else
       {:error, :too_many_connections} ->
         ThousandIsland.Telemetry.span_event(span, :spawn_error)
+        accept(listener_socket, connection_sup_pid, server_config, span, count + 1)
 
-      {:error, reason} when reason in [:closed, :einval, :econnaborted] ->
+      {:error, :econnaborted} ->
+        ThousandIsland.Telemetry.span_event(span, :econnaborted)
+        accept(listener_socket, connection_sup_pid, server_config, span, count + 1)
+
+      {:error, reason} when reason in [:closed, :einval] ->
         ThousandIsland.Telemetry.stop_span(span, %{connections: count})
 
       {:error, reason} ->

lib/thousand_island/logger.ex

@@ -21,7 +21,10 @@ defmodule ThousandIsland.Logger do
   """
   @spec attach_logger(log_level()) :: :ok | {:error, :already_exists}
   def attach_logger(:error) do
-    events = [[:thousand_island, :acceptor, :spawn_error]]
+    events = [
+      [:thousand_island, :acceptor, :spawn_error],
+      [:thousand_island, :acceptor, :econnaborted]
+    ]
 
     :telemetry.attach_many("#{__MODULE__}.error", events, &__MODULE__.log_error/4, nil)
   end

lib/thousand_island/telemetry.ex

@@ -97,6 +97,21 @@ defmodule ThousandIsland.Telemetry do
 
       * `telemetry_span_context`: A unique identifier for this span
 
+  * `[:thousand_island, :acceptor, :econnaborted]`
+
+      Thousand Island was unable to spawn a process to handle a connection since the remote end
+      closed before we could accept it. This usually occurs when it takes too long for your server
+      to start processing a connection; you may want to look at tuning OS-level TCP parameters or
+      adding more server capacity.
+
+      This event contains the following measurements:
+
+      * `monotonic_time`: The time of this event, in `:native` units
+
+      This event contains the following metadata:
+
+      * `telemetry_span_context`: A unique identifier for this span
+
   ## `[:thousand_island, :connection, *]`
 
   Represents Thousand Island handling a specific client request
@@ -281,6 +296,7 @@ defmodule ThousandIsland.Telemetry do
   @type event_name ::
           :ready
           | :spawn_error
+          | :econnaborted
           | :recv_error
           | :send_error
           | :sendfile_error

test/thousand_island/server_test.exs

@@ -134,6 +134,20 @@ defmodule ThousandIsland.ServerTest do
       assert :gen_tcp.recv(client, 0) == {:ok, ~c"HELLO"}
       assert :gen_tcp.recv(other_client, 0) == {:error, :closed}
       :gen_tcp.close(other_client)
+
+      # Close the first connection and ensure new connections are now accepted
+      :gen_tcp.close(client)
+
+      # Give things enough time for the first connection to time out
+      Process.sleep(500)
+
+      {:ok, third_client} = :gen_tcp.connect(:localhost, port, active: false)
+      :ok = :gen_tcp.send(third_client, "BUONGIORNO")
+
+      # Give things enough time to send if they were going to
+      Process.sleep(100)
+
+      assert :gen_tcp.recv(third_client, 0) == {:ok, ~c"BUONGIORNO"}
     end
 
     test "should emit telemetry events as expected" do