Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Include or Where .AsNotracking queries seems to perform worse in EF Core than leaving the .AsNotracking property out. #14366

Open
HjalteParner opened this issue Jan 10, 2019 · 12 comments

Comments

@HjalteParner
Copy link

Include or Where .AsNotracking queries seems to perform worse in EF Core than leaving the .AsNotracking property out. This was not the case in EF 6.

So while DbSet.AsNoTracking.ToList() is slightly better or on par with DbSet.AsNoTracking.ToList()
then

DbSet.Where.AsNoTracking.ToList()
DbSet.Include.AsNoTracking.ToList()
DbSet.Include.Where.AsNoTracking.ToList()

performance a lot worse than

DbSet.Where.ToList()
DbSet.Include.ToList()
DbSet.Include.Where.ToList()

respectively.

Steps to reproduce

using Microsoft.EntityFrameworkCore;
using System;
using System.Collections.Generic;
using System.Linq;

namespace ConsoleApp2
{
    class Program
    {
        static void Main(string[] args)
        {
            Console.WriteLine("{0} Start EF Core", DateTime.Now);

            using (var context = new BlogContext())
            {
                context.ChangeTracker.AutoDetectChangesEnabled = false;
                
                // Create new database
                //Console.WriteLine("{0} Create Database", DateTime.Now);
                //context.Database.EnsureDeleted();
                //context.Database.EnsureCreated();

                // Add blog posts
                //Console.WriteLine("{0} Add Blog Posts", DateTime.Now);
                //for (int i = 0; i < 100000; i++)
                //{
                //    var blog = new Blog();
                //    blog.Posts = new List<Post>();
                //    for (int j = 0; j < 10; j++)
                //    {
                //        var post = new Post();
                //        blog.Posts.Add(post);
                //    }
                //    context.Blogs.Add(blog);
                //    context.SaveChanges();
                //}

                // Query blogs
                List<Post> posts;
                Console.WriteLine("{0} Query blog posts", DateTime.Now);
                posts = context.Posts.ToList();
                Console.WriteLine("{0} context.Posts.ToList() {1}", DateTime.Now, posts.Count);
                posts = context.Posts.ToList();
                Console.WriteLine("{0} context.Posts.ToList() {1}", DateTime.Now, posts.Count);
                posts = context.Posts.AsNoTracking().ToList();
                Console.WriteLine("{0} context.Posts.AsNoTracking().ToList() {1}", DateTime.Now, posts.Count);
                posts = context.Posts.Where(p => p.Blog.BlogID > 100).ToList();
                Console.WriteLine("{0} context.Posts.Where(p => p.Blog.BlogID > 100).ToList() {1}", DateTime.Now, posts.Count);
                posts = context.Posts.Where(p => p.Blog.BlogID > 100).AsNoTracking().ToList();
                Console.WriteLine("{0} context.Posts.Where(p => p.Blog.BlogID > 100).AsNoTracking().ToList() {1}", DateTime.Now, posts.Count);
                posts = context.Posts.Include(p => p.Blog).ToList();
                Console.WriteLine("{0} context.Posts.Include(p => p.Blog).ToList() {1}", DateTime.Now, posts.Count);
                posts = context.Posts.Include(p => p.Blog).AsNoTracking().ToList();
                Console.WriteLine("{0} context.Posts.Include(p => p.Blog).AsNoTracking().ToList() {1}", DateTime.Now, posts.Count);
                posts = context.Posts.Include(p => p.Blog).Where(p => p.Blog.BlogID > 100).ToList();
                Console.WriteLine("{0} context.Posts.Include(p => p.Blog).Where(p => p.Blog.BlogID > 100).ToList() {1}", DateTime.Now, posts.Count);
                posts = context.Posts.Include(p => p.Blog).Where(p => p.Blog.BlogID > 100).AsNoTracking().ToList();
                Console.WriteLine("{0} context.Posts.Include(p => p.Blog).Where(p => p.Blog.BlogID > 100).AsNoTracking().ToList() {1}", DateTime.Now, posts.Count);
            }

            Console.WriteLine("{0} End", DateTime.Now);
        }
    }

    public class Blog
    {
        public int BlogID { get; set; }
        public List<Post> Posts { get; set; }
    }

    public class Post
    {
        public int PostID { get; set; }
        public int BlogID { get; set; }
        public Blog Blog { get; set; }
    }

    public class BlogContext: DbContext
    {
        public DbSet<Blog> Blogs { get; set; }
        public DbSet<Post> Posts { get; set; }

        protected override void OnConfiguring(DbContextOptionsBuilder optionsBuilder)
        {
            optionsBuilder.UseSqlServer(@"Server=(localdb)\MSSQLLocalDB;Database=EFCore;Trusted_Connection=True;");
        }
    }
}
@ajcvickers
Copy link
Contributor

@HjalteParner There are a couple dimensions beyond tracking/no-tracking here, so I updated your test code to separate them out more--see below. The dimensions I split out are:

  • The first time a query is run it must be compiled.
  • If entities are already tracked by the context, then a tracking query will return those instances rather than creating new.

Here's what I see:

Running once to prime the query cache...
Test case ToList ran 1 iterations in 4205ms
Test case NoTrackingToList ran 1 iterations in 641ms
Test case Where ran 1 iterations in 37284ms
Test case NoTrackingWhere ran 1 iterations in 28720ms
Test case Include ran 1 iterations in 62706ms
Test case NoTrackingInclude ran 1 iterations in 40460ms
Test case WhereInclude ran 1 iterations in 64198ms
Test case NoTrackingWhereInclude ran 1 iterations in 40912ms

Running with posts already tracked...
Test case ToList ran 1 iterations in 772ms
Test case NoTrackingToList ran 1 iterations in 540ms
Test case Where ran 1 iterations in 866ms
Test case NoTrackingWhere ran 1 iterations in 27995ms
Test case Include ran 1 iterations in 9204ms
Test case NoTrackingInclude ran 1 iterations in 37974ms
Test case WhereInclude ran 1 iterations in 10986ms
Test case NoTrackingWhereInclude ran 1 iterations in 37481ms

Running with posts not tracked...
Test case ToList ran 1 iterations in 5103ms
Test case NoTrackingToList ran 1 iterations in 550ms
Test case Where ran 1 iterations in 37600ms
Test case NoTrackingWhere ran 1 iterations in 28572ms
Test case Include ran 1 iterations in 61652ms
Test case NoTrackingInclude ran 1 iterations in 37712ms
Test case WhereInclude ran 1 iterations in 64283ms
Test case NoTrackingWhereInclude ran 1 iterations in 39485ms

Observations:

  • With such a lot of data being queried, the query compilation part is negligible.
  • When the context is not already tracking any entities, no-tracking is always faster
  • When the context is tracking entities, then tracking queries can be faster. Note that this is also the case for EF6 with at least some queries, although I don't know how much difference it makes, or what it pivots on.)

We'll look at this in triage, but from what I see the results look basically expected.

public class Program
{
    public static void Main()
    {
        //using (var context = new BlogContext())
        //{
        //    Console.WriteLine("Seeding...");

        //    context.ChangeTracker.AutoDetectChangesEnabled = false;

        //    context.Database.EnsureDeleted();
        //    context.Database.EnsureCreated();

        //    for (int i = 0; i < 100000; i++)
        //    {
        //        var blog = new Blog {Posts = new List<Post>()};

        //        for (var j = 0; j < 10; j++)
        //        {
        //            blog.Posts.Add(new Post());
        //        }

        //        context.Add(blog);
        //    }

        //    context.SaveChanges();
        //}

        Console.WriteLine("Running once to prime the query cache...");
        TimeQueries(1, false);

        Console.WriteLine("Running with posts already tracked...");
        TimeQueries(1, true);

        Console.WriteLine("Running with posts not tracked...");
        TimeQueries(1, false);
    }

    private static void TimeQueries(int iterations, bool postsLoaded)
    {
        foreach (TestCase testCase in Enum.GetValues(typeof(TestCase)))
        {
            using (var context = new BlogContext())
            {
                context.ChangeTracker.AutoDetectChangesEnabled = false;

                List<Post> posts;

                if (postsLoaded)
                {
                    posts = context.Posts.ToList();
                }

                var timer = Stopwatch.StartNew();

                for (var i = 0; i < iterations; i++)
                {
                    switch (testCase)
                    {
                        case TestCase.ToList:
                            posts = context.Posts.ToList();
                            break;
                        case TestCase.NoTrackingToList:
                            posts = context.Posts.AsNoTracking().ToList();
                            break;
                        case TestCase.Where:
                            posts = context.Posts.Where(p => p.Blog.BlogID > 100).ToList();
                            break;
                        case TestCase.NoTrackingWhere:
                            posts = context.Posts.Where(p => p.Blog.BlogID > 100).AsNoTracking().ToList();
                            break;
                        case TestCase.Include:
                            posts = context.Posts.Include(p => p.Blog).ToList();
                            break;
                        case TestCase.NoTrackingInclude:
                            posts = context.Posts.Include(p => p.Blog).AsNoTracking().ToList();
                            break;
                        case TestCase.WhereInclude:
                            posts = context.Posts.Include(p => p.Blog).Where(p => p.Blog.BlogID > 100).ToList();
                            break;
                        case TestCase.NoTrackingWhereInclude:
                            posts = context.Posts.Include(p => p.Blog).Where(p => p.Blog.BlogID > 100).AsNoTracking().ToList();
                            break;
                    }
                }

                timer.Stop();

                Console.WriteLine($"Test case {testCase} ran {iterations} iterations in {timer.ElapsedMilliseconds}ms");
            }
        }
    }
}

public enum TestCase
{
    ToList,
    NoTrackingToList,
    Where,
    NoTrackingWhere,
    Include,
    NoTrackingInclude,
    WhereInclude,
    NoTrackingWhereInclude
}

public class Blog
{
    public int BlogID { get; set; }
    public List<Post> Posts { get; set; }
}

public class Post
{
    public int PostID { get; set; }
    public int BlogID { get; set; }
    public Blog Blog { get; set; }
}

public class BlogContext : DbContext
{
    public DbSet<Blog> Blogs { get; set; }
    public DbSet<Post> Posts { get; set; }

    protected override void OnConfiguring(DbContextOptionsBuilder optionsBuilder)
    {
        optionsBuilder.UseSqlServer(@"Server=(localdb)\mssqllocaldb;Database=Test;ConnectRetryCount=0");
    }
}

@HjalteParner
Copy link
Author

HjalteParner commented Jan 11, 2019

@ajcvickers Thanks for your comprehensive answer and your refactoring of my test code, which is much neater now.

You are correct that my issue has more to do with the Include and Where clause than Tracking vs. No Tracking and in addition even more to do with the performance comparison between EF Core vs. EF6 so the title should probably be changed to reflect this, if you agree that there is an issue with EF Core.

Unfortunately having already tracked entities is not possible for me as my production database is huge compared to the test database presented here - which is why I need the Where clause
in addition to the some details from the parent (in fact in the production, it's from the grandparent) as well - which is why i need the include (join).

I have made a test using your refactored code on my computer using both EF6 and EF Core.

Below is my results:

EF6
Running once to prime the query cache...
Test case ToList ran 1 iterations in 30635ms
Test case NoTrackingToList ran 1 iterations in 2329ms
Test case Where ran 1 iterations in 27338ms
Test case NoTrackingWhere ran 1 iterations in 1649ms
Test case Include ran 1 iterations in 40649ms
Test case NoTrackingInclude ran 1 iterations in 15693ms
Test case WhereInclude ran 1 iterations in 40526ms
Test case NoTrackingWhereInclude ran 1 iterations in 15316ms

Running with posts already tracked...
Test case ToList ran 1 iterations in 1208ms
Test case NoTrackingToList ran 1 iterations in 1852ms
Test case Where ran 1 iterations in 1363ms
Test case NoTrackingWhere ran 1 iterations in 1835ms
Test case Include ran 1 iterations in 21641ms
Test case NoTrackingInclude ran 1 iterations in 17399ms
Test case WhereInclude ran 1 iterations in 22569ms
Test case NoTrackingWhereInclude ran 1 iterations in 18567ms

Running with posts not tracked...
Test case ToList ran 1 iterations in 30367ms
Test case NoTrackingToList ran 1 iterations in 2556ms
Test case Where ran 1 iterations in 25095ms
Test case NoTrackingWhere ran 1 iterations in 2278ms
Test case Include ran 1 iterations in 38989ms
Test case NoTrackingInclude ran 1 iterations in 15146ms
Test case WhereInclude ran 1 iterations in 36872ms
Test case NoTrackingWhereInclude ran 1 iterations in 15044ms

EF Core
Running once to prime the query cache...
Test case ToList ran 1 iterations in 9613ms
Test case NoTrackingToList ran 1 iterations in 1278ms
Test case Where ran 1 iterations in 76336ms
Test case NoTrackingWhere ran 1 iterations in 58301ms
Test case Include ran 1 iterations in 123529ms
Test case NoTrackingInclude ran 1 iterations in 82854ms
Test case WhereInclude ran 1 iterations in 121332ms
Test case NoTrackingWhereInclude ran 1 iterations in 70365ms

Running with posts already tracked...
Test case ToList ran 1 iterations in 1623ms
Test case NoTrackingToList ran 1 iterations in 1132ms
Test case Where ran 1 iterations in 1610ms
Test case NoTrackingWhere ran 1 iterations in 58405ms
Test case Include ran 1 iterations in 16745ms
Test case NoTrackingInclude ran 1 iterations in 78411ms
Test case WhereInclude ran 1 iterations in 20362ms
Test case NoTrackingWhereInclude ran 1 iterations in 74163ms

Running with posts not tracked...
Test case ToList ran 1 iterations in 9239ms
Test case NoTrackingToList ran 1 iterations in 1098ms
Test case Where ran 1 iterations in 72227ms
Test case NoTrackingWhere ran 1 iterations in 57913ms
Test case Include ran 1 iterations in 116401ms
Test case NoTrackingInclude ran 1 iterations in 68680ms
Test case WhereInclude ran 1 iterations in 120856ms
Test case NoTrackingWhereInclude ran 1 iterations in 71566ms

From above I gather:

  • I would expect EF Core to perform better than EF6 or at least on par with EF6. However EF Core only performs better in the basic queries while EF Core performs worse than EF6 in the Where, Include and WhereInclude queries (by a factor 4-5 or so) no matter if tracked or no tracked.
  • I would expect Where to perform better than basic queries as fewer records needs to go back into context and database server is exactly optimized for queering. However while EF6 Where queries exactly performs better than basic queries, this is by not the case in EF Core - slower by a factor 5-7!
  • I would expect Include to perform worse than basic queries as more records needs to go back into context from the database server. This is also the case for both EF6 and EF Core. However EF Core performs relatively much worse than EF6 - slower by a factor 10/7 for EF Core vs 1.3/6 for EF6!
    I would expect WhereInclude to perform somewhere in between e.g. closer to basic as Where performs better and Include performs worse. However this is not quite the case for either framework but again EF Core is much slower than EF6 - slower by a factor 12/70 vs 1.2/14 respectively.
  • Looking at 1 and 3 in both frameworks, Prime doesn't make a significant difference (which is also what you mentioned).

Last but not least!

  • You must have a faster test system than I have - on which I envy you ;-)

@ajcvickers
Copy link
Contributor

@HjalteParner Thanks for the additional information. This does indeed look worrying; we will discuss. /cc @divega

@ajcvickers
Copy link
Contributor

Triage: We need to investigate this further for 3.0. However, this should happen after the major query changes are merged.

@peterkfa
Copy link

peterkfa commented Apr 10, 2019

I am also experiencing an increase of anywhere from 20%-200% in execution time when adding .AsNoTracking() to my query when using EFCore 2.2.4. While my query is much more complex than the one above, it does include multiple joins, includes, and where clauses.

This was tested using BenchmarkDotNet with warmup enabled and 20 iterations of the test run per method against a SQL database without any possible external factors affecting it. I ran the test in various configurations and got the same consistent result of AsNoTracking slowing things down appreciably.

|----------------------Method-|-----Mean-|----Error-|---StdDev-|------Min-|------Max-|
|-----------------------------|---------:|---------:|---------:|---------:|---------:|
|--------GetWithTrackingAsync-|--68.11-s-|-0.9863-s-|-0.6524-s-|--67.11-s-|--69.11-s-|
|------GetWithNoTrackingAsync-|-173.83-s-|-1.7734-s-|-1.1730-s-|-172.19-s-|-175.58-s-|

@tap-absg
Copy link

tap-absg commented Jul 3, 2019

Looking at this, I modified @ajcvickers code to use the In Memory database and DI so I could use the Db Context Pooling and remove localdb from the equation. My results are here

Seeding...
Running once to prime the query cache...
Test case ToList ran 1 iterations in 778ms
Test case NoTrackingToList ran 1 iterations in 23796ms
Test case Where ran 1 iterations in 1030ms
Test case NoTrackingWhere ran 1 iterations in 27023ms
Test case Include ran 1 iterations in 4348ms
Test case NoTrackingInclude ran 1 iterations in 30329ms
Test case WhereInclude ran 1 iterations in 4625ms
Test case NoTrackingWhereInclude ran 1 iterations in 28536ms
Running with posts already tracked...
Test case ToList ran 1 iterations in 784ms
Test case NoTrackingToList ran 1 iterations in 22510ms
Test case Where ran 1 iterations in 986ms
Test case NoTrackingWhere ran 1 iterations in 23248ms
Test case Include ran 1 iterations in 4308ms
Test case NoTrackingInclude ran 1 iterations in 32144ms
Test case WhereInclude ran 1 iterations in 4827ms
Test case NoTrackingWhereInclude ran 1 iterations in 30422ms
Running with posts not tracked...
Test case ToList ran 1 iterations in 796ms
Test case NoTrackingToList ran 1 iterations in 24029ms
Test case Where ran 1 iterations in 1020ms
Test case NoTrackingWhere ran 1 iterations in 24929ms
Test case Include ran 1 iterations in 4936ms
Test case NoTrackingInclude ran 1 iterations in 30231ms
Test case WhereInclude ran 1 iterations in 5053ms
Test case NoTrackingWhereInclude ran 1 iterations in 32542ms

There probably should be a warning added to https://docs.microsoft.com/en-us/ef/core/querying/tracking about this defect

@pgrm
Copy link

pgrm commented Jan 19, 2020

@ajcvickers - for those of us who might have found this question and are concerned enabling AsNoTracking for all queries which don't need tracking, by default - is this only an issue in specific cases? Does it still exist in ef core 3.1.1?

thx for the insights

@ajcvickers
Copy link
Contributor

@pgrm We haven't root-caused the issue yet. It's certainly only an issue in specific cases. If you're concerned about perf here, then I think you'll need to do perf testing on your application.

@mkanakis
Copy link

@pgrm

For what is worth, in my case for two different test scenarios average query duration between tracking and no-tracking is:

  • 1st scenario: 5.0ms vs 4.63ms
  • 2st scenario: 4.14ms vs 3.80ms

It seems that no-tracking is doing a better job, even though the numbers are not significant in my opinion.

It also seems, that as @ajcvickers mentioned it is case-specific and not general.

@midgleyc
Copy link

midgleyc commented Aug 2, 2022

I've just hit a query (in 6.0.7) that performs significantly worse (~5x slower) under AsNoTracking compared to with tracking. It calls Include using a component mapped to a view.

By changing AsNoTracking into AsNoTrackingWithIdentityResolution the speed penalty goes away.

@Mateusz19021996
Copy link

Any updates on it?

@ajcvickers
Copy link
Contributor

This issue is in the Backlog milestone. This means that it is not planned for the next release (EF Core 8.0). We will re-assess the backlog following the this release and consider this item at that time. However, keep in mind that there are many other high priority features with which it will be competing for resources. Make sure to vote (👍) for this issue if it is important to you.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests