EF Core Querying Every DbSet Under Certain Circumstances

Question

EF Core Querying Every DbSet Under Certain Circumstances

scottsauber opened this issue 6 years ago · 10 comments

This was originally logged at #13310 and #15000. /cc @rosspace, @ajcvickers, and @divega who were involved in the originals.

Error:
When I hit a SQL exception of some sort in certain scenarios, such as a foreign key violation or a length exceeded, EF Core goes haywire and starts querying every DbSet in the DbContext. This causes my server(s) to run out of memory.

In tracking this down, I found that this happens when the following are true:

Pending update for AT LEAST two different entities
The SQL exception occurs for a 3rd entity AND AT LEAST two records of that entity.

I will come up with a minimal repro in the coming days that has all the data seeded and all that, but I figured I'd log this to give a head start on this.

Steps to reproduce

The code below throws an error. Note, it will not behave this way if there is only one other valid entity pending an update (below the user and role variables are pending an update). And it will not behave this way if there is only one UserRole with a SQL issue (i.e. if you switch the i < 2 to i < 1 it will not have this issue).

    [AllowAnonymous]
    public class IndexModel : PageModel
    {
        private readonly ApplicationDbContext _dbContext;

        public IndexModel(ApplicationDbContext dbContext)
        {
            _dbContext = dbContext;
        }

        public async Task<IActionResult> OnGet()
        {   
            // First update pending
            var user = await _dbContext.Users.FirstOrDefaultAsync();
            user.PhoneNumber = user.PhoneNumber == "5551234567" ? "2221234567" : "5551234567";

            // Second update pending
            var role = await _dbContext.Roles.FirstOrDefaultAsync();
            role.ConcurrencyStamp = Guid.NewGuid().ToString();

            // Foreign key issue
            for (int i = 0; i < 2; i++)
            {
                var userRole = new BenefitsPortalUserRole
                {
                    UserId = "0f7183fd-94f6-40de-9ee4-e30f4d3b6167",
                    RoleId = Guid.NewGuid().ToString() // this role ID is not valid
                };

                _dbContext.UserRoles.Add(userRole);
            }

           await _dbContext.SaveChangesAsync();
            
            return Page();
        }
    }

Below is the logs from running this. You can see it queries all the DbSets (in this case, I only have the Identity DbSets in my DbContext) like it queries the Application_User_External_Tokens even though that's not involved in this at all. It looks like it does this twice. I have bolded where it happens below.

EfCoreRepro> [23:56:38 INF] Request starting HTTP/1.1 GET http://localhost:44325/
EfCoreRepro> [23:56:38 INF] Route matched with {page = "/Index", action = "", controller = ""}. Executing action /Index
EfCoreRepro> [23:56:38 INF] Executing handler method OnGet with arguments (null) - ModelState is Valid
EfCoreRepro> [23:56:38 INF] Entity Framework Core 2.1.8-servicing-32085 initialized 'ApplicationDbContext' using provider 'Microsoft.EntityFrameworkCore.SqlServer' with options: None
EfCoreRepro> [23:56:38 INF] Executed DbCommand (41ms) [Parameters=[], CommandType='Text', CommandTimeout='30']
EfCoreRepro> SELECT TOP(1) [g].[Id], [g].[AccessFailedCount], [g].[ConcurrencyStamp], [g].[Email], [g].[EmailConfirmed], [g].[LockoutEnabled], [g].[LockoutEnd], [g].[NeedsToChangePassword], [g].[NormalizedEmail], [g].[NormalizedUserName], [g].[PasswordHash], [g].[PersonId], [g].[PhoneNumber], [g].[PhoneNumberConfirmed], [g].[SecurityStamp], [g].[TwoFactorEnabled], [g].[UserName]
EfCoreRepro> FROM [Application_Users] AS [g]
EfCoreRepro> [23:56:38 INF] Executed DbCommand (39ms) [Parameters=[], CommandType='Text', CommandTimeout='30']
EfCoreRepro> SELECT TOP(1) [g].[Id], [g].[ConcurrencyStamp], [g].[Name], [g].[NormalizedName]
EfCoreRepro> FROM [Application_Roles] AS [g]
EfCoreRepro> [23:56:38 INF] Executed DbCommand (48ms) [Parameters=[@p1='?' (Size = 450), @p0='?' (Size = 8000) (DbType = AnsiString), @p2='?' (Size = 100) (DbType = AnsiString), @p3='?' (DbType = Int32), @P4='?' (Size = 8000) (DbType = AnsiString), @p5='?' (Size = 100) (DbType = AnsiString), @p6='?' (DbType = Int32), @P7='?' (Size = 900) (DbType = AnsiString), @p8='?' (Size = 100) (DbType = AnsiString), @p9='?' (DbType = Int32), @p10='?' (Size = 8000) (DbType = AnsiString), @p11='?' (Size = 100) (DbType = AnsiString), @p12='?' (DbType = Int32), @P13='?' (Size = 900) (DbType = AnsiString), @P15='?' (Size = 450), @p16='?' (Size = 8000) (DbType = AnsiString), @p14='?' (Size = 15) (DbType = AnsiString)], CommandType='Text', CommandTimeout='30']
EfCoreRepro> SET NOCOUNT ON;
EfCoreRepro> UPDATE [Application_Roles] SET [ConcurrencyStamp] = @p0
EfCoreRepro> WHERE [Id] = @p1;
EfCoreRepro> SELECT @@rowcount;
EfCoreRepro>
EfCoreRepro> DECLARE @inserted1 TABLE ([Id] bigint, [_Position] [int]);
EfCoreRepro> MERGE [Application_User_Roles] USING (
EfCoreRepro> VALUES (@p2, @p3, @P4, @p5, @p6, @P7, 0),
EfCoreRepro> (@p8, @p9, @p10, @p11, @p12, @P13, 1)) AS i ([EmployerGuid], [EmployerId], [RoleId], [SubgroupGuid], [SubgroupId], [UserId], _Position) ON 1=0
EfCoreRepro> WHEN NOT MATCHED THEN
EfCoreRepro> INSERT ([EmployerGuid], [EmployerId], [RoleId], [SubgroupGuid], [SubgroupId], [UserId])
EfCoreRepro> VALUES (i.[EmployerGuid], i.[EmployerId], i.[RoleId], i.[SubgroupGuid], i.[SubgroupId], i.[UserId])
EfCoreRepro> OUTPUT INSERTED.[Id], i._Position
EfCoreRepro> INTO @inserted1;
EfCoreRepro>
EfCoreRepro> SELECT [t].[Id] FROM [Application_User_Roles] t
EfCoreRepro> INNER JOIN @inserted1 i ON ([t].[Id] = [i].[Id])
EfCoreRepro> ORDER BY [i].[_Position];
EfCoreRepro>
EfCoreRepro> UPDATE [Application_Users] SET [PhoneNumber] = @p14
EfCoreRepro> WHERE [Id] = @P15 AND [ConcurrencyStamp] = @p16;
EfCoreRepro> SELECT @@rowcount;
EfCoreRepro> [23:56:38 INF] Executed DbCommand (43ms) [Parameters=[], CommandType='Text', CommandTimeout='30']
EfCoreRepro> SELECT [g].[Id], [g].[EmployerGuid], [g].[EmployerId], [g].[RoleId], [g].[SubgroupGuid], [g].[SubgroupId], [g].[UserId]
EfCoreRepro> FROM [Application_User_Roles] AS [g]
EfCoreRepro> [23:56:38 ERR] An exception occurred in the database while iterating the results of a query for context type 'Entities.ApplicationDbContext'.
EfCoreRepro> System.InvalidOperationException: An exception occurred while reading a database value for property 'ApplicationUserRole.EmployerId'. The expected type was 'System.Int32' but the actual value was null. ---> System.NullReferenceException: Object reference not set to an instance of an object.
EfCoreRepro> at Microsoft.EntityFrameworkCore.Metadata.Internal.EntityMaterializerSource.TryReadValue[TValue](ValueBuffer& valueBuffer, Int32 index, IPropertyBase property)
EfCoreRepro> --- End of inner exception stack trace ---
EfCoreRepro> at Microsoft.EntityFrameworkCore.Metadata.Internal.EntityMaterializerSource.ThrowReadValueException[TValue](Exception exception, Object value, IPropertyBase property)
EfCoreRepro> at Microsoft.EntityFrameworkCore.Metadata.Internal.EntityMaterializerSource.TryReadValue[TValue](ValueBuffer& valueBuffer, Int32 index, IPropertyBase property)
EfCoreRepro> at lambda_method(Closure , MaterializationContext )
EfCoreRepro> at Microsoft.EntityFrameworkCore.Query.ExpressionVisitors.Internal.UnbufferedEntityShaper1.Shape(QueryContext queryContext, ValueBuffer& valueBuffer) EfCoreRepro> at Microsoft.EntityFrameworkCore.Query.Internal.QueryingEnumerable1.Enumerator.BufferlessMoveNext(DbContext _, Boolean buffer)
EfCoreRepro> at Microsoft.EntityFrameworkCore.SqlServer.Storage.Internal.SqlServerExecutionStrategy.Execute[TState,TResult](TState state, Func3 operation, Func3 verifySucceeded)
EfCoreRepro> at Microsoft.EntityFrameworkCore.Query.Internal.QueryingEnumerable1.Enumerator.MoveNext() EfCoreRepro> at Microsoft.EntityFrameworkCore.Query.Internal.LinqOperatorProvider._TrackEntities[TOut,TIn](IEnumerable1 results, QueryContext queryContext, IList1 entityTrackingInfos, IList1 entityAccessors)+MoveNext()
EfCoreRepro> at Microsoft.EntityFrameworkCore.Query.Internal.LinqOperatorProvider.ExceptionInterceptor1.EnumeratorExceptionInterceptor.MoveNext() EfCoreRepro> System.InvalidOperationException: An exception occurred while reading a database value for property 'ApplicationUserRole.EmployerId'. The expected type was 'System.Int32' but the actual value was null. ---> System.NullReferenceException: Object reference not set to an instance of an object. EfCoreRepro> at Microsoft.EntityFrameworkCore.Metadata.Internal.EntityMaterializerSource.TryReadValue[TValue](ValueBuffer& valueBuffer, Int32 index, IPropertyBase property) EfCoreRepro> --- End of inner exception stack trace --- EfCoreRepro> at Microsoft.EntityFrameworkCore.Metadata.Internal.EntityMaterializerSource.ThrowReadValueException[TValue](Exception exception, Object value, IPropertyBase property) EfCoreRepro> at Microsoft.EntityFrameworkCore.Metadata.Internal.EntityMaterializerSource.TryReadValue[TValue](ValueBuffer& valueBuffer, Int32 index, IPropertyBase property) EfCoreRepro> at lambda_method(Closure , MaterializationContext ) EfCoreRepro> at Microsoft.EntityFrameworkCore.Query.ExpressionVisitors.Internal.UnbufferedEntityShaper1.Shape(QueryContext queryContext, ValueBuffer& valueBuffer)
EfCoreRepro> at Microsoft.EntityFrameworkCore.Query.Internal.QueryingEnumerable1.Enumerator.BufferlessMoveNext(DbContext _, Boolean buffer) EfCoreRepro> at Microsoft.EntityFrameworkCore.SqlServer.Storage.Internal.SqlServerExecutionStrategy.Execute[TState,TResult](TState state, Func3 operation, Func3 verifySucceeded) EfCoreRepro> at Microsoft.EntityFrameworkCore.Query.Internal.QueryingEnumerable1.Enumerator.MoveNext()
EfCoreRepro> at Microsoft.EntityFrameworkCore.Query.Internal.LinqOperatorProvider._TrackEntities[TOut,TIn](IEnumerable1 results, QueryContext queryContext, IList1 entityTrackingInfos, IList1 entityAccessors)+MoveNext() EfCoreRepro> at Microsoft.EntityFrameworkCore.Query.Internal.LinqOperatorProvider.ExceptionInterceptor1.EnumeratorExceptionInterceptor.MoveNext()
EfCoreRepro> [23:56:38 INF] Executed DbCommand (41ms) [Parameters=[], CommandType='Text', CommandTimeout='30']
EfCoreRepro> SELECT [g].[Id], [g].[ConcurrencyStamp], [g].[Name], [g].[NormalizedName]
EfCoreRepro> FROM [Application_Roles] AS [g]
EfCoreRepro> [23:56:38 INF] Executed DbCommand (42ms) [Parameters=[], CommandType='Text', CommandTimeout='30']
EfCoreRepro> SELECT [g].[Id], [g].[ClaimType], [g].[ClaimValue], [g].[RoleId]
EfCoreRepro> FROM [Application_Role_Claims] AS [g]
EfCoreRepro> [23:56:38 INF] Executed DbCommand (39ms) [Parameters=[], CommandType='Text', CommandTimeout='30']
EfCoreRepro> SELECT [g].[Id], [g].[AccessFailedCount], [g].[ConcurrencyStamp], [g].[Email], [g].[EmailConfirmed], [g].[LockoutEnabled], [g].[LockoutEnd], [g].[NeedsToChangePassword], [g].[NormalizedEmail], [g].[NormalizedUserName], [g].[PasswordHash], [g].[PersonId], [g].[PhoneNumber], [g].[PhoneNumberConfirmed], [g].[SecurityStamp], [g].[TwoFactorEnabled], [g].[UserName]
EfCoreRepro> FROM [Application_Users] AS [g]
EfCoreRepro> [23:56:38 INF] Executed DbCommand (40ms) [Parameters=[], CommandType='Text', CommandTimeout='30']
EfCoreRepro> SELECT [g].[Id], [g].[ClaimType], [g].[ClaimValue], [g].[UserId]
EfCoreRepro> FROM [Application_User_Claims] AS [g]
EfCoreRepro> [23:56:38 INF] Executed DbCommand (41ms) [Parameters=[], CommandType='Text', CommandTimeout='30']
EfCoreRepro> SELECT [g].[LoginProvider], [g].[ProviderKey], [g].[ProviderDisplayName], [g].[UserId]
EfCoreRepro> FROM [Application_User_External_Logins] AS [g]
EfCoreRepro> [23:56:38 INF] Executed DbCommand (40ms) [Parameters=[], CommandType='Text', CommandTimeout='30']
EfCoreRepro> SELECT [g].[UserId], [g].[LoginProvider], [g].[Name], [g].[Value]
EfCoreRepro> FROM [Application_User_External_Tokens] AS [g]
EfCoreRepro> [23:56:38 ERR] An exception occurred in the database while saving changes for context type 'Entities.ApplicationDbContext'.
EfCoreRepro> Microsoft.EntityFrameworkCore.DbUpdateException: An error occurred while updating the entries. See the inner exception for details. ---> System.Data.SqlClient.SqlException: The MERGE statement conflicted with the FOREIGN KEY constraint "FK_PortalUserRoles_PortalRoles_RoleId". The conflict occurred in database "EfCoreRepro", table "dbo.Application_Roles", column 'Id'.
EfCoreRepro> at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action1 wrapCloseInAction) EfCoreRepro> at System.Data.SqlClient.SqlInternalConnection.OnError(SqlException exception, Boolean breakConnection, Action1 wrapCloseInAction)
EfCoreRepro> at System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj, Boolean callerHasConnectionLock, Boolean asyncClose)
EfCoreRepro> at System.Data.SqlClient.TdsParser.TryRun(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj, Boolean& dataReady)
EfCoreRepro> at System.Data.SqlClient.SqlDataReader.TryHasMoreRows(Boolean& moreRows)
EfCoreRepro> at System.Data.SqlClient.SqlDataReader.TryHasMoreResults(Boolean& moreResults)
EfCoreRepro> at System.Data.SqlClient.SqlDataReader.TryNextResult(Boolean& more)
EfCoreRepro> at System.Data.SqlClient.SqlDataReader.<>c__DisplayClass187_0.b__1(Task t)
EfCoreRepro> at System.Data.SqlClient.SqlDataReader.InvokeRetryable[T](Func2 moreFunc, TaskCompletionSource1 source, IDisposable objectToDispose)
EfCoreRepro> --- End of stack trace from previous location where exception was thrown ---
EfCoreRepro> at Microsoft.EntityFrameworkCore.Update.AffectedCountModificationCommandBatch.ConsumeAsync(RelationalDataReader reader, CancellationToken cancellationToken)
EfCoreRepro> --- End of inner exception stack trace ---
EfCoreRepro> at Microsoft.EntityFrameworkCore.Update.AffectedCountModificationCommandBatch.ConsumeAsync(RelationalDataReader reader, CancellationToken cancellationToken)
EfCoreRepro> at Microsoft.EntityFrameworkCore.Update.ReaderModificationCommandBatch.ExecuteAsync(IRelationalConnection connection, CancellationToken cancellationToken)
EfCoreRepro> at Microsoft.EntityFrameworkCore.Update.Internal.BatchExecutor.ExecuteAsync(DbContext _, ValueTuple2 parameters, CancellationToken cancellationToken) EfCoreRepro> at Microsoft.EntityFrameworkCore.SqlServer.Storage.Internal.SqlServerExecutionStrategy.ExecuteAsync[TState,TResult](TState state, Func4 operation, Func4 verifySucceeded, CancellationToken cancellationToken) EfCoreRepro> at Microsoft.EntityFrameworkCore.ChangeTracking.Internal.StateManager.SaveChangesAsync(IReadOnlyList1 entriesToSave, CancellationToken cancellationToken)
EfCoreRepro> at Microsoft.EntityFrameworkCore.ChangeTracking.Internal.StateManager.SaveChangesAsync(Boolean acceptAllChangesOnSuccess, CancellationToken cancellationToken)
EfCoreRepro> at Microsoft.EntityFrameworkCore.DbContext.SaveChangesAsync(Boolean acceptAllChangesOnSuccess, CancellationToken cancellationToken)
EfCoreRepro> Microsoft.EntityFrameworkCore.DbUpdateException: An error occurred while updating the entries. See the inner exception for details. ---> System.Data.SqlClient.SqlException: The MERGE statement conflicted with the FOREIGN KEY constraint "FK_PortalUserRoles_PortalRoles_RoleId". The conflict occurred in database "EfCoreRepro", table "dbo.Application_Roles", column 'Id'.
EfCoreRepro> at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action1 wrapCloseInAction) EfCoreRepro> at System.Data.SqlClient.SqlInternalConnection.OnError(SqlException exception, Boolean breakConnection, Action1 wrapCloseInAction)
EfCoreRepro> at System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj, Boolean callerHasConnectionLock, Boolean asyncClose)
EfCoreRepro> at System.Data.SqlClient.TdsParser.TryRun(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj, Boolean& dataReady)
EfCoreRepro> at System.Data.SqlClient.SqlDataReader.TryHasMoreRows(Boolean& moreRows)
EfCoreRepro> at System.Data.SqlClient.SqlDataReader.TryHasMoreResults(Boolean& moreResults)
EfCoreRepro> at System.Data.SqlClient.SqlDataReader.TryNextResult(Boolean& more)
EfCoreRepro> at System.Data.SqlClient.SqlDataReader.<>c__DisplayClass187_0.b__1(Task t)
EfCoreRepro> at System.Data.SqlClient.SqlDataReader.InvokeRetryable[T](Func2 moreFunc, TaskCompletionSource1 source, IDisposable objectToDispose)
EfCoreRepro> --- End of stack trace from previous location where exception was thrown ---
EfCoreRepro> at Microsoft.EntityFrameworkCore.Update.AffectedCountModificationCommandBatch.ConsumeAsync(RelationalDataReader reader, CancellationToken cancellationToken)
EfCoreRepro> --- End of inner exception stack trace ---
EfCoreRepro> at Microsoft.EntityFrameworkCore.Update.AffectedCountModificationCommandBatch.ConsumeAsync(RelationalDataReader reader, CancellationToken cancellationToken)
EfCoreRepro> at Microsoft.EntityFrameworkCore.Update.ReaderModificationCommandBatch.ExecuteAsync(IRelationalConnection connection, CancellationToken cancellationToken)
EfCoreRepro> at Microsoft.EntityFrameworkCore.Update.Internal.BatchExecutor.ExecuteAsync(DbContext _, ValueTuple2 parameters, CancellationToken cancellationToken) EfCoreRepro> at Microsoft.EntityFrameworkCore.SqlServer.Storage.Internal.SqlServerExecutionStrategy.ExecuteAsync[TState,TResult](TState state, Func4 operation, Func4 verifySucceeded, CancellationToken cancellationToken) EfCoreRepro> at Microsoft.EntityFrameworkCore.ChangeTracking.Internal.StateManager.SaveChangesAsync(IReadOnlyList1 entriesToSave, CancellationToken cancellationToken)
EfCoreRepro> at Microsoft.EntityFrameworkCore.ChangeTracking.Internal.StateManager.SaveChangesAsync(Boolean acceptAllChangesOnSuccess, CancellationToken cancellationToken)
EfCoreRepro> at Microsoft.EntityFrameworkCore.DbContext.SaveChangesAsync(Boolean acceptAllChangesOnSuccess, CancellationToken cancellationToken)
EfCoreRepro> [23:56:38 INF] Executed action /Index in 526.8129ms
EfCoreRepro> [23:56:38 INF] Executed DbCommand (39ms) [Parameters=[], CommandType='Text', CommandTimeout='30']
EfCoreRepro> SELECT OBJECT_ID(N'[__EFMigrationsHistory]');
EfCoreRepro> [23:56:38 INF] Executed DbCommand (41ms) [Parameters=[], CommandType='Text', CommandTimeout='30']
EfCoreRepro> SELECT [g].[Id], [g].[EmployerGuid], [g].[EmployerId], [g].[RoleId], [g].[SubgroupGuid], [g].[SubgroupId], [g].[UserId]
EfCoreRepro> FROM [Application_User_Roles] AS [g]
EfCoreRepro> [23:56:38 ERR] An exception occurred in the database while iterating the results of a query for context type 'Entities.ApplicationDbContext'.
EfCoreRepro> System.InvalidOperationException: An exception occurred while reading a database value for property 'ApplicationUserRole.EmployerId'. The expected type was 'System.Int32' but the actual value was null. ---> System.NullReferenceException: Object reference not set to an instance of an object.
EfCoreRepro> at Microsoft.EntityFrameworkCore.Metadata.Internal.EntityMaterializerSource.TryReadValue[TValue](ValueBuffer& valueBuffer, Int32 index, IPropertyBase property)
EfCoreRepro> --- End of inner exception stack trace ---
EfCoreRepro> at Microsoft.EntityFrameworkCore.Metadata.Internal.EntityMaterializerSource.ThrowReadValueException[TValue](Exception exception, Object value, IPropertyBase property)
EfCoreRepro> at Microsoft.EntityFrameworkCore.Metadata.Internal.EntityMaterializerSource.TryReadValue[TValue](ValueBuffer& valueBuffer, Int32 index, IPropertyBase property)
EfCoreRepro> at lambda_method(Closure , MaterializationContext )
EfCoreRepro> at Microsoft.EntityFrameworkCore.Query.ExpressionVisitors.Internal.UnbufferedEntityShaper1.Shape(QueryContext queryContext, ValueBuffer& valueBuffer) EfCoreRepro> at Microsoft.EntityFrameworkCore.Query.Internal.QueryingEnumerable1.Enumerator.BufferlessMoveNext(DbContext _, Boolean buffer)
EfCoreRepro> at Microsoft.EntityFrameworkCore.SqlServer.Storage.Internal.SqlServerExecutionStrategy.Execute[TState,TResult](TState state, Func3 operation, Func3 verifySucceeded)
EfCoreRepro> at Microsoft.EntityFrameworkCore.Query.Internal.QueryingEnumerable1.Enumerator.MoveNext() EfCoreRepro> at Microsoft.EntityFrameworkCore.Query.Internal.LinqOperatorProvider._TrackEntities[TOut,TIn](IEnumerable1 results, QueryContext queryContext, IList1 entityTrackingInfos, IList1 entityAccessors)+MoveNext()
EfCoreRepro> at Microsoft.EntityFrameworkCore.Query.Internal.LinqOperatorProvider.ExceptionInterceptor1.EnumeratorExceptionInterceptor.MoveNext() EfCoreRepro> System.InvalidOperationException: An exception occurred while reading a database value for property 'ApplicationUserRole.EmployerId'. The expected type was 'System.Int32' but the actual value was null. ---> System.NullReferenceException: Object reference not set to an instance of an object. EfCoreRepro> at Microsoft.EntityFrameworkCore.Metadata.Internal.EntityMaterializerSource.TryReadValue[TValue](ValueBuffer& valueBuffer, Int32 index, IPropertyBase property) EfCoreRepro> --- End of inner exception stack trace --- EfCoreRepro> at Microsoft.EntityFrameworkCore.Metadata.Internal.EntityMaterializerSource.ThrowReadValueException[TValue](Exception exception, Object value, IPropertyBase property) EfCoreRepro> at Microsoft.EntityFrameworkCore.Metadata.Internal.EntityMaterializerSource.TryReadValue[TValue](ValueBuffer& valueBuffer, Int32 index, IPropertyBase property) EfCoreRepro> at lambda_method(Closure , MaterializationContext ) EfCoreRepro> at Microsoft.EntityFrameworkCore.Query.ExpressionVisitors.Internal.UnbufferedEntityShaper1.Shape(QueryContext queryContext, ValueBuffer& valueBuffer)
EfCoreRepro> at Microsoft.EntityFrameworkCore.Query.Internal.QueryingEnumerable1.Enumerator.BufferlessMoveNext(DbContext _, Boolean buffer) EfCoreRepro> at Microsoft.EntityFrameworkCore.SqlServer.Storage.Internal.SqlServerExecutionStrategy.Execute[TState,TResult](TState state, Func3 operation, Func3 verifySucceeded) EfCoreRepro> at Microsoft.EntityFrameworkCore.Query.Internal.QueryingEnumerable1.Enumerator.MoveNext()
EfCoreRepro> at Microsoft.EntityFrameworkCore.Query.Internal.LinqOperatorProvider._TrackEntities[TOut,TIn](IEnumerable1 results, QueryContext queryContext, IList1 entityTrackingInfos, IList1 entityAccessors)+MoveNext() EfCoreRepro> at Microsoft.EntityFrameworkCore.Query.Internal.LinqOperatorProvider.ExceptionInterceptor1.EnumeratorExceptionInterceptor.MoveNext()
EfCoreRepro> [23:56:38 INF] Executed DbCommand (43ms) [Parameters=[], CommandType='Text', CommandTimeout='30']
EfCoreRepro> SELECT [g].[Id], [g].[ConcurrencyStamp], [g].[Name], [g].[NormalizedName]
EfCoreRepro> FROM [Application_Roles] AS [g]
EfCoreRepro> [23:56:38 INF] Executed DbCommand (38ms) [Parameters=[], CommandType='Text', CommandTimeout='30']
EfCoreRepro> SELECT [g].[Id], [g].[ClaimType], [g].[ClaimValue], [g].[RoleId]
EfCoreRepro> FROM [Application_Role_Claims] AS [g]
EfCoreRepro> [23:56:38 INF] Executed DbCommand (40ms) [Parameters=[], CommandType='Text', CommandTimeout='30']
EfCoreRepro> SELECT [g].[Id], [g].[AccessFailedCount], [g].[ConcurrencyStamp], [g].[Email], [g].[EmailConfirmed], [g].[LockoutEnabled], [g].[LockoutEnd], [g].[NeedsToChangePassword], [g].[NormalizedEmail], [g].[NormalizedUserName], [g].[PasswordHash], [g].[PersonId], [g].[PhoneNumber], [g].[PhoneNumberConfirmed], [g].[SecurityStamp], [g].[TwoFactorEnabled], [g].[UserName]
EfCoreRepro> FROM [Application_Users] AS [g]
EfCoreRepro> [23:56:39 INF] Executed DbCommand (42ms) [Parameters=[], CommandType='Text', CommandTimeout='30']
EfCoreRepro> SELECT [g].[Id], [g].[ClaimType], [g].[ClaimValue], [g].[UserId]
EfCoreRepro> FROM [Application_User_Claims] AS [g]
EfCoreRepro> [23:56:39 INF] Executed DbCommand (48ms) [Parameters=[], CommandType='Text', CommandTimeout='30']
EfCoreRepro> SELECT [g].[LoginProvider], [g].[ProviderKey], [g].[ProviderDisplayName], [g].[UserId]
EfCoreRepro> FROM [Application_User_External_Logins] AS [g]
EfCoreRepro> [23:56:39 INF] Executed DbCommand (40ms) [Parameters=[], CommandType='Text', CommandTimeout='30']
EfCoreRepro> SELECT [g].[UserId], [g].[LoginProvider], [g].[Name], [g].[Value]
EfCoreRepro> FROM [Application_User_External_Tokens] AS [g]
EfCoreRepro> [23:56:38 ERR] An unhandled exception has occurred while executing the request.
EfCoreRepro> Microsoft.EntityFrameworkCore.DbUpdateException: An error occurred while updating the entries. See the inner exception for details. ---> System.Data.SqlClient.SqlException: The MERGE statement conflicted with the FOREIGN KEY constraint "FK_PortalUserRoles_PortalRoles_RoleId". The conflict occurred in database "EfCoreRepro", table "dbo.Application_Roles", column 'Id'.
EfCoreRepro> at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action1 wrapCloseInAction) EfCoreRepro> at System.Data.SqlClient.SqlInternalConnection.OnError(SqlException exception, Boolean breakConnection, Action1 wrapCloseInAction)
EfCoreRepro> at System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj, Boolean callerHasConnectionLock, Boolean asyncClose)
EfCoreRepro> at System.Data.SqlClient.TdsParser.TryRun(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj, Boolean& dataReady)
EfCoreRepro> at System.Data.SqlClient.SqlDataReader.TryHasMoreRows(Boolean& moreRows)
EfCoreRepro> at System.Data.SqlClient.SqlDataReader.TryHasMoreResults(Boolean& moreResults)
EfCoreRepro> at System.Data.SqlClient.SqlDataReader.TryNextResult(Boolean& more)
EfCoreRepro> at System.Data.SqlClient.SqlDataReader.<>c__DisplayClass187_0.b__1(Task t)
EfCoreRepro> at System.Data.SqlClient.SqlDataReader.InvokeRetryable[T](Func2 moreFunc, TaskCompletionSource1 source, IDisposable objectToDispose)
EfCoreRepro> --- End of stack trace from previous location where exception was thrown ---
EfCoreRepro> at Microsoft.EntityFrameworkCore.Update.AffectedCountModificationCommandBatch.ConsumeAsync(RelationalDataReader reader, CancellationToken cancellationToken)
EfCoreRepro> --- End of inner exception stack trace ---
EfCoreRepro> at Microsoft.EntityFrameworkCore.Update.AffectedCountModificationCommandBatch.ConsumeAsync(RelationalDataReader reader, CancellationToken cancellationToken)
EfCoreRepro> at Microsoft.EntityFrameworkCore.Update.ReaderModificationCommandBatch.ExecuteAsync(IRelationalConnection connection, CancellationToken cancellationToken)
EfCoreRepro> at Microsoft.EntityFrameworkCore.Update.Internal.BatchExecutor.ExecuteAsync(DbContext _, ValueTuple2 parameters, CancellationToken cancellationToken) EfCoreRepro> at Microsoft.EntityFrameworkCore.SqlServer.Storage.Internal.SqlServerExecutionStrategy.ExecuteAsync[TState,TResult](TState state, Func4 operation, Func4 verifySucceeded, CancellationToken cancellationToken) EfCoreRepro> at Microsoft.EntityFrameworkCore.ChangeTracking.Internal.StateManager.SaveChangesAsync(IReadOnlyList1 entriesToSave, CancellationToken cancellationToken)
EfCoreRepro> at Microsoft.EntityFrameworkCore.ChangeTracking.Internal.StateManager.SaveChangesAsync(Boolean acceptAllChangesOnSuccess, CancellationToken cancellationToken)
EfCoreRepro> at Microsoft.EntityFrameworkCore.DbContext.SaveChangesAsync(Boolean acceptAllChangesOnSuccess, CancellationToken cancellationToken)
EfCoreRepro> at EfCoreRepro.Pages.IndexModel.OnGet() in C:\dev\EfCoreRepro\EfCoreRepro\Pages\Index.cshtml.cs:line 44
EfCoreRepro> at Microsoft.AspNetCore.Mvc.RazorPages.Internal.ExecutorFactory.GenericTaskHandlerMethod.Convert[T](Object taskAsObject)
EfCoreRepro> at Microsoft.AspNetCore.Mvc.RazorPages.Internal.ExecutorFactory.GenericTaskHandlerMethod.Execute(Object receiver, Object[] arguments)
EfCoreRepro> at Microsoft.AspNetCore.Mvc.RazorPages.Internal.PageActionInvoker.InvokeHandlerMethodAsync()
EfCoreRepro> at Microsoft.AspNetCore.Mvc.RazorPages.Internal.PageActionInvoker.InvokeNextPageFilterAsync()
EfCoreRepro> at Microsoft.AspNetCore.Mvc.RazorPages.Internal.PageActionInvoker.Rethrow(PageHandlerExecutedContext context)
EfCoreRepro> at Microsoft.AspNetCore.Mvc.RazorPages.Internal.PageActionInvoker.Next(State& next, Scope& scope, Object& state, Boolean& isCompleted)
EfCoreRepro> at Microsoft.AspNetCore.Mvc.RazorPages.Internal.PageActionInvoker.InvokeInnerFilterAsync()
EfCoreRepro> at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker.InvokeNextResourceFilter()
EfCoreRepro> at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker.Rethrow(ResourceExecutedContext context)
EfCoreRepro> at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker.Next(State& next, Scope& scope, Object& state, Boolean& isCompleted)
EfCoreRepro> at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker.InvokeFilterPipelineAsync()
EfCoreRepro> at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker.InvokeAsync()
EfCoreRepro> at Microsoft.AspNetCore.Builder.RouterMiddleware.Invoke(HttpContext httpContext)
EfCoreRepro> at Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware.Invoke(HttpContext context)
EfCoreRepro> at StackExchange.Profiling.MiniProfilerMiddleware.Invoke(HttpContext context) in C:\projects\dotnet\src\MiniProfiler.AspNetCore\MiniProfilerMiddleware.cs:line 86
EfCoreRepro> at Microsoft.AspNetCore.Diagnostics.EntityFrameworkCore.MigrationsEndPointMiddleware.Invoke(HttpContext context)
EfCoreRepro> at Microsoft.AspNetCore.Diagnostics.EntityFrameworkCore.DatabaseErrorPageMiddleware.Invoke(HttpContext httpContext)
EfCoreRepro> at Microsoft.AspNetCore.Diagnostics.EntityFrameworkCore.DatabaseErrorPageMiddleware.Invoke(HttpContext httpContext)
EfCoreRepro> at Microsoft.AspNetCore.Diagnostics.DeveloperExceptionPageMiddleware.Invoke(HttpContext context)
EfCoreRepro> [23:56:39 INF] Request finished in 902.2378ms 500 text/html; charset=utf-8
EfCoreRepro> [23:56:39 INF] Request starting HTTP/1.1 GET http://localhost:44325/favicon.ico
EfCoreRepro> [23:56:39 INF] Sending file. Request path: '/favicon.ico'. Physical path: 'C:\dev\EfCoreRepro\EfCoreRepro\wwwroot\favicon.ico'
EfCoreRepro> [23:56:39 INF] Request finished in 23.8229ms 200 image/x-icon

When I have a real DbContext with lots of DbSets and tons of data in them, this essentially will eat all the memory on my server, although I've set my IIS App Pool to auto-restart after it hits 2GB to mitigate this issue.

Further technical details

EF Core version: 2.1.8
Database Provider: Microsoft.EntityFrameworkCore.SqlServer
Operating system: Windows 10
IDE: VS 2017 15.9.7

Answer 1 · 2019-03-31T13:56:21.000Z

Have you tried/tested with EF Core 2.2.3 ?

Answer 2 · 2019-03-31T19:28:39.000Z

@ErikEJ - yes I can confirm it happens on EF Core 2.2.3 as well.. I will use that in my minimal repro I'm creating now.

Answer 3 · 2019-03-31T21:09:12.000Z

I have a theory, but haven't verified it yet. If something tries to serialize the DbUpdateException, then it might attempt to traverse the entire graph of objects associated with the exception. This would result in attempting to read all properties of the DbContext, which in turn means that every DbSet property will be potentially read and then enumerated.

In EF6, DbUpdateException had custom serialization code. Most of the serialization APIs were not even present in the PCL targets that EF Core started with, and we didn't go back and add anything as more things came back to core. We probably need to do this now.

Answer 4 · 2019-03-31T21:58:17.000Z

@ajcvickers - I’m mobile right now but I am using Serilog with a few sinks but I’m also using Serilog.Exceptions which sounds like it could be the culprit. I’ll try this out tonight and report back.

Answer 5 · 2019-04-01T01:37:43.000Z

@ajcvickers - Confirmed. Serilog.Exceptions is serializing DbUpdateException which is causing the issue you described. When I remove .Enrich.WithExceptionDetails() from my Serilog config, then the repro above no longer queries every DbSet on the DbContext and all is good.

I will still put up a minimal repro showing this, but at least I have a workaround of removing Serilog.Exceptions, or adding a PropertyFilter/Custom Destructurer.

/cc @RehanSaeed so you're aware. Not sure if there's anything for you to do here with Serilog.Exceptions or if the work will be on EF's side.

@rosspace - I'm curious if you're also using Serilog.Exceptions or if you're serializing Exceptions another way, since you decribe hitting this on DbUpdateConcurrencyException which inherits from DbUpdateException.

Thanks @ajcvickers! This ends my 6 month long journey of trying to track down this issue off and on. 👍

Do you want me to leave this open to track the reason for the upcoming serialization work?

Answer 6 · 2019-04-01T08:08:55.000Z

That's interesting, was totally not aware of that. In Serilog.Exceptions, the DbUpdateException would get serialized using the reflection based destructurer. I'm not sure if the custom serialization work described above would fix the issue. As this is a special case, the fix is to use a custom destructurer for this exception. Ideally we should create a NuGet package (Serilog.Exceptions.EntityFrameworkCore) for this purpose as it's a fairly common occurance and we can cover any other exceptions in Entity Framework. I've raised RehanSaeed/Serilog.Exceptions#100 to fix this.

Answer 7 · 2019-04-01T12:53:53.000Z

I am using Serilog.Exceptions. Great find. I would have never thought of that.

Answer 8 · 2019-04-01T21:23:39.000Z

@ajcvickers Holy cow. Great debugging.

Answer 9 · 2019-05-22T20:21:39.000Z

Closing this as external since fixing this requires changes to Serilog.Exceptions, as described above. However, see #15779 for a closely related fix.

Answer 10 · 2019-07-11T13:03:46.000Z

Serilog.Exceptions has a new NuGet package to help resolve this issue. More at https://github.com/RehanSaeed/Serilog.Exceptions.