Context
We appear to be having an Entity Framework 6.x related issue. We've spent weeks attempting to nail down performance issues and fixed most if not all which we can find/think of. In short, we are seeing a massive drop in performance when utilizing Include.
- Utilizing EFCache.
- Enabled db model caching running EF 6.2.
- Making use of cached views.
- Using a context without Lazy Loading where possible utilizing the correct (and minimal) includes.
- Using
AsNoTrackingfor read-only data. - Using a context without proxy generation nor autodetect changes (though the latter appears to be a minimal improvement).
- Context lifetime is minimal, single query within using blocks where possible.
- Clean constructors on the objects so EF should experience minimal overhead in mapping the data to objects.
- "Async all the way" which certainly improved responsiveness, but does not reduce the work being done.
Current (presumed) issues we still have that could have an impact:
- Primary key, clustered GUIDs.
- Table per type hierarchy, with Entity being part of it, causing double joins.
Most of the related topics we've already burned through, without much effect. As far as we can tell, the database is 'okay'. Utilizing a log4net interceptor before the queries hit the database, we found out that although some of our queries with 3-7 includes are monstrous, they aren't abysmally slow: times ranging from 0ms to 100ms. It tends to be 2000ms up to 8000ms until the objects are 'ready' for use though.
We have at most 50.000 entities currently in our database. However, even with a near-clean database, there is minimal difference.
Code
(Simplified, extracted) model structure:
public class Entity
{
public virtual Guid Id { get; set; }
public virtual long Version { get; set; }
public virtual string EntityType { get; set; }
}
public class User : Entity
{
public virtual Guid Id { get; set; }
public virtual string Username { get; set; }
public virtual string Password { get; set; }
public virtual Person Person { get; set; }
}
public class Person : Entity
{
public virtual Guid Id { get; set; }
public virtual DateTime DateOfBirth { get; set; }
public virtual string Name { get; set; }
public virtual Employee Employee { get; set; }
}
public class Employee : Entity
{
public virtual Guid Id { get; set; }
public virtual string EmployeeCode { get; set; }
}
(Simplified) slow query. Monitoring by wrapping a Stopwatch indicates an average duration of two seconds, but the query itself lists only a few ms in log4net's generated log file:
var userId = .... // Obtained elsewhere
using (var context = new DbContext())
{
var user =
context.Set<User>()
.Include(u => u.Person.Employee)
.FirstOrDefault(u => u.Id == userId);
}
We've tried alternative approaches:
context.Set<User>().Where(u => u.Id == userId).Load();
context.Set<Person>().Where(p => p.User.Id == userId).Load();
context.Set<Employee>().Where(e => e.Person.User.Id == userId).Load();
var user = context.Set<User>().Local.FirstOrDefault(u => u.Id == userId);
Summary
Based on the provided information, does anyone see a clear issue which we may have missed, or otherwise have suggestions for things we could try?
Could the fact that we still have the two aforementioned 'issues' present dether EF from constructing the objects in a semi-fast way?
Perhaps relevant, using Find(userId) instead of FirstOrDefault blocks and does not appear to finish within a reasonable period.
Update 1
In response to @Ivan Stoev - running the above query ran for 98ms (2968ms) and generated the following (full) SQL statement:
SELECT
[Limit1].[CheckSum] AS [CheckSum],
[Limit1].[C1] AS [C1],
[Limit1].[Id] AS [Id],
[Limit1].[Version] AS [Version],
[Limit1].[EntityType] AS [EntityType],
[Limit1].[Deleted] AS [Deleted],
[Limit1].[UpdatedBy] AS [UpdatedBy],
[Limit1].[UpdatedAt] AS [UpdatedAt],
[Limit1].[CreatedBy] AS [CreatedBy],
[Limit1].[CreatedAt] AS [CreatedAt],
[Limit1].[LastRevision] AS [LastRevision],
[Limit1].[AccessControlListId] AS [AccessControlListId],
[Limit1].[EntityStatus] AS [EntityStatus],
[Limit1].[Username] AS [Username],
[Limit1].[Password] AS [Password],
[Limit1].[Email] AS [Email],
[Limit1].[ResetHash] AS [ResetHash],
[Limit1].[Flag] AS [Flag],
[Limit1].[CryptoKey] AS [CryptoKey],
[Limit1].[FailedPasswordTries] AS [FailedPasswordTries],
[Limit1].[LastPasswordTry] AS [LastPasswordTry],
[Limit1].[UXConfigId] AS [UXConfigId],
[Limit1].[LastActivity] AS [LastActivity],
[Limit1].[C2] AS [C2],
[Limit1].[C3] AS [C3],
[Limit1].[C4] AS [C4],
[Limit1].[C5] AS [C5],
[Limit1].[C6] AS [C6],
[Limit1].[C7] AS [C7],
[Limit1].[C8] AS [C8],
[Limit1].[C9] AS [C9],
[Limit1].[C10] AS [C10],
[Limit1].[C11] AS [C11],
[Limit1].[C12] AS [C12],
[Limit1].[C13] AS [C13],
[Limit1].[C14] AS [C14],
[Limit1].[C15] AS [C15],
[Limit1].[C16] AS [C16],
[Limit1].[Id1] AS [Id1],
[Limit1].[Version1] AS [Version1],
[Limit1].[EntityType1] AS [EntityType1],
[Limit1].[Deleted1] AS [Deleted1],
[Limit1].[UpdatedBy1] AS [UpdatedBy1],
[Limit1].[UpdatedAt1] AS [UpdatedAt1],
[Limit1].[CreatedBy1] AS [CreatedBy1],
[Limit1].[CreatedAt1] AS [CreatedAt1],
[Limit1].[LastRevision1] AS [LastRevision1],
[Limit1].[AccessControlListId1] AS [AccessControlListId1],
[Limit1].[EntityStatus1] AS [EntityStatus1],
[Limit1].[CheckSum1] AS [CheckSum1],
[Limit1].[C17] AS [C17],
[Limit1].[C18] AS [C18],
[Limit1].[C19] AS [C19],
[Limit1].[C20] AS [C20],
[Limit1].[C21] AS [C21],
[Limit1].[C22] AS [C22],
[Limit1].[C23] AS [C23],
[Limit1].[C24] AS [C24],
[Limit1].[C25] AS [C25],
[Limit1].[C26] AS [C26],
[Limit1].[Name_Firstname] AS [Name_Firstname],
[Limit1].[Name_Surname] AS [Name_Surname],
[Limit1].[Name_Prefix] AS [Name_Prefix],
[Limit1].[Name_Title] AS [Name_Title],
[Limit1].[Name_Middle] AS [Name_Middle],
[Limit1].[Name_Suffix] AS [Name_Suffix],
[Limit1].[Sex] AS [Sex],
[Limit1].[DateOfBirth] AS [DateOfBirth],
[Limit1].[State] AS [State],
[Limit1].[C27] AS [C27],
[Limit1].[C28] AS [C28],
[Limit1].[C29] AS [C29],
[Limit1].[C30] AS [C30],
[Limit1].[C31] AS [C31],
[Limit1].[Id2] AS [Id2],
[Limit1].[Version2] AS [Version2],
[Limit1].[EntityType2] AS [EntityType2],
[Limit1].[Deleted2] AS [Deleted2],
[Limit1].[UpdatedBy2] AS [UpdatedBy2],
[Limit1].[UpdatedAt2] AS [UpdatedAt2],
[Limit1].[CreatedBy2] AS [CreatedBy2],
[Limit1].[CreatedAt2] AS [CreatedAt2],
[Limit1].[LastRevision2] AS [LastRevision2],
[Limit1].[AccessControlListId2] AS [AccessControlListId2],
[Limit1].[EntityStatus2] AS [EntityStatus2],
[Limit1].[CheckSum2] AS [CheckSum2],
[Limit1].[C32] AS [C32],
[Limit1].[C33] AS [C33],
[Limit1].[C34] AS [C34],
[Limit1].[C35] AS [C35],
[Limit1].[C36] AS [C36],
[Limit1].[C37] AS [C37],
[Limit1].[C38] AS [C38],
[Limit1].[C39] AS [C39],
[Limit1].[C40] AS [C40],
[Limit1].[C41] AS [C41],
[Limit1].[C42] AS [C42],
[Limit1].[C43] AS [C43],
[Limit1].[C44] AS [C44],
[Limit1].[C45] AS [C45],
[Limit1].[C46] AS [C46],
[Limit1].[C47] AS [C47],
[Limit1].[C48] AS [C48],
[Limit1].[C49] AS [C49],
[Limit1].[C50] AS [C50],
[Limit1].[C51] AS [C51],
[Limit1].[Ssn] AS [Ssn],
[Limit1].[Employeenumber] AS [Employeenumber],
[Limit1].[Bankaccount] AS [Bankaccount],
[Limit1].[PersonId] AS [PersonId]
FROM ( SELECT TOP (1)
[Extent1].[Id] AS [Id],
[Extent1].[Username] AS [Username],
[Extent1].[Password] AS [Password],
[Extent1].[Email] AS [Email],
[Extent1].[ResetHash] AS [ResetHash],
[Extent1].[Flag] AS [Flag],
[Extent1].[CryptoKey] AS [CryptoKey],
[Extent1].[FailedPasswordTries] AS [FailedPasswordTries],
[Extent1].[LastPasswordTry] AS [LastPasswordTry],
[Extent1].[UXConfigId] AS [UXConfigId],
[Extent1].[LastActivity] AS [LastActivity],
[Extent2].[Version] AS [Version],
[Extent2].[EntityType] AS [EntityType],
[Extent2].[Deleted] AS [Deleted],
[Extent2].[UpdatedBy] AS [UpdatedBy],
[Extent2].[UpdatedAt] AS [UpdatedAt],
[Extent2].[CreatedBy] AS [CreatedBy],
[Extent2].[CreatedAt] AS [CreatedAt],
[Extent2].[LastRevision] AS [LastRevision],
[Extent2].[AccessControlListId] AS [AccessControlListId],
[Extent2].[EntityStatus] AS [EntityStatus],
[Extent2].[CheckSum] AS [CheckSum],
'0X0X' AS [C1],
CAST(NULL AS int) AS [C2],
CAST(NULL AS varchar(1)) AS [C3],
CAST(NULL AS varchar(1)) AS [C4],
CAST(NULL AS varchar(1)) AS [C5],
CAST(NULL AS varchar(1)) AS [C6],
CAST(NULL AS varchar(1)) AS [C7],
CAST(NULL AS varchar(1)) AS [C8],
CAST(NULL AS bigint) AS [C9],
CAST(NULL AS datetime2) AS [C10],
CAST(NULL AS bigint) AS [C11],
CAST(NULL AS varchar(1)) AS [C12],
CAST(NULL AS varchar(1)) AS [C13],
CAST(NULL AS varchar(1)) AS [C14],
CAST(NULL AS uniqueidentifier) AS [C15],
[Join3].[Id1] AS [Id1],
[Join3].[Name_Firstname] AS [Name_Firstname],
[Join3].[Name_Surname] AS [Name_Surname],
[Join3].[Name_Prefix] AS [Name_Prefix],
[Join3].[Name_Title] AS [Name_Title],
[Join3].[Name_Middle] AS [Name_Middle],
[Join3].[Name_Suffix] AS [Name_Suffix],
[Join3].[Sex] AS [Sex],
[Join3].[DateOfBirth] AS [DateOfBirth],
[Join3].[State] AS [State],
[Join3].[Version] AS [Version1],
[Join3].[EntityType] AS [EntityType1],
[Join3].[Deleted] AS [Deleted1],
[Join3].[UpdatedBy] AS [UpdatedBy1],
[Join3].[UpdatedAt] AS [UpdatedAt1],
[Join3].[CreatedBy] AS [CreatedBy1],
[Join3].[CreatedAt] AS [CreatedAt1],
[Join3].[LastRevision] AS [LastRevision1],
[Join3].[AccessControlListId] AS [AccessControlListId1],
[Join3].[EntityStatus] AS [EntityStatus1],
[Join3].[CheckSum] AS [CheckSum1],
CASE WHEN ([Join3].[Id1] IS NULL) THEN CAST(NULL AS varchar(1)) ELSE '0X1X' END AS [C16],
CAST(NULL AS varchar(1)) AS [C17],
CAST(NULL AS varchar(1)) AS [C18],
CAST(NULL AS varchar(1)) AS [C19],
CAST(NULL AS varchar(1)) AS [C20],
CAST(NULL AS bigint) AS [C21],
CAST(NULL AS varchar(1)) AS [C22],
CAST(NULL AS smallint) AS [C23],
CAST(NULL AS datetime2) AS [C24],
CAST(NULL AS uniqueidentifier) AS [C25],
CAST(NULL AS datetime2) AS [C26],
CAST(NULL AS varchar(1)) AS [C27],
CAST(NULL AS varchar(1)) AS [C28],
CAST(NULL AS varchar(1)) AS [C29],
CAST(NULL AS uniqueidentifier) AS [C30],
[Join6].[Id2] AS [Id2],
[Join6].[Ssn1] AS [Ssn],
[Join6].[Employeenumber1] AS [Employeenumber],
[Join6].[Bankaccount1] AS [Bankaccount],
[Join6].[PersonId1] AS [PersonId],
[Join6].[Version] AS [Version2],
[Join6].[EntityType] AS [EntityType2],
[Join6].[Deleted] AS [Deleted2],
[Join6].[UpdatedBy] AS [UpdatedBy2],
[Join6].[UpdatedAt] AS [UpdatedAt2],
[Join6].[CreatedBy] AS [CreatedBy2],
[Join6].[CreatedAt] AS [CreatedAt2],
[Join6].[LastRevision] AS [LastRevision2],
[Join6].[AccessControlListId] AS [AccessControlListId2],
[Join6].[EntityStatus] AS [EntityStatus2],
[Join6].[CheckSum] AS [CheckSum2],
CASE WHEN ([Join6].[Id2] IS NULL) THEN CAST(NULL AS varchar(1)) ELSE '0X2X' END AS [C31],
CAST(NULL AS varchar(1)) AS [C32],
CAST(NULL AS varchar(1)) AS [C33],
CAST(NULL AS varchar(1)) AS [C34],
CAST(NULL AS varchar(1)) AS [C35],
CAST(NULL AS bigint) AS [C36],
CAST(NULL AS varchar(1)) AS [C37],
CAST(NULL AS smallint) AS [C38],
CAST(NULL AS datetime2) AS [C39],
CAST(NULL AS uniqueidentifier) AS [C40],
CAST(NULL AS datetime2) AS [C41],
CAST(NULL AS int) AS [C42],
CAST(NULL AS varchar(1)) AS [C43],
CAST(NULL AS varchar(1)) AS [C44],
CAST(NULL AS varchar(1)) AS [C45],
CAST(NULL AS varchar(1)) AS [C46],
CAST(NULL AS varchar(1)) AS [C47],
CAST(NULL AS varchar(1)) AS [C48],
CAST(NULL AS bigint) AS [C49],
CAST(NULL AS datetime2) AS [C50],
CAST(NULL AS bigint) AS [C51]
FROM [dbo].[Users] AS [Extent1]
INNER JOIN (SELECT [Var_27].[Id] AS [Id], [Var_27].[Version] AS [Version], [Var_27].[EntityType] AS [EntityType], [Var_27].[Deleted] AS [Deleted], [Var_27].[UpdatedBy] AS [UpdatedBy], [Var_27].[UpdatedAt] AS [UpdatedAt], [Var_27].[CreatedBy] AS [CreatedBy], [Var_27].[CreatedAt] AS [CreatedAt], [Var_27].[LastRevision] AS [LastRevision], [Var_27].[AccessControlListId] AS [AccessControlListId], [Var_27].[EntityStatus] AS [EntityStatus], [Var_27].[CheckSum] AS [CheckSum]
FROM [dbo].[Entities] AS [Var_27]
WHERE [Var_27].[Deleted] <> 1 ) AS [Extent2] ON [Extent1].[Id] = [Extent2].[Id]
LEFT OUTER JOIN (SELECT [Extent3].[Id] AS [Id1], [Extent3].[Name_Firstname] AS [Name_Firstname], [Extent3].[Name_Surname] AS [Name_Surname], [Extent3].[Name_Prefix] AS [Name_Prefix], [Extent3].[Name_Title] AS [Name_Title], [Extent3].[Name_Middle] AS [Name_Middle], [Extent3].[Name_Suffix] AS [Name_Suffix], [Extent3].[Sex] AS [Sex], [Extent3].[DateOfBirth] AS [DateOfBirth], [Extent3].[State] AS [State], [Extent4].[Id] AS [Id3], [Extent4].[Version] AS [Version], [Extent4].[EntityType] AS [EntityType], [Extent4].[Deleted] AS [Deleted], [Extent4].[UpdatedBy] AS [UpdatedBy], [Extent4].[UpdatedAt] AS [UpdatedAt], [Extent4].[CreatedBy] AS [CreatedBy], [Extent4].[CreatedAt] AS [CreatedAt], [Extent4].[LastRevision] AS [LastRevision], [Extent4].[AccessControlListId] AS [AccessControlListId], [Extent4].[EntityStatus] AS [EntityStatus], [Extent4].[CheckSum] AS [CheckSum]
FROM [dbo].[People] AS [Extent3]
INNER JOIN (SELECT [Var_28].[Id] AS [Id], [Var_28].[Version] AS [Version], [Var_28].[EntityType] AS [EntityType], [Var_28].[Deleted] AS [Deleted], [Var_28].[UpdatedBy] AS [UpdatedBy], [Var_28].[UpdatedAt] AS [UpdatedAt], [Var_28].[CreatedBy] AS [CreatedBy], [Var_28].[CreatedAt] AS [CreatedAt], [Var_28].[LastRevision] AS [LastRevision], [Var_28].[AccessControlListId] AS [AccessControlListId], [Var_28].[EntityStatus] AS [EntityStatus], [Var_28].[CheckSum] AS [CheckSum]
FROM [dbo].[Entities] AS [Var_28]
WHERE [Var_28].[Deleted] <> 1 ) AS [Extent4] ON [Extent3].[Id] = [Extent4].[Id]
LEFT OUTER JOIN [dbo].[Employees] AS [Extent5] ON [Extent3].[Id] = [Extent5].[Person_Id] ) AS [Join3] ON [Join3].[Id1] = [Extent1].[Person_Id]
LEFT OUTER JOIN (SELECT [Extent6].[Id] AS [Id2], [Extent6].[Person_Id] AS [Person_Id1], [Extent6].[Ssn] AS [Ssn1], [Extent6].[Employeenumber] AS [Employeenumber1], [Extent6].[Bankaccount] AS [Bankaccount1], [Extent6].[PersonId] AS [PersonId1], [Extent7].[Id] AS [Id4], [Extent7].[Version] AS [Version], [Extent7].[EntityType] AS [EntityType], [Extent7].[Deleted] AS [Deleted], [Extent7].[UpdatedBy] AS [UpdatedBy], [Extent7].[UpdatedAt] AS [UpdatedAt], [Extent7].[CreatedBy] AS [CreatedBy], [Extent7].[CreatedAt] AS [CreatedAt], [Extent7].[LastRevision] AS [LastRevision], [Extent7].[AccessControlListId] AS [AccessControlListId], [Extent7].[EntityStatus] AS [EntityStatus], [Extent7].[CheckSum] AS [CheckSum], [Extent8].[Person_Id] AS [Person_Id2]
FROM [dbo].[Employees] AS [Extent6]
INNER JOIN (SELECT [Var_29].[Id] AS [Id], [Var_29].[Version] AS [Version], [Var_29].[EntityType] AS [EntityType], [Var_29].[Deleted] AS [Deleted], [Var_29].[UpdatedBy] AS [UpdatedBy], [Var_29].[UpdatedAt] AS [UpdatedAt], [Var_29].[CreatedBy] AS [CreatedBy], [Var_29].[CreatedAt] AS [CreatedAt], [Var_29].[LastRevision] AS [LastRevision], [Var_29].[AccessControlListId] AS [AccessControlListId], [Var_29].[EntityStatus] AS [EntityStatus], [Var_29].[CheckSum] AS [CheckSum]
FROM [dbo].[Entities] AS [Var_29]
WHERE [Var_29].[Deleted] <> 1 ) AS [Extent7] ON [Extent6].[Id] = [Extent7].[Id]
INNER JOIN [dbo].[Employees] AS [Extent8] ON 1 = 1 ) AS [Join6] ON ([Join6].[Person_Id1] = [Extent1].[Person_Id]) AND ([Extent1].[Person_Id] = [Join6].[Person_Id2])
WHERE [Extent1].[Id] = @p__linq__0
) AS [Limit1]
Update 2
In response to @grek40 - the interceptor we have in place adds to each select query to make sure the entities we are receiving do not have the flag Deleted == true. It is joining the Entities table for every object + include, and thus the above query shows 3 additional joins. If we disable the interceptor, we are left with 4 joins instead of 7. We didn't think much of it, but now that we've disabled it, the calculated time for the query above, through Entity Framework, went from ~3 seconds to ~2 seconds. It appears to have been accountable for 1/3rd of the performance issues we're seeing.
Update 3
In response to @GertArnold, the following is our mapping code for our Entity base class, matching the above query:
modelBuilder.Entity<Entity>()
.HasKey(p => new { p.Id })
// Table Per Type (TPT) inheritance root class
.ToTable("Entities", "dbo");
// Properties:
modelBuilder.Entity<Entity>()
.Property(p => p.Id)
.IsRequired()
.HasDatabaseGeneratedOption(System.ComponentModel.DataAnnotations.Schema.DatabaseGeneratedOption.None)
.HasColumnType("uniqueidentifier");
modelBuilder.Entity<Entity>()
.Property(p => p.Version)
.IsRequired()
.IsConcurrencyToken()
.HasColumnType("bigint");
modelBuilder.Entity<Entity>()
.Property(p => p.EntityType)
.IsRequired()
.HasColumnType("varchar");
modelBuilder.Entity<Entity>()
.Property(p => p.Deleted)
.IsRequired()
.HasColumnType("bit");
modelBuilder.Entity<Entity>()
.Property(p => p.UpdatedBy)
.HasColumnType("uniqueidentifier");
modelBuilder.Entity<Entity>()
.Property(p => p.UpdatedAt)
.HasColumnType("datetime");
modelBuilder.Entity<Entity>()
.Property(p => p.CreatedBy)
.HasColumnType("uniqueidentifier");
modelBuilder.Entity<Entity>()
.Property(p => p.CreatedAt)
.HasColumnType("datetime");
modelBuilder.Entity<Entity>()
.Property(p => p.LastRevision)
.IsRequired()
.HasColumnType("bigint");
modelBuilder.Entity<Entity>()
.Property(p => p.AccessControlListId)
.HasColumnType("uniqueidentifier");
modelBuilder.Entity<Entity>()
.Property(p => p.EntityStatus)
.IsRequired()
.HasColumnType("bigint");
modelBuilder.Entity<Entity>()
.Property(p => p.CheckSum)
.IsRequired()
.HasDatabaseGeneratedOption(System.ComponentModel.DataAnnotations.Schema.DatabaseGeneratedOption.Computed)
.IsConcurrencyToken()
.HasColumnType("int");
