Gitlab has spurious failures when cloning using git+https with authentication embedded in URL (#26393) · Issues · GitLab.org / GitLab

Gitlab has spurious failures when cloning using git+https with authentication embedded in URL

<details> <summary> Everyone can contribute. [Help move this issue forward](https://handbook.gitlab.com/handbook/marketing/developer-relations/contributor-success/community-contributors-workflows/#contributor-links) while earning points, leveling up and collecting rewards. </summary> - [Close this issue](https://contributors.gitlab.com/manage-issue?action=close&projectId=278964&issueIid=26393) </details>   ### Summary Running our own Omnibus edition instance we have many projects that rely on cloning a number of our own private repositories as a first stage in many jobs. These repositories required authentication and we embed this in the url. For example `git+https://user:password@git.domain.com/group/project.git` We've noticed increasingly that **cloning randomly fails and it is almost impossible to complete a full build stage**. This seems to be worse the more repositories you try to clone. For example the first repository usually clones ok but subsequent repositories are increasingly likely to fail. This means that for us right now: * almost all our pipelines routinely fail * when developing we have to clone repositories one by one manually and run against locally cached repositories * gitlab and our CI is of minimal value (since no pipelines work except by chance) ### Steps to reproduce Create multiple private repositories and attempt to clone those repositories as part of a pipeline job, or simpler, try to clone in a loop from a script. ### Example Project Not possible at this time. ### What is the current *bug* behavior? While cloning a repository the clone fails with one of: * Authentication error * RPC failed error Sample authentication error (obfuscated repo detail shown - $ACCESS_TOKEN expands to a valid user:password): ``` cuppa: location: [info] Cloning [git+https://$ACCESS_TOKEN@git.domain.com/group/project1] into [/home/gitlab-runner/builds/930b3548/0/group/main_project/_cuppa/git_https__ACCESS_TOKEN@git.domain.com__group_project1/] cuppa: location: [info] Cloning [git+https://$ACCESS_TOKEN@git.domain.com/group/project2] into [/home/gitlab-runner/builds/930b3548/0/group/main_project/_cuppa/git_https__ACCESS_TOKEN@git.domain.com__group_project2/] cuppa: location: [info] Cloning [git+https://$ACCESS_TOKEN@git.domain.com/another_group/app_project] into [/home/gitlab-runner/builds/930b3548/0/group/main_project/_cuppa/git_https__ACCESS_TOKEN@git.domain.com__another_group_app_project/] cuppa: location: [info] Cloning [git+https://$ACCESS_TOKEN@git.domain.com/group3/sys_project] into [/home/gitlab-runner/builds/930b3548/0/group/main_project/_cuppa/git_https__ACCESS_TOKEN@git.domain.com__group3_sys_project/] cuppa: location: [info] Cloning [git+https://$ACCESS_TOKEN@git.domain.com/group/project5] into [/home/gitlab-runner/builds/930b3548/0/group/main_project/_cuppa/git_https__ACCESS_TOKEN@git.domain.com__group_project5/] cuppa: location: [info] Cloning [git+https://$ACCESS_TOKEN@git.domain.com/group/project6] into [/home/gitlab-runner/builds/930b3548/0/group/main_project/_cuppa/git_https__ACCESS_TOKEN@git.domain.com__group_project6/] fatal: Authentication failed for 'https://ACCESS_TOKEN@git.domain.com/group/project6/' ``` **`fatal: Authentication failed for `** Sample RPC failed error (obfuscated repo detail shown - $ACCESS_TOKEN expands to a valid user:password): ``` cuppa: location: [info] Cloning [git+https://$ACCESS_TOKEN@git.domain.com/group/project1] into [/home/gitlab-runner/builds/930b3548/0/group/main_project/_cuppa/git_https__ACCESS_TOKEN@git.domain.com__group_project1/] cuppa: location: [info] Cloning [git+https://$ACCESS_TOKEN@git.domain.com/group/project2] into [/home/gitlab-runner/builds/930b3548/0/group/main_project/_cuppa/git_https__ACCESS_TOKEN@git.domain.com__group_project2/] error: RPC failed; curl 7 Failed to connect to git.domain.com port 443: Connection timed out fatal: the remote end hung up unexpectedly ``` **`fatal: the remote end hung up unexpectedly`** ### What is the expected *correct* behavior? Cloning should succeed without incident. ### Relevant logs and/or screenshots Shown below is the relevant excerpt from the `production.log` that corresponds to the first failure scenario shown. Notice that there is further mention of `project6` after the `Filter chain halted as :authenticate_user rendered or redirected` message.See the full excerpt for details but here is a snippet: ``` Started GET "/group/project6/info/refs?service=git-upload-pack" for 123.456.789.321 at 2019-01-28 14:14:27 +0000 Started GET "/group/project6.git/info/refs?service=git-upload-pack" for 123.456.789.321 at 2019-01-28 14:14:28 +0000 Processing by Projects::GitHttpController#info_refs as */* Parameters: {"service"=>"git-upload-pack", "namespace_id"=>"group", "project_id"=>"project6.git"} Filter chain halted as :authenticate_user rendered or redirected ``` <details> <summary>Expand for <strong>full production.log excerpt</strong></summary> <pre> Started GET "/group/project1/info/refs?service=git-upload-pack" for 123.456.789.321 at 2019-01-28 14:14:23 +0000 Started GET "/group/project1.git/info/refs?service=git-upload-pack" for 123.456.789.321 at 2019-01-28 14:14:23 +0000 Processing by Projects::GitHttpController#info_refs as */* Parameters: {"service"=>"git-upload-pack", "namespace_id"=>"group", "project_id"=>"project1.git"} Filter chain halted as :authenticate_user rendered or redirected Completed 401 Unauthorized in 12ms (Views: 0.9ms | ActiveRecord: 2.1ms) Started GET "/group/project1.git/info/refs?service=git-upload-pack" for 123.456.789.321 at 2019-01-28 14:14:23 +0000 Processing by Projects::GitHttpController#info_refs as */* Parameters: {"service"=>"git-upload-pack", "namespace_id"=>"group", "project_id"=>"project1.git"} Completed 200 OK in 171ms (Views: 0.7ms | ActiveRecord: 15.3ms) Started POST "/group/project1.git/git-upload-pack" for 123.456.789.321 at 2019-01-28 14:14:23 +0000 Processing by Projects::GitHttpController#git_upload_pack as app_project/x-git-upload-pack-result Parameters: {"namespace_id"=>"group", "project_id"=>"project1.git"} Completed 200 OK in 112ms (Views: 0.4ms | ActiveRecord: 5.2ms) Started GET "/group/project2/info/refs?service=git-upload-pack" for 123.456.789.321 at 2019-01-28 14:14:24 +0000 Started GET "/group/project2.git/info/refs?service=git-upload-pack" for 123.456.789.321 at 2019-01-28 14:14:24 +0000 Processing by Projects::GitHttpController#info_refs as */* Parameters: {"service"=>"git-upload-pack", "namespace_id"=>"group", "project_id"=>"project2.git"} Filter chain halted as :authenticate_user rendered or redirected Completed 401 Unauthorized in 14ms (Views: 0.8ms | ActiveRecord: 3.2ms) Started GET "/group/project2.git/info/refs?service=git-upload-pack" for 123.456.789.321 at 2019-01-28 14:14:24 +0000 Processing by Projects::GitHttpController#info_refs as */* Parameters: {"service"=>"git-upload-pack", "namespace_id"=>"group", "project_id"=>"project2.git"} Completed 200 OK in 108ms (Views: 0.4ms | ActiveRecord: 4.5ms) Started POST "/group/project2.git/git-upload-pack" for 123.456.789.321 at 2019-01-28 14:14:24 +0000 Processing by Projects::GitHttpController#git_upload_pack as app_project/x-git-upload-pack-result Parameters: {"namespace_id"=>"group", "project_id"=>"project2.git"} Completed 200 OK in 148ms (Views: 0.3ms | ActiveRecord: 10.1ms) Started GET "/another_group/app_project/info/refs?service=git-upload-pack" for 123.456.789.321 at 2019-01-28 14:14:25 +0000 Started GET "/another_group/app_project.git/info/refs?service=git-upload-pack" for 123.456.789.321 at 2019-01-28 14:14:25 +0000 Processing by Projects::GitHttpController#info_refs as */* Parameters: {"service"=>"git-upload-pack", "namespace_id"=>"another_group", "project_id"=>"app_project.git"} Filter chain halted as :authenticate_user rendered or redirected Completed 401 Unauthorized in 15ms (Views: 0.4ms | ActiveRecord: 6.5ms) Started GET "/another_group/app_project.git/info/refs?service=git-upload-pack" for 123.456.789.321 at 2019-01-28 14:14:25 +0000 Processing by Projects::GitHttpController#info_refs as */* Parameters: {"service"=>"git-upload-pack", "namespace_id"=>"another_group", "project_id"=>"app_project.git"} Completed 200 OK in 133ms (Views: 0.3ms | ActiveRecord: 5.4ms) Started POST "/another_group/app_project.git/git-upload-pack" for 123.456.789.321 at 2019-01-28 14:14:25 +0000 Processing by Projects::GitHttpController#git_upload_pack as app_project/x-git-upload-pack-result Parameters: {"namespace_id"=>"another_group", "project_id"=>"app_project.git"} Completed 200 OK in 109ms (Views: 0.3ms | ActiveRecord: 4.7ms) Started GET "/group/main_project/-/jobs/1277/trace.json?state=eyJvZmZzZXQiOjE0MjAsIm5fb3Blbl90YWdzIjowLCJmZ19jb2xvciI6bnVsbCwiYmdfY29sb3IiOm51bGwsInN0eWxlX21hc2siOjB9" for 192.149.225.10 at 2019-01-28 14:14:26 +0000 Processing by Projects::JobsController#trace as JSON Parameters: {"state"=>"eyJvZmZzZXQiOjE0MjAsIm5fb3Blbl90YWdzIjowLCJmZ19jb2xvciI6bnVsbCwiYmdfY29sb3IiOm51bGwsInN0eWxlX21hc2siOjB9", "namespace_id"=>"group", "project_id"=>"main_project", "id"=>"1277"} Completed 200 OK in 27ms (Views: 0.3ms | ActiveRecord: 3.6ms) Started GET "/group3/sys_project/info/refs?service=git-upload-pack" for 123.456.789.321 at 2019-01-28 14:14:26 +0000 Started GET "/group3/sys_project.git/info/refs?service=git-upload-pack" for 123.456.789.321 at 2019-01-28 14:14:26 +0000 Processing by Projects::GitHttpController#info_refs as */* Parameters: {"service"=>"git-upload-pack", "namespace_id"=>"group3", "project_id"=>"sys_project.git"} Filter chain halted as :authenticate_user rendered or redirected Completed 401 Unauthorized in 13ms (Views: 0.4ms | ActiveRecord: 2.9ms) Started GET "/group3/sys_project.git/info/refs?service=git-upload-pack" for 123.456.789.321 at 2019-01-28 14:14:26 +0000 Processing by Projects::GitHttpController#info_refs as */* Parameters: {"service"=>"git-upload-pack", "namespace_id"=>"group3", "project_id"=>"sys_project.git"} Completed 200 OK in 124ms (Views: 0.4ms | ActiveRecord: 10.2ms) Started POST "/group3/sys_project.git/git-upload-pack" for 123.456.789.321 at 2019-01-28 14:14:26 +0000 Processing by Projects::GitHttpController#git_upload_pack as app_project/x-git-upload-pack-result Parameters: {"namespace_id"=>"group3", "project_id"=>"sys_project.git"} Completed 200 OK in 116ms (Views: 0.4ms | ActiveRecord: 9.0ms) Started GET "/group/project5/info/refs?service=git-upload-pack" for 123.456.789.321 at 2019-01-28 14:14:27 +0000 Started GET "/group/project5.git/info/refs?service=git-upload-pack" for 123.456.789.321 at 2019-01-28 14:14:27 +0000 Processing by Projects::GitHttpController#info_refs as */* Parameters: {"service"=>"git-upload-pack", "namespace_id"=>"group", "project_id"=>"project5.git"} Filter chain halted as :authenticate_user rendered or redirected Completed 401 Unauthorized in 11ms (Views: 0.3ms | ActiveRecord: 2.1ms) Started GET "/group/project5.git/info/refs?service=git-upload-pack" for 123.456.789.321 at 2019-01-28 14:14:27 +0000 Processing by Projects::GitHttpController#info_refs as */* Parameters: {"service"=>"git-upload-pack", "namespace_id"=>"group", "project_id"=>"project5.git"} Completed 200 OK in 147ms (Views: 0.6ms | ActiveRecord: 9.6ms) Started POST "/group/project5.git/git-upload-pack" for 123.456.789.321 at 2019-01-28 14:14:27 +0000 Processing by Projects::GitHttpController#git_upload_pack as app_project/x-git-upload-pack-result Parameters: {"namespace_id"=>"group", "project_id"=>"project5.git"} Completed 200 OK in 119ms (Views: 0.4ms | ActiveRecord: 7.7ms) Started GET "/group/project6/info/refs?service=git-upload-pack" for 123.456.789.321 at 2019-01-28 14:14:27 +0000 Started GET "/group/project6.git/info/refs?service=git-upload-pack" for 123.456.789.321 at 2019-01-28 14:14:28 +0000 Processing by Projects::GitHttpController#info_refs as */* Parameters: {"service"=>"git-upload-pack", "namespace_id"=>"group", "project_id"=>"project6.git"} Filter chain halted as :authenticate_user rendered or redirected Completed 401 Unauthorized in 12ms (Views: 0.4ms | ActiveRecord: 1.9ms) Started GET "/group/main_project/-/jobs/1277.json" for 192.149.225.10 at 2019-01-28 14:14:29 +0000 Processing by Projects::JobsController#show as JSON Parameters: {"namespace_id"=>"group", "project_id"=>"main_project", "id"=>"1277"} Completed 200 OK in 177ms (Views: 1.9ms | ActiveRecord: 40.2ms) </pre> </details> ### Output of checks #### Results of GitLab environment info <details> <summary>Expand for output related to GitLab environment info</summary> <pre> System information System: Debian 9.7 Current User: git Using RVM: no Ruby Version: 2.5.3p105 Gem Version: 2.7.6 Bundler Version:1.16.6 Rake Version: 12.3.2 Redis Version: 3.2.12 Git Version: 2.18.1 Sidekiq Version:5.2.3 Go Version: unknown GitLab information Version: 11.7.0 Revision: 1d9280e Directory: /opt/gitlab/embedded/service/gitlab-rails DB Adapter: postgresql URL: https://git.domain.com HTTP Clone URL: https://git.domain.com/some-group/some-project.git SSH Clone URL: git@git.domain.com:some-group/some-project.git Using LDAP: no Using Omniauth: yes Omniauth Providers: GitLab Shell Version: 8.4.4 Repository storage paths: - default: /var/opt/gitlab/git-data/repositories Hooks: /opt/gitlab/embedded/service/gitlab-shell/hooks Git: /opt/gitlab/embedded/bin/git </pre> </details> #### Results of GitLab application Check <details> <summary>Expand for output related to the GitLab application check</summary> <pre> Checking GitLab subtasks ... Checking GitLab Shell ... GitLab Shell: ... GitLab Shell version >= 8.4.4 ? ... OK (8.4.4) 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 Gitaly ... Gitaly: ... default ... OK Checking Gitaly ... Finished Checking Sidekiq ... Sidekiq: ... Running? ... yes Number of Sidekiq processes ... 1 Checking Sidekiq ... Finished Checking Incoming Email ... Incoming Email: ... Reply by email is disabled in config/gitlab.yml Checking Incoming Email ... Finished Checking LDAP ... LDAP: ... LDAP is disabled in config/gitlab.yml Checking LDAP ... Finished Checking GitLab App ... Git configured correctly? ... yes Database config exists? ... yes All migrations up? ... yes Database contains orphaned GroupMembers? ... no GitLab config exists? ... yes GitLab config up to date? ... yes Log directory writable? ... yes Tmp directory writable? ... yes Uploads directory exists? ... yes Uploads directory has correct permissions? ... yes Uploads directory tmp has correct permissions? ... no Try fixing it: sudo chown -R git /var/opt/gitlab/gitlab-rails/uploads sudo find /var/opt/gitlab/gitlab-rails/uploads -type f -exec chmod 0644 {} \; sudo find /var/opt/gitlab/gitlab-rails/uploads -type d -not -path /var/opt/gitlab/gitlab-rails/uploads -exec chmod 0700 {} \; For more information see: doc/install/installation.md in section "GitLab" Please fix the error above and rerun the checks. Init script exists? ... skipped (omnibus-gitlab has no init script) Init script up-to-date? ... skipped (omnibus-gitlab has no init script) Projects have namespace: ... 3/1 ... yes 3/2 ... yes 3/3 ... yes 3/4 ... yes 7/5 ... yes 8/6 ... yes 8/7 ... yes 7/8 ... yes 15/9 ... yes 8/10 ... yes 17/11 ... yes 17/12 ... yes 25/14 ... yes 17/15 ... yes 18/16 ... yes 17/17 ... yes 19/18 ... yes 17/19 ... yes 3/20 ... yes 18/21 ... yes 17/23 ... yes 17/24 ... yes 17/25 ... yes 21/26 ... yes 19/27 ... yes 19/28 ... yes 18/29 ... yes 18/30 ... yes 15/31 ... yes 25/32 ... yes 25/33 ... yes 25/34 ... yes 25/35 ... yes 25/36 ... yes 25/37 ... yes 25/38 ... yes 25/39 ... yes 25/40 ... yes 25/41 ... yes 7/42 ... yes 25/43 ... yes 25/44 ... yes 25/45 ... yes 25/46 ... yes 25/47 ... yes Redis version >= 2.8.0? ... yes Ruby version >= 2.3.5 ? ... yes (2.5.3) Git version >= 2.18.0 ? ... yes (2.18.1) Git user has default SSH configuration? ... yes Active users: ... 18 Checking GitLab App ... Finished Checking GitLab subtasks ... Finished </pre> </details> ### Possible fixes No known fixes - nothing obvious in logs. Affects multiple versions of gitlab. Not isolated to gitlab-runner as happens directly on command line. Not sure where to look to investigate this more.

issue