New JGit error when upgrading to 2.1.5-85-ge5669ac

[Fredrik Luthander]

Hi there fellow Gerriters. :)

Yesterday, my team at $DAYJOB tried to upgrade Gerrit from version
2.1.3-rc2 to 2.1.5-85-ge5669ac (mostly to have the missing blob fix
specifically submitted for us). This upgrade however, was not
successful, and in the end we had to back down to the 2.1.3 version
again.

The upgrade itself was fine, however the following tests were not
successful. A specific git yields error when trying to replicate it.

The symptom is as follows:

The upgraded gerrit service is started.
First person to sync/fetch from the server can successfully get the
git together with other gits.
All following attempts to sync the git yields the following error:

$ git clone ssh://server/path/icu4c.git icu4c
Initialized empty Git repository in ~myhomedir/myrepos/icu4c/.git/
remote: Counting objects: 14001, done
remote: Finding sources: 100% (14001/14001)
fatal: pack has bad object at offset 13365870: inflate returned -5
fatal: index-pack failed
$

This was repeatable on several of our slave servers, but with somewhat
different error messages in error_log. I'll begin with the one I
believe to be the least helpful:

[2010-09-26 19:03:53,322] ERROR com.google.gerrit.sshd.BaseCommand :
Internal server error (user fredrik.luthander account 1000004) during
git-upload-pack '/path/icu4c.git'
com.google.gerrit.sshd.BaseCommand$Failure: fatal: 'path/icu4c': not a
git archive
at
com.google.gerrit.sshd.AbstractGitCommand.service(AbstractGitCommand.java:
100)
at com.google.gerrit.sshd.AbstractGitCommand.access
$000(AbstractGitCommand.java:34)
at com.google.gerrit.sshd.AbstractGitCommand
$1.run(AbstractGitCommand.java:69)
at com.google.gerrit.sshd.BaseCommand
$TaskThunk.run(BaseCommand.java:395)
at java.util.concurrent.Executors
$RunnableAdapter.call(Executors.java:441)
at java.util.concurrent.FutureTask
$Sync.innerRun(FutureTask.java:303)
at java.util.concurrent.FutureTask.run(FutureTask.java:138)
at java.util.concurrent.ScheduledThreadPoolExecutor
$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:98)
at java.util.concurrent.ScheduledThreadPoolExecutor
$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:207)
at com.google.gerrit.server.git.WorkQueue
$Task.run(WorkQueue.java:324)
at java.util.concurrent.ThreadPoolExecutor
$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor
$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:619)
Caused by: org.eclipse.jgit.errors.RepositoryNotFoundException:
repository not found: Cannot open repository platform/external/icu4c
at
com.google.gerrit.server.git.LocalDiskRepositoryManager.openRepository(LocalDiskRepositoryManager.java:
98)
at
com.google.gerrit.sshd.AbstractGitCommand.service(AbstractGitCommand.java:
98)
... 12 more
Caused by: org.eclipse.jgit.errors.RepositoryNotFoundException:
repository not found: /server/path/icu4c
at org.eclipse.jgit.lib.RepositoryCache
$FileKey.open(RepositoryCache.java:322)
at
org.eclipse.jgit.lib.RepositoryCache.openRepository(RepositoryCache.java:
171)
at
org.eclipse.jgit.lib.RepositoryCache.open(RepositoryCache.java:106)
at
org.eclipse.jgit.lib.RepositoryCache.open(RepositoryCache.java:81)
at
com.google.gerrit.server.git.LocalDiskRepositoryManager.openRepository(LocalDiskRepositoryManager.java:
95)
... 13 more

One another server however, we got a much more interesting stack
trace:

[2010-09-27 02:06:47,311] ERROR com.google.gerrit.sshd.BaseCommand :
Internal server error (user cecilia.svensson account 1000032) during
git-upload-pack '/path/icu4c.git'
org.eclipse.jgit.errors.CorruptObjectException: Object
86be6cbcd3527245d5cd9961dbdede05d2877268 is corrupt: incorrect length
at
org.eclipse.jgit.storage.file.UnpackedObject.checkValidEndOfStream(UnpackedObject.java:
250)
at
org.eclipse.jgit.storage.file.UnpackedObject.open(UnpackedObject.java:
140)
at
org.eclipse.jgit.storage.file.ObjectDirectory.openObject2(ObjectDirectory.java:
447)
at
org.eclipse.jgit.storage.file.ObjectDirectory.openObject1(ObjectDirectory.java:
338)
at
org.eclipse.jgit.storage.file.FileObjectDatabase.openObjectImpl1(FileObjectDatabase.java:
145)
at
org.eclipse.jgit.storage.file.FileObjectDatabase.openObject(FileObjectDatabase.java:
130)
at
org.eclipse.jgit.storage.file.WindowCursor.open(WindowCursor.java:108)
at
org.eclipse.jgit.storage.pack.PackWriter.writeWholeObjectDeflate(PackWriter.java:
906)
at
org.eclipse.jgit.storage.pack.PackWriter.writeObject(PackWriter.java:
863)
at
org.eclipse.jgit.storage.pack.PackOutputStream.writeObject(PackOutputStream.java:
161)
at
org.eclipse.jgit.storage.file.WindowCursor.writeObjects(WindowCursor.java:
153)
at
org.eclipse.jgit.storage.pack.PackWriter.writeObjects(PackWriter.java:
817)
at
org.eclipse.jgit.storage.pack.PackWriter.writePack(PackWriter.java:
504)
at
org.eclipse.jgit.transport.UploadPack.sendPack(UploadPack.java:657)
at
org.eclipse.jgit.transport.UploadPack.service(UploadPack.java:352)
at
org.eclipse.jgit.transport.UploadPack.upload(UploadPack.java:313)
at com.google.gerrit.sshd.commands.Upload.runImpl(Upload.java:
50)
at
com.google.gerrit.sshd.AbstractGitCommand.service(AbstractGitCommand.java:
104)
at com.google.gerrit.sshd.AbstractGitCommand.access
$000(AbstractGitCommand.java:34)
at com.google.gerrit.sshd.AbstractGitCommand
$1.run(AbstractGitCommand.java:69)
at com.google.gerrit.sshd.BaseCommand
$TaskThunk.run(BaseCommand.java:395)
at java.util.concurrent.Executors
$RunnableAdapter.call(Executors.java:441)
at java.util.concurrent.FutureTask
$Sync.innerRun(FutureTask.java:303)
at java.util.concurrent.FutureTask.run(FutureTask.java:138)
at java.util.concurrent.ScheduledThreadPoolExecutor
$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:98)
at java.util.concurrent.ScheduledThreadPoolExecutor
$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:207)
at com.google.gerrit.server.git.WorkQueue
$Task.run(WorkQueue.java:324)
at java.util.concurrent.ThreadPoolExecutor
$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor
$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:619)

A restart of the service doesn't help as far as we've been able to
tell, however manually running a git gc on the git will generate some
output (it fixes/repacks something), and after that it works to sync
from the git again! But only once. After that we're back to index-pack-
failed again. :-(
Its fully repeatable however, so in effect we needed to run git gc
once for every person syncing from that git, and that doesn't even
scale badly, it doesn't scale at all. :-)
So, we were forced to back down to our previous version again, and we
probably won't be able to upgrade anytime soon. It would please us if
we could try to fix this problem however, I suspect more shops than us
might run into this problem. The git in question, I'm not sure of its
contents, if you need it I'll check with the people what it contains,
if we are allowed to export it.

Looking forward to any feedback you might have on this.. thanks!

Shawn: Would you like me to post a new issue with the same details as
in this mail?

BR,
Fredrik

[Fredrik Luthander]

Hi everyone!

Nevermind the message below, this error can be attributed to the new
threshold value referenced by Shawn in his vacation announcement [1].

Even though we backed out, I hope this can serve as a reminder/
solution to anyone also running into the same error message on gerrit
2.1.5+.
Especially the "Object is corrupt" message is quite significant for
this error I believe.

[1]: http://groups.google.com/group/repo-discuss/browse_thread/thread/86998aa883ae9a96#

BR,
Fredrik

On Sep 27, 1:19 pm, Fredrik Luthander

[Shawn Pearce]

On Mon, Sep 27, 2010 at 04:19, Fredrik Luthander
<fredrik....@sonyericsson.com> wrote:
> Yesterday, my team at $DAYJOB tried to upgrade Gerrit from version
> 2.1.3-rc2 to 2.1.5-85-ge5669ac (mostly to have the missing blob fix
> specifically submitted for us). This upgrade however, was not
> successful, and in the end we had to back down to the 2.1.3 version
> again.
>
> The upgrade itself was fine, however the following tests were not
> successful. A specific git yields error when trying to replicate it.
>
> The symptom is as follows:
>
> The upgraded gerrit service is started.
> First person to sync/fetch from the server can successfully get the
> git together with other gits.
> All following attempts to sync the git yields the following error:

...

> [2010-09-27 02:06:47,311] ERROR com.google.gerrit.sshd.BaseCommand :
> Internal server error (user cecilia.svensson account 1000032) during
> git-upload-pack '/path/icu4c.git'
> org.eclipse.jgit.errors.CorruptObjectException: Object
> 86be6cbcd3527245d5cd9961dbdede05d2877268 is corrupt: incorrect length
>        at
> org.eclipse.jgit.storage.file.UnpackedObject.checkValidEndOfStream(UnpackedObject.java:
> 250)

Someone just reported a similar issue on the jgit-dev mailing list.
What is occurring is this:

During the first fetch/clone an object bigger than the
core.streamFileThreshold is encountered. The object is inflated and a
copy is stored as a loose object in $GIT_DIR/objects. This is because
the inflation cost of a delta bigger than the threshold is very high,
so we cache the object so that later accesses of the same thing are
cheaper.

On the second access the loose object is used instead, but its
consistency check on the end of the stream fails. This is the bug
that just got reported on the jgit-dev list earlier this morning.

If you set core.streamFileThreshold very big (e.g. 2047m) in
gerrit.config you can bypass all of this logic and avoid the bug.
This is what "my" servers are using right now.