diff --git a/src/MySqlConnector/Core/DiagnosticListenerExtensions.cs b/src/MySqlConnector/Core/DiagnosticListenerExtensions.cs new file mode 100644 index 000000000..e4c44c4e0 --- /dev/null +++ b/src/MySqlConnector/Core/DiagnosticListenerExtensions.cs @@ -0,0 +1,325 @@ +using System; +using System.Data; +using System.Diagnostics; +using System.Runtime.CompilerServices; +using MySql.Data.MySqlClient; + +namespace MySqlConnector.Core +{ + /// + /// Extension methods on the DiagnosticListener class to log MySqlCommand data + /// + internal static class DiagnosticListenerExtensions + { + // Diagnostics listeners name + public const string CommandListenerName = "MySqlConnector.Command"; + public const string ConnectionListenerName = "MySqlConnector.Connection"; + public const string TransactionListenerName = "MySqlConnector.Transaction"; + + // Command listener events name + public const string WriteStart = nameof(WriteStart); + public const string WriteStop = nameof(WriteStop); + public const string WriteError = nameof(WriteError); + + // Connection listener events name + public const string WriteOpenStart = nameof(WriteOpenStart); + public const string WriteOpenStop = nameof(WriteOpenStop); + public const string WriteOpenError = nameof(WriteOpenError); + public const string WriteCloseStart = nameof(WriteCloseStart); + public const string WriteCloseStop = nameof(WriteCloseStop); + public const string WriteCloseError = nameof(WriteCloseError); + + // Transaction listener events name + public const string WriteCommitStart = nameof(WriteCommitStart); + public const string WriteCommitStop = nameof(WriteCommitStop); + public const string WriteCommitError = nameof(WriteCommitError); + public const string WriteRollbackStart = nameof(WriteRollbackStart); + public const string WriteRollbackStop = nameof(WriteRollbackStop); + public const string WriteRollbackError = nameof(WriteRollbackError); + + public static Guid WriteCommandStart(this DiagnosticListener @this, MySqlCommand sqlCommand, [CallerMemberName] string operation = "") + { + if (@this.IsEnabled(WriteStart)) + { + Guid operationId = Guid.NewGuid(); + + @this.Write( + WriteStart, + new + { + OperationId = operationId, + Operation = operation, + Command = sqlCommand + }); + + return operationId; + } + else + return Guid.Empty; + } + + public static void WriteCommandStop(this DiagnosticListener @this, Guid operationId, MySqlCommand sqlCommand, [CallerMemberName] string operation = "") + { + if (@this.IsEnabled(WriteStop)) + { + @this.Write( + WriteStop, + new + { + OperationId = operationId, + Operation = operation, + Command = sqlCommand, + Timestamp = Stopwatch.GetTimestamp() + }); + } + } + + public static void WriteCommandError(this DiagnosticListener @this, Guid operationId, MySqlCommand sqlCommand, Exception ex, [CallerMemberName] string operation = "") + { + if (@this.IsEnabled(WriteError)) + { + @this.Write( + WriteError, + new + { + OperationId = operationId, + Operation = operation, + Command = sqlCommand, + Exception = ex, + Timestamp = Stopwatch.GetTimestamp() + }); + } + } + + public static Guid WriteConnectionOpenStart(this DiagnosticListener @this, MySqlConnection sqlConnection, [CallerMemberName] string operation = "") + { + if (@this.IsEnabled(WriteOpenStart)) + { + Guid operationId = Guid.NewGuid(); + + @this.Write( + WriteOpenStart, + new + { + OperationId = operationId, + Operation = operation, + Connection = sqlConnection, + Timestamp = Stopwatch.GetTimestamp() + }); + + return operationId; + } + else + return Guid.Empty; + } + + public static void WriteConnectionOpenStop(this DiagnosticListener @this, Guid operationId, MySqlConnection sqlConnection, [CallerMemberName] string operation = "") + { + if (@this.IsEnabled(WriteOpenStop)) + { + @this.Write( + WriteOpenStop, + new + { + OperationId = operationId, + Operation = operation, + Connection = sqlConnection, + Timestamp = Stopwatch.GetTimestamp() + }); + } + } + + public static void WriteConnectionOpenError(this DiagnosticListener @this, Guid operationId, MySqlConnection sqlConnection, Exception ex, [CallerMemberName] string operation = "") + { + if (@this.IsEnabled(WriteOpenError)) + { + @this.Write( + WriteOpenError, + new + { + OperationId = operationId, + Operation = operation, + Connection = sqlConnection, + Exception = ex, + Timestamp = Stopwatch.GetTimestamp() + }); + } + } + + public static Guid WriteConnectionCloseStart(this DiagnosticListener @this, MySqlConnection sqlConnection, [CallerMemberName] string operation = "") + { + if (@this.IsEnabled(WriteCloseStart)) + { + Guid operationId = Guid.NewGuid(); + + @this.Write( + WriteCloseStart, + new + { + OperationId = operationId, + Operation = operation, + Connection = sqlConnection, + Timestamp = Stopwatch.GetTimestamp() + }); + + return operationId; + } + else + return Guid.Empty; + } + + public static void WriteConnectionCloseStop(this DiagnosticListener @this, Guid operationId, string clientConnectionId, MySqlConnection sqlConnection, [CallerMemberName] string operation = "") + { + if (@this.IsEnabled(WriteCloseStop)) + { + @this.Write( + WriteCloseStop, + new + { + OperationId = operationId, + Operation = operation, + ConnectionId = clientConnectionId, + Connection = sqlConnection, + Timestamp = Stopwatch.GetTimestamp() + }); + } + } + + public static void WriteConnectionCloseError(this DiagnosticListener @this, Guid operationId, string clientConnectionId, MySqlConnection sqlConnection, Exception ex, [CallerMemberName] string operation = "") + { + if (@this.IsEnabled(WriteCloseError)) + { + @this.Write( + WriteCloseError, + new + { + OperationId = operationId, + Operation = operation, + ConnectionId = clientConnectionId, + Connection = sqlConnection, + Exception = ex, + Timestamp = Stopwatch.GetTimestamp() + }); + } + } + + public static Guid WriteTransactionCommitStart(this DiagnosticListener @this, IsolationLevel isolationLevel, MySqlConnection connection, [CallerMemberName] string operation = "") + { + if (@this.IsEnabled(WriteCommitStart)) + { + Guid operationId = Guid.NewGuid(); + + @this.Write( + WriteCommitStart, + new + { + OperationId = operationId, + Operation = operation, + IsolationLevel = isolationLevel, + Connection = connection, + Timestamp = Stopwatch.GetTimestamp() + }); + + return operationId; + } + else + return Guid.Empty; + } + + public static void WriteTransactionCommitStop(this DiagnosticListener @this, Guid operationId, IsolationLevel isolationLevel, MySqlConnection connection, [CallerMemberName] string operation = "") + { + if (@this.IsEnabled(WriteCommitStop)) + { + @this.Write( + WriteCommitStop, + new + { + OperationId = operationId, + Operation = operation, + IsolationLevel = isolationLevel, + Connection = connection, + Timestamp = Stopwatch.GetTimestamp() + }); + } + } + + public static void WriteTransactionCommitError(this DiagnosticListener @this, Guid operationId, IsolationLevel isolationLevel, MySqlConnection connection, Exception ex, [CallerMemberName] string operation = "") + { + if (@this.IsEnabled(WriteCommitError)) + { + @this.Write( + WriteCommitError, + new + { + OperationId = operationId, + Operation = operation, + IsolationLevel = isolationLevel, + Connection = connection, + Exception = ex, + Timestamp = Stopwatch.GetTimestamp() + }); + } + } + + public static Guid WriteTransactionRollbackStart(this DiagnosticListener @this, IsolationLevel isolationLevel, MySqlConnection connection, string transactionName, [CallerMemberName] string operation = "") + { + if (@this.IsEnabled(WriteRollbackStart)) + { + Guid operationId = Guid.NewGuid(); + + @this.Write( + WriteRollbackStart, + new + { + OperationId = operationId, + Operation = operation, + IsolationLevel = isolationLevel, + Connection = connection, + TransactionName = transactionName, + Timestamp = Stopwatch.GetTimestamp() + }); + + return operationId; + } + else + return Guid.Empty; + } + + public static void WriteTransactionRollbackStop(this DiagnosticListener @this, Guid operationId, IsolationLevel isolationLevel, MySqlConnection connection, string transactionName, [CallerMemberName] string operation = "") + { + if (@this.IsEnabled(WriteRollbackStop)) + { + @this.Write( + WriteRollbackStop, + new + { + OperationId = operationId, + Operation = operation, + IsolationLevel = isolationLevel, + Connection = connection, + TransactionName = transactionName, + Timestamp = Stopwatch.GetTimestamp() + }); + } + } + + public static void WriteTransactionRollbackError(this DiagnosticListener @this, Guid operationId, IsolationLevel isolationLevel, MySqlConnection connection, string transactionName, Exception ex, [CallerMemberName] string operation = "") + { + if (@this.IsEnabled(WriteRollbackError)) + { + @this.Write( + WriteRollbackError, + new + { + OperationId = operationId, + Operation = operation, + IsolationLevel = isolationLevel, + Connection = connection, + TransactionName = transactionName, + Exception = ex, + Timestamp = Stopwatch.GetTimestamp() + }); + } + } + } +} diff --git a/src/MySqlConnector/Core/TextCommandExecutor.cs b/src/MySqlConnector/Core/TextCommandExecutor.cs index f59362bf0..9651af3fd 100644 --- a/src/MySqlConnector/Core/TextCommandExecutor.cs +++ b/src/MySqlConnector/Core/TextCommandExecutor.cs @@ -1,6 +1,7 @@ using System; using System.Data; using System.Data.Common; +using System.Diagnostics; using System.IO; using System.Net.Sockets; using System.Threading; @@ -23,37 +24,77 @@ internal TextCommandExecutor(MySqlCommand command) public virtual async Task ExecuteNonQueryAsync(string commandText, MySqlParameterCollection parameterCollection, IOBehavior ioBehavior, CancellationToken cancellationToken) { - using (var reader = (MySqlDataReader) await ExecuteReaderAsync(commandText, parameterCollection, CommandBehavior.Default, ioBehavior, cancellationToken).ConfigureAwait(false)) + Exception e = default; + var operationId = s_diagnosticListener.WriteCommandStart(m_command); + + try { - do + using (var reader = (MySqlDataReader) await ExecuteReaderAsync(commandText, parameterCollection, + CommandBehavior.Default, ioBehavior, cancellationToken).ConfigureAwait(false)) { - while (await reader.ReadAsync(ioBehavior, cancellationToken).ConfigureAwait(false)) + do { - } - } while (await reader.NextResultAsync(ioBehavior, cancellationToken).ConfigureAwait(false)); - return reader.RecordsAffected; + while (await reader.ReadAsync(ioBehavior, cancellationToken).ConfigureAwait(false)) + { + } + } while (await reader.NextResultAsync(ioBehavior, cancellationToken).ConfigureAwait(false)); + + return reader.RecordsAffected; + } + } + catch (Exception ex) + { + e = ex; + throw; + } + finally + { + if (e != null) + s_diagnosticListener.WriteCommandError(operationId, m_command, e); + else + s_diagnosticListener.WriteCommandStop(operationId, m_command); } } public virtual async Task ExecuteScalarAsync(string commandText, MySqlParameterCollection parameterCollection, IOBehavior ioBehavior, CancellationToken cancellationToken) { - var hasSetResult = false; - object result = null; - using (var reader = (MySqlDataReader) await ExecuteReaderAsync(commandText, parameterCollection, CommandBehavior.SingleResult | CommandBehavior.SingleRow, ioBehavior, cancellationToken).ConfigureAwait(false)) + Exception e = default; + var operationId = s_diagnosticListener.WriteCommandStart(m_command); + + try { - do + var hasSetResult = false; + object result = null; + using (var reader = (MySqlDataReader) await ExecuteReaderAsync(commandText, parameterCollection, + CommandBehavior.SingleResult | CommandBehavior.SingleRow, ioBehavior, cancellationToken).ConfigureAwait(false)) { - var hasResult = await reader.ReadAsync(ioBehavior, cancellationToken).ConfigureAwait(false); - if (!hasSetResult) + do { - if (hasResult) - result = reader.GetValue(0); - hasSetResult = true; - } - } while (await reader.NextResultAsync(ioBehavior, cancellationToken).ConfigureAwait(false)); + var hasResult = await reader.ReadAsync(ioBehavior, cancellationToken).ConfigureAwait(false); + if (!hasSetResult) + { + if (hasResult) + result = reader.GetValue(0); + hasSetResult = true; + } + } while (await reader.NextResultAsync(ioBehavior, cancellationToken).ConfigureAwait(false)); + } + + return result; + } + catch (Exception ex) + { + e = ex; + throw; + } + finally + { + if (e != null) + s_diagnosticListener.WriteCommandError(operationId, m_command, e); + else + s_diagnosticListener.WriteCommandStop(operationId, m_command); } - return result; } public virtual async Task ExecuteReaderAsync(string commandText, MySqlParameterCollection parameterCollection, @@ -105,6 +146,7 @@ private PayloadData CreateQueryPayload(string commandText, MySqlParameterCollect } static readonly IMySqlConnectorLogger Log = MySqlConnectorLogManager.CreateLogger(nameof(TextCommandExecutor)); + static readonly DiagnosticListener s_diagnosticListener = new DiagnosticListener(DiagnosticListenerExtensions.CommandListenerName); readonly MySqlCommand m_command; } diff --git a/src/MySqlConnector/MySql.Data.MySqlClient/MySqlConnection.cs b/src/MySqlConnector/MySql.Data.MySqlClient/MySqlConnection.cs index 2251f38c2..c79a36951 100644 --- a/src/MySqlConnector/MySql.Data.MySqlClient/MySqlConnection.cs +++ b/src/MySqlConnector/MySql.Data.MySqlClient/MySqlConnection.cs @@ -2,6 +2,7 @@ using System.Collections.Generic; using System.Data; using System.Data.Common; +using System.Diagnostics; using System.Net.Sockets; using System.Security.Authentication; using System.Threading; @@ -165,6 +166,8 @@ private async Task OpenAsync(IOBehavior? ioBehavior, CancellationToken cancellat SetState(ConnectionState.Connecting); + Exception e = default; + var operationId = s_diagnosticListener.WriteConnectionOpenStart(this); try { m_session = await CreateSessionAsync(ioBehavior, cancellationToken).ConfigureAwait(false); @@ -172,16 +175,29 @@ private async Task OpenAsync(IOBehavior? ioBehavior, CancellationToken cancellat m_hasBeenOpened = true; SetState(ConnectionState.Open); } - catch (MySqlException) + catch (MySqlException ex) { + e = ex; SetState(ConnectionState.Closed); throw; } catch (SocketException ex) { + e = ex; SetState(ConnectionState.Closed); throw new MySqlException("Unable to connect to any of the specified MySQL hosts.", ex); } + finally + { + if (e != null) + { + s_diagnosticListener.WriteConnectionOpenError(operationId, this, e); + } + else + { + s_diagnosticListener.WriteConnectionOpenStop(operationId, this); + } + } #if !NETSTANDARD1_3 if (m_connectionSettings.AutoEnlist && System.Transactions.Transaction.Current != null) @@ -469,14 +485,23 @@ private void DoClose() if (m_connectionState != ConnectionState.Closed) { + Exception e = default; + var operationId = s_diagnosticListener.WriteConnectionCloseStart(this); try { CloseDatabase(); } + catch (Exception ex) + { + e = ex; + throw; + } finally { + string sessionId = null; if (m_session != null) { + sessionId = m_session.Id; if (m_connectionSettings.Pooling) m_session.ReturnToPool(); else @@ -484,6 +509,15 @@ private void DoClose() m_session = null; } SetState(ConnectionState.Closed); + + if (e != null) + { + s_diagnosticListener.WriteConnectionCloseError(operationId, sessionId, this, e); + } + else + { + s_diagnosticListener.WriteConnectionCloseStop(operationId, sessionId, this); + } } } } @@ -510,6 +544,7 @@ private ConnectionSettings GetConnectionSettings() static readonly StateChangeEventArgs s_stateChangeClosedConnecting = new StateChangeEventArgs(ConnectionState.Closed, ConnectionState.Connecting); static readonly StateChangeEventArgs s_stateChangeConnectingOpen = new StateChangeEventArgs(ConnectionState.Connecting, ConnectionState.Open); static readonly StateChangeEventArgs s_stateChangeOpenClosed = new StateChangeEventArgs(ConnectionState.Open, ConnectionState.Closed); + static readonly DiagnosticListener s_diagnosticListener = new DiagnosticListener(DiagnosticListenerExtensions.ConnectionListenerName); string m_connectionString; ConnectionSettings m_connectionSettings; diff --git a/src/MySqlConnector/MySql.Data.MySqlClient/MySqlTransaction.cs b/src/MySqlConnector/MySql.Data.MySqlClient/MySqlTransaction.cs index 598ecffbd..879e24c21 100644 --- a/src/MySqlConnector/MySql.Data.MySqlClient/MySqlTransaction.cs +++ b/src/MySqlConnector/MySql.Data.MySqlClient/MySqlTransaction.cs @@ -1,8 +1,10 @@ using System; using System.Data; using System.Data.Common; +using System.Diagnostics; using System.Threading; using System.Threading.Tasks; +using MySqlConnector.Core; using MySqlConnector.Protocol.Serialization; namespace MySql.Data.MySqlClient @@ -21,10 +23,27 @@ private async Task CommitAsync(IOBehavior ioBehavior, CancellationToken cancella if (Connection.CurrentTransaction == this) { - using (var cmd = new MySqlCommand("commit", Connection, this)) - await cmd.ExecuteNonQueryAsync(ioBehavior, cancellationToken).ConfigureAwait(false); - Connection.CurrentTransaction = null; - Connection = null; + Exception e = default; + var operationId = s_diagnosticListener.WriteTransactionCommitStart(IsolationLevel, Connection); + try + { + using (var cmd = new MySqlCommand("commit", Connection, this)) + await cmd.ExecuteNonQueryAsync(ioBehavior, cancellationToken).ConfigureAwait(false); + Connection.CurrentTransaction = null; + Connection = null; + } + catch (Exception ex) + { + e = ex; + throw; + } + finally + { + if (e != null) + s_diagnosticListener.WriteTransactionCommitError(operationId, IsolationLevel, Connection, e); + else + s_diagnosticListener.WriteTransactionCommitStop(operationId, IsolationLevel, Connection); + } } else if (Connection.CurrentTransaction != null) { @@ -48,10 +67,27 @@ private async Task RollbackAsync(IOBehavior ioBehavior, CancellationToken cancel if (Connection.CurrentTransaction == this) { - using (var cmd = new MySqlCommand("rollback", Connection, this)) - await cmd.ExecuteNonQueryAsync(ioBehavior, cancellationToken).ConfigureAwait(false); - Connection.CurrentTransaction = null; - Connection = null; + Exception e = default; + var operationId = s_diagnosticListener.WriteTransactionRollbackStart(IsolationLevel, Connection, null); + try + { + using (var cmd = new MySqlCommand("rollback", Connection, this)) + await cmd.ExecuteNonQueryAsync(ioBehavior, cancellationToken).ConfigureAwait(false); + Connection.CurrentTransaction = null; + Connection = null; + } + catch (Exception ex) + { + e = ex; + throw; + } + finally + { + if (e != null) + s_diagnosticListener.WriteTransactionRollbackError(operationId, IsolationLevel, Connection, null, e); + else + s_diagnosticListener.WriteTransactionRollbackStop(operationId, IsolationLevel, Connection, null); + } } else if (Connection.CurrentTransaction != null) { @@ -104,6 +140,8 @@ private void VerifyNotDisposed() throw new ObjectDisposedException(nameof(MySqlTransaction)); } + static readonly DiagnosticListener s_diagnosticListener = new DiagnosticListener(DiagnosticListenerExtensions.TransactionListenerName); + bool m_isDisposed; } } diff --git a/src/MySqlConnector/MySqlConnector.csproj b/src/MySqlConnector/MySqlConnector.csproj index 7c1e43308..277ec3e56 100644 --- a/src/MySqlConnector/MySqlConnector.csproj +++ b/src/MySqlConnector/MySqlConnector.csproj @@ -14,6 +14,7 @@ + @@ -22,6 +23,7 @@ +