We have an application running that makes and intensive usage of EF version 4.1. Right now an update is not scheduled, but this is not the point.
We are going under a process of huge optimization as the workload over the Sql Server database is very high. I successfully succeeded (after never succeeding) in profiling the sent queries (we are under Sql Azure) and I discovered that a lot of awful queries were sent, because of stupid usage of Includes. We removed all the avoidable "Includes", by substituing them with direct queries on the sets (i.e. 10 queries against 1 before) and the total workload on Sql Server has dramatically reduced.
But then I discovered that the global code is running slower. How may this be possible? I started tracing and I discovered that even if a query was processed in less that 50ms, EF takes more than 1 second to materialize the entities. That's awful. It's 2 order degrees more than a normal sql query through ADO.Net.
I tried by disabling the Entity Tracking on the set and querying the set with AsNoTracking() but nothing seems changed.
I never had the possibility to analyze the total split time between query processing and object materialization, but I never ever thought that that was the impact. Is there any more that I can try?
--
Update 2015/06/15 - Performance Analysis
I ran 7 different set of tests, and each test has been run 10 times. I tracked the total time to execute the .NET code using the old version (1 huge query with a lot of Includes) and the new version (1 small query for each old Include).
I would say that the problem is, as Jeroen Vannevel said in the comment, the latency of the multiple request / response. Here are the summed results. Please consider that when I write "item" I mean a complex entity, composed by at least 10 different entities taken from 10 different DB tables.
GET of 1 item from the DB
- OLD method: 3.5 seconds average
- NEW method: 276 milliseconds average
GET of 10 items
- OLD method: 3.6 seconds average
- NEW method: 340 milliseconds average (+23%)
GET of 50 items
- OLD method: 4.0 seconds average
- NEW method: 440 milliseconds average (+30%)
GET of 100 items
- OLD method: 4.5 seconds average
- NEW method: 595 milliseconds average (+35%)
GET of 250 items
- OLD method: 5.7 seconds average
- NEW method: 948 milliseconds average (+60%)
GET of 500 items
- OLD method: 5.9 seconds average
- NEW method: 1.8 seconds average (almost +100%)
GET of 1000 items
- OLD method: 6.9 seconds average
- NEW method: 5.1 seconds average (over +180%)
So it seems that, while the OLD method is very slow from the very first execution, because of the heavy query, it increments "slowly" as I get more and more items from the DB.
I would say that as soon as the packet grows up, the time to transfer it to the calling machine is higher than DB time. May this really be the reason?
Thanks Marco