From either version 7.0.3 -> 8.0.2 or from 8.0.0 -> 8.0.2, occasionally the upgrade fails (we have done multiple proof of concept updates) with:
Processing step 'QBM FinalizeCustomer (wait for post processing customer)' failed.
at ConfigWizard.Pages.PageMigration.<StartMigration>d__17.MoveNext()
at System.Runtime.CompilerServices.TaskAwaiter.GetResult()
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
--- End of stack trace from previous location where exception was thrown ---
at System.Threading.Tasks.Task.Execute()
at Quantum.Migrator.Migrator.RunInstallation(Boolean bUpdate)
6 - Wait command failed.
at Quantum.Migrator.Base.ExtensionMethods.ExecuteWithLogging(IMigrationStep step, MigrationContext context)
at Quantum.Migrator.Base.ExtensionMethods.ExecuteWithLogging(IList`1 lCommands, MigrationContext context)
Evaluation of error conditions processed.
at Quantum.Migrator.Base.ExtensionMethods.ExecuteWithLogging(IList`1 lCommands, MigrationContext context)
at Quantum.Migrator.Base.CommandBase.Execute(MigrationContext context)
at Quantum.Migrator.WaitCommand.OnExecute(MigrationContext context)
Error conditions returned with true.
at Quantum.Migrator.WaitCommand.OnExecute(MigrationContext context)
Sometimes a restore of the database and re-upgrade attempt completes, but it isn't consistent.
The schema installation operation appears to have "QBM-K-QBMConstraintEnable2" process with "DPR-K-TriggerCreateMembership" as next in line, but it queues and repeats the "QBM-K-QBMConstraintEnable2"
Crash report
2019-03-19 16:54:32 SqlLog (< 1 ms) - select 1 where exists (select top 1 1 from DialogDBQueue )
2019-03-19 16:54:33 SqlLog (< 1 ms) - select UID_Task, CountWaiting, CountProcessing, SortOrder, IsResetted from QBM_VDBQueueContent order by SortOrder
2019-03-19 16:54:33 SqlLog (< 1 ms) - select 1 where exists (select top 1 1 from DialogDBQueue )
2019-03-19 16:54:34 SqlLog (< 1 ms) - Pin DbSession to physical connection
2019-03-19 16:54:34 SqlLog (< 1 ms) -
select 1 where exists (select top 1 1
from DialogJournal j
where j.MessageDate > DATEADD(SS, -10, GETUTCDATE())
and j.MessageType in ('E')
and (j.MessageString like '%alter%table%constraint%'
or j.MessageString like '%QBM_PRITriggerCreate%'
or j.MessageString like '%QBM_PMakeConstraint%'
)
)
2019-03-19 16:54:34 SqlLog (< 1 ms) - Pinned physical connection
2019-03-19 16:54:34 SqlLog (< 1 ms) - Pin DbSession to physical connection
2019-03-19 16:54:34 SqlLog (< 1 ms) -
select 1 where not exists (select top 1 1
from DialogJournal j
where j.MessageDate > DATEADD(MI, -10, GETUTCDATE())
and j.MessageType in ('E')
)
2019-03-19 16:54:34 SqlLog (< 1 ms) - Pinned physical connection
2019-03-19 16:54:34 SqlLog (< 1 ms) - Pin DbSession to physical connection
2019-03-19 16:54:34 SqlLog (< 1 ms) -
declare @notReady int exec @notReady = QBM_PMigrationNotReadyForComp select @notReady
2019-03-19 16:54:34 SqlLog (< 1 ms) - Pinned physical connection
2019-03-19 16:54:34 SqlLog (< 1 ms) - select UID_Task, CountWaiting, CountProcessing, SortOrder, IsResetted from QBM_VDBQueueContent order by SortOrder
2019-03-19 16:54:34 SqlLog (< 1 ms) - select 1 where exists (select top 1 1 from DialogDBQueue )
2019-03-19 16:54:35 SqlLog (< 1 ms) - select UID_Task, CountWaiting, CountProcessing, SortOrder, IsResetted from QBM_VDBQueueContent order by SortOrder
2019-03-19 16:54:35 SqlLog (< 1 ms) - select 1 where exists (select top 1 1 from DialogDBQueue )
2019-03-19 16:54:36 SqlLog (< 1 ms) - select UID_Task, CountWaiting, CountProcessing, SortOrder, IsResetted from QBM_VDBQueueContent order by SortOrder
2019-03-19 16:54:36 SqlLog (< 1 ms) - select 1 where exists (select top 1 1 from DialogDBQueue )
2019-03-19 16:54:37 SqlLog (< 1 ms) - select UID_Task, CountWaiting, CountProcessing, SortOrder, IsResetted from QBM_VDBQueueContent order by SortOrder
2019-03-19 16:54:37 SqlLog (< 1 ms) - select 1 where exists (select top 1 1 from DialogDBQueue )
2019-03-19 16:54:38 SqlLog (< 1 ms) - select UID_Task, CountWaiting, CountProcessing, SortOrder, IsResetted from QBM_VDBQueueContent order by SortOrder
2019-03-19 16:54:38 SqlLog (< 1 ms) - select 1 where exists (select top 1 1 from DialogDBQueue )
2019-03-19 16:54:39 SqlLog (< 1 ms) - Pin DbSession to physical connection
2019-03-19 16:54:39 SqlLog (< 1 ms) -
select 1 where exists (select top 1 1
from DialogJournal j
where j.MessageDate > DATEADD(SS, -10, GETUTCDATE())
and j.MessageType in ('E')
and (j.MessageString like '%alter%table%constraint%'
or j.MessageString like '%QBM_PRITriggerCreate%'
or j.MessageString like '%QBM_PMakeConstraint%'
)
)
2019-03-19 16:54:39 SqlLog (< 1 ms) - Pinned physical connection
2019-03-19 16:54:39 SqlLog (< 1 ms) - Pin DbSession to physical connection
2019-03-19 16:54:39 SqlLog (< 1 ms) -
select 1 where not exists (select top 1 1
from DialogJournal j
where j.MessageDate > DATEADD(MI, -10, GETUTCDATE())
and j.MessageType in ('E')
)
2019-03-19 16:54:39 SqlLog (< 1 ms) - Pinned physical connection
2019-03-19 16:54:39 SqlLog (< 1 ms) - Pin DbSession to physical connection
2019-03-19 16:54:39 SqlLog (< 1 ms) -
declare @notReady int exec @notReady = QBM_PMigrationNotReadyForComp select @notReady
2019-03-19 16:54:39 SqlLog (< 1 ms) - Pinned physical connection
2019-03-19 16:54:39 SqlLog (< 1 ms) - select UID_Task, CountWaiting, CountProcessing, SortOrder, IsResetted from QBM_VDBQueueContent order by SortOrder
2019-03-19 16:54:39 SqlLog (< 1 ms) - select 1 where exists (select top 1 1 from DialogDBQueue )
2019-03-19 16:54:40 SqlLog (< 1 ms) - select UID_Task, CountWaiting, CountProcessing, SortOrder, IsResetted from QBM_VDBQueueContent order by SortOrder
2019-03-19 16:54:40 SqlLog (< 1 ms) - select 1 where exists (select top 1 1 from DialogDBQueue )
2019-03-19 16:54:41 SqlLog (< 1 ms) - select UID_Task, CountWaiting, CountProcessing, SortOrder, IsResetted from QBM_VDBQueueContent order by SortOrder
2019-03-19 16:54:41 SqlLog (< 1 ms) - select 1 where exists (select top 1 1 from DialogDBQueue )
2019-03-19 16:54:42 SqlLog (< 1 ms) - select UID_Task, CountWaiting, CountProcessing, SortOrder, IsResetted from QBM_VDBQueueContent order by SortOrder
2019-03-19 16:54:42 SqlLog (< 1 ms) - select 1 where exists (select top 1 1 from DialogDBQueue )
2019-03-19 16:54:43 SqlLog (< 1 ms) - select UID_Task, CountWaiting, CountProcessing, SortOrder, IsResetted from QBM_VDBQueueContent order by SortOrder
2019-03-19 16:54:43 SqlLog (< 1 ms) - select 1 where exists (select top 1 1 from DialogDBQueue )
2019-03-19 16:54:44 SqlLog (< 1 ms) - Pin DbSession to physical connection
2019-03-19 16:54:44 SqlLog (< 1 ms) -
select 1 where exists (select top 1 1
from DialogJournal j
where j.MessageDate > DATEADD(SS, -10, GETUTCDATE())
and j.MessageType in ('E')
and (j.MessageString like '%alter%table%constraint%'
or j.MessageString like '%QBM_PRITriggerCreate%'
or j.MessageString like '%QBM_PMakeConstraint%'
)
)
2019-03-19 16:54:44 SqlLog (< 1 ms) - Pinned physical connection
2019-03-19 16:54:44 SqlLog (< 1 ms) - Pin DbSession to physical connection
2019-03-19 16:54:44 SqlLog (< 1 ms) -
select 1 where not exists (select top 1 1
from DialogJournal j
where j.MessageDate > DATEADD(MI, -10, GETUTCDATE())
and j.MessageType in ('E')
)
2019-03-19 16:54:44 SqlLog (< 1 ms) - Pinned physical connection
2019-03-19 16:54:44 SqlLog (< 1 ms) - Pin DbSession to physical connection
2019-03-19 16:54:44 SqlLog (< 1 ms) -
declare @notReady int exec @notReady = QBM_PMigrationNotReadyForComp select @notReady
2019-03-19 16:54:44 SqlLog (< 1 ms) - Pinned physical connection
2019-03-19 16:54:44 SqlLog (< 1 ms) - select UID_Task, CountWaiting, CountProcessing, SortOrder, IsResetted from QBM_VDBQueueContent order by SortOrder
2019-03-19 16:54:44 SqlLog (< 1 ms) - select 1 where exists (select top 1 1 from DialogDBQueue )
2019-03-19 16:54:45 SqlLog (< 1 ms) - select UID_Task, CountWaiting, CountProcessing, SortOrder, IsResetted from QBM_VDBQueueContent order by SortOrder
2019-03-19 16:54:45 SqlLog (< 1 ms) - select 1 where exists (select top 1 1 from DialogDBQueue )
2019-03-19 16:54:46 SqlLog (< 1 ms) - select UID_Task, CountWaiting, CountProcessing, SortOrder, IsResetted from QBM_VDBQueueContent order by SortOrder
2019-03-19 16:54:46 SqlLog (< 1 ms) - select 1 where exists (select top 1 1 from DialogDBQueue )
2019-03-19 16:54:47 SqlLog (< 1 ms) - select UID_Task, CountWaiting, CountProcessing, SortOrder, IsResetted from QBM_VDBQueueContent order by SortOrder
2019-03-19 16:54:47 SqlLog (< 1 ms) - select 1 where exists (select top 1 1 from DialogDBQueue )
2019-03-19 16:54:48 SqlLog (< 1 ms) - select UID_Task, CountWaiting, CountProcessing, SortOrder, IsResetted from QBM_VDBQueueContent order by SortOrder
2019-03-19 16:54:48 SqlLog (< 1 ms) - select 1 where exists (select top 1 1 from DialogDBQueue )
2019-03-19 16:54:49 SqlLog (< 1 ms) - Pin DbSession to physical connection
2019-03-19 16:54:49 SqlLog (< 1 ms) -
select 1 where exists (select top 1 1
from DialogJournal j
where j.MessageDate > DATEADD(SS, -10, GETUTCDATE())
and j.MessageType in ('E')
and (j.MessageString like '%alter%table%constraint%'
or j.MessageString like '%QBM_PRITriggerCreate%'
or j.MessageString like '%QBM_PMakeConstraint%'
)
)
2019-03-19 16:54:49 SqlLog (< 1 ms) - Pinned physical connection
2019-03-19 16:54:49 SqlLog (< 1 ms) - Pin DbSession to physical connection
2019-03-19 16:54:49 SqlLog (< 1 ms) -
select 1 where not exists (select top 1 1
from DialogJournal j
where j.MessageDate > DATEADD(MI, -10, GETUTCDATE())
and j.MessageType in ('E')
)
2019-03-19 16:54:49 SqlLog (< 1 ms) - Pinned physical connection
2019-03-19 16:54:49 SqlLog (< 1 ms) - Pin DbSession to physical connection
2019-03-19 16:54:49 SqlLog (< 1 ms) -
declare @notReady int exec @notReady = QBM_PMigrationNotReadyForComp select @notReady
2019-03-19 16:54:49 SqlLog (< 1 ms) - Pinned physical connection
2019-03-19 16:54:49 SqlLog (< 1 ms) - select UID_Task, CountWaiting, CountProcessing, SortOrder, IsResetted from QBM_VDBQueueContent order by SortOrder
2019-03-19 16:54:49 SqlLog (< 1 ms) - select 1 where exists (select top 1 1 from DialogDBQueue )
2019-03-19 16:54:50 SqlLog (< 1 ms) - select UID_Task, CountWaiting, CountProcessing, SortOrder, IsResetted from QBM_VDBQueueContent order by SortOrder
2019-03-19 16:54:50 SqlLog (< 1 ms) - select 1 where exists (select top 1 1 from DialogDBQueue )
2019-03-19 16:54:51 SqlLog (< 1 ms) - select UID_Task, CountWaiting, CountProcessing, SortOrder, IsResetted from QBM_VDBQueueContent order by SortOrder
2019-03-19 16:54:51 SqlLog (< 1 ms) - select 1 where exists (select top 1 1 from DialogDBQueue )
2019-03-19 16:54:52 SqlLog (< 1 ms) - select UID_Task, CountWaiting, CountProcessing, SortOrder, IsResetted from QBM_VDBQueueContent order by SortOrder
2019-03-19 16:54:52 SqlLog (< 1 ms) - select 1 where exists (select top 1 1 from DialogDBQueue )
2019-03-19 16:54:53 SqlLog (< 1 ms) - select UID_Task, CountWaiting, CountProcessing, SortOrder, IsResetted from QBM_VDBQueueContent order by SortOrder
2019-03-19 16:54:53 SqlLog (< 1 ms) - select 1 where exists (select top 1 1 from DialogDBQueue )
2019-03-19 16:54:54 SqlLog (< 1 ms) - Pin DbSession to physical connection
2019-03-19 16:54:54 SqlLog (< 1 ms) -
select 1 where exists (select top 1 1
from DialogJournal j
where j.MessageDate > DATEADD(SS, -10, GETUTCDATE())
and j.MessageType in ('E')
and (j.MessageString like '%alter%table%constraint%'
or j.MessageString like '%QBM_PRITriggerCreate%'
or j.MessageString like '%QBM_PMakeConstraint%'
)
)
2019-03-19 16:54:54 SqlLog (< 1 ms) - Pinned physical connection
2019-03-19 16:54:54 SqlLog (< 1 ms) - Pin DbSession to physical connection
2019-03-19 16:54:54 SqlLog (< 1 ms) -
select 1 where not exists (select top 1 1
from DialogJournal j
where j.MessageDate > DATEADD(MI, -10, GETUTCDATE())
and j.MessageType in ('E')
)
2019-03-19 16:54:54 SqlLog (< 1 ms) - Pinned physical connection
2019-03-19 16:54:54 SqlLog (< 1 ms) - Pin DbSession to physical connection
2019-03-19 16:54:54 SqlLog (< 1 ms) -
declare @notReady int exec @notReady = QBM_PMigrationNotReadyForComp select @notReady
2019-03-19 16:54:54 SqlLog (< 1 ms) - Pinned physical connection
2019-03-19 16:54:54 SqlLog (< 1 ms) - select UID_Task, CountWaiting, CountProcessing, SortOrder, IsResetted from QBM_VDBQueueContent order by SortOrder
2019-03-19 16:54:54 SqlLog (< 1 ms) - select 1 where exists (select top 1 1 from DialogDBQueue )
2019-03-19 16:54:55 SqlLog (< 1 ms) - select UID_Task, CountWaiting, CountProcessing, SortOrder, IsResetted from QBM_VDBQueueContent order by SortOrder
2019-03-19 16:54:55 SqlLog (< 1 ms) - select 1 where exists (select top 1 1 from DialogDBQueue )
2019-03-19 16:54:56 SqlLog (< 1 ms) - select UID_Task, CountWaiting, CountProcessing, SortOrder, IsResetted from QBM_VDBQueueContent order by SortOrder
2019-03-19 16:54:56 SqlLog (< 1 ms) - select 1 where exists (select top 1 1 from DialogDBQueue )
2019-03-19 16:54:57 SqlLog (< 1 ms) - select UID_Task, CountWaiting, CountProcessing, SortOrder, IsResetted from QBM_VDBQueueContent order by SortOrder
2019-03-19 16:54:57 SqlLog (< 1 ms) - select 1 where exists (select top 1 1 from DialogDBQueue )
2019-03-19 16:54:58 SqlLog (< 1 ms) - select UID_Task, CountWaiting, CountProcessing, SortOrder, IsResetted from QBM_VDBQueueContent order by SortOrder
2019-03-19 16:54:58 SqlLog (1 ms) - select 1 where exists (select top 1 1 from DialogDBQueue )
2019-03-19 16:54:59 SqlLog (< 1 ms) - Pin DbSession to physical connection
2019-03-19 16:54:59 SqlLog (< 1 ms) -
select 1 where exists (select top 1 1
from DialogJournal j
where j.MessageDate > DATEADD(SS, -10, GETUTCDATE())
and j.MessageType in ('E')
and (j.MessageString like '%alter%table%constraint%'
or j.MessageString like '%QBM_PRITriggerCreate%'
or j.MessageString like '%QBM_PMakeConstraint%'
)
)
2019-03-19 16:54:59 SqlLog (< 1 ms) - Pinned physical connection
2019-03-19 16:54:59 SqlLog (< 1 ms) - Pin DbSession to physical connection
2019-03-19 16:54:59 SqlLog (< 1 ms) -
select 1 where not exists (select top 1 1
from DialogJournal j
where j.MessageDate > DATEADD(MI, -10, GETUTCDATE())
and j.MessageType in ('E')
)
2019-03-19 16:54:59 SqlLog (< 1 ms) - Pinned physical connection
2019-03-19 16:54:59 SqlLog (< 1 ms) - Pin DbSession to physical connection
2019-03-19 16:54:59 SqlLog (2 ms) -
declare @notReady int exec @notReady = QBM_PMigrationNotReadyForComp select @notReady
2019-03-19 16:54:59 SqlLog (2 ms) - Pinned physical connection
2019-03-19 16:54:59 SqlLog (5 ms) - select UID_Task, CountWaiting, CountProcessing, SortOrder, IsResetted from QBM_VDBQueueContent order by SortOrder
2019-03-19 16:54:59 SqlLog (< 1 ms) - select 1 where exists (select top 1 1 from DialogDBQueue )
2019-03-19 16:55:00 SqlLog (< 1 ms) - select UID_Task, CountWaiting, CountProcessing, SortOrder, IsResetted from QBM_VDBQueueContent order by SortOrder
2019-03-19 16:55:00 SqlLog (< 1 ms) - select 1 where exists (select top 1 1 from DialogDBQueue )
2019-03-19 16:55:01 SqlLog (< 1 ms) - select UID_Task, CountWaiting, CountProcessing, SortOrder, IsResetted from QBM_VDBQueueContent order by SortOrder
2019-03-19 16:55:01 SqlLog (< 1 ms) - select 1 where exists (select top 1 1 from DialogDBQueue )
2019-03-19 16:55:02 SqlLog (< 1 ms) - select UID_Task, CountWaiting, CountProcessing, SortOrder, IsResetted from QBM_VDBQueueContent order by SortOrder
2019-03-19 16:55:02 SqlLog (< 1 ms) - select 1 where exists (select top 1 1 from DialogDBQueue )
2019-03-19 16:55:03 SqlLog (5 ms) - select UID_Task, CountWaiting, CountProcessing, SortOrder, IsResetted from QBM_VDBQueueContent order by SortOrder
2019-03-19 16:55:03 SqlLog (< 1 ms) - select 1 where exists (select top 1 1 from DialogDBQueue )
2019-03-19 16:55:04 SqlLog (< 1 ms) - Pin DbSession to physical connection
2019-03-19 16:55:04 SqlLog (< 1 ms) -
select 1 where exists (select top 1 1
from DialogJournal j
where j.MessageDate > DATEADD(SS, -10, GETUTCDATE())
and j.MessageType in ('E')
and (j.MessageString like '%alter%table%constraint%'
or j.MessageString like '%QBM_PRITriggerCreate%'
or j.MessageString like '%QBM_PMakeConstraint%'
)
)
2019-03-19 16:55:04 SqlLog (< 1 ms) - Pinned physical connection
2019-03-19 16:55:04 Quantum.Migrator.Migrator 6 - Wait command failed.
2019-03-19 16:55:04 Quantum.Migrator.Migrator Processing step 'QBM FinalizeCustomer (wait for post processing customer)' failed.
2019-03-19 16:55:04 Quantum.Migrator.Migrator Migration failed with exception.
2019-03-19 16:55:04 Quantum.Migrator.Migrator Processing post steps
2019-03-19 16:55:04 Quantum.Migrator.Migrator Processing Quantum.Migrator.MigrationSteps steps
2019-03-19 16:55:04 Quantum.Migrator.Migrator Quantum.Migrator.MigrationSteps steps to execute.
2019-03-19 16:55:04 Quantum.Migrator.Migrator 0 steps to execute.
2019-03-19 16:55:04 VI.FormBase.ExceptionMgr Processing step 'QBM FinalizeCustomer (wait for post processing customer)' failed.
Some of the troubleshooting steps attempted:
1. Schedules were disabled
2. Job and dbqueues were emptied, all job services and web portals stopped
3. Cleared and re-enabled sql agents(qbmwatchdogprepare) right before upgrade
Any tips, please?
Thanks