Skip to content

[BUG] DEBUG logging hitting IllegalAccessError and NullPointerException on CosmosAsyncClient init #11589

New issue
New issue
Closed
Closed
[BUG] DEBUG logging hitting IllegalAccessError and NullPointerException on CosmosAsyncClient init#11589
Assignees
David-Noble-at-work
Labels
Cosmoscosmos:v4-itemIndicates this feature will be shipped as part of V4 release train
@olivertowers

Description

@olivertowers
olivertowers
opened on May 29, 2020

Describe the bug
High number of errors are uncovered after initializing CosmosAsyncClient, and fall into 2 categories:

  1. java.lang.IllegalAccessError: com/azure/cosmos/implementation/directconnectivity/rntbd/RntbdToken which occurs shortly after trace: RxDocumentClientImpl|Initializing DocumentClient with serviceEndpoint. The error does not appear to repeat after this point.

  2. NullPointerException in RntbdClientChannelPool.computeLoadFactor. This causes GoneExceptions and a sequence of back-off and retry steps, and this seem to block further operations.

If i switch to INFO log level, we don't see any correlating issue surface and application moves forward as expected.

Exception or Stack Trace

  1. IllegalAccessError
May 29, 2020 11:45:55 AM com.fasterxml.jackson.module.afterburner.ser.OptimizedBeanPropertyWriter _reportProblem
WARNING: Disabling Afterburner serialization for class com.azure.cosmos.implementation.directconnectivity.rntbd.RntbdToken (field #1; mutator com.fasterxml.jackson.module.afterburner.ser.BooleanMethodPropertyWriter), due to access error (type java.lang.IllegalAccessError, message=com/azure/cosmos/implementation/directconnectivity/rntbd/RntbdToken)

java.lang.IllegalAccessError: com/azure/cosmos/implementation/directconnectivity/rntbd/RntbdToken
        at com.azure.cosmos.implementation.directconnectivity.rntbd.RntbdToken$Access4JacksonSerializer168f725c.booleanGetter(com/azure/cosmos/implementation/directconnectivity/rntbd/RntbdToken$Access4JacksonSerializer.java)
        at com.fasterxml.jackson.module.afterburner.ser.BooleanMethodPropertyWriter.serializeAsField(BooleanMethodPropertyWriter.java:55)
        at com.fasterxml.jackson.databind.ser.std.BeanSerializerBase.serializeFields(BeanSerializerBase.java:722)
        at com.fasterxml.jackson.databind.ser.BeanSerializer.serialize(BeanSerializer.java:166)
        at com.fasterxml.jackson.databind.ser.BeanPropertyWriter.serializeAsField(BeanPropertyWriter.java:727)
        at com.fasterxml.jackson.module.afterburner.ser.ObjectFieldPropertyWriter.serializeAsField(ObjectFieldPropertyWriter.java:40)
        at com.fasterxml.jackson.databind.ser.std.BeanSerializerBase.serializeFields(BeanSerializerBase.java:722)
        at com.fasterxml.jackson.databind.ser.BeanSerializer.serialize(BeanSerializer.java:166)
        at com.fasterxml.jackson.databind.ser.BeanPropertyWriter.serializeAsField(BeanPropertyWriter.java:727)
        at com.fasterxml.jackson.databind.ser.std.BeanSerializerBase.serializeFields(BeanSerializerBase.java:722)
        at com.fasterxml.jackson.databind.ser.BeanSerializer.serialize(BeanSerializer.java:166)
        at com.fasterxml.jackson.databind.ser.DefaultSerializerProvider._serialize(DefaultSerializerProvider.java:480)
        at com.fasterxml.jackson.databind.ser.DefaultSerializerProvider.serializeValue(DefaultSerializerProvider.java:319)
        at com.fasterxml.jackson.databind.ObjectWriter$Prefetch.serialize(ObjectWriter.java:1433)
        at com.fasterxml.jackson.databind.ObjectWriter._configAndWriteValue(ObjectWriter.java:1135)
        at com.fasterxml.jackson.databind.ObjectWriter.writeValueAsString(ObjectWriter.java:1005)
        at com.azure.cosmos.implementation.directconnectivity.rntbd.RntbdContextRequest.toString(RntbdContextRequest.java:98)
        at org.apache.logging.log4j.message.ParameterFormatter.tryObjectToString(ParameterFormatter.java:607)
        at org.apache.logging.log4j.message.ParameterFormatter.recursiveDeepToString(ParameterFormatter.java:458)
        at org.apache.logging.log4j.message.ParameterFormatter.formatMessage2(ParameterFormatter.java:189)
        at org.apache.logging.log4j.message.ReusableParameterizedMessage.formatTo(ReusableParameterizedMessage.java:329)
        at org.apache.logging.log4j.core.impl.MutableLogEvent.setMessage(MutableLogEvent.java:213)
        at org.apache.logging.log4j.core.impl.ReusableLogEventFactory.createEvent(ReusableLogEventFactory.java:100)
        at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:457)
        at org.apache.logging.log4j.core.config.AwaitCompletionReliabilityStrategy.log(AwaitCompletionReliabilityStrategy.java:82)
        at org.apache.logging.log4j.core.Logger.log(Logger.java:162)
        at org.apache.logging.log4j.spi.AbstractLogger.tryLogMessage(AbstractLogger.java:2190)
        at org.apache.logging.log4j.spi.AbstractLogger.logMessageTrackRecursion(AbstractLogger.java:2144)
        at org.apache.logging.log4j.spi.AbstractLogger.logMessageSafely(AbstractLogger.java:2127)
        at org.apache.logging.log4j.spi.AbstractLogger.logMessage(AbstractLogger.java:2026)
        at org.apache.logging.log4j.spi.AbstractLogger.logIfEnabled(AbstractLogger.java:1899)
        at org.apache.logging.slf4j.Log4jLogger.debug(Log4jLogger.java:129)
        at com.azure.cosmos.implementation.directconnectivity.rntbd.RntbdContextRequestEncoder.encode(RntbdContextRequestEncoder.java:58)
        at com.azure.cosmos.implementation.directconnectivity.rntbd.RntbdContextRequestEncoder.encode(RntbdContextRequestEncoder.java:12)
        at io.netty.handler.codec.MessageToByteEncoder.write(MessageToByteEncoder.java:107)
        at io.netty.channel.CombinedChannelDuplexHandler.write(CombinedChannelDuplexHandler.java:346)
        at com.azure.cosmos.implementation.directconnectivity.rntbd.RntbdContextNegotiator.startRntbdContextRequest(RntbdContextNegotiator.java:80)
        at com.azure.cosmos.implementation.directconnectivity.rntbd.RntbdContextNegotiator.write(RntbdContextNegotiator.java:63)
        at io.netty.channel.AbstractChannelHandlerContext.invokeWrite0(AbstractChannelHandlerContext.java:715)
        at io.netty.channel.AbstractChannelHandlerContext.invokeWrite(AbstractChannelHandlerContext.java:707)
        at io.netty.channel.AbstractChannelHandlerContext.write(AbstractChannelHandlerContext.java:790)
        at io.netty.channel.AbstractChannelHandlerContext.write(AbstractChannelHandlerContext.java:700)
        at io.netty.handler.codec.MessageToByteEncoder.write(MessageToByteEncoder.java:120)
        at io.netty.channel.AbstractChannelHandlerContext.invokeWrite0(AbstractChannelHandlerContext.java:715)
        at io.netty.channel.AbstractChannelHandlerContext.invokeWrite(AbstractChannelHandlerContext.java:707)
        at io.netty.channel.AbstractChannelHandlerContext.write(AbstractChannelHandlerContext.java:790)
        at io.netty.channel.AbstractChannelHandlerContext.write(AbstractChannelHandlerContext.java:700)
        at com.azure.cosmos.implementation.directconnectivity.rntbd.RntbdRequestManager.write(RntbdRequestManager.java:503)
        at io.netty.channel.AbstractChannelHandlerContext.invokeWrite0(AbstractChannelHandlerContext.java:715)
        at io.netty.channel.AbstractChannelHandlerContext.invokeWriteAndFlush(AbstractChannelHandlerContext.java:762)
        at io.netty.channel.AbstractChannelHandlerContext.write(AbstractChannelHandlerContext.java:788)
        at io.netty.channel.AbstractChannelHandlerContext.writeAndFlush(AbstractChannelHandlerContext.java:756)
        at io.netty.channel.AbstractChannelHandlerContext.writeAndFlush(AbstractChannelHandlerContext.java:806)
        at io.netty.channel.DefaultChannelPipeline.writeAndFlush(DefaultChannelPipeline.java:1025)
        at io.netty.channel.AbstractChannel.writeAndFlush(AbstractChannel.java:294)
        at com.azure.cosmos.implementation.directconnectivity.rntbd.RntbdClientChannelPool$AcquireListener.lambda$operationComplete$1(RntbdClientChannelPool.java:1216)
        at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164)
        at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:472)
        at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:497)
        at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989)
        at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
        at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
        at java.lang.Thread.run(Thread.java:748)
  1. NullPointerException
StoreReader|Exception is thrown while doing readMany:
com.azure.cosmos.implementation.GoneException: failed to establish connection to 127.0.0.1:10251: null
        at com.azure.cosmos.implementation.directconnectivity.rntbd.RntbdServiceEndpoint.writeWhenConnected(RntbdServiceEndpoint.java:270) ~[azure-cosmos-4.0.1-beta.3.jar:?]
        Suppressed: reactor.core.publisher.FluxOnAssembly$OnAssemblyException:
Assembly trace from producer [reactor.core.publisher.MonoCompletionStage] :
        reactor.core.publisher.Mono.fromFuture(Mono.java:486)
        com.azure.cosmos.implementation.directconnectivity.RntbdTransportClient.invokeStoreAsync(RntbdTransportClient.java:126)
Error has been observed at the following site(s):
        |_ Mono.fromFuture ? at com.azure.cosmos.implementation.directconnectivity.RntbdTransportClient.invokeStoreAsync(RntbdTransportClient.java:126)
        |_ Mono.doOnCancel ? at com.azure.cosmos.implementation.directconnectivity.RntbdTransportClient.invokeStoreAsync(RntbdTransportClient.java:138)
        |_       Mono.flux ? at com.azure.cosmos.implementation.directconnectivity.StoreReader.readFromReplicas(StoreReader.java:219)
        |_    Flux.flatMap ? at com.azure.cosmos.implementation.directconnectivity.StoreReader.toStoreResult(StoreReader.java:145)
Stack trace:
                at com.azure.cosmos.implementation.directconnectivity.rntbd.RntbdServiceEndpoint.writeWhenConnected(RntbdServiceEndpoint.java:270) ~[azure-cosmos-4.0.1-beta.3.jar:?]
                at com.azure.cosmos.implementation.directconnectivity.rntbd.RntbdServiceEndpoint.write(RntbdServiceEndpoint.java:233) ~[azure-cosmos-4.0.1-beta.3.jar:?]
                at com.azure.cosmos.implementation.directconnectivity.rntbd.RntbdServiceEndpoint.request(RntbdServiceEndpoint.java:180) ~[azure-cosmos-4.0.1-beta.3.jar:?]
                at com.azure.cosmos.implementation.directconnectivity.RntbdTransportClient.invokeStoreAsync(RntbdTransportClient.java:122) ~[azure-cosmos-4.0.1-beta.3.jar:?]
                at com.azure.cosmos.implementation.directconnectivity.TransportClient.invokeResourceOperationAsync(TransportClient.java:21) ~[azure-cosmos-4.0.1-beta.3.jar:?]
                at com.azure.cosmos.implementation.directconnectivity.StoreReader.readFromStoreAsync(StoreReader.java:626) ~[azure-cosmos-4.0.1-beta.3.jar:?]
                at com.azure.cosmos.implementation.directconnectivity.StoreReader.readFromReplicas(StoreReader.java:212) ~[azure-cosmos-4.0.1-beta.3.jar:?]
                at com.azure.cosmos.implementation.directconnectivity.StoreReader.lambda$readMultipleReplicasInternalAsync$10(StoreReader.java:394) ~[azure-cosmos-4.0.1-beta.3.jar:?]
                at reactor.core.publisher.FluxDefer.subscribe(FluxDefer.java:46) ~[reactor-core-3.3.5.RELEASE.jar:3.3.5.RELEASE]
                at reactor.core.publisher.InternalFluxOperator.subscribe(InternalFluxOperator.java:62) ~[reactor-core-3.3.5.RELEASE.jar:3.3.5.RELEASE]
                at reactor.core.publisher.FluxRepeatPredicate$RepeatPredicateSubscriber.resubscribe(FluxRepeatPredicate.java:113) ~[reactor-core-3.3.5.RELEASE.jar:3.3.5.RELEASE]
                at reactor.core.publisher.FluxRepeatPredicate.subscribeOrReturn(FluxRepeatPredicate.java:49) ~[reactor-core-3.3.5.RELEASE.jar:3.3.5.RELEASE]
                at reactor.core.publisher.Mono.subscribe(Mono.java:4203) ~[reactor-core-3.3.5.RELEASE.jar:3.3.5.RELEASE]
                at reactor.core.publisher.FluxConcatArray$ConcatArraySubscriber.onComplete(FluxConcatArray.java:207) ~[reactor-core-3.3.5.RELEASE.jar:3.3.5.RELEASE]
                at reactor.core.publisher.FluxConcatArray.subscribe(FluxConcatArray.java:80) ~[reactor-core-3.3.5.RELEASE.jar:3.3.5.RELEASE]
                at reactor.core.publisher.InternalFluxOperator.subscribe(InternalFluxOperator.java:62) ~[reactor-core-3.3.5.RELEASE.jar:3.3.5.RELEASE]
                at reactor.core.publisher.FluxDefer.subscribe(FluxDefer.java:54) ~[reactor-core-3.3.5.RELEASE.jar:3.3.5.RELEASE]
                at reactor.core.publisher.Flux.subscribe(Flux.java:8325) ~[reactor-core-3.3.5.RELEASE.jar:3.3.5.RELEASE]
                at reactor.core.publisher.FluxSwitchIfEmpty$SwitchIfEmptySubscriber.onComplete(FluxSwitchIfEmpty.java:75) ~[reactor-core-3.3.5.RELEASE.jar:3.3.5.RELEASE]
                at reactor.core.publisher.Operators.complete(Operators.java:135) ~[reactor-core-3.3.5.RELEASE.jar:3.3.5.RELEASE]
                at reactor.core.publisher.FluxEmpty.subscribe(FluxEmpty.java:41) ~[reactor-core-3.3.5.RELEASE.jar:3.3.5.RELEASE]
                at reactor.core.publisher.Flux.subscribe(Flux.java:8325) ~[reactor-core-3.3.5.RELEASE.jar:3.3.5.RELEASE]
                at reactor.core.publisher.FluxFlatMap$FlatMapMain.onNext(FluxFlatMap.java:418) ~[reactor-core-3.3.5.RELEASE.jar:3.3.5.RELEASE]
                at reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.onNext(FluxMapFuseable.java:121) ~[reactor-core-3.3.5.RELEASE.jar:3.3.5.RELEASE]
                at reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.onNext(FluxMapFuseable.java:121) ~[reactor-core-3.3.5.RELEASE.jar:3.3.5.RELEASE]
                at reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.onNext(FluxMapFuseable.java:121) ~[reactor-core-3.3.5.RELEASE.jar:3.3.5.RELEASE]
                at reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.onNext(FluxMapFuseable.java:121) ~[reactor-core-3.3.5.RELEASE.jar:3.3.5.RELEASE]
                at reactor.core.publisher.Operators$MonoSubscriber.complete(Operators.java:1755) ~[reactor-core-3.3.5.RELEASE.jar:3.3.5.RELEASE]
                at reactor.core.publisher.MonoFlatMap$FlatMapMain.onNext(MonoFlatMap.java:144) ~[reactor-core-3.3.5.RELEASE.jar:3.3.5.RELEASE]
                at reactor.core.publisher.Operators$MonoSubscriber.complete(Operators.java:1755) ~[reactor-core-3.3.5.RELEASE.jar:3.3.5.RELEASE]
                at reactor.core.publisher.MonoFlatMap$FlatMapMain.onNext(MonoFlatMap.java:144) ~[reactor-core-3.3.5.RELEASE.jar:3.3.5.RELEASE]
                at reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.onNext(FluxMapFuseable.java:121) ~[reactor-core-3.3.5.RELEASE.jar:3.3.5.RELEASE]
                at reactor.core.publisher.MonoPeekTerminal$MonoTerminalPeekSubscriber.onNext(MonoPeekTerminal.java:173) ~[reactor-core-3.3.5.RELEASE.jar:3.3.5.RELEASE]
                at reactor.core.publisher.FluxMapFuseable$MapFuseableConditionalSubscriber.onNext(FluxMapFuseable.java:287) ~[reactor-core-3.3.5.RELEASE.jar:3.3.5.RELEASE]
                at reactor.core.publisher.FluxMapFuseable$MapFuseableConditionalSubscriber.onNext(FluxMapFuseable.java:287) ~[reactor-core-3.3.5.RELEASE.jar:3.3.5.RELEASE]
                at reactor.core.publisher.Operators$MonoSubscriber.complete(Operators.java:1755) ~[reactor-core-3.3.5.RELEASE.jar:3.3.5.RELEASE]
                at reactor.core.publisher.MonoFlatMap$FlatMapInner.onNext(MonoFlatMap.java:241) ~[reactor-core-3.3.5.RELEASE.jar:3.3.5.RELEASE]
                at reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.onNext(FluxMapFuseable.java:121) ~[reactor-core-3.3.5.RELEASE.jar:3.3.5.RELEASE]
                at reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.onNext(FluxMapFuseable.java:121) ~[reactor-core-3.3.5.RELEASE.jar:3.3.5.RELEASE]
                at reactor.core.publisher.FluxSwitchIfEmpty$SwitchIfEmptySubscriber.onNext(FluxSwitchIfEmpty.java:67) ~[reactor-core-3.3.5.RELEASE.jar:3.3.5.RELEASE]
                at reactor.core.publisher.FluxHandleFuseable$HandleFuseableSubscriber.onNext(FluxHandleFuseable.java:178) ~[reactor-core-3.3.5.RELEASE.jar:3.3.5.RELEASE]
                at reactor.core.publisher.FluxMapFuseable$MapFuseableConditionalSubscriber.onNext(FluxMapFuseable.java:287) ~[reactor-core-3.3.5.RELEASE.jar:3.3.5.RELEASE]
                at reactor.core.publisher.FluxDoFinally$DoFinallySubscriber.onNext(FluxDoFinally.java:123) ~[reactor-core-3.3.5.RELEASE.jar:3.3.5.RELEASE]
                at reactor.core.publisher.FluxHandleFuseable$HandleFuseableSubscriber.onNext(FluxHandleFuseable.java:178) ~[reactor-core-3.3.5.RELEASE.jar:3.3.5.RELEASE]
                at reactor.core.publisher.FluxContextStart$ContextStartSubscriber.onNext(FluxContextStart.java:96) ~[reactor-core-3.3.5.RELEASE.jar:3.3.5.RELEASE]
                at reactor.core.publisher.Operators$MonoSubscriber.complete(Operators.java:1755) ~[reactor-core-3.3.5.RELEASE.jar:3.3.5.RELEASE]
                at reactor.core.publisher.MonoCollectList$MonoCollectListSubscriber.onComplete(MonoCollectList.java:121) ~[reactor-core-3.3.5.RELEASE.jar:3.3.5.RELEASE]
                at reactor.core.publisher.FluxPeekFuseable$PeekFuseableSubscriber.onComplete(FluxPeekFuseable.java:270) ~[reactor-core-3.3.5.RELEASE.jar:3.3.5.RELEASE]
                at reactor.core.publisher.FluxMap$MapSubscriber.onComplete(FluxMap.java:136) [reactor-core-3.3.5.RELEASE.jar:3.3.5.RELEASE]
                at reactor.netty.channel.FluxReceive.terminateReceiver(FluxReceive.java:419) [reactor-netty-0.9.5.RELEASE.jar:0.9.5.RELEASE]
                at reactor.netty.channel.FluxReceive.drainReceiver(FluxReceive.java:209) [reactor-netty-0.9.5.RELEASE.jar:0.9.5.RELEASE]
                at reactor.netty.channel.FluxReceive.onInboundComplete(FluxReceive.java:367) [reactor-netty-0.9.5.RELEASE.jar:0.9.5.RELEASE]
                at reactor.netty.channel.ChannelOperations.onInboundComplete(ChannelOperations.java:363) [reactor-netty-0.9.5.RELEASE.jar:0.9.5.RELEASE]
                at reactor.netty.channel.ChannelOperations.terminate(ChannelOperations.java:412) [reactor-netty-0.9.5.RELEASE.jar:0.9.5.RELEASE]
                at reactor.netty.http.client.HttpClientOperations.onInboundNext(HttpClientOperations.java:585) [reactor-netty-0.9.5.RELEASE.jar:0.9.5.RELEASE]
                at reactor.netty.channel.ChannelOperationsHandler.channelRead(ChannelOperationsHandler.java:90) [reactor-netty-0.9.5.RELEASE.jar:0.9.5.RELEASE]
                at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:377) [netty-transport-4.1.46.Final.jar:4.1.46.Final]
                at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:363) [netty-transport-4.1.46.Final.jar:4.1.46.Final]
                at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:355) [netty-transport-4.1.46.Final.jar:4.1.46.Final]
                at io.netty.channel.CombinedChannelDuplexHandler$DelegatingChannelHandlerContext.fireChannelRead(CombinedChannelDuplexHandler.java:436) [netty-transport-4.1.46.Final.jar:4.1.46.Final]
                at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:321) [netty-codec-4.1.46.Final.jar:4.1.46.Final]
                at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:295) [netty-codec-4.1.46.Final.jar:4.1.46.Final]
                at io.netty.channel.CombinedChannelDuplexHandler.channelRead(CombinedChannelDuplexHandler.java:251) [netty-transport-4.1.46.Final.jar:4.1.46.Final]
                at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:377) [netty-transport-4.1.46.Final.jar:4.1.46.Final]
                at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:363) [netty-transport-4.1.46.Final.jar:4.1.46.Final]
                at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:355) [netty-transport-4.1.46.Final.jar:4.1.46.Final]
                at io.netty.handler.ssl.SslHandler.unwrap(SslHandler.java:1484) [netty-handler-4.1.46.Final.jar:4.1.46.Final]
                at io.netty.handler.ssl.SslHandler.decodeJdkCompatible(SslHandler.java:1233) [netty-handler-4.1.46.Final.jar:4.1.46.Final]
                at io.netty.handler.ssl.SslHandler.decode(SslHandler.java:1280) [netty-handler-4.1.46.Final.jar:4.1.46.Final]
                at io.netty.handler.codec.ByteToMessageDecoder.decodeRemovalReentryProtection(ByteToMessageDecoder.java:498) [netty-codec-4.1.46.Final.jar:4.1.46.Final]
                at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:437) [netty-codec-4.1.46.Final.jar:4.1.46.Final]
                at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:276) [netty-codec-4.1.46.Final.jar:4.1.46.Final]
                at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:377) [netty-transport-4.1.46.Final.jar:4.1.46.Final]
                at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:363) [netty-transport-4.1.46.Final.jar:4.1.46.Final]
                at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:355) [netty-transport-4.1.46.Final.jar:4.1.46.Final]
                at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1410) [netty-transport-4.1.46.Final.jar:4.1.46.Final]
                at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:377) [netty-transport-4.1.46.Final.jar:4.1.46.Final]
                at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:363) [netty-transport-4.1.46.Final.jar:4.1.46.Final]
                at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:919) [netty-transport-4.1.46.Final.jar:4.1.46.Final]
                at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:163) [netty-transport-4.1.46.Final.jar:4.1.46.Final]
                at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:714) [netty-transport-4.1.46.Final.jar:4.1.46.Final]
                at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:650) [netty-transport-4.1.46.Final.jar:4.1.46.Final]
                at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:576) [netty-transport-4.1.46.Final.jar:4.1.46.Final]
                at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:493) [netty-transport-4.1.46.Final.jar:4.1.46.Final]
                at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989) [netty-common-4.1.46.Final.jar:4.1.46.Final]
                at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) [netty-common-4.1.46.Final.jar:4.1.46.Final]
                at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [netty-common-4.1.46.Final.jar:4.1.46.Final]
                at java.lang.Thread.run(Thread.java:748) [?:1.8.0_131]
Caused by: java.lang.NullPointerException
        at com.azure.cosmos.implementation.directconnectivity.rntbd.RntbdClientChannelPool.computeLoadFactor(RntbdClientChannelPool.java:626) ~[azure-cosmos-4.0.1-beta.3.jar:?]
        at com.azure.cosmos.implementation.directconnectivity.rntbd.RntbdClientChannelPool.acquireChannel(RntbdClientChannelPool.java:519) ~[azure-cosmos-4.0.1-beta.3.jar:?]
        at com.azure.cosmos.implementation.directconnectivity.rntbd.RntbdClientChannelPool.lambda$acquire$0(RntbdClientChannelPool.java:339) ~[azure-cosmos-4.0.1-beta.3.jar:?]
        at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164) ~[netty-common-4.1.46.Final.jar:4.1.46.Final]
        at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:472) ~[netty-common-4.1.46.Final.jar:4.1.46.Final]
        at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:500) [netty-transport-4.1.46.Final.jar:4.1.46.Final]
        at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989) [netty-common-4.1.46.Final.jar:4.1.46.Final]
        at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) [netty-common-4.1.46.Final.jar:4.1.46.Final]
        at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [netty-common-4.1.46.Final.jar:4.1.46.Final]
        at java.lang.Thread.run(Thread.java:748) [?:1.8.0_131]

To Reproduce

  1. Use module com.azure:azure-cosmos:4.0.1-beta.3
  2. Create CosmosAsyncClient:
        return new CosmosClientBuilder()
            .endpoint(cosmosDBEndpoint)
            .key(cosmosDBKey)
            .directMode()
            .connectionReuseAcrossClientsEnabled(true)
            .contentResponseOnWriteEnabled(true)
            .consistencyLevel(ConsistencyLevel.EVENTUAL)
            .buildAsyncClient();
  1. Enable log4j level debug to loggers under com.azure:
  <Logger name="com.azure" level="debug">
    <AppenderRef ref="Console"/>
  </Logger>
  1. Attempt to do any read/write operation with the client.

Environment and runtime:

  • OS: Win10
  • JDK: 1.8.0_131
  • Running JUnit tests with Maven.

Code Snippet
See above repro steps.

Expected behavior
Be able to enable debug log level on SDK without hitting exceptions/errors that appear specific to debug level only.

Screenshots
If applicable, add screenshots to help explain your problem.

Setup (please complete the following information):

  • OS: Win10
  • Maven: Running JUnit tests
  • JDK: 1.8.0_131
  • azure-cosmos: 4.0.1-beta.3

Information Checklist

  • Bug Description Added
  • Repro Steps Added
  • Setup information Added

Metadata

Metadata

Assignees

Labels

Cosmoscosmos:v4-itemIndicates this feature will be shipped as part of V4 release train

Type

No type

Projects

No projects

Milestone

No milestone

Relationships

None yet

Development

No branches or pull requests

Issue actions