This discussion has been locked.
You can no longer post new replies to this discussion. If you have a question you can start a new discussion

Database Update to 8.0.2 (QBM FinalizeCustomer failed

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

Parents Reply
  • Generally after we encountered the issue, we restored the database without trying any of the tools(since the error message itself says it left the db in an unreliable state).  If we re-encounter this issue I'll load up JobQueueInfo to see what the journal says.

Children
No Data