diff --git a/app/models/concerns/journaled/changes.rb b/app/models/concerns/journaled/changes.rb index c84f2f5..d181fd9 100644 --- a/app/models/concerns/journaled/changes.rb +++ b/app/models/concerns/journaled/changes.rb @@ -56,7 +56,7 @@ def update_columns(attributes, opts = { force: false }) end class_methods do - def journal_changes_to(*attribute_names, as:, enqueue_with: {}) # rubocop:disable Naming/MethodParameterName + def journal_changes_to(*attribute_names, as:, enqueue_with: {}) if attribute_names.empty? || attribute_names.any? { |n| !n.is_a?(Symbol) } raise "one or more symbol attribute_name arguments is required" end diff --git a/app/models/journaled/audit_log/event.rb b/app/models/journaled/audit_log/event.rb new file mode 100644 index 0000000..abfd759 --- /dev/null +++ b/app/models/journaled/audit_log/event.rb @@ -0,0 +1,87 @@ +# FIXME: This cannot be included in lib/ because Journaled::Event is autoloaded via app/models +# Autoloading Journaled::Event isn't strictly necessary, and for compatibility it would +# make sense to move it to lib/. +module Journaled + module AuditLog + Event = Struct.new(:record, :database_operation, :unfiltered_changes) do + include Journaled::Event + + journal_attributes :class_name, :table_name, :record_id, + :database_operation, :changes, :snapshot, :actor, tagged: true + + def journaled_stream_name + AuditLog.default_stream_name || super + end + + def created_at + case database_operation + when 'insert' + record_created_at + when 'update' + record_updated_at + when 'delete' + Time.zone.now + else + raise "Unhandled database operation type: #{database_operation}" + end + end + + def record_created_at + record.try(:created_at) || Time.zone.now + end + + def record_updated_at + record.try(:updated_at) || Time.zone.now + end + + def class_name + record.class.name + end + + def table_name + record.class.table_name + end + + def record_id + record.id + end + + def changes + filtered_changes = unfiltered_changes.deep_dup.deep_symbolize_keys + filtered_changes.each do |key, value| + filtered_changes[key] = value.map { |val| '[FILTERED]' if val } if filter_key?(key) + end + end + + def snapshot + filtered_attributes if record._log_snapshot || AuditLog.snapshots_enabled + end + + def actor + Journaled.actor_uri + end + + private + + def filter_key?(key) + filter_params.include?(key) || encrypted_column?(key) + end + + def encrypted_column?(key) + key.to_s.end_with?('_crypt', '_hmac') || + (Rails::VERSION::MAJOR >= 7 && record.encrypted_attribute?(key)) + end + + def filter_params + Rails.application.config.filter_parameters + end + + def filtered_attributes + attrs = record.attributes.dup.symbolize_keys + attrs.each do |key, _value| + attrs[key] = '[FILTERED]' if filter_key?(key) + end + end + end + end +end diff --git a/journaled.gemspec b/journaled.gemspec index 5fb8460..484a546 100644 --- a/journaled.gemspec +++ b/journaled.gemspec @@ -23,6 +23,7 @@ Gem::Specification.new do |s| s.add_dependency "activejob" s.add_dependency "activerecord" + s.add_dependency "activesupport" s.add_dependency "aws-sdk-kinesis", "< 2" s.add_dependency "json-schema" s.add_dependency "railties", ">= 5.2" diff --git a/journaled_schemas/journaled/audit_log/event.json b/journaled_schemas/journaled/audit_log/event.json new file mode 100644 index 0000000..acab339 --- /dev/null +++ b/journaled_schemas/journaled/audit_log/event.json @@ -0,0 +1,31 @@ +{ + "type": "object", + "title": "audit_log_event", + "additionalProperties": false, + "required": [ + "id", + "event_type", + "created_at", + "class_name", + "table_name", + "record_id", + "database_operation", + "changes", + "snapshot", + "actor", + "tags" + ], + "properties": { + "id": { "type": "string" }, + "event_type": { "type": "string" }, + "created_at": { "type": "string" }, + "class_name": { "type": "string" }, + "table_name": { "type": "string" }, + "record_id": { "type": ["string", "integer"] }, + "database_operation": { "type": "string" }, + "changes": { "type": "object", "additionalProperties": true }, + "snapshot": { "type": ["object", "null"], "additionalProperties": true }, + "actor": { "type": "string" }, + "tags": { "type": "object", "additionalProperties": true } + } +} diff --git a/lib/journaled.rb b/lib/journaled.rb index 19c57e0..9fa3f83 100644 --- a/lib/journaled.rb +++ b/lib/journaled.rb @@ -69,3 +69,5 @@ def self.tag!(**tags) Current.tags = Current.tags.merge(tags) end end + +require 'journaled/audit_log' diff --git a/lib/journaled/audit_log.rb b/lib/journaled/audit_log.rb new file mode 100644 index 0000000..5071c29 --- /dev/null +++ b/lib/journaled/audit_log.rb @@ -0,0 +1,194 @@ +require 'active_support/core_ext/module/attribute_accessors_per_thread' + +module Journaled + module AuditLog + extend ActiveSupport::Concern + + DEFAULT_EXCLUDED_CLASSES = %w( + Delayed::Job + PaperTrail::Version + ActiveStorage::Attachment + ActiveStorage::Blob + ActiveRecord::InternalMetadata + ActiveRecord::SchemaMigration + ).freeze + + mattr_accessor(:default_ignored_columns) { %i(created_at updated_at) } + mattr_accessor(:default_stream_name) { Journaled.default_stream_name } + mattr_accessor(:excluded_classes) { DEFAULT_EXCLUDED_CLASSES.dup } + thread_mattr_accessor(:snapshots_enabled) { false } + thread_mattr_accessor(:_disabled) { false } + thread_mattr_accessor(:_force) { false } + + class << self + def exclude_classes! + excluded_classes.each do |name| + if Rails::VERSION::MAJOR >= 6 && Rails.autoloaders.zeitwerk_enabled? + zeitwerk_exclude!(name) + else + classic_exclude!(name) + end + end + end + + def with_snapshots + snapshots_enabled_was = snapshots_enabled + self.snapshots_enabled = true + yield + ensure + self.snapshots_enabled = snapshots_enabled_was + end + + def without_audit_logging + disabled_was = _disabled + self._disabled = true + yield + ensure + self._disabled = disabled_was + end + + private + + def zeitwerk_exclude!(name) + if Object.const_defined?(name) + name.constantize.skip_audit_log + else + Rails.autoloaders.main.on_load(name) { |klass, _path| klass.skip_audit_log } + end + end + + def classic_exclude!(name) + name.constantize.skip_audit_log + rescue NameError + nil + end + end + + Config = Struct.new(:enabled, :ignored_columns) do + private :enabled + def enabled? + !AuditLog._disabled && self[:enabled].present? + end + end + + included do + prepend BlockedMethods + singleton_class.prepend BlockedClassMethods + + class_attribute :audit_log_config, default: Config.new(false, AuditLog.default_ignored_columns) + attr_accessor :_log_snapshot + + after_create { _emit_audit_log!('insert') } + after_update { _emit_audit_log!('update') if _audit_log_changes.any? } + after_destroy { _emit_audit_log!('delete') } + end + + class_methods do + def has_audit_log(ignore: []) + ignored_columns = _audit_log_inherited_ignored_columns + [ignore].flatten(1) + self.audit_log_config = Config.new(true, ignored_columns.uniq) + end + + def skip_audit_log + self.audit_log_config = Config.new(false, _audit_log_inherited_ignored_columns.uniq) + end + + private + + def _audit_log_inherited_ignored_columns + (superclass.try(:audit_log_config)&.ignored_columns || []) + audit_log_config.ignored_columns + end + end + + module BlockedMethods + BLOCKED_METHODS = { + delete: '#destroy', + update_column: '#update!', + update_columns: '#update!', + }.freeze + + def delete(**kwargs) + _journaled_audit_log_check!(:delete, **kwargs) do + super() + end + end + + def update_column(name, value, **kwargs) + _journaled_audit_log_check!(:update_column, **kwargs.merge(name => value)) do + super(name, value) + end + end + + def update_columns(args = {}, **kwargs) + _journaled_audit_log_check!(:update_columns, **args.merge(kwargs)) do + super(args.merge(kwargs).except(:_force)) + end + end + + def _journaled_audit_log_check!(method, **kwargs) # rubocop:disable Metrics/AbcSize + force_was = AuditLog._force + AuditLog._force = kwargs.delete(:_force) if kwargs.key?(:_force) + audited_columns = kwargs.keys - audit_log_config.ignored_columns + + if method == :delete || audited_columns.any? + column_message = <<~MSG if kwargs.any? + You are attempting to change the following audited columns: + #{audited_columns.inspect} + + MSG + raise <<~MSG if audit_log_config.enabled? && !AuditLog._force + #{column_message}Using `#{method}` is blocked because it skips audit logging (and other Rails callbacks)! + Consider using `#{BLOCKED_METHODS[method]}` instead, or pass `_force: true` as an argument. + MSG + end + + yield + ensure + AuditLog._force = force_was + end + end + + module BlockedClassMethods + BLOCKED_METHODS = { + delete_all: '.destroy_all', + insert: '.create!', + insert_all: '.each { create!(...) }', + update_all: '.find_each { update!(...) }', + upsert: '.create_or_find_by!', + upsert_all: '.each { create_or_find_by!(...) }', + }.freeze + + BLOCKED_METHODS.each do |method, alternative| + define_method(method) do |*args, **kwargs, &block| + force_was = AuditLog._force + AuditLog._force = kwargs.delete(:_force) if kwargs.key?(:_force) + + raise <<~MSG if audit_log_config.enabled? && !AuditLog._force + `#{method}` is blocked because it skips callbacks and audit logs! + Consider using `#{alternative}` instead, or pass `_force: true` as an argument. + MSG + + super(*args, **kwargs, &block) + ensure + AuditLog._force = force_was + end + end + end + + def _emit_audit_log!(database_operation) + if audit_log_config.enabled? + event = Journaled::AuditLog::Event.new(self, database_operation, _audit_log_changes) + ActiveSupport::Notifications.instrument('journaled.audit_log.journal', event: event) do + event.journal! + end + end + end + + def _audit_log_changes + previous_changes.except(*audit_log_config.ignored_columns) + end + end +end + +ActiveSupport.on_load(:active_record) { include Journaled::AuditLog } +Journaled::Engine.config.after_initialize { Journaled::AuditLog.exclude_classes! } diff --git a/lib/journaled/version.rb b/lib/journaled/version.rb index 3a0a731..bc37eb6 100644 --- a/lib/journaled/version.rb +++ b/lib/journaled/version.rb @@ -1,3 +1,3 @@ module Journaled - VERSION = "5.0.0".freeze + VERSION = "5.1.0".freeze end diff --git a/spec/dummy/config/application.rb b/spec/dummy/config/application.rb index 9e1e0ba..615667c 100644 --- a/spec/dummy/config/application.rb +++ b/spec/dummy/config/application.rb @@ -10,16 +10,8 @@ module Dummy class Application < Rails::Application - # Settings in config/environments/* take precedence over those specified here. - # Application configuration should go into files in config/initializers - # -- all .rb files in that directory are automatically loaded. - - # Set Time.zone default to the specified zone and make Active Record auto-convert to this zone. - # Run "rake -D time" for a list of tasks for finding time zone names. Default is UTC. - # config.time_zone = 'Central Time (US & Canada)' - - # The default locale is :en and all translations from config/locales/*.rb,yml are auto loaded. - # config.i18n.load_path += Dir[Rails.root.join('my', 'locales', '*.{rb,yml}').to_s] - # config.i18n.default_locale = :de + config.autoloader = Rails::VERSION::MAJOR >= 7 ? :zeitwerk : :classic + config.active_record.sqlite3.represent_boolean_as_integer = true if Rails::VERSION::MAJOR < 6 + config.active_record.legacy_connection_handling = false if Rails::VERSION::MAJOR >= 7 end end diff --git a/spec/lib/journaled/audit_log_spec.rb b/spec/lib/journaled/audit_log_spec.rb new file mode 100644 index 0000000..12b7a14 --- /dev/null +++ b/spec/lib/journaled/audit_log_spec.rb @@ -0,0 +1,581 @@ +require 'rails_helper' + +RSpec.describe Journaled::AuditLog do + let(:auditable_model) do + Class.new do + extend ActiveModel::Callbacks + define_model_callbacks :create, :update, :destroy, only: %i(after) + + include Journaled::AuditLog + + def self.table_name + 'objects' + end + + def id + 'random-id' + end + + def created_at + 'very-recently' + end + + def updated_at + 'close-to-now' + end + + def attributes + { all: 'attributes', password: true } + end + + if Rails::VERSION::MAJOR >= 7 + def encrypted_attribute?(_key) + false + end + end + end + end + + before do + stub_const('MyModel', auditable_model) + end + + around do |example| + Journaled.tagged(request_id: 123) do + example.run + end + end + + describe '.default_ignored_columns' do + it 'defaults to timestamps, but is configurable' do + expect(described_class.default_ignored_columns).to eq %i(created_at updated_at) + described_class.default_ignored_columns = [] + expect(described_class.default_ignored_columns).to eq [] + ensure + described_class.default_ignored_columns = %i(created_at updated_at) + end + end + + describe '.default_stream_name' do + it 'defaults to primary default, but is configurable' do + expect(described_class.default_stream_name).to be_nil + described_class.default_stream_name = 'dont_cross_the_streams' + expect(described_class.default_stream_name).to eq 'dont_cross_the_streams' + ensure + described_class.default_stream_name = nil + end + end + + describe '.excluded_classes' do + let(:defaults) do + %w( + Delayed::Job + PaperTrail::Version + ActiveStorage::Attachment + ActiveStorage::Blob + ActiveRecord::InternalMetadata + ActiveRecord::SchemaMigration + ) + end + + it 'defaults to DJ and papertrail, but is configurable, and will disable audit logging' do + expect(described_class.excluded_classes).to eq defaults + described_class.excluded_classes += %w(MyModel) + expect(described_class.excluded_classes).to eq defaults + %w(MyModel) + ensure + described_class.excluded_classes = defaults + end + end + + describe '.has_audit_log, .skip_audit_log' do + around do |example| + described_class.default_ignored_columns = %i(DEFAULTS) + example.run + ensure + described_class.default_ignored_columns = %i(created_at updated_at) + end + + subject { MyModel } + + it 'enables/disables audit logging' do + expect(subject.audit_log_config.enabled?).to be(false) + expect(subject.audit_log_config.ignored_columns).to eq(%i(DEFAULTS)) + subject.has_audit_log + expect(subject.audit_log_config.enabled?).to be(true) + expect(subject.audit_log_config.ignored_columns).to eq(%i(DEFAULTS)) + subject.has_audit_log ignore: %i(foo bar baz) + expect(subject.audit_log_config.enabled?).to be(true) + expect(subject.audit_log_config.ignored_columns).to eq(%i(DEFAULTS foo bar baz)) + subject.skip_audit_log + expect(subject.audit_log_config.enabled?).to be(false) + expect(subject.audit_log_config.ignored_columns).to eq(%i(DEFAULTS foo bar baz)) + end + + it 'can be composed with multiple calls' do + subject.has_audit_log ignore: %i(foo) + subject.has_audit_log ignore: %i(bar) + expect(subject.audit_log_config.ignored_columns).to eq(%i(DEFAULTS foo bar)) + end + + it 'deduplicates identical fields' do + subject.has_audit_log ignore: %i(foo) + subject.has_audit_log ignore: %i(DEFAULTS foo) + expect(subject.audit_log_config.ignored_columns).to eq(%i(DEFAULTS foo)) + end + + it 'accepts a single name (instead of an array)' do + subject.has_audit_log ignore: :bar + expect(subject.audit_log_config.ignored_columns).to eq(%i(DEFAULTS bar)) + end + + context 'with a subclass' do + let(:auditable_subclass) do + Class.new(subject) { include Journaled::AuditLog } + end + + before do + stub_const('MySubclass', auditable_subclass) + end + + it 'inherits the config by default, and merges ignored columns' do + expect(MySubclass.audit_log_config.enabled?).to be(false) + expect(MySubclass.audit_log_config.ignored_columns).to eq(%i(DEFAULTS)) + subject.has_audit_log ignore: %i(foo) + expect(MySubclass.audit_log_config.enabled?).to be(true) + expect(MySubclass.audit_log_config.ignored_columns).to eq(%i(DEFAULTS foo)) + MySubclass.has_audit_log ignore: :bar + expect(MySubclass.audit_log_config.enabled?).to be(true) + expect(subject.audit_log_config.ignored_columns).to eq(%i(DEFAULTS foo)) + expect(MySubclass.audit_log_config.ignored_columns).to eq(%i(DEFAULTS foo bar)) + end + + it 'allows the subclass to skip audit logging, and vice versa' do + subject.has_audit_log ignore: %i(foo) + MySubclass.skip_audit_log + expect(subject.audit_log_config.enabled?).to be(true) + expect(subject.audit_log_config.ignored_columns).to eq(%i(DEFAULTS foo)) + expect(MySubclass.audit_log_config.enabled?).to be(false) + expect(MySubclass.audit_log_config.ignored_columns).to eq(%i(DEFAULTS foo)) + subject.skip_audit_log + MySubclass.has_audit_log ignore: %i(foo) + expect(subject.audit_log_config.enabled?).to be(false) + expect(subject.audit_log_config.ignored_columns).to eq(%i(DEFAULTS foo)) + expect(MySubclass.audit_log_config.enabled?).to be(true) + expect(MySubclass.audit_log_config.ignored_columns).to eq(%i(DEFAULTS foo)) + end + + it 'does not apply to subclasses that are in the exclusion list' do + excluded_classes_was = described_class.excluded_classes.dup + described_class.excluded_classes << 'MySubclass' + described_class.exclude_classes! # typically run via an initializer + + subject.has_audit_log + expect(subject.audit_log_config.enabled?).to be(true) + expect(MySubclass.audit_log_config.enabled?).to be(false) + ensure + described_class.excluded_classes = excluded_classes_was + end + end + end + + describe '#save, #update, #destroy' do + let(:attributes) { %i(name email_addr json synced_at) } + + before do + attrs = attributes + auditable_model.class_eval do + include ActiveModel::Dirty + + attr_reader(*attrs) + + define_attribute_methods(*attrs) + + attrs.each do |attr| + define_method("#{attr}=") do |val| + send("#{attr}_will_change!") unless val == send(attr) + instance_variable_set("@#{attr}", val) + end + end + + def initialize(**attrs) + assign_attrs(**attrs) + end + + def save + run_callbacks(:create) { changes_applied } # always a 'create' action, for simplicity + end + + def update(**attrs) + run_callbacks(:update) { assign_attrs(**attrs) && changes_applied } + end + + def destroy + run_callbacks(:destroy) { changes_applied } + end + + def assign_attrs(**attrs) + attrs.each { |attr, value| send("#{attr}=", value) } + end + end + end + + subject { MyModel.new(name: 'bob', email_addr: 'bob@example.org', json: { asdf: 123 }, synced_at: 'now') } + + it 'does not emit a journaled event (because audit logging is not enabled)' do + expect { subject.save } + .to not_journal_event_including(event_type: 'journaled_audit_log_event') + expect { subject.update(name: 'robert') } + .to not_journal_event_including(event_type: 'journaled_audit_log_event') + expect { subject.destroy } + .to not_journal_event_including(event_type: 'journaled_audit_log_event') + end + + context 'when audit logging is enabled' do + around { |example| freeze_time { example.run } } + before { auditable_model.class_eval { has_audit_log } } + + it 'emits events through the lifecycle of an object' do + expect { subject.save }.to journal_event_including( + event_type: 'journaled_audit_log_event', + created_at: 'very-recently', + class_name: 'MyModel', + table_name: 'objects', + record_id: 'random-id', + database_operation: 'insert', + changes: { + name: [nil, 'bob'], + email_addr: [nil, 'bob@example.org'], + json: [nil, { asdf: 123 }], + synced_at: [nil, 'now'], + }, + snapshot: {}, + actor: 'gid://dummy', + tags: { request_id: 123 }, + ) + expect { subject.update(name: 'robert') }.to journal_event_including( + event_type: 'journaled_audit_log_event', + created_at: 'close-to-now', + database_operation: 'update', + changes: { name: %w(bob robert) }, + snapshot: {}, + ) + expect { subject.update(name: 'robert') } + .to not_journal_event_including(event_type: 'journaled_audit_log_event') + expect { subject.destroy }.to journal_event_including( + event_type: 'journaled_audit_log_event', + created_at: Time.current, + database_operation: 'delete', + changes: {}, + snapshot: {}, + ) + end + + context 'when audit logging is disabled globally' do + around do |example| + described_class.without_audit_logging do + example.run + end + end + + it 'does not emit a journaled event' do + expect(subject.audit_log_config).not_to be_enabled + expect { subject.save } + .to not_journal_event_including(event_type: 'journaled_audit_log_event') + expect { subject.update(name: 'robert') } + .to not_journal_event_including(event_type: 'journaled_audit_log_event') + expect { subject.destroy } + .to not_journal_event_including(event_type: 'journaled_audit_log_event') + end + end + + context 'and a field is in the filter_paramters config' do + around do |example| + Rails.application.config.filter_parameters << :name + example.run + ensure + Rails.application.config.filter_parameters = Rails.application.config.filter_parameters - [:name] + end + + subject { MyModel.new(name: 'homer') } + + it 'filters that field through the lifecycle of the model' do + expect { subject.save } + .to journal_event_including(changes: { name: [nil, '[FILTERED]'] }) + expect { subject.update(name: 'bart') } + .to journal_event_including(changes: { name: ['[FILTERED]', '[FILTERED]'] }) + expect { subject.update(name: 'bart') } + .to not_journal_event_including(event_type: 'journaled_audit_log_event') + expect { subject.destroy }.to journal_event_including(changes: {}) + end + end + + context 'and fields end with _crypt or _hmac' do + let(:attributes) { super() + %i(favorite_color_crypt favorite_color_hmac) } + + subject { MyModel.new(name: 'homer', favorite_color_crypt: '123', favorite_color_hmac: '456') } + + it 'filters those fields through the lifecycle of the model' do + expect { subject.save }.to journal_event_including( + changes: { + name: [nil, 'homer'], + favorite_color_crypt: [nil, '[FILTERED]'], + favorite_color_hmac: [nil, '[FILTERED]'], + }, + ) + expect { subject.update(name: 'bart', favorite_color_crypt: '789', favorite_color_hmac: '789') } + .to journal_event_including( + changes: { + name: %w(homer bart), + favorite_color_crypt: ['[FILTERED]', '[FILTERED]'], + favorite_color_hmac: ['[FILTERED]', '[FILTERED]'], + }, + ) + expect { subject.update(name: 'bart', favorite_color_crypt: '789', favorite_color_hmac: '789') } + .to not_journal_event_including(event_type: 'journaled_audit_log_event') + expect { subject.destroy }.to journal_event_including(changes: {}) + end + end + + context 'and snapshotting is enabled via the attribute' do + subject { MyModel.new(name: 'bob', _log_snapshot: true) } + + it 'emits snapshots when `:_log_snapshot` is `true`, and filters the expected fields' do + expect { subject.save } + .to journal_event_including(snapshot: { all: 'attributes', password: '[FILTERED]' }) + expect { subject.update(name: 'robert') } + .to journal_event_including(snapshot: { all: 'attributes', password: '[FILTERED]' }) + subject._log_snapshot = false + expect { subject.update(name: 'bob') } + .to not_journal_event_including(snapshot: { all: 'attributes', password: '[FILTERED]' }) + subject._log_snapshot = true + expect { subject.destroy } + .to journal_event_including(snapshot: { all: 'attributes', password: '[FILTERED]' }) + end + end + + context 'and snapshotting is enabled globally' do + subject { MyModel.new(name: 'bob') } + + it 'emits snapshots through the lifecycle of the object, and filters the expected fields' do + described_class.with_snapshots do + expect { subject.save } + .to journal_event_including(snapshot: { all: 'attributes', password: '[FILTERED]' }) + expect { subject.update(name: 'robert') } + .to journal_event_including(snapshot: { all: 'attributes', password: '[FILTERED]' }) + end + expect { subject.update(name: 'bob') } + .to not_journal_event_including(snapshot: { all: 'attributes', password: '[FILTERED]' }) + described_class.with_snapshots do + expect { subject.destroy } + .to journal_event_including(snapshot: { all: 'attributes', password: '[FILTERED]' }) + end + end + end + end + + context 'and a field is ignored' do + before { auditable_model.class_eval { has_audit_log ignore: :synced_at } } + + subject { MyModel.new(name: 'bob', synced_at: 'earlier') } + + it 'excludes that field and does not emit events when the field changes' do + expect { subject.save } + .to journal_event_including(changes: { name: [nil, 'bob'] }) + .and not_journal_event_including(changes: { synced_at: [nil, 'earlier'] }) + expect { subject.update(synced_at: 'now') } + .to not_journal_event_including(event_type: 'journaled_audit_log_event') + expect { subject.destroy }.to journal_event_including( + event_type: 'journaled_audit_log_event', + database_operation: 'delete', + changes: {}, + ) + end + end + + context 'with a real ActiveRecord model' do + let(:journaled_class) do + Class.new(ActiveRecord::Base) do + has_audit_log + + self.table_name = 'widgets' + end + end + + before do + stub_const('Widget', journaled_class) + end + + subject do + Widget.new(name: 'test') + end + + around { |example| freeze_time { example.run } } + + it 'is audited and supports snapshots' do + expect { subject.save! }.to journal_event_including( + event_type: 'journaled_audit_log_event', + table_name: 'widgets', + class_name: 'Widget', + database_operation: 'insert', + changes: { + name: [nil, 'test'], + }, + snapshot: {}, + ).and not_journal_event_including(changes: { created_at: [nil, Time.zone.now] }) + .and emit_notification('journaled.event.stage') + .and emit_notification('journaled.batch.enqueue') + .and emit_notification('journaled.audit_log.journal') + expect { subject.save! }.to not_journal_event_including( + event_type: 'journaled_audit_log_event', + table_name: 'widgets', + ) + expect { subject.update!(name: 'not_test', _log_snapshot: true) }.to journal_event_including( + event_type: 'journaled_audit_log_event', + table_name: 'widgets', + database_operation: 'update', + changes: { + name: %w(test not_test), + }, + snapshot: { + name: 'not_test', + }, + ) + .and emit_notification('journaled.audit_log.journal') + + # rubocop:disable Rails/SkipsModelValidations + expect { subject.update_column(:name, 'banana') } + .to raise_error(/skips audit logging/) + expect { subject.update_column(:name, 'elephant', _force: true) } + .not_to raise_error + expect { subject.update_column(:name, 'other') } + .to raise_error(/skips audit logging/) + # rubocop:enable Rails/SkipsModelValidations + + expect { subject.destroy }.to journal_event_including( + event_type: 'journaled_audit_log_event', + table_name: 'widgets', + class_name: 'Widget', + database_operation: 'delete', + changes: {}, + snapshot: {}, + ) + .and emit_notification('journaled.audit_log.journal') + end + end + end + + # rubocop:disable Rails/SkipsModelValidations + describe '#delete, #update_column, #update_columns' do + before do + auditable_model.class_eval do + def delete(*); end + def update_column(*); end + def update_columns(*); end + end + end + + subject { MyModel.new } + + it 'does not block calls (because audit logging is disabled)' do + expect { subject.delete }.to not_raise_error + expect { subject.update_column(:foo, 'bar') }.to not_raise_error + expect { subject.update_columns(foo: 'bar') }.to not_raise_error + end + + context 'when audit logging is enabled' do + before { auditable_model.class_eval { has_audit_log } } + + it 'blocks the action' do + expect { subject.delete }.to raise_error(<<~MSG) + Using `delete` is blocked because it skips audit logging (and other Rails callbacks)! + Consider using `#destroy` instead, or pass `_force: true` as an argument. + MSG + expect { subject.update_column(:foo, 'bar') }.to raise_error(<<~MSG) + You are attempting to change the following audited columns: + [:foo] + + Using `update_column` is blocked because it skips audit logging (and other Rails callbacks)! + Consider using `#update!` instead, or pass `_force: true` as an argument. + MSG + expect { subject.update_columns(foo: 'bar') }.to raise_error(<<~MSG) + You are attempting to change the following audited columns: + [:foo] + + Using `update_columns` is blocked because it skips audit logging (and other Rails callbacks)! + Consider using `#update!` instead, or pass `_force: true` as an argument. + MSG + end + + it 'does not block the action if _force: true is passed' do + expect { subject.delete(_force: true) }.to not_raise_error + expect { subject.update_column(:foo, 'bar', _force: true) }.to not_raise_error + expect { subject.update_columns(foo: 'bar', _force: true) }.to not_raise_error + end + end + end + + describe '.delete_all, .insert, .insert_all, .update_all, .upsert, .upsert_all' do + subject { MyModel } + + before do + auditable_model.class_eval do + def self.delete_all(*); end + def self.insert(*); end + def self.insert_all(*); end + def self.update_all(*); end + def self.upsert(*); end + def self.upsert_all(*); end + end + end + + it 'does not block calls (because audit logging is disabled)' do + expect { subject.delete_all }.to not_raise_error + expect { subject.insert(foo: 'bar') }.to not_raise_error + expect { subject.insert_all([{ foo: 'bar' }]) }.to not_raise_error + expect { subject.update_all([{ foo: 'bar' }]) }.to not_raise_error + expect { subject.upsert(foo: 'bar') }.to not_raise_error + expect { subject.upsert_all([{ foo: 'bar' }]) }.to not_raise_error + end + + context 'when audit logging is enabled' do + before { auditable_model.class_eval { has_audit_log } } + + it 'blocks the action' do + expect { subject.delete_all }.to raise_error(<<~MSG) + `delete_all` is blocked because it skips callbacks and audit logs! + Consider using `.destroy_all` instead, or pass `_force: true` as an argument. + MSG + expect { subject.insert(foo: 'bar') }.to raise_error(<<~MSG) + `insert` is blocked because it skips callbacks and audit logs! + Consider using `.create!` instead, or pass `_force: true` as an argument. + MSG + expect { subject.insert_all([{ foo: 'bar' }]) }.to raise_error(<<~MSG) + `insert_all` is blocked because it skips callbacks and audit logs! + Consider using `.each { create!(...) }` instead, or pass `_force: true` as an argument. + MSG + expect { subject.update_all([{ foo: 'bar' }]) }.to raise_error(<<~MSG) + `update_all` is blocked because it skips callbacks and audit logs! + Consider using `.find_each { update!(...) }` instead, or pass `_force: true` as an argument. + MSG + expect { subject.upsert(foo: 'bar') }.to raise_error(<<~MSG) + `upsert` is blocked because it skips callbacks and audit logs! + Consider using `.create_or_find_by!` instead, or pass `_force: true` as an argument. + MSG + expect { subject.upsert_all([{ foo: 'bar' }]) }.to raise_error(<<~MSG) + `upsert_all` is blocked because it skips callbacks and audit logs! + Consider using `.each { create_or_find_by!(...) }` instead, or pass `_force: true` as an argument. + MSG + end + + it 'does not block the action when _force: true is passed' do + expect { subject.delete_all(_force: true) }.to not_raise_error + expect { subject.insert(foo: 'bar', _force: true) }.to not_raise_error + expect { subject.insert_all([{ foo: 'bar' }], _force: true) }.to not_raise_error + expect { subject.update_all([{ foo: 'bar' }], _force: true) }.to not_raise_error + expect { subject.upsert(foo: 'bar', _force: true) }.to not_raise_error + expect { subject.upsert_all([{ foo: 'bar' }], _force: true) }.to not_raise_error + end + end + end + # rubocop:enable Rails/SkipsModelValidations +end diff --git a/spec/spec_helper.rb b/spec/spec_helper.rb index a5b1367..7a091e5 100644 --- a/spec/spec_helper.rb +++ b/spec/spec_helper.rb @@ -1,9 +1,8 @@ rails_env = ENV['RAILS_ENV'] ||= 'test' require 'uncruft' -require File.expand_path('dummy/config/environment.rb', __dir__) +require 'active_support/testing/time_helpers' -Rails.application.config.active_record.sqlite3.represent_boolean_as_integer = true if Rails::VERSION::MAJOR < 6 -Rails.application.config.active_record.legacy_connection_handling = false if Rails::VERSION::MAJOR >= 7 +require File.expand_path('dummy/config/environment.rb', __dir__) Rails.configuration.database_configuration[rails_env].tap do |c| ActiveRecord::Tasks::DatabaseTasks.create(c) @@ -12,8 +11,11 @@ end RSpec::Matchers.define_negated_matcher :not_change, :change +RSpec::Matchers.define_negated_matcher :not_raise_error, :raise_error RSpec.configure do |config| + config.include ActiveSupport::Testing::TimeHelpers + config.expect_with :rspec do |expectations| expectations.include_chain_clauses_in_custom_matcher_descriptions = true end @@ -24,3 +26,44 @@ config.order = :random end + +RSpec::Matchers.define :emit_notification do |expected_event_name| + attr_reader :actual, :expected + + def supports_block_expectations? + true + end + + chain :with_payload, :expected_payload + chain :with_value, :expected_value + diffable + + match do |block| + @expected = { event_name: expected_event_name, payload: expected_payload, value: expected_value } + @actuals = [] + callback = ->(name, _started, _finished, _unique_id, payload) do + @actuals << { event_name: name, payload: payload.except(:value), value: payload[:value] } + end + + ActiveSupport::Notifications.subscribed(callback, expected_event_name, &block) + + unless expected_payload + @actuals.each { |a| a.delete(:payload) } + @expected.delete(:payload) + end + + @actual = @actuals.select { |a| values_match?(@expected.except(:value), a.except(:value)) } + @expected = [@expected] + values_match?(@expected, @actual) + end + + failure_message do + <<~MSG + Expected the code block to emit: + #{@expected.first.inspect} + + But instead, the following were emitted: + #{(@actual.presence || @actuals).map(&:inspect).join("\n ")} + MSG + end +end