[CSHARP-1961] Possible bug in connection state management Created: 11/Apr/17  Updated: 15/May/17  Resolved: 15/May/17

Status: Closed
Project: C# Driver
Component/s: Connectivity
Affects Version/s: 2.4.3
Fix Version/s: 2.4.4

Type: Bug Priority: Minor - P4
Reporter: Aristarkh Zagorodnikov Assignee: Robert Stam
Resolution: Done Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

.NET 4.6.2, Windows 10 x64



 Description   

When one of our databases fail over we sometimes get these exceptions:

MongoDB.Driver.MongoConnectionException: An exception occurred while opening a connection to the server. ---> System.InvalidOperationException: Invalid BinaryConnection state transition from 2 to Failed.
MongoDB.Driver.Core.Connections.BinaryConnection.ConnectionFailed(Exception exception)
MongoDB.Driver.Core.Connections.BinaryConnection.<ReceiveBufferAsync>d__51.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
!Async.Rethrow
MongoDB.Driver.Core.Connections.BinaryConnection.<ReceiveBufferAsync>d__52.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
!Async.Rethrow
MongoDB.Driver.Core.Connections.BinaryConnection.<ReceiveMessageAsync>d__54.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
!Async.Rethrow
MongoDB.Driver.Core.WireProtocol.CommandWireProtocol`1.<ExecuteAsync>d__11.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
!Async.Rethrow
MongoDB.Driver.Core.Connections.ConnectionInitializer.<InitializeConnectionAsync>d__3.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
!Async.Rethrow
MongoDB.Driver.Core.Connections.BinaryConnection.<OpenHelperAsync>d__48.MoveNext()
   --- End of inner exception stack trace ---
MongoDB.Driver.Core.Connections.BinaryConnection.<OpenHelperAsync>d__48.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
!Async.Rethrow
MongoDB.Driver.Core.Servers.Server.<GetChannelAsync>d__27.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
!Async.Rethrow
MongoDB.Driver.Core.Operations.BulkMixedWriteOperation.<ExecuteAsync>d__39.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
!Async.Rethrow
MongoDB.Driver.OperationExecutor.<ExecuteWriteOperationAsync>d__3`1.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
!Async.Rethrow
MongoDB.Driver.MongoCollectionImpl`1.<ExecuteWriteOperationAsync>d__62`1.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
!Async.Rethrow
MongoDB.Driver.MongoCollectionImpl`1.<BulkWriteAsync>d__22.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
!Async.Rethrow
MongoDB.Driver.MongoCollectionBase`1.<UpdateOneAsync>d__47.MoveNext()
--- End of stack trace from previous location where exception was thrown ---

While the top-level exception (MongoConnectionException) looks good, the inner InvalidOperationException looks suspect to me.

P.S. !Async.Rethrow is part of our diagnostics' stack trace compression, it's equivalent to

System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)



 Comments   
Comment by Githook User [ 15/May/17 ]

Author:

{u'username': u'rstam', u'name': u'rstam', u'email': u'robert@robertstam.org'}

Message: CSHARP-1961: Fix bug in connection state transition.
Branch: master
https://github.com/mongodb/mongo-csharp-driver/commit/a8797a34c254a249f666983d5e49ab2a1ce66eb3

Comment by Robert Stam [ 08/May/17 ]

Thanks for the update.

The invalid state transition exception in the cluster description is a bug that was hiding the original connection exception, which makes it hard to know exactly what happened.

Comment by Shawn Mclean [ 08/May/17 ]

So my problem above was documented.

Dotnet core does not support SNI TLS on linux: https://github.com/dotnet/corefx/issues/9608

Atlas free tier requires this.

Comment by Shawn Mclean [ 06/May/17 ]

I have this exact issue when running a dotnet core app in a linux docker container. The same app works fine on windows.

This occurred when changing from a single instance connection string to a replica set hosted on atlas.

Stack trace:

System.TimeoutException: A timeout occured after 30000ms selecting a server using CompositeServerSelector{ Selectors = ReadPreferenceServerSelector{ ReadPreference = { Mode : Primary } }, LatencyLimitingServerSelector{ AllowedLatencyRange = 00:00:00.0150000 } }. Client view of cluster state is { ClusterId : "1", ConnectionMode : "Automatic", Type : "Unknown", State : "Disconnected", Servers : [{ ServerId: "{ ClusterId : 1, EndPoint : "Unspecified/dev-cluster-shard-00-00-bujrx.mongodb.net:27017" }", EndPoint: "Unspecified/dev-cluster-shard-00-00-bujrx.mongodb.net:27017", State: "Disconnected", Type: "Unknown", HeartbeatException: "MongoDB.Driver.MongoConnectionException: An exception occurred while opening a connection to the server. ---> System.InvalidOperationException: Invalid BinaryConnection state transition from 2 to Failed.
   at MongoDB.Driver.Core.Connections.BinaryConnection.ConnectionFailed(Exception exception)
   at MongoDB.Driver.Core.Connections.BinaryConnection.<ReceiveBufferAsync>d__51.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at MongoDB.Driver.Core.Connections.BinaryConnection.<ReceiveBufferAsync>d__52.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at MongoDB.Driver.Core.Connections.BinaryConnection.<ReceiveMessageAsync>d__54.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at MongoDB.Driver.Core.WireProtocol.CommandWireProtocol`1.<ExecuteAsync>d__11.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at MongoDB.Driver.Core.Connections.ConnectionInitializer.<InitializeConnectionAsync>d__3.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at MongoDB.Driver.Core.Connections.BinaryConnection.<OpenHelperAsync>d__48.MoveNext()
   --- End of inner exception stack trace ---
   at MongoDB.Driver.Core.Connections.BinaryConnection.<OpenHelperAsync>d__48.MoveNext()

Comment by Robert Stam [ 13/Apr/17 ]

The exception in the Description does seem like a bug.

Not sure about the other one in the Comment.

Comment by Aristarkh Zagorodnikov [ 11/Apr/17 ]

I'm not sure if this is related and indicates a possible race condition, but consider this one too:

MongoDB.Driver.MongoConnectionException: An exception occurred while opening a connection to the server. ---> System.ObjectDisposedException: Cannot access a disposed object.
Object name: 'System.Net.Sockets.Socket'.
System.Net.Sockets.Socket.SetSocketOption(SocketOptionLevel optionLevel, SocketOptionName optionName, Int32 optionValue)
MongoDB.Driver.Core.Connections.TcpStreamFactory.ConfigureConnectedSocket(Socket socket)
MongoDB.Driver.Core.Connections.TcpStreamFactory.CreateNetworkStream(Socket socket)
MongoDB.Driver.Core.Connections.TcpStreamFactory.CreateStream(EndPoint endPoint, CancellationToken cancellationToken)
MongoDB.Driver.Core.Connections.BinaryConnection.OpenHelper(CancellationToken cancellationToken)
   --- End of inner exception stack trace ---
MongoDB.Driver.Core.Connections.BinaryConnection.OpenHelper(CancellationToken cancellationToken)
MongoDB.Driver.Core.Connections.BinaryConnection.Open(CancellationToken cancellationToken)
MongoDB.Driver.Core.ConnectionPools.ExclusiveConnectionPool.AcquiredConnection.Open(CancellationToken cancellationToken)
MongoDB.Driver.Core.Servers.Server.GetChannel(CancellationToken cancellationToken)
MongoDB.Driver.Core.Bindings.ServerChannelSource.GetChannel(CancellationToken cancellationToken)
MongoDB.Driver.Core.Bindings.ChannelSourceHandle.GetChannel(CancellationToken cancellationToken)
MongoDB.Driver.Core.Operations.FindOperation`1.Execute(IReadBinding binding, CancellationToken cancellationToken)
MongoDB.Driver.OperationExecutor.ExecuteReadOperation[TResult](IReadBinding binding, IReadOperation`1 operation, CancellationToken cancellationToken)
MongoDB.Driver.MongoCollectionImpl`1.ExecuteReadOperation[TResult](IReadOperation`1 operation, ReadPreference readPreference, CancellationToken cancellationToken)
MongoDB.Driver.MongoCollectionImpl`1.ExecuteReadOperation[TResult](IReadOperation`1 operation, CancellationToken cancellationToken)
MongoDB.Driver.MongoCollectionImpl`1.FindSync[TProjection](FilterDefinition`1 filter, FindOptions`2 options, CancellationToken cancellationToken)

Generated at Wed Feb 07 21:41:12 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.