Create lazy-loading and change-tracking proxy types lazily

[henrikdahl8240]

I have made this simple function:

private void buttonRoot_Click(object sender, EventArgs e)
{
    DateTime start = DateTime.Now;
    using (BikeShop_DbContext dbContext = new BikeShop_DbContext(new DbContextOptionsBuilder<BikeShop_DbContext>()
        //.UseLazyLoadingProxies()
        .UseSqlServer(@"data source=.;initial catalog=BikeShop;integrated security=True;MultipleActiveResultSets=True", opts => opts.CommandTimeout((int)TimeSpan.FromMinutes(10).TotalSeconds)).Options))
    {
        var root = dbContext.Roots.First();
        DateTime finish = DateTime.Now;
        MessageBox.Show(this, $"root.ID: {root.ID}.\n Start: {start}\nFinish: {finish}\nDuration: {finish - start}", "Root ID");
    }
}

On my machine, it takes 4:18 to execute, i.e. four minutes and 18 seconds.

It is important to notice, that I have commented out the invocation of .UseLazyLoadingProxies(). I obviously need these proxies, so it's just to compare.

So now I uncomment .UseLazyLoadingProxies() so it will also be run, i.e.:

private void buttonRoot_Click(object sender, EventArgs e)
{
    DateTime start = DateTime.Now;
    using (BikeShop_DbContext dbContext = new BikeShop_DbContext(new DbContextOptionsBuilder<BikeShop_DbContext>()
        .UseLazyLoadingProxies()
        .UseSqlServer(@"data source=.;initial catalog=BikeShop;integrated security=True;MultipleActiveResultSets=True", opts => opts.CommandTimeout((int)TimeSpan.FromMinutes(10).TotalSeconds)).Options))
    {
        var root = dbContext.Roots.First();
        DateTime finish = DateTime.Now;
        MessageBox.Show(this, $"root.ID: {root.ID}.\n Start: {start}\nFinish: {finish}\nDuration: {finish - start}", "Root ID");
    }
}

Now it takes 34:42 to execute, i.e. 34 minutes and 42 seconds. By simple subtraction, the invocation of .UseLazyLoadingProxies() adds approximately half an hour to the duration or makes initialization to take approximately 10 times longer time.

There was a lot of criticism on the initialization time in scope of EF 6. It seems like this gives exactly the same problem.

Can't you for instance lazy initialize or we could call it initialize on demand instead? Perhaps you have a better idea?

Do you agree, that it's a major problem, that use of your proxy feature forces initialization to take really long time?

I would like to mention, that I have in the magnitude of 4.000 entities in my model. Only one of these is being looked up by my small program example.

EF Core version: 3.1.2
Database provider: Microsoft.EntityFrameworkCore.SqlServer
Target framework: NET Core 3.1
Operating system: Windows 10 Professional
IDE: Visual Studio 2019 16.4.5.

[ajcvickers]

@henrikdahl8240 Can you attach your EF model (entity types and DbContext) so that we can investigate. This seems slower than expected even for 4000 entity types.

[henrikdahl8240]

Can't you give a suggestion for how to do that without challenging the immaterial rights. Do you for example have a reference for a Roslyn project which anonymizes all names in all projects in a solution?

I would like to share the model, but I would like to do it without disclosing anything for real.

[ErikEJ]

@henrikdahl8240 You can run an obfuscator?

[henrikdahl8240]

Yes, but I have never done that before. Can you suggest how to do that? Can I see the result myself? Is there one built-in in Visual Studio?

[ErikEJ]

https://docs.microsoft.com/en-us/visualstudio/ide/dotfuscator/?view=vs-2019
https://www.preemptive.com/dotfuscator/ce/docs/help/getting_started_gui.html

Then you can decompile the resulting dll and extract the relevant classes

[henrikdahl8240]

Thank you very much, Erik. Do you also have a suggestion concerning the decompilation step?

[ajcvickers]

@henrikdahl8240 If you don't want to share it publicly, then you can send it to me directly and we will keep it private. avickers at microsoft.com

[henrikdahl8240]

@ajcvickers It sounds excellent. I will put some efforts into that.

[ErikEJ]

I usually use dotPeek

[henrikdahl8240]

OK. I will take a look. Thank you for the hints, @ErikEJ

[henrikdahl8240]

@ajcvickers As you may see, I mailed you a soution on March 6. 2020 13:46. Perhaps you may run it to reproduce the problems yourself?

The mail details the few steps you should go through.

[ajcvickers]

@henrikdahl8240 Thanks--we got the code.

Note for team: I am able to reproduce this; culprit is model building but I haven't profiled to find out where. /cc @AndriySvyryd

Running the code below on my fast machine without lazy-loading proxies:

Creating model...
Done in 81904
Creating database...
Done in 113199
Running query...
Done in 124

With proxies:

Creating model...
Done in 701398
Creating database...
Done in 112623
Running query...
Done in 132

Model has 5,860 entity types with a total of 13,876 navigations.

EntityTypeConfigurations are already being used.

using (HenrikDahl_DbContext dbContext = new HenrikDahl_DbContext(new DbContextOptionsBuilder<HenrikDahl_DbCon
    .UseLazyLoadingProxies()
    .UseSqlServer(Your.SqlServerConnectionString, opts => opts.CommandTimeout((int)TimeSpan.FromMinutes(10).T
{
    Console.WriteLine("Creating model...");

    var timer = Stopwatch.StartNew();
    
    var model = dbContext.Model;
    timer.Stop();
    Console.WriteLine($"Done in {timer.ElapsedMilliseconds}");
    
    Console.WriteLine("Creating database...");

    timer = Stopwatch.StartNew();
    dbContext.Database.EnsureDeleted();
    dbContext.Database.EnsureCreated();
    timer.Stop();
    
    Console.WriteLine($"Done in {timer.ElapsedMilliseconds}");

    Console.WriteLine("Running query...");

    timer = Stopwatch.StartNew();
    var samoyed = dbContext.Samoyeds.FirstOrDefault();
    timer.Stop();
    
    Console.WriteLine($"Done in {timer.ElapsedMilliseconds}");
}

[AndriySvyryd]

It might be just the time it takes to create the proxy types

[henrikdahl8240]

Shouldn't proxy types generally be created as they are needed and not up-frot, i.e. created lazy-wise? Perhaps it could be an option for UseLazyLoadingProxies whether the proxy classes should be created eager-wise or lazy-wise. Otherwise I guess it will always be a pain in situations with relatively many entity types. I assume that the requirement of using "virtual" for all collections and navigation properties enable this.

I would imagine, that EF Core should rather shine with many entity types than with few entity types. Probably many can figure out to make such ORM stuff if it only needs to perform well in situations with few entity types. I assume that all non-trivial enterprise solutions will have many, many entity types and it's here EF Core should shine, at least from my point of view.

[ajcvickers]

@AndriySvyryd Yes, but I think it would be good to understand where the time is being used even in the non-proxy model building.

[ajcvickers]

Notes from team triage:

• We will investigate the model building perf to at least understand where the time is going without proxies
• This issue will track lazy creation of proxy instances, but this won't make it in 5.0 since it requires changes to the way extensions interact with model building.

@henrikdahl8240

I assume that all non-trivial enterprise solutions will have many, many entity types

This number of entity types and relationships is at the high end of what we see. We have a long-term goal to pre-compile the model, which is ultimately the way to make this the most performant. That being said, the perf here is a lot slower than I expected, which is why we're investigating.

[ErikEJ]

@henrikdahl8240 Many modern enterprise solutions are based on micro services and a limited number of entity types managed by each micro service.

[henrikdahl8240]

@ErikEJ How do you ensure domain level consistency in the situation you have on mind as you do not have the entire domain model in one database?

[DeluxeAgency2020]

@AndriySvyryd, @ajcvickers
Whats is the status of this issue. Is any workaround or suggestion? Will this issue be fixed in ef 5?

[AndriySvyryd]

@DeluxeAgency2020 We'll investigate this in 5.0 timeframe, but it's unlikely that any significant improvement will be made for 5.0 RTM

[roji]

Tested on 6.0.0-preview.7 without proxies:

• 29% of model building time is spent doing SortedDictionary.TryGetValue inside Annotatable.FindAnnotation, see Perf bottleneck because of SortedDictionary in Annotatable.FindAnnotation #25488.
• Another huge hotspot is Attribute.IsDefined, opened Attribute.IsDefined is a perf hotsport during model building #25891 to track
• Finally, turning on proxies shows the entire time spent in ProxyFactory.CreateProxyType. Castle.DynamicProxy has an internal caching mechanism so that it doesn't regenerate the proxy type for the same combination of CLR Type, interface list and ProxyGenerationOptions; as far as I can see we're not doing anything wrong, so this looks like pure proxy generation time which cannot be optimized away. We may have some opportunities for not generating proxies where they're not needed, opened Avoid generating proxies when they're not needed #25892.
  • Once crazy thought, is that in today's world these proxies could be generated at compile-time with source generators, I wonder if Castle or some other proxy generation package has this feature.

[AndriySvyryd]

Related to the last point: #24902

[ajcvickers]

From #20135 (comment)

This issue will track lazy creation of proxy instances.

[ajcvickers]

Fixed in #28127.

Perf for model with 449 entity types, 6390 properties, and 720 relationships.

6.0

No proxies

Method	Mean	Error	StdDev
TimeToFirstQuery	1.085 s	0.0083 s	0.0167 s

Change tracking proxies

Method	Mean	Error	StdDev
TimeToFirstQuery	13.01 s	0.204 s	0.411 s

7.0

No proxies

Method	Mean	Error	StdDev
TimeToFirstQuery	1.442 s	0.0134 s	0.0272 s

Change tracking proxies

Method	Mean	Error	StdDev
TimeToFirstQuery	1.446 s	0.0160 s	0.0323 s

Change tracking proxies and compiled model

Method	Mean	Error	StdDev
TimeToFirstQuery	162.4 ms	6.16 ms	12.45 ms

See #24902.

Also, see #28129.

[roji]

Very nice!