From c77567e317b95b5082e1e82ab43a6b46887f5024 Mon Sep 17 00:00:00 2001 From: Petr Heinz Date: Wed, 23 Sep 2026 16:33:16 +0200 Subject: [PATCH 01/11] Add failing tests for T-10657: Rails 8.2 event reporter log subscribers Rails main turned the framework log subscribers into ActiveSupport::EventReporter::LogSubscriber subclasses fed by Rails.event. Pin the EventLogSubscriber behaviour (forward app events, skip the events Rails already logs) and give the ActionView unit tests an 8.2-shaped event. On rails-edge the suite still fails to load until the integration is ported. Co-Authored-By: Claude Fable 5.1 --- .../action_view/log_subscriber_spec.rb | 9 +++++-- .../event_log_subscriber_spec.rb | 26 +++++++++++++++++++ 2 files changed, 33 insertions(+), 2 deletions(-) create mode 100644 spec/logtail-rails/event_log_subscriber_spec.rb diff --git a/spec/logtail-rails/action_view/log_subscriber_spec.rb b/spec/logtail-rails/action_view/log_subscriber_spec.rb index 280cf1b..71a14ea 100755 --- a/spec/logtail-rails/action_view/log_subscriber_spec.rb +++ b/spec/logtail-rails/action_view/log_subscriber_spec.rb @@ -61,8 +61,13 @@ def method_for_action(action_name) if defined?(described_class::LogtailLogSubscriber) describe described_class::LogtailLogSubscriber do let(:event) do - event = Struct.new(:duration, :payload) - event.new(2.0, identifier: "path/to/template.html") + if ::ActionView::LogSubscriber < ::ActiveSupport::LogSubscriber + event = Struct.new(:duration, :payload) + event.new(2.0, identifier: "path/to/template.html") + else + # Rails 8.2+ delivers structured events through ActiveSupport::EventReporter + { name: "action_view.render_template", payload: { identifier: "path/to/template.html", duration_ms: 2.0 } } + end end around(:each) do |example| diff --git a/spec/logtail-rails/event_log_subscriber_spec.rb b/spec/logtail-rails/event_log_subscriber_spec.rb new file mode 100644 index 0000000..5c832da --- /dev/null +++ b/spec/logtail-rails/event_log_subscriber_spec.rb @@ -0,0 +1,26 @@ +require "spec_helper" + +RSpec.describe Logtail::Integrations::Rails::EventLogSubscriber do + let(:io) { StringIO.new } + let(:logger) { Logtail::Logger.new(io) } + let(:subscriber) { described_class.new(logger) } + + around(:each) do |example| + with_rails_logger(logger) { example.run } + end + + it "logs events reported by the application" do + subscriber.emit({ name: "user.created", payload: { id: 1 }, tags: {}, context: {}, source_location: {} }) + + expect(io.string).to include('"message":"[user.created] id=1"') + expect(io.string).to include('"event_name":"user.created"') + end + + it "does not log events the Rails framework already logs" do + skip("Rails 8.2 routes the framework's own events through Rails.event") unless defined?(::ActiveSupport::EventReporter::LogSubscriber) + + subscriber.emit({ name: "active_record.sql", payload: { sql: "select 1" }, tags: {}, context: {}, source_location: {} }) + + expect(io.string).to eq("") + end +end From 04379669ce8ca01cf22cfc21dc9efd47af6a1412 Mon Sep 17 00:00:00 2001 From: Petr Heinz Date: Wed, 23 Sep 2026 16:41:53 +0200 Subject: [PATCH 02/11] Load the ActionController and ActionView railties in the spec app Rails 8.2 sets ActionView::LogSubscriber.rails_root in the ActionView railtie's action_view.root initializer, earlier versions derived it from Rails.root lazily. Without the railtie the edge subscribers strip "/" instead of the app root from template paths. The ActionView railtie needs the ActionController one. Co-Authored-By: Claude Fable 5.1 --- spec/support/rails.rb | 4 ++++ 1 file changed, 4 insertions(+) diff --git a/spec/support/rails.rb b/spec/support/rails.rb index 47cef1c..ca98cb5 100755 --- a/spec/support/rails.rb +++ b/spec/support/rails.rb @@ -1,4 +1,8 @@ require "rails" +# Rails 8.2+ sets the template root the ActionView log subscribers strip in the action_view.root +# initializer, and the ActionView railtie needs the ActionController one +require "action_controller/railtie" +require "action_view/railtie" require "logtail-rails/railtie" # Default the rails logger to nothing, each test should be From 002d8c38cf88f9b1aa466a1b4165b6484e8a8785 Mon Sep 17 00:00:00 2001 From: Petr Heinz Date: Wed, 23 Sep 2026 16:41:53 +0200 Subject: [PATCH 03/11] T-10657 Support Rails 8.2 event reporter log subscribers On Rails main the controller, view and record log subscribers are ActiveSupport::EventReporter::LogSubscribers fed by Rails.event, so the gem could not find them in ActiveSupport::LogSubscriber.log_subscribers and raised at boot. ActiveSupportLogSubscriber swaps such subscribers through the event reporter, delivering only the events for the methods the Logtail subscriber defines itself, like attach_to does. The Logtail subscribers get a Rails 8.2 body reading the event payload hash and emitting the same controller_called, template_rendered and sql_query_executed events. EventLogSubscriber skips the framework namespaces so the events Rails already logs are not forwarded a second time. Co-Authored-By: Claude Fable 5.1 --- .../action_controller/log_subscriber.rb | 2 +- .../log_subscriber/logtail_log_subscriber.rb | 47 +++-- .../action_view/log_subscriber.rb | 2 +- .../log_subscriber/logtail_log_subscriber.rb | 167 ++++++++++++------ .../active_record/log_subscriber.rb | 2 +- .../log_subscriber/logtail_log_subscriber.rb | 54 ++++-- .../active_support_log_subscriber.rb | 28 +++ lib/logtail-rails/event_log_subscriber.rb | 12 ++ 8 files changed, 232 insertions(+), 82 deletions(-) diff --git a/lib/logtail-rails/action_controller/log_subscriber.rb b/lib/logtail-rails/action_controller/log_subscriber.rb index 9f7bf33..55409d7 100755 --- a/lib/logtail-rails/action_controller/log_subscriber.rb +++ b/lib/logtail-rails/action_controller/log_subscriber.rb @@ -18,7 +18,7 @@ def integrate! return true if Logtail::Integrations::Rails::ActiveSupportLogSubscriber.subscribed?(:action_controller, LogtailLogSubscriber) Logtail::Integrations::Rails::ActiveSupportLogSubscriber.unsubscribe!(:action_controller, ::ActionController::LogSubscriber) - LogtailLogSubscriber.attach_to(:action_controller) + Logtail::Integrations::Rails::ActiveSupportLogSubscriber.subscribe!(:action_controller, LogtailLogSubscriber) end end end diff --git a/lib/logtail-rails/action_controller/log_subscriber/logtail_log_subscriber.rb b/lib/logtail-rails/action_controller/log_subscriber/logtail_log_subscriber.rb index 7bcbcd2..a8a7809 100755 --- a/lib/logtail-rails/action_controller/log_subscriber/logtail_log_subscriber.rb +++ b/lib/logtail-rails/action_controller/log_subscriber/logtail_log_subscriber.rb @@ -9,21 +9,42 @@ class LogSubscriber < Integrator # # @private class LogtailLogSubscriber < ::ActionController::LogSubscriber - def start_processing(event) - return true if silence? + if ::ActionController::LogSubscriber < ::ActiveSupport::LogSubscriber + def start_processing(event) + return true if silence? - info do - payload = event.payload - params = payload[:params].except(*INTERNAL_PARAMS) - format = extract_format(payload) - format = format.to_s.upcase if format.is_a?(Symbol) + info do + payload = event.payload + params = payload[:params].except(*INTERNAL_PARAMS) + format = extract_format(payload) + format = format.to_s.upcase if format.is_a?(Symbol) - Events::ControllerCall.new( - controller: payload[:controller], - action: payload[:action], - format: format, - params: params - ) + Events::ControllerCall.new( + controller: payload[:controller], + action: payload[:action], + format: format, + params: params + ) + end + end + else + # Rails 8.2+ feeds this subscriber from Rails.event: the event is a hash whose + # payload already comes without the internal params and with the format upcased. + self.namespace = "action_controller" + + def request_started(event) + return true if silence? + + info do + payload = event[:payload] + + Events::ControllerCall.new( + controller: payload[:controller], + action: payload[:action], + format: payload[:format], + params: payload[:params] + ) + end end end diff --git a/lib/logtail-rails/action_view/log_subscriber.rb b/lib/logtail-rails/action_view/log_subscriber.rb index 5334195..02322b8 100755 --- a/lib/logtail-rails/action_view/log_subscriber.rb +++ b/lib/logtail-rails/action_view/log_subscriber.rb @@ -17,7 +17,7 @@ def integrate! return true if Logtail::Integrations::Rails::ActiveSupportLogSubscriber.subscribed?(:action_view, LogtailLogSubscriber) Logtail::Integrations::Rails::ActiveSupportLogSubscriber.unsubscribe!(:action_view, ::ActionView::LogSubscriber) - LogtailLogSubscriber.attach_to(:action_view) + Logtail::Integrations::Rails::ActiveSupportLogSubscriber.subscribe!(:action_view, LogtailLogSubscriber) end end end diff --git a/lib/logtail-rails/action_view/log_subscriber/logtail_log_subscriber.rb b/lib/logtail-rails/action_view/log_subscriber/logtail_log_subscriber.rb index 72eaf13..4aa9ce7 100755 --- a/lib/logtail-rails/action_view/log_subscriber/logtail_log_subscriber.rb +++ b/lib/logtail-rails/action_view/log_subscriber/logtail_log_subscriber.rb @@ -9,51 +9,34 @@ class LogSubscriber < Integrator # # @private class LogtailLogSubscriber < ::ActionView::LogSubscriber - def render_template(event) - return true if silence? - - info do - full_name = from_rails_root(event.payload[:identifier]) - message = " Rendered #{full_name}" - message << " within #{from_rails_root(event.payload[:layout])}" if event.payload[:layout] - message << " (#{event.duration.round(1)}ms)" - - Events::TemplateRender.new( - name: full_name, - duration_ms: event.duration, - message: message - ) - end - end - subscribe_log_level :render_template, :info if defined?(subscribe_log_level) - - def render_partial(event) - return true if silence? - - info do - full_name = from_rails_root(event.payload[:identifier]) - message = " Rendered #{full_name}" - message << " within #{from_rails_root(event.payload[:layout])}" if event.payload[:layout] - message << " (#{event.duration.round(1)}ms)" - message << " #{cache_message(event.payload)}" if event.payload.key?(:cache_hit) - - Events::TemplateRender.new( - name: full_name, - duration_ms: event.duration, - message: message - ) + if ::ActionView::LogSubscriber < ::ActiveSupport::LogSubscriber + def render_template(event) + return true if silence? + + info do + full_name = from_rails_root(event.payload[:identifier]) + message = " Rendered #{full_name}" + message << " within #{from_rails_root(event.payload[:layout])}" if event.payload[:layout] + message << " (#{event.duration.round(1)}ms)" + + Events::TemplateRender.new( + name: full_name, + duration_ms: event.duration, + message: message + ) + end end - end + subscribe_log_level :render_template, :info if defined?(subscribe_log_level) - def render_collection(event) - return true if silence? + def render_partial(event) + return true if silence? - if respond_to?(:render_count, true) info do - identifier = event.payload[:identifier] || "templates" - full_name = from_rails_root(identifier) - message = " Rendered collection of #{full_name}" \ - " #{render_count(event.payload)} (#{event.duration.round(1)}ms)" + full_name = from_rails_root(event.payload[:identifier]) + message = " Rendered #{full_name}" + message << " within #{from_rails_root(event.payload[:layout])}" if event.payload[:layout] + message << " (#{event.duration.round(1)}ms)" + message << " #{cache_message(event.payload)}" if event.payload.key?(:cache_hit) Events::TemplateRender.new( name: full_name, @@ -61,21 +44,99 @@ def render_collection(event) message: message ) end - else - # Older versions of rails delegate this method to #render_template - render_template(event) end - end - def self.attach_to(*) - super + def render_collection(event) + return true if silence? + + if respond_to?(:render_count, true) + info do + identifier = event.payload[:identifier] || "templates" + full_name = from_rails_root(identifier) + message = " Rendered collection of #{full_name}" \ + " #{render_count(event.payload)} (#{event.duration.round(1)}ms)" - if ::Rails::VERSION::MAJOR > 7 || ::Rails::VERSION::MAJOR == 7 && ::Rails::VERSION::MINOR >= 1 - # Clean extra listeners subscribed in parent's attach_to method - ::ActiveSupport::Notifications.notifier.listeners_for("render_template.action_view") - .concat(::ActiveSupport::Notifications.notifier.listeners_for("render_layout.action_view")).flatten - .filter { |listener| listener.delegate.class == ::ActionView::LogSubscriber::Start } - .each { |listener| ActiveSupport::Notifications.unsubscribe(listener) } + Events::TemplateRender.new( + name: full_name, + duration_ms: event.duration, + message: message + ) + end + else + # Older versions of rails delegate this method to #render_template + render_template(event) + end + end + + def self.attach_to(*) + super + + if ::Rails::VERSION::MAJOR > 7 || ::Rails::VERSION::MAJOR == 7 && ::Rails::VERSION::MINOR >= 1 + # Clean extra listeners subscribed in parent's attach_to method + ::ActiveSupport::Notifications.notifier.listeners_for("render_template.action_view") + .concat(::ActiveSupport::Notifications.notifier.listeners_for("render_layout.action_view")).flatten + .filter { |listener| listener.delegate.class == ::ActionView::LogSubscriber::Start } + .each { |listener| ActiveSupport::Notifications.unsubscribe(listener) } + end + end + else + # Rails 8.2+ feeds this subscriber from Rails.event: the event is a hash and the + # payload carries the duration. + self.namespace = "action_view" + + def render_template(event) + return true if silence? + + info do + payload = event[:payload] + full_name = from_rails_root(payload[:identifier]) + message = " Rendered #{full_name}" + message << " within #{from_rails_root(payload[:layout])}" if payload[:layout] + message << " (#{payload[:duration_ms].round(1)}ms)" + + Events::TemplateRender.new( + name: full_name, + duration_ms: payload[:duration_ms], + message: message + ) + end + end + event_log_level :render_template, :info + + def render_partial(event) + return true if silence? + + info do + payload = event[:payload] + full_name = from_rails_root(payload[:identifier]) + message = " Rendered #{full_name}" + message << " within #{from_rails_root(payload[:layout])}" if payload[:layout] + message << " (#{payload[:duration_ms].round(1)}ms)" + message << " #{cache_message(payload)}" unless payload[:cache_hit].nil? + + Events::TemplateRender.new( + name: full_name, + duration_ms: payload[:duration_ms], + message: message + ) + end + end + + def render_collection(event) + return true if silence? + + info do + payload = event[:payload] + full_name = from_rails_root(payload[:identifier] || "templates") + message = " Rendered collection of #{full_name}" \ + " #{render_count(payload)} (#{payload[:duration_ms].round(1)}ms)" + + Events::TemplateRender.new( + name: full_name, + duration_ms: payload[:duration_ms], + message: message + ) + end end end diff --git a/lib/logtail-rails/active_record/log_subscriber.rb b/lib/logtail-rails/active_record/log_subscriber.rb index 8c11be4..a71eb72 100755 --- a/lib/logtail-rails/active_record/log_subscriber.rb +++ b/lib/logtail-rails/active_record/log_subscriber.rb @@ -12,7 +12,7 @@ def integrate! return true if Logtail::Integrations::Rails::ActiveSupportLogSubscriber.subscribed?(:active_record, LogtailLogSubscriber) Logtail::Integrations::Rails::ActiveSupportLogSubscriber.unsubscribe!(:active_record, ::ActiveRecord::LogSubscriber) - LogtailLogSubscriber.attach_to(:active_record) + Logtail::Integrations::Rails::ActiveSupportLogSubscriber.subscribe!(:active_record, LogtailLogSubscriber) end end end diff --git a/lib/logtail-rails/active_record/log_subscriber/logtail_log_subscriber.rb b/lib/logtail-rails/active_record/log_subscriber/logtail_log_subscriber.rb index 6cfe126..0c70cb6 100755 --- a/lib/logtail-rails/active_record/log_subscriber/logtail_log_subscriber.rb +++ b/lib/logtail-rails/active_record/log_subscriber/logtail_log_subscriber.rb @@ -15,26 +15,54 @@ class LogSubscriber < Integrator # # @private class LogtailLogSubscriber < ::ActiveRecord::LogSubscriber - def sql(event) - return true if silence? + if ::ActiveRecord::LogSubscriber < ::ActiveSupport::LogSubscriber + def sql(event) + return true if silence? - r = super(event) + r = super(event) - if @message - payload = event.payload + if @message + payload = event.payload - sql_event = Events::SQLQuery.new( - sql: payload[:sql], - duration_ms: event.duration, - message: @message, - ) + sql_event = Events::SQLQuery.new( + sql: payload[:sql], + duration_ms: event.duration, + message: @message, + ) - logger.debug sql_event + logger.debug sql_event - @message = nil + @message = nil + end + + r end + else + # Rails 8.2+ feeds this subscriber from Rails.event: the event is a hash and the + # payload carries the duration. + self.namespace = "active_record" + + def sql(event) + return true if silence? + + r = super(event) + + if @message + payload = event[:payload] - r + sql_event = Events::SQLQuery.new( + sql: payload[:sql], + duration_ms: payload[:duration_ms], + message: @message, + ) + + logger.debug sql_event + + @message = nil + end + + r + end end private diff --git a/lib/logtail-rails/active_support_log_subscriber.rb b/lib/logtail-rails/active_support_log_subscriber.rb index 89e0c5c..0c826c5 100755 --- a/lib/logtail-rails/active_support_log_subscriber.rb +++ b/lib/logtail-rails/active_support_log_subscriber.rb @@ -6,6 +6,12 @@ module ActiveSupportLogSubscriber extend self def find(component, type) + if event_reporter_subscriber?(type) + return ::ActiveSupport.event_reporter.subscribers.map { |entry| entry[:subscriber] }.find do |subscriber| + subscriber.class == type + end + end + ::ActiveSupport::LogSubscriber.log_subscribers.find do |subscriber| subscriber.class == type end @@ -15,9 +21,25 @@ def subscribed?(component, type) !find(component, type).nil? end + def subscribe!(component, type) + if event_reporter_subscriber?(type) + # Like attach_to below, only deliver the events for the methods the subscriber defines itself + events = type.public_instance_methods(false).map { |method| "#{component}.#{method}" } + ::ActiveSupport.event_reporter.subscribe(type.new) { |event| events.include?(event[:name]) } + return + end + + type.attach_to(component) + end + # I don't know why this has to be so complicated, but it is. This code was taken from # lograge :/ def unsubscribe!(component, type) + if event_reporter_subscriber?(type) + ::ActiveSupport.event_reporter.unsubscribe(type) + return + end + if defined?(type.detach_from) type.detach_from(component) return @@ -38,6 +60,12 @@ def unsubscribe!(component, type) end end end + + # Rails 8.2+ feeds the framework log subscribers from Rails.event instead of + # ActiveSupport::Notifications. + def event_reporter_subscriber?(type) + defined?(::ActiveSupport::EventReporter::LogSubscriber) && type < ::ActiveSupport::EventReporter::LogSubscriber + end end end end diff --git a/lib/logtail-rails/event_log_subscriber.rb b/lib/logtail-rails/event_log_subscriber.rb index 8fddee5..f1131ae 100644 --- a/lib/logtail-rails/event_log_subscriber.rb +++ b/lib/logtail-rails/event_log_subscriber.rb @@ -22,6 +22,7 @@ def initialize(logger) # Rails 8.1 event emission method - called when events are emitted def emit(event) return unless self.class.enabled + return if framework_event?(event) # Log the event with all its data to Rails.logger # Create a structured log entry with the event data @@ -42,6 +43,17 @@ def emit(event) private + # Rails 8.2+ routes the framework's own instrumentation (controller calls, SQL queries, + # template renders, ...) through Rails.event as well. The Rails log subscribers, and ours + # replacing them, already log those, so only the application's own events are forwarded. + def framework_event?(event) + return false unless defined?(::ActiveSupport::EventReporter::LogSubscriber) + + ::ActiveSupport::EventReporter::LogSubscriber.descendants.any? do |log_subscriber| + event[:name].start_with?("#{log_subscriber.namespace}.") + end + end + def build_log_message(event) payload = event[:payload] || {} payload_str = payload.map { |key, value| "#{key}=#{value}" }.join(" ") From 598d5efcc6c077802beff52072692e93e580ebd4 Mon Sep 17 00:00:00 2001 From: Petr Heinz Date: Wed, 23 Sep 2026 16:47:16 +0200 Subject: [PATCH 04/11] Only run the EventLogSubscriber spec where Rails.event exists Nothing subscribes the EventLogSubscriber before Rails 8.1. On Rails 5.0 and 5.1 mattr_accessor ignores the default: option, so its enabled flag is nil there and emit logs nothing. Co-Authored-By: Claude Fable 5.1 --- spec/logtail-rails/event_log_subscriber_spec.rb | 4 ++++ 1 file changed, 4 insertions(+) diff --git a/spec/logtail-rails/event_log_subscriber_spec.rb b/spec/logtail-rails/event_log_subscriber_spec.rb index 5c832da..38d8017 100644 --- a/spec/logtail-rails/event_log_subscriber_spec.rb +++ b/spec/logtail-rails/event_log_subscriber_spec.rb @@ -5,6 +5,10 @@ let(:logger) { Logtail::Logger.new(io) } let(:subscriber) { described_class.new(logger) } + before(:each) do + skip("EventLogSubscriber is only subscribed where Rails.event exists, Rails 8.1 and higher") unless Rails.respond_to?(:event) + end + around(:each) do |example| with_rails_logger(logger) { example.run } end From 50477ac53fa555e33dc432481428076f70d0c221 Mon Sep 17 00:00:00 2001 From: Petr Heinz Date: Wed, 23 Sep 2026 16:47:16 +0200 Subject: [PATCH 05/11] Exclude rails-edge on Ruby 3.2 from CI, Rails main requires Ruby 3.3.1 Co-Authored-By: Claude Fable 5.1 --- .github/workflows/main.yml | 2 ++ 1 file changed, 2 insertions(+) diff --git a/.github/workflows/main.yml b/.github/workflows/main.yml index 68f6695..5add602 100644 --- a/.github/workflows/main.yml +++ b/.github/workflows/main.yml @@ -40,6 +40,8 @@ jobs: - "rails-5.1" - "rails-5.0" exclude: + - gemfile: "rails-edge" + ruby-version: "3.2" - gemfile: "rails-edge" ruby-version: "3.1" - gemfile: "rails-edge" From 97e7ff08abdf2224fc03a397ed1384a209ed384c Mon Sep 17 00:00:00 2001 From: Petr Heinz Date: Tue, 29 Sep 2026 13:09:30 +0200 Subject: [PATCH 06/11] Add failing tests for T-10657: template renders without Rails' debug events Rails 8.2 reports the rendering events to Rails.event in debug mode only, which config.log_level = :info turns off at boot. The template render event the gem logs at info must not depend on that, so the subscriber is expected to take notification events again, like on Rails 8.1 and older. Co-Authored-By: Claude Fable 5.1 --- .../action_view/log_subscriber_spec.rb | 29 ++++++++++++++----- 1 file changed, 22 insertions(+), 7 deletions(-) diff --git a/spec/logtail-rails/action_view/log_subscriber_spec.rb b/spec/logtail-rails/action_view/log_subscriber_spec.rb index 71a14ea..29d0b5e 100755 --- a/spec/logtail-rails/action_view/log_subscriber_spec.rb +++ b/spec/logtail-rails/action_view/log_subscriber_spec.rb @@ -54,6 +54,26 @@ def method_for_action(action_name) expect(lines[2].strip).to match(/Rendered spec\/support\/rails\/templates\/template.html \(\d+\.\d+ms\)/) expect(lines[2]).to include("\"template_rendered\":{\"name\":\"spec/support/rails/templates/template.html\"") end + + if Rails.respond_to?(:event) + # What config.log_level = :info does when the app boots. Rails 8.2 reports the rendering + # events to Rails.event in debug mode only. + context "with the debug mode of Rails.event turned off" do + around(:each) do |example| + debug_mode = Rails.event.debug_mode? + Rails.event.debug_mode = false + example.run + Rails.event.debug_mode = debug_mode + end + + it "should log a template render event once" do + dispatch_rails_request("/action_view_log_subscriber") + lines = clean_lines(io.string.split("\n")) + expect(lines[2].strip).to match(/Rendered spec\/support\/rails\/templates\/template.html \(\d+\.\d+ms\)/) + expect(lines[2]).to include("\"template_rendered\":{\"name\":\"spec/support/rails/templates/template.html\"") + end + end + end end end end @@ -61,13 +81,8 @@ def method_for_action(action_name) if defined?(described_class::LogtailLogSubscriber) describe described_class::LogtailLogSubscriber do let(:event) do - if ::ActionView::LogSubscriber < ::ActiveSupport::LogSubscriber - event = Struct.new(:duration, :payload) - event.new(2.0, identifier: "path/to/template.html") - else - # Rails 8.2+ delivers structured events through ActiveSupport::EventReporter - { name: "action_view.render_template", payload: { identifier: "path/to/template.html", duration_ms: 2.0 } } - end + event = Struct.new(:duration, :payload) + event.new(2.0, identifier: "path/to/template.html") end around(:each) do |example| From 7a28285001f4663390a849989a5fdff736356fbb Mon Sep 17 00:00:00 2001 From: Petr Heinz Date: Tue, 29 Sep 2026 13:10:41 +0200 Subject: [PATCH 07/11] T-10657 Keep logging template renders on Rails 8.2 without debug mode Rails 8.2 reports the rendering events to Rails.event in debug mode only, which config.log_level = :info turns off at boot, so the template render event the gem logs at info went missing in production. The view subscriber listens to the notifications again, like on Rails 8.1 and older. It can no longer extend the default subscriber there, so it brings the log levels, the logger and the helpers that one provided. Co-Authored-By: Claude Fable 5.1 --- .../log_subscriber/logtail_log_subscriber.rb | 188 ++++++++---------- 1 file changed, 85 insertions(+), 103 deletions(-) diff --git a/lib/logtail-rails/action_view/log_subscriber/logtail_log_subscriber.rb b/lib/logtail-rails/action_view/log_subscriber/logtail_log_subscriber.rb index 4aa9ce7..7fb451f 100755 --- a/lib/logtail-rails/action_view/log_subscriber/logtail_log_subscriber.rb +++ b/lib/logtail-rails/action_view/log_subscriber/logtail_log_subscriber.rb @@ -7,36 +7,57 @@ class LogSubscriber < Integrator # The intent of this subscriber is to, as transparently as possible, properly # track events that are being logged here. # + # Until Rails 8.1 it extends the default subscriber. Rails 8.2 turned that one into a + # subscriber of Rails.event, which receives the rendering events in debug mode only, so + # there this subscriber listens to the notifications on its own. + # # @private - class LogtailLogSubscriber < ::ActionView::LogSubscriber - if ::ActionView::LogSubscriber < ::ActiveSupport::LogSubscriber - def render_template(event) - return true if silence? - - info do - full_name = from_rails_root(event.payload[:identifier]) - message = " Rendered #{full_name}" - message << " within #{from_rails_root(event.payload[:layout])}" if event.payload[:layout] - message << " (#{event.duration.round(1)}ms)" - - Events::TemplateRender.new( - name: full_name, - duration_ms: event.duration, - message: message - ) - end + class LogtailLogSubscriber < (::ActionView::LogSubscriber < ::ActiveSupport::LogSubscriber ? ::ActionView::LogSubscriber : ::ActiveSupport::LogSubscriber) + def render_template(event) + return true if silence? + + info do + full_name = from_rails_root(event.payload[:identifier]) + message = " Rendered #{full_name}" + message << " within #{from_rails_root(event.payload[:layout])}" if event.payload[:layout] + message << " (#{event.duration.round(1)}ms)" + + Events::TemplateRender.new( + name: full_name, + duration_ms: event.duration, + message: message + ) + end + end + subscribe_log_level :render_template, :info if defined?(subscribe_log_level) + + def render_partial(event) + return true if silence? + + info do + full_name = from_rails_root(event.payload[:identifier]) + message = " Rendered #{full_name}" + message << " within #{from_rails_root(event.payload[:layout])}" if event.payload[:layout] + message << " (#{event.duration.round(1)}ms)" + message << " #{cache_message(event.payload)}" if event.payload.key?(:cache_hit) + + Events::TemplateRender.new( + name: full_name, + duration_ms: event.duration, + message: message + ) end - subscribe_log_level :render_template, :info if defined?(subscribe_log_level) + end - def render_partial(event) - return true if silence? + def render_collection(event) + return true if silence? + if respond_to?(:render_count, true) info do - full_name = from_rails_root(event.payload[:identifier]) - message = " Rendered #{full_name}" - message << " within #{from_rails_root(event.payload[:layout])}" if event.payload[:layout] - message << " (#{event.duration.round(1)}ms)" - message << " #{cache_message(event.payload)}" if event.payload.key?(:cache_hit) + identifier = event.payload[:identifier] || "templates" + full_name = from_rails_root(identifier) + message = " Rendered collection of #{full_name}" \ + " #{render_count(event.payload)} (#{event.duration.round(1)}ms)" Events::TemplateRender.new( name: full_name, @@ -44,30 +65,13 @@ def render_partial(event) message: message ) end + else + # Older versions of rails delegate this method to #render_template + render_template(event) end + end - def render_collection(event) - return true if silence? - - if respond_to?(:render_count, true) - info do - identifier = event.payload[:identifier] || "templates" - full_name = from_rails_root(identifier) - message = " Rendered collection of #{full_name}" \ - " #{render_count(event.payload)} (#{event.duration.round(1)}ms)" - - Events::TemplateRender.new( - name: full_name, - duration_ms: event.duration, - message: message - ) - end - else - # Older versions of rails delegate this method to #render_template - render_template(event) - end - end - + if superclass == ::ActionView::LogSubscriber def self.attach_to(*) super @@ -80,63 +84,12 @@ def self.attach_to(*) end end else - # Rails 8.2+ feeds this subscriber from Rails.event: the event is a hash and the - # payload carries the duration. - self.namespace = "action_view" - - def render_template(event) - return true if silence? - - info do - payload = event[:payload] - full_name = from_rails_root(payload[:identifier]) - message = " Rendered #{full_name}" - message << " within #{from_rails_root(payload[:layout])}" if payload[:layout] - message << " (#{payload[:duration_ms].round(1)}ms)" - - Events::TemplateRender.new( - name: full_name, - duration_ms: payload[:duration_ms], - message: message - ) - end - end - event_log_level :render_template, :info - - def render_partial(event) - return true if silence? + # The default subscriber used to bring these log levels, the logger and the helpers below + subscribe_log_level :render_partial, :debug + subscribe_log_level :render_collection, :debug - info do - payload = event[:payload] - full_name = from_rails_root(payload[:identifier]) - message = " Rendered #{full_name}" - message << " within #{from_rails_root(payload[:layout])}" if payload[:layout] - message << " (#{payload[:duration_ms].round(1)}ms)" - message << " #{cache_message(payload)}" unless payload[:cache_hit].nil? - - Events::TemplateRender.new( - name: full_name, - duration_ms: payload[:duration_ms], - message: message - ) - end - end - - def render_collection(event) - return true if silence? - - info do - payload = event[:payload] - full_name = from_rails_root(payload[:identifier] || "templates") - message = " Rendered collection of #{full_name}" \ - " #{render_count(payload)} (#{payload[:duration_ms].round(1)}ms)" - - Events::TemplateRender.new( - name: full_name, - duration_ms: payload[:duration_ms], - message: message - ) - end + def logger + ::ActionView::Base.logger end end @@ -151,6 +104,35 @@ def log_rendering_start(*args) def silence? ActionView.silence? end + + unless superclass == ::ActionView::LogSubscriber + def from_rails_root(string) + string = string.sub(rails_root, "") + string.sub!(/^app\/views\//, "") + string + end + + def rails_root + @rails_root ||= "#{::Rails.root}/" + end + + def render_count(payload) + if payload[:cache_hits] + "[#{payload[:cache_hits]} / #{payload[:count]} cache hits]" + else + "[#{payload[:count]} times]" + end + end + + def cache_message(payload) + case payload[:cache_hit] + when :hit + "[cache hit]" + when :miss + "[cache miss]" + end + end + end end end end From d9efe151ee945097bade1cd8c825846973132c39 Mon Sep 17 00:00:00 2001 From: Petr Heinz Date: Tue, 29 Sep 2026 13:10:41 +0200 Subject: [PATCH 08/11] The spec app no longer needs the railties They were loaded for the template root Rails 8.2 sets in an initializer. The view subscriber derives it from Rails.root itself now. Co-Authored-By: Claude Fable 5.1 --- spec/support/rails.rb | 4 ---- 1 file changed, 4 deletions(-) diff --git a/spec/support/rails.rb b/spec/support/rails.rb index ca98cb5..47cef1c 100755 --- a/spec/support/rails.rb +++ b/spec/support/rails.rb @@ -1,8 +1,4 @@ require "rails" -# Rails 8.2+ sets the template root the ActionView log subscribers strip in the action_view.root -# initializer, and the ActionView railtie needs the ActionController one -require "action_controller/railtie" -require "action_view/railtie" require "logtail-rails/railtie" # Default the rails logger to nothing, each test should be From 00ed528c54d579698788b41410ce783250444691 Mon Sep 17 00:00:00 2001 From: Petr Heinz Date: Tue, 29 Sep 2026 13:24:51 +0200 Subject: [PATCH 09/11] Add failing tests for T-10657: SQL queries without Rails' debug events Rails 8.2 reports the SQL events to Rails.event in debug mode only, which follows config.log_level at boot and not the level of the logger. A logger at debug must get the queries either way, bind values included. Co-Authored-By: Claude Fable 5.1 --- .../active_record/log_subscriber_spec.rb | 31 +++++++++++++++++++ 1 file changed, 31 insertions(+) diff --git a/spec/logtail-rails/active_record/log_subscriber_spec.rb b/spec/logtail-rails/active_record/log_subscriber_spec.rb index ba7da80..0b071b3 100755 --- a/spec/logtail-rails/active_record/log_subscriber_spec.rb +++ b/spec/logtail-rails/active_record/log_subscriber_spec.rb @@ -39,6 +39,37 @@ expect(string).to include("\"level\":\"debug\"") expect(string).to include("\"sql_query_executed\":") end + + it "should log the bind values" do + User.where(first_name: "Petr").to_a + expect(io.string).to include('[[\"first_name\", \"Petr\"]]') + end + + if Rails.respond_to?(:event) + # What config.log_level = :info does when the app boots. Rails 8.2 reports the SQL events + # to Rails.event in debug mode only, whatever the level of the logger is. + context "with the debug mode of Rails.event turned off" do + around(:each) do |example| + debug_mode = Rails.event.debug_mode? + Rails.event.debug_mode = false + example.run + Rails.event.debug_mode = debug_mode + end + + it "should log the sql query" do + ActiveRecord::Base.connection.execute("select * from users") + expect(io.string).to include("select * from users") + expect(io.string).to include("duration_ms") + expect(io.string).to include("\"level\":\"debug\"") + expect(io.string).to include("\"sql_query_executed\":") + end + + it "should log the bind values" do + User.where(first_name: "Petr").to_a + expect(io.string).to include('[[\"first_name\", \"Petr\"]]') + end + end + end end end end From 25bc77651fd5b5a5769edc77d19b7180a8b5050e Mon Sep 17 00:00:00 2001 From: Petr Heinz Date: Tue, 29 Sep 2026 13:25:48 +0200 Subject: [PATCH 10/11] T-10657 Keep logging SQL queries on Rails 8.2 without debug mode Rails 8.2 reports the SQL events to Rails.event in debug mode only, which follows config.log_level at boot and not the level of the logger. The record subscriber listens to the notifications again, like on Rails 8.1 and older. Rails split its SQL logging into a translation that renders and filters the binds and a formatting of the line, both are reused as they are, without Rails.event between them. Co-Authored-By: Claude Fable 5.1 --- .../log_subscriber/logtail_log_subscriber.rb | 71 +++++++++++++------ 1 file changed, 48 insertions(+), 23 deletions(-) diff --git a/lib/logtail-rails/active_record/log_subscriber/logtail_log_subscriber.rb b/lib/logtail-rails/active_record/log_subscriber/logtail_log_subscriber.rb index 0c70cb6..ddbcfa9 100755 --- a/lib/logtail-rails/active_record/log_subscriber/logtail_log_subscriber.rb +++ b/lib/logtail-rails/active_record/log_subscriber/logtail_log_subscriber.rb @@ -13,9 +13,13 @@ class LogSubscriber < Integrator # track events that are being logged here. This LogSubscriber will never change # default behavior / log messages. # + # Until Rails 8.1 it extends the default subscriber. Rails 8.2 turned that one into a + # subscriber of Rails.event, which receives the SQL events in debug mode only, so there + # this subscriber listens to the notifications on its own. + # # @private - class LogtailLogSubscriber < ::ActiveRecord::LogSubscriber - if ::ActiveRecord::LogSubscriber < ::ActiveSupport::LogSubscriber + class LogtailLogSubscriber < (::ActiveRecord::LogSubscriber < ::ActiveSupport::LogSubscriber ? ::ActiveRecord::LogSubscriber : ::ActiveSupport::LogSubscriber) + if superclass == ::ActiveRecord::LogSubscriber def sql(event) return true if silence? @@ -37,39 +41,60 @@ def sql(event) r end + + private + def debug(message) + @message = message + end else - # Rails 8.2+ feeds this subscriber from Rails.event: the event is a hash and the - # payload carries the duration. - self.namespace = "active_record" + require "active_record/structured_event_subscriber" - def sql(event) - return true if silence? + # Rails 8.2 split ActiveRecord::LogSubscriber#sql in two: a subscriber that turns the + # notification into an event for Rails.event, rendering and filtering the binds, and + # a log subscriber that formats the event. Both are used here as they are, without + # Rails.event between them. + class Translation < ::ActiveRecord::StructuredEventSubscriber + attr_reader :payload - r = super(event) + def emit_debug_event(name, payload = nil, caller_depth: 1, **kwargs) + @payload = payload || kwargs + end + end - if @message - payload = event[:payload] + class Formatting < ::ActiveRecord::LogSubscriber + attr_reader :message - sql_event = Events::SQLQuery.new( - sql: payload[:sql], - duration_ms: payload[:duration_ms], - message: @message, - ) + private + def debug(message) + @message = message + end + end - logger.debug sql_event + def sql(event) + return true if silence? - @message = nil - end + translation = Translation.new + translation.sql(event) + # Schema and explain queries are not reported + return unless translation.payload - r + formatting = Formatting.new + formatting.sql({ name: "active_record.sql", payload: translation.payload }) + + logger.debug Events::SQLQuery.new( + sql: event.payload[:sql], + duration_ms: event.duration, + message: formatting.message, + ) end - end + subscribe_log_level :sql, :debug - private - def debug(message) - @message = message + def logger + ::ActiveRecord::Base.logger + end end + private def silence? ActiveRecord.silence? end From 788ef9f793eea26fec8567b9a087827d1f39e159 Mon Sep 17 00:00:00 2001 From: Petr Heinz Date: Wed, 30 Sep 2026 17:51:57 +0200 Subject: [PATCH 11/11] CI: green matrix on Rails 7.1 to 8.0 and TruffleRuby, add Ruby 4.0 (#57) Co-authored-by: Claude Fable 5.1 --- .github/workflows/main.yml | 11 +++++++---- gemfiles/rails-7.1.gemfile | 2 ++ gemfiles/rails-7.2.gemfile | 4 +++- gemfiles/rails-8.0.gemfile | 3 ++- gemfiles/rails-8.1.gemfile | 1 - gemfiles/rails-edge.gemfile | 1 - logtail-rails.gemspec | 5 ++++- 7 files changed, 18 insertions(+), 9 deletions(-) diff --git a/.github/workflows/main.yml b/.github/workflows/main.yml index 5add602..01ddc7c 100644 --- a/.github/workflows/main.yml +++ b/.github/workflows/main.yml @@ -18,6 +18,7 @@ jobs: matrix: ruby-version: + - "4.0" - "3" - "3.3" - "3.2" @@ -52,8 +53,6 @@ jobs: ruby-version: "2.6" - gemfile: "rails-edge" ruby-version: "2.5" - - gemfile: "rails-8.1" - ruby-version: "truffleruby" - gemfile: "rails-8.1" ruby-version: "3.1" @@ -65,8 +64,6 @@ jobs: ruby-version: "2.6" - gemfile: "rails-8.1" ruby-version: "2.5" - - gemfile: "rails-8.1" - ruby-version: "truffleruby" - gemfile: "rails-8.0" ruby-version: "3.1" @@ -98,6 +95,8 @@ jobs: - gemfile: "rails-7.0" ruby-version: "2.5" + - gemfile: "rails-5.2" + ruby-version: "4.0" - gemfile: "rails-5.2" ruby-version: "3" - gemfile: "rails-5.2" @@ -111,6 +110,8 @@ jobs: - gemfile: "rails-5.2" ruby-version: "truffleruby" + - gemfile: "rails-5.1" + ruby-version: "4.0" - gemfile: "rails-5.1" ruby-version: "3" - gemfile: "rails-5.1" @@ -124,6 +125,8 @@ jobs: - gemfile: "rails-5.1" ruby-version: "truffleruby" + - gemfile: "rails-5.0" + ruby-version: "4.0" - gemfile: "rails-5.0" ruby-version: "3" - gemfile: "rails-5.0" diff --git a/gemfiles/rails-7.1.gemfile b/gemfiles/rails-7.1.gemfile index 13f0883..83ac20c 100755 --- a/gemfiles/rails-7.1.gemfile +++ b/gemfiles/rails-7.1.gemfile @@ -5,6 +5,8 @@ gem 'sidekiq', '>= 7.3.0', require: false if RUBY_VERSION >= '2.7.0' gem 'logtail' gem 'logtail-rack' +# ActiveSupport passes quirks_mode to JSON.generate until 7.2.4 and 8.1, json 3 no longer accepts it +gem 'json', '< 3' if RUBY_PLATFORM == "java" gem 'mime-types', '2.6.2' diff --git a/gemfiles/rails-7.2.gemfile b/gemfiles/rails-7.2.gemfile index 0a9637b..2a86de7 100644 --- a/gemfiles/rails-7.2.gemfile +++ b/gemfiles/rails-7.2.gemfile @@ -1,6 +1,8 @@ source 'https://rubygems.org' -gem 'rails', '~> 7.2.0' +# 7.2.4 is the first release that works with json 3. Without the floor, Bundler prefers +# minitest 6 over it and settles for Rails 7.2.3. +gem 'rails', '~> 7.2.4' gem 'sidekiq', '>= 7.3.0', require: false gem 'logtail' diff --git a/gemfiles/rails-8.0.gemfile b/gemfiles/rails-8.0.gemfile index 6b3342f..d34482f 100755 --- a/gemfiles/rails-8.0.gemfile +++ b/gemfiles/rails-8.0.gemfile @@ -5,6 +5,7 @@ gem 'sidekiq', '>= 7.3.0', require: false gem 'logtail' gem 'logtail-rack' -gem "sqlite3", ">= 2.0" +# ActiveSupport passes quirks_mode to JSON.generate until 7.2.4 and 8.1, json 3 no longer accepts it +gem 'json', '< 3' gemspec :path => '../' diff --git a/gemfiles/rails-8.1.gemfile b/gemfiles/rails-8.1.gemfile index f9657d3..03b4e39 100755 --- a/gemfiles/rails-8.1.gemfile +++ b/gemfiles/rails-8.1.gemfile @@ -5,6 +5,5 @@ gem 'sidekiq', '>= 7.3.0', require: false gem 'logtail' gem 'logtail-rack' -gem "sqlite3", ">= 2.0" gemspec :path => '../' diff --git a/gemfiles/rails-edge.gemfile b/gemfiles/rails-edge.gemfile index e4caa85..ac2df52 100755 --- a/gemfiles/rails-edge.gemfile +++ b/gemfiles/rails-edge.gemfile @@ -5,7 +5,6 @@ gem 'sidekiq', '>= 7.3.0', require: false if RUBY_VERSION >= '2.7.0' gem 'logtail' gem 'logtail-rack' -gem "sqlite3", ">= 2.0" if RUBY_PLATFORM == "java" gem 'mime-types', '2.6.2' diff --git a/logtail-rails.gemspec b/logtail-rails.gemspec index b9c8c7b..f3faf7f 100644 --- a/logtail-rails.gemspec +++ b/logtail-rails.gemspec @@ -58,7 +58,10 @@ Gem::Specification.new do |spec| spec.add_development_dependency('activerecord-jdbcsqlite3-adapter', '>= 0') elsif rails_version >= 3 && rails_version < 6 spec.add_development_dependency('sqlite3', '1.3.13') - else + elsif rails_version >= 6 && rails_version < 8 spec.add_development_dependency('sqlite3', '~> 1.5.0') + else + # Rails 8 and newer, which is also what rails-edge and the root Gemfile resolve to + spec.add_development_dependency('sqlite3', '>= 2.0') end end