rename debug_logger to error_logger; add levels; fix tests

lib/puma/error_logger.rb

@@ -5,7 +5,7 @@ require 'puma/const'
 module Puma
   # The implementation of a logging in debug mode.
   #
-  class DebugLogger
+  class ErrorLogger
     include Const
 
     attr_reader :ioerr
@@ -23,25 +23,41 @@ module Puma
       new $stderr
     end
 
-    # Any error has occured during debug mode.
+    # Print occured error details.
     # +options+ hash with additional options:
-    # - +force+ (default nil) to log info even if debug mode is turned off
     # - +error+ is an exception object
     # - +req+ the http request
     # - +text+ (default nil) custom string to print in title
     #   and before all remaining info.
     #
-    def error_dump(options={})
+    def info(options={})
-      return unless @debug || options[:force]
+      error_dump(options)
+    end
 
+    # Print occured error details only if
+    # environment variable PUMA_DEBUG is defined.
+    # +options+ hash with additional options:
+    # - +error+ is an exception object
+    # - +req+ the http request
+    # - +text+ (default nil) custom string to print in title
+    #   and before all remaining info.
+    #
+    def debug(options={})
+      return unless @debug
+      error_dump(options)
+    end
+
+    private
+
+    def error_dump(options={})
       error = options[:error]
       req = options[:req]
       env = req.env if req
       text = options[:text]
 
       string_block = []
-      formatted_text = " #{text}:" if text
+      formatted_text = " #{text}" if text
-      formatted_error = " #{error.inspect}" if error
+      formatted_error = ": #{error.inspect}" if error
       string_block << "#{Time.now}#{formatted_text}#{formatted_error}"
 
       if env
@@ -55,10 +71,8 @@ module Puma
       ioerr.puts string_block.join("\n")
     end
 
-    private
-
     def request_title(env)
-      request_line = REQUEST_FORMAT % [
+      REQUEST_FORMAT % [
         env[REQUEST_METHOD],
         env[REQUEST_PATH] || env[PATH_INFO],
         env[QUERY_STRING] || "",

lib/puma/events.rb

@@ -1,7 +1,7 @@
 # frozen_string_literal: true
 
 require "puma/null_io"
-require 'puma/debug_logger'
+require 'puma/error_logger'
 require 'stringio'
 
 module Puma
@@ -34,7 +34,7 @@ module Puma
       @stderr.sync = true
 
       @debug = ENV.key? 'PUMA_DEBUG'
-      @debug_logger = DebugLogger.new(@stderr)
+      @error_logger = ErrorLogger.new(@stderr)
 
       @hooks = Hash.new { |h,k| h[k] = [] }
     end
@@ -79,7 +79,7 @@ module Puma
     # Write +str+ to +@stderr+
     #
     def error(str)
-      @debug_logger.error_dump(text: format("ERROR: #{str}"))
+      @error_logger.info(text: format("ERROR: #{str}"))
       exit 1
     end
 
@@ -88,35 +88,44 @@ module Puma
     end
 
     # An HTTP connection error has occurred.
-    # +error+ a connection exception, +req+ the request
+    # +error+ a connection exception, +req+ the request,
+    # and +text+ additional info
     #
     def connection_error(error, req, text="HTTP connection error")
-      @debug_logger.error_dump(error: error, req: req, text: text)
+      @error_logger.info(error: error, req: req, text: text)
     end
 
     # An HTTP parse error has occurred.
-    # +req+ the request, and +error+ a
+    # +error+ a parsing exception,
-    # parsing exception.
+    # and +req+ the request.
     #
     def parse_error(error, req)
-      @debug_logger.error_dump(error: error, req: req, text: 'HTTP parse error, malformed request', force: true)
+      @error_logger.info(error: error, req: req, text: 'HTTP parse error, malformed request')
     end
 
     # An SSL error has occurred.
-    # +peeraddr+ peer address, +peercert+
+    # +error+ an exception object, +peeraddr+ peer address,
-    # any peer certificate (if present), and +error+ an exception object.
+    # and +peercert+ any peer certificate (if present).
     #
     def ssl_error(error, peeraddr, peercert)
       subject = peercert ? peercert.subject : nil
-      @debug_logger.error_dump(error: error, text: "SSL error, peer: #{peeraddr}, peer cert: #{subject}", force: true)
+      @error_logger.info(error: error, text: "SSL error, peer: #{peeraddr}, peer cert: #{subject}")
     end
 
     # An unknown error has occurred.
-    # +error+ an exception object,
+    # +error+ an exception object, +req+ the request,
-    # +kind+ some additional info, and +req+ the request.
+    # and +text+ additional info
     #
-    def unknown_error(error, req=nil, kind="Unknown")
+    def unknown_error(error, req=nil, text="Unknown error")
-      @debug_logger.error_dump(error: error, req: req, text: kind, force: true)
+      @error_logger.info(error: error, req: req, text: text)
+    end
+
+    # Log occurred error debug dump.
+    # +error+ an exception object, +req+ the request,
+    # and +text+ additional info
+    #
+    def debug_error(error, req=nil, text="")
+      @error_logger.debug(error: error, req: req, text: text)
     end
 
     def on_booted(&block)

lib/puma/server.rb

@@ -563,7 +563,7 @@ module Puma
 
             fast_write client, "\r\n".freeze
           rescue ConnectionError => e
-            @events.connection_error e, nil
+            @events.debug_error e
             # noop, if we lost the socket we just won't send the early hints
           end
         }

test/test_debug_logger.rb

@@ -1,81 +0,0 @@
-require 'puma/debug_logger'
-require_relative "helper"
-
-class TestDebugLogger < Minitest::Test
-  Req = Struct.new(:env, :body)
-
-  def setup
-    @debug_logger = Puma::DebugLogger.stdio
-  end
-
-  def test_stdio
-    debug_logger = Puma::DebugLogger.stdio
-
-    assert_equal STDERR, debug_logger.ioerr
-  end
-
-  def test_error_dump_if_debug_false
-    _, err = capture_io do
-      @debug_logger.error_dump(text: 'blank')
-    end
-
-    assert_empty err
-  end
-
-  def test_error_dump_force
-    _, err = capture_io do
-      Puma::DebugLogger.stdio.error_dump(text: 'ready', force: true)
-    end
-
-    assert_match %r!ready!, err
-  end
-
-  def test_error_dump_with_only_error
-    with_debug_mode do
-      _, err = capture_io do
-        Puma::DebugLogger.stdio.error_dump(error: StandardError.new('ready'))
-      end
-
-      assert_match %r!#<StandardError: ready>!, err
-    end
-  end
-
-  def test_error_dump_with_request
-    with_debug_mode do
-
-      env = {
-        'REQUEST_METHOD' => 'GET',
-        'PATH_INFO' => '/debug',
-        'HTTP_X_FORWARDED_FOR' => '8.8.8.8'
-      }
-      req = Req.new(env, '{"hello":"world"}')
-
-      _, err = capture_io do
-        Puma::DebugLogger.stdio.error_dump(error: StandardError.new, req: req)
-      end
-
-      assert_match %r!Handling request { "GET /debug" - \(8\.8\.8\.8\) }!, err
-      assert_match %r!Headers: {"X_FORWARDED_FOR"=>"8\.8\.8\.8"}!, err
-      assert_match %r!Body: {"hello":"world"}!, err
-    end
-  end
-
-  def test_error_dump_with_text
-    with_debug_mode do
-      _, err = capture_io do
-        Puma::DebugLogger.stdio.error_dump(text: 'The client disconnected while we were reading data')
-      end
-
-      assert_match %r!The client disconnected while we were reading data!, err
-    end
-  end
-
-  private
-
-  def with_debug_mode
-    original_debug, ENV["PUMA_DEBUG"] = ENV["PUMA_DEBUG"], "1"
-    yield
-  ensure
-    ENV["PUMA_DEBUG"] = original_debug
-  end
-end

test/test_error_logger.rb

@@ -0,0 +1,72 @@
+require 'puma/error_logger'
+require_relative "helper"
+
+class TestErrorLogger < Minitest::Test
+  Req = Struct.new(:env, :body)
+
+  def test_stdio
+    error_logger = Puma::ErrorLogger.stdio
+
+    assert_equal STDERR, error_logger.ioerr
+  end
+
+  def test_info_with_only_error
+    _, err = capture_io do
+      Puma::ErrorLogger.stdio.info(error: StandardError.new('ready'))
+    end
+
+    assert_match %r!#<StandardError: ready>!, err
+  end
+
+  def test_info_with_request
+    env = {
+      'REQUEST_METHOD' => 'GET',
+      'PATH_INFO' => '/debug',
+      'HTTP_X_FORWARDED_FOR' => '8.8.8.8'
+    }
+    req = Req.new(env, '{"hello":"world"}')
+
+    _, err = capture_io do
+      Puma::ErrorLogger.stdio.info(error: StandardError.new, req: req)
+    end
+
+    assert_match %r!Handling request { "GET /debug" - \(8\.8\.8\.8\) }!, err
+    assert_match %r!Headers: {"X_FORWARDED_FOR"=>"8\.8\.8\.8"}!, err
+    assert_match %r!Body: {"hello":"world"}!, err
+  end
+
+  def test_info_with_text
+    _, err = capture_io do
+      Puma::ErrorLogger.stdio.info(text: 'The client disconnected while we were reading data')
+    end
+
+    assert_match %r!The client disconnected while we were reading data!, err
+  end
+
+  def test_debug_without_debug_mode
+    _, err = capture_io do
+      Puma::ErrorLogger.stdio.debug(text: 'blank')
+    end
+
+    assert_empty err
+  end
+
+  def test_debug_with_debug_mode
+    with_debug_mode do
+      _, err = capture_io do
+        Puma::ErrorLogger.stdio.debug(text: 'non-blank')
+      end
+
+      assert_match %r!non-blank!, err
+    end
+  end
+
+  private
+
+  def with_debug_mode
+    original_debug, ENV["PUMA_DEBUG"] = ENV["PUMA_DEBUG"], "1"
+    yield
+  ensure
+    ENV["PUMA_DEBUG"] = original_debug
+  end
+end

test/test_events.rb

@@ -120,14 +120,16 @@ class TestEvents < Minitest::Test
     did_exit = false
 
     _, err = capture_io do
-      Puma::Events.stdio.error("interrupted")
+      begin
+        Puma::Events.stdio.error("interrupted")
+      rescue SystemExit
+        did_exit = true
+      ensure
+        assert did_exit
+      end
     end
 
-    assert_equal "ERROR: interrupted", err
+    assert_match %r!ERROR: interrupted!, err
-  rescue SystemExit
-    did_exit = true
-  ensure
-    assert did_exit
   end
 
   def test_pid_formatter