Ofrich/add logs to multitenant violations

lib/multitenant.rb

@@ -9,21 +9,44 @@ class << self
     CURRENT_TENANT = 'Multitenant.current_tenant'.freeze
     ALLOW_DANGEROUS = 'Multitenant.allow_dangerous_cross_tenants'.freeze
     EXTRA_TENANT_IDS = 'Multitenant.extra_tenant_ids'.freeze
+    ALLOW_NEXT_TENANT_OPERATION = 'Multitenant.allow_next_tenant_operation'.freeze
+
+    @@multitenant_violation_log_sample_rate = 0
+
+    def set_multitenant_violation_log_sample_rate(sample_rate)
+      @@multitenant_violation_log_sample_rate = sample_rate
+    end
+
+    def multitenant_violation_log_sample_rate
+      @@multitenant_violation_log_sample_rate
+    end
+
+    def allow_next_tenant_operation
+      Thread.current[ALLOW_NEXT_TENANT_OPERATION] = true
+    end
 
     def current_tenant
       Thread.current[CURRENT_TENANT]
     end
 
     def current_tenant=(value)
-      Thread.current[CURRENT_TENANT] = value
+      if current_tenant != value && value != nil
+        log_multitenant_violation_if_needed('current_tenant_set')
+      end
+
+      _set_current_tenant(value)
     end
 
     def allow_dangerous_cross_tenants
       Thread.current[ALLOW_DANGEROUS]
     end
 
     def allow_dangerous_cross_tenants=(value)
-      Thread.current[ALLOW_DANGEROUS] = value
+      if value && !allow_dangerous_cross_tenants
+        log_multitenant_violation_if_needed('allow_dangerous_cross_tenants_set')
+      end
+
+      _set_allow_dangerous_cross_tenants(value)
     end
 
     def extra_tenant_ids
@@ -37,24 +60,67 @@ def extra_tenant_ids=(value)
     # execute a block scoped to the current tenant
     # unsets the current tenant after execution
     def with_tenant(tenant, options = {}, &block)
+      if current_tenant != tenant && tenant != nil
+        log_multitenant_violation_if_needed('with_tenant')
+      end
+
       previous_tenant = Multitenant.current_tenant
-      Multitenant.current_tenant = tenant
+      _set_current_tenant(tenant)
+
       previous_extra_tenant_ids = Multitenant.extra_tenant_ids
       Multitenant.extra_tenant_ids = options[:extra_tenant_ids] if options[:extra_tenant_ids]
       yield
     ensure
-      Multitenant.current_tenant = previous_tenant
+      _set_current_tenant(previous_tenant)
       Multitenant.extra_tenant_ids = previous_extra_tenant_ids
     end
 
     def dangerous_cross_tenants(&block)
+      if !allow_dangerous_cross_tenants
+        log_multitenant_violation_if_needed('dangerous_cross_tenants')
+      end
+
       previous_value = Multitenant.allow_dangerous_cross_tenants
-      Multitenant.allow_dangerous_cross_tenants = true
+      _set_allow_dangerous_cross_tenants(true)
+
       Multitenant.with_tenant(nil) do
         yield
       end
     ensure
-      Multitenant.allow_dangerous_cross_tenants = previous_value
+      _set_allow_dangerous_cross_tenants(previous_value)
+    end
+
+    private
+
+    def _set_current_tenant(value)
+      Thread.current[CURRENT_TENANT] = value
+    end
+
+    def _set_allow_dangerous_cross_tenants(value)
+      Thread.current[ALLOW_DANGEROUS] = value
+    end
+
+    def log_multitenant_violation_if_needed(kind)
+      if Thread.current[ALLOW_NEXT_TENANT_OPERATION]
+        Thread.current[ALLOW_NEXT_TENANT_OPERATION] = false
+        return
+      end
+
+      return unless Random.rand < Multitenant.multitenant_violation_log_sample_rate
+
+      caller_frame = caller(2, 1).first rescue 'unknown'
+
+      $logger.warn(
+        tag: 'multitenant_violation',
+        message: 'multitenant usage outside allowed contexts',
+        kind: kind,
+        caller: caller_frame
+      )
+    rescue => e
+      begin
+        $logger.error(tag: 'multitenant_violation', message: 'error while logging multitenant violation', error: e.message)
+      rescue
+      end
     end
   end
 

spec/multitenant_spec.rb

@@ -218,4 +218,176 @@ class Item < ActiveRecord::Base
       @user.company_id.should == @company.id
     end
   end
+
+  describe "logging" do
+    let(:mock_logger) { double('logger') }
+
+    before do
+      $logger = mock_logger
+      Multitenant.set_multitenant_violation_log_sample_rate(1.0)
+      mock_logger.stub(:respond_to?).with(:warn).and_return(true)
+      mock_logger.stub(:respond_to?).with(:error).and_return(true)
+    end
+
+    after do
+      Multitenant.set_multitenant_violation_log_sample_rate(0)
+      $logger = nil
+    end
+
+    it "current_tenant= logs violations when changing tenant" do
+      tenant = Company.create! :name => 'test'
+
+      mock_logger.should_receive(:warn).with(
+        :tag => 'multitenant_violation',
+        :message => 'multitenant usage outside allowed contexts',
+        :kind => 'current_tenant_set'
+      )
+      Multitenant.current_tenant = tenant
+    end
+
+    it "current_tenant= skips logging when allow_next_tenant_operation is called" do
+      tenant = Company.create! :name => 'test'
+      Multitenant.allow_next_tenant_operation
+
+      mock_logger.should_not_receive(:warn)
+      Multitenant.current_tenant = tenant
+    end
+
+    it "current_tenant= logs normally after skip flag is consumed" do
+      tenant1 = Company.create! :name => 'test1'
+      tenant2 = Company.create! :name => 'test2'
+
+      # Use skip flag first to consume it
+      Multitenant.allow_next_tenant_operation
+      Multitenant.current_tenant = tenant1
+
+      # Next call should log normally (proving flag was consumed)
+      mock_logger.should_receive(:warn).with(
+        :tag => 'multitenant_violation',
+        :message => 'multitenant usage outside allowed contexts',
+        :kind => 'current_tenant_set'
+      )
+      Multitenant.current_tenant = tenant2
+    end
+
+    it "allow_dangerous_cross_tenants= logs violations when enabling dangerous mode" do
+      # Ensure initial state is false so the logging condition will be met
+      Thread.current['Multitenant.allow_dangerous_cross_tenants'] = false
+
+      mock_logger.should_receive(:warn).with(
+        :tag => 'multitenant_violation',
+        :message => 'multitenant usage outside allowed contexts',
+        :kind => 'allow_dangerous_cross_tenants_set'
+      )
+      Multitenant.allow_dangerous_cross_tenants = true
+    end
+
+    it "allow_dangerous_cross_tenants= skips logging when allow_next_tenant_operation is called" do
+      # Ensure initial state is false so the logging condition will be met
+      Thread.current['Multitenant.allow_dangerous_cross_tenants'] = false
+      Multitenant.allow_next_tenant_operation
+
+      mock_logger.should_not_receive(:warn)
+      Multitenant.allow_dangerous_cross_tenants = true
+    end
+
+    it "allow_dangerous_cross_tenants= logs normally after skip flag is consumed" do
+      # Ensure initial state is false
+      Thread.current['Multitenant.allow_dangerous_cross_tenants'] = false
+
+      # Use skip flag first to consume it
+      Multitenant.allow_next_tenant_operation
+      Multitenant.allow_dangerous_cross_tenants = true
+
+      # Reset state and next call should log normally
+      Thread.current['Multitenant.allow_dangerous_cross_tenants'] = false
+      mock_logger.should_receive(:warn).with(
+        :tag => 'multitenant_violation',
+        :message => 'multitenant usage outside allowed contexts',
+        :kind => 'allow_dangerous_cross_tenants_set'
+      )
+      Multitenant.allow_dangerous_cross_tenants = true
+    end
+
+    it "with_tenant logs violations when switching tenant" do
+      current_tenant = Company.create! :name => 'current'
+      new_tenant = Company.create! :name => 'new'
+      Thread.current['Multitenant.current_tenant'] = current_tenant
+
+      mock_logger.should_receive(:warn).with(
+        :tag => 'multitenant_violation',
+        :message => 'multitenant usage outside allowed contexts',
+        :kind => 'with_tenant'
+      )
+      Multitenant.with_tenant(new_tenant) { }
+    end
+
+    it "with_tenant skips logging when allow_next_tenant_operation is called" do
+      current_tenant = Company.create! :name => 'current'
+      new_tenant = Company.create! :name => 'new'
+      Thread.current['Multitenant.current_tenant'] = current_tenant
+      Multitenant.allow_next_tenant_operation
+
+      mock_logger.should_not_receive(:warn)
+      Multitenant.with_tenant(new_tenant) { }
+    end
+
+    it "with_tenant logs normally after skip flag is consumed" do
+      current_tenant = Company.create! :name => 'current'
+      new_tenant1 = Company.create! :name => 'new1'
+      new_tenant2 = Company.create! :name => 'new2'
+      Thread.current['Multitenant.current_tenant'] = current_tenant
+
+      # Use skip flag first to consume it
+      Multitenant.allow_next_tenant_operation
+      Multitenant.with_tenant(new_tenant1) { }
+
+      # Next call should log normally
+      mock_logger.should_receive(:warn).with(
+        :tag => 'multitenant_violation',
+        :message => 'multitenant usage outside allowed contexts',
+        :kind => 'with_tenant'
+      )
+      Multitenant.with_tenant(new_tenant2) { }
+    end
+
+    it "dangerous_cross_tenants logs violations when entering dangerous mode" do
+      # Ensure allow_dangerous_cross_tenants is false so logging condition is met
+      Thread.current['Multitenant.allow_dangerous_cross_tenants'] = false
+
+      mock_logger.should_receive(:warn).with(
+        :tag => 'multitenant_violation',
+        :message => 'multitenant usage outside allowed contexts',
+        :kind => 'dangerous_cross_tenants'
+      )
+      Multitenant.dangerous_cross_tenants { }
+    end
+
+    it "dangerous_cross_tenants skips logging when allow_next_tenant_operation is called" do
+      # Ensure allow_dangerous_cross_tenants is false so logging condition is met
+      Thread.current['Multitenant.allow_dangerous_cross_tenants'] = false
+      Multitenant.allow_next_tenant_operation
+
+      mock_logger.should_not_receive(:warn)
+      Multitenant.dangerous_cross_tenants { }
+    end
+
+    it "dangerous_cross_tenants logs normally after skip flag is consumed" do
+      # Ensure allow_dangerous_cross_tenants is false so logging condition is met
+      Thread.current['Multitenant.allow_dangerous_cross_tenants'] = false
+
+      # Use skip flag first to consume it
+      Multitenant.allow_next_tenant_operation
+      Multitenant.dangerous_cross_tenants { }
+
+      # Reset state and next call should log normally
+      Thread.current['Multitenant.allow_dangerous_cross_tenants'] = false
+      mock_logger.should_receive(:warn).with(
+        :tag => 'multitenant_violation',
+        :message => 'multitenant usage outside allowed contexts',
+        :kind => 'dangerous_cross_tenants'
+      )
+      Multitenant.dangerous_cross_tenants { }
+    end
+  end
 end