efcore icon indicating copy to clipboard operation
efcore copied to clipboard

Compiled model performance trends

Open ajcvickers opened this issue 10 months ago • 9 comments

In investigating the compiled model changes in EF9, I noticed that things were taking quite a lot longer than expected, so I did some analysis.

The model here is the one used in the samples: https://github.com/dotnet/EntityFramework.Docs/tree/main/samples/core/Miscellaneous/CompiledModels

The first issue is that, for this sample model with 449 entity types, 6390 properties, and 720 relationships, the startup time is now worse when using a compiled model.

EF version Normal (s) Compiled model (s)
EF Core 6 3.71 0.93
EF Core 7 4.07 1.04
EF Core 8 4.52 3.37
EF Core 9 4.48 5.24
image

By startup time, I mean wall clock time to run the following:

using (var context = new BlogsContext())
{
    entityCount = context.Model.GetEntityTypes().Count();
}

My suspicion that a lot of this is assembly loading and/or JIT, based on the increase in DLL size across releases:

EF version Normal (MB) Compiled model (MB)
EF Core 6 0.9 2
EF Core 7 0.9 2
EF Core 8 0.9 8
EF Core 9 0.9 20
image

Related to all this is that the time to run dotnet ef dbcontext optimize on this same model has increased very dramatically in EF9.

EF version Time to run dbcontext optimize (s)
EF Core 6 11
EF Core 7 11
EF Core 8 40
EF Core 9 107
image

ajcvickers avatar Apr 06 '24 11:04 ajcvickers

Note: see profiling session done by @muzopraha in #33495:

image

roji avatar Apr 09 '24 12:04 roji

This also shows regression for non-compiled models. Is a separate issue needed to track that?

stevendarby avatar Apr 13 '24 08:04 stevendarby

@stevendarby yeah, that's true - we'll discuss this in the team as well.

roji avatar Apr 13 '24 08:04 roji

@stevendarby @roji We discussed the regression in 8.0 at the time, and it was considered acceptable because if people had slow model building performance then they could use compiled models! Oh, the irony.

ajcvickers avatar Apr 13 '24 09:04 ajcvickers

@ajcvickers Irony aside, it's also not really true in all cases - for example, if you use query filters?

stevendarby avatar Apr 13 '24 09:04 stevendarby

@stevendarby Agreed.

ajcvickers avatar Apr 13 '24 09:04 ajcvickers

Is it a reasonable workaround, for now, to compile the model with EF Core 7, but then upgrade packages and run with v8 or v9? It doesn't crash and burn immediately, but I'd like to know if that's a completely unsupported mix. Thanks.

Not sure how surprising this is, but when I encountered this issue, I discovered that AOT doesn't really improve the model init time of compiled models. (Leaving aside the fact queries won't run on AOT).

iainnicol-hymans avatar Apr 16 '24 09:04 iainnicol-hymans

Is it a reasonable workaround, for now, to compile the model with EF Core 7, but then upgrade packages and run with v8 or v9? It doesn't crash and burn immediately, but I'd like to know if that's a completely unsupported mix. Thanks.

No, it's completely unsupported. A "better" workaround would be to use some post-processing script to remove the slow calls added in the newer code. Most of them will be just computed lazily when not using NativeAOT.

AndriySvyryd avatar Apr 19 '24 18:04 AndriySvyryd

This is the proposed action plan to deal with this regression:

  • [x] By default generate a compiled model equivalent to what EF Core 6 would generate, with CLI switches that would add more code to the compiled model (For NativeAOT fully eager generation is required)
  • [ ] #31370
  • [ ] #34440
  • [x] Fully qualify (including the return type) the generated lambdas #33773
  • [x] "Lift" reused lambdas, comparers and type mappings to a common location
  • [ ] #34441
  • [ ] #34442
  • [ ] #32717

AndriySvyryd avatar Apr 22 '24 23:04 AndriySvyryd

Is this going to be taken care of for .NET 9.0? This has become almost intolerable for our app. Our app has 100 tables which have a total of 6500 columns.

It is a short-lived application but the initial connection to the database takes 1-5 minutes depending on the hardware specs. That initial connection takes more time than the whole rest of the app.

I am really hopeful this can be given high priority.

TonyValenti avatar Jun 06 '24 21:06 TonyValenti

@TonyValenti As a workaround you can use something like this:

function CompiledModelFix {
    $file = '.\PathToDbContextProject\CompiledModels\{MyDbContext}ModelBuilder.cs'
    $content = Get-Content $file -Raw

    # Remove specific line
    $content = $content -replace 'AddRuntimeAnnotation\("Relational:RelationalModel", CreateRelationalModel\(\)\);', ''

    # Remove specific method
    $content = $content -replace 'private IRelationalModel CreateRelationalModel\s*\(\)\s*\{[\s\S]*', '} }'

    while ($true) {
        try {
            # Attempt to write to the file with UTF-8 encoding and BOM
            Set-Content -Path $file -Value $content -Force -Encoding UTF8 -ErrorAction Stop

            Write-Host -BackgroundColor Yellow "Fix was applied..."
            break  # Exit the loop if writing is successful
        }
        catch {
            # If writing fails due to file being used by another process, wait and retry
            Start-Sleep -Seconds 1
        }
    }
}

It`s a part of ps1 script (for adding\removing migrations), that removes slow code in CompiledModel.

ramonesz297 avatar Jun 08 '24 21:06 ramonesz297

My leadership would consider that a brittle approach and would not allow us to use that.

I'm really hopeful this gets significant investment.

TonyValenti avatar Jun 08 '24 22:06 TonyValenti

Hi @AndriySvyryd - Do you know when dev will start on this? Is there anything I can do to help this get prioritized?

I really, really, really want to make sure this gets resolved for 9.0.

TonyValenti avatar Jun 12 '24 14:06 TonyValenti

@TonyValenti I can't tell exactly when or what, but something will be done about this for 9.0

AndriySvyryd avatar Jun 12 '24 16:06 AndriySvyryd

I'm so glad this has priority. These performance challenges are really killing us.

Is there a method (that would work with both compiled and non-compiled models) that we could call that would cause EFCore to generate/cache whatever information is necessary?

In one of our apps, we'd like to experiment with launching a background tread that handles this initialization so that when a user wants to create a database, they're not waiting for minutes.

TonyValenti avatar Aug 09 '24 16:08 TonyValenti

@TonyValenti Calling context.Model will initialize (and cache) it

AndriySvyryd avatar Aug 09 '24 23:08 AndriySvyryd

Hi @AndriySvyryd - That helped but I think that doesn't fully initialize everything.

On my PC, with no tweaks, the first database creation takes 43 seconds. On my PC, with a background context.Model (and waiting on the background load to complete), the first database creation takes 21 seconds. That's an improvement but still terrible. On my PC, with no tweaks, the second database creation takes 3 seconds.

What can I do that will cause everything to preload that a database creation would cause?

TonyValenti avatar Aug 10 '24 03:08 TonyValenti

@TonyValenti That might be due to a different issue that is now fixed in 9.0. Try also calling context.GetService<IDesignTimeModel>().Model

AndriySvyryd avatar Aug 10 '24 19:08 AndriySvyryd

@AndriySvyryd - Thank you! That did it!

[20:06:52 INF] Creating Database...
[20:06:55 INF] Success!

In 9.0, do you think something like this will still be necessary or do you think that it is possible that out of the box, we'll be able to hit the 3-second mark like that?

TonyValenti avatar Aug 11 '24 01:08 TonyValenti

@TonyValenti The second line might not be necessary. But I think you'll still need to prebuild the compiled model to get this experience even with the improvements.

AndriySvyryd avatar Aug 11 '24 02:08 AndriySvyryd

The critical part has been completed. Additional work is tracked in other issues.

AndriySvyryd avatar Aug 14 '24 22:08 AndriySvyryd

@ajcvickers Would it be possible to re-run your tests on the same machine so we can measure the improvements?

knd775 avatar Aug 15 '24 13:08 knd775

I reran some of the benchmark scenarios on my machine.

But I measured this, which should be more representative for normal app first query:

using var context = new BlogsContext();
var model = context.Model.GetRelationalModel();

I was also using Release builds and the corresponding version of dotnet ef (I assume @ajcvickers did the same)

EF version Normal (s) Compiled model (s) Compiled model --nativeaot (s)
EF Core 8 6.9 4.1 N/A
EF Core 9-rc1 6.3 3.2 6.3
EF version Normal (MB) Compiled model (MB) Compiled model --nativeaot (MB)
EF Core 8 0.9 5 N/A
EF Core 9-rc1 0.9 2 13

So, it looks like the compiled model in 8 does improve the startup time (at the cost of the size).

The additional code added in 9 for NativeAOT can make it worse in some cases, but now it isn't generated by default. And I wouldn't recommend using --nativeaot unless you plan to publish your app using NativeAOT.

And the reason to consider using NativeAOT is that the startup time becomes 0.4s! (But it takes around 8 minutes to compile)

AndriySvyryd avatar Aug 17 '24 00:08 AndriySvyryd

Can you compare to 6/7 on the same machine please? I'm particularly interested in the normal model compile time, which regressed in 8/9 compared to 6/7. https://github.com/dotnet/efcore/issues/33483#issuecomment-2053570775

stevendarby avatar Aug 20 '24 19:08 stevendarby

@stevendarby

EF version Normal (s)
EF Core 6 5.2
EF Core 7 7

Model building is expected to take longer as we add more features, even if your model doesn't use them.

We plan to rearchitect the conventions infrastructure at some point - https://github.com/dotnet/efcore/issues/9329, but it's unclear how much impact it will have in practice until it's implemented. For now, we are focusing on improving the compiled model.

AndriySvyryd avatar Aug 21 '24 03:08 AndriySvyryd