8

Closed

[Performance] Entity materialization slower in EF6.0.1

description

Hi,

I was doing some benchmarking on various ORMs to see how our own ORM framework's performance relates to that. The topic of this benchmark is solely entity object materialization, so a large set is fetched and materialized into entity objects. I use AdventureWorks for this, on SQL Server 2005 (not really important, see below). I fetch all 31465 rows of Sales.SalesOrderHeader. I run all benchmarks on a core2quad with windows 8, 32bit, 4GB ram, .NET 4.5.1 installed (VS.NET 2012/2013) and all are release builds.

The results with EFv5 (with code) are here: http://pastebin.com/AdsKitr3

This morning I changed EFv5 code for EFv6 (6.0.1, latest from nuget) and reran the benchmarks. I was surprised to see that EFv6 was 3 times slower. See: http://pastebin.com/ffeieP3v . I checked whether it re-imported the EDMX every time which wasn't the case, creating the context is once 136ms or so, the other times 0ms.

I ran a profile on the DB activity using our profiler to see whether I configured something wrong. EFv6 executes 1 query per loop, which is expected, spends 2.34ms on the SQL query execution, and roughly between 536-650ms on consuming the 31K rows from the datareader. So on that side, things are all OK.

So I ran a .NET profile with dotTrace 4.5.1, and things look seriously wrong. See screenshot: https://twitter.com/FransBouma/status/395156195419238400/photo/1
I've saved this snapshot, in case you want to look at it.

As this was run with EFv6 code generated with our designer, I wondered whether I made a mistake somewhere, configured it wrong, so I created an AdventureWorks project using the VS.NET 2013 designer for EFv6. Imported all tables, accepted all defaults and generated code using the shipped .tt. Updated the references to 6.0.1 from nuget and basically did the same benchmark again. Release builds, .NET 4.5. To my surprise it was even slower:
Fetched 31465 entity framework v6.0.1 entities from the DB. Took 9837ms
Fetched 31465 entity framework v6.0.1 entities from the DB. Took 7767ms
Fetched 31465 entity framework v6.0.1 entities from the DB. Took 7724ms
Fetched 31465 entity framework v6.0.1 entities from the DB. Took 7508ms

Absurd slowness compared to EFv5, so I again ran a .NET profiling using dotTrace. It spends 0.02% of its time in the GetEnumerator to fetch the actual data, and the rest in the MoveNext over the result. I've also saved this snapshot, in case you want to look at it. (it's 14MB so I can't attach it).

I've attached this second code base, it's simple code generated from the MS designer.

To me something is seriously off, however I have no idea what. From the looks of it, EF tries to do a lot of stuff with the data pulled from the DB which is irrelevant (as it's a single set of entities, no FKs, related entities, inheritance etc.).

Hope this helps, let me know if you want the dotTrace (a product from JetBrains) snapshots or that I have to run something else for you.

Cheers,

Frans Bouma, lead dev LLBLGen Pro.

I

file attachments

Closed Dec 4, 2013 at 4:22 PM by mgirgin

comments

divega wrote Oct 29, 2013 at 4:32 PM

Hi Frans. Thanks for the heads up. We will investigate.

TheDeeds wrote Nov 6, 2013 at 4:06 AM

We should merge #1786 with this one.

Can we have some stress testing cases in the repo?

SolutionsDesign wrote Nov 6, 2013 at 8:11 AM

Looks indeed like the same issue, as #1786 also is about entity materialization. The .NET profile using dotTrace I did showed massive time loss in the area of FK value synchronization, identity map lookups etc.

The repro here is illustrating the issue (on adventureworks) in such a way that attaching a .net profiler will immediately show you big problems with entity management inside the context with large sets.

cocowalla wrote Nov 12, 2013 at 11:56 AM

I've got the same issue. Materialisation was painfully slow in EF5, and now it's painfully, woefully slow in EF6.

DavidObando wrote Nov 12, 2013 at 6:27 PM

Hi Frans. We have tried to reproduce the reported 7x performance difference from EF5 to EF6, but after trying multiple approaches so far we haven't been able to do it. Could you share via skydrive a copy of the EF5 model you used to obtain your results, as well as the EF6 model that's showing the performance degradation? Additionally, could you share the profiles you collected for EF5 and EF6? That would help us a lot.

SolutionsDesign wrote Nov 12, 2013 at 7:35 PM

In an email thread with Andrew Peters he was able to reproduce the massive slowness just fine? Or are you explicitly looking for the difference between EF5 and EF6? The slowness in EF6 was reproducible by Andrew Peters.

The EF6 model that showed the degradation is attached to this issue, it's a ready to use repro.

I'll attach the EF5 code shortly, and will see if I can upload the profile snapshots somewhere and will post here after that.

SolutionsDesign wrote Nov 12, 2013 at 7:40 PM

I've attached the EFv5 model + persistence classes which I used in my tests for EF5.

SolutionsDesign wrote Nov 13, 2013 at 4:15 PM

I've privately emailed David Obando and Andrew Peters with urls to the profile files.

AndrewPeters wrote Nov 26, 2013 at 5:01 PM

The team is working on 6.0.2 release that addresses several of these performance concerns.

SolutionsDesign wrote Nov 26, 2013 at 6:32 PM

Just for my understanding: the code which fixes this isn't checked in yet? as the issue is now marked as resolved...

divega wrote Nov 26, 2013 at 7:26 PM

Hi Frans,

I hope that breaking this down will help make it clearer:
  1. The root cause of the performance difference you observed was a difference between the two models that you used to repro. As far as we know now there isn't any scenario in which EF6 is anywhere near 7 times slower than EF5. However, thanks to the repros you provided we identified an issue that makes materialization of tracked queries slower for larger and more complex models. The issue affects both EF5 and EF6 (and probably previous versions of EF). We are now using a more specific work item to track that.
  2. Besides that, various changes that improve performance have been checked-in to 6.0.2.
Given #1 and #2 we no longer need this work item.

Hope this helps,
Diego

SolutionsDesign wrote Nov 26, 2013 at 7:51 PM

Ah, thanks, I forgot all about that other item indeed. Sorry for the trouble :)

mgirgin wrote Dec 4, 2013 at 4:21 PM

Closing this bug per the last two comments. We'll be using 1829 track the issue Diego describes.