Test helper: expect { }.to journal_event_including(...) (#24)

This introduces a new test helper. It allows you to check for one or more matching event being journaled:

```ruby
expect { my_code }.to journal_event_including(name: 'foo')
expect { my_code }.to journal_events_including({ name: 'foo', value: 1 }, { name: 'foo', value: 2 })
```

This will only do exact matches on the specified fields (and will not match one way or the other against unspecified fields). Part of the reason I didn't do exact matching across _all_ fields is that things like ID and git commit are generated on the fly, and I figured that what we really want is a way to concisely specify only the fields under test.

It also supports negative assertions (in two forms):

```ruby
expect { my_code }.not_to journal_event
expect { my_code }.to not_journal_event # supports chaining with `.and`
```

And it supports several chainable modifiers:

```ruby
expect { my_code }.to journal_event_including(name: 'foo')
  .with_schema_name('my_event_schema')
  .with_partition_key(user.id)
  .with_stream_name('my_stream_name')
  .with_enqueue_opts(run_at: future_time)
  .with_priority(999)
```

All of this can be chained together to test for multiple sets of events with multiple sets of options:

```ruby
expect { subject.journal! }
  .to journal_events_including({ name: 'event1', value: 300 }, { name: 'event2', value: 200 })
    .with_schema_name('set_1_schema')
    .with_partition_key('set_1_partition_key')
    .with_stream_name('set_1_stream_name')
    .with_priority(10)
  .and journal_event_including(name: 'event3', value: 100)
    .with_schema_name('set_2_schema')
    .with_partition_key('set_2_partition_key')
    .with_stream_name('set_2_stream_name')
    .with_priority(20)
  .and not_journal_event_including(name: 'other_event')
```

As a bonus, this emits a new `ActiveSupport::Notification` that could be consumed to, say, emit a `StatsD` event, etc. I added a callout in the README.

.rubocop_todo.yml

@@ -1,6 +1,6 @@
 # This configuration was generated by
 # `rubocop --auto-gen-config`
-# on 2019-09-13 12:19:43 -0400 using RuboCop version 0.61.1.
+# on 2022-04-06 17:45:31 UTC using RuboCop version 1.26.0.
 # The point is for the user to remove these configuration records
 # one by one as the offenses are removed from the code base.
 # Note that changes in the inspected code, or installation of new
@@ -16,12 +16,10 @@ RSpec/SubjectStub:
   Exclude:
     - 'spec/models/concerns/journaled/actor_spec.rb'
 
-# Offense count: 16
-# Configuration parameters: IgnoreSymbolicNames.
+# Offense count: 12
+# Configuration parameters: IgnoreNameless, IgnoreSymbolicNames.
 RSpec/VerifiedDoubles:
   Exclude:
     - 'spec/models/concerns/journaled/actor_spec.rb'
-    - 'spec/models/concerns/journaled/changes_spec.rb'
     - 'spec/models/journaled/actor_uri_provider_spec.rb'
     - 'spec/models/journaled/change_writer_spec.rb'
-    - 'spec/models/journaled/writer_spec.rb'

README.md

@@ -179,52 +179,6 @@ journaling. Note that the less-frequently-used methods `toggle`,
 `increment*`, `decrement*`, and `update_counters` are not intercepted at
 this time.
 
-### Tagged Events
-
-Events may be optionally marked as "tagged." This will add a `tags` field, intended for tracing and
-auditing purposes.
-
-```ruby
-class MyEvent
-  include Journaled::Event
-
-  journal_attributes :attr_1, :attr_2, tagged: true
-end
-```
-
-You may then use `Journaled.tag!` and `Journaled.tagged` inside of your
-`ApplicationController` and `ApplicationJob` classes (or anywhere else!) to tag
-all events with request and job metadata:
-
-```ruby
-class ApplicationController < ActionController::Base
-  before_action do
-    Journaled.tag!(request_id: request.request_id, current_user_id: current_user&.id)
-  end
-end
-
-class ApplicationJob < ActiveJob::Base
-  around_perform do |job, perform|
-    Journaled.tagged(job_id: job.id) { perform.call }
-  end
-end
-```
-
-This feature relies on `ActiveSupport::CurrentAttributes` under the hood, so these tags are local to
-the current thread, and will be cleared at the end of each request request/job.
-
-#### Testing
-
-If you use RSpec (and have required `journaled/rspec` in your
-`spec/rails_helper.rb`), you can regression-protect important journaling
-config with the `journal_changes_to` matcher:
-
-```ruby
-it "journals exactly these things or there will be heck to pay" do
-  expect(User).to journal_changes_to(:email, :first_name, :last_name, as: :identity_change)
-end
-```
-
 ### Custom Journaling
 
 For every custom implementation of journaling in your application, define the JSON schema for the attributes in your event.
@@ -309,6 +263,40 @@ An event like the following will be journaled to kinesis:
 }
 ```
 
+### Tagged Events
+
+Events may be optionally marked as "tagged." This will add a `tags` field, intended for tracing and
+auditing purposes.
+
+```ruby
+class MyEvent
+  include Journaled::Event
+
+  journal_attributes :attr_1, :attr_2, tagged: true
+end
+```
+
+You may then use `Journaled.tag!` and `Journaled.tagged` inside of your
+`ApplicationController` and `ApplicationJob` classes (or anywhere else!) to tag
+all events with request and job metadata:
+
+```ruby
+class ApplicationController < ActionController::Base
+  before_action do
+    Journaled.tag!(request_id: request.request_id, current_user_id: current_user&.id)
+  end
+end
+
+class ApplicationJob < ActiveJob::Base
+  around_perform do |job, perform|
+    Journaled.tagged(job_id: job.id) { perform.call }
+  end
+end
+```
+
+This feature relies on `ActiveSupport::CurrentAttributes` under the hood, so these tags are local to
+the current thread, and will be cleared at the end of each request request/job.
+
 ### Helper methods for custom events
 
 Journaled provides a couple helper methods that may be useful in your
@@ -352,6 +340,102 @@ Returns one of the following in order of preference:
 In order for this to be most useful, you must configure your controller
 as described in [Change Journaling](#change-journaling) above.
 
+### Testing
+
+If you use RSpec, you can test for journaling behaviors with the
+`journal_event(s)_including` and `journal_changes_to` matchers. First, make
+sure to require `journaled/rspec` in your spec setup (e.g.
+`spec/rails_helper.rb`):
+
+```ruby
+require 'journaled/rspec'
+```
+
+#### Checking for specific events
+
+The `journal_event_including` and `journal_events_including` matchers allow you
+to check for one or more matching event being journaled:
+
+```ruby
+expect { my_code }
+  .to journal_event_including(name: 'foo')
+expect { my_code }
+  .to journal_events_including({ name: 'foo', value: 1 }, { name: 'foo', value: 2 })
+```
+
+This will only perform matches on the specified fields (and will not match one
+way or the other against unspecified fields). These matchers will also ignore
+any extraneous events that are not positively matched (as they may be unrelated
+to behavior under test).
+
+When writing tests, pairing every positive assertion with a negative assertion
+is a good practice, and so negative matching is also supported (via both
+`.not_to` and `.to not_`):
+
+```ruby
+expect { my_code }
+  .not_to journal_events_including({ name: 'foo' }, { name: 'bar' })
+expect { my_code }
+  .to raise_error(SomeError)
+  .and not_journal_event_including(name: 'foo') # the `not_` variant can chain off of `.and`
+```
+
+Several chainable modifiers are also available:
+
+```ruby
+expect { my_code }.to journal_event_including(name: 'foo')
+  .with_schema_name('my_event_schema')
+  .with_partition_key(user.id)
+  .with_stream_name('my_stream_name')
+  .with_enqueue_opts(run_at: future_time)
+  .with_priority(999)
+```
+
+All of this can be chained together to test for multiple sets of events with
+multiple sets of options:
+
+```ruby
+expect { subject.journal! }
+  .to journal_events_including({ name: 'event1', value: 300 }, { name: 'event2', value: 200 })
+    .with_priority(10)
+  .and journal_event_including(name: 'event3', value: 100)
+    .with_priority(20)
+  .and not_journal_event_including(name: 'other_event')
+```
+
+#### Checking for `Journaled::Changes` declarations
+
+The `journal_changes_to` matcher checks against the list of attributes specified
+on the model. It does not actually test that an event is emitted within a given
+codepath, and is instead intended to guard against accidental regressions that
+may impact external consumers of these events:
+
+```ruby
+it "journals exactly these things or there will be heck to pay" do
+  expect(User).to journal_changes_to(:email, :first_name, :last_name, as: :identity_change)
+end
+```
+
+### Instrumentation
+
+When an event is enqueued, an `ActiveSupport::Notification` titled
+`journaled.event.enqueue` is emitted. Its payload will include the `:event` and
+its background job `:priority`.
+
+This can be forwarded along to your preferred monitoring solution via a Rails
+initializer:
+
+```ruby
+ActiveSupport::Notifications.subscribe('journaled.event.enqueue') do |*args|
+  payload = ActiveSupport::Notifications::Event.new(*args).payload
+  journaled_event = payload[:event]
+
+  tags = { priority: payload[:priority], event_type: journaled_event.journaled_attributes[:event_type] }
+
+  Statsd.increment('journaled.event.enqueue', tags: tags.map { |k,v| "#{k.to_s[0..64]}:#{v.to_s[0..255]}" })
+end
+```
+
 ## Upgrades
 
 Since this gem relies on background jobs (which can remain in the queue across

app/models/journaled/event.rb

@@ -63,7 +63,7 @@ def event_type
   end
 
   included do
-    cattr_accessor(:journaled_enqueue_opts, instance_writer: false) { {} }
+    class_attribute :journaled_enqueue_opts, default: {}
 
     journal_attributes :id, :event_type, :created_at
   end

app/models/journaled/writer.rb

@@ -26,9 +26,9 @@ def initialize(journaled_event:)
 
   def journal!
     validate!
-    Journaled::DeliveryJob
-      .set(journaled_enqueue_opts.reverse_merge(priority: Journaled.job_priority))
-      .perform_later(**delivery_perform_args)
+    ActiveSupport::Notifications.instrument('journaled.event.enqueue', event: journaled_event, priority: job_opts[:priority]) do
+      Journaled::DeliveryJob.set(job_opts).perform_later(**delivery_perform_args)
+    end
   end
 
   private
@@ -43,6 +43,10 @@ def validate!
     schema_validator(journaled_schema_name).validate! serialized_event
   end
 
+  def job_opts
+    journaled_enqueue_opts.reverse_merge(priority: Journaled.job_priority)
+  end
+
   def delivery_perform_args
     {
       serialized_event: serialized_event,

lib/journaled/rspec.rb

@@ -16,3 +16,89 @@
     "expected #{model_class} not to journal changes to #{attribute_names.map(&:inspect).join(', ')} as #{as.inspect}"
   end
 end
+
+RSpec::Matchers.define_negated_matcher :not_journal_changes_to, :journal_changes_to
+
+RSpec::Matchers.define :journal_events_including do |*expected_events|
+  raise "Please specify at least one expected event. RSpec argument matchers are supported." if expected_events.empty?
+
+  attr_accessor :expected, :actual, :matches, :nonmatches
+
+  chain :with_schema_name, :expected_schema_name
+  chain :with_partition_key, :expected_partition_key
+  chain :with_stream_name, :expected_stream_name
+  chain :with_enqueue_opts, :expected_enqueue_opts
+  chain :with_priority, :expected_priority
+
+  def supports_block_expectations?
+    true
+  end
+
+  def hash_including_recursive(hash)
+    hash_including(
+      hash.transform_values { |v| v.is_a?(Hash) ? hash_including_recursive(v) : v },
+    )
+  end
+
+  match do |block|
+    expected_events = [expected_events.first].flatten(1) unless expected_events.length > 1
+
+    self.expected = expected_events.map { |e| { journaled_attributes: e } }
+    expected.each { |e| e.merge!(journaled_schema_name: expected_schema_name) } if expected_schema_name
+    expected.each { |e| e.merge!(journaled_partition_key: expected_partition_key) } if expected_partition_key
+    expected.each { |e| e.merge!(journaled_stream_name: expected_stream_name) } if expected_stream_name
+    expected.each { |e| e.merge!(journaled_enqueue_opts: expected_enqueue_opts) } if expected_enqueue_opts
+    expected.each { |e| e.merge!(priority: expected_priority) } if expected_priority
+    self.actual = []
+
+    callback = ->(_name, _started, _finished, _unique_id, payload) do
+      event = payload[:event]
+      a = { journaled_attributes: event.journaled_attributes }
+      a[:journaled_schema_name] = event.journaled_schema_name if expected_schema_name
+      a[:journaled_partition_key] = event.journaled_partition_key if expected_partition_key
+      a[:journaled_stream_name] = event.journaled_stream_name if expected_stream_name
+      a[:journaled_enqueue_opts] = event.journaled_enqueue_opts if expected_enqueue_opts
+      a[:priority] = payload[:priority] if expected_priority
+      actual << a
+    end
+
+    ActiveSupport::Notifications.subscribed(callback, 'journaled.event.enqueue', &block)
+
+    self.matches = actual.select do |a|
+      expected.any? { |e| values_match?(hash_including_recursive(e), a) }
+    end
+
+    self.nonmatches = actual - matches
+
+    exact_matches = matches.dup
+    matches.count == expected.count && expected.all? do |e|
+      match, index = exact_matches.each_with_index.find { |a, _| values_match?(hash_including_recursive(e), a) }
+      exact_matches.delete_at(index) if match
+    end && exact_matches.empty?
+  end
+
+  failure_message do
+    <<~MSG
+      Expected the code block to journal exactly one matching event per expected event.
+
+      Expected Events (#{expected.count}):
+      ===============================================================================
+        #{expected.map(&:to_json).join("\n ")}
+      ===============================================================================
+
+      Matching Events (#{matches.count}):
+      ===============================================================================
+        #{matches.map(&:to_json).join("\n ")}
+      ===============================================================================
+
+      Non-Matching Events (#{nonmatches.count}):
+      ===============================================================================
+        #{nonmatches.map(&:to_json).join("\n  ")}
+      ===============================================================================
+    MSG
+  end
+end
+
+RSpec::Matchers.alias_matcher :journal_event_including, :journal_events_including
+RSpec::Matchers.define_negated_matcher :not_journal_events_including, :journal_events_including
+RSpec::Matchers.define_negated_matcher :not_journal_event_including, :journal_event_including

lib/journaled/version.rb

@@ -1,3 +1,3 @@
 module Journaled
-  VERSION = "4.2.0".freeze
+  VERSION = "4.3.0".freeze
 end

spec/models/concerns/journaled/changes_spec.rb

@@ -44,7 +44,7 @@ def trigger_after_destroy_hooks
 
   subject { klass.new }
 
-  let(:change_writer) { double(Journaled::ChangeWriter, create: true, update: true, delete: true) }
+  let(:change_writer) { instance_double(Journaled::ChangeWriter, create: true, update: true, delete: true) }
 
   before do
     allow(Journaled::ChangeWriter).to receive(:new) do |opts|