Deadlock is unrecoverable

Discussion of open issues, suggestions and bugs regarding ADO.NET provider for MySQL
Post Reply
jleblanc
Posts: 14
Joined: Tue 19 Apr 2016 22:31

Deadlock is unrecoverable

Post by jleblanc » Tue 19 Apr 2016 22:44

During periods of high activity in our system, sometimes things deadlock in the database. While we are trying to minimize the occurrence of deadlocks, they will still happen occasionally. What we are noticing though, is that when using the Devart connector for MySQL, our application does not recover from deadlocks. Once a deadlock has occurred, further database activity fails, and this is a serious problem.

The Environment
  • Windows 8.1 Pro 64bit
  • MariaDB 5.5.34 Win64
  • Devart DotConnect MySQL version 8.4.616.0
The Issue
I have created a sample program that demonstrates the issue we are having, it does the following (in order):
  1. Sets up some tables for testing
  2. Causes a deadlock between transactions across some of those tables
  3. After the deadlock has occurred, try to insert data into a completely separate table
We expect that despite the deadlock, all subsequent inserts should succeed; however this is not the case. The first insert seems to always work, but the next one fails with the error below.

Code: Select all

Unhandled Exception: Devart.Data.MySql.MySqlException: XAER_RMFAIL: The command cannot be executed when global transaction is in the  ROLLBACK ONLY state
   at Devart.Data.MySql.bi.a()
   at Devart.Data.MySql.bi.i()
   at Devart.Data.MySql.ag.a(ab[]& A_0, Int32& A_1, Boolean A_2)
   at Devart.Data.MySql.ag.a(Byte[] A_0, Int32 A_1, Boolean A_2, String A_3)
   at Devart.Data.MySql.MySqlInternalConnection.BeginTransaction(Guid distributedIdentifier, IsolationLevel isolationLevel)
   at Devart.Common.DbConnectionInternal.EnlistToDistributedTransactionInternal(Transaction transaction)
   at Devart.Common.DbConnectionInternal.b()
   at Devart.Data.MySql.MySqlInternalConnection.b()
   at Devart.Common.DbConnectionFactory.b(DbConnectionBase A_0)
   at Devart.Common.DbConnectionClosed.Open(DbConnectionBase outerConnection)
   at Devart.Common.DbConnectionBase.Open()
   at Devart.Data.MySql.MySqlConnection.m()
   at Devart.Data.MySql.MySqlConnection.Open()
This problem is reliably reproducible, and we've tried the following things to fix it:
  • Setting TransactionScopeLocal to true in the connection string - this made no difference
  • Setting innodb_support_xa to off on the server - this made no difference
What We've Noticed
No matter what, Devart always uses distributed transactions when a TransactionScope is involved, the TransactionScopeLocal setting appears to be completely ignored. MySQL's Connector/Net works as expected.

Below is the source code to reproduce the issue. The code is compatible with both Devart's dotConnect, and MySQL's Connector/Net. All of the InsertStuff() calls work when using MySQL's Connector/Net, but only one of them works when using Devart's dotConnect.

Is this a bug in dotConnect, or are we doing something wrong?

.Net Framework 4.5

Code: Select all

using System;
using System.Threading;
using System.Threading.Tasks;
using System.Transactions;
using Devart.Data.MySql;

namespace DevartDeadlockExperiment
{
	internal class Program
	{
		private const string DeadlockTable1 = "test_deadlock_table_1";
		private const string DeadlockTable2 = "test_deadlock_table_2";
		private const string TestTable = "test_deadlock_table_3";

		private static ManualResetEvent _sentinel1;
		private static ManualResetEvent _sentinel2;

		private static string _connectionString;

		private static string GetConnectionString()
		{
			return new MySqlConnectionStringBuilder
			{				
				Host = "localhost",
				Database = "testdatabase",
				UserId = "root",
				Password = "yourpassword",
				Port = 3306
			}.ConnectionString;
		}

		public static void RunDeadlocker2()
		{
			_sentinel2.WaitOne();

			using (var scope = new TransactionScope())
			using (var connection = new MySqlConnection(_connectionString))
			{
				connection.Open();
				using (var queryCommand = connection.CreateCommand())
				{
					queryCommand.CommandText =
						"UPDATE test_deadlock_table_2 SET `testCol` = 2; UPDATE test_deadlock_table_1 SET `testCol` = 2;";

					Task.Delay(500).ContinueWith(t => _sentinel1.Set());
					queryCommand.ExecuteNonQuery();
				}
				scope.Complete();
			}
		}

		public static int RunDeadlocker1()
		{
			using (var scope = new TransactionScope())
			using (var connection = new MySqlConnection(_connectionString))
			{
				connection.Open();
				using (var queryCommand = connection.CreateCommand())
				{
					queryCommand.CommandText = "UPDATE test_deadlock_table_1 SET `testCol` = 1;";
					queryCommand.ExecuteNonQuery();
				}

				_sentinel2.Set();
				_sentinel1.WaitOne();

				using (var queryCommand = connection.CreateCommand())
				{
					queryCommand.CommandText = "UPDATE test_deadlock_table_2 SET `testCol` = 1;";
					queryCommand.ExecuteNonQuery();
				}
				scope.Complete();
			}

			return 0;
		}

		private static void CreateDeadlockTestTable(string tableName)
		{
			using (var connection = new MySqlConnection(_connectionString))
			{
				connection.Open();
				using (var queryCommand = connection.CreateCommand())
				{
					queryCommand.CommandText = "CREATE TABLE " + tableName + " (`testCol` INT(10) NULL); " + "INSERT INTO " +
					                           tableName + " SELECT 0;";
					queryCommand.ExecuteNonQuery();
				}
			}
		}

		private static void DropDeadlockTestTable(string tableName)
		{
			using (var connection = new MySqlConnection(_connectionString))
			{
				connection.Open();
				using (var queryCommand = connection.CreateCommand())
				{
					queryCommand.CommandText = "DROP TABLE " + tableName + ";";
					queryCommand.ExecuteNonQuery();
				}
			}
		}

		private static void InsertStuff()
		{
			Console.Write("Inserting...");
			using (var scope = new TransactionScope())
			using (var connection = new MySqlConnection(_connectionString))
			{
				connection.Open();
				{
					using (var command = connection.CreateCommand())
					{
						command.CommandText =
							"INSERT INTO test_deadlock_table_3(testCol) VALUES (555);";
						command.ExecuteNonQuery();
					}
					scope.Complete();
				}
			}
			Console.WriteLine("done");
		}

		private static void Main(string[] args)
		{
			_sentinel1 = new ManualResetEvent(false);
			_sentinel2 = new ManualResetEvent(false);

			var dbMonitor = new MySqlMonitor {IsActive = true};

			_connectionString = GetConnectionString();

			CreateDeadlockTestTable(DeadlockTable1);
			CreateDeadlockTestTable(DeadlockTable2);
			CreateDeadlockTestTable(TestTable);

			var deadlocker2 = Task.Run(() => RunDeadlocker2());

			try
			{
				Task.Run(() => RunDeadlocker1()).Wait();
			}
			catch (Exception ex)
			{
				Console.WriteLine(ex);
			}
			finally
			{
				deadlocker2.Wait();
			}

			Console.WriteLine("got here");
			InsertStuff();
			InsertStuff();
			InsertStuff();
			InsertStuff();
			InsertStuff();

			DropDeadlockTestTable(DeadlockTable1);
			DropDeadlockTestTable(DeadlockTable2);
			DropDeadlockTestTable(TestTable);
		}
	}
}
If it matters, here is my my.ini file:

Code: Select all

[mysqld]
performance_schema
slow_query_log = 1
slow_query_log_file = D:/Databases/Logs/mysql-slow.log
log = D:/Databases/Logs/mysql.log
log-error = D:/Databases/Logs/mysql-error.log
log_warnings = 2
innodb_print_all_deadlocks = "ON"
datadir=D:/Databases
port=3306
sql_mode="STRICT_TRANS_TABLES,NO_ENGINE_SUBSTITUTION"
default_storage_engine=innodb
innodb_buffer_pool_size=511M
innodb_log_file_size=50M
character-set-server=utf8
event_scheduler="OFF"
max_connections=1000
wait_timeout=300
innodb_file_per_table
innodb_flush_log_at_trx_commit = 0
max_allowed_packet = 16M
[client]
port=3306

Shalex
Site Admin
Posts: 9543
Joined: Thu 14 Aug 2008 12:44

Re: Deadlock is unrecoverable

Post by Shalex » Tue 26 Apr 2016 06:26

We have reproduced the issue and are investigating it. We will notify you about the result.

Shalex
Site Admin
Posts: 9543
Joined: Thu 14 Aug 2008 12:44

Re: Deadlock is unrecoverable

Post by Shalex » Thu 28 Apr 2016 11:23

The bug with processing errors within TransactionScope is fixed. We will notify you when the corresponding build of dotConnect for MySQL is available for download.

jleblanc
Posts: 14
Joined: Tue 19 Apr 2016 22:31

Re: Deadlock is unrecoverable

Post by jleblanc » Thu 28 Apr 2016 16:40

Fantastic! Thanks!

Shalex
Site Admin
Posts: 9543
Joined: Thu 14 Aug 2008 12:44

Re: Deadlock is unrecoverable

Post by Shalex » Fri 06 May 2016 08:27

New build of dotConnect for MySQL 8.5.644 is available for download now: http://forums.devart.com/viewtopic.php?f=2&t=33634.

jleblanc
Posts: 14
Joined: Tue 19 Apr 2016 22:31

Re: Deadlock is unrecoverable

Post by jleblanc » Mon 09 May 2016 23:03

Thanks, we're upgrading now.

jleblanc
Posts: 14
Joined: Tue 19 Apr 2016 22:31

Re: Deadlock is unrecoverable

Post by jleblanc » Wed 11 May 2016 18:12

This is resolved, thanks!

dpursanov
Posts: 10
Joined: Wed 16 Nov 2016 12:44

Re: Deadlock is unrecoverable

Post by dpursanov » Fri 13 Oct 2017 13:34

Hello, I think similar error appears in build #8.9.946. Deadlock error returns with text:
XAER_RMFAIL: The command cannot be executed when global transaction is in the PREPARED state. During that all the operations that use the TransactionScope of the specific block are returning error.. Restarting webserver solves the problem. Had to return to the old version of devart. Can you confirm the problem? The build #8.9.946 was the last update for our organization, we need to renew to get the latest one, but in case the bug is still there we'll have to wait for the future fixes.

Shalex
Site Admin
Posts: 9543
Joined: Thu 14 Aug 2008 12:44

Re: Deadlock is unrecoverable

Post by Shalex » Mon 16 Oct 2017 09:45

Please specify the exact code (with the corresponding DDL/DML script) for reproducing the problem. Should we use the code snippet listed at viewtopic.php?t=33531#p115946?

dpursanov
Posts: 10
Joined: Wed 16 Nov 2016 12:44

Re: Deadlock is unrecoverable

Post by dpursanov » Mon 16 Oct 2017 12:02

Don't really know what part of code throws the exception, because the project is large and the error appears in totally "unrelated" blocks.
But here is the trace:

Code: Select all

System.Data.Entity.Core.EntityCommandExecutionException: An error occurred while executing the command definition. See the inner exception for details. ---> Devart.Data.MySql.MySqlException: XAER_RMFAIL: The command cannot be executed when global transaction is in the  PREPARED state
   at Devart.Data.MySql.bi.a()
   at Devart.Data.MySql.bi.i()
   at Devart.Data.MySql.ae.a(aa[]& A_0, Int32& A_1, Boolean A_2)
   at Devart.Data.MySql.ae.a(Byte[] A_0, Int32 A_1, Boolean A_2, String A_3)
   at Devart.Data.MySql.i.b()
   at Devart.Data.MySql.MySqlCommand.InternalExecute(CommandBehavior behavior, IDisposable stmt, Int32 startRecord, Int32 maxRecords)
   at Devart.Common.DbCommandBase.ExecuteDbDataReader(CommandBehavior behavior, Boolean nonQuery)
   at Devart.Data.MySql.Entity.ai.a(CommandBehavior A_0)
   at System.Data.Entity.Infrastructure.Interception.InternalDispatcher`1.Dispatch[TTarget,TInterceptionContext,TResult](TTarget target, Func`3 operation, TInterceptionContext interceptionContext, Action`3 executing, Action`3 executed)
   at System.Data.Entity.Infrastructure.Interception.DbCommandDispatcher.Reader(DbCommand command, DbCommandInterceptionContext interceptionContext)
   at System.Data.Entity.Core.EntityClient.Internal.EntityCommandDefinition.ExecuteStoreCommands(EntityCommand entityCommand, CommandBehavior behavior)
   --- End of inner exception stack trace ---
   at System.Data.Entity.Core.EntityClient.Internal.EntityCommandDefinition.ExecuteStoreCommands(EntityCommand entityCommand, CommandBehavior behavior)
   at System.Data.Entity.Core.Objects.ObjectContext.CreateFunctionObjectResult[TElement](EntityCommand entityCommand, ReadOnlyCollection`1 entitySets, EdmType[] edmTypes, ExecutionOptions executionOptions)
   at System.Data.Entity.Core.Objects.ObjectContext.<>c__DisplayClass47`1.<ExecuteFunction>b__46()
   at System.Data.Entity.Core.Objects.ObjectContext.ExecuteInTransaction[T](Func`1 func, IDbExecutionStrategy executionStrategy, Boolean startLocalTransaction, Boolean releaseConnectionOnSuccess)
   at System.Data.Entity.Core.Objects.ObjectContext.<>c__DisplayClass47`1.<ExecuteFunction>b__45()
   at System.Data.Entity.Core.Objects.ObjectContext.ExecuteFunction[TElement](String functionName, ExecutionOptions executionOptions, ObjectParameter[] parameters)
   at XService.XEntities.Xappgetuserparameter(String ptoken, String pip, Nullable`1 pparametertype)
   at XService.Service.GetAccountAddress(String account, String token)
   at XService.Service.UserGetInfo(String token, String ip, Boolean cached) System.Data.Entity.Core.EntityCommandExecutionException: An error occurred while executing the command definition. See the inner exception for details. ---> Devart.Data.MySql.MySqlException: XAER_RMFAIL: The command cannot be executed when global transaction is in the  PREPARED state
   at Devart.Data.MySql.bi.a()
   at Devart.Data.MySql.bi.i()
   at Devart.Data.MySql.ae.a(aa[]& A_0, Int32& A_1, Boolean A_2)
   at Devart.Data.MySql.ae.a(Byte[] A_0, Int32 A_1, Boolean A_2, String A_3)
   at Devart.Data.MySql.i.b()
   at Devart.Data.MySql.MySqlCommand.InternalExecute(CommandBehavior behavior, IDisposable stmt, Int32 startRecord, Int32 maxRecords)
   at Devart.Common.DbCommandBase.ExecuteDbDataReader(CommandBehavior behavior, Boolean nonQuery)
   at Devart.Data.MySql.Entity.ai.a(CommandBehavior A_0)
   at System.Data.Entity.Infrastructure.Interception.InternalDispatcher`1.Dispatch[TTarget,TInterceptionContext,TResult](TTarget target, Func`3 operation, TInterceptionContext interceptionContext, Action`3 executing, Action`3 executed)
   at System.Data.Entity.Infrastructure.Interception.DbCommandDispatcher.Reader(DbCommand command, DbCommandInterceptionContext interceptionContext)
   at System.Data.Entity.Core.EntityClient.Internal.EntityCommandDefinition.ExecuteStoreCommands(EntityCommand entityCommand, CommandBehavior behavior)
   --- End of inner exception stack trace ---
   at System.Data.Entity.Core.EntityClient.Internal.EntityCommandDefinition.ExecuteStoreCommands(EntityCommand entityCommand, CommandBehavior behavior)
   at System.Data.Entity.Core.Objects.ObjectContext.CreateFunctionObjectResult[TElement](EntityCommand entityCommand, ReadOnlyCollection`1 entitySets, EdmType[] edmTypes, ExecutionOptions executionOptions)
   at System.Data.Entity.Core.Objects.ObjectContext.<>c__DisplayClass47`1.<ExecuteFunction>b__46()
   at System.Data.Entity.Core.Objects.ObjectContext.ExecuteInTransaction[T](Func`1 func, IDbExecutionStrategy executionStrategy, Boolean startLocalTransaction, Boolean releaseConnectionOnSuccess)
   at System.Data.Entity.Core.Objects.ObjectContext.<>c__DisplayClass47`1.<ExecuteFunction>b__45()
   at System.Data.Entity.Core.Objects.ObjectContext.ExecuteFunction[TElement](String functionName, ExecutionOptions executionOptions, ObjectParameter[] parameters)
   at XService.XEntities.Xappgetuserparameter(String ptoken, String pip, Nullable`1 pparametertype)
   at XService.Service.GetAccountAddress(String account, String token)
   at XService.Service.UserGetInfo(String token, String ip, Boolean cached) An error occurred while executing the command definition. See the inner exception for details.
XAER_RMFAIL: The command cannot be executed when global transaction is in the  PREPARED state    at Devart.Data.MySql.bi.a()
   at Devart.Data.MySql.bi.i()
   at Devart.Data.MySql.ae.a(aa[]& A_0, Int32& A_1, Boolean A_2)
   at Devart.Data.MySql.ae.a(Byte[] A_0, Int32 A_1, Boolean A_2, String A_3)
   at Devart.Data.MySql.i.b()
   at Devart.Data.MySql.MySqlCommand.InternalExecute(CommandBehavior behavior, IDisposable stmt, Int32 startRecord, Int32 maxRecords)
   at Devart.Common.DbCommandBase.ExecuteDbDataReader(CommandBehavior behavior, Boolean nonQuery)
   at Devart.Data.MySql.Entity.ai.a(CommandBehavior A_0)
   at System.Data.Entity.Infrastructure.Interception.InternalDispatcher`1.Dispatch[TTarget,TInterceptionContext,TResult](TTarget target, Func`3 operation, TInterceptionContext interceptionContext, Action`3 executing, Action`3 executed)
   at System.Data.Entity.Infrastructure.Interception.DbCommandDispatcher.Reader(DbCommand command, DbCommandInterceptionContext interceptionContext)
   at System.Data.Entity.Core.EntityClient.Internal.EntityCommandDefinition.ExecuteStoreCommands(EntityCommand entityCommand, CommandBehavior behavior)

Shalex
Site Admin
Posts: 9543
Joined: Thu 14 Aug 2008 12:44

Re: Deadlock is unrecoverable

Post by Shalex » Tue 17 Oct 2017 18:18

We are investigating the issue.

If you manage to localize the case, please upload a test project with the corresponding DDL/DML script to ftp://ftp.devart.com (credentials: anonymous / yourEmail).

dpursanov
Posts: 10
Joined: Wed 16 Nov 2016 12:44

Re: Deadlock is unrecoverable

Post by dpursanov » Wed 18 Oct 2017 12:41

Thanks I'll try to.. The only thing I found for now is that this error appears when certain block is wrapped into TransactionScope using block.

Shalex
Site Admin
Posts: 9543
Joined: Thu 14 Aug 2008 12:44

Re: Deadlock is unrecoverable

Post by Shalex » Mon 30 Oct 2017 17:03

dpursanov, please follow these steps:
1) upgrade to the newest (8.10.1013) build of dotConnect for MySQL
2) add the "Transaction Scope Local=true;" option to your connection string

Does this help?

dpursanov
Posts: 10
Joined: Wed 16 Nov 2016 12:44

Re: Deadlock is unrecoverable

Post by dpursanov » Tue 31 Oct 2017 12:14

Can't update yet.. We have to renew our license. Thank you for the reply, will definitely try after upgrade and reply here.

dpursanov
Posts: 10
Joined: Wed 16 Nov 2016 12:44

Re: Deadlock is unrecoverable

Post by dpursanov » Thu 09 Nov 2017 06:31

Upgraded, for now it seems that this fixes the problem... Thank you!

Post Reply