SQL timeout errors after 3.8-4.5 NOP upgrade

2 months ago
Hi
I recently updated my website from NOP version 3.80 to version 4.50

All went to plan during the update but since it completed my logs are filled with SQL time out errors
I believe it is related to my products having lots of specification attributes which can be filtered on from the category view
Due to this part of the error trace
Page URL
https://www.myecf.co.uk/handles-knobs?specs=1,2,3,4,5,6,7,8,9,19,50,51,53,62,68,80,139,144,273,382,462,481,2641,154

The errors are being generated about one every 1-2 seconds

Full error trace below
Log level
Error
Short message
Execution Timeout Expired.  The timeout period elapsed prior to completion of the operation or the server is not responding.
Full message
Microsoft.Data.SqlClient.SqlException (0x80131904): 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.SqlCommand.<>c.<ExecuteDbDataReaderAsync>b__207_0(Task`1 result)
   at System.Threading.Tasks.ContinuationResultTaskFromResultTask`2.InnerInvoke()
   at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state)
--- End of stack trace from previous location ---
   at System.Threading.Tasks.Task.ExecuteWithThreadLocal(Task& currentTaskSlot, Thread threadPoolThread)
--- End of stack trace from previous location ---
   at LinqToDB.Data.DataConnection.ExecuteReaderAsync(CommandBehavior commandBehavior, CancellationToken cancellationToken)
   at LinqToDB.Data.DataConnection.QueryRunner.ExecuteReaderAsync(CancellationToken cancellationToken)
   at LinqToDB.Linq.QueryRunner.ExecuteElementAsync[T](Query query, IDataContext dataContext, Mapper`1 mapper, Expression expression, Object[] ps, Object[] preambles, CancellationToken cancellationToken)
   at LinqToDB.Linq.QueryRunner.ExecuteElementAsync[T](Query query, IDataContext dataContext, Mapper`1 mapper, Expression expression, Object[] ps, Object[] preambles, CancellationToken cancellationToken)
   at LinqToDB.Linq.ExpressionQuery`1.LinqToDB.Async.IQueryProviderAsync.ExecuteAsync[TResult](Expression expression, CancellationToken cancellationToken)
   at System.Linq.AsyncIQueryableExtensions.ToPagedListAsync[T](IQueryable`1 source, Int32 pageIndex, Int32 pageSize, Boolean getOnlyTotalCount)
   at Nop.Services.Catalog.ProductService.SearchProductsAsync(Int32 pageIndex, Int32 pageSize, IList`1 categoryIds, IList`1 manufacturerIds, Int32 storeId, Int32 vendorId, Int32 warehouseId, Nullable`1 productType, Boolean visibleIndividuallyOnly, Boolean excludeFeaturedProducts, Nullable`1 priceMin, Nullable`1 priceMax, Int32 productTagId, String keywords, Boolean searchDescriptions, Boolean searchManufacturerPartNumber, Boolean searchSku, Boolean searchProductTags, Int32 languageId, IList`1 filteredSpecOptions, ProductSortingEnum orderBy, Boolean showHidden, Nullable`1 overridePublished)
   at Nop.Web.Factories.CatalogModelFactory.PrepareCategoryProductsModelAsync(Category category, CatalogProductsCommand command)
   at Nop.Web.Factories.CatalogModelFactory.PrepareCategoryModelAsync(Category category, CatalogProductsCommand command)
   at Nop.Web.Controllers.CatalogController.Category(Int32 categoryId, CatalogProductsCommand command)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ActionMethodExecutor.TaskOfIActionResultExecutor.Execute(IActionResultTypeMapper mapper, ObjectMethodExecutor executor, Object controller, Object[] arguments)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.<InvokeActionMethodAsync>g__Awaited|12_0(ControllerActionInvoker invoker, ValueTask`1 actionResultValueTask)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.<InvokeNextActionFilterAsync>g__Awaited|10_0(ControllerActionInvoker invoker, Task lastTask, State next, Scope scope, Object state, Boolean isCompleted)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.Rethrow(ActionExecutedContextSealed context)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.Next(State& next, Scope& scope, Object& state, Boolean& isCompleted)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.<InvokeInnerFilterAsync>g__Awaited|13_0(ControllerActionInvoker invoker, Task lastTask, State next, Scope scope, Object state, Boolean isCompleted)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.<InvokeNextResourceFilter>g__Awaited|25_0(ResourceInvoker invoker, Task lastTask, State next, Scope scope, Object state, Boolean isCompleted)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.Rethrow(ResourceExecutedContextSealed context)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.Next(State& next, Scope& scope, Object& state, Boolean& isCompleted)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.<InvokeFilterPipelineAsync>g__Awaited|20_0(ResourceInvoker invoker, Task lastTask, State next, Scope scope, Object state, Boolean isCompleted)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.<InvokeAsync>g__Logged|17_1(ResourceInvoker invoker)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.<InvokeAsync>g__Logged|17_1(ResourceInvoker invoker)
   at Microsoft.AspNetCore.Routing.EndpointMiddleware.<Invoke>g__AwaitRequestTask|6_0(Endpoint endpoint, Task requestTask, ILogger logger)
   at Microsoft.AspNetCore.Authorization.AuthorizationMiddleware.Invoke(HttpContext context)
   at Nop.Services.Authentication.AuthenticationMiddleware.InvokeAsync(HttpContext context)
   at StackExchange.Profiling.MiniProfilerMiddleware.Invoke(HttpContext context) in C:\projects\dotnet\src\MiniProfiler.AspNetCore\MiniProfilerMiddleware.cs:line 121
   at WebMarkupMin.AspNetCore6.WebMarkupMinMiddleware.ProcessAsync(HttpContext context, Boolean useMinification, Boolean useCompression)
   at WebMarkupMin.AspNetCore6.WebMarkupMinMiddleware.ProcessAsync(HttpContext context, Boolean useMinification, Boolean useCompression)
   at WebMarkupMin.AspNetCore6.WebMarkupMinMiddlewareBase.Invoke(HttpContext context)
   at Microsoft.AspNetCore.Localization.RequestLocalizationMiddleware.Invoke(HttpContext context)
   at Microsoft.AspNetCore.Session.SessionMiddleware.Invoke(HttpContext context)
   at Microsoft.AspNetCore.Session.SessionMiddleware.Invoke(HttpContext context)
   at Nop.Services.Installation.InstallUrlMiddleware.InvokeAsync(HttpContext context, IWebHelper webHelper)
   at Nop.Services.Common.KeepAliveMiddleware.InvokeAsync(HttpContext context, IWebHelper webHelper)
   at Microsoft.AspNetCore.Diagnostics.StatusCodePagesMiddleware.Invoke(HttpContext context)
   at Microsoft.AspNetCore.Diagnostics.StatusCodePagesMiddleware.Invoke(HttpContext context)
   at Microsoft.AspNetCore.Diagnostics.ExceptionHandlerMiddleware.<Invoke>g__Awaited|6_0(ExceptionHandlerMiddleware middleware, HttpContext context, Task task)
ClientConnectionId:17998bbd-b4af-4263-9c39-2a5e58120470
Error Number:-2,State:0,Class:11
ClientConnectionId before routing:3a8aec86-7f5f-4252-80eb-de30bc6e99c3
Routing Destination:e0b69b0f6344.tr7529.uksouth1-a.worker.database.windows.net,11029
2 months ago
Do you have any timeout settings on your DB connection string (in appsettings.json)
2 months ago
Hi

Yes updated it from Null to 60 but didn't resolve the issue

Thanks
2 months ago
Troubleshoot the query and see if the PLAN offers any guidance

Identify long queries.  When query is running, exec this
SELECT r.session_id,  
       r.status,  
       r.command,  
       t.text AS [ SQL Text]
FROM sys.dm_exec_requests r
CROSS APPLY sys.dm_exec_sql_text (r.sql_handle) t
WHERE r.status = 'running'
      AND r.total_elapsed_time > 60000; -- Adjust the threshold as needed (time in milliseconds)


Then you can run that query manually.  Use a prior
SET SHOWPLAN_TEXT ON ;
or, in SSMS, right-click the window and "Include actual execution plan"
1 month ago
Also it's recommended to re-index database tables after any version upgrade because tables could be heavily fragmented (if many database changes are applied during the upgrade). Please do it in admin area > system > maintenance
1 month ago
Hi there,

I'm encountering a similar issue on my capcut mod apk website after updating from NOP version 3.80 to version 4.50. Like you, my logs are also getting flooded with SQL timeout errors. It seems that these errors are stemming from the extensive specification attributes attached to my products, especially when filtering from the category view. The error trace you provided aligns closely with what I'm experiencing. It's quite concerning as these errors are occurring frequently, almost every 1-2 seconds. Let's keep each other updated if we find any solutions or workarounds to this problem.
1 month ago
Has any tried running the SQL that I posted above to Identify long running queries?