v15 - Timeout on startup

[nackler]

Which Umbraco version are you using? (Please write the exact version, example: 10.1.0)

15.1.1

Bug summary

After upgrade from v14 to v15.1.1

During application startup I'm now getting a timeout exception in the logs and in the browser. When I refresh the page after the site has started completely the exception does not occur again. I bring it up because I never saw this on v14 so it seems like something new in v15. Is it 'broken'? I'm not sure if this would classify but the first visitor to my site that causes the site to startup will get an exception page. Subsequent visitors will see the site as normal.

Specifics

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.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action1 wrapCloseInAction) at Microsoft.Data.SqlClient.SqlInternalConnection.OnError(SqlException exception, Boolean breakConnection, Action1 wrapCloseInAction)
at Microsoft.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj, SqlCommand command, Boolean callerHasConnectionLock, Boolean asyncClose)
at Microsoft.Data.SqlClient.TdsParser.TryRun(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj, Boolean& dataReady)
at Microsoft.Data.SqlClient.SqlDataReader.TrySetMetaData(_SqlMetaDataSet metaData, Boolean moreInfo)
at Microsoft.Data.SqlClient.TdsParser.TryRun(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj, Boolean& dataReady)
at Microsoft.Data.SqlClient.SqlDataReader.TryConsumeMetaData()
at Microsoft.Data.SqlClient.SqlDataReader.get_MetaData()
at Microsoft.Data.SqlClient.SqlCommand.FinishExecuteReader(SqlDataReader ds, RunBehavior runBehavior, String resetOptionsString, Boolean isInternal, Boolean forDescribeParameterEncryption, Boolean shouldCacheForAlwaysEncrypted)
at Microsoft.Data.SqlClient.SqlCommand.RunExecuteReaderTds(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, Boolean isAsync, Int32 timeout, Task& task, Boolean asyncWrite, Boolean inRetry, SqlDataReader ds, Boolean describeParameterEncryptionRequest)
at Microsoft.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, TaskCompletionSource1 completion, Int32 timeout, Task& task, Boolean& usedCache, Boolean asyncWrite, Boolean inRetry, String method) at Microsoft.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method) at Microsoft.Data.SqlClient.SqlCommand.ExecuteReader(CommandBehavior behavior) at Microsoft.Data.SqlClient.SqlCommand.ExecuteDbDataReader(CommandBehavior behavior) at StackExchange.Profiling.Data.ProfiledDbCommand.ExecuteDbDataReader(CommandBehavior behavior) in C:\projects\dotnet\src\MiniProfiler.Shared\Data\ProfiledDbCommand.cs:line 204 at Umbraco.Cms.Infrastructure.Persistence.FaultHandling.FaultHandlingDbCommand.<>c__DisplayClass35_0.<ExecuteDbDataReader>b__0() at Umbraco.Cms.Infrastructure.Persistence.FaultHandling.FaultHandlingDbCommand.<>c__DisplayClass38_01.b__0()
at Umbraco.Cms.Infrastructure.Persistence.FaultHandling.RetryPolicy.ExecuteAction[TResult](Func1 func) at Umbraco.Cms.Infrastructure.Persistence.FaultHandling.FaultHandlingDbCommand.Execute[T](Func1 f)
at Umbraco.Cms.Infrastructure.Persistence.FaultHandling.FaultHandlingDbCommand.ExecuteDbDataReader(CommandBehavior behavior)
at NPoco.Database.<>c__DisplayClass298_0.b__0()
at NPoco.Database.ExecutionHook[T](Func1 action) at NPoco.Database.ExecuteReaderHelper(DbCommand cmd) at NPoco.Database.ExecuteDataReader(DbCommand cmd, Boolean sync) at NPoco.AsyncHelper.RunSync[T](Task1 task)
at NPoco.Database.QueryImp[T](T instance, Expression1 listExpression, Func2 idFunc, Sql Sql, PocoData pocoData)+MoveNext()
at System.Collections.Generic.List1..ctor(IEnumerable1 collection)
at System.Linq.Enumerable.ToList[TSource](IEnumerable1 source) at NPoco.Database.Fetch[T](Sql sql) at NPoco.Database.PageImpAsync[T](Int64 page, Int64 itemsPerPage, String sql, Object[] args, Boolean sync) at NPoco.AsyncHelper.RunSync[T](Task1 task)
at NPoco.Database.Page[T](Int64 page, Int64 itemsPerPage, String sql, Object[] args)
at NPoco.Database.Page[T](Int64 page, Int64 itemsPerPage, Sql sql)
at Umbraco.Cms.Infrastructure.Persistence.Repositories.Implement.EntityRepository.GetPagedResultsByQuery(IQuery1 query, Guid[] objectTypes, Int64 pageIndex, Int32 pageSize, Int64& totalRecords, IQuery1 filter, Ordering ordering, Action1 sqlCustomization) at Umbraco.Cms.Infrastructure.Persistence.Repositories.Implement.EntityRepository.GetPagedResultsByQuery(IQuery1 query, ISet1 objectTypes, Int64 pageIndex, Int32 pageSize, Int64& totalRecords, IQuery1 filter, Ordering ordering)
at Umbraco.Cms.Core.Persistence.Repositories.IEntityRepository.GetPagedResultsByQuery(IQuery1 query, Guid objectType, Int64 pageIndex, Int32 pageSize, Int64& totalRecords, IQuery1 filter, Ordering ordering)
at Umbraco.Cms.Core.Services.EntityService.GetPagedChildren(Int32 id, UmbracoObjectTypes objectType, Int64 pageIndex, Int32 pageSize, Boolean trashed, IQuery1 filter, Ordering ordering, Int64& totalRecords) at Umbraco.Cms.Core.Services.EntityService.GetPagedChildren(Int32 id, UmbracoObjectTypes objectType, Int64 pageIndex, Int32 pageSize, Int64& totalRecords, IQuery1 filter, Ordering ordering)
at Umbraco.Cms.Core.Services.EntityService.GetPagedChildren(Nullable1 parentKey, IEnumerable1 parentObjectTypes, UmbracoObjectTypes childObjectType, Int32 skip, Int32 take, Int64& totalRecords, IQuery1 filter, Ordering ordering) at Umbraco.Cms.Core.Services.EntityService.GetPagedChildren(Nullable1 parentKey, UmbracoObjectTypes childObjectType, Int32 skip, Int32 take, Int64& totalRecords, IQuery1 filter, Ordering ordering) at Umbraco.Cms.Api.Management.Controllers.Tree.EntityTreeControllerBase1.GetPagedRootEntities(Int32 skip, Int32 take, Int64& totalItems)
at Umbraco.Cms.Api.Management.Controllers.Tree.UserStartNodeTreeControllerBase1.GetPagedRootEntities(Int32 skip, Int32 take, Int64& totalItems) at Umbraco.Cms.Api.Management.Controllers.Tree.EntityTreeControllerBase1.GetRoot(Int32 skip, Int32 take)
at Umbraco.Cms.Api.Management.Controllers.Document.Tree.RootDocumentTreeController.Root(CancellationToken cancellationToken, Int32 skip, Int32 take, Nullable1 dataTypeId) at lambda_method775(Closure, Object) at Microsoft.AspNetCore.Mvc.Infrastructure.ActionMethodExecutor.AwaitableObjectResultExecutor.Execute(ActionContext actionContext, IActionResultTypeMapper mapper, ObjectMethodExecutor executor, Object controller, Object[] arguments) at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.<InvokeActionMethodAsync>g__Awaited|12_0(ControllerActionInvoker invoker, ValueTask1 actionResultValueTask)
at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.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()
--- End of stack trace from previous location ---
at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.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()
--- End of stack trace from previous location ---
at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.g__Awaited|17_0(ResourceInvoker invoker, Task task, IDisposable scope)
at Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.g__Awaited|17_0(ResourceInvoker invoker, Task task, IDisposable scope)
at Umbraco.Cms.Web.Common.Middleware.BasicAuthenticationMiddleware.InvokeAsync(HttpContext context, RequestDelegate next)
at Microsoft.AspNetCore.Builder.UseMiddlewareExtensions.InterfaceMiddlewareBinder.<>c__DisplayClass2_0.<b__0>d.MoveNext()
--- End of stack trace from previous location ---
at Umbraco.Cms.Api.Management.Middleware.BackOfficeExternalLoginProviderErrorMiddleware.InvokeAsync(HttpContext context, RequestDelegate next)
at Microsoft.AspNetCore.Builder.UseMiddlewareExtensions.InterfaceMiddlewareBinder.<>c__DisplayClass2_0.<b__0>d.MoveNext()
--- End of stack trace from previous location ---
at Swashbuckle.AspNetCore.SwaggerUI.SwaggerUIMiddleware.Invoke(HttpContext httpContext)
at Swashbuckle.AspNetCore.Swagger.SwaggerMiddleware.Invoke(HttpContext httpContext, ISwaggerProvider swaggerProvider)
at Microsoft.AspNetCore.Session.SessionMiddleware.Invoke(HttpContext context)
at Microsoft.AspNetCore.Session.SessionMiddleware.Invoke(HttpContext context)
at Microsoft.AspNetCore.Localization.RequestLocalizationMiddleware.Invoke(HttpContext context)
at Microsoft.AspNetCore.Authorization.AuthorizationMiddleware.Invoke(HttpContext context)
at Microsoft.AspNetCore.Authentication.AuthenticationMiddleware.Invoke(HttpContext context)
at StackExchange.Profiling.MiniProfilerMiddleware.Invoke(HttpContext context) in C:\projects\dotnet\src\MiniProfiler.AspNetCore\MiniProfilerMiddleware.cs:line 112
at Umbraco.Cms.Web.Common.Middleware.UmbracoRequestMiddleware.InvokeAsync(HttpContext context, RequestDelegate next)
at Umbraco.Cms.Web.Common.Middleware.UmbracoRequestMiddleware.InvokeAsync(HttpContext context, RequestDelegate next)
at Microsoft.AspNetCore.Builder.UseMiddlewareExtensions.InterfaceMiddlewareBinder.<>c__DisplayClass2_0.<b__0>d.MoveNext()
--- End of stack trace from previous location ---
at Umbraco.Cms.Web.Common.Middleware.PreviewAuthenticationMiddleware.InvokeAsync(HttpContext context, RequestDelegate next)
at Microsoft.AspNetCore.Builder.UseMiddlewareExtensions.InterfaceMiddlewareBinder.<>c__DisplayClass2_0.<b__0>d.MoveNext()
--- End of stack trace from previous location ---
at Umbraco.Cms.Web.Common.Middleware.UmbracoRequestLoggingMiddleware.InvokeAsync(HttpContext context, RequestDelegate next)
at Microsoft.AspNetCore.Builder.UseMiddlewareExtensions.InterfaceMiddlewareBinder.<>c__DisplayClass2_0.<b__0>d.MoveNext()
--- End of stack trace from previous location ---
at Microsoft.AspNetCore.Diagnostics.ExceptionHandlerMiddlewareImpl.g__Awaited|10_0(ExceptionHandlerMiddlewareImpl middleware, HttpContext context, Task task)
ClientConnectionId:db7216a5-01dc-4194-981b-f6128685344a
Error Number:-2,State:0,Class:11

Steps to reproduce

I'm not sure if this manifests on a new install with a blank site. Putting it in here in case others are seeing the same issue and wondering if it is just them.

Expected result / actual result

Expect to see my home page, instead getting an error page.

[github-actions]

Hi there @nackler!

Firstly, a big thank you for raising this issue. Every piece of feedback we receive helps us to make Umbraco better.

We really appreciate your patience while we wait for our team to have a look at this but we wanted to let you know that we see this and share with you the plan for what comes next.

• We'll assess whether this issue relates to something that has already been fixed in a later version of the release that it has been raised for.
• If it's a bug, is it related to a release that we are actively supporting or is it related to a release that's in the end-of-life or security-only phase?
• We'll replicate the issue to ensure that the problem is as described.
• We'll decide whether the behavior is an issue or if the behavior is intended.

We wish we could work with everyone directly and assess your issue immediately but we're in the fortunate position of having lots of contributions to work with and only a few humans who are able to do it. We are making progress though and in the meantime, we will keep you in the loop and let you know when we have any questions.

Thanks, from your friendly Umbraco GitHub bot 🤖 🙂