[CSHARP-1628] Unobserved task exception when connection times out Created: 18/Apr/16  Updated: 18/May/16  Resolved: 21/Apr/16

Status: Closed
Project: C# Driver
Component/s: Connectivity
Affects Version/s: 2.2.2
Fix Version/s: 2.2.4

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

Backwards Compatibility: Fully Compatible

 Description   

When server connection times out, an unobserved task exception is thrown, even when synchronous API is used (see stack trace below).
We have a handler for such exceptions installed globally (from the days when such exceptions terminated current AppDomain), so we occasionally get these traced when servers get down. While they are mostly harmless, I believe these exceptions should be handled and (probably) muted.

at MongoDB.Driver.Core.Connections.BinaryConnection.OpenHelper(CancellationToken cancellationToken)
at MongoDB.Driver.Core.Connections.BinaryConnection.Open(CancellationToken cancellationToken)
at MongoDB.Driver.Core.ConnectionPools.ExclusiveConnectionPool.AcquiredConnection.Open(CancellationToken cancellationToken)
at MongoDB.Driver.Core.Servers.ClusterableServer.GetChannel(CancellationToken cancellationToken)
at MongoDB.Driver.Core.Bindings.ServerChannelSource.GetChannel(CancellationToken cancellationToken)
at MongoDB.Driver.Core.Bindings.ChannelSourceHandle.GetChannel(CancellationToken cancellationToken)
at MongoDB.Driver.Core.Operations.CountOperation.Execute(IReadBinding binding, CancellationToken cancellationToken)
at MongoDB.Driver.OperationExecutor.ExecuteReadOperation[TResult](IReadBinding binding, IReadOperation`1 operation, CancellationToken cancellationToken)
at MongoDB.Driver.MongoCollectionImpl`1.ExecuteReadOperation[TResult](IReadOperation`1 operation, ReadPreference readPreference, CancellationToken cancellationToken)
at MongoDB.Driver.MongoCollectionImpl`1.ExecuteReadOperation[TResult](IReadOperation`1 operation, CancellationToken cancellationToken)
at MongoDB.Driver.MongoCollectionImpl`1.Count(FilterDefinition`1 filter, CountOptions options, CancellationToken cancellationToken)



 Comments   
Comment by Aristarkh Zagorodnikov [ 21/Apr/16 ]

Ah, sorry, I didn't pay attention to that part, thanks for the update.

Comment by Craig Wilson [ 21/Apr/16 ]

It did... because your commit message didn't include the CSHARP-1628 text, our JIRA bot didn't include it here.

https://github.com/mongodb/mongo-csharp-driver/commits/master

Comment by Aristarkh Zagorodnikov [ 21/Apr/16 ]

It appears that the PR didn't make it into the commit (at least judging from the githook-provided links).

Comment by Githook User [ 21/Apr/16 ]

Author:

{u'username': u'craiggwilson', u'name': u'Craig Wilson', u'email': u'craiggwilson@gmail.com'}

Message: CSHARP-1628: fixed issue with unobserved task exception.
Branch: v2.2.x
https://github.com/mongodb/mongo-csharp-driver/commit/80e8aba618af54c1dfdbecb4312087d37c2d1cd6

Comment by Githook User [ 21/Apr/16 ]

Author:

{u'username': u'craiggwilson', u'name': u'Craig Wilson', u'email': u'craiggwilson@gmail.com'}

Message: CSHARP-1628: fixed issue with unobserved task exception.
Branch: master
https://github.com/mongodb/mongo-csharp-driver/commit/7455b09891674c727f9a01717d81ed70045a22eb

Comment by Craig Wilson [ 20/Apr/16 ]

Yeah, how you described is exactly how I reproduced this. I've accepted your PR. I had tried this exact thing but put the call to IgnoreExceptions in a different place and it didn't help. Moving it to where you put it solved the issue. Putting it through CR now and will get this into 2.2.4.

Comment by Aristarkh Zagorodnikov [ 20/Apr/16 ]

Craig,

Since the UTE is thrown from the finalizer, the easiest way to repro is to create a separate thread that does GC.Collect() interleaved with Thread.Sleep(1), and then try to perform a database operation in a loop with low connection timeout (see my comment above).

I tested your fix and it works, but I have a couple of suggestions.
1. I don't really think you need to store the exception (it never will be used), calling the accessor is enough
2. The library already contains Task.IgnoreExceptions extension method that does what I suggest at (1), I think it's a better way
3. I believe observing exceptions could be added right after the TCS is set up for additional safety, instead of observing the exception in the handler

There is a PR for this, see https://github.com/craiggwilson/mongo-csharp-driver/pull/4

P.S. I'd name the method ObserveExceptions, since IgnoreExceptions is a bit misleading (should be no problem since it's internal)

Comment by Craig Wilson [ 19/Apr/16 ]

Aristarkh,

I had to do some code manipulation to get this to repro. The issue is that we create a TaskCompletionSource even on the sync path as our BinaryConnection class is thread-safe and used from both the sync and async stack. So, basically assigning the exception to a dummy variable seems to have fixed the issue. If you are able, would you mind building from source and trying this out in your scenario? It is located on my fork here: https://github.com/craiggwilson/mongo-csharp-driver/tree/csharp1628.

Thanks,
Craig

Comment by Aristarkh Zagorodnikov [ 19/Apr/16 ]

Connecting to replica set with connection timeout (MongoClientSettings.ConnectTimeout) set to absurdly low value (like 1 ms for a machine over WAN) worked for us.
Don't forget to install unobserved handler, or there will be nothing to catch =)

Comment by Craig Wilson [ 19/Apr/16 ]

Hi Aristarkh,

I have a theory but am having trouble reproducing it. I'll let you know what I find. If you know of a way to reliably reproduce this, let me know.

Craig

Comment by Aristarkh Zagorodnikov [ 18/Apr/16 ]

A bit more detailed stack trace:

at MongoDB.Driver.Core.Connections.TcpStreamFactory.Connect(Socket socket, EndPoint endPoint, CancellationToken cancellationToken)
at MongoDB.Driver.Core.Connections.TcpStreamFactory.CreateStream(EndPoint endPoint, CancellationToken cancellationToken)
at MongoDB.Driver.Core.Connections.BinaryConnection.OpenHelper(CancellationToken cancellationToken)
— End of inner exception stack trace —
at MongoDB.Driver.Core.Connections.BinaryConnection.OpenHelper(CancellationToken cancellationToken)
at MongoDB.Driver.Core.Connections.BinaryConnection.Open(CancellationToken cancellationToken)
at MongoDB.Driver.Core.ConnectionPools.ExclusiveConnectionPool.AcquiredConnection.Open(CancellationToken cancellationToken)
at MongoDB.Driver.Core.Servers.ClusterableServer.GetChannel(CancellationToken cancellationToken)
at MongoDB.Driver.Core.Bindings.ServerChannelSource.GetChannel(CancellationToken cancellationToken)
at MongoDB.Driver.Core.Bindings.ChannelSourceHandle.GetChannel(CancellationToken cancellationToken)
at MongoDB.Driver.Core.Operations.FindOperation`1.Execute(IReadBinding binding, CancellationToken cancellationToken)
at MongoDB.Driver.OperationExecutor.ExecuteReadOperation[TResult](IReadBinding binding, IReadOperation`1 operation, CancellationToken cancellationToken)
at MongoDB.Driver.MongoCollectionImpl`1.ExecuteReadOperation[TResult](IReadOperation`1 operation, ReadPreference readPreference, CancellationToken cancellationToken)
at MongoDB.Driver.MongoCollectionImpl`1.ExecuteReadOperation[TResult](IReadOperation`1 operation, CancellationToken cancellationToken)
at MongoDB.Driver.MongoCollectionImpl`1.FindSync[TProjection](FilterDefinition`1 filter, FindOptions`2 options, CancellationToken cancellationToken)

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