Reputation: 2585
We're belatedly upgrading a successful .net Core 2.1 MVC application to .net Core 5, and everything has gone well, apart from some confusing Microsoft.Data.SqlClient.SqlException 'Execution Timeout Expired'
exceptions in a number of queries that used to work perfectly well in EF Core 2.1.
This is an example of one of the queries we're having problems with
var products = await _context.ShopProducts
.Include(p => p.Category)
.Include(p => p.Brand)
.Include(p => p.CreatedBy)
.Include(p => p.LastUpdatedBy)
.Include(p => p.Variants).ThenInclude(pv => pv.ProductVariantAttributes)
.Include(p => p.Variants).ThenInclude(pv => pv.CountryOfOrigin)
.Include(p => p.Page)
.Include(p => p.CountryOfOrigin)
.OrderBy(p => p.Name)
.Where(p =>
(string.IsNullOrEmpty(searchText)
|| (
p.Name.Contains(searchText)
|| p.Description.Contains(searchText)
|| p.Variants.Any(v => v.SKU.Contains(searchText))
|| p.Variants.Any(v => v.GTIN.Contains(searchText))
|| p.Brand.BrandName.Contains(searchText)
|| p.CountryOfOriginCode == searchText
|| p.Category.Breadcrumb.Contains(searchText)
)
)
).ToPagedListAsync(page, pageSize);
And the exceptions we're getting.
Microsoft.Data.SqlClient.SqlException (0x80131904): Execution Timeout Expired. The timeout period elapsed prior to completion of the operation or the server is not responding.
Execution Timeout Expired. The timeout period elapsed prior to completion of the operation or the server is not responding.
---> System.ComponentModel.Win32Exception (258): The wait operation timed out.
at Microsoft.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction)
at Microsoft.Data.SqlClient.SqlInternalConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction)
at Microsoft.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj, Boolean callerHasConnectionLock, Boolean asyncClose)
at Microsoft.Data.SqlClient.TdsParserStateObject.ThrowExceptionAndWarning(Boolean callerHasConnectionLock, Boolean asyncClose)
at Microsoft.Data.SqlClient.TdsParserStateObject.ReadSniError(TdsParserStateObject stateObj, UInt32 error)
at Microsoft.Data.SqlClient.TdsParserStateObject.ReadSniSyncOverAsync()
at Microsoft.Data.SqlClient.TdsParserStateObject.TryReadNetworkPacket()
at Microsoft.Data.SqlClient.TdsParserStateObject.TryPrepareBuffer()
at Microsoft.Data.SqlClient.TdsParserStateObject.TryReadByteArray(Span`1 buff, Int32 len, Int32& totalRead)
at Microsoft.Data.SqlClient.TdsParserStateObject.TryReadChar(Char& value)
at Microsoft.Data.SqlClient.TdsParser.TryReadPlpUnicodeCharsChunk(Char[] buff, Int32 offst, Int32 len, TdsParserStateObject stateObj, Int32& charsRead)
at Microsoft.Data.SqlClient.TdsParser.TryReadPlpUnicodeChars(Char[]& buff, Int32 offst, Int32 len, TdsParserStateObject stateObj, Int32& totalCharsRead)
at Microsoft.Data.SqlClient.TdsParser.TryReadSqlStringValue(SqlBuffer value, Byte type, Int32 length, Encoding encoding, Boolean isPlp, TdsParserStateObject stateObj)
at Microsoft.Data.SqlClient.TdsParser.TryReadSqlValue(SqlBuffer value, SqlMetaDataPriv md, Int32 length, TdsParserStateObject stateObj, SqlCommandColumnEncryptionSetting columnEncryptionOverride, String columnName, SqlCommand command)
at Microsoft.Data.SqlClient.SqlDataReader.TryReadColumnInternal(Int32 i, Boolean readHeaderOnly)
at Microsoft.Data.SqlClient.SqlDataReader.ReadColumnHeader(Int32 i)
at Microsoft.Data.SqlClient.SqlDataReader.IsDBNull(Int32 i)
at lambda_method1671(Closure , QueryContext , DbDataReader )
at Microsoft.EntityFrameworkCore.Query.RelationalShapedQueryCompilingExpressionVisitor.ShaperProcessingExpressionVisitor.PopulateIncludeCollection[TIncludingEntity,TIncludedEntity](Int32 collectionId, QueryContext queryContext, DbDataReader dbDataReader, SingleQueryResultCoordinator resultCoordinator, Func`3 parentIdentifier, Func`3 outerIdentifier, Func`3 selfIdentifier, IReadOnlyList`1 parentIdentifierValueComparers, IReadOnlyList`1 outerIdentifierValueComparers, IReadOnlyList`1 selfIdentifierValueComparers, Func`5 innerShaper, INavigationBase inverseNavigation, Action`2 fixup, Boolean trackingQuery)
at lambda_method1679(Closure , QueryContext , DbDataReader , ResultContext , SingleQueryResultCoordinator )
at Microsoft.EntityFrameworkCore.Query.Internal.SingleQueryingEnumerable`1.Enumerator.MoveNext()
This query will work perfectly if the searchText
parameter is not specfied, so I thought it must be something index / data related, but running the SQL generated for the query, with and without the searchText
parameter, executes instantaneously when run directly on the database, so it seems to rule out the database as the problem.
Could EF Core 5 be struggling to assemble all the data into object instances? I realise we're returning a large object tree from this query, 152 columns in total, but only 10 rows due to the pageSize
variable.
As it doesn't time out when no searchText
is specified, and as EF Core 2.1 was able to put it all together with no problem, that doesn't seem to quite make sense either.
Any suggestions for ways to tune the query, or insights anyone has from their own EF Core 2.1 to 3.1 / 5 upgrades, or anything that leaps out from the exception stack trace would be very much appreciated.
UPDATE
Apologies for doing my debugging live on SO, but I've found that it's the p.Description.Contains(searchText)
clause in the query that seems to cause the timeout. If I comment it out, the query runs successfully.
The Product.Description
data is an HTML string of up to 1028 chars, with an average length of 350 chars, and again, querying this directly in SQL is no problem at all. Could it cause problems for EF in some other way though?
[DataType(DataType.Html)]
public string Description { get; set; }
Upvotes: 3
Views: 971
Reputation: 34783
The empty search text will work because the composed SQL will ignore any of the other conditions if it is empty. A better way of implementing that would be to keep the condition logic in code rather than the expression:
var query = _context.ShopProducts
.Include(p => p.Category)
.Include(p => p.Brand)
.Include(p => p.CreatedBy)
.Include(p => p.LastUpdatedBy)
.Include(p => p.Variants)
.ThenInclude(pv => pv.ProductVariantAttributes)
.Include(p => p.Variants)
.ThenInclude(pv => pv.CountryOfOrigin)
.Include(p => p.Page)
.Include(p => p.CountryOfOrigin)
.OrderBy(p => p.Name);
if (!string.IsNullOrEmpty(searchText))
query = query.Where(p => p.Name.Contains(searchText)
|| p.Description.Contains(searchText)
|| p.Variants.Any(v => v.SKU.Contains(searchText))
|| p.Variants.Any(v => v.GTIN.Contains(searchText))
|| p.Brand.BrandName.Contains(searchText)
|| p.CountryOfOriginCode == searchText
|| p.Category.Breadcrumb.Contains(searchText));
var products = await query.ToPagedListAsync(page, pageSize);
Leaving the if
statement in code ensures these conditions only make it to SQL if they are needed. This is advisable especially where you might have multiple separate search terms and conditionally apply each of them.
The crux of your problem is likely that you are kicking off what will surely be an extremely inefficient query that cannot take advantage of any form of indexing, being a multi LIKE %{term}%
query. If there is one way to allow users to trigger an effective DDOS against your server, it is this. It will be slow, and users will doubt it started and kick it off repeatedly. (spawning new tabs and such)
In systems there is often a text search capability where there is the possibly of searching across multiple different possible values. You don't do yourself or your users any favours by condensing these down into one uber search. The trouble is that if 95% of the time the search could be directed by the user to the most common type or fields of search it could be considerably faster, but to cater for the 5%, all searches must be the (s)lowest common denominator.
Some options to consider:
Changes like this can help keep the 95%+ of the searching as fast and efficient as possible. I would also consider employing a queuing mechanism for potentially expensive searches where the criteria and pagination data is popped onto a queue with a searchQueueID passed back to the caller which then polls for results using that ID, or can cancel their search. The queue is serviced by a small pool of worker threads that process search requests in sequence and populate a results storage against the searchQueueID and completed status to be picked up by the polling loop. This can help ensure that only so many of these potentially expensive searches are being executed at any given time. (I.e. all kicked off by different users.)
Upvotes: 2
Reputation: 89091
Consider using Split Queries to improve performance on queries with lots of Include's.
Upvotes: 5