Efcore: Why is EF Core 3.1.1 slower than EF Core 2.2.6?

[sgtagan]

Save 1 record
EF Core 2.2.6 Run 1: 96.6822ms. Run 2: 2.1267ms. Run 3: 1.6975ms.
EF Core 3.1.1 Run 1: 267.0279ms. Run 2: 7.1322ms. Run 3: 4.0974ms.

Retrieve 1 record
EF Core 2.2.6 Run 1: 0.0218ms. Run 2: 0.024ms. Run 3: 0.0123ms.
EF Core 3.1.1 Run 1: 0.0729ms. Run 2: 0.0204ms. Run 3: 0.0167ms.

Save 10,000 records
EF Core 2.2.6 Run 1: 202.2927ms. Run 2: 58.1302ms. Run 3: 50.2324ms.
EF Core 3.1.1 Run 1: 825.3337ms. Run 2: 207.5495ms. Run 3: 216.0945ms.

Retrieve 10,001 records
EF Core 2.2.6 Run 1: 0.0266ms. Run 2: 0.0302ms. Run 3: 0.0503ms.
EF Core 3.1.1 Run 1: 0.0273ms. Run 2: 0.0302ms. Run 3: 0.0754ms.

Stopwatch sw = new Stopwatch();
            string s1 = "";
            string s2 = "";
            string s3 = "";
            string s4 = "";
            for (int j = 1; j <= 3; j++)
            {
                // Add 1 record
                sw.Reset();
                sw.Start();
                TestHeader o = new TestHeader()
                {
                    Name = $"Tester"
                };

                TestContext db = new TestContext();
                db.Add(o);
                db.SaveChanges();
                sw.Stop();
                TimeSpan ts = sw.Elapsed;

                s1 += $"Run {j}: {ts.TotalMilliseconds.ToString()}ms.  ";

                // Retrieve 1 record
                sw.Reset();
                sw.Start();
                db = new TestContext();
                var item = db.TestHeader;
                sw.Stop();
                ts = sw.Elapsed;

                s2 += $"Run {j}: {ts.TotalMilliseconds.ToString()}ms.  ";

                // Add 10,000 records
                sw.Reset();
                sw.Start();
                List<TestHeader> list = new List<TestHeader>();
                for (int i = 0; i <= 10000; i++)
                {
                    TestHeader user = new TestHeader()
                    {
                        Name = $"User {i}"
                    };

                    list.Add(user);
                }

                db = new TestContext();
                db.BulkInsert(list);
                sw.Stop();
                ts = sw.Elapsed;

                s3 += $"Run {j}: {ts.TotalMilliseconds.ToString()}ms.  ";

                // Retrieve 10,001 records
                sw.Restart();
                sw.Start();
                db = new TestContext();
                var s = db.TestHeader;
                sw.Stop();
                ts = sw.Elapsed;
                s4 += $"Run {j}: {ts.TotalMilliseconds.ToString()}ms.  ";

                db.RemoveRange(s);
                db.SaveChanges();
            }

[scalablecory]

@Pilchie

[ajcvickers]

@AndriySvyryd @roji to take a look and verify if this is something we need to track. (Note: biggest difference is coming from the update pipeline, but also the test doesn't do warm-up, etc.)

[AndriySvyryd]

Assuming that both run on .NET Core 3.1.0, targetting SQL Server and using this entity type:
C# class TestHeader { public int Id { get; set; } public string Name { get; set; } }

I ran the update benchmark using BenchmarkDotNet and didn't see a significant difference apart from Gen 0 allocations:

2.2.6:

| Method | Count | Mean | Error | StdDev | Median | Min | Gen 0 | Gen 1 | Gen 2 | Allocated |
|---------------- |------ |-------------:|-----------:|-----------:|-------------:|-------------:|----------:|----------:|----------:|------------:|
| BulkSaveChanges | 1 | 4.280 ms | 0.2066 ms | 0.5655 ms | 4.056 ms | 3.577 ms | - | - | - | 51.69 KB |
| BulkSaveChanges | 10000 | 1,340.131 ms | 26.7917 ms | 40.9137 ms | 1,333.024 ms | 1,289.080 ms | 9000.0000 | 3000.0000 | 1000.0000 | 74579.25 KB |

3.1.1:

| Method | Count | Mean | Error | StdDev | Median | Min | Gen 0 | Gen 1 | Gen 2 | Allocated |
|---------------- |------ |-------------:|-----------:|-----------:|-------------:|-------------:|-----------:|----------:|----------:|-------------:|
| BulkSaveChanges | 1 | 4.418 ms | 0.1377 ms | 0.3675 ms | 4.326 ms | 3.968 ms | - | - | - | 61.05 KB |
| BulkSaveChanges | 10000 | 1,537.679 ms | 30.6955 ms | 84.5442 ms | 1,496.900 ms | 1,439.245 ms | 14000.0000 | 4000.0000 | 1000.0000 | 107881.81 KB |

[sgtagan]

Why both on .net core 3.1.0? supposed to use 2.2 and 3.1?

and what is your code for these? i use regular EF core codes. Add() and SaveChanges instead of BulkSaveChanges() for single insert.

[roji]

@sgtagan your benchmark is problematic in various ways. There is no warm-up phase, meaning that you include various start-up costs in your benchmark (e.g. query compilation). Unless I'm missing something you're also only running each scenario once, which doesn't provide much certainty as to the results.

I'd suggest you take a look at BenchmarkDotNet, which is a superb library which takes care of all the common pitfalls of benchmarking. It's really easy to start with and provides very reliable results. If you have a BDN scenario which performs much worse on 3.1, please post the full benchmark code for that and we'll look into it.

@AndriySvyryd could you post the benchmark code?

[sgtagan]

Alright, looks not so much difference. Thanks. How to use milliseconds instead of nanoseconds?

[EDITED. Changed ns to ms. Thanks @roji ]
EFCore 2.2.6

             

Method	Mean [ms]	Error [ms]	StdDev [ms]	Median [ms]
Save_1_Record	1.4114 ms	0.0702 ms	0.2036 ms	1.3827 ms
Load_1_Record	0.0009 ms	0.0000 ms	0.0000 ms	0.0009 ms
Save_10000_Record	48.8672 ms	2.5019 ms	7.1381 ms	46.7122 ms
Load_10000_Record	0.0008 ms	0.0000 ms	0.0000 ms	0.0008 ms

EFCore 3.1.1

             

Method	Mean [ms]	Error [ms]	StdDev [ms]	Median [ms]
Save_1_Record	1.6398 ms	0.1149 ms	0.3241 ms	1.6005 ms
Load_1_Record	0.0009 ms	0.0000 ms	0.0000 ms	0.0009 ms
Save_10000_Record	45.4850 ms	1.5392 ms	4.4899 ms	44.1879 ms
Load_10000_Record	0.0009 ms	0.0000 ms	0.0000 ms	0.0009 ms

public class TestBenchmark
    {
        public void Load()
        {
            var db = new TestContext();
            var item = db.TestHeader;
        }
        public void SaveBulk()
        {
            List<TestHeader> list = new List<TestHeader>();
            for (int i = 1; i <= 10000; i++)
            {
                TestHeader user = new TestHeader()
                {
                    Name = $"User {i}"
                };

                list.Add(user);
            }

            var db = new TestContext();
            db.BulkInsert(list);
        }
        public void SaveSingle()
        {
            var db = new TestContext();
            TestHeader o = new TestHeader()
            {
                Name = $"Tester"
            };
            db.Add(o);
            db.SaveChanges();
        }

        [Benchmark]
        public void Save_1_Record()
        {
            SaveSingle();
        }

        [Benchmark]
        public void Load_1_Record()
        {
            Load();
        }

        [Benchmark]
        public void Save_10000_Record()
        {
            SaveBulk();
        }

        [Benchmark]
        public void Load_10000_Record()
        {
            Load();
        }
    }
    class Program
    {
        static void Main(string[] args)
        {
            var summary = BenchmarkRunner.Run<TestBenchmark>();
        }
    }

[roji]

IIRC there's a TimeUnit setting on the SummaryStyle, search around the docs a bit and you'll probably find a sample. Otherwise BDN automatically selects an optimal time unit.