EF - from projection to domain mapping takes 7 minutes

Question

EntityFramework generates this query:

SELECT 
[Project1].[Ocr_Status] AS [Ocr_Status], 
[Project1].[Id] AS [Id], 
[Project1].[Caption] AS [Caption], 
[Project1].[Name] AS [Name], 
[Project1].[Description] AS [Description], 
[Project1].[Url] AS [Url], 
[Project1].[PictureUri] AS [PictureUri], 
[Project1].[ThumbnailUri] AS [ThumbnailUri], 
[Project1].[ValidFrom] AS [ValidFrom], 
[Project1].[ValidTo] AS [ValidTo], 
[Project1].[VisibleFrom] AS [VisibleFrom], 
[Project1].[VisibleTo] AS [VisibleTo], 
[Project1].[Ocr_Id] AS [Ocr_Id], 
[Project1].[Status] AS [Status], 
[Project1].[Gradient_Width] AS [Gradient_Width], 
[Project1].[Gradient_Color] AS [Gradient_Color], 
[Project1].[BrandId] AS [BrandId], 
[Project1].[StoreOfflineJson] AS [StoreOfflineJson], 
[Project1].[CreatedBy] AS [CreatedBy], 
[Project1].[CreatedOn] AS [CreatedOn], 
[Project1].[LastModifiedBy] AS [LastModifiedBy], 
[Project1].[LastModifiedOn] AS [LastModifiedOn], 
[Project1].[RowVersion] AS [RowVersion], 
[Project1].[C1] AS [C1], 
[Project1].[Id1] AS [Id1], 
[Project1].[PictureUri1] AS [PictureUri1], 
[Project1].[Page] AS [Page], 
[Project1].[Text] AS [Text], 
[Project1].[FlyerId] AS [FlyerId], 
[Project1].[CreatedBy1] AS [CreatedBy1], 
[Project1].[CreatedOn1] AS [CreatedOn1], 
[Project1].[LastModifiedBy1] AS [LastModifiedBy1], 
[Project1].[LastModifiedOn1] AS [LastModifiedOn1], 
[Project1].[RowVersion1] AS [RowVersion1]
FROM ( SELECT 
    [Extent1].[Id] AS [Id], 
    [Extent1].[Caption] AS [Caption], 
    [Extent1].[Name] AS [Name], 
    [Extent1].[Description] AS [Description], 
    [Extent1].[Url] AS [Url], 
    [Extent1].[PictureUri] AS [PictureUri], 
    [Extent1].[ThumbnailUri] AS [ThumbnailUri], 
    [Extent1].[ValidFrom] AS [ValidFrom], 
    [Extent1].[ValidTo] AS [ValidTo], 
    [Extent1].[VisibleFrom] AS [VisibleFrom], 
    [Extent1].[VisibleTo] AS [VisibleTo], 
    [Extent1].[Ocr_Id] AS [Ocr_Id], 
    [Extent1].[Ocr_Status] AS [Ocr_Status], 
    [Extent1].[Status] AS [Status], 
    [Extent1].[Gradient_Width] AS [Gradient_Width], 
    [Extent1].[Gradient_Color] AS [Gradient_Color], 
    [Extent1].[BrandId] AS [BrandId], 
    [Extent1].[StoreOfflineJson] AS [StoreOfflineJson], 
    [Extent1].[CreatedBy] AS [CreatedBy], 
    [Extent1].[CreatedOn] AS [CreatedOn], 
    [Extent1].[LastModifiedBy] AS [LastModifiedBy], 
    [Extent1].[LastModifiedOn] AS [LastModifiedOn], 
    [Extent1].[RowVersion] AS [RowVersion], 
    [Extent2].[Id] AS [Id1], 
    [Extent2].[PictureUri] AS [PictureUri1], 
    [Extent2].[Page] AS [Page], 
    [Extent2].[Text] AS [Text], 
    [Extent2].[FlyerId] AS [FlyerId], 
    [Extent2].[CreatedBy] AS [CreatedBy1], 
    [Extent2].[CreatedOn] AS [CreatedOn1], 
    [Extent2].[LastModifiedBy] AS [LastModifiedBy1], 
    [Extent2].[LastModifiedOn] AS [LastModifiedOn1], 
    [Extent2].[RowVersion] AS [RowVersion1], 
    CASE WHEN ([Extent2].[Id] IS NULL) THEN CAST(NULL AS int) ELSE 1 END AS [C1]
    FROM  [Flyers].[Flyers] AS [Extent1]
    LEFT OUTER JOIN [Flyers].[Pages] AS [Extent2] ON [Extent1].[Id] = [Extent2].[FlyerId]
    WHERE ( NOT (((( CAST( [Extent1].[Status] AS int)) & ( CAST( 4 AS int))) = 4) AND ((CASE WHEN (( CAST( [Extent1].[Status] AS int)) & ( CAST( 4 AS int)) IS NULL) THEN cast(1 as bit) ELSE cast(0 as bit) END) = 0))) AND ( NOT (((( CAST( [Extent1].[Status] AS int)) & ( CAST( 1 AS int))) = 1) AND ((CASE WHEN (( CAST( [Extent1].[Status] AS int)) & ( CAST( 1 AS int)) IS NULL) THEN cast(1 as bit) ELSE cast(0 as bit) END) = 0))) AND ((( CAST( [Extent1].[Status] AS int)) & ( CAST( 2 AS int))) = 2) AND (3 = [Extent1].[Ocr_Status])
)  AS [Project1]
ORDER BY [Project1].[Id] ASC, [Project1].[C1] ASC

In MSSMS this query is done in 1-3s, but in app:

-- Executing asynchronously at 30.05.2017 11:19:40 +02:00
-- Completed in **525 ms** with result: SqlDataReader

So the query completed in 0.5s yes?

Then it's projection time. It takes 6-10 min.

return await Context.Flyers.Where(predicate).Include(f => f.Pages).ToListAsync();

What is going on? There are about 300 rows.

EDIT: add where predicate

The predicate looks like this:

Expression<Func<BackOfficeFlyer, bool>> exsp = flyer =>
                !flyer.Status.HasFlag(FlyerStatus.Active) &&
                !flyer.Status.HasFlag(FlyerStatus.Deleted) &&
                flyer.Status.HasFlag(FlyerStatus.Validated) &&
                flyer.Ocr.Status == OcrStatus.Finished;

Get into the SQL Server Profiler and check for amount of queries and execution times and intervals between one query and the next one. — Cleptus, May 30 '17 at 09:31
Via MS SQL Server Management the query completes in 1-3 seconds. It stops while mapping query results to domain model. — Nerf, May 30 '17 at 09:38
@Nerf SQL Server **Profiler**. To check if other queries are being executed. — , May 30 '17 at 10:32
To your question `So the query completed in 0.5s yes?`It looks like the query executes in whatever time the profiler tells you. The `Completed in **525 ms**` message includes also network time so those 525 seconds will be bigger than the profiler times. Dunno why those 6-10 mins... — Cleptus, May 30 '17 at 10:43
Yeah your Where is scary not clean, clean that and you maybe able to make sense of the rest — Seabizkit, May 30 '17 at 11:15
Perhaps some navigated properties are loaded lazily. Try absolutely disable lazy loading (this.Configuration.LazyLoadingEnabled = false) and repeat your query. — Mark Shevchenko, May 30 '17 at 11:37
This may be of interest http://www.sommarskog.se/query-plan-mysteries.html as well as this if you are using async https://stackoverflow.com/a/28619983/1236044 — jbl, May 31 '17 at 09:55

EF - from projection to domain mapping takes 7 minutes

EDIT: add where predicate

0 Answers0