search

mysql-net / MySqlConnector

MySQL Connector for .NET
https://mysqlconnector.net
MIT License
1.39k stars 336 forks source link

SslStream System.ObjectDisposedException #873

Closed laurent-jeancler-realist closed 3 years ago

laurent-jeancler-realist commented 4 years ago

Hi, Since we had some some "Packet received out-of-order. Expected 1; got 0." errors happening in our ASP Net application with MySqlConnector, we decided to update to 0.69.8.

The error seems to have changed now, and we have now some errors related to SslStream being disposed twice I guess. It always happens inside a "fire and forget" task being triggered by a controller action.

We are using MySqlConnector 0.69.8, with MySQL 8.0.13 and Pomelo 2.2.6, the application is Asp.Net (.Net Framework 4.7.1), no async code, and are facing regularly that kind of error :

> System.ObjectDisposedException: Impossible d'accéder à un objet supprimé.
> Nom de l'objet : 'SslStream'.
>    à System.Net.Security.SslState.CheckThrow(Boolean authSuccessCheck, Boolean shutdownCheck)
>    à System.Net.Security.SslState.get_SecureStream()
>    à System.Net.Security.SslStream.Write(Byte[] buffer, Int32 offset, Int32 count)
>    à MySqlConnector.Utilities.Utility.Write(Stream stream, ReadOnlyMemory`1 data)
>    à MySqlConnector.Protocol.Serialization.StreamByteHandler.WriteBytesAsync(ReadOnlyMemory`1 data, IOBehavior ioBehavior)
> --- Fin de la trace de la pile à partir de l'emplacement précédent au niveau duquel l'exception a été levée ---
>    à System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
>    à System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
>    à MySqlConnector.Protocol.Serialization.ProtocolUtility.<<WritePacketAsync>g__WritePacketAsyncAwaited|8_0>d.MoveNext()
> --- Fin de la trace de la pile à partir de l'emplacement précédent au niveau duquel l'exception a été levée ---
>    à System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
>    à System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
>    à MySqlConnector.Core.ServerSession.<DisposeAsync>d__67.MoveNext()
> --- Fin de la trace de la pile à partir de l'emplacement précédent au niveau duquel l'exception a été levée ---
>    à System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
>    à MySqlConnector.Core.ConnectionPool.<GetSessionAsync>d__10.MoveNext()
> --- Fin de la trace de la pile à partir de l'emplacement précédent au niveau duquel l'exception a été levée ---
>    à System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
>    à System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
>    à MySql.Data.MySqlClient.MySqlConnection.<CreateSessionAsync>d__111.MoveNext()
> --- Fin de la trace de la pile à partir de l'emplacement précédent au niveau duquel l'exception a été levée ---
>    à System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
>    à System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
>    à MySql.Data.MySqlClient.MySqlConnection.<OpenAsync>d__27.MoveNext()
> --- Fin de la trace de la pile à partir de l'emplacement précédent au niveau duquel l'exception a été levée ---
>    à System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
>    à System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
>    à MySql.Data.MySqlClient.MySqlConnection.Open()
>    à Microsoft.EntityFrameworkCore.Storage.RelationalConnection.OpenDbConnection(Boolean errorsExpected)
>    à Microsoft.EntityFrameworkCore.Storage.RelationalConnection.Open(Boolean errorsExpected)
>    à Microsoft.EntityFrameworkCore.Query.Internal.QueryingEnumerable`1.Enumerator.BufferlessMoveNext(DbContext _, Boolean buffer)
>    à Pomelo.EntityFrameworkCore.MySql.Storage.Internal.MySqlExecutionStrategy.Execute[TState,TResult](TState state, Func`3 operation, Func`3 verifySucceeded)
>    à Microsoft.EntityFrameworkCore.Query.Internal.QueryingEnumerable`1.Enumerator.MoveNext()
>    à System.Linq.Enumerable.FirstOrDefault[TSource](IEnumerable`1 source)
>    à Microsoft.EntityFrameworkCore.Query.Internal.LinqOperatorProvider.ResultEnumerable`1.GetEnumerator()
>    à Microsoft.EntityFrameworkCore.Query.Internal.LinqOperatorProvider.<_TrackEntities>d__17`2.MoveNext()
>    à Microsoft.EntityFrameworkCore.Query.Internal.LinqOperatorProvider.ExceptionInterceptor`1.EnumeratorExceptionInterceptor.MoveNext()
>    à System.Linq.Enumerable.First[TSource](IEnumerable`1 source)
>    à Microsoft.EntityFrameworkCore.Query.Internal.QueryCompiler.<>c__DisplayClass15_1`1.<CompileQueryCore>b__0(QueryContext qc)
>    à Microsoft.EntityFrameworkCore.Internal.EntityFinder`1.Find(Object[] keyValues)
>    à GAFront.Controllers.ContactController.<>c__DisplayClass24_0.<SendContactEmails>b__0() dans C:\AzureDevOpsAgents\artifacts_agent_cluster_2_1\_work\14\s\GA.Net\GAFront\Controllers\ContactController.cs:ligne 670
>    à System.Threading.Tasks.Task.Execute()
bgrainger commented 4 years ago

Your exception call stack doesn't have line numbers, but it looks like it's coming from this line in ServerSession.DisposeAsync: https://github.com/mysql-net/MySqlConnector/blob/da1e39e2c5f2201f1a276ce67ef35d5649a9244b/src/MySqlConnector/Core/ServerSession.cs#L318

However, there's already a catch (ObjectDisposedException) handler, which was added in #411.

Is this exception going unhandled and crashing the application, or is this possibly just logging a first-chance exception that will get handled by MySqlConnector?

laurent-jeancler-realist commented 4 years ago

Thanks for your answer.

There is no application crash as code throwing that exception is run in a delegate parameter of Task.Run(). It is a "Fire and Forget" async execution (as task is not awaited)

Here is the code that throw the exception and we are logging the exception in our centralized log system.

// running a fire and forget task
Task.Run(() =>
{
    try
    {
        int cId = contactId;
        int vId = visitorId;
        string aId = accountId;
        string adId = advertId;
        _logger.LogInformation($"Task.Run SendContactEmails contactId:{cId} - visitorId:{vId} - accountId:{aId} - advertId:{adId}");

        // create separate scope for Scope registered dependencies.
        using (IServiceScope scope = _serviceScopeFactory.CreateScope())
        {
            IUnitOfWork uow = scope.ServiceProvider.GetService<IUnitOfWork>();
            IAccountRepository accountRepository = scope.ServiceProvider.GetService<IAccountRepository>();
            IMailService mailService = scope.ServiceProvider.GetService<IMailService>();

            // todo: refactor bad practice to call repositories in controller, anyway this whole thing need to be called from another process and used a queuing system
            Contact contact = uow.Repository<Contact>().Find(cId);
            Visitor visitor = uow.Repository<Visitor>().Find(vId);
            // use accountRepository as we need account.Client afterwards
            Account account = accountRepository.GetAccountById(aId);
            Advert advert = uow.Repository<Advert>().Query().Include(x => x.AdvertsDetails).GetFirstOrDefault(a => a.AdvertId == adId);
            mailService.SendContactEmails(contact, visitor, account, advert);
        }
    }
    catch (Exception e)
    {
        _logger.LogError(e, $"Error in SendContactEmails contactId {contactId} - userNumber {visitorId} - accountId {accountId} - advertId {advertId} - {e}");
        throw;
    }
});

I know that you added some defensive code (try catch) for such cases but it seems not being enough in my case. The exception is unhandled and catched by our logging mechanism.

bgrainger commented 4 years ago

it seems not being enough in my case. The exception is unhandled and catched by our logging mechanism

I'm not yet understanding how this is possible, based on the call stack. I'm not sure what I'm missing.

laurent-jeancler-realist commented 4 years ago

Hello,

We have changed how we handled long running tasks, by using a message queue service instead of a "Fire and forget" task and we do not see that error anymore.

So I close that issue.

Thanks @bgrainger for your help and your great product.

Best regards,

Laurent.

laurent-jeancler-realist commented 4 years ago

Hi, the issue has resurfaced again.

I'm still using MySqlConnector 0.69.8.

Here is the ObjectDisposedException stack trace :

System.ObjectDisposedException: Cannot access a disposed object. Nom de l'objet : 'SslStream'. à System.Net.Security.SslState.CheckThrow(Boolean authSuccessCheck, Boolean shutdownCheck) à System.Net.Security.SslState.get_SecureStream() à System.Net.Security.SslStream.Write(Byte[] buffer, Int32 offset, Int32 count) à MySqlConnector.Utilities.Utility.Write(Stream stream, ReadOnlyMemory1 data) à MySqlConnector.Protocol.Serialization.StreamByteHandler.WriteBytesAsync(ReadOnlyMemory1 data, IOBehavior ioBehavior) --- Fin de la trace de la pile à partir de l'emplacement précédent au niveau duquel l'exception a été levée --- à System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() à System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) à MySqlConnector.Protocol.Serialization.ProtocolUtility.<<WritePacketAsync>g__WritePacketAsyncAwaited|8_0>d.MoveNext() --- Fin de la trace de la pile à partir de l'emplacement précédent au niveau duquel l'exception a été levée --- à System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() à System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) à MySqlConnector.Core.ServerSession.<DisposeAsync>d__67.MoveNext() --- Fin de la trace de la pile à partir de l'emplacement précédent au niveau duquel l'exception a été levée --- à System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() à MySqlConnector.Core.ConnectionPool.<GetSessionAsync>d__10.MoveNext() --- Fin de la trace de la pile à partir de l'emplacement précédent au niveau duquel l'exception a été levée --- à System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() à System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) à MySql.Data.MySqlClient.MySqlConnection.<CreateSessionAsync>d__111.MoveNext() --- Fin de la trace de la pile à partir de l'emplacement précédent au niveau duquel l'exception a été levée --- à System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() à System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) à MySql.Data.MySqlClient.MySqlConnection.<OpenAsync>d__27.MoveNext() --- Fin de la trace de la pile à partir de l'emplacement précédent au niveau duquel l'exception a été levée --- à System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw() à System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) à MySql.Data.MySqlClient.MySqlConnection.Open() à Microsoft.EntityFrameworkCore.Storage.RelationalConnection.OpenDbConnection(Boolean errorsExpected) à Microsoft.EntityFrameworkCore.Storage.RelationalConnection.Open(Boolean errorsExpected) à Microsoft.EntityFrameworkCore.Query.Internal.QueryingEnumerable1.Enumerator.BufferlessMoveNext(DbContext _, Boolean buffer) à Microsoft.EntityFrameworkCore.Storage.ExecutionStrategy.ExecuteImplementation[TState,TResult](Func3 operation, Func3 verifySucceeded, TState state) à Microsoft.EntityFrameworkCore.Query.Internal.QueryingEnumerable1.Enumerator.MoveNext() à System.Linq.Enumerable.FirstOrDefault[TSource](IEnumerable1 source) à Microsoft.EntityFrameworkCore.Query.Internal.LinqOperatorProvider.ResultEnumerable1.GetEnumerator() à Microsoft.EntityFrameworkCore.Query.Internal.LinqOperatorProvider.<_TrackEntities>d__172.MoveNext() à Microsoft.EntityFrameworkCore.Query.Internal.LinqOperatorProvider.ExceptionInterceptor1.EnumeratorExceptionInterceptor.MoveNext() à System.Linq.Enumerable.First[TSource](IEnumerable1 source) à Microsoft.EntityFrameworkCore.Query.Internal.QueryCompiler.<>cDisplayClass15_11.<CompileQueryCore>b__0(QueryContext qc) à Buffalo.Repositories.Repository1.Find(Expression1 filter, Expression1[] relations) à GAServices.CustomRepositories.PropertiesVisitsRepository.AddVisit(String id, String lang) dans C:\AzureDevOpsAgents\artifacts_agent_cluster_2_1_work\14\s\GA.Net\GAServices\CustomRepositories\PropertiesVisitsRepository.cs:ligne 37 à GAFront.Controllers.PropertyController.TagVisit(String id) dans C:\AzureDevOpsAgents\artifacts_agent_cluster_2_1_work\14\s\GA.Net\GAFront\Controllers\PropertyController.cs:ligne 205 à lambda_method(Closure , ControllerBase , Object[] ) à System.Web.Mvc.ReflectedActionDescriptor.Execute(ControllerContext controllerContext, IDictionary2 parameters) à System.Web.Mvc.ControllerActionInvoker.InvokeActionMethod(ControllerContext controllerContext, ActionDescriptor actionDescriptor, IDictionary2 parameters) à System.Web.Mvc.Async.AsyncControllerActionInvoker.b39(IAsyncResult asyncResult, ActionInvocation innerInvokeState) à System.Web.Mvc.Async.AsyncResultWrapper.WrappedAsyncResult2.CallEndDelegate(IAsyncResult asyncResult) à System.Web.Mvc.Async.AsyncControllerActionInvoker.EndInvokeActionMethod(IAsyncResult asyncResult) à System.Web.Mvc.Async.AsyncControllerActionInvoker.AsyncInvocationWithFilters.<InvokeActionMethodFilterAsynchronouslyRecursive>b__3d() à System.Web.Mvc.Async.AsyncControllerActionInvoker.AsyncInvocationWithFilters.<>c__DisplayClass46.<InvokeActionMethodFilterAsynchronouslyRecursive>b__3f()

And we are explicitly catching "System.ObjectDisposedException" in the code :

`[HttpGet] public ActionResult TagVisit(string id) { try { if (!GAContext.Current.IsSearchRobot && !string.IsNullOrWhiteSpace(id) && (GAContext.Current.UrlReferrer == null || !GAContext.Current.UrlReferrer.Query.Contains("avoidCaching=1"))) { _publicationService.VisitsAdvert(id, GAContext.Current.Lang); } return new FilePathResult(Server.MapPath("~/Content/resources/img/1x1.png"), "image/png"); } catch (ObjectDisposedException ex) { _logger.LogError(ex, "TagVissitException", null); throw; }

    }`

Considering the code on github, I don't know how this is possible.

Regards,

Laurent.

laurent-jeancler-realist commented 4 years ago

Hello, We have tons of "ObjectDisposedException" in our centralized log system now. To figure out why this is happenning, we chose to log "MySqlConnector" internals using https://mysqlconnector.net/overview/logging/

And we share ou findings with you. The "ObjectDisposedException" surfaces when processing a http request in asp.net mvc

for the same http request we have the following workflow (using MySqlConnector source code and internal logs)

  1. "Pool1 waiting for an available session" log in ConnectionPool.GetSessionAsync
  2. "Pool1 found an existing session; checking it for validity" log in ConnectionPool.GetSessionAsync
  3. "Session1.4 ServerVersion=8.0.21 supports reset connection; sending reset connection request" log in ServerSession.TryResetConnectionAsync
  4. "Session1.4 setting state to Failed" log in ServerSession.SetFailed with that exception
System.ObjectDisposedException: Cannot access a disposed object.
Nom de l'objet : 'SslStream'.
   à System.Net.Security.SslState.CheckThrow(Boolean authSuccessCheck, Boolean shutdownCheck)
   à System.Net.Security.SslState.get_SecureStream()
   à System.Net.Security.SslStream.Write(Byte[] buffer, Int32 offset, Int32 count)
   à MySqlConnector.Utilities.Utility.Write(Stream stream, ReadOnlyMemory'1 data)
   à MySqlConnector.Protocol.Serialization.StreamByteHandler.WriteBytesAsync(ReadOnlyMemory'1 data, IOBehavior ioBehavior)
--- Fin de la trace de la pile à partir de l'emplacement précédent au niveau duquel l'exception a été levée ---
   à System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   à System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   à MySqlConnector.Protocol.Serialization.ProtocolUtility.<<WritePacketAsync>g__WritePacketAsyncAwaited
8_0>d.MoveNext()
--- Fin de la trace de la pile à partir de l'emplacement précédent au niveau duquel l'exception a été levée ---
   à System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   à System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   à MySqlConnector.Core.ServerSession.<SendReplyAsyncAwaited>d__80.MoveNext()
--- Fin de la trace de la pile à partir de l'emplacement précédent au niveau duquel l'exception a été levée ---",
  1. "Pool1 disposing created Session1.4 due to exception: Cannot access a disposed object.\r\nObject name: 'SslStream'." log in ConnectionPool.GetSessionAsync
  2. "Session1.4 sending QUIT command" log in ServerSession.DisposeAsync
  3. "Session1.4 closing stream/socket" log in "ServerSession.ShutdownSocket"
  4. AND finally the exception is thrown
"System.ObjectDisposedException: Cannot access a disposed object.
Nom de l'objet : 'SslStream'.
   à System.Net.Security.SslState.CheckThrow(Boolean authSuccessCheck, Boolean shutdownCheck)
   à System.Net.Security.SslState.get_SecureStream()
   à System.Net.Security.SslStream.Write(Byte[] buffer, Int32 offset, Int32 count)
   à MySqlConnector.Utilities.Utility.Write(Stream stream, ReadOnlyMemory'1 data)
   à MySqlConnector.Protocol.Serialization.StreamByteHandler.WriteBytesAsync(ReadOnlyMemory'1 data, IOBehavior ioBehavior)
--- Fin de la trace de la pile à partir de l'emplacement précédent au niveau duquel l'exception a été levée ---
   à System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   à System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   à MySqlConnector.Protocol.Serialization.ProtocolUtility.<<WritePacketAsync>g__WritePacketAsyncAwaited8_0>d.MoveNext()
--- Fin de la trace de la pile à partir de l'emplacement précédent au niveau duquel l'exception a été levée ---
   à System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   à System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   à MySqlConnector.Core.ServerSession.<DisposeAsync>d__67.MoveNext()
--- Fin de la trace de la pile à partir de l'emplacement précédent au niveau duquel l'exception a été levée ---
   à System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   à MySqlConnector.Core.ConnectionPool.<GetSessionAsync>d__10.MoveNext()
--- Fin de la trace de la pile à partir de l'emplacement précédent au niveau duquel l'exception a été levée ---
   à System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   à System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   à MySql.Data.MySqlClient.MySqlConnection.<CreateSessionAsync>d__111.MoveNext()
--- Fin de la trace de la pile à partir de l'emplacement précédent au niveau duquel l'exception a été levée ---
   à System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   à System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   à MySql.Data.MySqlClient.MySqlConnection.<OpenAsync>d__27.MoveNext()
--- Fin de la trace de la pile à partir de l'emplacement précédent au niveau duquel l'exception a été levée ---
   à System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   à System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   à MySql.Data.MySqlClient.MySqlConnection.Open()
   à Microsoft.EntityFrameworkCore.Storage.RelationalConnection.OpenDbConnection(Boolean errorsExpected)
   à Microsoft.EntityFrameworkCore.Storage.RelationalConnection.Open(Boolean errorsExpected)
   à Microsoft.EntityFrameworkCore.Query.Internal.QueryingEnumerable'1.Enumerator.BufferlessMoveNext(DbContext _, Boolean buffer)
   à Pomelo.EntityFrameworkCore.MySql.Storage.Internal.MySqlExecutionStrategy.Execute[TState,TResult](TState state, Func'3 operation, Func'3 verifySucceeded)
   à Microsoft.EntityFrameworkCore.Query.Internal.QueryingEnumerable'1.Enumerator.MoveNext()
   à System.Linq.Enumerable.FirstOrDefault[TSource](IEnumerable'1 source)
   à Microsoft.EntityFrameworkCore.Query.Internal.LinqOperatorProvider.ResultEnumerable'1.GetEnumerator()
   à Microsoft.EntityFrameworkCore.Query.Internal.LinqOperatorProvider.<_TrackEntities>d__17'2.MoveNext()
   à Microsoft.EntityFrameworkCore.Query.Internal.LinqOperatorProvider.ExceptionInterceptor'1.EnumeratorExceptionInterceptor.MoveNext()
   à System.Linq.Enumerable.First[TSource](IEnumerable'1 source)
   à Microsoft.EntityFrameworkCore.Query.Internal.QueryCompiler.<>c__DisplayClass15_1'1.<CompileQueryCore>b__0(QueryContext qc)
   à Buffalo.Repositories.Repository'1.Find(Expression'1 filter, Expression'1[] relations)
   à GAServices.CustomRepositories.PropertiesVisitsRepository.AddVisit(String id, String lang) dans C:\\AzureDevOpsAgents\\artifacts_agent_cluster_1_1\\_work\\14\\s\\GA.Net\\GAServices\\CustomRepositories\\PropertiesVisitsRepository.cs:ligne 37
   à GAFront.Controllers.PropertyController.TagVisit(String id) dans C:\\AzureDevOpsAgents\\artifacts_agent_cluster_1_1\\_work\\14\\s\\GA.Net\\GAFront\\Controllers\\PropertyController.cs:ligne 194
   à lambda_method(Closure , ControllerBase , Object[] )
   à System.Web.Mvc.ReflectedActionDescriptor.Execute(ControllerContext controllerContext, IDictionary'2 parameters)
   à System.Web.Mvc.ControllerActionInvoker.InvokeActionMethod(ControllerContext controllerContext, ActionDescriptor actionDescriptor, IDictionary'2 parameters)
   à System.Web.Mvc.Async.AsyncControllerActionInvoker.<BeginInvokeSynchronousActionMethod>b__39(IAsyncResult asyncResult, ActionInvocation innerInvokeState)
   à System.Web.Mvc.Async.AsyncResultWrapper.WrappedAsyncResult'2.CallEndDelegate(IAsyncResult asyncResult)
   à System.Web.Mvc.Async.AsyncControllerActionInvoker.EndInvokeActionMethod(IAsyncResult asyncResult)
   à System.Web.Mvc.Async.AsyncControllerActionInvoker.AsyncInvocationWithFilters.<InvokeActionMethodFilterAsynchronouslyRecursive>b__3d()
   à System.Web.Mvc.Async.AsyncControllerActionInvoker.AsyncInvocationWithFilters.<>c__DisplayClass46.<InvokeActionMethodFilterAsynchronouslyRecursive>b__3f()
   à System.Web.Mvc.Async.AsyncControllerActionInvoker.AsyncInvocationWithFilters.<>c__DisplayClass46.<InvokeActionMethodFilterAsynchronouslyRecursive>b__3f()
   à System.Web.Mvc.Async.AsyncControllerActionInvoker.AsyncInvocationWithFilters.<>c__DisplayClass46.<InvokeActionMethodFilterAsynchronouslyRecursive>b__3f()
   à System.Web.Mvc.Async.AsyncControllerActionInvoker.AsyncInvocationWithFilters.<>c__DisplayClass46.<InvokeActionMethodFilterAsynchronouslyRecursive>b__3f()
   à System.Web.Mvc.Async.AsyncControllerActionInvoker.AsyncInvocationWithFilters.<>c__DisplayClass46.<InvokeActionMethodFilterAsynchronouslyRecursive>b__3f()
   à System.Web.Mvc.Async.AsyncControllerActionInvoker.AsyncInvocationWithFilters.<>c__DisplayClass46.<InvokeActionMethodFilterAsynchronouslyRecursive>b__3f()
   à System.Web.Mvc.Async.AsyncControllerActionInvoker.AsyncInvocationWithFilters.<>c__DisplayClass46.<InvokeActionMethodFilterAsynchronouslyRecursive>b__3f()
   à System.Web.Mvc.Async.AsyncControllerActionInvoker.AsyncInvocationWithFilters.<>c__DisplayClass46.<InvokeActionMethodFilterAsynchronouslyRecursive>b__3f()
   à System.Web.Mvc.Async.AsyncControllerActionInvoker.EndInvokeActionMethodWithFilters(IAsyncResult asyncResult)
   à System.Web.Mvc.Async.AsyncControllerActionInvoker.<>c__DisplayClass21.<>c__DisplayClass2b.<BeginInvokeAction>b__1c()
   à System.Web.Mvc.Async.AsyncControllerActionInvoker.<>c__DisplayClass21.<BeginInvokeAction>b__1e(IAsyncResult asyncResult)
   à System.Web.Mvc.Async.AsyncControllerActionInvoker.EndInvokeAction(IAsyncResult asyncResult)
   à System.Web.Mvc.Controller.<BeginExecuteCore>b__1d(IAsyncResult asyncResult, ExecuteCoreState innerState)
   à System.Web.Mvc.Async.AsyncResultWrapper.WrappedAsyncVoid'1.CallEndDelegate(IAsyncResult asyncResult)
   à System.Web.Mvc.Controller.EndExecuteCore(IAsyncResult asyncResult)"

And I think that the last call stack is wrong and should be the callstack in "4." and that will explain why the ObjectDisposedException is not catched by your code. Because "ObjectDisposedException" seems to be thrown in ServerSession.TryResetConnectionAsync method call in ConnectionPool.GetSessionAsync That exception is then thrown in "try catch" block at the end of ConnectionPool.GetSessionAsync method

catch (Exception ex)
{
    if (session is not null)
    {
        try
        {
            Log.Debug(ex, "Pool{0} disposing created Session{1} due to exception: {2}", m_logArguments[0], session.Id, ex.Message);
            AdjustHostConnectionCount(session, -1);
            await session.DisposeAsync(ioBehavior, CancellationToken.None).ConfigureAwait(false);
        }
        catch (Exception unexpectedException)
        {
            Log.Error(unexpectedException, "Pool{0} unexpected error in GetSessionAsync: {1}", m_logArguments[0], unexpectedException.Message);
        }
    }
    m_sessionSemaphore.Release();
    throw; <--- HERE
}

Regards,

Laurent.

bgrainger commented 4 years ago

Thanks for the detailed reply!

I'm still not sure how to interpret these call stacks, but there may be a problem with exceptions being thrown from catch blocks.

I think it should be safe to catch (ObjectDisposedException) in TryResetConnectionAsync, but I'm not 100% sure if that will solve your problem or not. (I don't know if I can inject failures to try to reproduce your problem here.)

Are you still using 0.69.9 (and need a fix in that release) or have you updated to 1.0.1?

laurent-jeancler-realist commented 4 years ago

Hi,

Yes, we are still using 0.69.8, so if you can update the 0.69.8 to 0.69.9 that will be great !

Best regards,

Laurent Jeancler

bgrainger commented 4 years ago

0.69.9 has already shipped, but this fix could go in 0.69.10.

bgrainger commented 4 years ago

I published 0.69.10 with your fix; please let me know if it solves this problem!

laurent-jeancler-realist commented 4 years ago

Thank's a lot for helping us. After updating our main site in production with 0.69.10, we dit not see any ObjectDisposedException exceptions anymore.

So I will close that issue in a few days.

But, we still have some errors regarding the MySql connection (always the same error in ServerSession.ReceiveReplyAsync, the internal log is Session1.207 failed in ReceiveReplyAsync)

System.IO.IOException: Unable to read data from the transport connection: Une opération de blocage a été interrompue par un appel à WSACancelBlockingCall. ---> System.Net.Sockets.SocketException: Une opération de blocage a été interrompue par un appel à WSACancelBlockingCall
   à System.Net.Sockets.NetworkStream.Read(Byte[] buffer, Int32 offset, Int32 size)
   --- Fin de la trace de la pile d'exception interne ---
   à System.Net.Sockets.NetworkStream.Read(Byte[] buffer, Int32 offset, Int32 size)
   à System.Net.FixedSizeReader.ReadPacket(Byte[] buffer, Int32 offset, Int32 count)
   à System.Net.Security._SslStream.StartFrameHeader(Byte[] buffer, Int32 offset, Int32 count, AsyncProtocolRequest asyncRequest)
   à System.Net.Security._SslStream.StartReading(Byte[] buffer, Int32 offset, Int32 count, AsyncProtocolRequest asyncRequest)
   à System.Net.Security._SslStream.ProcessRead(Byte[] buffer, Int32 offset, Int32 count, AsyncProtocolRequest asyncRequest)
   à System.Net.Security.SslStream.Read(Byte[] buffer, Int32 offset, Int32 count)
   à MySqlConnector.Utilities.Utility.Read(Stream stream, Memory`1 buffer)
   à MySqlConnector.Protocol.Serialization.StreamByteHandler.<ReadBytesAsync>g__DoReadBytesSync|6_0(Memory`1 buffer_)
--- Fin de la trace de la pile à partir de l'emplacement précédent au niveau duquel l'exception a été levée ---
   à System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   à MySqlConnector.Protocol.Serialization.BufferedByteReader.<ReadBytesAsync>d__2.MoveNext()
--- Fin de la trace de la pile à partir de l'emplacement précédent au niveau duquel l'exception a été levée ---
   à System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   à System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   à MySqlConnector.Protocol.Serialization.ProtocolUtility.ReadPacketAsync(BufferedByteReader bufferedByteReader, IByteHandler byteHandler, Func`1 getNextSequenceNumber, ProtocolErrorBehavior protocolErrorBehavior, IOBehavior ioBehavior)
   à MySqlConnector.Protocol.Serialization.ProtocolUtility.DoReadPayloadAsync(BufferedByteReader bufferedByteReader, IByteHandler byteHandler, Func`1 getNextSequenceNumber, ArraySegmentHolder`1 previousPayloads, ProtocolErrorBehavior protocolErrorBehavior, IOBehavior ioBehavior)
   à MySqlConnector.Protocol.Serialization.StandardPayloadHandler.ReadPayloadAsync(ArraySegmentHolder`1 cache, ProtocolErrorBehavior protocolErrorBehavior, IOBehavior ioBehavior)
   à MySqlConnector.Core.ServerSession.ReceiveReplyAsync(IOBehavior ioBehavior, CancellationToken cancellationToken)
--- Fin de la trace de la pile à partir de l'emplacement précédent au niveau duquel l'exception a été levée ---
   à System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   à System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   à MySqlConnector.Core.ServerSession.<ReceiveReplyAsyncAwaited>d__78.MoveNext()
--- Fin de la trace de la pile à partir de l'emplacement précédent au niveau duquel l'exception a été levée ---
   à System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   à MySqlConnector.Core.ResultSet.<ReadResultSetHeaderAsync>d__2.MoveNext()
bgrainger commented 4 years ago

Google translates that as A blocking operation was interrupted by a call to WSACancelBlockingCall.

Based on the call stack, it looks like StreamByteHandler.ReadBytesAsync is calling DoReadBytesSync, which means a sync I/O read was started on a Stream that does support read timeouts. I can't tell if there is an actual timeout or not, and if it would manifest itself in this way.

It looks like your code may be executing a query; do you have a full callstack all the way up to application code?

bgrainger commented 3 years ago

Closing due to inactivity; please reopen if this is still an ongoing issue.