EndOfStreamException: Attempted to read past the end of the stream

Rich_Levy · May 18, 2023, 6:53pm

Hi All,

We are using a Serverless Instance of MongoDb using the 2.18 version of the .NET driver. During reads, the following exception occurs from time to time.

System.IO.EndOfStreamException: Attempted to read past the end of the stream.

There doesn’t seem to be a pattern of why this exception occurs. Any help understanding what is going on would be greatly appreciated. Full call stack below:

MongoDB.Driver.MongoConnectionException: An exception occurred while receiving a message from the server.
 ---> System.IO.EndOfStreamException: Attempted to read past the end of the stream.
   at MongoDB.Driver.Core.Misc.StreamExtensionMethods.ReadBytes(Stream stream, Byte[] buffer, Int32 offset, Int32 count, CancellationToken cancellationToken)
   at MongoDB.Driver.Core.Connections.BinaryConnection.ReceiveBuffer(CancellationToken cancellationToken)
   --- End of inner exception stack trace ---
   at MongoDB.Driver.Core.Connections.BinaryConnection.ReceiveBuffer(CancellationToken cancellationToken)
   at MongoDB.Driver.Core.Connections.BinaryConnection.ReceiveBuffer(Int32 responseTo, CancellationToken cancellationToken)
--- End of stack trace from previous location ---
   at MongoDB.Driver.Core.Connections.BinaryConnection.Dropbox.RemoveMessage(Int32 responseTo)
   at MongoDB.Driver.Core.Connections.BinaryConnection.ReceiveBuffer(Int32 responseTo, CancellationToken cancellationToken)
   at MongoDB.Driver.Core.Connections.BinaryConnection.ReceiveMessage(Int32 responseTo, IMessageEncoderSelector encoderSelector, MessageEncoderSettings messageEncoderSettings, CancellationToken cancellationToken)
   at MongoDB.Driver.Core.ConnectionPools.ExclusiveConnectionPool.PooledConnection.ReceiveMessage(Int32 responseTo, IMessageEncoderSelector encoderSelector, MessageEncoderSettings messageEncoderSettings, CancellationToken cancellationToken)
   at MongoDB.Driver.Core.ConnectionPools.ExclusiveConnectionPool.AcquiredConnection.ReceiveMessage(Int32 responseTo, IMessageEncoderSelector encoderSelector, MessageEncoderSettings messageEncoderSettings, CancellationToken cancellationToken)
   at MongoDB.Driver.Core.WireProtocol.CommandUsingCommandMessageWireProtocol`1.Execute(IConnection connection, CancellationToken cancellationToken)
   at MongoDB.Driver.Core.WireProtocol.CommandWireProtocol`1.Execute(IConnection connection, CancellationToken cancellationToken)
   at MongoDB.Driver.Core.Servers.Server.ServerChannel.ExecuteProtocol[TResult](IWireProtocol`1 protocol, ICoreSession session, CancellationToken cancellationToken)
   at MongoDB.Driver.Core.Servers.Server.ServerChannel.Command[TResult](ICoreSession session, ReadPreference readPreference, DatabaseNamespace databaseNamespace, BsonDocument command, IEnumerable`1 commandPayloads, IElementNameValidator commandValidator, BsonDocument additionalOptions, Action`1 postWriteAction, CommandResponseHandling responseHandling, IBsonSerializer`1 resultSerializer, MessageEncoderSettings messageEncoderSettings, CancellationToken cancellationToken)
   at MongoDB.Driver.Core.Operations.RetryableWriteCommandOperationBase.ExecuteAttempt(RetryableWriteContext context, Int32 attempt, Nullable`1 transactionNumber, CancellationToken cancellationToken)
   at MongoDB.Driver.Core.Operations.RetryableWriteOperationExecutor.Execute[TResult](IRetryableWriteOperation`1 operation, RetryableWriteContext context, CancellationToken cancellationToken)
   at MongoDB.Driver.Core.Operations.BulkUnmixedWriteOperationBase`1.ExecuteBatch(RetryableWriteContext context, Batch batch, CancellationToken cancellationToken)
   at MongoDB.Driver.Core.Operations.BulkUnmixedWriteOperationBase`1.ExecuteBatches(RetryableWriteContext context, CancellationToken cancellationToken)
   at MongoDB.Driver.Core.Operations.BulkUnmixedWriteOperationBase`1.Execute(RetryableWriteContext context, CancellationToken cancellationToken)
   at MongoDB.Driver.Core.Operations.BulkMixedWriteOperation.ExecuteBatch(RetryableWriteContext context, Batch batch, CancellationToken cancellationToken)
   at MongoDB.Driver.Core.Operations.BulkMixedWriteOperation.Execute(IWriteBinding binding, CancellationToken cancellationToken)
   at MongoDB.Driver.OperationExecutor.ExecuteWriteOperation[TResult](IWriteBinding binding, IWriteOperation`1 operation, CancellationToken cancellationToken)
   at MongoDB.Driver.MongoCollectionImpl`1.ExecuteWriteOperation[TResult](IClientSessionHandle session, IWriteOperation`1 operation, CancellationToken cancellationToken)
   at MongoDB.Driver.MongoCollectionImpl`1.BulkWrite(IClientSessionHandle session, IEnumerable`1 requests, BulkWriteOptions options, CancellationToken cancellationToken)
   at MongoDB.Driver.MongoCollectionImpl`1.<>c__DisplayClass28_0.<BulkWrite>b__0(IClientSessionHandle session)
   at MongoDB.Driver.MongoCollectionImpl`1.UsingImplicitSession[TResult](Func`2 func, CancellationToken cancellationToken)
   at MongoDB.Driver.MongoCollectionImpl`1.BulkWrite(IEnumerable`1 requests, BulkWriteOptions options, CancellationToken cancellationToken)
   at MongoDB.Driver.MongoCollectionBase`1.<>c__DisplayClass68_0.<InsertOne>b__0(IEnumerable`1 requests, BulkWriteOptions bulkWriteOptions)
   at MongoDB.Driver.MongoCollectionBase`1.InsertOne(TDocument document, InsertOneOptions options, Action`2 bulkWrite)
   at MongoDB.Driver.MongoCollectionBase`1.InsertOne(TDocument document, InsertOneOptions options, CancellationToken cancellationToken)

James_Kovacs · May 29, 2023, 11:08pm

Hi, @Rich_Levy,

Welcome to the MongoDB Community Forums. I understand that you’re occasionally seeing EndOfStreamExceptions from the MongoDB .NET/C# Driver v2.18 when using a Serverless instance.

Typically EndOfStreamExceptions happen when the remote end of a network connection hangs up on a client. From the stack trace, I can see that you’re performing an InsertOne operation and the exception happens while waiting for an acknowledgement from the cluster that the write was completed successfully. Even though the default write concern in MongoDB Atlas is w: majority, I wouldn’t expect the InsertOne response to timeout waiting for the majority write to complete.

On which cloud provider does your Serverless instance reside?
Is the operation always an InsertOne or does it happen with other operations too? If so, which other operations?
When it does happen, what is the size of the documents involved? Are they large documents a few MB in size? Smaller documents? Or no discernable pattern with respect to document size?
Does it happen at particular times of day?

I would suggest enabling Logging to help discern a pattern around when the exceptions occur. My educated guess is that they happen when there is a delay in receiving the write acknowledgement and an intermediate router terminates the TCP connection because it thinks it is idle.

Hopefully that gives you some ideas to assist with troubleshooting.

Sincerely,
James

Rich_Levy · May 31, 2023, 6:09pm

Hi James,

Thanks for responding to my question. Here are some answers to your follow-up questions:

Our serverless instance resides in Azure/Virginia-East2. Our connection is made through a Serverless Private Endpoint
We’ve seen the same System.IO.EndOfStreamException during other operations as well. Call stacks are pasted below
- ToListAsync
- FindAsync
- InsertOne

There doesn’t seem to be a discernable pattern related to document size. We’ve seen it occur with large documents (> 1MB) as well as small documents
There is no pattern regarding time of day.

We will enable Logging to see if this provides additional information.

Do these additional call stacks help diagnose the problem? Do they point to your educated guess regarding the terminated TCP connection? Is there a known remedy for terminated TCP connections because mongo thinks its idle?

Thanks,
Rich

Stack trace when using FindAsync:
var data = await (await collection.FindAsync(filter, null, CancellationToken).ToListAsync(cancellationToken);

   MongoDB.Driver.MongoConnectionException: An exception occurred while receiving a message from the server.
   ---> System.IO.EndOfStreamException: Attempted to read past the end of the stream.
   at MongoDB.Driver.Core.Misc.StreamExtensionMethods.ReadBytesAsync(Stream stream, Byte[] buffer, Int32 offset, Int32 count, TimeSpan timeout, CancellationToken cancellationToken)
   at MongoDB.Driver.Core.Connections.BinaryConnection.ReceiveBufferAsync(CancellationToken cancellationToken)
   --- End of inner exception stack trace ---
   at MongoDB.Driver.Core.Connections.BinaryConnection.ReceiveBufferAsync(CancellationToken cancellationToken)
   at MongoDB.Driver.Core.Connections.BinaryConnection.ReceiveBufferAsync(Int32 responseTo, CancellationToken cancellationToken)
   at MongoDB.Driver.Core.Connections.BinaryConnection.Dropbox.RemoveMessage(Int32 responseTo)
   at MongoDB.Driver.Core.Connections.BinaryConnection.ReceiveBufferAsync(Int32 responseTo, CancellationToken cancellationToken)
   at MongoDB.Driver.Core.Connections.BinaryConnection.ReceiveMessageAsync(Int32 responseTo, IMessageEncoderSelector encoderSelector, MessageEncoderSettings messageEncoderSettings, CancellationToken cancellationToken)
   at MongoDB.Driver.Core.ConnectionPools.ExclusiveConnectionPool.PooledConnection.ReceiveMessageAsync(Int32 responseTo, IMessageEncoderSelector encoderSelector, MessageEncoderSettings messageEncoderSettings, CancellationToken cancellationToken)
   at MongoDB.Driver.Core.WireProtocol.CommandUsingCommandMessageWireProtocol`1.ExecuteAsync(IConnection connection, CancellationToken cancellationToken)
   at MongoDB.Driver.Core.Servers.Server.ServerChannel.ExecuteProtocolAsync[TResult](IWireProtocol`1 protocol, ICoreSession session, CancellationToken cancellationToken)
   at MongoDB.Driver.Core.Operations.RetryableReadOperationExecutor.ExecuteAsync[TResult](IRetryableReadOperation`1 operation, RetryableReadContext context, CancellationToken cancellationToken)
   at MongoDB.Driver.Core.Operations.ReadCommandOperation`1.ExecuteAsync(RetryableReadContext context, CancellationToken cancellationToken)
   at MongoDB.Driver.Core.Operations.FindOperation`1.ExecuteAsync(RetryableReadContext context, CancellationToken cancellationToken)
   at MongoDB.Driver.Core.Operations.FindOperation`1.ExecuteAsync(IReadBinding binding, CancellationToken cancellationToken)
   at MongoDB.Driver.OperationExecutor.ExecuteReadOperationAsync[TResult](IReadBinding binding, IReadOperation`1 operation, CancellationToken cancellationToken)
   at MongoDB.Driver.MongoCollectionImpl`1.ExecuteReadOperationAsync[TResult](IClientSessionHandle session, IReadOperation`1 operation, ReadPreference readPreference, CancellationToken cancellationToken)
   at MongoDB.Driver.MongoCollectionImpl`1.UsingImplicitSessionAsync[TResult](Func`2 funcAsync, CancellationToken cancellationToken)

Stack trace when using ToListAsync:
var data = await collection.Find(filter).ToListAsync(cancellationToken);

   MongoDB.Driver.MongoConnectionException: An exception occurred while receiving a message from the server.
   ---> System.IO.EndOfStreamException: Attempted to read past the end of the stream.
   at MongoDB.Driver.Core.Misc.StreamExtensionMethods.ReadBytesAsync(Stream stream, Byte[] buffer, Int32 offset, Int32 count, TimeSpan timeout, CancellationToken cancellationToken)
   at MongoDB.Driver.Core.Connections.BinaryConnection.ReceiveBufferAsync(CancellationToken cancellationToken)
   --- End of inner exception stack trace ---
   at MongoDB.Driver.Core.Connections.BinaryConnection.ReceiveBufferAsync(CancellationToken cancellationToken)
   at MongoDB.Driver.Core.Connections.BinaryConnection.ReceiveBufferAsync(Int32 responseTo, CancellationToken cancellationToken)
   at MongoDB.Driver.Core.Connections.BinaryConnection.Dropbox.RemoveMessage(Int32 responseTo)
   at MongoDB.Driver.Core.Connections.BinaryConnection.ReceiveBufferAsync(Int32 responseTo, CancellationToken cancellationToken)
   at MongoDB.Driver.Core.Connections.BinaryConnection.ReceiveMessageAsync(Int32 responseTo, IMessageEncoderSelector encoderSelector, MessageEncoderSettings messageEncoderSettings, CancellationToken cancellationToken)
   at MongoDB.Driver.Core.ConnectionPools.ExclusiveConnectionPool.PooledConnection.ReceiveMessageAsync(Int32 responseTo, IMessageEncoderSelector encoderSelector, MessageEncoderSettings messageEncoderSettings, CancellationToken cancellationToken)
   at MongoDB.Driver.Core.WireProtocol.CommandUsingCommandMessageWireProtocol`1.ExecuteAsync(IConnection connection, CancellationToken cancellationToken)
   at MongoDB.Driver.Core.Servers.Server.ServerChannel.ExecuteProtocolAsync[TResult](IWireProtocol`1 protocol, ICoreSession session, CancellationToken cancellationToken)
   at MongoDB.Driver.Core.Operations.RetryableReadOperationExecutor.ExecuteAsync[TResult](IRetryableReadOperation`1 operation, RetryableReadContext context, CancellationToken cancellationToken)
   at MongoDB.Driver.Core.Operations.ReadCommandOperation`1.ExecuteAsync(RetryableReadContext context, CancellationToken cancellationToken)
   at MongoDB.Driver.Core.Operations.FindOperation`1.ExecuteAsync(RetryableReadContext context, CancellationToken cancellationToken)
   at MongoDB.Driver.Core.Operations.FindOperation`1.ExecuteAsync(IReadBinding binding, CancellationToken cancellationToken)
   at MongoDB.Driver.OperationExecutor.ExecuteReadOperationAsync[TResult](IReadBinding binding, IReadOperation`1 operation, CancellationToken cancellationToken)
   at MongoDB.Driver.MongoCollectionImpl`1.ExecuteReadOperationAsync[TResult](IClientSessionHandle session, IReadOperation`1 operation, ReadPreference readPreference, CancellationToken cancellationToken)
   at MongoDB.Driver.MongoCollectionImpl`1.UsingImplicitSessionAsync[TResult](Func`2 funcAsync, CancellationToken cancellationToken)
   at MongoDB.Driver.IAsyncCursorSourceExtensions.ToListAsync[TDocument](IAsyncCursorSource`1 source, CancellationToken cancellationToken)

James_Kovacs · May 31, 2023, 11:42pm

Hi, @Rich_Levy,

Thank you for providing the additional information and stack traces. I was hoping that we would see a pattern with a particular operation, time of day, document size, or other variable.

Part of the challenge is that neither the MongoDB .NET/C# Driver nor the MongoDB Atlas Serverless instance is the one terminating the TCP connection. Typically the culprit is some intermediate load balancer or router in the cloud infrastructure. We enable TCP keepalives by default, which send periodic empty TCP messages (e.g. keepalives) on the socket if there is no data traffic. This is a standard TCP mechanism to keep connections alive even when they are waiting for responses.

Azure is known to have very short default idle timeouts for its Azure load balancers. Typical idle timeouts are 7200 seconds (2 hours), but Azure load balancers are set to 240 seconds (4 minutes) by default. We recently audited our Serverless infrastructure and adjusted TCP keepalive times to account for the low default timeout used by Azure. These changes were deployed in the last week and I am cautiously optimistic that this will resolve this issue since you are deployed on Azure. Please let us know if you observe any more timeouts after today.

You may also wish to review Does TCP keepalive time affect MongoDB Deployments? and ensure that your default TCP keepalive settings on your app servers are configured correctly. Although we enable TCP keepalives in the .NET/C# Driver by default, Microsoft does not provide an API to modify the keepalive time on non-Windows platforms. On Linux and MacOS, we must use the OS-configured value for TCP keepalive. If you are hosting your C# application on a Linux app server, the FAQ linked above explains how to modify the operating system’s TCP keepalive value correctly.

Lastly enabling the Logging API is prudent as it will provide us with additional information should the problem happen again. In particular how long the operation was inflight before the EndOfStreamException occurred.

Please let me know if you have any questions and especially if you see another EndOfStreamException after the recent tweaks to our TCP keepalives in the Atlas Serverless infrastructure.

Sincerely,
James

Rich_Levy · June 2, 2023, 6:20pm

Hi James,

We are in the process of deploying logging for the mongo driver for better understanding of this error. Which categories and at what log levels do you recommend for capturing the relevant information? We would like to capture the relevant information without blowing out our log sizes.

Unfortunately we are still seeing the EndOfStreamException even with the recent updates to your Azure environment.

We are considering adding a Retry around our Mongo calls. Is this something you recommend?
For the InsertOne, InsertMany, InsertOneAsync, InsertManyAsync operations is it safe to retry? For these calls, is it necessary to check if the data was persisted before retrying the command?

Our configuration has Connection Pooling enabled. We were wondering if Connection Pooling is contributing to the problem or is in any way related. Is it advisable to turn off Connection Pooling?

We are running our code in a http app server environment using linux. You recommended changing the OS TCP keepalive. If we modify the OS TCP keepalive will it have any adverse effects on other operations outside the realm of mongo?

Thanks,
Rich

James_Kovacs · June 3, 2023, 12:06am

Hi, @Rich_Levy,

I was cautiously optimistic that the infrastructure changes to TCP keepalive would address the issue that you’ve encountered. It is unfortunate that they did not.

Given the nature of the problem, MongoDB.Command and MongoDB.Connection both at Debug would be a good place to start. MongoDB.Command will emit command started, succeeded, and failed messages providing timings of when commands start and complete. MongoDB.Connection will inform when connections are created, checked in/out of a pool, and terminated.

Regarding whether to implement retry logic around your MongoDB calls, this is a recommended practice. Retryable reads and writes will attempt retryable operations again if they fail, but only once. Retrying once handles the most common case of an election or sporadic network failure, but does not handle more complex scenarios. Build a Resilient Application with MongoDB Atlas is a good read. Especially relevant here is the section on Error Handling.

Regarding the safety of retries, the built-in retryable writes mechanism (which retries once) handles the case where a write was performed successfully but the response message was lost. If you implement your own retry mechanism as a backstop to retryable writes, you will have to implement your own idempotent transformation logic, data persistence checks, optimistic locking mechanism, or ACID transactions.

ASIDE: Client-side Operations Timeouts (CSOT) will more elegantly solve this problem by allowing multiple retries within a specified timeout period, but has not been implemented in the .NET/C# Driver yet. Please follow CSHARP-3393 for updates.

Regarding connection pooling, the .NET/C# Driver performs connection pooling automatically, which amortizes the cost of connection creation through connection re-use. There is no way to disable connection pooling, but you can adjust various pooling parameters, such as minPoolSize, maxPoolSize, maxIdleTimeMS, and other pooling parameters. Based on the observed behaviour, I don’t believe that adjusting connection pooling parameters will help address the issue.

Regarding the TCP keepalive change, it is configured on Linux at the operating system level. While it can be configured on the per-socket level, the .NET socket library does not expose these parameters to us. Adjusting the TCP keepalive for the operating system will affect all TCP socket connections, but generally does not have an adverse affect. Keepalives are small packets (64 bytes over ethernet) designed to keep a connection alive even when no data is transitting the connection. If data is actively being exchanged in either direction, no keepalives will be sent. It is only when socket traffic goes quiet that keepalives are sent.

I’m happy to answer any additional questions you might have. I do understand that you are working with our technical services team as well. Please share any logs and diagnostics with them. They can then route that data to me for analysis so that you don’t have to share it in a public forum.

Sincerely,
James