From 02bb112a937699077e0b84292144f4514fcf9ff3 Mon Sep 17 00:00:00 2001 From: Shay Rojansky Date: Thu, 22 Apr 2021 23:42:57 +0300 Subject: [PATCH] Suppress logging checks in hot query paths (#24304) (#24724) Part of #23611 (cherry picked from commit 0ca7426b85c005d6210f8cdc2ff2b9b47c2bf258) --- .../IRelationalCommandDiagnosticsLogger.cs | 407 ++++ .../IRelationalConnectionDiagnosticsLogger.cs | 154 ++ .../RelationalCommandDiagnosticsLogger.cs | 1317 ++++++++++++ .../RelationalConnectionDiagnosticsLogger.cs | 679 ++++++ .../Diagnostics/RelationalLoggerExtensions.cs | 1858 ----------------- ...ntityFrameworkRelationalServicesBuilder.cs | 8 + .../HistoryRepositoryDependencies.cs | 4 +- .../Migrations/Internal/Migrator.cs | 4 +- .../Migrations/MigrationCommand.cs | 4 +- .../MigrationsSqlGeneratorDependencies.cs | 4 +- .../Query/RelationalQueryContext.cs | 7 + .../IRelationalDatabaseFacadeDependencies.cs | 6 + .../RelationalDatabaseFacadeDependencies.cs | 6 +- .../Storage/RelationalCommand.cs | 401 ++-- .../RelationalCommandParameterObject.cs | 6 +- .../Storage/RelationalConnection.cs | 105 +- .../RelationalConnectionDependencies.cs | 4 +- .../Storage/RelationalDataReader.cs | 12 +- .../RelationalDatabaseCreatorDependencies.cs | 4 +- ...ficationCommandBatchFactoryDependencies.cs | 4 +- ...ISqlServerSequenceValueGeneratorFactory.cs | 2 +- .../SqlServerSequenceHiLoValueGenerator.cs | 4 +- .../SqlServerSequenceValueGeneratorFactory.cs | 2 +- .../SqlServerValueGeneratorSelector.cs | 4 +- src/EFCore/DbContextOptionsBuilder.cs | 16 + src/EFCore/DbContextOptionsBuilder`.cs | 16 + .../Diagnostics/Internal/DiagnosticsLogger.cs | 57 + .../Infrastructure/CoreOptionsExtension.cs | 32 + test/EFCore.Cosmos.Tests/CosmosEventIdTest.cs | 2 +- .../Design/MigrationScaffolderTest.cs | 2 +- .../InMemoryEventIdTest.cs | 2 +- .../CommandInterceptionTestBase.cs | 16 +- .../MigrationCommandExecutorTest.cs | 13 +- .../MigrationCommandListBuilderTest.cs | 2 +- .../RelationalApiConsistencyTest.cs | 7 +- .../RelationalEventIdTest.cs | 35 +- .../Storage/RelationalCommandTest.cs | 26 +- .../FakeProvider/FakeRelationalConnection.cs | 5 +- .../FakeRelationalCommandDiagnosticsLogger.cs | 220 ++ .../ReaderModificationCommandBatchTest.cs | 2 +- .../TestUtilities/TestLoggerFactory.cs | 29 + .../SqlServerConnectionTest.cs | 22 +- .../SqlServerEventIdTest.cs | 2 +- .../SqlServerSequenceValueGeneratorTest.cs | 6 +- ...rverModificationCommandBatchFactoryTest.cs | 4 +- .../SqlServerModificationCommandBatchTest.cs | 2 +- test/EFCore.Sqlite.Tests/SqliteEventIdTest.cs | 2 +- test/EFCore.Tests/ApiConsistencyTest.cs | 6 +- .../Infrastructure/CoreEventIdTest.cs | 2 +- .../Infrastructure/EventIdTestBase.cs | 87 +- 50 files changed, 3453 insertions(+), 2168 deletions(-) create mode 100644 src/EFCore.Relational/Diagnostics/IRelationalCommandDiagnosticsLogger.cs create mode 100644 src/EFCore.Relational/Diagnostics/IRelationalConnectionDiagnosticsLogger.cs create mode 100644 src/EFCore.Relational/Diagnostics/Internal/RelationalCommandDiagnosticsLogger.cs create mode 100644 src/EFCore.Relational/Diagnostics/Internal/RelationalConnectionDiagnosticsLogger.cs create mode 100644 test/EFCore.Relational.Tests/TestUtilities/FakeRelationalCommandDiagnosticsLogger.cs create mode 100644 test/EFCore.Specification.Tests/TestUtilities/TestLoggerFactory.cs diff --git a/src/EFCore.Relational/Diagnostics/IRelationalCommandDiagnosticsLogger.cs b/src/EFCore.Relational/Diagnostics/IRelationalCommandDiagnosticsLogger.cs new file mode 100644 index 00000000000..56737ad515a --- /dev/null +++ b/src/EFCore.Relational/Diagnostics/IRelationalCommandDiagnosticsLogger.cs @@ -0,0 +1,407 @@ +// Copyright (c) .NET Foundation. All rights reserved. +// Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information. + +using System; +using System.Data.Common; +using System.Threading; +using System.Threading.Tasks; +using Microsoft.EntityFrameworkCore.Storage; + +namespace Microsoft.EntityFrameworkCore.Diagnostics +{ + /// + /// An with some extra functionality suited for high-performance logging. + /// + public interface IRelationalCommandDiagnosticsLogger : IDiagnosticsLogger + { + /// + /// Logs for the event. + /// + /// The connection. + /// The type of method that will be called on this command. + /// The currently being used, to null if not known. + /// The correlation ID associated with the given . + /// The correlation ID associated with the being used. + /// The time that execution began. + /// An intercepted result. + InterceptionResult CommandCreating( + IRelationalConnection connection, + DbCommandMethod commandMethod, + DbContext? context, + Guid commandId, + Guid connectionId, + DateTimeOffset startTime); + + /// + /// Logs for the event. + /// + /// The connection. + /// The database command object. + /// The type of method that will be called on this command. + /// The currently being used, to null if not known. + /// The correlation ID associated with the given . + /// The correlation ID associated with the being used. + /// The time that execution began. + /// The duration of the command creation. + /// An intercepted result. + DbCommand CommandCreated( + IRelationalConnection connection, + DbCommand command, + DbCommandMethod commandMethod, + DbContext? context, + Guid commandId, + Guid connectionId, + DateTimeOffset startTime, + TimeSpan duration); + + /// + /// Logs for the event. + /// + /// The connection. + /// The database command object. + /// The currently being used, to null if not known. + /// The correlation ID associated with the given . + /// The correlation ID associated with the being used. + /// The time that execution began. + /// An intercepted result. + InterceptionResult CommandReaderExecuting( + IRelationalConnection connection, + DbCommand command, + DbContext? context, + Guid commandId, + Guid connectionId, + DateTimeOffset startTime); + + /// + /// Logs for the event. + /// + /// The connection. + /// The database command object. + /// The currently being used, to null if not known. + /// The correlation ID associated with the given . + /// The correlation ID associated with the being used. + /// The time that execution began. + /// An intercepted result. + InterceptionResult CommandScalarExecuting( + IRelationalConnection connection, + DbCommand command, + DbContext? context, + Guid commandId, + Guid connectionId, + DateTimeOffset startTime); + + /// + /// Logs for the event. + /// + /// The connection. + /// The database command object. + /// The currently being used, to null if not known. + /// The correlation ID associated with the given . + /// The correlation ID associated with the being used. + /// The time that execution began. + /// An intercepted result. + InterceptionResult CommandNonQueryExecuting( + IRelationalConnection connection, + DbCommand command, + DbContext? context, + Guid commandId, + Guid connectionId, + DateTimeOffset startTime); + + /// + /// Logs for the event. + /// + /// The connection. + /// The database command object. + /// The currently being used, to null if not known. + /// The correlation ID associated with the given . + /// The correlation ID associated with the being used. + /// The time that execution began. + /// A to observe while waiting for the task to complete. + /// An intercepted result. + /// If the is canceled. + ValueTask> CommandReaderExecutingAsync( + IRelationalConnection connection, + DbCommand command, + DbContext? context, + Guid commandId, + Guid connectionId, + DateTimeOffset startTime, + CancellationToken cancellationToken = default); + + /// + /// Logs for the event. + /// + /// The connection. + /// The database command object. + /// The currently being used, to null if not known. + /// The correlation ID associated with the given . + /// The correlation ID associated with the being used. + /// The time that execution began. + /// A to observe while waiting for the task to complete. + /// An intercepted result. + /// If the is canceled. + ValueTask> CommandScalarExecutingAsync( + IRelationalConnection connection, + DbCommand command, + DbContext? context, + Guid commandId, + Guid connectionId, + DateTimeOffset startTime, + CancellationToken cancellationToken = default); + + /// + /// Logs for the event. + /// + /// The connection. + /// The database command object. + /// The currently being used, to null if not known. + /// The correlation ID associated with the given . + /// The correlation ID associated with the being used. + /// The time that execution began. + /// A to observe while waiting for the task to complete. + /// An intercepted result. + /// If the is canceled. + ValueTask> CommandNonQueryExecutingAsync( + IRelationalConnection connection, + DbCommand command, + DbContext? context, + Guid commandId, + Guid connectionId, + DateTimeOffset startTime, + CancellationToken cancellationToken = default); + + /// + /// Logs for the event. + /// + /// The connection. + /// The database command object. + /// The currently being used, to null if not known. + /// The correlation ID associated with the given . + /// The correlation ID associated with the being used. + /// The return value from the underlying method execution. + /// The time that execution began. + /// The duration of the command execution, not including consuming results. + /// The result of execution, which may have been modified by an interceptor. + DbDataReader CommandReaderExecuted( + IRelationalConnection connection, + DbCommand command, + DbContext? context, + Guid commandId, + Guid connectionId, + DbDataReader methodResult, + DateTimeOffset startTime, + TimeSpan duration); + + /// + /// Logs for the event. + /// + /// The connection. + /// The database command object. + /// The currently being used, to null if not known. + /// The correlation ID associated with the given . + /// The correlation ID associated with the being used. + /// The return value from the underlying method execution. + /// The time that execution began. + /// The duration of the command execution, not including consuming results. + /// The result of execution, which may have been modified by an interceptor. + object? CommandScalarExecuted( + IRelationalConnection connection, + DbCommand command, + DbContext? context, + Guid commandId, + Guid connectionId, + object? methodResult, + DateTimeOffset startTime, + TimeSpan duration); + + /// + /// Logs for the event. + /// + /// The connection. + /// The database command object. + /// The currently being used, to null if not known. + /// The correlation ID associated with the given . + /// The correlation ID associated with the being used. + /// The return value from the underlying method execution. + /// The time that execution began. + /// The duration of the command execution, not including consuming results. + /// The result of execution, which may have been modified by an interceptor. + int CommandNonQueryExecuted( + IRelationalConnection connection, + DbCommand command, + DbContext? context, + Guid commandId, + Guid connectionId, + int methodResult, + DateTimeOffset startTime, + TimeSpan duration); + + /// + /// Logs for the event. + /// + /// The connection. + /// The database command object. + /// The currently being used, to null if not known. + /// The correlation ID associated with the given . + /// The correlation ID associated with the being used. + /// The return value from the underlying method execution. + /// The time that execution began. + /// The duration of the command execution, not including consuming results. + /// A to observe while waiting for the task to complete. + /// The result of execution, which may have been modified by an interceptor. + /// If the is canceled. + ValueTask CommandReaderExecutedAsync( + IRelationalConnection connection, + DbCommand command, + DbContext? context, + Guid commandId, + Guid connectionId, + DbDataReader methodResult, + DateTimeOffset startTime, + TimeSpan duration, + CancellationToken cancellationToken = default); + + /// + /// Logs for the event. + /// + /// The connection. + /// The database command object. + /// The currently being used, to null if not known. + /// The correlation ID associated with the given . + /// The correlation ID associated with the being used. + /// The return value from the underlying method execution. + /// The time that execution began. + /// The duration of the command execution, not including consuming results. + /// A to observe while waiting for the task to complete. + /// The result of execution, which may have been modified by an interceptor. + /// If the is canceled. + ValueTask CommandScalarExecutedAsync( + IRelationalConnection connection, + DbCommand command, + DbContext? context, + Guid commandId, + Guid connectionId, + object? methodResult, + DateTimeOffset startTime, + TimeSpan duration, + CancellationToken cancellationToken = default); + + /// + /// Logs for the event. + /// + /// The connection. + /// The database command object. + /// The currently being used, to null if not known. + /// The correlation ID associated with the given . + /// The correlation ID associated with the being used. + /// The return value from the underlying method execution. + /// The time that execution began. + /// The duration of the command execution, not including consuming results. + /// A to observe while waiting for the task to complete. + /// The result of execution, which may have been modified by an interceptor. + /// If the is canceled. + ValueTask CommandNonQueryExecutedAsync( + IRelationalConnection connection, + DbCommand command, + DbContext? context, + Guid commandId, + Guid connectionId, + int methodResult, + DateTimeOffset startTime, + TimeSpan duration, + CancellationToken cancellationToken = default); + + /// + /// Logs for the event. + /// + /// The connection. + /// The database command object. + /// The currently being used, to null if not known. + /// Represents the method that will be called to execute the command. + /// The correlation ID associated with the given . + /// The correlation ID associated with the being used. + /// The exception that caused this failure. + /// The time that execution began. + /// The amount of time that passed until the exception was raised. + void CommandError( + IRelationalConnection connection, + DbCommand command, + DbContext? context, + DbCommandMethod executeMethod, + Guid commandId, + Guid connectionId, + Exception exception, + DateTimeOffset startTime, + TimeSpan duration); + + /// + /// Logs for the event. + /// + /// The connection. + /// The database command object. + /// The currently being used, to null if not known. + /// Represents the method that will be called to execute the command. + /// The correlation ID associated with the given . + /// The correlation ID associated with the being used. + /// The exception that caused this failure. + /// The time that execution began. + /// The amount of time that passed until the exception was raised. + /// A to observe while waiting for the task to complete. + /// A representing the async operation. + /// If the is canceled. + Task CommandErrorAsync( + IRelationalConnection connection, + DbCommand command, + DbContext? context, + DbCommandMethod executeMethod, + Guid commandId, + Guid connectionId, + Exception exception, + DateTimeOffset startTime, + TimeSpan duration, + CancellationToken cancellationToken = default); + + /// + /// Logs for the event. + /// + /// The connection. + /// The database command object. + /// The data reader. + /// The correlation ID associated with the given . + /// The number of records in the database that were affected. + /// The number of records that were read. + /// The time that the operation was started. + /// The elapsed time from when the operation was started. + /// The result of execution, which may have been modified by an interceptor. + InterceptionResult DataReaderDisposing( + IRelationalConnection connection, + DbCommand command, + DbDataReader dataReader, + Guid commandId, + int recordsAffected, + int readCount, + DateTimeOffset startTime, + TimeSpan duration); + + /// + /// Whether or need + /// to be logged. + /// + bool ShouldLogCommandCreate(DateTimeOffset now); + + /// + /// Whether or need + /// to be logged. + /// + bool ShouldLogCommandExecute(DateTimeOffset now); + + /// + /// Whether needs to be logged. + /// + bool ShouldLogDataReaderDispose(DateTimeOffset now); + + private bool ShouldLogParameterValues(DbCommand command) + => command.Parameters.Count > 0 && ShouldLogSensitiveData(); + } +} diff --git a/src/EFCore.Relational/Diagnostics/IRelationalConnectionDiagnosticsLogger.cs b/src/EFCore.Relational/Diagnostics/IRelationalConnectionDiagnosticsLogger.cs new file mode 100644 index 00000000000..a411452dc93 --- /dev/null +++ b/src/EFCore.Relational/Diagnostics/IRelationalConnectionDiagnosticsLogger.cs @@ -0,0 +1,154 @@ +// Copyright (c) .NET Foundation. All rights reserved. +// Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information. + +using System; +using System.Threading; +using System.Threading.Tasks; +using Microsoft.EntityFrameworkCore.Storage; + +namespace Microsoft.EntityFrameworkCore.Diagnostics +{ + /// + /// An with some extra functionality suited for high-performance logging. + /// + public interface IRelationalConnectionDiagnosticsLogger : IDiagnosticsLogger + { + /// + /// Logs for the event. + /// + /// The connection. + /// The time that the operation was started. + /// The result of execution, which may have been modified by an interceptor. + InterceptionResult ConnectionOpening( + IRelationalConnection connection, + DateTimeOffset startTime); + + /// + /// Logs for the event. + /// + /// The connection. + /// The time that the operation was started. + /// A to observe while waiting for the task to complete. + /// A representing the async operation. + /// If the is canceled. + ValueTask ConnectionOpeningAsync( + IRelationalConnection connection, + DateTimeOffset startTime, + CancellationToken cancellationToken); + + /// + /// Logs for the event. + /// + /// The connection. + /// The time that the operation was started. + /// The amount of time before the connection was opened. + void ConnectionOpened( + IRelationalConnection connection, + DateTimeOffset startTime, + TimeSpan duration); + + /// + /// Logs for the event. + /// + /// The connection. + /// The time that the operation was started. + /// The amount of time before the connection was opened. + /// A to observe while waiting for the task to complete. + /// A representing the async operation. + /// If the is canceled. + Task ConnectionOpenedAsync( + IRelationalConnection connection, + DateTimeOffset startTime, + TimeSpan duration, + CancellationToken cancellationToken = default); + + /// + /// Logs for the event. + /// + /// The connection. + /// The time that the operation was started. + /// The result of execution, which may have been modified by an interceptor. + InterceptionResult ConnectionClosing( + IRelationalConnection connection, + DateTimeOffset startTime); + + /// + /// Logs for the event. + /// + /// The connection. + /// The time that the operation was started. + /// A representing the async operation. + ValueTask ConnectionClosingAsync( + IRelationalConnection connection, + DateTimeOffset startTime); + + /// + /// Logs for the event. + /// + /// The connection. + /// The time that the operation was started. + /// The amount of time before the connection was closed. + void ConnectionClosed( + IRelationalConnection connection, + DateTimeOffset startTime, + TimeSpan duration); + + /// + /// Logs for the event. + /// + /// The connection. + /// The time that the operation was started. + /// The amount of time before the connection was closed. + /// A representing the async operation. + Task ConnectionClosedAsync( + IRelationalConnection connection, + DateTimeOffset startTime, + TimeSpan duration); + + /// + /// Logs for the event. + /// + /// The connection. + /// The exception representing the error. + /// The time that the operation was started. + /// The elapsed time before the operation failed. + /// A flag indicating the exception is being handled and so it should be logged at Debug level. + void ConnectionError( + IRelationalConnection connection, + Exception exception, + DateTimeOffset startTime, + TimeSpan duration, + bool logErrorAsDebug); + + /// + /// Logs for the event. + /// + /// The connection. + /// The exception representing the error. + /// The time that the operation was started. + /// The elapsed time before the operation failed. + /// A flag indicating the exception is being handled and so it should be logged at Debug level. + /// A to observe while waiting for the task to complete. + /// A representing the async operation. + /// If the is canceled. + Task ConnectionErrorAsync( + IRelationalConnection connection, + Exception exception, + DateTimeOffset startTime, + TimeSpan duration, + bool logErrorAsDebug, + CancellationToken cancellationToken = default); + + /// + /// Whether or need + /// to be logged. + /// + bool ShouldLogConnectionOpen(DateTimeOffset now); + + /// + /// Whether or need + /// to be logged. + /// + bool ShouldLogConnectionClose(DateTimeOffset now); + } +} diff --git a/src/EFCore.Relational/Diagnostics/Internal/RelationalCommandDiagnosticsLogger.cs b/src/EFCore.Relational/Diagnostics/Internal/RelationalCommandDiagnosticsLogger.cs new file mode 100644 index 00000000000..711e45c36d2 --- /dev/null +++ b/src/EFCore.Relational/Diagnostics/Internal/RelationalCommandDiagnosticsLogger.cs @@ -0,0 +1,1317 @@ +// Copyright (c) .NET Foundation. All rights reserved. +// Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information. + +using System; +using System.Data; +using System.Data.Common; +using System.Diagnostics; +using System.Globalization; +using System.Threading; +using System.Threading.Tasks; +using Microsoft.EntityFrameworkCore.Infrastructure; +using Microsoft.EntityFrameworkCore.Storage; +using Microsoft.EntityFrameworkCore.Storage.Internal; +using Microsoft.Extensions.Logging; + +#pragma warning disable EF1001 + +namespace Microsoft.EntityFrameworkCore.Diagnostics.Internal +{ + /// + /// This is an internal API that supports the Entity Framework Core infrastructure and not subject to + /// the same compatibility standards as public APIs. It may be changed or removed without notice in + /// any release. You should only use it directly in your code with extreme caution and knowing that + /// doing so can result in application failures when updating to a new Entity Framework Core release. + /// + public class RelationalCommandDiagnosticsLogger + : DiagnosticsLogger, IRelationalCommandDiagnosticsLogger + { + private DateTimeOffset _suppressCommandCreateExpiration; + private DateTimeOffset _suppressCommandExecuteExpiration; + private DateTimeOffset _suppressDataReaderDisposingExpiration; + + private readonly TimeSpan _loggingConfigCacheTime; + + /// + /// This is an internal API that supports the Entity Framework Core infrastructure and not subject to + /// the same compatibility standards as public APIs. It may be changed or removed without notice in + /// any release. You should only use it directly in your code with extreme caution and knowing that + /// doing so can result in application failures when updating to a new Entity Framework Core release. + /// + public RelationalCommandDiagnosticsLogger( + ILoggerFactory loggerFactory, + ILoggingOptions loggingOptions, + DiagnosticSource diagnosticSource, + LoggingDefinitions loggingDefinitions, + IDbContextLogger contextLogger, + IDbContextOptions contextOptions, + IInterceptors? interceptors = null) + : base(loggerFactory, loggingOptions, diagnosticSource, loggingDefinitions, contextLogger, interceptors) + { + _loggingConfigCacheTime = contextOptions.FindExtension()?.LoggingConfigCacheTime ?? + CoreOptionsExtension.DefaultLoggingConfigCacheTime; + } + + #region CommandCreating + + /// + /// This is an internal API that supports the Entity Framework Core infrastructure and not subject to + /// the same compatibility standards as public APIs. It may be changed or removed without notice in + /// any release. You should only use it directly in your code with extreme caution and knowing that + /// doing so can result in application failures when updating to a new Entity Framework Core release. + /// + public virtual InterceptionResult CommandCreating( + IRelationalConnection connection, + DbCommandMethod commandMethod, + DbContext? context, + Guid commandId, + Guid connectionId, + DateTimeOffset startTime) + { + _suppressCommandCreateExpiration = startTime + _loggingConfigCacheTime; + + var definition = RelationalResources.LogCommandCreating(this); + + if (ShouldLog(definition)) + { + _suppressCommandCreateExpiration = default; + + definition.Log(this, commandMethod.ToString()); + } + + if (NeedsEventData( + definition, out var interceptor, out var diagnosticSourceEnabled, out var simpleLogEnabled)) + { + _suppressCommandCreateExpiration = default; + + var eventData = BroadcastCommandCreating( + connection.DbConnection, + context, + commandMethod, + commandId, + connectionId, + async: false, + startTime, + definition, + diagnosticSourceEnabled, + simpleLogEnabled); + + if (interceptor != null) + { + return interceptor.CommandCreating(eventData, default); + } + } + + return default; + } + + private CommandCorrelatedEventData BroadcastCommandCreating( + DbConnection connection, + DbContext? context, + DbCommandMethod executeMethod, + Guid commandId, + Guid connectionId, + bool async, + DateTimeOffset startTime, + EventDefinition definition, + bool diagnosticSourceEnabled, + bool simpleLogEnabled) + { + var eventData = new CommandCorrelatedEventData( + definition, + CommandCreating, + connection, + context, + executeMethod, + commandId, + connectionId, + async, + startTime); + + DispatchEventData(definition, eventData, diagnosticSourceEnabled, simpleLogEnabled); + + return eventData; + + static string CommandCreating(EventDefinitionBase definition, EventData payload) + { + var d = (EventDefinition)definition; + var p = (CommandCorrelatedEventData)payload; + return d.GenerateMessage(p.ExecuteMethod.ToString()); + } + } + + #endregion CommandCreating + + #region CommandCreated + + /// + /// This is an internal API that supports the Entity Framework Core infrastructure and not subject to + /// the same compatibility standards as public APIs. It may be changed or removed without notice in + /// any release. You should only use it directly in your code with extreme caution and knowing that + /// doing so can result in application failures when updating to a new Entity Framework Core release. + /// + public virtual DbCommand CommandCreated( + IRelationalConnection connection, + DbCommand command, + DbCommandMethod commandMethod, + DbContext? context, + Guid commandId, + Guid connectionId, + DateTimeOffset startTime, + TimeSpan duration) + { + var definition = RelationalResources.LogCommandCreated(this); + + if (ShouldLog(definition)) + { + _suppressCommandCreateExpiration = default; + + definition.Log(this, commandMethod.ToString(), (int)duration.TotalMilliseconds); + } + + if (NeedsEventData( + definition, out var interceptor, out var diagnosticSourceEnabled, out var simpleLogEnabled)) + { + _suppressCommandCreateExpiration = default; + + var eventData = BroadcastCommandCreated( + connection.DbConnection, + command, + context, + commandMethod, + commandId, + connectionId, + async: false, + startTime, + duration, + definition, + diagnosticSourceEnabled, + simpleLogEnabled); + + if (interceptor != null) + { + return interceptor.CommandCreated(eventData, command); + } + } + + return command; + } + + private CommandEndEventData BroadcastCommandCreated( + DbConnection connection, + DbCommand command, + DbContext? context, + DbCommandMethod executeMethod, + Guid commandId, + Guid connectionId, + bool async, + DateTimeOffset startTime, + TimeSpan duration, + EventDefinition definition, + bool diagnosticSourceEnabled, + bool simpleLogEnabled) + { + var eventData = new CommandEndEventData( + definition, + CommandCreated, + connection, + command, + context, + executeMethod, + commandId, + connectionId, + async, + false, + startTime, + duration); + + DispatchEventData(definition, eventData, diagnosticSourceEnabled, simpleLogEnabled); + + return eventData; + + static string CommandCreated(EventDefinitionBase definition, EventData payload) + { + var d = (EventDefinition)definition; + var p = (CommandEndEventData)payload; + return d.GenerateMessage(p.ExecuteMethod.ToString(), (int)p.Duration.TotalMilliseconds); + } + } + + #endregion CommandCreated + + #region CommandExecuting + + /// + /// This is an internal API that supports the Entity Framework Core infrastructure and not subject to + /// the same compatibility standards as public APIs. It may be changed or removed without notice in + /// any release. You should only use it directly in your code with extreme caution and knowing that + /// doing so can result in application failures when updating to a new Entity Framework Core release. + /// + public virtual InterceptionResult CommandReaderExecuting( + IRelationalConnection connection, + DbCommand command, + DbContext? context, + Guid commandId, + Guid connectionId, + DateTimeOffset startTime) + { + _suppressCommandExecuteExpiration = startTime + _loggingConfigCacheTime; + + var definition = RelationalResources.LogExecutingCommand(this); + + if (ShouldLog(definition)) + { + _suppressCommandExecuteExpiration = default; + + definition.Log( + this, + command.Parameters.FormatParameters(ShouldLogParameterValues(command)), + command.CommandType, + command.CommandTimeout, + Environment.NewLine, + command.CommandText.TrimEnd()); + } + + if (NeedsEventData( + definition, out var interceptor, out var diagnosticSourceEnabled, out var simpleLogEnabled)) + { + _suppressCommandExecuteExpiration = default; + + var eventData = BroadcastCommandExecuting( + connection.DbConnection, + command, + context, + DbCommandMethod.ExecuteReader, + commandId, + connectionId, + false, + startTime, + definition, + diagnosticSourceEnabled, + simpleLogEnabled); + + if (interceptor != null) + { + return interceptor.ReaderExecuting(command, eventData, default); + } + } + + return default; + } + + /// + /// This is an internal API that supports the Entity Framework Core infrastructure and not subject to + /// the same compatibility standards as public APIs. It may be changed or removed without notice in + /// any release. You should only use it directly in your code with extreme caution and knowing that + /// doing so can result in application failures when updating to a new Entity Framework Core release. + /// + public virtual InterceptionResult CommandScalarExecuting( + IRelationalConnection connection, + DbCommand command, + DbContext? context, + Guid commandId, + Guid connectionId, + DateTimeOffset startTime) + { + _suppressCommandExecuteExpiration = startTime + _loggingConfigCacheTime; + + var definition = RelationalResources.LogExecutingCommand(this); + + if (ShouldLog(definition)) + { + _suppressCommandExecuteExpiration = default; + + definition.Log( + this, + command.Parameters.FormatParameters(ShouldLogParameterValues(command)), + command.CommandType, + command.CommandTimeout, + Environment.NewLine, + command.CommandText.TrimEnd()); + } + + if (NeedsEventData( + definition, out var interceptor, out var diagnosticSourceEnabled, out var simpleLogEnabled)) + { + _suppressCommandExecuteExpiration = default; + + var eventData = BroadcastCommandExecuting( + connection.DbConnection, + command, + context, + DbCommandMethod.ExecuteScalar, + commandId, + connectionId, + false, + startTime, + definition, + diagnosticSourceEnabled, + simpleLogEnabled); + + if (interceptor != null) + { + return interceptor.ScalarExecuting(command, eventData, default); + } + } + + return default; + } + + /// + /// This is an internal API that supports the Entity Framework Core infrastructure and not subject to + /// the same compatibility standards as public APIs. It may be changed or removed without notice in + /// any release. You should only use it directly in your code with extreme caution and knowing that + /// doing so can result in application failures when updating to a new Entity Framework Core release. + /// + public virtual InterceptionResult CommandNonQueryExecuting( + IRelationalConnection connection, + DbCommand command, + DbContext? context, + Guid commandId, + Guid connectionId, + DateTimeOffset startTime) + { + _suppressCommandExecuteExpiration = startTime + _loggingConfigCacheTime; + + var definition = RelationalResources.LogExecutingCommand(this); + + if (ShouldLog(definition)) + { + _suppressCommandExecuteExpiration = default; + + definition.Log( + this, + command.Parameters.FormatParameters(ShouldLogParameterValues(command)), + command.CommandType, + command.CommandTimeout, + Environment.NewLine, + command.CommandText.TrimEnd()); + } + + if (NeedsEventData( + definition, out var interceptor, out var diagnosticSourceEnabled, out var simpleLogEnabled)) + { + _suppressCommandExecuteExpiration = default; + + var eventData = BroadcastCommandExecuting( + connection.DbConnection, + command, + context, + DbCommandMethod.ExecuteNonQuery, + commandId, + connectionId, + false, + startTime, + definition, + diagnosticSourceEnabled, + simpleLogEnabled); + + if (interceptor != null) + { + return interceptor.NonQueryExecuting(command, eventData, default); + } + } + + return default; + } + + /// + /// This is an internal API that supports the Entity Framework Core infrastructure and not subject to + /// the same compatibility standards as public APIs. It may be changed or removed without notice in + /// any release. You should only use it directly in your code with extreme caution and knowing that + /// doing so can result in application failures when updating to a new Entity Framework Core release. + /// + public virtual ValueTask> CommandReaderExecutingAsync( + IRelationalConnection connection, + DbCommand command, + DbContext? context, + Guid commandId, + Guid connectionId, + DateTimeOffset startTime, + CancellationToken cancellationToken = default) + { + _suppressCommandExecuteExpiration = startTime + _loggingConfigCacheTime; + + var definition = RelationalResources.LogExecutingCommand(this); + + if (ShouldLog(definition)) + { + _suppressCommandExecuteExpiration = default; + + definition.Log( + this, + command.Parameters.FormatParameters(ShouldLogParameterValues(command)), + command.CommandType, + command.CommandTimeout, + Environment.NewLine, + command.CommandText.TrimEnd()); + } + + if (NeedsEventData( + definition, out var interceptor, out var diagnosticSourceEnabled, out var simpleLogEnabled)) + { + _suppressCommandExecuteExpiration = default; + + var eventData = BroadcastCommandExecuting( + connection.DbConnection, + command, + context, + DbCommandMethod.ExecuteReader, + commandId, + connectionId, + async: true, + startTime, + definition, + diagnosticSourceEnabled, + simpleLogEnabled); + + if (interceptor != null) + { + return interceptor.ReaderExecutingAsync(command, eventData, default, cancellationToken); + } + } + + return default; + } + + /// + /// This is an internal API that supports the Entity Framework Core infrastructure and not subject to + /// the same compatibility standards as public APIs. It may be changed or removed without notice in + /// any release. You should only use it directly in your code with extreme caution and knowing that + /// doing so can result in application failures when updating to a new Entity Framework Core release. + /// + public virtual ValueTask> CommandScalarExecutingAsync( + IRelationalConnection connection, + DbCommand command, + DbContext? context, + Guid commandId, + Guid connectionId, + DateTimeOffset startTime, + CancellationToken cancellationToken = default) + { + _suppressCommandExecuteExpiration = startTime + _loggingConfigCacheTime; + + var definition = RelationalResources.LogExecutingCommand(this); + + if (ShouldLog(definition)) + { + _suppressCommandExecuteExpiration = default; + + definition.Log( + this, + command.Parameters.FormatParameters(ShouldLogParameterValues(command)), + command.CommandType, + command.CommandTimeout, + Environment.NewLine, + command.CommandText.TrimEnd()); + } + + if (NeedsEventData( + definition, out var interceptor, out var diagnosticSourceEnabled, out var simpleLogEnabled)) + { + _suppressCommandExecuteExpiration = default; + + var eventData = BroadcastCommandExecuting( + connection.DbConnection, + command, + context, + DbCommandMethod.ExecuteScalar, + commandId, + connectionId, + async: true, + startTime, + definition, + diagnosticSourceEnabled, + simpleLogEnabled); + + if (interceptor != null) + { + return interceptor.ScalarExecutingAsync(command, eventData, default, cancellationToken); + } + } + + return default; + } + + /// + /// This is an internal API that supports the Entity Framework Core infrastructure and not subject to + /// the same compatibility standards as public APIs. It may be changed or removed without notice in + /// any release. You should only use it directly in your code with extreme caution and knowing that + /// doing so can result in application failures when updating to a new Entity Framework Core release. + /// + public virtual ValueTask> CommandNonQueryExecutingAsync( + IRelationalConnection connection, + DbCommand command, + DbContext? context, + Guid commandId, + Guid connectionId, + DateTimeOffset startTime, + CancellationToken cancellationToken = default) + { + _suppressCommandExecuteExpiration = startTime + _loggingConfigCacheTime; + + var definition = RelationalResources.LogExecutingCommand(this); + + if (ShouldLog(definition)) + { + _suppressCommandExecuteExpiration = default; + + definition.Log( + this, + command.Parameters.FormatParameters(ShouldLogParameterValues(command)), + command.CommandType, + command.CommandTimeout, + Environment.NewLine, + command.CommandText.TrimEnd()); + } + + if (NeedsEventData( + definition, out var interceptor, out var diagnosticSourceEnabled, out var simpleLogEnabled)) + { + _suppressCommandExecuteExpiration = default; + + var eventData = BroadcastCommandExecuting( + connection.DbConnection, + command, + context, + DbCommandMethod.ExecuteNonQuery, + commandId, + connectionId, + async: true, + startTime, + definition, + diagnosticSourceEnabled, + simpleLogEnabled); + + if (interceptor != null) + { + return interceptor.NonQueryExecutingAsync(command, eventData, default, cancellationToken); + } + } + + return default; + } + + private CommandEventData BroadcastCommandExecuting( + DbConnection connection, + DbCommand command, + DbContext? context, + DbCommandMethod executeMethod, + Guid commandId, + Guid connectionId, + bool async, + DateTimeOffset startTime, + EventDefinition definition, + bool diagnosticSourceEnabled, + bool simpleLogEnabled) + { + var eventData = new CommandEventData( + definition, + CommandExecuting, + connection, + command, + context, + executeMethod, + commandId, + connectionId, + async, + ShouldLogParameterValues(command), + startTime); + + DispatchEventData(definition, eventData, diagnosticSourceEnabled, simpleLogEnabled); + + return eventData; + + static string CommandExecuting(EventDefinitionBase definition, EventData payload) + { + var d = (EventDefinition)definition; + var p = (CommandEventData)payload; + return d.GenerateMessage( + p.Command.Parameters.FormatParameters(p.LogParameterValues), + p.Command.CommandType, + p.Command.CommandTimeout, + Environment.NewLine, + p.Command.CommandText.TrimEnd()); + } + } + + #endregion CommandExecuting + + #region CommandExecuted + + /// + /// This is an internal API that supports the Entity Framework Core infrastructure and not subject to + /// the same compatibility standards as public APIs. It may be changed or removed without notice in + /// any release. You should only use it directly in your code with extreme caution and knowing that + /// doing so can result in application failures when updating to a new Entity Framework Core release. + /// + public virtual DbDataReader CommandReaderExecuted( + IRelationalConnection connection, + DbCommand command, + DbContext? context, + Guid commandId, + Guid connectionId, + DbDataReader methodResult, + DateTimeOffset startTime, + TimeSpan duration) + { + var definition = RelationalResources.LogExecutedCommand(this); + + if (ShouldLog(definition)) + { + _suppressCommandExecuteExpiration = default; + + definition.Log( + this, + string.Format(CultureInfo.InvariantCulture, "{0:N0}", duration.TotalMilliseconds), + command.Parameters.FormatParameters(ShouldLogParameterValues(command)), + command.CommandType, + command.CommandTimeout, + Environment.NewLine, + command.CommandText.TrimEnd()); + } + + if (NeedsEventData( + definition, out var interceptor, out var diagnosticSourceEnabled, out var simpleLogEnabled)) + { + _suppressCommandExecuteExpiration = default; + + var eventData = BroadcastCommandExecuted( + connection.DbConnection, + command, + context, + DbCommandMethod.ExecuteReader, + commandId, + connectionId, + methodResult, + async: false, + startTime, + duration, + definition, + diagnosticSourceEnabled, + simpleLogEnabled); + + if (interceptor != null) + { + return interceptor.ReaderExecuted(command, eventData, methodResult); + } + } + + return methodResult; + } + + /// + /// This is an internal API that supports the Entity Framework Core infrastructure and not subject to + /// the same compatibility standards as public APIs. It may be changed or removed without notice in + /// any release. You should only use it directly in your code with extreme caution and knowing that + /// doing so can result in application failures when updating to a new Entity Framework Core release. + /// + public virtual object? CommandScalarExecuted( + IRelationalConnection connection, + DbCommand command, + DbContext? context, + Guid commandId, + Guid connectionId, + object? methodResult, + DateTimeOffset startTime, + TimeSpan duration) + { + var definition = RelationalResources.LogExecutedCommand(this); + + if (ShouldLog(definition)) + { + _suppressCommandExecuteExpiration = default; + + definition.Log( + this, + string.Format(CultureInfo.InvariantCulture, "{0:N0}", duration.TotalMilliseconds), + command.Parameters.FormatParameters(ShouldLogParameterValues(command)), + command.CommandType, + command.CommandTimeout, + Environment.NewLine, + command.CommandText.TrimEnd()); + } + + if (NeedsEventData( + definition, out var interceptor, out var diagnosticSourceEnabled, out var simpleLogEnabled)) + { + _suppressCommandExecuteExpiration = default; + + var eventData = BroadcastCommandExecuted( + connection.DbConnection, + command, + context, + DbCommandMethod.ExecuteScalar, + commandId, + connectionId, + methodResult, + async: false, + startTime, + duration, + definition, + diagnosticSourceEnabled, + simpleLogEnabled); + + if (interceptor != null) + { + return interceptor.ScalarExecuted(command, eventData, methodResult); + } + } + + return methodResult; + } + + /// + /// This is an internal API that supports the Entity Framework Core infrastructure and not subject to + /// the same compatibility standards as public APIs. It may be changed or removed without notice in + /// any release. You should only use it directly in your code with extreme caution and knowing that + /// doing so can result in application failures when updating to a new Entity Framework Core release. + /// + public virtual int CommandNonQueryExecuted( + IRelationalConnection connection, + DbCommand command, + DbContext? context, + Guid commandId, + Guid connectionId, + int methodResult, + DateTimeOffset startTime, + TimeSpan duration) + { + var definition = RelationalResources.LogExecutedCommand(this); + + if (ShouldLog(definition)) + { + _suppressCommandExecuteExpiration = default; + + definition.Log( + this, + string.Format(CultureInfo.InvariantCulture, "{0:N0}", duration.TotalMilliseconds), + command.Parameters.FormatParameters(ShouldLogParameterValues(command)), + command.CommandType, + command.CommandTimeout, + Environment.NewLine, + command.CommandText.TrimEnd()); + } + + if (NeedsEventData( + definition, out var interceptor, out var diagnosticSourceEnabled, out var simpleLogEnabled)) + { + _suppressCommandExecuteExpiration = default; + + var eventData = BroadcastCommandExecuted( + connection.DbConnection, + command, + context, + DbCommandMethod.ExecuteNonQuery, + commandId, + connectionId, + methodResult, + async: false, + startTime, + duration, + definition, + diagnosticSourceEnabled, + simpleLogEnabled); + + if (interceptor != null) + { + return interceptor.NonQueryExecuted(command, eventData, methodResult); + } + } + + return methodResult; + } + + /// + /// This is an internal API that supports the Entity Framework Core infrastructure and not subject to + /// the same compatibility standards as public APIs. It may be changed or removed without notice in + /// any release. You should only use it directly in your code with extreme caution and knowing that + /// doing so can result in application failures when updating to a new Entity Framework Core release. + /// + public virtual ValueTask CommandReaderExecutedAsync( + IRelationalConnection connection, + DbCommand command, + DbContext? context, + Guid commandId, + Guid connectionId, + DbDataReader methodResult, + DateTimeOffset startTime, + TimeSpan duration, + CancellationToken cancellationToken = default) + { + var definition = RelationalResources.LogExecutedCommand(this); + + if (ShouldLog(definition)) + { + _suppressCommandExecuteExpiration = default; + + definition.Log( + this, + string.Format(CultureInfo.InvariantCulture, "{0:N0}", duration.TotalMilliseconds), + command.Parameters.FormatParameters(ShouldLogParameterValues(command)), + command.CommandType, + command.CommandTimeout, + Environment.NewLine, + command.CommandText.TrimEnd()); + } + + if (NeedsEventData( + definition, out var interceptor, out var diagnosticSourceEnabled, out var simpleLogEnabled)) + { + _suppressCommandExecuteExpiration = default; + + var eventData = BroadcastCommandExecuted( + connection.DbConnection, + command, + context, + DbCommandMethod.ExecuteReader, + commandId, + connectionId, + methodResult, + async: true, + startTime, + duration, + definition, + diagnosticSourceEnabled, + simpleLogEnabled); + + if (interceptor != null) + { + return interceptor.ReaderExecutedAsync(command, eventData, methodResult, cancellationToken); + } + } + + return new ValueTask(methodResult); + } + + /// + /// This is an internal API that supports the Entity Framework Core infrastructure and not subject to + /// the same compatibility standards as public APIs. It may be changed or removed without notice in + /// any release. You should only use it directly in your code with extreme caution and knowing that + /// doing so can result in application failures when updating to a new Entity Framework Core release. + /// + public virtual ValueTask CommandScalarExecutedAsync( + IRelationalConnection connection, + DbCommand command, + DbContext? context, + Guid commandId, + Guid connectionId, + object? methodResult, + DateTimeOffset startTime, + TimeSpan duration, + CancellationToken cancellationToken = default) + { + var definition = RelationalResources.LogExecutedCommand(this); + + if (ShouldLog(definition)) + { + _suppressCommandExecuteExpiration = default; + + definition.Log( + this, + string.Format(CultureInfo.InvariantCulture, "{0:N0}", duration.TotalMilliseconds), + command.Parameters.FormatParameters(ShouldLogParameterValues(command)), + command.CommandType, + command.CommandTimeout, + Environment.NewLine, + command.CommandText.TrimEnd()); + } + + if (NeedsEventData( + definition, out var interceptor, out var diagnosticSourceEnabled, out var simpleLogEnabled)) + { + _suppressCommandExecuteExpiration = default; + + var eventData = BroadcastCommandExecuted( + connection.DbConnection, + command, + context, + DbCommandMethod.ExecuteScalar, + commandId, + connectionId, + methodResult, + async: true, + startTime, + duration, + definition, + diagnosticSourceEnabled, + simpleLogEnabled); + + if (interceptor != null) + { + return interceptor.ScalarExecutedAsync(command, eventData, methodResult, cancellationToken); + } + } + + return new ValueTask(methodResult); + } + + /// + /// This is an internal API that supports the Entity Framework Core infrastructure and not subject to + /// the same compatibility standards as public APIs. It may be changed or removed without notice in + /// any release. You should only use it directly in your code with extreme caution and knowing that + /// doing so can result in application failures when updating to a new Entity Framework Core release. + /// + public virtual ValueTask CommandNonQueryExecutedAsync( + IRelationalConnection connection, + DbCommand command, + DbContext? context, + Guid commandId, + Guid connectionId, + int methodResult, + DateTimeOffset startTime, + TimeSpan duration, + CancellationToken cancellationToken = default) + { + var definition = RelationalResources.LogExecutedCommand(this); + + if (ShouldLog(definition)) + { + _suppressCommandExecuteExpiration = default; + + definition.Log( + this, + string.Format(CultureInfo.InvariantCulture, "{0:N0}", duration.TotalMilliseconds), + command.Parameters.FormatParameters(ShouldLogParameterValues(command)), + command.CommandType, + command.CommandTimeout, + Environment.NewLine, + command.CommandText.TrimEnd()); + } + + if (NeedsEventData( + definition, out var interceptor, out var diagnosticSourceEnabled, out var simpleLogEnabled)) + { + _suppressCommandExecuteExpiration = default; + + var eventData = BroadcastCommandExecuted( + connection.DbConnection, + command, + context, + DbCommandMethod.ExecuteNonQuery, + commandId, + connectionId, + methodResult, + async: true, + startTime, + duration, + definition, + diagnosticSourceEnabled, + simpleLogEnabled); + + if (interceptor != null) + { + return interceptor.NonQueryExecutedAsync(command, eventData, methodResult, cancellationToken); + } + } + + return new ValueTask(methodResult); + } + + private CommandExecutedEventData BroadcastCommandExecuted( + DbConnection connection, + DbCommand command, + DbContext? context, + DbCommandMethod executeMethod, + Guid commandId, + Guid connectionId, + object? methodResult, + bool async, + DateTimeOffset startTime, + TimeSpan duration, + EventDefinition definition, + bool diagnosticSourceEnabled, + bool simpleLogEnabled) + { + var eventData = new CommandExecutedEventData( + definition, + CommandExecuted, + connection, + command, + context, + executeMethod, + commandId, + connectionId, + methodResult, + async, + ShouldLogParameterValues(command), + startTime, + duration); + + DispatchEventData(definition, eventData, diagnosticSourceEnabled, simpleLogEnabled); + + return eventData; + + static string CommandExecuted(EventDefinitionBase definition, EventData payload) + { + var d = (EventDefinition)definition; + var p = (CommandExecutedEventData)payload; + return d.GenerateMessage( + string.Format(CultureInfo.InvariantCulture, "{0:N0}", p.Duration.TotalMilliseconds), + p.Command.Parameters.FormatParameters(p.LogParameterValues), + p.Command.CommandType, + p.Command.CommandTimeout, + Environment.NewLine, + p.Command.CommandText.TrimEnd()); + } + } + + #endregion CommandExecuted + + #region CommandError + + /// + /// This is an internal API that supports the Entity Framework Core infrastructure and not subject to + /// the same compatibility standards as public APIs. It may be changed or removed without notice in + /// any release. You should only use it directly in your code with extreme caution and knowing that + /// doing so can result in application failures when updating to a new Entity Framework Core release. + /// + public virtual void CommandError( + IRelationalConnection connection, + DbCommand command, + DbContext? context, + DbCommandMethod executeMethod, + Guid commandId, + Guid connectionId, + Exception exception, + DateTimeOffset startTime, + TimeSpan duration) + { + var definition = RelationalResources.LogCommandFailed(this); + + LogCommandError(command, duration, definition); + + if (NeedsEventData( + definition, out var interceptor, out var diagnosticSourceEnabled, out var simpleLogEnabled)) + { + var eventData = BroadcastCommandError( + connection.DbConnection, + command, + context, + executeMethod, + commandId, + connectionId, + exception, + false, + startTime, + duration, + definition, + diagnosticSourceEnabled, + simpleLogEnabled); + + interceptor?.CommandFailed(command, eventData); + } + } + + private void LogCommandError( + DbCommand command, + TimeSpan duration, + EventDefinition definition) + { + if (ShouldLog(definition)) + { + definition.Log( + this, + string.Format(CultureInfo.InvariantCulture, "{0:N0}", duration.TotalMilliseconds), + command.Parameters.FormatParameters(ShouldLogParameterValues(command)), + command.CommandType, + command.CommandTimeout, + Environment.NewLine, + command.CommandText.TrimEnd()); + } + } + + /// + /// This is an internal API that supports the Entity Framework Core infrastructure and not subject to + /// the same compatibility standards as public APIs. It may be changed or removed without notice in + /// any release. You should only use it directly in your code with extreme caution and knowing that + /// doing so can result in application failures when updating to a new Entity Framework Core release. + /// + public virtual Task CommandErrorAsync( + IRelationalConnection connection, + DbCommand command, + DbContext? context, + DbCommandMethod executeMethod, + Guid commandId, + Guid connectionId, + Exception exception, + DateTimeOffset startTime, + TimeSpan duration, + CancellationToken cancellationToken = default) + { + var definition = RelationalResources.LogCommandFailed(this); + + LogCommandError(command, duration, definition); + + if (NeedsEventData( + definition, out var interceptor, out var diagnosticSourceEnabled, out var simpleLogEnabled)) + { + var eventData = BroadcastCommandError( + connection.DbConnection, + command, + context, + executeMethod, + commandId, + connectionId, + exception, + true, + startTime, + duration, + definition, + diagnosticSourceEnabled, + simpleLogEnabled); + + if (interceptor != null) + { + return interceptor.CommandFailedAsync(command, eventData, cancellationToken); + } + } + + return Task.CompletedTask; + } + + private CommandErrorEventData BroadcastCommandError( + DbConnection connection, + DbCommand command, + DbContext? context, + DbCommandMethod executeMethod, + Guid commandId, + Guid connectionId, + Exception exception, + bool async, + DateTimeOffset startTime, + TimeSpan duration, + EventDefinition definition, + bool diagnosticSourceEnabled, + bool simpleLogEnabled) + { + var eventData = new CommandErrorEventData( + definition, + CommandError, + connection, + command, + context, + executeMethod, + commandId, + connectionId, + exception, + async, + ShouldLogParameterValues(command), + startTime, + duration); + + DispatchEventData(definition, eventData, diagnosticSourceEnabled, simpleLogEnabled); + + return eventData; + + static string CommandError(EventDefinitionBase definition, EventData payload) + { + var d = (EventDefinition)definition; + var p = (CommandErrorEventData)payload; + return d.GenerateMessage( + string.Format(CultureInfo.InvariantCulture, "{0:N0}", p.Duration.TotalMilliseconds), + p.Command.Parameters.FormatParameters(p.LogParameterValues), + p.Command.CommandType, + p.Command.CommandTimeout, + Environment.NewLine, + p.Command.CommandText.TrimEnd()); + } + } + + #endregion CommandError + + #region DataReaderDisposing + + /// + /// This is an internal API that supports the Entity Framework Core infrastructure and not subject to + /// the same compatibility standards as public APIs. It may be changed or removed without notice in + /// any release. You should only use it directly in your code with extreme caution and knowing that + /// doing so can result in application failures when updating to a new Entity Framework Core release. + /// + public virtual InterceptionResult DataReaderDisposing( + IRelationalConnection connection, + DbCommand command, + DbDataReader dataReader, + Guid commandId, + int recordsAffected, + int readCount, + DateTimeOffset startTime, + TimeSpan duration) + { + _suppressDataReaderDisposingExpiration = startTime + _loggingConfigCacheTime; + + var definition = RelationalResources.LogDisposingDataReader(this); + + if (ShouldLog(definition)) + { + _suppressDataReaderDisposingExpiration = default; + + definition.Log(this); + } + + if (NeedsEventData( + definition, out var interceptor, out var diagnosticSourceEnabled, out var simpleLogEnabled)) + { + _suppressDataReaderDisposingExpiration = default; + + var eventData = new DataReaderDisposingEventData( + definition, + (d, p) => ((EventDefinition)d).GenerateMessage(), + command, + dataReader, + connection.Context, + commandId, + connection.ConnectionId, + recordsAffected, + readCount, + startTime, + duration); + + DispatchEventData(definition, eventData, diagnosticSourceEnabled, simpleLogEnabled); + + if (interceptor != null) + { + return interceptor.DataReaderDisposing(command, eventData, default); + } + } + + return default; + } + + #endregion DataReaderDisposing + + #region ShouldLog checks + + /// + /// This is an internal API that supports the Entity Framework Core infrastructure and not subject to + /// the same compatibility standards as public APIs. It may be changed or removed without notice in + /// any release. You should only use it directly in your code with extreme caution and knowing that + /// doing so can result in application failures when updating to a new Entity Framework Core release. + /// + public virtual bool ShouldLogCommandCreate(DateTimeOffset now) + => now > _suppressCommandCreateExpiration; + + /// + /// This is an internal API that supports the Entity Framework Core infrastructure and not subject to + /// the same compatibility standards as public APIs. It may be changed or removed without notice in + /// any release. You should only use it directly in your code with extreme caution and knowing that + /// doing so can result in application failures when updating to a new Entity Framework Core release. + /// + public virtual bool ShouldLogCommandExecute(DateTimeOffset now) + => now > _suppressCommandExecuteExpiration; + + /// + /// This is an internal API that supports the Entity Framework Core infrastructure and not subject to + /// the same compatibility standards as public APIs. It may be changed or removed without notice in + /// any release. You should only use it directly in your code with extreme caution and knowing that + /// doing so can result in application failures when updating to a new Entity Framework Core release. + /// + public virtual bool ShouldLogDataReaderDispose(DateTimeOffset now) + => now > _suppressDataReaderDisposingExpiration; + + private bool ShouldLogParameterValues(DbCommand command) + => command.Parameters.Count > 0 && ShouldLogSensitiveData(); + + #endregion ShouldLog checks + } +} diff --git a/src/EFCore.Relational/Diagnostics/Internal/RelationalConnectionDiagnosticsLogger.cs b/src/EFCore.Relational/Diagnostics/Internal/RelationalConnectionDiagnosticsLogger.cs new file mode 100644 index 00000000000..fc95cc34c14 --- /dev/null +++ b/src/EFCore.Relational/Diagnostics/Internal/RelationalConnectionDiagnosticsLogger.cs @@ -0,0 +1,679 @@ +// Copyright (c) .NET Foundation. All rights reserved. +// Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information. + +using System; +using System.Diagnostics; +using System.Threading; +using System.Threading.Tasks; +using Microsoft.EntityFrameworkCore.Infrastructure; +using Microsoft.EntityFrameworkCore.Storage; +using Microsoft.Extensions.Logging; + +#pragma warning disable EF1001 + +namespace Microsoft.EntityFrameworkCore.Diagnostics.Internal +{ + /// + /// This is an internal API that supports the Entity Framework Core infrastructure and not subject to + /// the same compatibility standards as public APIs. It may be changed or removed without notice in + /// any release. You should only use it directly in your code with extreme caution and knowing that + /// doing so can result in application failures when updating to a new Entity Framework Core release. + /// + public class RelationalConnectionDiagnosticsLogger + : DiagnosticsLogger, IRelationalConnectionDiagnosticsLogger + { + private DateTimeOffset _suppressOpenExpiration; + private DateTimeOffset _suppressCloseExpiration; + + private readonly TimeSpan _loggingConfigCacheTime; + + /// + /// This is an internal API that supports the Entity Framework Core infrastructure and not subject to + /// the same compatibility standards as public APIs. It may be changed or removed without notice in + /// any release. You should only use it directly in your code with extreme caution and knowing that + /// doing so can result in application failures when updating to a new Entity Framework Core release. + /// + public RelationalConnectionDiagnosticsLogger( + ILoggerFactory loggerFactory, + ILoggingOptions loggingOptions, + DiagnosticSource diagnosticSource, + LoggingDefinitions loggingDefinitions, + IDbContextLogger contextLogger, + IDbContextOptions contextOptions, + IInterceptors? interceptors = null) + : base(loggerFactory, loggingOptions, diagnosticSource, loggingDefinitions, contextLogger, interceptors) + { + _loggingConfigCacheTime = contextOptions.FindExtension()?.LoggingConfigCacheTime ?? + CoreOptionsExtension.DefaultLoggingConfigCacheTime; + } + + #region ConnectionOpening + + /// + /// This is an internal API that supports the Entity Framework Core infrastructure and not subject to + /// the same compatibility standards as public APIs. It may be changed or removed without notice in + /// any release. You should only use it directly in your code with extreme caution and knowing that + /// doing so can result in application failures when updating to a new Entity Framework Core release. + /// + public virtual InterceptionResult ConnectionOpening( + IRelationalConnection connection, + DateTimeOffset startTime) + { + _suppressOpenExpiration = startTime + _loggingConfigCacheTime; + + var definition = RelationalResources.LogOpeningConnection(this); + + if (ShouldLog(definition)) + { + _suppressOpenExpiration = default; + + definition.Log(this, connection.DbConnection.Database, connection.DbConnection.DataSource); + } + + if (NeedsEventData( + definition, out var interceptor, out var diagnosticSourceEnabled, out var simpleLogEnabled)) + { + _suppressOpenExpiration = default; + + var eventData = BroadcastConnectionOpening( + connection, + startTime, + definition, + async: false, + diagnosticSourceEnabled, + simpleLogEnabled); + + if (interceptor != null) + { + return interceptor.ConnectionOpening(connection.DbConnection, eventData, default); + } + } + + return default; + } + + /// + /// This is an internal API that supports the Entity Framework Core infrastructure and not subject to + /// the same compatibility standards as public APIs. It may be changed or removed without notice in + /// any release. You should only use it directly in your code with extreme caution and knowing that + /// doing so can result in application failures when updating to a new Entity Framework Core release. + /// + public virtual ValueTask ConnectionOpeningAsync( + IRelationalConnection connection, + DateTimeOffset startTime, + CancellationToken cancellationToken) + { + _suppressOpenExpiration = startTime + _loggingConfigCacheTime; + + var definition = RelationalResources.LogOpeningConnection(this); + + if (ShouldLog(definition)) + { + _suppressOpenExpiration = default; + + definition.Log(this, connection.DbConnection.Database, connection.DbConnection.DataSource); + } + + if (NeedsEventData( + definition, out var interceptor, out var diagnosticSourceEnabled, out var simpleLogEnabled)) + { + _suppressOpenExpiration = default; + + var eventData = BroadcastConnectionOpening( + connection, + startTime, + definition, + async: true, + diagnosticSourceEnabled, + simpleLogEnabled); + + if (interceptor != null) + { + return interceptor.ConnectionOpeningAsync(connection.DbConnection, eventData, default, cancellationToken); + } + } + + return default; + } + + private ConnectionEventData BroadcastConnectionOpening( + IRelationalConnection connection, + DateTimeOffset startTime, + EventDefinition definition, + bool async, + bool diagnosticSourceEnabled, + bool simpleLogEnabled) + { + var eventData = new ConnectionEventData( + definition, + ConnectionOpening, + connection.DbConnection, + connection.Context, + connection.ConnectionId, + async, + startTime); + + DispatchEventData(definition, eventData, diagnosticSourceEnabled, simpleLogEnabled); + + return eventData; + + static string ConnectionOpening(EventDefinitionBase definition, EventData payload) + { + var d = (EventDefinition)definition; + var p = (ConnectionEventData)payload; + return d.GenerateMessage( + p.Connection.Database, + p.Connection.DataSource); + } + } + + #endregion ConnectionOpening + + #region ConnectionOpened + + /// + /// This is an internal API that supports the Entity Framework Core infrastructure and not subject to + /// the same compatibility standards as public APIs. It may be changed or removed without notice in + /// any release. You should only use it directly in your code with extreme caution and knowing that + /// doing so can result in application failures when updating to a new Entity Framework Core release. + /// + public virtual void ConnectionOpened( + IRelationalConnection connection, + DateTimeOffset startTime, + TimeSpan duration) + { + var definition = RelationalResources.LogOpenedConnection(this); + + if (ShouldLog(definition)) + { + _suppressOpenExpiration = default; + + definition.Log(this, connection.DbConnection.Database, connection.DbConnection.DataSource); + } + + if (NeedsEventData( + definition, out var interceptor, out var diagnosticSourceEnabled, out var simpleLogEnabled)) + { + _suppressOpenExpiration = default; + + var eventData = BroadcastConnectionOpened( + connection, + async: false, + startTime, + duration, + definition, + diagnosticSourceEnabled, + simpleLogEnabled); + + interceptor?.ConnectionOpened(connection.DbConnection, eventData); + } + } + + /// + /// This is an internal API that supports the Entity Framework Core infrastructure and not subject to + /// the same compatibility standards as public APIs. It may be changed or removed without notice in + /// any release. You should only use it directly in your code with extreme caution and knowing that + /// doing so can result in application failures when updating to a new Entity Framework Core release. + /// + public virtual Task ConnectionOpenedAsync( + IRelationalConnection connection, + DateTimeOffset startTime, + TimeSpan duration, + CancellationToken cancellationToken = default) + { + var definition = RelationalResources.LogOpenedConnection(this); + + if (ShouldLog(definition)) + { + _suppressOpenExpiration = default; + + definition.Log(this, connection.DbConnection.Database, connection.DbConnection.DataSource); + } + + if (NeedsEventData( + definition, out var interceptor, out var diagnosticSourceEnabled, out var simpleLogEnabled)) + { + _suppressOpenExpiration = default; + + var eventData = BroadcastConnectionOpened( + connection, + async: true, + startTime, + duration, + definition, + diagnosticSourceEnabled, + simpleLogEnabled); + + if (interceptor != null) + { + return interceptor.ConnectionOpenedAsync(connection.DbConnection, eventData, cancellationToken); + } + } + + return Task.CompletedTask; + } + + private ConnectionEndEventData BroadcastConnectionOpened( + IRelationalConnection connection, + bool async, + DateTimeOffset startTime, + TimeSpan duration, + EventDefinition definition, + bool diagnosticSourceEnabled, + bool simpleLogEnabled) + { + var eventData = new ConnectionEndEventData( + definition, + ConnectionOpened, + connection.DbConnection, + connection.Context, + connection.ConnectionId, + async, + startTime, + duration); + + DispatchEventData(definition, eventData, diagnosticSourceEnabled, simpleLogEnabled); + + return eventData; + + static string ConnectionOpened(EventDefinitionBase definition, EventData payload) + { + var d = (EventDefinition)definition; + var p = (ConnectionEndEventData)payload; + return d.GenerateMessage( + p.Connection.Database, + p.Connection.DataSource); + } + } + + #endregion ConnectionOpened + + #region ConnectionClosing + + /// + /// This is an internal API that supports the Entity Framework Core infrastructure and not subject to + /// the same compatibility standards as public APIs. It may be changed or removed without notice in + /// any release. You should only use it directly in your code with extreme caution and knowing that + /// doing so can result in application failures when updating to a new Entity Framework Core release. + /// + public virtual InterceptionResult ConnectionClosing( + IRelationalConnection connection, + DateTimeOffset startTime) + { + _suppressCloseExpiration = startTime + _loggingConfigCacheTime; + + var definition = RelationalResources.LogClosingConnection(this); + + if (ShouldLog(definition)) + { + _suppressCloseExpiration = default; + + definition.Log(this, connection.DbConnection.Database, connection.DbConnection.DataSource); + } + + if (NeedsEventData( + definition, out var interceptor, out var diagnosticSourceEnabled, out var simpleLogEnabled)) + { + _suppressCloseExpiration = default; + + var eventData = BroadcastConnectionClosing( + connection, + startTime, + async: false, + definition, + diagnosticSourceEnabled, + simpleLogEnabled); + + if (interceptor != null) + { + return interceptor.ConnectionClosing(connection.DbConnection, eventData, default); + } + } + + return default; + } + + /// + /// This is an internal API that supports the Entity Framework Core infrastructure and not subject to + /// the same compatibility standards as public APIs. It may be changed or removed without notice in + /// any release. You should only use it directly in your code with extreme caution and knowing that + /// doing so can result in application failures when updating to a new Entity Framework Core release. + /// + public virtual ValueTask ConnectionClosingAsync( + IRelationalConnection connection, + DateTimeOffset startTime) + { + _suppressCloseExpiration = startTime + _loggingConfigCacheTime; + + var definition = RelationalResources.LogClosingConnection(this); + + if (ShouldLog(definition)) + { + _suppressCloseExpiration = default; + + definition.Log(this, connection.DbConnection.Database, connection.DbConnection.DataSource); + } + + if (NeedsEventData( + definition, out var interceptor, out var diagnosticSourceEnabled, out var simpleLogEnabled)) + { + _suppressCloseExpiration = default; + + var eventData = BroadcastConnectionClosing( + connection, + startTime, + async: true, + definition, + diagnosticSourceEnabled, + simpleLogEnabled); + + if (interceptor != null) + { + return interceptor.ConnectionClosingAsync(connection.DbConnection, eventData, default); + } + } + + return default; + } + + private ConnectionEventData BroadcastConnectionClosing( + IRelationalConnection connection, + DateTimeOffset startTime, + bool async, + EventDefinition definition, + bool diagnosticSourceEnabled, + bool simpleLogEnabled) + { + var eventData = new ConnectionEventData( + definition, + ConnectionClosing, + connection.DbConnection, + connection.Context, + connection.ConnectionId, + async, + startTime); + + DispatchEventData(definition, eventData, diagnosticSourceEnabled, simpleLogEnabled); + + return eventData; + + static string ConnectionClosing(EventDefinitionBase definition, EventData payload) + { + var d = (EventDefinition)definition; + var p = (ConnectionEventData)payload; + return d.GenerateMessage( + p.Connection.Database, + p.Connection.DataSource); + } + } + + #endregion ConnectionClosing + + #region ConnectionClosed + + /// + /// This is an internal API that supports the Entity Framework Core infrastructure and not subject to + /// the same compatibility standards as public APIs. It may be changed or removed without notice in + /// any release. You should only use it directly in your code with extreme caution and knowing that + /// doing so can result in application failures when updating to a new Entity Framework Core release. + /// + public virtual void ConnectionClosed( + IRelationalConnection connection, + DateTimeOffset startTime, + TimeSpan duration) + { + var definition = RelationalResources.LogClosedConnection(this); + + if (ShouldLog(definition)) + { + _suppressCloseExpiration = default; + + definition.Log(this, connection.DbConnection.Database, connection.DbConnection.DataSource); + } + + if (NeedsEventData( + definition, out var interceptor, out var diagnosticSourceEnabled, out var simpleLogEnabled)) + { + _suppressCloseExpiration = default; + + var eventData = BroadcastCollectionClosed( + connection, + startTime, + duration, + false, + definition, + diagnosticSourceEnabled, + simpleLogEnabled); + + interceptor?.ConnectionClosed(connection.DbConnection, eventData); + } + } + + /// + /// This is an internal API that supports the Entity Framework Core infrastructure and not subject to + /// the same compatibility standards as public APIs. It may be changed or removed without notice in + /// any release. You should only use it directly in your code with extreme caution and knowing that + /// doing so can result in application failures when updating to a new Entity Framework Core release. + /// + public virtual Task ConnectionClosedAsync( + IRelationalConnection connection, + DateTimeOffset startTime, + TimeSpan duration) + { + var definition = RelationalResources.LogClosedConnection(this); + + if (ShouldLog(definition)) + { + _suppressCloseExpiration = default; + + definition.Log(this, connection.DbConnection.Database, connection.DbConnection.DataSource); + } + + if (NeedsEventData( + definition, out var interceptor, out var diagnosticSourceEnabled, out var simpleLogEnabled)) + { + _suppressCloseExpiration = default; + + var eventData = BroadcastCollectionClosed( + connection, + startTime, + duration, + async: true, + definition, + diagnosticSourceEnabled, + simpleLogEnabled); + + if (interceptor != null) + { + return interceptor.ConnectionClosedAsync(connection.DbConnection, eventData); + } + } + + return Task.CompletedTask; + } + + private ConnectionEndEventData BroadcastCollectionClosed( + IRelationalConnection connection, + DateTimeOffset startTime, + TimeSpan duration, + bool async, + EventDefinition definition, + bool diagnosticSourceEnabled, + bool simpleLogEnabled) + { + var eventData = new ConnectionEndEventData( + definition, + ConnectionClosed, + connection.DbConnection, + connection.Context, + connection.ConnectionId, + async, + startTime, + duration); + + DispatchEventData(definition, eventData, diagnosticSourceEnabled, simpleLogEnabled); + + return eventData; + + static string ConnectionClosed(EventDefinitionBase definition, EventData payload) + { + var d = (EventDefinition)definition; + var p = (ConnectionEndEventData)payload; + return d.GenerateMessage( + p.Connection.Database, + p.Connection.DataSource); + } + } + + #endregion ConnectionClosed + + #region ConnectionError + + /// + /// This is an internal API that supports the Entity Framework Core infrastructure and not subject to + /// the same compatibility standards as public APIs. It may be changed or removed without notice in + /// any release. You should only use it directly in your code with extreme caution and knowing that + /// doing so can result in application failures when updating to a new Entity Framework Core release. + /// + public virtual void ConnectionError( + IRelationalConnection connection, + Exception exception, + DateTimeOffset startTime, + TimeSpan duration, + bool logErrorAsDebug) + { + var definition = logErrorAsDebug + ? RelationalResources.LogConnectionErrorAsDebug(this) + : RelationalResources.LogConnectionError(this); + + LogConnectionError(connection, definition); + + if (NeedsEventData( + definition, out var interceptor, out var diagnosticSourceEnabled, out var simpleLogEnabled)) + { + var eventData = BroadcastConnectionError( + connection, + exception, + startTime, + duration, + false, + definition, + diagnosticSourceEnabled, + simpleLogEnabled); + + interceptor?.ConnectionFailed(connection.DbConnection, eventData); + } + } + + /// + /// This is an internal API that supports the Entity Framework Core infrastructure and not subject to + /// the same compatibility standards as public APIs. It may be changed or removed without notice in + /// any release. You should only use it directly in your code with extreme caution and knowing that + /// doing so can result in application failures when updating to a new Entity Framework Core release. + /// + public virtual Task ConnectionErrorAsync( + IRelationalConnection connection, + Exception exception, + DateTimeOffset startTime, + TimeSpan duration, + bool logErrorAsDebug, + CancellationToken cancellationToken = default) + { + var definition = logErrorAsDebug + ? RelationalResources.LogConnectionErrorAsDebug(this) + : RelationalResources.LogConnectionError(this); + + LogConnectionError(connection, definition); + + if (NeedsEventData( + definition, out var interceptor, out var diagnosticSourceEnabled, out var simpleLogEnabled)) + { + var eventData = BroadcastConnectionError( + connection, + exception, + startTime, + duration, + true, + definition, + diagnosticSourceEnabled, + simpleLogEnabled); + + if (interceptor != null) + { + return interceptor.ConnectionFailedAsync(connection.DbConnection, eventData, cancellationToken); + } + } + + return Task.CompletedTask; + } + + private ConnectionErrorEventData BroadcastConnectionError( + IRelationalConnection connection, + Exception exception, + DateTimeOffset startTime, + TimeSpan duration, + bool async, + EventDefinition definition, + bool diagnosticSourceEnabled, + bool simpleLogEnabled) + { + var eventData = new ConnectionErrorEventData( + definition, + ConnectionError, + connection.DbConnection, + connection.Context, + connection.ConnectionId, + exception, + async, + startTime, + duration); + + DispatchEventData(definition, eventData, diagnosticSourceEnabled, simpleLogEnabled); + + return eventData; + + static string ConnectionError(EventDefinitionBase definition, EventData payload) + { + var d = (EventDefinition)definition; + var p = (ConnectionErrorEventData)payload; + return d.GenerateMessage( + p.Connection.Database, + p.Connection.DataSource); + } + } + + private void LogConnectionError( + IRelationalConnection connection, + EventDefinition definition) + { + if (ShouldLog(definition)) + { + definition.Log(this, connection.DbConnection.Database, connection.DbConnection.DataSource); + } + } + + #endregion ConnectionError + + #region ShouldLog checks + + /// + /// This is an internal API that supports the Entity Framework Core infrastructure and not subject to + /// the same compatibility standards as public APIs. It may be changed or removed without notice in + /// any release. You should only use it directly in your code with extreme caution and knowing that + /// doing so can result in application failures when updating to a new Entity Framework Core release. + /// + public virtual bool ShouldLogConnectionOpen(DateTimeOffset now) + => now > _suppressOpenExpiration; + + /// + /// This is an internal API that supports the Entity Framework Core infrastructure and not subject to + /// the same compatibility standards as public APIs. It may be changed or removed without notice in + /// any release. You should only use it directly in your code with extreme caution and knowing that + /// doing so can result in application failures when updating to a new Entity Framework Core release. + /// + public virtual bool ShouldLogConnectionClose(DateTimeOffset now) + => now > _suppressCloseExpiration; + + #endregion ShouldLog checks + } +} diff --git a/src/EFCore.Relational/Diagnostics/RelationalLoggerExtensions.cs b/src/EFCore.Relational/Diagnostics/RelationalLoggerExtensions.cs index 6d7d795432c..55146ed3e93 100644 --- a/src/EFCore.Relational/Diagnostics/RelationalLoggerExtensions.cs +++ b/src/EFCore.Relational/Diagnostics/RelationalLoggerExtensions.cs @@ -41,1806 +41,6 @@ namespace Microsoft.EntityFrameworkCore.Diagnostics /// public static class RelationalLoggerExtensions { - /// - /// Logs for the event. - /// - /// The diagnostics logger to use. - /// The connection. - /// The type of method that will be called on this command. - /// The currently being used, to null if not known. - /// The correlation ID associated with the given . - /// The correlation ID associated with the being used. - /// The time that execution began. - /// An intercepted result. - public static InterceptionResult CommandCreating( - this IDiagnosticsLogger diagnostics, - IRelationalConnection connection, - DbCommandMethod commandMethod, - DbContext? context, - Guid commandId, - Guid connectionId, - DateTimeOffset startTime) - { - var definition = RelationalResources.LogCommandCreating(diagnostics); - - LogCommandCreating(diagnostics, definition, commandMethod); - - if (diagnostics.NeedsEventData( - definition, out var interceptor, out var diagnosticSourceEnabled, out var simpleLogEnabled)) - { - var eventData = BroadcastCommandCreating( - diagnostics, - connection.DbConnection, - context, - commandMethod, - commandId, - connectionId, - false, - startTime, - definition, - diagnosticSourceEnabled, - simpleLogEnabled); - - if (interceptor != null) - { - return interceptor.CommandCreating(eventData, default); - } - } - - return default; - } - - private static CommandCorrelatedEventData BroadcastCommandCreating( - IDiagnosticsLogger diagnostics, - DbConnection connection, - DbContext? context, - DbCommandMethod executeMethod, - Guid commandId, - Guid connectionId, - bool async, - DateTimeOffset startTime, - EventDefinition definition, - bool diagnosticSourceEnabled, - bool simpleLogEnabled) - { - var eventData = new CommandCorrelatedEventData( - definition, - CommandCreating, - connection, - context, - executeMethod, - commandId, - connectionId, - async, - startTime); - - diagnostics.DispatchEventData(definition, eventData, diagnosticSourceEnabled, simpleLogEnabled); - - return eventData; - } - - private static void LogCommandCreating( - IDiagnosticsLogger diagnostics, - EventDefinition definition, - DbCommandMethod commandMethod) - { - if (diagnostics.ShouldLog(definition)) - { - definition.Log(diagnostics, commandMethod.ToString()); - } - } - - private static string CommandCreating(EventDefinitionBase definition, EventData payload) - { - var d = (EventDefinition)definition; - var p = (CommandCorrelatedEventData)payload; - return d.GenerateMessage(p.ExecuteMethod.ToString()); - } - - /// - /// Logs for the event. - /// - /// The diagnostics logger to use. - /// The connection. - /// The database command object. - /// The type of method that will be called on this command. - /// The currently being used, to null if not known. - /// The correlation ID associated with the given . - /// The correlation ID associated with the being used. - /// The time that execution began. - /// The duration of the command creation. - /// An intercepted result. - public static DbCommand CommandCreated( - this IDiagnosticsLogger diagnostics, - IRelationalConnection connection, - DbCommand command, - DbCommandMethod commandMethod, - DbContext? context, - Guid commandId, - Guid connectionId, - DateTimeOffset startTime, - TimeSpan duration) - { - var definition = RelationalResources.LogCommandCreated(diagnostics); - - LogCommandCreated(diagnostics, definition, commandMethod, duration); - - if (diagnostics.NeedsEventData( - definition, out var interceptor, out var diagnosticSourceEnabled, out var simpleLogEnabled)) - { - var eventData = BroadcastCommandCreated( - diagnostics, - connection.DbConnection, - command, - context, - commandMethod, - commandId, - connectionId, - false, - startTime, - duration, - definition, - diagnosticSourceEnabled, - simpleLogEnabled); - - if (interceptor != null) - { - return interceptor.CommandCreated(eventData, command); - } - } - - return command; - } - - private static CommandEndEventData BroadcastCommandCreated( - IDiagnosticsLogger diagnostics, - DbConnection connection, - DbCommand command, - DbContext? context, - DbCommandMethod executeMethod, - Guid commandId, - Guid connectionId, - bool async, - DateTimeOffset startTime, - TimeSpan duration, - EventDefinition definition, - bool diagnosticSourceEnabled, - bool simpleLogEnabled) - { - var eventData = new CommandEndEventData( - definition, - CommandCreated, - connection, - command, - context, - executeMethod, - commandId, - connectionId, - async, - false, - startTime, - duration); - - diagnostics.DispatchEventData(definition, eventData, diagnosticSourceEnabled, simpleLogEnabled); - - return eventData; - } - - private static void LogCommandCreated( - IDiagnosticsLogger diagnostics, - EventDefinition definition, - DbCommandMethod commandMethod, - TimeSpan duration) - { - if (diagnostics.ShouldLog(definition)) - { - definition.Log(diagnostics, commandMethod.ToString(), (int)duration.TotalMilliseconds); - } - } - - private static string CommandCreated(EventDefinitionBase definition, EventData payload) - { - var d = (EventDefinition)definition; - var p = (CommandEndEventData)payload; - return d.GenerateMessage(p.ExecuteMethod.ToString(), (int)p.Duration.TotalMilliseconds); - } - - /// - /// Logs for the event. - /// - /// The diagnostics logger to use. - /// The connection. - /// The database command object. - /// The currently being used, to null if not known. - /// The correlation ID associated with the given . - /// The correlation ID associated with the being used. - /// The time that execution began. - /// An intercepted result. - public static InterceptionResult CommandReaderExecuting( - this IDiagnosticsLogger diagnostics, - IRelationalConnection connection, - DbCommand command, - DbContext? context, - Guid commandId, - Guid connectionId, - DateTimeOffset startTime) - { - var definition = RelationalResources.LogExecutingCommand(diagnostics); - - LogCommandExecuting(diagnostics, command, definition); - - if (diagnostics.NeedsEventData( - definition, out var interceptor, out var diagnosticSourceEnabled, out var simpleLogEnabled)) - { - var eventData = BroadcastCommandExecuting( - diagnostics, - connection.DbConnection, - command, - context, - DbCommandMethod.ExecuteReader, - commandId, - connectionId, - false, - startTime, - definition, - diagnosticSourceEnabled, - simpleLogEnabled); - - if (interceptor != null) - { - return interceptor.ReaderExecuting(command, eventData, default); - } - } - - return default; - } - - /// - /// Logs for the event. - /// - /// The diagnostics logger to use. - /// The connection. - /// The database command object. - /// The currently being used, to null if not known. - /// The correlation ID associated with the given . - /// The correlation ID associated with the being used. - /// The time that execution began. - /// An intercepted result. - public static InterceptionResult CommandScalarExecuting( - this IDiagnosticsLogger diagnostics, - IRelationalConnection connection, - DbCommand command, - DbContext? context, - Guid commandId, - Guid connectionId, - DateTimeOffset startTime) - { - var definition = RelationalResources.LogExecutingCommand(diagnostics); - - LogCommandExecuting(diagnostics, command, definition); - - if (diagnostics.NeedsEventData( - definition, out var interceptor, out var diagnosticSourceEnabled, out var simpleLogEnabled)) - { - var eventData = BroadcastCommandExecuting( - diagnostics, - connection.DbConnection, - command, - context, - DbCommandMethod.ExecuteScalar, - commandId, - connectionId, - false, - startTime, - definition, - diagnosticSourceEnabled, - simpleLogEnabled); - - if (interceptor != null) - { - return interceptor.ScalarExecuting(command, eventData, default); - } - } - - return default; - } - - /// - /// Logs for the event. - /// - /// The diagnostics logger to use. - /// The connection. - /// The database command object. - /// The currently being used, to null if not known. - /// The correlation ID associated with the given . - /// The correlation ID associated with the being used. - /// The time that execution began. - /// An intercepted result. - public static InterceptionResult CommandNonQueryExecuting( - this IDiagnosticsLogger diagnostics, - IRelationalConnection connection, - DbCommand command, - DbContext? context, - Guid commandId, - Guid connectionId, - DateTimeOffset startTime) - { - var definition = RelationalResources.LogExecutingCommand(diagnostics); - - LogCommandExecuting(diagnostics, command, definition); - - if (diagnostics.NeedsEventData( - definition, out var interceptor, out var diagnosticSourceEnabled, out var simpleLogEnabled)) - { - var eventData = BroadcastCommandExecuting( - diagnostics, - connection.DbConnection, - command, - context, - DbCommandMethod.ExecuteNonQuery, - commandId, - connectionId, - false, - startTime, - definition, - diagnosticSourceEnabled, - simpleLogEnabled); - - if (interceptor != null) - { - return interceptor.NonQueryExecuting(command, eventData, default); - } - } - - return default; - } - - /// - /// Logs for the event. - /// - /// The diagnostics logger to use. - /// The connection. - /// The database command object. - /// The currently being used, to null if not known. - /// The correlation ID associated with the given . - /// The correlation ID associated with the being used. - /// The time that execution began. - /// A to observe while waiting for the task to complete. - /// An intercepted result. - /// If the is canceled. - public static ValueTask> CommandReaderExecutingAsync( - this IDiagnosticsLogger diagnostics, - IRelationalConnection connection, - DbCommand command, - DbContext? context, - Guid commandId, - Guid connectionId, - DateTimeOffset startTime, - CancellationToken cancellationToken = default) - { - var definition = RelationalResources.LogExecutingCommand(diagnostics); - - LogCommandExecuting(diagnostics, command, definition); - - if (diagnostics.NeedsEventData( - definition, out var interceptor, out var diagnosticSourceEnabled, out var simpleLogEnabled)) - { - var eventData = BroadcastCommandExecuting( - diagnostics, - connection.DbConnection, - command, - context, - DbCommandMethod.ExecuteReader, - commandId, - connectionId, - true, - startTime, - definition, - diagnosticSourceEnabled, - simpleLogEnabled); - - if (interceptor != null) - { - return interceptor.ReaderExecutingAsync(command, eventData, default, cancellationToken); - } - } - - return default; - } - - /// - /// Logs for the event. - /// - /// The diagnostics logger to use. - /// The connection. - /// The database command object. - /// The currently being used, to null if not known. - /// The correlation ID associated with the given . - /// The correlation ID associated with the being used. - /// The time that execution began. - /// A to observe while waiting for the task to complete. - /// An intercepted result. - /// If the is canceled. - public static ValueTask> CommandScalarExecutingAsync( - this IDiagnosticsLogger diagnostics, - IRelationalConnection connection, - DbCommand command, - DbContext? context, - Guid commandId, - Guid connectionId, - DateTimeOffset startTime, - CancellationToken cancellationToken = default) - { - var definition = RelationalResources.LogExecutingCommand(diagnostics); - - LogCommandExecuting(diagnostics, command, definition); - - if (diagnostics.NeedsEventData( - definition, out var interceptor, out var diagnosticSourceEnabled, out var simpleLogEnabled)) - { - var eventData = BroadcastCommandExecuting( - diagnostics, - connection.DbConnection, - command, - context, - DbCommandMethod.ExecuteScalar, - commandId, - connectionId, - true, - startTime, - definition, - diagnosticSourceEnabled, - simpleLogEnabled); - - if (interceptor != null) - { - return interceptor.ScalarExecutingAsync(command, eventData, default, cancellationToken); - } - } - - return default; - } - - /// - /// Logs for the event. - /// - /// The diagnostics logger to use. - /// The connection. - /// The database command object. - /// The currently being used, to null if not known. - /// The correlation ID associated with the given . - /// The correlation ID associated with the being used. - /// The time that execution began. - /// A to observe while waiting for the task to complete. - /// An intercepted result. - /// If the is canceled. - public static ValueTask> CommandNonQueryExecutingAsync( - this IDiagnosticsLogger diagnostics, - IRelationalConnection connection, - DbCommand command, - DbContext? context, - Guid commandId, - Guid connectionId, - DateTimeOffset startTime, - CancellationToken cancellationToken = default) - { - var definition = RelationalResources.LogExecutingCommand(diagnostics); - - LogCommandExecuting(diagnostics, command, definition); - - if (diagnostics.NeedsEventData( - definition, out var interceptor, out var diagnosticSourceEnabled, out var simpleLogEnabled)) - { - var eventData = BroadcastCommandExecuting( - diagnostics, - connection.DbConnection, - command, - context, - DbCommandMethod.ExecuteNonQuery, - commandId, - connectionId, - true, - startTime, - definition, - diagnosticSourceEnabled, - simpleLogEnabled); - - if (interceptor != null) - { - return interceptor.NonQueryExecutingAsync(command, eventData, default, cancellationToken); - } - } - - return default; - } - - private static CommandEventData BroadcastCommandExecuting( - IDiagnosticsLogger diagnostics, - DbConnection connection, - DbCommand command, - DbContext? context, - DbCommandMethod executeMethod, - Guid commandId, - Guid connectionId, - bool async, - DateTimeOffset startTime, - EventDefinition definition, - bool diagnosticSourceEnabled, - bool simpleLogEnabled) - { - var eventData = new CommandEventData( - definition, - CommandExecuting, - connection, - command, - context, - executeMethod, - commandId, - connectionId, - async, - ShouldLogParameterValues(diagnostics, command), - startTime); - - diagnostics.DispatchEventData(definition, eventData, diagnosticSourceEnabled, simpleLogEnabled); - - return eventData; - } - - private static void LogCommandExecuting( - IDiagnosticsLogger diagnostics, - DbCommand command, - EventDefinition definition) - { - if (diagnostics.ShouldLog(definition)) - { - definition.Log( - diagnostics, - command.Parameters.FormatParameters(ShouldLogParameterValues(diagnostics, command)), - command.CommandType, - command.CommandTimeout, - Environment.NewLine, - command.CommandText.TrimEnd()); - } - } - - private static string CommandExecuting(EventDefinitionBase definition, EventData payload) - { - var d = (EventDefinition)definition; - var p = (CommandEventData)payload; - return d.GenerateMessage( - p.Command.Parameters.FormatParameters(p.LogParameterValues), - p.Command.CommandType, - p.Command.CommandTimeout, - Environment.NewLine, - p.Command.CommandText.TrimEnd()); - } - - private static bool ShouldLogParameterValues( - IDiagnosticsLogger diagnostics, - DbCommand command) - => command.Parameters.Count > 0 - && diagnostics.ShouldLogSensitiveData(); - - /// - /// Logs for the event. - /// - /// The diagnostics logger to use. - /// The connection. - /// The database command object. - /// The currently being used, to null if not known. - /// The correlation ID associated with the given . - /// The correlation ID associated with the being used. - /// The return value from the underlying method execution. - /// The time that execution began. - /// The duration of the command execution, not including consuming results. - /// The result of execution, which may have been modified by an interceptor. - public static DbDataReader CommandReaderExecuted( - this IDiagnosticsLogger diagnostics, - IRelationalConnection connection, - DbCommand command, - DbContext? context, - Guid commandId, - Guid connectionId, - DbDataReader methodResult, - DateTimeOffset startTime, - TimeSpan duration) - { - var definition = RelationalResources.LogExecutedCommand(diagnostics); - - LogCommandExecuted(diagnostics, command, duration, definition); - - if (diagnostics.NeedsEventData( - definition, out var interceptor, out var diagnosticSourceEnabled, out var simpleLogEnabled)) - { - var eventData = BroadcastCommandExecuted( - diagnostics, - connection.DbConnection, - command, - context, - DbCommandMethod.ExecuteReader, - commandId, - connectionId, - methodResult, - false, - startTime, - duration, - definition, - diagnosticSourceEnabled, - simpleLogEnabled); - - if (interceptor != null) - { - return interceptor.ReaderExecuted(command, eventData, methodResult); - } - } - - return methodResult; - } - - /// - /// Logs for the event. - /// - /// The diagnostics logger to use. - /// The connection. - /// The database command object. - /// The currently being used, to null if not known. - /// The correlation ID associated with the given . - /// The correlation ID associated with the being used. - /// The return value from the underlying method execution. - /// The time that execution began. - /// The duration of the command execution, not including consuming results. - /// The result of execution, which may have been modified by an interceptor. - public static object? CommandScalarExecuted( - this IDiagnosticsLogger diagnostics, - IRelationalConnection connection, - DbCommand command, - DbContext? context, - Guid commandId, - Guid connectionId, - object? methodResult, - DateTimeOffset startTime, - TimeSpan duration) - { - var definition = RelationalResources.LogExecutedCommand(diagnostics); - - LogCommandExecuted(diagnostics, command, duration, definition); - - if (diagnostics.NeedsEventData( - definition, out var interceptor, out var diagnosticSourceEnabled, out var simpleLogEnabled)) - { - var eventData = BroadcastCommandExecuted( - diagnostics, - connection.DbConnection, - command, - context, - DbCommandMethod.ExecuteScalar, - commandId, - connectionId, - methodResult, - false, - startTime, - duration, - definition, - diagnosticSourceEnabled, - simpleLogEnabled); - - if (interceptor != null) - { - return interceptor.ScalarExecuted(command, eventData, methodResult); - } - } - - return methodResult; - } - - /// - /// Logs for the event. - /// - /// The diagnostics logger to use. - /// The connection. - /// The database command object. - /// The currently being used, to null if not known. - /// The correlation ID associated with the given . - /// The correlation ID associated with the being used. - /// The return value from the underlying method execution. - /// The time that execution began. - /// The duration of the command execution, not including consuming results. - /// The result of execution, which may have been modified by an interceptor. - public static int CommandNonQueryExecuted( - this IDiagnosticsLogger diagnostics, - IRelationalConnection connection, - DbCommand command, - DbContext? context, - Guid commandId, - Guid connectionId, - int methodResult, - DateTimeOffset startTime, - TimeSpan duration) - { - var definition = RelationalResources.LogExecutedCommand(diagnostics); - - LogCommandExecuted(diagnostics, command, duration, definition); - - if (diagnostics.NeedsEventData( - definition, out var interceptor, out var diagnosticSourceEnabled, out var simpleLogEnabled)) - { - var eventData = BroadcastCommandExecuted( - diagnostics, - connection.DbConnection, - command, - context, - DbCommandMethod.ExecuteNonQuery, - commandId, - connectionId, - methodResult, - false, - startTime, - duration, - definition, - diagnosticSourceEnabled, - simpleLogEnabled); - - if (interceptor != null) - { - return interceptor.NonQueryExecuted(command, eventData, methodResult); - } - } - - return methodResult; - } - - /// - /// Logs for the event. - /// - /// The diagnostics logger to use. - /// The connection. - /// The database command object. - /// The currently being used, to null if not known. - /// The correlation ID associated with the given . - /// The correlation ID associated with the being used. - /// The return value from the underlying method execution. - /// The time that execution began. - /// The duration of the command execution, not including consuming results. - /// A to observe while waiting for the task to complete. - /// The result of execution, which may have been modified by an interceptor. - /// If the is canceled. - public static ValueTask CommandReaderExecutedAsync( - this IDiagnosticsLogger diagnostics, - IRelationalConnection connection, - DbCommand command, - DbContext? context, - Guid commandId, - Guid connectionId, - DbDataReader methodResult, - DateTimeOffset startTime, - TimeSpan duration, - CancellationToken cancellationToken = default) - { - var definition = RelationalResources.LogExecutedCommand(diagnostics); - - LogCommandExecuted(diagnostics, command, duration, definition); - - if (diagnostics.NeedsEventData( - definition, out var interceptor, out var diagnosticSourceEnabled, out var simpleLogEnabled)) - { - var eventData = BroadcastCommandExecuted( - diagnostics, - connection.DbConnection, - command, - context, - DbCommandMethod.ExecuteReader, - commandId, - connectionId, - methodResult, - true, - startTime, - duration, - definition, - diagnosticSourceEnabled, - simpleLogEnabled); - - if (interceptor != null) - { - return interceptor.ReaderExecutedAsync(command, eventData, methodResult, cancellationToken); - } - } - - return new ValueTask(methodResult); - } - - /// - /// Logs for the event. - /// - /// The diagnostics logger to use. - /// The connection. - /// The database command object. - /// The currently being used, to null if not known. - /// The correlation ID associated with the given . - /// The correlation ID associated with the being used. - /// The return value from the underlying method execution. - /// The time that execution began. - /// The duration of the command execution, not including consuming results. - /// A to observe while waiting for the task to complete. - /// The result of execution, which may have been modified by an interceptor. - /// If the is canceled. - public static ValueTask CommandScalarExecutedAsync( - this IDiagnosticsLogger diagnostics, - IRelationalConnection connection, - DbCommand command, - DbContext? context, - Guid commandId, - Guid connectionId, - object? methodResult, - DateTimeOffset startTime, - TimeSpan duration, - CancellationToken cancellationToken = default) - { - var definition = RelationalResources.LogExecutedCommand(diagnostics); - - LogCommandExecuted(diagnostics, command, duration, definition); - - if (diagnostics.NeedsEventData( - definition, out var interceptor, out var diagnosticSourceEnabled, out var simpleLogEnabled)) - { - var eventData = BroadcastCommandExecuted( - diagnostics, - connection.DbConnection, - command, - context, - DbCommandMethod.ExecuteScalar, - commandId, - connectionId, - methodResult, - true, - startTime, - duration, - definition, - diagnosticSourceEnabled, - simpleLogEnabled); - - if (interceptor != null) - { - return interceptor.ScalarExecutedAsync(command, eventData, methodResult, cancellationToken); - } - } - - return new ValueTask(methodResult); - } - - /// - /// Logs for the event. - /// - /// The diagnostics logger to use. - /// The connection. - /// The database command object. - /// The currently being used, to null if not known. - /// The correlation ID associated with the given . - /// The correlation ID associated with the being used. - /// The return value from the underlying method execution. - /// The time that execution began. - /// The duration of the command execution, not including consuming results. - /// A to observe while waiting for the task to complete. - /// The result of execution, which may have been modified by an interceptor. - /// If the is canceled. - public static ValueTask CommandNonQueryExecutedAsync( - this IDiagnosticsLogger diagnostics, - IRelationalConnection connection, - DbCommand command, - DbContext? context, - Guid commandId, - Guid connectionId, - int methodResult, - DateTimeOffset startTime, - TimeSpan duration, - CancellationToken cancellationToken = default) - { - var definition = RelationalResources.LogExecutedCommand(diagnostics); - - LogCommandExecuted(diagnostics, command, duration, definition); - - if (diagnostics.NeedsEventData( - definition, out var interceptor, out var diagnosticSourceEnabled, out var simpleLogEnabled)) - { - var eventData = BroadcastCommandExecuted( - diagnostics, - connection.DbConnection, - command, - context, - DbCommandMethod.ExecuteNonQuery, - commandId, - connectionId, - methodResult, - true, - startTime, - duration, - definition, - diagnosticSourceEnabled, - simpleLogEnabled); - - if (interceptor != null) - { - return interceptor.NonQueryExecutedAsync(command, eventData, methodResult, cancellationToken); - } - } - - return new ValueTask(methodResult); - } - - private static CommandExecutedEventData BroadcastCommandExecuted( - IDiagnosticsLogger diagnostics, - DbConnection connection, - DbCommand command, - DbContext? context, - DbCommandMethod executeMethod, - Guid commandId, - Guid connectionId, - object? methodResult, - bool async, - DateTimeOffset startTime, - TimeSpan duration, - EventDefinition definition, - bool diagnosticSourceEnabled, - bool simpleLogEnabled) - { - var eventData = new CommandExecutedEventData( - definition, - CommandExecuted, - connection, - command, - context, - executeMethod, - commandId, - connectionId, - methodResult, - async, - ShouldLogParameterValues(diagnostics, command), - startTime, - duration); - - diagnostics.DispatchEventData(definition, eventData, diagnosticSourceEnabled, simpleLogEnabled); - - return eventData; - } - - private static void LogCommandExecuted( - IDiagnosticsLogger diagnostics, - DbCommand command, - TimeSpan duration, - EventDefinition definition) - { - if (diagnostics.ShouldLog(definition)) - { - definition.Log( - diagnostics, - string.Format(CultureInfo.InvariantCulture, "{0:N0}", duration.TotalMilliseconds), - command.Parameters.FormatParameters(ShouldLogParameterValues(diagnostics, command)), - command.CommandType, - command.CommandTimeout, - Environment.NewLine, - command.CommandText.TrimEnd()); - } - } - - private static string CommandExecuted(EventDefinitionBase definition, EventData payload) - { - var d = (EventDefinition)definition; - var p = (CommandExecutedEventData)payload; - return d.GenerateMessage( - string.Format(CultureInfo.InvariantCulture, "{0:N0}", p.Duration.TotalMilliseconds), - p.Command.Parameters.FormatParameters(p.LogParameterValues), - p.Command.CommandType, - p.Command.CommandTimeout, - Environment.NewLine, - p.Command.CommandText.TrimEnd()); - } - - /// - /// Logs for the event. - /// - /// The diagnostics logger to use. - /// The connection. - /// The database command object. - /// The currently being used, to null if not known. - /// Represents the method that will be called to execute the command. - /// The correlation ID associated with the given . - /// The correlation ID associated with the being used. - /// The exception that caused this failure. - /// The time that execution began. - /// The amount of time that passed until the exception was raised. - public static void CommandError( - this IDiagnosticsLogger diagnostics, - IRelationalConnection connection, - DbCommand command, - DbContext? context, - DbCommandMethod executeMethod, - Guid commandId, - Guid connectionId, - Exception exception, - DateTimeOffset startTime, - TimeSpan duration) - { - var definition = RelationalResources.LogCommandFailed(diagnostics); - - LogCommandError(diagnostics, command, duration, definition); - - if (diagnostics.NeedsEventData( - definition, out var interceptor, out var diagnosticSourceEnabled, out var simpleLogEnabled)) - { - var eventData = BroadcastCommandError( - diagnostics, - connection.DbConnection, - command, - context, - executeMethod, - commandId, - connectionId, - exception, - false, - startTime, - duration, - definition, - diagnosticSourceEnabled, - simpleLogEnabled); - - interceptor?.CommandFailed(command, eventData); - } - } - - private static void LogCommandError( - IDiagnosticsLogger diagnostics, - DbCommand command, - TimeSpan duration, - EventDefinition definition) - { - if (diagnostics.ShouldLog(definition)) - { - definition.Log( - diagnostics, - string.Format(CultureInfo.InvariantCulture, "{0:N0}", duration.TotalMilliseconds), - command.Parameters.FormatParameters(ShouldLogParameterValues(diagnostics, command)), - command.CommandType, - command.CommandTimeout, - Environment.NewLine, - command.CommandText.TrimEnd()); - } - } - - /// - /// Logs for the event. - /// - /// The diagnostics logger to use. - /// The connection. - /// The database command object. - /// The currently being used, to null if not known. - /// Represents the method that will be called to execute the command. - /// The correlation ID associated with the given . - /// The correlation ID associated with the being used. - /// The exception that caused this failure. - /// The time that execution began. - /// The amount of time that passed until the exception was raised. - /// A to observe while waiting for the task to complete. - /// A representing the async operation. - /// If the is canceled. - public static Task CommandErrorAsync( - this IDiagnosticsLogger diagnostics, - IRelationalConnection connection, - DbCommand command, - DbContext? context, - DbCommandMethod executeMethod, - Guid commandId, - Guid connectionId, - Exception exception, - DateTimeOffset startTime, - TimeSpan duration, - CancellationToken cancellationToken = default) - { - var definition = RelationalResources.LogCommandFailed(diagnostics); - - LogCommandError(diagnostics, command, duration, definition); - - if (diagnostics.NeedsEventData( - definition, out var interceptor, out var diagnosticSourceEnabled, out var simpleLogEnabled)) - { - var eventData = BroadcastCommandError( - diagnostics, - connection.DbConnection, - command, - context, - executeMethod, - commandId, - connectionId, - exception, - true, - startTime, - duration, - definition, - diagnosticSourceEnabled, - simpleLogEnabled); - - if (interceptor != null) - { - return interceptor.CommandFailedAsync(command, eventData, cancellationToken); - } - } - - return Task.CompletedTask; - } - - private static CommandErrorEventData BroadcastCommandError( - IDiagnosticsLogger diagnostics, - DbConnection connection, - DbCommand command, - DbContext? context, - DbCommandMethod executeMethod, - Guid commandId, - Guid connectionId, - Exception exception, - bool async, - DateTimeOffset startTime, - TimeSpan duration, - EventDefinition definition, - bool diagnosticSourceEnabled, - bool simpleLogEnabled) - { - var eventData = new CommandErrorEventData( - definition, - CommandError, - connection, - command, - context, - executeMethod, - commandId, - connectionId, - exception, - async, - ShouldLogParameterValues(diagnostics, command), - startTime, - duration); - - diagnostics.DispatchEventData(definition, eventData, diagnosticSourceEnabled, simpleLogEnabled); - - return eventData; - } - - private static string CommandError(EventDefinitionBase definition, EventData payload) - { - var d = (EventDefinition)definition; - var p = (CommandErrorEventData)payload; - return d.GenerateMessage( - string.Format(CultureInfo.InvariantCulture, "{0:N0}", p.Duration.TotalMilliseconds), - p.Command.Parameters.FormatParameters(p.LogParameterValues), - p.Command.CommandType, - p.Command.CommandTimeout, - Environment.NewLine, - p.Command.CommandText.TrimEnd()); - } - - /// - /// Logs for the event. - /// - /// The diagnostics logger to use. - /// The connection. - /// The time that the operation was started. - /// The result of execution, which may have been modified by an interceptor. - public static InterceptionResult ConnectionOpening( - this IDiagnosticsLogger diagnostics, - IRelationalConnection connection, - DateTimeOffset startTime) - { - var definition = RelationalResources.LogOpeningConnection(diagnostics); - - LogConnectionOpening(diagnostics, connection, definition); - - if (diagnostics.NeedsEventData( - definition, out var interceptor, out var diagnosticSourceEnabled, out var simpleLogEnabled)) - { - var eventData = BroadcastConnectionOpening( - diagnostics, - connection, - startTime, - definition, - false, - diagnosticSourceEnabled, - simpleLogEnabled); - - if (interceptor != null) - { - return interceptor.ConnectionOpening(connection.DbConnection, eventData, default); - } - } - - return default; - } - - /// - /// Logs for the event. - /// - /// The diagnostics logger to use. - /// The connection. - /// The time that the operation was started. - /// A to observe while waiting for the task to complete. - /// A representing the async operation. - /// If the is canceled. - public static ValueTask ConnectionOpeningAsync( - this IDiagnosticsLogger diagnostics, - IRelationalConnection connection, - DateTimeOffset startTime, - CancellationToken cancellationToken) - { - var definition = RelationalResources.LogOpeningConnection(diagnostics); - - LogConnectionOpening(diagnostics, connection, definition); - - if (diagnostics.NeedsEventData( - definition, out var interceptor, out var diagnosticSourceEnabled, out var simpleLogEnabled)) - { - var eventData = BroadcastConnectionOpening( - diagnostics, - connection, - startTime, - definition, - true, - diagnosticSourceEnabled, - simpleLogEnabled); - - if (interceptor != null) - { - return interceptor.ConnectionOpeningAsync(connection.DbConnection, eventData, default, cancellationToken); - } - } - - return default; - } - - private static void LogConnectionOpening( - IDiagnosticsLogger diagnostics, - IRelationalConnection connection, - EventDefinition definition) - { - if (diagnostics.ShouldLog(definition)) - { - definition.Log( - diagnostics, - connection.DbConnection.Database, connection.DbConnection.DataSource); - } - } - - private static ConnectionEventData BroadcastConnectionOpening( - IDiagnosticsLogger diagnostics, - IRelationalConnection connection, - DateTimeOffset startTime, - EventDefinition definition, - bool async, - bool diagnosticSourceEnabled, - bool simpleLogEnabled) - { - var eventData = new ConnectionEventData( - definition, - ConnectionOpening, - connection.DbConnection, - connection.Context, - connection.ConnectionId, - async, - startTime); - - diagnostics.DispatchEventData(definition, eventData, diagnosticSourceEnabled, simpleLogEnabled); - - return eventData; - } - - private static string ConnectionOpening(EventDefinitionBase definition, EventData payload) - { - var d = (EventDefinition)definition; - var p = (ConnectionEventData)payload; - return d.GenerateMessage( - p.Connection.Database, - p.Connection.DataSource); - } - - /// - /// Logs for the event. - /// - /// The diagnostics logger to use. - /// The connection. - /// The time that the operation was started. - /// The amount of time before the connection was opened. - public static void ConnectionOpened( - this IDiagnosticsLogger diagnostics, - IRelationalConnection connection, - DateTimeOffset startTime, - TimeSpan duration) - { - var definition = RelationalResources.LogOpenedConnection(diagnostics); - - LogConnectionOpened(diagnostics, connection, definition); - - if (diagnostics.NeedsEventData( - definition, out var interceptor, out var diagnosticSourceEnabled, out var simpleLogEnabled)) - { - var eventData = BroadcastConnectionOpened( - diagnostics, - connection, - false, - startTime, - duration, - definition, - diagnosticSourceEnabled, - simpleLogEnabled); - - interceptor?.ConnectionOpened(connection.DbConnection, eventData); - } - } - - /// - /// Logs for the event. - /// - /// The diagnostics logger to use. - /// The connection. - /// The time that the operation was started. - /// The amount of time before the connection was opened. - /// A to observe while waiting for the task to complete. - /// A representing the async operation. - /// If the is canceled. - public static Task ConnectionOpenedAsync( - this IDiagnosticsLogger diagnostics, - IRelationalConnection connection, - DateTimeOffset startTime, - TimeSpan duration, - CancellationToken cancellationToken = default) - { - var definition = RelationalResources.LogOpenedConnection(diagnostics); - - LogConnectionOpened(diagnostics, connection, definition); - - if (diagnostics.NeedsEventData( - definition, out var interceptor, out var diagnosticSourceEnabled, out var simpleLogEnabled)) - { - var eventData = BroadcastConnectionOpened( - diagnostics, - connection, - true, - startTime, - duration, - definition, - diagnosticSourceEnabled, - simpleLogEnabled); - - if (interceptor != null) - { - return interceptor.ConnectionOpenedAsync(connection.DbConnection, eventData, cancellationToken); - } - } - - return Task.CompletedTask; - } - - private static ConnectionEndEventData BroadcastConnectionOpened( - IDiagnosticsLogger diagnostics, - IRelationalConnection connection, - bool async, - DateTimeOffset startTime, - TimeSpan duration, - EventDefinition definition, - bool diagnosticSourceEnabled, - bool simpleLogEnabled) - { - var eventData = new ConnectionEndEventData( - definition, - ConnectionOpened, - connection.DbConnection, - connection.Context, - connection.ConnectionId, - async, - startTime, - duration); - - diagnostics.DispatchEventData(definition, eventData, diagnosticSourceEnabled, simpleLogEnabled); - - return eventData; - } - - private static void LogConnectionOpened( - IDiagnosticsLogger diagnostics, - IRelationalConnection connection, - EventDefinition definition) - { - if (diagnostics.ShouldLog(definition)) - { - definition.Log( - diagnostics, - connection.DbConnection.Database, connection.DbConnection.DataSource); - } - } - - private static string ConnectionOpened(EventDefinitionBase definition, EventData payload) - { - var d = (EventDefinition)definition; - var p = (ConnectionEndEventData)payload; - return d.GenerateMessage( - p.Connection.Database, - p.Connection.DataSource); - } - - /// - /// Logs for the event. - /// - /// The diagnostics logger to use. - /// The connection. - /// The time that the operation was started. - /// The result of execution, which may have been modified by an interceptor. - public static InterceptionResult ConnectionClosing( - this IDiagnosticsLogger diagnostics, - IRelationalConnection connection, - DateTimeOffset startTime) - { - var definition = RelationalResources.LogClosingConnection(diagnostics); - - LogConnectionClosing(diagnostics, connection, definition); - - if (diagnostics.NeedsEventData( - definition, out var interceptor, out var diagnosticSourceEnabled, out var simpleLogEnabled)) - { - var eventData = BroadcastConnectionClosing( - diagnostics, - connection, - startTime, - false, - definition, - diagnosticSourceEnabled, - simpleLogEnabled); - - if (interceptor != null) - { - return interceptor.ConnectionClosing(connection.DbConnection, eventData, default); - } - } - - return default; - } - - /// - /// Logs for the event. - /// - /// The diagnostics logger to use. - /// The connection. - /// The time that the operation was started. - /// A representing the async operation. - public static ValueTask ConnectionClosingAsync( - this IDiagnosticsLogger diagnostics, - IRelationalConnection connection, - DateTimeOffset startTime) - { - var definition = RelationalResources.LogClosingConnection(diagnostics); - - LogConnectionClosing(diagnostics, connection, definition); - - if (diagnostics.NeedsEventData( - definition, out var interceptor, out var diagnosticSourceEnabled, out var simpleLogEnabled)) - { - var eventData = BroadcastConnectionClosing( - diagnostics, - connection, - startTime, - true, - definition, - diagnosticSourceEnabled, - simpleLogEnabled); - - if (interceptor != null) - { - return interceptor.ConnectionClosingAsync(connection.DbConnection, eventData, default); - } - } - - return default; - } - - private static ConnectionEventData BroadcastConnectionClosing( - IDiagnosticsLogger diagnostics, - IRelationalConnection connection, - DateTimeOffset startTime, - bool async, - EventDefinition definition, - bool diagnosticSourceEnabled, - bool simpleLogEnabled) - { - var eventData = new ConnectionEventData( - definition, - ConnectionClosing, - connection.DbConnection, - connection.Context, - connection.ConnectionId, - async, - startTime); - - diagnostics.DispatchEventData(definition, eventData, diagnosticSourceEnabled, simpleLogEnabled); - - return eventData; - } - - private static void LogConnectionClosing( - IDiagnosticsLogger diagnostics, - IRelationalConnection connection, - EventDefinition definition) - { - if (diagnostics.ShouldLog(definition)) - { - definition.Log( - diagnostics, - connection.DbConnection.Database, connection.DbConnection.DataSource); - } - } - - private static string ConnectionClosing(EventDefinitionBase definition, EventData payload) - { - var d = (EventDefinition)definition; - var p = (ConnectionEventData)payload; - return d.GenerateMessage( - p.Connection.Database, - p.Connection.DataSource); - } - - /// - /// Logs for the event. - /// - /// The diagnostics logger to use. - /// The connection. - /// The time that the operation was started. - /// The amount of time before the connection was closed. - public static void ConnectionClosed( - this IDiagnosticsLogger diagnostics, - IRelationalConnection connection, - DateTimeOffset startTime, - TimeSpan duration) - { - var definition = RelationalResources.LogClosedConnection(diagnostics); - - LogConnectionClosed(diagnostics, connection, definition); - - if (diagnostics.NeedsEventData( - definition, out var interceptor, out var diagnosticSourceEnabled, out var simpleLogEnabled)) - { - var eventData = BroadcastCollectionClosed( - diagnostics, - connection, - startTime, - duration, - false, - definition, - diagnosticSourceEnabled, - simpleLogEnabled); - - interceptor?.ConnectionClosed(connection.DbConnection, eventData); - } - } - - /// - /// Logs for the event. - /// - /// The diagnostics logger to use. - /// The connection. - /// The time that the operation was started. - /// The amount of time before the connection was closed. - /// A representing the async operation. - public static Task ConnectionClosedAsync( - this IDiagnosticsLogger diagnostics, - IRelationalConnection connection, - DateTimeOffset startTime, - TimeSpan duration) - { - var definition = RelationalResources.LogClosedConnection(diagnostics); - - LogConnectionClosed(diagnostics, connection, definition); - - if (diagnostics.NeedsEventData( - definition, out var interceptor, out var diagnosticSourceEnabled, out var simpleLogEnabled)) - { - var eventData = BroadcastCollectionClosed( - diagnostics, - connection, - startTime, - duration, - true, - definition, - diagnosticSourceEnabled, - simpleLogEnabled); - - if (interceptor != null) - { - return interceptor.ConnectionClosedAsync(connection.DbConnection, eventData); - } - } - - return Task.CompletedTask; - } - - private static ConnectionEndEventData BroadcastCollectionClosed( - IDiagnosticsLogger diagnostics, - IRelationalConnection connection, - DateTimeOffset startTime, - TimeSpan duration, - bool async, - EventDefinition definition, - bool diagnosticSourceEnabled, - bool simpleLogEnabled) - { - var eventData = new ConnectionEndEventData( - definition, - ConnectionClosed, - connection.DbConnection, - connection.Context, - connection.ConnectionId, - async, - startTime, - duration); - - diagnostics.DispatchEventData(definition, eventData, diagnosticSourceEnabled, simpleLogEnabled); - - return eventData; - } - - private static void LogConnectionClosed( - IDiagnosticsLogger diagnostics, - IRelationalConnection connection, - EventDefinition definition) - { - if (diagnostics.ShouldLog(definition)) - { - definition.Log( - diagnostics, - connection.DbConnection.Database, connection.DbConnection.DataSource); - } - } - - private static string ConnectionClosed(EventDefinitionBase definition, EventData payload) - { - var d = (EventDefinition)definition; - var p = (ConnectionEndEventData)payload; - return d.GenerateMessage( - p.Connection.Database, - p.Connection.DataSource); - } - - /// - /// Logs for the event. - /// - /// The diagnostics logger to use. - /// The connection. - /// The exception representing the error. - /// The time that the operation was started. - /// The elapsed time before the operation failed. - /// A flag indicating the exception is being handled and so it should be logged at Debug level. - public static void ConnectionError( - this IDiagnosticsLogger diagnostics, - IRelationalConnection connection, - Exception exception, - DateTimeOffset startTime, - TimeSpan duration, - bool logErrorAsDebug) - { - var definition = logErrorAsDebug - ? RelationalResources.LogConnectionErrorAsDebug(diagnostics) - : RelationalResources.LogConnectionError(diagnostics); - - LogConnectionError(diagnostics, connection, definition); - - if (diagnostics.NeedsEventData( - definition, out var interceptor, out var diagnosticSourceEnabled, out var simpleLogEnabled)) - { - var eventData = BroadcastConnectionError( - diagnostics, - connection, - exception, - startTime, - duration, - false, - definition, - diagnosticSourceEnabled, - simpleLogEnabled); - - interceptor?.ConnectionFailed(connection.DbConnection, eventData); - } - } - - /// - /// Logs for the event. - /// - /// The diagnostics logger to use. - /// The connection. - /// The exception representing the error. - /// The time that the operation was started. - /// The elapsed time before the operation failed. - /// A flag indicating the exception is being handled and so it should be logged at Debug level. - /// A to observe while waiting for the task to complete. - /// A representing the async operation. - /// If the is canceled. - public static Task ConnectionErrorAsync( - this IDiagnosticsLogger diagnostics, - IRelationalConnection connection, - Exception exception, - DateTimeOffset startTime, - TimeSpan duration, - bool logErrorAsDebug, - CancellationToken cancellationToken = default) - { - var definition = logErrorAsDebug - ? RelationalResources.LogConnectionErrorAsDebug(diagnostics) - : RelationalResources.LogConnectionError(diagnostics); - - LogConnectionError(diagnostics, connection, definition); - - if (diagnostics.NeedsEventData( - definition, out var interceptor, out var diagnosticSourceEnabled, out var simpleLogEnabled)) - { - var eventData = BroadcastConnectionError( - diagnostics, - connection, - exception, - startTime, - duration, - true, - definition, - diagnosticSourceEnabled, - simpleLogEnabled); - - if (interceptor != null) - { - return interceptor.ConnectionFailedAsync(connection.DbConnection, eventData, cancellationToken); - } - } - - return Task.CompletedTask; - } - - private static ConnectionErrorEventData BroadcastConnectionError( - IDiagnosticsLogger diagnostics, - IRelationalConnection connection, - Exception exception, - DateTimeOffset startTime, - TimeSpan duration, - bool async, - EventDefinition definition, - bool diagnosticSourceEnabled, - bool simpleLogEnabled) - { - var eventData = new ConnectionErrorEventData( - definition, - ConnectionError, - connection.DbConnection, - connection.Context, - connection.ConnectionId, - exception, - async, - startTime, - duration); - - diagnostics.DispatchEventData(definition, eventData, diagnosticSourceEnabled, simpleLogEnabled); - - return eventData; - } - - private static void LogConnectionError( - IDiagnosticsLogger diagnostics, - IRelationalConnection connection, - EventDefinition definition) - { - if (diagnostics.ShouldLog(definition)) - { - definition.Log( - diagnostics, - connection.DbConnection.Database, connection.DbConnection.DataSource); - } - } - - private static string ConnectionError(EventDefinitionBase definition, EventData payload) - { - var d = (EventDefinition)definition; - var p = (ConnectionErrorEventData)payload; - return d.GenerateMessage( - p.Connection.Database, - p.Connection.DataSource); - } - /// /// Logs for the event. /// @@ -3785,64 +1985,6 @@ private static string ExplicitTransactionEnlisted(EventDefinitionBase definition return d.GenerateMessage(p.Transaction.IsolationLevel.ToString("G")); } - /// - /// Logs for the event. - /// - /// The diagnostics logger to use. - /// The connection. - /// The database command object. - /// The data reader. - /// The correlation ID associated with the given . - /// The number of records in the database that were affected. - /// The number of records that were read. - /// The time that the operation was started. - /// The elapsed time from when the operation was started. - /// The result of execution, which may have been modified by an interceptor. - public static InterceptionResult DataReaderDisposing( - this IDiagnosticsLogger diagnostics, - IRelationalConnection connection, - DbCommand command, - DbDataReader dataReader, - Guid commandId, - int recordsAffected, - int readCount, - DateTimeOffset startTime, - TimeSpan duration) - { - var definition = RelationalResources.LogDisposingDataReader(diagnostics); - - if (diagnostics.ShouldLog(definition)) - { - definition.Log(diagnostics); - } - - if (diagnostics.NeedsEventData( - definition, out var interceptor, out var diagnosticSourceEnabled, out var simpleLogEnabled)) - { - var eventData = new DataReaderDisposingEventData( - definition, - (d, p) => ((EventDefinition)d).GenerateMessage(), - command, - dataReader, - connection.Context, - commandId, - connection.ConnectionId, - recordsAffected, - readCount, - startTime, - duration); - - diagnostics.DispatchEventData(definition, eventData, diagnosticSourceEnabled, simpleLogEnabled); - - if (interceptor != null) - { - return interceptor.DataReaderDisposing(command, eventData, default); - } - } - - return default; - } - /// /// Logs for the event. /// diff --git a/src/EFCore.Relational/Infrastructure/EntityFrameworkRelationalServicesBuilder.cs b/src/EFCore.Relational/Infrastructure/EntityFrameworkRelationalServicesBuilder.cs index 7cb0ce3a324..9e1cded2ba3 100644 --- a/src/EFCore.Relational/Infrastructure/EntityFrameworkRelationalServicesBuilder.cs +++ b/src/EFCore.Relational/Infrastructure/EntityFrameworkRelationalServicesBuilder.cs @@ -85,6 +85,10 @@ public class EntityFrameworkRelationalServicesBuilder : EntityFrameworkServicesB { typeof(IRelationalDatabaseCreator), new ServiceCharacteristics(ServiceLifetime.Scoped) }, { typeof(IHistoryRepository), new ServiceCharacteristics(ServiceLifetime.Scoped) }, { typeof(INamedConnectionStringResolver), new ServiceCharacteristics(ServiceLifetime.Scoped) }, + { typeof(IRelationalConnectionDiagnosticsLogger), new ServiceCharacteristics(ServiceLifetime.Scoped) }, + { typeof(IDiagnosticsLogger), new ServiceCharacteristics(ServiceLifetime.Scoped) }, + { typeof(IRelationalCommandDiagnosticsLogger), new ServiceCharacteristics(ServiceLifetime.Scoped) }, + { typeof(IDiagnosticsLogger), new ServiceCharacteristics(ServiceLifetime.Scoped) }, { typeof(IInterceptor), new ServiceCharacteristics(ServiceLifetime.Scoped, multipleRegistrations: true) }, { typeof(IRelationalTypeMappingSourcePlugin), @@ -159,6 +163,10 @@ public override EntityFrameworkServicesBuilder TryAddCoreServices() TryAdd(); TryAdd(p => p.GetRequiredService()); TryAdd(); + TryAdd(); + TryAdd>(p => p.GetRequiredService()); + TryAdd(); + TryAdd>(p => p.GetRequiredService()); TryAdd(); TryAdd(); TryAdd(); diff --git a/src/EFCore.Relational/Migrations/HistoryRepositoryDependencies.cs b/src/EFCore.Relational/Migrations/HistoryRepositoryDependencies.cs index 72d20b8415f..bb3c33e2d19 100644 --- a/src/EFCore.Relational/Migrations/HistoryRepositoryDependencies.cs +++ b/src/EFCore.Relational/Migrations/HistoryRepositoryDependencies.cs @@ -85,7 +85,7 @@ public sealed record HistoryRepositoryDependencies ICurrentDbContext currentContext, IModelRuntimeInitializer modelRuntimeInitializer, IDiagnosticsLogger modelLogger, - IDiagnosticsLogger commandLogger) + IRelationalCommandDiagnosticsLogger commandLogger) { Check.NotNull(databaseCreator, nameof(databaseCreator)); Check.NotNull(rawSqlCommandBuilder, nameof(rawSqlCommandBuilder)); @@ -188,6 +188,6 @@ public sealed record HistoryRepositoryDependencies /// /// The command logger /// - public IDiagnosticsLogger CommandLogger { get; init; } + public IRelationalCommandDiagnosticsLogger CommandLogger { get; init; } } } diff --git a/src/EFCore.Relational/Migrations/Internal/Migrator.cs b/src/EFCore.Relational/Migrations/Internal/Migrator.cs index a9328dcbb68..549a7a3151d 100644 --- a/src/EFCore.Relational/Migrations/Internal/Migrator.cs +++ b/src/EFCore.Relational/Migrations/Internal/Migrator.cs @@ -43,7 +43,7 @@ public class Migrator : IMigrator private readonly ICurrentDbContext _currentContext; private readonly IModelRuntimeInitializer _modelRuntimeInitializer; private readonly IDiagnosticsLogger _logger; - private readonly IDiagnosticsLogger _commandLogger; + private readonly IRelationalCommandDiagnosticsLogger _commandLogger; private readonly string _activeProvider; /// @@ -64,7 +64,7 @@ public class Migrator : IMigrator ICurrentDbContext currentContext, IModelRuntimeInitializer modelRuntimeInitializer, IDiagnosticsLogger logger, - IDiagnosticsLogger commandLogger, + IRelationalCommandDiagnosticsLogger commandLogger, IDatabaseProvider databaseProvider) { Check.NotNull(migrationsAssembly, nameof(migrationsAssembly)); diff --git a/src/EFCore.Relational/Migrations/MigrationCommand.cs b/src/EFCore.Relational/Migrations/MigrationCommand.cs index 01418ef1a01..1abf7079451 100644 --- a/src/EFCore.Relational/Migrations/MigrationCommand.cs +++ b/src/EFCore.Relational/Migrations/MigrationCommand.cs @@ -29,7 +29,7 @@ public class MigrationCommand public MigrationCommand( IRelationalCommand relationalCommand, DbContext? context, - IDiagnosticsLogger logger, + IRelationalCommandDiagnosticsLogger logger, bool transactionSuppressed = false) { Check.NotNull(relationalCommand, nameof(relationalCommand)); @@ -54,7 +54,7 @@ public virtual string CommandText /// /// The associated command logger. /// - public virtual IDiagnosticsLogger CommandLogger { get; } + public virtual IRelationalCommandDiagnosticsLogger CommandLogger { get; } /// /// Executes the command and returns the number of rows affected. diff --git a/src/EFCore.Relational/Migrations/MigrationsSqlGeneratorDependencies.cs b/src/EFCore.Relational/Migrations/MigrationsSqlGeneratorDependencies.cs index bbfa97be1fa..c9b6eb489e7 100644 --- a/src/EFCore.Relational/Migrations/MigrationsSqlGeneratorDependencies.cs +++ b/src/EFCore.Relational/Migrations/MigrationsSqlGeneratorDependencies.cs @@ -62,7 +62,7 @@ public sealed record MigrationsSqlGeneratorDependencies IRelationalTypeMappingSource typeMappingSource, ICurrentDbContext currentContext, ILoggingOptions loggingOptions, - IDiagnosticsLogger logger, + IRelationalCommandDiagnosticsLogger logger, IDiagnosticsLogger migrationsLogger) { Check.NotNull(commandBuilderFactory, nameof(commandBuilderFactory)); @@ -117,7 +117,7 @@ public sealed record MigrationsSqlGeneratorDependencies /// /// The database command logger. /// - public IDiagnosticsLogger Logger { get; init; } + public IRelationalCommandDiagnosticsLogger Logger { get; init; } /// /// The database command logger. diff --git a/src/EFCore.Relational/Query/RelationalQueryContext.cs b/src/EFCore.Relational/Query/RelationalQueryContext.cs index 0b0e09d6163..e15686438e1 100644 --- a/src/EFCore.Relational/Query/RelationalQueryContext.cs +++ b/src/EFCore.Relational/Query/RelationalQueryContext.cs @@ -2,6 +2,7 @@ // Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information. using System.Data.Common; +using Microsoft.EntityFrameworkCore.Diagnostics; using Microsoft.EntityFrameworkCore.Storage; using Microsoft.EntityFrameworkCore.Utilities; @@ -58,5 +59,11 @@ public virtual IRelationalQueryStringFactory RelationalQueryStringFactory /// public virtual IRelationalConnection Connection => RelationalDependencies.RelationalConnection; + + /// + /// The command logger to use while executing the query. + /// + public new virtual IRelationalCommandDiagnosticsLogger CommandLogger + => (IRelationalCommandDiagnosticsLogger)base.CommandLogger; } } diff --git a/src/EFCore.Relational/Storage/IRelationalDatabaseFacadeDependencies.cs b/src/EFCore.Relational/Storage/IRelationalDatabaseFacadeDependencies.cs index aa949d5bb02..31909e75503 100644 --- a/src/EFCore.Relational/Storage/IRelationalDatabaseFacadeDependencies.cs +++ b/src/EFCore.Relational/Storage/IRelationalDatabaseFacadeDependencies.cs @@ -1,6 +1,7 @@ // Copyright (c) .NET Foundation. All rights reserved. // Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information. +using Microsoft.EntityFrameworkCore.Diagnostics; using Microsoft.EntityFrameworkCore.Infrastructure; using Microsoft.Extensions.DependencyInjection; @@ -32,5 +33,10 @@ public interface IRelationalDatabaseFacadeDependencies : IDatabaseFacadeDependen /// The raw SQL command builder. /// IRawSqlCommandBuilder RawSqlCommandBuilder { get; } + + /// + /// A command logger. + /// + new IRelationalCommandDiagnosticsLogger CommandLogger { get; } } } diff --git a/src/EFCore.Relational/Storage/Internal/RelationalDatabaseFacadeDependencies.cs b/src/EFCore.Relational/Storage/Internal/RelationalDatabaseFacadeDependencies.cs index a76502d4e7c..bb7ed0718ff 100644 --- a/src/EFCore.Relational/Storage/Internal/RelationalDatabaseFacadeDependencies.cs +++ b/src/EFCore.Relational/Storage/Internal/RelationalDatabaseFacadeDependencies.cs @@ -26,7 +26,7 @@ public record RelationalDatabaseFacadeDependencies : IRelationalDatabaseFacadeDe IDatabaseCreator databaseCreator, IExecutionStrategyFactory executionStrategyFactory, IEnumerable databaseProviders, - IDiagnosticsLogger commandLogger, + IRelationalCommandDiagnosticsLogger commandLogger, IConcurrencyDetector concurrencyDetector, IRelationalConnection relationalConnection, IRawSqlCommandBuilder rawSqlCommandBuilder, @@ -81,7 +81,9 @@ public record RelationalDatabaseFacadeDependencies : IRelationalDatabaseFacadeDe /// any release. You should only use it directly in your code with extreme caution and knowing that /// doing so can result in application failures when updating to a new Entity Framework Core release. /// - public virtual IDiagnosticsLogger CommandLogger { get; init; } + public virtual IRelationalCommandDiagnosticsLogger CommandLogger { get; init; } + + IDiagnosticsLogger IDatabaseFacadeDependencies.CommandLogger => CommandLogger; /// /// This is an internal API that supports the Entity Framework Core infrastructure and not subject to diff --git a/src/EFCore.Relational/Storage/RelationalCommand.cs b/src/EFCore.Relational/Storage/RelationalCommand.cs index 72e5809048a..7b711c1ecdc 100644 --- a/src/EFCore.Relational/Storage/RelationalCommand.cs +++ b/src/EFCore.Relational/Storage/RelationalCommand.cs @@ -79,38 +79,52 @@ public virtual int ExecuteNonQuery(RelationalCommandParameterObject parameterObj { var (connection, context, logger) = (parameterObject.Connection, parameterObject.Context, parameterObject.Logger); - var commandId = Guid.NewGuid(); + var startTime = DateTimeOffset.UtcNow; + + var shouldLogCommandCreate = logger?.ShouldLogCommandCreate(startTime) == true; + var shouldLogCommandExecute = logger?.ShouldLogCommandExecute(startTime) == true; + + // Guid.NewGuid is expensive, do it only if needed + var commandId = shouldLogCommandCreate || shouldLogCommandExecute ? Guid.NewGuid() : default; + var command = CreateDbCommand(parameterObject, commandId, DbCommandMethod.ExecuteNonQuery); connection.Open(); - var startTime = DateTimeOffset.UtcNow; - _stopwatch.Restart(); try { - var interceptionResult = logger?.CommandNonQueryExecuting( - connection, - command, - context, - commandId, - connection.ConnectionId, - startTime) - ?? default; + if (shouldLogCommandExecute) + { + _stopwatch.Restart(); - var nonQueryResult = interceptionResult.HasResult - ? interceptionResult.Result - : command.ExecuteNonQuery(); + var interceptionResult = logger?.CommandNonQueryExecuting( + connection, + command, + context, + commandId, + connection.ConnectionId, + startTime) + ?? default; - return logger?.CommandNonQueryExecuted( - connection, - command, - context, - commandId, - connection.ConnectionId, - nonQueryResult, - startTime, - _stopwatch.Elapsed) - ?? nonQueryResult; + var nonQueryResult = interceptionResult.HasResult + ? interceptionResult.Result + : command.ExecuteNonQuery(); + + return logger?.CommandNonQueryExecuted( + connection, + command, + context, + commandId, + connection.ConnectionId, + nonQueryResult, + startTime, + _stopwatch.Elapsed) + ?? nonQueryResult; + } + else + { + return command.ExecuteNonQuery(); + } } catch (Exception exception) { @@ -133,24 +147,6 @@ public virtual int ExecuteNonQuery(RelationalCommandParameterObject parameterObj } } - private static void CleanupCommand( - DbCommand command, - IRelationalConnection connection) - { - command.Parameters.Clear(); - command.Dispose(); - connection.Close(); - } - - private static async Task CleanupCommandAsync( - DbCommand command, - IRelationalConnection connection) - { - command.Parameters.Clear(); - await command.DisposeAsync().ConfigureAwait(false); - await connection.CloseAsync().ConfigureAwait(false); - } - /// /// Asynchronously executes the command with no results. /// @@ -166,47 +162,61 @@ public virtual int ExecuteNonQuery(RelationalCommandParameterObject parameterObj { var (connection, context, logger) = (parameterObject.Connection, parameterObject.Context, parameterObject.Logger); - var commandId = Guid.NewGuid(); + var startTime = DateTimeOffset.UtcNow; + + var shouldLogCommandCreate = logger?.ShouldLogCommandCreate(startTime) == true; + var shouldLogCommandExecute = logger?.ShouldLogCommandExecute(startTime) == true; + + // Guid.NewGuid is expensive, do it only if needed + var commandId = shouldLogCommandCreate || shouldLogCommandExecute ? Guid.NewGuid() : default; + var command = CreateDbCommand(parameterObject, commandId, DbCommandMethod.ExecuteNonQuery); await connection.OpenAsync(cancellationToken).ConfigureAwait(false); - var startTime = DateTimeOffset.UtcNow; - _stopwatch.Restart(); try { - var interceptionResult = logger == null - ? default - : await logger.CommandNonQueryExecutingAsync( - connection, - command, - context, - commandId, - connection.ConnectionId, - startTime, - cancellationToken) - .ConfigureAwait(false); - - var result = interceptionResult.HasResult - ? interceptionResult.Result - : await command.ExecuteNonQueryAsync(cancellationToken).ConfigureAwait(false); - - if (logger != null) + if (shouldLogCommandExecute) { - result = await logger.CommandNonQueryExecutedAsync( - connection, - command, - context, - commandId, - connection.ConnectionId, - result, - startTime, - _stopwatch.Elapsed, - cancellationToken) - .ConfigureAwait(false); + _stopwatch.Restart(); + + var interceptionResult = logger == null + ? default + : await logger.CommandNonQueryExecutingAsync( + connection, + command, + context, + commandId, + connection.ConnectionId, + startTime, + cancellationToken) + .ConfigureAwait(false); + + var result = interceptionResult.HasResult + ? interceptionResult.Result + : await command.ExecuteNonQueryAsync(cancellationToken).ConfigureAwait(false); + + if (logger != null) + { + result = await logger.CommandNonQueryExecutedAsync( + connection, + command, + context, + commandId, + connection.ConnectionId, + result, + startTime, + _stopwatch.Elapsed, + cancellationToken) + .ConfigureAwait(false); + } + + return result; + } + else + { + return await command.ExecuteNonQueryAsync(cancellationToken).ConfigureAwait(false); } - - return result; } catch (Exception exception) { @@ -243,38 +253,52 @@ public virtual int ExecuteNonQuery(RelationalCommandParameterObject parameterObj { var (connection, context, logger) = (parameterObject.Connection, parameterObject.Context, parameterObject.Logger); - var commandId = Guid.NewGuid(); + var startTime = DateTimeOffset.UtcNow; + + var shouldLogCommandCreate = logger?.ShouldLogCommandCreate(startTime) == true; + var shouldLogCommandExecute = logger?.ShouldLogCommandExecute(startTime) == true; + + // Guid.NewGuid is expensive, do it only if needed + var commandId = shouldLogCommandCreate || shouldLogCommandExecute ? Guid.NewGuid() : default; + var command = CreateDbCommand(parameterObject, commandId, DbCommandMethod.ExecuteScalar); connection.Open(); - var startTime = DateTimeOffset.UtcNow; - _stopwatch.Restart(); try { - var interceptionResult = logger?.CommandScalarExecuting( - connection, - command, - context, - commandId, - connection.ConnectionId, - startTime) - ?? default; + if (shouldLogCommandExecute) + { + _stopwatch.Restart(); - var result = interceptionResult.HasResult - ? interceptionResult.Result - : command.ExecuteScalar(); + var interceptionResult = logger?.CommandScalarExecuting( + connection, + command, + context, + commandId, + connection.ConnectionId, + startTime) + ?? default; - return logger?.CommandScalarExecuted( - connection, - command, - context, - commandId, - connection.ConnectionId, - result, - startTime, - _stopwatch.Elapsed) - ?? result; + var result = interceptionResult.HasResult + ? interceptionResult.Result + : command.ExecuteScalar(); + + return logger?.CommandScalarExecuted( + connection, + command, + context, + commandId, + connection.ConnectionId, + result, + startTime, + _stopwatch.Elapsed) + ?? result; + } + else + { + return command.ExecuteScalar(); + } } catch (Exception exception) { @@ -312,47 +336,60 @@ public virtual int ExecuteNonQuery(RelationalCommandParameterObject parameterObj { var (connection, context, logger) = (parameterObject.Connection, parameterObject.Context, parameterObject.Logger); - var commandId = Guid.NewGuid(); + var startTime = DateTimeOffset.UtcNow; + + var shouldLogCommandCreate = logger?.ShouldLogCommandCreate(startTime) == true; + var shouldLogCommandExecute = logger?.ShouldLogCommandExecute(startTime) == true; + + // Guid.NewGuid is expensive, do it only if needed + var commandId = shouldLogCommandCreate || shouldLogCommandExecute ? Guid.NewGuid() : default; + var command = CreateDbCommand(parameterObject, commandId, DbCommandMethod.ExecuteScalar); await connection.OpenAsync(cancellationToken).ConfigureAwait(false); - var startTime = DateTimeOffset.UtcNow; - _stopwatch.Restart(); - try { - var interceptionResult = logger == null - ? default - : await logger.CommandScalarExecutingAsync( + if (shouldLogCommandExecute) + { + _stopwatch.Restart(); + + var interceptionResult = logger == null + ? default + : await logger.CommandScalarExecutingAsync( + connection, + command, + context, + commandId, + connection.ConnectionId, + startTime, + cancellationToken) + .ConfigureAwait(false); + + var result = interceptionResult.HasResult + ? interceptionResult.Result + : await command.ExecuteScalarAsync(cancellationToken).ConfigureAwait(false); + + if (logger != null) + { + result = await logger.CommandScalarExecutedAsync( connection, command, context, commandId, connection.ConnectionId, + result, startTime, - cancellationToken) - .ConfigureAwait(false); - - var result = interceptionResult.HasResult - ? interceptionResult.Result - : await command.ExecuteScalarAsync(cancellationToken).ConfigureAwait(false); + _stopwatch.Elapsed, + cancellationToken).ConfigureAwait(false); + } - if (logger != null) + return result; + } + else { - result = await logger.CommandScalarExecutedAsync( - connection, - command, - context, - commandId, - connection.ConnectionId, - result, - startTime, - _stopwatch.Elapsed, - cancellationToken).ConfigureAwait(false); + return await command.ExecuteScalarAsync(cancellationToken).ConfigureAwait(false); } - - return result; } catch (Exception exception) { @@ -393,34 +430,40 @@ public virtual RelationalDataReader ExecuteReader(RelationalCommandParameterObje var logger = parameterObject.Logger; var detailedErrorsEnabled = parameterObject.DetailedErrorsEnabled; - var commandId = Guid.NewGuid(); + var startTime = DateTimeOffset.UtcNow; + + var shouldLogCommandCreate = logger?.ShouldLogCommandCreate(startTime) == true; + var shouldLogCommandExecute = logger?.ShouldLogCommandExecute(startTime) == true; + + // Guid.NewGuid is expensive, do it only if needed + var commandId = shouldLogCommandCreate || shouldLogCommandExecute ? Guid.NewGuid() : default; + var command = CreateDbCommand(parameterObject, commandId, DbCommandMethod.ExecuteReader); connection.Open(); - var startTime = DateTimeOffset.UtcNow; - _stopwatch.Restart(); - var readerOpen = false; DbDataReader reader; + try { - var interceptionResult = logger?.CommandReaderExecuting( + if (shouldLogCommandExecute) + { + _stopwatch.Restart(); + + var interceptionResult = logger!.CommandReaderExecuting( connection, command, context, commandId, connection.ConnectionId, - startTime) - ?? default; + startTime); - reader = interceptionResult.HasResult - ? interceptionResult.Result - : command.ExecuteReader(); + reader = interceptionResult.HasResult + ? interceptionResult.Result + : command.ExecuteReader(); - if (logger != null) - { - reader = logger.CommandReaderExecuted( + reader = logger!.CommandReaderExecuted( connection, command, context, @@ -430,6 +473,10 @@ public virtual RelationalDataReader ExecuteReader(RelationalCommandParameterObje startTime, _stopwatch.Elapsed); } + else + { + reader = command.ExecuteReader(); + } } catch (Exception exception) { @@ -490,21 +537,28 @@ public virtual RelationalDataReader ExecuteReader(RelationalCommandParameterObje var logger = parameterObject.Logger; var detailedErrorsEnabled = parameterObject.DetailedErrorsEnabled; - var commandId = Guid.NewGuid(); + var startTime = DateTimeOffset.UtcNow; + + var shouldLogCommandCreate = logger?.ShouldLogCommandCreate(startTime) == true; + var shouldLogCommandExecute = logger?.ShouldLogCommandExecute(startTime) == true; + + // Guid.NewGuid is expensive, do it only if needed + var commandId = shouldLogCommandCreate || shouldLogCommandExecute ? Guid.NewGuid() : default; + var command = CreateDbCommand(parameterObject, commandId, DbCommandMethod.ExecuteReader); await connection.OpenAsync(cancellationToken).ConfigureAwait(false); - var startTime = DateTimeOffset.UtcNow; - _stopwatch.Restart(); - var readerOpen = false; DbDataReader reader; + try { - var interceptionResult = logger == null - ? default - : await logger.CommandReaderExecutingAsync( + if (shouldLogCommandExecute) + { + _stopwatch.Restart(); + + var interceptionResult = await logger!.CommandReaderExecutingAsync( connection, command, context, @@ -514,13 +568,11 @@ public virtual RelationalDataReader ExecuteReader(RelationalCommandParameterObje cancellationToken) .ConfigureAwait(false); - reader = interceptionResult.HasResult - ? interceptionResult.Result - : await command.ExecuteReaderAsync(cancellationToken).ConfigureAwait(false); + reader = interceptionResult.HasResult + ? interceptionResult.Result + : await command.ExecuteReaderAsync(cancellationToken).ConfigureAwait(false); - if (logger != null) - { - reader = await logger.CommandReaderExecutedAsync( + reader = await logger!.CommandReaderExecutedAsync( connection, command, context, @@ -532,6 +584,10 @@ public virtual RelationalDataReader ExecuteReader(RelationalCommandParameterObje cancellationToken) .ConfigureAwait(false); } + else + { + reader = await command.ExecuteReaderAsync(cancellationToken).ConfigureAwait(false); + } } catch (Exception exception) { @@ -546,7 +602,7 @@ public virtual RelationalDataReader ExecuteReader(RelationalCommandParameterObje connection.ConnectionId, exception, startTime, - _stopwatch.Elapsed, + DateTimeOffset.UtcNow - startTime, cancellationToken) .ConfigureAwait(false); } @@ -603,20 +659,27 @@ public virtual RelationalDataReader ExecuteReader(RelationalCommandParameterObje var connectionId = connection.ConnectionId; var startTime = DateTimeOffset.UtcNow; - _stopwatch.Restart(); - - var interceptionResult = logger?.CommandCreating(connection, commandMethod, context, commandId, connectionId, startTime) - ?? default; - var command = interceptionResult.HasResult - ? interceptionResult.Result - : connection.DbConnection.CreateCommand(); + DbCommand command; - if (logger != null) + if (logger?.ShouldLogCommandCreate(startTime) == true) { + _stopwatch.Restart(); + + var interceptionResult = logger.CommandCreating( + connection, commandMethod, context, commandId, connectionId, startTime); + + command = interceptionResult.HasResult + ? interceptionResult.Result + : connection.DbConnection.CreateCommand(); + command = logger.CommandCreated( connection, command, commandMethod, context, commandId, connectionId, startTime, _stopwatch.Elapsed); } + else + { + command = connection.DbConnection.CreateCommand(); + } command.CommandText = CommandText; @@ -649,6 +712,24 @@ public virtual RelationalDataReader ExecuteReader(RelationalCommandParameterObje return command; } + private static void CleanupCommand( + DbCommand command, + IRelationalConnection connection) + { + command.Parameters.Clear(); + command.Dispose(); + connection.Close(); + } + + private static async Task CleanupCommandAsync( + DbCommand command, + IRelationalConnection connection) + { + command.Parameters.Clear(); + await command.DisposeAsync().ConfigureAwait(false); + await connection.CloseAsync().ConfigureAwait(false); + } + /// /// /// Creates a new to be used by and diff --git a/src/EFCore.Relational/Storage/RelationalCommandParameterObject.cs b/src/EFCore.Relational/Storage/RelationalCommandParameterObject.cs index bc5765cb770..011e74c849e 100644 --- a/src/EFCore.Relational/Storage/RelationalCommandParameterObject.cs +++ b/src/EFCore.Relational/Storage/RelationalCommandParameterObject.cs @@ -37,7 +37,7 @@ namespace Microsoft.EntityFrameworkCore.Storage IReadOnlyDictionary? parameterValues, IReadOnlyList? readerColumns, DbContext? context, - IDiagnosticsLogger? logger) + IRelationalCommandDiagnosticsLogger? logger) : this(connection, parameterValues, readerColumns, context, logger, detailedErrorsEnabled: false) { } @@ -62,7 +62,7 @@ namespace Microsoft.EntityFrameworkCore.Storage IReadOnlyDictionary? parameterValues, IReadOnlyList? readerColumns, DbContext? context, - IDiagnosticsLogger? logger, + IRelationalCommandDiagnosticsLogger? logger, bool detailedErrorsEnabled) { Check.NotNull(connection, nameof(connection)); @@ -98,7 +98,7 @@ namespace Microsoft.EntityFrameworkCore.Storage /// /// A logger, or if no logger is available. /// - public IDiagnosticsLogger? Logger { get; } + public IRelationalCommandDiagnosticsLogger? Logger { get; } /// /// A value indicating if detailed errors are enabled. diff --git a/src/EFCore.Relational/Storage/RelationalConnection.cs b/src/EFCore.Relational/Storage/RelationalConnection.cs index 78519aab6db..6dc5f252b7e 100644 --- a/src/EFCore.Relational/Storage/RelationalConnection.cs +++ b/src/EFCore.Relational/Storage/RelationalConnection.cs @@ -690,23 +690,32 @@ private void ClearTransactions(bool clearAmbient) private void OpenInternal(bool errorsExpected) { + var logger = Dependencies.ConnectionLogger; var startTime = DateTimeOffset.UtcNow; - _stopwatch.Restart(); - - var interceptionResult = Dependencies.ConnectionLogger.ConnectionOpening(this, startTime); try { - if (!interceptionResult.IsSuppressed) + if (logger.ShouldLogConnectionOpen(startTime)) + { + _stopwatch.Restart(); + + var interceptionResult = logger.ConnectionOpening(this, startTime); + + if (!interceptionResult.IsSuppressed) + { + OpenDbConnection(errorsExpected); + } + + logger.ConnectionOpened(this, startTime, _stopwatch.Elapsed); + } + else { OpenDbConnection(errorsExpected); } - - Dependencies.ConnectionLogger.ConnectionOpened(this, startTime, _stopwatch.Elapsed); } catch (Exception e) { - Dependencies.ConnectionLogger.ConnectionError(this, e, startTime, _stopwatch.Elapsed, errorsExpected); + logger.ConnectionError(this, e, startTime, _stopwatch.Elapsed, errorsExpected); throw; } @@ -727,30 +736,37 @@ protected virtual void OpenDbConnection(bool errorsExpected) private async Task OpenInternalAsync(bool errorsExpected, CancellationToken cancellationToken) { + var logger = Dependencies.ConnectionLogger; var startTime = DateTimeOffset.UtcNow; - _stopwatch.Restart(); - - var interceptionResult - = await Dependencies.ConnectionLogger.ConnectionOpeningAsync(this, startTime, cancellationToken) - .ConfigureAwait(false); try { - if (!interceptionResult.IsSuppressed) + if (logger.ShouldLogConnectionOpen(startTime)) + { + _stopwatch.Restart(); + + var interceptionResult + = await logger.ConnectionOpeningAsync(this, startTime, cancellationToken).ConfigureAwait(false); + + if (!interceptionResult.IsSuppressed) + { + await OpenDbConnectionAsync(errorsExpected, cancellationToken).ConfigureAwait(false); + } + + await logger.ConnectionOpenedAsync(this, startTime, _stopwatch.Elapsed, cancellationToken).ConfigureAwait(false); + } + else { await OpenDbConnectionAsync(errorsExpected, cancellationToken).ConfigureAwait(false); } - - await Dependencies.ConnectionLogger.ConnectionOpenedAsync(this, startTime, _stopwatch.Elapsed, cancellationToken) - .ConfigureAwait(false); } catch (Exception e) { - await Dependencies.ConnectionLogger.ConnectionErrorAsync( + await logger.ConnectionErrorAsync( this, e, startTime, - _stopwatch.Elapsed, + DateTimeOffset.UtcNow - startTime, errorsExpected, cancellationToken) .ConfigureAwait(false); @@ -842,21 +858,30 @@ public virtual bool Close() if (DbConnectionState != ConnectionState.Closed) { + var logger = Dependencies.ConnectionLogger; var startTime = DateTimeOffset.UtcNow; - _stopwatch.Restart(); - - var interceptionResult = Dependencies.ConnectionLogger.ConnectionClosing(this, startTime); try { - if (!interceptionResult.IsSuppressed) + if (logger.ShouldLogConnectionClose(startTime)) { - CloseDbConnection(); + _stopwatch.Restart(); + + var interceptionResult = Dependencies.ConnectionLogger.ConnectionClosing(this, startTime); + + if (!interceptionResult.IsSuppressed) + { + CloseDbConnection(); + } + + Dependencies.ConnectionLogger.ConnectionClosed(this, startTime, _stopwatch.Elapsed); + } + else + { + CloseDbConnectionAsync(); } wasClosed = true; - - Dependencies.ConnectionLogger.ConnectionClosed(this, startTime, _stopwatch.Elapsed); } catch (Exception e) { @@ -901,26 +926,32 @@ public virtual async Task CloseAsync() if (DbConnectionState != ConnectionState.Closed) { + var logger = Dependencies.ConnectionLogger; var startTime = DateTimeOffset.UtcNow; - _stopwatch.Restart(); - - var interceptionResult = await Dependencies.ConnectionLogger.ConnectionClosingAsync(this, startTime) - .ConfigureAwait(false); try { - if (!interceptionResult.IsSuppressed) + if (logger.ShouldLogConnectionClose(startTime)) + { + _stopwatch.Restart(); + + var interceptionResult = await Dependencies.ConnectionLogger.ConnectionClosingAsync(this, startTime) + .ConfigureAwait(false); + + if (!interceptionResult.IsSuppressed) + { + await CloseDbConnectionAsync().ConfigureAwait(false); + } + + await Dependencies.ConnectionLogger.ConnectionClosedAsync(this, startTime, _stopwatch.Elapsed) + .ConfigureAwait(false); + } + else { await CloseDbConnectionAsync().ConfigureAwait(false); } wasClosed = true; - - await Dependencies.ConnectionLogger.ConnectionClosedAsync( - this, - startTime, - _stopwatch.Elapsed) - .ConfigureAwait(false); } catch (Exception e) { @@ -928,7 +959,7 @@ public virtual async Task CloseAsync() this, e, startTime, - _stopwatch.Elapsed, + DateTimeOffset.UtcNow - startTime, false) .ConfigureAwait(false); diff --git a/src/EFCore.Relational/Storage/RelationalConnectionDependencies.cs b/src/EFCore.Relational/Storage/RelationalConnectionDependencies.cs index 610a6d69e03..74ec95d9a59 100644 --- a/src/EFCore.Relational/Storage/RelationalConnectionDependencies.cs +++ b/src/EFCore.Relational/Storage/RelationalConnectionDependencies.cs @@ -57,7 +57,7 @@ public sealed record RelationalConnectionDependencies public RelationalConnectionDependencies( IDbContextOptions contextOptions, IDiagnosticsLogger transactionLogger, - IDiagnosticsLogger connectionLogger, + IRelationalConnectionDiagnosticsLogger connectionLogger, INamedConnectionStringResolver connectionStringResolver, IRelationalTransactionFactory relationalTransactionFactory, ICurrentDbContext currentContext, @@ -93,7 +93,7 @@ public sealed record RelationalConnectionDependencies /// /// The logger to which connection messages will be written. /// - public IDiagnosticsLogger ConnectionLogger { get; init; } + public IRelationalConnectionDiagnosticsLogger ConnectionLogger { get; init; } /// /// A service for resolving a connection string from a name. diff --git a/src/EFCore.Relational/Storage/RelationalDataReader.cs b/src/EFCore.Relational/Storage/RelationalDataReader.cs index d60d5b20d50..199d7effe3c 100644 --- a/src/EFCore.Relational/Storage/RelationalDataReader.cs +++ b/src/EFCore.Relational/Storage/RelationalDataReader.cs @@ -28,7 +28,7 @@ public class RelationalDataReader : IDisposable, IAsyncDisposable private DbCommand _command = default!; private DbDataReader _reader = default!; private Guid _commandId; - private IDiagnosticsLogger? _logger; + private IRelationalCommandDiagnosticsLogger? _logger; private DateTimeOffset _startTime; private readonly Stopwatch _stopwatch = new(); @@ -36,6 +36,8 @@ public class RelationalDataReader : IDisposable, IAsyncDisposable private bool _disposed; + private static readonly TimeSpan _oneSecond = TimeSpan.FromSeconds(1); + /// /// Initializes a new instance of the class. /// @@ -60,7 +62,7 @@ public RelationalDataReader(IRelationalCommand relationalCommand) DbCommand command, DbDataReader reader, Guid commandId, - IDiagnosticsLogger? logger) + IRelationalCommandDiagnosticsLogger? logger) { Check.NotNull(command, nameof(command)); Check.NotNull(reader, nameof(reader)); @@ -70,8 +72,8 @@ public RelationalDataReader(IRelationalCommand relationalCommand) _reader = reader; _commandId = commandId; _logger = logger; - _startTime = DateTimeOffset.UtcNow; _disposed = false; + _startTime = DateTimeOffset.UtcNow; _stopwatch.Restart(); } @@ -122,7 +124,7 @@ public virtual void Dispose() { _reader.Close(); // can throw - if (_logger != null) + if (_logger?.ShouldLogDataReaderDispose(DateTimeOffset.UtcNow) == true) { interceptionResult = _logger.DataReaderDisposing( _relationalConnection, @@ -162,7 +164,7 @@ public virtual async ValueTask DisposeAsync() { await _reader.CloseAsync().ConfigureAwait(false); // can throw - if (_logger != null) + if (_logger?.ShouldLogDataReaderDispose(DateTimeOffset.UtcNow) == true) { interceptionResult = _logger.DataReaderDisposing( _relationalConnection, diff --git a/src/EFCore.Relational/Storage/RelationalDatabaseCreatorDependencies.cs b/src/EFCore.Relational/Storage/RelationalDatabaseCreatorDependencies.cs index c77144ac775..3943b8e96ea 100644 --- a/src/EFCore.Relational/Storage/RelationalDatabaseCreatorDependencies.cs +++ b/src/EFCore.Relational/Storage/RelationalDatabaseCreatorDependencies.cs @@ -71,7 +71,7 @@ public sealed record RelationalDatabaseCreatorDependencies ISqlGenerationHelper sqlGenerationHelper, IExecutionStrategyFactory executionStrategyFactory, ICurrentDbContext currentContext, - IDiagnosticsLogger commandLogger) + IRelationalCommandDiagnosticsLogger commandLogger) { Check.NotNull(model, nameof(model)); Check.NotNull(connection, nameof(connection)); @@ -135,7 +135,7 @@ public sealed record RelationalDatabaseCreatorDependencies /// /// The command logger. /// - public IDiagnosticsLogger CommandLogger { get; init; } + public IRelationalCommandDiagnosticsLogger CommandLogger { get; init; } /// /// Contains the currently in use. diff --git a/src/EFCore.Relational/Update/ModificationCommandBatchFactoryDependencies.cs b/src/EFCore.Relational/Update/ModificationCommandBatchFactoryDependencies.cs index 3bd1eb84591..904ff165063 100644 --- a/src/EFCore.Relational/Update/ModificationCommandBatchFactoryDependencies.cs +++ b/src/EFCore.Relational/Update/ModificationCommandBatchFactoryDependencies.cs @@ -60,7 +60,7 @@ public sealed record ModificationCommandBatchFactoryDependencies IUpdateSqlGenerator updateSqlGenerator, IRelationalValueBufferFactoryFactory valueBufferFactoryFactory, ICurrentDbContext currentContext, - IDiagnosticsLogger logger) + IRelationalCommandDiagnosticsLogger logger) { Check.NotNull(commandBuilderFactory, nameof(commandBuilderFactory)); Check.NotNull(sqlGenerationHelper, nameof(sqlGenerationHelper)); @@ -79,7 +79,7 @@ public sealed record ModificationCommandBatchFactoryDependencies /// /// A logger. /// - public IDiagnosticsLogger Logger { get; init; } + public IRelationalCommandDiagnosticsLogger Logger { get; init; } /// /// The command builder factory. diff --git a/src/EFCore.SqlServer/ValueGeneration/Internal/ISqlServerSequenceValueGeneratorFactory.cs b/src/EFCore.SqlServer/ValueGeneration/Internal/ISqlServerSequenceValueGeneratorFactory.cs index aa7969cf7f4..86f597ad554 100644 --- a/src/EFCore.SqlServer/ValueGeneration/Internal/ISqlServerSequenceValueGeneratorFactory.cs +++ b/src/EFCore.SqlServer/ValueGeneration/Internal/ISqlServerSequenceValueGeneratorFactory.cs @@ -28,6 +28,6 @@ public interface ISqlServerSequenceValueGeneratorFactory SqlServerSequenceValueGeneratorState generatorState, ISqlServerConnection connection, IRawSqlCommandBuilder rawSqlCommandBuilder, - IDiagnosticsLogger commandLogger); + IRelationalCommandDiagnosticsLogger commandLogger); } } diff --git a/src/EFCore.SqlServer/ValueGeneration/Internal/SqlServerSequenceHiLoValueGenerator.cs b/src/EFCore.SqlServer/ValueGeneration/Internal/SqlServerSequenceHiLoValueGenerator.cs index f3712dbd8c4..1abf3909551 100644 --- a/src/EFCore.SqlServer/ValueGeneration/Internal/SqlServerSequenceHiLoValueGenerator.cs +++ b/src/EFCore.SqlServer/ValueGeneration/Internal/SqlServerSequenceHiLoValueGenerator.cs @@ -26,7 +26,7 @@ public class SqlServerSequenceHiLoValueGenerator : HiLoValueGenerator _commandLogger; + private readonly IRelationalCommandDiagnosticsLogger _commandLogger; /// /// This is an internal API that supports the Entity Framework Core infrastructure and not subject to @@ -39,7 +39,7 @@ public class SqlServerSequenceHiLoValueGenerator : HiLoValueGenerator commandLogger) + IRelationalCommandDiagnosticsLogger commandLogger) : base(generatorState) { _sequence = generatorState.Sequence; diff --git a/src/EFCore.SqlServer/ValueGeneration/Internal/SqlServerSequenceValueGeneratorFactory.cs b/src/EFCore.SqlServer/ValueGeneration/Internal/SqlServerSequenceValueGeneratorFactory.cs index f8666bd1c1e..7bb0b571813 100644 --- a/src/EFCore.SqlServer/ValueGeneration/Internal/SqlServerSequenceValueGeneratorFactory.cs +++ b/src/EFCore.SqlServer/ValueGeneration/Internal/SqlServerSequenceValueGeneratorFactory.cs @@ -44,7 +44,7 @@ public class SqlServerSequenceValueGeneratorFactory : ISqlServerSequenceValueGen SqlServerSequenceValueGeneratorState generatorState, ISqlServerConnection connection, IRawSqlCommandBuilder rawSqlCommandBuilder, - IDiagnosticsLogger commandLogger) + IRelationalCommandDiagnosticsLogger commandLogger) { var type = property.ClrType.UnwrapNullableType().UnwrapEnumType(); diff --git a/src/EFCore.SqlServer/ValueGeneration/Internal/SqlServerValueGeneratorSelector.cs b/src/EFCore.SqlServer/ValueGeneration/Internal/SqlServerValueGeneratorSelector.cs index 911b9bf0d4a..3b9ed7c4f89 100644 --- a/src/EFCore.SqlServer/ValueGeneration/Internal/SqlServerValueGeneratorSelector.cs +++ b/src/EFCore.SqlServer/ValueGeneration/Internal/SqlServerValueGeneratorSelector.cs @@ -31,7 +31,7 @@ public class SqlServerValueGeneratorSelector : RelationalValueGeneratorSelector private readonly ISqlServerSequenceValueGeneratorFactory _sequenceFactory; private readonly ISqlServerConnection _connection; private readonly IRawSqlCommandBuilder _rawSqlCommandBuilder; - private readonly IDiagnosticsLogger _commandLogger; + private readonly IRelationalCommandDiagnosticsLogger _commandLogger; /// /// This is an internal API that supports the Entity Framework Core infrastructure and not subject to @@ -44,7 +44,7 @@ public class SqlServerValueGeneratorSelector : RelationalValueGeneratorSelector ISqlServerSequenceValueGeneratorFactory sequenceFactory, ISqlServerConnection connection, IRawSqlCommandBuilder rawSqlCommandBuilder, - IDiagnosticsLogger commandLogger) + IRelationalCommandDiagnosticsLogger commandLogger) : base(dependencies) { _sequenceFactory = sequenceFactory; diff --git a/src/EFCore/DbContextOptionsBuilder.cs b/src/EFCore/DbContextOptionsBuilder.cs index 8e7b273c3e7..a1bf155697c 100644 --- a/src/EFCore/DbContextOptionsBuilder.cs +++ b/src/EFCore/DbContextOptionsBuilder.cs @@ -4,6 +4,7 @@ using System; using System.Collections.Generic; using System.ComponentModel; +using System.Diagnostics; using System.Linq; using Microsoft.EntityFrameworkCore.ChangeTracking; using Microsoft.EntityFrameworkCore.Diagnostics; @@ -629,6 +630,21 @@ public virtual DbContextOptionsBuilder AddInterceptors(IEnumerable public virtual DbContextOptionsBuilder AddInterceptors(params IInterceptor[] interceptors) => AddInterceptors((IEnumerable)interceptors); + /// + /// + /// Configures how long EF Core will cache logging configuration in certain high-performance paths. This makes + /// EF Core skip potentially costly logging checks, but means that runtime logging changes (e.g. registering a + /// new may not be taken into account right away). + /// + /// + /// Defaults to one second. + /// + /// + /// The maximum time period over which to skip logging checks before checking again. + /// The same builder instance so that multiple calls can be chained. + public virtual DbContextOptionsBuilder LoggingConfigCacheTime(TimeSpan loggingConfigCacheTime) + => WithOption(e => e.WithLoggingConfigCacheTime(loggingConfigCacheTime)); + /// /// /// Adds the given extension to the options. If an existing extension of the same type already exists, it will be replaced. diff --git a/src/EFCore/DbContextOptionsBuilder`.cs b/src/EFCore/DbContextOptionsBuilder`.cs index 767f2b08bd6..4cd9d5d089f 100644 --- a/src/EFCore/DbContextOptionsBuilder`.cs +++ b/src/EFCore/DbContextOptionsBuilder`.cs @@ -3,6 +3,7 @@ using System; using System.Collections.Generic; +using System.Diagnostics; using System.Linq; using Microsoft.EntityFrameworkCore.ChangeTracking; using Microsoft.EntityFrameworkCore.Diagnostics; @@ -507,5 +508,20 @@ public new virtual DbContextOptionsBuilder AddInterceptors(IEnumerable /// The same builder instance so that multiple calls can be chained. public new virtual DbContextOptionsBuilder AddInterceptors(params IInterceptor[] interceptors) => (DbContextOptionsBuilder)base.AddInterceptors(interceptors); + + /// + /// + /// Configures how long EF Core will cache logging configuration in certain high-performance paths. This makes + /// EF Core skip potentially costly logging checks, but means that runtime logging changes (e.g. registering a + /// new may not be taken into account right away). + /// + /// + /// Defaults to one second. + /// + /// + /// The maximum time period over which to skip logging checks before checking again. + /// The same builder instance so that multiple calls can be chained. + public new virtual DbContextOptionsBuilder LoggingConfigCacheTime(TimeSpan loggingConfigCacheTime) + => (DbContextOptionsBuilder)base.LoggingConfigCacheTime(loggingConfigCacheTime); } } diff --git a/src/EFCore/Diagnostics/Internal/DiagnosticsLogger.cs b/src/EFCore/Diagnostics/Internal/DiagnosticsLogger.cs index 8ddf9e11cbd..dd70f71f621 100644 --- a/src/EFCore/Diagnostics/Internal/DiagnosticsLogger.cs +++ b/src/EFCore/Diagnostics/Internal/DiagnosticsLogger.cs @@ -2,6 +2,7 @@ // Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information. using System.Diagnostics; +using System.Runtime.CompilerServices; using Microsoft.Extensions.DependencyInjection; using Microsoft.Extensions.Logging; @@ -114,5 +115,61 @@ public virtual bool ShouldLogSensitiveData() return options.IsSensitiveDataLoggingEnabled; } + + /// + /// Dispatches the given to a , if enabled, and + /// a , if enabled. + /// + /// The definition of the event to log. + /// The event data. + /// True to dispatch to a ; otherwise. + /// True to dispatch to a ; otherwise. + [MethodImpl(MethodImplOptions.AggressiveInlining)] // Because hot path for logging + protected void DispatchEventData( + EventDefinitionBase definition, + EventData eventData, + bool diagnosticSourceEnabled, + bool simpleLogEnabled) + => ((IDiagnosticsLogger)this).DispatchEventData(definition, eventData, diagnosticSourceEnabled, simpleLogEnabled); + + /// + /// Checks whether or not the message should be sent to the . + /// + /// The definition of the event to log. + /// + /// if logging is enabled and the event should not be ignored; + /// otherwise. + /// + [MethodImpl(MethodImplOptions.AggressiveInlining)] // Because hot path for logging + protected bool ShouldLog(EventDefinitionBase definition) + => ((IDiagnosticsLogger)this).ShouldLog(definition); + + /// + /// Determines whether or not an instance is needed based on whether or + /// not there is a , an , or an enabled for + /// the given event. + /// + /// The definition of the event. + /// The to use if enabled; otherwise null. + /// + /// Set to if a is enabled; + /// otherwise. + /// + /// + /// True to if a is enabled; + /// otherwise. + /// + /// + /// if either a diagnostic source, a LogTo logger, or an interceptor is enabled; + /// otherwise. + /// + [MethodImpl(MethodImplOptions.AggressiveInlining)] // Because hot path for logging + protected bool NeedsEventData( + EventDefinitionBase definition, + out TInterceptor? interceptor, + out bool diagnosticSourceEnabled, + out bool simpleLogEnabled) + where TInterceptor : class, IInterceptor + => ((IDiagnosticsLogger)this).NeedsEventData(definition, out interceptor, out diagnosticSourceEnabled, out simpleLogEnabled); } } diff --git a/src/EFCore/Infrastructure/CoreOptionsExtension.cs b/src/EFCore/Infrastructure/CoreOptionsExtension.cs index b8729af6036..e51426a7311 100644 --- a/src/EFCore/Infrastructure/CoreOptionsExtension.cs +++ b/src/EFCore/Infrastructure/CoreOptionsExtension.cs @@ -39,10 +39,17 @@ public class CoreOptionsExtension : IDbContextOptionsExtension private QueryTrackingBehavior _queryTrackingBehavior = QueryTrackingBehavior.TrackAll; private IDictionary<(Type, Type?), Type>? _replacedServices; private int? _maxPoolSize; + private TimeSpan _loggingConfigCacheTime = DefaultLoggingConfigCacheTime; private bool _serviceProviderCachingEnabled = true; private DbContextOptionsExtensionInfo? _info; private IEnumerable? _interceptors; + /// + /// The default for how long EF Core will cache logging configuration in certain high-performance paths: one second. + /// See . + /// + public static readonly TimeSpan DefaultLoggingConfigCacheTime = TimeSpan.FromSeconds(1); + private WarningsConfiguration _warningsConfiguration = new WarningsConfiguration() .TryWithExplicit(CoreEventId.ManyServiceProvidersCreatedWarning, WarningBehavior.Throw) @@ -76,6 +83,7 @@ protected CoreOptionsExtension(CoreOptionsExtension copyFrom) _warningsConfiguration = copyFrom.WarningsConfiguration; _queryTrackingBehavior = copyFrom.QueryTrackingBehavior; _maxPoolSize = copyFrom.MaxPoolSize; + _loggingConfigCacheTime = copyFrom.LoggingConfigCacheTime; _serviceProviderCachingEnabled = copyFrom.ServiceProviderCachingEnabled; _interceptors = copyFrom.Interceptors?.ToList(); @@ -288,6 +296,21 @@ public virtual CoreOptionsExtension WithMaxPoolSize(int? maxPoolSize) return clone; } + /// + /// Creates a new instance with all options the same as for this instance, but with the given option changed. + /// It is unusual to call this method directly. Instead use . + /// + /// The maximum time period over which to skip logging checks before checking again. + /// A new instance with the option changed. + public virtual CoreOptionsExtension WithLoggingConfigCacheTime(TimeSpan loggingConfigCacheTime) + { + var clone = Clone(); + + clone._loggingConfigCacheTime = loggingConfigCacheTime; + + return clone; + } + /// /// Creates a new instance with all options the same as for this instance, but with the given option changed. /// It is unusual to call this method directly. Instead use . @@ -424,6 +447,15 @@ public virtual bool ServiceProviderCachingEnabled public virtual int? MaxPoolSize => _maxPoolSize; + /// + /// The option set from the + /// + /// method. + /// + public virtual TimeSpan LoggingConfigCacheTime + => _loggingConfigCacheTime; + /// /// The options set from the method. /// diff --git a/test/EFCore.Cosmos.Tests/CosmosEventIdTest.cs b/test/EFCore.Cosmos.Tests/CosmosEventIdTest.cs index fa735720931..f74f1de048b 100644 --- a/test/EFCore.Cosmos.Tests/CosmosEventIdTest.cs +++ b/test/EFCore.Cosmos.Tests/CosmosEventIdTest.cs @@ -28,7 +28,7 @@ public void Every_eventId_has_a_logger_method_and_logs_when_level_enabled() TestEventLogging( typeof(CosmosEventId), typeof(CosmosLoggerExtensions), - typeof(CosmosLoggingDefinitions), + new CosmosLoggingDefinitions(), fakeFactories); } } diff --git a/test/EFCore.Design.Tests/Migrations/Design/MigrationScaffolderTest.cs b/test/EFCore.Design.Tests/Migrations/Design/MigrationScaffolderTest.cs index ecd30b0b675..4b14eb9dfc1 100644 --- a/test/EFCore.Design.Tests/Migrations/Design/MigrationScaffolderTest.cs +++ b/test/EFCore.Design.Tests/Migrations/Design/MigrationScaffolderTest.cs @@ -134,7 +134,7 @@ var migrationAssembly services.GetRequiredService(), services.GetRequiredService(), services.GetRequiredService>(), - services.GetRequiredService>(), + services.GetRequiredService(), services.GetRequiredService()))); } diff --git a/test/EFCore.InMemory.Tests/InMemoryEventIdTest.cs b/test/EFCore.InMemory.Tests/InMemoryEventIdTest.cs index 4e30aea70d0..a21f3eb8bff 100644 --- a/test/EFCore.InMemory.Tests/InMemoryEventIdTest.cs +++ b/test/EFCore.InMemory.Tests/InMemoryEventIdTest.cs @@ -26,7 +26,7 @@ public void Every_eventId_has_a_logger_method_and_logs_when_level_enabled() TestEventLogging( typeof(InMemoryEventId), typeof(InMemoryLoggerExtensions), - typeof(InMemoryLoggingDefinitions), + new InMemoryLoggingDefinitions(), fakeFactories); } } diff --git a/test/EFCore.Relational.Specification.Tests/CommandInterceptionTestBase.cs b/test/EFCore.Relational.Specification.Tests/CommandInterceptionTestBase.cs index 7327c5196a6..7c45471d82d 100644 --- a/test/EFCore.Relational.Specification.Tests/CommandInterceptionTestBase.cs +++ b/test/EFCore.Relational.Specification.Tests/CommandInterceptionTestBase.cs @@ -76,7 +76,7 @@ public virtual async Task Intercept_scalar_passively(bool async, bool inject) var command = context.GetService().Create().Append(sql).Build(); var connection = context.GetService(); - var logger = context.GetService>(); + var logger = context.GetService(); var commandParameterObject = new RelationalCommandParameterObject(connection, null, null, context, logger); @@ -284,7 +284,7 @@ public virtual async Task Intercept_scalar_to_suppress_execution(bool async, boo var command = context.GetService().Create().Append(sql).Build(); var connection = context.GetService(); - var logger = context.GetService>(); + var logger = context.GetService(); var commandParameterObject = new RelationalCommandParameterObject(connection, null, null, context, logger); @@ -469,7 +469,7 @@ public virtual async Task Intercept_scalar_to_mutate_command(bool async, bool in var command = context.GetService().Create().Append(sql).Build(); var connection = context.GetService(); - var logger = context.GetService>(); + var logger = context.GetService(); var commandParameterObject = new RelationalCommandParameterObject(connection, null, null, context, logger); @@ -667,7 +667,7 @@ public virtual async Task Intercept_scalar_to_replace_execution(bool async, bool var command = context.GetService().Create().Append(sql).Build(); var connection = context.GetService(); - var logger = context.GetService>(); + var logger = context.GetService(); var commandParameterObject = new RelationalCommandParameterObject(connection, null, null, context, logger); @@ -961,7 +961,7 @@ public virtual async Task Intercept_scalar_to_replace_result(bool async, bool in var command = context.GetService().Create().Append(sql).Build(); var connection = context.GetService(); - var logger = context.GetService>(); + var logger = context.GetService(); var commandParameterObject = new RelationalCommandParameterObject(connection, null, null, context, logger); @@ -1114,7 +1114,7 @@ public virtual async Task Intercept_scalar_that_throws(bool async, bool inject) var command = context.GetService().Create().Append(sql).Build(); var connection = context.GetService(); - var logger = context.GetService>(); + var logger = context.GetService(); var commandParameterObject = new RelationalCommandParameterObject(connection, null, null, context, logger); @@ -1198,7 +1198,7 @@ public virtual async Task Intercept_scalar_to_throw(bool async, bool inject) { var command = context.GetService().Create().Append("SELECT 1").Build(); var connection = context.GetService(); - var logger = context.GetService>(); + var logger = context.GetService(); var commandParameterObject = new RelationalCommandParameterObject(connection, null, null, context, logger); @@ -1330,7 +1330,7 @@ private static async Task TestCompositeScalarInterceptors(UniverseContext contex { var command = context.GetService().Create().Append("SELECT 1").Build(); var connection = context.GetService(); - var logger = context.GetService>(); + var logger = context.GetService(); var commandParameterObject = new RelationalCommandParameterObject(connection, null, null, context, logger); diff --git a/test/EFCore.Relational.Tests/Migrations/MigrationCommandExecutorTest.cs b/test/EFCore.Relational.Tests/Migrations/MigrationCommandExecutorTest.cs index 7cd66c1bbed..dc9384f150e 100644 --- a/test/EFCore.Relational.Tests/Migrations/MigrationCommandExecutorTest.cs +++ b/test/EFCore.Relational.Tests/Migrations/MigrationCommandExecutorTest.cs @@ -4,6 +4,7 @@ using System; using System.Collections.Generic; using System.Threading.Tasks; +using Microsoft.EntityFrameworkCore.Diagnostics.Internal; using Microsoft.EntityFrameworkCore.Infrastructure; using Microsoft.EntityFrameworkCore.Migrations.Internal; using Microsoft.EntityFrameworkCore.Storage; @@ -21,7 +22,7 @@ public class MigrationCommandExecutorTest public async Task Executes_migration_commands_in_same_transaction(bool async) { var fakeConnection = CreateConnection(); - var logger = new FakeDiagnosticsLogger(); + var logger = new FakeRelationalCommandDiagnosticsLogger(); var commandList = new List { @@ -63,7 +64,7 @@ public async Task Executes_migration_commands_in_same_transaction(bool async) public async Task Executes_migration_commands_with_transaction_suppressed_outside_of_transaction(bool async) { var fakeConnection = CreateConnection(); - var logger = new FakeDiagnosticsLogger(); + var logger = new FakeRelationalCommandDiagnosticsLogger(); var commandList = new List { @@ -99,7 +100,7 @@ public async Task Executes_migration_commands_with_transaction_suppressed_outsid public async Task Ends_transaction_when_transaction_is_suppressed(bool async) { var fakeConnection = CreateConnection(); - var logger = new FakeDiagnosticsLogger(); + var logger = new FakeRelationalCommandDiagnosticsLogger(); var commandList = new List { @@ -140,7 +141,7 @@ public async Task Ends_transaction_when_transaction_is_suppressed(bool async) public async Task Begins_new_transaction_when_transaction_nolonger_suppressed(bool async) { var fakeConnection = CreateConnection(); - var logger = new FakeDiagnosticsLogger(); + var logger = new FakeRelationalCommandDiagnosticsLogger(); var commandList = new List { @@ -181,7 +182,7 @@ public async Task Begins_new_transaction_when_transaction_nolonger_suppressed(bo public async Task Executes_commands_in_order_regardless_of_transaction_suppression(bool async) { var fakeConnection = CreateConnection(); - var logger = new FakeDiagnosticsLogger(); + var logger = new FakeRelationalCommandDiagnosticsLogger(); var commandList = new List { @@ -256,7 +257,7 @@ public async Task Disposes_transaction_on_exception(bool async) CreateOptions( new FakeRelationalOptionsExtension().WithConnection(fakeDbConnection))); - var logger = new FakeDiagnosticsLogger(); + var logger = new FakeRelationalCommandDiagnosticsLogger(); var commandList = new List { new(CreateRelationalCommand(), null, logger) }; diff --git a/test/EFCore.Relational.Tests/Migrations/MigrationCommandListBuilderTest.cs b/test/EFCore.Relational.Tests/Migrations/MigrationCommandListBuilderTest.cs index 5a90fdc14cc..3d66f429289 100644 --- a/test/EFCore.Relational.Tests/Migrations/MigrationCommandListBuilderTest.cs +++ b/test/EFCore.Relational.Tests/Migrations/MigrationCommandListBuilderTest.cs @@ -130,7 +130,7 @@ private MigrationCommandListBuilder CreateBuilder() TestServiceFactory.Instance.Create(), TestServiceFactory.Instance.Create()); - var logger = new FakeDiagnosticsLogger(); + var logger = new FakeRelationalCommandDiagnosticsLogger(); var migrationsLogger = new FakeDiagnosticsLogger(); var generationHelper = new RelationalSqlGenerationHelper(new RelationalSqlGenerationHelperDependencies()); diff --git a/test/EFCore.Relational.Tests/RelationalApiConsistencyTest.cs b/test/EFCore.Relational.Tests/RelationalApiConsistencyTest.cs index ccc256ae32e..9fff29b0c7e 100644 --- a/test/EFCore.Relational.Tests/RelationalApiConsistencyTest.cs +++ b/test/EFCore.Relational.Tests/RelationalApiConsistencyTest.cs @@ -6,6 +6,7 @@ using System.Linq; using System.Reflection; using Microsoft.EntityFrameworkCore.Diagnostics; +using Microsoft.EntityFrameworkCore.Diagnostics.Internal; using Microsoft.EntityFrameworkCore.Infrastructure; using Microsoft.EntityFrameworkCore.Metadata; using Microsoft.EntityFrameworkCore.Metadata.Builders; @@ -206,8 +207,10 @@ public override typeof(DbConnectionInterceptor).GetMethod(nameof(DbConnectionInterceptor.ConnectionClosedAsync)), typeof(IDbConnectionInterceptor).GetMethod(nameof(IDbConnectionInterceptor.ConnectionClosingAsync)), typeof(IDbConnectionInterceptor).GetMethod(nameof(IDbConnectionInterceptor.ConnectionClosedAsync)), - typeof(RelationalLoggerExtensions).GetMethod(nameof(RelationalLoggerExtensions.ConnectionClosingAsync)), - typeof(RelationalLoggerExtensions).GetMethod(nameof(RelationalLoggerExtensions.ConnectionClosedAsync)) + typeof(IRelationalConnectionDiagnosticsLogger).GetMethod(nameof(IRelationalConnectionDiagnosticsLogger.ConnectionClosingAsync)), + typeof(IRelationalConnectionDiagnosticsLogger).GetMethod(nameof(IRelationalConnectionDiagnosticsLogger.ConnectionClosedAsync)), + typeof(RelationalConnectionDiagnosticsLogger).GetMethod(nameof(IRelationalConnectionDiagnosticsLogger.ConnectionClosingAsync)), + typeof(RelationalConnectionDiagnosticsLogger).GetMethod(nameof(IRelationalConnectionDiagnosticsLogger.ConnectionClosedAsync)) }; public List> RelationalMetadataMethods { get; } = new(); diff --git a/test/EFCore.Relational.Tests/RelationalEventIdTest.cs b/test/EFCore.Relational.Tests/RelationalEventIdTest.cs index 0c684c4eab7..865b1e13c31 100644 --- a/test/EFCore.Relational.Tests/RelationalEventIdTest.cs +++ b/test/EFCore.Relational.Tests/RelationalEventIdTest.cs @@ -13,6 +13,7 @@ using System.Transactions; using Microsoft.EntityFrameworkCore.ChangeTracking.Internal; using Microsoft.EntityFrameworkCore.Diagnostics; +using Microsoft.EntityFrameworkCore.Diagnostics.Internal; using Microsoft.EntityFrameworkCore.Infrastructure; using Microsoft.EntityFrameworkCore.Metadata; using Microsoft.EntityFrameworkCore.Metadata.Internal; @@ -22,8 +23,10 @@ using Microsoft.EntityFrameworkCore.Storage; using Microsoft.EntityFrameworkCore.Storage.ValueConversion; using Microsoft.EntityFrameworkCore.TestUtilities; +using Microsoft.EntityFrameworkCore.TestUtilities.FakeProvider; using Microsoft.EntityFrameworkCore.Update; using Microsoft.Extensions.DependencyInjection; +using Microsoft.Extensions.Logging; using Xunit; using Index = Microsoft.EntityFrameworkCore.Metadata.Internal.Index; using IsolationLevel = System.Data.IsolationLevel; @@ -84,32 +87,38 @@ public void Every_eventId_has_a_logger_method_and_logs_when_level_enabled() TestEventLogging( typeof(RelationalEventId), typeof(RelationalLoggerExtensions), - typeof(TestRelationalLoggingDefinitions), + new[] + { + typeof(IRelationalConnectionDiagnosticsLogger), + typeof(IRelationalCommandDiagnosticsLogger) + }, + new TestRelationalLoggingDefinitions(), fakeFactories, + services => FakeRelationalOptionsExtension.AddEntityFrameworkRelationalDatabase(services), new Dictionary> { { nameof(RelationalEventId.CommandExecuting), new List { - nameof(RelationalLoggerExtensions.CommandReaderExecuting), - nameof(RelationalLoggerExtensions.CommandScalarExecuting), - nameof(RelationalLoggerExtensions.CommandNonQueryExecuting), - nameof(RelationalLoggerExtensions.CommandReaderExecutingAsync), - nameof(RelationalLoggerExtensions.CommandScalarExecutingAsync), - nameof(RelationalLoggerExtensions.CommandNonQueryExecutingAsync) + nameof(IRelationalCommandDiagnosticsLogger.CommandReaderExecuting), + nameof(IRelationalCommandDiagnosticsLogger.CommandScalarExecuting), + nameof(IRelationalCommandDiagnosticsLogger.CommandNonQueryExecuting), + nameof(IRelationalCommandDiagnosticsLogger.CommandReaderExecutingAsync), + nameof(IRelationalCommandDiagnosticsLogger.CommandScalarExecutingAsync), + nameof(IRelationalCommandDiagnosticsLogger.CommandNonQueryExecutingAsync) } }, { nameof(RelationalEventId.CommandExecuted), new List { - nameof(RelationalLoggerExtensions.CommandReaderExecutedAsync), - nameof(RelationalLoggerExtensions.CommandScalarExecutedAsync), - nameof(RelationalLoggerExtensions.CommandNonQueryExecutedAsync), - nameof(RelationalLoggerExtensions.CommandReaderExecuted), - nameof(RelationalLoggerExtensions.CommandScalarExecuted), - nameof(RelationalLoggerExtensions.CommandNonQueryExecuted) + nameof(IRelationalCommandDiagnosticsLogger.CommandReaderExecutedAsync), + nameof(IRelationalCommandDiagnosticsLogger.CommandScalarExecutedAsync), + nameof(IRelationalCommandDiagnosticsLogger.CommandNonQueryExecutedAsync), + nameof(IRelationalCommandDiagnosticsLogger.CommandReaderExecuted), + nameof(IRelationalCommandDiagnosticsLogger.CommandScalarExecuted), + nameof(IRelationalCommandDiagnosticsLogger.CommandNonQueryExecuted) } } }); diff --git a/test/EFCore.Relational.Tests/Storage/RelationalCommandTest.cs b/test/EFCore.Relational.Tests/Storage/RelationalCommandTest.cs index e38f3b7d749..d124b06dec8 100644 --- a/test/EFCore.Relational.Tests/Storage/RelationalCommandTest.cs +++ b/test/EFCore.Relational.Tests/Storage/RelationalCommandTest.cs @@ -25,12 +25,12 @@ namespace Microsoft.EntityFrameworkCore.Storage IRelationalConnection, IRelationalCommand, IReadOnlyDictionary, - IDiagnosticsLogger>; + IRelationalCommandDiagnosticsLogger>; using CommandFunc = Func< IRelationalConnection, IRelationalCommand, IReadOnlyDictionary, - IDiagnosticsLogger, + IRelationalCommandDiagnosticsLogger, Task>; public class RelationalCommandTest @@ -890,7 +890,7 @@ public ThrowingRelationalReader(IRelationalCommand relationalCommand) DbCommand command, DbDataReader reader, Guid commandId, - IDiagnosticsLogger logger) + IRelationalCommandDiagnosticsLogger logger) => throw new InvalidOperationException("Bang!"); } } @@ -1008,12 +1008,13 @@ public ThrowingRelationalReader(IRelationalCommand relationalCommand) var fakeConnection = new FakeRelationalConnection(options); - var logger = new DiagnosticsLogger( + var logger = new RelationalCommandDiagnosticsLogger( logFactory, new FakeLoggingOptions(false), new DiagnosticListener("Fake"), new TestRelationalLoggingDefinitions(), - new NullDbContextLogger()); + new NullDbContextLogger(), + CreateOptions()); var relationalCommand = CreateRelationalCommand( commandText: "Logged Command", @@ -1066,12 +1067,13 @@ public ThrowingRelationalReader(IRelationalCommand relationalCommand) var fakeConnection = new FakeRelationalConnection(options); - var logger = new DiagnosticsLogger( + var logger = new RelationalCommandDiagnosticsLogger( logFactory, new FakeLoggingOptions(true), new DiagnosticListener("Fake"), new TestRelationalLoggingDefinitions(), - new NullDbContextLogger()); + new NullDbContextLogger(), + CreateOptions()); var relationalCommand = CreateRelationalCommand( commandText: "Logged Command", @@ -1124,12 +1126,13 @@ public ThrowingRelationalReader(IRelationalCommand relationalCommand) var diagnostic = new List>(); - var logger = new DiagnosticsLogger( + var logger = new RelationalCommandDiagnosticsLogger( new ListLoggerFactory(), new FakeLoggingOptions(false), new ListDiagnosticSource(diagnostic), new TestRelationalLoggingDefinitions(), - new NullDbContextLogger()); + new NullDbContextLogger(), + CreateOptions()); var relationalCommand = CreateRelationalCommand( parameters: new[] @@ -1195,12 +1198,13 @@ public ThrowingRelationalReader(IRelationalCommand relationalCommand) var fakeConnection = new FakeRelationalConnection(options); - var logger = new DiagnosticsLogger( + var logger = new RelationalCommandDiagnosticsLogger( new ListLoggerFactory(), new FakeLoggingOptions(false), new ListDiagnosticSource(diagnostic), new TestRelationalLoggingDefinitions(), - new NullDbContextLogger()); + new NullDbContextLogger(), + CreateOptions()); var relationalCommand = CreateRelationalCommand( parameters: new[] diff --git a/test/EFCore.Relational.Tests/TestUtilities/FakeProvider/FakeRelationalConnection.cs b/test/EFCore.Relational.Tests/TestUtilities/FakeProvider/FakeRelationalConnection.cs index 4d02f03b848..d0601be6ebc 100644 --- a/test/EFCore.Relational.Tests/TestUtilities/FakeProvider/FakeRelationalConnection.cs +++ b/test/EFCore.Relational.Tests/TestUtilities/FakeProvider/FakeRelationalConnection.cs @@ -29,12 +29,13 @@ public FakeRelationalConnection(IDbContextOptions options = null) new DiagnosticListener("FakeDiagnosticListener"), new TestRelationalLoggingDefinitions(), new NullDbContextLogger()), - new DiagnosticsLogger( + new RelationalConnectionDiagnosticsLogger( new LoggerFactory(), new LoggingOptions(), new DiagnosticListener("FakeDiagnosticListener"), new TestRelationalLoggingDefinitions(), - new NullDbContextLogger()), + new NullDbContextLogger(), + CreateOptions()), new NamedConnectionStringResolver(options ?? CreateOptions()), new RelationalTransactionFactory( new RelationalTransactionFactoryDependencies( diff --git a/test/EFCore.Relational.Tests/TestUtilities/FakeRelationalCommandDiagnosticsLogger.cs b/test/EFCore.Relational.Tests/TestUtilities/FakeRelationalCommandDiagnosticsLogger.cs new file mode 100644 index 00000000000..8100da2a7a0 --- /dev/null +++ b/test/EFCore.Relational.Tests/TestUtilities/FakeRelationalCommandDiagnosticsLogger.cs @@ -0,0 +1,220 @@ +// Copyright (c) .NET Foundation. All rights reserved. +// Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information. + +using System; +using System.Data.Common; +using System.Threading; +using System.Threading.Tasks; +using Microsoft.EntityFrameworkCore.Diagnostics; +using Microsoft.EntityFrameworkCore.Storage; + +#nullable enable + +namespace Microsoft.EntityFrameworkCore.TestUtilities +{ + public class FakeRelationalCommandDiagnosticsLogger + : FakeDiagnosticsLogger, IRelationalCommandDiagnosticsLogger + { + public InterceptionResult CommandCreating( + IRelationalConnection connection, + DbCommandMethod commandMethod, + DbContext? context, + Guid commandId, + Guid connectionId, + DateTimeOffset startTime) + => default; + + public DbCommand CommandCreated( + IRelationalConnection connection, + DbCommand command, + DbCommandMethod commandMethod, + DbContext? context, + Guid commandId, + Guid connectionId, + DateTimeOffset startTime, + TimeSpan duration) + => command; + + public InterceptionResult CommandReaderExecuting( + IRelationalConnection connection, + DbCommand command, + DbContext? context, + Guid commandId, + Guid connectionId, + DateTimeOffset startTime) + => default; + + public InterceptionResult CommandScalarExecuting( + IRelationalConnection connection, + DbCommand command, + DbContext? context, + Guid commandId, + Guid connectionId, + DateTimeOffset startTime) + => default; + + /// + /// Logs for the event. + /// + /// The connection. + /// The database command object. + /// The currently being used, to null if not known. + /// The correlation ID associated with the given . + /// The correlation ID associated with the being used. + /// The time that execution began. + /// An intercepted result. + public InterceptionResult CommandNonQueryExecuting( + IRelationalConnection connection, + DbCommand command, + DbContext? context, + Guid commandId, + Guid connectionId, + DateTimeOffset startTime) + => default; + + public ValueTask> CommandReaderExecutingAsync( + IRelationalConnection connection, + DbCommand command, + DbContext? context, + Guid commandId, + Guid connectionId, + DateTimeOffset startTime, + CancellationToken cancellationToken = default) + => default; + + public ValueTask> CommandScalarExecutingAsync( + IRelationalConnection connection, + DbCommand command, + DbContext? context, + Guid commandId, + Guid connectionId, + DateTimeOffset startTime, + CancellationToken cancellationToken = default) + => default; + + public ValueTask> CommandNonQueryExecutingAsync( + IRelationalConnection connection, + DbCommand command, + DbContext? context, + Guid commandId, + Guid connectionId, + DateTimeOffset startTime, + CancellationToken cancellationToken = default) + => default; + + public DbDataReader CommandReaderExecuted( + IRelationalConnection connection, + DbCommand command, + DbContext? context, + Guid commandId, + Guid connectionId, + DbDataReader methodResult, + DateTimeOffset startTime, + TimeSpan duration) + => methodResult; + + public object? CommandScalarExecuted( + IRelationalConnection connection, + DbCommand command, + DbContext? context, + Guid commandId, + Guid connectionId, + object? methodResult, + DateTimeOffset startTime, + TimeSpan duration) + => methodResult; + + public int CommandNonQueryExecuted( + IRelationalConnection connection, + DbCommand command, + DbContext? context, + Guid commandId, + Guid connectionId, + int methodResult, + DateTimeOffset startTime, + TimeSpan duration) + => methodResult; + + public ValueTask CommandReaderExecutedAsync( + IRelationalConnection connection, + DbCommand command, + DbContext? context, + Guid commandId, + Guid connectionId, + DbDataReader methodResult, + DateTimeOffset startTime, + TimeSpan duration, + CancellationToken cancellationToken = default) + => new(methodResult); + + public ValueTask CommandScalarExecutedAsync( + IRelationalConnection connection, + DbCommand command, + DbContext? context, + Guid commandId, + Guid connectionId, + object? methodResult, + DateTimeOffset startTime, + TimeSpan duration, + CancellationToken cancellationToken = default) + => new(methodResult); + + public ValueTask CommandNonQueryExecutedAsync( + IRelationalConnection connection, + DbCommand command, + DbContext? context, + Guid commandId, + Guid connectionId, + int methodResult, + DateTimeOffset startTime, + TimeSpan duration, + CancellationToken cancellationToken = default) + => new(methodResult); + + public void CommandError( + IRelationalConnection connection, + DbCommand command, + DbContext? context, + DbCommandMethod executeMethod, + Guid commandId, + Guid connectionId, + Exception exception, + DateTimeOffset startTime, + TimeSpan duration) + { + } + + public Task CommandErrorAsync( + IRelationalConnection connection, + DbCommand command, + DbContext? context, + DbCommandMethod executeMethod, + Guid commandId, + Guid connectionId, + Exception exception, + DateTimeOffset startTime, + TimeSpan duration, + CancellationToken cancellationToken = default) + => Task.CompletedTask; + + public InterceptionResult DataReaderDisposing( + IRelationalConnection connection, + DbCommand command, + DbDataReader dataReader, + Guid commandId, + int recordsAffected, + int readCount, + DateTimeOffset startTime, + TimeSpan duration) + => default; + + public bool ShouldLogCommandCreate(DateTimeOffset now) + => true; + + public bool ShouldLogCommandExecute(DateTimeOffset now) + => true; + + public bool ShouldLogDataReaderDispose(DateTimeOffset now) + => true; + } +} diff --git a/test/EFCore.Relational.Tests/Update/ReaderModificationCommandBatchTest.cs b/test/EFCore.Relational.Tests/Update/ReaderModificationCommandBatchTest.cs index 21c2f89f1d7..e48d087762a 100644 --- a/test/EFCore.Relational.Tests/Update/ReaderModificationCommandBatchTest.cs +++ b/test/EFCore.Relational.Tests/Update/ReaderModificationCommandBatchTest.cs @@ -560,7 +560,7 @@ private class ModificationCommandBatchFake : AffectedCountModificationCommandBat TestServiceFactory.Instance.Create(), TestServiceFactory.Instance.Create()); - var logger = new FakeDiagnosticsLogger(); + var logger = new FakeRelationalCommandDiagnosticsLogger(); return new ModificationCommandBatchFactoryDependencies( new RelationalCommandBuilderFactory( diff --git a/test/EFCore.Specification.Tests/TestUtilities/TestLoggerFactory.cs b/test/EFCore.Specification.Tests/TestUtilities/TestLoggerFactory.cs new file mode 100644 index 00000000000..041e1ceb217 --- /dev/null +++ b/test/EFCore.Specification.Tests/TestUtilities/TestLoggerFactory.cs @@ -0,0 +1,29 @@ +// Copyright (c) .NET Foundation. All rights reserved. +// Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information. + +using System; +using Microsoft.EntityFrameworkCore.Diagnostics; +using Microsoft.Extensions.Logging; + +namespace Microsoft.EntityFrameworkCore.TestUtilities +{ + public class TestLoggerFactory : ILoggerFactory + { + public TestLogger Logger { get; } + + public LogLevel? LoggedAt => Logger.LoggedAt; + public EventId LoggedEvent => Logger.LoggedEvent; + public string Message => Logger.Message; + + public TestLoggerFactory(LoggingDefinitions definitions) + => Logger = new TestLogger(definitions); + + public ILogger CreateLogger(string categoryName) + => Logger; + + public void AddProvider(ILoggerProvider provider) + => throw new NotSupportedException(); + + public void Dispose() {} + } +} diff --git a/test/EFCore.SqlServer.Tests/SqlServerConnectionTest.cs b/test/EFCore.SqlServer.Tests/SqlServerConnectionTest.cs index 46ef0636372..c3263b3d30c 100644 --- a/test/EFCore.SqlServer.Tests/SqlServerConnectionTest.cs +++ b/test/EFCore.SqlServer.Tests/SqlServerConnectionTest.cs @@ -4,12 +4,14 @@ using System.Diagnostics; using Microsoft.Data.SqlClient; using Microsoft.EntityFrameworkCore.Diagnostics.Internal; +using Microsoft.EntityFrameworkCore.Infrastructure; using Microsoft.EntityFrameworkCore.Infrastructure.Internal; using Microsoft.EntityFrameworkCore.SqlServer.Diagnostics.Internal; using Microsoft.EntityFrameworkCore.SqlServer.Storage.Internal; using Microsoft.EntityFrameworkCore.Storage; using Microsoft.EntityFrameworkCore.Storage.Internal; using Microsoft.EntityFrameworkCore.TestUtilities; +using Microsoft.EntityFrameworkCore.TestUtilities.FakeProvider; using Microsoft.Extensions.Logging; using Xunit; @@ -75,12 +77,13 @@ public static RelationalConnectionDependencies CreateDependencies(DbContextOptio new DiagnosticListener("FakeDiagnosticListener"), new SqlServerLoggingDefinitions(), new NullDbContextLogger()), - new DiagnosticsLogger( + new RelationalConnectionDiagnosticsLogger( new LoggerFactory(), new LoggingOptions(), new DiagnosticListener("FakeDiagnosticListener"), new SqlServerLoggingDefinitions(), - new NullDbContextLogger()), + new NullDbContextLogger(), + CreateOptions()), new NamedConnectionStringResolver(options), new RelationalTransactionFactory( new RelationalTransactionFactoryDependencies( @@ -94,6 +97,21 @@ public static RelationalConnectionDependencies CreateDependencies(DbContextOptio TestServiceFactory.Instance.Create())))); } + private const string ConnectionString = "Fake Connection String"; + + private static IDbContextOptions CreateOptions( + RelationalOptionsExtension optionsExtension = null) + { + var optionsBuilder = new DbContextOptionsBuilder(); + + ((IDbContextOptionsBuilderInfrastructure)optionsBuilder) + .AddOrUpdateExtension( + optionsExtension + ?? new FakeRelationalOptionsExtension().WithConnectionString(ConnectionString)); + + return optionsBuilder.Options; + } + private class FakeDbContext : DbContext { } diff --git a/test/EFCore.SqlServer.Tests/SqlServerEventIdTest.cs b/test/EFCore.SqlServer.Tests/SqlServerEventIdTest.cs index 64cc9b9caa2..b587e2d9d5e 100644 --- a/test/EFCore.SqlServer.Tests/SqlServerEventIdTest.cs +++ b/test/EFCore.SqlServer.Tests/SqlServerEventIdTest.cs @@ -37,7 +37,7 @@ public void Every_eventId_has_a_logger_method_and_logs_when_level_enabled() TestEventLogging( typeof(SqlServerEventId), typeof(SqlServerLoggerExtensions), - typeof(SqlServerLoggingDefinitions), + new SqlServerLoggingDefinitions(), fakeFactories); } } diff --git a/test/EFCore.SqlServer.Tests/SqlServerSequenceValueGeneratorTest.cs b/test/EFCore.SqlServer.Tests/SqlServerSequenceValueGeneratorTest.cs index 9d6211f79b6..2fefa42e9f0 100644 --- a/test/EFCore.SqlServer.Tests/SqlServerSequenceValueGeneratorTest.cs +++ b/test/EFCore.SqlServer.Tests/SqlServerSequenceValueGeneratorTest.cs @@ -92,7 +92,7 @@ private async Task Generates_sequential_values(bool async) TestServiceFactory.Instance.Create()))), state, CreateConnection(), - new FakeDiagnosticsLogger()); + new FakeRelationalCommandDiagnosticsLogger()); for (var i = 1; i <= 27; i++) { @@ -145,7 +145,7 @@ private async Task>> GenerateValuesInMultipleThreads(int TestServiceFactory.Instance.Create(), TestServiceFactory.Instance.Create()))); - var logger = new FakeDiagnosticsLogger(); + var logger = new FakeRelationalCommandDiagnosticsLogger(); var tests = new Func[threadCount]; var generatedValues = new List[threadCount]; @@ -197,7 +197,7 @@ public void Does_not_generate_temp_values() TestServiceFactory.Instance.Create()))), state, CreateConnection(), - new FakeDiagnosticsLogger()); + new FakeRelationalCommandDiagnosticsLogger()); Assert.False(generator.GeneratesTemporaryValues); } diff --git a/test/EFCore.SqlServer.Tests/Update/SqlServerModificationCommandBatchFactoryTest.cs b/test/EFCore.SqlServer.Tests/Update/SqlServerModificationCommandBatchFactoryTest.cs index b2409738597..f879f27056d 100644 --- a/test/EFCore.SqlServer.Tests/Update/SqlServerModificationCommandBatchFactoryTest.cs +++ b/test/EFCore.SqlServer.Tests/Update/SqlServerModificationCommandBatchFactoryTest.cs @@ -23,7 +23,7 @@ public void Uses_MaxBatchSize_specified_in_SqlServerOptionsExtension() TestServiceFactory.Instance.Create(), TestServiceFactory.Instance.Create()); - var logger = new FakeDiagnosticsLogger(); + var logger = new FakeRelationalCommandDiagnosticsLogger(); var factory = new SqlServerModificationCommandBatchFactory( new ModificationCommandBatchFactoryDependencies( @@ -60,7 +60,7 @@ public void MaxBatchSize_is_optional() TestServiceFactory.Instance.Create(), TestServiceFactory.Instance.Create()); - var logger = new FakeDiagnosticsLogger(); + var logger = new FakeRelationalCommandDiagnosticsLogger(); var factory = new SqlServerModificationCommandBatchFactory( new ModificationCommandBatchFactoryDependencies( diff --git a/test/EFCore.SqlServer.Tests/Update/SqlServerModificationCommandBatchTest.cs b/test/EFCore.SqlServer.Tests/Update/SqlServerModificationCommandBatchTest.cs index 4ff01d4826b..c75d0c7ef45 100644 --- a/test/EFCore.SqlServer.Tests/Update/SqlServerModificationCommandBatchTest.cs +++ b/test/EFCore.SqlServer.Tests/Update/SqlServerModificationCommandBatchTest.cs @@ -20,7 +20,7 @@ public void AddCommand_returns_false_when_max_batch_size_is_reached() TestServiceFactory.Instance.Create(), TestServiceFactory.Instance.Create()); - var logger = new FakeDiagnosticsLogger(); + var logger = new FakeRelationalCommandDiagnosticsLogger(); var batch = new SqlServerModificationCommandBatch( new ModificationCommandBatchFactoryDependencies( diff --git a/test/EFCore.Sqlite.Tests/SqliteEventIdTest.cs b/test/EFCore.Sqlite.Tests/SqliteEventIdTest.cs index 1e8925d8f67..b0b3b81314f 100644 --- a/test/EFCore.Sqlite.Tests/SqliteEventIdTest.cs +++ b/test/EFCore.Sqlite.Tests/SqliteEventIdTest.cs @@ -34,7 +34,7 @@ public void Every_eventId_has_a_logger_method_and_logs_when_level_enabled() TestEventLogging( typeof(SqliteEventId), typeof(SqliteLoggerExtensions), - typeof(SqliteLoggingDefinitions), + new SqliteLoggingDefinitions(), fakeFactories); } diff --git a/test/EFCore.Tests/ApiConsistencyTest.cs b/test/EFCore.Tests/ApiConsistencyTest.cs index e668dd6e96a..e52d4bac0d3 100644 --- a/test/EFCore.Tests/ApiConsistencyTest.cs +++ b/test/EFCore.Tests/ApiConsistencyTest.cs @@ -5,6 +5,7 @@ using System.Collections.Generic; using System.Reflection; using Microsoft.EntityFrameworkCore.ChangeTracking.Internal; +using Microsoft.EntityFrameworkCore.Diagnostics.Internal; using Microsoft.EntityFrameworkCore.Infrastructure; using Microsoft.EntityFrameworkCore.Metadata; using Microsoft.EntityFrameworkCore.Metadata.Builders; @@ -82,7 +83,10 @@ protected override void Initialize() typeof(CompiledQueryCacheKeyGenerator).GetMethod("GenerateCacheKeyCore", AnyInstance), typeof(InternalEntityEntry).GetMethod("get_Item"), typeof(InternalEntityEntry).GetMethod("set_Item"), - typeof(InternalEntityEntry).GetMethod(nameof(InternalEntityEntry.HasDefaultValue)) + typeof(InternalEntityEntry).GetMethod(nameof(InternalEntityEntry.HasDefaultValue)), + typeof(DiagnosticsLogger<>).GetMethod("DispatchEventData", AnyInstance), + typeof(DiagnosticsLogger<>).GetMethod("ShouldLog", AnyInstance), + typeof(DiagnosticsLogger<>).GetMethod("NeedsEventData", AnyInstance) }; public override HashSet NotAnnotatedMethods { get; } = new() diff --git a/test/EFCore.Tests/Infrastructure/CoreEventIdTest.cs b/test/EFCore.Tests/Infrastructure/CoreEventIdTest.cs index 5c92855f1a4..2436769cfb1 100644 --- a/test/EFCore.Tests/Infrastructure/CoreEventIdTest.cs +++ b/test/EFCore.Tests/Infrastructure/CoreEventIdTest.cs @@ -83,7 +83,7 @@ public void Every_eventId_has_a_logger_method_and_logs_when_level_enabled() TestEventLogging( typeof(CoreEventId), typeof(CoreLoggerExtensions), - typeof(TestLoggingDefinitions), + new TestLoggingDefinitions(), fakeFactories); } diff --git a/test/EFCore.Tests/Infrastructure/EventIdTestBase.cs b/test/EFCore.Tests/Infrastructure/EventIdTestBase.cs index e638cb6e617..f3c9afe348f 100644 --- a/test/EFCore.Tests/Infrastructure/EventIdTestBase.cs +++ b/test/EFCore.Tests/Infrastructure/EventIdTestBase.cs @@ -3,10 +3,13 @@ using System; using System.Collections.Generic; +using System.Diagnostics; using System.Linq; using System.Reflection; using Microsoft.EntityFrameworkCore.Diagnostics; using Microsoft.EntityFrameworkCore.TestUtilities; +using Microsoft.Extensions.DependencyInjection; +using Microsoft.Extensions.DependencyInjection.Extensions; using Microsoft.Extensions.Logging; using Xunit; @@ -16,26 +19,49 @@ public abstract class EventIdTestBase { public void TestEventLogging( Type eventIdType, - Type loggerExtensionsType, - Type loggerDefinitionsType, + Type loggerExtensionType, + LoggingDefinitions loggerDefinitions, IDictionary> fakeFactories, Dictionary> eventMappings = null) + => TestEventLogging( + eventIdType, + loggerExtensionType, + loggerMethodTypes: Array.Empty(), + loggerDefinitions, + fakeFactories, + serviceCollectionBuilder: services => new EntityFrameworkServicesBuilder(services).TryAddCoreServices(), + eventMappings); + + public void TestEventLogging( + Type eventIdType, + Type loggerExtensionType, + Type[] loggerMethodTypes, + LoggingDefinitions loggerDefinitions, + IDictionary> fakeFactories, + Action serviceCollectionBuilder, + Dictionary> eventMappings = null) { + var testLoggerFactory = new TestLoggerFactory(loggerDefinitions); + var testLogger = testLoggerFactory.Logger; + var testDiagnostics = new TestDiagnosticSource(); + var contextLogger = new TestDbContextLogger(); + + var serviceCollection = new ServiceCollection(); + serviceCollection.TryAdd(new ServiceDescriptor(typeof(LoggingDefinitions), loggerDefinitions)); + serviceCollection.TryAdd(new ServiceDescriptor(typeof(ILoggerFactory), testLoggerFactory)); + serviceCollection.TryAdd(new ServiceDescriptor(typeof(DiagnosticSource), testDiagnostics)); + serviceCollection.TryAdd(new ServiceDescriptor(typeof(IDbContextLogger), contextLogger)); + serviceCollection.TryAdd(new ServiceDescriptor(typeof(IDbContextOptions), new DbContextOptionsBuilder().Options)); + serviceCollectionBuilder(serviceCollection); + using var serviceProvider = serviceCollection.BuildServiceProvider(); + using var serviceScope = serviceProvider.CreateScope(); + var scopeServiceProvider = serviceScope.ServiceProvider; + var eventIdFields = eventIdType.GetTypeInfo() .DeclaredFields .Where(p => p.FieldType == typeof(EventId) && p.GetCustomAttribute() == null) .ToList(); - var declaredMethods = loggerExtensionsType.GetTypeInfo() - .DeclaredMethods - .Where(m => m.IsPublic) - .OrderBy(e => e.Name) - .ToList(); - - var loggerMethods = declaredMethods - .GroupBy(e => e.Name) - .ToDictionary(m => m.Key, e => e.First()); - foreach (var eventIdField in eventIdFields) { var eventName = eventIdField.Name; @@ -47,12 +73,21 @@ public abstract class EventIdTestBase foreach (var mappedName in mappedNames) { - Assert.Contains(mappedName, loggerMethods.Keys); + var loggerMethod = loggerMethodTypes + .Append(loggerExtensionType) + .Select(t => t.GetMethod(mappedName)) + .FirstOrDefault(m => m is not null); - var loggerMethod = loggerMethods[mappedName]; + Assert.True(loggerMethod is not null, $"Couldn't find logger method {mappedName}"); + var isExtensionMethod = loggerMethod.IsStatic; var loggerParameters = loggerMethod.GetParameters(); - var category = loggerParameters[0].ParameterType.GenericTypeArguments[0]; + + var category = isExtensionMethod + ? loggerParameters[0].ParameterType.GenericTypeArguments[0] + : loggerMethod.DeclaringType!.GetInterfaces() + .Single(i => i.IsGenericType && i.GetGenericTypeDefinition() == typeof(IDiagnosticsLogger<>)) + .GetGenericArguments()[0]; if (category.ContainsGenericParameters) { @@ -67,15 +102,19 @@ public abstract class EventIdTestBase var categoryName = Activator.CreateInstance(category).ToString(); Assert.Equal(categoryName + "." + eventName, eventId.Name); - var testLogger = - (TestLoggerBase)Activator.CreateInstance(typeof(TestLogger<,>).MakeGenericType(category, loggerDefinitionsType)); - var testDiagnostics = (TestDiagnosticSource)testLogger.DiagnosticSource; - var contextLogger = (TestDbContextLogger)testLogger.DbContextLogger; + var diagnosticLogger = scopeServiceProvider.GetRequiredService( + isExtensionMethod + ? typeof(IDiagnosticsLogger<>).MakeGenericType(category) + : loggerMethod.DeclaringType); var args = new object[loggerParameters.Length]; - args[0] = testLogger; + var i = 0; + if (isExtensionMethod) + { + args[i++] = diagnosticLogger; + } - for (var i = 1; i < args.Length; i++) + for (; i < args.Length; i++) { var type = loggerParameters[i].ParameterType; @@ -113,11 +152,11 @@ public abstract class EventIdTestBase testLogger.LoggedAt = null; testDiagnostics.LoggedEventName = null; - loggerMethod.Invoke(null, args); + loggerMethod.Invoke(isExtensionMethod ? null : diagnosticLogger, args); - if (testLogger.LoggedAt != null) + if (testLoggerFactory.LoggedAt != null) { - Assert.Equal(logLevel, testLogger.LoggedAt); + Assert.Equal(logLevel, testLoggerFactory.LoggedAt); logged = true; if (categoryName != DbLoggerCategory.Scaffolding.Name)