Add transaction logging. Fixes #1411

src/MySqlConnector/Logging/EventIds.cs

@@ -131,6 +131,14 @@ internal static class EventIds
 	public const int ColumnMappingAlreadyHasExpression = 2508;
 	public const int SettingExpressionToMapColumn = 2509;
 
+	// Transaction events, 2700-2799
+	public const int StartingTransaction = 2700;
+	public const int StartedTransaction = 2701;
+	public const int CommittingTransaction = 2702;
+	public const int CommittedTransaction = 2703;
+	public const int RollingBackTransaction = 2704;
+	public const int RolledBackTransaction = 2705;
+
 	// Connection pool events, 3000-3099
 	public const int WaitingForAvailableSession = 3000;
 	public const int CreatingNewConnectionPool = 3001;

src/MySqlConnector/Logging/Log.cs

@@ -324,6 +324,24 @@ internal static partial class Log
 	[LoggerMessage(EventIds.SettingExpressionToMapColumn, LogLevel.Trace, "Setting expression to map column {SourceOrdinal} to {DestinationColumn}: {Expression}")]
 	public static partial void SettingExpressionToMapColumn(ILogger logger, int sourceOrdinal, string destinationColumn, string expression);
 
+	[LoggerMessage(EventIds.StartingTransaction, LogLevel.Debug, "Session {SessionId} starting transaction")]
+	public static partial void StartingTransaction(ILogger logger, string sessionId);
+
+	[LoggerMessage(EventIds.StartedTransaction, LogLevel.Trace, "Session {SessionId} started transaction")]
+	public static partial void StartedTransaction(ILogger logger, string sessionId);
+
+	[LoggerMessage(EventIds.CommittingTransaction, LogLevel.Trace, "Session {SessionId} committing transaction")]
+	public static partial void CommittingTransaction(ILogger logger, string sessionId);
+
+	[LoggerMessage(EventIds.CommittedTransaction, LogLevel.Debug, "Session {SessionId} committed transaction")]
+	public static partial void CommittedTransaction(ILogger logger, string sessionId);
+
+	[LoggerMessage(EventIds.RollingBackTransaction, LogLevel.Trace, "Session {SessionId} rolling back transaction")]
+	public static partial void RollingBackTransaction(ILogger logger, string sessionId);
+
+	[LoggerMessage(EventIds.RolledBackTransaction, LogLevel.Debug, "Session {SessionId} rolled back transaction")]
+	public static partial void RolledBackTransaction(ILogger logger, string sessionId);
+
 	[LoggerMessage(EventIds.WaitingForAvailableSession, LogLevel.Trace, "Pool {PoolId} waiting for an available session")]
 	public static partial void WaitingForAvailableSession(ILogger logger, int poolId);
 

src/MySqlConnector/Logging/MySqlConnectorLoggingConfiguration.cs

@@ -10,6 +10,7 @@ internal sealed class MySqlConnectorLoggingConfiguration(ILoggerFactory loggerFa
 	public ILogger CommandLogger { get; } = loggerFactory.CreateLogger("MySqlConnector.MySqlCommand");
 	public ILogger PoolLogger { get; } = loggerFactory.CreateLogger("MySqlConnector.ConnectionPool");
 	public ILogger BulkCopyLogger { get; } = loggerFactory.CreateLogger("MySqlConnector.MySqlBulkCopy");
+	public ILogger TransactionLogger { get; } = loggerFactory.CreateLogger("MySqlConnector.Transaction");
 
 	public static MySqlConnectorLoggingConfiguration NullConfiguration { get; } = new MySqlConnectorLoggingConfiguration(NullLoggerFactory.Instance);
 	public static MySqlConnectorLoggingConfiguration GlobalConfiguration { get; set; } = NullConfiguration;

src/MySqlConnector/MySqlConnection.cs

@@ -46,6 +46,7 @@ private MySqlConnection(string connectionString, MySqlConnectorLoggingConfigurat
 		m_connectionString = connectionString;
 		LoggingConfiguration = loggingConfiguration;
 		m_logger = loggingConfiguration.ConnectionLogger;
+		m_transactionLogger = loggingConfiguration.TransactionLogger;
 	}
 
 #pragma warning disable CA2012 // Safe because method completes synchronously
@@ -146,8 +147,10 @@ private async ValueTask<MySqlTransaction> BeginTransactionAsync(IsolationLevel i
 		if (m_enlistedTransaction is not null)
 			throw new InvalidOperationException("Cannot begin a transaction when already enlisted in a transaction.");
 
+		Log.StartingTransaction(m_transactionLogger, m_session!.Id);
+
 		// get the bytes for both payloads concatenated together (suitable for pipelining)
-		var startTransactionPayload = GetStartTransactionPayload(isolationLevel, isReadOnly, m_session!.SupportsQueryAttributes);
+		var startTransactionPayload = GetStartTransactionPayload(isolationLevel, isReadOnly, m_session.SupportsQueryAttributes);
 
 		if (GetInitializedConnectionSettings() is { UseCompression: false, Pipelining: not false })
 		{
@@ -175,7 +178,7 @@ private async ValueTask<MySqlTransaction> BeginTransactionAsync(IsolationLevel i
 			OkPayload.Verify(payload.Span, m_session.SupportsDeprecateEof, m_session.SupportsSessionTrack);
 		}
 
-		var transaction = new MySqlTransaction(this, isolationLevel);
+		var transaction = new MySqlTransaction(this, isolationLevel, m_transactionLogger);
 		CurrentTransaction = transaction;
 		return transaction;
 	}
@@ -1259,6 +1262,7 @@ private async ValueTask CloseDatabaseAsync(IOBehavior ioBehavior, CancellationTo
 
 	private readonly MySqlDataSource? m_dataSource;
 	private readonly ILogger m_logger;
+	private readonly ILogger m_transactionLogger;
 	private string m_connectionString;
 	private ConnectionSettings? m_connectionSettings;
 	private ServerSession? m_session;

src/MySqlConnector/MySqlTransaction.cs

@@ -1,4 +1,6 @@
 using System.Net.Sockets;
+using Microsoft.Extensions.Logging;
+using MySqlConnector.Logging;
 using MySqlConnector.Protocol.Serialization;
 using MySqlConnector.Utilities;
 
@@ -30,11 +32,13 @@ private async Task CommitAsync(IOBehavior ioBehavior, CancellationToken cancella
 		VerifyValid();
 
 		using var activity = Connection!.Session.StartActivity("Commit");
+		Log.CommittingTransaction(m_logger, Connection.Session.Id);
 		try
 		{
 			using (var cmd = new MySqlCommand("commit", Connection, this) { NoActivity = true })
 				await cmd.ExecuteNonQueryAsync(ioBehavior, cancellationToken).ConfigureAwait(false);
 			Connection!.CurrentTransaction = null;
+			Log.CommittedTransaction(m_logger, Connection.Session.Id);
 			Connection = null;
 		}
 		catch (Exception ex) when (activity is { IsAllDataRequested: true })
@@ -254,19 +258,24 @@ private async Task DoDisposeAsync(IOBehavior ioBehavior, CancellationToken cance
 		Connection = null;
 	}
 
-	internal MySqlTransaction(MySqlConnection connection, IsolationLevel isolationLevel)
+	internal MySqlTransaction(MySqlConnection connection, IsolationLevel isolationLevel, ILogger logger)
 	{
 		Connection = connection;
 		IsolationLevel = isolationLevel;
+		m_logger = logger;
+
+		Log.StartedTransaction(m_logger, Connection.Session.Id);
 	}
 
 	private async Task DoRollback(IOBehavior ioBehavior, CancellationToken cancellationToken)
 	{
 		using var activity = Connection!.Session.StartActivity("Rollback");
+		Log.RollingBackTransaction(m_logger, Connection.Session.Id);
 		try
 		{
 			using var cmd = new MySqlCommand("rollback", Connection, this) { NoActivity = true };
 			await cmd.ExecuteNonQueryAsync(ioBehavior, cancellationToken).ConfigureAwait(false);
+			Log.RolledBackTransaction(m_logger, Connection.Session.Id);
 		}
 		catch (Exception ex) when (activity is { IsAllDataRequested: true })
 		{
@@ -293,5 +302,6 @@ private void VerifyValid()
 
 	private static string QuoteIdentifier(string identifier) => "`" + identifier.Replace("`", "``") + "`";
 
+	private readonly ILogger m_logger;
 	private bool m_isDisposed;
 }