Project Templates - When creating a new group-owned project from a template, the import frequently fails with error "Import timed out. Import took longer than 54000 seconds" or clocks on importing page indefinitely
Summary
We are seeing extremely poor performance when creating a new group-owned project from a template. The 'Import in progress' page will loop after submitting, refreshing every few seconds. In some cases this will eventually (in less than 54,000 seconds) fail with error "Import timed out. Import took longer than 54000 seconds" as in #37685 (closed), in other cases the page loops indefinitely. In cases where the import does succeed it is still very slow.
The customer reported that freeing up some RAM did partially mitigate the issue, but I can consistently recreate it with a 4-core, 12 GB host under zero load.
Reported in ZenDesk ticket 103941 (internal link).
Steps to reproduce
- Spin up a new Omnibus GitLab 11.2 instance
- Create a new group
- Pull up the group, create a new project owned by the group using the "Ruby on Rails" template
- Note that this will occur with any template, both the three standard ones and custom templates
- The importing page will load and then refresh every few seconds
- The import will continue indefinitely without progress or eventually error out. My current import has been running for seven hours with no progress.
Note: This issue is not seen when creating a new user-owned project from a template. This appears to be specific to group-owned projects.
What is the current bug behavior?
The new project is either not successfully created, or takes an extremely long time to do so.
What is the expected correct behavior?
The new project is created within a few seconds for a minimal template, or a reasonable amount of time for a more complex one.
Relevant logs and/or screenshots
Page Clocking
Error
No errors seen in the logs while the page is looping. Below are the relevant logs from when the import failed.
gitaly/current
2018-09-19_19:12:59.19645 time="2018-09-19T19:12:59Z" level=info msg="finished unary call" grpc.code=OK grpc.meta.client_name=gitlab-web grpc.method=RepositoryExists grpc.request.glRepository=project-4 grpc.request.repoPath=a-group/import-template.git grpc.request.repoStorage=default grpc.request.topLevelGroup=a-group grpc.service=gitaly.RepositoryService grpc.time_ms=0 peer.address=@ span.kind=server system=grpc
2018-09-19_19:12:59.19879 time="2018-09-19T19:12:59Z" level=info msg="finished unary call" grpc.code=OK grpc.meta.client_name=gitlab-web grpc.method=RepositoryExists grpc.request.glRepository=wiki-4 grpc.request.repoPath=a-group/import-template.wiki.git grpc.request.repoStorage=default grpc.request.topLevelGroup=a-group grpc.service=gitaly.RepositoryService grpc.time_ms=0 peer.address=@ span.kind=server system=grpc
2018-09-19_19:12:59.20201 time="2018-09-19T19:12:59Z" level=info msg="finished unary call" grpc.code=OK grpc.meta.client_name=gitlab-web grpc.method=CreateRepository grpc.request.glRepository= grpc.request.repoPath=a-group/import-template.wiki.git grpc.request.repoStorage=default grpc.request.topLevelGroup=a-group grpc.service=gitaly.RepositoryService grpc.time_ms=1 peer.address=@ span.kind=server system=grpc
2018-09-19_19:12:59.20364 time="2018-09-19T19:12:59Z" level=info msg="finished unary call" grpc.code=OK grpc.meta.client_name=gitlab-web grpc.method=RepositoryExists grpc.request.glRepository=wiki-4 grpc.request.repoPath=a-group/import-template.wiki.git grpc.request.repoStorage=default grpc.request.topLevelGroup=a-group grpc.service=gitaly.RepositoryService grpc.time_ms=0 peer.address=@ span.kind=server system=grpc
2018-09-19_19:12:59.20791 time="2018-09-19T19:12:59Z" level=info msg="finished unary call" grpc.code=OK grpc.meta.client_name=gitlab-web grpc.method=RepositoryExists grpc.request.glRepository=wiki-4 grpc.request.repoPath=a-group/import-template.wiki.git grpc.request.repoStorage=default grpc.request.topLevelGroup=a-group grpc.service=gitaly.RepositoryService grpc.time_ms=0 peer.address=@ span.kind=server system=grpc
2018-09-19_19:12:59.21153 time="2018-09-19T19:12:59Z" level=info msg="finished unary call" grpc.code=OK grpc.meta.client_name=gitlab-web grpc.method=HasLocalBranches grpc.request.glRepository=wiki-4 grpc.request.repoPath=a-group/import-template.wiki.git grpc.request.repoStorage=default grpc.request.topLevelGroup=a-group grpc.service=gitaly.RepositoryService grpc.time_ms=1 peer.address=@ span.kind=server system=grpc
2018-09-19_19:12:59.53613 time="2018-09-19T19:12:59Z" level=info msg="finished unary call" grpc.code=OK grpc.meta.client_name=gitlab-web grpc.method=RepositoryExists grpc.request.glRepository=project-4 grpc.request.repoPath=a-group/import-template.git grpc.request.repoStorage=default grpc.request.topLevelGroup=a-group grpc.service=gitaly.RepositoryService grpc.time_ms=0 peer.address=@ span.kind=server system=grpc
2018-09-19_19:12:59.58997 time="2018-09-19T19:12:59Z" level=info msg="finished unary call" error="rpc error: code = NotFound desc = GetRepoPath: not a git repository '/var/opt/gitlab/git-data/repositories/a-group/import-template.git'" grpc.code=NotFound grpc.meta.client_name=gitlab-web grpc.method=FindDefaultBranchName grpc.request.glRepository=project-4 grpc.request.repoPath=a-group/import-template.git grpc.request.repoStorage=default grpc.request.topLevelGroup=a-group grpc.service=gitaly.RefService grpc.time_ms=0 peer.address=@ span.kind=server system=grpc
2018-09-19_19:12:59.62048 time="2018-09-19T19:12:59Z" level=info msg="finished unary call" grpc.code=OK grpc.meta.client_name=gitlab-sidekiq grpc.method=FindCommit grpc.request.glRepository=project-2 grpc.request.repoPath=a-group/import-test.git grpc.request.repoStorage=default grpc.request.topLevelGroup=a-group grpc.service=gitaly.CommitService grpc.time_ms=3 peer.address=@ span.kind=server system=grpc
gitlab-rails/production.log
Processing by ProjectsController#create as HTML
Parameters: {"utf8"=>"✓", "authenticity_token"=>"[FILTERED]", "project"=>{"template_name"=>"import-test", "use_custom_template"=>"true", "ci_cd_only"=>"fal
se", "namespace_id"=>"2", "path"=>"import-template", "description"=>"", "visibility_level"=>"0"}}
Started GET "/a-group/temp/import" for 192.168.122.1 at 2018-09-19 12:12:59 -0700
Processing by Projects::ImportsController#show as HTML
Parameters: {"namespace_id"=>"a-group", "project_id"=>"temp"}
Error writing to .git/config for project a-group/import-template (4): repository does not exist.
Completed 200 OK in 120ms (Views: 94.4ms | ActiveRecord: 6.4ms | Elasticsearch: 0.0ms)
Output of checks
Results of GitLab environment info
Expand for output related to GitLab environment info
System information System: Ubuntu 16.04 Proxy: no Current User: git Using RVM: no Ruby Version: 2.4.4p296 Gem Version: 2.7.6 Bundler Version:1.16.2 Rake Version: 12.3.1 Redis Version: 3.2.11 Git Version: 2.18.0 Sidekiq Version:5.1.3 Go Version: unknown
GitLab information Version: 11.2.3-ee Revision: aadca99 Directory: /opt/gitlab/embedded/service/gitlab-rails DB Adapter: postgresql DB Version: 9.6.8 URL: http://gitlab.wchandler-template.com HTTP Clone URL: http://gitlab.wchandler-template.com/some-group/some-project.git SSH Clone URL: git@gitlab.wchandler-template.com:some-group/some-project.git Elasticsearch: no Geo: no Using LDAP: no Using Omniauth: no
GitLab Shell Version: 8.1.1 Repository storage paths:
- default: /var/opt/gitlab/git-data/repositories Hooks: /opt/gitlab/embedded/service/gitlab-shell/hooks Git: /opt/gitlab/embedded/bin/git
Results of GitLab application Check
Expand for output related to the GitLab application check
System information System: Ubuntu 16.04 Proxy: no Current User: git Using RVM: no Ruby Version: 2.4.4p296 Gem Version: 2.7.6 Bundler Version:1.16.2 Rake Version: 12.3.1 Redis Version: 3.2.11 Git Version: 2.18.0 Sidekiq Version:5.1.3 Go Version: unknown
GitLab information Version: 11.2.3-ee Revision: aadca99 Directory: /opt/gitlab/embedded/service/gitlab-rails DB Adapter: postgresql DB Version: 9.6.8 URL: http://gitlab.wchandler-template.com HTTP Clone URL: http://gitlab.wchandler-template.com/some-group/some-project.git SSH Clone URL: git@gitlab.wchandler-template.com:some-group/some-project.git Elasticsearch: no Geo: no Using LDAP: no Using Omniauth: no
GitLab Shell Version: 8.1.1 Repository storage paths:
- default: /var/opt/gitlab/git-data/repositories Hooks: /opt/gitlab/embedded/service/gitlab-shell/hooks Git: /opt/gitlab/embedded/bin/git root@will-103941:/var/log/gitlab# gitlab-rake gitlab:check SANITIZE=true Checking GitLab Shell ...
GitLab Shell version >= 8.1.1 ? ... OK (8.1.1) Repo base directory exists? default... yes Repo storage directories are symlinks? default... no Repo paths owned by git:root, or git:git? default... yes Repo paths access is drwxrws---? default... yes hooks directories in repos are links: ... 2/1 ... ok Running /opt/gitlab/embedded/service/gitlab-shell/bin/check Check GitLab API access: OK Redis available via internal API: OK
Access to /var/opt/gitlab/.ssh/authorized_keys: OK gitlab-shell self-check successful
Checking GitLab Shell ... Finished
Checking Sidekiq ...
Running? ... yes Number of Sidekiq processes ... 1
Checking Sidekiq ... Finished
Reply by email is disabled in config/gitlab.yml Checking LDAP ...
LDAP is disabled in config/gitlab.yml
Checking LDAP ... Finished
Checking GitLab ...
Git configured correctly? ... yes Database config exists? ... yes All migrations up? ... yes