Tests for Rails.logger when :logger patch is enabled (#2659)

* [sentry-rails] add support for isolated specs

* [sentry-rails] add tests for Rails logger when :logger patch is enabled

Author: solnic

lib/sentry/test/rake_tasks.rb

@@ -0,0 +1,59 @@
+# frozen_string_literal: true
+
+require "rake/clean"
+require "rspec/core/rake_task"
+
+module Sentry
+  module Test
+    module RakeTasks
+      extend Rake::DSL
+
+      def self.define_spec_tasks(options = {})
+        opts = {
+          isolated_specs_pattern: "spec/isolated/**/*_spec.rb",
+          spec_pattern: nil,
+          spec_exclude_pattern: nil,
+          spec_rspec_opts: nil,
+          isolated_rspec_opts: nil
+        }.merge(options)
+
+        RSpec::Core::RakeTask.new(:spec).tap do |task|
+          task.pattern = opts[:spec_pattern] if opts[:spec_pattern]
+          task.exclude_pattern = opts[:spec_exclude_pattern] if opts[:spec_exclude_pattern]
+          task.rspec_opts = opts[:spec_rspec_opts] if opts[:spec_rspec_opts]
+        end
+
+        namespace :spec do
+          RSpec::Core::RakeTask.new(:isolated).tap do |task|
+            task.pattern = opts[:isolated_specs_pattern]
+            task.rspec_opts = opts[:isolated_rspec_opts] if opts[:isolated_rspec_opts]
+          end
+        end
+      end
+
+      # Define versioned specs task (sentry-rails specific)
+      def self.define_versioned_specs_task(options = {})
+        opts = {
+          rspec_opts: "--order rand"
+        }.merge(options)
+
+        namespace :spec do
+          RSpec::Core::RakeTask.new(:versioned).tap do |task|
+            ruby_ver_dir = RUBY_VERSION.split(".")[0..1].join(".")
+            matching_dir = Dir["spec/versioned/*"].detect { |dir| File.basename(dir) <= ruby_ver_dir }
+
+            unless matching_dir
+              puts "No versioned specs found for ruby #{RUBY_VERSION}"
+              exit 0
+            end
+
+            puts "Running versioned specs from #{matching_dir} for ruby #{RUBY_VERSION}"
+
+            task.rspec_opts = opts[:rspec_opts]
+            task.pattern = "#{matching_dir}/**/*_spec.rb"
+          end
+        end
+      end
+    end
+  end
+end

sentry-rails/Rakefile

@@ -1,34 +1,17 @@
 # frozen_string_literal: true
 
 require "bundler/gem_tasks"
-require "rspec/core/rake_task"
+require_relative "../lib/sentry/test/rake_tasks"
 
-RSpec::Core::RakeTask.new(:spec).tap do |task|
-  task.rspec_opts = "--order rand"
-  task.pattern = "spec/sentry/**/*_spec.rb"
-end
+Sentry::Test::RakeTasks.define_spec_tasks(
+  spec_pattern: "spec/sentry/**/*_spec.rb",
+  spec_rspec_opts: "--order rand --format progress",
+  isolated_specs_pattern: "spec/isolated/**/*_spec.rb",
+  isolated_rspec_opts: "--format progress"
+)
 
-namespace :spec do
-  RSpec::Core::RakeTask.new(:versioned).tap do |task|
-    ruby_ver_dir = RUBY_VERSION.split(".")[0..1].join(".")
-    matching_dir = Dir["spec/versioned/*"].detect { |dir| File.basename(dir) <= ruby_ver_dir }
+Sentry::Test::RakeTasks.define_versioned_specs_task(
+  rspec_opts: "--order rand --format progress"
+)
 
-    unless matching_dir
-      puts "No versioned specs found for ruby #{RUBY_VERSION}"
-      exit 0
-    end
-
-    puts "Running versioned specs from #{matching_dir} for ruby #{RUBY_VERSION}"
-
-    task.rspec_opts = "--order rand"
-    task.pattern = "#{matching_dir}/**/*_spec.rb"
-  end
-end
-
-task :isolated_specs do
-  Dir["spec/isolated/*"].each do |file|
-    sh "bundle exec ruby #{file}"
-  end
-end
-
-task default: [:spec, :"spec:versioned", :isolated_specs]
+task default: [:spec, :"spec:versioned", :"spec:isolated"]

sentry-rails/spec/isolated/rails_logger_patch_spec.rb

@@ -0,0 +1,157 @@
+# frozen_string_literal: true
+
+begin
+  require "simplecov"
+  SimpleCov.command_name "RailsLoggerPatch"
+rescue LoadError
+end
+
+require "logger"
+require "sentry-ruby"
+require "sentry/test_helper"
+
+require_relative "../dummy/test_rails_app/app"
+
+RSpec.describe "Rails.logger with :logger patch" do
+  include Sentry::TestHelper
+
+  # Set up a real Rails app with logger
+  let(:log_output) { StringIO.new }
+  let(:app) do
+    make_basic_app do |config|
+      config.enable_logs = true
+      config.enabled_patches = [:logger]
+      config.max_log_events = 10
+      config.sdk_logger = Logger.new(nil)
+    end
+  end
+
+  before do
+    app
+    Rails.logger = Logger.new(log_output)
+  end
+
+  context "when :logger patch is enabled" do
+    it "captures Rails.logger calls when :logger patch is enabled" do
+      Rails.logger.debug("Test debug message")
+      Rails.logger.info("Test info message")
+      Rails.logger.warn("Test warning message")
+      Rails.logger.error("Test error message")
+      Rails.logger.fatal("Test fatal message")
+
+      Sentry.get_current_client.log_event_buffer.flush
+
+      expect(sentry_logs).not_to be_empty
+
+      log_messages = sentry_logs.map { |log| log[:body] }
+      expect(log_messages).to include(
+        "Test debug message",
+        "Test info message",
+        "Test warning message",
+        "Test error message",
+        "Test fatal message"
+      )
+
+      test_logs = sentry_logs.select { |log| log[:body].start_with?("Test ") }
+      log_levels = test_logs.map { |log| log[:level] }
+      expect(log_levels).to contain_exactly("debug", "info", "warn", "error", "fatal")
+    end
+
+    it "captures Rails.logger calls with block syntax" do
+      Rails.logger.info { "Block message" }
+
+      Sentry.get_current_client.log_event_buffer.flush
+
+      expect(sentry_logs).not_to be_empty
+
+      log_messages = sentry_logs.map { |log| log[:body] }
+      expect(log_messages).to include("Block message")
+
+      block_log = sentry_logs.find { |log| log[:body] == "Block message" }
+      expect(block_log[:level]).to eq("info")
+    end
+
+    it "captures Rails.logger calls with progname" do
+      Rails.logger.info("MyProgram") { "Message with progname" }
+
+      Sentry.get_current_client.log_event_buffer.flush
+
+      expect(sentry_logs).not_to be_empty
+
+      log_messages = sentry_logs.map { |log| log[:body] }
+      expect(log_messages).to include("Message with progname")
+
+      progname_log = sentry_logs.find { |log| log[:body] == "Message with progname" }
+      expect(progname_log[:level]).to eq("info")
+    end
+
+    it "does not capture Sentry SDK internal logs" do
+      Rails.logger.info(Sentry::Logger::PROGNAME) { "Internal Sentry message" }
+
+      Sentry.get_current_client.log_event_buffer.flush
+
+      log_messages = sentry_logs.map { |log| log[:body] }
+      expect(log_messages).not_to include("Internal Sentry message")
+    end
+
+    it "strips whitespace from log messages" do
+      Rails.logger.info("  Message with whitespace  ")
+
+      Sentry.get_current_client.log_event_buffer.flush
+
+      expect(sentry_logs).not_to be_empty
+
+      log_messages = sentry_logs.map { |log| log[:body] }
+      expect(log_messages).to include("Message with whitespace")
+    end
+
+    it "handles non-string log messages" do
+      Rails.logger.info(12345)
+
+      Sentry.get_current_client.log_event_buffer.flush
+
+      expect(sentry_logs).not_to be_empty
+
+      log_messages = sentry_logs.map { |log| log[:body] }
+      expect(log_messages).to include("12345")
+    end
+  end
+
+  context "when Rails.logger is a BroadcastLogger", skip: !defined?(ActiveSupport::BroadcastLogger) do
+    let(:string_io1) { StringIO.new }
+    let(:string_io2) { StringIO.new }
+    let(:logger1) { Logger.new(string_io1) }
+    let(:logger2) { Logger.new(string_io2) }
+    let(:broadcast_logger) { ActiveSupport::BroadcastLogger.new(logger1, logger2) }
+    let(:broadcast_app) do
+      make_basic_app do |config|
+        config.enable_logs = true
+        config.enabled_patches = [:logger]
+        config.max_log_events = 10
+        config.sdk_logger = Logger.new(nil)
+      end
+    end
+
+    before do
+      broadcast_app
+      Rails.logger = broadcast_logger
+    end
+
+    it "captures logs from BroadcastLogger" do
+      Rails.logger.info("Broadcast message")
+
+      Sentry.get_current_client.log_event_buffer.flush
+
+      expect(sentry_logs).not_to be_empty
+
+      log_messages = sentry_logs.map { |log| log[:body] }
+      expect(log_messages).to include("Broadcast message")
+
+      broadcast_log = sentry_logs.find { |log| log[:body] == "Broadcast message" }
+      expect(broadcast_log[:level]).to eq("info")
+
+      expect(string_io1.string).to include("Broadcast message")
+      expect(string_io2.string).to include("Broadcast message")
+    end
+  end
+end

sentry-ruby/Rakefile

@@ -6,16 +6,13 @@ CLOBBER.include "pkg"
 require "bundler/gem_helper"
 Bundler::GemHelper.install_tasks(name: "sentry-ruby")
 
-require "rspec/core/rake_task"
+require_relative "../lib/sentry/test/rake_tasks"
 
 ISOLATED_SPECS = "spec/isolated/**/*_spec.rb"
 
-RSpec::Core::RakeTask.new(:spec).tap do |task|
-  task.exclude_pattern = ISOLATED_SPECS
-end
+Sentry::Test::RakeTasks.define_spec_tasks(
+  isolated_specs_pattern: ISOLATED_SPECS,
+  spec_exclude_pattern: ISOLATED_SPECS
+)
 
-RSpec::Core::RakeTask.new(:isolated_specs).tap do |task|
-  task.pattern = ISOLATED_SPECS
-end
-
-task default: [:spec, :isolated_specs]
+task default: [:spec, :"spec:isolated"]