Indexing for repository with id failed and should be retried Caused by: java.util.concurrent.Executi

Question

Hi,

I've upgaded to bitbucket 5.15.2 and some (not all) repositories report timing out when indexing.  Is this  a config issue where I can increase to allow index to finish without timeout?

Java error below:

2019-03-13 18:42:04,464 ERROR [io-pump:thread-1] c.a.b.i.s.i.e.DefaultIndexEventWorker Indexing - Failed for repository CPE/ikanos_ref (id: 231) with error: Indexing for repository with id 231 failed and should be retried
com.atlassian.bitbucket.internal.search.indexing.exceptions.IndexException: Indexing for repository with id 231 failed and should be retried
at com.atlassian.bitbucket.internal.search.indexing.indexer.DefaultIndexService.lambda$updateIndexStateForError$26(DefaultIndexService.java:453)
at rx.internal.operators.OnSubscribeMap$MapSubscriber.onNext(OnSubscribeMap.java:69)
at rx.internal.operators.OperatorOnErrorResumeNextViaFunction$4.onNext(OperatorOnErrorResumeNextViaFunction.java:154)
at rx.internal.operators.OperatorMerge$MergeSubscriber.emitScalar(OperatorMerge.java:511)
at rx.internal.operators.OperatorMerge$MergeSubscriber.tryEmit(OperatorMerge.java:466)
at rx.internal.operators.OperatorMerge$MergeSubscriber.onNext(OperatorMerge.java:244)
at rx.internal.operators.OperatorMerge$MergeSubscriber.onNext(OperatorMerge.java:148)
at rx.internal.operators.OnSubscribeMap$MapSubscriber.onNext(OnSubscribeMap.java:77)
at rx.internal.operators.OperatorMerge$MergeSubscriber.emitScalar(OperatorMerge.java:511)
at rx.internal.operators.OperatorMerge$MergeSubscriber.tryEmit(OperatorMerge.java:466)
at rx.internal.operators.OperatorMerge$MergeSubscriber.onNext(OperatorMerge.java:244)
at rx.internal.operators.OperatorMerge$MergeSubscriber.onNext(OperatorMerge.java:148)
at rx.internal.operators.OnSubscribeMap$MapSubscriber.onNext(OnSubscribeMap.java:77)
at rx.internal.producers.SingleProducer.request(SingleProducer.java:65)
at rx.Subscriber.setProducer(Subscriber.java:211)
at rx.internal.operators.OnSubscribeMap$MapSubscriber.setProducer(OnSubscribeMap.java:102)
at rx.internal.operators.OnSubscribeToObservableFuture$ToObservableFuture.call(OnSubscribeToObservableFuture.java:75)
at rx.internal.operators.OnSubscribeToObservableFuture$ToObservableFuture.call(OnSubscribeToObservableFuture.java:43)
at rx.Observable.unsafeSubscribe(Observable.java:10327)
at rx.internal.operators.OnSubscribeMap.call(OnSubscribeMap.java:48)
at rx.internal.operators.OnSubscribeMap.call(OnSubscribeMap.java:33)
at rx.internal.operators.OnSubscribeLift.call(OnSubscribeLift.java:48)
at rx.internal.operators.OnSubscribeLift.call(OnSubscribeLift.java:30)
at rx.Observable.unsafeSubscribe(Observable.java:10327)
at rx.internal.operators.OnSubscribeMap.call(OnSubscribeMap.java:48)
at rx.internal.operators.OnSubscribeMap.call(OnSubscribeMap.java:33)
at rx.internal.operators.OnSubscribeLift.call(OnSubscribeLift.java:48)
at rx.internal.operators.OnSubscribeLift.call(OnSubscribeLift.java:30)
at rx.internal.operators.OnSubscribeLift.call(OnSubscribeLift.java:48)
at rx.internal.operators.OnSubscribeLift.call(OnSubscribeLift.java:30)
at rx.Observable.unsafeSubscribe(Observable.java:10327)
at rx.internal.operators.OnSubscribeMap.call(OnSubscribeMap.java:48)
at rx.internal.operators.OnSubscribeMap.call(OnSubscribeMap.java:33)
at rx.internal.operators.OnSubscribeLift.call(OnSubscribeLift.java:48)
at rx.internal.operators.OnSubscribeLift.call(OnSubscribeLift.java:30)
at rx.Observable.unsafeSubscribe(Observable.java:10327)
at rx.internal.operators.OperatorMerge$MergeSubscriber.onNext(OperatorMerge.java:248)
at rx.internal.operators.OperatorMerge$MergeSubscriber.onNext(OperatorMerge.java:148)
at rx.internal.operators.OperatorMapNotification$MapNotificationSubscriber.tryEmit(OperatorMapNotification.java:152)
at rx.internal.operators.OperatorMapNotification$MapNotificationSubscriber.onError(OperatorMapNotification.java:110)
at rx.internal.operators.DeferredScalarSubscriber.onError(DeferredScalarSubscriber.java:67)
at rx.internal.operators.OperatorMerge$MergeSubscriber.reportError(OperatorMerge.java:266)
at rx.internal.operators.OperatorMerge$MergeSubscriber.checkTerminate(OperatorMerge.java:818)
at rx.internal.operators.OperatorMerge$MergeSubscriber.emitLoop(OperatorMerge.java:579)
at rx.internal.operators.OperatorMerge$MergeSubscriber.emit(OperatorMerge.java:568)
at rx.internal.operators.OperatorMerge$InnerSubscriber.onError(OperatorMerge.java:855)
at rx.internal.operators.OnSubscribeMap$MapSubscriber.onError(OnSubscribeMap.java:88)
at rx.internal.operators.OperatorMerge$MergeSubscriber.reportError(OperatorMerge.java:266)
at rx.internal.operators.OperatorMerge$MergeSubscriber.checkTerminate(OperatorMerge.java:818)
at rx.internal.operators.OperatorMerge$MergeSubscriber.emitLoop(OperatorMerge.java:579)
at rx.internal.operators.OperatorMerge$MergeSubscriber.emit(OperatorMerge.java:568)
at rx.internal.operators.OperatorMerge$MergeSubscriber.onError(OperatorMerge.java:276)
at rx.internal.operators.OnSubscribeMap$MapSubscriber.onError(OnSubscribeMap.java:88)
at rx.exceptions.Exceptions.throwOrReport(Exceptions.java:212)
at rx.internal.operators.OnSubscribeToObservableFuture$ToObservableFuture.call(OnSubscribeToObservableFuture.java:86)
at rx.internal.operators.OnSubscribeToObservableFuture$ToObservableFuture.call(OnSubscribeToObservableFuture.java:43)
at rx.Observable.unsafeSubscribe(Observable.java:10327)
at rx.internal.operators.OnSubscribeMap.call(OnSubscribeMap.java:48)
at rx.internal.operators.OnSubscribeMap.call(OnSubscribeMap.java:33)
at rx.internal.operators.OnSubscribeLift.call(OnSubscribeLift.java:48)
at rx.internal.operators.OnSubscribeLift.call(OnSubscribeLift.java:30)
at rx.Observable.unsafeSubscribe(Observable.java:10327)
at rx.internal.operators.OnSubscribeMap.call(OnSubscribeMap.java:48)
at rx.internal.operators.OnSubscribeMap.call(OnSubscribeMap.java:33)
at rx.Observable.unsafeSubscribe(Observable.java:10327)
at rx.internal.operators.OperatorMerge$MergeSubscriber.onNext(OperatorMerge.java:248)
at rx.internal.operators.OperatorMerge$MergeSubscriber.onNext(OperatorMerge.java:148)
at rx.internal.operators.OnSubscribeMap$MapSubscriber.onNext(OnSubscribeMap.java:77)
at com.atlassian.bitbucket.internal.search.indexing.indexer.BufferOnSizeAndCount$BufferingSubscriber.onNext(BufferOnSizeAndCount.java:96)
at com.atlassian.bitbucket.internal.search.indexing.indexer.BufferOnSizeAndCount$BufferingSubscriber.onNext(BufferOnSizeAndCount.java:47)
at com.atlassian.bitbucket.internal.search.indexing.indexer.BlockProducerOnNext$1.onNext(BlockProducerOnNext.java:73)
at com.atlassian.bitbucket.internal.search.indexing.content.ObserverBulkContentCallback.onFile(ObserverBulkContentCallback.java:110)
at com.atlassian.stash.internal.scm.git.bulk.BulkBatchCatFileHandler.lambda$process$0(BulkBatchCatFileHandler.java:56)
at com.atlassian.stash.internal.scm.git.command.catfile.AbstractBatchCatFileHandler.requestObject(AbstractBatchCatFileHandler.java:106)
at com.atlassian.stash.internal.scm.git.bulk.BulkBatchCatFileHandler.process(BulkBatchCatFileHandler.java:52)
at com.atlassian.stash.internal.scm.git.command.catfile.AbstractBatchCatFileHandler.process(AbstractBatchCatFileHandler.java:65)
at com.atlassian.bitbucket.io.AbstractCommandInputOutputHandler.process(AbstractCommandInputOutputHandler.java:42)
at com.atlassian.bitbucket.scm.SummarizingProcessHandler$DelegatingInputStreamHandler.process(SummarizingProcessHandler.java:184)
at com.atlassian.bitbucket.scm.SummarizingProcessHandler$DelegatingInputStreamHandler.process(SummarizingProcessHandler.java:166)
at com.atlassian.bitbucket.scm.SummarizingProcessHandler.processOutput(SummarizingProcessHandler.java:90)
at com.atlassian.utils.process.ExternalProcessImpl$StdoutHandler.handle(ExternalProcessImpl.java:794)
at com.atlassian.utils.process.ExternalProcessImpl$HandlerLatchedRunnable.doTask(ExternalProcessImpl.java:731)
at com.atlassian.utils.process.LatchedRunnable.run(LatchedRunnable.java:158)
at com.atlassian.utils.process.ExternalProcessImpl$AsynchronousHandlerLatchedRunnable.run(ExternalProcessImpl.java:700)
at com.atlassian.stash.internal.concurrent.DefaultTransferableStateManager$StateTransferringRunnable.run(DefaultTransferableStateManager.java:166)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.lang.Thread.run(Thread.java:748)
... 1 frame trimmed
Caused by: java.util.concurrent.ExecutionException: java.net.SocketTimeoutException
at java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:357)
at java.util.concurrent.CompletableFuture.get(CompletableFuture.java:1895)
at rx.internal.operators.OnSubscribeToObservableFuture$ToObservableFuture.call(OnSubscribeToObservableFuture.java:74)
... 33 common frames omitted
Caused by: java.net.SocketTimeoutException: null
at org.apache.http.nio.protocol.HttpAsyncRequestExecutor.timeout(HttpAsyncRequestExecutor.java:375)
at org.apache.http.impl.nio.client.InternalIODispatch.onTimeout(InternalIODispatch.java:92)
at org.apache.http.impl.nio.client.InternalIODispatch.onTimeout(InternalIODispatch.java:39)
at org.apache.http.impl.nio.reactor.AbstractIODispatch.timeout(AbstractIODispatch.java:175)
at org.apache.http.impl.nio.reactor.BaseIOReactor.sessionTimedOut(BaseIOReactor.java:263)
at org.apache.http.impl.nio.reactor.AbstractIOReactor.timeoutCheck(AbstractIOReactor.java:492)
at org.apache.http.impl.nio.reactor.BaseIOReactor.validate(BaseIOReactor.java:213)
at org.apache.http.impl.nio.reactor.AbstractIOReactor.execute(AbstractIOReactor.java:280)
at org.apache.http.impl.nio.reactor.BaseIOReactor.execute(BaseIOReactor.java:104)
at org.apache.http.impl.nio.reactor.AbstractMultiworkerIOReactor$Worker.run(AbstractMultiworkerIOReactor.java:588)
at java.lang.Thread.run(Thread.java:748)

Kevin Reynolds_i19z6l · Answer

Done.  
So I assume that if I see no errors in the log then the re-index was successful?

Does atlassian know why it fails during upgrades?

Stephen Sifers · Answer

Hello,

Since you're making a REST API call to start the reindex there will not be a response to let you know it's completed. This is due to how the REST API interacts with transactions.

Additionally, per our Guidelines, we ask you to change your display name within Community as this can be misleading to other customers. While you are most certainly an Admin of the Atlassian products, your name can be perceived as an admin at Atlassian.

Regards,
Stephen Sifers

Kevin Reynolds_i19z6l · Answer

Hello

We too also had this problem 
I ran the index manually as you suggest - in the logs it indicated that it was starting the manual index but I never got any indication that it completed - I only surmise it had because of CPU activity dropping off.   Should it return a message when complete?