A suspended select Query when called by C# EF core, MSSQL management studio executes the query just fine. Why?

Question

I cannot give you enough data to reproduce the errors, so I am going to give you as much data as I can get away with.

I have a select statement executing from EF core.

var bookings = context.Booking
                      .Where(booking => booking.ConsigneeNumber == customer.GetCustomerTarget().Code 
                             && booking.CreatedAt >= from 
                             && booking.CreatedAt < to 
                             && booking.BookingLine.Any(b => b.BookingLineSpecification
                                                        .Any(c => c.CurrencyCode == code))
                            )

                     .Include(booking => booking.BookingLine)
                         .ThenInclude(bl => bl.BookingLineSpecification)
                         .ThenInclude(bls => bls.UnitType)
                     .Include(booking => booking.BookingLine)
                         .ThenInclude(bl => bl.BookingLineAddress)
                         .ThenInclude(bla => bla.Country)
                     .Include(booking => booking.BookingLine)
                         .ThenInclude(bl => bl.BookingLineAddress)
                         .ThenInclude(bla => bla.PostalCode)
                     .Include(booking => booking.BookingLine)
                         .ThenInclude(bl => bl.BookingLineSpecification)
                         .ThenInclude(bls => bls.RelBookingLineSpecificationSalesInvoiceDetail)
                         .ThenInclude(Rel => Rel.SalesInvoiceDetail);

The SQL query itself being suspended on the MSSQL server becomes:

     (@__GetCustomerTarget_Code_0 bigint,@__from_1 datetime2(7),@__to_2 datetime2(7),@__code_3 varchar(255))
        SELECT [booking].[Id], 
    [booking].[booking_provider_id], 
    [booking].[booking_status_id], 
    [booking].[consignee_name], 
    [booking].[consignee_number], 
    [booking].[created_at], 
    [booking].[created_by], 
    [booking].[currency_code], 
    [booking].[deliveryNumber], 
    [booking].[description], 
    [booking].[destroyed_at], 
    [booking].[destroyed_by], 
    [booking].[inter_company_number], 
    [booking].[invoicee_name], 
    [booking].[invoicee_number], 
    [booking].[is_create], 
    [booking].[location_id], 
    [booking].[location_name], 
    [booking].[maturity_level_id], 
    [booking].[number], 
    [booking].[order_number], 
    [booking].[provider_key], 
    [booking].[shipment_id], 
    [booking].[system_responsible_id], 
    [booking].[updated_at], 
    [booking].[updated_by]  
    FROM [Integration].[booking] AS [booking]  
WHERE ((([booking].[consignee_number] = @__GetCustomerTarget_Code_0) 
AND ([booking].[created_at] >= @__from_1)) 
AND ([booking].[created_at] < @__to_2)) 
AND EXISTS (      
SELECT 1      
FROM [Integration].[booking_line] AS [b]      
WHERE EXISTS (          
SELECT 1          
FROM [Integration].[booking_line_specification] AS [c]          
WHERE ([c].[currency_code] = @__code_3) AND ([b].[Id] = [c].[booking_line_id])) AND ([booking].[Id] = [b].[booking_id]))

This statement executes in zero seconds (but some miliseconds) when executed in MSSQL management studio. However the C# application experiences a timeout.

When I use the internal tools on MSSQL I can see that the spid is suspended, and permanently waiting. However the reason seems to be altering. In the beginning its due to IO_COMPLETION. Then its SOS_YIELD_~something and finally PAGEIOLATCH_SH This final state it stays in

I, for the life of me, cannot figure out why MSSQL can execute the query with no issue at all. But EF seemingly fails to utilize Indexes. Or something else I am missing entirely.

I am simply out of ideas. Can anyone point me in a direction that might help?

I have tried:

Running it in Visual stuido 2017. Running in release mode. I have tried Enabling lazy mode, and not use includes. I have tried removing lazy loads and includes, just to see if I could get the bookings back.

Nope. MSSQL seems to refuse EF Core from utilizing the Indexes.

The thing is, the query only hangs when I provide certain parameters. Other parameters work just fine. Specifically, if I provide different currency codes, this seems to make all the difference for MSSQL if the query gets suspended or not.

I have completely rebuilt the indexes required to execute this query efficiently according to the execution plan in MSSQL management studio.

Any further information that might be required please let me know, and I will see what I can do, to the best of my efforts.

UPDATE Actual execution plan:

UPDATE 2: I would like to point out, that this is currently being used for development, and thus this DB, my software and anything in between, is under my "control".

In so far as my apparently inexperienced mind can control anything :)

So any suggestions on how to better debug the problem, or requests for more data will be met with vigor and appreciation. And will likely be possible, especially if hinted at how to provide it to you! (And me)

SQL Profiler: opening connection to the DB:

set quoted_identifier on
set arithabort on
set numeric_roundabort off
set ansi_warnings on
set ansi_padding on
set ansi_nulls on
set concat_null_yields_null on
set cursor_close_on_commit off
set implicit_transactions off
set language us_english
set dateformat mdy
set datefirst 7
set transaction isolation level read committed

[Can't use DB indexes with Entity Framework using where clauses](https://stackoverflow.com/questions/47430973/cant-use-db-indexes-with-entity-framework-using-where-clauses/) — Denis Rubashkin, Jan 09 '19 at 13:21
@DenisRubashkin I have tried to define all parameters like this: .HasColumnType("varchar") No change. — Morten Bork, Jan 09 '19 at 14:50
I meant you should try to add `OPTION (RECOMPILE)` to your query using, for example, DBInterceptor. — Denis Rubashkin, Jan 09 '19 at 15:25
@DenisRubashkin I see our miscommunication. There is no implementation for the Intercept abstraction for CORE as fair as I can tell.. — Morten Bork, Jan 10 '19 at 09:18
@DenisRubashkin Also the Indexes are not corrupted in anyway. The problem exists purely on the select statement. All inserts etc, that are done afterwards with the data executes at an expected time frame, compared to the inserts done in MSSQL. — Morten Bork, Jan 10 '19 at 09:24
SQL Server doesn't prevent EF Core from using indexes, it's the *query itself* that may prevent the query analyzer from using indexes. Or it could be that the actual data statistics make using the existing indexes a bad idea. Or it could be that there are no good indexes. — Panagiotis Kanavos, Jan 10 '19 at 09:40
@PanagiotisKanavos I have used the execution plan to validate the index requirements for the query to run properly. If you read my Question, I state specifically, that in Management studio, the queries execute in expected time frames. However, when the query comes from C# EF CORE -> It seems the indexes do not get used, or something else is slowing down the responses. Some of these very slow responses actually return empty result sets. — Morten Bork, Jan 10 '19 at 09:54
@MortenBork EF Core doesn't affect how the *query optimizer* uses indexes. Your execution plan shows that indexes *are* used. The expensive key lookup is caused because some column in `BookingLineSpecification` is *not* included in the index and must be read separately. I suspect that's `booking_line_id` — Panagiotis Kanavos, Jan 10 '19 at 10:00
@MortenBork execution plans are created and cached the first time a query is executed, based on the query parameters used that first time, based on the data statistics. A key lookup will be fast if there are only a few columns to match so the optimizer may choose that over looking up another index. The same execution plan may be slow if you try to look up a currency with a *lot* of matching specification lines. That's why Denis said you should use `OPTION (RECOMPILE)` to force SQL Server to recompile the query each time — Panagiotis Kanavos, Jan 10 '19 at 10:04
@MortenBork you should try getting rid of the key lookup by finding what it's trying to load (it appears in the node's properties) and put those columns in the index. You could try adding them as [included columns](https://learn.microsoft.com/en-us/sql/relational-databases/indexes/create-indexes-with-included-columns?view=sql-server-2017) — Panagiotis Kanavos, Jan 10 '19 at 10:07
@PagagiotisKanavos The key lookup is the primary key look up between the booking, booking line, and booking line specification. That bit is quite vital if not in this specific look up then in many, many other. Also, my performance in MSSQL is damn near perfect? It seems you are saying that there is a problem with the indexes themselves? Then why is MSSQL management studio not experiencing any of these issues? — Morten Bork, Jan 10 '19 at 11:04
@MortenBork, MSSQL management studio doesn't experience any of these issues because it uses different query plans for different parameters' values. But the query from EF will be executed using `sp_executesql` and you will get a saved plan for the values provided for the first time. Looking at your shown plan, for example, if you get 1000 rows from each table you will have to do 1000*1000*1000 key lookups. — Denis Rubashkin, Jan 10 '19 at 11:34
@MortenBork Nothing of a "dunce" about not knowing something, especially seem you appear very willing to learn! Try Googling "sp_executesql parameter sniffing query plan" - a good starting point would probably be https://www.brentozar.com/archive/2013/06/the-elephant-and-the-mouse-or-parameter-sniffing-in-sql-server/ — Ian Kemp, Jan 10 '19 at 13:07
Anyone have a suggestion on how to get EF core to embed that pesky "Option(Recompile)" in my query? Because that is causing my brain to hurt now. — Morten Bork, Jan 10 '19 at 13:42
@PanagiotisKanavos You where 100% on the money. I have written my own answer to what I did to resolve the issue, but if you make one, I will reward yours ass accepted. — Morten Bork, Jan 11 '19 at 11:05

Morten Bork · Accepted Answer · 2019-01-18T07:20:45.983

This is our answer for anyone who wishes to know what we did to resolve this issue. It is quite a "hack" to resolve the fact, that entity framework core, does in fact not let you do this by design, or does it by itself by design.

We execute this stored procedure prior to an actual execution on our C# code that asks for this specific data.

This looks for cached execution plans that can be used for a query that looks a lot like the one EF generates. And then it kills them one by one.

It is not a good thing to do. 1, It requires the user to have permissions to do this. No application should have this permission level. You can argue you all you want it "could have", but really, you all know it shouldn't have. 2,
In code, I am executing a stored procedure prior to a select statement to get the application to perform. Really. Really? Well, yes. I am. Is it neat? no. Is it clean? no. I wouldn't even really recommend doing it as such, there are so many possible pitfalls in this, if you change parameters, or alter the query in any way, you have to rebuild the "like" string. I built it in the first place by using SQL Profiler to sniff the query, and then copied the bits that were as unique as possible towards other possible query executions. Could there be an incorrect identification? Yes. If you run the select a million times a second, this is likely not a viable solution. etc.

But it works for me.

EF core, executes its query in a stored procedure. But doesn't work with includes, if you use stored procedures. My brain bleeds from trying to wrap my head around this. So this painful solution is the one I am using.

/****** Object:  StoredProcedure [dbo].[WipePlanForDraftLoad]    Script Date: 11/01/2019 11:50:03 ******/
SET ANSI_NULLS ON
GO

SET QUOTED_IDENTIFIER ON
GO

-- =============================================
-- Author:  Morten Bork, Henrik Davidsen    
-- Create date: 2019-01-11
-- Description: Procedure to Wipe a cached plan for a query that sort of matches a specific string
-- =============================================
CREATE PROCEDURE [dbo].[WipePlanForDraftLoad]
    -- Add the parameters for the stored procedure here

AS
BEGIN

declare plans cursor 
for 
select t1.plan_handle from sys.dm_exec_cached_plans t1
left outer join sys.dm_exec_query_stats t2 on t1.plan_handle = t2.plan_handle
outer apply sys.dm_exec_sql_text(sql_Handle) 
where text like '%(@__customerCode_0 bigint,@__from_1 datetime2(7),@__to_2 datetime2(7),@__currencyCode_3 varchar(255))%WHERE (\[c\].\[currency_code\] = @__currencyCode_3) AND (\[b\].\[Id\] = \[c\].\[booking_line_id\])) AND (\[booking\].\[Id\] = \[b\].\[booking_id\])%' escape '\'

declare @plan_handle varbinary(64)
open plans
fetch next from plans into @plan_handle
while @@FETCH_STATUS = 0
begin
    dbcc freeproccache(@plan_handle)
    fetch next from plans into @plan_handle
end
close plans
deallocate plans
END
GO

Thanks for returning and enriching this site with such a thorough explanation. I see this parameter sniffing issue so often and this is usually the go to http://www.sommarskog.se/query-plan-mysteries.html — Nick.Mc, Jan 11 '19 at 11:10

score 0 · Answer 2 · answered Jan 09 '19 at 13:25

0

I had a similar issue a while back, and it had to do with certain defaults being set in SSMS that EF does not automatically set. If you can, try setting ARITHABORT ON for the EF session from code, and see if the query executes the same as it does in SSMS.

answered Jan 09 '19 at 13:25

CodeMonkey

419
2
10

I executed context.Database.ExecuteSqlCommand("SET ARITHABORT ON"); Right before the execution of the query. It did not help. – Morten Bork Jan 09 '19 at 14:48
That may not work because each execution in entity framework is in its own scope. It needs to be either done in the context of the executed query (if you are passing a string) or it needs to be set during the initialization of the database class. Perhaps as a test, try passing the generated SQL string but add the arithabort statement above it and see if that does anything? – CodeMonkey Jan 09 '19 at 15:43
1

I Set it on, pr default, server side. And this does seem to have reduced some of the queries response time somewhat, down from a time out, to about 6 seconds. However MSSQL still does the query in less than a second. I tried upping the EF CORE command timeout, to see how long the queries take. The longest one after the arithAbort is set to "ON" is 2 minutes a 43 seconds. While the query on MSSQL takes 9 seconds. – Morten Bork Jan 10 '19 at 09:09
There's a similar issue that may help you more: https://stackoverflow.com/questions/47093440/major-performance-difference-between-entity-framework-generated-sp-executesql-an – CodeMonkey Jan 10 '19 at 15:42
This link references EF framwork version. Not core. Core, doesn't implement the Interceptor interface/abstraction. – Morten Bork Jan 11 '19 at 07:58
Just to be clear, it's not the setting that makes the difference, it's the fact that the entire query fingerprint now matches a good plan in cache and it uses a good plan instead of a bad one. This is not a real solution. – Nick.Mc Jan 11 '19 at 11:11

A suspended select Query when called by C# EF core, MSSQL management studio executes the query just fine. Why?

2 Answers2