Expected state to be Connected but was Failed.

[jon-swain-autocab]

Hi,

Version: 0.49.3 (Also confirmed as issue on 0.56.0)

We are getting the following exception whenever we lose connection to the MySql server.

This can easily be re-created with a simple console application which runs the simple query 'SELECT 1' every second (with a try catch around it). Whilst the application is running stop and then restart the MySql server and the exception will be logged.

It seems the issue is that the State property is set to 'Open' but internally you have a stats set to 'Failed'

System.InvalidOperationException: Expected state to be Connected but was Failed.
at MySqlConnector.Core.ServerSession.VerifyState(State state)
at MySqlConnector.Core.ServerSession.StartQuerying(MySqlCommand command)
at MySqlConnector.Core.TextCommandExecutor.d__1.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 MySql.Data.MySqlClient.MySqlCommand.d__63.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 MySql.Data.MySqlClient.MySqlCommand.ExecuteScalar()
at GhostAccounts.Server.Database.MaxJobIdImportedIntoDatabase.GetValue(ConnectionWrapper aConnection) in C:\Autocab\Ghost-git1\GhostAccounts.Server\Database\MaxJobIdImportedIntoDatabase.cs:line 31
at Gpc.Server.Accounts.AccountsServer.ProcessNextBatchOfJobMessagesFromDispatcher() in C:\Autocab\Ghost-git1\Server.Accounts\AccountsServer.cs:line 145
at Gpc.Server.Accounts.AccountsServer.ProcessNextBatchOfJobMessagesFromDispatcherIfItsTimeToDoSo() in C:\Autocab\Ghost-git1\Server.Accounts\AccountsServer.cs:line 127 --> Critical exception caught in Gpc.Server.Accounts.AccountsServer.ProcessNextBatchOfJobMessagesFromDispatcherIfItsTimeToDoSo

[bgrainger]

Are you expecting a MySqlException to be thrown instead?

Connector/NET throws the following (if the server is shut down while querying):

MySql.Data.MySqlClient.MySqlException (0x80004005): Fatal error encountered during command execution.
 ---> MySql.Data.MySqlClient.MySqlException (0x80004005): Fatal error encountered attempting to read the resultset.
 ---> MySql.Data.MySqlClient.MySqlException (0x80004005): Reading from the stream has failed.
 ---> System.IO.IOException: Unable to read data from the transport connection: An established connection was aborted by the software in your host machine.
 ---> System.Net.Sockets.SocketException: An established connection was aborted by the software in your host machine
   at System.Net.Sockets.Socket.Receive(Byte[] buffer, Int32 offset, Int32 size, SocketFlags socketFlags)
   at System.Net.Sockets.NetworkStream.Read(Byte[] buffer, Int32 offset, Int32 size)
   --- End of inner exception stack trace ---
   at System.Net.Sockets.NetworkStream.Read(Byte[] buffer, Int32 offset, Int32 size)
   at MySql.Data.MySqlClient.TimedStream.Read(Byte[] buffer, Int32 offset, Int32 count)
   at MySql.Data.MySqlClient.MySqlStream.ReadFully(Stream stream, Byte[] buffer, Int32 offset, Int32 count)
   at MySql.Data.MySqlClient.MySqlStream.LoadPacket()
   at MySql.Data.MySqlClient.MySqlStream.LoadPacket()
   at MySql.Data.MySqlClient.MySqlStream.ReadPacket()
   at MySql.Data.MySqlClient.NativeDriver.GetResult(Int32& affectedRow, Int64& insertedId)
   at MySql.Data.MySqlClient.Driver.GetResult(Int32 statementId, Int32& affectedRows, Int64& insertedId)
   at MySql.Data.MySqlClient.Driver.NextResult(Int32 statementId, Boolean force)
   at MySql.Data.MySqlClient.MySqlDataReader.NextResult()
   at MySql.Data.MySqlClient.MySqlDataReader.NextResult()
   at MySql.Data.MySqlClient.MySqlCommand.ExecuteReader(CommandBehavior behavior)
   at MySql.Data.MySqlClient.MySqlCommand.ExecuteReader(CommandBehavior behavior)
   at MySql.Data.MySqlClient.MySqlCommand.ExecuteDbDataReader(CommandBehavior behavior)
   at System.Data.Common.DbCommand.System.Data.IDbCommand.ExecuteReader(CommandBehavior behavior)

[jon-swain-autocab]

No i am expecting the State property on MySqlConnection object to be 'Broken' or 'Closed' after the first exception due to the server being shutdown, however its not its still 'Open'

[bgrainger]

I'm not immediately able to reproduce the problem. When my test code calls ExecuteScalar("SELECT 1;") a MySqlException "Failed to read the result set." is thrown; afterwards, MySqlConnection.State is set to Closed.

[jon-swain-autocab]

I've included the code i have used to recreate it below. (you'll need to replace the credentials and the db name to test)

var builder = new MySqlConnectionStringBuilder( "server=localhost;user id=root;password=<password>;persist security info=True;default command timeout=0;use compression=False" )
{
    Database = "<db_name>",
    AllowUserVariables = true,
    Pooling = false,
    DefaultCommandTimeout = 0
};

using( var connection = new MySqlConnection( builder.ToString() ) )
{
    connection.Open();

    while( true )
    {
        Console.WriteLine( $"Connection state is now '{connection.State}' (Q to quit, any other key to continue)" );
        var key = Console.ReadKey();

        if( key.Key == ConsoleKey.Q )
        {
            break;
        }

        try
        {
            using( var command = connection.CreateCommand() )
            {
                command.CommandText = "SELECT 1";

                var output = command.ExecuteScalar();

                Console.WriteLine( $"SUCCESS: {command.CommandText} was successful" );
            }
        }
        catch( Exception ex )
        {
            Console.WriteLine( $"FAILURE: {ex.Message}" );
        }
    }
}

I recreated by following the steps below

• Run console app
• Press return to run first SELECT 1 query
• NOW Stop and restart MySQL
• Press return to run SELECT 1 query again (you will see FAILURE: Failed to read the result set.)
• Connection is now in state 'Open' but not internally where it is 'Failed'
• Press return to run SELECT 1 query again (you will see FAILURE: Expected state to be Connected but was Failed.)

[bgrainger]

Thanks for the example code; here is my output from it (with MySqlConnector 0.56.0):

Connection state is now 'Open' (Q to quit, any other key to continue)
 FAILURE: Failed to read the result set.
Connection state is now 'Closed' (Q to quit, any other key to continue)
 FAILURE: Connection must be Open; current state is Closed
Connection state is now 'Closed' (Q to quit, any other key to continue)

The connection state does correctly transition to Closed for me.

[bgrainger]

Can you post the full results of exception.ToString() for the FAILURE: Failed to read the result set. exception you're getting (the first exception)?

[jon-swain-autocab]

From my test program (NOTE i am using version 5.7.10 of MySql server)

Connection state is now 'Open' (Q to quit, any other key to continue)

SUCCESS: SELECT 1 was successful

Connection state is now 'Open' (Q to quit, any other key to continue)

FAILURE: MySql.Data.MySqlClient.MySqlException (0x80004005): Failed to read the result set. ---> System.Net.Sockets.SocketException (0x80004005): An established connection was aborted by the software in your host machine
   at System.Net.Sockets.Socket.Receive(Byte[] buffer, Int32 offset, Int32 size, SocketFlags socketFlags)
   at MySqlConnector.Protocol.Serialization.SocketByteHandler.<ReadBytesAsync>g__DoReadBytesSync|6_0(ArraySegment`1 buffer_)
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.ConfiguredValueTaskAwaitable`1.ConfiguredValueTaskAwaiter.GetResult()
   at MySqlConnector.Protocol.Serialization.BufferedByteReader.<ReadBytesAsync>d__2.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Threading.Tasks.ValueTask`1.get_Result()
   at MySqlConnector.Protocol.Serialization.ProtocolUtility.ReadPacketAsync(BufferedByteReader bufferedByteReader, IByteHandler byteHandler, Func`1 getNextSequenceNumber, ProtocolErrorBehavior protocolErrorBehavior, IOBehavior ioBehavior)
   at MySqlConnector.Protocol.Serialization.ProtocolUtility.DoReadPayloadAsync(BufferedByteReader bufferedByteReader, IByteHandler byteHandler, Func`1 getNextSequenceNumber, ArraySegmentHolder`1 previousPayloads, ProtocolErrorBehavior protocolErrorBehavior, IOBehavior ioBehavior)
   at MySqlConnector.Protocol.Serialization.StandardPayloadHandler.ReadPayloadAsync(ArraySegmentHolder`1 cache, ProtocolErrorBehavior protocolErrorBehavior, IOBehavior ioBehavior)
   at MySqlConnector.Core.ServerSession.ReceiveReplyAsync(IOBehavior ioBehavior, CancellationToken cancellationToken)
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at MySqlConnector.Core.ServerSession.TryAsyncContinuation(Task`1 task)
   at System.Threading.Tasks.ContinuationResultTaskFromResultTask`2.InnerInvoke()
   at System.Threading.Tasks.Task.Execute()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.ConfiguredValueTaskAwaitable`1.ConfiguredValueTaskAwaiter.GetResult()
   at MySqlConnector.Core.ResultSet.<ReadResultSetHeaderAsync>d__1.MoveNext()
   at MySql.Data.MySqlClient.MySqlDataReader.ActivateResultSet(ResultSet resultSet)
   at MySql.Data.MySqlClient.MySqlDataReader.<ReadFirstResultSetAsync>d__96.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at MySql.Data.MySqlClient.MySqlDataReader.<CreateAsync>d__95.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at MySqlConnector.Core.TextCommandExecutor.<ExecuteReaderAsync>d__1.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at MySql.Data.MySqlClient.MySqlCommand.<ExecuteScalarAsync>d__63.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at MySql.Data.MySqlClient.MySqlCommand.ExecuteScalar()
   at MySqlConnectorTestApp.Program.Main(String[] args) in C:\Development\Sandbox\MySqlConnectorTestApp\MySqlConnectorTestApp\Program.cs:line 38

Connection state is now 'Open' (Q to quit, any other key to continue)

FAILURE: System.InvalidOperationException: Expected state to be Connected but was Failed.
   at MySqlConnector.Core.ServerSession.VerifyState(State state)
   at MySqlConnector.Core.ServerSession.StartQuerying(MySqlCommand command)
   at MySqlConnector.Core.TextCommandExecutor.<ExecuteReaderAsync>d__1.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at MySql.Data.MySqlClient.MySqlCommand.<ExecuteScalarAsync>d__63.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at MySql.Data.MySqlClient.MySqlCommand.ExecuteScalar()
   at MySqlConnectorTestApp.Program.Main(String[] args) in C:\Development\Sandbox\MySqlConnectorTestApp\MySqlConnectorTestApp\Program.cs:line 38

Connection state is now 'Open' (Q to quit, any other key to continue)

[bgrainger]

I still can't repro this problem, and am unsure why ServerSession.TryAsyncContinuation (in your call stack) isn't setting the connection state to failed.

It seems odd that you don't have any line numbers in your stack traces; they would normally be included.

What version of MySqlConnector are you testing with, what is your client OS version, and what .NET Framework (or .NET Core) are you using?

[bgrainger]

I still can't repro this problem

I wasn't using Pooling=false; disabling connection pooling exposes the issue.

[bgrainger]

The bug is that ServerSession.OwningConnection was never set when Pooling=false, so the state of the related MySqlConnection couldn't be updated.

[bgrainger]

Fixed in 0.57.0-beta6.

[jon-swain-autocab]

Thats great news