Introduction
You have a SQL Server database, and one or more of your queries are running slow. You need to figure out why. You're not going to find the solution to your specific problem in this blog post, but you will find the first troubleshooting step that may literally save you from spending entire days going down the wrong path to diagnose and solve the problem.
After reading this, you will know the three categories that a slow query can fall into, and how to figure out which of those categories fit your problem query. From there, you'll be able to narrow down your research and other troubleshooting steps to find a solution to your problem faster.
Category 1: The query runs slowly
In my experience so far, most slow queries fall into this category. Queries in this category take a long time to complete because the steps that SQL Server take to execute it (the execution plan) are resource-intensive and/or time-intensive. For example, your query may be doing a Clustered Index Scan on a table with tens of millions of rows, and that can take a long time.
The individual causes of this kind of slow query can include, but are not limited to:
- Missing indexes
- Poorly written SQL
- Excessive indexes (in the case of inserts, updates, deletes)
- Parameter sniffing
The actual solution to your problem will be vastly different depending on what the exact cause is, but, if you can determine that your query actually runs slowly, you've already narrowed down your research into the cause and the solution.
Category 2: The query compiles slowly
When you run a query, SQL Server can't execute it until it has an execution plan. An execution plan is the set of steps that SQL Server will take to actually serve your query — the actual, physical and logical steps. This process is called compiling an execution plan. For example, let's say you run the following query:
SELECT * FROM dbo.Users WHERE CreatedDate >= '2023-01-01'
To actually execute that query, SQL Server may compile an execution plan that looks something like this:
- Non-clustered index scan on the `IX_Users_CreatedDate`
- Key lookup with the clustered index
- Nested loops to join the results of steps 1 and 2
- Parallelism (Gather streams)
- SELECT
For most queries, it takes very little time to compile the execution plan, e.g. 30 milliseconds (ms). The query above may only take 1ms to compile; however, more complex SQL queries may take much longer to compile. The worst I've seen in production was 30 seconds, which is abysmal! In fact, when a query has such a long compile time, you may even see a "compilation time out," which means that SQL Server stopped trying to come up with the most optimal plan and just said, "Forget it, we'll roll with what we have so far." With such a query, it may take very little time to actually run, but that up-front cost of compiling the query may be costing you big time: especially if your applications are using the `OPTION(RECOMPILE)` query hint so that the execution plan gets compiled every time.
If it turns out your problem query is returning slowly because of a long compile time, this is actually good news because this can be incredibly easy to solve. It's likely that you're one search engine search away from a solution that will take minutes to implement.
NOTE: A long compile time may not have much impact on your system because SQL Server only needs to compile an execution plan if it doesn't already have one cached in the plan cache. The result is that, for a particularly complex query, it will take 20 seconds to compile the execution plan the first time that query runs, but then SQL Server doesn't need to spend any time compiling a plan for subsequent executions of that same query; however, an execution plan can get flushed from the plan cache for a number of reasons, e.g. the statistics on one of the tables involved in the query got updated. If events like that happen particularly often, then that will turn long compile times into a real problem for end users.
In my time troubleshooting SQL Server performance issues, compile time is pretty rarely the cause of a slow query, but when compile time is the problem, you can easily spend hours or days spinning your wheels if you don't realize the query is just taking a long time to compile.
Category 3: The query is waiting for something
Your production server probably has a lot going on. The query you're running is not the only thing SQL Server has to worry about. There may be some other query that needs to update the same data you need to read, or other queries are hogging all the CPU or RAM on the system, etc. These things, along with a host of other events, will cause your query to have to wait for a lock to be released or some RAM to free up before it can even get started.
In other words, your slow query is not actually slow — it's simply having to wait a long time before it's allowed to start running — but the effect on your applications and your end users is the same. The big difference is that your troubleshooting efforts will probably have to be focused on other queries in order to fix this query. So, if your query is waiting on some lock to be released, you may need to tune a different query so it takes out fewer locks or holds those locks for less time.
If there are many different queries across your system that are running slowly or timing out, chances are that your problem falls into this category.
How do I determine which category my query falls into?
The best way to find out which category a specific slow query falls into is to reproduce the issue by running the query manually in SQL Server Management Studio and capturing the actual execution plan. The execution plan will have very specific information that will help you categorize your slow query. I'll provide instructions for how to do this, then show some examples.
How to get the actual execution plan
- Open SQL Server Management Studio and open a query window for the database in question.
- Press `CTRL + M` to enable capturing the actual execution plan for your query. There's also a button directly above the query window that you can click — it's the button that says "Include Actual Execution Plan" in a tooltip when you hover over it.
- Run your query.
- When it's done, there will be an "Execution Plan" tab next to the "Results" and "Messages" tabs below the query window. Click the "Execution Plan" tab to view the execution plan.
- Anywhere in the execution plan tab, right-click and select "Show Execution Plan XML". The XML view is the best way to get at the specific information we're looking for.
Analyzing the execution plan
Checking for waits
Once you have your execution plan XML open, you can examine it to see what the query is spending time doing. First, do a `CTRL + F` to do a search for "WaitStats". When you do that search, you may see something like this:
<WaitStats> <Wait WaitType="LCK_M_S" WaitTimeMs="38265" WaitCount="1" /> </WaitStats>
This section of the XML shows us a list of "waits" that happened while trying to run the query. In this case, we see we had an "LCK_M_S" type of wait, and the query waited for a whopping 38 seconds! This query did indeed take 38 seconds to run in SSMS, so I've found the cause of my problem. Now, if I do a search engine search for "SQL Server LCK_M_S", we find that this means that my query needed to take a "shared lock" on a resource (in this case a table) and it had to wait 38 seconds to get that lock. Now I have a very specific direction to go in with my research and troubleshooting.
There are a lot of different wait types in SQL Server, and you may end up going in very different directions with your troubleshooting efforts depending on which type of wait is making your query slow. In the case of a lock wait like this, I might use a tool like sp_whoisactive to find out what other transaction/query is blocking my query. On the other hand, if your query is spending a lot of time on a "PAGEIOLATCH_EX" wait, you may end up using the "Top Resource Consuming Queries" report in Query Store to find out which query (or queries) are doing the most physical reads.
Checking for compile time
If the total "WaitTimeMs" in the WaitStats section isn't significant, or if there is no "WaitStats" section at all, next you should find out how long the query takes to compile. To do this, in your execution plan XML, do a search for the term "CompileTime". You should find something like this:
<QueryPlan DegreeOfParallelism="1" CachedPlanSize="1056" CompileTime="5943" CompileCPU="5943" CompileMemory="33896">
For a simple query you should see a "CompileTime" of 0ms, or perhaps as much as 10ms, but here we see 5943 milliseconds, which is just shy of 6 seconds! What this means is that it took SQL Server 6 seconds just to put together an execution plan for this query. That's before the query even gets to run. You may see this for very complicated queries, e.g., queries that have multiple nested sub-queries or an exceptionally large number of joins. In one case, I saw a query with a compile time of over 30 seconds in production. Our application-side timeout was 30 seconds, so this particular query was timing out and causing errors for end users.
There's a caveat here: SQL Server should only actually spend that time the first time it runs the query. Subsequent executions should just re-use that same execution plan, skipping all that compile time. So something you'll see if compile time is your problem is that the query is slow the first time you run it, but then the second, third, etc. time you run it is much faster.
Solving this problem can be incredibly low-effort (the last time I ran into it, it took 15 minutes to develop a fix), so, the faster you can identify this as the cause of your problem, the faster you'll have a resolution.
Checking for run time
If you've already eliminated compile time and wait time as the cause of your slow query, that leaves us with the third possibility — it's just a slow query. Let's take the following execution plan as an example:
<?xml version="1.0" encoding="utf-16"?> <ShowPlanXML xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xmlns:xsd="http://www.w3.org/2001/XMLSchema" Version="1.564" Build="16.0.1000.6" xmlns="http://schemas.microsoft.com/sqlserver/2004/07/showplan"> <BatchSequence> <Batch> <Statements> <StmtSimple StatementCompId="1" StatementEstRows="1285280" StatementId="1" StatementOptmLevel="FULL" CardinalityEstimationModelVersion="70" StatementSubTreeCost="80.0303" StatementText="SELECT *
FROM Object1" StatementType="SELECT" QueryHash="0x3352E00A1F942050" QueryPlanHash="0xE26E3CB998E16684" RetrievedFromCache="true" StatementSqlHandle="0x0900CE27F0841D17EE29F830B0383DD372BF0000000000000000000000000000000000000000000000000000" DatabaseContextSettingsId="7" ParentObjectId="0" StatementParameterizationType="0" SecurityPolicyApplied="false"> <StatementSetOptions ANSI_NULLS="true" ANSI_PADDING="true" ANSI_WARNINGS="true" ARITHABORT="true" CONCAT_NULL_YIELDS_NULL="true" NUMERIC_ROUNDABORT="false" QUOTED_IDENTIFIER="true" /> <QueryPlan DegreeOfParallelism="0" NonParallelPlanReason="TSQLUserDefinedFunctionsNotParallelizable" MemoryGrant="67552" CachedPlanSize="112" CompileTime="5" CompileCPU="5" CompileMemory="920"> <MissingIndexes> <MissingIndexGroup Impact="82.7209"> <MissingIndex Database="Database1" Schema="Schema1" Table="Object2"> <ColumnGroup Usage="EQUALITY"> <Column Name="Column3" ColumnId="7" /> </ColumnGroup> <ColumnGroup Usage="INCLUDE"> <Column Name="Column2" ColumnId="6" /> <Column Name="Column4" ColumnId="9" /> <Column Name="Column5" ColumnId="11" /> <Column Name="Column6" ColumnId="12" /> <Column Name="Column13" ColumnId="14" /> <Column Name="Column7" ColumnId="15" /> <Column Name="Column8" ColumnId="16" /> <Column Name="Column9" ColumnId="19" /> <Column Name="Column10" ColumnId="22" /> </ColumnGroup> </MissingIndex> </MissingIndexGroup> </MissingIndexes> <Warnings> <MemoryGrantWarning GrantWarningKind="Excessive Grant" RequestedMemory="67552" GrantedMemory="67552" MaxUsedMemory="2112" /> </Warnings> <MemoryGrantInfo SerialRequiredMemory="2048" SerialDesiredMemory="67552" RequiredMemory="2048" DesiredMemory="67552" RequestedMemory="67552" GrantWaitTime="0" GrantedMemory="67552" MaxUsedMemory="2112" MaxQueryMemory="3966864" /> <OptimizerHardwareDependentProperties EstimatedAvailableMemoryGrant="389427" EstimatedPagesCached="194713" EstimatedAvailableDegreeOfParallelism="4" MaxCompileMemory="11859840" /> <WaitStats> <Wait WaitType="SOS_SCHEDULER_YIELD" WaitTimeMs="16" WaitCount="4469" /> <Wait WaitType="ASYNC_NETWORK_IO" WaitTimeMs="12" WaitCount="2" /> </WaitStats> <QueryTimeStats CpuTime="17901" ElapsedTime="17919" UdfCpuTime="12925" UdfElapsedTime="12919" /> <RelOp AvgRowSize="2584" EstimateCPU="0.128528" EstimateIO="0" EstimateRebinds="0" EstimateRewinds="0" EstimatedExecutionMode="Row" EstimateRows="1285280" LogicalOp="Compute Scalar" NodeId="0" Parallel="false" PhysicalOp="Compute Scalar" EstimatedTotalSubtreeCost="80.0303"> <OutputList> <ColumnReference Database="Database1" Schema="Schema1" Table="Object2" Column="Column1" /> <ColumnReference Database="Database1" Schema="Schema1" Table="Object2" Column="Column2" /> <ColumnReference Database="Database1" Schema="Schema1" Table="Object2" Column="Column3" /> <ColumnReference Database="Database1" Schema="Schema1" Table="Object2" Column="Column4" /> <ColumnReference Database="Database1" Schema="Schema1" Table="Object2" Column="Column5" /> <ColumnReference Database="Database1" Schema="Schema1" Table="Object2" Column="Column6" /> <ColumnReference Database="Database1" Schema="Schema1" Table="Object2" Column="Column7" /> <ColumnReference Database="Database1" Schema="Schema1" Table="Object2" Column="Column8" /> <ColumnReference Database="Database1" Schema="Schema1" Table="Object2" Column="Column9" /> <ColumnReference Database="Database1" Schema="Schema1" Table="Object2" Column="Column10" /> <ColumnReference Database="Database1" Schema="Schema1" Table="Object3" Column="Column11" /> <ColumnReference Database="Database1" Schema="Schema1" Table="Object4" Alias="Object5" Column="Column12" /> <ColumnReference Column="Expr1005" /> </OutputList> <RunTimeInformation> <RunTimeCountersPerThread Thread="0" ActualRows="1758196" Batches="0" ActualEndOfScans="1" ActualExecutions="1" ActualExecutionMode="Row" ActualElapsedms="15298" ActualCPUms="15293" /> </RunTimeInformation> <ComputeScalar> <DefinedValues> <DefinedValue> <ColumnReference Column="Expr1005" /> <ScalarOperator ScalarString="ScalarString1"> <UserDefinedFunction FunctionName="Function1"> <ScalarOperator> <Identifier> <ColumnReference Database="Database1" Schema="Schema1" Table="Object2" Column="Column13" /> </Identifier> </ScalarOperator> </UserDefinedFunction> </ScalarOperator> </DefinedValue> </DefinedValues> <RelOp AvgRowSize="2607" EstimateCPU="10.9251" EstimateIO="0" EstimateRebinds="0" EstimateRewinds="0" EstimatedExecutionMode="Row" EstimateRows="1285280" LogicalOp="Right Outer Join" NodeId="1" Parallel="false" PhysicalOp="Hash Match" EstimatedTotalSubtreeCost="79.9018"> <OutputList> <ColumnReference Database="Database1" Schema="Schema1" Table="Object2" Column="Column1" /> <ColumnReference Database="Database1" Schema="Schema1" Table="Object2" Column="Column2" /> <ColumnReference Database="Database1" Schema="Schema1" Table="Object2" Column="Column3" /> <ColumnReference Database="Database1" Schema="Schema1" Table="Object2" Column="Column4" /> <ColumnReference Database="Database1" Schema="Schema1" Table="Object2" Column="Column5" /> <ColumnReference Database="Database1" Schema="Schema1" Table="Object2" Column="Column6" /> <ColumnReference Database="Database1" Schema="Schema1" Table="Object2" Column="Column13" /> <ColumnReference Database="Database1" Schema="Schema1" Table="Object2" Column="Column7" /> <ColumnReference Database="Database1" Schema="Schema1" Table="Object2" Column="Column8" /> <ColumnReference Database="Database1" Schema="Schema1" Table="Object2" Column="Column9" /> <ColumnReference Database="Database1" Schema="Schema1" Table="Object2" Column="Column10" /> <ColumnReference Database="Database1" Schema="Schema1" Table="Object3" Column="Column11" /> <ColumnReference Database="Database1" Schema="Schema1" Table="Object4" Alias="Object5" Column="Column12" /> </OutputList> <MemoryFractions Input="0.923425" Output="0.923425" /> <RunTimeInformation> <RunTimeCountersPerThread Thread="0" ActualRows="1758196" Batches="0" ActualEndOfScans="1" ActualExecutions="1" ActualExecutionMode="Row" ActualElapsedms="1730" ActualCPUms="1730" ActualScans="0" ActualLogicalReads="0" ActualPhysicalReads="0" ActualReadAheads="0" ActualLobLogicalReads="0" ActualLobPhysicalReads="0" ActualLobReadAheads="0" InputMemoryGrant="61512" OutputMemoryGrant="61512" UsedMemoryGrant="1472" /> </RunTimeInformation> <Hash> <DefinedValues /> <HashKeysBuild> <ColumnReference Database="Database1" Schema="Schema1" Table="Object4" Alias="Object5" Column="Column14" /> </HashKeysBuild> <HashKeysProbe> <ColumnReference Database="Database1" Schema="Schema1" Table="Object2" Column="Column4" /> </HashKeysProbe> <ProbeResidual> <ScalarOperator ScalarString="ScalarString2"> <Compare CompareOp="EQ"> <ScalarOperator> <Identifier> <ColumnReference Database="Database1" Schema="Schema1" Table="Object4" Alias="Object5" Column="Column14" /> </Identifier> </ScalarOperator> <ScalarOperator> <Identifier> <ColumnReference Database="Database1" Schema="Schema1" Table="Object2" Column="Column4" /> </Identifier> </ScalarOperator> </Compare> </ScalarOperator> </ProbeResidual> <RelOp AvgRowSize="135" EstimateCPU="0.0129687" EstimateIO="1.87942" EstimateRebinds="0" EstimateRewinds="0" EstimatedExecutionMode="Row" EstimateRows="11647" EstimatedRowsRead="11647" LogicalOp="Clustered Index Scan" NodeId="2" Parallel="false" PhysicalOp="Clustered Index Scan" EstimatedTotalSubtreeCost="1.89239" TableCardinality="11647"> <OutputList> <ColumnReference Database="Database1" Schema="Schema1" Table="Object4" Alias="Object5" Column="Column14" /> <ColumnReference Database="Database1" Schema="Schema1" Table="Object4" Alias="Object5" Column="Column12" /> </OutputList> <RunTimeInformation> <RunTimeCountersPerThread Thread="0" ActualRows="11647" ActualRowsRead="11647" Batches="0" ActualEndOfScans="1" ActualExecutions="1" ActualExecutionMode="Row" ActualElapsedms="6" ActualCPUms="6" ActualScans="1" ActualLogicalReads="2552" ActualPhysicalReads="0" ActualReadAheads="0" ActualLobLogicalReads="0" ActualLobPhysicalReads="0" ActualLobReadAheads="0" /> </RunTimeInformation> <IndexScan Ordered="false" ForcedIndex="false" ForceScan="false" NoExpandHint="false" Storage="RowStore"> <DefinedValues> <DefinedValue> <ColumnReference Database="Database1" Schema="Schema1" Table="Object4" Alias="Object5" Column="Column14" /> </DefinedValue> <DefinedValue> <ColumnReference Database="Database1" Schema="Schema1" Table="Object4" Alias="Object5" Column="Column12" /> </DefinedValue> </DefinedValues> <Object Database="Database1" Schema="Schema1" Table="Object4" Index="Index1" Alias="Object5" IndexKind="Clustered" Storage="RowStore" /> </IndexScan> </RelOp> <RelOp AvgRowSize="2501" EstimateCPU="12.9357" EstimateIO="0" EstimateRebinds="0" EstimateRewinds="0" EstimatedExecutionMode="Row" EstimateRows="1285280" LogicalOp="Inner Join" NodeId="3" Parallel="false" PhysicalOp="Hash Match" EstimatedTotalSubtreeCost="67.0843"> <OutputList> <ColumnReference Database="Database1" Schema="Schema1" Table="Object2" Column="Column1" /> <ColumnReference Database="Database1" Schema="Schema1" Table="Object2" Column="Column2" /> <ColumnReference Database="Database1" Schema="Schema1" Table="Object2" Column="Column3" /> <ColumnReference Database="Database1" Schema="Schema1" Table="Object2" Column="Column4" /> <ColumnReference Database="Database1" Schema="Schema1" Table="Object2" Column="Column5" /> <ColumnReference Database="Database1" Schema="Schema1" Table="Object2" Column="Column6" /> <ColumnReference Database="Database1" Schema="Schema1" Table="Object2" Column="Column13" /> <ColumnReference Database="Database1" Schema="Schema1" Table="Object2" Column="Column7" /> <ColumnReference Database="Database1" Schema="Schema1" Table="Object2" Column="Column8" /> <ColumnReference Database="Database1" Schema="Schema1" Table="Object2" Column="Column9" /> <ColumnReference Database="Database1" Schema="Schema1" Table="Object2" Column="Column10" /> <ColumnReference Database="Database1" Schema="Schema1" Table="Object3" Column="Column11" /> </OutputList> <MemoryFractions Input="0.0765755" Output="0.0765755" /> <RunTimeInformation> <RunTimeCountersPerThread Thread="0" ActualRows="1758196" Batches="0" ActualEndOfScans="1" ActualExecutions="1" ActualExecutionMode="Row" ActualElapsedms="1090" ActualCPUms="1090" ActualScans="0" ActualLogicalReads="0" ActualPhysicalReads="0" ActualReadAheads="0" ActualLobLogicalReads="0" ActualLobPhysicalReads="0" ActualLobReadAheads="0" InputMemoryGrant="6032" OutputMemoryGrant="6032" UsedMemoryGrant="640" /> </RunTimeInformation> <Hash> <DefinedValues /> <HashKeysBuild> <ColumnReference Database="Database1" Schema="Schema1" Table="Object3" Column="Column14" /> </HashKeysBuild> <HashKeysProbe> <ColumnReference Database="Database1" Schema="Schema1" Table="Object2" Column="Column3" /> </HashKeysProbe> <ProbeResidual> <ScalarOperator ScalarString="ScalarString3"> <Compare CompareOp="EQ"> <ScalarOperator> <Identifier> <ColumnReference Database="Database1" Schema="Schema1" Table="Object2" Column="Column3" /> </Identifier> </ScalarOperator> <ScalarOperator> <Identifier> <ColumnReference Database="Database1" Schema="Schema1" Table="Object3" Column="Column14" /> </Identifier> </ScalarOperator> </Compare> </ScalarOperator> </ProbeResidual> <RelOp AvgRowSize="51" EstimateCPU="0.0007422" EstimateIO="0.0409028" EstimateRebinds="0" EstimateRewinds="0" EstimatedExecutionMode="Row" EstimateRows="532" EstimatedRowsRead="532" LogicalOp="Clustered Index Scan" NodeId="4" Parallel="false" PhysicalOp="Clustered Index Scan" EstimatedTotalSubtreeCost="0.041645" TableCardinality="532"> <OutputList> <ColumnReference Database="Database1" Schema="Schema1" Table="Object3" Column="Column14" /> <ColumnReference Database="Database1" Schema="Schema1" Table="Object3" Column="Column11" /> </OutputList> <RunTimeInformation> <RunTimeCountersPerThread Thread="0" ActualRows="532" ActualRowsRead="532" Batches="0" ActualEndOfScans="1" ActualExecutions="1" ActualExecutionMode="Row" ActualElapsedms="0" ActualCPUms="0" ActualScans="1" ActualLogicalReads="54" ActualPhysicalReads="0" ActualReadAheads="0" ActualLobLogicalReads="0" ActualLobPhysicalReads="0" ActualLobReadAheads="0" /> </RunTimeInformation> <IndexScan Ordered="false" ForcedIndex="false" ForceScan="false" NoExpandHint="false" Storage="RowStore"> <DefinedValues> <DefinedValue> <ColumnReference Database="Database1" Schema="Schema1" Table="Object3" Column="Column14" /> </DefinedValue> <DefinedValue> <ColumnReference Database="Database1" Schema="Schema1" Table="Object3" Column="Column11" /> </DefinedValue> </DefinedValues> <Object Database="Database1" Schema="Schema1" Table="Object3" Index="Index2" IndexKind="Clustered" Storage="RowStore" /> </IndexScan> </RelOp> <RelOp AvgRowSize="2479" EstimateCPU="1.9342" EstimateIO="52.1728" EstimateRebinds="0" EstimateRewinds="0" EstimatedExecutionMode="Row" EstimateRows="1758220" EstimatedRowsRead="1758220" LogicalOp="Clustered Index Scan" NodeId="5" Parallel="false" PhysicalOp="Clustered Index Scan" EstimatedTotalSubtreeCost="54.107" TableCardinality="1758220"> <OutputList> <ColumnReference Database="Database1" Schema="Schema1" Table="Object2" Column="Column1" /> <ColumnReference Database="Database1" Schema="Schema1" Table="Object2" Column="Column2" /> <ColumnReference Database="Database1" Schema="Schema1" Table="Object2" Column="Column3" /> <ColumnReference Database="Database1" Schema="Schema1" Table="Object2" Column="Column4" /> <ColumnReference Database="Database1" Schema="Schema1" Table="Object2" Column="Column5" /> <ColumnReference Database="Database1" Schema="Schema1" Table="Object2" Column="Column6" /> <ColumnReference Database="Database1" Schema="Schema1" Table="Object2" Column="Column13" /> <ColumnReference Database="Database1" Schema="Schema1" Table="Object2" Column="Column7" /> <ColumnReference Database="Database1" Schema="Schema1" Table="Object2" Column="Column8" /> <ColumnReference Database="Database1" Schema="Schema1" Table="Object2" Column="Column9" /> <ColumnReference Database="Database1" Schema="Schema1" Table="Object2" Column="Column10" /> </OutputList> <RunTimeInformation> <RunTimeCountersPerThread Thread="0" ActualRows="1758223" ActualRowsRead="1758223" Batches="0" ActualEndOfScans="1" ActualExecutions="1" ActualExecutionMode="Row" ActualElapsedms="481" ActualCPUms="481" ActualScans="1" ActualLogicalReads="70819" ActualPhysicalReads="0" ActualReadAheads="0" ActualLobLogicalReads="0" ActualLobPhysicalReads="0" ActualLobReadAheads="0" /> </RunTimeInformation> <IndexScan Ordered="false" ForcedIndex="false" ForceScan="false" NoExpandHint="false" Storage="RowStore"> <DefinedValues> <DefinedValue> <ColumnReference Database="Database1" Schema="Schema1" Table="Object2" Column="Column1" /> </DefinedValue> <DefinedValue> <ColumnReference Database="Database1" Schema="Schema1" Table="Object2" Column="Column2" /> </DefinedValue> <DefinedValue> <ColumnReference Database="Database1" Schema="Schema1" Table="Object2" Column="Column3" /> </DefinedValue> <DefinedValue> <ColumnReference Database="Database1" Schema="Schema1" Table="Object2" Column="Column4" /> </DefinedValue> <DefinedValue> <ColumnReference Database="Database1" Schema="Schema1" Table="Object2" Column="Column5" /> </DefinedValue> <DefinedValue> <ColumnReference Database="Database1" Schema="Schema1" Table="Object2" Column="Column6" /> </DefinedValue> <DefinedValue> <ColumnReference Database="Database1" Schema="Schema1" Table="Object2" Column="Column13" /> </DefinedValue> <DefinedValue> <ColumnReference Database="Database1" Schema="Schema1" Table="Object2" Column="Column7" /> </DefinedValue> <DefinedValue> <ColumnReference Database="Database1" Schema="Schema1" Table="Object2" Column="Column8" /> </DefinedValue> <DefinedValue> <ColumnReference Database="Database1" Schema="Schema1" Table="Object2" Column="Column9" /> </DefinedValue> <DefinedValue> <ColumnReference Database="Database1" Schema="Schema1" Table="Object2" Column="Column10" /> </DefinedValue> </DefinedValues> <Object Database="Database1" Schema="Schema1" Table="Object2" Index="Index3" IndexKind="Clustered" Storage="RowStore" /> </IndexScan> </RelOp> </Hash> </RelOp> </Hash> </RelOp> </ComputeScalar> </RelOp> </QueryPlan> </StmtSimple> </Statements> </Batch> </BatchSequence> </ShowPlanXML>
In this execution plan, we can see from the "WaitStats" section that our query only spent a total of about 28ms waiting. It only took 5 milliseconds to compile, but, if you search for "ElapsedTime", you see that it took 17919 milliseconds, or just shy of 18 seconds, to run. So, this is just a slow query.
At this point we need to analyze the execution plan further to see where all that time is being spent and go from there to solve it. Maybe we need to add a new non-clustered index somewhere, or maybe we can add a new where clause to reduce the number of results on one side of an expensive join. There are many different causes of this problem and many different solutions, and that's outside the scope of this article.
The takeaway
When you run into a database performance issue with SQL Server, it can feel overwhelming to try and troubleshoot it, but the first step is always going to be to gather information. If you start with the steps outlined in this article, you can quickly narrow down the problem and get to an answer faster. Remember, the first step in your troubleshooting journey is finding out what your query is spending so much time doing: compiling, waiting, or running.
Learn more about our Application Development expertise and contact us for your next project.