Re: [Users] Vds broker

And this happens when I try to migrate a vm to a newly added host: 014-03-25 12:49:24,223 INFO [org.ovirt.engine.core.bll.StopVmCommand] (pool-6-thread-47) [3fbc17c4] Running command: StopVmCommand internal: false. Entities affected : ID: c8d88175-46ae-43fc-a335-1f3badc91f2d Type: VM 2014-03-25 12:49:24,328 INFO [org.ovirt.engine.core.vdsbroker.DestroyVmVDSCommand] (pool-6-thread-47) [3fbc17c4] START, DestroyVmVDSCommand(HostName = mercury1, HostId = b34902ea-ad11-45d3-96ee-47de1864e4e0, vmId=c8d88175-46ae-43fc-a335-1f3badc91f2d, force=false, secondsToWait=0, gracefully=false), log id: 6ced0d30 2014-03-25 12:49:24,352 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.DestroyVDSCommand] (pool-6-thread-47) [3fbc17c4] START, DestroyVDSCommand(HostName = mercury1, HostId = b34902ea-ad11-45d3-96ee-47de1864e4e0, vmId=c8d88175-46ae-43fc-a335-1f3badc91f2d, force=false, secondsToWait=0, gracefully=false), log id: 2750e4d 2014-03-25 12:49:25,028 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.DestroyVDSCommand] (pool-6-thread-47) [3fbc17c4] FINISH, DestroyVDSCommand, log id: 2750e4d 2014-03-25 12:49:25,069 INFO [org.ovirt.engine.core.vdsbroker.DestroyVmVDSCommand] (pool-6-thread-47) [3fbc17c4] FINISH, DestroyVmVDSCommand, return: Down, log id: 6ced0d30 2014-03-25 12:49:25,105 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (pool-6-thread-47) [3fbc17c4] Correlation ID: 3fbc17c4, Job ID: fe838ca6-a821-479a-84f4-4003d1d4aa79, Call Stack: null, Custom Event ID: -1, Message: VM test powered off by admin@internal (Host: mercury1). 2014-03-25 12:49:26,928 WARN [org.ovirt.engine.core.vdsbroker.VdsManager] (DefaultQuartzScheduler_Worker-35) Failed to refresh VDS , vds = 497c0af3-4897-46f4-bffa-049bcd0ae713 : buran, error = java.lang.NullPointerException, continuing.: java.lang.NullPointerException 2014-03-25 12:49:32,874 INFO [org.ovirt.engine.core.bll.RemoveVmCommand] (ajp--127.0.0.1-8702-7) [193ff58e] Lock Acquired to object EngineLock [exclusiveLocks= key: c8d88175-46ae-43fc-a335-1f3badc91f2d value: VM , sharedLocks= ] 2014-03-25 12:49:32,922 INFO [org.ovirt.engine.core.bll.RemoveVmCommand] (pool-6-thread-47) [193ff58e] Running command: RemoveVmCommand internal: false. Entities affected : ID: c8d88175-46ae-43fc-a335-1f3badc91f2d Type: VM 2014-03-25 12:49:32,923 INFO [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] (pool-6-thread-47) [193ff58e] START, SetVmStatusVDSCommand( vmId = c8d88175-46ae-43fc-a335-1f3badc91f2d, status = ImageLocked), log id: 5fd52b9 2014-03-25 12:49:32,929 INFO [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] (pool-6-thread-47) [193ff58e] FINISH, SetVmStatusVDSCommand, log id: 5fd52b9 2014-03-25 12:49:32,937 INFO [org.ovirt.engine.core.bll.RemoveVmCommand] (pool-6-thread-47) [193ff58e] Lock freed to object EngineLock [exclusiveLocks= key: c8d88175-46ae-43fc-a335-1f3badc91f2d value: VM , sharedLocks= ] 2014-03-25 12:49:33,034 INFO [org.ovirt.engine.core.bll.RemoveAllVmImagesCommand] (pool-6-thread-47) Running command: RemoveAllVmImagesCommand internal: true. Entities affected : ID: c8d88175-46ae-43fc-a335-1f3badc91f2d Type: VM 2014-03-25 12:49:33,072 INFO [org.ovirt.engine.core.bll.RemoveImageCommand] (pool-6-thread-47) Running command: RemoveImageCommand internal: true. Entities affected : ID: 00000000-0000-0000-0000-000000000000 Type: Storage 2014-03-25 12:49:33,117 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] (pool-6-thread-47) START, DeleteImageGroupVDSCommand( storagePoolId = 1d03dc05-008b-4d14-97ce-b17bd714183d, ignoreFailoverLimit = false, storageDomainId = 2d289011-8671-4995-8015-d5bdf6a7e9dc, imageGroupId = 69c393a2-4d5a-405e-9e77-677c3b636ec3, postZeros = false, forceDelete = false), log id: 5a78ac25 2014-03-25 12:49:33,482 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] (pool-6-thread-47) FINISH, DeleteImageGroupVDSCommand, log id: 5a78ac25 2014-03-25 12:49:33,527 INFO [org.ovirt.engine.core.bll.CommandAsyncTask] (pool-6-thread-47) CommandAsyncTask::Adding CommandMultiAsyncTasks object for command 755d17e4-701b-434f-9c25-9cded5d84db0 2014-03-25 12:49:33,535 INFO [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (pool-6-thread-47) CommandMultiAsyncTasks::AttachTask: Attaching task c12bd7c5-fea7-48c5-822e-61f38a417dbd to command 755d17e4-701b-434f-9c25-9cded5d84db0. 2014-03-25 12:49:33,556 INFO [org.ovirt.engine.core.bll.AsyncTaskManager] (pool-6-thread-47) Adding task c12bd7c5-fea7-48c5-822e-61f38a417dbd (Parent Command RemoveVm, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters), polling hasn't started yet.. 2014-03-25 12:49:33,766 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (pool-6-thread-47) Correlation ID: 193ff58e, Job ID: 990e8f42-b6af-403b-ab95-8dda0afb10cd, Call Stack: null, Custom Event ID: -1, Message: VM test was successfully removed. 2014-03-25 12:49:33,770 INFO [org.ovirt.engine.core.bll.SPMAsyncTask] (pool-6-thread-47) BaseAsyncTask::StartPollingTask: Starting to poll task c12bd7c5-fea7-48c5-822e-61f38a417dbd. 2014-03-25 12:49:41,802 INFO [org.ovirt.engine.core.bll.MigrateVmToServerCommand] (ajp--127.0.0.1-8702-5) [58f6afd] Lock Acquired to object EngineLock [exclusiveLocks= key: bdd6779f-8dd6-4aae-a239-e6e11a009d51 value: VM , sharedLocks= ] 2014-03-25 12:49:41,985 INFO [org.ovirt.engine.core.bll.MigrateVmToServerCommand] (pool-6-thread-43) [58f6afd] Running command: MigrateVmToServerCommand internal: false. Entities affected : ID: bdd6779f-8dd6-4aae-a239-e6e11a009d51 Type: VM 2014-03-25 12:49:42,171 INFO [org.ovirt.engine.core.vdsbroker.MigrateVDSCommand] (pool-6-thread-43) [58f6afd] START, MigrateVDSCommand(HostName = mercury2, HostId = 54b28569-cb79-4f03-b1fe-f32bb3521a78, vmId=bdd6779f-8dd6-4aae-a239-e6e11a009d51, srcHost= mercury2.brusselsairport.aero, dstVdsId=b34902ea-ad11-45d3-96ee-47de1864e4e0, dstHost= mercury1.brusselsairport.aero:54321, migrationMethod=ONLINE, tunnelMigration=false), log id: 784529d7 2014-03-25 12:49:42,181 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.MigrateBrokerVDSCommand] (pool-6-thread-43) [58f6afd] VdsBroker::migrate::Entered (vm_guid=bdd6779f-8dd6-4aae-a239-e6e11a009d51, srcHost= mercury2.brusselsairport.aero, dstHost=mercury1.brusselsairport.aero:54321, method=online 2014-03-25 12:49:42,226 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.MigrateBrokerVDSCommand] (pool-6-thread-43) [58f6afd] START, MigrateBrokerVDSCommand(HostName = mercury2, HostId = 54b28569-cb79-4f03-b1fe-f32bb3521a78, vmId=bdd6779f-8dd6-4aae-a239-e6e11a009d51, srcHost= mercury2.brusselsairport.aero, dstVdsId=b34902ea-ad11-45d3-96ee-47de1864e4e0, dstHost= mercury1.brusselsairport.aero:54321, migrationMethod=ONLINE, tunnelMigration=false), log id: 7f5ea344 2014-03-25 12:49:42,244 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.MigrateBrokerVDSCommand] (pool-6-thread-43) [58f6afd] FINISH, MigrateBrokerVDSCommand, log id: 7f5ea344 2014-03-25 12:49:42,251 INFO [org.ovirt.engine.core.vdsbroker.MigrateVDSCommand] (pool-6-thread-43) [58f6afd] FINISH, MigrateVDSCommand, return: MigratingFrom, log id: 784529d7 2014-03-25 12:49:42,270 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (pool-6-thread-43) [58f6afd] Correlation ID: 58f6afd, Job ID: 6cb80ca5-009c-4ab5-92e8-eace26687e1f, Call Stack: null, Custom Event ID: -1, Message: Migration started (VM: dropzone01prod, Source: mercury2, Destination: mercury1, User: admin@internal). 2014-03-25 12:49:42,338 WARN [org.ovirt.engine.core.vdsbroker.VdsManager] (DefaultQuartzScheduler_Worker-89) Failed to refresh VDS , vds = 497c0af3-4897-46f4-bffa-049bcd0ae713 : buran, error = java.lang.NullPointerException, continuing.: java.lang.NullPointerException 2014-03-25 12:49:43,314 INFO [org.ovirt.engine.core.bll.AsyncTaskManager] (DefaultQuartzScheduler_Worker-8) Polling and updating Async Tasks: 1 tasks, 1 tasks to poll now 2014-03-25 12:49:43,329 INFO [org.ovirt.engine.core.bll.SPMAsyncTask] (DefaultQuartzScheduler_Worker-8) SPMAsyncTask::PollTask: Polling task c12bd7c5-fea7-48c5-822e-61f38a417dbd (Parent Command RemoveVm, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) returned status finished, result 'success'. 2014-03-25 12:49:43,337 INFO [org.ovirt.engine.core.bll.SPMAsyncTask] (DefaultQuartzScheduler_Worker-8) BaseAsyncTask::OnTaskEndSuccess: Task c12bd7c5-fea7-48c5-822e-61f38a417dbd (Parent Command RemoveVm, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) ended successfully. 2014-03-25 12:49:43,346 INFO [org.ovirt.engine.core.bll.CommandAsyncTask] (DefaultQuartzScheduler_Worker-8) CommandAsyncTask::EndActionIfNecessary: All tasks of command 755d17e4-701b-434f-9c25-9cded5d84db0 has ended -> executing EndAction 2014-03-25 12:49:43,351 INFO [org.ovirt.engine.core.bll.CommandAsyncTask] (DefaultQuartzScheduler_Worker-8) CommandAsyncTask::EndAction: Ending action for 1 tasks (command ID: 755d17e4-701b-434f-9c25-9cded5d84db0): calling EndAction . 2014-03-25 12:49:43,356 INFO [org.ovirt.engine.core.bll.CommandAsyncTask] (pool-6-thread-43) CommandAsyncTask::EndCommandAction [within thread] context: Attempting to EndAction RemoveVm, executionIndex: 0 2014-03-25 12:49:43,364 INFO [org.ovirt.engine.core.bll.RemoveVmCommand] (pool-6-thread-43) Ending command successfully: org.ovirt.engine.core.bll.RemoveVmCommand 2014-03-25 12:49:43,366 INFO [org.ovirt.engine.core.bll.CommandAsyncTask] (pool-6-thread-43) CommandAsyncTask::HandleEndActionResult [within thread]: EndAction for action type RemoveVm completed, handling the result. 2014-03-25 12:49:43,376 INFO [org.ovirt.engine.core.bll.CommandAsyncTask] (pool-6-thread-43) CommandAsyncTask::HandleEndActionResult [within thread]: EndAction for action type RemoveVm succeeded, clearing tasks. 2014-03-25 12:49:43,390 INFO [org.ovirt.engine.core.bll.SPMAsyncTask] (pool-6-thread-43) SPMAsyncTask::ClearAsyncTask: Attempting to clear task c12bd7c5-fea7-48c5-822e-61f38a417dbd 2014-03-25 12:49:43,397 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (pool-6-thread-43) START, SPMClearTaskVDSCommand( storagePoolId = 1d03dc05-008b-4d14-97ce-b17bd714183d, ignoreFailoverLimit = false, taskId = c12bd7c5-fea7-48c5-822e-61f38a417dbd), log id: 1c7fd187 2014-03-25 12:49:43,458 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (pool-6-thread-43) START, HSMClearTaskVDSCommand(HostName = mercury1, HostId = b34902ea-ad11-45d3-96ee-47de1864e4e0, taskId=c12bd7c5-fea7-48c5-822e-61f38a417dbd), log id: 64668319 2014-03-25 12:49:43,487 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (pool-6-thread-43) FINISH, HSMClearTaskVDSCommand, log id: 64668319 2014-03-25 12:49:43,488 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (pool-6-thread-43) FINISH, SPMClearTaskVDSCommand, log id: 1c7fd187 2014-03-25 12:49:43,490 INFO [org.ovirt.engine.core.bll.SPMAsyncTask] (pool-6-thread-43) BaseAsyncTask::RemoveTaskFromDB: Removed task c12bd7c5-fea7-48c5-822e-61f38a417dbd from DataBase 2014-03-25 12:49:43,491 INFO [org.ovirt.engine.core.bll.CommandAsyncTask] (pool-6-thread-43) CommandAsyncTask::HandleEndActionResult [within thread]: Removing CommandMultiAsyncTasks object for entity 755d17e4-701b-434f-9c25-9cded5d84db0 2014-03-25 12:49:45,462 INFO [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-17) VM dropzone01prod bdd6779f-8dd6-4aae-a239-e6e11a009d51 moved from MigratingFrom --> Up 2014-03-25 12:49:45,463 INFO [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-17) Adding VM bdd6779f-8dd6-4aae-a239-e6e11a009d51 to re-run list 2014-03-25 12:49:45,468 ERROR [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-17) Rerun vm bdd6779f-8dd6-4aae-a239-e6e11a009d51. Called from vds mercury2 2014-03-25 12:49:45,505 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.MigrateStatusVDSCommand] (pool-6-thread-43) START, MigrateStatusVDSCommand(HostName = mercury2, HostId = 54b28569-cb79-4f03-b1fe-f32bb3521a78, vmId=bdd6779f-8dd6-4aae-a239-e6e11a009d51), log id: 4e8a7f33 2014-03-25 12:49:45,521 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.MigrateStatusVDSCommand] (pool-6-thread-43) Failed in MigrateStatusVDS method 2014-03-25 12:49:45,525 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.MigrateStatusVDSCommand] (pool-6-thread-43) Error code migrateErr and error message VDSGenericException: VDSErrorException: Failed to MigrateStatusVDS, error = Fatal error during migration 2014-03-25 12:49:45,531 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.MigrateStatusVDSCommand] (pool-6-thread-43) Command org.ovirt.engine.core.vdsbroker.vdsbroker.MigrateStatusVDSCommand return value StatusOnlyReturnForXmlRpc [mStatus=StatusForXmlRpc [mCode=12, mMessage=Fatal error during migration]] 2014-03-25 12:49:45,539 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.MigrateStatusVDSCommand] (pool-6-thread-43) HostName = mercury2 2014-03-25 12:49:45,548 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.MigrateStatusVDSCommand] (pool-6-thread-43) Command MigrateStatusVDS execution failed. Exception: VDSErrorException: VDSGenericException: VDSErrorException: Failed to MigrateStatusVDS, error = Fatal error during migration 2014-03-25 12:49:45,557 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.MigrateStatusVDSCommand] (pool-6-thread-43) FINISH, MigrateStatusVDSCommand, log id: 4e8a7f33 2014-03-25 12:49:45,563 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (pool-6-thread-43) Correlation ID: 58f6afd, Job ID: 6cb80ca5-009c-4ab5-92e8-eace26687e1f, Call Stack: null, Custom Event ID: -1, Message: Migration failed due to Error: Fatal error during migration (VM: dropzone01prod, Source: mercury2, Destination: mercury1). 2014-03-25 12:49:57,699 WARN [org.ovirt.engine.core.vdsbroker.VdsManager] (DefaultQuartzScheduler_Worker-57) Failed to refresh VDS , vds = 497c0af3-4897-46f4-bffa-049bcd0ae713 : buran, error = java.lang.NullPointerException, continuing.: java.lang.NullPointerException 2014-03-25 12:41 GMT+01:00 Koen Vanoppen <vanoppen.koen(a)gmail.com&gt;: