diff --git a/src/EFCore.Relational/Diagnostics/RelationalEventId.cs b/src/EFCore.Relational/Diagnostics/RelationalEventId.cs index 626c1f6bb72..cdadab9e70d 100644 --- a/src/EFCore.Relational/Diagnostics/RelationalEventId.cs +++ b/src/EFCore.Relational/Diagnostics/RelationalEventId.cs @@ -107,7 +107,8 @@ private enum Id BatchSmallerThanMinBatchSize, BatchExecutorFailedToRollbackToSavepoint, BatchExecutorFailedToReleaseSavepoint, - OptionalDependentWithAllNullPropertiesWarning + OptionalDependentWithAllNullPropertiesWarning, + UnexpectedTrailingResultSetWhenSaving, } private static readonly string _connectionPrefix = DbLoggerCategory.Database.Connection.Name + "."; @@ -1001,4 +1002,16 @@ private static EventId MakeUpdateId(Id id) /// public static readonly EventId OptionalDependentWithAllNullPropertiesWarning = MakeUpdateId(Id.OptionalDependentWithAllNullPropertiesWarning); + + /// + /// An unexpected trailing result set was found when reading the results of a SaveChanges operation; this may indicate that a stored + /// procedure returned a result set without being configured for it in the EF model. Check your stored procedure definitions. + /// + /// + /// + /// This event is in the category. + /// + /// + public static readonly EventId UnexpectedTrailingResultSetWhenSaving = + MakeUpdateId(Id.UnexpectedTrailingResultSetWhenSaving); } diff --git a/src/EFCore.Relational/Diagnostics/RelationalLoggerExtensions.cs b/src/EFCore.Relational/Diagnostics/RelationalLoggerExtensions.cs index 0a0940c7af0..52b4eba0d40 100644 --- a/src/EFCore.Relational/Diagnostics/RelationalLoggerExtensions.cs +++ b/src/EFCore.Relational/Diagnostics/RelationalLoggerExtensions.cs @@ -3327,4 +3327,31 @@ private static string ColumnOrderIgnoredWarning(EventDefinitionBase definition, var p = (MigrationColumnOperationEventData)payload; return d.GenerateMessage((p.ColumnOperation.Table, p.ColumnOperation.Schema).FormatTable(), p.ColumnOperation.Name); } + + /// + /// Logs for the event. + /// + /// The diagnostics logger to use. + public static void UnexpectedTrailingResultSetWhenSaving(this IDiagnosticsLogger diagnostics) + { + var definition = RelationalResources.LogUnexpectedTrailingResultSetWhenSaving(diagnostics); + + if (diagnostics.ShouldLog(definition)) + { + definition.Log(diagnostics); + } + + if (diagnostics.NeedsEventData(definition, out var diagnosticSourceEnabled, out var simpleLogEnabled)) + { + var eventData = new EventData( + definition, + static (definition, _) => + { + var d = (EventDefinition)definition; + return d.GenerateMessage(); + }); + + diagnostics.DispatchEventData(definition, eventData, diagnosticSourceEnabled, simpleLogEnabled); + } + } } diff --git a/src/EFCore.Relational/Diagnostics/RelationalLoggingDefinitions.cs b/src/EFCore.Relational/Diagnostics/RelationalLoggingDefinitions.cs index 80558d28f3e..86a8eedeaf1 100644 --- a/src/EFCore.Relational/Diagnostics/RelationalLoggingDefinitions.cs +++ b/src/EFCore.Relational/Diagnostics/RelationalLoggingDefinitions.cs @@ -663,4 +663,13 @@ public abstract class RelationalLoggingDefinitions : LoggingDefinitions /// [EntityFrameworkInternal] public EventDefinitionBase? LogExceptionDuringExecuteUpdate; + + /// + /// 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. + /// + [EntityFrameworkInternal] + public EventDefinitionBase? LogUnexpectedTrailingResultSetWhenSaving; } diff --git a/src/EFCore.Relational/Properties/RelationalStrings.Designer.cs b/src/EFCore.Relational/Properties/RelationalStrings.Designer.cs index ed0c5243b14..36282a2012c 100644 --- a/src/EFCore.Relational/Properties/RelationalStrings.Designer.cs +++ b/src/EFCore.Relational/Properties/RelationalStrings.Designer.cs @@ -1197,6 +1197,12 @@ public static string MissingParameterValue(object? parameter) GetString("MissingParameterValue", nameof(parameter)), parameter); + /// + /// A result set was was missing when reading the results of a SaveChanges operation; this may indicate that a stored procedure was configured to return results in the EF model, but did not. Check your stored procedure definitions. + /// + public static string MissingResultSetWhenSaving + => GetString("MissingResultSetWhenSaving"); + /// /// Cannot add commands to a completed ModificationCommandBatch. /// @@ -3663,6 +3669,31 @@ public static EventDefinition LogTransactionError(IDiagnosticsLogger logger) return (EventDefinition)definition; } + /// + /// An unexpected trailing result set was found when reading the results of a SaveChanges operation; this may indicate that a stored procedure returned a result set without being configured for it in the EF model. Check your stored procedure definitions. + /// + public static EventDefinition LogUnexpectedTrailingResultSetWhenSaving(IDiagnosticsLogger logger) + { + var definition = ((RelationalLoggingDefinitions)logger.Definitions).LogUnexpectedTrailingResultSetWhenSaving; + if (definition == null) + { + definition = NonCapturingLazyInitializer.EnsureInitialized( + ref ((RelationalLoggingDefinitions)logger.Definitions).LogUnexpectedTrailingResultSetWhenSaving, + logger, + static logger => new EventDefinition( + logger.Options, + RelationalEventId.UnexpectedTrailingResultSetWhenSaving, + LogLevel.Warning, + "CoreEventId.UnexpectedTrailingResultSetWhenSaving", + level => LoggerMessage.Define( + level, + RelationalEventId.UnexpectedTrailingResultSetWhenSaving, + _resourceManager.GetString("LogUnexpectedTrailingResultSetWhenSaving")!))); + } + + return (EventDefinition)definition; + } + /// /// The unnamed index on the entity type '{entityType}' specifies properties {indexProperties}, but none of these properties are mapped to a column in any table. This index will not be created in the database. /// diff --git a/src/EFCore.Relational/Properties/RelationalStrings.resx b/src/EFCore.Relational/Properties/RelationalStrings.resx index 0fa62864e84..906dd230f13 100644 --- a/src/EFCore.Relational/Properties/RelationalStrings.resx +++ b/src/EFCore.Relational/Properties/RelationalStrings.resx @@ -809,6 +809,10 @@ An error occurred using a transaction. Error RelationalEventId.TransactionError + + An unexpected trailing result set was found when reading the results of a SaveChanges operation; this may indicate that a stored procedure returned a result set without being configured for it in the EF model. Check your stored procedure definitions. + Warning CoreEventId.UnexpectedTrailingResultSetWhenSaving + The unnamed index on the entity type '{entityType}' specifies properties {indexProperties}, but none of these properties are mapped to a column in any table. This index will not be created in the database. Warning RelationalEventId.AllIndexPropertiesNotToMappedToAnyTable string string @@ -855,6 +859,9 @@ No value was provided for the required parameter '{parameter}'. + + A result set was was missing when reading the results of a SaveChanges operation; this may indicate that a stored procedure was configured to return results in the EF model, but did not. Check your stored procedure definitions. + Cannot add commands to a completed ModificationCommandBatch. diff --git a/src/EFCore.Relational/Storage/RelationalDataReader.cs b/src/EFCore.Relational/Storage/RelationalDataReader.cs index f6258fc42aa..9b09a3ecc40 100644 --- a/src/EFCore.Relational/Storage/RelationalDataReader.cs +++ b/src/EFCore.Relational/Storage/RelationalDataReader.cs @@ -1,8 +1,6 @@ // Licensed to the .NET Foundation under one or more agreements. // The .NET Foundation licenses this file to you under the MIT license. -using System.Data.Common; - namespace Microsoft.EntityFrameworkCore.Storage; /// @@ -30,6 +28,7 @@ public class RelationalDataReader : IDisposable, IAsyncDisposable private int _readCount; + private bool _closed; private bool _disposed; /// @@ -53,6 +52,7 @@ public virtual void Initialize( _commandId = commandId; _logger = logger; _readCount = 0; + _closed = false; _disposed = false; _startTime = DateTimeOffset.UtcNow; _stopwatch.Restart(); @@ -105,63 +105,116 @@ public virtual Task ReadAsync(CancellationToken cancellationToken = defaul return _reader.ReadAsync(cancellationToken); } + /// + /// Closes the reader. + /// + public virtual void Close() + { + if (_closed) + { + return; + } + + var closeInterceptionResult = default(InterceptionResult); + try + { + if (_logger?.ShouldLogDataReaderClose(DateTimeOffset.UtcNow) == true) + { + closeInterceptionResult = _logger.DataReaderClosing( + _relationalConnection, + _command, + _reader, + _commandId, + _reader.RecordsAffected, + _readCount, + _startTime); // can throw + } + } + finally + { + _closed = true; + + if (!closeInterceptionResult.IsSuppressed) + { + _reader.Close(); // can throw + } + } + } + /// /// Performs application-defined tasks associated with freeing, releasing, or resetting unmanaged resources. /// public virtual void Dispose() { - if (!_disposed) + if (_disposed) + { + return; + } + + var interceptionResult = default(InterceptionResult); + try { - var interceptionResult = default(InterceptionResult); - try + Close(); + + if (_logger?.ShouldLogDataReaderDispose(DateTimeOffset.UtcNow) == true) { - var closeInterceptionResult = default(InterceptionResult); - try - { - if (_logger?.ShouldLogDataReaderClose(DateTimeOffset.UtcNow) == true) - { - closeInterceptionResult = _logger.DataReaderClosing( - _relationalConnection, - _command, - _reader, - _commandId, - _reader.RecordsAffected, - _readCount, - _startTime); // can throw - } - } - finally - { - if (!closeInterceptionResult.IsSuppressed) - { - _reader.Close(); // can throw - } - } - - if (_logger?.ShouldLogDataReaderDispose(DateTimeOffset.UtcNow) == true) - { - interceptionResult = _logger.DataReaderDisposing( - _relationalConnection, - _command, - _reader, - _commandId, - _reader.RecordsAffected, - _readCount, - _startTime, - _stopwatch.Elapsed); // can throw - } + interceptionResult = _logger.DataReaderDisposing( + _relationalConnection, + _command, + _reader, + _commandId, + _reader.RecordsAffected, + _readCount, + _startTime, + _stopwatch.Elapsed); // can throw } - finally + } + finally + { + _disposed = true; + + if (!interceptionResult.IsSuppressed) { - _disposed = true; - - if (!interceptionResult.IsSuppressed) - { - _reader.Dispose(); - _command.Parameters.Clear(); - _command.Dispose(); - _relationalConnection.Close(); - } + _reader.Dispose(); + _command.Parameters.Clear(); + _command.Dispose(); + _relationalConnection.Close(); + } + } + } + + /// + /// Closes the reader. + /// + public virtual async ValueTask CloseAsync() + { + if (_closed) + { + return; + } + + var closeInterceptionResult = default(InterceptionResult); + try + { + if (_logger?.ShouldLogDataReaderClose(DateTimeOffset.UtcNow) == true) + { + closeInterceptionResult = await _logger.DataReaderClosingAsync( + _relationalConnection, + _command, + _reader, + _commandId, + _reader.RecordsAffected, + _readCount, + _startTime).ConfigureAwait(false); // can throw + } + } + finally + { + _closed = true; + + if (!closeInterceptionResult.IsSuppressed) + { + await _reader.CloseAsync().ConfigureAwait(false); // can throw } } } @@ -171,58 +224,47 @@ public virtual void Dispose() /// public virtual async ValueTask DisposeAsync() { - if (!_disposed) + if (_disposed) { - var interceptionResult = default(InterceptionResult); - try + return; + } + + var interceptionResult = default(InterceptionResult); + try + { + // Skip extra async call for most cases + if (_logger?.ShouldLogDataReaderClose(DateTimeOffset.UtcNow) == true) + { + await CloseAsync().ConfigureAwait(false); + } + else { - var closeInterceptionResult = default(InterceptionResult); - try - { - if (_logger?.ShouldLogDataReaderClose(DateTimeOffset.UtcNow) == true) - { - closeInterceptionResult = await _logger.DataReaderClosingAsync( - _relationalConnection, - _command, - _reader, - _commandId, - _reader.RecordsAffected, - _readCount, - _startTime).ConfigureAwait(false); // can throw - } - } - finally - { - if (!closeInterceptionResult.IsSuppressed) - { - await _reader.CloseAsync().ConfigureAwait(false); // can throw - } - } - - if (_logger?.ShouldLogDataReaderDispose(DateTimeOffset.UtcNow) == true) - { - interceptionResult = _logger.DataReaderDisposing( - _relationalConnection, - _command, - _reader, - _commandId, - _reader.RecordsAffected, - _readCount, - _startTime, - _stopwatch.Elapsed); // can throw - } + await _reader.CloseAsync().ConfigureAwait(false); // can throw } - finally + + if (_logger?.ShouldLogDataReaderDispose(DateTimeOffset.UtcNow) == true) + { + interceptionResult = _logger.DataReaderDisposing( + _relationalConnection, + _command, + _reader, + _commandId, + _reader.RecordsAffected, + _readCount, + _startTime, + _stopwatch.Elapsed); // can throw + } + } + finally + { + _disposed = true; + + if (!interceptionResult.IsSuppressed) { - _disposed = true; - - if (!interceptionResult.IsSuppressed) - { - await _reader.DisposeAsync().ConfigureAwait(false); - _command.Parameters.Clear(); - await _command.DisposeAsync().ConfigureAwait(false); - await _relationalConnection.CloseAsync().ConfigureAwait(false); - } + await _reader.DisposeAsync().ConfigureAwait(false); + _command.Parameters.Clear(); + await _command.DisposeAsync().ConfigureAwait(false); + await _relationalConnection.CloseAsync().ConfigureAwait(false); } } } diff --git a/src/EFCore.Relational/Update/AffectedCountModificationCommandBatch.cs b/src/EFCore.Relational/Update/AffectedCountModificationCommandBatch.cs index 9faca89b6a9..1a2c0aec283 100644 --- a/src/EFCore.Relational/Update/AffectedCountModificationCommandBatch.cs +++ b/src/EFCore.Relational/Update/AffectedCountModificationCommandBatch.cs @@ -53,7 +53,7 @@ protected override void Consume(RelationalDataReader reader) { if (onResultSet == false) { - Check.DebugFail("Missing a result set"); + throw new InvalidOperationException(RelationalStrings.MissingResultSetWhenSaving); } var lastHandledCommandIndex = command.RequiresResultPropagation @@ -75,12 +75,15 @@ protected override void Consume(RelationalDataReader reader) } } - Debug.Assert(onResultSet != true, "Unexpected result set found at end"); + if (onResultSet == true) + { + Dependencies.UpdateLogger.UnexpectedTrailingResultSetWhenSaving(); + } + + reader.Close(); if (hasOutputParameters) { - reader.DbDataReader.Close(); - var parameterCounter = 0; IReadOnlyModificationCommand command; @@ -133,7 +136,7 @@ protected override void Consume(RelationalDataReader reader) throw new DbUpdateException( RelationalStrings.UpdateStoreException, ex, - ModificationCommands[commandIndex].Entries); + ModificationCommands[commandIndex < ModificationCommands.Count ? commandIndex : ModificationCommands.Count - 1].Entries); } } @@ -168,7 +171,7 @@ protected override async Task ConsumeAsync( { if (onResultSet == false) { - Check.DebugFail("Missing a result set"); + throw new InvalidOperationException(RelationalStrings.MissingResultSetWhenSaving); } var lastHandledCommandIndex = command.RequiresResultPropagation @@ -190,12 +193,15 @@ protected override async Task ConsumeAsync( } } - Debug.Assert(onResultSet != true, "Unexpected result set found at end"); + if (onResultSet == true) + { + Dependencies.UpdateLogger.UnexpectedTrailingResultSetWhenSaving(); + } + + await reader.CloseAsync().ConfigureAwait(false); if (hasOutputParameters) { - await reader.DbDataReader.CloseAsync().ConfigureAwait(false); - var parameterCounter = 0; IReadOnlyModificationCommand command; @@ -249,7 +255,7 @@ await ThrowAggregateUpdateConcurrencyExceptionAsync( throw new DbUpdateException( RelationalStrings.UpdateStoreException, ex, - ModificationCommands[commandIndex].Entries); + ModificationCommands[commandIndex < ModificationCommands.Count ? commandIndex : ModificationCommands.Count - 1].Entries); } } diff --git a/src/EFCore.Relational/Update/ModificationCommand.cs b/src/EFCore.Relational/Update/ModificationCommand.cs index 67de152450c..b9a9a011451 100644 --- a/src/EFCore.Relational/Update/ModificationCommand.cs +++ b/src/EFCore.Relational/Update/ModificationCommand.cs @@ -866,6 +866,11 @@ public virtual void PropagateResults(RelationalDataReader relationalReader) break; case IStoreStoredProcedureResultColumn resultColumn: + if (ReferenceEquals(RowsAffectedColumn, resultColumn)) + { + continue; + } + // For stored procedure result sets, we need to get the column ordering from metadata. readerIndex = resultColumn.Position; #if DEBUG diff --git a/test/EFCore.Relational.Specification.Tests/TestModels/StoredProcedureUpdateModel/StoredProcedureUpdateContext.cs b/test/EFCore.Relational.Specification.Tests/TestModels/StoredProcedureUpdateModel/StoredProcedureUpdateContext.cs index b2ebb87e1c0..83a22de60d3 100644 --- a/test/EFCore.Relational.Specification.Tests/TestModels/StoredProcedureUpdateModel/StoredProcedureUpdateContext.cs +++ b/test/EFCore.Relational.Specification.Tests/TestModels/StoredProcedureUpdateModel/StoredProcedureUpdateContext.cs @@ -22,6 +22,9 @@ public DbSet WithTwoResultColumns public DbSet WithOutputParameterAndResultColumn => Set(nameof(WithOutputParameterAndResultColumn)); + public DbSet WithOutputParameterAndRowsAffectedResultColumn + => Set(nameof(WithOutputParameterAndRowsAffectedResultColumn)); + public DbSet WithOutputParameterAndResultColumnAndResultValue => Set(nameof(WithOutputParameterAndResultColumnAndResultValue)); diff --git a/test/EFCore.Relational.Specification.Tests/Update/StoredProcedureUpdateFixtureBase.cs b/test/EFCore.Relational.Specification.Tests/Update/StoredProcedureUpdateFixtureBase.cs index 9463d4d6d11..d3e98524fd1 100644 --- a/test/EFCore.Relational.Specification.Tests/Update/StoredProcedureUpdateFixtureBase.cs +++ b/test/EFCore.Relational.Specification.Tests/Update/StoredProcedureUpdateFixtureBase.cs @@ -61,6 +61,21 @@ protected override void OnModelCreating(ModelBuilder modelBuilder, DbContext con .HasResultColumn(w => w.AdditionalProperty)); }); + modelBuilder.SharedTypeEntity( + nameof(StoredProcedureUpdateContext.WithOutputParameterAndRowsAffectedResultColumn), + b => + { + b.Property(w => w.AdditionalProperty).HasComputedColumnSql("8"); + + b.UpdateUsingStoredProcedure( + nameof(StoredProcedureUpdateContext.WithOutputParameterAndRowsAffectedResultColumn) + "_Update", + spb => spb + .HasParameter(w => w.Id) + .HasParameter(w => w.Name) + .HasParameter(w => w.AdditionalProperty, pb => pb.IsOutput()) + .HasRowsAffectedResultColumn()); + }); + modelBuilder.SharedTypeEntity(nameof(StoredProcedureUpdateContext.WithTwoOutputParameters)) .UpdateUsingStoredProcedure( nameof(StoredProcedureUpdateContext.WithTwoOutputParameters) + "_Update", spb => spb diff --git a/test/EFCore.Relational.Specification.Tests/Update/StoredProcedureUpdateTestBase.cs b/test/EFCore.Relational.Specification.Tests/Update/StoredProcedureUpdateTestBase.cs index c127eef6ddf..8ffbcec4085 100644 --- a/test/EFCore.Relational.Specification.Tests/Update/StoredProcedureUpdateTestBase.cs +++ b/test/EFCore.Relational.Specification.Tests/Update/StoredProcedureUpdateTestBase.cs @@ -152,6 +152,31 @@ public virtual async Task Update_partial(bool async) } } + [ConditionalTheory] + [MemberData(nameof(IsAsyncData))] + public virtual async Task Update_with_output_parameter_and_rows_affected_result_column(bool async) + { + await using var context = CreateContext(); + + var entity = new EntityWithAdditionalProperty { Name = "Foo" }; + context.WithOutputParameterAndRowsAffectedResultColumn.Add(entity); + await context.SaveChangesAsync(); + + entity.Name = "Updated"; + + ClearLog(); + + await SaveChanges(context, async); + + using (Fixture.TestSqlLoggerFactory.SuspendRecordingEvents()) + { + var actual = await context.WithOutputParameterAndRowsAffectedResultColumn.SingleAsync(w => w.Id == entity.Id); + + Assert.Equal("Updated", actual.Name); + Assert.Equal(8, actual.AdditionalProperty); + } + } + [ConditionalTheory] [MemberData(nameof(IsAsyncData))] public virtual async Task Delete(bool async) diff --git a/test/EFCore.SqlServer.FunctionalTests/Update/StoredProcedureUpdateSqlServerTest.cs b/test/EFCore.SqlServer.FunctionalTests/Update/StoredProcedureUpdateSqlServerTest.cs index 642e474132f..95fe914f8c7 100644 --- a/test/EFCore.SqlServer.FunctionalTests/Update/StoredProcedureUpdateSqlServerTest.cs +++ b/test/EFCore.SqlServer.FunctionalTests/Update/StoredProcedureUpdateSqlServerTest.cs @@ -115,6 +115,19 @@ public override async Task Update_partial(bool async) EXEC [WithTwoOutputParameters_Update] @p0, @p1, @p2;"); } + public override async Task Update_with_output_parameter_and_rows_affected_result_column(bool async) + { + await base.Update_with_output_parameter_and_rows_affected_result_column(async); + + AssertSql( + @"@p0='1' +@p1='Updated' (Size = 4000) +@p2=NULL (Nullable = false) (Direction = Output) (DbType = Int32) + +SET NOCOUNT ON; +EXEC [WithOutputParameterAndRowsAffectedResultColumn_Update] @p0, @p1, @p2 OUTPUT;"); + } + public override async Task Delete(bool async) { await base.Delete(async); @@ -384,6 +397,7 @@ public override void CleanData() TRUNCATE TABLE [WithOriginalAndCurrentValueOnNonConcurrencyToken]; TRUNCATE TABLE [WithOutputParameter]; TRUNCATE TABLE [WithOutputParameterAndResultColumn]; +TRUNCATE TABLE [WithOutputParameterAndRowsAffectedResultColumn]; TRUNCATE TABLE [WithOutputParameterAndResultColumnAndResultValue]; TRUNCATE TABLE [WithResultColumn]; TRUNCATE TABLE [WithTwoResultColumns]; @@ -458,10 +472,19 @@ AS BEGIN GO +CREATE PROCEDURE WithOutputParameterAndRowsAffectedResultColumn_Update(@Id int, @Name varchar(max), @AdditionalProperty int OUT) +AS BEGIN + UPDATE [WithOutputParameterAndRowsAffectedResultColumn] SET [Name] = @Name, @AdditionalProperty = [AdditionalProperty] WHERE [Id] = @Id; + SELECT @@ROWCOUNT; +END; + +GO + CREATE PROCEDURE WithTwoOutputParameters_Update(@Id int, @Name varchar(max), @AdditionalProperty int) AS UPDATE [WithTwoOutputParameters] SET [Name] = @Name, [AdditionalProperty] = @AdditionalProperty WHERE [Id] = @id; GO + CREATE PROCEDURE WithRowsAffectedParameter_Update(@Id int, @Name varchar(max), @RowsAffected int OUT) AS BEGIN UPDATE [WithRowsAffectedParameter] SET [Name] = @Name WHERE [Id] = @Id;