Skip to content

Improve Execute.WithConnection PerformDBOperation logging #2089

Open
@jzabroski

Description

@jzabroski

Is your feature request related to a problem? Please describe.
If a migration times out, sometimes the log simply says something like the below. This is poor from an auditability standpoint, and also requires sifting through the Stack Trace to find the real issue (line 282).

PerformDBOperation
Performing DB Operation
Rolling back transaction
!!! Execution Timeout Expired.  The timeout period elapsed prior to completion of the operation or the server is not responding.
!!! +- The wait operation timed out.
Unhandled exception. Microsoft.Data.SqlClient.SqlException (0x80131904): Execution Timeout Expired.  The timeout period elapsed prior to completion of the operation or the server is not responding.
 ---> System.ComponentModel.Win32Exception (258): The wait operation timed out.
   at Microsoft.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction)
   at Microsoft.Data.SqlClient.SqlInternalConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction)
   at Microsoft.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj, SqlCommand command, Boolean callerHasConnectionLock, Boolean asyncClose)
   at Microsoft.Data.SqlClient.TdsParser.TryRun(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj, Boolean& dataReady)
   at Microsoft.Data.SqlClient.SqlDataReader.TryConsumeMetaData()
   at Microsoft.Data.SqlClient.SqlDataReader.get_MetaData()
   at Microsoft.Data.SqlClient.SqlCommand.FinishExecuteReader(SqlDataReader ds, RunBehavior runBehavior, String resetOptionsString, Boolean isInternal, Boolean forDescribeParameterEncryption, Boolean shouldCacheForAlwaysEncrypted)
   at Microsoft.Data.SqlClient.SqlCommand.RunExecuteReaderTds(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, Boolean isAsync, Int32 timeout, Task& task, Boolean asyncWrite, Boolean inRetry, SqlDataReader ds, Boolean describeParameterEncryptionRequest)
   at Microsoft.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, TaskCompletionSource`1 completion, Int32 timeout, Task& task, Boolean& usedCache, Boolean asyncWrite, Boolean inRetry, String method)
   at Microsoft.Data.SqlClient.SqlCommand.ExecuteReader(CommandBehavior behavior)
   at Microsoft.Data.SqlClient.SqlCommand.ExecuteDbDataReader(CommandBehavior behavior)
   at Database.Extensions.SysDataHelper.GetAllTables(IDbConnection connection, IDbTransaction transaction)
   at Database.Extensions.TemporalTableExtensions.<>c.<VerifyTemporalTablePeriodIntegrity>b__3_0(IDbConnection connection, IDbTransaction transaction) in D:\TeamCity\buildAgent\work\77094892e16807fb\source\Database\Extensions\TemporalTableExtensions.cs:line 282

Describe the solution you'd like
Add an override for IExecuteExpressionRoot:

        /// <summary>
        /// Calls an action to execute dynamically generated SQL statements
        /// </summary>
        /// <param name="operation">The operation to execute on a given connection and transaction</param>
        void WithConnection(Action<IDbConnection, IDbTransaction> operation, string description);

and update the various processors that call PerformDBOperation to log the description parameter.

Metadata

Metadata

Assignees

No one assigned

    Labels

    featureA new feature (we all like those)

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions