From 547df85817cc97cd9fee01274ea08b80102e2d74 Mon Sep 17 00:00:00 2001 From: Jay Swain Date: Mon, 8 Dec 2025 16:16:54 -0800 Subject: [PATCH 1/2] Introduce FinderResultsLogger for analysis Introducing a logger for performance analysis and privilege escalation detection. Data results should help guide us to enforce authorization with post-filtering as well as tune our scopes used in finders. part of: https://gitlab.com/gitlab-org/gitlab/-/work_items/581753 --- .../concerns/authz/loggable_results.rb | 76 +++++++++++++++++ app/finders/issuable_finder.rb | 6 ++ app/finders/issues_finder.rb | 4 + app/workers/all_queues.yml | 10 +++ .../authz/finder_results_logger_worker.rb | 83 +++++++++++++++++++ config/sidekiq_queues.yml | 2 + 6 files changed, 181 insertions(+) create mode 100644 app/finders/concerns/authz/loggable_results.rb create mode 100644 app/workers/authz/finder_results_logger_worker.rb diff --git a/app/finders/concerns/authz/loggable_results.rb b/app/finders/concerns/authz/loggable_results.rb new file mode 100644 index 00000000000000..509dfe1f9e7dac --- /dev/null +++ b/app/finders/concerns/authz/loggable_results.rb @@ -0,0 +1,76 @@ +# frozen_string_literal: true + +module Authz + module LoggableResults + extend ActiveSupport::Concern + + def log_results!(current_user, original_args:) + return if current_user.nil? + # do not enqueue logging jobs if we're already in one. + return if Sidekiq.server? + + serialized_args = serialize_args(original_args) + + Authz::FinderResultsLoggerWorker.perform_later( + 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(_origin) + params.filter_map { |arg| serialize_value(arg) } + end + + def serialize_value(value) + serialized = case value + when NilClass, TrueClass, FalseClass, Numeric, String + value + when Symbol + { _symbol: value.to_s } + when ActiveRecord::Base + { _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 + 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 # Discard unserializable values + end + end +end diff --git a/app/finders/issuable_finder.rb b/app/finders/issuable_finder.rb index ec2a80ffb710c2..114ddfb44d2f13 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 addb14cebf0aa5..83654ea9b73fbc 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 da5b596f874316..7d6bf94b93b9f3 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 00000000000000..7a39a90e5dfb06 --- /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 a6ee9d6c04ade8..a55610ee213d0d 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 -- GitLab From d25e92089d8d2d2cb268c5e0151adfc731661cac Mon Sep 17 00:00:00 2001 From: Jay Swain Date: Wed, 10 Dec 2025 18:33:49 -0800 Subject: [PATCH 2/2] Backfill Authz::LoggableResults spec Spec is a WIP. More contexts need to be added. We might want to have a separate module for the serialization/deserialization stuff just to keep it in sync. Question popped up which is "should arguments always be an array"? I think it should, but does that work always? --- .../concerns/authz/loggable_results.rb | 23 ++- .../concerns/authz/loggable_results_spec.rb | 148 ++++++++++++++++++ 2 files changed, 164 insertions(+), 7 deletions(-) create mode 100644 spec/finders/concerns/authz/loggable_results_spec.rb diff --git a/app/finders/concerns/authz/loggable_results.rb b/app/finders/concerns/authz/loggable_results.rb index 509dfe1f9e7dac..bd273d51167627 100644 --- a/app/finders/concerns/authz/loggable_results.rb +++ b/app/finders/concerns/authz/loggable_results.rb @@ -6,12 +6,15 @@ module LoggableResults def log_results!(current_user, original_args:) return if current_user.nil? - # do not enqueue logging jobs if we're already in one. + # 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_later( + Authz::FinderResultsLoggerWorker.perform_async( current_user.id, serialized_args, self.class.name @@ -27,8 +30,8 @@ def log_results!(current_user, original_args:) private - def serialize_args(_origin) - params.filter_map { |arg| serialize_value(arg) } + def serialize_args(args) + args.filter_map { |arg| serialize_value(arg) } end def serialize_value(value) @@ -36,9 +39,9 @@ def serialize_value(value) when NilClass, TrueClass, FalseClass, Numeric, String value when Symbol - { _symbol: value.to_s } + serialize_value({ _symbol: value.to_s }) when ActiveRecord::Base - { _type: value.class.name, id: value.id } + 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 @@ -57,6 +60,12 @@ def serialize_value(value) 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 @@ -70,7 +79,7 @@ def validate_json_serializable(value) value: value ) - nil # Discard unserializable values + nil end end end 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 00000000000000..7158f0046c2c2a --- /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 -- GitLab