[rails] add structured logger subscribers

Author: solnic

Gemfile.dev

@@ -26,7 +26,6 @@ if RUBY_VERSION >= "3.4"
   gem "benchmark"
   gem "base64"
   gem "ostruct"
-  gem "psych"
 end
 
 # For RSpec

sentry-rails/Gemfile

@@ -63,6 +63,10 @@ if ruby_version < Gem::Version.new("2.5.0")
   gem "loofah", "2.20.0"
 end
 
+if rails_version >= Gem::Version.new("7.1")
+  gem "psych", "~> 4.0.0"
+end
+
 gem "mini_magick"
 
 gem "sprockets-rails"

sentry-rails/lib/sentry/rails.rb

@@ -5,6 +5,7 @@
 require "sentry/integrable"
 require "sentry/rails/tracing"
 require "sentry/rails/configuration"
+require "sentry/rails/structured_logging"
 require "sentry/rails/engine"
 require "sentry/rails/railtie"
 

sentry-rails/lib/sentry/rails/configuration.rb

@@ -159,6 +159,25 @@ class Configuration
       # Set this option to true if you want Sentry to capture each retry failure
       attr_accessor :active_job_report_on_retry_error
 
+      # Configuration for structured logging feature
+      # @return [StructuredLoggingConfiguration]
+      attr_reader :structured_logging
+
+      # Allow setting structured_logging as a boolean for convenience
+      # @param value [Boolean, StructuredLoggingConfiguration]
+      def structured_logging=(value)
+        case value
+        when true
+          @structured_logging.enable = true
+        when false
+          @structured_logging.enabled = false
+        when StructuredLoggingConfiguration
+          @structured_logging = value
+        else
+          raise ArgumentError, "structured_logging must be a boolean or StructuredLoggingConfiguration"
+        end
+      end
+
       def initialize
         @register_error_subscriber = false
         @report_rescued_exceptions = true
@@ -176,6 +195,29 @@ def initialize
         @db_query_source_threshold_ms = 100
         @active_support_logger_subscription_items = Sentry::Rails::ACTIVE_SUPPORT_LOGGER_SUBSCRIPTION_ITEMS_DEFAULT.dup
         @active_job_report_on_retry_error = false
+        @structured_logging = StructuredLoggingConfiguration.new
+      end
+    end
+
+    class StructuredLoggingConfiguration
+      # Enable or disable structured logging
+      # @return [Boolean]
+      attr_accessor :enabled
+
+      # Array of components to attach structured logging to
+      # Supported values: [:active_record, :action_controller, :action_mailer, :active_job]
+      # @return [Array<Symbol>]
+      attr_accessor :attach_to
+
+      def initialize
+        @enabled = false
+        @attach_to = []
+      end
+
+      # Check if structured logging is enabled
+      # @return [Boolean]
+      def enabled?
+        @enabled
       end
     end
   end

sentry-rails/lib/sentry/rails/log_subscriber.rb

@@ -0,0 +1,90 @@
+# frozen_string_literal: true
+
+require "active_support/log_subscriber"
+
+module Sentry
+  module Rails
+    # Base class for Sentry log subscribers that extends ActiveSupport::LogSubscriber
+    # to provide structured logging capabilities for Rails components.
+    #
+    # This class follows Rails' LogSubscriber pattern and provides common functionality
+    # for capturing Rails instrumentation events and logging them through Sentry's
+    # structured logging system.
+    #
+    # @example Creating a custom log subscriber
+    #   class MySubscriber < Sentry::Rails::LogSubscriber
+    #     attach_to :my_component
+    #
+    #     def my_event(event)
+    #       log_structured_event(
+    #         message: "My event occurred",
+    #         level: :info,
+    #         attributes: {
+    #           duration_ms: event.duration,
+    #           custom_data: event.payload[:custom_data]
+    #         }
+    #       )
+    #     end
+    #   end
+    class LogSubscriber < ActiveSupport::LogSubscriber
+      class << self
+        if ::Rails.version.to_f < 6.0
+          # Rails 5.x does not provide detach_from
+          def detach_from(namespace, notifications = ActiveSupport::Notifications)
+            listeners = public_instance_methods(false)
+              .flat_map { |key|
+                notifications.notifier.listeners_for("#{key}.#{namespace}")
+              }
+              .select { |listener| listener.instance_variable_get(:@delegate).is_a?(self) }
+
+            listeners.map do |listener|
+              notifications.notifier.unsubscribe(listener)
+            end
+          end
+        end
+      end
+
+      protected
+
+      # Log a structured event using Sentry's structured logger
+      #
+      # @param message [String] The log message
+      # @param level [Symbol] The log level (:trace, :debug, :info, :warn, :error, :fatal)
+      # @param attributes [Hash] Additional structured attributes to include
+      def log_structured_event(message:, level: :info, attributes: {})
+        Sentry.logger.public_send(level, message, **attributes)
+      rescue => e
+        # Silently handle any errors in logging to avoid breaking the application
+        Sentry.configuration.sdk_logger.debug("Failed to log structured event: #{e.message}")
+      end
+
+      # Check if an event should be excluded from logging
+      #
+      # @param event [ActiveSupport::Notifications::Event] The event to check
+      # @return [Boolean] true if the event should be excluded
+      def excluded_event?(event)
+        # Skip Rails' internal events
+        return true if event.name.start_with?("!")
+
+        false
+      end
+
+      # Calculate duration in milliseconds from an event
+      #
+      # @param event [ActiveSupport::Notifications::Event] The event
+      # @return [Float] Duration in milliseconds
+      def duration_ms(event)
+        event.duration.round(2)
+      end
+
+      # Determine log level based on duration (for performance-sensitive events)
+      #
+      # @param duration_ms [Float] Duration in milliseconds
+      # @param slow_threshold [Float] Threshold in milliseconds to consider "slow"
+      # @return [Symbol] Log level (:info or :warn)
+      def level_for_duration(duration_ms, slow_threshold = 1000.0)
+        duration_ms > slow_threshold ? :warn : :info
+      end
+    end
+  end
+end

sentry-rails/lib/sentry/rails/log_subscribers/action_controller_subscriber.rb

@@ -0,0 +1,116 @@
+# frozen_string_literal: true
+
+require "sentry/rails/log_subscriber"
+require "sentry/rails/log_subscribers/parameter_filter"
+
+module Sentry
+  module Rails
+    module LogSubscribers
+      # LogSubscriber for ActionController events that captures HTTP request processing
+      # and logs them using Sentry's structured logging system.
+      #
+      # This subscriber captures process_action.action_controller events and formats them
+      # with relevant request information including controller, action, HTTP status,
+      # request parameters, and performance metrics.
+      #
+      # @example Usage
+      #   # Enable structured logging for ActionController
+      #   Sentry.init do |config|
+      #     config.enable_logs = true
+      #     config.rails.structured_logging = true
+      #     config.rails.structured_logging.attach_to = [:action_controller]
+      #   end
+      class ActionControllerSubscriber < Sentry::Rails::LogSubscriber
+        include ParameterFilter
+
+        # Handle process_action.action_controller events
+        #
+        # @param event [ActiveSupport::Notifications::Event] The controller action event
+        def process_action(event)
+          return if excluded_event?(event)
+
+          payload = event.payload
+          duration = event.time.round(2)
+
+          controller = payload[:controller]
+          action = payload[:action]
+
+          status = extract_status(payload)
+
+          attributes = {
+            controller: controller,
+            action: action,
+            status: status,
+            duration_ms: duration,
+            method: payload[:method],
+            path: payload[:path],
+            format: payload[:format]
+          }
+
+          if payload[:view_runtime]
+            attributes[:view_runtime_ms] = payload[:view_runtime].round(2)
+          end
+
+          if payload[:db_runtime]
+            attributes[:db_runtime_ms] = payload[:db_runtime].round(2)
+          end
+
+          if Sentry.configuration.send_default_pii && payload[:params]
+            filtered_params = filter_sensitive_params(payload[:params])
+            attributes[:params] = filtered_params unless filtered_params.empty?
+          end
+
+          level = level_for_request(payload)
+          message = "#{controller}##{action}"
+
+          log_structured_event(
+            message: message,
+            level: level,
+            attributes: attributes
+          )
+        end
+
+        private
+
+        def extract_status(payload)
+          if payload[:status]
+            payload[:status]
+          elsif payload[:exception]
+            case payload[:exception].first
+            when "ActionController::RoutingError"
+              404
+            when "ActionController::BadRequest"
+              400
+            else
+              500
+            end
+          end
+        end
+
+        def level_for_request(payload)
+          status = payload[:status]
+
+          # In Rails < 6.0 status is not set when an action raised an exception
+          if status.nil? && payload[:exception]
+            case payload[:exception].first
+            when "ActionController::RoutingError"
+              :warn
+            when "ActionController::BadRequest"
+              :warn
+            else
+              :error
+            end
+          elsif status >= 200 && status < 400
+            :info
+          elsif status >= 400 && status < 500
+            :warn
+          elsif status >= 500
+            :error
+          else
+            :info
+          end
+        end
+      end
+    end
+  end
+end

sentry-rails/lib/sentry/rails/log_subscribers/action_mailer_subscriber.rb

@@ -0,0 +1,105 @@
+# frozen_string_literal: true
+
+require "sentry/rails/log_subscriber"
+require "sentry/rails/log_subscribers/parameter_filter"
+
+module Sentry
+  module Rails
+    module LogSubscribers
+      # LogSubscriber for ActionMailer events that captures email delivery
+      # and processing events using Sentry's structured logging system.
+      #
+      # This subscriber captures deliver.action_mailer and process.action_mailer events
+      # and formats them with relevant email information while respecting PII settings.
+      #
+      # @example Usage
+      #   # Enable structured logging for ActionMailer
+      #   Sentry.init do |config|
+      #     config.enable_logs = true
+      #     config.rails.structured_logging = true
+      #     config.rails.structured_logging.attach_to = [:action_mailer]
+      #   end
+      class ActionMailerSubscriber < Sentry::Rails::LogSubscriber
+        include ParameterFilter
+
+        # Handle deliver.action_mailer events
+        #
+        # @param event [ActiveSupport::Notifications::Event] The email delivery event
+        def deliver(event)
+          return if excluded_event?(event)
+
+          payload = event.payload
+          mailer = payload[:mailer]
+          duration = duration_ms(event)
+
+          # Prepare structured attributes
+          attributes = {
+            mailer: mailer,
+            duration_ms: duration,
+            perform_deliveries: payload[:perform_deliveries]
+          }
+
+          # Add delivery method if available
+          attributes[:delivery_method] = payload[:delivery_method] if payload[:delivery_method]
+
+          # Add date if available
+          attributes[:date] = payload[:date].to_s if payload[:date]
+
+          # Only include email details if PII is allowed
+          if Sentry.configuration.send_default_pii
+            # Note: We're being very conservative here and not including
+            # to, from, subject, or body to avoid PII leakage
+            # Users can customize this behavior by extending the subscriber
+            attributes[:message_id] = payload[:message_id] if payload[:message_id]
+          end
+
+          message = "Email delivered via #{mailer}"
+
+          # Log the structured event
+          log_structured_event(
+            message: message,
+            level: :info,
+            attributes: attributes
+          )
+        end
+
+        # Handle process.action_mailer events
+        #
+        # @param event [ActiveSupport::Notifications::Event] The email processing event
+        def process(event)
+          return if excluded_event?(event)
+
+          payload = event.payload
+          mailer = payload[:mailer]
+          action = payload[:action]
+          duration = duration_ms(event)
+
+          # Prepare structured attributes
+          attributes = {
+            mailer: mailer,
+            action: action,
+            duration_ms: duration
+          }
+
+          # Add parameters if PII is allowed and they exist
+          if Sentry.configuration.send_default_pii && payload[:params]
+            # Filter sensitive parameters
+            filtered_params = filter_sensitive_params(payload[:params])
+            attributes[:params] = filtered_params unless filtered_params.empty?
+          end
+
+          message = "#{mailer}##{action}"
+
+          # Log the structured event
+          log_structured_event(
+            message: message,
+            level: :info,
+            attributes: attributes
+          )
+        end
+
+        private
+      end
+    end
+  end
+end