From cd724d48814a69bb8509421a55bc4f7db9947007 Mon Sep 17 00:00:00 2001 From: Adam Spiers Date: Sun, 6 Sep 2026 00:53:09 +0100 Subject: [PATCH 1/2] Ensure Bugsnag attribution in log messages Prefix messages before passing them to loggers so formatters that ignore progname retain the Bugsnag namespace. Preserve lazy logging and the default output format while avoiding duplicate prefixes. --- lib/bugsnag/configuration.rb | 21 +++++++--- .../on_breadcrumb_callback_list_spec.rb | 6 +-- spec/breadcrumbs/validator_spec.rb | 4 +- spec/bugsnag_spec.rb | 12 +++--- spec/configuration_spec.rb | 40 ++++++++++++++----- spec/integrations/logger_spec.rb | 2 +- spec/on_error_spec.rb | 10 ++--- spec/session_tracker_spec.rb | 15 +++++++ 8 files changed, 78 insertions(+), 32 deletions(-) diff --git a/lib/bugsnag/configuration.rb b/lib/bugsnag/configuration.rb index 050305b80..cde59db2b 100644 --- a/lib/bugsnag/configuration.rb +++ b/lib/bugsnag/configuration.rb @@ -283,8 +283,10 @@ def initialize # Set up logging self.logger = Logger.new(STDOUT) self.logger.level = Logger::INFO - self.logger.formatter = proc do |severity, datetime, progname, msg| - "** #{progname} #{datetime}: #{msg}\n" + self.logger.formatter = proc do |_severity, datetime, _progname, msg| + message = msg.to_s + message = message[PROG_NAME.length..-1].sub(/\A:?\s*/, "") if message.start_with?(PROG_NAME) + "** #{PROG_NAME} #{datetime}: #{message}\n" end # Configure the bugsnag middleware stack @@ -440,7 +442,7 @@ def clear_request_data # # @param message [String, #to_s] The message to log def info(message) - logger.info(PROG_NAME) { message } + logger.info(nil) { format_log_message(message) } end ## @@ -448,7 +450,7 @@ def info(message) # # @param message [String, #to_s] The message to log def warn(message) - logger.warn(PROG_NAME) { message } + logger.warn(nil) { format_log_message(message) } end ## @@ -456,7 +458,7 @@ def warn(message) # # @param message [String, #to_s] The message to log def error(message) - logger.error(PROG_NAME) { message } + logger.error(nil) { format_log_message(message) } end ## @@ -464,7 +466,7 @@ def error(message) # # @param message [String, #to_s] The message to log def debug(message) - logger.debug(PROG_NAME) { message } + logger.debug(nil) { format_log_message(message) } end ## @@ -764,6 +766,13 @@ def auto_track_sessions=(track_sessions) PROG_NAME = "[Bugsnag]" + def format_log_message(message) + message = message.to_s + return message if message.start_with?(PROG_NAME) + + "#{PROG_NAME} #{message}" + end + def default_hostname # Send the heroku dyno name instead of hostname if available ENV["DYNO"] || Socket.gethostname; diff --git a/spec/breadcrumbs/on_breadcrumb_callback_list_spec.rb b/spec/breadcrumbs/on_breadcrumb_callback_list_spec.rb index 6011124ab..571f3b796 100644 --- a/spec/breadcrumbs/on_breadcrumb_callback_list_spec.rb +++ b/spec/breadcrumbs/on_breadcrumb_callback_list_spec.rb @@ -246,11 +246,11 @@ def call(breadcrumb) message_index = 0 expected_messages = [ - /^Error occurred in on_breadcrumb callback: 'Oh no!'$/, - /^on_breadcrumb callback stacktrace:/ + /^\[Bugsnag\] Error occurred in on_breadcrumb callback: 'Oh no!'$/, + /^\[Bugsnag\] on_breadcrumb callback stacktrace:/ ] - expect(logger).to have_received(:warn).with("[Bugsnag]").twice do |&block| + expect(logger).to have_received(:warn).with(nil).twice do |&block| expect(block.call).to match(expected_messages[message_index]) message_index += 1 end diff --git a/spec/breadcrumbs/validator_spec.rb b/spec/breadcrumbs/validator_spec.rb index 99e0e1015..a5c5bfa34 100644 --- a/spec/breadcrumbs/validator_spec.rb +++ b/spec/breadcrumbs/validator_spec.rb @@ -49,8 +49,8 @@ expect(breadcrumb.ignore?).to eq(true) - expect(Bugsnag.configuration.logger).to have_received(:debug) do |&block| - expect(block.call).to eq("Automatic breadcrumb of type #{type} ignored: #{name}") + expect(Bugsnag.configuration.logger).to have_received(:debug).with(nil) do |&block| + expect(block.call).to eq("[Bugsnag] Automatic breadcrumb of type #{type} ignored: #{name}") end end diff --git a/spec/bugsnag_spec.rb b/spec/bugsnag_spec.rb index 328b15a62..6ad6981cf 100644 --- a/spec/bugsnag_spec.rb +++ b/spec/bugsnag_spec.rb @@ -64,11 +64,11 @@ end expected_messages = [ - /^Error in notify block: This is the error message$/, - /^Error in notify block stacktrace: \[/ + /^\[Bugsnag\] Error in notify block: This is the error message$/, + /^\[Bugsnag\] Error in notify block stacktrace: \[/ ].each - expect(Bugsnag.configuration.logger).to have_received(:warn).with('[Bugsnag]').twice do |&block| + expect(Bugsnag.configuration.logger).to have_received(:warn).with(nil).twice do |&block| expect(block.call).to match(expected_messages.next) end @@ -84,11 +84,11 @@ end expected_messages = [ - /^Error in internal notify block: This is an auto_notify error$/, - /^Error in internal notify block stacktrace: \[/ + /^\[Bugsnag\] Error in internal notify block: This is an auto_notify error$/, + /^\[Bugsnag\] Error in internal notify block stacktrace: \[/ ].each - expect(Bugsnag.configuration.logger).to have_received(:warn).with('[Bugsnag]').twice do |&block| + expect(Bugsnag.configuration.logger).to have_received(:warn).with(nil).twice do |&block| expect(block.call).to match(expected_messages.next) end diff --git a/spec/configuration_spec.rb b/spec/configuration_spec.rb index da2ac3119..d818b558b 100644 --- a/spec/configuration_spec.rb +++ b/spec/configuration_spec.rb @@ -364,8 +364,8 @@ describe "logger" do before do @output = StringIO.new - @formatter = proc do |severity, _datetime, progname, message| - "#{progname} #{severity}: #{message}" + @formatter = proc do |severity, _datetime, _progname, message| + "#{severity}: #{message}" end logger = Logger.new(@output) @@ -379,6 +379,21 @@ def output_lines @output.readlines.map(&:chomp) # old rubies don't support `readlines(chomp: true)` end + it "preserves the default log format" do + datetime = Time.utc(2026, 9, 6) + output = subject.logger.formatter.call( + "INFO", datetime, nil, "[Bugsnag] Info message" + ) + + expect(output).to eq("** [Bugsnag] #{datetime}: Info message\n") + expect(subject.logger.formatter.call("INFO", datetime, nil, "[Bugsnag]: Info message")).to eq( + "** [Bugsnag] #{datetime}: Info message\n" + ) + expect(subject.logger.formatter.call("INFO", datetime, nil, "[Bugsnag]")).to eq( + "** [Bugsnag] #{datetime}: \n" + ) + end + context "using configure" do before do Bugsnag.configuration.api_key = nil @@ -398,7 +413,7 @@ def output_lines 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' + 'WARN: [Bugsnag] No valid API key has been set, notifications will not be sent' ) end @@ -407,7 +422,7 @@ def output_lines 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' + 'WARN: [Bugsnag] No valid API key has been set, notifications will not be sent' ) end end @@ -428,7 +443,7 @@ def output_lines 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' + 'WARN: [Bugsnag] No valid API key has been set, notifications will not be sent' ) end @@ -457,7 +472,7 @@ def output_lines Bugsnag.configuration.info("Info message") expect(output_lines.length).to be(1) - expect(output_lines.first).to eq('[Bugsnag] INFO: Info message') + expect(output_lines.first).to eq('INFO: [Bugsnag] Info message') end it "should log warning messages to the set logger" do @@ -466,7 +481,7 @@ def output_lines Bugsnag.configuration.warn("Warning message") expect(output_lines.length).to be(1) - expect(output_lines.first).to eq('[Bugsnag] WARN: Warning message') + expect(output_lines.first).to eq('WARN: [Bugsnag] Warning message') end it "should log error messages to the set logger" do @@ -475,7 +490,7 @@ def output_lines Bugsnag.configuration.error("Error message") expect(output_lines.length).to be(1) - expect(output_lines.first).to eq('[Bugsnag] ERROR: Error message') + expect(output_lines.first).to eq('ERROR: [Bugsnag] Error message') end it "should log debug messages to the set logger" do @@ -484,7 +499,14 @@ def output_lines Bugsnag.configuration.debug("Debug message") expect(output_lines.length).to be(1) - expect(output_lines.first).to eq('[Bugsnag] DEBUG: Debug message') + expect(output_lines.first).to eq('DEBUG: [Bugsnag] Debug message') + end + + it "does not duplicate an existing Bugsnag prefix" do + Bugsnag.configuration.info("[Bugsnag] Info message") + + expect(output_lines.length).to be(1) + expect(output_lines.first).to eq('INFO: [Bugsnag] Info message') end end diff --git a/spec/integrations/logger_spec.rb b/spec/integrations/logger_spec.rb index 6fbe49e44..7b444863c 100644 --- a/spec/integrations/logger_spec.rb +++ b/spec/integrations/logger_spec.rb @@ -8,7 +8,7 @@ end context 'in a Rails app' do - key_warning = '[Bugsnag]: No valid API key has been set, notifications will not be sent' + key_warning = '[Bugsnag] No valid API key has been set, notifications will not be sent' is_jruby = defined?(RUBY_ENGINE) && RUBY_ENGINE == 'jruby' incompatible = (RUBY_VERSION < '2.0.0') || is_jruby diff --git a/spec/on_error_spec.rb b/spec/on_error_spec.rb index 798befd1d..f57995592 100644 --- a/spec/on_error_spec.rb +++ b/spec/on_error_spec.rb @@ -198,8 +198,8 @@ expect(Bugsnag).not_to have_sent_notification expect(called_count).to be(2) - expect(logger).to have_received(:debug).with("[Bugsnag]") do |&block| - expect(block.call).to eq("Not notifying RuntimeError due to ignore being signified in user provided middleware") + expect(logger).to have_received(:debug).with(nil) do |&block| + expect(block.call).to eq("[Bugsnag] Not notifying RuntimeError due to ignore being signified in user provided middleware") end end @@ -257,11 +257,11 @@ message_index = 0 expected_messages = [ - /^Error occurred in on_error callback: 'bad things'$/, - /^on_error callback stacktrace:/ + /^\[Bugsnag\] Error occurred in on_error callback: 'bad things'$/, + /^\[Bugsnag\] on_error callback stacktrace:/ ] - expect(logger).to have_received(:warn).with("[Bugsnag]").twice do |&block| + expect(logger).to have_received(:warn).with(nil).twice do |&block| expect(block.call).to match(expected_messages[message_index]) message_index += 1 end diff --git a/spec/session_tracker_spec.rb b/spec/session_tracker_spec.rb index 81bcb6578..9e646c376 100644 --- a/spec/session_tracker_spec.rb +++ b/spec/session_tracker_spec.rb @@ -117,6 +117,21 @@ expect(payload["sessionCounts"].size).to eq(1) end + it 'attributes invalid API key delivery failures to Bugsnag' do + output = StringIO.new + logger = Logger.new(output) + logger.formatter = proc do |_severity, _datetime, _progname, message| + message + end + Bugsnag.configuration.logger = logger + allow(Bugsnag.configuration).to receive(:valid_api_key?).and_return(false) + + Bugsnag.start_session + Bugsnag.session_tracker.send_sessions + + expect(output.string).to eq('[Bugsnag] Not delivering sessions due to an invalid api_key') + end + it 'sets details from config' do Bugsnag.configure do |conf| conf.auto_capture_sessions = true From 1527a7da556fd3a526545d52d620e848cfded1e3 Mon Sep 17 00:00:00 2001 From: Adam Spiers Date: Mon, 7 Sep 2026 19:13:03 +0100 Subject: [PATCH 2/2] Address review: keep progname and drop trailing space on empty messages Restore PROG_NAME as the logger progname argument so consumers that read progname separately from the message (structured logging, custom formatters) keep the previous contract. The message prefix still guarantees attribution for formatters that discard progname, so both audiences are served. Return the bare prefix for nil or empty messages instead of "[Bugsnag] ", which left a trailing space and was inconsistent with the idempotency rule that a message already starting with the prefix is passed through unchanged. --- lib/bugsnag/configuration.rb | 9 ++++--- .../on_breadcrumb_callback_list_spec.rb | 2 +- spec/breadcrumbs/validator_spec.rb | 2 +- spec/bugsnag_spec.rb | 4 +-- spec/configuration_spec.rb | 26 +++++++++++++++++++ spec/on_error_spec.rb | 4 +-- 6 files changed, 37 insertions(+), 10 deletions(-) diff --git a/lib/bugsnag/configuration.rb b/lib/bugsnag/configuration.rb index cde59db2b..9c7ccbfab 100644 --- a/lib/bugsnag/configuration.rb +++ b/lib/bugsnag/configuration.rb @@ -442,7 +442,7 @@ def clear_request_data # # @param message [String, #to_s] The message to log def info(message) - logger.info(nil) { format_log_message(message) } + logger.info(PROG_NAME) { format_log_message(message) } end ## @@ -450,7 +450,7 @@ def info(message) # # @param message [String, #to_s] The message to log def warn(message) - logger.warn(nil) { format_log_message(message) } + logger.warn(PROG_NAME) { format_log_message(message) } end ## @@ -458,7 +458,7 @@ def warn(message) # # @param message [String, #to_s] The message to log def error(message) - logger.error(nil) { format_log_message(message) } + logger.error(PROG_NAME) { format_log_message(message) } end ## @@ -466,7 +466,7 @@ def error(message) # # @param message [String, #to_s] The message to log def debug(message) - logger.debug(nil) { format_log_message(message) } + logger.debug(PROG_NAME) { format_log_message(message) } end ## @@ -769,6 +769,7 @@ def auto_track_sessions=(track_sessions) def format_log_message(message) message = message.to_s return message if message.start_with?(PROG_NAME) + return PROG_NAME if message.empty? "#{PROG_NAME} #{message}" end diff --git a/spec/breadcrumbs/on_breadcrumb_callback_list_spec.rb b/spec/breadcrumbs/on_breadcrumb_callback_list_spec.rb index 571f3b796..1d81ebe11 100644 --- a/spec/breadcrumbs/on_breadcrumb_callback_list_spec.rb +++ b/spec/breadcrumbs/on_breadcrumb_callback_list_spec.rb @@ -250,7 +250,7 @@ def call(breadcrumb) /^\[Bugsnag\] on_breadcrumb callback stacktrace:/ ] - expect(logger).to have_received(:warn).with(nil).twice do |&block| + expect(logger).to have_received(:warn).with("[Bugsnag]").twice do |&block| expect(block.call).to match(expected_messages[message_index]) message_index += 1 end diff --git a/spec/breadcrumbs/validator_spec.rb b/spec/breadcrumbs/validator_spec.rb index a5c5bfa34..44f2aea8c 100644 --- a/spec/breadcrumbs/validator_spec.rb +++ b/spec/breadcrumbs/validator_spec.rb @@ -49,7 +49,7 @@ expect(breadcrumb.ignore?).to eq(true) - expect(Bugsnag.configuration.logger).to have_received(:debug).with(nil) do |&block| + expect(Bugsnag.configuration.logger).to have_received(:debug).with("[Bugsnag]") do |&block| expect(block.call).to eq("[Bugsnag] Automatic breadcrumb of type #{type} ignored: #{name}") end end diff --git a/spec/bugsnag_spec.rb b/spec/bugsnag_spec.rb index 6ad6981cf..3b3437cc8 100644 --- a/spec/bugsnag_spec.rb +++ b/spec/bugsnag_spec.rb @@ -68,7 +68,7 @@ /^\[Bugsnag\] Error in notify block stacktrace: \[/ ].each - expect(Bugsnag.configuration.logger).to have_received(:warn).with(nil).twice do |&block| + expect(Bugsnag.configuration.logger).to have_received(:warn).with("[Bugsnag]").twice do |&block| expect(block.call).to match(expected_messages.next) end @@ -88,7 +88,7 @@ /^\[Bugsnag\] Error in internal notify block stacktrace: \[/ ].each - expect(Bugsnag.configuration.logger).to have_received(:warn).with(nil).twice do |&block| + expect(Bugsnag.configuration.logger).to have_received(:warn).with("[Bugsnag]").twice do |&block| expect(block.call).to match(expected_messages.next) end diff --git a/spec/configuration_spec.rb b/spec/configuration_spec.rb index d818b558b..d184637cf 100644 --- a/spec/configuration_spec.rb +++ b/spec/configuration_spec.rb @@ -394,6 +394,32 @@ def output_lines ) end + it "sets the Bugsnag progname on the logger as well as the message" do + logger = double("logger") + subject.logger = logger + + %i[info warn error debug].each do |level| + expect(logger).to receive(level).with("[Bugsnag]") do |_progname, &block| + expect(block.call).to eq("[Bugsnag] #{level} message") + end + + subject.public_send(level, "#{level} message") + end + end + + it "does not leave a trailing space when the message is empty" do + logger = double("logger") + subject.logger = logger + + [nil, ""].each do |message| + expect(logger).to receive(:info).with("[Bugsnag]") do |_progname, &block| + expect(block.call).to eq("[Bugsnag]") + end + + subject.info(message) + end + end + context "using configure" do before do Bugsnag.configuration.api_key = nil diff --git a/spec/on_error_spec.rb b/spec/on_error_spec.rb index f57995592..017f5697c 100644 --- a/spec/on_error_spec.rb +++ b/spec/on_error_spec.rb @@ -198,7 +198,7 @@ expect(Bugsnag).not_to have_sent_notification expect(called_count).to be(2) - expect(logger).to have_received(:debug).with(nil) do |&block| + expect(logger).to have_received(:debug).with("[Bugsnag]") do |&block| expect(block.call).to eq("[Bugsnag] Not notifying RuntimeError due to ignore being signified in user provided middleware") end end @@ -261,7 +261,7 @@ /^\[Bugsnag\] on_error callback stacktrace:/ ] - expect(logger).to have_received(:warn).with(nil).twice do |&block| + expect(logger).to have_received(:warn).with("[Bugsnag]").twice do |&block| expect(block.call).to match(expected_messages[message_index]) message_index += 1 end