Skip to main content

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index] [List Home]
[jgit-dev] Tracking down upload failures due to Missing object

Hi,

We use JGit 4.1.2 as part of a Gerrit 2.12 installation and we have been having cloning and fetching errors in some of our repositories. Clients receive a fatal error and a typical stack trace when using SSH looks like this:

[2017-05-29 13:05:27,499] [SSH git-upload-pack '/project' (user)] ERROR com.google.gerrit.sshd.BaseCommand : Internal server error (user user account 1009118) during git-upload-pack '/project'
org.eclipse.jgit.errors.PackProtocolException: want 2238f9e2d5e8526479e994cafcb409930b9ed3ae not valid
	at org.eclipse.jgit.transport.UploadPack.parseWants(UploadPack.java:1190)
	at org.eclipse.jgit.transport.UploadPack.processHaveLines(UploadPack.java:1063)
	at o\rg.eclipse.jgit.transport.UploadPack.negotiate(UploadPack.java:1028)
	at org.eclipse.jgit.transport.UploadPack.service(UploadPack.java:744)
	at org.eclipse.jgit.transport.UploadPack.upload(UploadPack.java:666)
	at com.google.gerrit.sshd.commands.Upload.runImpl(Upload.java:87)
	at com.google.gerrit.sshd.AbstractGitCommand.service(AbstractGitCommand.java:101)
	at com.google.gerrit.sshd.AbstractGitCommand.access$000(AbstractGitCommand.java:32)
	at com.google.gerrit.sshd.AbstractGitCommand$1.run(AbstractGitCommand.java:70)
	at com.google.gerrit.sshd.BaseCommand$TaskThunk.run(BaseCommand.java:437)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
	at com.google.gerrit.server.git.WorkQueue$Task.run(WorkQueue.java:396)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	at java.lang.Thread.run(Thread.java:745)
Caused by: org.eclipse.jgit.errors.MissingObjectException: Missing unknown 2238f9e2d5e8526479e994cafcb409930b9ed3ae
	at org.eclipse.jgit.internal.storage.file.WindowCursor.open(WindowCursor.java:156)
	at org.eclipse.jgit.lib.ObjectReader$1.open(ObjectReader.java:299)
	at org.eclipse.jgit.revwalk.RevWalk$2.next(RevWalk.java:971)
	at org.eclipse.jgit.transport.UploadPack.parseWants(UploadPack.java:1176)
	... 17 more

Looking for the "missing" object in the repository shows that most of the time it is a commit that has been recently created/updated and that it exists in the repo as an unpacked object, i.e., it is present in the objects folder. Running GC on the repository seems to "fix" the issue but it also been seen that, in some cases, just retrying the clone can be enough for it to succeed. Reproducing the issue have proven hard as it seems to be transient in nature and in a local machine (compared to the server) the clone always succeed.

Looking at the code for this specific stack trace we noticed that parsing the list of 'wants' fails to find the just updated object; what catches the attention is that even if the object is loose, in ObjectDirectory.openObject the check to see if the object is unpacked (line 384) seems to be always false. We are trying to understand now how this UnpackedObjectCache works and if it's a possibility for the object just not being added to the cache. For what we've seen so far, there are calls to the ObjectDirectoryInserter.insert method from multiple related commands but we still need to look more deeply in the way this cache works.

A variation of this same error is when the negotiation is successful but writing the pack fails because of the same error, complaining about a "missing" object that is present in the repository.

In the case of HTTP cloning/fetching, the stack trace [1] is a bit different but the final cause seems to be related as the operation fails when checking if the 'wants' have been advertised. In this case, the repository is walked marking the 'wants' as starting points of the walk and the 'have' objects as uninteresting. At the end, the "missing" object is left unmarked (UploadPack, line 1316) and a "want not valid" exception thrown.

In all cases, the common point seems to be JGit not "seeing" the just created/updated object. The goal of this post is to get the opinion of the Jgit experts on this issue and about the way we have approached the problem. May be there is something evident we are not seeing... Any suggestion about this problem or how to better troubleshoot it is welcomed.

Thanks,
Hector


[1]

[2017-05-29 18:38:06,478] [HTTP-35717] WARN  / : Internal error during upload-pack from /project.git
org.eclipse.jgit.errors.PackProtocolException: want 4c9e362e229a6a288682128d1e3645082f44892b not valid
	at org.eclipse.jgit.transport.UploadPack.checkNotAdvertisedWants(UploadPack.java:1318)
	at org.eclipse.jgit.transport.UploadPack.access$100(UploadPack.java:108)
	at org.eclipse.jgit.transport.UploadPack$ReachableCommitRequestValidator.checkWants(UploadPack.java:1230)
	at org.eclipse.jgit.transport.UploadPack$AdvertisedRequestValidator.checkWants(UploadPack.java:1214)
	at org.eclipse.jgit.transport.UploadPack.parseWants(UploadPack.java:1171)
	at org.eclipse.jgit.transport.UploadPack.processHaveLines(UploadPack.java:1063)
	at org.eclipse.jgit.transport.UploadPack.negotiate(UploadPack.java:1028)
	at org.eclipse.jgit.transport.UploadPack.service(UploadPack.java:744)
	at org.eclipse.jgit.transport.UploadPack.upload(UploadPack.java:666)
	at org.eclipse.jgit.http.server.UploadPackServlet.doPost(UploadPackServlet.java:191)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:648)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:729)
	at org.eclipse.jgit.http.server.glue.UrlPipeline$Chain.doFilter(UrlPipeline.java:237)
	at com.google.gerrit.httpd.GitOverHttpServlet$UploadFilter.doFilter(GitOverHttpServlet.java:270)
	at org.eclipse.jgit.http.server.glue.UrlPipeline$Chain.doFilter(UrlPipeline.java:235)
	at org.eclipse.jgit.http.server.UploadPackServlet$Factory.doFilter(UploadPackServlet.java:149)
	at org.eclipse.jgit.http.server.glue.UrlPipeline$Chain.doFilter(UrlPipeline.java:235)
	at org.eclipse.jgit.http.server.RepositoryFilter.doFilter(RepositoryFilter.java:151)
	at org.eclipse.jgit.http.server.glue.UrlPipeline$Chain.doFilter(UrlPipeline.java:235)
	at org.eclipse.jgit.http.server.NoCacheFilter.doFilter(NoCacheFilter.java:80)
	at org.eclipse.jgit.http.server.glue.UrlPipeline$Chain.doFilter(UrlPipeline.java:235)
	at org.eclipse.jgit.http.server.glue.UrlPipeline.service(UrlPipeline.java:215)
	at org.eclipse.jgit.http.server.glue.SuffixPipeline.service(SuffixPipeline.java:101)
	at org.eclipse.jgit.http.server.glue.MetaFilter.doFilter(MetaFilter.java:175)
	at org.eclipse.jgit.http.server.glue.MetaServlet.service(MetaServlet.java:133)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:729)
	at com.google.inject.servlet.ServletDefinition.doServiceImpl(ServletDefinition.java:287)
	at com.google.inject.servlet.ServletDefinition.doService(ServletDefinition.java:277)
	at com.google.inject.servlet.ServletDefinition.service(ServletDefinition.java:182)
	at com.google.inject.servlet.ManagedServletPipeline.service(ManagedServletPipeline.java:91)
	at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:85)
	at com.google.gerrit.httpd.GetUserFilter.doFilter(GetUserFilter.java:82)
	at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:82)
	at com.google.gerrit.httpd.RunAsFilter.doFilter(RunAsFilter.java:117)
	at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:82)
	at com.google.gerrit.httpd.RequireSslFilter.doFilter(RequireSslFilter.java:68)
	at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:82)
	at com.google.gerrit.httpd.ProjectBasicAuthFilter.doFilter(ProjectBasicAuthFilter.java:105)
	at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:82)
	at com.google.gerrit.httpd.ProjectBasicAuthFilter.doFilter(ProjectBasicAuthFilter.java:105)
	at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:82)
	at com.google.gerrit.httpd.AllRequestFilter$FilterProxy$1.doFilter(AllRequestFilter.java:136)
	at com.google.gerrit.httpd.AllRequestFilter$FilterProxy.doFilter(AllRequestFilter.java:138)
	at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:82)
	at com.google.gerrit.httpd.RequestContextFilter.doFilter(RequestContextFilter.java:75)
	at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:82)
	at com.google.gerrit.pgm.http.jetty.ProjectQoSFilter.doFilter(ProjectQoSFilter.java:131)
	at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:82)
	at com.google.inject.servlet.ManagedFilterPipeline.dispatch(ManagedFilterPipeline.java:119)
	at com.google.inject.servlet.GuiceFilter$1.call(GuiceFilter.java:133)
	at com.google.inject.servlet.GuiceFilter$1.call(GuiceFilter.java:130)
	at com.google.inject.servlet.GuiceFilter$Context.call(GuiceFilter.java:203)
	at com.google.inject.servlet.GuiceFilter.doFilter(GuiceFilter.java:130)
	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1652)
	at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:585)
	at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:221)
	at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1127)
	at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:515)
	at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185)
	at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1061)
	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:97)
	at org.eclipse.jetty.server.handler.RequestLogHandler.handle(RequestLogHandler.java:95)
	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:97)
	at org.eclipse.jetty.server.Server.handleAsync(Server.java:549)
	at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:317)
	at org.eclipse.jetty.server.HttpChannel.run(HttpChannel.java:261)
	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:635)
	at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:555)
	at java.lang.Thread.run(Thread.java:745)



Back to the top