ArrayIndexOutOfBoundsException when

Hey,

We are getting the following exception when trying to persist a record:

Caused by: java.lang.ArrayIndexOutOfBoundsException: Histogram recorded value cannot be negative. at com.couchbase.client.core.deps.org.HdrHistogram.AbstractHistogram.countsArrayIndex(AbstractHistogram.java:2090) Suppressed: reactor.core.publisher.FluxOnAssembly$OnAssemblyException: Error has been observed at the following site(s): *____________________ ⇢ at com.couchbase.client.core.Reactor$MyLittleAssemblyFactory.callOnAssembly(Reactor.java:202) |_ Mono.doFinally ⇢ at com.couchbase.client.core.Reactor.wrap(Reactor.java:63) |_ Mono.onErrorResume ⇢ at com.couchbase.client.core.Reactor.wrap(Reactor.java:69) |_ ⇢ at com.couchbase.client.java.ReactiveCollection.lambda$upsert$13(ReactiveCollection.java:494) *__________Mono.error ⇢ at com.couchbase.client.core.Reactor.lambda$wrap$1(Reactor.java:73) *__________Mono.defer ⇢ at com.couchbase.client.java.ReactiveCollection.upsert(ReactiveCollection.java:490) |_ Mono.flatMap ⇢ at org.springframework.data.couchbase.core.ReactiveUpsertByIdOperationSupport$ReactiveUpsertByIdSupport.lambda$one$2(ReactiveUpsertByIdOperationSupport.java:88) *________Mono.flatMap ⇢ at org.springframework.data.couchbase.core.ReactiveUpsertByIdOperationSupport$ReactiveUpsertByIdSupport.one(ReactiveUpsertByIdOperationSupport.java:85) |_ Mono.onErrorMap ⇢ at org.springframework.data.couchbase.core.ReactiveUpsertByIdOperationSupport$ReactiveUpsertByIdSupport.one(ReactiveUpsertByIdOperationSupport.java:90) |_ ⇢ at org.springframework.data.couchbase.repository.support.SimpleReactiveCouchbaseRepository.save(SimpleReactiveCouchbaseRepository.java:83) *________Flux.flatMap ⇢ at org.springframework.data.couchbase.repository.support.SimpleReactiveCouchbaseRepository.saveAll(SimpleReactiveCouchbaseRepository.java:94) *______Flux.usingWhen ⇢ at org.springframework.data.repository.core.support.RepositoryMethodInvoker$ReactiveInvocationListenerDecorator.decorate(RepositoryMethodInvoker.java:242) |_ Flux.name ⇢ at com.nexmo.connectors.metrics.ReactiveMetrics.addMetricToFlux(ReactiveMetrics.java:33) |_ Flux.tag ⇢ at com.nexmo.connectors.metrics.ReactiveMetrics.addMetricToFlux(ReactiveMetrics.java:33) |_ Flux.metrics ⇢ at com.nexmo.connectors.metrics.ReactiveMetrics.addMetricToFlux(ReactiveMetrics.java:33) |_ Flux.doOnNext ⇢ at com.nexmo.connectors.association.AssociationPersistenceImpl.persistAssociation(AssociationPersistenceImpl.java:61) |_ Flux.doOnError ⇢ at com.nexmo.connectors.association.AssociationPersistenceImpl.persistAssociation(AssociationPersistenceImpl.java:62) |_ Flux.retryWhen ⇢ at com.nexmo.connectors.association.AssociationPersistenceImpl.persistAssociation(AssociationPersistenceImpl.java:63) *__________Mono.error ⇢ at reactor.util.retry.RetryBackoffSpec.lambda$generateCompanion$4(RetryBackoffSpec.java:553) *______Flux.concatMap ⇢ at reactor.util.retry.RetryBackoffSpec.generateCompanion(RetryBackoffSpec.java:542) Original Stack Trace: at com.couchbase.client.core.deps.org.HdrHistogram.AbstractHistogram.countsArrayIndex(AbstractHistogram.java:2090) at com.couchbase.client.core.deps.org.HdrHistogram.AbstractHistogram.recordSingleValue(AbstractHistogram.java:427) at com.couchbase.client.core.deps.org.HdrHistogram.AbstractHistogram.recordValue(AbstractHistogram.java:346) at com.couchbase.client.core.deps.org.LatencyUtils.LatencyStats.recordLatency(LatencyStats.java:201) at com.couchbase.client.core.cnc.metrics.AggregatingValueRecorder.recordValue(AggregatingValueRecorder.java:46) at com.couchbase.client.core.msg.RequestContext.logicallyComplete(RequestContext.java:216) at com.couchbase.client.java.kv.DurabilityUtils.lambda$wrapWithDurability$2(DurabilityUtils.java:58) at java.base/java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:859) at java.base/java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire(CompletableFuture.java:837) at java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:506) at java.base/java.util.concurrent.CompletableFuture.complete(CompletableFuture.java:2073) at com.couchbase.client.core.msg.BaseRequest.succeed(BaseRequest.java:154) at com.couchbase.client.core.io.netty.kv.KeyValueMessageHandler.decodeAndComplete(KeyValueMessageHandler.java:387) at com.couchbase.client.core.io.netty.kv.KeyValueMessageHandler.decode(KeyValueMessageHandler.java:366) at com.couchbase.client.core.io.netty.kv.KeyValueMessageHandler.channelRead(KeyValueMessageHandler.java:282) at com.couchbase.client.core.deps.io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) at com.couchbase.client.core.deps.io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) at com.couchbase.client.core.deps.io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357) at com.couchbase.client.core.io.netty.kv.MemcacheProtocolVerificationHandler.channelRead(MemcacheProtocolVerificationHandler.java:85) at com.couchbase.client.core.deps.io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) at com.couchbase.client.core.deps.io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) at com.couchbase.client.core.deps.io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357) at com.couchbase.client.core.deps.io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:324) at com.couchbase.client.core.deps.io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:296) at com.couchbase.client.core.deps.io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) at com.couchbase.client.core.deps.io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) at com.couchbase.client.core.deps.io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357) at com.couchbase.client.core.deps.io.netty.handler.flush.FlushConsolidationHandler.channelRead(FlushConsolidationHandler.java:152) at com.couchbase.client.core.deps.io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) at com.couchbase.client.core.deps.io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) at com.couchbase.client.core.deps.io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357) at com.couchbase.client.core.deps.io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1410) at com.couchbase.client.core.deps.io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) at com.couchbase.client.core.deps.io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) at com.couchbase.client.core.deps.io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:919) at com.couchbase.client.core.deps.io.netty.channel.epoll.AbstractEpollStreamChannel$EpollStreamUnsafe.epollInReady(AbstractEpollStreamChannel.java:795) at com.couchbase.client.core.deps.io.netty.channel.epoll.EpollEventLoop.processReady(EpollEventLoop.java:480) at com.couchbase.client.core.deps.io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:378) at com.couchbase.client.core.deps.io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:986) at com.couchbase.client.core.deps.io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) at com.couchbase.client.core.deps.io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) at java.base/java.lang.Thread.run(Thread.java:829)

We are using spring data couchbase with the following versions:

org.springframework.boot:spring-boot-starter-data-couchbase-reactive:2.6.3
|    |    +--- org.springframework.boot:spring-boot-starter:2.6.3 (*)
|    |    +--- io.projectreactor:reactor-core:3.4.14 (*)
|    |    +--- io.reactivex:rxjava-reactive-streams:1.2.1
|    |    \--- org.springframework.data:spring-data-couchbase:4.3.1
|    |         +--- org.springframework:spring-context-support:5.3.15
|    |         |    +--- org.springframework:spring-beans:5.3.15 (*)
|    |         |    +--- org.springframework:spring-context:5.3.15 (*)
|    |         |    \--- org.springframework:spring-core:5.3.15 (*)
|    |         +--- org.springframework:spring-web:5.3.15 (*)
|    |         +--- org.springframework:spring-tx:5.3.15
|    |         |    +--- org.springframework:spring-beans:5.3.15 (*)
|    |         |    \--- org.springframework:spring-core:5.3.15 (*)
|    |         +--- org.springframework.data:spring-data-commons:2.6.1
|    |         |    +--- org.springframework:spring-core:5.3.15 (*)
|    |         |    +--- org.springframework:spring-beans:5.3.15 (*)
|    |         |    \--- org.slf4j:slf4j-api:1.7.32 -> 1.7.33
|    |         +--- com.couchbase.client:java-client:3.2.4
|    |         |    \--- com.couchbase.client:core-io:2.2.4
|    |         |         +--- io.projectreactor:reactor-core:3.4.12 -> 3.4.14 (*)
|    |         |         \--- org.reactivestreams:reactive-streams:1.0.3
|    |         +--- com.fasterxml.jackson.core:jackson-databind:2.13.1 (*)
|    |         \--- org.slf4j:slf4j-api:1.7.32 -> 1.7.33

It is not clear to us what the cause of the exception is. Does anyone have any idea?

Cheers,
Leon

@Leon_Patmore it looks like in your case System.nanoTime() went backwards which caused a negative value and then the histogram complained. I don’t know why it went backwards, but this is something we need to handle in the SDK in any case.

Any idea what could’ve causes nanoTime going back on your machine?

@Leon_Patmore on which OS and which JDK are you on?

Edit: btw we applied a workaround fix and it will be part of the next release. See https://issues.couchbase.com/browse/JVMCBC-1071

1 Like