Azure / azure-cosmosdb-java

Java Async SDK for SQL API of Azure Cosmos DB
MIT License
54 stars 61 forks source link

Uninformative warning messages #335

Open vchernogorov opened 4 years ago

vchernogorov commented 4 years ago

I have a web API with CosmosDB integrated. Sometimes in logs I see lots of uninformative warnings with a stack trace coming from RntbdRequestManager class:

2020-05-12T15:25:29.744899838Z 2020-05-12 15:25:29.744  WARN 124 --- [osEventLoop-3-1] c.a.d.c.i.d.rntbd.RntbdRequestManager    : ChannelHandlerContext(RntbdRequestManager#0, [id: 0x71439764, L:/172.16.3.2:37762 ! R:byaprdddc01-docdb-1.documents.azure.com/13.93.156.125:11564]) channelUnregistered exceptionally
2020-05-12T15:25:29.945621415Z 2020-05-12 15:25:29.945  WARN 124 --- [osEventLoop-3-1] c.a.d.c.i.d.rntbd.RntbdRequestManager    : ChannelHandlerContext(RntbdRequestManager#0, [id: 0xf0bec5aa, L:/172.16.3.2:46848 - R:byaprdddc01-docdb-1.documents.azure.com/13.93.156.125:11553]) closing due to:
2020-05-12T15:25:29.945702316Z
2020-05-12T15:25:29.945708816Z java.lang.IllegalStateException: null
2020-05-12T15:25:29.945713416Z  at com.google.common.base.Preconditions.checkState(Preconditions.java:491) ~[guava-27.0.1-jre.jar!/:na]
2020-05-12T15:25:29.945718216Z  at com.azure.data.cosmos.internal.directconnectivity.rntbd.RntbdResponse.lambda$release$0(RntbdResponse.java:201) ~[azure-cosmos-3.3.1.jar!/:na]
2020-05-12T15:25:29.945722716Z  at java.base/java.util.concurrent.atomic.AtomicInteger.accumulateAndGet(Unknown Source) ~[na:na]
2020-05-12T15:25:29.945727116Z  at com.azure.data.cosmos.internal.directconnectivity.rntbd.RntbdResponse.release(RntbdResponse.java:184) ~[azure-cosmos-3.3.1.jar!/:na]
2020-05-12T15:25:29.945731616Z  at com.azure.data.cosmos.internal.directconnectivity.rntbd.RntbdResponse.release(RntbdResponse.java:172) ~[azure-cosmos-3.3.1.jar!/:na]
2020-05-12T15:25:29.945745116Z  at com.azure.data.cosmos.internal.directconnectivity.rntbd.RntbdRequestManager.channelRead(RntbdRequestManager.java:193) ~[azure-cosmos-3.3.1.jar!/:na]
2020-05-12T15:25:29.945749716Z  at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) ~[netty-transport-4.1.48.Final.jar!/:4.1.48.Final]
2020-05-12T15:25:29.945754116Z  at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) ~[netty-transport-4.1.48.Final.jar!/:4.1.48.Final]
2020-05-12T15:25:29.945758716Z  at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357) ~[netty-transport-4.1.48.Final.jar!/:4.1.48.Final]
2020-05-12T15:25:29.945763016Z  at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:321) ~[netty-codec-4.1.48.Final.jar!/:4.1.48.Final]
2020-05-12T15:25:29.945767416Z  at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:295) ~[netty-codec-4.1.48.Final.jar!/:4.1.48.Final]
2020-05-12T15:25:29.945778516Z  at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) ~[netty-transport-4.1.48.Final.jar!/:4.1.48.Final]
2020-05-12T15:25:29.945784916Z  at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) ~[netty-transport-4.1.48.Final.jar!/:4.1.48.Final]
2020-05-12T15:25:29.945789416Z  at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357) ~[netty-transport-4.1.48.Final.jar!/:4.1.48.Final]
2020-05-12T15:25:29.945793916Z  at io.netty.channel.CombinedChannelDuplexHandler$DelegatingChannelHandlerContext.fireChannelRead(CombinedChannelDuplexHandler.java:436) ~[netty-transport-4.1.48.Final.jar!/:4.1.48.Final]
2020-05-12T15:25:29.945798216Z  at io.netty.channel.CombinedChannelDuplexHandler.channelRead(CombinedChannelDuplexHandler.java:253) ~[netty-transport-4.1.48.Final.jar!/:4.1.48.Final]
2020-05-12T15:25:29.945802516Z  at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) ~[netty-transport-4.1.48.Final.jar!/:4.1.48.Final]
2020-05-12T15:25:29.945806816Z  at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) ~[netty-transport-4.1.48.Final.jar!/:4.1.48.Final]
2020-05-12T15:25:29.945811116Z  at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357) ~[netty-transport-4.1.48.Final.jar!/:4.1.48.Final]
2020-05-12T15:25:29.945815416Z  at io.netty.handler.timeout.IdleStateHandler.channelRead(IdleStateHandler.java:286) ~[netty-handler-4.1.48.Final.jar!/:4.1.48.Final]
2020-05-12T15:25:29.945819616Z  at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) ~[netty-transport-4.1.48.Final.jar!/:4.1.48.Final]
2020-05-12T15:25:29.945823916Z  at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) ~[netty-transport-4.1.48.Final.jar!/:4.1.48.Final]
2020-05-12T15:25:29.945828216Z  at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357) ~[netty-transport-4.1.48.Final.jar!/:4.1.48.Final]
2020-05-12T15:25:29.945832416Z  at io.netty.handler.ssl.SslHandler.unwrap(SslHandler.java:1486) ~[netty-handler-4.1.48.Final.jar!/:4.1.48.Final]
2020-05-12T15:25:29.945836716Z  at io.netty.handler.ssl.SslHandler.decodeJdkCompatible(SslHandler.java:1235) ~[netty-handler-4.1.48.Final.jar!/:4.1.48.Final]
2020-05-12T15:25:29.945841316Z  at io.netty.handler.ssl.SslHandler.decode(SslHandler.java:1282) ~[netty-handler-4.1.48.Final.jar!/:4.1.48.Final]
2020-05-12T15:25:29.945845616Z  at io.netty.handler.codec.ByteToMessageDecoder.decodeRemovalReentryProtection(ByteToMessageDecoder.java:498) ~[netty-codec-4.1.48.Final.jar!/:4.1.48.Final]
2020-05-12T15:25:29.945849916Z  at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:437) ~[netty-codec-4.1.48.Final.jar!/:4.1.48.Final]
2020-05-12T15:25:29.945854116Z  at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:276) ~[netty-codec-4.1.48.Final.jar!/:4.1.48.Final]
2020-05-12T15:25:29.945860817Z  at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) ~[netty-transport-4.1.48.Final.jar!/:4.1.48.Final]
2020-05-12T15:25:29.945900417Z  at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) ~[netty-transport-4.1.48.Final.jar!/:4.1.48.Final]
2020-05-12T15:25:29.945908717Z  at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357) ~[netty-transport-4.1.48.Final.jar!/:4.1.48.Final]
2020-05-12T15:25:29.945913217Z  at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1410) ~[netty-transport-4.1.48.Final.jar!/:4.1.48.Final]
2020-05-12T15:25:29.945917517Z  at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) ~[netty-transport-4.1.48.Final.jar!/:4.1.48.Final]
2020-05-12T15:25:29.945921817Z  at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) ~[netty-transport-4.1.48.Final.jar!/:4.1.48.Final]
2020-05-12T15:25:29.945926017Z  at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:919) ~[netty-transport-4.1.48.Final.jar!/:4.1.48.Final]
2020-05-12T15:25:29.945930417Z  at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:163) ~[netty-transport-4.1.48.Final.jar!/:4.1.48.Final]
2020-05-12T15:25:29.945934617Z  at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:714) ~[netty-transport-4.1.48.Final.jar!/:4.1.48.Final]
2020-05-12T15:25:29.945938817Z  at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:650) ~[netty-transport-4.1.48.Final.jar!/:4.1.48.Final]
2020-05-12T15:25:29.945943917Z  at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:576) ~[netty-transport-4.1.48.Final.jar!/:4.1.48.Final]
2020-05-12T15:25:29.945948317Z  at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:493) ~[netty-transport-4.1.48.Final.jar!/:4.1.48.Final]
2020-05-12T15:25:29.945952617Z  at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989) ~[netty-common-4.1.48.Final.jar!/:4.1.48.Final]
2020-05-12T15:25:29.945956817Z  at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) ~[netty-common-4.1.48.Final.jar!/:4.1.48.Final]
2020-05-12T15:25:29.945961117Z  at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) ~[netty-common-4.1.48.Final.jar!/:4.1.48.Final]
2020-05-12T15:25:29.945965417Z  at java.base/java.lang.Thread.run(Unknown Source) ~[na:na]

And I don't know how to get rid of these messages.