Efcore: Performance/Caching Issue in Parallel Testing Environment

[Mike-E-angelo]

EFCore has been working abosolutely great for me in my development efforts. Everything has been intuitive and responsive for my needs.

I am especially appreciative of how easy it has been to setup and unit test it. This is a much welcomed addition!

However, in my efforts to do so, I have encountered a performance issue that occurs in xUnit, which is the testing SDK/environment that I utilize. It does not occur in MSFT-Test.

Steps to reproduce

I have created a very simple reproduction of this issue here:

https://github.com/Mike-E-wins/EFCore.Performance.Parallel

For each xUnit and MSFT-Test SDKs, I have created two test classes that run the same code in five different tests within each class.

When running the tests in xUnit, I get the following:

With MSFT-Test:

You can see that with xUnit, there appears to be a cache miss of some sort occurring, whereas MSFT-Test executes as expected.

In my examples, I am also making use of IdentitySDK, so that might be part of this issue as well. In my simple profiling, however, it seems the issue occurs with accessing the DbContext.DbContextDependencies property:

In my provided tests here I have managed (THANKFULLY! 😆) to reproduce this with a very simple example utilizing a likewise simple DbContext without any additional configured entities/DbSets. In my real-world case, however, my DbContext has a few DbSets configured with it, and each test class taking upwards towards 1.5 seconds.

This means that any new test class that I add with EFCore functionality adds this much time to my test runs, plus _all_ EFCore-associated test classes are impacted the more DbSet/entities that I add to the DbContext.

It would be great to know if I am overlooking something obvious in my configuration/understanding of xUnit. I hope that is the issue here! Otherwise, I wanted to report it just in case this is not known/captured somewhere.

In any case, thank you for your great work with EFCore. It is a great release and this really the only issue I have encountered with it, so IMO this is a very good product. 👍 I say this as someone who has been using it since 1.0 in .NET Framework, .edmx form designers and all!

Further technical details

EF Core version: 3.1.3
Database provider: Microsoft.EntityFrameworkCore.InMemory
Target framework: .NET Core 3.1
Operating system: Windows 10 1909
IDE: Microsoft Visual Studio Community 2019 Version 16.5.4

[roji]

xunit runs all test classes in parallel, where AFAIK MSTest doesn't (at least not by default). What's probably happening is that the first tests from each class are run concurrently, and so some work has to be done twice.

If I disable xunit parallelization by sticking the following in the project:

c# [assembly: CollectionBehavior(DisableTestParallelization = true)]

the tests run sequentially as with MSTest and the running time goes down. However, I definitely wouldn't do this, since with a more standard testing pattern (see below) parallelization almost always helps.

What is somewhat unusual about your test suite, is that each test spins up a whole new ASP.NET host - with its entire service provider - from scratch (and not stopping it, by the way). I'm not sure exactly what kind of testing you're writing, but typically a full ASP.NET server would not part of the testing (unless this is some sort of integration test). In any case, I would definitely not start a whole server for each thread, but at most one, and use it concurrently from the different tests. If you do that, the startup slowness you're seeing should also disappear.

@ajcvickers do you think we should look at the slowdown when starting two hosts in parallel? This definitely doesn't seem like a typical scenario by any means, but I'm still a bit curious why it's happening.

[Mike-E-angelo]

I wondered if I was going to get an attending to WRT my dubious test practices, and you did not disappoint, @roji. 😁

That was great feedback. Thank you very much for that, and for taking the time to attentively review my concerns and code. Do know that in my "real world" testing I do dispose of those servers. 😇

I completely get what you are saying as far as integration/unit testing goes. Call me a sucker, however, for being able to do such a thing as newing up an entire server for each and every test. Best practices aside, I am in love with such a notion and do not mind abusing it accordingly, especially when there is such little overhead/penalty in doing so (outside of this issue, that is).

In any case, I went ahead and simplified the tests, and even added an NUnit project as it, too, allows for parallelization. You can find those here:

https://github.com/Mike-E-wins/EFCore.Performance.Parallel

(I have also updated the original post with the new repo URL and the title of this issue to better reflect the nature of the problem.)

You can see that even without using a test server and simply calling Set<User>().ToArrayAsync(), the results are the same, albeit with shorter resulting duration as it now has less infrastructure to initialize:

So it would seem your hypothesis is correct, and this is a parallel-based issue in how the DbContext is initialized. 👍

[ajcvickers]

@roji Do you think there is more going on here than building the internal service provider and then building the model? Both of these things typically happen only once.

[roji]

@ajcvickers I had a small doubt but after checking everything seems fine.

Note that although two tests report slow first-time startup (519ms), that startup happens in parallel and so the overall test run time remains constant, whether parallelization is enabled or not. @Mike-E-wins that means there's no advantage in disabling parallelization, only disadvantages. As a last note, you can also create your DbContextOptions once (e.g. as a static variable somewhere) and reuse it everywhere.

Am going to close this as everything seems to be working as expected, but don't hesitate to post back if you have more questions.

[Mike-E-angelo]

OK, so it took me a little bit to wrap my head around this. I am going to write some notes here for anyone else that happens to run into this problem, as well for my own edification.

By default, xUnit runs up to the number of processors available on the machine when it processes tests. In my case, that is 8. So, if one of those threads is locked on a resource (in this case the model initializer), then any other test that also accesses that resource is also blocked until that resource is released.

To illustrate, I created a total of 20 test classes for a total of 100 tests. Look what happens:

8 classes get "hung" but then the remaining 12 buzz right through as expected. As I mentioned, I have 8 processors on my machine so that fits my understanding of what's happening.

To further expound:

1. The first thread gets through to the model initializer and locks it, blocking any further access.
2. The remaining (up to) 7 threads also reach the model initializer but are blocked until the first thread releases it.
3. The first thread completes and releases the initialized model.
4. The remaining threads continue with the model initialized from the first thread.

So, 7 of those 8 "slow" tests aren't "also re-initializing" the model as I originally understood, but are in fact waiting on the first thread to initialize the model and are reflecting the time as such. Further, this isn't an _infinite_ problem as I feared when I originally posted this issue, but a _finite_ one limited to the number of processors that are configured by xUnit to process tests in parallel (in my case 8).

Thanks to @roji for helping me walk through this exercise. Tricky!

[roji]

Your analysis makes sense. It's indeed unfortunate that the tests look like they're slow, although the parallelism makes all these "slow" tests run concurrently. In particular, looking at your screenshot above, it seems like a real UI bug to say that the entire test suite took 4.3 seconds - that's a cumulative figure of the individual running times, although the wall clock time here should really be ~540ms total.