diff --git a/lib/logtail-rails/event_log_subscriber.rb b/lib/logtail-rails/event_log_subscriber.rb index d24185a..c3d3aa7 100644 --- a/lib/logtail-rails/event_log_subscriber.rb +++ b/lib/logtail-rails/event_log_subscriber.rb @@ -6,7 +6,7 @@ module Rails # them with all their data to Rails.logger, which sends them to Better Stack. class EventLogSubscriber # Rails logger instance - attr_reader :logger + attr_accessor :logger # Log level to use for logging events mattr_accessor :log_level, default: :info @@ -14,6 +14,17 @@ class EventLogSubscriber # Allows to disable the subscriber mattr_accessor :enabled, default: true + # Subscribes to Rails.event once. Later calls only hand the events to the new logger, so that + # calling Logtail::Logger.create_default_logger again doesn't log every event twice. + def self.subscribe(logger) + if @subscriber + @subscriber.logger = logger + else + @subscriber = new(logger) + ::Rails.event.subscribe(@subscriber) + end + end + # Initialize the subscriber with a logger instance def initialize(logger) @logger = logger diff --git a/lib/logtail-rails/logger.rb b/lib/logtail-rails/logger.rb index 8e969c2..292bab3 100755 --- a/lib/logtail-rails/logger.rb +++ b/lib/logtail-rails/logger.rb @@ -49,6 +49,10 @@ def stop_broadcasting_to(io_device_or_logger) def self.create_logger(*io_devices_and_loggers) logger = Logtail::Logger.new(*io_devices_and_loggers) + # Rails applies config.log_level to Rails.logger while booting, but not to a logger added with broadcast_to later + log_level = Rails.application.config.log_level if ENV['LOG_LEVEL'].blank? && Rails.application + logger.level = ::ActiveSupport::Logger.const_get(log_level.to_s.upcase) if log_level + tagged_logging_supported = Rails::VERSION::MAJOR >= 7 || Rails::VERSION::MAJOR == 6 && Rails::VERSION::MINOR >= 1 logger = ::ActiveSupport::TaggedLogging.new(logger) if tagged_logging_supported @@ -79,7 +83,7 @@ def self.create_default_logger(source_token, options = {}) end # For Rails 8.1 and above, subscribe to the event system - Rails.event.subscribe(Logtail::Integrations::Rails::EventLogSubscriber.new(logger)) if Rails.respond_to?(:event) + Logtail::Integrations::Rails::EventLogSubscriber.subscribe(logger) if Rails.respond_to?(:event) logger end diff --git a/spec/logtail-rails/http_events_spec.rb b/spec/logtail-rails/http_events_spec.rb index 2e8bb2a..d185ab9 100755 --- a/spec/logtail-rails/http_events_spec.rb +++ b/spec/logtail-rails/http_events_spec.rb @@ -45,7 +45,7 @@ def method_for_action(action_name) expect(lines[0]).to include("Started GET \\\"/rack_http\\\"") expect(lines[1]).to include("Processing by RackHttpController#index as HTML") - expect(lines[2]).to include("Completed 200 OK in 0.0ms") + expect(lines[2]).to match(/Completed 200 OK in \d+\.\d+ms/) end context "with the route silenced" do @@ -87,7 +87,7 @@ def method_for_action(action_name) expect(lines.length).to eq(2) expect(lines[0]).to include("Processing by RackHttpController#index as HTML") - expect(lines[1]).to include("GET /rack_http completed with 200 OK in 0.0ms") + expect(lines[1]).to match(/GET \/rack_http completed with 200 OK in \d+\.\d+ms/) end end end diff --git a/spec/logtail-rails/logger_spec.rb b/spec/logtail-rails/logger_spec.rb index c9dd38b..32dc2f0 100755 --- a/spec/logtail-rails/logger_spec.rb +++ b/spec/logtail-rails/logger_spec.rb @@ -122,5 +122,52 @@ expect(Sidekiq.logger).to eq(log_double) end + + context "when called more than once" do + let(:io) { StringIO.new } + + # spec_helper.rb makes every EventLogSubscriber log to Rails.logger + around(:each) do |example| + with_rails_logger(Logtail::Logger.new(io)) { example.run } + end + + it "should log each Rails.event once" do + skip("Rails.event exists in Rails 8.1 and higher") unless Rails.respond_to?(:event) + + Logtail::Logger.create_default_logger("foo") + Logtail::Logger.create_default_logger("foo") + Rails.event.notify("logger_spec.created", id: 1) + + expect(io.string.lines.grep(/logger_spec\.created/).length).to eq(1) + end + end + + context "with config.log_level" do + around(:each) do |example| + log_level = Rails.application.config.log_level + Rails.application.config.log_level = :info + example.run + Rails.application.config.log_level = log_level + end + + before do + allow(Logtail::Logger).to receive(:create_logger).and_call_original + end + + # Rails sets config.log_level on Rails.logger, but not on a logger added with broadcast_to after boot + it "should use it as the level" do + logger = Logtail::Logger.create_default_logger("foo") + + expect(logger.level).to eq(::Logger::INFO) + end + + it "should prefer the LOG_LEVEL environment variable" do + ENV["LOG_LEVEL"] = "warn" + logger = Logtail::Logger.create_default_logger("foo") + ENV.delete("LOG_LEVEL") + + expect(logger.level).to eq(::Logger::WARN) + end + end end end diff --git a/spec/logtail-rails/rack_logger_spec.rb b/spec/logtail-rails/rack_logger_spec.rb index e3c2109..6976159 100755 --- a/spec/logtail-rails/rack_logger_spec.rb +++ b/spec/logtail-rails/rack_logger_spec.rb @@ -49,7 +49,7 @@ def method_for_action(action_name) expect(lines.length).to eq(3) expect(lines[0]).to include("Started GET \\\"/rails_rack_logger\\\"") expect(lines[1]).to include("Processing by RailsRackLoggerController#index as HTML") - expect(lines[2]).to include("Completed 200 OK in 0.0ms") + expect(lines[2]).to match(/Completed 200 OK in \d+\.\d+ms/) ensure Logtail::Integrations::Rails::EventLogSubscriber.enabled = original_enabled end