Same SQL query is fast or slow depending on execution context

Question

I've encountered a strange phenomena then investigatating a slow view of a typical ASP.NET MVC application. One of the queries is running ridiculously slow for no obvious reason. The LINQ query in question look like this (Db is DbContext):

var testResults = Db.CustomTestResults
    .Include(tr => tr.TestMachine.Platform)
    .Include(tr => tr.TestCase)
    .Include(tr => tr.CustomTestResultAnalysis.Select(tra => tra.AnalysisOutcomeData))
    .Where(tr => tr.CustomTestBuildId == testBuild.Id)
    .ToList()
    .AsReadOnly();

nothing special actually. Depending on filter query result set can vary in size, from 10 to 10000 records at max.

The SQL generated query (captured by LINQ debug log), executed from SSMS, runs fast, about 2 seconds for the largest sets and less than a second for smaller ones. However then run by IIS strange things happen. The queries began to run like ~1/100x slower speed. The smaller ones take ~10 seconds to execute, the larger are failing due to query execution timeout. I'm not sure if any other queries are affected, but this one is only that is dealing with large data sets, so it's most obvious to notice the problem.

As this was not confusing enough this same code was running perfectly as expected not so long ago. So the bug seems to be caused by some external factors. The database is SQL Server 2014 SP2, EF is at v6.2, IIS 7.5.

Would appreciate any ideas in what areas and how I could investigate this further.

Use XEvent Profiler or the (deprecated) SQL Server Profiler to capture the events around the EF query's execution and the *actual* execution plan. EF may be setting an unexpected setting, use batching to load the data or use a slow cursor - which it shouldn't. Extended Events can capture a lot more than SQL Server profiler — Panagiotis Kanavos, Dec 22 '17 at 11:07
Try using a microORM like Dappert for reporting queries to avoid such unfortunate decisions by EF too. You should disable change tracking for reporting queries if you haven't already, although that can't explain an orders-of-magnitude delay — Panagiotis Kanavos, Dec 22 '17 at 11:09
BTW I've encountered the same issue. A query that run just fine with SSMS started taking significantly longer with EF after months. Change tracking *was* disabled. — Panagiotis Kanavos, Dec 22 '17 at 11:53
@PanagiotisKanavos actually this makes a lot of sense, thank you. That would explain why the performance whould change suddenly without any reason. Unfortunatelly I don't have priveleges to run profiler. Is there any way I can regulate which query options EF uses, and force them in some way? — Petr Abdulin, Dec 22 '17 at 12:06
If you don't know what happened, you can't fix it. In SQL Server 2014 tracing is done through Extended Events, not the Profiler. Can't you start an XE session from SSMS? If you can't do it on production, try it on a test environment. The sequence of events will be the same — Panagiotis Kanavos, Dec 22 '17 at 12:16
@PetrAbdulin, Erland Sommarskog's article [Slow in the Application, Fast in SSMS](http://www.sommarskog.se/query-plan-mysteries.html) may help explain the reason. Especially, make sure the SSMS query is executed as a parameterized query using `sp_executesql` rather than with local variables or literals and make sure the session SET settings are the same. — Dan Guzman, Dec 22 '17 at 12:20

score 1 · Accepted Answer · answered Dec 26 '17 at 06:44

As it turned out, the issue was in SQL Server optimizations, which start to work some time after multiple runs of the similar queries. This problem can be detected by any nonrelevant change to the original query, which fixes performance for some time.

This behaviour can be properly mitigated by controlling query command options. One of the solutions for EF is demonstrated here.

As a temporary "quick-and-dirty" solution I used this approach to randomize query each time, thus preventing optimizations by SQL Server engine:

private static IQueryable<CustomTestResult> RandomizeQuery(IQueryable<CustomTestResult> query)
{
    const int minConditions = 1;
    const int maxConditions = 5;
    const int minId = -100;
    const int maxId = -1;

    var random = new Random();
    var conditionsCount = random.Next(minConditions, maxConditions);
    for (int i = 0; i < conditionsCount; i++)
    {
        var randomId = random.Next(minId, maxId);
        query = query.Where(test => test.Id != randomId);
    }

    return query;
}

score 0 · Answer 2 · answered Dec 22 '17 at 11:02

0

Since the SQL has not changed but it is having issues depending on what platform you run on I would start with your settings. A GREAT reference for the whys and hows is written by Erland Sommarskog this: http://www.sommarskog.se/query-plan-mysteries.html

It is long but I imagine you will find your answer in there.

answered Dec 22 '17 at 11:02

JMabee

2,230
2
9
13

1

This should be a comment since it doesn't asnwer the question. The *database* is the same, so the settings shouldn't matter. The *actual* execution plan for the EF query may be different, maybe not. Erland's article doesn't talk about this though – Panagiotis Kanavos Dec 22 '17 at 11:04

Same SQL query is fast or slow depending on execution context

2 Answers2