Using Plan Explorer With Entity Framework
My team at the office gently reminded me that it has been some time since I wrote a technical blog post and, as we all know, muscles that aren't exercised tend to become atrophied. I felt this was a good opportunity to showcase one of my favorite use cases for Plan Explorer!
Entity Framework, just like other ORMs, takes your application code (in my case C#) and magically turns it into T-SQL. The problem, as any good DBA will tell you, is that the magic comes at a cost: you can end up with a query that doesn't perform well and is difficult to tune due to poor readability of the actual T-SQL code.
For example, something like this -
var exerciseLogs = db.ExerciseLogs
.Include(l => l.Metrics)
.Include(l => l.User)
.Include(l => l.WorkoutBlockExercise)
.Where(l => (l.UserID == user.Id
&& l.LogDate >= minDate)
&& (l.ExerciseID == chartDefinition.ExerciseID
|| l.ExerciseID == null))
.ToList();
Turns into something like this -
SELECT
[Project1].[WorkoutBlockLogID] AS [WorkoutBlockLogID],
[Project1].[WorkoutLogID] AS [WorkoutLogID],
[Project1].[ScheduledWorkoutID] AS [ScheduledWorkoutID],
[Project1].[WorkoutBlockExerciseID1] AS [WorkoutBlockExerciseID],
[Project1].[SetNumber] AS [SetNumber],
[Project1].[ExerciseLogID] AS [ExerciseLogID],
[Project1].[UserID] AS [UserID],
[Project1].[WorkoutBlockExerciseID] AS [WorkoutBlockExerciseID1],
[Project1].[LogDate] AS [LogDate],
[Project1].[CreateDate] AS [CreateDate],
[Project1].[ExerciseID] AS [ExerciseID],
[Project1].[WorkoutBlockID] AS [WorkoutBlockID],
[Project1].[ExerciseID1] AS [ExerciseID1],
[Project1].[Multiplier] AS [Multiplier],
[Project1].[Repetitions] AS [Repetitions],
[Project1].[Distance] AS [Distance],
[Project1].[Duration] AS [Duration],
[Project1].[RestDuration] AS [RestDuration],
[Project1].[DefaultRepetitions] AS [DefaultRepetitions],
[Project1].[DefaultMultiplier] AS [DefaultMultiplier],
[Project1].[DefaultResistanceMale] AS [DefaultResistanceMale],
[Project1].[DefaultResistanceFemale] AS [DefaultResistanceFemale],
[Project1].[Sequence] AS [Sequence],
[Project1].[WorkoutBlockLog_WorkoutBlockLogID] AS [WorkoutBlockLog_WorkoutBlockLogID],
[Project1].[C1] AS [C1],
[Project1].[MeasurementTypeID] AS [MeasurementTypeID],
[Project1].[ExerciseLogMetricID] AS [ExerciseLogMetricID],
[Project1].[Value] AS [Value],
[Project1].[UnitOfMeasureID] AS [UnitOfMeasureID],
[Project1].[ExerciseLog_ExerciseLogID] AS [ExerciseLog_ExerciseLogID]
FROM ( SELECT
[Filter1].[ExerciseLogID] AS [ExerciseLogID],
[Filter1].[UserID1] AS [UserID],
[Filter1].[WorkoutBlockExerciseID1] AS [WorkoutBlockExerciseID],
[Filter1].[LogDate1] AS [LogDate],
[Filter1].[CreateDate1] AS [CreateDate],
[Filter1].[ExerciseID1] AS [ExerciseID],
[Filter1].[SetNumber] AS [SetNumber],
[Filter1].[WorkoutBlockLog_WorkoutBlockLogID] AS [WorkoutBlockLog_WorkoutBlockLogID],
[Filter1].[WorkoutBlockLogID] AS [WorkoutBlockLogID],
[Filter1].[WorkoutLogID] AS [WorkoutLogID],
[Filter1].[ScheduledWorkoutID1] AS [ScheduledWorkoutID],
[Filter1].[WorkoutBlockExerciseID2] AS [WorkoutBlockExerciseID1],
[Filter1].[WorkoutBlockID1] AS [WorkoutBlockID],
[Filter1].[ExerciseID2] AS [ExerciseID1],
[Filter1].[Multiplier] AS [Multiplier],
[Filter1].[Repetitions] AS [Repetitions],
[Filter1].[Distance] AS [Distance],
[Filter1].[Duration] AS [Duration],
[Filter1].[RestDuration] AS [RestDuration],
[Filter1].[DefaultRepetitions] AS [DefaultRepetitions],
[Filter1].[DefaultMultiplier] AS [DefaultMultiplier],
[Filter1].[DefaultResistanceMale] AS [DefaultResistanceMale],
[Filter1].[DefaultResistanceFemale] AS [DefaultResistanceFemale],
[Filter1].[Sequence] AS [Sequence],
[Filter1].[ExerciseLogMetricID] AS [ExerciseLogMetricID],
[Filter1].[MeasurementTypeID] AS [MeasurementTypeID],
[Filter1].[Value] AS [Value],
[Filter1].[UnitOfMeasureID] AS [UnitOfMeasureID],
[Filter1].[ExerciseLog_ExerciseLogID] AS [ExerciseLog_ExerciseLogID],
CASE WHEN ([Filter1].[MeasurementTypeID] IS NULL) THEN CAST(NULL AS int) ELSE 1 END AS [C1]
FROM ( SELECT [Extent1].[ExerciseLogID] AS [ExerciseLogID], [Extent1].[UserID] AS [UserID1],
[Extent1].[WorkoutBlockExerciseID] AS [WorkoutBlockExerciseID1],
[Extent1].[LogDate] AS [LogDate1], [Extent1].[CreateDate] AS [CreateDate1],
[Extent1].[ExerciseID] AS [ExerciseID1], [Extent1].[SetNumber] AS [SetNumber],
[Extent1].[WorkoutBlockLog_WorkoutBlockLogID] AS [WorkoutBlockLog_WorkoutBlockLogID],
[Extent2].[WorkoutBlockLogID] AS [WorkoutBlockLogID],
[Extent3].[WorkoutLogID] AS [WorkoutLogID],
[Extent4].[ScheduledWorkoutID] AS [ScheduledWorkoutID1],
[Extent4].[WorkoutTypeID] AS [WorkoutTypeID],
[Extent5].[WorkoutBlockExerciseID] AS [WorkoutBlockExerciseID2],
[Extent5].[WorkoutBlockID] AS [WorkoutBlockID1], [Extent5].[ExerciseID] AS [ExerciseID2],
[Extent5].[Multiplier] AS [Multiplier], [Extent5].[Repetitions] AS [Repetitions],
[Extent5].[Distance] AS [Distance], [Extent5].[Duration] AS [Duration],
[Extent5].[RestDuration] AS [RestDuration],
[Extent5].[DefaultRepetitions] AS [DefaultRepetitions],
[Extent5].[DefaultMultiplier] AS [DefaultMultiplier],
[Extent5].[DefaultResistanceMale] AS [DefaultResistanceMale],
[Extent5].[DefaultResistanceFemale] AS [DefaultResistanceFemale],
[Extent5].[Sequence] AS [Sequence], [Extent6].[ExerciseLogMetricID] AS [ExerciseLogMetricID],
[Extent6].[MeasurementTypeID] AS [MeasurementTypeID], [Extent6].[Value] AS [Value],
[Extent6].[UnitOfMeasureID] AS [UnitOfMeasureID],
[Extent6].[ExerciseLog_ExerciseLogID] AS [ExerciseLog_ExerciseLogID]
FROM [dbo].[ExerciseLogs] AS [Extent1]
LEFT OUTER JOIN [dbo].[WorkoutBlockLogs] AS [Extent2]
ON [Extent1].[WorkoutBlockLog_WorkoutBlockLogID] = [Extent2].[WorkoutBlockLogID]
LEFT OUTER JOIN [dbo].[WorkoutLogs] AS [Extent3]
ON [Extent2].[WorkoutLog_WorkoutLogID] = [Extent3].[WorkoutLogID]
LEFT OUTER JOIN [dbo].[ScheduledWorkouts] AS [Extent4]
ON [Extent3].[ScheduledWorkoutID] = [Extent4].[ScheduledWorkoutID]
LEFT OUTER JOIN [dbo].[WorkoutBlockExercises] AS [Extent5]
ON [Extent1].[WorkoutBlockExerciseID] = [Extent5].[WorkoutBlockExerciseID]
LEFT OUTER JOIN [dbo].[ExerciseLogMetrics] AS [Extent6]
ON [Extent1].[ExerciseLogID] = [Extent6].[ExerciseLog_ExerciseLogID]
WHERE (([Extent1].[ExerciseID] IS NOT NULL) AND ([Extent1].[ExerciseID]
IN (#)) AND ([Extent1].[ExerciseID] IS NOT NULL))
OR (([Extent1].[WorkoutBlockExerciseID] IS NOT NULL)
AND ([Extent5].[ExerciseID] IN (#))
AND ([Extent5].[ExerciseID] IS NOT NULL))
) AS [Filter1]
WHERE ([Filter1].[WorkoutTypeID] = @p__linq__0)
AND (([Filter1].[UserID1] = @p__linq__1)
OR (([Filter1].[UserID1] IS NULL)
AND (@p__linq__1 IS NULL)))
) AS [Project1]
ORDER BY [Project1].[LogDate] DESC,
[Project1].[WorkoutBlockLogID] ASC,
[Project1].[WorkoutLogID] ASC,
[Project1].[ScheduledWorkoutID] ASC,
[Project1].[WorkoutBlockExerciseID1] ASC,
[Project1].[ExerciseLogID] ASC,
[Project1].[C1] ASC
That is not the query I'll be looking at today, but it is certainly on my list. :)
Normally, I use DB Sentry in SentryOne to monitor "WarriorTracker," an Azure SQL Database. I'd review the top 5-10 heaviest queries and do my best to target them with indexes (or any number of other tuning methods.)
Today, however, I am looking for a very specific query. Due to the nature of Entity Framework queries, it is difficult to match the T-SQL from DB Sentry with LINQ queries in C#. In order to do this, I'm going to need to use some nice features of Visual Studio 2017, and Plan Explorer.
Going into this, all I know is that some Gyms using the WarriorTracker system are experiencing some slowness when loading a feature we call the "Big Screen." This is a full screen view showing today's workout along with some details about nutrition and other things that, according to my doctor, I should be paying a lot more attention to.
I'm going to need to get the exact query that gathers data for this feature and the way to do that is to stop on a breakpoint in the application code.
That isn't all, though. I also want to use a Visual Studio feature called Intellitrace. I had it turned off (because it slows down debugging) but in this case I really need it because it can show me the query that's being sent from Entity Framework to the Azure SQL Database.
Now, when I debug and navigate to the Big Screen, I'll hit my breakpoint, step over it, and grab my query from the Intellitrace profiler. It will be the next ADO event after the breakpoint.
From here, I take the query, open Plan Explorer, and get to work. I'm hoping to avoid rewriting the query, so I'm going to look at things like statistics, and indexing opportunities first.
DECLARE @p__linq__0 AS SQL_VARIANT;
SET @p__linq__0 = NULL;
SELECT
[Limit1].[C2] AS [C1],
[Limit1].[C1] AS [C2],
[Limit1].[Id] AS [Id],
[Limit1].[UserName] AS [UserName],
[Limit1].[PasswordHash] AS [PasswordHash],
[Limit1].[SecurityStamp] AS [SecurityStamp],
[Limit1].[FullName] AS [FullName],
[Limit1].[EmailAddress] AS [EmailAddress],
[Limit1].[Gender] AS [Gender],
[Limit1].[DateOfBirth] AS [DateOfBirth],
[Limit1].[PrimaryAffiliateID] AS [PrimaryAffiliateID],
[Limit1].[OrganizationID] AS [OrganizationID],
[Limit1].[ShareResultsByDefault] AS [ShareResultsByDefault],
[Limit1].[PasswordResetToken] AS [PasswordResetToken],
[Limit1].[PasswordResetExpiration] AS [PasswordResetExpiration],
[Limit1].[Country] AS [Country],
[Limit1].[State] AS [State],
[Limit1].[City] AS [City],
[Limit1].[DateJoined] AS [DateJoined],
[Limit1].[ShowOnMonthlyLeaders] AS [ShowOnMonthlyLeaders],
[Limit1].[GroupType] AS [GroupType],
[Limit1].[ChartRange] AS [ChartRange],
[Limit1].[MeasurementSystemType] AS [MeasurementSystemType],
[Limit1].[IsDisabled] AS [IsDisabled],
[Limit1].[UserScheduleID] AS [UserScheduleID],
[Limit1].[Schedule_UserScheduleID] AS [Schedule_UserScheduleID]
FROM ( SELECT TOP (1)
[Extent1].[Id] AS [Id],
[Extent1].[UserName] AS [UserName],
[Extent1].[PasswordHash] AS [PasswordHash],
[Extent1].[SecurityStamp] AS [SecurityStamp],
[Extent1].[FullName] AS [FullName],
[Extent1].[EmailAddress] AS [EmailAddress],
[Extent1].[Gender] AS [Gender],
[Extent1].[DateOfBirth] AS [DateOfBirth],
[Extent1].[PrimaryAffiliateID] AS [PrimaryAffiliateID],
[Extent1].[OrganizationID] AS [OrganizationID],
[Extent1].[ShareResultsByDefault] AS [ShareResultsByDefault],
[Extent1].[PasswordResetToken] AS [PasswordResetToken],
[Extent1].[PasswordResetExpiration] AS [PasswordResetExpiration],
[Extent1].[Country] AS [Country],
[Extent1].[State] AS [State],
[Extent1].[City] AS [City],
[Extent1].[DateJoined] AS [DateJoined],
[Extent1].[ShowOnMonthlyLeaders] AS [ShowOnMonthlyLeaders],
[Extent1].[GroupType] AS [GroupType],
[Extent1].[ChartRange] AS [ChartRange],
[Extent1].[MeasurementSystemType] AS [MeasurementSystemType],
[Extent1].[IsDisabled] AS [IsDisabled],
[Extent1].[Schedule_UserScheduleID] AS [Schedule_UserScheduleID],
[Extent2].[UserScheduleID] AS [UserScheduleID],
'0X0X' AS [C1],
1 AS [C2]
FROM [dbo].[AspNetUsers] AS [Extent1]
LEFT OUTER JOIN [dbo].[UserSchedules] AS [Extent2]
ON [Extent1].[Id] = [Extent2].[UserID]
WHERE ([Extent1].[Discriminator] = N'ApplicationUser')
AND (([Extent1].[UserName] = @p__linq__0)
OR (([Extent1].[UserName] IS NULL)
AND (@p__linq__0 IS NULL)))
) AS [Limit1]
Note that my variables are set to defaults. I can look back to my debugging session in Visual Studio for those. Armed with that information, I adjusted the top of the script as follows:
DECLARE @p__linq__0 AS nvarchar(255); SET @p__linq__0 = N'jhall';
One thing I know (because I know the application, and the code, very well) is that this query runs all the time, on every page, and in just about every function. If one thing has to run blazingly fast, it's this query. With that in mind, when I go to my Index Analysis tab in PE, the first thing I see is a bit upsetting:
The index being used by this query is not very efficient at all. Part of it, indeed, is how Entity Framework put the T-SQL together. It is quite hard to follow, and overly aggressive considering the data that I actually need at this point. However I am not going to focus on that. Instead, I'm going to focus on making an index that the query can use to run better.
I am filtering on both Username, and Id for the user table. I think something using those 2 columns could help me out. However, as I begin to formulate a plan, I am stopped by what I am going to call poor database design. I don't mind saying that, because the truth is, I am the one that did it. Early on, it was assumed we would always be searching for users by their Id, and the Username column was created using nvarchar(max). It was decided that the application would control the length of the Username, and it does, but this is an example of how we should be thinking about database performance at every stage of a project, no matter how big or small. You see, I can't use this column in an index key, because of the data type, and to change the data type now is going to introduce a lot of risk. I still have options, but the easiest is all but closed to me, with noone to blame but myself.
With that weighing heavily on my options, I decide the best way forward, for now, will be to reduce how often this query runs dramatically. I can look the user data up this way once, without the additional join. Then I can hold the Id in cache, and use that to grab the full user context from that point on. This will always use the clustered index on the user table, and reduce the overall cost of this query running all the time by turning the scan into a seek for a single row from a clustered index.
And, that is what I did, ultimately resulting in a consistent reduction in DTU usage on the Azure SQL Database. I will look to refactor the table later, but for now I have the desired effect.
I've shared this experience here, mainly to illustrate how I often use both Visual Studio and Plan Explorer together to iron out the issues that can arise from using ORM frameworks. The tools themselves can't always lead me to the answers, but without them, the way forward would be very foggy. In addition, I was able to identify some early design mistakes that can be corrected to help with performance in the longer term.
Did this go exactly how I thought it would when I started out? No, I can't say that it did, but in the real world, we rarely get to have the exact experience we envision. Meeting the goal I set out to accomplish was the important thing to focus on.
Until next time,
-JRH