mysql-net / MySqlConnector

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

InvalidOperationException rolling back transaction #745

Open bgrainger opened 4 years ago

bgrainger commented 4 years ago

A recent integration test suite failed with:

SideBySide.CancelTests.CancelBatchBeforeRead [SKIP]
  ! SideBySide.CancelTests.CancelBatchBeforeRead [1ms]
The active test run was aborted. Reason: Test host process crashed : Unhandled exception. System.InvalidOperationException: This MySqlConnection is already in use. See https://fl.vu/mysql-conn-reuse
   at MySqlConnector.Core.ServerSession.StartQuerying(ICancellableCommand command) in /home/vsts/work/1/s/src/MySqlConnector/Core/ServerSession.cs:line 229
   at MySqlConnector.Core.CommandExecutor.ExecuteReaderAsync(IReadOnlyList`1 commands, ICommandPayloadCreator payloadCreator, CommandBehavior behavior, IOBehavior ioBehavior, CancellationToken cancellationToken) in /home/vsts/work/1/s/src/MySqlConnector/Core/CommandExecutor.cs:line 58
   at MySql.Data.MySqlClient.MySqlCommand.ExecuteNonQueryAsync(IOBehavior ioBehavior, CancellationToken cancellationToken) in /home/vsts/work/1/s/src/MySqlConnector/MySql.Data.MySqlClient/MySqlCommand.cs:line 230
   at MySql.Data.MySqlClient.MySqlCommand.ExecuteNonQuery() in /home/vsts/work/1/s/src/MySqlConnector/MySql.Data.MySqlClient/MySqlCommand.cs:line 74
   at MySqlConnector.Core.StandardEnlistedTransaction.OnRollback(Enlistment enlistment) in /home/vsts/work/1/s/src/MySqlConnector/Core/StandardEnlistedTransaction.cs:line 49
   at MySqlConnector.Core.EnlistedTransactionBase.System.Transactions.IEnlistmentNotification.Rollback(Enlistment enlistment) in /home/vsts/work/1/s/src/MySqlConnector/Core/EnlistedTransactionBase.cs:line 40
   at System.Transactions.VolatileEnlistmentAborting.EnterState(InternalEnlistment enlistment)
   at System.Transactions.VolatileEnlistmentActive.InternalAborted(InternalEnlistment enlistment)
   at System.Transactions.TransactionStateAborted.EnterState(InternalTransaction tx)
   at System.Transactions.TransactionStateActive.Rollback(InternalTransaction tx, Exception e)
   at System.Transactions.EnlistableStates.Timeout(InternalTransaction tx)
   at System.Transactions.Bucket.TimeoutTransactions()
   at System.Transactions.BucketSet.TimeoutTransactions()
   at System.Transactions.TransactionTable.ThreadTimer(Object state)
   at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state)

At first glance, it appears that an active connection is being used to issue a ROLLBACK command. This will fail if the connection is already being used to execute a query.

To make it work, we would need to cancel the command (i.e., issue KILL QUERY x on a separate connection), wait for the first connection to become idle, then execute the ROLLBACK. This could be done either by blocking, or perhaps by setting a "pending rollback" flag on the connection (that is executed when any existing command finishes running).

bgrainger commented 4 years ago

This happened again:

Unhandled Exception: System.InvalidOperationException: This MySqlConnection is already in use. See https://fl.vu/mysql-conn-reuse
   at MySqlConnector.Core.ServerSession.StartQuerying(ICancellableCommand command) in /_/src/MySqlConnector/Core/ServerSession.cs:line 214
   at MySqlConnector.Core.CommandExecutor.ExecuteReaderAsync(IReadOnlyList`1 commands, ICommandPayloadCreator payloadCreator, CommandBehavior behavior, IOBehavior ioBehavior, CancellationToken cancellationToken) in /_/src/MySqlConnector/Core/CommandExecutor.cs:line 58
   at MySql.Data.MySqlClient.MySqlCommand.ExecuteNonQueryAsync(IOBehavior ioBehavior, CancellationToken cancellationToken) in /_/src/MySqlConnector/MySql.Data.MySqlClient/MySqlCommand.cs:line 220
   at MySql.Data.MySqlClient.MySqlCommand.ExecuteNonQuery() in /_/src/MySqlConnector/MySql.Data.MySqlClient/MySqlCommand.cs:line 67
   at MySqlConnector.Core.StandardEnlistedTransaction.OnRollback(Enlistment enlistment) in /_/src/MySqlConnector/Core/StandardEnlistedTransaction.cs:line 52
   at MySqlConnector.Core.EnlistedTransactionBase.System.Transactions.IEnlistmentNotification.Rollback(Enlistment enlistment) in /_/src/MySqlConnector/Core/EnlistedTransactionBase.cs:line 40
   at System.Transactions.VolatileEnlistmentAborting.EnterState(InternalEnlistment enlistment)
   at System.Transactions.VolatileEnlistmentActive.InternalAborted(InternalEnlistment enlistment)
   at System.Transactions.TransactionStateAborted.EnterState(InternalTransaction tx)
   at System.Transactions.TransactionStateActive.Rollback(InternalTransaction tx, Exception e)
   at System.Transactions.EnlistableStates.Timeout(InternalTransaction tx)
   at System.Transactions.Bucket.TimeoutTransactions()
   at System.Transactions.BucketSet.TimeoutTransactions()
   at System.Transactions.TransactionTable.ThreadTimer(Object state)
   at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state)
--- End of stack trace from previous location where exception was thrown ---
   at System.Threading.TimerQueueTimer.CallCallback()
   at System.Threading.TimerQueueTimer.Fire()
   at System.Threading.TimerQueue.FireNextTimers()
xtroncode commented 3 years ago

Hi @bgrainger , We are getting the following exception

Unhandled exception. System.InvalidOperationException: Cannot set MySqlCommand.CommandText when there is an open DataReader for this command; it must be closed first.
at MySql.Data.MySqlClient.MySqlCommand.set_CommandText(String value) in /_/src/MySqlConnector/MySql.Data.MySqlClient/MySqlCommand.cs:line 148
at MySqlConnector.Core.XaEnlistedTransaction.ExecuteXaCommand(String statement) in /_/src/MySqlConnector/Core/XaEnlistedTransaction.cs:line 50
at MySqlConnector.Core.XaEnlistedTransaction.OnRollback(Enlistment enlistment) in /_/src/MySqlConnector/Core/XaEnlistedTransaction.cs:line 42
at MySqlConnector.Core.EnlistedTransactionBase.System.Transactions.IEnlistmentNotification.Rollback(Enlistment enlistment) in /_/src/MySqlConnector/Core/EnlistedTransactionBase.cs:line 40
at System.Transactions.VolatileEnlistmentAborting.EnterState(InternalEnlistment enlistment)
at System.Transactions.VolatileEnlistmentActive.InternalAborted(InternalEnlistment enlistment)
at System.Transactions.TransactionStateAborted.EnterState(InternalTransaction tx)
at System.Transactions.TransactionStateActive.Rollback(InternalTransaction tx, Exception e)
at System.Transactions.EnlistableStates.Timeout(InternalTransaction tx)
at System.Transactions.Bucket.TimeoutTransactions()
at System.Transactions.BucketSet.TimeoutTransactions()
at System.Transactions.TransactionTable.ThreadTimer(Object state)
at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state)
--- End of stack trace from previous location where exception was thrown ---
at System.Threading.TimerQueueTimer.CallCallback(Boolean isThreadPool)
at System.Threading.TimerQueueTimer.Fire(Boolean isThreadPool)
at System.Threading.TimerQueue.FireNextTimers()

The trace seems to be closely related, we are using v0.69.4 of the connector. Is this a similar issue ? How can we go about fixing this. We are unable to replicate this and are facing application restarts whenever this occurrs.

Thanks.

bgrainger commented 3 years ago

It does seem related, but not sure if it's exactly the same; the OP has StandardEnlistedTransaction in the callstack but yours has XaEnlistedTransaction. However, they both come from a System.Transactions timeout.

How can we go about fixing this.

To be honest, a consistent repro would be great, and a PR with the fix would be even better. 😀

bgrainger commented 3 years ago

The bug can be reproed with this code:

using (var transactionScope = new TransactionScope(TransactionScopeOption.Required, TimeSpan.FromSeconds(0.5)))
{
    using (var connection = new MySqlConnection(ConnectionString))
    {
        connection.Open();
        connection.Execute("SELECT SLEEP(1);");
    }

    transactionScope.Complete();
}

With UseXaTransactions=true:

   at MySqlConnector.Core.ServerSession.StartQuerying(ICancellableCommand command) in C:\Code\MySql\MySqlConnector\src\MySqlConnector\Core\ServerSession.cs:line 256
   at MySqlConnector.Core.CommandExecutor.ExecuteReaderAsync(IReadOnlyList`1 commands, ICommandPayloadCreator payloadCreator, CommandBehavior behavior, IOBehavior ioBehavior, CancellationToken cancellationToken) in C:\Code\MySql\MySqlConnector\src\MySqlConnector\Core\CommandExecutor.cs:line 55
   at MySqlConnector.MySqlCommand.ExecuteNonQueryAsync(IOBehavior ioBehavior, CancellationToken cancellationToken) in C:\Code\MySql\MySqlConnector\src\MySqlConnector\MySqlCommand.cs:line 264
   at MySqlConnector.MySqlCommand.ExecuteNonQuery() in C:\Code\MySql\MySqlConnector\src\MySqlConnector\MySqlCommand.cs:line 100
   at MySqlConnector.Core.XaEnlistedTransaction.ExecuteXaCommand(String statement) in C:\Code\MySql\MySqlConnector\src\MySqlConnector\Core\XaEnlistedTransaction.cs:line 48
   at MySqlConnector.Core.XaEnlistedTransaction.OnRollback(Enlistment enlistment) in C:\Code\MySql\MySqlConnector\src\MySqlConnector\Core\XaEnlistedTransaction.cs:line 40
   at MySqlConnector.Core.EnlistedTransactionBase.System.Transactions.IEnlistmentNotification.Rollback(Enlistment enlistment) in C:\Code\MySql\MySqlConnector\src\MySqlConnector\Core\EnlistedTransactionBase.cs:line 38
   at System.Transactions.VolatileEnlistmentAborting.EnterState(InternalEnlistment enlistment)
   at System.Transactions.VolatileEnlistmentActive.InternalAborted(InternalEnlistment enlistment)
   at System.Transactions.TransactionStateAborted.EnterState(InternalTransaction tx)
   at System.Transactions.TransactionStateActive.Rollback(InternalTransaction tx, Exception e)
   at System.Transactions.EnlistableStates.Timeout(InternalTransaction tx)
   at System.Transactions.Bucket.TimeoutTransactions()
   at System.Transactions.BucketSet.TimeoutTransactions()
   at System.Transactions.TransactionTable.ThreadTimer(Object state)
   at System.Threading.TimerQueueTimer.<>c.<.cctor>b__23_0(Object state)
   at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state)
--- End of stack trace from previous location ---
   at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state)
   at System.Threading.TimerQueueTimer.CallCallback(Boolean isThreadPool)
   at System.Threading.TimerQueueTimer.Fire(Boolean isThreadPool)
   at System.Threading.TimerQueue.FireNextTimers()
   at System.Threading.TimerQueue.AppDomainTimerCallback(Int32 id)

With UseXaTransactions=false:

   at MySqlConnector.Core.ServerSession.StartQuerying(ICancellableCommand command) in C:\Code\MySql\MySqlConnector\src\MySqlConnector\Core\ServerSession.cs:line 256
   at MySqlConnector.Core.CommandExecutor.ExecuteReaderAsync(IReadOnlyList`1 commands, ICommandPayloadCreator payloadCreator, CommandBehavior behavior, IOBehavior ioBehavior, CancellationToken cancellationToken) in C:\Code\MySql\MySqlConnector\src\MySqlConnector\Core\CommandExecutor.cs:line 55
   at MySqlConnector.MySqlCommand.ExecuteNonQueryAsync(IOBehavior ioBehavior, CancellationToken cancellationToken) in C:\Code\MySql\MySqlConnector\src\MySqlConnector\MySqlCommand.cs:line 264
   at MySqlConnector.MySqlCommand.ExecuteNonQuery() in C:\Code\MySql\MySqlConnector\src\MySqlConnector\MySqlCommand.cs:line 100
   at MySqlConnector.Core.StandardEnlistedTransaction.OnRollback(Enlistment enlistment) in C:\Code\MySql\MySqlConnector\src\MySqlConnector\Core\StandardEnlistedTransaction.cs:line 52
   at MySqlConnector.Core.EnlistedTransactionBase.System.Transactions.IEnlistmentNotification.Rollback(Enlistment enlistment) in C:\Code\MySql\MySqlConnector\src\MySqlConnector\Core\EnlistedTransactionBase.cs:line 38
   at System.Transactions.VolatileEnlistmentAborting.EnterState(InternalEnlistment enlistment)
   at System.Transactions.VolatileEnlistmentActive.InternalAborted(InternalEnlistment enlistment)
   at System.Transactions.TransactionStateAborted.EnterState(InternalTransaction tx)
   at System.Transactions.TransactionStateActive.Rollback(InternalTransaction tx, Exception e)
   at System.Transactions.EnlistableStates.Timeout(InternalTransaction tx)
   at System.Transactions.Bucket.TimeoutTransactions()
   at System.Transactions.BucketSet.TimeoutTransactions()
   at System.Transactions.TransactionTable.ThreadTimer(Object state)
   at System.Threading.TimerQueueTimer.<>c.<.cctor>b__23_0(Object state)
   at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state)
--- End of stack trace from previous location ---
   at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state)
   at System.Threading.TimerQueueTimer.CallCallback(Boolean isThreadPool)
   at System.Threading.TimerQueueTimer.Fire(Boolean isThreadPool)
   at System.Threading.TimerQueue.FireNextTimers()
   at System.Threading.TimerQueue.AppDomainTimerCallback(Int32 id)
bgrainger commented 3 years ago

@xtroncode's exception message is probably due to #867, which isn't fixed in 0.x. @xtroncode are you able to update to 1.x, or are you stuck on 0.x?

bgrainger commented 3 years ago

We need to detect if the connection (that we wish to roll back) is currently being used to execute a command. If so, cancel that command, issue DO SLEEP(0) to clear the pending cancellation (as is done currently), then issue ROLLBACK. Meanwhile, block and wait for all that to happen in the enlisted transaction's Rollback method.

This is likely to be subtle and difficult, as many of those methods have not been designed for concurrent usage (from multiple threads) so there are many places where state will be getting updated, and all of them now need to be protected.

bgrainger commented 3 years ago

Code that encounters this race condition with MySqlConnector is also very likely to be broken under MySql.Data, too: https://bugs.mysql.com/bug.php?id=102129

xtroncode commented 3 years ago

@bgrainger Thanks for the explanation, I'll look at the release notes and see if we can move to 1.x .

bgrainger commented 3 years ago

@xtroncode Note that the underlying bug/race condition (this specific issue) isn't fixed in 1.x yet, but due to the complexity of fixing it, it probably wouldn't ever be backported to 0.x (which is why I was wondering if you were able to upgrade).

xtroncode commented 3 years ago

I tried upgrading but we have some other dependency that isn't compatible with 1.x yet. So we are trying to figure why the timeout occurs or will move the transaction to a stored procedure (we use transactions in just one place).

Thanks.

bgrainger commented 3 years ago

Another workaround would be to switch from TransactionScope (implicit, global state, complex Transaction Manager behind it) to connection.BeginTransaction (simple, straightforward, no "magic").

ysiivan commented 1 month ago

5 years later and this is still a problem it seems? I'm on MySqlConnector 2.3.7, .NET8 and getting this when the scope times out:

Unhandled exception. System.InvalidOperationException: This MySqlConnection is already in use. See https://fl.vu/mysql-conn-reuse
   at MySqlConnector.Core.ServerSession.StartQuerying(ICancellableCommand command) in /_/src/MySqlConnector/Core/ServerSession.cs:line 288
   at MySqlConnector.Core.CommandExecutor.ExecuteReaderAsync(CommandListPosition commandListPosition, ICommandPayloadCreator payloadCreator, CommandBehavior behavior, Activity activity, IOBehavior ioBehavior, CancellationToken cancellationToken)
   at MySqlConnector.MySqlCommand.ExecuteNonQueryAsync(IOBehavior ioBehavior, CancellationToken cancellationToken) in /_/src/MySqlConnector/MySqlCommand.cs:line 309
   at MySqlConnector.MySqlCommand.ExecuteNonQuery() in /_/src/MySqlConnector/MySqlCommand.cs:line 108
   at MySqlConnector.Core.XaEnlistedTransaction.ExecuteXaCommand(String statement) in /_/src/MySqlConnector/Core/XaEnlistedTransaction.cs:line 50
   at MySqlConnector.Core.XaEnlistedTransaction.OnRollback(Enlistment enlistment) in /_/src/MySqlConnector/Core/XaEnlistedTransaction.cs:line 36
   at MySqlConnector.Core.EnlistedTransactionBase.System.Transactions.IEnlistmentNotification.Rollback(Enlistment enlistment) in /_/src/MySqlConnector/Core/EnlistedTransactionBase.cs:line 47
   at System.Transactions.VolatileEnlistmentAborting.EnterState(InternalEnlistment enlistment)
   at System.Transactions.TransactionStateAborted.EnterState(InternalTransaction tx)
   at System.Transactions.EnlistableStates.Timeout(InternalTransaction tx)
   at System.Transactions.Bucket.TimeoutTransactions()
   at System.Transactions.BucketSet.TimeoutTransactions()
   at System.Transactions.TransactionTable.ThreadTimer(Object state)
   at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state)
--- End of stack trace from previous location ---
   at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state)
   at System.Threading.TimerQueueTimer.Fire(Boolean isThreadPool)
   at System.Threading.TimerQueue.FireNextTimers()
   at System.Threading.ThreadPoolWorkQueue.Dispatch()
   at System.Threading.PortableThreadPool.WorkerThread.WorkerThreadStart()

The exception does not get caught in the enclosing try/catch and crashes the application. Not that there would be a way to recover, but still.

I have code that started in MSSQL and it'll be a rewrite to switch to basic transactions.

PeterHagen commented 1 month ago

I have code that started in MSSQL and it'll be a rewrite to switch to basic transactions.

I have never seen this happen. I tried the code in the log from 2020 with connection.Execute("SELECT SLEEP(1);");, but Execute is not available in connection. I also don't see how that transactionScope would influence the connection. Can you show some sample code?

ysiivan commented 1 month ago

I have never seen this happen. I tried the code in the log from 2020 with connection.Execute("SELECT SLEEP(1);");, but Execute is not available in connection. I also don't see how that transactionScope would influence the connection. Can you show some sample code?

The sample code above does show the problem. That Execute comes from Dapper, but you can use a MySqlCommad instance to run ExecuteNonQuery or ExecuteReader or whateever.