Why does this EF query take so long?

Question

We have an EF4 query that is taking about 10 seconds to complete. The query isn't so complex, but as there are a lot of related tables included, it's taking a long time. I'm trying to speed it up.

The original query looks something like this (shortened for clarity)...

var supportTickets = ctx.SupportTickets
  .Include(s => s.System.Customer.Country)
  .Include(s => s.System.Site.Address.Country)
  // other includes omitted
  .OrderByDescending(s => s.ID)
  .ToList();
var ticketsList = supportTickets
  .Select(CreateSupportTicketListOverview)
  .ToList();

CreateSupportTicketListOverview() is a method that takes the entity and returns a DTO based on it. A shortened version of it looks like this...

private static SupportTicketListOverview CreateSupportTicketListOverview(SupportTicket x)
  {
    return new SupportTicketListOverview {
      ID = x.ID,
      SystemNumber = x.System != null ? x.System.SystemNumber : "",
      CustomerName = x.System != null && x.System.Customer != null ? x.System.Customer.Name : "",
      ShortSummary = x.ShortSummary,
      SiteName = x.Site != null ? x.Site.SiteName : "",
      Status = x.Status != null ? x.Status.Description : "",
      // other properties omitted for clarity
    };
  }

As I said, this takes about 10 seconds and returns just under 4000 results. SQL Server Profiler shows that the query took about 6.6s. If we copy the SQL that is generated and run that on its own, it only takes about 2 seconds, which confuses me. Why is it so much faster when run on its own? The time needed to create the entities would not be included in the database query would it? If it were, what is the rest of the time spent doing?

I tried to improve this by turning off tracking and pulling just the required data from the database, rather than the full entities. The revised code looks like this (again shortened for clarity)...

  var tickets = ((SalesTrackerCRMEntities) getContext()).SupportTickets
      .AsNoTracking()
      .Include(s => s.System.Customer.Country)
      .Include(s => s.System.Site.Address.Country)
      .OrderByDescending(s => s.ID)
      .Select(t => new {
        SystemNumber = t.System != null ? t.System.DHRNumber : "", t.ID,
        CustomerName = t.System != null && t.System.Customer != null ? t.System.Customer.Name : "",
        SiteName = t.Site != null ? t.Site.SiteName : "",
        Status = t.Status != null ? t.Status.Description : "",
        // other stuff omitted
      })
      .AsEnumerable();
  var tickets1 =tickets
      .Select(t => new SupportTicketListOverview {
        ID = t.ID,
        SystemNumber = t.SystemNumber,
        CustomerName = t.CustomerName,
        ShortSummary = t.ShortSummary,
        SiteName = t.SiteName,
        Status = t.Status,
        // other stuff omitted
      })
      .ToList();

To my surprise, this took about 15 seconds to complete. Looking in the profiler, the database query itself took around 0.7s, ie ten times faster than the original query, but the EF query overall took 50% longer.

So I'm completely confused. I did some searching, but all the advice I found was for things I'm already doing. For example, this blog post gives seven ways to improve EF performance. These include not using the repository pattern (wasn't really sure what he meant here, as he didn't show any example of how to do or not to do it), not using paging (we don't), using projections (we are, at least in the new query), turning off lazy loading (it was off already), turning off tracking (already did) and using indexes on the tables (we already are). The final tip was to reduce the number of queries. Can't see how we can do this here, as we need all the related data.

In summary, the original database query takes 6.6s, and the overall EF query takes 10s. The revised query takes .7s for the database part, but 15s for the overall EF query. All of these are far too long.

Is anyone able to advise how I can speed up the query? Thanks

Is your database server in another region? I had (kind of) similar issue when my azure web app was hosted in US region and my database (wrongly) in Brazil region. — Developer, Nov 10 '16 at 17:17
Are the tables your accessing properly indexed? EF4 sucks in terms of assembling a decent query. — Neo, Nov 10 '16 at 17:22
http://stackoverflow.com/questions/2876616/returning-ienumerablet-vs-iqueryablet — Hackerman, Nov 10 '16 at 17:23
@Developer It's all in the same location, so that's not it. Thanks anyway — DreamingOfSleep, Nov 10 '16 at 17:29
@MisterPositive As I said in my qyestion, all tables are indexed. Thanks anyway — DreamingOfSleep, Nov 10 '16 at 17:30
@DreamingOfSleep I read your question correctly. Have you taken the query that is generated by EF and executed it in SSMS to verify your indexes are being used? — Neo, Nov 10 '16 at 17:32
@MisterPositive Forgive my mistake, please can you explain how I would tell if the indexes are being used? I have run the query in SSMS, but can't see where I would find out about the indexes. Thanks — DreamingOfSleep, Nov 10 '16 at 17:40
You can start here. Its a very broad subject :-) https://www.simple-talk.com/sql/performance/execution-plan-basics/ — Neo, Nov 10 '16 at 17:41
@MisterPositive Thanks for that. Unfortunately, the SQL that EF produces is a stored procedure, so the execution plan only has one step, and doesn't seem to show any details about the indexes. I'm going to try and pull the SQL out of the sp and run it as a plain query, but given the length and complexity, I'm not sure how easy that will be. — DreamingOfSleep, Nov 10 '16 at 17:54
Also look at @Hackerman comment. That link is also potentially relevant. These types of issues are the most painful IMHO. — Neo, Nov 10 '16 at 17:54
@Hackerman +1 for the link, it's gold dust! Sadly, it didn't make any difference in my case — DreamingOfSleep, Nov 10 '16 at 17:55
This is one of the reasons about, why I hate EF!..so there is no difference using `IQueryable supportTickets` and removing the `ToList`? — Hackerman, Nov 10 '16 at 18:02
@Hackerman I can't remove it altogether, I need to enumerate the query before converting to the DTO, as the latter code uses some stuff (removed for clarity!) that can't be passed to the database. I tried a few variations of what I produce, but none made any difference — DreamingOfSleep, Nov 10 '16 at 18:21
Yeah, but you can do the `ToList` to the `IQueryable` object in another line....basically do the IQueryable part, and once you get the result transform it to list. — Hackerman, Nov 10 '16 at 18:25
@Hackerman Sorry, I don't follow. If I create an IQ, then on the next line call ToList(), what difference is it from just calling ToList() before? — DreamingOfSleep, Nov 10 '16 at 20:32
How many other includes are you using? Using too many is a red flag that perhaps the design of your queries/entities needs attention. The most resource-demanding part you should pay close attention to is the actual projection cost of a query, not the query itself. Try using Lazy Loading instead of eager loading as this last one has a performance penalty: https://msdn.microsoft.com/en-us/library/jj574232(v=vs.113).aspx — Charles, Nov 10 '16 at 20:52
Is this the first request after connecting to the database? The first request after opening the *first* connection requires EF to read all data and generate the internal model. This takes it's time. — Stephen Reindl, Nov 10 '16 at 21:45
@Charles We are already using lazy loading, and the reason we have so many includes is because we are flattening a very complex hierarchy of tables. The design is fine, it's just a very complex scenario. As it happens, I tried switching lazy loading back on to see if it made any difference, and it didn't — DreamingOfSleep, Nov 15 '16 at 15:35
@StephenReindl No, this isn't the first connect, this happens every time. I time it by making the call once to get past the first time, then a further ten times, taking an average of the time required for each of those ten. — DreamingOfSleep, Nov 15 '16 at 15:36
I f you really need all that information, I think you need to rethink the strategy you are using to get the information. Those includes are killing the application's performance and are going to cause you a lot of problems in the future. Execute separate queries and only get the information you need. Splitting the process in smaller parts will make things better. A few links of interest: Include pitfalls: http://mikee.se/Archive.aspx/Details/entity_framework_pitfalls,_include_20140101 The CQRS pattern: https://msdn.microsoft.com/en-us/library/dn568103.aspx — Charles, Nov 15 '16 at 18:52
@Charles Thanks for those links. As it happens, splitting it down into multiple queries was the next thing on my list of experiments. I've done this elsewhere with good results. The CORS article looks well worth reading. Printed it out and will go through it carefully. Thanks again. — DreamingOfSleep, Nov 17 '16 at 15:21
@DreamingOfSleep how did you fix this? facing same issue here — Mohammad Ali, Dec 18 '20 at 12:27

score 0 · Answer 1 · answered Dec 08 '16 at 15:34

What version of SQL Server are you using? if it's 2016 you can enable Query Store (https://msdn.microsoft.com/en-us/library/dn817826.aspx) and find what t-sql query is being executed by your EF4 query. If it's older version you can, while you EF4 query is running use this (http://blog.sqlauthority.com/2009/01/07/sql-server-find-currently-running-query-t-sql/) to find query text and see why the query is slow by running it against the server and analyzing the plan/missing indexes/etc.

Thanks, but as I said in my original question, if we copy the SQL into SSMS, it only takes about 2s to run, so that's not the problem. — Avrohom Yisroel, Dec 11 '16 at 14:59

Why does this EF query take so long?

1 Answers1