Queries really slow due to null checks

[jamesgurung]

I'm getting a lot of slowdowns on the EF Core 3 preview. Here's an example.

var firstResult = await Db.Results.FirstOrDefaultAsync(o => o.TestId == 1);

This generates the following SQL, which runs really slowly on my SQL Azure database (>3 seconds):

exec sp_executesql N'SELECT TOP(1) [r].[Id]
FROM [Results] AS [r]
WHERE (([r].[TestId] = @__testId_0) AND ([r].[TestId] IS NOT NULL AND @__testId_0 IS NOT NULL))
OR ([r].[TestId] IS NULL AND @__testId_0 IS NULL)',N'@__testId_0 int',@__testId_0=1

The SQL I would expect is (<0.1 seconds):

exec sp_executesql N'SELECT TOP(1) [r].[Id]
FROM [Results] AS [r]
WHERE ([r].[TestId] = @__testId_0)',N'@__testId_0 int',@__testId_0=1

Further technical details

EF Core version: 3.0.0-preview8.19405.11
Database Provider: Microsoft.EntityFrameworkCore.SqlServer
Operating system: Windows 10
IDE: Visual Studio 2019 Version 16.3 Preview 2

[ajcvickers]

@smitpatel @maumar What's the risk in doing the optimization here? Perf could be a reason to fix this for 3.0.

[ajcvickers]

/cc @divega

[divega]

I think it is related to #15892 which is about bringing back the additional layer of cache based on null/non-null parameter values.

[divega]

Also, we still have the ability to switch on database null semantics as a workaround, correct?

[jamesgurung]

To be clear, in the example above Result.TestId is a nullable int - so the null case does need to be considered. What would be wrong with this (which runs fast)?

WHERE (@__testId_0 IS NULL AND [r].[TestId] IS NULL) OR ([r].[TestId] = @__testId_0)

[roji]

As @jamesgurung says, the original query above could use some null semantics improvements which are unrelated to a parameter-sniffing cache layer: [r].[TestId] IS NOT NULL AND @__testId_0 IS NOT NULL is unnecessary since the first condition ([r].[TestId] = @__testId_0) can only be satisfied if both sides are non-null.

@maumar is aware of this. @jamesgurung, can you please report on the perf of your suggestion in #17543 (comment))?

[jamesgurung]

The query I suggested runs in about 0.05 seconds, which is the same speed as running the query without any null checks. So ~50x faster.

[roji]

@jamesgurung thanks for the info. It's disappointing that SQL Server doesn't short-circuit this entirely, but in any case we'll be removing the unnecessary checks on our side.

[maumar]

related: #16221

[windsOne]

Please speed up this issues

[mscrivo]

Yeah this needs to be fixed asap. We just deployed code that uses 3.0 and had to immediately revert to 2.2 because simple queries blew up our SQL Azure CPU usage. Went from under 50% to 100% and stayed there until we rolled back.

[mscrivo]

Is there any possible mitigation for this in the 3.0 release?

[roji]

@mscrivo and others, this is currently to planned for fixing in 3.1, which will be released by the end of the year. We won't be fixing this in 3.0.

[mscrivo]

@roji Thanks for the update. That's rather disappointing as it means we have to either rollback a month's worth of work and maintain it on a branch until 3.1 is out, or scramble and find all places in our code where this pattern exists and rewrite it to force EF Core to generate different SQL. This should have definitely been called out in the known issues of the release notes.

Here's what we're seeing for reference:

declare @_param_ID_0 bigint=111111

-- EF Core 3.0
SELECT    [i].[ID], ...
FROM [Table] AS [i]
WHERE (
        (
            ([i].[OtherNullableID] = @_param_ID_0) AND ([i].[OtherNullableID] IS NOT NULL AND @_param_ID_0 IS NOT NULL)
            ) 
        OR 
        (
            [i].[OtherNullableID] IS NULL AND @_param_ID_0 IS NULL
            )
        ) 
        
        AND ([i].[Type] <> 1)

/*
Table 'Table'. Scan count 13, logical reads 1983575, physical reads 6539, page server reads 0, read-ahead reads 1651369, page server read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob page server reads 0, lob read-ahead reads 0, lob page server read-ahead reads 0.

 SQL Server Execution Times:
   CPU time = 57124 ms,  elapsed time = 10894 ms.

*/

-- EF Core 2.2
(@_param_ID_0 bigint)SELECT [_].[ID], ...
FROM [Table] AS [_]  
WHERE ([_].[OtherNullableID] = @_param_ID_0) AND ([_].[Type] <> 1)

/*
Table 'Table'. Scan count 2, logical reads 8, physical reads 0, page server reads 0, read-ahead reads 0, page server read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob page server reads 0, lob read-ahead reads 0, lob page server read-ahead reads 0.

 SQL Server Execution Times:
   CPU time = 0 ms,  elapsed time = 0 ms.

*/

On a table with 91 million records. Not big by any stretch.

[cnblogs-dudu]

We encountered a SQL Server 100% CPU utilization issue on Alibaba Cloud with many IS NOT NULL in SQL generated by EF Core 3.0. Sometime it resulted in extremely poor execution plan performance.

[maumar]

Partial fix has been checked in - 069d334

This addresses queries that heavily rely on SQL parameters (closure variables). Outstanding issues are adding "simplified" null semantics optimization that would not add extra terms in non-negated predicates to distinguish null from false, and optimize scenarios around enum flags (#18500)

[maumar]

FYI, fix got into the latest nightly build (3.1.0-preview2.19522.3)

[jamesgurung]

@maumar Thank you. Is this a full fix to the null semantics as described in this issue, or the partial fix you mentioned above?

[maumar]

@jamesgurung just the partial fix for now. It should be an improvement for scenarios that heavily use parameters, but there are more optimizations to do (and I will report the progress on this thread as they get checked in).

With the current fix, the original query presented in the issue will now look like this:

SELECT TOP(1) [r].[Id]
FROM [Results] AS [r]
WHERE (([r].[TestId] = @__testId_0) AND [r].[TestId] IS NOT NULL)

I will be adding more optimizations shortly and will post updates on this thread.

[maumar]

update: checked in another optimization that deals with enum flags (and other complex expressions compared to null). See #16078 for additional info.

[jamesgurung]

@maumar Fantastic - will be upgrading from 2.x to 3.1 Preview 2 when it's out!