Exception: 4:Deadline Exceeded - Can repository housekeeping be removed from the import?
Fixes:
- %14.9 and later might have reduced incidence of this issue owing to the fix in !82326 (merged)
- %15.0 and later !85505 (merged) makes this housekeeping run asynchronously
Summary
Support has been working with a customer on a GitLab instance migration; team members can read more in the ticket.
I have a project for reproducing some of their issues, and it frequently fails to import with:
ERROR -- : Exception: 4:Deadline Exceeded.The customer is also seeing this, having worked through some other issues.
It appears to be caused by repository housekeeping. This doesn't (on the face of it) seem to be critical to the success of an import.
Steps to reproduce
Perform an import on a project with large repository. Housekeeping runs after most/all of the other import tasks are complete.
Example Project
I have a 664MB project export, but it's too big to attach here.
What is the current bug behavior?
Import fails with Exception: 4:Deadline Exceeded.
What is the expected correct behavior?
Import succeeds.
IF a repo needs housekeeping, Gitaly can handle that on its own schedule?
Relevant logs and/or screenshots
Log output from
- Importing my test project to a test Omnibus instance.
- GitLab 14.4
bigprojectv1_20210516_1310_justgit-20211028150319.debug.gz
D, [2021-10-28T15:32:06.954300 #26056] DEBUG -- : TRANSACTION (1.9ms) /*application:web,db_config_name:main*/ COMMIT
D, [2021-10-28T15:32:07.013200 #26056] DEBUG -- : InternalId Destroy (1.0ms) /*application:web,db_config_name:main*/ DELETE FROM "internal_ids" WHERE "internal_ids"."project_id" = 15
D, [2021-10-28T15:32:07.016312 #26056] DEBUG -- : TRANSACTION (0.3ms) /*application:web,db_config_name:main*/ BEGIN
D, [2021-10-28T15:32:07.017120 #26056] DEBUG -- : ProjectImportState Update (0.6ms) /*application:web,db_config_name:main*/ UPDATE "project_mirror_data" SET "status" = 'finished' WHERE "project_mirror_data"."id" = 12
D, [2021-10-28T15:32:07.019766 #26056] DEBUG -- : ProjectImportState Update (0.9ms) /*application:web,db_config_name:main*/ UPDATE "project_mirror_data" SET "jid" = NULL WHERE "project_mirror_data"."id" = 12
D, [2021-10-28T15:32:07.030012 #26056] DEBUG -- : TRANSACTION (2.1ms) /*application:web,db_config_name:main*/ COMMIT
E, [2021-10-28T15:32:37.001388 #26056] ERROR -- : Exception: 4:Deadline Exceeded.
[2021-10-28T15:32:37.001454 #26056] DEBUG -- : ["/opt/gitlab/embedded/service/gitlab-rails/lib/gitlab/git/wraps_gitaly_errors.rb:13:in `rescue in wrapped_gitaly_errors'"
"/opt/gitlab/embedded/service/gitlab-rails/lib/gitlab/git/wraps_gitaly_errors.rb:6:in `wrapped_gitaly_errors'"
"/opt/gitlab/embedded/service/gitlab-rails/lib/gitlab/git/repository.rb:240:in `delete_all_refs_except'"
"/opt/gitlab/embedded/lib/ruby/gems/2.7.0/gems/activesupport-6.1.4.1/lib/active_support/core_ext/module/delegation.rb:310:in `public_send'"
"/opt/gitlab/embedded/lib/ruby/gems/2.7.0/gems/activesupport-6.1.4.1/lib/active_support/core_ext/module/delegation.rb:310:in `method_missing'"
"/opt/gitlab/embedded/service/gitlab-rails/app/services/projects/after_import_service.rb:16:in `block (2 levels) in execute'"
"/opt/gitlab/embedded/service/gitlab-rails/lib/gitlab/import_export/import_failure_service.rb:26:in `block in with_retry'"
"/opt/gitlab/embedded/lib/ruby/gems/2.7.0/gems/retriable-3.1.2/lib/retriable.rb:61:in `block in retriable'"
"/opt/gitlab/embedded/lib/ruby/gems/2.7.0/gems/retriable-3.1.2/lib/retriable.rb:56:in `times'"
"/opt/gitlab/embedded/lib/ruby/gems/2.7.0/gems/retriable-3.1.2/lib/retriable.rb:56:in `retriable'"
"/opt/gitlab/embedded/lib/ruby/gems/2.7.0/gems/retriable-3.1.2/lib/retriable.rb:22:in `with_context'"
"/opt/gitlab/embedded/service/gitlab-rails/lib/gitlab/import_export/import_failure_service.rb:25:in `with_retry'"
"/opt/gitlab/embedded/service/gitlab-rails/app/services/projects/after_import_service.rb:15:in `block in execute'"
"/opt/gitlab/embedded/service/gitlab-rails/app/services/repositories/housekeeping_service.rb:30:in `execute'"
"/opt/gitlab/embedded/service/gitlab-rails/app/services/projects/after_import_service.rb:14:in `execute'"
"/opt/gitlab/embedded/service/gitlab-rails/app/models/project_import_state.rb:68:in `block (3 levels) in <class:ProjectImportState>'"
"/opt/gitlab/embedded/service/gitlab-rails/lib/after_commit_queue.rb:39:in `instance_eval'"
"/opt/gitlab/embedded/service/gitlab-rails/lib/after_commit_queue.rb:39:in `_run_after_commit_queue'"Output of checks
My most recent reproduction was GitLab 14.4, but the code is unchanged.
I'd been encountering this in test prior to June 2021 (so: 13.12 and earlier)
Possible fixes
I think this code is where the ERROR -- : Exception: 4:Deadline Exceeded. occurs:
service.execute do
import_failure_service.with_retry(action: 'delete_all_refs') do
repository.delete_all_refs_except(RESERVED_REF_PREFIXES)
end
endMove housekeeping process to a separate sidekiq worker in order for big imports to have an opportunity to finish.