CancellationToken does not cancel some requests, so they wait too long (about 15 minutes)

[vaital3000]

Software versions MySqlConnector version: 2.1.0 Server type (MySQL, MariaDB, Aurora, etc.) and version: MySql 5.7.32 .NET version: net6 (Optional) ORM NuGet packages and versions: EFCore 6.0.0 with Pomelo.EntityFrameworkCore.MySql 6.0.0

Also this problem reproduced with MySqlConnector version: 1.3.12 .NET version: netcoreapp3.1 (Optional) ORM NuGet packages and versions: EFCore 5.0.10 And MySqlConnector version: 0.56.0 .NET version: netcoreapp3.1 (Optional) ORM NuGet packages and versions: Dapper 1.60.6

Describe the bug CancellationToken does not cancel some requests, so they wait too long (about 15 minutes)

Exception

The operation was canceled.
   at System.Threading.CancellationToken.ThrowOperationCanceledException()
   at MySqlConnector.MySqlConnection.OpenAsync(Nullable`1 ioBehavior, CancellationToken cancellationToken) in /_/src/MySqlConnector/MySqlConnection.cs:line 445
   at Microsoft.EntityFrameworkCore.Storage.RelationalConnection.OpenInternalAsync(Boolean errorsExpected, CancellationToken cancellationToken)
   at Microsoft.EntityFrameworkCore.Storage.RelationalConnection.OpenInternalAsync(Boolean errorsExpected, CancellationToken cancellationToken)
   at Microsoft.EntityFrameworkCore.Storage.RelationalConnection.OpenAsync(CancellationToken cancellationToken, Boolean errorsExpected)
   at Pomelo.EntityFrameworkCore.MySql.Storage.Internal.MySqlRelationalConnection.OpenAsync(CancellationToken cancellationToken, Boolean errorsExpected)
   at Microsoft.EntityFrameworkCore.Storage.RelationalConnection.BeginTransactionAsync(IsolationLevel isolationLevel, CancellationToken cancellationToken)
   at Microsoft.EntityFrameworkCore.Storage.RelationalConnection.BeginTransactionAsync(CancellationToken cancellationToken)
   at Microsoft.EntityFrameworkCore.Update.Internal.BatchExecutor.ExecuteAsync(IEnumerable`1 commandBatches, IRelationalConnection connection, CancellationToken cancellationToken)
   at Microsoft.EntityFrameworkCore.Update.Internal.BatchExecutor.ExecuteAsync(IEnumerable`1 commandBatches, IRelationalConnection connection, CancellationToken cancellationToken)
   at Microsoft.EntityFrameworkCore.Update.Internal.BatchExecutor.ExecuteAsync(IEnumerable`1 commandBatches, IRelationalConnection connection, CancellationToken cancellationToken)
   at Microsoft.EntityFrameworkCore.ChangeTracking.Internal.StateManager.SaveChangesAsync(IList`1 entriesToSave, CancellationToken cancellationToken)
   at Microsoft.EntityFrameworkCore.ChangeTracking.Internal.StateManager.SaveChangesAsync(StateManager stateManager, Boolean acceptAllChangesOnSuccess, CancellationToken cancellationToken)
   at Pomelo.EntityFrameworkCore.MySql.Storage.Internal.MySqlExecutionStrategy.ExecuteAsync[TState,TResult](TState state, Func`4 operation, Func`4 verifySucceeded, CancellationToken cancellationToken)
   at Microsoft.EntityFrameworkCore.DbContext.SaveChangesAsync(Boolean acceptAllChangesOnSuccess, CancellationToken cancellationToken)
   at Microsoft.EntityFrameworkCore.DbContext.SaveChangesAsync(Boolean acceptAllChangesOnSuccess, CancellationToken cancellationToken)
   at Dodo.Accounting.EfRepository.Repositories.MaterialConsumption.OrderRepository.CreateAsync(Order order, CancellationToken ct) in /home/runner/work/accounting/accounting/src/Dodo.Accounting.EfRepository/Repositories/MaterialConsumption/OrderRepository.cs:line 52

Code sample It is difficult to simple reproduce. It happens on production about 6 times per 12 hours with 3-6rps.

Expected behavior The request was canceled after the CancellationToken was canceled.

Additional context Initially the problem is the connection to the database too long. This could be a problem on the Linux or network side. But, when I try to cancel request with CancellationToken, It happen after about 15 minutes. It's too long, because I can't run retry for handling message. Logs with MySqlConnector 2.1

Logs for MySqlConnector 1.3.12

I found that "ServerSession.ReceiveReplyAsync" in "MySqlConnector\Core\ServerSession.cs:909" don't pass CancellationToken deeper. Are there any reasons for this?

[bgrainger]

I can't think of anything that defaults to a 15-minute timeout. Have you set any of ConnectionTimeout, DefaultCommandTimeout or MySqlCommand.CommandTimeout to 900 (i.e., 15 minutes)?

What is your connection string (excluding the password)?

[vaital3000]

My connection string is

Data Source=we-mysql-accounting-dodo.mysql.database.azure.com; Port=3306; Initial Catalog=materialconsumption; Character Set=utf8; User Id=; Password=; convertzerodatetime=true; Allow User Variables=True; Pooling=true; SSL Mode=Preferred; ConnectionLifeTime=180

I analyzed my logs again. (for 1.3.12, because it's more detailed) Firstly I saw Session{0} ServerVersion={1} supports reset connection; sending reset connection request Then exception was thrown

Unable to read data from the transport connection: Connection timed out.
at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.ThrowException(SocketError error, CancellationToken cancellationToken)
   at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.System.Threading.Tasks.Sources.IValueTaskSource<System.Int32>.GetResult(Int16 token)
   at System.Net.Security.SslStream.EnsureFullTlsFrameAsync[TIOAdapter](TIOAdapter adapter)
   at System.Net.Security.SslStream.ReadAsyncInternal[TIOAdapter](TIOAdapter adapter, Memory`1 buffer)
   at MySqlConnector.Protocol.Serialization.StreamByteHandler.<ReadBytesAsync>g__DoReadBytesAsync|6_2(Memory`1 buffer) in /_/src/MySqlConnector/Protocol/Serialization/StreamByteHandler.cs:line 85
   at MySqlConnector.Protocol.Serialization.BufferedByteReader.ReadBytesAsync(IByteHandler byteHandler, ArraySegment`1 buffer, Int32 totalBytesToRead, IOBehavior ioBehavior) in /_/src/MySqlConnector/Protocol/Serialization/BufferedByteReader.cs:line 34
   at MySqlConnector.Protocol.Serialization.ProtocolUtility.<ReadPacketAsync>g__AddContinuation|1_0(ValueTask`1 headerBytes, BufferedByteReader bufferedByteReader, IByteHandler byteHandler, Func`1 getNextSequenceNumber, ProtocolErrorBehavior protocolErrorBehavior, IOBehavior ioBehavior) in /_/src/MySqlConnector/Protocol/Serialization/ProtocolUtility.cs:line 409
   at MySqlConnector.Protocol.Serialization.ProtocolUtility.<DoReadPayloadAsync>g__AddContinuation|5_0(ValueTask`1 readPacketTask, BufferedByteReader bufferedByteReader, IByteHandler byteHandler, Func`1 getNextSequenceNumber, ArraySegmentHolder`1 previousPayloads, ProtocolErrorBehavior protocolErrorBehavior, IOBehavior ioBehavior) in /_/src/MySqlConnector/Protocol/Serialization/ProtocolUtility.cs:line 480
   at MySqlConnector.Core.ServerSession.ReceiveReplyAsyncAwaited(ValueTask`1 task) in /_/src/MySqlConnector/Core/ServerSession.cs:line 956

Then I saw Session{0} ignoring IOException in TryResetConnectionAsync

And then I saw Exception

Cannot access a disposed object.
Object name: 'System.Net.Sockets.Socket'.
at System.Net.Sockets.Socket.BeginConnect(IPAddress address, Int32 port, AsyncCallback requestCallback, Object state)
 at System.Net.Sockets.TcpClient.BeginConnect(IPAddress address, Int32 port, AsyncCallback requestCallback, Object state)
 at System.Threading.Tasks.TaskFactory`1.FromAsyncImpl[TArg1,TArg2](Func`5 beginMethod, Func`2 endFunction, Action`1 endAction, TArg1 arg1, TArg2 arg2, Object state, TaskCreationOptions creationOptions)
 at System.Net.Sockets.TcpClient.ConnectAsync(IPAddress address, Int32 port)
 at MySqlConnector.Core.ServerSession.OpenTcpSocketAsync(ConnectionSettings cs, ILoadBalancer loadBalancer, IOBehavior ioBehavior, CancellationToken cancellationToken) in /_/src/MySqlConnector/Core/ServerSession.cs:line 873

because CancellationToken was cancelled.

[vaital3000]

Also I see this Exception for MySqlConnector 2.1

Unable to read data from the transport connection: Connection timed out.
 at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.ThrowException(SocketError error, CancellationToken cancellationToken)
   at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.System.Threading.Tasks.Sources.IValueTaskSource<System.Int32>.GetResult(Int16 token)
   at System.Net.Security.SslStream.EnsureFullTlsFrameAsync[TIOAdapter](TIOAdapter adapter)
   at System.Net.Security.SslStream.ReadAsyncInternal[TIOAdapter](TIOAdapter adapter, Memory`1 buffer)
   at MySqlConnector.Protocol.Serialization.StreamByteHandler.<ReadBytesAsync>g__DoReadBytesAsync|6_2(Memory`1 buffer) in /_/src/MySqlConnector/Protocol/Serialization/StreamByteHandler.cs:line 85
   at MySqlConnector.Protocol.Serialization.BufferedByteReader.ReadBytesAsync(IByteHandler byteHandler, ArraySegment`1 buffer, Int32 totalBytesToRead, IOBehavior ioBehavior) in /_/src/MySqlConnector/Protocol/Serialization/BufferedByteReader.cs:line 34
   at MySqlConnector.Protocol.Serialization.ProtocolUtility.<ReadPacketAsync>g__AddContinuation|1_0(ValueTask`1 headerBytes, BufferedByteReader bufferedByteReader, IByteHandler byteHandler, Func`1 getNextSequenceNumber, ProtocolErrorBehavior protocolErrorBehavior, IOBehavior ioBehavior) in /_/src/MySqlConnector/Protocol/Serialization/ProtocolUtility.cs:line 409
   at MySqlConnector.Protocol.Serialization.ProtocolUtility.<DoReadPayloadAsync>g__AddContinuation|5_0(ValueTask`1 readPacketTask, BufferedByteReader bufferedByteReader, IByteHandler byteHandler, Func`1 getNextSequenceNumber, ArraySegmentHolder`1 previousPayloads, ProtocolErrorBehavior protocolErrorBehavior, IOBehavior ioBehavior) in /_/src/MySqlConnector/Protocol/Serialization/ProtocolUtility.cs:line 480
   at MySqlConnector.Core.ServerSession.ReceiveReplyAsyncAwaited(ValueTask`1 task) in /_/src/MySqlConnector/Core/ServerSession.cs:line 956

[vaital3000]

@bgrainger any ideas? Can I collect more diagnostic information? I updated MySqlConnector to 2.1.7, but I still see this problem.

[bgrainger]

It seems like there could be a problem in MySqlConnector if Socket.Send blocks: neither the CommandTimeout nor a user-provided CancellationToken would abort the method.

I'm not sure yet if there's a good way to simulate this for testing, and why it seems to be a repeatable problem for you.

[billshooting]

Hi @bgrainger any progress for this issue? We also see this issue in our production env. The connection timeout after 15 minutes. exception: MySqlConnector.MySqlException (0x80004005): Connect Timeout expired. ---> System.ObjectDisposedException: Cannot access a disposed object. Object name: 'System.Net.Sockets.Socket'. at System.Net.Sockets.Socket.BeginConnect(IPAddress address, Int32 port, AsyncCallback requestCallback, Object state) at System.Net.Sockets.TcpClient.BeginConnect(IPAddress address, Int32 port, AsyncCallback requestCallback, Object state) at System.Threading.Tasks.TaskFactory1.FromAsyncImpl[TArg1,TArg2](Func5 beginMethod, Func2 endFunction, Action1 endAction, TArg1 arg1, TArg2 arg2, Object state, TaskCreationOptions creationOptions) at System.Net.Sockets.TcpClient.ConnectAsync(IPAddress address, Int32 port) at MySqlConnector.Core.ServerSession.OpenTcpSocketAsync(ConnectionSettings cs, ILoadBalancer loadBalancer, IOBehavior ioBehavior, CancellationToken cancellationToken) in /_/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/Core/ServerSession.cs:line 368 at MySqlConnector.Core.ConnectionPool.GetSessionAsync(MySqlConnection connection, Int32 startTickCount, IOBehavior ioBehavior, CancellationToken cancellationToken) in /_/src/MySqlConnector/Core/ConnectionPool.cs:line 142

[vaital3000]

Hi! We also found this problem in another application, when we ran it in kubernetes. There was no problem in Windows VM.