Azure-pipelines-agent: Git fetch fails with exit code 128 when many builds are queued concurrently

Created on 12 Apr 2019 · 7Comments · Source: microsoft/azure-pipelines-agent

What's not working?

After migrating TFS 2018 to Azure DevOps Server 2019, we have seen that some builds are failing when the agents download the code from the Git repository.

The error is the following:

2019-04-12T07:51:48.4046286Z ##[section]Starting: Checkout
2019-04-12T07:51:48.4203988Z ==============================================================================
2019-04-12T07:51:48.4204278Z Task         : Get sources
2019-04-12T07:51:48.4204346Z Description  : Get sources from a repository. Supports Git, TfsVC, and SVN repositories.
2019-04-12T07:51:48.4204530Z Version      : 1.0.0
2019-04-12T07:51:48.4204580Z Author       : Microsoft
2019-04-12T07:51:48.4204651Z Help         : [More Information](https://go.microsoft.com/fwlink/?LinkId=798199)
2019-04-12T07:51:48.4204712Z ==============================================================================
2019-04-12T07:51:48.7185304Z Syncing repository: YYY (Git)
2019-04-12T07:51:48.7298437Z Prepending Path environment variable with directory containing 'git.exe'.
2019-04-12T07:51:48.7364058Z ##[command]git version
2019-04-12T07:51:48.7718050Z git version 2.18.0.windows.1
2019-04-12T07:51:48.8087458Z ##[command]git init "D:\Agents\2\_work\351\s"
2019-04-12T07:51:48.8429950Z Initialized empty Git repository in D:/Agents/2/_work/351/s/.git/
2019-04-12T07:51:48.8471749Z ##[command]git remote add origin http://XXX:8080/tfs/YYY/YYY/_git/YYY
2019-04-12T07:51:48.8734695Z ##[command]git config gc.auto 0
2019-04-12T07:51:48.8980935Z ##[command]git config --get-all http.http://XXX:8080/tfs/YYY/YYY/_git/YYY.extraheader
2019-04-12T07:51:48.9212262Z ##[command]git config --get-all http.proxy
2019-04-12T07:51:48.9485603Z ##[command]git -c http.extraheader="AUTHORIZATION: bearer ***" fetch --tags --prune --progress --no-recurse-submodules origin +refs/heads/*:refs/remotes/origin/* +refs/pull/2251/merge:refs/remotes/pull/2251/merge
2019-04-12T07:51:49.7986249Z remote: Azure Repos        
2019-04-12T07:51:50.4251155Z remote: 
2019-04-12T07:51:50.4252484Z remote: Found 407029 objects to send. (627 ms)        
2019-04-12T07:51:50.4258202Z remote: TF400733: The request has been canceled: This request was blocked because there are too many clones running at the same time. Please try again later..
2019-04-12T07:51:50.4264222Z fatal: protocol error: bad pack header
2019-04-12T07:51:50.4619757Z ##[warning]Git fetch failed with exit code 128, back off 8.863 seconds before retry.
2019-04-12T07:51:59.3294796Z ##[command]git -c http.extraheader="AUTHORIZATION: bearer ***" fetch --tags --prune --progress --no-recurse-submodules origin +refs/heads/*:refs/remotes/origin/* +refs/pull/2251/merge:refs/remotes/pull/2251/merge
2019-04-12T07:52:00.2051035Z remote: Azure Repos        
2019-04-12T07:52:00.8351662Z remote: 
2019-04-12T07:52:00.8352492Z remote: Found 407029 objects to send. (630 ms)        
2019-04-12T07:52:00.8359717Z remote: TF400733: The request has been canceled: This request was blocked because there are too many clones running at the same time. Please try again later..
2019-04-12T07:52:00.8366028Z fatal: protocol error: bad pack header
2019-04-12T07:52:00.8569408Z ##[warning]Git fetch failed with exit code 128, back off 9.855 seconds before retry.
2019-04-12T07:52:10.7185817Z ##[command]git -c http.extraheader="AUTHORIZATION: bearer ***" fetch --tags --prune --progress --no-recurse-submodules origin +refs/heads/*:refs/remotes/origin/* +refs/pull/2251/merge:refs/remotes/pull/2251/merge
2019-04-12T07:52:11.5654156Z remote: Azure Repos        
2019-04-12T07:52:12.2035320Z remote: 
2019-04-12T07:52:12.2036458Z remote: Found 407029 objects to send. (638 ms)        
2019-04-12T07:52:12.2043232Z remote: TF400733: The request has been canceled: This request was blocked because there are too many clones running at the same time. Please try again later..
2019-04-12T07:52:12.2048874Z fatal: protocol error: bad pack header
2019-04-12T07:52:12.2313996Z ##[error]Git fetch failed with exit code: 128
2019-04-12T07:52:12.3032015Z ##[section]Finishing: Checkout

The error occurs when we make a commit in a pull request of a file that affects many builds. The number of builds is almost 60, and as we have 50 build agents, all the builds execute concurrently. The problem is worse because when all of these builds end, and a new single build is queued and needs to download the repository, the error is also triggered, so we think it is a software limit error, and not a hardware restriction. The machine which hosts Azure DevOps Server has 16 GB RAM and 16 cores, and in the previous version, the error was not triggered.

We think that this error could be avoided if the Git repository is cloned fewer times. There is a pending issue on the build agent https://github.com/Microsoft/azure-pipelines-agent/issues/1506 which demands better reuse of the code in the agents. If the agent has a single copy of the repository for all builds, the full repository clone will not be triggered in each build.

How can we solve this problem? Is there any workaround? For now, we solved the problem restarting the DevOps server, but this is an ugly fix.

For us it is very important to solve it because we have a fully automated process and the builds can not be failing due to this error types.

Agent Version and Platform

Version of your agent? 2.149.2
OS of the machine running the agent? Windows

Azure DevOps Type and Version

Azure DevOps Server 2019 RTM (17.143.28621.4)

question

Source

juanperezADD

👍6

All 7 comments

@juanperezADD do you happen to know why you have so many clone instead of incremental fetch? since you migrated from TFS2018, i would expected the agent will re-use most of the existing repository on disk instead of cloning new one.

is this a newly created definition or repository?

you might also want to ask https://developercommunity.visualstudio.com/spaces/22/index.html since the error is coming from the git server.

the only work around i can think is enable your 50 agents in batches, like 5 a time, so you can slowly get all 50 agents clone the repository.

TingluoHuang on 12 Apr 2019

We had this error today. I believe at the time we did not have many clones executing simultaneously - builds were failing, most of the agents were idle. Everybody was getting the same error - we tried from several accounts. It was happening only on one particular git repository - other git repositories in the same project could be cloned with no issues at all.
We have restarted the IIS on the application server and this has solved the issue temporarily. We have upgraded our TFS recently - we have not seen this error before the upgrade.

dpurge on 16 Apr 2019

👀1

@dpurge please file issue on https://developercommunity.visualstudio.com/spaces/22/index.html or file report ticket since this sounds like a TFS git server issue which is out of the scope of this repository.

TingluoHuang on 16 Apr 2019

Looking up in the developer community, this same ticket was created over there.

Starkie on 16 Apr 2019

@TingluoHuang

do you happen to know why you have so many clone instead of incremental fetch? since you migrated from TFS2018, i would expected the agent will re-use most of the existing repository on disk instead of cloning new one.
is this a newly created definition or repository?

This is an example of an agent that re-uses most of the existing repository on disk instead of cloning a new one. I don't know why some times the agents are cloning the repository when no new build definitions nor repositories have been created.

2019-04-24T21:25:05.0703415Z ##[section]Starting: Checkout
2019-04-24T21:25:05.0868975Z ==============================================================================
2019-04-24T21:25:05.0869288Z Task         : Get sources
2019-04-24T21:25:05.0869476Z Description  : Get sources from a repository. Supports Git, TfsVC, and SVN repositories.
2019-04-24T21:25:05.0869552Z Version      : 1.0.0
2019-04-24T21:25:05.0869617Z Author       : Microsoft
2019-04-24T21:25:05.0869687Z Help         : [More Information](https://go.microsoft.com/fwlink/?LinkId=798199)
2019-04-24T21:25:05.0869775Z ==============================================================================
2019-04-24T21:25:05.3976204Z Syncing repository: YYY (Git)
2019-04-24T21:25:05.4102532Z Prepending Path environment variable with directory containing 'git.exe'.
2019-04-24T21:25:05.4164435Z ##[command]git version
2019-04-24T21:25:05.4523730Z git version 2.18.0.windows.1
2019-04-24T21:25:05.4726711Z ##[command]git config --get remote.origin.url
2019-04-24T21:25:05.5025298Z ##[command]git clean -ffdx
2019-04-24T21:25:06.4146035Z ##[command]git reset --hard HEAD
2019-04-24T21:25:09.0281703Z HEAD is now at 2adf2f341a Merged PR 2259: Corrección de los diagramas y modelado de la navegación en User.
2019-04-24T21:25:09.0363620Z ##[command]git config gc.auto 0
2019-04-24T21:25:09.0609030Z ##[command]git config --get-all http.http://XXX:8080/tfs/YYY/YYY/_git/YYY.extraheader
2019-04-24T21:25:09.0827970Z ##[command]git config --get-all http.proxy
2019-04-24T21:25:09.1096357Z ##[command]git -c http.extraheader="AUTHORIZATION: bearer ***" fetch --tags --prune --progress --no-recurse-submodules origin
2019-04-24T21:25:13.4588275Z From http://XXX:8080/tfs/YYY/YYY/_git/YYY
2019-04-24T21:25:13.4588931Z  - [deleted]               (none)     -> origin/ZZZ
2019-04-24T21:25:13.4589128Z  - [deleted]               (none)     -> origin/NNN
2019-04-24T21:25:14.6776677Z remote: Azure Repos        
2019-04-24T21:25:15.3625378Z remote: 
2019-04-24T21:25:15.3626803Z remote: Found 11310 objects to send. (684 ms)        
2019-04-24T21:25:15.3627615Z remote: TF400733: The request has been canceled: This request was blocked because there are too many clones running at the same time. Please try again later..
2019-04-24T21:25:15.3631984Z fatal: protocol error: bad pack header
2019-04-24T21:25:15.4074981Z ##[warning]Git fetch failed with exit code 128, back off 6.289 seconds before retry.
2019-04-24T21:25:21.7022256Z ##[command]git -c http.extraheader="AUTHORIZATION: bearer ***" fetch --tags --prune --progress --no-recurse-submodules origin
2019-04-24T21:25:25.2323045Z remote: Azure Repos        
2019-04-24T21:25:25.6408633Z remote: 
2019-04-24T21:25:25.6409689Z remote: Found 11310 objects to send. (408 ms)        
2019-04-24T21:25:25.6410281Z remote: TF400733: The request has been canceled: This request was blocked because there are too many clones running at the same time. Please try again later..
2019-04-24T21:25:25.6414181Z fatal: protocol error: bad pack header
2019-04-24T21:25:25.6682706Z ##[warning]Git fetch failed with exit code 128, back off 7.422 seconds before retry.
2019-04-24T21:25:33.1057008Z ##[command]git -c http.extraheader="AUTHORIZATION: bearer ***" fetch --tags --prune --progress --no-recurse-submodules origin
2019-04-24T21:25:36.6675480Z remote: Azure Repos        
2019-04-24T21:25:37.1240518Z remote: 
2019-04-24T21:25:37.1241650Z remote: Found 11310 objects to send. (455 ms)        
2019-04-24T21:25:37.1242281Z remote: TF400733: The request has been canceled: This request was blocked because there are too many clones running at the same time. Please try again later..
2019-04-24T21:25:37.1247054Z fatal: protocol error: bad pack header
2019-04-24T21:25:37.1536422Z ##[error]Git fetch failed with exit code: 128
2019-04-24T21:25:37.2222387Z ##[section]Finishing: Checkout

you might also want to ask https://developercommunity.visualstudio.com/spaces/22/index.html since the error is coming from the git server.

As @Starkie says, there is an issue pending to answer that it was created a month ago. I've also created it here because this site seems more followed.

the only work around i can think is enable your 50 agents in batches, like 5 a time, so you can slowly get all 50 agents clone the repository.