summaryrefslogtreecommitdiff
diff options
context:
space:
mode:
authorTiago Botelho <tiagonbotelho@hotmail.com>2018-10-22 15:49:20 +0100
committerTiago Botelho <tiagonbotelho@hotmail.com>2018-10-25 10:10:45 +0100
commit084a8b6101c25e5d3d4f97f078abd9a649a2fb64 (patch)
tree888cd28681c079561effde22bf6094e7c8db71b4
parentf5d71ad8f3d1899a29bc12c4fcc8847b14195e3a (diff)
downloadgitlab-ce-084a8b6101c25e5d3d4f97f078abd9a649a2fb64.tar.gz
Adds tracing messages for slow git pushes
Whenever a git push takes more than 50 seconds the user will receive a trace from each check performed along with their timings
-rw-r--r--app/controllers/projects/git_http_controller.rb5
-rw-r--r--changelogs/unreleased/42790-improve-feedback-for-internal-git-access-checks-timeouts.yml5
-rw-r--r--lib/api/internal.rb2
-rw-r--r--lib/gitlab/checks/change_access.rb108
-rw-r--r--lib/gitlab/checks/lfs_integrity.rb5
-rw-r--r--lib/gitlab/checks/timed_logger.rb69
-rw-r--r--lib/gitlab/git/lfs_changes.rb4
-rw-r--r--lib/gitlab/git_access.rb22
-rw-r--r--lib/gitlab/gitaly_client/blob_service.rb17
-rw-r--r--spec/lib/gitlab/checks/change_access_spec.rb18
-rw-r--r--spec/lib/gitlab/checks/lfs_integrity_spec.rb3
-rw-r--r--spec/lib/gitlab/checks/timed_logger_spec.rb75
-rw-r--r--spec/lib/gitlab/git/lfs_changes_spec.rb4
-rw-r--r--spec/lib/gitlab/git_access_spec.rb10
-rw-r--r--spec/requests/api/internal_spec.rb18
15 files changed, 317 insertions, 48 deletions
diff --git a/app/controllers/projects/git_http_controller.rb b/app/controllers/projects/git_http_controller.rb
index be708835e30..c0aa39d87c6 100644
--- a/app/controllers/projects/git_http_controller.rb
+++ b/app/controllers/projects/git_http_controller.rb
@@ -8,6 +8,7 @@ class Projects::GitHttpController < Projects::GitHttpClientController
rescue_from Gitlab::GitAccess::UnauthorizedError, with: :render_403
rescue_from Gitlab::GitAccess::NotFoundError, with: :render_404
rescue_from Gitlab::GitAccess::ProjectCreationError, with: :render_422
+ rescue_from Gitlab::GitAccess::TimeoutError, with: :render_503
# GET /foo/bar.git/info/refs?service=git-upload-pack (git pull)
# GET /foo/bar.git/info/refs?service=git-receive-pack (git push)
@@ -62,6 +63,10 @@ class Projects::GitHttpController < Projects::GitHttpClientController
render plain: exception.message, status: :unprocessable_entity
end
+ def render_503(exception)
+ render plain: exception.message, status: :service_unavailable
+ end
+
def access
@access ||= access_klass.new(access_actor, project,
'http', authentication_abilities: authentication_abilities,
diff --git a/changelogs/unreleased/42790-improve-feedback-for-internal-git-access-checks-timeouts.yml b/changelogs/unreleased/42790-improve-feedback-for-internal-git-access-checks-timeouts.yml
new file mode 100644
index 00000000000..d58d8da3a0e
--- /dev/null
+++ b/changelogs/unreleased/42790-improve-feedback-for-internal-git-access-checks-timeouts.yml
@@ -0,0 +1,5 @@
+---
+title: Adds trace of each access check when git push times out
+merge_request: 22265
+author:
+type: added
diff --git a/lib/api/internal.rb b/lib/api/internal.rb
index 4dd6b19e353..ae40b5f7557 100644
--- a/lib/api/internal.rb
+++ b/lib/api/internal.rb
@@ -65,6 +65,8 @@ module API
result
rescue Gitlab::GitAccess::UnauthorizedError => e
break response_with_status(code: 401, success: false, message: e.message)
+ rescue Gitlab::GitAccess::TimeoutError => e
+ break response_with_status(code: 503, success: false, message: e.message)
rescue Gitlab::GitAccess::NotFoundError => e
break response_with_status(code: 404, success: false, message: e.message)
end
diff --git a/lib/gitlab/checks/change_access.rb b/lib/gitlab/checks/change_access.rb
index 49e7f7e1fd7..52a72de3b15 100644
--- a/lib/gitlab/checks/change_access.rb
+++ b/lib/gitlab/checks/change_access.rb
@@ -18,11 +18,24 @@ module Gitlab
lfs_objects_missing: 'LFS objects are missing. Ensure LFS is properly set up or try a manual "git lfs push --all".'
}.freeze
- attr_reader :user_access, :project, :skip_authorization, :skip_lfs_integrity_check, :protocol, :oldrev, :newrev, :ref, :branch_name, :tag_name
+ LOG_MESSAGES = {
+ push_checks: "Checking if you are allowed to push...",
+ delete_default_branch_check: "Checking if default branch is being deleted...",
+ protected_branch_checks: "Checking if you are force pushing to a protected branch...",
+ protected_branch_push_checks: "Checking if you are allowed to push to the protected branch...",
+ protected_branch_deletion_checks: "Checking if you are allowed to delete the protected branch...",
+ tag_checks: "Checking if you are allowed to change existing tags...",
+ protected_tag_checks: "Checking if you are creating, updating or deleting a protected tag...",
+ lfs_objects_exist_check: "Scanning repository for blobs stored in LFS and verifying their files have been uploaded to GitLab...",
+ commits_check_file_paths_validation: "Validating commits' file paths...",
+ commits_check: "Validating commits..." # different message in EE
+ }.freeze
+
+ attr_reader :user_access, :project, :skip_authorization, :skip_lfs_integrity_check, :protocol, :oldrev, :newrev, :ref, :branch_name, :tag_name, :logger
def initialize(
change, user_access:, project:, skip_authorization: false,
- skip_lfs_integrity_check: false, protocol:
+ skip_lfs_integrity_check: false, protocol:, logger:
)
@oldrev, @newrev, @ref = change.values_at(:oldrev, :newrev, :ref)
@branch_name = Gitlab::Git.branch_name(@ref)
@@ -32,6 +45,9 @@ module Gitlab
@skip_authorization = skip_authorization
@skip_lfs_integrity_check = skip_lfs_integrity_check
@protocol = protocol
+
+ @logger = logger
+ @logger.log << "Running checks for ref: #{@branch_name || @tag_name}"
end
def exec(skip_commits_check: false)
@@ -49,26 +65,32 @@ module Gitlab
protected
def push_checks
- unless can_push?
- raise GitAccess::UnauthorizedError, ERROR_MESSAGES[:push_code]
+ logger.log_timed(LOG_MESSAGES[__method__]) do
+ unless can_push?
+ raise GitAccess::UnauthorizedError, ERROR_MESSAGES[:push_code]
+ end
end
end
def branch_checks
return unless branch_name
- if deletion? && branch_name == project.default_branch
- raise GitAccess::UnauthorizedError, ERROR_MESSAGES[:delete_default_branch]
+ logger.log_timed(LOG_MESSAGES[:delete_default_branch_check]) do
+ if deletion? && branch_name == project.default_branch
+ raise GitAccess::UnauthorizedError, ERROR_MESSAGES[:delete_default_branch]
+ end
end
protected_branch_checks
end
def protected_branch_checks
- return unless ProtectedBranch.protected?(project, branch_name)
+ logger.log_timed(LOG_MESSAGES[__method__]) do
+ return unless ProtectedBranch.protected?(project, branch_name) # rubocop:disable Cop/AvoidReturnFromBlocks
- if forced_push?
- raise GitAccess::UnauthorizedError, ERROR_MESSAGES[:force_push_protected_branch]
+ if forced_push?
+ raise GitAccess::UnauthorizedError, ERROR_MESSAGES[:force_push_protected_branch]
+ end
end
if deletion?
@@ -79,23 +101,27 @@ module Gitlab
end
def protected_branch_deletion_checks
- unless user_access.can_delete_branch?(branch_name)
- raise GitAccess::UnauthorizedError, ERROR_MESSAGES[:non_master_delete_protected_branch]
- end
+ logger.log_timed(LOG_MESSAGES[__method__]) do
+ unless user_access.can_delete_branch?(branch_name)
+ raise GitAccess::UnauthorizedError, ERROR_MESSAGES[:non_master_delete_protected_branch]
+ end
- unless updated_from_web?
- raise GitAccess::UnauthorizedError, ERROR_MESSAGES[:non_web_delete_protected_branch]
+ unless updated_from_web?
+ raise GitAccess::UnauthorizedError, ERROR_MESSAGES[:non_web_delete_protected_branch]
+ end
end
end
def protected_branch_push_checks
- if matching_merge_request?
- unless user_access.can_merge_to_branch?(branch_name) || user_access.can_push_to_branch?(branch_name)
- raise GitAccess::UnauthorizedError, ERROR_MESSAGES[:merge_protected_branch]
- end
- else
- unless user_access.can_push_to_branch?(branch_name)
- raise GitAccess::UnauthorizedError, push_to_protected_branch_rejected_message
+ logger.log_timed(LOG_MESSAGES[__method__]) do
+ if matching_merge_request?
+ unless user_access.can_merge_to_branch?(branch_name) || user_access.can_push_to_branch?(branch_name)
+ raise GitAccess::UnauthorizedError, ERROR_MESSAGES[:merge_protected_branch]
+ end
+ else
+ unless user_access.can_push_to_branch?(branch_name)
+ raise GitAccess::UnauthorizedError, push_to_protected_branch_rejected_message
+ end
end
end
end
@@ -103,21 +129,25 @@ module Gitlab
def tag_checks
return unless tag_name
- if tag_exists? && user_access.cannot_do_action?(:admin_project)
- raise GitAccess::UnauthorizedError, ERROR_MESSAGES[:change_existing_tags]
+ logger.log_timed(LOG_MESSAGES[__method__]) do
+ if tag_exists? && user_access.cannot_do_action?(:admin_project)
+ raise GitAccess::UnauthorizedError, ERROR_MESSAGES[:change_existing_tags]
+ end
end
protected_tag_checks
end
def protected_tag_checks
- return unless ProtectedTag.protected?(project, tag_name)
+ logger.log_timed(LOG_MESSAGES[__method__]) do
+ return unless ProtectedTag.protected?(project, tag_name) # rubocop:disable Cop/AvoidReturnFromBlocks
- raise(GitAccess::UnauthorizedError, ERROR_MESSAGES[:update_protected_tag]) if update?
- raise(GitAccess::UnauthorizedError, ERROR_MESSAGES[:delete_protected_tag]) if deletion?
+ raise(GitAccess::UnauthorizedError, ERROR_MESSAGES[:update_protected_tag]) if update?
+ raise(GitAccess::UnauthorizedError, ERROR_MESSAGES[:delete_protected_tag]) if deletion?
- unless user_access.can_create_tag?(tag_name)
- raise GitAccess::UnauthorizedError, ERROR_MESSAGES[:create_protected_tag]
+ unless user_access.can_create_tag?(tag_name)
+ raise GitAccess::UnauthorizedError, ERROR_MESSAGES[:create_protected_tag]
+ end
end
end
@@ -125,14 +155,18 @@ module Gitlab
return if deletion? || newrev.nil?
return unless should_run_commit_validations?
- # n+1: https://gitlab.com/gitlab-org/gitlab-ee/issues/3593
- ::Gitlab::GitalyClient.allow_n_plus_1_calls do
- commits.each do |commit|
- commit_check.validate(commit, validations_for_commit(commit))
+ logger.log_timed(LOG_MESSAGES[__method__]) do
+ # n+1: https://gitlab.com/gitlab-org/gitlab-ee/issues/3593
+ ::Gitlab::GitalyClient.allow_n_plus_1_calls do
+ commits.each do |commit|
+ commit_check.validate(commit, validations_for_commit(commit))
+ end
end
end
- commit_check.validate_file_paths
+ logger.log_timed(LOG_MESSAGES[:commits_check_file_paths_validation]) do
+ commit_check.validate_file_paths
+ end
end
# Method overwritten in EE to inject custom validations
@@ -194,10 +228,12 @@ module Gitlab
end
def lfs_objects_exist_check
- lfs_check = Checks::LfsIntegrity.new(project, newrev)
+ logger.log_timed(LOG_MESSAGES[__method__]) do
+ lfs_check = Checks::LfsIntegrity.new(project, newrev, logger.time_left)
- if lfs_check.objects_missing?
- raise GitAccess::UnauthorizedError, ERROR_MESSAGES[:lfs_objects_missing]
+ if lfs_check.objects_missing?
+ raise GitAccess::UnauthorizedError, ERROR_MESSAGES[:lfs_objects_missing]
+ end
end
end
diff --git a/lib/gitlab/checks/lfs_integrity.rb b/lib/gitlab/checks/lfs_integrity.rb
index fa3dc1808df..1652d5a30a4 100644
--- a/lib/gitlab/checks/lfs_integrity.rb
+++ b/lib/gitlab/checks/lfs_integrity.rb
@@ -3,9 +3,10 @@
module Gitlab
module Checks
class LfsIntegrity
- def initialize(project, newrev)
+ def initialize(project, newrev, time_left)
@project = project
@newrev = newrev
+ @time_left = time_left
end
# rubocop: disable CodeReuse/ActiveRecord
@@ -13,7 +14,7 @@ module Gitlab
return false unless @newrev && @project.lfs_enabled?
new_lfs_pointers = Gitlab::Git::LfsChanges.new(@project.repository, @newrev)
- .new_pointers(object_limit: ::Gitlab::Git::Repository::REV_LIST_COMMIT_LIMIT)
+ .new_pointers(object_limit: ::Gitlab::Git::Repository::REV_LIST_COMMIT_LIMIT, dynamic_timeout: @time_left)
return false unless new_lfs_pointers.present?
diff --git a/lib/gitlab/checks/timed_logger.rb b/lib/gitlab/checks/timed_logger.rb
new file mode 100644
index 00000000000..cbb079a5383
--- /dev/null
+++ b/lib/gitlab/checks/timed_logger.rb
@@ -0,0 +1,69 @@
+# frozen_string_literal: true
+
+module Gitlab
+ module Checks
+ class TimedLogger
+ TimeoutError = Class.new(StandardError)
+
+ attr_reader :start_time
+ attr_accessor :log, :timeout
+
+ def initialize(start_time: Time.now, log: [], timeout:)
+ @start_time = start_time
+ @timeout = timeout
+ @log = log
+ end
+
+ def log_timed(log_message, start = Time.now)
+ check_timeout_reached
+
+ timed = true
+
+ yield
+
+ log << log_message + time_suffix_message(start: start)
+ rescue GRPC::DeadlineExceeded, TimeoutError
+ args = { cancelled: true }
+ args[:start] = start if timed
+
+ log << log_message + time_suffix_message(args)
+
+ raise TimeoutError
+ end
+
+ def check_timeout_reached
+ return unless time_expired?
+
+ raise TimeoutError
+ end
+
+ def time_left
+ (start_time + timeout.seconds) - Time.now
+ end
+
+ private
+
+ def time_expired?
+ time_left <= 0
+ end
+
+ def time_suffix_message(cancelled: false, start: nil)
+ return " (#{elapsed_time(start)}ms)" unless cancelled
+
+ if start
+ " (cancelled after #{elapsed_time(start)}ms)"
+ else
+ " (cancelled)"
+ end
+ end
+
+ def elapsed_time(start)
+ to_ms(Time.now - start)
+ end
+
+ def to_ms(elapsed)
+ (elapsed.to_f * 1000).round(2)
+ end
+ end
+ end
+end
diff --git a/lib/gitlab/git/lfs_changes.rb b/lib/gitlab/git/lfs_changes.rb
index f0fab1e76a3..d7148165408 100644
--- a/lib/gitlab/git/lfs_changes.rb
+++ b/lib/gitlab/git/lfs_changes.rb
@@ -6,8 +6,8 @@ module Gitlab
@newrev = newrev
end
- def new_pointers(object_limit: nil, not_in: nil)
- @repository.gitaly_blob_client.get_new_lfs_pointers(@newrev, object_limit, not_in)
+ def new_pointers(object_limit: nil, not_in: nil, dynamic_timeout: nil)
+ @repository.gitaly_blob_client.get_new_lfs_pointers(@newrev, object_limit, not_in, dynamic_timeout)
end
def all_pointers
diff --git a/lib/gitlab/git_access.rb b/lib/gitlab/git_access.rb
index 827c04ae035..713a98bb556 100644
--- a/lib/gitlab/git_access.rb
+++ b/lib/gitlab/git_access.rb
@@ -9,6 +9,7 @@ module Gitlab
UnauthorizedError = Class.new(StandardError)
NotFoundError = Class.new(StandardError)
ProjectCreationError = Class.new(StandardError)
+ TimeoutError = Class.new(StandardError)
ProjectMovedError = Class.new(NotFoundError)
ERROR_MESSAGES = {
@@ -26,11 +27,12 @@ module Gitlab
cannot_push_to_read_only: "You can't push code to a read-only GitLab instance."
}.freeze
+ INTERNAL_TIMEOUT = 50.seconds.freeze
DOWNLOAD_COMMANDS = %w{git-upload-pack git-upload-archive}.freeze
PUSH_COMMANDS = %w{git-receive-pack}.freeze
ALL_COMMANDS = DOWNLOAD_COMMANDS + PUSH_COMMANDS
- attr_reader :actor, :project, :protocol, :authentication_abilities, :namespace_path, :project_path, :redirected_path, :auth_result_type, :changes
+ attr_reader :actor, :project, :protocol, :authentication_abilities, :namespace_path, :project_path, :redirected_path, :auth_result_type, :changes, :logger
def initialize(actor, project, protocol, authentication_abilities:, namespace_path: nil, project_path: nil, redirected_path: nil, auth_result_type: nil)
@actor = actor
@@ -44,6 +46,7 @@ module Gitlab
end
def check(cmd, changes)
+ @logger = Checks::TimedLogger.new(timeout: INTERNAL_TIMEOUT)
@changes = changes
check_protocol!
@@ -269,14 +272,25 @@ module Gitlab
end
def check_single_change_access(change, skip_lfs_integrity_check: false)
- Checks::ChangeAccess.new(
+ change_access = Checks::ChangeAccess.new(
change,
user_access: user_access,
project: project,
skip_authorization: deploy_key?,
skip_lfs_integrity_check: skip_lfs_integrity_check,
- protocol: protocol
- ).exec
+ protocol: protocol,
+ logger: logger
+ )
+
+ change_access.exec
+ rescue Checks::TimedLogger::TimeoutError
+ header = <<~MESSAGE
+ Push operation timed out
+
+ Timing information for debugging purposes:
+ MESSAGE
+
+ raise TimeoutError, header + logger.log.join("\n")
end
def deploy_key
diff --git a/lib/gitlab/gitaly_client/blob_service.rb b/lib/gitlab/gitaly_client/blob_service.rb
index 1840bf45154..086ce31e678 100644
--- a/lib/gitlab/gitaly_client/blob_service.rb
+++ b/lib/gitlab/gitaly_client/blob_service.rb
@@ -72,7 +72,7 @@ module Gitlab
GitalyClient::BlobsStitcher.new(response)
end
- def get_new_lfs_pointers(revision, limit, not_in)
+ def get_new_lfs_pointers(revision, limit, not_in, dynamic_timeout = nil)
request = Gitaly::GetNewLFSPointersRequest.new(
repository: @gitaly_repo,
revision: encode_binary(revision),
@@ -85,7 +85,20 @@ module Gitlab
request.not_in_refs += not_in
end
- response = GitalyClient.call(@gitaly_repo.storage_name, :blob_service, :get_new_lfs_pointers, request, timeout: GitalyClient.medium_timeout)
+ timeout =
+ if dynamic_timeout
+ [dynamic_timeout, GitalyClient.medium_timeout].min
+ else
+ GitalyClient.medium_timeout
+ end
+
+ response = GitalyClient.call(
+ @gitaly_repo.storage_name,
+ :blob_service,
+ :get_new_lfs_pointers,
+ request,
+ timeout: timeout
+ )
map_lfs_pointers(response)
end
diff --git a/spec/lib/gitlab/checks/change_access_spec.rb b/spec/lib/gitlab/checks/change_access_spec.rb
index 4df426c54ae..81804ba5c76 100644
--- a/spec/lib/gitlab/checks/change_access_spec.rb
+++ b/spec/lib/gitlab/checks/change_access_spec.rb
@@ -10,13 +10,16 @@ describe Gitlab::Checks::ChangeAccess do
let(:ref) { 'refs/heads/master' }
let(:changes) { { oldrev: oldrev, newrev: newrev, ref: ref } }
let(:protocol) { 'ssh' }
+ let(:timeout) { Gitlab::GitAccess::INTERNAL_TIMEOUT }
+ let(:logger) { Gitlab::Checks::TimedLogger.new(timeout: timeout) }
subject(:change_access) do
described_class.new(
changes,
project: project,
user_access: user_access,
- protocol: protocol
+ protocol: protocol,
+ logger: logger
)
end
@@ -30,6 +33,19 @@ describe Gitlab::Checks::ChangeAccess do
end
end
+ context 'when time limit was reached' do
+ it 'raises a TimeoutError' do
+ logger = Gitlab::Checks::TimedLogger.new(start_time: timeout.ago, timeout: timeout)
+ access = described_class.new(changes,
+ project: project,
+ user_access: user_access,
+ protocol: protocol,
+ logger: logger)
+
+ expect { access.exec }.to raise_error(Gitlab::Checks::TimedLogger::TimeoutError)
+ end
+ end
+
context 'when the user is not allowed to push to the repo' do
it 'raises an error' do
expect(user_access).to receive(:can_do_action?).with(:push_code).and_return(false)
diff --git a/spec/lib/gitlab/checks/lfs_integrity_spec.rb b/spec/lib/gitlab/checks/lfs_integrity_spec.rb
index ec22e3a198e..0488720cec8 100644
--- a/spec/lib/gitlab/checks/lfs_integrity_spec.rb
+++ b/spec/lib/gitlab/checks/lfs_integrity_spec.rb
@@ -3,6 +3,7 @@ require 'spec_helper'
describe Gitlab::Checks::LfsIntegrity do
include ProjectForksHelper
+ let!(:time_left) { 50 }
let(:project) { create(:project, :repository) }
let(:repository) { project.repository }
let(:newrev) do
@@ -15,7 +16,7 @@ describe Gitlab::Checks::LfsIntegrity do
operations.commit_tree('8856a329dd38ca86dfb9ce5aa58a16d88cc119bd', "New LFS objects")
end
- subject { described_class.new(project, newrev) }
+ subject { described_class.new(project, newrev, time_left) }
describe '#objects_missing?' do
let(:blob_object) { repository.blob_at_branch('lfs', 'files/lfs/lfs_object.iso') }
diff --git a/spec/lib/gitlab/checks/timed_logger_spec.rb b/spec/lib/gitlab/checks/timed_logger_spec.rb
new file mode 100644
index 00000000000..726f2bf2144
--- /dev/null
+++ b/spec/lib/gitlab/checks/timed_logger_spec.rb
@@ -0,0 +1,75 @@
+# frozen_string_literal: true
+
+require 'spec_helper'
+
+describe Gitlab::Checks::TimedLogger do
+ let(:log_messages) do
+ {
+ foo: "Foo message..."
+ }
+ end
+
+ class FooCheck
+ attr_accessor :logger
+
+ INTERNAL_TIMEOUT = 50.seconds.freeze
+
+ def initialize(start_time, ref)
+ @logger = Gitlab::Checks::TimedLogger.new(start_time: start_time, timeout: INTERNAL_TIMEOUT)
+ @logger.log << "Checking ref: #{ref}"
+ end
+
+ def bar_check
+ 2 + 2
+ end
+
+ def grpc_check
+ raise GRPC::DeadlineExceeded
+ end
+ end
+
+ describe '#log_timed' do
+ it 'logs message' do
+ start = Time.now
+ check = FooCheck.new(start, "bar")
+
+ Timecop.freeze(start + 30.seconds) do
+ check.logger.log_timed(log_messages[:foo], start) { check.bar_check }
+ end
+
+ expect(check.logger.log).to eq(["Checking ref: bar", "Foo message... (30000.0ms)"])
+ end
+
+ context 'when time limit was reached' do
+ it 'cancels action' do
+ start = Time.now
+ check = FooCheck.new(start, "bar")
+
+ Timecop.freeze(start + 50.seconds) do
+ expect do
+ check.logger.log_timed(log_messages[:foo], start) do
+ check.bar_check
+ end
+ end.to raise_error(described_class::TimeoutError)
+ end
+
+ expect(check.logger.log).to eq(["Checking ref: bar", "Foo message... (cancelled)"])
+ end
+
+ it 'cancels action with time elapsed if work was performed' do
+ start = Time.now
+ check = FooCheck.new(start, "bar")
+
+ Timecop.freeze(start + 30.seconds) do
+ expect do
+ check.logger.log_timed(log_messages[:foo], start) do
+ check.grpc_check
+ end
+ end.to raise_error(described_class::TimeoutError)
+
+ expect(check.logger.log).to eq(["Checking ref: bar", "Foo message... (cancelled after 30000.0ms)"])
+ end
+ end
+ end
+ end
+end
diff --git a/spec/lib/gitlab/git/lfs_changes_spec.rb b/spec/lib/gitlab/git/lfs_changes_spec.rb
index c5e7ab959b2..d035df7e0c2 100644
--- a/spec/lib/gitlab/git/lfs_changes_spec.rb
+++ b/spec/lib/gitlab/git/lfs_changes_spec.rb
@@ -15,5 +15,9 @@ describe Gitlab::Git::LfsChanges do
it 'limits new_objects using object_limit' do
expect(subject.new_pointers(object_limit: 1)).to eq([])
end
+
+ it 'times out if given a small dynamic timeout' do
+ expect { subject.new_pointers(dynamic_timeout: 0.001) }.to raise_error(GRPC::DeadlineExceeded)
+ end
end
end
diff --git a/spec/lib/gitlab/git_access_spec.rb b/spec/lib/gitlab/git_access_spec.rb
index e7da5565c26..a417ef77c9e 100644
--- a/spec/lib/gitlab/git_access_spec.rb
+++ b/spec/lib/gitlab/git_access_spec.rb
@@ -934,6 +934,16 @@ describe Gitlab::GitAccess do
# There is still an N+1 query with protected branches
expect { access.check('git-receive-pack', changes) }.not_to exceed_query_limit(control_count).with_threshold(1)
end
+
+ it 'raises TimeoutError when #check_single_change_access raises a timeout error' do
+ message = "Push operation timed out\n\nTiming information for debugging purposes:\nRunning checks for ref: wow"
+
+ expect_next_instance_of(Gitlab::Checks::ChangeAccess) do |check|
+ expect(check).to receive(:exec).and_raise(Gitlab::Checks::TimedLogger::TimeoutError)
+ end
+
+ expect { access.check('git-receive-pack', changes) }.to raise_error(described_class::TimeoutError, message)
+ end
end
end
diff --git a/spec/requests/api/internal_spec.rb b/spec/requests/api/internal_spec.rb
index e0b5b34f9c4..2ebcb787d06 100644
--- a/spec/requests/api/internal_spec.rb
+++ b/spec/requests/api/internal_spec.rb
@@ -494,6 +494,24 @@ describe API::Internal do
end
end
+ context 'request times out' do
+ context 'git push' do
+ it 'responds with a gateway timeout' do
+ personal_project = create(:project, namespace: user.namespace)
+
+ expect_next_instance_of(Gitlab::GitAccess) do |access|
+ expect(access).to receive(:check).and_raise(Gitlab::GitAccess::TimeoutError, "Foo")
+ end
+ push(key, personal_project)
+
+ expect(response).to have_gitlab_http_status(503)
+ expect(json_response['status']).to be_falsey
+ expect(json_response['message']).to eq("Foo")
+ expect(user.reload.last_activity_on).to be_nil
+ end
+ end
+ end
+
context "archived project" do
before do
project.add_developer(user)