From 88e627cf14b47ca5d63f2cb0ffe24124fb4b116a Mon Sep 17 00:00:00 2001 From: Yorick Peterse Date: Sun, 22 Jan 2017 18:22:02 +0100 Subject: Fix race conditions for AuthorizedProjectsWorker There were two cases that could be problematic: 1. Because sometimes AuthorizedProjectsWorker would be scheduled in a transaction it was possible for a job to run/complete before a COMMIT; resulting in it either producing an error, or producing no new data. 2. When scheduling jobs the code would not wait until completion. This could lead to a user creating a project and then immediately trying to push to it. Usually this will work fine, but given enough load it might take a few seconds before a user has access. The first one is problematic, the second one is mostly just annoying (but annoying enough to warrant a solution). This commit changes two things to deal with this: 1. Sidekiq scheduling now takes places after a COMMIT, this is ensured by scheduling using Rails' after_commit hook instead of doing so in an arbitrary method. 2. When scheduling jobs the calling thread now waits for all jobs to complete. Solution 2 requires tracking of job completions. Sidekiq provides a way to find a job by its ID, but this involves scanning over the entire queue; something that is very in-efficient for large queues. As such a more efficient solution is necessary. There are two main Gems that can do this in a more efficient manner: * sidekiq-status * sidekiq_status No, this is not a joke. Both Gems do a similar thing (but slightly different), and the only difference in their name is a dash vs an underscore. Both Gems however provide far more than just checking if a job has been completed, and both have their problems. sidekiq-status does not appear to be actively maintained, with the last release being in 2015. It also has some issues during testing as API calls are not stubbed in any way. sidekiq_status on the other hand does not appear to be very popular, and introduces a similar amount of code. Because of this I opted to write a simple home grown solution. After all, all we need is storing a job ID somewhere so we can efficiently look it up; we don't need extra web UIs (as provided by sidekiq-status) or complex APIs to update progress, etc. This is where Gitlab::SidekiqStatus comes in handy. This namespace contains some code used for tracking, removing, and looking up job IDs; all without having to scan over an entire queue. Data is removed explicitly, but also expires automatically just in case. Using this API we can now schedule jobs in a fork-join like manner: we schedule the jobs in Sidekiq, process them in parallel, then wait for completion. By using Sidekiq we can leverage all the benefits such as being able to scale across multiple cores and hosts, retrying failed jobs, etc. The one downside is that we need to make sure we can deal with unexpected increases in job processing timings. To deal with this the class Gitlab::JobWaiter (used for waiting for jobs to complete) will only wait a number of seconds (30 by default). Once this timeout is reached it will simply return. For GitLab.com almost all AuthorizedProjectWorker jobs complete in seconds, only very rarely do we spike to job timings of around a minute. These in turn seem to be the result of external factors (e.g. deploys), in which case a user is most likely not able to use the system anyway. In short, this new solution should ensure that jobs are processed properly and that in almost all cases a user has access to their resources whenever they need to have access. --- Gemfile | 2 +- Gemfile.lock | 4 +- app/models/member.rb | 20 ++++--- app/models/project_group_link.rb | 3 +- .../user_project_access_changed_service.rb | 2 +- app/workers/authorized_projects_worker.rb | 7 +++ .../refresh-authorizations-fork-join.yml | 4 ++ config/initializers/sidekiq.rb | 9 +++ db/fixtures/development/01_admin.rb | 2 + db/fixtures/development/04_project.rb | 2 +- db/fixtures/development/05_users.rb | 2 + db/fixtures/development/06_teams.rb | 2 +- db/fixtures/development/07_milestones.rb | 2 + db/fixtures/development/09_issues.rb | 2 + db/fixtures/development/10_merge_requests.rb | 2 + db/fixtures/development/11_keys.rb | 22 +++++--- db/fixtures/development/12_snippets.rb | 2 + db/fixtures/development/13_comments.rb | 2 + db/fixtures/development/14_pipelines.rb | 2 + db/fixtures/development/15_award_emoji.rb | 2 + db/fixtures/development/16_protected_branches.rb | 2 + db/fixtures/development/17_cycle_analytics.rb | 2 +- features/support/env.rb | 3 +- lib/gitlab/job_waiter.rb | 27 +++++++++ lib/gitlab/sidekiq_status.rb | 66 ++++++++++++++++++++++ lib/gitlab/sidekiq_status/client_middleware.rb | 10 ++++ lib/gitlab/sidekiq_status/server_middleware.rb | 13 +++++ spec/lib/gitlab/job_waiter_spec.rb | 30 ++++++++++ .../sidekiq_status/client_middleware_spec.rb | 12 ++++ .../sidekiq_status/server_middleware_spec.rb | 14 +++++ spec/lib/gitlab/sidekiq_status_spec.rb | 50 ++++++++++++++++ .../user_project_access_changed_service_spec.rb | 12 ++++ spec/spec_helper.rb | 1 - spec/support/sidekiq.rb | 5 ++ spec/workers/authorized_projects_worker_spec.rb | 12 ++++ 35 files changed, 325 insertions(+), 29 deletions(-) create mode 100644 changelogs/unreleased/refresh-authorizations-fork-join.yml create mode 100644 lib/gitlab/job_waiter.rb create mode 100644 lib/gitlab/sidekiq_status.rb create mode 100644 lib/gitlab/sidekiq_status/client_middleware.rb create mode 100644 lib/gitlab/sidekiq_status/server_middleware.rb create mode 100644 spec/lib/gitlab/job_waiter_spec.rb create mode 100644 spec/lib/gitlab/sidekiq_status/client_middleware_spec.rb create mode 100644 spec/lib/gitlab/sidekiq_status/server_middleware_spec.rb create mode 100644 spec/lib/gitlab/sidekiq_status_spec.rb create mode 100644 spec/services/user_project_access_changed_service_spec.rb create mode 100644 spec/support/sidekiq.rb diff --git a/Gemfile b/Gemfile index 83ba5d31b92..2dace9689d1 100644 --- a/Gemfile +++ b/Gemfile @@ -322,7 +322,7 @@ group :test do gem 'email_spec', '~> 1.6.0' gem 'json-schema', '~> 2.6.2' gem 'webmock', '~> 1.21.0' - gem 'test_after_commit', '~> 0.4.2' + gem 'test_after_commit', '~> 1.1' gem 'sham_rack', '~> 1.3.6' gem 'timecop', '~> 0.8.0' end diff --git a/Gemfile.lock b/Gemfile.lock index 104e6444803..d8070caac56 100644 --- a/Gemfile.lock +++ b/Gemfile.lock @@ -760,7 +760,7 @@ GEM teaspoon-jasmine (2.2.0) teaspoon (>= 1.0.0) temple (0.7.7) - test_after_commit (0.4.2) + test_after_commit (1.1.0) activerecord (>= 3.2) thin (1.7.0) daemons (~> 1.0, >= 1.0.9) @@ -997,7 +997,7 @@ DEPENDENCIES sys-filesystem (~> 1.1.6) teaspoon (~> 1.1.0) teaspoon-jasmine (~> 2.2.0) - test_after_commit (~> 0.4.2) + test_after_commit (~> 1.1) thin (~> 1.7.0) timecop (~> 0.8.0) truncato (~> 0.7.8) diff --git a/app/models/member.rb b/app/models/member.rb index c585e0b450e..26a6054e00d 100644 --- a/app/models/member.rb +++ b/app/models/member.rb @@ -68,9 +68,9 @@ class Member < ActiveRecord::Base after_create :send_request, if: :request?, unless: :importing? after_create :create_notification_setting, unless: [:pending?, :importing?] after_create :post_create_hook, unless: [:pending?, :importing?] - after_create :refresh_member_authorized_projects, if: :importing? after_update :post_update_hook, unless: [:pending?, :importing?] after_destroy :post_destroy_hook, unless: :pending? + after_commit :refresh_member_authorized_projects delegate :name, :username, :email, to: :user, prefix: true @@ -147,8 +147,6 @@ class Member < ActiveRecord::Base member.save end - UserProjectAccessChangedService.new(user.id).execute if user.is_a?(User) - member end @@ -275,23 +273,27 @@ class Member < ActiveRecord::Base end def post_create_hook - UserProjectAccessChangedService.new(user.id).execute system_hook_service.execute_hooks_for(self, :create) end def post_update_hook - UserProjectAccessChangedService.new(user.id).execute if access_level_changed? + # override in sub class end def post_destroy_hook - refresh_member_authorized_projects system_hook_service.execute_hooks_for(self, :destroy) end + # Refreshes authorizations of the current member. + # + # This method schedules a job using Sidekiq and as such **must not** be called + # in a transaction. Doing so can lead to the job running before the + # transaction has been committed, resulting in the job either throwing an + # error or not doing any meaningful work. def refresh_member_authorized_projects - # If user/source is being destroyed, project access are gonna be destroyed eventually - # because of DB foreign keys, so we shouldn't bother with refreshing after each - # member is destroyed through association + # If user/source is being destroyed, project access are going to be + # destroyed eventually because of DB foreign keys, so we shouldn't bother + # with refreshing after each member is destroyed through association return if destroyed_by_association.present? UserProjectAccessChangedService.new(user_id).execute diff --git a/app/models/project_group_link.rb b/app/models/project_group_link.rb index 6149c35cc61..5cb6b0c527d 100644 --- a/app/models/project_group_link.rb +++ b/app/models/project_group_link.rb @@ -16,8 +16,7 @@ class ProjectGroupLink < ActiveRecord::Base validates :group_access, inclusion: { in: Gitlab::Access.values }, presence: true validate :different_group - after_create :refresh_group_members_authorized_projects - after_destroy :refresh_group_members_authorized_projects + after_commit :refresh_group_members_authorized_projects def self.access_options Gitlab::Access.options diff --git a/app/services/user_project_access_changed_service.rb b/app/services/user_project_access_changed_service.rb index 2469b4f0d7c..d7a6804ee88 100644 --- a/app/services/user_project_access_changed_service.rb +++ b/app/services/user_project_access_changed_service.rb @@ -4,6 +4,6 @@ class UserProjectAccessChangedService end def execute - AuthorizedProjectsWorker.bulk_perform_async(@user_ids.map { |id| [id] }) + AuthorizedProjectsWorker.bulk_perform_and_wait(@user_ids.map { |id| [id] }) end end diff --git a/app/workers/authorized_projects_worker.rb b/app/workers/authorized_projects_worker.rb index 2badd0680fb..6abbb5a5250 100644 --- a/app/workers/authorized_projects_worker.rb +++ b/app/workers/authorized_projects_worker.rb @@ -2,6 +2,13 @@ class AuthorizedProjectsWorker include Sidekiq::Worker include DedicatedSidekiqQueue + # Schedules multiple jobs and waits for them to be completed. + def self.bulk_perform_and_wait(args_list) + job_ids = bulk_perform_async(args_list) + + Gitlab::JobWaiter.new(job_ids).wait + end + def self.bulk_perform_async(args_list) Sidekiq::Client.push_bulk('class' => self, 'args' => args_list) end diff --git a/changelogs/unreleased/refresh-authorizations-fork-join.yml b/changelogs/unreleased/refresh-authorizations-fork-join.yml new file mode 100644 index 00000000000..b1349b9447d --- /dev/null +++ b/changelogs/unreleased/refresh-authorizations-fork-join.yml @@ -0,0 +1,4 @@ +--- +title: Fix race conditions for AuthorizedProjectsWorker +merge_request: +author: diff --git a/config/initializers/sidekiq.rb b/config/initializers/sidekiq.rb index 5a7365bb0f6..fa318384405 100644 --- a/config/initializers/sidekiq.rb +++ b/config/initializers/sidekiq.rb @@ -12,6 +12,11 @@ Sidekiq.configure_server do |config| chain.add Gitlab::SidekiqMiddleware::ArgumentsLogger if ENV['SIDEKIQ_LOG_ARGUMENTS'] chain.add Gitlab::SidekiqMiddleware::MemoryKiller if ENV['SIDEKIQ_MEMORY_KILLER_MAX_RSS'] chain.add Gitlab::SidekiqMiddleware::RequestStoreMiddleware unless ENV['SIDEKIQ_REQUEST_STORE'] == '0' + chain.add Gitlab::SidekiqStatus::ServerMiddleware + end + + config.client_middleware do |chain| + chain.add Gitlab::SidekiqStatus::ClientMiddleware end # Sidekiq-cron: load recurring jobs from gitlab.yml @@ -46,6 +51,10 @@ end Sidekiq.configure_client do |config| config.redis = redis_config_hash + + config.client_middleware do |chain| + chain.add Gitlab::SidekiqStatus::ClientMiddleware + end end # The Sidekiq client API always adds the queue to the Sidekiq queue diff --git a/db/fixtures/development/01_admin.rb b/db/fixtures/development/01_admin.rb index bba2fc4b186..6f241f6fa4a 100644 --- a/db/fixtures/development/01_admin.rb +++ b/db/fixtures/development/01_admin.rb @@ -1,3 +1,5 @@ +require './spec/support/sidekiq' + Gitlab::Seeder.quiet do User.seed do |s| s.id = 1 diff --git a/db/fixtures/development/04_project.rb b/db/fixtures/development/04_project.rb index a984eda5ab5..c2b8f7ba819 100644 --- a/db/fixtures/development/04_project.rb +++ b/db/fixtures/development/04_project.rb @@ -1,4 +1,4 @@ -require 'sidekiq/testing' +require './spec/support/sidekiq' Sidekiq::Testing.inline! do Gitlab::Seeder.quiet do diff --git a/db/fixtures/development/05_users.rb b/db/fixtures/development/05_users.rb index 03da29c4c68..101ff3a1209 100644 --- a/db/fixtures/development/05_users.rb +++ b/db/fixtures/development/05_users.rb @@ -1,3 +1,5 @@ +require './spec/support/sidekiq' + Gitlab::Seeder.quiet do 20.times do |i| begin diff --git a/db/fixtures/development/06_teams.rb b/db/fixtures/development/06_teams.rb index 5c2a03fec3f..86e0a38aae1 100644 --- a/db/fixtures/development/06_teams.rb +++ b/db/fixtures/development/06_teams.rb @@ -1,4 +1,4 @@ -require 'sidekiq/testing' +require './spec/support/sidekiq' Sidekiq::Testing.inline! do Gitlab::Seeder.quiet do diff --git a/db/fixtures/development/07_milestones.rb b/db/fixtures/development/07_milestones.rb index 540e4e68259..271bfbc97e0 100644 --- a/db/fixtures/development/07_milestones.rb +++ b/db/fixtures/development/07_milestones.rb @@ -1,3 +1,5 @@ +require './spec/support/sidekiq' + Gitlab::Seeder.quiet do Project.all.each do |project| 5.times do |i| diff --git a/db/fixtures/development/09_issues.rb b/db/fixtures/development/09_issues.rb index 4fa572fca9b..d93d133d157 100644 --- a/db/fixtures/development/09_issues.rb +++ b/db/fixtures/development/09_issues.rb @@ -1,3 +1,5 @@ +require './spec/support/sidekiq' + Gitlab::Seeder.quiet do Project.all.each do |project| 10.times do diff --git a/db/fixtures/development/10_merge_requests.rb b/db/fixtures/development/10_merge_requests.rb index 87fb8e3300d..c04afe97277 100644 --- a/db/fixtures/development/10_merge_requests.rb +++ b/db/fixtures/development/10_merge_requests.rb @@ -1,3 +1,5 @@ +require './spec/support/sidekiq' + Gitlab::Seeder.quiet do # Limit the number of merge requests per project to avoid long seeds MAX_NUM_MERGE_REQUESTS = 10 diff --git a/db/fixtures/development/11_keys.rb b/db/fixtures/development/11_keys.rb index 8b4bee384e1..51e22137d6f 100644 --- a/db/fixtures/development/11_keys.rb +++ b/db/fixtures/development/11_keys.rb @@ -1,12 +1,18 @@ -Gitlab::Seeder.quiet do - User.first(10).each do |user| - key = "ssh-rsa AAAAB3NzaC1yc2EAAAABJQAAAIEAiPWx6WM4lhHNedGfBpPJNPpZ7yKu+dnn1SJejgt#{user.id + 100}6k6YjzGGphH2TUxwKzxcKDKKezwkpfnxPkSMkuEspGRt/aZZ9wa++Oi7Qkr8prgHc4soW6NUlfDzpvZK2H5E7eQaSeP3SAwGmQKUFHCddNaP0L+hM7zhFNzjFvpaMgJw0=" +require './spec/support/sidekiq' - user.keys.create( - title: "Sample key #{user.id}", - key: key - ) +# Creating keys runs a gitlab-shell worker. Since we may not have the right +# gitlab-shell path set (yet) we need to disable this for these fixtures. +Sidekiq::Testing.disable! do + Gitlab::Seeder.quiet do + User.first(10).each do |user| + key = "ssh-rsa AAAAB3NzaC1yc2EAAAABJQAAAIEAiPWx6WM4lhHNedGfBpPJNPpZ7yKu+dnn1SJejgt#{user.id + 100}6k6YjzGGphH2TUxwKzxcKDKKezwkpfnxPkSMkuEspGRt/aZZ9wa++Oi7Qkr8prgHc4soW6NUlfDzpvZK2H5E7eQaSeP3SAwGmQKUFHCddNaP0L+hM7zhFNzjFvpaMgJw0=" - print '.' + user.keys.create( + title: "Sample key #{user.id}", + key: key + ) + + print '.' + end end end diff --git a/db/fixtures/development/12_snippets.rb b/db/fixtures/development/12_snippets.rb index 74898544a69..4f3bdba043d 100644 --- a/db/fixtures/development/12_snippets.rb +++ b/db/fixtures/development/12_snippets.rb @@ -1,3 +1,5 @@ +require './spec/support/sidekiq' + Gitlab::Seeder.quiet do content =< '123' }, double(:queue), double(:pool)) { nil } + end + end +end diff --git a/spec/lib/gitlab/sidekiq_status/server_middleware_spec.rb b/spec/lib/gitlab/sidekiq_status/server_middleware_spec.rb new file mode 100644 index 00000000000..80728197b8c --- /dev/null +++ b/spec/lib/gitlab/sidekiq_status/server_middleware_spec.rb @@ -0,0 +1,14 @@ +require 'spec_helper' + +describe Gitlab::SidekiqStatus::ServerMiddleware do + describe '#call' do + it 'stops tracking of a job upon completion' do + expect(Gitlab::SidekiqStatus).to receive(:unset).with('123') + + ret = described_class.new. + call(double(:worker), { 'jid' => '123' }, double(:queue)) { 10 } + + expect(ret).to eq(10) + end + end +end diff --git a/spec/lib/gitlab/sidekiq_status_spec.rb b/spec/lib/gitlab/sidekiq_status_spec.rb new file mode 100644 index 00000000000..0aa36a3416b --- /dev/null +++ b/spec/lib/gitlab/sidekiq_status_spec.rb @@ -0,0 +1,50 @@ +require 'spec_helper' + +describe Gitlab::SidekiqStatus do + describe '.set', :redis do + it 'stores the job ID' do + described_class.set('123') + + key = described_class.key_for('123') + + Sidekiq.redis do |redis| + expect(redis.exists(key)).to eq(true) + expect(redis.ttl(key) > 0).to eq(true) + end + end + end + + describe '.unset', :redis do + it 'removes the job ID' do + described_class.set('123') + described_class.unset('123') + + key = described_class.key_for('123') + + Sidekiq.redis do |redis| + expect(redis.exists(key)).to eq(false) + end + end + end + + describe '.all_completed?', :redis do + it 'returns true if all jobs have been completed' do + expect(described_class.all_completed?(%w(123))).to eq(true) + end + + it 'returns false if a job has not yet been completed' do + described_class.set('123') + + expect(described_class.all_completed?(%w(123 456))).to eq(false) + end + end + + describe '.key_for' do + it 'returns the key for a job ID' do + key = described_class.key_for('123') + + expect(key).to be_an_instance_of(String) + expect(key).to include('123') + end + end +end diff --git a/spec/services/user_project_access_changed_service_spec.rb b/spec/services/user_project_access_changed_service_spec.rb new file mode 100644 index 00000000000..b4efe7de431 --- /dev/null +++ b/spec/services/user_project_access_changed_service_spec.rb @@ -0,0 +1,12 @@ +require 'spec_helper' + +describe UserProjectAccessChangedService do + describe '#execute' do + it 'schedules the user IDs' do + expect(AuthorizedProjectsWorker).to receive(:bulk_perform_and_wait). + with([[1], [2]]) + + described_class.new([1, 2]).execute + end + end +end diff --git a/spec/spec_helper.rb b/spec/spec_helper.rb index 6ee3307512d..4c5972d8111 100644 --- a/spec/spec_helper.rb +++ b/spec/spec_helper.rb @@ -6,7 +6,6 @@ ENV["RAILS_ENV"] ||= 'test' require File.expand_path("../../config/environment", __FILE__) require 'rspec/rails' require 'shoulda/matchers' -require 'sidekiq/testing/inline' require 'rspec/retry' if ENV['CI'] && !ENV['NO_KNAPSACK'] diff --git a/spec/support/sidekiq.rb b/spec/support/sidekiq.rb new file mode 100644 index 00000000000..575d3451150 --- /dev/null +++ b/spec/support/sidekiq.rb @@ -0,0 +1,5 @@ +require 'sidekiq/testing/inline' + +Sidekiq::Testing.server_middleware do |chain| + chain.add Gitlab::SidekiqStatus::ServerMiddleware +end diff --git a/spec/workers/authorized_projects_worker_spec.rb b/spec/workers/authorized_projects_worker_spec.rb index b6591f272f6..97c4bfcd248 100644 --- a/spec/workers/authorized_projects_worker_spec.rb +++ b/spec/workers/authorized_projects_worker_spec.rb @@ -3,6 +3,18 @@ require 'spec_helper' describe AuthorizedProjectsWorker do let(:worker) { described_class.new } + describe '.bulk_perform_and_wait' do + it 'schedules the ids and waits for the jobs to complete' do + project = create(:project) + + project.owner.project_authorizations.delete_all + + described_class.bulk_perform_and_wait([[project.owner.id]]) + + expect(project.owner.project_authorizations.count).to eq(1) + end + end + describe '#perform' do it "refreshes user's authorized projects" do user = create(:user) -- cgit v1.2.3