Performance: ProtectedBranches::CreateService#sync_code_owner_approval_rules
Summary
Observing slow performance when modifying the protected branches rules via the API.
Steps to reproduce
This is reproducible at a customer instance (link for internal use) with the following specs:
- 53167 merge requests to master.
- ~400 merge requests are in open state.
- ~380 lines in codeowner files.
- Gitaly timeouts are:
Default 180
,Fast 30
andMedium 90
.
What is the current bug behavior?
When the Protected branches API is used to modify the master
branch rules, the call takes more than 3 minutes, eventually timing out due to hitting Gitaly default timeout (180).
It's important to note that this doesn't happen when attempting to modify other branches.
API call: /api/v4/projects/23/protected_branches?allowed_to_merge[][group_id]=332&allowed_to_push[][group_id]=332&allowed_to_merge[][group_id]=35&allowed_to_merge[][group_id]=329&name=master
What is the expected correct behavior?
The protected_branches
API request, outlined in the previous section, completes within reasonable time.
Relevant logs and/or screenshots
{"time":"2020-08-08T20:13:03.068Z","severity":"INFO","duration_s":171.51,"db_duration_s":39.71,"view_duration_s":131.8,"status":500,"method":"POST","path":"/api/v4/projects/23/protected_branches","params":[{"key":"name","value":"master"},{"key":"allowed_to_merge","value":[{"group_id":"35"},{"group_id":"332"}]},{"key":"{}","value":null}],"host":"<redacted>","remote_ip":"<redacted>, <redacted>","ua":"Python-urllib/2.7","route":"/api/:version/projects/:id/protected_branches","user_id":1,"username":"root","exception.class":"Gitlab::RequestContext::RequestDeadlineExceeded","exception.message":"Request takes longer than 171","exception.backtrace":["lib/gitlab/gitaly_client.rb:187:in `execute'","lib/gitlab/gitaly_client.rb:170:in `block in call'","lib/gitlab/gitaly_client.rb:198:in `measure_timings'","lib/gitlab/gitaly_client.rb:169:in `call'","lib/gitlab/gitaly_client/commit_service.rb:215:in `diff_stats'","lib/gitlab/git/repository.rb:455:in `block in diff_stats'","lib/gitlab/git/wraps_gitaly_errors.rb:7:in `wrapped_gitaly_errors'","lib/gitlab/git/repository.rb:454:in `diff_stats'","app/models/repository.rb:472:in `method_missing'","ee/lib/gitlab/code_owners.rb:61:in `slow_path_lookup'","ee/lib/gitlab/code_owners.rb:45:in `paths_for_merge_request'","ee/lib/gitlab/code_owners.rb:33:in `loader_for_merge_request'","ee/lib/gitlab/code_owners.rb:23:in `entries_for_merge_request'","ee/app/services/merge_requests/sync_code_owner_approval_rules.rb:46:in `code_owner_entries'","ee/app/services/merge_requests/sync_code_owner_approval_rules.rb:41:in `patterns'","ee/app/services/merge_requests/sync_code_owner_approval_rules.rb:37:in `delete_outdated_code_owner_rules'","ee/app/services/merge_requests/sync_code_owner_approval_rules.rb:13:in `execute'","ee/app/services/ee/protected_branches/create_service.rb:32:in `block in sync_code_owner_approval_rules'","ee/app/services/ee/protected_branches/create_service.rb:31:in `each'","ee/app/services/ee/protected_branches/create_service.rb:31:in `sync_code_owner_approval_rules'","ee/app/services/ee/protected_branches/create_service.rb:25:in `save_protected_branch'","app/services/protected_branches/create_service.rb:8:in `execute'","ee/app/services/ee/protected_branches/create_service.rb:12:in `execute'","app/services/protected_branches/api_service.rb:6:in `create'","lib/api/protected_branches.rb:74:in `block (2 levels) in <class:ProtectedBranches>'","ee/lib/gitlab/ip_address_state.rb:10:in `with'","ee/lib/gitlab/jira/middleware.rb:19:in `call'"],"queue_duration_s":0.02,"gitaly_calls":11,"gitaly_duration_s":0.01,"redis_calls":2,"redis_duration_s":0.0,"correlation_id":"me28R4i3FP5"}
Output of checks
This bug is observed in 12.10.14-ee
.
Possible fixes
The line of code responsible for this: https://gitlab.com/gitlab-org/gitlab/-/blob/master/ee/app/services/ee/protected_branches/create_service.rb#L25
Possibly related issue: #232991
Possible workarounds: Increase Gitaly Default timeout.