Log delivery failures as errors

CHANGELOG.md

@@ -7,6 +7,8 @@ Changelog
 
 * Sessions will now be delivered every 10 seconds, instead of every 30 seconds
   | [#680](https://github.com/bugsnag/bugsnag-ruby/pull/680)
+* Log errors that prevent delivery at `ERROR` level
+  | [#681](https://github.com/bugsnag/bugsnag-ruby/pull/681)
 
 ### Fixes
 

lib/bugsnag/configuration.rb

@@ -392,15 +392,23 @@ def info(message)
     ##
     # Logs a warning level message
     #
-    # @param (see info)
+    # @param message [String, #to_s] The message to log
     def warn(message)
       logger.warn(PROG_NAME) { message }
     end
 
+    ##
+    # Logs an error level message
+    #
+    # @param message [String, #to_s] The message to log
+    def error(message)
+      logger.error(PROG_NAME) { message }
+    end
+
     ##
     # Logs a debug level message
     #
-    # @param (see info)
+    # @param message [String, #to_s] The message to log
     def debug(message)
       logger.debug(PROG_NAME) { message }
     end

lib/bugsnag/delivery/synchronous.rb

@@ -18,8 +18,8 @@ def deliver(url, body, configuration, options={})
             # KLUDGE: Since we don't re-raise http exceptions, this breaks rspec
             raise if e.class.to_s == "RSpec::Expectations::ExpectationNotMetError"
 
-            configuration.warn("Notification to #{url} failed, #{e.inspect}")
-            configuration.warn(e.backtrace)
+            configuration.error("Unable to send information to Bugsnag (#{url}), #{e.inspect}")
+            configuration.error(e.backtrace)
           end
         end
 

lib/bugsnag/delivery/thread_queue.rb

@@ -31,8 +31,8 @@ def serialize_and_deliver(url, get_payload, configuration, options={})
             begin
               payload = get_payload.call
             rescue StandardError => e
-              configuration.warn("Notification to #{url} failed, #{e.inspect}")
-              configuration.warn(e.backtrace)
+              configuration.error("Unable to send information to Bugsnag (#{url}), #{e.inspect}")
+              configuration.error(e.backtrace)
             end
 
             Synchronous.deliver(url, payload, configuration, options) unless payload.nil?

spec/configuration_spec.rb

@@ -246,76 +246,53 @@
   end
 
   describe "logger" do
-    class TestLogger
-      attr_accessor :logs
-
-      def initialize
-        @logs = []
-      end
-
-      def log(level, name, &block)
-        message = block.call
-        @logs << {
-          :level => level,
-          :name => name,
-          :message => message
-        }
-      end
-
-      def info(name, &block)
-        log('info', name, &block)
+    before do
+      @output = StringIO.new
+      @formatter = proc do |severity, _datetime, progname, message|
+        "#{progname} #{severity}: #{message}"
       end
 
-      def warn(name, &block)
-        log('warning', name, &block)
-      end
+      logger = Logger.new(@output)
+      logger.formatter = @formatter
 
-      def debug(name, &block)
-        log('debug', name, &block)
-      end
+      Bugsnag.configuration.logger = logger
     end
 
-    before do
-      @logger = TestLogger.new
-      Bugsnag.configure do |bugsnag|
-        bugsnag.logger = @logger
-      end
+    def output_lines
+      @output.rewind # always read from the start of output
+      @output.readlines.map(&:chomp) # old rubies don't support `readlines(chomp: true)`
     end
 
     context "using configure" do
       before do
         Bugsnag.configuration.api_key = nil
         Bugsnag.instance_variable_set("@key_warning", nil)
         ENV['BUGSNAG_API_KEY'] = nil
-        expect(@logger.logs.size).to eq(0)
+        expect(output_lines).to be_empty
       end
 
       context "API key is not specified" do
         it "skips logging a warning if validate_api_key is false" do
           Bugsnag.configure(false)
-          expect(@logger.logs.size).to eq(0)
+          expect(output_lines).to be_empty
         end
 
         it "logs a warning by default" do
           Bugsnag.configure
-          expect(@logger.logs.size).to eq(1)
-          log = @logger.logs.first
-          expect(log).to eq({
-            :level => "warning",
-            :name => "[Bugsnag]",
-            :message => "No valid API key has been set, notifications will not be sent"
-          })
+
+          expect(output_lines.length).to be(1)
+          expect(output_lines.first).to eq(
+            '[Bugsnag] WARN: No valid API key has been set, notifications will not be sent'
+          )
         end
 
         it "logs a warning if validate_api_key is true" do
           Bugsnag.configure(true)
-          expect(@logger.logs.size).to eq(1)
-          log = @logger.logs.first
-          expect(log).to eq({
-            :level => "warning",
-            :name => "[Bugsnag]",
-            :message => "No valid API key has been set, notifications will not be sent"
-          })
+
+          expect(output_lines.length).to be(1)
+          expect(output_lines.first).to eq(
+            '[Bugsnag] WARN: No valid API key has been set, notifications will not be sent'
+          )
         end
       end
 
@@ -324,64 +301,57 @@ def debug(name, &block)
           Bugsnag.configure do |config|
             config.api_key = 'd57a2472bd130ac0ab0f52715bbdc600'
           end
-          expect(@logger.logs.size).to eq(0)
+
+          expect(output_lines).to be_empty
         end
 
         it "logs a warning if the configured API key is invalid" do
           Bugsnag.configure do |config|
             config.api_key = 'WARNING: not a real key'
           end
-          expect(@logger.logs.size).to eq(1)
-          log = @logger.logs.first
-          expect(log).to eq({
-            :level => "warning",
-            :name => "[Bugsnag]",
-            :message => "No valid API key has been set, notifications will not be sent"
-          })
+
+          expect(output_lines.length).to be(1)
+          expect(output_lines.first).to eq(
+            '[Bugsnag] WARN: No valid API key has been set, notifications will not be sent'
+          )
         end
       end
     end
 
     it "should log info messages to the set logger" do
-      expect(@logger.logs.size).to eq(0)
+      expect(output_lines).to be_empty
+
       Bugsnag.configuration.info("Info message")
-      expect(@logger.logs.size).to eq(1)
-      log = @logger.logs.first
-      expect(log).to eq({
-        :level => "info",
-        :name => "[Bugsnag]",
-        :message => "Info message"
-      })
+
+      expect(output_lines.length).to be(1)
+      expect(output_lines.first).to eq('[Bugsnag] INFO: Info message')
     end
 
     it "should log warning messages to the set logger" do
-      expect(@logger.logs.size).to eq(0)
+      expect(output_lines).to be_empty
+
       Bugsnag.configuration.warn("Warning message")
-      expect(@logger.logs.size).to eq(1)
-      log = @logger.logs.first
-      expect(log).to eq({
-        :level => "warning",
-        :name => "[Bugsnag]",
-        :message => "Warning message"
-      })
+
+      expect(output_lines.length).to be(1)
+      expect(output_lines.first).to eq('[Bugsnag] WARN: Warning message')
+    end
+
+    it "should log error messages to the set logger" do
+      expect(output_lines).to be_empty
+
+      Bugsnag.configuration.error("Error message")
+
+      expect(output_lines.length).to be(1)
+      expect(output_lines.first).to eq('[Bugsnag] ERROR: Error message')
     end
 
     it "should log debug messages to the set logger" do
-      expect(@logger.logs.size).to eq(0)
+      expect(output_lines).to be_empty
+
       Bugsnag.configuration.debug("Debug message")
-      expect(@logger.logs.size).to eq(1)
-      log = @logger.logs.first
-      expect(log).to eq({
-        :level => "debug",
-        :name => "[Bugsnag]",
-        :message => "Debug message"
-      })
-    end
 
-    after do
-      Bugsnag.configure do |bugsnag|
-        bugsnag.logger = Logger.new(StringIO.new)
-      end
+      expect(output_lines.length).to be(1)
+      expect(output_lines.first).to eq('[Bugsnag] DEBUG: Debug message')
     end
   end