MySqlConnector icon indicating copy to clipboard operation
MySqlConnector copied to clipboard

Disposed socket on connect timeout

Open ghost opened this issue 5 years ago • 5 comments
trafficstars

In a highly concurrent environment I frequently get (some) issues, one of which is a disposed socket on the connect. Involved stack traces are:

MySqlConnector.MySqlException (0x80004005): Connect Timeout expired.
 ---> MySqlConnector.MySqlException (0x80004005): Connect Timeout expired.
 ---> System.ObjectDisposedException: Cannot access a disposed object.
Object name: 'System.Net.Sockets.Socket'.
   at System.Net.Sockets.Socket.EndConnect(IAsyncResult asyncResult)
   at System.Net.Sockets.TcpClient.EndConnect(IAsyncResult asyncResult)
   at System.Threading.Tasks.TaskFactory`1.FromAsyncCoreLogic(IAsyncResult iar, Func`2 endFunction, Action`1 endAction, Task`1 promise, Boolean requiresSynchronization)
--- End of stack trace from previous location where exception was thrown ---
   at MySqlConnector.Core.ServerSession.OpenTcpSocketAsync(ConnectionSettings cs, ILoadBalancer loadBalancer, IOBehavior ioBehavior, CancellationToken cancellationToken) in /src/MySqlConnector/src/MySqlConnector/Core/ServerSession.cs:line 903
   at MySqlConnector.Core.ServerSession.OpenTcpSocketAsync(ConnectionSettings cs, ILoadBalancer loadBalancer, IOBehavior ioBehavior, CancellationToken cancellationToken)
   at MySqlConnector.Core.ServerSession.ConnectAsync(ConnectionSettings cs, Int32 startTickCount, ILoadBalancer loadBalancer, IOBehavior ioBehavior, CancellationToken cancellationToken) in /src/MySqlConnector/src/MySqlConnector/Core/ServerSession.cs:line 368
   at MySqlConnector.MySqlConnection.CreateSessionAsync(ConnectionPool pool, Int32 startTickCount, Nullable`1 ioBehavior, CancellationToken cancellationToken) in /src/MySqlConnector/src/MySqlConnector/MySqlConnection.cs:line 850
   at MySqlConnector.MySqlConnection.CreateSessionAsync(ConnectionPool pool, Int32 startTickCount, Nullable`1 ioBehavior, CancellationToken cancellationToken) in /src/MySqlConnector/src/MySqlConnector/MySqlConnection.cs:line 850
   at MySqlConnector.MySqlConnection.OpenAsync(Nullable`1 ioBehavior, CancellationToken cancellationToken) in /src/MySqlConnector/src/MySqlConnector/MySqlConnection.cs:line 419

I have conn pooling disabled temporarily to overcome some conn leaks. latest .net core 3.1 on ubuntu.

How to go about diagnosing this?

ghost avatar Aug 13 '20 20:08 ghost

The connection timeout is implemented by disposing the socket, that's why you're seeing that as the inner exception: https://github.com/mysql-net/MySqlConnector/blob/ac71c24f35aea4bf2b1b97e6c32585a0d4e1f38a/src/MySqlConnector/Core/ServerSession.cs#L897

The better question is "why is the connect timeout expiring?" (not "why is it implemented this way?").

I have conn pooling disabled temporarily

Did you do that to avoid the exception above, or did you start seeing the exception above after disabling pooling? If the latter, my psychic debugging is that you're rotating through outgoing ports so frequently that you're ending up in a TIME_WAIT scenario. I'd recommend looking at the status of all sockets on the MySQL Server

bgrainger avatar Aug 13 '20 20:08 bgrainger

Got used to treat Cannot access a disposed object.as a flaw one way or another. It's GCP mysql, afaik there are no more than 1k conns open out of max 4k. will see if i can look into sockets there (not a linux expert myself).

I disabled pooling as i have leaks somehow; getting to max conns in pool frequently, even at max 500 per pod. I've reviewed my code countless times and just by review I cannot spot any issues. As always nothing can be reproduced on my machine.

Besides this open timeout, i am also battling process recycles due to exceptions on background threads. Example:

System.InvalidOperationException: Connection must be Open; current state is Closed
   at MySqlConnector.MySqlConnection.get_Session() in /src/MySqlConnector/src/MySqlConnector/MySqlConnection.cs:line 655
   at MySqlConnector.MySqlConnection.get_ServerThread() in /src/MySqlConnector/src/MySqlConnector/MySqlConnection.cs:line 473
   at MySqlConnector.MySqlConnection.Cancel(ICancellableCommand command) in /src/MySqlConnector/src/MySqlConnector/MySqlConnection.cs:line 679
   at MySqlConnector.MySqlCommand.Cancel() in /src/MySqlConnector/src/MySqlConnector/MySqlCommand.cs:line 107
   at System.Threading.CancellationToken.<>c.<.cctor>b__26_0(Object obj)
   at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state)
```
I've already forked the repo to apply some diag fixes;

ghost avatar Aug 13 '20 22:08 ghost

This call stack reminds me of https://github.com/mysql-net/MySqlConnector/issues/820.

I wrote in https://github.com/mysql-net/MySqlConnector/issues/820#issuecomment-629707089:

There is definitely a problem if MySqlCommand.Cancel throws an exception in the cases when it's triggered by a CancellationToken.

That comment seems to apply to this situation, and there's probably additional hardening that needs to happen but I'd like to understand the race condition more fully first.

bgrainger avatar Aug 13 '20 23:08 bgrainger

I am trying to log more info on my fork. All my process crashes seem to be related to session being destroyed while cancelling callback is still registered. The cancel method on the command gets invoked, gets to connection.cancel, which throws when accessing the session; i've also noticed the session being destroyed when reading the server thread id, after being correctly captured in the connection.cancel method.

It smells like the session gets teared down, for some reason, while some pending work is still left - for eg some registered cancellation tokens. I imagine that the session might be killed by the server as well, but in the end, the library should be able to handle this properly (the socket in the session gets disconnected, so the library can become aware of this).

I've managed to silence some scenarios, but not all. You can follow the changes on my fork here.

ghost avatar Aug 17 '20 08:08 ghost

@bgrainger I seem to have a similar problem. But main problem is time of falling. It is about 15 minutes.(I can retry this query) I try to use CancellationToken, but it doesn't work.

Also I don't understand why cancellationToken don't send from SendReplyAsync and ReceiveReplyAsync methods. image

Version of Mysql Connector 1.3.14 with netcoreapp3.1 on linux.

vaital3000 avatar Nov 11 '21 12:11 vaital3000