Log access to classification label and project

Log access to a classification label and project when External Policy
Control is enabled.

doc/user/admin_area/settings/external_authorization.md

@@ -28,6 +28,10 @@ functionality that render cross-project data. That includes:
 This is to prevent performing to many requests at once to the external
 authorization service.
 
+Whenever access is granted or denied this is logged in a logfile called
+`external-policy-access-control.log`.
+Read more about logs GitLab keeps in the [omnibus documentation][omnibus-log-docs].
+
 ## Configuration
 
 The external authorization service can be enabled by an admin on the GitLab's
@@ -104,3 +108,4 @@ The label will be shown on all project pages in the upper right corner.
 ![classification label on project page](img/classification_label_on_project_page.png)
 
 [omnibus-ssl-docs]: https://docs.gitlab.com/omnibus/settings/ssl.html
+[omnibus-log-docs]: https://docs.gitlab.com/omnibus/settings/logs.html

ee/app/policies/ee/project_policy.rb

@@ -19,7 +19,8 @@ module EE
       condition(:classification_label_authorized, score: 32) do
         EE::Gitlab::ExternalAuthorization.access_allowed?(
           @user,
-          @subject.external_authorization_classification_label
+          @subject.external_authorization_classification_label,
+          @subject.full_path
         )
       end
 

ee/changelogs/unreleased/bvl-external-auth-logging.yml

+---
+title: Log every access when external authorization is enabled
+merge_request: 5117
+author:
+type: added

ee/lib/ee/gitlab/external_authorization.rb

@@ -5,29 +5,36 @@ module EE
 
       RequestFailed = Class.new(StandardError)
 
-      def self.access_allowed?(user, label)
+      def self.access_allowed?(user, label, project_path = nil)
         return true unless perform_check?
         return false unless user
 
-        access_for_user_to_label(user, label).has_access?
+        access_for_user_to_label(user, label, project_path).has_access?
       end
 
       def self.rejection_reason(user, label)
         return nil unless enabled?
         return nil unless user
 
-        access_for_user_to_label(user, label).reason
+        access_for_user_to_label(user, label, nil).reason
       end
 
-      def self.access_for_user_to_label(user, label)
+      def self.access_for_user_to_label(user, label, project_path)
         if RequestStore.active?
           RequestStore.fetch("external_authorisation:user-#{user.id}:label-#{label}") do
-            EE::Gitlab::ExternalAuthorization::Access.new(user, label).load!
+            load_access(user, label, project_path)
           end
         else
-          EE::Gitlab::ExternalAuthorization::Access.new(user, label).load!
+          load_access(user, label, project_path)
         end
       end
+
+      def self.load_access(user, label, project_path)
+        access = EE::Gitlab::ExternalAuthorization::Access.new(user, label).load!
+        ::EE::Gitlab::ExternalAuthorization::Logger.log_access(access, project_path)
+
+        access
+      end
     end
   end
 end

ee/lib/ee/gitlab/external_authorization/access.rb

@@ -2,7 +2,11 @@ module EE
   module Gitlab
     module ExternalAuthorization
       class Access
-        attr_reader :access, :reason, :loaded_at
+        attr_reader :user,
+                    :reason,
+                    :loaded_at,
+                    :label,
+                    :load_type
 
         def initialize(user, label)
           @user, @label = user, label
@@ -25,10 +29,12 @@ module EE
         private
 
         def load_from_cache
+          @load_type = :cache
           @access, @reason, @loaded_at = cache.load
         end
 
         def load_from_service
+          @load_type = :request
           response = Client.new(@user, @label).request_access
           @access = response.successful?
           @reason = response.reason

ee/lib/ee/gitlab/external_authorization/logger.rb

+module EE
+  module Gitlab
+    module ExternalAuthorization
+      class Logger < ::Gitlab::Logger
+        def self.log_access(access, project_path)
+          status = access.has_access? ? "GRANTED" : "DENIED"
+          message = "#{status} #{access.user.email} access to '#{access.label}'"
+
+          message << " (#{project_path})" if project_path.present?
+          message << " - #{access.load_type} #{access.loaded_at}" if access.load_type == :cache
+
+          info(message)
+        end
+
+        def self.file_name_noext
+          'external-policy-access-control'
+        end
+      end
+    end
+  end
+end

ee/spec/features/projects/issues/viewing_issues_with_external_authorization_enabled_spec.rb

@@ -78,7 +78,9 @@ describe 'viewing an issue with cross project references' do
 
     it 'only hits the external service for the project the user is viewing' do
       expect(EE::Gitlab::ExternalAuthorization)
-        .to receive(:access_allowed?).with(user, 'default_label').at_least(1).and_return(true)
+        .to receive(:access_allowed?).with(user, 'default_label', any_args).at_least(1).and_return(true)
+      expect(EE::Gitlab::ExternalAuthorization)
+        .not_to receive(:access_allowed?).with(user, 'other_label', any_args)
 
       visit project_issue_path(project, issue)
     end

ee/spec/lib/ee/gitlab/external_authorization/logger_spec.rb

+require 'spec_helper'
+
+describe EE::Gitlab::ExternalAuthorization::Logger do
+  let(:request_time) { Time.parse('2018-03-26 20:22:15') }
+
+  def fake_access(has_access, user, load_type = :request)
+    access = double('access')
+    allow(access).to receive_messages(user: user,
+                                      has_access?: has_access,
+                                      loaded_at: request_time,
+                                      label: 'dummy_label',
+                                      load_type: load_type)
+
+    access
+  end
+
+  describe '.log_access' do
+    it 'logs a nice message for an access request' do
+      expected_message = "GRANTED admin@example.com access to 'dummy_label' (the/project/path)"
+      fake_access = fake_access(true, build(:user, email: 'admin@example.com'))
+
+      expect(described_class).to receive(:info).with(expected_message)
+
+      described_class.log_access(fake_access, 'the/project/path')
+    end
+
+    it 'does not trip without a project path' do
+      expected_message = "DENIED admin@example.com access to 'dummy_label'"
+      fake_access = fake_access(false, build(:user, email: 'admin@example.com'))
+
+      expect(described_class).to receive(:info).with(expected_message)
+
+      described_class.log_access(fake_access, nil)
+    end
+
+    it 'adds the load time for cached accesses' do
+      expected_message = "DENIED admin@example.com access to 'dummy_label' - cache #{request_time}"
+      fake_access = fake_access(false, build(:user, email: 'admin@example.com'), :cache)
+
+      expect(described_class).to receive(:info).with(expected_message)
+
+      described_class.log_access(fake_access, nil)
+    end
+  end
+end

ee/spec/lib/ee/gitlab/external_authorization_spec.rb

@@ -21,7 +21,7 @@ describe EE::Gitlab::ExternalAuthorization, :request_store do
   end
 
   describe '#rejection_reason' do
-    it 'is alwaus nil when the feature is disabled' do
+    it 'is always nil when the feature is disabled' do
       expect(::Gitlab::CurrentSettings.current_application_settings)
         .to receive(:external_authorization_service_enabled?) { false }
 
@@ -38,7 +38,17 @@ describe EE::Gitlab::ExternalAuthorization, :request_store do
       expect(EE::Gitlab::ExternalAuthorization::Access)
         .to receive(:new).with(user, label).once.and_call_original
 
-      2.times { described_class.access_for_user_to_label(user, label) }
+      2.times { described_class.access_for_user_to_label(user, label, nil) }
+    end
+
+    it 'logs the access request once per request' do
+      expect(EE::Gitlab::ExternalAuthorization::Logger)
+        .to receive(:log_access)
+              .with(an_instance_of(EE::Gitlab::ExternalAuthorization::Access),
+                    'the/project/path')
+              .once
+
+      2.times { described_class.access_for_user_to_label(user, label, 'the/project/path') }
     end
   end
 end

ee/spec/policies/project_policy_spec.rb

@@ -164,16 +164,22 @@ describe ProjectPolicy do
       end
 
       it 'prevents all but seeing a public project in a list when access is denied' do
-        external_service_deny_access(owner, project)
-        external_service_deny_access(developer, project)
+        [developer, owner, build(:user), nil].each do |user|
+          external_service_deny_access(user, project)
+          policy = described_class.new(user, project)
 
-        [developer, owner, create(:user), nil].each do |user|
-          policy = described_class.new(owner, project)
           expect(policy).not_to be_allowed(:read_project)
           expect(policy).not_to be_allowed(:owner_access)
           expect(policy).not_to be_allowed(:change_namespace)
         end
       end
+
+      it 'passes the full path to external authorization for logging purposes' do
+        expect(EE::Gitlab::ExternalAuthorization)
+          .to receive(:access_allowed?).with(owner, 'default_label', project.full_path).and_call_original
+
+        described_class.new(owner, project).allowed?(:read_project)
+      end
     end
   end
 end

ee/spec/support/external_authorization_service_helpers.rb

@@ -21,7 +21,7 @@ module ExternalAuthorizationServiceHelpers
 
     allow(EE::Gitlab::ExternalAuthorization)
       .to receive(:access_allowed?)
-            .with(user, classification_label)
+            .with(user, classification_label, any_args)
             .and_return(allowed)
   end