Sql-server – Performance problem with big query on first run

entity-frameworkperformancesql server

I'm having a problem with a query usually being so slow on first time run that it times out and then executing in under a second once it's loaded into cache.

The query looks something like this

exec sp_executesql N'SELECT
    [Project1].RecordID AS [RecordId],
    ...
    FROM ( SELECT
        [Extent1].RecordId] AS [RecordId],
        ...
        FROM Items AS [Extent1]
        LEFT OUTER JOIN ItemParameters as [Extent2] 
        ON [Extent1].[RecordId] = [Extent2].[SampleId]
        WHERE ...
    ) as [Project1]
    ORDER BY [Project1].CreatedDate DESC, [Project1].RecordId ASC, ...

The query is generated by EntityFramework for me and only has this one join. The Items table is ~3.5 million rows and ~2.5 GB data and the ItemParameters is ~23.6 million rows and ~19.2 GB data. The query returns 11400 rows and, as far as I can tell, properly hits the indexes.

I've written a test program that does this in a loop, forever:

  • Restart the SQL Server service (MSSQLSERVER).
  • Sleep for 6 minutes. To allow it to start up.
  • Execute above query.
  • Write execution time to a file.

The results are disturbing. Sometimes it takes 4 minutes and sometimes it takes 4 seconds and I don't see why. It is running on a VM Ware virtual machine. On my developer laptop the same query (against a third of the data) is completed in 3 seconds.

I've run it with set statistics io on and set statistics time on and the output looks like this:

(11409 rows affected)
Table 'ItemParameters'. Scan count 3803, logical reads 19689, physical reads 2724, read-ahead reads 4261, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
Table 'Items'. Scan count 109, logical reads 40423, physical reads 4, read-ahead reads 4089, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.

 SQL Server Execution Times:
   CPU time = 546 ms,  elapsed time = 92636 ms.

 SQL Server Execution Times:
   CPU time = 702 ms,  elapsed time = 94012 ms.

Things I've done to speed up performance:

What can I do to make sure the query executes quickly enough every time? Any help is greatly appreciated.

EDIT

Best Answer

What can I do to make sure the query executes quickly enough every time?

It's unlikely that this is a query performance issue. You're doing very little IO, using very little CPU time, and the query isn't processing very much data. The likely solution will be to resolve the hardware or configuration issue that is causing your query to run for so long sometimes. In one of your executions the query 92636 ms of elapsed time but only used 546 ms of CPU time That means that SQL Server was waiting for something for over 92 seconds during query execution. Based on your description of the problem it's likely that there's a severe IO problem on the server. 11000 physical reads isn't that much and what you're seeing isn't normal.

You didn't include your version of SQL Server, but to get more information about the problem I would look at wait stats. You seem to have control over the server so you can try taking a before and after snapshot of the sys.dm_os_wait_stats DMV and seeing which waits increase after the query finishes executing. That DMV is server wide so you'll want to avoid running other queries if possible. You can also reset the DMV immediately before running your query by running the following T-SQL:

DBCC SQLPERF ("sys.dm_os_wait_stats" , CLEAR);

The wait stats should let you confirm if IO is indeed the problem. You may need to work with the admin in charge of the VM or storage to resolve this issue.