diff --git a/app/finders/concerns/authz/loggable_results.rb b/app/finders/concerns/authz/loggable_results.rb new file mode 100644 index 0000000000000000000000000000000000000000..bd273d51167627ae4c96733a0a1a60c7a1f1a305 --- /dev/null +++ b/app/finders/concerns/authz/loggable_results.rb @@ -0,0 +1,85 @@ +# frozen_string_literal: true + +module Authz + module LoggableResults + extend ActiveSupport::Concern + + def log_results!(current_user, original_args:) + return if current_user.nil? + # don't enqueue logging jobs if we're already in one. + return if Sidekiq.server? + + # TODO: we need to check a feature flag + # TODO: we need to raise if original_args isn't an array + + serialized_args = serialize_args(original_args) + + Authz::FinderResultsLoggerWorker.perform_async( + current_user.id, + serialized_args, + self.class.name + ) + rescue StandardError => e + Gitlab::AppLogger.warn( + message: 'FinderResultsLogger - Failed to enqueue', + class_name: self.class.name, + error_class: e.class.name, + error_message: e.message + ) + end + + private + + def serialize_args(args) + args.filter_map { |arg| serialize_value(arg) } + end + + def serialize_value(value) + serialized = case value + when NilClass, TrueClass, FalseClass, Numeric, String + value + when Symbol + serialize_value({ _symbol: value.to_s }) + when ActiveRecord::Base + serialize_value({ _type: value.class.name, id: value.id }) + when Hash + value.transform_keys(&:to_s).transform_values { |v| serialize_value(v) }.compact + when Array + value.filter_map { |v| serialize_value(v) } + when Time, DateTime, Date + value.iso8601 + when ActionController::Parameters + serialize_value(value.to_h) + else + safe_to_s(value) + end + + validate_json_serializable(serialized) + end + + def safe_to_s(value) + value.to_s + rescue StandardError + Gitlab::AppLogger.warn( + message: 'FinderResultsLogger - Exception raised when calling to_s', + class_name: self.class.name, + value: value.class.name + ) + + nil + end + + def validate_json_serializable(value) + Gitlab::Json.parse(Gitlab::Json.generate(value)) + value + rescue JSON::GeneratorError, TypeError, JSON::ParserError + Gitlab::AppLogger.warn( + message: 'FinderResultsLogger - Failed to serialize', + class_name: self.class.name, + value: value + ) + + nil + end + end +end diff --git a/app/finders/issuable_finder.rb b/app/finders/issuable_finder.rb index ec2a80ffb710c2611bf441f8921836fc1593dda4..114ddfb44d2f137053a788e516228dbd6d6067db 100644 --- a/app/finders/issuable_finder.rb +++ b/app/finders/issuable_finder.rb @@ -45,6 +45,7 @@ class IssuableFinder include CreatedAtFilter include Gitlab::Utils::StrongMemoize include UpdatedAtFilter + include Authz::LoggableResults requires_cross_project_access unless: -> { params.project? } @@ -114,6 +115,11 @@ def initialize(current_user, params = {}) @current_user = current_user @original_params = params @params = params_class.new(params, current_user, klass) + + log_results!( + current_user, + original_args: [current_user, params] + ) end def execute diff --git a/app/finders/issues_finder.rb b/app/finders/issues_finder.rb index addb14cebf0aa58668008d41a418e66a9aed6022..83654ea9b73fbce72abb72fc0db28a3949e21bb9 100644 --- a/app/finders/issues_finder.rb +++ b/app/finders/issues_finder.rb @@ -45,6 +45,10 @@ def params_class self.class.const_get(:Params, false) end + def permitted?(issue) + current_user.can?(:read_issue, issue) + end + private def filter_items(items) diff --git a/app/workers/all_queues.yml b/app/workers/all_queues.yml index da5b596f87431622d56563e869f5dc74426caaf1..7d6bf94b93b9f3d6bdc9b4b58677978369152f52 100644 --- a/app/workers/all_queues.yml +++ b/app/workers/all_queues.yml @@ -3147,6 +3147,16 @@ :idempotent: true :tags: [] :queue_namespace: +- :name: authz_finder_results_logger + :worker_name: Authz::FinderResultsLoggerWorker + :feature_category: :permissions + :has_external_dependencies: false + :urgency: :low + :resource_boundary: :unknown + :weight: 1 + :idempotent: true + :tags: [] + :queue_namespace: - :name: batched_git_ref_updates_project_cleanup :worker_name: BatchedGitRefUpdates::ProjectCleanupWorker :feature_category: :gitaly diff --git a/app/workers/authz/finder_results_logger_worker.rb b/app/workers/authz/finder_results_logger_worker.rb new file mode 100644 index 0000000000000000000000000000000000000000..7a39a90e5dfb0656388e4086005617c14b5dbbe0 --- /dev/null +++ b/app/workers/authz/finder_results_logger_worker.rb @@ -0,0 +1,83 @@ +# frozen_string_literal: true + +module Authz + class FinderResultsLoggerWorker + include ApplicationWorker + + feature_category :permissions + + idempotent! + data_consistency :delayed + + def perform(current_user_id, serialized_args, class_name) + @class_name = class_name + @serialized_args = serialized_args + + current_user = User.find_by_id(current_user_id) + return unless current_user + + args = deserialize_value(serialized_args) + finder = class_name.constantize.new(current_user, **args) + + results = nil + @execution_duration = Benchmark.realtime do + results = finder.execute.page(1) + end + + permitted = nil + @post_filter_duration = Benchmark.realtime do + permitted = results.all? { |item| finder.permitted?(item) } + end + + if permitted + log_data("Authorized") + else + log_data("Unauthorized") + end + end + + private + + def log_data(message) + Gitlab::AppLogger.info( + message: "FinderResultsLogger: #{message}", + class_name: @class_name, + arguments: @serialized_args, + execution_duration: @execution_duration, + post_filter_duration: @post_filter_duration + ) + end + + def deserialize_value(value) + case value + when Hash + if value['_symbol'] + value['_symbol'].to_sym + elsif value['_type'] && value['id'] + deserialize_activerecord(value) + else + value.transform_values { |v| deserialize_value(v) } + end + when Array + value.map { |v| deserialize_value(v) } + when String + deserialize_datetime(value) || value + else + value + end + end + + def deserialize_activerecord(hash) + klass = hash['_type'].constantize + klass.find_by_id(hash['id']) + rescue NameError, ActiveRecord::RecordNotFound + nil + end + + def deserialize_datetime(string) + Time.iso8601(string) + rescue ArgumentError + nil + end + end +end diff --git a/config/sidekiq_queues.yml b/config/sidekiq_queues.yml index a6ee9d6c04ade87d6941c05b810266e448adee11..a55610ee213d0d20c72ba36f2ece62f1d15cca83 100644 --- a/config/sidekiq_queues.yml +++ b/config/sidekiq_queues.yml @@ -117,6 +117,8 @@ - 2 - - authorized_projects - 2 +- - authz_finder_results_logger + - 1 - - authz_user_group_member_roles_destroy_for_group - 1 - - authz_user_group_member_roles_destroy_for_shared_group diff --git a/spec/finders/concerns/authz/loggable_results_spec.rb b/spec/finders/concerns/authz/loggable_results_spec.rb new file mode 100644 index 0000000000000000000000000000000000000000..7158f0046c2c2aec43c212431e4b2605c7ebde4a --- /dev/null +++ b/spec/finders/concerns/authz/loggable_results_spec.rb @@ -0,0 +1,148 @@ +# frozen_string_literal: true + +require 'spec_helper' + +RSpec.describe Authz::LoggableResults, feature_category: :permissions do + subject(:log_results!) { finder_class.new.log_results!(user, original_args: params) } + + let_it_be(:user) { create(:user) } + let(:params) { [] } + + let(:finder_class) do + klass = Class.new do + include Authz::LoggableResults + end + + stub_const('ThingiesFinder', klass) + + klass + end + + describe 'log_results!' do + context 'when user is nil' do + let(:user) { nil } + + it "doesn't enqueue worker" do + expect(Authz::FinderResultsLoggerWorker).not_to receive(:perform_async) + log_results! + end + end + + context 'when user is not nil' do + context 'when params provided', :timecop do + let_it_be(:project) { create(:project) } + let(:date) { Date.yesterday } + let(:time) { Time.now } + let(:unserializable) do + class_double(IssuableFinder::Params).tap do |obj| + allow(obj).to receive(:to_s).and_raise(StandardError, 'BECOME UNSERIALIZABLE') + end + end + + let(:params) do + [ + user, + :public, + true, + 'scoped', + time, + unserializable, + { + scope: 'all', + project: project, + projects: [project], + not: { project_id: project.id }, + due_after: date, + admin: true, + public: false, + state: :enabled + } + ] + end + + it 'serializes params and enqueues worker' do + expect(Authz::FinderResultsLoggerWorker).to receive(:perform_async).with( + user.id, + [ + { + "_type" => "User", + "id" => user.id + }, + { + "_symbol" => "public" + }, + true, + "scoped", + time.iso8601, + { + "scope" => "all", + "project" => { + "_type" => "Project", + "id" => project.id + }, + "projects" => [ + { + "_type" => "Project", + "id" => project.id + } + ], + "not" => { + "project_id" => project.id + }, + "due_after" => date.iso8601, + "admin" => true, + "public" => false, + "state" => { + "_symbol" => "enabled" # TODO: Why do we use underscore for symbol and type? + } + } + ], + finder_class.name + ) + + log_results! + end + + it 'catches and logs when exception raised when calling .to_s' do + expect(Gitlab::AppLogger).to receive(:warn).with( + message: 'FinderResultsLogger - Exception raised when calling to_s', + class_name: finder_class.name, + value: unserializable.class.name + ) + + log_results! + end + end + + context 'when inside sidekiq job', :with_sidekiq_context do + it "doesn't enqueue worker" do + expect(Authz::FinderResultsLoggerWorker).not_to receive(:perform_async) + + log_results! + end + end + + context 'when an error is thrown' do + let(:error) { StandardError.new('Serialization failed') } + + before do + allow_next_instance_of(finder_class) do |instance| + allow(instance).to receive(:serialize_args).and_raise(error) + end + end + + it "doesn't enqueue worker, and logs the error" do + expect(Authz::FinderResultsLoggerWorker).not_to receive(:perform_async) + expect(Gitlab::AppLogger).to receive(:warn).with( + message: 'FinderResultsLogger - Failed to enqueue', + class_name: finder_class.name, + error_class: 'StandardError', + error_message: 'Serialization failed' + ) + + log_results! + end + end + end + end +end