Git fetch intermittently fails

619 views
Skip to first unread message

Jérémie Faucher-Goulet

unread,
Jun 16, 2016, 12:57:59 PM6/16/16
to Jenkins Users
Hello all,
I've got a nagging problem for which I'd welcome some thoughtful expert input...

Once in a while, our builds will fail with the output pasted below in the console. This is a build triggered by another job, which itself is triggered remotely by Atlassian Fisheye when a commit is pushed to the repository. This is part of our CI system.

Building remotely on grs-jslave (linux openwrt cmockery2) in workspace /var/grs-jenkins03/workspace/smv6-6lr-core_Develop_Linux
 
> git rev-parse --is-inside-work-tree # timeout=10
Fetching changes from the remote Git repository
 
> git config remote.origin.url https://grs-softsvnrepo1.trilliant.local:8081/scm/git/smv6-6lr-core # timeout=10
Cleaning workspace
 
> git rev-parse --verify HEAD # timeout=10
Resetting working tree
 
> git reset --hard # timeout=10
 
> git clean -fdx # timeout=10
Fetching upstream changes from https://grs-softsvnrepo1.trilliant.local:8081/scm/git/smv6-6lr-core
 
> git --version # timeout=10
using .gitcredentials to set credentials
 
> git config --local credential.username grfbuild # timeout=10
 
> git config --local credential.helper store --file=/tmp/git9025647881849389319.credentials # timeout=10
 
> git -c core.askpass=true fetch --tags --progress https://grs-softsvnrepo1.trilliant.local:8081/scm/git/smv6-6lr-core +refs/heads/*:refs/remotes/origin/*
 
> git config --local --remove-section credential # timeout=10
ERROR
: Error fetching remote repo 'origin'
hudson.plugins.git.GitException: Failed to fetch from https://grs-softsvnrepo1.trilliant.local:8081/scm/git/smv6-6lr-core
        at
hudson.plugins.git.GitSCM.fetchFrom(GitSCM.java:766)
        at
hudson.plugins.git.GitSCM.retrieveChanges(GitSCM.java:1022)
        at
hudson.plugins.git.GitSCM.checkout(GitSCM.java:1053)
        at
hudson.scm.SCM.checkout(SCM.java:485)
        at
hudson.model.AbstractProject.checkout(AbstractProject.java:1275)
        at
hudson.model.AbstractBuild$AbstractBuildExecution.defaultCheckout(AbstractBuild.java:610)
        at
jenkins.scm.SCMCheckoutStrategy.checkout(SCMCheckoutStrategy.java:86)
        at
hudson.model.AbstractBuild$AbstractBuildExecution.run(AbstractBuild.java:532)
        at
hudson.model.Run.execute(Run.java:1741)
        at
hudson.model.FreeStyleBuild.run(FreeStyleBuild.java:43)
        at
hudson.model.ResourceController.execute(ResourceController.java:98)
        at
hudson.model.Executor.run(Executor.java:408)
Caused by: hudson.plugins.git.GitException: Command "git -c core.askpass=true fetch --tags --progress https://grs-softsvnrepo1.trilliant.local:8081/scm/git/smv6-6lr-core +refs/heads/*:refs/remotes/origin/*" returned status code 1:
stdout
: Fetching submodule contrib/exegin-nan

stderr
: remote: Counting objects: 1          
remote
: Counting objects: 57, done        
remote
: Finding sources:   4% (1/25)          
remote
: Finding sources:   8% (2/25)          
remote
: Finding sources:  12% (3/25)          
remote
: Finding sources:  16% (4/25)          
remote
: Finding sources:  20% (5/25)          
remote
: Finding sources:  24% (6/25)          
remote
: Finding sources:  28% (7/25)          
remote
: Finding sources:  32% (8/25)          
remote
: Finding sources:  36% (9/25)          
remote
: Finding sources:  40% (10/25)          
remote
: Finding sources:  44% (11/25)          
remote
: Finding sources:  48% (12/25)          
remote
: Finding sources:  52% (13/25)          
remote
: Finding sources:  56% (14/25)          
remote
: Finding sources:  60% (15/25)          
remote
: Finding sources:  64% (16/25)          
remote
: Finding sources:  68% (17/25)          
remote
: Finding sources:  72% (18/25)          
remote
: Finding sources:  76% (19/25)          
remote
: Finding sources:  80% (20/25)          
remote
: Finding sources:  84% (21/25)          
remote
: Finding sources:  88% (22/25)          
remote
: Finding sources:  92% (23/25)          
remote
: Finding sources:  96% (24/25)          
remote
: Finding sources: 100% (25/25)          
remote
: Finding sources: 100% (25/25)        
remote
: Getting sizes:   2% (1/42)          
remote
: Getting sizes:   4% (2/42)          
remote
: Getting sizes:   7% (3/42)          
remote
: Getting sizes:   9% (4/42)          
remote
: Getting sizes:  11% (5/42)          
remote
: Getting sizes:  14% (6/42)          
remote
: Getting sizes:  16% (7/42)          
remote
: Getting sizes:  19% (8/42)          
remote
: Getting sizes:  21% (9/42)          
remote
: Getting sizes:  23% (10/42)          
remote
: Getting sizes:  26% (11/42)          
remote
: Getting sizes:  28% (12/42)          
remote
: Getting sizes:  30% (13/42)          
remote
: Getting sizes:  33% (14/42)          
remote
: Getting sizes:  35% (15/42)          
remote
: Getting sizes:  38% (16/42)          
remote
: Getting sizes:  40% (17/42)          
remote
: Getting sizes:  42% (18/42)          
remote
: Getting sizes:  45% (19/42)          
remote
: Getting sizes:  47% (20/42)          
remote
: Getting sizes:  50% (21/42)          
remote
: Getting sizes:  52% (22/42)          
remote
: Getting sizes:  54% (23/42)          
remote
: Getting sizes:  57% (24/42)          
remote
: Getting sizes:  59% (25/42)          
remote
: Getting sizes:  61% (26/42)          
remote
: Getting sizes:  64% (27/42)          
remote
: Getting sizes:  66% (28/42)          
remote
: Getting sizes:  69% (29/42)          
remote
: Getting sizes:  71% (30/42)          
remote
: Getting sizes:  73% (31/42)          
remote
: Getting sizes:  76% (32/42)          
remote
: Getting sizes:  78% (33/42)          
remote
: Getting sizes:  80% (34/42)          
remote
: Getting sizes:  83% (35/42)          
remote
: Getting sizes:  85% (36/42)          
remote
: Getting sizes:  88% (37/42)          
remote
: Getting sizes:  90% (38/42)          
remote
: Getting sizes:  92% (39/42)          
remote
: Getting sizes:  95% (40/42)          
remote
: Getting sizes:  97% (41/42)          
remote
: Getting sizes: 100% (42/42)          
remote
: Getting sizes: 100% (42/42)        
remote
: Total 25 (delta 12), reused 25 (delta 12)        
From https://grs-softsvnrepo1.trilliant.local:8081/scm/git/smv6-6lr-core
   
029fa64..dee5ad4  develop    -> origin/develop
 
* [new branch]      feature/fb-new-exegin-3_6_0 -> origin/feature/fb-new-exegin-3_6_0
fatal
: remote error: Invalid username or password.

        at org
.jenkinsci.plugins.gitclient.CliGitAPIImpl.launchCommandIn(CliGitAPIImpl.java:1710)
        at org
.jenkinsci.plugins.gitclient.CliGitAPIImpl.launchCommandWithCredentials(CliGitAPIImpl.java:1454)
        at org
.jenkinsci.plugins.gitclient.CliGitAPIImpl.access$300(CliGitAPIImpl.java:63)
        at org
.jenkinsci.plugins.gitclient.CliGitAPIImpl$1.execute(CliGitAPIImpl.java:314)
        at org
.jenkinsci.plugins.gitclient.RemoteGitImpl$CommandInvocationHandler$1.call(RemoteGitImpl.java:152)
        at org
.jenkinsci.plugins.gitclient.RemoteGitImpl$CommandInvocationHandler$1.call(RemoteGitImpl.java:145)
        at hudson
.remoting.UserRequest.perform(UserRequest.java:121)
        at hudson
.remoting.UserRequest.perform(UserRequest.java:49)
        at hudson
.remoting.Request$2.run(Request.java:326)
        at hudson
.remoting.InterceptingExecutorService$1.call(InterceptingExecutorService.java:68)
        at java
.util.concurrent.FutureTask.run(FutureTask.java:262)
        at java
.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
        at java
.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
        at java
.lang.Thread.run(Thread.java:745)
        at
......remote call to grs-jslave(Native Method)
        at hudson
.remoting.Channel.attachCallSiteStackTrace(Channel.java:1413)
        at hudson
.remoting.UserResponse.retrieve(UserRequest.java:221)
        at hudson
.remoting.Channel.call(Channel.java:778)
        at org
.jenkinsci.plugins.gitclient.RemoteGitImpl$CommandInvocationHandler.execute(RemoteGitImpl.java:145)
        at sun
.reflect.GeneratedMethodAccessor570.invoke(Unknown Source)
        at sun
.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
        at java
.lang.reflect.Method.invoke(Unknown Source)
        at org
.jenkinsci.plugins.gitclient.RemoteGitImpl$CommandInvocationHandler.invoke(RemoteGitImpl.java:131)
        at com
.sun.proxy.$Proxy70.execute(Unknown Source)
        at hudson
.plugins.git.GitSCM.fetchFrom(GitSCM.java:764)
       
... 11 more
ERROR
: null

Other tidbits or observations:
  • It seems to fail when there hasn't been any builds for a while, as if something was cached. I've never seen two failures in rapid succession. When we get this failure, usually immediately relaunching the same build will work the second time around.
  • I'm confused by the fact that it seems to try fetching git submodules when it fails. We haven't enabled any advanced submodule behavior and a successful build doesn't show any submodule fetches being made.
  • This occurs on both Windows and Linux (We run a similar build on a Linux machine configured as a Jenkins slave).
  • From the windows error, I've read somewhere that it might have something to do with "wincreds" being configured globally while we use "store" locally. But how would that apply to Linux? Furthermore I've confirmed that wincred isn't configured on the windows machine.
On a windows build, we get a slightly different output:

ERROR: Error fetching remote repo 'origin'
hudson.plugins.git.GitException: Failed to fetch from https://grs-softsvnrepo1.trilliant.local:8081/scm/git/smv6-6lr-core
        at
hudson.plugins.git.GitSCM.fetchFrom(GitSCM.java:766)
        at
hudson.plugins.git.GitSCM.retrieveChanges(GitSCM.java:1022)
        at
hudson.plugins.git.GitSCM.checkout(GitSCM.java:1053)
        at
org.jenkinsci.plugins.multiplescms.MultiSCM.checkout(MultiSCM.java:129)
        at
hudson.scm.SCM.checkout(SCM.java:485)
        at
hudson.model.AbstractProject.checkout(AbstractProject.java:1275)
        at
hudson.model.AbstractBuild$AbstractBuildExecution.defaultCheckout(AbstractBuild.java:610)
        at
jenkins.scm.SCMCheckoutStrategy.checkout(SCMCheckoutStrategy.java:86)
        at
hudson.model.AbstractBuild$AbstractBuildExecution.run(AbstractBuild.java:532)
        at
hudson.model.Run.execute(Run.java:1741)
        at
hudson.model.FreeStyleBuild.run(FreeStyleBuild.java:43)
        at
hudson.model.ResourceController.execute(ResourceController.java:98)
        at
hudson.model.Executor.run(Executor.java:408)
Caused by: hudson.plugins.git.GitException: Command "C:\Program Files\Git\bin\git.exe -c core.askpass=true fetch --tags --progress https://grs-softsvnrepo1.trilliant.local:8081/scm/git/smv6-6lr-core +refs/heads/*:refs/remotes/origin/*" returned status code 1:
stdout
:
stderr
:
This application has requested the Runtime to terminate it in an unusual way.
Please contact the application's support team for more information.
Assertion failed!

Program: C:\Program Files\Git\mingw64\libexec\git-core\git-credential-store.exe
File: exec_cmd.c, Line 23

Expression: argv0_path
remote: Counting objects: 1          
remote: Counting objects: 593, done        
remote: Finding sources:   1% (4/322)          
remote: Finding sources:   2% (7/322)          
remote: Finding sources:   3% (10/322)

Normally developers would have a look when the build fails and they receive the notification email. However, since the build often fails for Git fetch reasons, nobody looks at the failures anymore and the real issues get overlooked for a while, defeating the very purpose of having a CI system in place. I'm really hoping to figure this one out...

Has anyone encountered such behavior before? Any hints on what is happening? Anything I should do to investigate this further?

Thank you,

Jérémie

Mark Waite

unread,
Jun 28, 2016, 4:24:40 PM6/28/16
to Jenkins Users
Are you trying to clone a huge repo with JGit on the git server?  If so, you might try cloning the same repo with command line git on the server.

I don't recognize "Finding sources" or "Getting sizes" as common messages from command line git as a server.

Mark Waite

Jérémie Faucher-Goulet

unread,
Jun 28, 2016, 7:53:54 PM6/28/16
to Jenkins Users
Hi Mark,

Thanks for taking time answering,

What do you mean by "git server" and "git as a server"?
We currently use (and clone via HTTPS) from a private installation of scm-manager version 1.41. But I don't think the "git server" is at cause since only Jenkins experiences these issues.
Jenkins is currently configured to use Git via command line. The windows machine is running Git 2.8.3. The Linux slave machine is running Git 1.9.1.

Is the repo big? Not that big, unless you are counting the submodules. My understanding however is that submodules should not be initialized unless we've specified an advanced behaviour in the job.
Beside, this is not a clone operation here that fails. The repository already is in the job's workspace from a previous successful build. This is a git fetch.

It is my belief the "Finding sources" and "Getting sizes" messages comes from the fact that the "--progress" option was passed to git fetch when Jenkins was doing it's thing. I could be competently wrong too however ;-)

FYI. the following 'Additional Behaviours' are used in the job:
  • Clean before checkout
  • Check out to a sub-directory
  • Custom SCM name
Best regards,

Jérémie

Mark Waite

unread,
Jun 29, 2016, 3:02:32 PM6/29/16
to Jenkins Users


On Tuesday, June 28, 2016 at 5:53:54 PM UTC-6, Jérémie Faucher-Goulet wrote:
Hi Mark,

Thanks for taking time answering,

What do you mean by "git server" and "git as a server"?

I meant scm-manager in your case.  As far as I can tell from reading the scm-manager changelog, they use JGit as their internal git implementation.  I suspect that means they don't use command line git on the server side.
 
We currently use (and clone via HTTPS) from a private installation of scm-manager version 1.41. But I don't think the "git server" is at cause since only Jenkins experiences these issues.
Jenkins is currently configured to use Git via command line. The windows machine is running Git 2.8.3. The Linux slave machine is running Git 1.9.1.


I thought you said that Jenkins only saw those failures intermittently.  If only intermittently, then Jenkins more frequent use of checkouts may mean it is more likely to be seen there than by users doing checkout.

Jérémie Faucher-Goulet

unread,
Jun 29, 2016, 5:43:02 PM6/29/16
to Jenkins Users
In that case, yes you are correct, scm-manager does use JGit. I assume that the "Remote: " part of the messages means these messages come from the server? I'm not familiar with Git protocols.

Yes, we see these failures intermittently on Jenkins. However, I should perhaps have been more specific about the failure rate. I would guesstimate that 25% of the builds will fail with a failure to fetch from the server. With a team of 10-15 developers never getting this issue over the span of almost a year, I'd say it should have been reproduced/seen by then if it wasn't specific to Jenkins or the machine it's running on. And developers uses multiple tools on the client side such as SourceTree, GitKraken, Egit (Eclipse), and Git (command-line).

I'm still very much confused by the fact that Jenkins will show a line in the logs that it will update/fetch a git submodule when the error occurs. On successful builds, the submodules aren't touched. Could it be that Jenkinds calls git from within the wrong 'current directory'?

Other thing I've noticed:

Sometimes we will get the error below from git being called manually by scripts during the build process. Even though it's supposed to be "fatal", the operations itself looks successful. This was only seen on Windows however and could relate to a different issue.
This application has requested the Runtime to terminate it in an unusual way.
Please contact the application's support team for more information.
Assertion failed!

Program: C:\Program Files\Git\mingw64\libexec\git-core\git-credential-store.exe
File: exec_cmd.c, Line 23

Jérémie

Mark Waite

unread,
Jun 29, 2016, 9:11:53 PM6/29/16
to jenkins...@googlegroups.com
On Wed, Jun 29, 2016 at 3:43 PM Jérémie Faucher-Goulet <jer...@gmail.com> wrote:
In that case, yes you are correct, scm-manager does use JGit. I assume that the "Remote: " part of the messages means these messages come from the server? I'm not familiar with Git protocols.

Yes, we see these failures intermittently on Jenkins. However, I should perhaps have been more specific about the failure rate. I would guesstimate that 25% of the builds will fail with a failure to fetch from the server. With a team of 10-15 developers never getting this issue over the span of almost a year, I'd say it should have been reproduced/seen by then if it wasn't specific to Jenkins or the machine it's running on. And developers uses multiple tools on the client side such as SourceTree, GitKraken, Egit (Eclipse), and Git (command-line).

I'm still very much confused by the fact that Jenkins will show a line in the logs that it will update/fetch a git submodule when the error occurs. On successful builds, the submodules aren't touched. Could it be that Jenkinds calls git from within the wrong 'current directory'?

I believe there is some submodule processing by default in the git plugin.  At least, there is a checkbox "Disable submodule processing" in the advanced submodule processing section of "Additional Behaviours".  You could try that.

Mark Waite

Mark Waite

unread,
Jun 30, 2016, 8:51:50 AM6/30/16
to Jenkins Users


On Wednesday, June 29, 2016 at 3:43:02 PM UTC-6, Jérémie Faucher-Goulet wrote:

Other thing I've noticed:

Sometimes we will get the error below from git being called manually by scripts during the build process. Even though it's supposed to be "fatal", the operations itself looks successful. This was only seen on Windows however and could relate to a different issue.
This application has requested the Runtime to terminate it in an unusual way.
Please contact the application's support team for more information.
Assertion failed!

Program: C:\Program Files\Git\mingw64\libexec\git-core\git-credential-store.exe
File: exec_cmd.c, Line 23


I think that is telling you that the git credential store program has crashed.  The git plugin does not invoke the git credential store directly, so I assume that is a condition you'd need to investigate with the authors of the git credential store program.

Mark Waite

Jérémie Faucher-Goulet

unread,
Jun 30, 2016, 9:12:43 AM6/30/16
to Jenkins Users
I will try that, but I believe this is more of a consequence of the issue I'm having rather than the cause.

I'll monitor more closely what's happening and keep a longer build history to see if a pattern shows up.
Any suggestion on what I should try or do to investigate this further?

Regards,

Jérémie
Reply all
Reply to author
Forward
0 new messages