[ovirt-users] Disk migration eats all CPU, vms running in SPM become unresponsive
Federico Alberto Sayd
fsayd at uncu.edu.ar
Thu Jul 24 16:16:25 UTC 2014
Hello:
I am experiencing some troubles with ovirt nodes:
When a node is selected as SPM and I move a disk between storage
domains, it seems that migration process eats all CPU and some VMs
(running on the SPM) hang, others lose network connectivity. The events
tab at Ovirt Engine reports the CPU exceeding the defined threshold and
then reports that VMs in such host (SPM) are not responding.
How can I debug this? Why do the VMs become unresponsive or lost network
connectivity when the host CPU goes too high?
I have attached a screenshot of the ovirt-engine events, and the
relevant engine.log
My setup:
oVirt Engine Version:
3.4.0-1.el6 (Centos 6.5)
Nodes:
Centos 6.5
vdsm-4.14.6-0.el6
libvirt-0.10.2-29.el6_5.9
KVM: 0.12.1.2 - 2.415.el6_5.10 (jenkins build)
Regards
Federico
-------------- next part --------------
A non-text attachment was scrubbed...
Name: engine-error.png
Type: image/png
Size: 111639 bytes
Desc: not available
URL: <http://lists.ovirt.org/pipermail/users/attachments/20140724/33198d60/attachment-0001.png>
-------------- next part --------------
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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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.
More information about the Users
mailing list