Major - P3 Summary
Using MongoDB Atlas 7 (replicated: 1 primary, 2 secondaries) and Java Driver version 5.1.1, we see several times a day an AssertionError being logged on ERROR level by the MongoDB driver.
This error was not seen when using Java Driver version 4.11.2 before.
log_processed.level ERROR
log_processed.logger org.mongodb.driver.connection
log_processed.message Callback onResult call produced an error
log_processed.thread nioEventLoopGroup-2-4{code}
Stacktrace:
java.lang.AssertionError: null at com.mongodb.assertions.Assertions.assertTrue(Assertions.java:158) at com.mongodb.internal.operation.CursorResourceManager.setServerCursor(CursorResourceManager.java:224) at com.mongodb.internal.operation.AsyncCommandBatchCursor.lambda$getMoreLoop$2(AsyncCommandBatchCursor.java:186) at com.mongodb.internal.async.ErrorHandlingResultCallback.onResult(ErrorHandlingResultCallback.java:47) at com.mongodb.internal.connection.DefaultServer$DefaultServerProtocolExecutor.lambda$executeAsync$0(DefaultServer.java:249) at com.mongodb.internal.async.ErrorHandlingResultCallback.onResult(ErrorHandlingResultCallback.java:47) at com.mongodb.internal.connection.CommandProtocolImpl.lambda$executeAsync$0(CommandProtocolImpl.java:88) at com.mongodb.internal.connection.DefaultConnectionPool$PooledConnection.lambda$sendAndReceiveAsync$1(DefaultConnectionPool.java:774) at com.mongodb.internal.connection.UsageTrackingInternalConnection.lambda$sendAndReceiveAsync$1(UsageTrackingInternalConnection.java:150) at com.mongodb.internal.async.ErrorHandlingResultCallback.onResult(ErrorHandlingResultCallback.java:47) at com.mongodb.internal.async.AsyncSupplier.lambda$finish$0(AsyncSupplier.java:65) at com.mongodb.internal.async.SingleResultCallback.complete(SingleResultCallback.java:67) at com.mongodb.internal.async.AsyncSupplier.lambda$onErrorIf$5(AsyncSupplier.java:122) at com.mongodb.internal.async.AsyncSupplier.lambda$finish$0(AsyncSupplier.java:65) at com.mongodb.internal.async.AsyncSupplier.lambda$finish$0(AsyncSupplier.java:65) at com.mongodb.internal.connection.InternalStreamConnection.lambda$sendCommandMessageAsync$7(InternalStreamConnection.java:613) at com.mongodb.internal.connection.InternalStreamConnection$MessageHeaderCallback$MessageCallback.onResult(InternalStreamConnection.java:908) at com.mongodb.internal.connection.InternalStreamConnection$MessageHeaderCallback$MessageCallback.onResult(InternalStreamConnection.java:871) at com.mongodb.internal.connection.InternalStreamConnection$3.completed(InternalStreamConnection.java:730) at com.mongodb.internal.connection.InternalStreamConnection$3.completed(InternalStreamConnection.java:727) at com.mongodb.internal.connection.netty.NettyStream.readAsync(NettyStream.java:330) at com.mongodb.internal.connection.netty.NettyStream.readAsync(NettyStream.java:274) at com.mongodb.internal.connection.InternalStreamConnection.readAsync(InternalStreamConnection.java:727) at com.mongodb.internal.connection.InternalStreamConnection.access$600(InternalStreamConnection.java:99) at com.mongodb.internal.connection.InternalStreamConnection$MessageHeaderCallback.onResult(InternalStreamConnection.java:861) at com.mongodb.internal.connection.InternalStreamConnection$MessageHeaderCallback.onResult(InternalStreamConnection.java:845) at com.mongodb.internal.connection.InternalStreamConnection$3.completed(InternalStreamConnection.java:730) at com.mongodb.internal.connection.InternalStreamConnection$3.completed(InternalStreamConnection.java:727) at com.mongodb.internal.connection.netty.NettyStream.readAsync(NettyStream.java:330) at com.mongodb.internal.connection.netty.NettyStream.handleReadResponse(NettyStream.java:357) at com.mongodb.internal.connection.netty.NettyStream.access$1100(NettyStream.java:112) at com.mongodb.internal.connection.netty.NettyStream$InboundBufferHandler.channelRead0(NettyStream.java:433) at com.mongodb.internal.connection.netty.NettyStream$InboundBufferHandler.channelRead0(NettyStream.java:430) at io.netty.channel.SimpleChannelInboundHandler.channelRead(SimpleChannelInboundHandler.java:99) at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:444) at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420) at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412) at io.netty.handler.ssl.SslHandler.unwrap(SslHandler.java:1473) at io.netty.handler.ssl.SslHandler.decodeJdkCompatible(SslHandler.java:1336) at io.netty.handler.ssl.SslHandler.decode(SslHandler.java:1385) at io.netty.handler.codec.ByteToMessageDecoder.decodeRemovalReentryProtection(ByteToMessageDecoder.java:530) at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:469) at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:290) at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:444) at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420) at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412) at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1407) at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:440) at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420) at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:918) at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:166) at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:788) at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:724) at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:650) at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:562) at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:994) at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) at java.base/java.lang.Thread.run(Thread.java:840)
We cannot exactly say which operation causes this, as the stacktrace does not contain this information.
We assume this is caused by use of the asynchronous API.
How to Reproduce
Unknown
Additional Background
The MongoDB Java driver assertion checks for:
void setServerCursor(@Nullable final ServerCursor serverCursor) {
assertTrue(state.inProgress());
...
So state.inProgress() _seems to evaluate to false.