instrument permissions

fixes CNVS-34170

test plan:
 * configure statsd.yml
 * use the app
 * observe data sent to statsd, and logged, re: permissions

Change-Id: I1ff35f4679fffcac49774e1bad0cf2540b7f17b8
Reviewed-on: https://gerrit.instructure.com/99727
Tested-by: Jenkins
Reviewed-by: Simon Williams <simon@instructure.com>
Product-Review: Simon Williams <simon@instructure.com>
QA-Review: Simon Williams <simon@instructure.com>

Gemfile.d/app.rb

@@ -93,7 +93,7 @@ gem 'useragent', '0.16.8', require: false
 gem 'crocodoc-ruby', '0.0.1', require: false
 gem 'hey', '1.3.0', require: false
 gem 'sentry-raven', '0.15.6', require: false
-gem 'canvas_statsd', '1.0.8'
+gem 'canvas_statsd', '2.0.1'
   gem 'statsd-ruby', '1.3.0', require: false
   gem 'aroi', '0.0.4', require: false
 gem 'diplomat', '1.0.0', require: false

config/initializers/statsd_timing.rb

@@ -1 +1,5 @@
-CanvasStatsd.track_default_metrics logger: Rails.logger
+CanvasStatsd::DefaultTracking.track_sql
+CanvasStatsd::DefaultTracking.track_active_record
+CanvasStatsd::DefaultTracking.track_cache
+CanvasStatsd::BlockTracking.logger = CanvasStatsd::RequestLogger.new(Rails.logger)
+CanvasStatsd::RequestTracking.enable logger: Rails.logger

gems/adheres_to_policy/adheres_to_policy.gemspec

@@ -15,6 +15,7 @@ Gem::Specification.new do |spec|
   spec.require_paths = ["lib"]
 
   spec.add_dependency 'rails', ">= 3.2", "< 5.1"
+  spec.add_dependency 'canvas_statsd', "~> 2.0"
 
   spec.add_development_dependency "bundler", "~> 1.5"
   spec.add_development_dependency "rake"

gems/adheres_to_policy/lib/adheres_to_policy/cache.rb

@@ -23,7 +23,8 @@ module AdheresToPolicy
 
     # Public: Gets the cached object with the provided key.  Will call the block
     #         if the key does not exist in the cache and store that returned value
-    #         from the block into the cache.
+    #         from the block into the cache, along with how it got the value
+    #         (:in_proc, :out_of_proc, :generated)
     #
     # key - The key to use for the cached object.
     # block - The block to call to get the value to write to the cache.
@@ -31,21 +32,22 @@ module AdheresToPolicy
     # Examples
     #
     #   fetch(:key) { 'value' }
-    #   # => 'value'
+    #   # => ['value', :in_proc]
     #
     # Returns the value of the cached object from the key.
     def self.fetch(key)
-      return yield unless key
+      return [yield, :bypass_generated] unless key
 
-      value = self.read(key)
+      value, how_it_got_it = self.read(key)
       if value.nil?
         if block_given?
+          how_it_got_it = :generated
           value = yield
           self.write(key, value)
         end
       end
 
-      value
+      [value, how_it_got_it]
     end
 
     # Public: Writes an object to the cache with the provided key.  This also
@@ -84,10 +86,11 @@ module AdheresToPolicy
       return unless key
 
       @cache ||= {}
-      if @cache.has_key?(key)
-        @cache[key]
+      if @cache.key?(key)
+        [@cache[key], :in_proc]
       else
-        @cache[key] = Rails.cache.read(key)
+        result = @cache[key] = Rails.cache.read(key)
+        [result, :out_of_proc]
       end
     end
 
@@ -112,4 +115,4 @@ module AdheresToPolicy
       end
     end
   end
-end
+end

gems/adheres_to_policy/lib/adheres_to_policy/instance_methods.rb

@@ -16,6 +16,8 @@
 # with this program. If not, see <http://www.gnu.org/licenses/>.
 #
 
+require 'canvas_statsd'
+
 module AdheresToPolicy
   module InstanceMethods
     # Public: Gets the requested rights granted to a user.
@@ -223,34 +225,39 @@ module AdheresToPolicy
       # Check the cache for the sought_right.  If it exists in the cache its
       # state (true or false) will be returned.  Otherwise we calculate the
       # state and cache it.
-      Cache.fetch(permission_cache_key_for(user, session, sought_right)) do
+      value, how_it_got_it = Cache.fetch(permission_cache_key_for(user, session, sought_right)) do
+        CanvasStatsd::BlockTracking.track("adheres_to_policy.#{self.class.name&.underscore}.#{sought_right}", category: :adheres_to_policy) do
 
-        conditions = self.class.policy.conditions[sought_right]
-        next false unless conditions
+          conditions = self.class.policy.conditions[sought_right]
+          next false unless conditions
 
-        # Loop through all the conditions until we find the first one that
-        # grants us the sought_right.
-        conditions.any? do |condition|
-          if condition.applies?(self, user, session)
+          # Loop through all the conditions until we find the first one that
+          # grants us the sought_right.
+          conditions.any? do |condition|
+            if condition.applies?(self, user, session)
 
-            # Since the condition is true we can loop through all the rights
-            # that belong to it and cache them.  This will short circut the above
-            # Rails.cache.fetch for future checks that we won't have to do again.
-            condition.rights.each do |condition_right|
+              # Since the condition is true we can loop through all the rights
+              # that belong to it and cache them.  This will short circut the above
+              # Rails.cache.fetch for future checks that we won't have to do again.
+              condition.rights.each do |condition_right|
 
-              # Skip the condition_right if its the one we are looking for.
-              # The Rails.cache.fetch will take care of caching it for us.
-              if condition_right != sought_right
+                # Skip the condition_right if its the one we are looking for.
+                # The Rails.cache.fetch will take care of caching it for us.
+                if condition_right != sought_right
 
-                # Cache the condition_right since we already know they have access.
-                Cache.write(permission_cache_key_for(user, session, condition_right), true)
+                  # Cache the condition_right since we already know they have access.
+                  Cache.write(permission_cache_key_for(user, session, condition_right), true)
+                end
               end
-            end
 
-            true
+              true
+            end
           end
         end
       end
+      CanvasStatsd::Statsd.instance&.increment("adheres_to_policy.#{self.class.name&.underscore}.#{sought_right}.#{how_it_got_it}")
+
+      value
     end
 
     # Internal: Gets the cache key for the user and right.

gems/adheres_to_policy/spec/adheres_to_policy/cache_spec.rb

@@ -28,20 +28,20 @@ describe AdheresToPolicy::Cache do
       AdheresToPolicy::Cache.write(:key, 'value')
       expect(AdheresToPolicy::Cache).to_not receive(:write)
       value = AdheresToPolicy::Cache.fetch(:key){ 'new_value' }
-      expect(value).to eq 'value'
+      expect(value).to eq ['value', :in_proc]
     end
 
     it "writes the key and value if it was not read" do
       expect(AdheresToPolicy::Cache).to receive(:write).with(:key, 'value')
       value = AdheresToPolicy::Cache.fetch(:key){ 'value' }
-      expect(value).to eq 'value'
+      expect(value).to eq ['value', :generated]
     end
 
     it "does not write the key if the value is 'false'" do
       AdheresToPolicy::Cache.write(:key, false)
       expect(AdheresToPolicy::Cache).to_not receive(:write)
       value = AdheresToPolicy::Cache.fetch(:key){ 'new_value' }
-      expect(value).to eq false
+      expect(value).to eq [false, :in_proc]
     end
   end
 
@@ -59,12 +59,12 @@ describe AdheresToPolicy::Cache do
     end
 
     it "reads the provided key" do
-      expect(AdheresToPolicy::Cache.read(:key)).to eq 'value'
+      expect(AdheresToPolicy::Cache.read(:key)).to eq ['value', :in_proc]
     end
 
     it "returns nil if the key does not exist" do
       expect(Rails.cache).to receive(:read).with(:key2)
-      expect(AdheresToPolicy::Cache.read(:key2)).to eq nil
+      expect(AdheresToPolicy::Cache.read(:key2)).to eq [nil, :out_of_proc]
     end
   end
 
@@ -84,4 +84,4 @@ describe AdheresToPolicy::Cache do
       expect(cached).to eq({ :key2 => 'value2' })
     end
   end
-end
+end