diff --git a/actionpack/lib/action_dispatch.rb b/actionpack/lib/action_dispatch.rb index 24107c901b15c..554053219ff2f 100644 --- a/actionpack/lib/action_dispatch.rb +++ b/actionpack/lib/action_dispatch.rb @@ -70,6 +70,7 @@ class MissingController < NameError autoload :HostAuthorization autoload :RequestId autoload :Callbacks + autoload :ClearEventReporterContext autoload :Cookies autoload :ActionableExceptions autoload :DebugExceptions diff --git a/actionpack/lib/action_dispatch/middleware/clear_event_reporter_context.rb b/actionpack/lib/action_dispatch/middleware/clear_event_reporter_context.rb new file mode 100644 index 0000000000000..1dfffdf0e75ae --- /dev/null +++ b/actionpack/lib/action_dispatch/middleware/clear_event_reporter_context.rb @@ -0,0 +1,26 @@ +# frozen_string_literal: true + +module ActionDispatch + # Middleware that sets up a callback on rack.response_finished to clear + # the EventReporter context when the response is finished. This ensures that + # context is cleared as late as possible in the request lifecycle. + class ClearEventReporterContext # :nodoc: + def initialize(app) + @app = app + end + + def call(env) + response = @app.call(env) + + env["rack.response_finished"] ||= [] + env["rack.response_finished"] << -> do + ActiveSupport.event_reporter.clear_context + end + + response + rescue Exception => e + ActiveSupport.event_reporter.clear_context + raise e + end + end +end diff --git a/actionpack/test/dispatch/clear_event_reporter_context_test.rb b/actionpack/test/dispatch/clear_event_reporter_context_test.rb new file mode 100644 index 0000000000000..ac36a32c0a854 --- /dev/null +++ b/actionpack/test/dispatch/clear_event_reporter_context_test.rb @@ -0,0 +1,39 @@ +# frozen_string_literal: true + +require "abstract_unit" + +class ClearEventReporterContextTest < ActiveSupport::TestCase + def setup + @app = ->(env) { [200, {}, ["Hello"]] } + @middleware = ActionDispatch::ClearEventReporterContext.new(@app) + @reporter = ActiveSupport.event_reporter + end + + test "clears event reporter context in response finished callback" do + @reporter.set_context(shop_id: 123) + + env = {} + @middleware.call(env) + + assert env["rack.response_finished"] + assert_equal 1, env["rack.response_finished"].length + + env["rack.response_finished"].each(&:call) + + assert_equal({}, @reporter.context) + end + + test "clears event reporter context when exception is raised" do + @reporter.set_context(shop_id: 123) + + exception_app = ->(env) { raise StandardError, "Test exception" } + exception_middleware = ActionDispatch::ClearEventReporterContext.new(exception_app) + + env = {} + assert_raises(StandardError) do + exception_middleware.call(env) + end + + assert_equal({}, @reporter.context) + end +end diff --git a/activejob/lib/active_job/railtie.rb b/activejob/lib/active_job/railtie.rb index d8624ba7b9822..b45874acd61ce 100644 --- a/activejob/lib/active_job/railtie.rb +++ b/activejob/lib/active_job/railtie.rb @@ -98,6 +98,16 @@ class Railtie < Rails::Railtie # :nodoc: end end + initializer "active_job.clear_event_reporter_context" do + ActiveSupport.on_load(:active_job) do + ActiveJob::Callbacks.singleton_class.set_callback(:execute, :around) do |_, inner| + inner.call + ensure + ActiveSupport.event_reporter.clear_context + end + end + end + initializer "active_job.query_log_tags" do |app| query_logs_tags_enabled = app.config.respond_to?(:active_record) && app.config.active_record.query_log_tags_enabled && diff --git a/activesupport/CHANGELOG.md b/activesupport/CHANGELOG.md index 2e57ef044b9d7..c24a7482d124a 100644 --- a/activesupport/CHANGELOG.md +++ b/activesupport/CHANGELOG.md @@ -1,3 +1,44 @@ +* Add Structured Event Reporter, accessible via `Rails.event`. + + The Event Reporter provides a unified interface for producing structured events in Rails + applications: + + ```ruby + Rails.event.notify("user.signup", user_id: 123, email: "user@example.com") + ``` + + It supports adding tags to events: + + ```ruby + Rails.event.tagged("graphql") do + # Event includes tags: { graphql: true } + Rails.event.notify("user.signup", user_id: 123, email: "user@example.com") + end + ``` + + As well as context: + ```ruby + # All events will contain context: {request_id: "abc123", shop_id: 456} + Rails.event.set_context(request_id: "abc123", shop_id: 456) + ``` + + Events are emitted to subscribers. Applications register subscribers to + control how events are serialized and emitted. Rails provides several default + encoders that can be used to serialize events to common formats: + + ```ruby + class MySubscriber + def emit(event) + encoded_event = ActiveSupport::EventReporter.encoder(:json).encode(event) + StructuredLogExporter.export(encoded_event) + end + end + + Rails.event.subscribe(MySubscriber.new) + ``` + + *Adrianna Chang* + * Make `ActiveSupport::Gzip.compress` deterministic based on input. `ActiveSupport::Gzip.compress` used to include a timestamp in the output, diff --git a/activesupport/lib/active_support.rb b/activesupport/lib/active_support.rb index c62972ec52e2f..f8ed8a835b364 100644 --- a/activesupport/lib/active_support.rb +++ b/activesupport/lib/active_support.rb @@ -48,6 +48,7 @@ module ActiveSupport autoload :ExecutionWrapper autoload :Executor autoload :ErrorReporter + autoload :EventReporter autoload :FileUpdateChecker autoload :EventedFileUpdateChecker autoload :ForkTracker @@ -110,6 +111,11 @@ def self.eager_load! @error_reporter = ActiveSupport::ErrorReporter.new singleton_class.attr_accessor :error_reporter # :nodoc: + @event_reporter = ActiveSupport::EventReporter.new + singleton_class.attr_accessor :event_reporter # :nodoc: + + cattr_accessor :filter_parameters, default: [] # :nodoc: + def self.cache_format_version Cache.format_version end diff --git a/activesupport/lib/active_support/event_reporter.rb b/activesupport/lib/active_support/event_reporter.rb new file mode 100644 index 0000000000000..5341cb72fcdcb --- /dev/null +++ b/activesupport/lib/active_support/event_reporter.rb @@ -0,0 +1,516 @@ +# typed: true +# frozen_string_literal: true + +require "active_support/core_ext/hash/indifferent_access" +require_relative "event_reporter/encoders" + +module ActiveSupport + class TagStack # :nodoc: + EMPTY_TAGS = {}.with_indifferent_access.freeze + FIBER_KEY = :event_reporter_tags + + class << self + def tags + Fiber[FIBER_KEY] || EMPTY_TAGS + end + + def with_tags(*args, **kwargs) + existing_tags = tags + tags = existing_tags.dup + tags.merge!(resolve_tags(args, kwargs)) + new_tags = tags.freeze + + begin + Fiber[FIBER_KEY] = new_tags + yield + ensure + Fiber[FIBER_KEY] = existing_tags + end + end + + private + def resolve_tags(args, kwargs) + tags = {}.with_indifferent_access + + args.each do |arg| + case arg + when String, Symbol + tags[arg] = true + when Hash + arg.each { |key, value| tags[key] = value } + else + tags[arg.class.name] = arg + end + end + + kwargs.each { |key, value| tags[key] = value } + tags + end + end + end + + class EventContext # :nodoc: + EMPTY_CONTEXT = {}.with_indifferent_access.freeze + FIBER_KEY = :event_reporter_context + + class << self + def context + Fiber[FIBER_KEY] || EMPTY_CONTEXT + end + + def set_context(context_hash) + new_context = self.context.dup + context_hash.each { |key, value| new_context[key] = value } + + Fiber[FIBER_KEY] = new_context.freeze + end + + def clear + Fiber[FIBER_KEY] = EMPTY_CONTEXT + end + end + end + + # = Active Support \Event Reporter + # + # +ActiveSupport::EventReporter+ provides an interface for reporting structured events to subscribers. + # + # To report an event, you can use the +notify+ method: + # + # Rails.event.notify("user_created", { id: 123 }) + # # Emits event: + # # { + # # name: "user_created", + # # payload: { id: 123 }, + # # timestamp: 1738964843208679035, + # # source_location: { filepath: "path/to/file.rb", lineno: 123, label: "UserService#create" } + # # } + # + # The +notify+ API can receive either an event name and a payload hash, or an event object. + + # ==== Event Objects + # + # If an event object is passed to the +notify+ API, it will be passed through to subscribers as-is, and the name of the + # object's class will be used as the event name. + # + # class UserCreatedEvent + # def initialize(id:, name:) + # @id = id + # @name = name + # end + # + # def to_h + # { + # id: @id, + # name: @name + # } + # end + # end + # + # Rails.event.notify(UserCreatedEvent.new(id: 123, name: "John Doe")) + # # Emits event: + # # { + # # name: "UserCreatedEvent", + # # payload: #, + # # timestamp: 1738964843208679035, + # # source_location: { filepath: "path/to/file.rb", lineno: 123, label: "UserService#create" } + # # } + # + # An event is any Ruby object representing a schematized event. While payload hashes allow arbitrary, + # implicitly-structured data, event objects are intended to enforce a particular schema. + # + # ==== Default Encoders + # + # Rails provides default encoders for common serialization formats. Event objects and tags MUST + # implement +to_h+ to be serialized. + # + # class JSONLogSubscriber + # def emit(event) + # # event = { name: "UserCreatedEvent", payload: { UserCreatedEvent: # } } + # json_data = ActiveSupport::EventReporter.encoder(:json).encode(event) + # # => { + # # "name": "UserCreatedEvent", + # # "payload": { + # # "id": 123, + # # "name": "John Doe" + # # } + # # } + # Rails.logger.info(json_data) + # end + # end + # + # class MessagePackSubscriber + # def emit(event) + # msgpack_data = ActiveSupport::EventReporter.encoder(:msgpack).encode(event) + # BatchExporter.export(msgpack_data) + # end + # end + # + # ==== Debug Events + # + # You can use the +debug+ method to report an event that will only be reported if the + # event reporter is in debug mode: + # + # Rails.event.debug("my_debug_event", { foo: "bar" }) + # + # ==== Tags + # + # To add additional context to an event, separate from the event payload, you can add + # tags via the +tagged+ method: + # + # Rails.event.tagged("graphql") do + # Rails.event.notify("user_created", { id: 123 }) + # end + # + # # Emits event: + # # { + # # name: "user_created", + # # payload: { id: 123 }, + # # tags: { graphql: true }, + # # timestamp: 1738964843208679035, + # # source_location: { filepath: "path/to/file.rb", lineno: 123, label: "UserService#create" } + # # } + # + # ==== Context Store + # + # You may want to attach metadata to every event emitted by the reporter. While tags + # provide domain-specific context for a series of events, context is scoped to the job / request + # and should be used for metadata associated with the execution context. + # Context can be set via the +set_context+ method: + # + # Rails.event.set_context(request_id: "abcd123", user_agent: "TestAgent") + # Rails.event.notify("user_created", { id: 123 }) + # + # # Emits event: + # # { + # # name: "user_created", + # # payload: { id: 123 }, + # # context: { request_id: "abcd123", user_agent: TestAgent" }, + # # timestamp: 1738964843208679035, + # # source_location: { filepath: "path/to/file.rb", lineno: 123, label: "UserService#create" } + # # } + # + # Context is reset automatically before and after each request. + # + # A custom context store can be configured via `config.active_support.event_reporter_context_store`. + # + # # config/application.rb + # config.active_support.event_reporter_context_store = CustomContextStore + # + # class CustomContextStore + # class << self + # def context + # # Return the context. + # end + # + # def set_context(context_hash) + # # Append context_hash to the existing context store. + # end + # + # def clear + # # Delete the stored context. + # end + # end + # end + # + class EventReporter + attr_reader :subscribers + attr_accessor :raise_on_error + + class << self + attr_accessor :context_store # :nodoc: + + # Lookup an encoder by name or symbol + # + # ActiveSupport::EventReporter.encoder(:json) + # # => ActiveSupport::EventReporter::Encoders::JSON + # + # ActiveSupport::EventReporter.encoder("msgpack") + # # => ActiveSupport::EventReporter::Encoders::MessagePack + # + # ==== Arguments + # + # * +format+ - The encoder format as a symbol or string + # + # ==== Raises + # + # * +KeyError+ - If the encoder format is not found + def encoder(format) + encoders = { + json: Encoders::JSON, + msgpack: Encoders::MessagePack + } + encoders.fetch(format.to_sym) do + raise KeyError, "Unknown encoder format: #{format.inspect}. Available formats: #{encoders.keys.join(', ')}" + end + end + end + + self.context_store = EventContext + + def initialize(*subscribers, raise_on_error: false, tags: nil) + @subscribers = [] + subscribers.each { |subscriber| subscribe(subscriber) } + @raise_on_error = raise_on_error + end + + # Registers a new event subscriber. The subscriber must respond to + # + # emit(event: Hash) + # + # The event hash will have the following keys: + # + # name: String (The name of the event) + # payload: Hash, Object (The payload of the event, or the event object itself) + # tags: Hash (The tags of the event) + # timestamp: Float (The timestamp of the event, in nanoseconds) + # source_location: Hash (The source location of the event, containing the filepath, lineno, and label) + # + def subscribe(subscriber) + unless subscriber.respond_to?(:emit) + raise ArgumentError, "Event subscriber #{subscriber.class.name} must respond to #emit" + end + + @subscribers << subscriber + end + + # Reports an event to all registered subscribers. An event name and payload can be provided: + # + # Rails.event.notify("user.created", { id: 123 }) + # # Emits event: + # # { + # # name: "user.created", + # # payload: { id: 123 }, + # # tags: {}, + # # timestamp: 1738964843208679035, + # # source_location: { filepath: "path/to/file.rb", lineno: 123, label: "UserService#create" } + # # } + # + # Note that the payload is converted to a HashWithIndifferentAccess, so keys can be accessed as strings or symbols. + # + # Alternatively, an event object can be provided: + # + # Rails.event.notify(UserCreatedEvent.new(id: 123)) + # # Emits event: + # # { + # # name: "UserCreatedEvent", + # # payload: #, + # # tags: {}, + # # timestamp: 1738964843208679035, + # # source_location: { filepath: "path/to/file.rb", lineno: 123, label: "UserService#create" } + # # } + # + # ==== Arguments + # + # * +:payload+ - The event payload when using string/symbol event names. + # + # * +:caller_depth+ - The stack depth to use for source location (default: 1). + # + # * +:kwargs+ - Additional payload data when using string/symbol event names. + def notify(name_or_object, payload = nil, caller_depth: 1, **kwargs) + name = resolve_name(name_or_object) + payload = resolve_payload(name_or_object, payload, **kwargs) + + event = { + name: name, + payload: payload, + tags: TagStack.tags, + context: context_store.context, + timestamp: Process.clock_gettime(Process::CLOCK_REALTIME, :nanosecond), + } + + caller_location = caller_locations(caller_depth, 1)&.first + + if caller_location + source_location = { + filepath: caller_location.path, + lineno: caller_location.lineno, + label: caller_location.label, + } + event[:source_location] = source_location + end + + subscribers.each do |subscriber| + subscriber.emit(event) + rescue => subscriber_error + if raise_on_error + raise + else + warn(<<~MESSAGE) + Event reporter subscriber #{subscriber.class.name} raised an error on #emit: #{subscriber_error.message} + #{subscriber_error.backtrace&.join("\n")} + MESSAGE + end + end + end + + # Temporarily enables debug mode for the duration of the block. + # Calls to +debug+ will only be reported if debug mode is enabled. + # + # Rails.event.with_debug do + # Rails.event.debug("sql.query", { sql: "SELECT * FROM users" }) + # end + def with_debug + prior = Fiber[:event_reporter_debug_mode] + Fiber[:event_reporter_debug_mode] = true + yield + ensure + Fiber[:event_reporter_debug_mode] = prior + end + + # Check if debug mode is currently enabled. + def debug_mode? + Fiber[:event_reporter_debug_mode] + end + + # Report an event only when in debug mode. For example: + # + # Rails.event.debug("sql.query", { sql: "SELECT * FROM users" }) + # + # ==== Arguments + # + # * +:payload+ - The event payload when using string/symbol event names. + # + # * +:caller_depth+ - The stack depth to use for source location (default: 1). + # + # * +:kwargs+ - Additional payload data when using string/symbol event names. + def debug(name_or_object, payload = nil, caller_depth: 1, **kwargs) + if debug_mode? + if block_given? + notify(name_or_object, payload, caller_depth: caller_depth + 1, **kwargs.merge(yield)) + else + notify(name_or_object, payload, caller_depth: caller_depth + 1, **kwargs) + end + end + end + + # Add tags to events to supply additional context. Tags operate in a stack-oriented manner, + # so all events emitted within the block inherit the same set of tags. For example: + # + # Rails.event.tagged("graphql") do + # Rails.event.notify("user.created", { id: 123 }) + # end + # + # # Emits event: + # # { + # # name: "user.created", + # # payload: { id: 123 }, + # # tags: { graphql: true }, + # # timestamp: 1738964843208679035, + # # source_location: { filepath: "path/to/file.rb", lineno: 123, label: "UserService#create" } + # # } + # + # Tags can be provided as arguments or as keyword arguments, and can be nested: + # + # Rails.event.tagged("graphql") do + # # Other code here... + # Rails.event.tagged(section: "admin") do + # Rails.event.notify("user.created", { id: 123 }) + # end + # end + # + # # Emits event: + # # { + # # name: "user.created", + # # payload: { id: 123 }, + # # tags: { section: "admin", graphql: true }, + # # timestamp: 1738964843208679035, + # # source_location: { filepath: "path/to/file.rb", lineno: 123, label: "UserService#create" } + # # } + # + # Note that tags are converted to a HashWithIndifferentAccess, so keys can be accessed as strings or symbols. + # + # The +tagged+ API can also receive a tag object: + # + # graphql_tag = GraphqlTag.new(operation_name: "user_created", operation_type: "mutation") + # Rails.event.tagged(graphql_tag) do + # Rails.event.notify("user.created", { id: 123 }) + # end + # + # # Emits event: + # # { + # # name: "user.created", + # # payload: { id: 123 }, + # # tags: { "GraphqlTag": # }, + # # timestamp: 1738964843208679035, + # # source_location: { filepath: "path/to/file.rb", lineno: 123, label: "UserService#create" } + # # } + def tagged(*args, **kwargs, &block) + TagStack.with_tags(*args, **kwargs, &block) + end + + # Sets context data that will be included with all events emitted by the reporter. + # Context data should be scoped to the job or request, and is reset automatically + # before and after each request and job. + # + # Rails.event.set_context(user_agent: "TestAgent") + # Rails.event.set_context(job_id: "abc123") + # Rails.event.tagged("graphql") do + # Rails.event.notify("user_created", { id: 123 }) + # end + # + # # Emits event: + # # { + # # name: "user_created", + # # payload: { id: 123 }, + # # tags: { graphql: true }, + # # context: { user_agent: "TestAgent", job_id: "abc123" }, + # # timestamp: 1738964843208679035 + # # } + def set_context(context) + context_store.set_context(context) + end + + # Clears all context data + def clear_context + context_store.clear + end + + # Returns the current context data + def context + context_store.context + end + + private + def context_store + self.class.context_store + end + + def resolve_name(name_or_object) + case name_or_object + when String, Symbol + name_or_object.to_s + else + name_or_object.class.name + end + end + + def resolve_payload(name_or_object, payload, **kwargs) + case name_or_object + when String, Symbol + handle_unexpected_args(name_or_object, payload, kwargs) if payload && kwargs.any? + if kwargs.any? + kwargs.with_indifferent_access + elsif payload + payload.with_indifferent_access + end + else + handle_unexpected_args(name_or_object, payload, kwargs) if payload || kwargs.any? + name_or_object + end + end + + def handle_unexpected_args(name_or_object, payload, kwargs) + message = <<~MESSAGE + Rails.event.notify accepts either an event object, a payload hash, or keyword arguments. + Received: #{name_or_object.inspect}, #{payload.inspect}, #{kwargs.inspect} + MESSAGE + + if raise_on_error + raise ArgumentError, message + else + warn(message) + end + end + end +end diff --git a/activesupport/lib/active_support/event_reporter/encoders.rb b/activesupport/lib/active_support/event_reporter/encoders.rb new file mode 100644 index 0000000000000..59912e08b5030 --- /dev/null +++ b/activesupport/lib/active_support/event_reporter/encoders.rb @@ -0,0 +1,95 @@ +# typed: true +# frozen_string_literal: true + +require "active_support/parameter_filter" + +module ActiveSupport + class EventReporter + # = Event Encoders + # + # Default encoders for serializing structured events. These encoders can be used + # by subscribers to convert event data into various formats. + # + # Example usage in a subscriber: + # + # class LogSubscriber + # def emit(event) + # encoded_data = ActiveSupport::EventReporter::Encoders::JSON.encode(event) + # Rails.logger.info(encoded_data) + # end + # end + # + module Encoders + # Base encoder class that other encoders can inherit from + class Base + # Encodes an event hash into a serialized format + # + # @param event [Hash] The event hash containing name, payload, tags, context, timestamp, and source_location + # @return [String] The encoded event data + def self.encode(event) + raise NotImplementedError, "Subclasses must implement #encode" + end + + private + + def self.transform_event(event) + parameter_filter = ActiveSupport::ParameterFilter.new(ActiveSupport.filter_parameters, mask: ActiveSupport::ParameterFilter::FILTERED) + event[:payload] = parameter_filter.filter(event[:payload].to_h) + event[:tags] = event[:tags].transform_values do |value| + value.respond_to?(:to_h) ? value.to_h : value + end + + event + end + end + + # JSON encoder for serializing events to JSON format. + # + # event = { name: "user_created", payload: { id: 123 }, tags: { api: true } } + # ActiveSupport::EventReporter::Encoders::JSON.encode(event) + # # => { + # # "name": "user_created", + # # "payload": { + # # "id": 123 + # # }, + # # "tags": { + # # "api": true + # # }, + # # "context": {} + # # } + # + # Schematized events and tags MUST respond to #to_h to be serialized. + # + # event = { name: "UserCreatedEvent", payload: #, tags: { "GraphqlTag": # } } + # ActiveSupport::EventReporter::Encoders::JSON.encode(event) + # # => { + # # "name": "UserCreatedEvent", + # # "payload": { + # # "id": 123 + # # }, + # # "tags": { + # # "GraphqlTag": { + # # "operation_name": "user_created", + # # "operation_type": "mutation" + # # } + # # }, + # # "context": {} + # # } + + class JSON < Base + def self.encode(event) + ::JSON.dump(transform_event(event)) + end + end + + class MessagePack < Base + def self.encode(event) + require "msgpack" + ::MessagePack.pack(transform_event(event)) + rescue LoadError + raise LoadError, "msgpack gem is required for MessagePack encoding. Add 'gem \"msgpack\"' to your Gemfile." + end + end + end + end +end diff --git a/activesupport/lib/active_support/event_reporter/test_helper.rb b/activesupport/lib/active_support/event_reporter/test_helper.rb new file mode 100644 index 0000000000000..eb76b56d47dc5 --- /dev/null +++ b/activesupport/lib/active_support/event_reporter/test_helper.rb @@ -0,0 +1,48 @@ +# frozen_string_literal: true + +module ActiveSupport::EventReporter::TestHelper # :nodoc: + class EventSubscriber + attr_reader :events + + def initialize + @events = [] + end + + def emit(event) + @events << event + end + end + + def event_matcher(name:, payload: nil, tags: {}, context: {}, source_location: nil) + ->(event) { + return false unless event[:name] == name + return false unless hash_matches?(event[:payload], payload) + return false unless hash_matches?(event[:tags], tags) + return false unless hash_matches?(event[:context], context) + + if source_location + [:filepath, :lineno, :label].each do |key| + return false unless event[:source_location][key] == source_location[key] if source_location[key] + end + end + + true + } + end + + private + def hash_matches?(actual, expected) + return true if actual.nil? && expected.nil? + return false if actual.nil? || expected.nil? + + return actual == expected unless actual.is_a?(Hash) && expected.is_a?(Hash) + + return false unless actual.size == expected.size + + expected.each do |key, value| + return false unless actual[key] == value + end + + true + end +end diff --git a/activesupport/lib/active_support/railtie.rb b/activesupport/lib/active_support/railtie.rb index 5ab73c8d08ae3..0d1182caf5e1e 100644 --- a/activesupport/lib/active_support/railtie.rb +++ b/activesupport/lib/active_support/railtie.rb @@ -69,6 +69,17 @@ class Railtie < Rails::Railtie # :nodoc: end end + initializer "active_support.reset_event_reporter_context" do |app| + app.reloader.before_class_unload { ActiveSupport.event_reporter.clear_context } + app.executor.to_run { ActiveSupport.event_reporter.clear_context } + end + + initializer "active_support.set_filter_parameters" do |app| + app.after_initialize do + ActiveSupport.filter_parameters += Rails.application.config.filter_parameters + end + end + initializer "active_support.deprecation_behavior" do |app| if app.config.active_support.report_deprecations == false app.deprecators.silenced = true diff --git a/activesupport/lib/active_support/test_case.rb b/activesupport/lib/active_support/test_case.rb index 130685a1313e6..d6e26d3b584d2 100644 --- a/activesupport/lib/active_support/test_case.rb +++ b/activesupport/lib/active_support/test_case.rb @@ -6,6 +6,7 @@ require "active_support/testing/tests_without_assertions" require "active_support/testing/assertions" require "active_support/testing/error_reporter_assertions" +require "active_support/testing/event_reporter_assertions" require "active_support/testing/deprecation" require "active_support/testing/declarative" require "active_support/testing/isolation" @@ -178,6 +179,7 @@ def parallelize_teardown(&block) prepend ActiveSupport::Testing::TestsWithoutAssertions include ActiveSupport::Testing::Assertions include ActiveSupport::Testing::ErrorReporterAssertions + include ActiveSupport::Testing::EventReporterAssertions include ActiveSupport::Testing::NotificationAssertions include ActiveSupport::Testing::Deprecation include ActiveSupport::Testing::ConstantStubbing diff --git a/activesupport/lib/active_support/testing/event_reporter_assertions.rb b/activesupport/lib/active_support/testing/event_reporter_assertions.rb new file mode 100644 index 0000000000000..266900ea4a38e --- /dev/null +++ b/activesupport/lib/active_support/testing/event_reporter_assertions.rb @@ -0,0 +1,164 @@ +# typed: true +# frozen_string_literal: true + +module ActiveSupport + module Testing + # Provides test helpers for asserting on ActiveSupport::EventReporter events. + module EventReporterAssertions + module EventCollector # :nodoc: all + @subscribed = false + @mutex = Mutex.new + + class Event + attr_reader :event_data + + def initialize(event_data) + @event_data = event_data + end + + def inspect + "#{event_data[:name]} (payload: #{event_data[:payload].inspect}, tags: #{event_data[:tags].inspect})" + end + + def matches?(name, payload, tags) + return false unless name == event_data[:name] + + if payload && payload.is_a?(Hash) + return false unless payload.all? do |k, v| + if v.is_a?(Regexp) + event_data.dig(:payload, k).to_s.match?(v) + else + event_data.dig(:payload, k) == v + end + end + end + + return false unless tags.all? do |k, v| + if v.is_a?(Regexp) + event_data.dig(:tags, k).to_s.match?(v) + else + event_data.dig(:tags, k) == v + end + end + true + end + end + + class << self + def emit(event) + event_recorders&.each do |events| + events << Event.new(event) + end + true + end + + def record + subscribe + events = [] + event_recorders << events + begin + yield + events + ensure + event_recorders.delete_if { |r| events.equal?(r) } + end + end + + private + def subscribe + return if @subscribed + + @mutex.synchronize do + unless @subscribed + if ActiveSupport.event_reporter + ActiveSupport.event_reporter.subscribe(self) + @subscribed = true + else + raise Minitest::Assertion, "No event reporter is configured" + end + end + end + end + + def event_recorders + ActiveSupport::IsolatedExecutionState[:active_support_event_reporter_assertions] ||= [] + end + end + end + + # Asserts that the block does not cause an event to be reported to +Rails.event+. + # + # If no name is provided, passes if evaluated code in the yielded block reports no events. + # + # assert_no_event_reported do + # service_that_does_not_report_events.perform + # end + # + # If a name is provided, passes if evaluated code in the yielded block reports no events + # with that name. + # + # assert_no_event_reported("user.created") do + # service_that_does_not_report_events.perform + # end + def assert_no_event_reported(name = nil, payload: {}, tags: {}, &block) + events = EventCollector.record(&block) + + if name.nil? + assert_predicate(events, :empty?) + else + matching_event = events.find { |event| event.matches?(name, payload, tags) } + if matching_event + message = "Expected no '#{name}' event to be reported, but found:\n " \ + "#{matching_event.inspect}" + flunk(message) + end + assert(true) + end + end + + # Asserts that the block causes an event with the given name to be reported + # to +Rails.event+. + # + # Passes if the evaluated code in the yielded block reports a matching event. + # + # assert_event_reported("user.created") do + # Rails.event.notify("user.created", { id: 123 }) + # end + # + # To test further details about the reported event, you can specify payload and tag matchers. + # + # assert_event_reported("user.created", + # payload: { id: 123, name: "John Doe" }, + # tags: { request_id: /[0-9]+/ } + # ) do + # Rails.event.tagged(request_id: "123") do + # Rails.event.notify("user.created", { id: 123, name: "John Doe" }) + # end + # end + # + # The matchers support partial matching - only the specified keys need to match. + # + # assert_event_reported("user.created", payload: { id: 123 }) do + # Rails.event.notify("user.created", { id: 123, name: "John Doe" }) + # end + def assert_event_reported(name, payload: nil, tags: {}, &block) + events = EventCollector.record(&block) + + if events.empty? + flunk("Expected an event to be reported, but there were no events reported.") + elsif (event = events.find { |event| event.matches?(name, payload, tags) }) + assert(true) + event.event_data + else + message = "Expected an event to be reported matching:\n " \ + "name: #{name}\n " \ + "payload: #{payload.inspect}\n " \ + "tags: #{tags.inspect}\n" \ + "but none of the #{events.size} reported events matched:\n " \ + "#{events.map(&:inspect).join("\n ")}" + flunk(message) + end + end + end + end +end diff --git a/activesupport/test/event_reporter_test.rb b/activesupport/test/event_reporter_test.rb new file mode 100644 index 0000000000000..adfb1dd1ee4cc --- /dev/null +++ b/activesupport/test/event_reporter_test.rb @@ -0,0 +1,686 @@ +# typed: true +# frozen_string_literal: true + +require_relative "abstract_unit" +require "active_support/event_reporter/test_helper" +require "json" + +module ActiveSupport + class EventReporterTest < ActiveSupport::TestCase + include EventReporter::TestHelper + + setup do + @subscriber = EventReporter::TestHelper::EventSubscriber.new + @reporter = EventReporter.new(@subscriber, raise_on_error: true) + end + + TestEvent = Class.new do + class << self + def name + "TestEvent" + end + end + + def initialize(data) + @data = data + end + end + + HttpRequestTag = Class.new do + class << self + def name + "HttpRequestTag" + end + end + + def initialize(http_method, http_status) + @http_method = http_method + @http_status = http_status + end + end + + test "#subscribe" do + reporter = ActiveSupport::EventReporter.new + reporter.subscribe(@subscriber) + assert_equal([@subscriber], reporter.subscribers) + end + + test "#subscribe raises ArgumentError when sink doesn't respond to emit" do + invalid_subscriber = Object.new + + error = assert_raises(ArgumentError) do + @reporter.subscribe(invalid_subscriber) + end + + assert_equal "Event subscriber Object must respond to #emit", error.message + end + + test "#notify with name" do + assert_called_with(@subscriber, :emit, [ + event_matcher(name: "test_event") + ]) do + @reporter.notify(:test_event) + end + end + + test "#notify with name and hash payload" do + assert_called_with(@subscriber, :emit, [ + event_matcher(name: "test_event", payload: { key: "value" }) + ]) do + @reporter.notify(:test_event, { key: "value" }) + end + end + + test "#notify with name and kwargs" do + assert_called_with(@subscriber, :emit, [ + event_matcher(name: "test_event", payload: { key: "value" }) + ]) do + @reporter.notify(:test_event, key: "value") + end + end + + test "#notify with hash payload and kwargs raises" do + error = assert_raises(ArgumentError) do + @reporter.notify(:test_event, { key: "value" }, extra: "arg") + end + + assert_match( + /Rails.event.notify accepts either an event object, a payload hash, or keyword arguments/, + error.message + ) + end + + test "#notify includes source location in event payload" do + def test_method + @reporter.notify("test_event") + end + lineno = __LINE__ - 2 + + assert_called_with(@subscriber, :emit, [ + event_matcher(name: "test_event", source_location: { + filepath: __FILE__, + lineno: lineno + }) + ]) do + test_method + end + end + + test "#notify with caller depth option" do + def custom_log_abstraction(message) + @reporter.notify(:custom_event, caller_depth: 2, message: message) + end + + def another_test_method + custom_log_abstraction("hello") + end + lineno = __LINE__ - 2 + + assert_called_with(@subscriber, :emit, [ + event_matcher( + name: "custom_event", payload: { message: "hello" }, source_location: { + filepath: __FILE__, + lineno: lineno + }) + ]) do + another_test_method + end + end + + test "#notify with event object" do + event = TestEvent.new("value") + + assert_called_with(@subscriber, :emit, [ + event_matcher(name: "TestEvent", payload: event) + ]) do + @reporter.notify(event) + end + end + + test "#notify with event object and kwargs raises when raise_on_error is true" do + event = TestEvent.new("value") + error = assert_raises(ArgumentError) do + @reporter.notify(event, extra: "arg") + end + + assert_match( + /Rails.event.notify accepts either an event object, a payload hash, or keyword arguments/, + error.message + ) + end + + test "#notify with event object and hash payload raises when raise_on_error is true" do + event = TestEvent.new("value") + error = assert_raises(ArgumentError) do + @reporter.notify(event, { extra: "arg" }) + rescue RailsStrictWarnings::WarningError => _e + # Expected warning + end + + assert_match( + /Rails.event.notify accepts either an event object, a payload hash, or keyword arguments/, + error.message + ) + end + + test "#notify with event object and kwargs warns when raise_on_error is false" do + previous_raise_on_error = @reporter.raise_on_error + @reporter.raise_on_error = false + + event = TestEvent.new("value") + + _out, err = capture_io do + assert_called_with(@subscriber, :emit, [ + event_matcher(name: "TestEvent", payload: event) + ]) do + @reporter.notify(event, extra: "arg") + rescue RailsStrictWarnings::WarningError => _e + # Expected warning + end + end + + assert_match(/Rails.event.notify accepts either an event object, a payload hash, or keyword arguments/, err) + + ensure + @reporter.raise_on_error = previous_raise_on_error + end + + test "#notify warns about subscriber errors when raise_on_error is false" do + previous_raise_on_error = @reporter.raise_on_error + @reporter.raise_on_error = false + + error_subscriber = Class.new do + def emit(event) + raise StandardError.new("Uh oh!") + end + end + + @reporter.subscribe(error_subscriber.new) + + _out, err = capture_io do + @reporter.notify(:test_event) + rescue RailsStrictWarnings::WarningError => _e + # Expected warning + end + + assert_match(/Event reporter subscriber #{error_subscriber.name} raised an error on #emit: Uh oh!/, err) + ensure + @reporter.raise_on_error = previous_raise_on_error + end + + test "#notify raises subscriber errors when raise_on_error is true" do + error_subscriber = Class.new do + def emit(event) + raise StandardError.new("Uh oh!") + end + end + + @reporter.subscribe(error_subscriber.new) + + error = assert_raises(StandardError) do + @reporter.notify(:test_event) + end + + assert_equal("Uh oh!", error.message) + end + + test "#with_debug" do + @reporter.with_debug do + assert_predicate @reporter, :debug_mode? + end + assert_not_predicate @reporter, :debug_mode? + end + + test "#with_debug works with nested calls" do + @reporter.with_debug do + assert_predicate @reporter, :debug_mode? + + @reporter.with_debug do + assert_predicate @reporter, :debug_mode? + end + + assert_predicate @reporter, :debug_mode? + end + end + + test "#debug emits when in debug mode" do + @reporter.with_debug do + assert_called_with(@subscriber, :emit, [ + event_matcher(name: "test_event", payload: { key: "value" }) + ]) do + @reporter.debug(:test_event, key: "value") + end + end + end + + test "#debug with caller depth" do + def custom_debug_log_abstraction(message) + @reporter.debug(:custom_event, caller_depth: 2, message: message) + end + + def test_method_debug + custom_debug_log_abstraction("hello") + end + lineno = __LINE__ - 2 + + assert_called_with(@subscriber, :emit, [ + event_matcher(name: "custom_event", payload: { message: "hello" }, source_location: { + filepath: __FILE__, + lineno: lineno + }) + ]) do + @reporter.with_debug { test_method_debug } + end + end + + test "#debug emits in debug mode with block" do + @reporter.with_debug do + assert_called_with(@subscriber, :emit, [ + event_matcher(name: "test_event", payload: { slow_to_compute: "value" }) + ]) do + @reporter.debug(:test_event) do + { slow_to_compute: "value" } + end + end + end + end + + test "#debug does not emit when not in debug mode" do + assert_not_called(@subscriber, :emit) do + @reporter.debug(:test_event, key: "value") + end + end + + test "#debug with block merges kwargs" do + @reporter.with_debug do + assert_called_with(@subscriber, :emit, [ + event_matcher(name: "test_event", payload: { key: "value", slow_to_compute: "another_value" }) + ]) do + @reporter.debug(:test_event, key: "value") do + { slow_to_compute: "another_value" } + end + end + end + end + + test "#tagged adds tags to the emitted event" do + assert_called_with(@subscriber, :emit, [ + event_matcher(name: "test_event", payload: { key: "value" }, tags: { section: "admin" }) + ]) do + @reporter.tagged(section: "admin") do + @reporter.notify(:test_event, key: "value") + end + end + + assert_called_with(@subscriber, :emit, [ + event_matcher(name: "test_event", payload: { key: "value" }, tags: { section: "checkouts" }) + ]) do + @reporter.tagged({ section: "checkouts" }) do + @reporter.notify(:test_event, key: "value") + end + end + end + + test "#tagged with nested tags" do + @reporter.tagged(section: "admin") do + @reporter.tagged(nested: "tag") do + assert_called_with(@subscriber, :emit, [ + event_matcher(name: "test_event", payload: { key: "value" }, tags: { section: "admin", nested: "tag" }) + ]) do + @reporter.notify(:test_event, key: "value") + end + end + @reporter.tagged(hello: "world") do + assert_called_with(@subscriber, :emit, [ + event_matcher(name: "test_event", payload: { key: "value" }, tags: { section: "admin", hello: "world" }) + ]) do + @reporter.notify(:test_event, key: "value") + end + end + end + end + + test "#tagged with boolean tags" do + assert_called_with(@subscriber, :emit, [ + event_matcher(name: "test_event", payload: { key: "value" }, tags: { is_for_testing: true }) + ]) do + @reporter.tagged(:is_for_testing) do + @reporter.notify(:test_event, key: "value") + end + end + end + + test "#tagged can overwrite values on collision" do + assert_called_with(@subscriber, :emit, [ + event_matcher(name: "test_event", payload: { key: "value" }, tags: { section: "checkouts" }) + ]) do + @reporter.tagged(section: "admin") do + @reporter.tagged(section: "checkouts") do + @reporter.notify(:test_event, key: "value") + end + end + end + end + + test "#tagged with tag object" do + http_tag = HttpRequestTag.new("GET", 200) + + @reporter.tagged(http_tag) do + assert_called_with(@subscriber, :emit, [ + event_matcher(name: "test_event", payload: { key: "value" }, tags: { "HttpRequestTag": http_tag }) + ]) do + @reporter.notify(:test_event, key: "value") + end + end + end + + test "#tagged with mixed tags" do + http_tag = HttpRequestTag.new("GET", 200) + @reporter.tagged("foobar", http_tag, shop_id: 123) do + assert_called_with(@subscriber, :emit, [ + event_matcher(name: "test_event", payload: { key: "value" }, tags: { "foobar": true, "HttpRequestTag": http_tag, shop_id: 123 }) + ]) do + @reporter.notify(:test_event, key: "value") + end + end + end + + test "#tagged copies tag stack from parent fiber without mutating parent's tag stack" do + @reporter.tagged(shop_id: 999) do + Fiber.new do + @reporter.tagged(shop_id: 123) do + assert_called_with(@subscriber, :emit, [ + event_matcher(name: "test_event", payload: { key: "value" }, tags: { shop_id: 123 }) + ]) do + @reporter.notify(:test_event, key: "value") + end + end + end.resume + + assert_called_with(@subscriber, :emit, [ + event_matcher(name: "parent_event", payload: { key: "parent" }, tags: { shop_id: 999 }) + ]) do + @reporter.notify(:parent_event, key: "parent") + end + end + end + + test "#tagged maintains isolation between concurrent fibers" do + @reporter.tagged(shop_id: 123) do + fiber = Fiber.new do + assert_called_with(@subscriber, :emit, [ + event_matcher(name: "child_event", payload: { key: "value" }, tags: { shop_id: 123 }) + ]) do + @reporter.notify(:child_event, key: "value") + end + end + + @reporter.tagged(api_client_id: 456) do + fiber.resume + + # Verify parent fiber has both tags + assert_called_with(@subscriber, :emit, [ + event_matcher(name: "parent_event", payload: { key: "parent" }, tags: { shop_id: 123, api_client_id: 456 }) + ]) do + @reporter.notify(:parent_event, key: "parent") + end + end + end + end + end + + class ContextStoreTest < ActiveSupport::TestCase + include EventReporter::TestHelper + + setup do + @subscriber = EventReporter::TestHelper::EventSubscriber.new + @reporter = EventReporter.new(@subscriber, raise_on_error: true) + end + + teardown do + EventContext.clear + end + + test "#context returns empty hash by default" do + assert_equal({}, @reporter.context) + end + + test "#set_context sets context data" do + @reporter.set_context(shop_id: 123) + assert_equal(123, @reporter.context[:shop_id]) + end + + test "#set_context merges with existing context" do + @reporter.set_context(shop_id: 123) + @reporter.set_context(user_id: 456) + assert_equal(123, @reporter.context[:shop_id]) + assert_equal(456, @reporter.context[:user_id]) + end + + test "#set_context overwrites existing keys" do + @reporter.set_context(shop_id: 123) + @reporter.set_context(shop_id: 456) + assert_equal(456, @reporter.context[:shop_id]) + end + + test "#clear_context removes all context data" do + @reporter.set_context(shop_id: 123, user_id: 456) + @reporter.clear_context + assert_equal({}, @reporter.context) + end + + test "#notify includes context in event" do + @reporter.set_context(shop_id: 123) + + assert_called_with(@subscriber, :emit, [ + event_matcher(name: "test_event", payload: { key: "value" }, tags: {}, context: { shop_id: 123 }) + ]) do + @reporter.notify(:test_event, key: "value") + end + end + + test "#context inherited by child fibers without mutating parent's context" do + @reporter.set_context(shop_id: 999) + Fiber.new do + @reporter.set_context(shop_id: 123) + assert_called_with(@subscriber, :emit, [ + event_matcher(name: "test_event", context: { shop_id: 123 }) + ]) do + @reporter.notify(:test_event) + end + end.resume + + assert_called_with(@subscriber, :emit, [ + event_matcher(name: "parent_event", payload: { key: "parent" }, context: { shop_id: 999 }) + ]) do + @reporter.notify(:parent_event, key: "parent") + end + end + + test "#context isolated between concurrent fibers" do + @reporter.set_context(shop_id: 123) + fiber = Fiber.new do + assert_called_with(@subscriber, :emit, [ + event_matcher(name: "child_event", context: { shop_id: 123 }) + ]) do + @reporter.notify(:child_event) + end + end + + @reporter.set_context(api_client_id: 456) + fiber.resume + + assert_called_with(@subscriber, :emit, [ + event_matcher(name: "parent_event", context: { shop_id: 123, api_client_id: 456 }) + ]) do + @reporter.notify(:parent_event) + end + end + + test "context is preserved when using #tagged" do + @reporter.set_context(shop_id: 123) + + @reporter.tagged(request_id: "abc") do + assert_equal(123, @reporter.context[:shop_id]) + + assert_called_with(@subscriber, :emit, [ + event_matcher(name: "test_event", payload: { key: "value" }, tags: { request_id: "abc" }, context: { shop_id: 123 }) + ]) do + @reporter.notify(:test_event, key: "value") + end + end + end + end + + class EncodersTest < ActiveSupport::TestCase + TestEvent = Class.new do + class << self + def name + "TestEvent" + end + end + + def initialize(data) + @data = data + end + + def to_h + { + data: @data + } + end + end + + HttpRequestTag = Class.new do + class << self + def name + "HttpRequestTag" + end + end + + def initialize(http_method, http_status) + @http_method = http_method + @http_status = http_status + end + + def to_h + { + http_method: @http_method, + http_status: @http_status + } + end + end + + setup do + @event = { + name: "test_event", + payload: { id: 123, message: "hello" }, + tags: { section: "admin" }, + context: { user_id: 456 }, + timestamp: 1738964843208679035, + source_location: { filepath: "/path/to/file.rb", lineno: 42, label: "test_method" } + } + end + + test "looking up encoder by symbol" do + assert_equal EventReporter::Encoders::JSON, EventReporter.encoder(:json) + assert_equal EventReporter::Encoders::MessagePack, EventReporter.encoder(:msgpack) + end + + test "looking up encoder by string" do + assert_equal EventReporter::Encoders::JSON, EventReporter.encoder("json") + assert_equal EventReporter::Encoders::MessagePack, EventReporter.encoder("msgpack") + end + + test "looking up nonexistant encoder raises KeyError" do + error = assert_raises(KeyError) do + EventReporter.encoder(:unknown) + end + assert_equal "Unknown encoder format: :unknown. Available formats: json, msgpack", error.message + end + + test "Base encoder raises NotImplementedError" do + assert_raises(NotImplementedError) do + EventReporter::Encoders::Base.encode(@event) + end + end + + test "JSON encoder encodes event to JSON" do + json_string = EventReporter::Encoders::JSON.encode(@event) + parsed = ::JSON.parse(json_string) + + assert_equal "test_event", parsed["name"] + assert_equal({ "id" => 123, "message" => "hello" }, parsed["payload"]) + assert_equal({ "section" => "admin" }, parsed["tags"]) + assert_equal({ "user_id" => 456 }, parsed["context"]) + assert_equal 1738964843208679035, parsed["timestamp"] + assert_equal({ "filepath" => "/path/to/file.rb", "lineno" => 42, "label" => "test_method" }, parsed["source_location"]) + end + + test "JSON encoder serializes event objects and object tags as hashes" do + @event[:payload] = TestEvent.new("value") + @event[:tags] = { "HttpRequestTag": HttpRequestTag.new("GET", 200) } + json_string = EventReporter::Encoders::JSON.encode(@event) + parsed = ::JSON.parse(json_string) + + assert_equal "value", parsed["payload"]["data"] + assert_equal "GET", parsed["tags"]["HttpRequestTag"]["http_method"] + assert_equal 200, parsed["tags"]["HttpRequestTag"]["http_status"] + end + + test "JSON encoder filters parameters" do + previous_filter_parameters = ActiveSupport.filter_parameters + ActiveSupport.filter_parameters = [:zomg] + + @event[:payload][:zomg] = "secret" + json_string = EventReporter::Encoders::JSON.encode(@event) + parsed = ::JSON.parse(json_string) + + assert_equal({ "id" => 123, "message" => "hello", "zomg" => "[FILTERED]" }, parsed["payload"]) + ensure + ActiveSupport.filter_parameters = previous_filter_parameters + end + + test "MessagePack encoder encodes event to MessagePack" do + begin + require "msgpack" + rescue LoadError + skip "msgpack gem not available" + end + + msgpack_data = EventReporter::Encoders::MessagePack.encode(@event) + parsed = ::MessagePack.unpack(msgpack_data) + + assert_equal "test_event", parsed["name"] + assert_equal({ "id" => 123, "message" => "hello" }, parsed["payload"]) + assert_equal({ "section" => "admin" }, parsed["tags"]) + assert_equal({ "user_id" => 456 }, parsed["context"]) + assert_equal 1738964843208679035, parsed["timestamp"] + assert_equal({ "filepath" => "/path/to/file.rb", "lineno" => 42, "label" => "test_method" }, parsed["source_location"]) + end + + test "MessagePack encoder serializes event objects and object tags as hashes" do + @event[:payload] = TestEvent.new("value") + @event[:tags] = { "HttpRequestTag": HttpRequestTag.new("GET", 200) } + msgpack_data = EventReporter::Encoders::MessagePack.encode(@event) + parsed = ::MessagePack.unpack(msgpack_data) + + assert_equal "value", parsed["payload"]["data"] + assert_equal "GET", parsed["tags"]["HttpRequestTag"]["http_method"] + assert_equal 200, parsed["tags"]["HttpRequestTag"]["http_status"] + end + + test "MessagePack encoder filters parameters" do + previous_filter_parameters = ActiveSupport.filter_parameters + ActiveSupport.filter_parameters = [:zomg] + + @event[:payload][:zomg] = "secret" + msgpack_data = EventReporter::Encoders::MessagePack.encode(@event) + parsed = ::MessagePack.unpack(msgpack_data) + + assert_equal({ "id" => 123, "message" => "hello", "zomg" => "[FILTERED]" }, parsed["payload"]) + ensure + ActiveSupport.filter_parameters = previous_filter_parameters + end + end +end diff --git a/activesupport/test/testing/event_reporter_assertions_test.rb b/activesupport/test/testing/event_reporter_assertions_test.rb new file mode 100644 index 0000000000000..4dbf04643db63 --- /dev/null +++ b/activesupport/test/testing/event_reporter_assertions_test.rb @@ -0,0 +1,125 @@ +# typed: true +# frozen_string_literal: true + +require "active_support/test_case" + +module ActiveSupport + module Testing + class EventReporterAssertionsTest < ActiveSupport::TestCase + setup do + @reporter = ActiveSupport.event_reporter + end + + test "assert_event_reported" do + assert_event_reported("user.created") do + @reporter.notify("user.created", { id: 123, name: "John Doe" }) + end + end + + test "assert_event_reported with payload" do + assert_event_reported("user.created", payload: { id: 123, name: "John Doe" }) do + @reporter.notify("user.created", { id: 123, name: "John Doe" }) + end + end + + test "assert_event_reported with tags" do + assert_event_reported("user.created", tags: { graphql: true }) do + @reporter.tagged(:graphql) do + @reporter.notify("user.created", { id: 123, name: "John Doe" }) + end + end + end + + test "assert_event_reported partial matching" do + assert_event_reported("user.created", payload: { id: 123 }, tags: { foo: :bar }) do + @reporter.tagged(foo: :bar, baz: :qux) do + @reporter.notify("user.created", { id: 123, name: "John Doe" }) + end + end + end + + test "assert_event_reported with regex payload" do + assert_event_reported("user.created", payload: { id: /[0-9]+/ }) do + @reporter.notify("user.created", { id: 123, name: "John Doe" }) + end + end + + test "assert_event_reported with regex tags" do + assert_event_reported("user.created", tags: { foo: /bar/ }) do + @reporter.tagged(foo: :bar, baz: :qux) do + @reporter.notify("user.created") + end + end + end + + test "assert_no_event_reported" do + assert_no_event_reported do + # No events are reported here + end + end + + test "assert_no_event_reported with provided name" do + assert_no_event_reported("user.created") do + @reporter.notify("another.event") + end + end + + test "assert_no_event_reported with payload" do + assert_no_event_reported("user.created", payload: { id: 123, name: "Sazz Pataki" }) do + @reporter.notify("user.created", { id: 123, name: "Mabel Mora" }) + end + + assert_no_event_reported("user.created", payload: { name: "Sazz Pataki" }) do + @reporter.notify("user.created") + end + end + + test "assert_no_event_reported with tags" do + assert_no_event_reported("user.created", tags: { api: true, zip_code: 10003 }) do + @reporter.tagged(api: false, zip_code: 10003) do + @reporter.notify("user.created") + end + end + + assert_no_event_reported("user.created", tags: { api: true }) do + @reporter.notify("user.created") + end + end + + test "assert_event_reported fails when event is not reported" do + e = assert_raises(Minitest::Assertion) do + assert_event_reported("user.created") do + # No events are reported here + end + end + + assert_equal "Expected an event to be reported, but there were no events reported.", e.message + end + + test "assert_event_reported fails when different event is reported" do + e = assert_raises(Minitest::Assertion) do + assert_event_reported("user.created", payload: { id: 123 }) do + @reporter.notify("another.event", { id: 123, name: "John Doe" }) + end + end + + assert_match(/Expected an event to be reported matching:/, e.message) + assert_match(/name: user\.created/, e.message) + assert_match(/but none of the 1 reported events matched:/, e.message) + assert_match(/another\.event/, e.message) + end + + test "assert_no_event_reported fails when event is reported" do + payload = { id: 123, name: "John Doe" } + e = assert_raises(Minitest::Assertion) do + assert_no_event_reported("user.created") do + @reporter.notify("user.created", payload) + end + end + + assert_match(/Expected no 'user\.created' event to be reported, but found:/, e.message) + assert_match(/user\.created/, e.message) + end + end + end +end diff --git a/railties/lib/rails.rb b/railties/lib/rails.rb index 0944bf6c92fa2..fd65dab137f1b 100644 --- a/railties/lib/rails.rb +++ b/railties/lib/rails.rb @@ -93,6 +93,14 @@ def error ActiveSupport.error_reporter end + # Returns the ActiveSupport::EventReporter of the current \Rails project, + # otherwise it returns +nil+ if there is no project. + # + # Rails.event.notify("my_event", { message: "Hello, world!" }) + def event + ActiveSupport.event_reporter + end + # Returns all \Rails groups for loading based on: # # * The \Rails environment; diff --git a/railties/lib/rails/application/bootstrap.rb b/railties/lib/rails/application/bootstrap.rb index 562204c0fe2c3..deafe5a38287a 100644 --- a/railties/lib/rails/application/bootstrap.rb +++ b/railties/lib/rails/application/bootstrap.rb @@ -73,6 +73,10 @@ module Bootstrap end end + initializer :initialize_event_reporter, group: :all do + Rails.event.raise_on_error = config.consider_all_requests_local + end + # Initialize cache early in the stack so railties can make use of it. initializer :initialize_cache, group: :all do cache_format_version = config.active_support.delete(:cache_format_version) diff --git a/railties/lib/rails/application/default_middleware_stack.rb b/railties/lib/rails/application/default_middleware_stack.rb index a1e2d00bba300..4a63a6933e79d 100644 --- a/railties/lib/rails/application/default_middleware_stack.rb +++ b/railties/lib/rails/application/default_middleware_stack.rb @@ -58,6 +58,7 @@ def build_stack middleware.use ::Rails::Rack::SilenceRequest, path: path end + middleware.use ::ActionDispatch::ClearEventReporterContext middleware.use ::Rails::Rack::Logger, config.log_tags middleware.use ::ActionDispatch::ShowExceptions, show_exceptions_app middleware.use ::ActionDispatch::DebugExceptions, app, config.debug_exception_response_format diff --git a/railties/test/commands/middleware_test.rb b/railties/test/commands/middleware_test.rb index 0b3ddf0d5eb82..0a58c41e8f554 100644 --- a/railties/test/commands/middleware_test.rb +++ b/railties/test/commands/middleware_test.rb @@ -36,6 +36,7 @@ def app "Rack::MethodOverride", "ActionDispatch::RequestId", "ActionDispatch::RemoteIp", + "ActionDispatch::ClearEventReporterContext", "Rails::Rack::Logger", "ActionDispatch::ShowExceptions", "ActionDispatch::DebugExceptions", @@ -71,6 +72,7 @@ def app "Rack::MethodOverride", "ActionDispatch::RequestId", "ActionDispatch::RemoteIp", + "ActionDispatch::ClearEventReporterContext", "Rails::Rack::Logger", "ActionDispatch::ShowExceptions", "ActionDispatch::DebugExceptions", @@ -103,6 +105,7 @@ def app "Rack::Runtime", "ActionDispatch::RequestId", "ActionDispatch::RemoteIp", + "ActionDispatch::ClearEventReporterContext", "Rails::Rack::Logger", "ActionDispatch::ShowExceptions", "ActionDispatch::DebugExceptions",