Page MenuHomePhabricator

fatal: remote error: access denied or repository not exported: /mediawiki/extensions/ReadingLists
Open, LowPublic

Description

Encountered this once when attempting to merge a patch in the ReadingLists extension repo. It's not blocking work but I thought I'd err on the side of filing it.

15:16:43 Started by user anonymous
15:16:43 Building remotely on integration-slave-jessie-1002 (DebianGlue contintLabsSlave DebianJessie) in workspace /srv/jenkins-workspace/workspace/php55lint

[...]

15:16:43 Fetching upstream changes from git://contint1001.wikimedia.org/mediawiki/extensions/ReadingLists
15:16:43  > git fetch --tags --progress git://contint1001.wikimedia.org/mediawiki/extensions/ReadingLists refs/zuul/master/Ze74f9a112dde44b0a8585ec60a6b5c36 --depth=1
15:16:43 ERROR: Error fetching remote repo 'origin'
15:16:43 hudson.plugins.git.GitException: Failed to fetch from git://contint1001.wikimedia.org/mediawiki/extensions/ReadingLists
15:16:43 	at hudson.plugins.git.GitSCM.fetchFrom(GitSCM.java:812)
15:16:43 	at hudson.plugins.git.GitSCM.retrieveChanges(GitSCM.java:1079)
15:16:43 	at hudson.plugins.git.GitSCM.checkout(GitSCM.java:1110)
15:16:43 	at hudson.scm.SCM.checkout(SCM.java:495)
15:16:43 	at hudson.model.AbstractProject.checkout(AbstractProject.java:1202)
15:16:43 	at hudson.model.AbstractBuild$AbstractBuildExecution.defaultCheckout(AbstractBuild.java:574)
15:16:43 	at jenkins.scm.SCMCheckoutStrategy.checkout(SCMCheckoutStrategy.java:86)
15:16:43 	at hudson.model.AbstractBuild$AbstractBuildExecution.run(AbstractBuild.java:499)
15:16:43 	at hudson.model.Run.execute(Run.java:1724)
15:16:43 	at hudson.model.FreeStyleBuild.run(FreeStyleBuild.java:43)
15:16:43 	at hudson.model.ResourceController.execute(ResourceController.java:97)
15:16:43 	at hudson.model.Executor.run(Executor.java:429)
15:16:43 Caused by: hudson.plugins.git.GitException: Command "git fetch --tags --progress git://contint1001.wikimedia.org/mediawiki/extensions/ReadingLists refs/zuul/master/Ze74f9a112dde44b0a8585ec60a6b5c36 --depth=1" returned status code 128:
15:16:43 stdout: 
15:16:43 stderr: fatal: remote error: access denied or repository not exported: /mediawiki/extensions/ReadingLists
15:16:43 
15:16:43 	at org.jenkinsci.plugins.gitclient.CliGitAPIImpl.launchCommandIn(CliGitAPIImpl.java:1996)
15:16:43 	at org.jenkinsci.plugins.gitclient.CliGitAPIImpl.launchCommandWithCredentials(CliGitAPIImpl.java:1715)
15:16:43 	at org.jenkinsci.plugins.gitclient.CliGitAPIImpl.access$300(CliGitAPIImpl.java:72)
15:16:43 	at org.jenkinsci.plugins.gitclient.CliGitAPIImpl$1.execute(CliGitAPIImpl.java:405)
15:16:43 	at org.jenkinsci.plugins.gitclient.RemoteGitImpl$CommandInvocationHandler$1.call(RemoteGitImpl.java:153)
15:16:43 	at org.jenkinsci.plugins.gitclient.RemoteGitImpl$CommandInvocationHandler$1.call(RemoteGitImpl.java:146)
15:16:43 	at hudson.remoting.UserRequest.perform(UserRequest.java:207)
15:16:43 	at hudson.remoting.UserRequest.perform(UserRequest.java:53)
15:16:43 	at hudson.remoting.Request$2.run(Request.java:358)
15:16:43 	at hudson.remoting.InterceptingExecutorService$1.call(InterceptingExecutorService.java:72)
15:16:43 	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
15:16:43 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
15:16:43 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
15:16:43 	at java.lang.Thread.run(Thread.java:748)
15:16:43 	Suppressed: hudson.remoting.Channel$CallSiteStackTrace: Remote call to integration-slave-jessie-1002
15:16:43 		at hudson.remoting.Channel.attachCallSiteStackTrace(Channel.java:1693)
15:16:43 		at hudson.remoting.UserResponse.retrieve(UserRequest.java:310)
15:16:43 		at hudson.remoting.Channel.call(Channel.java:908)
15:16:43 		at org.jenkinsci.plugins.gitclient.RemoteGitImpl$CommandInvocationHandler.execute(RemoteGitImpl.java:146)
15:16:43 		at sun.reflect.GeneratedMethodAccessor318.invoke(Unknown Source)
15:16:43 		at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
15:16:43 		at java.lang.reflect.Method.invoke(Method.java:498)
15:16:43 		at org.jenkinsci.plugins.gitclient.RemoteGitImpl$CommandInvocationHandler.invoke(RemoteGitImpl.java:132)
15:16:43 		at com.sun.proxy.$Proxy79.execute(Unknown Source)
15:16:43 		at hudson.plugins.git.GitSCM.fetchFrom(GitSCM.java:810)
15:16:43 		at hudson.plugins.git.GitSCM.retrieveChanges(GitSCM.java:1079)
15:16:43 		at hudson.plugins.git.GitSCM.checkout(GitSCM.java:1110)
15:16:43 		at hudson.scm.SCM.checkout(SCM.java:495)
15:16:43 		at hudson.model.AbstractProject.checkout(AbstractProject.java:1202)
15:16:43 		at hudson.model.AbstractBuild$AbstractBuildExecution.defaultCheckout(AbstractBuild.java:574)
15:16:43 		at jenkins.scm.SCMCheckoutStrategy.checkout(SCMCheckoutStrategy.java:86)
15:16:43 		at hudson.model.AbstractBuild$AbstractBuildExecution.run(AbstractBuild.java:499)
15:16:43 		at hudson.model.Run.execute(Run.java:1724)
15:16:43 		at hudson.model.FreeStyleBuild.run(FreeStyleBuild.java:43)
15:16:43 		at hudson.model.ResourceController.execute(ResourceController.java:97)
15:16:43 		at hudson.model.Executor.run(Executor.java:429)
15:16:43 ERROR: Error fetching remote repo 'origin'
15:16:43 Finished: FAILURE

Some debug notes: T187897#5471466

Assumption

@hashar guesses there is a race condition between the git merge doing some file renaming (possibly via a copy + rm) and the git-daemon checking whether the path is a repo. git checks whether there is a .git directory and chdir to it. If the check happens at the exact time git delete some files, I guess we get the issue. There is no informative message as to why it fails though.

Event Timeline

The git-daemon gave:

Feb 21 15:16:43 contint1001 git-daemon[29526]: '/srv/zuul/git/mediawiki/extensions/ReadingLists' does not appear to be a git repository

And that happens once in a while on various repositories:

Feb  2 18:34:38 contint1001 git-daemon[9047]: '/srv/zuul/git/mediawiki/extensions/MassMessage' does not appear to be a git repository
Feb  4 15:27:46 contint1001 git-daemon[30655]: '/srv/zuul/git/mediawiki/extensions/LoginNotify' does not appear to be a git repository
Feb  5 22:36:22 contint1001 git-daemon[27528]: '/srv/zuul/git/mediawiki/extensions/MassMessage' does not appear to be a git repository
Feb  6 22:21:00 contint1001 git-daemon[7887]: '/srv/zuul/git/mediawiki/php/luasandbox' does not appear to be a git repository
Feb  6 22:21:01 contint1001 git-daemon[7892]: '/srv/zuul/git/mediawiki/php/luasandbox' does not appear to be a git repository
Feb  7 05:29:39 contint1001 git-daemon[6039]: '/srv/zuul/git/mediawiki/extensions/MassMessage' does not appear to be a git repository
Feb  8 00:44:25 contint1001 git-daemon[16163]: '/srv/zuul/git/mediawiki/extensions/ApprovedRevs' does not appear to be a git repository
Feb  8 13:51:51 contint1001 git-daemon[24643]: fatal: '.' does not appear to be a git repository
Feb  8 20:39:55 contint1001 git-daemon[15733]: '/srv/zuul/git/mediawiki/extensions/CloseWikis' does not appear to be a git repository
Feb  8 21:42:27 contint1001 git-daemon[16976]: '/srv/zuul/git/mediawiki/extensions/MassMessage' does not appear to be a git repository
Feb  9 17:13:21 contint1001 git-daemon[22882]: '/srv/zuul/git/mediawiki/extensions/Renameuser' does not appear to be a git repository
Feb 10 11:51:38 contint1001 git-daemon[6045]: '/srv/zuul/git/mediawiki/extensions/HitCounters' does not appear to be a git repository
Feb 10 11:55:13 contint1001 git-daemon[7341]: '/srv/zuul/git/mediawiki/extensions/FlvHandler' does not appear to be a git repository
Feb 10 19:56:00 contint1001 git-daemon[2057]: '/srv/zuul/git/mediawiki/extensions/AllTimeZones' does not appear to be a git repository
Feb 11 05:58:41 contint1001 git-daemon[28604]: '/srv/zuul/git/mediawiki/extensions/Scribunto' does not appear to be a git repository
Feb 12 18:46:09 contint1001 git-daemon[23676]: '/srv/zuul/git/mediawiki/extensions/SportsTeams' does not appear to be a git repository
Feb 13 14:10:27 contint1001 git-daemon[27585]: '/srv/zuul/git/mediawiki/php/wikidiff2' does not appear to be a git repository
Feb 14 20:37:19 contint1001 git-daemon[5020]: '/srv/zuul/git/mediawiki/extensions/AnchorHandler' does not appear to be a git repository
Feb 14 21:42:04 contint1001 git-daemon[1134]: '/srv/zuul/git/mediawiki/extensions/AnchorHandler' does not appear to be a git repository
Feb 15 09:03:53 contint1001 git-daemon[28278]: '/srv/zuul/git/mediawiki/extensions/CentralNotice' does not appear to be a git repository
Feb 15 13:10:06 contint1001 git-daemon[23587]: '/srv/zuul/git/mediawiki/extensions/SpamBlacklist' does not appear to be a git repository
Feb 15 22:29:24 contint1001 git-daemon[13711]: '/srv/zuul/git/mediawiki/extensions/SyntaxHighlight_GeSHi' does not appear to be a git repository
Feb 17 02:58:33 contint1001 git-daemon[19321]: '/srv/zuul/git/mediawiki/extensions/WikibaseQuality' does not appear to be a git repository
Feb 17 02:58:33 contint1001 git-daemon[19326]: '/srv/zuul/git/mediawiki/extensions/WikibaseQuality' does not appear to be a git repository
Feb 17 02:59:24 contint1001 git-daemon[20057]: '/srv/zuul/git/mediawiki/extensions/WikibaseQualityExternalValidation' does not appear to be a git repository
Feb 19 14:02:02 contint1001 git-daemon[4478]: '/srv/zuul/git/mediawiki/php/wikidiff2' does not appear to be a git repository
Feb 21 15:16:43 contint1001 git-daemon[29526]: '/srv/zuul/git/mediawiki/extensions/ReadingLists' does not appear to be a git repository
Feb 22 23:37:03 contint1001 git-daemon[19203]: '/srv/zuul/git/mediawiki/extensions/SyntaxHighlight_GeSHi' does not appear to be a git repository

I guess we can try running the git-daemon with --verbose to get more informations in syslog.

Also we might be reaching the maximum number of connections which defaults to 32.

Also we might be reaching the maximum number of connections which defaults to 32.

Moved to T222661

That still happens from time to time. In the CI build log:

14:50:24 + git fetch --depth 2 --quiet git://contint1001.wikimedia.org/operations/software/conftool refs/zuul/master/Zffe61a2d1f3043178462f7c561f111fb
14:50:24 fatal: remote error: access denied or repository not exported: /operations/software/conftool

On contint1001 git-daemon log:

Sep  6 14:50:24 contint1001 git-daemon[31715]: '/srv/zuul/git/operations/software/conftool' does not appear to be a git repository

From the repository reflog:

commit 14cd596
Reflog: HEAD@{0} (Wikimedia Zuul Merger <zuul-merger@contint1001>)
Reflog message: merge ae523a6e1d8c5ebface10df7ef8a7b7bf59a19c0: In-index merge
Author: Wikimedia Zuul Merger <zuul-merger@contint1001>
Date:   Fri Sep 6 14:51:15 2019 +0000

    Merge commit 'refs/changes/19/534819/1' of ssh://gerrit.wikimedia.org:29418/operations/software/conftool into HEAD

commit b13d97b
Reflog: HEAD@{1} (Wikimedia Zuul Merger <zuul-merger@contint1001>)
Reflog message: merge 7dc91237432a7a4d8c428db7225a87b03d03ca72: In-index merge
Author: Wikimedia Zuul Merger <zuul-merger@contint1001>
Date:   Fri Sep 6 14:51:15 2019 +0000

    Merge commit 'refs/changes/18/534818/1' of ssh://gerrit.wikimedia.org:29418/operations/software/conftool into HEAD

commit c9442cb
Reflog: HEAD@{2} (Wikimedia Zuul Merger <zuul-merger@contint1001>)
Reflog message: reset: moving to HEAD
Author: jenkins-bot <jenkins-bot@gerrit.wikimedia.org>
Date:   Fri Sep 6 13:44:05 2019 +0000

    Merge "Fix configuration file lookup when running with sudo"

In the zuul-merger logs:

2019-09-06 14:50:23,293 DEBUG zuul.Repo: CreateZuulRef master/Zda94ed7fa1c442f0973a55083332a6a9 at ed09adfba4f878f91b4e164cf22aafbd64ae3787 on <git.Repo "/srv/zuul/git/operations/software/conftool/.git">
2019-09-06 14:50:23,347 DEBUG zuul.MergeServer: Got merge job: 80c74076c7bb4c92aa9021b45804f92d
2019-09-06 14:50:23,347 DEBUG zuul.Merger: Merging for change 534818,1.
2019-09-06 14:50:23,347 DEBUG zuul.Merger: Processing refspec refs/changes/18/534818/1 for project operations/software/conftool / master ref Z544495c85bbe4a50ac9b4b4b0c87d543
2019-09-06 14:50:23,409 DEBUG zuul.Merger: Unable to find commit for ref master/Z544495c85bbe4a50ac9b4b4b0c87d543
2019-09-06 14:50:23,409 DEBUG zuul.Merger: No base commit found for (u'operations/software/conftool', u'master')
2019-09-06 14:50:23,409 DEBUG zuul.Repo: Resetting repository /srv/zuul/git/operations/software/conftool
2019-09-06 14:50:23,410 DEBUG zuul.Repo: Updating repository /srv/zuul/git/operations/software/conftool
2019-09-06 14:50:23,900 DEBUG zuul.Repo: Checking out c9442cb4344856d96f61b8a14f7b7e52ef839090
2019-09-06 14:50:24,627 DEBUG zuul.Repo: Merging refs/changes/18/534818/1 with args ['-s', 'resolve', 'FETCH_HEAD']
2019-09-06 14:50:24,667 DEBUG zuul.Repo: CreateZuulRef master/Z544495c85bbe4a50ac9b4b4b0c87d543 at a727c573eed9fc31efb4abc6abb2505ab933e840 on <git.Repo "/srv/zuul/git/operations/software/conftool/.git">
2019-09-06 14:50:24,723 DEBUG zuul.MergeServer: Got merge job: 4112a595cd1f43539f34a28212eb3a58
2019-09-06 14:50:24,723 DEBUG zuul.Merger: Merging for change 534818,1.
2019-09-06 14:50:24,723 DEBUG zuul.Merger: Processing refspec refs/changes/18/534818/1 for project operations/software/conftool / master ref Z544495c85bbe4a50ac9b4b4b0c87d543
2019-09-06 14:50:24,835 DEBUG zuul.Merger: Found commit a727c573eed9fc31efb4abc6abb2505ab933e840 for ref master/Z544495c85bbe4a50ac9b4b4b0c87d543
2019-09-06 14:50:24,835 DEBUG zuul.Merger: Merging for change 534819,1.
2019-09-06 14:50:24,835 DEBUG zuul.Merger: Processing refspec refs/changes/19/534819/1 for project operations/software/conftool / master ref Zea5ded0c4abc4aeead72d46cef8c1bfc
2019-09-06 14:50:24,876 DEBUG zuul.Merger: Unable to find commit for ref master/Zea5ded0c4abc4aeead72d46cef8c1bfc
2019-09-06 14:50:24,876 DEBUG zuul.Merger: Found base commit a727c573eed9fc31efb4abc6abb2505ab933e840 for (u'operations/software/conftool', u'master')
2019-09-06 14:50:24,877 DEBUG zuul.Repo: Checking out a727c573eed9fc31efb4abc6abb2505ab933e840
2019-09-06 14:50:25,123 DEBUG zuul.Repo: Merging refs/changes/19/534819/1 with args ['-s', 'resolve', 'FETCH_HEAD']
2019-09-06 14:50:25,158 DEBUG zuul.Repo: CreateZuulRef master/Zea5ded0c4abc4aeead72d46cef8c1bfc at 9137accd90bccc53e6c629eeae225013d5bd1e84 on <git.Repo "/srv/zuul/git/operations/software/conftool/.git">
2019-09-06 14:50:25,211 DEBUG zuul.MergeServer: Got merge job: a0100689b2b34271b87e5db0fa2629f1
2019-09-06 14:50:25,211 DEBUG zuul.Merger: Merging for change 534818,1.
2019-09-06 14:50:25,211 DEBUG zuul.Merger: Processing refspec refs/changes/18/534818/1 for project operations/software/conftool / master ref Zac2151e5e7954f84925d8cc1c194e6a6

So the repo had a few git merge operations going on when CI tried to fetch from it. I would guess there is a race condition between the git merge doing some file renaming (possibly via a copy + rm) and the git-daemon checking whether the path is a repo. If the check happens at the exact time git delete some files, I guess we get the issue :-\ That is pure guess from me, apparently git just check whether there is a .git directory and chdir to it, there is no informative message as to why it fails though :-\

Krinkle added a subscriber: Krinkle.

No trace of access denied or repository not exported in current logs under contint1001:/var/lib/jenkins/jobs.

contint1001:/var/lib/jenkins/jobs only has the jobs configuration, the build artifacts are at /srv/jenkins/builds. We instead should look at the git-daemon logs on contint1001 and contint2001:

sudo zgrep -c git.*appear /var/log/daemon.log*
/var/log/daemon.log:0
/var/log/daemon.log.1:4
/var/log/daemon.log.2.gz:1
/var/log/daemon.log.3.gz:34
/var/log/daemon.log.4.gz:22

That still occurs from time to time. A way to reduce the likeliness to hit the race condition would be to have more zuul-merger process and thus more git repositories which would spread the load.

Just saw this for GrowthExperiments https://integration.wikimedia.org/ci/job/mwgate-node12-docker/54976/console

09:25:05 + exec docker run --volume /srv/jenkins/workspace/workspace/mwgate-node12-docker/src:/src --volume /srv/jenkins/workspace/workspace/mwgate-node12-docker/cache:/cache --volume /srv/git:/srv/git:ro --security-opt seccomp=unconfined --init --rm --label jenkins.job=mwgate-node12-docker --label jenkins.build=54976 --env-file /dev/fd/63 docker-registry.wikimedia.org/releng/ci-src-setup-simple:0.4.2-s1
09:25:05 ++ /usr/bin/env
09:25:05 ++ egrep -v '^(HOME|SHELL|PATH|LOGNAME|MAIL)='
09:25:05 + git init
09:25:05 Initialized empty Git repository in /src/.git/
09:25:05 + git fetch --quiet --update-head-ok --depth 2 git://contint2001.wikimedia.org/mediawiki/extensions/GrowthExperiments +refs/zuul/master/Z3328202e0c70490a967bc4b7314b5b35:refs/zuul/master/Z3328202e0c70490a967bc4b7314b5b35
09:25:06 fatal: remote error: access denied or repository not exported: /mediawiki/extensions/GrowthExperiments
09:25:06 Build step 'Execute shell' marked build as failure

And on the Zuul-merge, it was processing another change for the same repository:

2021-11-10 08:25:05,173 DEBUG zuul.Merger: Merging for change 737786,2.
2021-11-10 08:25:05,174 DEBUG zuul.Merger: Processing refspec refs/changes/86/737786/2 for project mediawiki/extensions/GrowthExperiments / master ref Z2f41314146a548e29aa3d087a4134796
2021-11-10 08:25:05,602 DEBUG zuul.Merger: Unable to find commit for ref master/Z2f41314146a548e29aa3d087a4134796
2021-11-10 08:25:05,602 DEBUG zuul.Merger: Found base commit fa0bc5fba5050550f0ef3769980c147a6d23a893 for (u'mediawiki/extensions/GrowthExperiments', u'master')
2021-11-10 08:25:05,602 DEBUG zuul.Repo: Checking out fa0bc5fba5050550f0ef3769980c147a6d23a893
2021-11-10 08:25:07,920 DEBUG zuul.Repo: Merging refs/changes/86/737786/2 with args ['-s', 'resolve', 'FETCH_HEAD']
2021-11-10 08:25:08,007 DEBUG zuul.Repo: CreateZuulRef master/Z2f41314146a548e29aa3d087a4134796 at d69af698c348561bf102e8e9e694bf75c7d97c30 on <git.Repo "/srv/zuul/git/mediawiki/extensions/GrowthExperiments/.git">

It is a race condition :-\

Change 738370 had a related patch set uploaded (by Hashar; author: Hashar):

[operations/puppet@production] zuul: send errors from git-daemon to client

https://gerrit.wikimedia.org/r/738370

Change 738370 merged by David Caro:

[operations/puppet@production] zuul: send errors from git-daemon to client

https://gerrit.wikimedia.org/r/738370

git-daemon now runs with --informative-errors:

When informative errors are turned on, git-daemon will report more verbose errors to the client, differentiating conditions like "no such repository" from "repository not exported".
This is more convenient for clients, but may leak information about the existence of unexported repositories.
When informative errors are not enabled, all errors report "access denied" to the client.
The default is --no-informative-errors.

So hopefully next time it happens, git fetch will give a bit more informations than just fatal: remote error: access denied or repository not exported: <repo path>