From e58814c81297dcbe438dc96dab865e23e318798d Mon Sep 17 00:00:00 2001
From: Vladimir Dementyev <dementiev.vm@gmail.com>
Date: Fri, 20 Apr 2018 19:22:55 -0400
Subject: [PATCH 1/4] Add policy#apply instrumentation for Rails

---
 lib/action_policy/policy/cache.rb             |  5 +-
 lib/action_policy/policy/execution_result.rb  |  8 ++
 .../rails/policy/instrumentation.rb           | 24 ++++++
 lib/action_policy/railtie.rb                  |  6 ++
 test/action_policy/policy/cache_test.rb       | 24 +-----
 .../rails/policy/instrumentation_test.rb      | 80 +++++++++++++++++++
 test/stubs/in_memory_cache.rb                 | 25 ++++++
 7 files changed, 148 insertions(+), 24 deletions(-)
 create mode 100644 lib/action_policy/rails/policy/instrumentation.rb
 create mode 100644 test/action_policy/rails/policy/instrumentation_test.rb
 create mode 100644 test/stubs/in_memory_cache.rb

diff --git a/lib/action_policy/policy/cache.rb b/lib/action_policy/policy/cache.rb
index 50c64ce2..3bb4c8bc 100644
--- a/lib/action_policy/policy/cache.rb
+++ b/lib/action_policy/policy/cache.rb
@@ -42,7 +42,10 @@ def apply_with_cache(rule)
 
         ActionPolicy.cache_store.then do |store|
           @result = store.read(key)
-          next result.value unless result.nil?
+          unless result.nil?
+            result.cached!
+            next result.value
+          end
           yield
           store.write(key, result, options)
           result.value
diff --git a/lib/action_policy/policy/execution_result.rb b/lib/action_policy/policy/execution_result.rb
index 31deb080..7c48adcd 100644
--- a/lib/action_policy/policy/execution_result.rb
+++ b/lib/action_policy/policy/execution_result.rb
@@ -27,6 +27,14 @@ def fail?
         @value == false
       end
 
+      def cached!
+        @cached = true
+      end
+
+      def cached?
+        @cached == true
+      end
+
       def inspect
         "<#{policy}##{rule}: #{@value}>"
       end
diff --git a/lib/action_policy/rails/policy/instrumentation.rb b/lib/action_policy/rails/policy/instrumentation.rb
new file mode 100644
index 00000000..ac9bcf2c
--- /dev/null
+++ b/lib/action_policy/rails/policy/instrumentation.rb
@@ -0,0 +1,24 @@
+# frozen_string_literal: true
+
+module ActionPolicy # :nodoc:
+  module Policy
+    module Rails
+      # Add ActiveSupport::Notifications support.
+      #
+      # Fires `action_policy.apply` event on every `#apply` call.
+      module Instrumentation
+        EVENT_NAME = "action_policy.apply"
+
+        def apply(rule)
+          event = {policy: self.class.name, rule: rule.to_s}
+          ActiveSupport::Notifications.instrument(EVENT_NAME, event) do
+            res = super
+            event[:cached] = result.cached?
+            event[:value] = result.value
+            res
+          end
+        end
+      end
+    end
+  end
+end
diff --git a/lib/action_policy/railtie.rb b/lib/action_policy/railtie.rb
index f6914fae..1bb56da2 100644
--- a/lib/action_policy/railtie.rb
+++ b/lib/action_policy/railtie.rb
@@ -61,6 +61,12 @@ def cache_store=(store)
       end
     end
 
+    initializer "action_policy.instrumentation" do |_app|
+      require "action_policy/rails/policy/instrumentation"
+
+      ActionPolicy::Base.include ActionPolicy::Policy::Rails::Instrumentation
+    end
+
     config.to_prepare do |_app|
       ActionPolicy::LookupChain.namespace_cache_enabled =
         Rails.application.config.action_policy.namespace_cache_enabled
diff --git a/test/action_policy/policy/cache_test.rb b/test/action_policy/policy/cache_test.rb
index f78a92d4..3e0c7b77 100644
--- a/test/action_policy/policy/cache_test.rb
+++ b/test/action_policy/policy/cache_test.rb
@@ -2,29 +2,7 @@
 
 require "test_helper"
 
-class InMemoryCache
-  attr_accessor :store
-
-  def initialize
-    self.store = {}
-  end
-
-  def read(key)
-    deserialize(store[key]) if store.key?(key)
-  end
-
-  def write(key, val, _options)
-    store[key] = serialize(val)
-  end
-
-  def serialize(val)
-    Marshal.dump(val)
-  end
-
-  def deserialize(val)
-    Marshal.load(val)
-  end
-end
+require "stubs/in_memory_cache"
 
 class TestCache < Minitest::Test
   class TestPolicy
diff --git a/test/action_policy/rails/policy/instrumentation_test.rb b/test/action_policy/rails/policy/instrumentation_test.rb
new file mode 100644
index 00000000..6d3a363a
--- /dev/null
+++ b/test/action_policy/rails/policy/instrumentation_test.rb
@@ -0,0 +1,80 @@
+# frozen_string_literal: true
+
+require "test_helper"
+require "active_support"
+require "action_policy/rails/policy/instrumentation"
+
+class TestRailsInstrumentation < Minitest::Test
+  class TestPolicy
+    include ActionPolicy::Policy::Core
+    include ActionPolicy::Policy::Cache
+    include ActionPolicy::Policy::Rails::Instrumentation
+
+    cache :manage?
+
+    def manage?
+      true
+    end
+
+    def show?
+      false || record
+    end
+
+    def authorization_context
+      {}
+    end
+  end
+
+  def setup
+    ActionPolicy.cache_store = InMemoryCache.new
+    @events = []
+
+    ActiveSupport::Notifications.subscribe(/action_policy\./) do |event, *, data|
+      @events << [event, data]
+    end
+  end
+
+  def teardown
+    ActionPolicy.cache_store = nil
+  end
+
+  attr_reader :events
+
+  def test_instrument_apply
+    policy = TestPolicy.new false
+
+    refute policy.apply(:show?)
+
+    assert_equal 1, events.size
+
+    event, data = events.pop
+
+    assert_equal "action_policy.apply", event
+    assert_equal TestPolicy.name, data[:policy]
+    assert_equal "show?", data[:rule]
+    refute data[:cached]
+  end
+
+  def test_instrument_cached_apply
+    policy = TestPolicy.new true
+
+    assert policy.apply(:manage?)
+
+    assert_equal 1, events.size
+
+    event, data = events.pop
+
+    assert_equal "action_policy.apply", event
+    assert_equal TestPolicy.name, data[:policy]
+    assert_equal "manage?", data[:rule]
+    assert_equal false, data[:cached]
+
+    assert policy.apply(:manage?)
+
+    assert_equal 1, events.size
+
+    _event_2, data_2 = events.pop
+
+    assert_equal true, data_2[:cached]
+  end
+end
diff --git a/test/stubs/in_memory_cache.rb b/test/stubs/in_memory_cache.rb
new file mode 100644
index 00000000..2b503039
--- /dev/null
+++ b/test/stubs/in_memory_cache.rb
@@ -0,0 +1,25 @@
+# frozen_string_literal: true
+
+class InMemoryCache
+  attr_accessor :store
+
+  def initialize
+    self.store = {}
+  end
+
+  def read(key)
+    deserialize(store[key]) if store.key?(key)
+  end
+
+  def write(key, val, _options)
+    store[key] = serialize(val)
+  end
+
+  def serialize(val)
+    Marshal.dump(val)
+  end
+
+  def deserialize(val)
+    Marshal.load(val)
+  end
+end

From cd010132a31a5290ce3634dcb53fd570d0e08832 Mon Sep 17 00:00:00 2001
From: Vladimir Dementyev <dementiev.vm@gmail.com>
Date: Sat, 30 Mar 2019 12:06:57 -0400
Subject: [PATCH 2/4] feat: add 'action_policy.authorize' instrumentation

---
 lib/action_policy/authorizer.rb               |  6 +-
 lib/action_policy/policy/core.rb              |  2 +-
 lib/action_policy/rails/authorizer.rb         | 20 +++++++
 .../rails/policy/instrumentation.rb           |  4 +-
 lib/action_policy/railtie.rb                  | 16 ++---
 .../{policy => }/instrumentation_test.rb      | 60 ++++++++++++++++++-
 6 files changed, 95 insertions(+), 13 deletions(-)
 create mode 100644 lib/action_policy/rails/authorizer.rb
 rename test/action_policy/rails/{policy => }/instrumentation_test.rb (52%)

diff --git a/lib/action_policy/authorizer.rb b/lib/action_policy/authorizer.rb
index b40c837a..a3d8dec2 100644
--- a/lib/action_policy/authorizer.rb
+++ b/lib/action_policy/authorizer.rb
@@ -20,10 +20,14 @@ module Authorizer
     class << self
       # Performs authorization, raises an exception when check failed.
       def call(policy, rule)
-        policy.apply(rule) ||
+        authorize(policy, rule) ||
           raise(::ActionPolicy::Unauthorized.new(policy, rule))
       end
 
+      def authorize(policy, rule)
+        policy.apply(rule)
+      end
+
       # Applies scope to the target
       def scopify(target, policy, **options)
         policy.apply_scope(target, **options)
diff --git a/lib/action_policy/policy/core.rb b/lib/action_policy/policy/core.rb
index c7a69cb3..e90ef072 100644
--- a/lib/action_policy/policy/core.rb
+++ b/lib/action_policy/policy/core.rb
@@ -65,7 +65,7 @@ def identifier
 
       attr_reader :record, :result
 
-      def initialize(record = nil)
+      def initialize(record = nil, **_opts)
         @record = record
       end
 
diff --git a/lib/action_policy/rails/authorizer.rb b/lib/action_policy/rails/authorizer.rb
new file mode 100644
index 00000000..39f1ae72
--- /dev/null
+++ b/lib/action_policy/rails/authorizer.rb
@@ -0,0 +1,20 @@
+# frozen_string_literal: true
+
+module ActionPolicy # :nodoc:
+  module Rails
+    # Add instrumentation for `authorize!` method
+    module Authorizer
+      EVENT_NAME = "action_policy.authorize"
+
+      def authorize(policy, rule)
+        event = {policy: policy.class.name, rule: rule.to_s}
+        ActiveSupport::Notifications.instrument(EVENT_NAME, event) do
+          res = super
+          event[:cached] = policy.result.cached?
+          event[:value] = policy.result.value
+          res
+        end
+      end
+    end
+  end
+end
diff --git a/lib/action_policy/rails/policy/instrumentation.rb b/lib/action_policy/rails/policy/instrumentation.rb
index ac9bcf2c..71647341 100644
--- a/lib/action_policy/rails/policy/instrumentation.rb
+++ b/lib/action_policy/rails/policy/instrumentation.rb
@@ -5,9 +5,9 @@ module Policy
     module Rails
       # Add ActiveSupport::Notifications support.
       #
-      # Fires `action_policy.apply` event on every `#apply` call.
+      # Fires `action_policy.apply_rule` event on every `#apply` call.
       module Instrumentation
-        EVENT_NAME = "action_policy.apply"
+        EVENT_NAME = "action_policy.apply_rule"
 
         def apply(rule)
           event = {policy: self.class.name, rule: rule.to_s}
diff --git a/lib/action_policy/railtie.rb b/lib/action_policy/railtie.rb
index 1bb56da2..a805dc16 100644
--- a/lib/action_policy/railtie.rb
+++ b/lib/action_policy/railtie.rb
@@ -46,13 +46,13 @@ def cache_store=(store)
       self.controller_authorize_current_user = true
       self.auto_inject_into_channel = true
       self.channel_authorize_current_user = true
-      self.namespace_cache_enabled = Rails.env.production?
+      self.namespace_cache_enabled = ::Rails.env.production?
     end
 
     config.action_policy = Config
 
     initializer "action_policy.clear_per_thread_cache" do |app|
-      if Rails::VERSION::MAJOR >= 5
+      if ::Rails::VERSION::MAJOR >= 5
         app.executor.to_run { ActionPolicy::PerThreadCache.clear_all }
         app.executor.to_complete { ActionPolicy::PerThreadCache.clear_all }
       else
@@ -63,32 +63,34 @@ def cache_store=(store)
 
     initializer "action_policy.instrumentation" do |_app|
       require "action_policy/rails/policy/instrumentation"
+      require "action_policy/rails/authorizer"
 
       ActionPolicy::Base.include ActionPolicy::Policy::Rails::Instrumentation
+      ActionPolicy::Authorizer.singleton_class.prepend ActionPolicy::Rails::Authorizer
     end
 
     config.to_prepare do |_app|
       ActionPolicy::LookupChain.namespace_cache_enabled =
-        Rails.application.config.action_policy.namespace_cache_enabled
+        ::Rails.application.config.action_policy.namespace_cache_enabled
 
       ActiveSupport.on_load(:action_controller) do
         require "action_policy/rails/scope_matchers/action_controller_params"
 
-        next unless Rails.application.config.action_policy.auto_inject_into_controller
+        next unless ::Rails.application.config.action_policy.auto_inject_into_controller
 
         ActionController::Base.include ActionPolicy::Controller
 
-        next unless Rails.application.config.action_policy.controller_authorize_current_user
+        next unless ::Rails.application.config.action_policy.controller_authorize_current_user
 
         ActionController::Base.authorize :user, through: :current_user
       end
 
       ActiveSupport.on_load(:action_cable) do
-        next unless Rails.application.config.action_policy.auto_inject_into_channel
+        next unless ::Rails.application.config.action_policy.auto_inject_into_channel
 
         ActionCable::Channel::Base.include ActionPolicy::Channel
 
-        next unless Rails.application.config.action_policy.channel_authorize_current_user
+        next unless ::Rails.application.config.action_policy.channel_authorize_current_user
 
         ActionCable::Channel::Base.authorize :user, through: :current_user
       end
diff --git a/test/action_policy/rails/policy/instrumentation_test.rb b/test/action_policy/rails/instrumentation_test.rb
similarity index 52%
rename from test/action_policy/rails/policy/instrumentation_test.rb
rename to test/action_policy/rails/instrumentation_test.rb
index 6d3a363a..7defb36d 100644
--- a/test/action_policy/rails/policy/instrumentation_test.rb
+++ b/test/action_policy/rails/instrumentation_test.rb
@@ -1,8 +1,13 @@
 # frozen_string_literal: true
 
 require "test_helper"
+require "stubs/in_memory_cache"
+
 require "active_support"
 require "action_policy/rails/policy/instrumentation"
+require "action_policy/rails/authorizer"
+
+ActionPolicy::Authorizer.singleton_class.prepend ActionPolicy::Rails::Authorizer
 
 class TestRailsInstrumentation < Minitest::Test
   class TestPolicy
@@ -25,6 +30,20 @@ def authorization_context
     end
   end
 
+  class Service
+    include ActionPolicy::Behaviour
+
+    def call
+      authorize! :nil, to: :manage?, with: TestPolicy
+
+      "OK"
+    end
+
+    def visible?(record)
+      allowed_to? :show?, record, with: TestPolicy
+    end
+  end
+
   def setup
     ActionPolicy.cache_store = InMemoryCache.new
     @events = []
@@ -49,9 +68,10 @@ def test_instrument_apply
 
     event, data = events.pop
 
-    assert_equal "action_policy.apply", event
+    assert_equal "action_policy.apply_rule", event
     assert_equal TestPolicy.name, data[:policy]
     assert_equal "show?", data[:rule]
+    refute data[:value]
     refute data[:cached]
   end
 
@@ -64,7 +84,7 @@ def test_instrument_cached_apply
 
     event, data = events.pop
 
-    assert_equal "action_policy.apply", event
+    assert_equal "action_policy.apply_rule", event
     assert_equal TestPolicy.name, data[:policy]
     assert_equal "manage?", data[:rule]
     assert_equal false, data[:cached]
@@ -77,4 +97,40 @@ def test_instrument_cached_apply
 
     assert_equal true, data_2[:cached]
   end
+
+  def test_instrument_authorize
+    service = Service.new
+
+    assert_equal "OK", service.call
+    assert_equal 2, events.size
+
+    event, data = events.shift
+
+    assert_equal "action_policy.apply_rule", event
+    assert_equal TestPolicy.name, data[:policy]
+    assert_equal "manage?", data[:rule]
+    assert data[:value]
+    refute data[:cached]
+
+    event, data = events.shift
+
+    assert_equal "action_policy.authorize", event
+    assert_equal TestPolicy.name, data[:policy]
+    assert_equal "manage?", data[:rule]
+    assert data[:value]
+    refute data[:cached]
+
+    refute service.visible?(false)
+
+    assert_equal 1, events.size
+
+    event, data = events.shift
+
+    assert_equal "action_policy.apply_rule", event
+
+    assert_equal TestPolicy.name, data[:policy]
+    assert_equal "show?", data[:rule]
+    refute data[:value]
+    refute data[:cached]
+  end
 end

From d8ccbb81b78f097394a06c8d2036711e78fd0610 Mon Sep 17 00:00:00 2001
From: Vladimir Dementyev <dementiev.vm@gmail.com>
Date: Sat, 30 Mar 2019 12:30:29 -0400
Subject: [PATCH 3/4] docs: add instrumentation

---
 CHANGELOG.md            |  4 +++
 docs/instrumentation.md | 62 +++++++++++++++++++++++++++++++++++++++--
 2 files changed, 64 insertions(+), 2 deletions(-)

diff --git a/CHANGELOG.md b/CHANGELOG.md
index 9dd5f425..36769f16 100644
--- a/CHANGELOG.md
+++ b/CHANGELOG.md
@@ -1,5 +1,9 @@
 ## master
 
+- Added ActiveSupport-based instrumentation. ([@palkan][])
+
+  See [PR#4](https://github.com/palkan/action_policy/pull/4)
+
 - Allow passing authorization context explicitly. ([@palkan][])
 
   Closes [#3](https://github.com/palkan/action_policy/issues/3).
diff --git a/docs/instrumentation.md b/docs/instrumentation.md
index 2626dcf1..9986d0c8 100644
--- a/docs/instrumentation.md
+++ b/docs/instrumentation.md
@@ -1,5 +1,63 @@
 # Instrumentation
 
-🛠 **WORK IN PROGRESS**
+Action Policy integrates with [Rails instrumentation system](https://guides.rubyonrails.org/active_support_instrumentation.html), `ActiveSupport::Notifications`.
 
-See [the PR](https://github.com/palkan/action_policy/pull/4).
+## Events
+
+### `action_policy.apply_rule`
+
+This event is triggered every time a policy rule is applied:
+- when `authorize!` is called
+- when `allowed_to?` is called within the policy or the [behaviour](behaviour)
+- when `apply_rule` is called explicitly (i.e. `SomePolicy.new(record, context).apply_rule(record)`).
+
+The event contains the following information:
+- `:policy` – policy class name
+- `:rule` – applied rule (String)
+- `:value` – the result of the rule application (true of false)
+- `:cached` – whether we hit the [cache](caching)\*.
+
+\* This parameter tracks only the cache store usage, not memoization.
+
+You can use this event to track your policy cache usage and also detect _slow_ checks.
+
+Here is an example code for sending policy stats to [Librato](https://librato.com/)
+using [`librato-rack`](https://github.com/librato/librato-rack):
+
+```ruby
+ActiveSupport::Notifications.subscribe("action_policy.apply_rule") do |event, started, finished, _, data|
+  # Track hit and miss events separately (to display two measurements)
+  measurement = "#{event}.#{(data[:cached] ? "hit" : "miss")}"
+  # show ms times
+  timing = ((finished - started) * 1000).to_i
+  Librato.tracker.check_worker
+  Librato.timing measurement, timing, percentile: [95, 99]
+end
+```
+
+### `action_policy.authorize`
+
+This event is identitical to `action_policy.apply_rule` with the one difference:
+**it's only triggered when `authorize!` method is called**.
+
+The motivation behind having a separate event for this method is to monitor the number of failed
+authorizations: the very high number of failed authorization usually means that we do not take
+into account authorization rules in the application UI (e.g. we show a "Delete" button to the user not
+permitted to do that).
+
+The `action_policy.apply_rule` might have a large number of failures, 'cause it also tracks the usage of non-raising applications (i.e. `allowed_to?`).
+
+## Non-Rails usage
+
+If you don't use Rails itself but have `ActiveSupport::Notifications` available in your application,
+you can use the instrumentation feature with some additional configuration:
+
+```ruby
+# Enable `apply_rule` event by extending the base policy class
+require "action_policy/rails/policy/instrumentation"
+ActionPolicy::Base.include ActionPolicy::Policy::Rails::Instrumentation
+
+# Enabled `authorize` event by extending the authorizer class
+require "action_policy/rails/authorizer"
+ActionPolicy::Authorizer.singleton_class.prepend ActionPolicy::Rails::Authorizer
+```

From 47c0612c722a0db0eb370cf48f99f4edbc650a41 Mon Sep 17 00:00:00 2001
From: Vladimir Dementyev <dementiev.vm@gmail.com>
Date: Sat, 30 Mar 2019 12:48:55 -0400
Subject: [PATCH 4/4] feat: add ability to turn off instrumentation

---
 docs/instrumentation.md                          | 16 +++++++++++++---
 lib/action_policy/railtie.rb                     | 11 +++++++++--
 test/action_policy/rails/instrumentation_test.rb |  2 +-
 3 files changed, 23 insertions(+), 6 deletions(-)

diff --git a/docs/instrumentation.md b/docs/instrumentation.md
index 9986d0c8..1f342953 100644
--- a/docs/instrumentation.md
+++ b/docs/instrumentation.md
@@ -37,16 +37,26 @@ end
 
 ### `action_policy.authorize`
 
-This event is identitical to `action_policy.apply_rule` with the one difference:
+This event is identical to `action_policy.apply_rule` with the one difference:
 **it's only triggered when `authorize!` method is called**.
 
 The motivation behind having a separate event for this method is to monitor the number of failed
-authorizations: the very high number of failed authorization usually means that we do not take
-into account authorization rules in the application UI (e.g. we show a "Delete" button to the user not
+authorizations: the high number of failed authorizations usually means that we do not take
+into account authorization rules in the application UI (e.g., we show a "Delete" button to the user not
 permitted to do that).
 
 The `action_policy.apply_rule` might have a large number of failures, 'cause it also tracks the usage of non-raising applications (i.e. `allowed_to?`).
 
+## Turn off instrumentation
+
+Instrumentation is enabled by default. To turn it off add to your configuration:
+
+```ruby
+config.action_policy.instrumentation_enabled = false
+```
+
+**NOTE:** changing this setting after the application has been initialized doesn't take any effect.
+
 ## Non-Rails usage
 
 If you don't use Rails itself but have `ActiveSupport::Notifications` available in your application,
diff --git a/lib/action_policy/railtie.rb b/lib/action_policy/railtie.rb
index a805dc16..d4798323 100644
--- a/lib/action_policy/railtie.rb
+++ b/lib/action_policy/railtie.rb
@@ -30,6 +30,10 @@ class << self
         # Enabled only in production by default.
         attr_accessor :namespace_cache_enabled
 
+        # Define whether to include instrumentation functionality.
+        # Enabled by default.
+        attr_accessor :instrumentation_enabled
+
         def cache_store=(store)
           # Handle both:
           #   store = :memory
@@ -47,6 +51,7 @@ def cache_store=(store)
       self.auto_inject_into_channel = true
       self.channel_authorize_current_user = true
       self.namespace_cache_enabled = ::Rails.env.production?
+      self.instrumentation_enabled = true
     end
 
     config.action_policy = Config
@@ -61,11 +66,13 @@ def cache_store=(store)
       end
     end
 
-    initializer "action_policy.instrumentation" do |_app|
+    config.after_initialize do
+      next unless ::Rails.application.config.action_policy.instrumentation_enabled
+
       require "action_policy/rails/policy/instrumentation"
       require "action_policy/rails/authorizer"
 
-      ActionPolicy::Base.include ActionPolicy::Policy::Rails::Instrumentation
+      ActionPolicy::Base.prepend ActionPolicy::Policy::Rails::Instrumentation
       ActionPolicy::Authorizer.singleton_class.prepend ActionPolicy::Rails::Authorizer
     end
 
diff --git a/test/action_policy/rails/instrumentation_test.rb b/test/action_policy/rails/instrumentation_test.rb
index 7defb36d..3d3e5a0a 100644
--- a/test/action_policy/rails/instrumentation_test.rb
+++ b/test/action_policy/rails/instrumentation_test.rb
@@ -13,7 +13,7 @@ class TestRailsInstrumentation < Minitest::Test
   class TestPolicy
     include ActionPolicy::Policy::Core
     include ActionPolicy::Policy::Cache
-    include ActionPolicy::Policy::Rails::Instrumentation
+    prepend ActionPolicy::Policy::Rails::Instrumentation
 
     cache :manage?