Why is Entity Framework taking 30 seconds to load records when the generated query only takes 1/2 of a second?

Question

The executeTime below is 30 seconds the first time, and 25 seconds the next time I execute the same set of code. When watching in SQL Profiler, I immediately see a login, then it just sits there for about 30 seconds. Then as soon as the select statement is run, the app finishes the ToList command. When I run the generated query from Management Studio, the database query only takes about 400ms. It returns 14 rows and 350 columns. It looks like time it takes transforming the database results to the entities is so small it is not noticable.

So what is happening in the 30 seconds before the database call is made?

If entity framework is this slow, it is not possible for us to use it. Is there something I am doing wrong or something I can change to speed this up dramatically?

UPDATE: All right, if I use a Compiled query, the first time it take 30 seconds, and the second time it takes 1/4th of a second. Is there anything I can do to speed up the first call?

using (EntitiesContext context = new EntitiesContext()) 
{ 
    Stopwatch sw = new Stopwatch(); 
    sw.Start(); 
    var groupQuery = (from g in context.Groups.Include("DealContract") 
                    .Include("DealContract.Contracts") 
                    .Include("DealContract.Contracts.AdvertiserAccountType1") 
                    .Include("DealContract.Contracts.ContractItemDetails") 
                    .Include("DealContract.Contracts.Brands") 
                    .Include("DealContract.Contracts.Agencies") 
                    .Include("DealContract.Contracts.AdvertiserAccountType2") 
                    .Include("DealContract.Contracts.ContractProductLinks.Products") 
                    .Include("DealContract.Contracts.ContractPersonnelLinks") 
                    .Include("DealContract.Contracts.ContractSpotOrderTypes") 
                    .Include("DealContract.Contracts.Advertisers") 
                where g.GroupKey == 6 
                select g).OfType<Deal>(); 
    sw.Stop(); 
    var queryTime = sw.Elapsed; 
    sw.Reset(); 
    sw.Start(); 
    var groups = groupQuery.ToList(); 
    sw.Stop(); 
    var executeTime = sw.Elapsed; 
}

Answer 1

It is because of the Include. My guess is that you are eager loading a lot of objects into the memory. It takes much time to build the c# objects that corresponds to your db entities.

My recommendation for you is to try to lazy load only the data you need.

Answer 2

EF takes a while to start up. It needs build metadata from xml and probably generates objects used for mapping. So it takes a few sec to start up, i don't think there is a way to get around that, except never restarting your program.

Answer 3

The only way to make the initial compilation of the query faster that I know of is to make the query less complex. The MSDN documentation on performance considerations for the Entity Framework and Compiled Queries don't indicate that there is any way to save a compiled query for use in a different application execution session.

I would add that we have found that having lots of Includes can make query execution slower than having fewer Includes and doing more Loads on related entities later. Some trial and error is required to find the right medium.

However, I have to ask if you really need every property of every entity you are including here. It seems to me that there is a large number of different entity types in this query, so materializing them could well be quite expensive. If you are just trying to get tabular results which you don't intend to update, projecting the (relatively) fewer number of fields that you actually need into a flat, anonymous type should be significantly faster for various reasons. Also, this frees you from having to worry about eager loading, calling Load/IsLoaded, etc.

You can certainly speed up the initial view generation by precompiling the entity views. There is documentation on MSDN for this. But since you pay that cost at the time the first query is executed, your test with a simple query shows that this is running in the neighborhood of 2 seconds for you. It's nice to say that 2 seconds, but it won't save anything else.

Answer 4

I had this exact same problem, my query was taking 40 seconds.

I found the problem was with the .Include("table_name") functions. The more of these I had, the worse it was. Instead I changed my code to Lazy Load all the data I needed right after the query, this knocked the total time down to about 1.5 seconds from 40 seconds. As far as I know, this accomplishes the exact same thing.

So for your code it would be something like this:

            var groupQuery = (from g in context.Groups
                        where g.GroupKey == 6 
                        select g).OfType<Deal>(); 

            var groups = groupQuery.ToList();

            foreach (var g in groups)
            {
                // Assuming Dealcontract is an Object, not a Collection of Objects
                g.DealContractReference.Load();
                if (g.DealContract != null)
                {
                    foreach (var d in g.DealContract)
                    {
                        // If the Reference is to a collection, you can just to a Straight ".Load"
                        //  if it is an object, you call ".Load" on the refence instead like with "g.DealContractReference" above
                        d.Contracts.Load();
                        foreach (var c in d.Contracts)
                        {
                            c.AdvertiserAccountType1Reference.Load();
                            // etc....
                        }
                    }
                }
            }

Incidentally, if you were to add this line of code above the query in your current code, it would knock the time down to about 4-5 seconds (still too ling in my option) From what I understand, the "MergeOption.NoTracking" option disables a lot of the tracking overhead for updating and inserting stuff back into the database:

context.groups.MergeOption = MergeOption.NoTracking;