Maintenance page isn't shown while migrations are running in background

bjarnef commented 3 months ago

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

12.3.9

Bug summary

On an Umbraco Cloud project we upgraded from Umbraco v10.8.5 to v12.3.9 - locally this worked okay with a slim version of content in Umbraco, but after restoring af backup of live database, then migration seems to be running for a while.

We also have ShowMaintenancePageWhenInUpgradeState: true in appsettings.json but even though the maintance page doesn't show, but just seems to load the page for a long time.

The log shows the following:

{"@t":"2024-05-17T14:05:14.5654864Z","@mt":"Execute {MigrationType}","MigrationType":"TablesIndexesImprovement","SourceContext":"Umbraco.Cms.Infrastructure.Migrations.MigrationPlanExecutor","ProcessId":26604,"ProcessName":"iisexpress","ThreadId":1,"ApplicationId":"f8a8777e1a9657d6d5e2a3c88ad9ed8f166f7384","MachineName":"LAPTOP-BF","Log4NetLevel":"INFO "}
{"@t":"2024-05-17T14:05:14.5921602Z","@mt":"SQL [{ContextIndex}]: {Sql}","ContextIndex":0,"Sql":"DROP INDEX [IX_umbracoNode_ObjectType_trashed_sorted] ON [umbracoNode]","SourceContext":"Umbraco.Cms.Infrastructure.Migrations.MigrationContext","ProcessId":26604,"ProcessName":"iisexpress","ThreadId":1,"ApplicationId":"f8a8777e1a9657d6d5e2a3c88ad9ed8f166f7384","MachineName":"LAPTOP-BF","Log4NetLevel":"INFO "}
{"@t":"2024-05-17T14:05:14.6064572Z","@mt":"SQL [{ContextIndex}]: {Sql}","ContextIndex":1,"Sql":"CREATE NONCLUSTERED INDEX [IX_umbracoNode_ObjectType_trashed_sorted] ON [umbracoNode] ([nodeObjectType],[trashed],[sortOrder],[id]) INCLUDE ([uniqueID],[parentID],[level],[path],[nodeUser],[text],[createDate])","SourceContext":"Umbraco.Cms.Infrastructure.Migrations.MigrationContext","ProcessId":26604,"ProcessName":"iisexpress","ThreadId":1,"ApplicationId":"f8a8777e1a9657d6d5e2a3c88ad9ed8f166f7384","MachineName":"LAPTOP-BF","Log4NetLevel":"INFO "}
{"@t":"2024-05-17T14:05:14.7780363Z","@mt":"SQL [{ContextIndex}]: {Sql}","ContextIndex":2,"Sql":"DROP INDEX [IX_umbracoRedirectUrl_culture_hash] ON [umbracoRedirectUrl]","SourceContext":"Umbraco.Cms.Infrastructure.Migrations.MigrationContext","ProcessId":26604,"ProcessName":"iisexpress","ThreadId":1,"ApplicationId":"f8a8777e1a9657d6d5e2a3c88ad9ed8f166f7384","MachineName":"LAPTOP-BF","Log4NetLevel":"INFO "}
{"@t":"2024-05-17T14:05:14.7823333Z","@mt":"SQL [{ContextIndex}]: {Sql}","ContextIndex":3,"Sql":"CREATE NONCLUSTERED INDEX [IX_umbracoRedirectUrl_culture_hash] ON [umbracoRedirectUrl] ([createDateUtc]) INCLUDE ([culture],[url],[urlHash],[contentKey])","SourceContext":"Umbraco.Cms.Infrastructure.Migrations.MigrationContext","ProcessId":26604,"ProcessName":"iisexpress","ThreadId":1,"ApplicationId":"f8a8777e1a9657d6d5e2a3c88ad9ed8f166f7384","MachineName":"LAPTOP-BF","Log4NetLevel":"INFO "}
{"@t":"2024-05-17T14:05:14.8381968Z","@mt":"SQL [{ContextIndex}]: {Sql}","ContextIndex":4,"Sql":"DROP INDEX [IX_umbracoContentVersionCultureVariation_VersionId] ON [umbracoContentVersionCultureVariation]","SourceContext":"Umbraco.Cms.Infrastructure.Migrations.MigrationContext","ProcessId":26604,"ProcessName":"iisexpress","ThreadId":1,"ApplicationId":"f8a8777e1a9657d6d5e2a3c88ad9ed8f166f7384","MachineName":"LAPTOP-BF","Log4NetLevel":"INFO "}
{"@t":"2024-05-17T14:05:14.8406948Z","@mt":"SQL [{ContextIndex}]: {Sql}","ContextIndex":5,"Sql":"CREATE UNIQUE NONCLUSTERED INDEX [IX_umbracoContentVersionCultureVariation_VersionId] ON [umbracoContentVersionCultureVariation] ([versionId],[languageId]) INCLUDE ([id],[name],[date],[availableUserId])","SourceContext":"Umbraco.Cms.Infrastructure.Migrations.MigrationContext","ProcessId":26604,"ProcessName":"iisexpress","ThreadId":1,"ApplicationId":"f8a8777e1a9657d6d5e2a3c88ad9ed8f166f7384","MachineName":"LAPTOP-BF","Log4NetLevel":"INFO "}
{"@t":"2024-05-17T14:05:14.8656563Z","@mt":"SQL [{ContextIndex}]: {Sql}","ContextIndex":6,"Sql":"DROP INDEX [IX_umbracoContentVersion_NodeId] ON [umbracoContentVersion]","SourceContext":"Umbraco.Cms.Infrastructure.Migrations.MigrationContext","ProcessId":26604,"ProcessName":"iisexpress","ThreadId":1,"ApplicationId":"f8a8777e1a9657d6d5e2a3c88ad9ed8f166f7384","MachineName":"LAPTOP-BF","Log4NetLevel":"INFO "}
{"@t":"2024-05-17T14:05:14.8683810Z","@mt":"SQL [{ContextIndex}]: {Sql}","ContextIndex":7,"Sql":"CREATE NONCLUSTERED INDEX [IX_umbracoContentVersion_NodeId] ON [umbracoContentVersion] ([nodeId],[current]) INCLUDE ([id],[versionDate],[text],[userId],[preventCleanup])","SourceContext":"Umbraco.Cms.Infrastructure.Migrations.MigrationContext","ProcessId":26604,"ProcessName":"iisexpress","ThreadId":1,"ApplicationId":"f8a8777e1a9657d6d5e2a3c88ad9ed8f166f7384","MachineName":"LAPTOP-BF","Log4NetLevel":"INFO "}
{"@t":"2024-05-17T14:05:15.4024978Z","@mt":"SQL [{ContextIndex}]: {Sql}","ContextIndex":8,"Sql":"DROP INDEX [IX_cmsTagRelationship_tagId_nodeId] ON [cmsTagRelationship]","SourceContext":"Umbraco.Cms.Infrastructure.Migrations.MigrationContext","ProcessId":26604,"ProcessName":"iisexpress","ThreadId":1,"ApplicationId":"f8a8777e1a9657d6d5e2a3c88ad9ed8f166f7384","MachineName":"LAPTOP-BF","Log4NetLevel":"INFO "}
{"@t":"2024-05-17T14:05:15.4050993Z","@mt":"SQL [{ContextIndex}]: {Sql}","ContextIndex":9,"Sql":"CREATE NONCLUSTERED INDEX [IX_cmsTagRelationship_tagId_nodeId] ON [cmsTagRelationship] ([tagId],[nodeId]) INCLUDE ([propertyTypeId])","SourceContext":"Umbraco.Cms.Infrastructure.Migrations.MigrationContext","ProcessId":26604,"ProcessName":"iisexpress","ThreadId":1,"ApplicationId":"f8a8777e1a9657d6d5e2a3c88ad9ed8f166f7384","MachineName":"LAPTOP-BF","Log4NetLevel":"INFO "}
{"@t":"2024-05-17T14:05:15.4254668Z","@mt":"SQL [{ContextIndex}]: {Sql}","ContextIndex":10,"Sql":"DROP INDEX [IX_cmsTags_languageId_group] ON [cmsTags]","SourceContext":"Umbraco.Cms.Infrastructure.Migrations.MigrationContext","ProcessId":26604,"ProcessName":"iisexpress","ThreadId":1,"ApplicationId":"f8a8777e1a9657d6d5e2a3c88ad9ed8f166f7384","MachineName":"LAPTOP-BF","Log4NetLevel":"INFO "}
{"@t":"2024-05-17T14:05:15.4276481Z","@mt":"SQL [{ContextIndex}]: {Sql}","ContextIndex":11,"Sql":"CREATE NONCLUSTERED INDEX [IX_cmsTags_languageId_group] ON [cmsTags] ([languageId],[group]) INCLUDE ([id],[tag])","SourceContext":"Umbraco.Cms.Infrastructure.Migrations.MigrationContext","ProcessId":26604,"ProcessName":"iisexpress","ThreadId":1,"ApplicationId":"f8a8777e1a9657d6d5e2a3c88ad9ed8f166f7384","MachineName":"LAPTOP-BF","Log4NetLevel":"INFO "}
{"@t":"2024-05-17T14:05:15.4503781Z","@mt":"SQL [{ContextIndex}]: {Sql}","ContextIndex":12,"Sql":"DROP INDEX [IX_umbracoDocumentVersion_id_published] ON [umbracoDocumentVersion]","SourceContext":"Umbraco.Cms.Infrastructure.Migrations.MigrationContext","ProcessId":26604,"ProcessName":"iisexpress","ThreadId":1,"ApplicationId":"f8a8777e1a9657d6d5e2a3c88ad9ed8f166f7384","MachineName":"LAPTOP-BF","Log4NetLevel":"INFO "}
{"@t":"2024-05-17T14:05:15.4535874Z","@mt":"SQL [{ContextIndex}]: {Sql}","ContextIndex":13,"Sql":"CREATE NONCLUSTERED INDEX [IX_umbracoDocumentVersion_id_published] ON [umbracoDocumentVersion] ([id],[published]) INCLUDE ([templateId])","SourceContext":"Umbraco.Cms.Infrastructure.Migrations.MigrationContext","ProcessId":26604,"ProcessName":"iisexpress","ThreadId":1,"ApplicationId":"f8a8777e1a9657d6d5e2a3c88ad9ed8f166f7384","MachineName":"LAPTOP-BF","Log4NetLevel":"INFO "}
{"@t":"2024-05-17T14:05:15.6925826Z","@mt":"SQL [{ContextIndex}]: {Sql}","ContextIndex":14,"Sql":"DROP INDEX [IX_umbracoDocumentVersion_published] ON [umbracoDocumentVersion]","SourceContext":"Umbraco.Cms.Infrastructure.Migrations.MigrationContext","ProcessId":26604,"ProcessName":"iisexpress","ThreadId":1,"ApplicationId":"f8a8777e1a9657d6d5e2a3c88ad9ed8f166f7384","MachineName":"LAPTOP-BF","Log4NetLevel":"INFO "}
{"@t":"2024-05-17T14:05:15.6962664Z","@mt":"SQL [{ContextIndex}]: {Sql}","ContextIndex":15,"Sql":"CREATE NONCLUSTERED INDEX [IX_umbracoDocumentVersion_published] ON [umbracoDocumentVersion] ([published]) INCLUDE ([id],[templateId])","SourceContext":"Umbraco.Cms.Infrastructure.Migrations.MigrationContext","ProcessId":26604,"ProcessName":"iisexpress","ThreadId":1,"ApplicationId":"f8a8777e1a9657d6d5e2a3c88ad9ed8f166f7384","MachineName":"LAPTOP-BF","Log4NetLevel":"INFO "}
{"@t":"2024-05-17T14:05:16.1211017Z","@mt":"SQL [{ContextIndex}]: {Sql}","ContextIndex":16,"Sql":"DROP INDEX [IX_umbracoLog_datestamp] ON [umbracoLog]","SourceContext":"Umbraco.Cms.Infrastructure.Migrations.MigrationContext","ProcessId":26604,"ProcessName":"iisexpress","ThreadId":1,"ApplicationId":"f8a8777e1a9657d6d5e2a3c88ad9ed8f166f7384","MachineName":"LAPTOP-BF","Log4NetLevel":"INFO "}
{"@t":"2024-05-17T14:05:16.1252549Z","@mt":"SQL [{ContextIndex}]: {Sql}","ContextIndex":17,"Sql":"CREATE NONCLUSTERED INDEX [IX_umbracoLog_datestamp] ON [umbracoLog] ([Datestamp],[userId],[NodeId])","SourceContext":"Umbraco.Cms.Infrastructure.Migrations.MigrationContext","ProcessId":26604,"ProcessName":"iisexpress","ThreadId":1,"ApplicationId":"f8a8777e1a9657d6d5e2a3c88ad9ed8f166f7384","MachineName":"LAPTOP-BF","Log4NetLevel":"INFO "}
{"@t":"2024-05-17T14:05:16.9388967Z","@mt":"SQL [{ContextIndex}]: {Sql}","ContextIndex":18,"Sql":"DROP INDEX [IX_umbracoLog_datestamp_logheader] ON [umbracoLog]","SourceContext":"Umbraco.Cms.Infrastructure.Migrations.MigrationContext","ProcessId":26604,"ProcessName":"iisexpress","ThreadId":1,"ApplicationId":"f8a8777e1a9657d6d5e2a3c88ad9ed8f166f7384","MachineName":"LAPTOP-BF","Log4NetLevel":"INFO "}
{"@t":"2024-05-17T14:05:16.9412406Z","@mt":"SQL [{ContextIndex}]: {Sql}","ContextIndex":19,"Sql":"CREATE NONCLUSTERED INDEX [IX_umbracoLog_datestamp_logheader] ON [umbracoLog] ([Datestamp],[logHeader])","SourceContext":"Umbraco.Cms.Infrastructure.Migrations.MigrationContext","ProcessId":26604,"ProcessName":"iisexpress","ThreadId":1,"ApplicationId":"f8a8777e1a9657d6d5e2a3c88ad9ed8f166f7384","MachineName":"LAPTOP-BF","Log4NetLevel":"INFO "}
{"@t":"2024-05-17T14:05:17.7915822Z","@mt":"SQL [{ContextIndex}]: {Sql}","ContextIndex":20,"Sql":"DROP INDEX [IX_umbracoPropertyData_VersionId] ON [umbracoPropertyData]","SourceContext":"Umbraco.Cms.Infrastructure.Migrations.MigrationContext","ProcessId":26604,"ProcessName":"iisexpress","ThreadId":1,"ApplicationId":"f8a8777e1a9657d6d5e2a3c88ad9ed8f166f7384","MachineName":"LAPTOP-BF","Log4NetLevel":"INFO "}
{"@t":"2024-05-17T14:05:17.7939566Z","@mt":"SQL [{ContextIndex}]: {Sql}","ContextIndex":21,"Sql":"CREATE UNIQUE NONCLUSTERED INDEX [IX_umbracoPropertyData_VersionId] ON [umbracoPropertyData] ([versionId],[propertyTypeId],[languageId],[segment])","SourceContext":"Umbraco.Cms.Infrastructure.Migrations.MigrationContext","ProcessId":26604,"ProcessName":"iisexpress","ThreadId":1,"ApplicationId":"f8a8777e1a9657d6d5e2a3c88ad9ed8f166f7384","MachineName":"LAPTOP-BF","Log4NetLevel":"INFO "}
{"@t":"2024-05-17T14:05:53.4917732Z","@mt":"Exception ({InstanceId}).","@l":"Error","@x":"Microsoft.Data.SqlClient.SqlException (0x80131904): Execution Timeout Expired.  The timeout period elapsed prior to completion of the operation or the server is not responding.\r\n ---> System.ComponentModel.Win32Exception (258): The wait operation timed out.\r\n   at Microsoft.Data.SqlClient.SqlInternalConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction)\r\n   at Microsoft.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj, Boolean callerHasConnectionLock, Boolean asyncClose)\r\n   at Microsoft.Data.SqlClient.TdsParserStateObject.ThrowExceptionAndWarning(Boolean callerHasConnectionLock, Boolean asyncClose)\r\n   at Microsoft.Data.SqlClient.TdsParserStateObject.ReadSniError(TdsParserStateObject stateObj, UInt32 error)\r\n   at Microsoft.Data.SqlClient.TdsParserStateObject.ReadSniSyncOverAsync()\r\n   at Microsoft.Data.SqlClient.TdsParserStateObject.TryReadNetworkPacket()\r\n   at Microsoft.Data.SqlClient.TdsParserStateObject.TryPrepareBuffer()\r\n   at Microsoft.Data.SqlClient.TdsParserStateObject.TryReadByte(Byte& value)\r\n   at Microsoft.Data.SqlClient.TdsParser.TryRun(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj, Boolean& dataReady)\r\n   at Microsoft.Data.SqlClient.SqlCommand.RunExecuteNonQueryTds(String methodName, Boolean isAsync, Int32 timeout, Boolean asyncWrite)\r\n   at Microsoft.Data.SqlClient.SqlCommand.InternalExecuteNonQuery(TaskCompletionSource`1 completion, Boolean sendToPipe, Int32 timeout, Boolean& usedCache, Boolean asyncWrite, Boolean inRetry, String methodName)\r\n   at Microsoft.Data.SqlClient.SqlCommand.ExecuteNonQuery()\r\n   at StackExchange.Profiling.Data.ProfiledDbCommand.ExecuteNonQuery() in C:\\projects\\dotnet\\src\\MiniProfiler.Shared\\Data\\ProfiledDbCommand.cs:line 268\r\n   at Umbraco.Cms.Infrastructure.Persistence.FaultHandling.FaultHandlingDbCommand.<ExecuteNonQuery>b__32_0()\r\n   at Umbraco.Cms.Infrastructure.Persistence.FaultHandling.FaultHandlingDbCommand.<>c__DisplayClass38_0`1.<Execute>b__0()\r\n   at Umbraco.Cms.Infrastructure.Persistence.FaultHandling.RetryPolicy.ExecuteAction[TResult](Func`1 func)\r\n   at Umbraco.Cms.Infrastructure.Persistence.FaultHandling.FaultHandlingDbCommand.Execute[T](Func`1 f)\r\n   at Umbraco.Cms.Infrastructure.Persistence.FaultHandling.FaultHandlingDbCommand.ExecuteNonQuery()\r\n   at NPoco.Database.<>c__DisplayClass296_0.<ExecuteNonQueryHelper>b__0()\r\n   at NPoco.Database.ExecutionHook[T](Func`1 action)\r\n   at NPoco.Database.ExecuteNonQueryHelper(DbCommand cmd)\r\n   at NPoco.Database.Execute(String sql, CommandType commandType, Object[] args)\r\n   at NPoco.Database.Execute(Sql Sql)\r\n   at NPoco.Database.Execute(String sql, Object[] args)\r\n   at Umbraco.Cms.Infrastructure.Migrations.MigrationExpressionBase.ExecuteStatement(StringBuilder stmtBuilder)\r\n   at Umbraco.Cms.Infrastructure.Migrations.MigrationExpressionBase.Execute()\r\n   at Umbraco.Cms.Infrastructure.Migrations.MigrationBase.CreateIndex[T](String toCreate)\r\n   at Umbraco.Cms.Infrastructure.Migrations.Upgrade.V_12_1_0.TablesIndexesImprovement.Migrate()\r\n   at Umbraco.Cms.Infrastructure.Migrations.MigrationBase.Run()\r\n   at Umbraco.Cms.Infrastructure.Migrations.MigrationPlanExecutor.RunMigration(Type migrationType, MigrationContext context)\r\n   at Umbraco.Cms.Infrastructure.Migrations.MigrationPlanExecutor.RunScopedMigration(Type migrationType, MigrationPlan plan)\r\n   at Umbraco.Cms.Infrastructure.Migrations.MigrationPlanExecutor.RunMigrationPlan(MigrationPlan plan, String fromState)\r\nClientConnectionId:abd8f9e9-44b3-4b96-abec-86a6b86ced5d\r\nError Number:-2,State:0,Class:11","InstanceId":"bb5ab39f","SourceContext":"Umbraco.Cms.Infrastructure.Persistence.UmbracoDatabase","ProcessId":26604,"ProcessName":"iisexpress","ThreadId":1,"ApplicationId":"f8a8777e1a9657d6d5e2a3c88ad9ed8f166f7384","MachineName":"LAPTOP-BF","Log4NetLevel":"ERROR"}
{"@t":"2024-05-17T14:05:53.6958524Z","@mt":"Plan failed at step {TargetState}","@l":"Error","TargetState":"{1187192D-EDB5-4619-955D-91D48D738871}","SourceContext":"Umbraco.Cms.Infrastructure.Migrations.MigrationPlanExecutor","ProcessId":26604,"ProcessName":"iisexpress","ThreadId":1,"ApplicationId":"f8a8777e1a9657d6d5e2a3c88ad9ed8f166f7384","MachineName":"LAPTOP-BF","Log4NetLevel":"ERROR"}

and it seems this migration is heavy: https://github.com/umbraco/Umbraco-CMS/blob/v13/dev/src/Umbraco.Infrastructure/Migrations/Upgrade/V_12_1_0/TablesIndexesImprovement.cs

and on Umbraco Cloud development environment we keep getting this error:

Locally I could get it running a finish migration by increasing data Connection Timeout to 20 minutes.

"ConnectionStrings": {
  "umbracoDbDSN": "Server=localhost;Database=MyDatabase;Trusted_Connection=True;TrustServerCertificate=True;Connection Timeout=1200;",
  "umbracoDbDSN_ProviderName": "Microsoft.Data.SqlClient"
},

Specifics

No response

Steps to reproduce

Upgrade from Umbraco v10 latest to v12 latest. Eventually delete migration key for Umbraco core in umbracoKeyValue table so it run through the migration steps.

Expected result / actual result

No response

github-actions[bot] commented 3 months ago

Hi there @bjarnef!

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 :robot: :slightly_smiling_face:

mistyn8 commented 3 months ago

I've been battling this too.. on azure (so like cloud), still haven't got it complete as now getting a 500 server timeout though

startupTimeLimit for the aspnet core process helps with the 500.37 https://learn.microsoft.com/en-us/aspnet/core/host-and-deploy/aspnet-core-module?view=aspnetcore-3.1

in the web.config..

<aspNetCore startupTimeLimit="3600" processPath=".\www.exe" arguments="" stdoutLogEnabled="false" stdoutLogFile="\\?\%home%\LogFiles\stdout" hostingModel="InProcess">

Looking like have to anticipate some downtime and update the db locally and deploy out to azure, with an editor window freeze :-(

umbraco / Umbraco-CMS