2014-07-23 13:30:02,661 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.DestroyVDSCommand] (DefaultQuartzScheduler_Worker-62) START, DestroyVDSCommand(HostName = ov-nodo3, HostId = 338dbcd6-c02e-4033-89db-28cf4d528bb5, vmId=2891a8f3-be49-4d3c-849b-3e6f0dc5ae87, force=false, secondsToWait=0, gracefully=false), log id: 22958b6f 2014-07-23 13:30:03,306 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.DestroyVDSCommand] (DefaultQuartzScheduler_Worker-62) FINISH, DestroyVDSCommand, log id: 22958b6f 2014-07-23 13:30:03,308 INFO [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-62) RefreshVmList vm id 2891a8f3-be49-4d3c-849b-3e6f0dc5ae87 status = Down on vds ov-nodo3 ignoring it in the refresh until migration is done 2014-07-23 13:33:39,804 WARN [org.ovirt.engine.core.utils.threadpool.ThreadPoolUtil] (org.ovirt.thread.pool-6-thread-40) Executing a command: java.util.concurrent.FutureTask , but note that there are 1 tasks in the queue. 2014-07-23 13:37:41,193 INFO [org.ovirt.engine.core.bll.MoveDisksCommand] (ajp--127.0.0.1-8702-15) [63517ba7] Running command: MoveDisksCommand internal: false. Entities affected : ID: 0c2e967f-eb8d-4217-b590-fb83fd7a7039 Type: Disk 2014-07-23 13:37:41,336 INFO [org.ovirt.engine.core.bll.lsm.LiveMigrateVmDisksCommand] (ajp--127.0.0.1-8702-15) [63517ba7] Lock Acquired to object EngineLock [exclusiveLocks= key: 0c2e967f-eb8d-4217-b590-fb83fd7a7039 value: DISK , sharedLocks= key: 1e774249-0a14-41ab-ad91-081287f4283d value: VM ] 2014-07-23 13:37:41,456 INFO [org.ovirt.engine.core.bll.lsm.LiveMigrateVmDisksCommand] (org.ovirt.thread.pool-6-thread-26) [63517ba7] Running command: LiveMigrateVmDisksCommand Task handler: LiveSnapshotTaskHandler internal: false. Entities affected : ID: 7f802ec6-a9a0-4530-a38f-1fe7a37df7e6 Type: Disk, ID: 6e8c2454-aa64-4f70-9bdf-0b39d31ec6c5 Type: Storage 2014-07-23 13:37:41,536 INFO [org.ovirt.engine.core.bll.CreateAllSnapshotsFromVmCommand] (org.ovirt.thread.pool-6-thread-26) Running command: CreateAllSnapshotsFromVmCommand internal: true. Entities affected : ID: 1e774249-0a14-41ab-ad91-081287f4283d Type: VM 2014-07-23 13:37:41,601 INFO [org.ovirt.engine.core.bll.CreateSnapshotCommand] (org.ovirt.thread.pool-6-thread-26) [2d8224c0] Running command: CreateSnapshotCommand internal: true. Entities affected : ID: 00000000-0000-0000-0000-000000000000 Type: Storage 2014-07-23 13:37:41,618 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.CreateSnapshotVDSCommand] (org.ovirt.thread.pool-6-thread-26) [2d8224c0] START, CreateSnapshotVDSCommand( storagePoolId = a686da64-af46-435a-a7e9-3f597e9da802, ignoreFailoverLimit = false, storageDomainId = 7289cfd1-e325-40d5-9e66-7c208d003295, imageGroupId = 0c2e967f-eb8d-4217-b590-fb83fd7a7039, imageSizeInBytes = 21474836480, volumeFormat = COW, newImageId = 5669aa22-9c09-4f47-802b-52c0a8488703, newImageDescription = , imageId = 7f802ec6-a9a0-4530-a38f-1fe7a37df7e6, sourceImageGroupId = 0c2e967f-eb8d-4217-b590-fb83fd7a7039), log id: 50159597 2014-07-23 13:37:41,622 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.CreateSnapshotVDSCommand] (org.ovirt.thread.pool-6-thread-26) [2d8224c0] -- executeIrsBrokerCommand: calling 'createVolume' with two new parameters: description and UUID 2014-07-23 13:37:41,660 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.CreateSnapshotVDSCommand] (org.ovirt.thread.pool-6-thread-26) [2d8224c0] FINISH, CreateSnapshotVDSCommand, return: 5669aa22-9c09-4f47-802b-52c0a8488703, log id: 50159597 2014-07-23 13:37:41,677 INFO [org.ovirt.engine.core.bll.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-26) [2d8224c0] CommandAsyncTask::Adding CommandMultiAsyncTasks object for command 43ad7130-e200-4ebd-8f2e-c6076d97b366 2014-07-23 13:37:41,678 INFO [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (org.ovirt.thread.pool-6-thread-26) [2d8224c0] CommandMultiAsyncTasks::AttachTask: Attaching task 665fa325-ea0f-4145-a42a-4fd342048f58 to command 43ad7130-e200-4ebd-8f2e-c6076d97b366. 2014-07-23 13:37:41,687 INFO [org.ovirt.engine.core.bll.AsyncTaskManager] (org.ovirt.thread.pool-6-thread-26) [2d8224c0] Adding task 665fa325-ea0f-4145-a42a-4fd342048f58 (Parent Command LiveMigrateVmDisks, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters), polling hasn't started yet.. 2014-07-23 13:37:41,728 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-6-thread-26) Correlation ID: 711c1189, Job ID: db6c8918-617b-4bf2-8cd8-b83e0813136b, Call Stack: null, Custom Event ID: -1, Message: Snapshot 'Auto-generated for Live Storage Migration' creation for VM 'vm-1' was initiated by XXXX. 2014-07-23 13:37:41,733 INFO [org.ovirt.engine.core.bll.SPMAsyncTask] (org.ovirt.thread.pool-6-thread-26) BaseAsyncTask::startPollingTask: Starting to poll task 665fa325-ea0f-4145-a42a-4fd342048f58. 2014-07-23 13:37:46,861 INFO [org.ovirt.engine.core.bll.AsyncTaskManager] (DefaultQuartzScheduler_Worker-34) Polling and updating Async Tasks: 1 tasks, 1 tasks to poll now 2014-07-23 13:37:46,910 INFO [org.ovirt.engine.core.bll.SPMAsyncTask] (DefaultQuartzScheduler_Worker-34) SPMAsyncTask::PollTask: Polling task 665fa325-ea0f-4145-a42a-4fd342048f58 (Parent Command LiveMigrateVmDisks, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) returned status finished, result 'success'. 2014-07-23 13:37:46,920 INFO [org.ovirt.engine.core.bll.SPMAsyncTask] (DefaultQuartzScheduler_Worker-34) BaseAsyncTask::OnTaskEndSuccess: Task 665fa325-ea0f-4145-a42a-4fd342048f58 (Parent Command LiveMigrateVmDisks, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) ended successfully. 2014-07-23 13:37:46,922 INFO [org.ovirt.engine.core.bll.CommandAsyncTask] (DefaultQuartzScheduler_Worker-34) CommandAsyncTask::EndActionIfNecessary: All tasks of command 43ad7130-e200-4ebd-8f2e-c6076d97b366 has ended -> executing endAction 2014-07-23 13:37:46,923 INFO [org.ovirt.engine.core.bll.CommandAsyncTask] (DefaultQuartzScheduler_Worker-34) CommandAsyncTask::endAction: Ending action for 1 tasks (command ID: 43ad7130-e200-4ebd-8f2e-c6076d97b366): calling endAction . 2014-07-23 13:37:46,924 INFO [org.ovirt.engine.core.bll.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-5) CommandAsyncTask::EndCommandAction [within thread] context: Attempting to endAction LiveMigrateVmDisks, executionIndex: 0 2014-07-23 13:37:46,939 INFO [org.ovirt.engine.core.bll.lsm.LiveMigrateVmDisksCommand] (org.ovirt.thread.pool-6-thread-5) Ending command successfully: org.ovirt.engine.core.bll.lsm.LiveMigrateVmDisksCommand 2014-07-23 13:37:46,945 INFO [org.ovirt.engine.core.bll.CreateAllSnapshotsFromVmCommand] (org.ovirt.thread.pool-6-thread-5) Ending command successfully: org.ovirt.engine.core.bll.CreateAllSnapshotsFromVmCommand 2014-07-23 13:37:47,012 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.SnapshotVDSCommand] (org.ovirt.thread.pool-6-thread-5) START, SnapshotVDSCommand(HostName = ov-nodo3, HostId = 338dbcd6-c02e-4033-89db-28cf4d528bb5, vmId=1e774249-0a14-41ab-ad91-081287f4283d), log id: 517f8b8b 2014-07-23 13:37:57,728 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.SnapshotVDSCommand] (org.ovirt.thread.pool-6-thread-5) FINISH, SnapshotVDSCommand, log id: 517f8b8b 2014-07-23 13:37:57,735 INFO [org.ovirt.engine.core.bll.CreateSnapshotCommand] (org.ovirt.thread.pool-6-thread-5) [2d8224c0] Ending command successfully: org.ovirt.engine.core.bll.CreateSnapshotCommand 2014-07-23 13:37:57,745 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (org.ovirt.thread.pool-6-thread-5) [2d8224c0] START, GetImageInfoVDSCommand( storagePoolId = a686da64-af46-435a-a7e9-3f597e9da802, ignoreFailoverLimit = false, storageDomainId = 7289cfd1-e325-40d5-9e66-7c208d003295, imageGroupId = 0c2e967f-eb8d-4217-b590-fb83fd7a7039, imageId = 5669aa22-9c09-4f47-802b-52c0a8488703), log id: 2020d18a 2014-07-23 13:37:58,070 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (org.ovirt.thread.pool-6-thread-5) [2d8224c0] FINISH, GetImageInfoVDSCommand, return: org.ovirt.engine.core.common.businessentities.DiskImage@be5ff15a, log id: 2020d18a 2014-07-23 13:37:58,088 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-6-thread-5) Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: Snapshot 'Auto-generated for Live Storage Migration' creation for VM 'vm-1' has been completed. 2014-07-23 13:37:58,099 INFO [org.ovirt.engine.core.bll.lsm.LiveMigrateVmDisksCommand] (org.ovirt.thread.pool-6-thread-5) Running command: LiveMigrateVmDisksCommand Task handler: LiveMigrateDisksTaskHandler internal: false. Entities affected : ID: 7f802ec6-a9a0-4530-a38f-1fe7a37df7e6 Type: Disk, ID: 6e8c2454-aa64-4f70-9bdf-0b39d31ec6c5 Type: Storage 2014-07-23 13:37:58,252 INFO [org.ovirt.engine.core.bll.lsm.LiveMigrateDiskCommand] (org.ovirt.thread.pool-6-thread-5) [26e10691] Lock Acquired to object EngineLock [exclusiveLocks= , sharedLocks= key: 1e774249-0a14-41ab-ad91-081287f4283d value: VM ] 2014-07-23 13:37:58,268 INFO [org.ovirt.engine.core.bll.lsm.LiveMigrateDiskCommand] (org.ovirt.thread.pool-6-thread-5) [26e10691] Running command: LiveMigrateDiskCommand Task handler: CreateImagePlaceholderTaskHandler internal: true. Entities affected : ID: 0c2e967f-eb8d-4217-b590-fb83fd7a7039 Type: Disk, ID: 6e8c2454-aa64-4f70-9bdf-0b39d31ec6c5 Type: Storage 2014-07-23 13:37:58,276 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.CloneImageGroupStructureVDSCommand] (org.ovirt.thread.pool-6-thread-5) [26e10691] START, CloneImageGroupStructureVDSCommand( storagePoolId = a686da64-af46-435a-a7e9-3f597e9da802, ignoreFailoverLimit = false, storageDomainId = 7289cfd1-e325-40d5-9e66-7c208d003295, imageGroupId = 0c2e967f-eb8d-4217-b590-fb83fd7a7039, dstDomainId = 6e8c2454-aa64-4f70-9bdf-0b39d31ec6c5), log id: 109f7e5d 2014-07-23 13:37:58,313 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.CloneImageGroupStructureVDSCommand] (org.ovirt.thread.pool-6-thread-5) [26e10691] FINISH, CloneImageGroupStructureVDSCommand, log id: 109f7e5d 2014-07-23 13:37:58,320 INFO [org.ovirt.engine.core.bll.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-5) [26e10691] CommandAsyncTask::Adding CommandMultiAsyncTasks object for command b14935a2-564d-4563-a7c7-15a3422b379b 2014-07-23 13:37:58,321 INFO [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (org.ovirt.thread.pool-6-thread-5) [26e10691] CommandMultiAsyncTasks::AttachTask: Attaching task 1e86bd6f-174f-4d46-90fb-1cd952c16fdb to command b14935a2-564d-4563-a7c7-15a3422b379b. 2014-07-23 13:37:58,336 INFO [org.ovirt.engine.core.bll.AsyncTaskManager] (org.ovirt.thread.pool-6-thread-5) [26e10691] Adding task 1e86bd6f-174f-4d46-90fb-1cd952c16fdb (Parent Command LiveMigrateDisk, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters), polling hasn't started yet.. 2014-07-23 13:37:58,354 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-6-thread-5) [26e10691] Correlation ID: 26e10691, Job ID: 2c0bcbb3-f07e-49a4-9687-f5b8be5587a5, Call Stack: null, Custom Event ID: -1, Message: User XXX moving disk vm-1_Disk1 to domain stg2-sata-5500G. 2014-07-23 13:37:58,355 INFO [org.ovirt.engine.core.bll.SPMAsyncTask] (org.ovirt.thread.pool-6-thread-5) [26e10691] BaseAsyncTask::startPollingTask: Starting to poll task 1e86bd6f-174f-4d46-90fb-1cd952c16fdb. 2014-07-23 13:37:58,357 INFO [org.ovirt.engine.core.bll.SPMAsyncTask] (org.ovirt.thread.pool-6-thread-5) [26e10691] BaseAsyncTask::startPollingTask: Starting to poll task 1e86bd6f-174f-4d46-90fb-1cd952c16fdb. 2014-07-23 13:37:58,362 INFO [org.ovirt.engine.core.bll.lsm.LiveMigrateVmDisksCommand] (org.ovirt.thread.pool-6-thread-5) [26e10691] Lock freed to object EngineLock [exclusiveLocks= key: 0c2e967f-eb8d-4217-b590-fb83fd7a7039 value: DISK , sharedLocks= key: 1e774249-0a14-41ab-ad91-081287f4283d value: VM ] 2014-07-23 13:37:58,363 INFO [org.ovirt.engine.core.bll.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-5) CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type LiveMigrateVmDisks completed, handling the result. 2014-07-23 13:37:58,364 INFO [org.ovirt.engine.core.bll.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-5) CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type LiveMigrateVmDisks succeeded, clearing tasks. 2014-07-23 13:37:58,367 INFO [org.ovirt.engine.core.bll.SPMAsyncTask] (org.ovirt.thread.pool-6-thread-5) SPMAsyncTask::ClearAsyncTask: Attempting to clear task 665fa325-ea0f-4145-a42a-4fd342048f58 2014-07-23 13:37:58,368 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-5) START, SPMClearTaskVDSCommand( storagePoolId = a686da64-af46-435a-a7e9-3f597e9da802, ignoreFailoverLimit = false, taskId = 665fa325-ea0f-4145-a42a-4fd342048f58), log id: 5626e6ab 2014-07-23 13:37:58,372 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-5) START, HSMClearTaskVDSCommand(HostName = ov-nodo1, HostId = 8869a834-4a65-49c1-86c8-a08f9a753594, taskId=665fa325-ea0f-4145-a42a-4fd342048f58), log id: 7928f285 2014-07-23 13:37:58,403 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-5) FINISH, HSMClearTaskVDSCommand, log id: 7928f285 2014-07-23 13:37:58,404 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-5) FINISH, SPMClearTaskVDSCommand, log id: 5626e6ab 2014-07-23 13:37:58,412 INFO [org.ovirt.engine.core.bll.SPMAsyncTask] (org.ovirt.thread.pool-6-thread-5) BaseAsyncTask::RemoveTaskFromDB: Removed task 665fa325-ea0f-4145-a42a-4fd342048f58 from DataBase 2014-07-23 13:37:58,413 INFO [org.ovirt.engine.core.bll.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-5) CommandAsyncTask::HandleEndActionResult [within thread]: Removing CommandMultiAsyncTasks object for entity 43ad7130-e200-4ebd-8f2e-c6076d97b366 2014-07-23 13:38:06,926 INFO [org.ovirt.engine.core.bll.AsyncTaskManager] (DefaultQuartzScheduler_Worker-44) Polling and updating Async Tasks: 2 tasks, 1 tasks to poll now 2014-07-23 13:38:06,937 INFO [org.ovirt.engine.core.bll.SPMAsyncTask] (DefaultQuartzScheduler_Worker-44) SPMAsyncTask::PollTask: Polling task 1e86bd6f-174f-4d46-90fb-1cd952c16fdb (Parent Command LiveMigrateDisk, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) returned status finished, result 'success'. 2014-07-23 13:38:06,944 INFO [org.ovirt.engine.core.bll.SPMAsyncTask] (DefaultQuartzScheduler_Worker-44) BaseAsyncTask::OnTaskEndSuccess: Task 1e86bd6f-174f-4d46-90fb-1cd952c16fdb (Parent Command LiveMigrateDisk, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) ended successfully. 2014-07-23 13:38:06,945 INFO [org.ovirt.engine.core.bll.CommandAsyncTask] (DefaultQuartzScheduler_Worker-44) CommandAsyncTask::EndActionIfNecessary: All tasks of command b14935a2-564d-4563-a7c7-15a3422b379b has ended -> executing endAction 2014-07-23 13:38:06,946 INFO [org.ovirt.engine.core.bll.CommandAsyncTask] (DefaultQuartzScheduler_Worker-44) CommandAsyncTask::endAction: Ending action for 1 tasks (command ID: b14935a2-564d-4563-a7c7-15a3422b379b): calling endAction . 2014-07-23 13:38:06,947 INFO [org.ovirt.engine.core.bll.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-4) CommandAsyncTask::EndCommandAction [within thread] context: Attempting to endAction LiveMigrateDisk, executionIndex: 0 2014-07-23 13:38:07,022 INFO [org.ovirt.engine.core.bll.lsm.LiveMigrateDiskCommand] (org.ovirt.thread.pool-6-thread-4) [26e10691] Ending command successfully: org.ovirt.engine.core.bll.lsm.LiveMigrateDiskCommand 2014-07-23 13:38:07,025 INFO [org.ovirt.engine.core.bll.lsm.LiveMigrateDiskCommand] (org.ovirt.thread.pool-6-thread-4) [26e10691] Running command: LiveMigrateDiskCommand Task handler: VmReplicateDiskStartTaskHandler internal: false. Entities affected : ID: 0c2e967f-eb8d-4217-b590-fb83fd7a7039 Type: Disk, ID: 6e8c2454-aa64-4f70-9bdf-0b39d31ec6c5 Type: Storage 2014-07-23 13:38:07,029 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.VmReplicateDiskStartVDSCommand] (org.ovirt.thread.pool-6-thread-4) [26e10691] START, VmReplicateDiskStartVDSCommand(HostName = ov-nodo3, HostId = 338dbcd6-c02e-4033-89db-28cf4d528bb5, vmId=1e774249-0a14-41ab-ad91-081287f4283d), log id: 2d664391 2014-07-23 13:38:07,957 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.VmReplicateDiskStartVDSCommand] (org.ovirt.thread.pool-6-thread-4) [26e10691] FINISH, VmReplicateDiskStartVDSCommand, log id: 2d664391 2014-07-23 13:38:07,965 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SyncImageGroupDataVDSCommand] (org.ovirt.thread.pool-6-thread-4) [26e10691] START, SyncImageGroupDataVDSCommand( storagePoolId = a686da64-af46-435a-a7e9-3f597e9da802, ignoreFailoverLimit = false, storageDomainId = 7289cfd1-e325-40d5-9e66-7c208d003295, imageGroupId = 0c2e967f-eb8d-4217-b590-fb83fd7a7039, dstDomainId = 6e8c2454-aa64-4f70-9bdf-0b39d31ec6c5, syncType=INTERNAL), log id: 54c7900b 2014-07-23 13:38:08,037 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SyncImageGroupDataVDSCommand] (org.ovirt.thread.pool-6-thread-4) [26e10691] FINISH, SyncImageGroupDataVDSCommand, log id: 54c7900b 2014-07-23 13:38:08,044 INFO [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (org.ovirt.thread.pool-6-thread-4) [26e10691] CommandMultiAsyncTasks::AttachTask: Attaching task c2f04d15-df2d-48cb-bd33-814cf469954d to command b14935a2-564d-4563-a7c7-15a3422b379b. 2014-07-23 13:38:08,060 INFO [org.ovirt.engine.core.bll.AsyncTaskManager] (org.ovirt.thread.pool-6-thread-4) [26e10691] Adding task c2f04d15-df2d-48cb-bd33-814cf469954d (Parent Command LiveMigrateDisk, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters), polling hasn't started yet.. 2014-07-23 13:38:08,069 INFO [org.ovirt.engine.core.bll.SPMAsyncTask] (org.ovirt.thread.pool-6-thread-4) [26e10691] BaseAsyncTask::startPollingTask: Starting to poll task c2f04d15-df2d-48cb-bd33-814cf469954d. 2014-07-23 13:38:08,070 INFO [org.ovirt.engine.core.bll.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-4) CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type LiveMigrateDisk completed, handling the result. 2014-07-23 13:38:08,071 INFO [org.ovirt.engine.core.bll.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-4) CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type LiveMigrateDisk succeeded, clearing tasks. 2014-07-23 13:38:08,077 INFO [org.ovirt.engine.core.bll.SPMAsyncTask] (org.ovirt.thread.pool-6-thread-4) SPMAsyncTask::ClearAsyncTask: Attempting to clear task 1e86bd6f-174f-4d46-90fb-1cd952c16fdb 2014-07-23 13:38:08,078 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-4) START, SPMClearTaskVDSCommand( storagePoolId = a686da64-af46-435a-a7e9-3f597e9da802, ignoreFailoverLimit = false, taskId = 1e86bd6f-174f-4d46-90fb-1cd952c16fdb), log id: 33b4ec56 2014-07-23 13:38:08,082 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-4) START, HSMClearTaskVDSCommand(HostName = ov-nodo1, HostId = 8869a834-4a65-49c1-86c8-a08f9a753594, taskId=1e86bd6f-174f-4d46-90fb-1cd952c16fdb), log id: 2b081c9f 2014-07-23 13:38:08,093 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-4) FINISH, HSMClearTaskVDSCommand, log id: 2b081c9f 2014-07-23 13:38:08,094 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-4) FINISH, SPMClearTaskVDSCommand, log id: 33b4ec56 2014-07-23 13:38:08,097 INFO [org.ovirt.engine.core.bll.SPMAsyncTask] (org.ovirt.thread.pool-6-thread-4) BaseAsyncTask::RemoveTaskFromDB: Removed task 1e86bd6f-174f-4d46-90fb-1cd952c16fdb from DataBase 2014-07-23 13:38:08,098 INFO [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (org.ovirt.thread.pool-6-thread-4) [within thread]: Some of the tasks related to command id b14935a2-564d-4563-a7c7-15a3422b379b were not cleared yet (Task id c2f04d15-df2d-48cb-bd33-814cf469954d is in state Polling). 2014-07-23 13:38:13,079 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.FullListVdsCommand] (DefaultQuartzScheduler_Worker-78) START, FullListVdsCommand(HostName = ov-nodo3, HostId = 338dbcd6-c02e-4033-89db-28cf4d528bb5, vds=Host[ov-nodo3], vmIds=[1e774249-0a14-41ab-ad91-081287f4283d]), log id: 4b738e93 2014-07-23 13:38:13,093 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.FullListVdsCommand] (DefaultQuartzScheduler_Worker-78) FINISH, FullListVdsCommand, return: [{displaySecurePort=5901, kvmEnable=true, nicModel=rtl8139,pv, afterMigrationStatus=, keyboardLayout=en-us, displayIp=0, nice=0, timeOffset=7, transparentHugePages=true, vmId=1e774249-0a14-41ab-ad91-081287f4283d, acpiEnable=true, custom={device_9f3325f8-cdd2-4d7d-805e-9a3d5f9430dedevice_82b56809-608e-4308-bda0-c329cd16bc3ddevice_3b51569a-df41-4fd4-98bf-90575d351118device_09848f3e-3a6f-4def-a6d1-12d60bd5fb4cdevice_8d7bcba5-3a9e-4932-87de-30039897a006=VmDevice {vmId=1e774249-0a14-41ab-ad91-081287f4283d, deviceId=8d7bcba5-3a9e-4932-87de-30039897a006, device=spicevmc, type=CHANNEL, bootOrder=0, specParams={}, address={port=3, bus=0, controller=0, type=virtio-serial}, managed=false, plugged=true, readOnly=false, deviceAlias=channel2, customProperties={}, snapshotId=null}, device_9f3325f8-cdd2-4d7d-805e-9a3d5f9430dedevice_82b56809-608e-4308-bda0-c329cd16bc3ddevice_3b51569a-df41-4fd4-98bf-90575d351118device_09848f3e-3a6f-4def-a6d1-12d60bd5fb4c=VmDevice {vmId=1e774249-0a14-41ab-ad91-081287f4283d, deviceId=09848f3e-3a6f-4def-a6d1-12d60bd5fb4c, device=unix, type=CHANNEL, bootOrder=0, specParams={}, address={port=2, bus=0, controller=0, type=virtio-serial}, managed=false, plugged=true, readOnly=false, deviceAlias=channel1, customProperties={}, snapshotId=null}, sap_agent=true, device_9f3325f8-cdd2-4d7d-805e-9a3d5f9430dedevice_82b56809-608e-4308-bda0-c329cd16bc3d=VmDevice {vmId=1e774249-0a14-41ab-ad91-081287f4283d, deviceId=82b56809-608e-4308-bda0-c329cd16bc3d, device=virtio-serial, type=CONTROLLER, bootOrder=0, specParams={}, address={bus=0x00, domain=0x0000, type=pci, slot=0x0b, function=0x0}, managed=false, plugged=true, readOnly=false, deviceAlias=virtio-serial0, customProperties={}, snapshotId=null}, device_9f3325f8-cdd2-4d7d-805e-9a3d5f9430de=VmDevice {vmId=1e774249-0a14-41ab-ad91-081287f4283d, deviceId=9f3325f8-cdd2-4d7d-805e-9a3d5f9430de, device=ide, type=CONTROLLER, bootOrder=0, specParams={}, address={bus=0x00, domain=0x0000, type=pci, slot=0x01, function=0x1}, managed=false, plugged=true, readOnly=false, deviceAlias=ide0, customProperties={}, snapshotId=null}, device_9f3325f8-cdd2-4d7d-805e-9a3d5f9430dedevice_82b56809-608e-4308-bda0-c329cd16bc3ddevice_3b51569a-df41-4fd4-98bf-90575d351118=VmDevice {vmId=1e774249-0a14-41ab-ad91-081287f4283d, deviceId=3b51569a-df41-4fd4-98bf-90575d351118, device=unix, type=CHANNEL, bootOrder=0, specParams={}, address={port=1, bus=0, controller=0, type=virtio-serial}, managed=false, plugged=true, readOnly=false, deviceAlias=channel0, customProperties={}, snapshotId=null}}, spiceSslCipherSuite=DEFAULT, memSize=1024, smp=1, displayPort=5900, status=Up, vmType=kvm, emulatedMachine=rhel6.4.0, memGuaranteedSize=1024, display=qxl, pid=25549, smartcardEnable=false, spiceSecureChannels=smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard, smpCoresPerSocket=1, clientIp=, devices=[Ljava.lang.Object;@f957b98, vmName=vm-1, cpuType=Conroe}], log id: 4b738e93 2014-07-23 13:38:16,947 INFO [org.ovirt.engine.core.bll.AsyncTaskManager] (DefaultQuartzScheduler_Worker-45) Polling and updating Async Tasks: 3 tasks, 1 tasks to poll now 2014-07-23 13:38:16,958 INFO [org.ovirt.engine.core.bll.SPMAsyncTask] (DefaultQuartzScheduler_Worker-45) SPMAsyncTask::PollTask: Polling task c2f04d15-df2d-48cb-bd33-814cf469954d (Parent Command LiveMigrateDisk, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) returned status running. 2014-07-23 13:38:16,960 INFO [org.ovirt.engine.core.bll.AsyncTaskManager] (DefaultQuartzScheduler_Worker-45) Finished polling Tasks, will poll again in 10 seconds. 2014-07-23 13:38:56,784 INFO [org.ovirt.engine.core.bll.AsyncTaskManager] (DefaultQuartzScheduler_Worker-61) Setting new tasks map. The map contains now 2 tasks 2014-07-23 13:38:57,032 INFO [org.ovirt.engine.core.bll.AsyncTaskManager] (DefaultQuartzScheduler_Worker-88) Polling and updating Async Tasks: 2 tasks, 1 tasks to poll now 2014-07-23 13:38:57,042 INFO [org.ovirt.engine.core.bll.AsyncTaskManager] (DefaultQuartzScheduler_Worker-88) Finished polling Tasks, will poll again in 10 seconds. 2014-07-23 13:39:26,785 INFO [org.ovirt.engine.core.bll.AsyncTaskManager] (DefaultQuartzScheduler_Worker-14) [78580c4f] Setting new tasks map. The map contains now 1 tasks 2014-07-23 13:39:27,081 INFO [org.ovirt.engine.core.bll.AsyncTaskManager] (DefaultQuartzScheduler_Worker-78) Polling and updating Async Tasks: 1 tasks, 1 tasks to poll now 2014-07-23 13:39:27,090 INFO [org.ovirt.engine.core.bll.AsyncTaskManager] (DefaultQuartzScheduler_Worker-78) Finished polling Tasks, will poll again in 10 seconds. 2014-07-23 13:39:29,872 INFO [org.ovirt.engine.core.bll.AddVmFromSnapshotCommand] (ajp--127.0.0.1-8702-8) [e0a1ff3] Lock Acquired to object EngineLock [exclusiveLocks= key: 59689837-6b5b-49a9-a24a-85e056a11575 value: VM , sharedLocks= ] 2014-07-23 13:39:30,423 INFO [org.ovirt.engine.core.bll.AddVmFromSnapshotCommand] (ajp--127.0.0.1-8702-8) Running command: AddVmFromSnapshotCommand internal: false. Entities affected : ID: 8034f611-a99e-48ac-9f0d-5ed8e6671507 Type: VdsGroups, ID: 59689837-6b5b-49a9-a24a-85e056a11575 Type: VM, ID: c82fbd04-72c8-4b4e-935c-f3a8ef7e4681 Type: Storage 2014-07-23 13:39:30,671 INFO [org.ovirt.engine.core.bll.AddVmFromSnapshotCommand] (ajp--127.0.0.1-8702-8) Locking VM(id = 4c398452-0b7e-4748-b8a7-acad78ffc6c7) with compensation. 2014-07-23 13:39:30,677 INFO [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] (ajp--127.0.0.1-8702-8) START, SetVmStatusVDSCommand( vmId = 4c398452-0b7e-4748-b8a7-acad78ffc6c7, status = ImageLocked), log id: 256e25eb 2014-07-23 13:39:30,683 INFO [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] (ajp--127.0.0.1-8702-8) FINISH, SetVmStatusVDSCommand, log id: 256e25eb 2014-07-23 13:39:30,691 INFO [org.ovirt.engine.core.bll.AddVmFromSnapshotCommand] (ajp--127.0.0.1-8702-8) Lock freed to object EngineLock [exclusiveLocks= key: 59689837-6b5b-49a9-a24a-85e056a11575 value: VM , sharedLocks= ] 2014-07-23 13:39:30,744 INFO [org.ovirt.engine.core.bll.CopyImageGroupCommand] (ajp--127.0.0.1-8702-8) [3d7f5bc3] Running command: CopyImageGroupCommand internal: true. Entities affected : ID: c82fbd04-72c8-4b4e-935c-f3a8ef7e4681 Type: Storage 2014-07-23 13:39:30,950 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.CopyImageVDSCommand] (ajp--127.0.0.1-8702-8) [3d7f5bc3] START, CopyImageVDSCommand( storagePoolId = a686da64-af46-435a-a7e9-3f597e9da802, ignoreFailoverLimit = false, storageDomainId = c82fbd04-72c8-4b4e-935c-f3a8ef7e4681, imageGroupId = 2c68b768-1577-49a0-b0f9-865154ce0f6e, imageId = 4b9928e4-68b1-4258-87e9-6da16fc375af, dstImageGroupId = 44c60e9d-2c0d-4b67-806c-bea7631f8342, vmId = 4c398452-0b7e-4748-b8a7-acad78ffc6c7, dstImageId = ab09502d-da9c-49cf-b195-9e363bbfa995, imageDescription = , dstStorageDomainId = c82fbd04-72c8-4b4e-935c-f3a8ef7e4681, copyVolumeType = LeafVol, volumeFormat = COW, preallocate = Sparse, postZero = false, force = false), log id: 22ce9b41 2014-07-23 13:39:30,953 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.CopyImageVDSCommand] (ajp--127.0.0.1-8702-8) [3d7f5bc3] -- executeIrsBrokerCommand: calling 'copyImage' with two new parameters: description and UUID 2014-07-23 13:39:30,954 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.CopyImageVDSCommand] (ajp--127.0.0.1-8702-8) [3d7f5bc3] -- copyImage parameters: sdUUID=c82fbd04-72c8-4b4e-935c-f3a8ef7e4681 spUUID=a686da64-af46-435a-a7e9-3f597e9da802 vmGUID=4c398452-0b7e-4748-b8a7-acad78ffc6c7 srcImageGUID=2c68b768-1577-49a0-b0f9-865154ce0f6e srcVolUUID=4b9928e4-68b1-4258-87e9-6da16fc375af dstImageGUID=44c60e9d-2c0d-4b67-806c-bea7631f8342 dstVolUUID=ab09502d-da9c-49cf-b195-9e363bbfa995 descr= dstSdUUID=c82fbd04-72c8-4b4e-935c-f3a8ef7e4681 2014-07-23 13:39:32,038 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.CopyImageVDSCommand] (ajp--127.0.0.1-8702-8) [3d7f5bc3] FINISH, CopyImageVDSCommand, return: 00000000-0000-0000-0000-000000000000, log id: 22ce9b41 2014-07-23 13:39:32,420 INFO [org.ovirt.engine.core.bll.CommandAsyncTask] (ajp--127.0.0.1-8702-8) [3d7f5bc3] CommandAsyncTask::Adding CommandMultiAsyncTasks object for command be140dad-28dd-451a-9a7f-f6302879f34b 2014-07-23 13:39:32,421 INFO [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (ajp--127.0.0.1-8702-8) [3d7f5bc3] CommandMultiAsyncTasks::AttachTask: Attaching task 872ebdef-a447-4fee-ae55-1139271b0e19 to command be140dad-28dd-451a-9a7f-f6302879f34b. 2014-07-23 13:39:32,439 INFO [org.ovirt.engine.core.bll.AsyncTaskManager] (ajp--127.0.0.1-8702-8) [3d7f5bc3] Adding task 872ebdef-a447-4fee-ae55-1139271b0e19 (Parent Command AddVmFromSnapshot, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters), polling hasn't started yet.. 2014-07-23 13:39:32,785 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-8) [3d7f5bc3] Correlation ID: e0a1ff3, Job ID: 657ce043-8f6f-41aa-be48-f9f2b68f7cda, Call Stack: null, Custom Event ID: -1, Message: VM vm-2 creation was initiated by XXX. 2014-07-23 13:39:32,786 INFO [org.ovirt.engine.core.bll.SPMAsyncTask] (ajp--127.0.0.1-8702-8) [3d7f5bc3] BaseAsyncTask::startPollingTask: Starting to poll task 872ebdef-a447-4fee-ae55-1139271b0e19. 2014-07-23 13:39:37,091 INFO [org.ovirt.engine.core.bll.AsyncTaskManager] (DefaultQuartzScheduler_Worker-28) Polling and updating Async Tasks: 2 tasks, 2 tasks to poll now 2014-07-23 13:39:37,103 INFO [org.ovirt.engine.core.bll.SPMAsyncTask] (DefaultQuartzScheduler_Worker-28) SPMAsyncTask::PollTask: Polling task 872ebdef-a447-4fee-ae55-1139271b0e19 (Parent Command AddVmFromSnapshot, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) returned status running. 2014-07-23 13:39:37,104 INFO [org.ovirt.engine.core.bll.AsyncTaskManager] (DefaultQuartzScheduler_Worker-28) Finished polling Tasks, will poll again in 10 seconds. 2014-07-23 13:40:19,452 INFO [org.ovirt.engine.core.bll.SPMAsyncTask] (DefaultQuartzScheduler_Worker-11) [5b31a7d1] SPMAsyncTask::PollTask: Polling task 872ebdef-a447-4fee-ae55-1139271b0e19 (Parent Command AddVmFromSnapshot, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) returned status finished, result 'success'. 2014-07-23 13:40:19,467 INFO [org.ovirt.engine.core.bll.SPMAsyncTask] (DefaultQuartzScheduler_Worker-11) [5b31a7d1] BaseAsyncTask::OnTaskEndSuccess: Task 872ebdef-a447-4fee-ae55-1139271b0e19 (Parent Command AddVmFromSnapshot, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) ended successfully. 2014-07-23 13:40:19,468 INFO [org.ovirt.engine.core.bll.CommandAsyncTask] (DefaultQuartzScheduler_Worker-11) [5b31a7d1] CommandAsyncTask::EndActionIfNecessary: All tasks of command be140dad-28dd-451a-9a7f-f6302879f34b has ended -> executing endAction 2014-07-23 13:40:19,469 INFO [org.ovirt.engine.core.bll.CommandAsyncTask] (DefaultQuartzScheduler_Worker-11) [5b31a7d1] CommandAsyncTask::endAction: Ending action for 1 tasks (command ID: be140dad-28dd-451a-9a7f-f6302879f34b): calling endAction . 2014-07-23 13:40:19,470 INFO [org.ovirt.engine.core.bll.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-39) [5b31a7d1] CommandAsyncTask::EndCommandAction [within thread] context: Attempting to endAction AddVmFromSnapshot, executionIndex: 0 2014-07-23 13:40:19,491 INFO [org.ovirt.engine.core.bll.AddVmFromSnapshotCommand] (org.ovirt.thread.pool-6-thread-39) [e0a1ff3] Ending command successfully: org.ovirt.engine.core.bll.AddVmFromSnapshotCommand 2014-07-23 13:40:19,513 INFO [org.ovirt.engine.core.bll.CopyImageGroupCommand] (org.ovirt.thread.pool-6-thread-39) [3d7f5bc3] Ending command successfully: org.ovirt.engine.core.bll.CopyImageGroupCommand 2014-07-23 13:40:19,516 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (org.ovirt.thread.pool-6-thread-39) [3d7f5bc3] START, GetImageInfoVDSCommand( storagePoolId = a686da64-af46-435a-a7e9-3f597e9da802, ignoreFailoverLimit = false, storageDomainId = c82fbd04-72c8-4b4e-935c-f3a8ef7e4681, imageGroupId = 44c60e9d-2c0d-4b67-806c-bea7631f8342, imageId = ab09502d-da9c-49cf-b195-9e363bbfa995), log id: 15467be8 2014-07-23 13:40:19,575 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (org.ovirt.thread.pool-6-thread-39) [3d7f5bc3] FINISH, GetImageInfoVDSCommand, return: org.ovirt.engine.core.common.businessentities.DiskImage@ec92796d, log id: 15467be8 2014-07-23 13:40:19,585 INFO [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] (org.ovirt.thread.pool-6-thread-39) START, SetVmStatusVDSCommand( vmId = 4c398452-0b7e-4748-b8a7-acad78ffc6c7, status = Down), log id: 1091de40 2014-07-23 13:40:19,591 INFO [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] (org.ovirt.thread.pool-6-thread-39) FINISH, SetVmStatusVDSCommand, log id: 1091de40 2014-07-23 13:40:19,617 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-6-thread-39) Correlation ID: e0a1ff3, Job ID: 657ce043-8f6f-41aa-be48-f9f2b68f7cda, Call Stack: null, Custom Event ID: -1, Message: VM vm-2 creation has been completed. 2014-07-23 13:40:19,619 INFO [org.ovirt.engine.core.bll.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-39) CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type AddVmFromSnapshot completed, handling the result. 2014-07-23 13:40:19,619 INFO [org.ovirt.engine.core.bll.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-39) CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type AddVmFromSnapshot succeeded, clearing tasks. 2014-07-23 13:40:19,623 INFO [org.ovirt.engine.core.bll.SPMAsyncTask] (org.ovirt.thread.pool-6-thread-39) SPMAsyncTask::ClearAsyncTask: Attempting to clear task 872ebdef-a447-4fee-ae55-1139271b0e19 2014-07-23 13:40:19,625 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-39) START, SPMClearTaskVDSCommand( storagePoolId = a686da64-af46-435a-a7e9-3f597e9da802, ignoreFailoverLimit = false, taskId = 872ebdef-a447-4fee-ae55-1139271b0e19), log id: 7b4ddaea 2014-07-23 13:40:19,627 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-39) START, HSMClearTaskVDSCommand(HostName = ov-nodo1, HostId = 8869a834-4a65-49c1-86c8-a08f9a753594, taskId=872ebdef-a447-4fee-ae55-1139271b0e19), log id: 345f77e4 2014-07-23 13:40:19,636 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-39) FINISH, HSMClearTaskVDSCommand, log id: 345f77e4 2014-07-23 13:40:19,637 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-39) FINISH, SPMClearTaskVDSCommand, log id: 7b4ddaea 2014-07-23 13:40:19,639 INFO [org.ovirt.engine.core.bll.SPMAsyncTask] (org.ovirt.thread.pool-6-thread-39) BaseAsyncTask::RemoveTaskFromDB: Removed task 872ebdef-a447-4fee-ae55-1139271b0e19 from DataBase 2014-07-23 13:40:19,640 INFO [org.ovirt.engine.core.bll.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-39) CommandAsyncTask::HandleEndActionResult [within thread]: Removing CommandMultiAsyncTasks object for entity be140dad-28dd-451a-9a7f-f6302879f34b 2014-07-23 13:40:59,508 INFO [org.ovirt.engine.core.bll.SPMAsyncTask] (DefaultQuartzScheduler_Worker-91) SPMAsyncTask::PollTask: Polling task c2f04d15-df2d-48cb-bd33-814cf469954d (Parent Command LiveMigrateDisk, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) returned status finished, result 'success'. 2014-07-23 13:40:59,513 INFO [org.ovirt.engine.core.bll.SPMAsyncTask] (DefaultQuartzScheduler_Worker-91) BaseAsyncTask::OnTaskEndSuccess: Task c2f04d15-df2d-48cb-bd33-814cf469954d (Parent Command LiveMigrateDisk, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) ended successfully. 2014-07-23 13:40:59,519 INFO [org.ovirt.engine.core.bll.CommandAsyncTask] (DefaultQuartzScheduler_Worker-91) CommandAsyncTask::EndActionIfNecessary: All tasks of command b14935a2-564d-4563-a7c7-15a3422b379b has ended -> executing endAction 2014-07-23 13:40:59,520 INFO [org.ovirt.engine.core.bll.CommandAsyncTask] (DefaultQuartzScheduler_Worker-91) CommandAsyncTask::endAction: Ending action for 1 tasks (command ID: b14935a2-564d-4563-a7c7-15a3422b379b): calling endAction . 2014-07-23 13:40:59,521 INFO [org.ovirt.engine.core.bll.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-25) CommandAsyncTask::EndCommandAction [within thread] context: Attempting to endAction LiveMigrateDisk, executionIndex: 1 2014-07-23 13:40:59,600 INFO [org.ovirt.engine.core.bll.lsm.LiveMigrateDiskCommand] (org.ovirt.thread.pool-6-thread-25) [26e10691] Ending command successfully: org.ovirt.engine.core.bll.lsm.LiveMigrateDiskCommand 2014-07-23 13:40:59,601 INFO [org.ovirt.engine.core.bll.lsm.LiveMigrateDiskCommand] (org.ovirt.thread.pool-6-thread-25) [26e10691] Running command: LiveMigrateDiskCommand Task handler: VmReplicateDiskFinishTaskHandler internal: false. Entities affected : ID: 0c2e967f-eb8d-4217-b590-fb83fd7a7039 Type: Disk, ID: 6e8c2454-aa64-4f70-9bdf-0b39d31ec6c5 Type: Storage 2014-07-23 13:40:59,626 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.VmReplicateDiskFinishVDSCommand] (org.ovirt.thread.pool-6-thread-25) [26e10691] START, VmReplicateDiskFinishVDSCommand(HostName = ov-nodo3, HostId = 338dbcd6-c02e-4033-89db-28cf4d528bb5, vmId=1e774249-0a14-41ab-ad91-081287f4283d), log id: 49150733 2014-07-23 13:41:00,691 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.VmReplicateDiskFinishVDSCommand] (org.ovirt.thread.pool-6-thread-25) [26e10691] FINISH, VmReplicateDiskFinishVDSCommand, log id: 49150733 2014-07-23 13:41:00,699 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (org.ovirt.thread.pool-6-thread-25) [26e10691] START, GetImageInfoVDSCommand( storagePoolId = a686da64-af46-435a-a7e9-3f597e9da802, ignoreFailoverLimit = false, storageDomainId = 6e8c2454-aa64-4f70-9bdf-0b39d31ec6c5, imageGroupId = 0c2e967f-eb8d-4217-b590-fb83fd7a7039, imageId = 7f802ec6-a9a0-4530-a38f-1fe7a37df7e6), log id: 67714b 2014-07-23 13:41:00,762 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (org.ovirt.thread.pool-6-thread-25) [26e10691] FINISH, GetImageInfoVDSCommand, return: org.ovirt.engine.core.common.businessentities.DiskImage@83f8a259, log id: 67714b 2014-07-23 13:41:00,768 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (org.ovirt.thread.pool-6-thread-25) [26e10691] START, GetImageInfoVDSCommand( storagePoolId = a686da64-af46-435a-a7e9-3f597e9da802, ignoreFailoverLimit = false, storageDomainId = 6e8c2454-aa64-4f70-9bdf-0b39d31ec6c5, imageGroupId = 0c2e967f-eb8d-4217-b590-fb83fd7a7039, imageId = 5669aa22-9c09-4f47-802b-52c0a8488703), log id: 309b0f15 2014-07-23 13:41:00,815 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (org.ovirt.thread.pool-6-thread-25) [26e10691] FINISH, GetImageInfoVDSCommand, return: org.ovirt.engine.core.common.businessentities.DiskImage@4b521d41, log id: 309b0f15 2014-07-23 13:41:00,850 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] (org.ovirt.thread.pool-6-thread-25) [26e10691] START, DeleteImageGroupVDSCommand( storagePoolId = a686da64-af46-435a-a7e9-3f597e9da802, ignoreFailoverLimit = false, storageDomainId = 7289cfd1-e325-40d5-9e66-7c208d003295, imageGroupId = 0c2e967f-eb8d-4217-b590-fb83fd7a7039, postZeros = false, forceDelete = false), log id: 1c5e6830 2014-07-23 13:41:01,230 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.FullListVdsCommand] (DefaultQuartzScheduler_Worker-86) START, FullListVdsCommand(HostName = ov-nodo3, HostId = 338dbcd6-c02e-4033-89db-28cf4d528bb5, vds=Host[ov-nodo3], vmIds=[1e774249-0a14-41ab-ad91-081287f4283d]), log id: 1e452e64 2014-07-23 13:41:01,243 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.FullListVdsCommand] (DefaultQuartzScheduler_Worker-86) FINISH, FullListVdsCommand, return: [{displaySecurePort=5901, kvmEnable=true, nicModel=rtl8139,pv, afterMigrationStatus=, keyboardLayout=en-us, displayIp=0, nice=0, timeOffset=7, transparentHugePages=true, vmId=1e774249-0a14-41ab-ad91-081287f4283d, acpiEnable=true, custom={device_9f3325f8-cdd2-4d7d-805e-9a3d5f9430dedevice_82b56809-608e-4308-bda0-c329cd16bc3ddevice_3b51569a-df41-4fd4-98bf-90575d351118device_09848f3e-3a6f-4def-a6d1-12d60bd5fb4cdevice_8d7bcba5-3a9e-4932-87de-30039897a006=VmDevice {vmId=1e774249-0a14-41ab-ad91-081287f4283d, deviceId=8d7bcba5-3a9e-4932-87de-30039897a006, device=spicevmc, type=CHANNEL, bootOrder=0, specParams={}, address={port=3, bus=0, controller=0, type=virtio-serial}, managed=false, plugged=true, readOnly=false, deviceAlias=channel2, customProperties={}, snapshotId=null}, device_9f3325f8-cdd2-4d7d-805e-9a3d5f9430dedevice_82b56809-608e-4308-bda0-c329cd16bc3ddevice_3b51569a-df41-4fd4-98bf-90575d351118device_09848f3e-3a6f-4def-a6d1-12d60bd5fb4c=VmDevice {vmId=1e774249-0a14-41ab-ad91-081287f4283d, deviceId=09848f3e-3a6f-4def-a6d1-12d60bd5fb4c, device=unix, type=CHANNEL, bootOrder=0, specParams={}, address={port=2, bus=0, controller=0, type=virtio-serial}, managed=false, plugged=true, readOnly=false, deviceAlias=channel1, customProperties={}, snapshotId=null}, sap_agent=true, device_9f3325f8-cdd2-4d7d-805e-9a3d5f9430dedevice_82b56809-608e-4308-bda0-c329cd16bc3d=VmDevice {vmId=1e774249-0a14-41ab-ad91-081287f4283d, deviceId=82b56809-608e-4308-bda0-c329cd16bc3d, device=virtio-serial, type=CONTROLLER, bootOrder=0, specParams={}, address={bus=0x00, domain=0x0000, type=pci, slot=0x0b, function=0x0}, managed=false, plugged=true, readOnly=false, deviceAlias=virtio-serial0, customProperties={}, snapshotId=null}, device_9f3325f8-cdd2-4d7d-805e-9a3d5f9430de=VmDevice {vmId=1e774249-0a14-41ab-ad91-081287f4283d, deviceId=9f3325f8-cdd2-4d7d-805e-9a3d5f9430de, device=ide, type=CONTROLLER, bootOrder=0, specParams={}, address={bus=0x00, domain=0x0000, type=pci, slot=0x01, function=0x1}, managed=false, plugged=true, readOnly=false, deviceAlias=ide0, customProperties={}, snapshotId=null}, device_9f3325f8-cdd2-4d7d-805e-9a3d5f9430dedevice_82b56809-608e-4308-bda0-c329cd16bc3ddevice_3b51569a-df41-4fd4-98bf-90575d351118=VmDevice {vmId=1e774249-0a14-41ab-ad91-081287f4283d, deviceId=3b51569a-df41-4fd4-98bf-90575d351118, device=unix, type=CHANNEL, bootOrder=0, specParams={}, address={port=1, bus=0, controller=0, type=virtio-serial}, managed=false, plugged=true, readOnly=false, deviceAlias=channel0, customProperties={}, snapshotId=null}}, spiceSslCipherSuite=DEFAULT, memSize=1024, smp=1, displayPort=5900, status=Up, vmType=kvm, emulatedMachine=rhel6.4.0, memGuaranteedSize=1024, display=qxl, pid=25549, smartcardEnable=false, spiceSecureChannels=smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard, smpCoresPerSocket=1, clientIp=, devices=[Ljava.lang.Object;@4fe8b6c2, vmName=vm-1, cpuType=Conroe}], log id: 1e452e64 2014-07-23 13:41:02,089 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] (org.ovirt.thread.pool-6-thread-25) [26e10691] FINISH, DeleteImageGroupVDSCommand, log id: 1c5e6830 2014-07-23 13:41:02,096 INFO [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (org.ovirt.thread.pool-6-thread-25) [26e10691] CommandMultiAsyncTasks::AttachTask: Attaching task cae33980-6ad4-434e-8990-7fb2270af48a to command b14935a2-564d-4563-a7c7-15a3422b379b. 2014-07-23 13:41:02,115 INFO [org.ovirt.engine.core.bll.AsyncTaskManager] (org.ovirt.thread.pool-6-thread-25) [26e10691] Adding task cae33980-6ad4-434e-8990-7fb2270af48a (Parent Command LiveMigrateDisk, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters), polling hasn't started yet.. 2014-07-23 13:41:02,120 INFO [org.ovirt.engine.core.bll.SPMAsyncTask] (org.ovirt.thread.pool-6-thread-25) [26e10691] BaseAsyncTask::startPollingTask: Starting to poll task cae33980-6ad4-434e-8990-7fb2270af48a. 2014-07-23 13:41:02,121 INFO [org.ovirt.engine.core.bll.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-25) CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type LiveMigrateDisk completed, handling the result. 2014-07-23 13:41:02,122 INFO [org.ovirt.engine.core.bll.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-25) CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type LiveMigrateDisk succeeded, clearing tasks. 2014-07-23 13:41:02,123 INFO [org.ovirt.engine.core.bll.SPMAsyncTask] (org.ovirt.thread.pool-6-thread-25) SPMAsyncTask::ClearAsyncTask: Attempting to clear task c2f04d15-df2d-48cb-bd33-814cf469954d 2014-07-23 13:41:02,123 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-25) START, SPMClearTaskVDSCommand( storagePoolId = a686da64-af46-435a-a7e9-3f597e9da802, ignoreFailoverLimit = false, taskId = c2f04d15-df2d-48cb-bd33-814cf469954d), log id: 569e44e1 2014-07-23 13:41:02,126 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-25) START, HSMClearTaskVDSCommand(HostName = ov-nodo1, HostId = 8869a834-4a65-49c1-86c8-a08f9a753594, taskId=c2f04d15-df2d-48cb-bd33-814cf469954d), log id: 30bc3c34 2014-07-23 13:41:02,136 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-25) FINISH, HSMClearTaskVDSCommand, log id: 30bc3c34 2014-07-23 13:41:02,137 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-25) FINISH, SPMClearTaskVDSCommand, log id: 569e44e1 2014-07-23 13:41:02,141 INFO [org.ovirt.engine.core.bll.SPMAsyncTask] (org.ovirt.thread.pool-6-thread-25) BaseAsyncTask::RemoveTaskFromDB: Removed task c2f04d15-df2d-48cb-bd33-814cf469954d from DataBase 2014-07-23 13:41:02,141 INFO [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (org.ovirt.thread.pool-6-thread-25) [within thread]: Some of the tasks related to command id b14935a2-564d-4563-a7c7-15a3422b379b were not cleared yet (Task id cae33980-6ad4-434e-8990-7fb2270af48a is in state Polling). 2014-07-23 13:41:09,523 INFO [org.ovirt.engine.core.bll.AsyncTaskManager] (DefaultQuartzScheduler_Worker-16) Polling and updating Async Tasks: 3 tasks, 1 tasks to poll now 2014-07-23 13:41:09,532 INFO [org.ovirt.engine.core.bll.SPMAsyncTask] (DefaultQuartzScheduler_Worker-16) SPMAsyncTask::PollTask: Polling task cae33980-6ad4-434e-8990-7fb2270af48a (Parent Command LiveMigrateDisk, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) returned status finished, result 'success'. 2014-07-23 13:41:09,538 INFO [org.ovirt.engine.core.bll.SPMAsyncTask] (DefaultQuartzScheduler_Worker-16) BaseAsyncTask::OnTaskEndSuccess: Task cae33980-6ad4-434e-8990-7fb2270af48a (Parent Command LiveMigrateDisk, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) ended successfully. 2014-07-23 13:41:09,539 INFO [org.ovirt.engine.core.bll.CommandAsyncTask] (DefaultQuartzScheduler_Worker-16) CommandAsyncTask::EndActionIfNecessary: All tasks of command b14935a2-564d-4563-a7c7-15a3422b379b has ended -> executing endAction 2014-07-23 13:41:09,540 INFO [org.ovirt.engine.core.bll.CommandAsyncTask] (DefaultQuartzScheduler_Worker-16) CommandAsyncTask::endAction: Ending action for 1 tasks (command ID: b14935a2-564d-4563-a7c7-15a3422b379b): calling endAction . 2014-07-23 13:41:09,541 INFO [org.ovirt.engine.core.bll.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-33) CommandAsyncTask::EndCommandAction [within thread] context: Attempting to endAction LiveMigrateDisk, executionIndex: 2 2014-07-23 13:41:09,619 INFO [org.ovirt.engine.core.bll.lsm.LiveMigrateDiskCommand] (org.ovirt.thread.pool-6-thread-33) [26e10691] Ending command successfully: org.ovirt.engine.core.bll.lsm.LiveMigrateDiskCommand 2014-07-23 13:41:09,620 INFO [org.ovirt.engine.core.bll.lsm.LiveMigrateDiskCommand] (org.ovirt.thread.pool-6-thread-33) [26e10691] Lock freed to object EngineLock [exclusiveLocks= , sharedLocks= key: 1e774249-0a14-41ab-ad91-081287f4283d value: VM ] 2014-07-23 13:41:09,657 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-6-thread-33) [26e10691] Correlation ID: 26e10691, Job ID: 2c0bcbb3-f07e-49a4-9687-f5b8be5587a5, Call Stack: null, Custom Event ID: -1, Message: User XXX finished moving disk vm-1_Disk1 to domain stg2-sata-5500G. 2014-07-23 13:41:09,659 INFO [org.ovirt.engine.core.bll.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-33) CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type LiveMigrateDisk completed, handling the result. 2014-07-23 13:41:09,659 INFO [org.ovirt.engine.core.bll.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-33) CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type LiveMigrateDisk succeeded, clearing tasks. 2014-07-23 13:41:09,663 INFO [org.ovirt.engine.core.bll.SPMAsyncTask] (org.ovirt.thread.pool-6-thread-33) SPMAsyncTask::ClearAsyncTask: Attempting to clear task cae33980-6ad4-434e-8990-7fb2270af48a 2014-07-23 13:41:09,664 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-33) START, SPMClearTaskVDSCommand( storagePoolId = a686da64-af46-435a-a7e9-3f597e9da802, ignoreFailoverLimit = false, taskId = cae33980-6ad4-434e-8990-7fb2270af48a), log id: 3d9283bc 2014-07-23 13:41:09,666 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-33) START, HSMClearTaskVDSCommand(HostName = ov-nodo1, HostId = 8869a834-4a65-49c1-86c8-a08f9a753594, taskId=cae33980-6ad4-434e-8990-7fb2270af48a), log id: 5e06cb38 2014-07-23 13:41:09,676 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-33) FINISH, HSMClearTaskVDSCommand, log id: 5e06cb38 2014-07-23 13:41:09,677 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-33) FINISH, SPMClearTaskVDSCommand, log id: 3d9283bc 2014-07-23 13:41:09,680 INFO [org.ovirt.engine.core.bll.SPMAsyncTask] (org.ovirt.thread.pool-6-thread-33) BaseAsyncTask::RemoveTaskFromDB: Removed task cae33980-6ad4-434e-8990-7fb2270af48a from DataBase 2014-07-23 13:41:09,681 INFO [org.ovirt.engine.core.bll.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-33) CommandAsyncTask::HandleEndActionResult [within thread]: Removing CommandMultiAsyncTasks object for entity b14935a2-564d-4563-a7c7-15a3422b379b 2014-07-23 13:41:18,376 INFO [org.ovirt.engine.core.bll.UpdateVmCommand] (ajp--127.0.0.1-8702-5) [6d857175] Lock Acquired to object EngineLock [exclusiveLocks= key: vm-2 value: VM_NAME , sharedLocks= ] 2014-07-23 13:41:18,448 INFO [org.ovirt.engine.core.bll.UpdateVmCommand] (ajp--127.0.0.1-8702-5) [6d857175] Running command: UpdateVmCommand internal: false. Entities affected : ID: 4c398452-0b7e-4748-b8a7-acad78ffc6c7 Type: VM 2014-07-23 13:41:18,485 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-5) [6d857175] Correlation ID: 6d857175, Job ID: 6e4ed677-7ceb-4ac2-b7df-aeeb968d1fb5, Call Stack: null, Custom Event ID: -1, Message: VM vm-2 configuration was updated by XXX. 2014-07-23 13:41:18,491 INFO [org.ovirt.engine.core.bll.UpdateVmCommand] (ajp--127.0.0.1-8702-5) [6d857175] Lock freed to object EngineLock [exclusiveLocks= key: vm-2 value: VM_NAME , sharedLocks= ] 2014-07-23 13:41:19,052 INFO [org.ovirt.engine.core.bll.network.vm.AddVmInterfaceCommand] (ajp--127.0.0.1-8702-9) [59492d95] Running command: AddVmInterfaceCommand internal: false. Entities affected : ID: 4c398452-0b7e-4748-b8a7-acad78ffc6c7 Type: VM, ID: ca32baeb-30fc-47bd-a102-cc2b151c976f Type: VnicProfile 2014-07-23 13:41:19,177 INFO [org.ovirt.engine.core.bll.network.vm.ActivateDeactivateVmNicCommand] (ajp--127.0.0.1-8702-9) [225171b6] Running command: ActivateDeactivateVmNicCommand internal: true. Entities affected : ID: 4c398452-0b7e-4748-b8a7-acad78ffc6c7 Type: VM 2014-07-23 13:41:19,211 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-9) [225171b6] Correlation ID: 225171b6, Call Stack: null, Custom Event ID: -1, Message: Network Interface nic2 (VirtIO) was plugged to VM vm-2. (User: XXX) 2014-07-23 13:41:19,223 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-9) [225171b6] Correlation ID: 59492d95, Call Stack: null, Custom Event ID: -1, Message: Interface nic2 (VirtIO) was added to VM vm-2. (User: XXX) 2014-07-23 13:41:19,678 INFO [org.ovirt.engine.core.bll.network.vm.UpdateVmInterfaceCommand] (ajp--127.0.0.1-8702-3) [749e9aa2] Running command: UpdateVmInterfaceCommand internal: false. Entities affected : ID: 4c398452-0b7e-4748-b8a7-acad78ffc6c7 Type: VM, ID: 0035645c-37de-4eee-a957-fd3845f258cb Type: VnicProfile 2014-07-23 13:41:19,726 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-3) [749e9aa2] Correlation ID: 749e9aa2, Call Stack: null, Custom Event ID: -1, Message: Interface nic1 (VirtIO) was updated for VM vm-2. (User: XXX) 2014-07-23 13:41:26,786 INFO [org.ovirt.engine.core.bll.AsyncTaskManager] (DefaultQuartzScheduler_Worker-98) Setting new tasks map. The map contains now 2 tasks 2014-07-23 13:42:26,787 INFO [org.ovirt.engine.core.bll.AsyncTaskManager] (DefaultQuartzScheduler_Worker-39) Setting new tasks map. The map contains now 0 tasks 2014-07-23 13:42:26,788 INFO [org.ovirt.engine.core.bll.AsyncTaskManager] (DefaultQuartzScheduler_Worker-39) Cleared all tasks of pool a686da64-af46-435a-a7e9-3f597e9da802. 2014-07-23 13:44:15,202 INFO [org.ovirt.engine.core.bll.RunVmCommand] (ajp--127.0.0.1-8702-11) [11b9f33b] Lock Acquired to object EngineLock [exclusiveLocks= key: 4c398452-0b7e-4748-b8a7-acad78ffc6c7 value: VM , sharedLocks= ] 2014-07-23 13:44:15,233 INFO [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (ajp--127.0.0.1-8702-11) [11b9f33b] START, IsVmDuringInitiatingVDSCommand( vmId = 4c398452-0b7e-4748-b8a7-acad78ffc6c7), log id: 3a9c5552 2014-07-23 13:44:15,234 INFO [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (ajp--127.0.0.1-8702-11) [11b9f33b] FINISH, IsVmDuringInitiatingVDSCommand, return: false, log id: 3a9c5552 2014-07-23 13:44:15,299 INFO [org.ovirt.engine.core.bll.RunVmCommand] (org.ovirt.thread.pool-6-thread-25) [11b9f33b] Running command: RunVmCommand internal: false. Entities affected : ID: 4c398452-0b7e-4748-b8a7-acad78ffc6c7 Type: VM 2014-07-23 13:44:15,335 INFO [org.ovirt.engine.core.bll.scheduling.policyunits.HaReservationWeightPolicyUnit] (org.ovirt.thread.pool-6-thread-25) [11b9f33b] Started HA reservation scoring method 2014-07-23 13:44:15,353 INFO [org.ovirt.engine.core.vdsbroker.CreateVmVDSCommand] (org.ovirt.thread.pool-6-thread-25) [11b9f33b] START, CreateVmVDSCommand(HostName = ov-nodo3, HostId = 338dbcd6-c02e-4033-89db-28cf4d528bb5, vmId=4c398452-0b7e-4748-b8a7-acad78ffc6c7, vm=VM [vm-2]), log id: 5f54178a 2014-07-23 13:44:15,371 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand] (org.ovirt.thread.pool-6-thread-25) [11b9f33b] START, CreateVDSCommand(HostName = ov-nodo3, HostId = 338dbcd6-c02e-4033-89db-28cf4d528bb5, vmId=4c398452-0b7e-4748-b8a7-acad78ffc6c7, vm=VM [vm-2]), log id: 6a6c13b1 2014-07-23 13:44:15,483 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand] (org.ovirt.thread.pool-6-thread-25) [11b9f33b] org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand spiceSslCipherSuite=DEFAULT,memSize=1024,kvmEnable=true,smp=1,vmType=kvm,emulatedMachine=rhel6.4.0,keyboardLayout=en-us,memGuaranteedSize=1024,pitReinjection=false,nice=0,display=qxl,smartcardEnable=false,smpCoresPerSocket=1,spiceSecureChannels=smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard,timeOffset=0,transparentHugePages=true,vmId=4c398452-0b7e-4748-b8a7-acad78ffc6c7,devices=[{specParams={ram=65536, vram=32768, heads=1}, device=qxl, type=video, deviceId=6bd422a6-0f35-4bf2-ba68-4e3d4b094a84}, {shared=false, bootOrder=1, iface=ide, index=2, address={unit=0, bus=1, target=0, controller=0, type=drive}, specParams={path=}, path=, device=cdrom, type=disk, readonly=true, deviceId=18100a2f-268f-42d1-8acf-56f972064dc5}, {shared=false, index=0, volumeID=ab09502d-da9c-49cf-b195-9e363bbfa995, propagateErrors=off, format=cow, type=disk, iface=virtio, bootOrder=2, address={bus=0x00, domain=0x0000, slot=0x06, type=pci, function=0x0}, domainID=c82fbd04-72c8-4b4e-935c-f3a8ef7e4681, imageID=44c60e9d-2c0d-4b67-806c-bea7631f8342, specParams={}, optional=false, device=disk, poolID=a686da64-af46-435a-a7e9-3f597e9da802, readonly=false, deviceId=44c60e9d-2c0d-4b67-806c-bea7631f8342}, {nicModel=pv, address={bus=0x00, domain=0x0000, slot=0x03, type=pci, function=0x0}, specParams={}, macAddr=00:1a:4a:77:71:d1, device=bridge, linkActive=true, type=interface, filter=vdsm-no-mac-spoofing, network=SRV_BDIGITAL, deviceId=a8e520e5-a9d0-4184-b7bf-3a19f0b724d5}, {nicModel=pv, specParams={}, macAddr=00:1a:4a:77:71:d4, device=bridge, linkActive=true, type=interface, filter=vdsm-no-mac-spoofing, network=NET_CAMPUS, deviceId=9fab4ec6-232d-4c3c-a750-f44b7839ab86}, {specParams={model=virtio}, device=memballoon, type=balloon, deviceId=fb2bf423-76d5-41c9-97ef-49a7e0033e6b}, {index=0, model=virtio-scsi, address={bus=0x00, domain=0x0000, slot=0x04, type=pci, function=0x0}, specParams={}, device=scsi, type=controller, deviceId=5bf25eda-0e30-49c2-ad82-3c2acb6df890}],acpiEnable=true,vmName=vm-2,cpuType=Conroe,custom={device_516b34ca-e3f4-4f2d-9a66-40d93225000ddevice_856df147-2f02-4780-98e2-085c64407f97=VmDevice {vmId=4c398452-0b7e-4748-b8a7-acad78ffc6c7, deviceId=856df147-2f02-4780-98e2-085c64407f97, device=spicevmc, type=CHANNEL, bootOrder=0, specParams={}, address={port=3, bus=0, controller=0, type=virtio-serial}, managed=false, plugged=true, readOnly=false, deviceAlias=channel2, customProperties={}, snapshotId=null}, device_516b34ca-e3f4-4f2d-9a66-40d93225000d=VmDevice {vmId=4c398452-0b7e-4748-b8a7-acad78ffc6c7, deviceId=516b34ca-e3f4-4f2d-9a66-40d93225000d, device=unix, type=CHANNEL, bootOrder=0, specParams={}, address={port=1, bus=0, controller=0, type=virtio-serial}, managed=false, plugged=true, readOnly=false, deviceAlias=channel0, customProperties={}, snapshotId=null}, device_516b34ca-e3f4-4f2d-9a66-40d93225000ddevice_856df147-2f02-4780-98e2-085c64407f97device_9cfe5551-29ec-4ecf-8135-acc6b27d1538device_d04bca5c-88da-44a9-b70f-1ae6cadbda14device_e41fe79c-0eaf-4fda-913d-f9ad1b3d4ed4=VmDevice {vmId=4c398452-0b7e-4748-b8a7-acad78ffc6c7, deviceId=e41fe79c-0eaf-4fda-913d-f9ad1b3d4ed4, device=ide, type=CONTROLLER, bootOrder=0, specParams={}, address={bus=0x00, domain=0x0000, type=pci, slot=0x01, function=0x1}, managed=false, plugged=true, readOnly=false, deviceAlias=ide0, customProperties={}, snapshotId=null}, device_516b34ca-e3f4-4f2d-9a66-40d93225000ddevice_856df147-2f02-4780-98e2-085c64407f97device_9cfe5551-29ec-4ecf-8135-acc6b27d1538device_d04bca5c-88da-44a9-b70f-1ae6cadbda14=VmDevice {vmId=4c398452-0b7e-4748-b8a7-acad78ffc6c7, deviceId=d04bca5c-88da-44a9-b70f-1ae6cadbda14, device=virtio-serial, type=CONTROLLER, bootOrder=0, specParams={}, address={bus=0x00, domain=0x0000, type=pci, slot=0x05, function=0x0}, managed=false, plugged=true, readOnly=false, deviceAlias=virtio-serial0, customProperties={}, snapshotId=null}, device_516b34ca-e3f4-4f2d-9a66-40d93225000ddevice_856df147-2f02-4780-98e2-085c64407f97device_9cfe5551-29ec-4ecf-8135-acc6b27d1538=VmDevice {vmId=4c398452-0b7e-4748-b8a7-acad78ffc6c7, deviceId=9cfe5551-29ec-4ecf-8135-acc6b27d1538, device=unix, type=CHANNEL, bootOrder=0, specParams={}, address={port=2, bus=0, controller=0, type=virtio-serial}, managed=false, plugged=true, readOnly=false, deviceAlias=channel1, customProperties={}, snapshotId=null}} 2014-07-23 13:44:15,497 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand] (org.ovirt.thread.pool-6-thread-25) [11b9f33b] FINISH, CreateVDSCommand, log id: 6a6c13b1 2014-07-23 13:44:15,509 INFO [org.ovirt.engine.core.vdsbroker.CreateVmVDSCommand] (org.ovirt.thread.pool-6-thread-25) [11b9f33b] FINISH, CreateVmVDSCommand, return: WaitForLaunch, log id: 5f54178a 2014-07-23 13:44:15,510 INFO [org.ovirt.engine.core.bll.RunVmCommand] (org.ovirt.thread.pool-6-thread-25) [11b9f33b] Lock freed to object EngineLock [exclusiveLocks= key: 4c398452-0b7e-4748-b8a7-acad78ffc6c7 value: VM , sharedLocks= ] 2014-07-23 13:44:15,519 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-6-thread-25) [11b9f33b] Correlation ID: 11b9f33b, Job ID: 388275cb-9713-4b39-a92f-9c94d17db5ff, Call Stack: null, Custom Event ID: -1, Message: VM vm-2 was started by XXX (Host: ov-nodo3). 2014-07-23 13:44:19,893 INFO [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-96) VM vm-2 4c398452-0b7e-4748-b8a7-acad78ffc6c7 moved from WaitForLaunch --> PoweringUp 2014-07-23 13:44:19,943 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.FullListVdsCommand] (DefaultQuartzScheduler_Worker-96) START, FullListVdsCommand(HostName = ov-nodo3, HostId = 338dbcd6-c02e-4033-89db-28cf4d528bb5, vds=Host[ov-nodo3], vmIds=[4c398452-0b7e-4748-b8a7-acad78ffc6c7]), log id: 4ec5114 2014-07-23 13:44:19,953 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.FullListVdsCommand] (DefaultQuartzScheduler_Worker-96) FINISH, FullListVdsCommand, return: [{displaySecurePort=5903, kvmEnable=true, nicModel=rtl8139,pv, keyboardLayout=en-us, displayIp=0, pauseCode=NOERR, nice=0, pitReinjection=false, timeOffset=0, transparentHugePages=true, vmId=4c398452-0b7e-4748-b8a7-acad78ffc6c7, acpiEnable=true, custom={device_516b34ca-e3f4-4f2d-9a66-40d93225000ddevice_856df147-2f02-4780-98e2-085c64407f97=VmDevice {vmId=4c398452-0b7e-4748-b8a7-acad78ffc6c7, deviceId=856df147-2f02-4780-98e2-085c64407f97, device=spicevmc, type=CHANNEL, bootOrder=0, specParams={}, address={port=3, bus=0, controller=0, type=virtio-serial}, managed=false, plugged=true, readOnly=false, deviceAlias=channel2, customProperties={}, snapshotId=null}, device_516b34ca-e3f4-4f2d-9a66-40d93225000d=VmDevice {vmId=4c398452-0b7e-4748-b8a7-acad78ffc6c7, deviceId=516b34ca-e3f4-4f2d-9a66-40d93225000d, device=unix, type=CHANNEL, bootOrder=0, specParams={}, address={port=1, bus=0, controller=0, type=virtio-serial}, managed=false, plugged=true, readOnly=false, deviceAlias=channel0, customProperties={}, snapshotId=null}, device_516b34ca-e3f4-4f2d-9a66-40d93225000ddevice_856df147-2f02-4780-98e2-085c64407f97device_9cfe5551-29ec-4ecf-8135-acc6b27d1538device_d04bca5c-88da-44a9-b70f-1ae6cadbda14device_e41fe79c-0eaf-4fda-913d-f9ad1b3d4ed4=VmDevice {vmId=4c398452-0b7e-4748-b8a7-acad78ffc6c7, deviceId=e41fe79c-0eaf-4fda-913d-f9ad1b3d4ed4, device=ide, type=CONTROLLER, bootOrder=0, specParams={}, address={bus=0x00, domain=0x0000, type=pci, slot=0x01, function=0x1}, managed=false, plugged=true, readOnly=false, deviceAlias=ide0, customProperties={}, snapshotId=null}, device_516b34ca-e3f4-4f2d-9a66-40d93225000ddevice_856df147-2f02-4780-98e2-085c64407f97device_9cfe5551-29ec-4ecf-8135-acc6b27d1538device_d04bca5c-88da-44a9-b70f-1ae6cadbda14=VmDevice {vmId=4c398452-0b7e-4748-b8a7-acad78ffc6c7, deviceId=d04bca5c-88da-44a9-b70f-1ae6cadbda14, device=virtio-serial, type=CONTROLLER, bootOrder=0, specParams={}, address={bus=0x00, domain=0x0000, type=pci, slot=0x05, function=0x0}, managed=false, plugged=true, readOnly=false, deviceAlias=virtio-serial0, customProperties={}, snapshotId=null}, device_516b34ca-e3f4-4f2d-9a66-40d93225000ddevice_856df147-2f02-4780-98e2-085c64407f97device_9cfe5551-29ec-4ecf-8135-acc6b27d1538=VmDevice {vmId=4c398452-0b7e-4748-b8a7-acad78ffc6c7, deviceId=9cfe5551-29ec-4ecf-8135-acc6b27d1538, device=unix, type=CHANNEL, bootOrder=0, specParams={}, address={port=2, bus=0, controller=0, type=virtio-serial}, managed=false, plugged=true, readOnly=false, deviceAlias=channel1, customProperties={}, snapshotId=null}}, spiceSslCipherSuite=DEFAULT, memSize=1024, displayPort=5902, smp=1, emulatedMachine=rhel6.4.0, status=Up, vmType=kvm, memGuaranteedSize=1024, display=qxl, pid=29281, smartcardEnable=false, smpCoresPerSocket=1, spiceSecureChannels=smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard, clientIp=, devices=[Ljava.lang.Object;@36befa92, vmName=vm-2, cpuType=Conroe}], log id: 4ec5114 2014-07-23 13:44:25,401 INFO [org.ovirt.engine.core.bll.SetVmTicketCommand] (ajp--127.0.0.1-8702-16) [7fe12884] Running command: SetVmTicketCommand internal: false. Entities affected : ID: 4c398452-0b7e-4748-b8a7-acad78ffc6c7 Type: VM 2014-07-23 13:44:25,408 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.SetVmTicketVDSCommand] (ajp--127.0.0.1-8702-16) [7fe12884] START, SetVmTicketVDSCommand(HostName = ov-nodo3, HostId = 338dbcd6-c02e-4033-89db-28cf4d528bb5, vmId=4c398452-0b7e-4748-b8a7-acad78ffc6c7, ticket=aleUh9cv4j1H, validTime=120,m userName=XXX, userId=3599fc5c-e65a-1032-83a3-916d82337fdd), log id: c29390d 2014-07-23 13:44:25,451 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.SetVmTicketVDSCommand] (ajp--127.0.0.1-8702-16) [7fe12884] FINISH, SetVmTicketVDSCommand, log id: c29390d 2014-07-23 13:44:25,460 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-16) [7fe12884] Correlation ID: 7fe12884, Call Stack: null, Custom Event ID: -1, Message: user XXX initiated console session for VM vm-2 2014-07-23 13:44:32,154 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-45) Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: User XXX@engine.uncu.edu.ar is connected to VM vm-2. 2014-07-23 13:45:18,186 INFO [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-36) [4041d99f] VM vm-2 4c398452-0b7e-4748-b8a7-acad78ffc6c7 moved from PoweringUp --> Up 2014-07-23 13:45:18,198 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-36) [4041d99f] Correlation ID: 11b9f33b, Job ID: 388275cb-9713-4b39-a92f-9c94d17db5ff, Call Stack: null, Custom Event ID: -1, Message: VM vm-2 started on Host ov-nodo3 2014-07-23 13:48:01,967 INFO [org.ovirt.engine.core.bll.OvfDataUpdater] (DefaultQuartzScheduler_Worker-97) Attempting to update VMs/Templates Ovf. 2014-07-23 13:48:01,969 INFO [org.ovirt.engine.core.bll.OvfDataUpdater] (DefaultQuartzScheduler_Worker-97) Attempting to update VM OVFs in Data Center CIT-FC 2014-07-23 13:48:02,092 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.UpdateVMVDSCommand] (DefaultQuartzScheduler_Worker-97) START, UpdateVMVDSCommand( storagePoolId = a686da64-af46-435a-a7e9-3f597e9da802, ignoreFailoverLimit = false, storageDomainId = 00000000-0000-0000-0000-000000000000, infoDictionary.size = 2), log id: 4946c6e5 2014-07-23 13:48:02,139 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.UpdateVMVDSCommand] (DefaultQuartzScheduler_Worker-97) FINISH, UpdateVMVDSCommand, log id: 4946c6e5 2014-07-23 13:48:02,143 INFO [org.ovirt.engine.core.bll.OvfDataUpdater] (DefaultQuartzScheduler_Worker-97) Successfully updated VM OVFs in Data Center CIT-FC 2014-07-23 13:48:02,144 INFO [org.ovirt.engine.core.bll.OvfDataUpdater] (DefaultQuartzScheduler_Worker-97) Attempting to update template OVFs in Data Center CIT-FC 2014-07-23 13:48:02,147 INFO [org.ovirt.engine.core.bll.OvfDataUpdater] (DefaultQuartzScheduler_Worker-97) Successfully updated templates OVFs in Data Center CIT-FC 2014-07-23 13:48:02,148 INFO [org.ovirt.engine.core.bll.OvfDataUpdater] (DefaultQuartzScheduler_Worker-97) Attempting to remove unneeded template/vm OVFs in Data Center CIT-FC 2014-07-23 13:48:02,150 INFO [org.ovirt.engine.core.bll.OvfDataUpdater] (DefaultQuartzScheduler_Worker-97) Successfully removed unneeded template/vm OVFs in Data Center CIT-FC 2014-07-23 13:49:41,379 WARN [org.ovirt.engine.core.utils.threadpool.ThreadPoolUtil] (org.ovirt.thread.pool-6-thread-38) Executing a command: java.util.concurrent.FutureTask , but note that there are 1 tasks in the queue. 2014-07-23 13:49:43,299 INFO [org.ovirt.engine.core.bll.MoveDisksCommand] (ajp--127.0.0.1-8702-7) [7f9b12d3] Running command: MoveDisksCommand internal: false. Entities affected : ID: b2d10cfb-1f88-4412-9dcb-9b8682dd563e Type: Disk 2014-07-23 13:49:43,428 INFO [org.ovirt.engine.core.bll.lsm.LiveMigrateVmDisksCommand] (ajp--127.0.0.1-8702-7) [7f9b12d3] Lock Acquired to object EngineLock [exclusiveLocks= key: b2d10cfb-1f88-4412-9dcb-9b8682dd563e value: DISK , sharedLocks= key: e15dad27-8f55-4c66-8f2e-2b7def112f0d value: VM ] 2014-07-23 13:49:43,549 WARN [org.ovirt.engine.core.bll.lsm.LiveMigrateVmDisksCommand] (ajp--127.0.0.1-8702-7) [7f9b12d3] CanDoAction of action LiveMigrateVmDisks failed. Reasons:VAR__ACTION__MOVE,VAR__TYPE__VM_DISK,ACTION_TYPE_FAILED_TEMPLATE_NOT_FOUND_ON_DESTINATION_DOMAIN 2014-07-23 13:49:43,551 INFO [org.ovirt.engine.core.bll.lsm.LiveMigrateVmDisksCommand] (ajp--127.0.0.1-8702-7) [7f9b12d3] Lock freed to object EngineLock [exclusiveLocks= key: b2d10cfb-1f88-4412-9dcb-9b8682dd563e value: DISK , sharedLocks= key: e15dad27-8f55-4c66-8f2e-2b7def112f0d value: VM ] 2014-07-23 13:50:22,118 INFO [org.ovirt.engine.core.bll.MoveDisksCommand] (ajp--127.0.0.1-8702-15) [2222c368] Running command: MoveDisksCommand internal: false. Entities affected : ID: 5446a197-370d-4b9e-9baa-727f30fb3506 Type: Disk 2014-07-23 13:50:22,227 INFO [org.ovirt.engine.core.bll.lsm.LiveMigrateVmDisksCommand] (ajp--127.0.0.1-8702-15) [2222c368] Lock Acquired to object EngineLock [exclusiveLocks= key: 5446a197-370d-4b9e-9baa-727f30fb3506 value: DISK , sharedLocks= key: 5c67eecf-a71c-497a-9c47-aa84c58deb30 value: VM ] 2014-07-23 13:50:22,306 INFO [org.ovirt.engine.core.bll.lsm.LiveMigrateVmDisksCommand] (org.ovirt.thread.pool-6-thread-31) [2222c368] Running command: LiveMigrateVmDisksCommand Task handler: LiveSnapshotTaskHandler internal: false. Entities affected : ID: 465a3c9d-e770-49af-982e-4de323ff892c Type: Disk, ID: 6e8c2454-aa64-4f70-9bdf-0b39d31ec6c5 Type: Storage 2014-07-23 13:50:22,358 INFO [org.ovirt.engine.core.bll.CreateAllSnapshotsFromVmCommand] (org.ovirt.thread.pool-6-thread-31) Running command: CreateAllSnapshotsFromVmCommand internal: true. Entities affected : ID: 5c67eecf-a71c-497a-9c47-aa84c58deb30 Type: VM 2014-07-23 13:50:22,372 INFO [org.ovirt.engine.core.bll.CreateSnapshotCommand] (org.ovirt.thread.pool-6-thread-31) [d1f73ee] Running command: CreateSnapshotCommand internal: true. Entities affected : ID: 00000000-0000-0000-0000-000000000000 Type: Storage 2014-07-23 13:50:22,379 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.CreateSnapshotVDSCommand] (org.ovirt.thread.pool-6-thread-31) [d1f73ee] START, CreateSnapshotVDSCommand( storagePoolId = a686da64-af46-435a-a7e9-3f597e9da802, ignoreFailoverLimit = false, storageDomainId = 7289cfd1-e325-40d5-9e66-7c208d003295, imageGroupId = 5446a197-370d-4b9e-9baa-727f30fb3506, imageSizeInBytes = 21474836480, volumeFormat = COW, newImageId = 06053c41-7e69-48a4-b929-6a321336768e, newImageDescription = , imageId = 465a3c9d-e770-49af-982e-4de323ff892c, sourceImageGroupId = 5446a197-370d-4b9e-9baa-727f30fb3506), log id: 5d1be01e 2014-07-23 13:50:22,381 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.CreateSnapshotVDSCommand] (org.ovirt.thread.pool-6-thread-31) [d1f73ee] -- executeIrsBrokerCommand: calling 'createVolume' with two new parameters: description and UUID 2014-07-23 13:50:22,411 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.CreateSnapshotVDSCommand] (org.ovirt.thread.pool-6-thread-31) [d1f73ee] FINISH, CreateSnapshotVDSCommand, return: 06053c41-7e69-48a4-b929-6a321336768e, log id: 5d1be01e 2014-07-23 13:50:22,421 INFO [org.ovirt.engine.core.bll.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-31) [d1f73ee] CommandAsyncTask::Adding CommandMultiAsyncTasks object for command 162f3c7f-fb70-4aee-a34c-781c22f2a991 2014-07-23 13:50:22,422 INFO [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (org.ovirt.thread.pool-6-thread-31) [d1f73ee] CommandMultiAsyncTasks::AttachTask: Attaching task de319bf3-6aca-4410-802c-4b0258d3765f to command 162f3c7f-fb70-4aee-a34c-781c22f2a991. 2014-07-23 13:50:22,431 INFO [org.ovirt.engine.core.bll.AsyncTaskManager] (org.ovirt.thread.pool-6-thread-31) [d1f73ee] Adding task de319bf3-6aca-4410-802c-4b0258d3765f (Parent Command LiveMigrateVmDisks, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters), polling hasn't started yet.. 2014-07-23 13:50:22,461 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-6-thread-31) Correlation ID: 4b5f6f7, Job ID: 9606fd07-3905-4587-85ff-666cf24f0f8b, Call Stack: null, Custom Event ID: -1, Message: Snapshot 'Auto-generated for Live Storage Migration' creation for VM 'vm-3' was initiated by XXX. 2014-07-23 13:50:22,465 INFO [org.ovirt.engine.core.bll.SPMAsyncTask] (org.ovirt.thread.pool-6-thread-31) BaseAsyncTask::startPollingTask: Starting to poll task de319bf3-6aca-4410-802c-4b0258d3765f. 2014-07-23 13:50:29,555 INFO [org.ovirt.engine.core.bll.AsyncTaskManager] (DefaultQuartzScheduler_Worker-50) Polling and updating Async Tasks: 1 tasks, 1 tasks to poll now 2014-07-23 13:50:29,566 INFO [org.ovirt.engine.core.bll.SPMAsyncTask] (DefaultQuartzScheduler_Worker-50) SPMAsyncTask::PollTask: Polling task de319bf3-6aca-4410-802c-4b0258d3765f (Parent Command LiveMigrateVmDisks, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) returned status finished, result 'success'. 2014-07-23 13:50:29,572 INFO [org.ovirt.engine.core.bll.SPMAsyncTask] (DefaultQuartzScheduler_Worker-50) BaseAsyncTask::OnTaskEndSuccess: Task de319bf3-6aca-4410-802c-4b0258d3765f (Parent Command LiveMigrateVmDisks, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) ended successfully. 2014-07-23 13:50:29,573 INFO [org.ovirt.engine.core.bll.CommandAsyncTask] (DefaultQuartzScheduler_Worker-50) CommandAsyncTask::EndActionIfNecessary: All tasks of command 162f3c7f-fb70-4aee-a34c-781c22f2a991 has ended -> executing endAction 2014-07-23 13:50:29,574 INFO [org.ovirt.engine.core.bll.CommandAsyncTask] (DefaultQuartzScheduler_Worker-50) CommandAsyncTask::endAction: Ending action for 1 tasks (command ID: 162f3c7f-fb70-4aee-a34c-781c22f2a991): calling endAction . 2014-07-23 13:50:29,575 INFO [org.ovirt.engine.core.bll.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-41) CommandAsyncTask::EndCommandAction [within thread] context: Attempting to endAction LiveMigrateVmDisks, executionIndex: 0 2014-07-23 13:50:29,585 INFO [org.ovirt.engine.core.bll.lsm.LiveMigrateVmDisksCommand] (org.ovirt.thread.pool-6-thread-41) Ending command successfully: org.ovirt.engine.core.bll.lsm.LiveMigrateVmDisksCommand 2014-07-23 13:50:29,590 INFO [org.ovirt.engine.core.bll.CreateAllSnapshotsFromVmCommand] (org.ovirt.thread.pool-6-thread-41) Ending command successfully: org.ovirt.engine.core.bll.CreateAllSnapshotsFromVmCommand 2014-07-23 13:50:29,611 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.SnapshotVDSCommand] (org.ovirt.thread.pool-6-thread-41) START, SnapshotVDSCommand(HostName = ov-nodo4, HostId = 1cf547f7-deca-4fdc-bd32-1af20b8fc0ce, vmId=5c67eecf-a71c-497a-9c47-aa84c58deb30), log id: acb1a62 2014-07-23 13:50:30,853 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.SnapshotVDSCommand] (org.ovirt.thread.pool-6-thread-41) FINISH, SnapshotVDSCommand, log id: acb1a62 2014-07-23 13:50:30,855 INFO [org.ovirt.engine.core.bll.CreateSnapshotCommand] (org.ovirt.thread.pool-6-thread-41) [d1f73ee] Ending command successfully: org.ovirt.engine.core.bll.CreateSnapshotCommand 2014-07-23 13:50:30,859 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (org.ovirt.thread.pool-6-thread-41) [d1f73ee] START, GetImageInfoVDSCommand( storagePoolId = a686da64-af46-435a-a7e9-3f597e9da802, ignoreFailoverLimit = false, storageDomainId = 7289cfd1-e325-40d5-9e66-7c208d003295, imageGroupId = 5446a197-370d-4b9e-9baa-727f30fb3506, imageId = 06053c41-7e69-48a4-b929-6a321336768e), log id: 7fedf38c 2014-07-23 13:50:31,147 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (org.ovirt.thread.pool-6-thread-41) [d1f73ee] FINISH, GetImageInfoVDSCommand, return: org.ovirt.engine.core.common.businessentities.DiskImage@f9014f2f, log id: 7fedf38c 2014-07-23 13:50:31,176 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-6-thread-41) Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: Snapshot 'Auto-generated for Live Storage Migration' creation for VM 'vm-3' has been completed. 2014-07-23 13:50:31,184 INFO [org.ovirt.engine.core.bll.lsm.LiveMigrateVmDisksCommand] (org.ovirt.thread.pool-6-thread-41) Running command: LiveMigrateVmDisksCommand Task handler: LiveMigrateDisksTaskHandler internal: false. Entities affected : ID: 465a3c9d-e770-49af-982e-4de323ff892c Type: Disk, ID: 6e8c2454-aa64-4f70-9bdf-0b39d31ec6c5 Type: Storage 2014-07-23 13:50:31,232 INFO [org.ovirt.engine.core.bll.lsm.LiveMigrateDiskCommand] (org.ovirt.thread.pool-6-thread-41) [3969cd16] Lock Acquired to object EngineLock [exclusiveLocks= , sharedLocks= key: 5c67eecf-a71c-497a-9c47-aa84c58deb30 value: VM ] 2014-07-23 13:50:31,247 INFO [org.ovirt.engine.core.bll.lsm.LiveMigrateDiskCommand] (org.ovirt.thread.pool-6-thread-41) [3969cd16] Running command: LiveMigrateDiskCommand Task handler: CreateImagePlaceholderTaskHandler internal: true. Entities affected : ID: 5446a197-370d-4b9e-9baa-727f30fb3506 Type: Disk, ID: 6e8c2454-aa64-4f70-9bdf-0b39d31ec6c5 Type: Storage 2014-07-23 13:50:31,253 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.CloneImageGroupStructureVDSCommand] (org.ovirt.thread.pool-6-thread-41) [3969cd16] START, CloneImageGroupStructureVDSCommand( storagePoolId = a686da64-af46-435a-a7e9-3f597e9da802, ignoreFailoverLimit = false, storageDomainId = 7289cfd1-e325-40d5-9e66-7c208d003295, imageGroupId = 5446a197-370d-4b9e-9baa-727f30fb3506, dstDomainId = 6e8c2454-aa64-4f70-9bdf-0b39d31ec6c5), log id: 1da91ca3 2014-07-23 13:50:31,327 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.CloneImageGroupStructureVDSCommand] (org.ovirt.thread.pool-6-thread-41) [3969cd16] FINISH, CloneImageGroupStructureVDSCommand, log id: 1da91ca3 2014-07-23 13:50:31,353 INFO [org.ovirt.engine.core.bll.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-41) [3969cd16] CommandAsyncTask::Adding CommandMultiAsyncTasks object for command a338ac41-37eb-4902-9caf-ac225acfe1df 2014-07-23 13:50:31,354 INFO [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (org.ovirt.thread.pool-6-thread-41) [3969cd16] CommandMultiAsyncTasks::AttachTask: Attaching task b64670d2-8af1-427f-9c9a-2e079e25cee6 to command a338ac41-37eb-4902-9caf-ac225acfe1df. 2014-07-23 13:50:31,361 INFO [org.ovirt.engine.core.bll.AsyncTaskManager] (org.ovirt.thread.pool-6-thread-41) [3969cd16] Adding task b64670d2-8af1-427f-9c9a-2e079e25cee6 (Parent Command LiveMigrateDisk, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters), polling hasn't started yet.. 2014-07-23 13:50:31,370 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-6-thread-41) [3969cd16] Correlation ID: 3969cd16, Job ID: b6986947-e242-43f8-a81f-6bca1af9f40f, Call Stack: null, Custom Event ID: -1, Message: User XXX moving disk debian_Disk1 to domain stg2-sata-5500G. 2014-07-23 13:50:31,371 INFO [org.ovirt.engine.core.bll.SPMAsyncTask] (org.ovirt.thread.pool-6-thread-41) [3969cd16] BaseAsyncTask::startPollingTask: Starting to poll task b64670d2-8af1-427f-9c9a-2e079e25cee6. 2014-07-23 13:50:31,373 INFO [org.ovirt.engine.core.bll.SPMAsyncTask] (org.ovirt.thread.pool-6-thread-41) [3969cd16] BaseAsyncTask::startPollingTask: Starting to poll task b64670d2-8af1-427f-9c9a-2e079e25cee6. 2014-07-23 13:50:31,377 INFO [org.ovirt.engine.core.bll.lsm.LiveMigrateVmDisksCommand] (org.ovirt.thread.pool-6-thread-41) [3969cd16] Lock freed to object EngineLock [exclusiveLocks= key: 5446a197-370d-4b9e-9baa-727f30fb3506 value: DISK , sharedLocks= key: 5c67eecf-a71c-497a-9c47-aa84c58deb30 value: VM ] 2014-07-23 13:50:31,378 INFO [org.ovirt.engine.core.bll.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-41) CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type LiveMigrateVmDisks completed, handling the result. 2014-07-23 13:50:31,379 INFO [org.ovirt.engine.core.bll.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-41) CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type LiveMigrateVmDisks succeeded, clearing tasks. 2014-07-23 13:50:31,383 INFO [org.ovirt.engine.core.bll.SPMAsyncTask] (org.ovirt.thread.pool-6-thread-41) SPMAsyncTask::ClearAsyncTask: Attempting to clear task de319bf3-6aca-4410-802c-4b0258d3765f 2014-07-23 13:50:31,383 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-41) START, SPMClearTaskVDSCommand( storagePoolId = a686da64-af46-435a-a7e9-3f597e9da802, ignoreFailoverLimit = false, taskId = de319bf3-6aca-4410-802c-4b0258d3765f), log id: dd970cd 2014-07-23 13:50:31,385 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-41) START, HSMClearTaskVDSCommand(HostName = ov-nodo1, HostId = 8869a834-4a65-49c1-86c8-a08f9a753594, taskId=de319bf3-6aca-4410-802c-4b0258d3765f), log id: 3e7ca9d5 2014-07-23 13:50:31,419 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-41) FINISH, HSMClearTaskVDSCommand, log id: 3e7ca9d5 2014-07-23 13:50:31,420 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-41) FINISH, SPMClearTaskVDSCommand, log id: dd970cd 2014-07-23 13:50:31,424 INFO [org.ovirt.engine.core.bll.SPMAsyncTask] (org.ovirt.thread.pool-6-thread-41) BaseAsyncTask::RemoveTaskFromDB: Removed task de319bf3-6aca-4410-802c-4b0258d3765f from DataBase 2014-07-23 13:50:31,425 INFO [org.ovirt.engine.core.bll.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-41) CommandAsyncTask::HandleEndActionResult [within thread]: Removing CommandMultiAsyncTasks object for entity 162f3c7f-fb70-4aee-a34c-781c22f2a991 2014-07-23 13:50:36,606 WARN [org.ovirt.engine.core.utils.threadpool.ThreadPoolUtil] (org.ovirt.thread.pool-6-thread-9) Executing a command: java.util.concurrent.FutureTask , but note that there are 1 tasks in the queue. 2014-07-23 13:50:39,576 INFO [org.ovirt.engine.core.bll.AsyncTaskManager] (DefaultQuartzScheduler_Worker-85) Polling and updating Async Tasks: 2 tasks, 1 tasks to poll now 2014-07-23 13:50:39,627 INFO [org.ovirt.engine.core.bll.SPMAsyncTask] (DefaultQuartzScheduler_Worker-85) SPMAsyncTask::PollTask: Polling task b64670d2-8af1-427f-9c9a-2e079e25cee6 (Parent Command LiveMigrateDisk, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) returned status finished, result 'success'. 2014-07-23 13:50:39,633 INFO [org.ovirt.engine.core.bll.SPMAsyncTask] (DefaultQuartzScheduler_Worker-85) BaseAsyncTask::OnTaskEndSuccess: Task b64670d2-8af1-427f-9c9a-2e079e25cee6 (Parent Command LiveMigrateDisk, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) ended successfully. 2014-07-23 13:50:39,634 INFO [org.ovirt.engine.core.bll.CommandAsyncTask] (DefaultQuartzScheduler_Worker-85) CommandAsyncTask::EndActionIfNecessary: All tasks of command a338ac41-37eb-4902-9caf-ac225acfe1df has ended -> executing endAction 2014-07-23 13:50:39,635 INFO [org.ovirt.engine.core.bll.CommandAsyncTask] (DefaultQuartzScheduler_Worker-85) CommandAsyncTask::endAction: Ending action for 1 tasks (command ID: a338ac41-37eb-4902-9caf-ac225acfe1df): calling endAction . 2014-07-23 13:50:39,636 INFO [org.ovirt.engine.core.bll.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-5) CommandAsyncTask::EndCommandAction [within thread] context: Attempting to endAction LiveMigrateDisk, executionIndex: 0 2014-07-23 13:50:39,652 INFO [org.ovirt.engine.core.bll.lsm.LiveMigrateDiskCommand] (org.ovirt.thread.pool-6-thread-5) [3969cd16] Ending command successfully: org.ovirt.engine.core.bll.lsm.LiveMigrateDiskCommand 2014-07-23 13:50:39,653 INFO [org.ovirt.engine.core.bll.lsm.LiveMigrateDiskCommand] (org.ovirt.thread.pool-6-thread-5) [3969cd16] Running command: LiveMigrateDiskCommand Task handler: VmReplicateDiskStartTaskHandler internal: false. Entities affected : ID: 5446a197-370d-4b9e-9baa-727f30fb3506 Type: Disk, ID: 6e8c2454-aa64-4f70-9bdf-0b39d31ec6c5 Type: Storage 2014-07-23 13:50:39,655 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.VmReplicateDiskStartVDSCommand] (org.ovirt.thread.pool-6-thread-5) [3969cd16] START, VmReplicateDiskStartVDSCommand(HostName = ov-nodo4, HostId = 1cf547f7-deca-4fdc-bd32-1af20b8fc0ce, vmId=5c67eecf-a71c-497a-9c47-aa84c58deb30), log id: 2eb58700 2014-07-23 13:50:40,693 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.VmReplicateDiskStartVDSCommand] (org.ovirt.thread.pool-6-thread-5) [3969cd16] FINISH, VmReplicateDiskStartVDSCommand, log id: 2eb58700 2014-07-23 13:50:40,699 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SyncImageGroupDataVDSCommand] (org.ovirt.thread.pool-6-thread-5) [3969cd16] START, SyncImageGroupDataVDSCommand( storagePoolId = a686da64-af46-435a-a7e9-3f597e9da802, ignoreFailoverLimit = false, storageDomainId = 7289cfd1-e325-40d5-9e66-7c208d003295, imageGroupId = 5446a197-370d-4b9e-9baa-727f30fb3506, dstDomainId = 6e8c2454-aa64-4f70-9bdf-0b39d31ec6c5, syncType=INTERNAL), log id: 5531cb92 2014-07-23 13:50:40,738 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SyncImageGroupDataVDSCommand] (org.ovirt.thread.pool-6-thread-5) [3969cd16] FINISH, SyncImageGroupDataVDSCommand, log id: 5531cb92 2014-07-23 13:50:40,755 INFO [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (org.ovirt.thread.pool-6-thread-5) [3969cd16] CommandMultiAsyncTasks::AttachTask: Attaching task c36ed769-6516-448e-b0f2-ad5407af8cf2 to command a338ac41-37eb-4902-9caf-ac225acfe1df. 2014-07-23 13:50:40,762 INFO [org.ovirt.engine.core.bll.AsyncTaskManager] (org.ovirt.thread.pool-6-thread-5) [3969cd16] Adding task c36ed769-6516-448e-b0f2-ad5407af8cf2 (Parent Command LiveMigrateDisk, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters), polling hasn't started yet.. 2014-07-23 13:50:40,766 INFO [org.ovirt.engine.core.bll.SPMAsyncTask] (org.ovirt.thread.pool-6-thread-5) [3969cd16] BaseAsyncTask::startPollingTask: Starting to poll task c36ed769-6516-448e-b0f2-ad5407af8cf2. 2014-07-23 13:50:40,767 INFO [org.ovirt.engine.core.bll.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-5) CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type LiveMigrateDisk completed, handling the result. 2014-07-23 13:50:40,768 INFO [org.ovirt.engine.core.bll.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-5) CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type LiveMigrateDisk succeeded, clearing tasks. 2014-07-23 13:50:40,768 INFO [org.ovirt.engine.core.bll.SPMAsyncTask] (org.ovirt.thread.pool-6-thread-5) SPMAsyncTask::ClearAsyncTask: Attempting to clear task b64670d2-8af1-427f-9c9a-2e079e25cee6 2014-07-23 13:50:40,769 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-5) START, SPMClearTaskVDSCommand( storagePoolId = a686da64-af46-435a-a7e9-3f597e9da802, ignoreFailoverLimit = false, taskId = b64670d2-8af1-427f-9c9a-2e079e25cee6), log id: 544fb28 2014-07-23 13:50:40,771 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-5) START, HSMClearTaskVDSCommand(HostName = ov-nodo1, HostId = 8869a834-4a65-49c1-86c8-a08f9a753594, taskId=b64670d2-8af1-427f-9c9a-2e079e25cee6), log id: 73c501cb 2014-07-23 13:50:40,782 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-5) FINISH, HSMClearTaskVDSCommand, log id: 73c501cb 2014-07-23 13:50:40,782 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-6-thread-5) FINISH, SPMClearTaskVDSCommand, log id: 544fb28 2014-07-23 13:50:40,785 INFO [org.ovirt.engine.core.bll.SPMAsyncTask] (org.ovirt.thread.pool-6-thread-5) BaseAsyncTask::RemoveTaskFromDB: Removed task b64670d2-8af1-427f-9c9a-2e079e25cee6 from DataBase 2014-07-23 13:50:40,786 INFO [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (org.ovirt.thread.pool-6-thread-5) [within thread]: Some of the tasks related to command id a338ac41-37eb-4902-9caf-ac225acfe1df were not cleared yet (Task id c36ed769-6516-448e-b0f2-ad5407af8cf2 is in state Polling). 2014-07-23 13:50:42,807 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.FullListVdsCommand] (DefaultQuartzScheduler_Worker-83) START, FullListVdsCommand(HostName = ov-nodo4, HostId = 1cf547f7-deca-4fdc-bd32-1af20b8fc0ce, vds=Host[ov-nodo4], vmIds=[5c67eecf-a71c-497a-9c47-aa84c58deb30]), log id: 523d9c68 2014-07-23 13:50:42,818 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.FullListVdsCommand] (DefaultQuartzScheduler_Worker-83) FINISH, FullListVdsCommand, return: [{displaySecurePort=5937, kvmEnable=true, nicModel=rtl8139,pv, afterMigrationStatus=, keyboardLayout=es, displayIp=0, pitReinjection=false, nice=0, timeOffset=0, transparentHugePages=true, vmId=5c67eecf-a71c-497a-9c47-aa84c58deb30, acpiEnable=true, custom={device_77851972-eef0-4720-ae9e-e1f2a7ed5dbddevice_0b5199a3-3e9b-438b-b84c-b347724607d2device_9a8bd2ae-19dc-4661-8d1a-74c6e148f1dd=VmDevice {vmId=5c67eecf-a71c-497a-9c47-aa84c58deb30, deviceId=9a8bd2ae-19dc-4661-8d1a-74c6e148f1dd, device=spicevmc, type=CHANNEL, bootOrder=0, specParams={}, address={port=3, bus=0, controller=0, type=virtio-serial}, managed=false, plugged=true, readOnly=false, deviceAlias=channel2, customProperties={}, snapshotId=null}, device_77851972-eef0-4720-ae9e-e1f2a7ed5dbddevice_0b5199a3-3e9b-438b-b84c-b347724607d2=VmDevice {vmId=5c67eecf-a71c-497a-9c47-aa84c58deb30, deviceId=0b5199a3-3e9b-438b-b84c-b347724607d2, device=unix, type=CHANNEL, bootOrder=0, specParams={}, address={port=2, bus=0, controller=0, type=virtio-serial}, managed=false, plugged=true, readOnly=false, deviceAlias=channel1, customProperties={}, snapshotId=null}, device_77851972-eef0-4720-ae9e-e1f2a7ed5dbd=VmDevice {vmId=5c67eecf-a71c-497a-9c47-aa84c58deb30, deviceId=77851972-eef0-4720-ae9e-e1f2a7ed5dbd, device=unix, type=CHANNEL, bootOrder=0, specParams={}, address={port=1, bus=0, controller=0, type=virtio-serial}, managed=false, plugged=true, readOnly=false, deviceAlias=channel0, customProperties={}, snapshotId=null}, device_77851972-eef0-4720-ae9e-e1f2a7ed5dbddevice_0b5199a3-3e9b-438b-b84c-b347724607d2device_9a8bd2ae-19dc-4661-8d1a-74c6e148f1dddevice_90036bea-eff5-4936-9a5a-13b2f158b5eedevice_83d4da9c-4912-4707-83ee-8cb53c3ce9d4=VmDevice {vmId=5c67eecf-a71c-497a-9c47-aa84c58deb30, deviceId=83d4da9c-4912-4707-83ee-8cb53c3ce9d4, device=virtio-serial, type=CONTROLLER, bootOrder=0, specParams={}, address={bus=0x00, domain=0x0000, type=pci, slot=0x06, function=0x0}, managed=false, plugged=true, readOnly=false, deviceAlias=virtio-serial0, customProperties={}, snapshotId=null}, device_77851972-eef0-4720-ae9e-e1f2a7ed5dbddevice_0b5199a3-3e9b-438b-b84c-b347724607d2device_9a8bd2ae-19dc-4661-8d1a-74c6e148f1dddevice_90036bea-eff5-4936-9a5a-13b2f158b5ee=VmDevice {vmId=5c67eecf-a71c-497a-9c47-aa84c58deb30, deviceId=90036bea-eff5-4936-9a5a-13b2f158b5ee, device=ide, type=CONTROLLER, bootOrder=0, specParams={}, address={bus=0x00, domain=0x0000, type=pci, slot=0x01, function=0x1}, managed=false, plugged=true, readOnly=false, deviceAlias=ide0, customProperties={}, snapshotId=null}}, spiceSslCipherSuite=DEFAULT, memSize=1024, smp=1, displayPort=5936, status=Up, vmType=kvm, emulatedMachine=rhel6.4.0, memGuaranteedSize=1024, display=qxl, pid=26151, smartcardEnable=false, spiceSecureChannels=smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard, smpCoresPerSocket=1, clientIp=, devices=[Ljava.lang.Object;@12a41d44, vmName=vm-3, cpuType=Conroe}], log id: 523d9c68 2014-07-23 13:50:46,186 WARN [org.ovirt.engine.core.utils.threadpool.ThreadPoolUtil] (org.ovirt.thread.pool-6-thread-26) Executing a command: java.util.concurrent.FutureTask , but note that there are 1 tasks in the queue. 2014-07-23 13:50:49,638 INFO [org.ovirt.engine.core.bll.AsyncTaskManager] (DefaultQuartzScheduler_Worker-17) Polling and updating Async Tasks: 3 tasks, 1 tasks to poll now 2014-07-23 13:50:49,647 INFO [org.ovirt.engine.core.bll.SPMAsyncTask] (DefaultQuartzScheduler_Worker-17) SPMAsyncTask::PollTask: Polling task c36ed769-6516-448e-b0f2-ad5407af8cf2 (Parent Command LiveMigrateDisk, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) returned status running. 2014-07-23 13:50:49,648 INFO [org.ovirt.engine.core.bll.AsyncTaskManager] (DefaultQuartzScheduler_Worker-17) Finished polling Tasks, will poll again in 10 seconds. 2014-07-23 13:51:58,763 INFO [org.ovirt.engine.core.bll.AsyncTaskManager] (DefaultQuartzScheduler_Worker-34) Setting new tasks map. The map contains now 1 tasks 2014-07-23 13:51:59,713 INFO [org.ovirt.engine.core.bll.AsyncTaskManager] (DefaultQuartzScheduler_Worker-78) Polling and updating Async Tasks: 1 tasks, 1 tasks to poll now 2014-07-23 13:51:59,722 INFO [org.ovirt.engine.core.bll.AsyncTaskManager] (DefaultQuartzScheduler_Worker-78) Finished polling Tasks, will poll again in 10 seconds. 2014-07-23 13:52:02,267 INFO [org.ovirt.engine.core.bll.MoveOrCopyDiskCommand] (ajp--127.0.0.1-8702-4) [7eb7b21a] Lock Acquired to object EngineLock [exclusiveLocks= key: 70c4576f-ea7a-4d90-9d3b-671dfdde01eb value: DISK , sharedLocks= key: 09bc525c-d3de-445b-88fd-80a289adcdb1 value: TEMPLATE ] 2014-07-23 13:52:02,376 INFO [org.ovirt.engine.core.bll.MoveOrCopyDiskCommand] (org.ovirt.thread.pool-6-thread-27) [7eb7b21a] Running command: MoveOrCopyDiskCommand internal: false. Entities affected : ID: 70c4576f-ea7a-4d90-9d3b-671dfdde01eb Type: Disk, ID: 6e8c2454-aa64-4f70-9bdf-0b39d31ec6c5 Type: Storage 2014-07-23 13:52:02,390 INFO [org.ovirt.engine.core.bll.CopyImageGroupCommand] (org.ovirt.thread.pool-6-thread-27) [7eb7b21a] Running command: CopyImageGroupCommand internal: true. Entities affected : ID: 6e8c2454-aa64-4f70-9bdf-0b39d31ec6c5 Type: Storage 2014-07-23 13:52:02,409 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.CopyImageVDSCommand] (org.ovirt.thread.pool-6-thread-27) [7eb7b21a] START, CopyImageVDSCommand( storagePoolId = a686da64-af46-435a-a7e9-3f597e9da802, ignoreFailoverLimit = false, storageDomainId = 7289cfd1-e325-40d5-9e66-7c208d003295, imageGroupId = 70c4576f-ea7a-4d90-9d3b-671dfdde01eb, imageId = 31260d06-756c-438b-8a02-a75b6fce5841, dstImageGroupId = 70c4576f-ea7a-4d90-9d3b-671dfdde01eb, vmId = 00000000-0000-0000-0000-000000000000, dstImageId = 31260d06-756c-438b-8a02-a75b6fce5841, imageDescription = , dstStorageDomainId = 6e8c2454-aa64-4f70-9bdf-0b39d31ec6c5, copyVolumeType = SharedVol, volumeFormat = RAW, preallocate = Preallocated, postZero = false, force = false), log id: 232030b9 2014-07-23 13:52:02,413 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.CopyImageVDSCommand] (org.ovirt.thread.pool-6-thread-27) [7eb7b21a] -- executeIrsBrokerCommand: calling 'copyImage' with two new parameters: description and UUID 2014-07-23 13:52:02,414 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.CopyImageVDSCommand] (org.ovirt.thread.pool-6-thread-27) [7eb7b21a] -- copyImage parameters: sdUUID=7289cfd1-e325-40d5-9e66-7c208d003295 spUUID=a686da64-af46-435a-a7e9-3f597e9da802 vmGUID=00000000-0000-0000-0000-000000000000 srcImageGUID=70c4576f-ea7a-4d90-9d3b-671dfdde01eb srcVolUUID=31260d06-756c-438b-8a02-a75b6fce5841 dstImageGUID=70c4576f-ea7a-4d90-9d3b-671dfdde01eb dstVolUUID=31260d06-756c-438b-8a02-a75b6fce5841 descr= dstSdUUID=6e8c2454-aa64-4f70-9bdf-0b39d31ec6c5 2014-07-23 13:52:03,098 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.CopyImageVDSCommand] (org.ovirt.thread.pool-6-thread-27) [7eb7b21a] FINISH, CopyImageVDSCommand, return: 00000000-0000-0000-0000-000000000000, log id: 232030b9 2014-07-23 13:52:03,106 INFO [org.ovirt.engine.core.bll.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-27) [7eb7b21a] CommandAsyncTask::Adding CommandMultiAsyncTasks object for command 60668aa5-5701-42ee-b0cc-9331027cfc49 2014-07-23 13:52:03,106 INFO [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (org.ovirt.thread.pool-6-thread-27) [7eb7b21a] CommandMultiAsyncTasks::AttachTask: Attaching task 777922b2-bace-45ad-9d90-d93830642fc3 to command 60668aa5-5701-42ee-b0cc-9331027cfc49. 2014-07-23 13:52:03,113 INFO [org.ovirt.engine.core.bll.AsyncTaskManager] (org.ovirt.thread.pool-6-thread-27) [7eb7b21a] Adding task 777922b2-bace-45ad-9d90-d93830642fc3 (Parent Command MoveOrCopyDisk, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters), polling hasn't started yet.. 2014-07-23 13:52:03,126 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-6-thread-27) [7eb7b21a] Correlation ID: 7eb7b21a, Job ID: bfec0039-2149-4e97-aa03-309ff36dff62, Call Stack: null, Custom Event ID: -1, Message: User XXX is copying template disk debian_Disk1 to domain stg2-sata-5500G. 2014-07-23 13:52:03,127 INFO [org.ovirt.engine.core.bll.SPMAsyncTask] (org.ovirt.thread.pool-6-thread-27) [7eb7b21a] BaseAsyncTask::startPollingTask: Starting to poll task 777922b2-bace-45ad-9d90-d93830642fc3. 2014-07-23 13:52:09,724 INFO [org.ovirt.engine.core.bll.AsyncTaskManager] (DefaultQuartzScheduler_Worker-93) Polling and updating Async Tasks: 2 tasks, 2 tasks to poll now 2014-07-23 13:52:09,761 INFO [org.ovirt.engine.core.bll.SPMAsyncTask] (DefaultQuartzScheduler_Worker-93) SPMAsyncTask::PollTask: Polling task 777922b2-bace-45ad-9d90-d93830642fc3 (Parent Command MoveOrCopyDisk, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) returned status running. 2014-07-23 13:52:09,762 INFO [org.ovirt.engine.core.bll.AsyncTaskManager] (DefaultQuartzScheduler_Worker-93) Finished polling Tasks, will poll again in 10 seconds. 2014-07-23 13:53:00,335 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.GetIsoListVDSCommand] (org.ovirt.thread.pool-6-thread-5) START, GetIsoListVDSCommand( storagePoolId = a686da64-af46-435a-a7e9-3f597e9da802, ignoreFailoverLimit = false), log id: 6ec1100d 2014-07-23 13:53:00,338 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HsmGetIsoListVDSCommand] (org.ovirt.thread.pool-6-thread-5) START, HsmGetIsoListVDSCommand(HostName = ov-nodo1, HostId = 8869a834-4a65-49c1-86c8-a08f9a753594, storagePoolId=a686da64-af46-435a-a7e9-3f597e9da802), log id: 4504fe49 2014-07-23 13:53:00,508 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HsmGetIsoListVDSCommand] (org.ovirt.thread.pool-6-thread-5) FINISH, HsmGetIsoListVDSCommand, return: {CentOS-5.10-x86_64-bin-1of9.iso={size=-1}, debian-5010-amd64-CD-1.iso={size=-1}, SW_DVD5_Win_Pro_7_64BIT_Spanish_Full_MLF_X15-71093.ISO={size=-1}, debian-testing-amd64-gnome-CD-1.iso={size=-1}, virtio-win-0.1-81.iso={size=-1}, clonezilla-live-1.2.11-23-i486.iso={size=-1}, debian-7.4.0-amd64-CD-1.iso={size=-1}, super_grub2_disk_i386_pc_2.00s2.iso={size=-1}, debian-7.1.0-i386-CD-1.iso={size=-1}, ubuntu-13.10-server-amd64.iso={size=-1}, clonezilla-live-2.2.2-32-amd64.iso={size=-1}, Hiren 15.2 con Ghost.iso={size=-1}, debian-testing-amd64-DVD-1.iso={size=-1}, virtio-win-0.1-65.iso={size=-1}, debian-6.0.9-amd64-netinst.iso={size=-1}, SW_DVD5_Windows_Svr_Std_and_DataCtr_2012_R2_64Bit_Spanish_Core_MLF_X19-05192.ISO={size=-1}}, log id: 4504fe49 2014-07-23 13:53:00,512 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.GetIsoListVDSCommand] (org.ovirt.thread.pool-6-thread-5) FINISH, GetIsoListVDSCommand, return: {CentOS-5.10-x86_64-bin-1of9.iso={size=-1}, debian-5010-amd64-CD-1.iso={size=-1}, SW_DVD5_Win_Pro_7_64BIT_Spanish_Full_MLF_X15-71093.ISO={size=-1}, debian-testing-amd64-gnome-CD-1.iso={size=-1}, virtio-win-0.1-81.iso={size=-1}, clonezilla-live-1.2.11-23-i486.iso={size=-1}, debian-7.4.0-amd64-CD-1.iso={size=-1}, super_grub2_disk_i386_pc_2.00s2.iso={size=-1}, debian-7.1.0-i386-CD-1.iso={size=-1}, ubuntu-13.10-server-amd64.iso={size=-1}, clonezilla-live-2.2.2-32-amd64.iso={size=-1}, Hiren 15.2 con Ghost.iso={size=-1}, debian-testing-amd64-DVD-1.iso={size=-1}, virtio-win-0.1-65.iso={size=-1}, debian-6.0.9-amd64-netinst.iso={size=-1}, SW_DVD5_Windows_Svr_Std_and_DataCtr_2012_R2_64Bit_Spanish_Core_MLF_X19-05192.ISO={size=-1}}, log id: 6ec1100d 2014-07-23 13:53:00,524 INFO [org.ovirt.engine.core.bll.IsoDomainListSyncronizer] (org.ovirt.thread.pool-6-thread-5) Finished automatic refresh process for ISO file type with success, for storage domain id 995e6771-fb8c-4a23-b05c-7b7b51d1fb17. 2014-07-23 13:58:06,840 WARN [org.ovirt.engine.core.utils.threadpool.ThreadPoolUtil] (org.ovirt.thread.pool-6-thread-36) Executing a command: java.util.concurrent.FutureTask , but note that there are 1 tasks in the queue. 2014-07-23 13:58:45,846 WARN [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-34) domain 7289cfd1-e325-40d5-9e66-7c208d003295:iscsi-intel in problem. vds: ov-nodo1 2014-07-23 13:58:45,849 WARN [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-34) domain c82fbd04-72c8-4b4e-935c-f3a8ef7e4681:stg1-sas-1600G in problem. vds: ov-nodo1 2014-07-23 13:58:45,851 WARN [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-34) domain 995e6771-fb8c-4a23-b05c-7b7b51d1fb17:ISO_DOMAIN in problem. vds: ov-nodo1 2014-07-23 13:59:18,365 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-41) Domain c82fbd04-72c8-4b4e-935c-f3a8ef7e4681:stg1-sas-1600G recovered from problem. vds: ov-nodo1 2014-07-23 13:59:18,366 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-41) Domain c82fbd04-72c8-4b4e-935c-f3a8ef7e4681:stg1-sas-1600G has recovered from problem. No active host in the DC is reporting it as problematic, so clearing the domain recovery timer. 2014-07-23 13:59:18,368 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-41) Domain 7289cfd1-e325-40d5-9e66-7c208d003295:iscsi-intel recovered from problem. vds: ov-nodo1 2014-07-23 13:59:18,369 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-41) Domain 7289cfd1-e325-40d5-9e66-7c208d003295:iscsi-intel has recovered from problem. No active host in the DC is reporting it as problematic, so clearing the domain recovery timer. 2014-07-23 13:59:18,371 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-41) Domain 995e6771-fb8c-4a23-b05c-7b7b51d1fb17:ISO_DOMAIN recovered from problem. vds: ov-nodo1 2014-07-23 13:59:18,372 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-41) Domain 995e6771-fb8c-4a23-b05c-7b7b51d1fb17:ISO_DOMAIN has recovered from problem. No active host in the DC is reporting it as problematic, so clearing the domain recovery timer. 2014-07-23 14:02:18,771 WARN [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-31) domain 6e8c2454-aa64-4f70-9bdf-0b39d31ec6c5:stg2-sata-5500G in problem. vds: ov-nodo1 2014-07-23 14:02:18,772 WARN [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-31) domain 7289cfd1-e325-40d5-9e66-7c208d003295:iscsi-intel in problem. vds: ov-nodo1 2014-07-23 14:02:18,774 WARN [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-31) domain c82fbd04-72c8-4b4e-935c-f3a8ef7e4681:stg1-sas-1600G in problem. vds: ov-nodo1 2014-07-23 14:02:18,775 WARN [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-31) domain d34de59a-6df4-4fbf-8072-bbac5d6e68a3:stg2-sas-3900G in problem. vds: ov-nodo1 2014-07-23 14:02:18,777 WARN [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-31) domain 995e6771-fb8c-4a23-b05c-7b7b51d1fb17:ISO_DOMAIN in problem. vds: ov-nodo1 2014-07-23 14:02:50,409 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-49) Domain 6e8c2454-aa64-4f70-9bdf-0b39d31ec6c5:stg2-sata-5500G recovered from problem. vds: ov-nodo1 2014-07-23 14:02:50,410 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-49) Domain 6e8c2454-aa64-4f70-9bdf-0b39d31ec6c5:stg2-sata-5500G has recovered from problem. No active host in the DC is reporting it as problematic, so clearing the domain recovery timer. 2014-07-23 14:02:50,412 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-49) Domain c82fbd04-72c8-4b4e-935c-f3a8ef7e4681:stg1-sas-1600G recovered from problem. vds: ov-nodo1 2014-07-23 14:02:50,413 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-49) Domain c82fbd04-72c8-4b4e-935c-f3a8ef7e4681:stg1-sas-1600G has recovered from problem. No active host in the DC is reporting it as problematic, so clearing the domain recovery timer. 2014-07-23 14:02:50,415 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-49) Domain 7289cfd1-e325-40d5-9e66-7c208d003295:iscsi-intel recovered from problem. vds: ov-nodo1 2014-07-23 14:02:50,415 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-49) Domain 7289cfd1-e325-40d5-9e66-7c208d003295:iscsi-intel has recovered from problem. No active host in the DC is reporting it as problematic, so clearing the domain recovery timer. 2014-07-23 14:02:50,417 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-49) Domain d34de59a-6df4-4fbf-8072-bbac5d6e68a3:stg2-sas-3900G recovered from problem. vds: ov-nodo1 2014-07-23 14:02:50,418 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-49) Domain d34de59a-6df4-4fbf-8072-bbac5d6e68a3:stg2-sas-3900G has recovered from problem. No active host in the DC is reporting it as problematic, so clearing the domain recovery timer. 2014-07-23 14:02:50,420 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-49) Domain 995e6771-fb8c-4a23-b05c-7b7b51d1fb17:ISO_DOMAIN recovered from problem. vds: ov-nodo1 2014-07-23 14:02:50,421 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-49) Domain 995e6771-fb8c-4a23-b05c-7b7b51d1fb17:ISO_DOMAIN has recovered from problem. No active host in the DC is reporting it as problematic, so clearing the domain recovery timer. 2014-07-23 14:03:52,267 WARN [org.ovirt.engine.core.utils.threadpool.ThreadPoolUtil] (org.ovirt.thread.pool-6-thread-4) Executing a command: java.util.concurrent.FutureTask , but note that there are 1 tasks in the queue. 2014-07-23 14:07:32,515 WARN [org.ovirt.engine.core.utils.threadpool.ThreadPoolUtil] (org.ovirt.thread.pool-6-thread-16) Executing a command: java.util.concurrent.FutureTask , but note that there are 1 tasks in the queue. 2014-07-23 14:12:12,080 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-52) Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: Used CPU of host ov-nodo1 [96%] exceeded defined threshold [95%]. 2014-07-23 14:12:12,119 WARN [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-44) domain c82fbd04-72c8-4b4e-935c-f3a8ef7e4681:stg1-sas-1600G in problem. vds: ov-nodo1 2014-07-23 14:13:50,098 WARN [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-42) domain d34de59a-6df4-4fbf-8072-bbac5d6e68a3:stg2-sas-3900G in problem. vds: ov-nodo1 2014-07-23 14:13:50,100 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-42) Domain c82fbd04-72c8-4b4e-935c-f3a8ef7e4681:stg1-sas-1600G recovered from problem. vds: ov-nodo1 2014-07-23 14:13:50,101 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-42) Domain c82fbd04-72c8-4b4e-935c-f3a8ef7e4681:stg1-sas-1600G has recovered from problem. No active host in the DC is reporting it as problematic, so clearing the domain recovery timer. 2014-07-23 14:14:56,052 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-17) Domain d34de59a-6df4-4fbf-8072-bbac5d6e68a3:stg2-sas-3900G recovered from problem. vds: ov-nodo1 2014-07-23 14:14:56,053 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-17) Domain d34de59a-6df4-4fbf-8072-bbac5d6e68a3:stg2-sas-3900G has recovered from problem. No active host in the DC is reporting it as problematic, so clearing the domain recovery timer. 2014-07-23 14:17:48,426 INFO [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-73) VM adm-mapuche-web1 c12a99a7-a8c3-4fd1-becb-1e494d7d2e7c moved from Up --> NotResponding 2014-07-23 14:17:48,494 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-73) Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: VM adm-mapuche-web1 is not responding. 2014-07-23 14:17:48,501 INFO [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-73) VM vm-4 14208353-fd7d-42f5-8f1d-60299309b2b9 moved from Up --> NotResponding 2014-07-23 14:17:48,513 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-73) Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: VM vm-4 is not responding. 2014-07-23 14:17:48,523 INFO [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-73) VM vm-5 55e5477a-0cc9-44e0-aae4-368d2eb88a48 moved from Up --> NotResponding 2014-07-23 14:17:48,533 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-73) Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: VM vm-5 is not responding. 2014-07-23 14:18:29,667 INFO [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-40) VM vm-4 14208353-fd7d-42f5-8f1d-60299309b2b9 moved from NotResponding --> Up 2014-07-23 14:18:29,668 INFO [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-40) VM vm-5 55e5477a-0cc9-44e0-aae4-368d2eb88a48 moved from NotResponding --> Up 2014-07-23 14:18:41,367 INFO [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-14) [78580c4f] VM adm-mapuche-web1 c12a99a7-a8c3-4fd1-becb-1e494d7d2e7c moved from NotResponding --> Up 2014-07-23 14:19:30,042 WARN [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-36) domain d34de59a-6df4-4fbf-8072-bbac5d6e68a3:stg2-sas-3900G in problem. vds: ov-nodo1 2014-07-23 14:20:23,621 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-40) Domain d34de59a-6df4-4fbf-8072-bbac5d6e68a3:stg2-sas-3900G recovered from problem. vds: ov-nodo1 2014-07-23 14:20:23,622 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-40) Domain d34de59a-6df4-4fbf-8072-bbac5d6e68a3:stg2-sas-3900G has recovered from problem. No active host in the DC is reporting it as problematic, so clearing the domain recovery timer. 2014-07-23 14:23:07,947 INFO [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-30) VM adm-mapuche-web1 c12a99a7-a8c3-4fd1-becb-1e494d7d2e7c moved from Up --> NotResponding 2014-07-23 14:23:08,009 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-30) Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: VM adm-mapuche-web1 is not responding. 2014-07-23 14:23:29,600 INFO [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-83) VM adm-mapuche-web1 c12a99a7-a8c3-4fd1-becb-1e494d7d2e7c moved from NotResponding --> Up 2014-07-23 14:24:15,475 WARN [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-23) domain d34de59a-6df4-4fbf-8072-bbac5d6e68a3:stg2-sas-3900G in problem. vds: ov-nodo1 2014-07-23 14:24:59,528 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-37) Domain d34de59a-6df4-4fbf-8072-bbac5d6e68a3:stg2-sas-3900G recovered from problem. vds: ov-nodo1 2014-07-23 14:24:59,529 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-37) Domain d34de59a-6df4-4fbf-8072-bbac5d6e68a3:stg2-sas-3900G has recovered from problem. No active host in the DC is reporting it as problematic, so clearing the domain recovery timer. 2014-07-23 14:28:38,587 WARN [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-45) domain 6e8c2454-aa64-4f70-9bdf-0b39d31ec6c5:stg2-sata-5500G in problem. vds: ov-nodo1 2014-07-23 14:28:38,589 WARN [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-45) domain 7289cfd1-e325-40d5-9e66-7c208d003295:iscsi-intel in problem. vds: ov-nodo1 2014-07-23 14:28:38,591 WARN [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-45) domain c82fbd04-72c8-4b4e-935c-f3a8ef7e4681:stg1-sas-1600G in problem. vds: ov-nodo1 2014-07-23 14:28:38,592 WARN [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-45) domain 995e6771-fb8c-4a23-b05c-7b7b51d1fb17:ISO_DOMAIN in problem. vds: ov-nodo1 2014-07-23 14:29:19,943 WARN [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-42) domain d34de59a-6df4-4fbf-8072-bbac5d6e68a3:stg2-sas-3900G in problem. vds: ov-nodo1 2014-07-23 14:29:19,944 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-42) Domain 6e8c2454-aa64-4f70-9bdf-0b39d31ec6c5:stg2-sata-5500G recovered from problem. vds: ov-nodo1 2014-07-23 14:29:19,945 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-42) Domain 6e8c2454-aa64-4f70-9bdf-0b39d31ec6c5:stg2-sata-5500G has recovered from problem. No active host in the DC is reporting it as problematic, so clearing the domain recovery timer. 2014-07-23 14:29:19,947 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-42) Domain c82fbd04-72c8-4b4e-935c-f3a8ef7e4681:stg1-sas-1600G recovered from problem. vds: ov-nodo1 2014-07-23 14:29:19,948 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-42) Domain c82fbd04-72c8-4b4e-935c-f3a8ef7e4681:stg1-sas-1600G has recovered from problem. No active host in the DC is reporting it as problematic, so clearing the domain recovery timer. 2014-07-23 14:29:19,950 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-42) Domain 7289cfd1-e325-40d5-9e66-7c208d003295:iscsi-intel recovered from problem. vds: ov-nodo1 2014-07-23 14:29:19,951 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-42) Domain 7289cfd1-e325-40d5-9e66-7c208d003295:iscsi-intel has recovered from problem. No active host in the DC is reporting it as problematic, so clearing the domain recovery timer. 2014-07-23 14:29:19,952 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-42) Domain 995e6771-fb8c-4a23-b05c-7b7b51d1fb17:ISO_DOMAIN recovered from problem. vds: ov-nodo1 2014-07-23 14:29:19,953 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-42) Domain 995e6771-fb8c-4a23-b05c-7b7b51d1fb17:ISO_DOMAIN has recovered from problem. No active host in the DC is reporting it as problematic, so clearing the domain recovery timer. 2014-07-23 14:29:45,072 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-29) Domain d34de59a-6df4-4fbf-8072-bbac5d6e68a3:stg2-sas-3900G recovered from problem. vds: ov-nodo1 2014-07-23 14:29:45,073 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-29) Domain d34de59a-6df4-4fbf-8072-bbac5d6e68a3:stg2-sas-3900G has recovered from problem. No active host in the DC is reporting it as problematic, so clearing the domain recovery timer. 2014-07-23 14:33:23,729 INFO [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-97) VM vm-6 27e19c92-a75d-4a38-a3c7-b95aee536d9a moved from Up --> NotResponding 2014-07-23 14:33:23,784 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-97) Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: VM vm-6 is not responding. 2014-07-23 14:33:23,806 INFO [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-97) VM vm-4 14208353-fd7d-42f5-8f1d-60299309b2b9 moved from Up --> NotResponding 2014-07-23 14:33:23,818 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-97) Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: VM vm-4 is not responding. 2014-07-23 14:33:23,931 WARN [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-47) domain 6e8c2454-aa64-4f70-9bdf-0b39d31ec6c5:stg2-sata-5500G in problem. vds: ov-nodo1 2014-07-23 14:33:23,933 WARN [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-47) domain 7289cfd1-e325-40d5-9e66-7c208d003295:iscsi-intel in problem. vds: ov-nodo1 2014-07-23 14:33:23,935 WARN [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-47) domain c82fbd04-72c8-4b4e-935c-f3a8ef7e4681:stg1-sas-1600G in problem. vds: ov-nodo1 2014-07-23 14:33:23,936 WARN [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-47) domain 995e6771-fb8c-4a23-b05c-7b7b51d1fb17:ISO_DOMAIN in problem. vds: ov-nodo1 2014-07-23 14:33:40,548 INFO [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-69) VM vm-6 27e19c92-a75d-4a38-a3c7-b95aee536d9a moved from NotResponding --> Up 2014-07-23 14:33:40,549 INFO [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-69) VM vm-4 14208353-fd7d-42f5-8f1d-60299309b2b9 moved from NotResponding --> Up 2014-07-23 14:34:05,619 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-27) Domain 6e8c2454-aa64-4f70-9bdf-0b39d31ec6c5:stg2-sata-5500G recovered from problem. vds: ov-nodo1 2014-07-23 14:34:05,620 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-27) Domain 6e8c2454-aa64-4f70-9bdf-0b39d31ec6c5:stg2-sata-5500G has recovered from problem. No active host in the DC is reporting it as problematic, so clearing the domain recovery timer. 2014-07-23 14:34:05,623 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-27) Domain c82fbd04-72c8-4b4e-935c-f3a8ef7e4681:stg1-sas-1600G recovered from problem. vds: ov-nodo1 2014-07-23 14:34:05,624 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-27) Domain c82fbd04-72c8-4b4e-935c-f3a8ef7e4681:stg1-sas-1600G has recovered from problem. No active host in the DC is reporting it as problematic, so clearing the domain recovery timer. 2014-07-23 14:34:05,626 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-27) Domain 7289cfd1-e325-40d5-9e66-7c208d003295:iscsi-intel recovered from problem. vds: ov-nodo1 2014-07-23 14:34:05,627 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-27) Domain 7289cfd1-e325-40d5-9e66-7c208d003295:iscsi-intel has recovered from problem. No active host in the DC is reporting it as problematic, so clearing the domain recovery timer. 2014-07-23 14:34:05,629 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-27) Domain 995e6771-fb8c-4a23-b05c-7b7b51d1fb17:ISO_DOMAIN recovered from problem. vds: ov-nodo1 2014-07-23 14:34:05,629 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-27) Domain 995e6771-fb8c-4a23-b05c-7b7b51d1fb17:ISO_DOMAIN has recovered from problem. No active host in the DC is reporting it as problematic, so clearing the domain recovery timer. 2014-07-23 14:34:42,563 WARN [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-41) domain d34de59a-6df4-4fbf-8072-bbac5d6e68a3:stg2-sas-3900G in problem. vds: ov-nodo1 2014-07-23 14:34:42,565 WARN [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-41) domain 995e6771-fb8c-4a23-b05c-7b7b51d1fb17:ISO_DOMAIN in problem. vds: ov-nodo1 2014-07-23 14:34:48,381 WARN [org.ovirt.engine.core.utils.threadpool.ThreadPoolUtil] (org.ovirt.thread.pool-6-thread-21) Executing a command: java.util.concurrent.FutureTask , but note that there are 1 tasks in the queue. 2014-07-23 14:36:21,201 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-4) Domain d34de59a-6df4-4fbf-8072-bbac5d6e68a3:stg2-sas-3900G recovered from problem. vds: ov-nodo1 2014-07-23 14:36:21,202 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-4) Domain d34de59a-6df4-4fbf-8072-bbac5d6e68a3:stg2-sas-3900G has recovered from problem. No active host in the DC is reporting it as problematic, so clearing the domain recovery timer. 2014-07-23 14:36:21,205 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-4) Domain 995e6771-fb8c-4a23-b05c-7b7b51d1fb17:ISO_DOMAIN recovered from problem. vds: ov-nodo1 2014-07-23 14:36:21,206 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-4) Domain 995e6771-fb8c-4a23-b05c-7b7b51d1fb17:ISO_DOMAIN has recovered from problem. No active host in the DC is reporting it as problematic, so clearing the domain recovery timer. 2014-07-23 14:37:12,633 WARN [org.ovirt.engine.core.utils.threadpool.ThreadPoolUtil] (org.ovirt.thread.pool-6-thread-23) Executing a command: java.util.concurrent.FutureTask , but note that there are 1 tasks in the queue. 2014-07-23 14:38:17,634 WARN [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-34) domain c82fbd04-72c8-4b4e-935c-f3a8ef7e4681:stg1-sas-1600G in problem. vds: ov-nodo1 2014-07-23 14:38:31,687 WARN [org.ovirt.engine.core.utils.threadpool.ThreadPoolUtil] (org.ovirt.thread.pool-6-thread-28) Executing a command: java.util.concurrent.FutureTask , but note that there are 1 tasks in the queue. 2014-07-23 14:38:34,703 WARN [org.ovirt.engine.core.utils.threadpool.ThreadPoolUtil] (org.ovirt.thread.pool-6-thread-40) Executing a command: java.util.concurrent.FutureTask , but note that there are 1 tasks in the queue. 2014-07-23 14:39:54,057 WARN [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-15) domain d34de59a-6df4-4fbf-8072-bbac5d6e68a3:stg2-sas-3900G in problem. vds: ov-nodo1 2014-07-23 14:40:45,453 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-16) Domain c82fbd04-72c8-4b4e-935c-f3a8ef7e4681:stg1-sas-1600G recovered from problem. vds: ov-nodo1 2014-07-23 14:40:45,454 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-16) Domain c82fbd04-72c8-4b4e-935c-f3a8ef7e4681:stg1-sas-1600G has recovered from problem. No active host in the DC is reporting it as problematic, so clearing the domain recovery timer. 2014-07-23 14:40:45,456 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-16) Domain d34de59a-6df4-4fbf-8072-bbac5d6e68a3:stg2-sas-3900G recovered from problem. vds: ov-nodo1 2014-07-23 14:40:45,456 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-16) Domain d34de59a-6df4-4fbf-8072-bbac5d6e68a3:stg2-sas-3900G has recovered from problem. No active host in the DC is reporting it as problematic, so clearing the domain recovery timer. 2014-07-23 14:42:39,754 WARN [org.ovirt.engine.core.utils.threadpool.ThreadPoolUtil] (org.ovirt.thread.pool-6-thread-14) Executing a command: java.util.concurrent.FutureTask , but note that there are 1 tasks in the queue. 2014-07-23 14:42:58,049 WARN [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-33) domain 6e8c2454-aa64-4f70-9bdf-0b39d31ec6c5:stg2-sata-5500G in problem. vds: ov-nodo1 2014-07-23 14:42:58,052 WARN [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-33) domain 7289cfd1-e325-40d5-9e66-7c208d003295:iscsi-intel in problem. vds: ov-nodo1 2014-07-23 14:42:58,053 WARN [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-33) domain c82fbd04-72c8-4b4e-935c-f3a8ef7e4681:stg1-sas-1600G in problem. vds: ov-nodo1 2014-07-23 14:42:58,058 WARN [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-33) domain 995e6771-fb8c-4a23-b05c-7b7b51d1fb17:ISO_DOMAIN in problem. vds: ov-nodo1 2014-07-23 14:43:35,050 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-26) Domain 6e8c2454-aa64-4f70-9bdf-0b39d31ec6c5:stg2-sata-5500G recovered from problem. vds: ov-nodo1 2014-07-23 14:43:35,051 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-26) Domain 6e8c2454-aa64-4f70-9bdf-0b39d31ec6c5:stg2-sata-5500G has recovered from problem. No active host in the DC is reporting it as problematic, so clearing the domain recovery timer. 2014-07-23 14:43:35,054 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-26) Domain 995e6771-fb8c-4a23-b05c-7b7b51d1fb17:ISO_DOMAIN recovered from problem. vds: ov-nodo1 2014-07-23 14:43:35,055 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-26) Domain 995e6771-fb8c-4a23-b05c-7b7b51d1fb17:ISO_DOMAIN has recovered from problem. No active host in the DC is reporting it as problematic, so clearing the domain recovery timer. 2014-07-23 14:44:21,237 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-1) Domain c82fbd04-72c8-4b4e-935c-f3a8ef7e4681:stg1-sas-1600G recovered from problem. vds: ov-nodo1 2014-07-23 14:44:21,237 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-1) Domain c82fbd04-72c8-4b4e-935c-f3a8ef7e4681:stg1-sas-1600G has recovered from problem. No active host in the DC is reporting it as problematic, so clearing the domain recovery timer. 2014-07-23 14:44:21,247 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-1) Domain 7289cfd1-e325-40d5-9e66-7c208d003295:iscsi-intel recovered from problem. vds: ov-nodo1 2014-07-23 14:44:21,248 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-1) Domain 7289cfd1-e325-40d5-9e66-7c208d003295:iscsi-intel has recovered from problem. No active host in the DC is reporting it as problematic, so clearing the domain recovery timer. 2014-07-23 14:45:31,058 WARN [org.ovirt.engine.core.utils.threadpool.ThreadPoolUtil] (org.ovirt.thread.pool-6-thread-1) Executing a command: java.util.concurrent.FutureTask , but note that there are 1 tasks in the queue. 2014-07-23 14:46:29,204 WARN [org.ovirt.engine.core.utils.threadpool.ThreadPoolUtil] (org.ovirt.thread.pool-6-thread-29) Executing a command: java.util.concurrent.FutureTask , but note that there are 1 tasks in the queue. 2014-07-23 14:46:35,429 WARN [org.ovirt.engine.core.utils.threadpool.ThreadPoolUtil] (org.ovirt.thread.pool-6-thread-41) Executing a command: java.util.concurrent.FutureTask , but note that there are 1 tasks in the queue. 2014-07-23 14:48:02,151 INFO [org.ovirt.engine.core.bll.OvfDataUpdater] (DefaultQuartzScheduler_Worker-43) Attempting to update VMs/Templates Ovf. 2014-07-23 14:48:02,154 INFO [org.ovirt.engine.core.bll.OvfDataUpdater] (DefaultQuartzScheduler_Worker-43) Attempting to update VM OVFs in Data Center CIT-FC 2014-07-23 14:48:02,256 INFO [org.ovirt.engine.core.bll.OvfDataUpdater] (DefaultQuartzScheduler_Worker-43) Successfully updated VM OVFs in Data Center CIT-FC 2014-07-23 14:48:02,257 INFO [org.ovirt.engine.core.bll.OvfDataUpdater] (DefaultQuartzScheduler_Worker-43) Attempting to update template OVFs in Data Center CIT-FC 2014-07-23 14:48:02,261 INFO [org.ovirt.engine.core.bll.OvfDataUpdater] (DefaultQuartzScheduler_Worker-43) Successfully updated templates OVFs in Data Center CIT-FC 2014-07-23 14:48:02,262 INFO [org.ovirt.engine.core.bll.OvfDataUpdater] (DefaultQuartzScheduler_Worker-43) Attempting to remove unneeded template/vm OVFs in Data Center CIT-FC 2014-07-23 14:48:02,264 INFO [org.ovirt.engine.core.bll.OvfDataUpdater] (DefaultQuartzScheduler_Worker-43) Successfully removed unneeded template/vm OVFs in Data Center CIT-FC 2014-07-23 14:49:16,578 WARN [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-16) domain 6e8c2454-aa64-4f70-9bdf-0b39d31ec6c5:stg2-sata-5500G in problem. vds: ov-nodo1 2014-07-23 14:49:16,580 WARN [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-16) domain 7289cfd1-e325-40d5-9e66-7c208d003295:iscsi-intel in problem. vds: ov-nodo1 2014-07-23 14:49:16,582 WARN [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-16) domain c82fbd04-72c8-4b4e-935c-f3a8ef7e4681:stg1-sas-1600G in problem. vds: ov-nodo1 2014-07-23 14:50:04,243 WARN [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-17) domain d34de59a-6df4-4fbf-8072-bbac5d6e68a3:stg2-sas-3900G in problem. vds: ov-nodo1 2014-07-23 14:50:04,245 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-17) Domain 6e8c2454-aa64-4f70-9bdf-0b39d31ec6c5:stg2-sata-5500G recovered from problem. vds: ov-nodo1 2014-07-23 14:50:04,246 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-17) Domain 6e8c2454-aa64-4f70-9bdf-0b39d31ec6c5:stg2-sata-5500G has recovered from problem. No active host in the DC is reporting it as problematic, so clearing the domain recovery timer. 2014-07-23 14:50:04,248 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-17) Domain c82fbd04-72c8-4b4e-935c-f3a8ef7e4681:stg1-sas-1600G recovered from problem. vds: ov-nodo1 2014-07-23 14:50:04,249 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-17) Domain c82fbd04-72c8-4b4e-935c-f3a8ef7e4681:stg1-sas-1600G has recovered from problem. No active host in the DC is reporting it as problematic, so clearing the domain recovery timer. 2014-07-23 14:50:04,252 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-17) Domain 7289cfd1-e325-40d5-9e66-7c208d003295:iscsi-intel recovered from problem. vds: ov-nodo1 2014-07-23 14:50:04,253 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-17) Domain 7289cfd1-e325-40d5-9e66-7c208d003295:iscsi-intel has recovered from problem. No active host in the DC is reporting it as problematic, so clearing the domain recovery timer. 2014-07-23 14:50:46,925 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-49) Domain d34de59a-6df4-4fbf-8072-bbac5d6e68a3:stg2-sas-3900G recovered from problem. vds: ov-nodo1 2014-07-23 14:50:46,926 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-49) Domain d34de59a-6df4-4fbf-8072-bbac5d6e68a3:stg2-sas-3900G has recovered from problem. No active host in the DC is reporting it as problematic, so clearing the domain recovery timer. 2014-07-23 14:53:00,535 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.GetIsoListVDSCommand] (org.ovirt.thread.pool-6-thread-4) START, GetIsoListVDSCommand( storagePoolId = a686da64-af46-435a-a7e9-3f597e9da802, ignoreFailoverLimit = false), log id: 2a5e035a 2014-07-23 14:53:07,619 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HsmGetIsoListVDSCommand] (org.ovirt.thread.pool-6-thread-4) START, HsmGetIsoListVDSCommand(HostName = ov-nodo1, HostId = 8869a834-4a65-49c1-86c8-a08f9a753594, storagePoolId=a686da64-af46-435a-a7e9-3f597e9da802), log id: 2fa3c939 2014-07-23 14:53:08,188 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HsmGetIsoListVDSCommand] (org.ovirt.thread.pool-6-thread-4) FINISH, HsmGetIsoListVDSCommand, return: {CentOS-5.10-x86_64-bin-1of9.iso={size=-1}, debian-5010-amd64-CD-1.iso={size=-1}, SW_DVD5_Win_Pro_7_64BIT_Spanish_Full_MLF_X15-71093.ISO={size=-1}, debian-testing-amd64-gnome-CD-1.iso={size=-1}, virtio-win-0.1-81.iso={size=-1}, clonezilla-live-1.2.11-23-i486.iso={size=-1}, debian-7.4.0-amd64-CD-1.iso={size=-1}, super_grub2_disk_i386_pc_2.00s2.iso={size=-1}, debian-7.1.0-i386-CD-1.iso={size=-1}, ubuntu-13.10-server-amd64.iso={size=-1}, clonezilla-live-2.2.2-32-amd64.iso={size=-1}, Hiren 15.2 con Ghost.iso={size=-1}, debian-testing-amd64-DVD-1.iso={size=-1}, virtio-win-0.1-65.iso={size=-1}, debian-6.0.9-amd64-netinst.iso={size=-1}, SW_DVD5_Windows_Svr_Std_and_DataCtr_2012_R2_64Bit_Spanish_Core_MLF_X19-05192.ISO={size=-1}}, log id: 2fa3c939 2014-07-23 14:53:08,191 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.GetIsoListVDSCommand] (org.ovirt.thread.pool-6-thread-4) FINISH, GetIsoListVDSCommand, return: {CentOS-5.10-x86_64-bin-1of9.iso={size=-1}, debian-5010-amd64-CD-1.iso={size=-1}, SW_DVD5_Win_Pro_7_64BIT_Spanish_Full_MLF_X15-71093.ISO={size=-1}, debian-testing-amd64-gnome-CD-1.iso={size=-1}, virtio-win-0.1-81.iso={size=-1}, clonezilla-live-1.2.11-23-i486.iso={size=-1}, debian-7.4.0-amd64-CD-1.iso={size=-1}, super_grub2_disk_i386_pc_2.00s2.iso={size=-1}, debian-7.1.0-i386-CD-1.iso={size=-1}, ubuntu-13.10-server-amd64.iso={size=-1}, clonezilla-live-2.2.2-32-amd64.iso={size=-1}, Hiren 15.2 con Ghost.iso={size=-1}, debian-testing-amd64-DVD-1.iso={size=-1}, virtio-win-0.1-65.iso={size=-1}, debian-6.0.9-amd64-netinst.iso={size=-1}, SW_DVD5_Windows_Svr_Std_and_DataCtr_2012_R2_64Bit_Spanish_Core_MLF_X19-05192.ISO={size=-1}}, log id: 2a5e035a 2014-07-23 14:53:08,205 INFO [org.ovirt.engine.core.bll.IsoDomainListSyncronizer] (org.ovirt.thread.pool-6-thread-4) Finished automatic refresh process for ISO file type with success, for storage domain id 995e6771-fb8c-4a23-b05c-7b7b51d1fb17. 2014-07-23 14:53:08,307 WARN [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-46) domain 6e8c2454-aa64-4f70-9bdf-0b39d31ec6c5:stg2-sata-5500G in problem. vds: ov-nodo1 2014-07-23 14:53:08,309 WARN [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-46) domain 7289cfd1-e325-40d5-9e66-7c208d003295:iscsi-intel in problem. vds: ov-nodo1 2014-07-23 14:53:08,311 WARN [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-46) domain c82fbd04-72c8-4b4e-935c-f3a8ef7e4681:stg1-sas-1600G in problem. vds: ov-nodo1 2014-07-23 14:53:08,313 WARN [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-46) domain d34de59a-6df4-4fbf-8072-bbac5d6e68a3:stg2-sas-3900G in problem. vds: ov-nodo1 2014-07-23 14:53:46,156 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-33) Domain 6e8c2454-aa64-4f70-9bdf-0b39d31ec6c5:stg2-sata-5500G recovered from problem. vds: ov-nodo1 2014-07-23 14:53:46,157 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-33) Domain 6e8c2454-aa64-4f70-9bdf-0b39d31ec6c5:stg2-sata-5500G has recovered from problem. No active host in the DC is reporting it as problematic, so clearing the domain recovery timer. 2014-07-23 14:53:46,160 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-33) Domain c82fbd04-72c8-4b4e-935c-f3a8ef7e4681:stg1-sas-1600G recovered from problem. vds: ov-nodo1 2014-07-23 14:53:46,160 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-33) Domain c82fbd04-72c8-4b4e-935c-f3a8ef7e4681:stg1-sas-1600G has recovered from problem. No active host in the DC is reporting it as problematic, so clearing the domain recovery timer. 2014-07-23 14:53:46,163 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-33) Domain 7289cfd1-e325-40d5-9e66-7c208d003295:iscsi-intel recovered from problem. vds: ov-nodo1 2014-07-23 14:53:46,164 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-33) Domain 7289cfd1-e325-40d5-9e66-7c208d003295:iscsi-intel has recovered from problem. No active host in the DC is reporting it as problematic, so clearing the domain recovery timer. 2014-07-23 14:53:46,166 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-33) Domain d34de59a-6df4-4fbf-8072-bbac5d6e68a3:stg2-sas-3900G recovered from problem. vds: ov-nodo1 2014-07-23 14:53:46,167 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-33) Domain d34de59a-6df4-4fbf-8072-bbac5d6e68a3:stg2-sas-3900G has recovered from problem. No active host in the DC is reporting it as problematic, so clearing the domain recovery timer. 2014-07-23 14:58:26,757 WARN [org.ovirt.engine.core.utils.threadpool.ThreadPoolUtil] (org.ovirt.thread.pool-6-thread-11) Executing a command: java.util.concurrent.FutureTask , but note that there are 1 tasks in the queue. 2014-07-23 14:59:45,681 WARN [org.ovirt.engine.core.utils.threadpool.ThreadPoolUtil] (org.ovirt.thread.pool-6-thread-5) Executing a command: java.util.concurrent.FutureTask , but note that there are 1 tasks in the queue. 2014-07-23 15:05:25,503 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-68) Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: User XXX@engine.uncu.edu.ar got disconnected from VM vm-2. 2014-07-23 15:06:15,873 INFO [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-41) VM vm-7 129f32cb-d8f9-4c8a-935a-8798d7ea98d3 moved from Up --> NotResponding 2014-07-23 15:06:15,922 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-41) Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: VM vm-7 is not responding. 2014-07-23 15:06:15,930 INFO [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-41) VM vm-6 27e19c92-a75d-4a38-a3c7-b95aee536d9a moved from Up --> NotResponding 2014-07-23 15:06:15,942 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-41) Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: VM vm-6 is not responding. 2014-07-23 15:06:15,968 INFO [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-41) VM vm-4 14208353-fd7d-42f5-8f1d-60299309b2b9 moved from Up --> NotResponding 2014-07-23 15:06:15,978 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-41) Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: VM vm-4 is not responding. 2014-07-23 15:06:16,002 INFO [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-41) VM vm-7 a9e68431-6edc-4ad6-bfaf-bb31c096292e moved from Up --> NotResponding 2014-07-23 15:06:16,012 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-41) Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: VM vm-7 is not responding. 2014-07-23 15:06:16,085 WARN [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-2) domain 6e8c2454-aa64-4f70-9bdf-0b39d31ec6c5:stg2-sata-5500G in problem. vds: ov-nodo1 2014-07-23 15:06:16,086 WARN [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-2) domain 7289cfd1-e325-40d5-9e66-7c208d003295:iscsi-intel in problem. vds: ov-nodo1 2014-07-23 15:06:16,087 WARN [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-2) domain c82fbd04-72c8-4b4e-935c-f3a8ef7e4681:stg1-sas-1600G in problem. vds: ov-nodo1 2014-07-23 15:06:16,089 WARN [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-2) domain d34de59a-6df4-4fbf-8072-bbac5d6e68a3:stg2-sas-3900G in problem. vds: ov-nodo1 2014-07-23 15:06:16,090 WARN [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-2) domain 995e6771-fb8c-4a23-b05c-7b7b51d1fb17:ISO_DOMAIN in problem. vds: ov-nodo1 2014-07-23 15:07:02,846 INFO [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-50) VM vm-7 129f32cb-d8f9-4c8a-935a-8798d7ea98d3 moved from NotResponding --> Up 2014-07-23 15:07:02,847 INFO [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-50) VM vm-6 27e19c92-a75d-4a38-a3c7-b95aee536d9a moved from NotResponding --> Up 2014-07-23 15:07:02,847 INFO [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-50) VM vm-4 14208353-fd7d-42f5-8f1d-60299309b2b9 moved from NotResponding --> Up 2014-07-23 15:07:02,848 INFO [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-50) VM vm-7 a9e68431-6edc-4ad6-bfaf-bb31c096292e moved from NotResponding --> Up 2014-07-23 15:07:07,519 INFO [org.ovirt.engine.core.bll.SetVmTicketCommand] (ajp--127.0.0.1-8702-12) [496473e3] Running command: SetVmTicketCommand internal: false. Entities affected : ID: 2fc82746-6a69-4044-bcfd-bd92f2329c07 Type: VM 2014-07-23 15:07:07,524 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.SetVmTicketVDSCommand] (ajp--127.0.0.1-8702-12) [496473e3] START, SetVmTicketVDSCommand(HostName = ov-nodo4, HostId = 1cf547f7-deca-4fdc-bd32-1af20b8fc0ce, vmId=2fc82746-6a69-4044-bcfd-bd92f2329c07, ticket=AZXEQjDkxcxV, validTime=120,m userName=XXX, userId=3599fc5c-e65a-1032-83a3-916d82337fdd), log id: 1e5156ad 2014-07-23 15:07:07,569 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.SetVmTicketVDSCommand] (ajp--127.0.0.1-8702-12) [496473e3] FINISH, SetVmTicketVDSCommand, log id: 1e5156ad 2014-07-23 15:07:07,589 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-12) [496473e3] Correlation ID: 496473e3, Call Stack: null, Custom Event ID: -1, Message: user XXX initiated console session for VM vm-8 2014-07-23 15:07:12,598 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-65) Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: User XXX@engine.uncu.edu.ar is connected to VM vm-8. 2014-07-23 15:07:56,810 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-10) Domain 6e8c2454-aa64-4f70-9bdf-0b39d31ec6c5:stg2-sata-5500G recovered from problem. vds: ov-nodo1 2014-07-23 15:07:56,810 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-10) Domain 6e8c2454-aa64-4f70-9bdf-0b39d31ec6c5:stg2-sata-5500G has recovered from problem. No active host in the DC is reporting it as problematic, so clearing the domain recovery timer. 2014-07-23 15:07:56,813 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-10) Domain d34de59a-6df4-4fbf-8072-bbac5d6e68a3:stg2-sas-3900G recovered from problem. vds: ov-nodo1 2014-07-23 15:07:56,814 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-10) Domain d34de59a-6df4-4fbf-8072-bbac5d6e68a3:stg2-sas-3900G has recovered from problem. No active host in the DC is reporting it as problematic, so clearing the domain recovery timer. 2014-07-23 15:07:58,680 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-45) Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: User XXX@engine.uncu.edu.ar got disconnected from VM vm-8. 2014-07-23 15:08:00,728 WARN [org.ovirt.engine.core.bll.SetVmTicketCommand] (ajp--127.0.0.1-8702-9) [1b9c4a02] User "3599fc5c-e65a-1032-83a3-916d82337fdd" is trying to take the console of virtual machine "2da91225-9e6c-4955-8b25-3c22f2e45abf", but the console is already taken by user "9e22d706-226b-4b16-88c3-39c59259ce4c". 2014-07-23 15:08:00,732 WARN [org.ovirt.engine.core.bll.SetVmTicketCommand] (ajp--127.0.0.1-8702-9) [1b9c4a02] User "3599fc5c-e65a-1032-83a3-916d82337fdd" is trying to take the console of virtual machine "2da91225-9e6c-4955-8b25-3c22f2e45abf", but the console is already taken by user "9e22d706-226b-4b16-88c3-39c59259ce4c". 2014-07-23 15:08:00,733 INFO [org.ovirt.engine.core.bll.SetVmTicketCommand] (ajp--127.0.0.1-8702-9) [1b9c4a02] Running command: SetVmTicketCommand internal: false. Entities affected : ID: 2da91225-9e6c-4955-8b25-3c22f2e45abf Type: VM, ID: 2da91225-9e6c-4955-8b25-3c22f2e45abf Type: VM 2014-07-23 15:08:00,739 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.SetVmTicketVDSCommand] (ajp--127.0.0.1-8702-9) [1b9c4a02] START, SetVmTicketVDSCommand(HostName = ov-nodo1, HostId = 8869a834-4a65-49c1-86c8-a08f9a753594, vmId=2da91225-9e6c-4955-8b25-3c22f2e45abf, ticket=q+dZiw0sPdmd, validTime=120,m userName=XXX, userId=3599fc5c-e65a-1032-83a3-916d82337fdd), log id: 32df3cfd 2014-07-23 15:08:14,510 WARN [org.ovirt.engine.core.bll.SetVmTicketCommand] (ajp--127.0.0.1-8702-8) [ffe5963] User "3599fc5c-e65a-1032-83a3-916d82337fdd" is trying to take the console of virtual machine "2da91225-9e6c-4955-8b25-3c22f2e45abf", but the console is already taken by user "9e22d706-226b-4b16-88c3-39c59259ce4c". 2014-07-23 15:08:14,514 WARN [org.ovirt.engine.core.bll.SetVmTicketCommand] (ajp--127.0.0.1-8702-8) [ffe5963] User "3599fc5c-e65a-1032-83a3-916d82337fdd" is trying to take the console of virtual machine "2da91225-9e6c-4955-8b25-3c22f2e45abf", but the console is already taken by user "9e22d706-226b-4b16-88c3-39c59259ce4c". 2014-07-23 15:08:14,515 INFO [org.ovirt.engine.core.bll.SetVmTicketCommand] (ajp--127.0.0.1-8702-8) [ffe5963] Running command: SetVmTicketCommand internal: false. Entities affected : ID: 2da91225-9e6c-4955-8b25-3c22f2e45abf Type: VM, ID: 2da91225-9e6c-4955-8b25-3c22f2e45abf Type: VM 2014-07-23 15:08:29,767 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.SetVmTicketVDSCommand] (ajp--127.0.0.1-8702-9) [1b9c4a02] FINISH, SetVmTicketVDSCommand, log id: 32df3cfd 2014-07-23 15:08:29,773 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.SetVmTicketVDSCommand] (ajp--127.0.0.1-8702-8) [ffe5963] START, SetVmTicketVDSCommand(HostName = ov-nodo1, HostId = 8869a834-4a65-49c1-86c8-a08f9a753594, vmId=2da91225-9e6c-4955-8b25-3c22f2e45abf, ticket=OXDTv8fF1dek, validTime=120,m userName=XXX, userId=3599fc5c-e65a-1032-83a3-916d82337fdd), log id: ad3c24b 2014-07-23 15:08:29,778 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-9) [1b9c4a02] Correlation ID: 1b9c4a02, Call Stack: null, Custom Event ID: -1, Message: user XXX initiated console session for VM vm-9 2014-07-23 15:08:29,909 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.SetVmTicketVDSCommand] (ajp--127.0.0.1-8702-8) [ffe5963] FINISH, SetVmTicketVDSCommand, log id: ad3c24b 2014-07-23 15:08:29,919 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-8) [ffe5963] Correlation ID: ffe5963, Call Stack: null, Custom Event ID: -1, Message: user XXX initiated console session for VM vm-9 2014-07-23 15:08:38,020 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-46) Domain c82fbd04-72c8-4b4e-935c-f3a8ef7e4681:stg1-sas-1600G recovered from problem. vds: ov-nodo1 2014-07-23 15:08:38,021 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-46) Domain c82fbd04-72c8-4b4e-935c-f3a8ef7e4681:stg1-sas-1600G has recovered from problem. No active host in the DC is reporting it as problematic, so clearing the domain recovery timer. 2014-07-23 15:08:38,024 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-46) Domain 7289cfd1-e325-40d5-9e66-7c208d003295:iscsi-intel recovered from problem. vds: ov-nodo1 2014-07-23 15:08:38,024 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-46) Domain 7289cfd1-e325-40d5-9e66-7c208d003295:iscsi-intel has recovered from problem. No active host in the DC is reporting it as problematic, so clearing the domain recovery timer. 2014-07-23 15:08:38,027 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-46) Domain 995e6771-fb8c-4a23-b05c-7b7b51d1fb17:ISO_DOMAIN recovered from problem. vds: ov-nodo1 2014-07-23 15:08:38,027 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (org.ovirt.thread.pool-6-thread-46) Domain 995e6771-fb8c-4a23-b05c-7b7b51d1fb17:ISO_DOMAIN has recovered from problem. No active host in the DC is reporting it as problematic, so clearing the domain recovery timer. 2014-07-23 15:08:44,329 WARN [org.ovirt.engine.core.utils.threadpool.ThreadPoolUtil] (org.ovirt.thread.pool-6-thread-49) Executing a command: java.util.concurrent.FutureTask , but note that there are 1 tasks in the queue.