[close #2371] Do not log EOFError (#2384)

* Failing test for #2371

The EOF can be triggered by opening a connection, not writing to it, then closing the connection. When this happens we can detect if an error was logged or not by inspecting the stderr string. 

This test fails

* [close #2371] Do not log EOFError

This is a continuation from #2382.

One of the ways that an EOFError can be triggered is by opening a connection, not writing to it, then closing it (there may be others). This should be an expected and non-exceptional activity. When it happens we should not log it.

This commit gets the test in the prior commit to pass.

The change to client.rb makes sense to me as this is the initial place where we're reading from the socket and then finding out the stream has been closed. Im not quite sure why the code in server.rb is needed. I think this comes from when the server is shutting down and trying to finish out connections.

I don't think this is the 100% right way to do things. I'm guessing that if we get an EOFError on a connection we should somehow consider it "dead" and never try to read from it again. I don't know if there's a better way to signify this in the `try_to_finish` method of client.rb

History.md

@@ -9,6 +9,7 @@
   * Prevent connections from entering Reactor after shutdown begins ([#2377])
   * Fix error backtrace debug logging && Do not log request dump if it is not parsed ([#2376])
   * Split TCP_CORK and TCP_INFO ([#2372])
+  * Do not log EOFError when a client connection is closed without write (#2384)
 
 * Refactor
   * Change Events#ssl_error signature from (error, peeraddr, peercert) to (error, ssl_socket) ([#2375])

lib/puma/client.rb

@@ -157,7 +157,9 @@ def try_to_finish
         data = @io.read_nonblock(CHUNK_SIZE)
       rescue IO::WaitReadable
         return false
-      rescue SystemCallError, IOError, EOFError
+      rescue EOFError
+        # Swallow error, don't log
+      rescue SystemCallError, IOError
         raise ConnectionError, "Connection error detected during read"
       end
 

lib/puma/server.rb

@@ -246,7 +246,11 @@ def run(background=true)
           client.close
 
           @events.parse_error e, client
-        rescue ConnectionError, EOFError, ThreadPool::ForceShutdown => e
+        rescue EOFError => e
+          client.close
+
+          # Swallow, do not log
+        rescue ConnectionError, ThreadPool::ForceShutdown => e
           client.close
 
           @events.connection_error e, client

test/test_puma_server.rb

@@ -256,6 +256,17 @@ def test_doesnt_print_backtrace_in_production
     assert_match(/HTTP\/1.0 500 Internal Server Error/, data)
   end
 
+
+  def test_eof_on_connection_close_is_not_logged_as_an_error
+    server_run
+
+    new_connection.close # Make a connection and close without writing
+
+    @server.stop(true)
+    stderr = @events.stderr.string
+    assert stderr.empty?, "Expected stderr from server to be empty but it was #{stderr.inspect}"
+  end
+
   def test_force_shutdown_custom_error_message
     handler = lambda {|err, env, status| [500, {"Content-Type" => "application/json"}, ["{}\n"]]}
     @server = Puma::Server.new @app, @events, {:lowlevel_error_handler => handler, :force_shutdown_after => 2}