Sometimes `/api/:version/internal/allowed` timeouts and prevents merges
Problem
Today, @jeanduplessis reported at https://gitlab.slack.com/archives/CHLKE258E/p1591602322127600 that merges were failing in the merge request in gitlab-com/www-gitlab-com
project. It left the following error message in the notes:
Something went wrong during merge pre-receive hook. API is not accessible
This error message was generated in Gitaly. It tried to access to /api/:version/internal/allowed
endpoint in Gitlab-Rails, however, it seemed something went wrong.
Here is a 500 log for the endpoint. At first, looking at the timestamp, it's corresponding to the notes (API is not accessible
) in the merge request, for example, gitlab-com/www-gitlab-com!50982 (comment 357053615) is noted at 08:34 UTC, you can see the same timestamp in Kibana. So we can assume that these errors are connected to the merge request.
At second, looking at the backtrace. It seems it hit statement timeout when searching a merge request.
lib/gitlab/checks/matching_merge_request.rb:17:in `match?'
lib/gitlab/checks/branch_check.rb:128:in `matching_merge_request?'
lib/gitlab/checks/branch_check.rb:92:in `block in protected_branch_push_checks'
lib/gitlab/checks/timed_logger.rb:27:in `log_timed'
lib/gitlab/checks/branch_check.rb:91:in `protected_branch_push_checks'
lib/gitlab/checks/branch_check.rb:56:in `protected_branch_checks'
lib/gitlab/checks/branch_check.rb:35:in `validate!'
lib/gitlab/checks/change_access.rb:45:in `ref_level_checks'
ee/lib/ee/gitlab/checks/change_access.rb:12:in `ref_level_checks'
lib/gitlab/checks/change_access.rb:29:in `exec'
lib/gitlab/git_access.rb:333:in `check_single_change_access'
lib/gitlab/git_access.rb:318:in `block in check_change_access!'
lib/gitlab/git_access.rb:313:in `each'
lib/gitlab/git_access.rb:313:in `with_index'
lib/gitlab/git_access.rb:313:in `check_change_access!'
ee/lib/ee/gitlab/git_access.rb:65:in `check_change_access!'
lib/gitlab/git_access.rb:292:in `check_push_access!'
lib/gitlab/git_access.rb:85:in `check'
ee/lib/ee/gitlab/git_access.rb:16:in `check'
lib/api/internal/base.rb:92:in `access_check!'
lib/api/internal/base.rb:44:in `check_allowed'
ee/lib/ee/api/internal/base.rb:22:in `block in check_allowed'
ee/lib/gitlab/ip_address_state.rb:10:in `with'
ee/lib/ee/api/internal/base.rb:21:in `check_allowed'
lib/api/internal/base.rb:118:in `block (2 levels) in <class:Base>'
ee/lib/omni_auth/strategies/group_saml.rb:41:in `other_phase'
ee/lib/gitlab/jira/middleware.rb:19:in `call'
def match?
@project.merge_requests
.with_state(:locked)
.where(in_progress_merge_commit_sha: @newrev, target_branch: @branch_name)
.exists?
end
So it seems there is a performance issue on this query, and interferes Gitaly operations sometimes.
Proposal
Maybe, optimize the query?