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

[Jason Neil]

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)

[Stephen Sifers]

Hello Jason,

Thank you for reporting the actions that took place up until you experienced the error. The error message you provided does give great detail into what occurred and why. I would like to ensure that before we move forward we should be using a stagging or testing instance with your developer license to avoid any corruption or lost data on your production instance. If you’re not familiar with a staging instance, please review How to establish staging server environments for Bitbucket Server

While on your staging instance, I would like you to attempt to index the repo that is having the errors manually using the following CURL:

curl -X POST -H 'Content-Type: application/json' -H 'Accept: application/json' -u <adminUsername>:<adminPassword> http://<bitbucketBaseUrl>/rest/indexing/latest/sync

Workaround located from BSERV-9799

Please let us know if indexing each repo manually helps to resolve the index issue or if you’re still presented with the same error.

Regards,
Stephen Sifers

[Kevin Reynolds]

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?

[Stephen Sifers]

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]

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?