[ovirt-users] Cannot clone snapshots

Cristian Mammoli c.mammoli at apra.it
Tue Jan 26 14:02:32 UTC 2016


Hi, I tried this script https://github.com/wefixit-AT/oVirtBackup
which basically does:
Snapshot a vm
clone the snapshot
delete the snapshot
export the clone to export domain
delete the clone

It worked fine for 4 vms then exited with error:
Message: VDSM kvm02 command failed: low level Image copy failed
VDSM command failed: Image does not exist in domain: 
u'image=a651c514-a81b-4cfc-a9bc-0bc4caf51568, 
domain=239c7309-7e4c-4545-8137-6bf1d43cad71'

Now I'm not able to clone snapshots anymore, not even manually everytime 
I get the same error:
This is engine.log when I snapshot the vm:

2016-01-26 14:58:32,984 WARN 
[org.ovirt.engine.core.bll.scheduling.policyunits.EvenGuestDistributionBalancePolicyUnit] 
(DefaultQuartzScheduler_Worker-46) [5de5361] There is no host with less 
than 8 running guests
2016-01-26 14:58:32,985 WARN 
[org.ovirt.engine.core.bll.scheduling.policyunits.CpuAndMemoryBalancingPolicyUnit] 
(DefaultQuartzScheduler_Worker-46) [5de5361] All hosts are 
over-utilized, can't balance the cluster 'Default' using the primary method
2016-01-26 14:58:38,685 INFO 
[org.ovirt.engine.core.bll.CreateAllSnapshotsFromVmCommand] (default 
task-1) [5b009390] Lock Acquired to object 
'EngineLock:{exclusiveLocks='[4e683012-8895-43da-b3e1-6d6271f4d829=<VM, 
ACTION_TYPE_FAILED_SNAPSHOT_IS_BEING_TAKEN_FOR_VM$VmName hpserver>]', 
sharedLocks='null'}'
2016-01-26 14:58:39,007 INFO 
[org.ovirt.engine.core.bll.CreateAllSnapshotsFromVmCommand] 
(org.ovirt.thread.pool-8-thread-12) [5b009390] Running command: 
CreateAllSnapshotsFromVmCommand internal: false. Entities affected :  
ID: 4e683012-8895-43da-b3e1-6d6271f4d829 Type: VMAction group 
MANIPULATE_VM_SNAPSHOTS with role type USER
2016-01-26 14:58:39,028 INFO 
[org.ovirt.engine.core.bll.CreateSnapshotCommand] 
(org.ovirt.thread.pool-8-thread-12) [217c647e] Running command: 
CreateSnapshotCommand internal: true. Entities affected :  ID: 
00000000-0000-0000-0000-000000000000 Type: Storage
2016-01-26 14:58:39,074 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.CreateSnapshotVDSCommand] 
(org.ovirt.thread.pool-8-thread-12) [217c647e] START, 
CreateSnapshotVDSCommand( 
CreateSnapshotVDSCommandParameters:{runAsync='true', 
storagePoolId='00000001-0001-0001-0001-000000000296', 
ignoreFailoverLimit='false', 
storageDomainId='239c7309-7e4c-4545-8137-6bf1d43cad71', 
imageGroupId='42e212c1-f669-43e1-8f90-20baf0c3f58c', 
imageSizeInBytes='37580963840', volumeFormat='COW', 
newImageId='5d8f7880-9125-4c91-ba04-532901d1d805', 
newImageDescription='', imageInitialSizeInBytes='0', 
imageId='449e8b88-ab34-4cf8-bc91-00128c35dc65', 
sourceImageGroupId='42e212c1-f669-43e1-8f90-20baf0c3f58c'}), log id: 
1113aa14
2016-01-26 14:58:39,078 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.CreateSnapshotVDSCommand] 
(org.ovirt.thread.pool-8-thread-12) [217c647e] -- 
executeIrsBrokerCommand: calling 'createVolume' with two new parameters: 
description and UUID
2016-01-26 14:58:40,351 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.CreateSnapshotVDSCommand] 
(org.ovirt.thread.pool-8-thread-12) [217c647e] FINISH, 
CreateSnapshotVDSCommand, return: 5d8f7880-9125-4c91-ba04-532901d1d805, 
log id: 1113aa14
2016-01-26 14:58:40,360 INFO 
[org.ovirt.engine.core.bll.tasks.CommandAsyncTask] 
(org.ovirt.thread.pool-8-thread-12) [217c647e] CommandAsyncTask::Adding 
CommandMultiAsyncTasks object for command 
'8f3ccf29-3056-4ab0-bc11-b987814fe5fd'
2016-01-26 14:58:40,360 INFO 
[org.ovirt.engine.core.bll.CommandMultiAsyncTasks] 
(org.ovirt.thread.pool-8-thread-12) [217c647e] 
CommandMultiAsyncTasks::AttachTask: Attaching task 
'293a6312-8c4f-4c89-a3f7-2f9f0557a9b8' to command 
'8f3ccf29-3056-4ab0-bc11-b987814fe5fd'.
2016-01-26 14:58:40,382 INFO 
[org.ovirt.engine.core.bll.tasks.AsyncTaskManager] 
(org.ovirt.thread.pool-8-thread-12) [217c647e] Adding task 
'293a6312-8c4f-4c89-a3f7-2f9f0557a9b8' (Parent Command 
'CreateAllSnapshotsFromVm', Parameters Type 
'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters'), polling 
hasn't started yet..
2016-01-26 14:58:40,420 INFO 
[org.ovirt.engine.core.bll.CreateSnapshotCommand] 
(org.ovirt.thread.pool-8-thread-12) [2adcf7fc] Running command: 
CreateSnapshotCommand internal: true. Entities affected :  ID: 
00000000-0000-0000-0000-000000000000 Type: Storage
2016-01-26 14:58:40,434 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.CreateSnapshotVDSCommand] 
(org.ovirt.thread.pool-8-thread-12) [2adcf7fc] START, 
CreateSnapshotVDSCommand( 
CreateSnapshotVDSCommandParameters:{runAsync='true', 
storagePoolId='00000001-0001-0001-0001-000000000296', 
ignoreFailoverLimit='false', 
storageDomainId='239c7309-7e4c-4545-8137-6bf1d43cad71', 
imageGroupId='dd1f13d8-4fb1-4f48-b7b6-cb912c0c1437', 
imageSizeInBytes='108447924224', volumeFormat='COW', 
newImageId='88a9ab18-7d4c-42f0-9067-0241b64cb7d0', 
newImageDescription='', imageInitialSizeInBytes='0', 
imageId='0856943c-c714-43a5-8f26-087143131d74', 
sourceImageGroupId='dd1f13d8-4fb1-4f48-b7b6-cb912c0c1437'}), log id: 
5b8489d6
2016-01-26 14:58:40,436 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.CreateSnapshotVDSCommand] 
(org.ovirt.thread.pool-8-thread-12) [2adcf7fc] -- 
executeIrsBrokerCommand: calling 'createVolume' with two new parameters: 
description and UUID
2016-01-26 14:58:41,267 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.CreateSnapshotVDSCommand] 
(org.ovirt.thread.pool-8-thread-12) [2adcf7fc] FINISH, 
CreateSnapshotVDSCommand, return: 88a9ab18-7d4c-42f0-9067-0241b64cb7d0, 
log id: 5b8489d6
2016-01-26 14:58:41,288 INFO 
[org.ovirt.engine.core.bll.CommandMultiAsyncTasks] 
(org.ovirt.thread.pool-8-thread-12) [2adcf7fc] 
CommandMultiAsyncTasks::AttachTask: Attaching task 
'010eec77-3b20-483c-bdd3-e9a8912f7ba5' to command 
'8f3ccf29-3056-4ab0-bc11-b987814fe5fd'.
2016-01-26 14:58:41,425 INFO 
[org.ovirt.engine.core.bll.tasks.AsyncTaskManager] 
(org.ovirt.thread.pool-8-thread-12) [2adcf7fc] Adding task 
'010eec77-3b20-483c-bdd3-e9a8912f7ba5' (Parent Command 
'CreateAllSnapshotsFromVm', Parameters Type 
'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters'), polling 
hasn't started yet..
2016-01-26 14:58:41,499 INFO 
[org.ovirt.engine.core.bll.CreateSnapshotCommand] 
(org.ovirt.thread.pool-8-thread-12) [a3e8512] Running command: 
CreateSnapshotCommand internal: true. Entities affected :  ID: 
00000000-0000-0000-0000-000000000000 Type: Storage
2016-01-26 14:58:41,613 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.CreateSnapshotVDSCommand] 
(org.ovirt.thread.pool-8-thread-12) [a3e8512] START, 
CreateSnapshotVDSCommand( 
CreateSnapshotVDSCommandParameters:{runAsync='true', 
storagePoolId='00000001-0001-0001-0001-000000000296', 
ignoreFailoverLimit='false', 
storageDomainId='239c7309-7e4c-4545-8137-6bf1d43cad71', 
imageGroupId='d98b8313-de2f-477a-94f8-78026497612b', 
imageSizeInBytes='108447924224', volumeFormat='COW', 
newImageId='dbbae52f-a408-41a4-8e6c-0c1919df5c93', 
newImageDescription='', imageInitialSizeInBytes='0', 
imageId='dd30f129-e8d0-4155-9c63-6ac1ee76fa8e', 
sourceImageGroupId='d98b8313-de2f-477a-94f8-78026497612b'}), log id: 
7e1deb44
2016-01-26 14:58:41,620 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.CreateSnapshotVDSCommand] 
(org.ovirt.thread.pool-8-thread-12) [a3e8512] -- 
executeIrsBrokerCommand: calling 'createVolume' with two new parameters: 
description and UUID
2016-01-26 14:58:43,843 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.CreateSnapshotVDSCommand] 
(org.ovirt.thread.pool-8-thread-12) [a3e8512] FINISH, 
CreateSnapshotVDSCommand, return: dbbae52f-a408-41a4-8e6c-0c1919df5c93, 
log id: 7e1deb44
2016-01-26 14:58:43,852 INFO 
[org.ovirt.engine.core.bll.CommandMultiAsyncTasks] 
(org.ovirt.thread.pool-8-thread-12) [a3e8512] 
CommandMultiAsyncTasks::AttachTask: Attaching task 
'9f0ac94f-deb9-4662-824b-f7144c869af0' to command 
'8f3ccf29-3056-4ab0-bc11-b987814fe5fd'.
2016-01-26 14:58:43,871 INFO 
[org.ovirt.engine.core.bll.tasks.AsyncTaskManager] 
(org.ovirt.thread.pool-8-thread-12) [a3e8512] Adding task 
'9f0ac94f-deb9-4662-824b-f7144c869af0' (Parent Command 
'CreateAllSnapshotsFromVm', Parameters Type 
'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters'), polling 
hasn't started yet..
2016-01-26 14:58:43,986 INFO 
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] 
(org.ovirt.thread.pool-8-thread-12) [a3e8512] Correlation ID: 5b009390, 
Job ID: b76122a8-a780-47e4-9c63-eac6b7f8b6e4, Call Stack: null, Custom 
Event ID: -1, Message: Snapshot 'test_snap' creation for VM 'hpserver' 
was initiated by rfocesq at omme.net@omme.net.
2016-01-26 14:58:43,987 INFO 
[org.ovirt.engine.core.bll.tasks.SPMAsyncTask] 
(org.ovirt.thread.pool-8-thread-12) [a3e8512] 
BaseAsyncTask::startPollingTask: Starting to poll task 
'293a6312-8c4f-4c89-a3f7-2f9f0557a9b8'.
2016-01-26 14:58:43,987 INFO 
[org.ovirt.engine.core.bll.tasks.SPMAsyncTask] 
(org.ovirt.thread.pool-8-thread-12) [a3e8512] 
BaseAsyncTask::startPollingTask: Starting to poll task 
'010eec77-3b20-483c-bdd3-e9a8912f7ba5'.
2016-01-26 14:58:43,987 INFO 
[org.ovirt.engine.core.bll.tasks.SPMAsyncTask] 
(org.ovirt.thread.pool-8-thread-12) [a3e8512] 
BaseAsyncTask::startPollingTask: Starting to poll task 
'9f0ac94f-deb9-4662-824b-f7144c869af0'.
2016-01-26 14:58:46,992 INFO 
[org.ovirt.engine.core.bll.tasks.AsyncTaskManager] 
(DefaultQuartzScheduler_Worker-2) [4c17fe49] Polling and updating Async 
Tasks: 3 tasks, 3 tasks to poll now
2016-01-26 14:58:48,951 INFO 
[org.ovirt.engine.core.bll.tasks.SPMAsyncTask] 
(DefaultQuartzScheduler_Worker-2) [4c17fe49] SPMAsyncTask::PollTask: 
Polling task '010eec77-3b20-483c-bdd3-e9a8912f7ba5' (Parent Command 
'CreateAllSnapshotsFromVm', Parameters Type 
'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') returned 
status 'finished', result 'success'.
2016-01-26 14:58:48,960 INFO 
[org.ovirt.engine.core.bll.tasks.SPMAsyncTask] 
(DefaultQuartzScheduler_Worker-2) [4c17fe49] 
BaseAsyncTask::onTaskEndSuccess: Task 
'010eec77-3b20-483c-bdd3-e9a8912f7ba5' (Parent Command 
'CreateAllSnapshotsFromVm', Parameters Type 
'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') ended 
successfully.
2016-01-26 14:58:48,965 INFO 
[org.ovirt.engine.core.bll.CommandMultiAsyncTasks] 
(DefaultQuartzScheduler_Worker-2) [4c17fe49] Task with DB Task ID 
'05694254-0fcc-4e77-95ac-ec4f4482c6f8' and VDSM Task ID 
'9f0ac94f-deb9-4662-824b-f7144c869af0' is in state Polling. End action 
for command 8f3ccf29-3056-4ab0-bc11-b987814fe5fd will proceed when all 
the entity's tasks are completed.
2016-01-26 14:58:48,965 INFO 
[org.ovirt.engine.core.bll.tasks.SPMAsyncTask] 
(DefaultQuartzScheduler_Worker-2) [4c17fe49] SPMAsyncTask::PollTask: 
Polling task '9f0ac94f-deb9-4662-824b-f7144c869af0' (Parent Command 
'CreateAllSnapshotsFromVm', Parameters Type 
'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') returned 
status 'running'.
2016-01-26 14:58:48,965 INFO 
[org.ovirt.engine.core.bll.tasks.SPMAsyncTask] 
(DefaultQuartzScheduler_Worker-2) [4c17fe49] SPMAsyncTask::PollTask: 
Polling task '293a6312-8c4f-4c89-a3f7-2f9f0557a9b8' (Parent Command 
'CreateAllSnapshotsFromVm', Parameters Type 
'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') returned 
status 'finished', result 'success'.
2016-01-26 14:58:48,971 INFO 
[org.ovirt.engine.core.bll.tasks.SPMAsyncTask] 
(DefaultQuartzScheduler_Worker-2) [4c17fe49] 
BaseAsyncTask::onTaskEndSuccess: Task 
'293a6312-8c4f-4c89-a3f7-2f9f0557a9b8' (Parent Command 
'CreateAllSnapshotsFromVm', Parameters Type 
'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') ended 
successfully.
2016-01-26 14:58:48,972 INFO 
[org.ovirt.engine.core.bll.CommandMultiAsyncTasks] 
(DefaultQuartzScheduler_Worker-2) [4c17fe49] Task with DB Task ID 
'05694254-0fcc-4e77-95ac-ec4f4482c6f8' and VDSM Task ID 
'9f0ac94f-deb9-4662-824b-f7144c869af0' is in state Polling. End action 
for command 8f3ccf29-3056-4ab0-bc11-b987814fe5fd will proceed when all 
the entity's tasks are completed.
2016-01-26 14:58:48,972 INFO 
[org.ovirt.engine.core.bll.tasks.AsyncTaskManager] 
(DefaultQuartzScheduler_Worker-2) [4c17fe49] Finished polling Tasks, 
will poll again in 10 seconds.
2016-01-26 14:59:00,359 INFO 
[org.ovirt.engine.core.bll.tasks.SPMAsyncTask] 
(DefaultQuartzScheduler_Worker-41) [] BaseAsyncTask::onTaskEndSuccess: 
Task '010eec77-3b20-483c-bdd3-e9a8912f7ba5' (Parent Command 
'CreateAllSnapshotsFromVm', Parameters Type 
'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') ended 
successfully.
2016-01-26 14:59:00,360 INFO 
[org.ovirt.engine.core.bll.CommandMultiAsyncTasks] 
(DefaultQuartzScheduler_Worker-41) [] Task with DB Task ID 
'05694254-0fcc-4e77-95ac-ec4f4482c6f8' and VDSM Task ID 
'9f0ac94f-deb9-4662-824b-f7144c869af0' is in state Polling. End action 
for command 8f3ccf29-3056-4ab0-bc11-b987814fe5fd will proceed when all 
the entity's tasks are completed.
2016-01-26 14:59:00,361 INFO 
[org.ovirt.engine.core.bll.tasks.SPMAsyncTask] 
(DefaultQuartzScheduler_Worker-41) [] SPMAsyncTask::PollTask: Polling 
task '9f0ac94f-deb9-4662-824b-f7144c869af0' (Parent Command 
'CreateAllSnapshotsFromVm', Parameters Type 
'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') returned 
status 'finished', result 'success'.
2016-01-26 14:59:00,368 INFO 
[org.ovirt.engine.core.bll.tasks.SPMAsyncTask] 
(DefaultQuartzScheduler_Worker-41) [] BaseAsyncTask::onTaskEndSuccess: 
Task '9f0ac94f-deb9-4662-824b-f7144c869af0' (Parent Command 
'CreateAllSnapshotsFromVm', Parameters Type 
'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') ended 
successfully.
2016-01-26 14:59:00,389 INFO 
[org.ovirt.engine.core.bll.tasks.CommandAsyncTask] 
(DefaultQuartzScheduler_Worker-41) [] 
CommandAsyncTask::endActionIfNecessary: All tasks of command 
'8f3ccf29-3056-4ab0-bc11-b987814fe5fd' has ended -> executing 'endAction'
2016-01-26 14:59:00,389 INFO 
[org.ovirt.engine.core.bll.tasks.CommandAsyncTask] 
(DefaultQuartzScheduler_Worker-41) [] CommandAsyncTask::endAction: 
Ending action for '3' tasks (command ID: 
'8f3ccf29-3056-4ab0-bc11-b987814fe5fd'): calling endAction '.
2016-01-26 14:59:00,390 INFO 
[org.ovirt.engine.core.bll.tasks.CommandAsyncTask] 
(org.ovirt.thread.pool-8-thread-25) [] 
CommandAsyncTask::endCommandAction [within thread] context: Attempting 
to endAction 'CreateAllSnapshotsFromVm', executionIndex: '0'
2016-01-26 14:59:00,541 INFO 
[org.ovirt.engine.core.bll.CreateAllSnapshotsFromVmCommand] 
(org.ovirt.thread.pool-8-thread-25) [] Ending command 
'org.ovirt.engine.core.bll.CreateAllSnapshotsFromVmCommand' successfully.
2016-01-26 14:59:00,647 INFO 
[org.ovirt.engine.core.vdsbroker.vdsbroker.SnapshotVDSCommand] 
(org.ovirt.thread.pool-8-thread-25) [] START, 
SnapshotVDSCommand(HostName = kvm01, 
SnapshotVDSCommandParameters:{runAsync='true', 
hostId='f18a051d-b893-41f7-9e97-0037abc7180d', 
vmId='4e683012-8895-43da-b3e1-6d6271f4d829'}), log id: 459fcd47
2016-01-26 14:59:05,465 INFO 
[org.ovirt.engine.core.vdsbroker.vdsbroker.SnapshotVDSCommand] 
(org.ovirt.thread.pool-8-thread-25) [] FINISH, SnapshotVDSCommand, log 
id: 459fcd47
2016-01-26 14:59:05,483 INFO 
[org.ovirt.engine.core.bll.CreateSnapshotCommand] 
(org.ovirt.thread.pool-8-thread-25) [2adcf7fc] Ending command 
'org.ovirt.engine.core.bll.CreateSnapshotCommand' successfully.
2016-01-26 14:59:05,506 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] 
(org.ovirt.thread.pool-8-thread-25) [2adcf7fc] START, 
GetImageInfoVDSCommand( 
GetImageInfoVDSCommandParameters:{runAsync='true', 
storagePoolId='00000001-0001-0001-0001-000000000296', 
ignoreFailoverLimit='false', 
storageDomainId='239c7309-7e4c-4545-8137-6bf1d43cad71', 
imageGroupId='dd1f13d8-4fb1-4f48-b7b6-cb912c0c1437', 
imageId='88a9ab18-7d4c-42f0-9067-0241b64cb7d0'}), log id: 17bd1fc
2016-01-26 14:59:06,562 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] 
(org.ovirt.thread.pool-8-thread-25) [2adcf7fc] FINISH, 
GetImageInfoVDSCommand, return: 
org.ovirt.engine.core.common.businessentities.storage.DiskImage at ce4f3490, log 
id: 17bd1fc
2016-01-26 14:59:06,607 INFO 
[org.ovirt.engine.core.bll.CreateSnapshotCommand] 
(org.ovirt.thread.pool-8-thread-25) [a3e8512] Ending command 
'org.ovirt.engine.core.bll.CreateSnapshotCommand' successfully.
2016-01-26 14:59:06,626 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] 
(org.ovirt.thread.pool-8-thread-25) [a3e8512] START, 
GetImageInfoVDSCommand( 
GetImageInfoVDSCommandParameters:{runAsync='true', 
storagePoolId='00000001-0001-0001-0001-000000000296', 
ignoreFailoverLimit='false', 
storageDomainId='239c7309-7e4c-4545-8137-6bf1d43cad71', 
imageGroupId='d98b8313-de2f-477a-94f8-78026497612b', 
imageId='dbbae52f-a408-41a4-8e6c-0c1919df5c93'}), log id: 6e1489cb
2016-01-26 14:59:08,023 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] 
(org.ovirt.thread.pool-8-thread-25) [a3e8512] FINISH, 
GetImageInfoVDSCommand, return: 
org.ovirt.engine.core.common.businessentities.storage.DiskImage at 3294df55, log 
id: 6e1489cb
2016-01-26 14:59:08,077 INFO 
[org.ovirt.engine.core.bll.CreateSnapshotCommand] 
(org.ovirt.thread.pool-8-thread-25) [217c647e] Ending command 
'org.ovirt.engine.core.bll.CreateSnapshotCommand' successfully.
2016-01-26 14:59:08,092 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] 
(org.ovirt.thread.pool-8-thread-25) [217c647e] START, 
GetImageInfoVDSCommand( 
GetImageInfoVDSCommandParameters:{runAsync='true', 
storagePoolId='00000001-0001-0001-0001-000000000296', 
ignoreFailoverLimit='false', 
storageDomainId='239c7309-7e4c-4545-8137-6bf1d43cad71', 
imageGroupId='42e212c1-f669-43e1-8f90-20baf0c3f58c', 
imageId='5d8f7880-9125-4c91-ba04-532901d1d805'}), log id: 1dae9b25
2016-01-26 14:59:08,388 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] 
(org.ovirt.thread.pool-8-thread-25) [217c647e] FINISH, 
GetImageInfoVDSCommand, return: 
org.ovirt.engine.core.common.businessentities.storage.DiskImage at 4bd18557, log 
id: 1dae9b25
2016-01-26 14:59:08,419 INFO 
[org.ovirt.engine.core.bll.CreateAllSnapshotsFromVmCommand] 
(org.ovirt.thread.pool-8-thread-25) [] Lock freed to object 
'EngineLock:{exclusiveLocks='[4e683012-8895-43da-b3e1-6d6271f4d829=<VM, 
ACTION_TYPE_FAILED_SNAPSHOT_IS_BEING_TAKEN_FOR_VM$VmName hpserver>]', 
sharedLocks='null'}'
2016-01-26 14:59:08,503 INFO 
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] 
(org.ovirt.thread.pool-8-thread-25) [] Correlation ID: 5b009390, Job ID: 
b76122a8-a780-47e4-9c63-eac6b7f8b6e4, Call Stack: null, Custom Event ID: 
-1, Message: Snapshot 'test_snap' creation for VM 'hpserver' has been 
completed.
2016-01-26 14:59:08,504 INFO 
[org.ovirt.engine.core.bll.tasks.CommandAsyncTask] 
(org.ovirt.thread.pool-8-thread-25) [] 
CommandAsyncTask::HandleEndActionResult [within thread]: endAction for 
action type 'CreateAllSnapshotsFromVm' completed, handling the result.
2016-01-26 14:59:08,504 INFO 
[org.ovirt.engine.core.bll.tasks.CommandAsyncTask] 
(org.ovirt.thread.pool-8-thread-25) [] 
CommandAsyncTask::HandleEndActionResult [within thread]: endAction for 
action type 'CreateAllSnapshotsFromVm' succeeded, clearing tasks.
2016-01-26 14:59:08,510 INFO 
[org.ovirt.engine.core.bll.tasks.SPMAsyncTask] 
(org.ovirt.thread.pool-8-thread-25) [] SPMAsyncTask::ClearAsyncTask: 
Attempting to clear task '010eec77-3b20-483c-bdd3-e9a8912f7ba5'
2016-01-26 14:59:08,513 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] 
(org.ovirt.thread.pool-8-thread-25) [] START, SPMClearTaskVDSCommand( 
SPMTaskGuidBaseVDSCommandParameters:{runAsync='true', 
storagePoolId='00000001-0001-0001-0001-000000000296', 
ignoreFailoverLimit='false', 
taskId='010eec77-3b20-483c-bdd3-e9a8912f7ba5'}), log id: 14a34aa3
2016-01-26 14:59:08,514 INFO 
[org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] 
(org.ovirt.thread.pool-8-thread-25) [] START, 
HSMClearTaskVDSCommand(HostName = kvm02, 
HSMTaskGuidBaseVDSCommandParameters:{runAsync='true', 
hostId='572aa833-37fb-4c4b-9576-9d367def2d04', 
taskId='010eec77-3b20-483c-bdd3-e9a8912f7ba5'}), log id: 3c0fbdc7
2016-01-26 14:59:08,959 INFO 
[org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] 
(org.ovirt.thread.pool-8-thread-25) [] FINISH, HSMClearTaskVDSCommand, 
log id: 3c0fbdc7
2016-01-26 14:59:08,960 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] 
(org.ovirt.thread.pool-8-thread-25) [] FINISH, SPMClearTaskVDSCommand, 
log id: 14a34aa3
2016-01-26 14:59:08,973 INFO 
[org.ovirt.engine.core.bll.tasks.SPMAsyncTask] 
(org.ovirt.thread.pool-8-thread-25) [] BaseAsyncTask::removeTaskFromDB: 
Removed task '010eec77-3b20-483c-bdd3-e9a8912f7ba5' from DataBase
2016-01-26 14:59:08,974 INFO 
[org.ovirt.engine.core.bll.tasks.SPMAsyncTask] 
(org.ovirt.thread.pool-8-thread-25) [] SPMAsyncTask::ClearAsyncTask: 
Attempting to clear task '9f0ac94f-deb9-4662-824b-f7144c869af0'
2016-01-26 14:59:08,976 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] 
(org.ovirt.thread.pool-8-thread-25) [] START, SPMClearTaskVDSCommand( 
SPMTaskGuidBaseVDSCommandParameters:{runAsync='true', 
storagePoolId='00000001-0001-0001-0001-000000000296', 
ignoreFailoverLimit='false', 
taskId='9f0ac94f-deb9-4662-824b-f7144c869af0'}), log id: b2a607c
2016-01-26 14:59:08,977 INFO 
[org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] 
(org.ovirt.thread.pool-8-thread-25) [] START, 
HSMClearTaskVDSCommand(HostName = kvm02, 
HSMTaskGuidBaseVDSCommandParameters:{runAsync='true', 
hostId='572aa833-37fb-4c4b-9576-9d367def2d04', 
taskId='9f0ac94f-deb9-4662-824b-f7144c869af0'}), log id: 3c0d79bc
2016-01-26 14:59:10,001 INFO 
[org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] 
(org.ovirt.thread.pool-8-thread-25) [] FINISH, HSMClearTaskVDSCommand, 
log id: 3c0d79bc
2016-01-26 14:59:10,002 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] 
(org.ovirt.thread.pool-8-thread-25) [] FINISH, SPMClearTaskVDSCommand, 
log id: b2a607c
2016-01-26 14:59:10,012 INFO 
[org.ovirt.engine.core.bll.tasks.SPMAsyncTask] 
(org.ovirt.thread.pool-8-thread-25) [] BaseAsyncTask::removeTaskFromDB: 
Removed task '9f0ac94f-deb9-4662-824b-f7144c869af0' from DataBase
2016-01-26 14:59:10,012 INFO 
[org.ovirt.engine.core.bll.tasks.SPMAsyncTask] 
(org.ovirt.thread.pool-8-thread-25) [] SPMAsyncTask::ClearAsyncTask: 
Attempting to clear task '293a6312-8c4f-4c89-a3f7-2f9f0557a9b8'
2016-01-26 14:59:10,014 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] 
(org.ovirt.thread.pool-8-thread-25) [] START, SPMClearTaskVDSCommand( 
SPMTaskGuidBaseVDSCommandParameters:{runAsync='true', 
storagePoolId='00000001-0001-0001-0001-000000000296', 
ignoreFailoverLimit='false', 
taskId='293a6312-8c4f-4c89-a3f7-2f9f0557a9b8'}), log id: 63c6b6df
2016-01-26 14:59:12,174 INFO 
[org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] 
(org.ovirt.thread.pool-8-thread-25) [] START, 
HSMClearTaskVDSCommand(HostName = kvm02, 
HSMTaskGuidBaseVDSCommandParameters:{runAsync='true', 
hostId='572aa833-37fb-4c4b-9576-9d367def2d04', 
taskId='293a6312-8c4f-4c89-a3f7-2f9f0557a9b8'}), log id: 593cc157
2016-01-26 14:59:12,573 INFO 
[org.ovirt.engine.core.vdsbroker.vdsbroker.FullListVDSCommand] 
(DefaultQuartzScheduler_Worker-6) [] START, FullListVDSCommand(HostName 
= , FullListVDSCommandParameters:{runAsync='true', 
hostId='f18a051d-b893-41f7-9e97-0037abc7180d', 
vds='Host[,f18a051d-b893-41f7-9e97-0037abc7180d]', 
vmIds='[4e683012-8895-43da-b3e1-6d6271f4d829]'}), log id: 3672e426
2016-01-26 14:59:12,575 INFO 
[org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] 
(org.ovirt.thread.pool-8-thread-25) [] FINISH, HSMClearTaskVDSCommand, 
log id: 593cc157
2016-01-26 14:59:12,575 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] 
(org.ovirt.thread.pool-8-thread-25) [] FINISH, SPMClearTaskVDSCommand, 
log id: 63c6b6df
2016-01-26 14:59:12,585 INFO 
[org.ovirt.engine.core.bll.tasks.SPMAsyncTask] 
(org.ovirt.thread.pool-8-thread-25) [] BaseAsyncTask::removeTaskFromDB: 
Removed task '293a6312-8c4f-4c89-a3f7-2f9f0557a9b8' from DataBase
2016-01-26 14:59:12,586 INFO 
[org.ovirt.engine.core.bll.tasks.CommandAsyncTask] 
(org.ovirt.thread.pool-8-thread-25) [] 
CommandAsyncTask::HandleEndActionResult [within thread]: Removing 
CommandMultiAsyncTasks object for entity 
'8f3ccf29-3056-4ab0-bc11-b987814fe5fd'
2016-01-26 14:59:13,652 INFO 
[org.ovirt.engine.core.vdsbroker.vdsbroker.FullListVDSCommand] 
(DefaultQuartzScheduler_Worker-6) [] FINISH, FullListVDSCommand, return: 
[{acpiEnable=true, emulatedMachine=pc-i440fx-rhel7.2.0, 
afterMigrationStatus=, tabletEnable=true, pid=32651, 
memGuaranteedSize=1024, transparentHugePages=true, displaySecurePort=-1, 
spiceSslCipherSuite=DEFAULT, cpuType=SandyBridge, smp=1, 
guestNumaNodes=[Ljava.lang.Object;@3c99c1b9, hypervEnable=true, 
numaTune={nodeset=0,1, mode=interleave}, 
custom={device_88ae2b1a-bcd6-4252-abc8-5dd81e315394device_9b763617-eb2b-44ec-b227-397ca7a14d40device_af2dd0fa-cdaf-42f5-8483-a2f6a2ad4a47=VmDevice:{id='VmDeviceId:{deviceId='af2dd0fa-cdaf-42f5-8483-a2f6a2ad4a47', 
vmId='4e683012-8895-43da-b3e1-6d6271f4d829'}', device='unix', 
type='CHANNEL', bootOrder='0', specParams='[]', address='{bus=0, 
controller=0, type=virtio-serial, port=2}', managed='false', 
plugged='true', readOnly='false', deviceAlias='channel1', 
customProperties='[]', snapshotId='null', logicalName='null', 
usingScsiReservation='false'}, 
device_88ae2b1a-bcd6-4252-abc8-5dd81e315394=VmDevice:{id='VmDeviceId:{deviceId='88ae2b1a-bcd6-4252-abc8-5dd81e315394', 
vmId='4e683012-8895-43da-b3e1-6d6271f4d829'}', device='unix', 
type='CHANNEL', bootOrder='0', specParams='[]', address='{bus=0, 
controller=0, type=virtio-serial, port=1}', managed='false', 
plugged='true', readOnly='false', deviceAlias='channel0', 
customProperties='[]', snapshotId='null', logicalName='null', 
usingScsiReservation='false'}, 
device_88ae2b1a-bcd6-4252-abc8-5dd81e315394device_9b763617-eb2b-44ec-b227-397ca7a14d40=VmDevice:{id='VmDeviceId:{deviceId='9b763617-eb2b-44ec-b227-397ca7a14d40', 
vmId='4e683012-8895-43da-b3e1-6d6271f4d829'}', device='ide', 
type='CONTROLLER', bootOrder='0', specParams='[]', address='{slot=0x01, 
bus=0x00, domain=0x0000, type=pci, function=0x1}', managed='false', 
plugged='true', readOnly='false', deviceAlias='ide0', 
customProperties='[]', snapshotId='null', logicalName='null', 
usingScsiReservation='false'}}, vmType=kvm, memSize=2048, 
smpCoresPerSocket=1, vmName=hpserver, nice=0, status=Up, 
maxMemSize=20480, bootMenuEnable=false, guestDiskMapping={}, 
vmId=4e683012-8895-43da-b3e1-6d6271f4d829, displayIp=0, 
displayPort=5914, smartcardEnable=false, 
spiceSecureChannels=smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard, 
maxMemSlots=16, nicModel=rtl8139,pv, keyboardLayout=it, kvmEnable=true, 
devices=[Ljava.lang.Object;@214fa7db, timeOffset=14401, maxVCpus=16, 
clientIp=, statusTime=5328205390, display=vnc}], log id: 3672e426
2016-01-26 14:59:13,658 INFO 
[org.ovirt.engine.core.vdsbroker.VmsMonitoring] 
(DefaultQuartzScheduler_Worker-6) [] Received a memballoon Device 
without an address when processing VM 
4e683012-8895-43da-b3e1-6d6271f4d829 devices, skipping device: 
{target=2097152, alias=balloon0, specParams={model=none}, 
deviceType=balloon, device=memballoon, type=balloon}
2016-01-26 14:59:13,658 INFO 
[org.ovirt.engine.core.vdsbroker.VmsMonitoring] 
(DefaultQuartzScheduler_Worker-6) [] Received a vnc Device without an 
address when processing VM 4e683012-8895-43da-b3e1-6d6271f4d829 devices, 
skipping device: {specParams={displayIp=0}, deviceType=graphics, 
deviceId=333c2dc5-837e-4fd3-b311-e0a7eb5ed45f, device=vnc, 
type=graphics, port=5914}
2016-01-26 14:59:13,659 ERROR 
[org.ovirt.engine.core.vdsbroker.VmsMonitoring] 
(DefaultQuartzScheduler_Worker-6) [] VM 
'4e683012-8895-43da-b3e1-6d6271f4d829' managed non pluggable device was 
removed unexpectedly from libvirt: 
'VmDevice:{id='VmDeviceId:{deviceId='333c2dc5-837e-4fd3-b311-e0a7eb5ed45f', 
vmId='4e683012-8895-43da-b3e1-6d6271f4d829'}', device='vnc', 
type='GRAPHICS', bootOrder='0', specParams='[]', address='', 
managed='true', plugged='false', readOnly='false', deviceAlias='', 
customProperties='[]', snapshotId='null', logicalName='null', 
usingScsiReservation='false'}'


And this when I clone the snapshot:
2016-01-26 15:00:14,932 INFO 
[org.ovirt.engine.core.bll.AddVmFromSnapshotCommand] (default task-20) 
[30049735] Lock Acquired to object 
'EngineLock:{exclusiveLocks='[4e683012-8895-43da-b3e1-6d6271f4d829=<VM, 
ACTION_TYPE_FAILED_OBJECT_LOCKED>, test_clone=<VM_NAME, 
ACTION_TYPE_FAILED_OBJECT_LOCKED>]', sharedLocks='null'}'
2016-01-26 15:00:15,511 INFO 
[org.ovirt.engine.core.bll.AddVmFromSnapshotCommand] (default task-20) 
[] Running command: AddVmFromSnapshotCommand internal: false. Entities 
affected :  ID: 00000002-0002-0002-0002-0000000000ca Type: 
VdsGroupsAction group CREATE_VM with role type USER,  ID: 
239c7309-7e4c-4545-8137-6bf1d43cad71 Type: StorageAction group 
CREATE_DISK with role type USER,  ID: 
239c7309-7e4c-4545-8137-6bf1d43cad71 Type: StorageAction group 
CREATE_DISK with role type USER,  ID: 
239c7309-7e4c-4545-8137-6bf1d43cad71 Type: StorageAction group 
CREATE_DISK with role type USER,  ID: 
4e683012-8895-43da-b3e1-6d6271f4d829 Type: VMAction group CREATE_VM with 
role type USER
2016-01-26 15:00:15,607 INFO 
[org.ovirt.engine.core.bll.AddVmFromSnapshotCommand] (default task-20) 
[] Locking VM(id = 'fa0f7dca-19d3-4f55-82c9-b81b235d913a') with 
compensation.
2016-01-26 15:00:15,610 INFO 
[org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] (default 
task-20) [] START, SetVmStatusVDSCommand( 
SetVmStatusVDSCommandParameters:{runAsync='true', 
vmId='fa0f7dca-19d3-4f55-82c9-b81b235d913a', status='ImageLocked', 
exitStatus='Normal'}), log id: 6a218716
2016-01-26 15:00:15,614 INFO 
[org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand] (default 
task-20) [] FINISH, SetVmStatusVDSCommand, log id: 6a218716
2016-01-26 15:00:15,617 INFO 
[org.ovirt.engine.core.bll.AddVmFromSnapshotCommand] (default task-20) 
[] Lock freed to object 
'EngineLock:{exclusiveLocks='[4e683012-8895-43da-b3e1-6d6271f4d829=<VM, 
ACTION_TYPE_FAILED_OBJECT_LOCKED>, test_clone=<VM_NAME, 
ACTION_TYPE_FAILED_OBJECT_LOCKED>]', sharedLocks='null'}'
2016-01-26 15:00:15,661 INFO 
[org.ovirt.engine.core.bll.CopyImageGroupCommand] (default task-20) 
[1a40e7c1] Running command: CopyImageGroupCommand internal: true. 
Entities affected :  ID: 239c7309-7e4c-4545-8137-6bf1d43cad71 Type: Storage
2016-01-26 15:00:15,697 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.CopyImageVDSCommand] (default 
task-20) [1a40e7c1] START, CopyImageVDSCommand( 
CopyImageVDSCommandParameters:{runAsync='true', 
storagePoolId='00000001-0001-0001-0001-000000000296', 
ignoreFailoverLimit='false', 
storageDomainId='239c7309-7e4c-4545-8137-6bf1d43cad71', 
imageGroupId='dd1f13d8-4fb1-4f48-b7b6-cb912c0c1437', 
imageId='0856943c-c714-43a5-8f26-087143131d74', 
dstImageGroupId='9a1bd54c-a55a-4edc-b1a4-0d6fcfed8bdc', 
vmId='fa0f7dca-19d3-4f55-82c9-b81b235d913a', 
dstImageId='58da4129-eb0f-476e-b060-94cb2740ab8d', imageDescription='', 
dstStorageDomainId='239c7309-7e4c-4545-8137-6bf1d43cad71', 
copyVolumeType='LeafVol', volumeFormat='RAW', 
preallocate='Preallocated', postZero='false', force='false'}), log id: 
54b72148
2016-01-26 15:00:15,699 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.CopyImageVDSCommand] (default 
task-20) [1a40e7c1] -- executeIrsBrokerCommand: calling 'copyImage' with 
two new parameters: description and UUID. Parameters:
2016-01-26 15:00:15,699 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.CopyImageVDSCommand] (default 
task-20) [1a40e7c1] ++ sdUUID=239c7309-7e4c-4545-8137-6bf1d43cad71
2016-01-26 15:00:15,699 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.CopyImageVDSCommand] (default 
task-20) [1a40e7c1] ++ spUUID=00000001-0001-0001-0001-000000000296
2016-01-26 15:00:15,699 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.CopyImageVDSCommand] (default 
task-20) [1a40e7c1] ++ vmGUID=fa0f7dca-19d3-4f55-82c9-b81b235d913a
2016-01-26 15:00:15,699 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.CopyImageVDSCommand] (default 
task-20) [1a40e7c1] ++ srcImageGUID=dd1f13d8-4fb1-4f48-b7b6-cb912c0c1437
2016-01-26 15:00:15,699 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.CopyImageVDSCommand] (default 
task-20) [1a40e7c1] ++ srcVolUUID=0856943c-c714-43a5-8f26-087143131d74
2016-01-26 15:00:15,699 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.CopyImageVDSCommand] (default 
task-20) [1a40e7c1] ++ dstImageGUID=9a1bd54c-a55a-4edc-b1a4-0d6fcfed8bdc
2016-01-26 15:00:15,699 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.CopyImageVDSCommand] (default 
task-20) [1a40e7c1] ++ dstVolUUID=58da4129-eb0f-476e-b060-94cb2740ab8d
2016-01-26 15:00:15,699 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.CopyImageVDSCommand] (default 
task-20) [1a40e7c1] ++ descr=
2016-01-26 15:00:15,699 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.CopyImageVDSCommand] (default 
task-20) [1a40e7c1] ++ dstSdUUID=239c7309-7e4c-4545-8137-6bf1d43cad71
2016-01-26 15:00:17,619 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.CopyImageVDSCommand] (default 
task-20) [1a40e7c1] FINISH, CopyImageVDSCommand, return: 
bf3ef9aa-5099-47b6-b954-9a6902eb17c9, log id: 54b72148
2016-01-26 15:00:17,632 INFO 
[org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (default task-20) 
[1a40e7c1] CommandAsyncTask::Adding CommandMultiAsyncTasks object for 
command 'aaac9162-4be3-473f-91f4-491c8eedb4ad'
2016-01-26 15:00:17,632 INFO 
[org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (default task-20) 
[1a40e7c1] CommandMultiAsyncTasks::AttachTask: Attaching task 
'bf3ef9aa-5099-47b6-b954-9a6902eb17c9' to command 
'aaac9162-4be3-473f-91f4-491c8eedb4ad'.
2016-01-26 15:00:17,668 INFO 
[org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (default task-20) 
[1a40e7c1] Adding task 'bf3ef9aa-5099-47b6-b954-9a6902eb17c9' (Parent 
Command 'AddVmFromSnapshot', Parameters Type 
'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters'), polling 
hasn't started yet..
2016-01-26 15:00:17,872 INFO 
[org.ovirt.engine.core.bll.CopyImageGroupCommand] (default task-20) 
[388cd805] Running command: CopyImageGroupCommand internal: true. 
Entities affected :  ID: 239c7309-7e4c-4545-8137-6bf1d43cad71 Type: Storage
2016-01-26 15:00:17,928 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.CopyImageVDSCommand] (default 
task-20) [388cd805] START, CopyImageVDSCommand( 
CopyImageVDSCommandParameters:{runAsync='true', 
storagePoolId='00000001-0001-0001-0001-000000000296', 
ignoreFailoverLimit='false', 
storageDomainId='239c7309-7e4c-4545-8137-6bf1d43cad71', 
imageGroupId='d98b8313-de2f-477a-94f8-78026497612b', 
imageId='dd30f129-e8d0-4155-9c63-6ac1ee76fa8e', 
dstImageGroupId='3f83427e-d3a9-4d0a-a176-aa713fbab255', 
vmId='fa0f7dca-19d3-4f55-82c9-b81b235d913a', 
dstImageId='31f56d0e-cf73-464d-ad9a-8a6b75c68563', imageDescription='', 
dstStorageDomainId='239c7309-7e4c-4545-8137-6bf1d43cad71', 
copyVolumeType='LeafVol', volumeFormat='RAW', 
preallocate='Preallocated', postZero='false', force='false'}), log id: 
3e52cd55
2016-01-26 15:00:17,930 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.CopyImageVDSCommand] (default 
task-20) [388cd805] -- executeIrsBrokerCommand: calling 'copyImage' with 
two new parameters: description and UUID. Parameters:
2016-01-26 15:00:17,931 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.CopyImageVDSCommand] (default 
task-20) [388cd805] ++ sdUUID=239c7309-7e4c-4545-8137-6bf1d43cad71
2016-01-26 15:00:17,931 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.CopyImageVDSCommand] (default 
task-20) [388cd805] ++ spUUID=00000001-0001-0001-0001-000000000296
2016-01-26 15:00:17,931 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.CopyImageVDSCommand] (default 
task-20) [388cd805] ++ vmGUID=fa0f7dca-19d3-4f55-82c9-b81b235d913a
2016-01-26 15:00:17,931 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.CopyImageVDSCommand] (default 
task-20) [388cd805] ++ srcImageGUID=d98b8313-de2f-477a-94f8-78026497612b
2016-01-26 15:00:17,931 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.CopyImageVDSCommand] (default 
task-20) [388cd805] ++ srcVolUUID=dd30f129-e8d0-4155-9c63-6ac1ee76fa8e
2016-01-26 15:00:17,931 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.CopyImageVDSCommand] (default 
task-20) [388cd805] ++ dstImageGUID=3f83427e-d3a9-4d0a-a176-aa713fbab255
2016-01-26 15:00:17,931 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.CopyImageVDSCommand] (default 
task-20) [388cd805] ++ dstVolUUID=31f56d0e-cf73-464d-ad9a-8a6b75c68563
2016-01-26 15:00:17,931 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.CopyImageVDSCommand] (default 
task-20) [388cd805] ++ descr=
2016-01-26 15:00:17,931 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.CopyImageVDSCommand] (default 
task-20) [388cd805] ++ dstSdUUID=239c7309-7e4c-4545-8137-6bf1d43cad71
2016-01-26 15:00:18,975 INFO 
[org.ovirt.engine.core.bll.tasks.AsyncTaskManager] 
(DefaultQuartzScheduler_Worker-88) [50bfaa54] Setting new tasks map. The 
map contains now 1 tasks
2016-01-26 15:00:19,707 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.CopyImageVDSCommand] (default 
task-20) [388cd805] FINISH, CopyImageVDSCommand, return: 
8347d2c2-1907-431c-baeb-b885ba6f200d, log id: 3e52cd55
2016-01-26 15:00:19,729 INFO 
[org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (default task-20) 
[388cd805] CommandMultiAsyncTasks::AttachTask: Attaching task 
'8347d2c2-1907-431c-baeb-b885ba6f200d' to command 
'aaac9162-4be3-473f-91f4-491c8eedb4ad'.
2016-01-26 15:00:19,768 INFO 
[org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (default task-20) 
[388cd805] Adding task '8347d2c2-1907-431c-baeb-b885ba6f200d' (Parent 
Command 'AddVmFromSnapshot', Parameters Type 
'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters'), polling 
hasn't started yet..
2016-01-26 15:00:19,886 INFO 
[org.ovirt.engine.core.bll.CopyImageGroupCommand] (default task-20) 
[66941705] Running command: CopyImageGroupCommand internal: true. 
Entities affected :  ID: 239c7309-7e4c-4545-8137-6bf1d43cad71 Type: Storage
2016-01-26 15:00:19,932 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.CopyImageVDSCommand] (default 
task-20) [66941705] START, CopyImageVDSCommand( 
CopyImageVDSCommandParameters:{runAsync='true', 
storagePoolId='00000001-0001-0001-0001-000000000296', 
ignoreFailoverLimit='false', 
storageDomainId='239c7309-7e4c-4545-8137-6bf1d43cad71', 
imageGroupId='42e212c1-f669-43e1-8f90-20baf0c3f58c', 
imageId='449e8b88-ab34-4cf8-bc91-00128c35dc65', 
dstImageGroupId='b06a9ad5-62ca-478e-9f0c-278feca4eda3', 
vmId='fa0f7dca-19d3-4f55-82c9-b81b235d913a', 
dstImageId='136257df-c62b-421b-a12a-dea765b16721', imageDescription='', 
dstStorageDomainId='239c7309-7e4c-4545-8137-6bf1d43cad71', 
copyVolumeType='LeafVol', volumeFormat='RAW', 
preallocate='Preallocated', postZero='false', force='false'}), log id: 
70cc5e38
2016-01-26 15:00:19,935 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.CopyImageVDSCommand] (default 
task-20) [66941705] -- executeIrsBrokerCommand: calling 'copyImage' with 
two new parameters: description and UUID. Parameters:
2016-01-26 15:00:19,935 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.CopyImageVDSCommand] (default 
task-20) [66941705] ++ sdUUID=239c7309-7e4c-4545-8137-6bf1d43cad71
2016-01-26 15:00:19,935 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.CopyImageVDSCommand] (default 
task-20) [66941705] ++ spUUID=00000001-0001-0001-0001-000000000296
2016-01-26 15:00:19,936 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.CopyImageVDSCommand] (default 
task-20) [66941705] ++ vmGUID=fa0f7dca-19d3-4f55-82c9-b81b235d913a
2016-01-26 15:00:19,936 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.CopyImageVDSCommand] (default 
task-20) [66941705] ++ srcImageGUID=42e212c1-f669-43e1-8f90-20baf0c3f58c
2016-01-26 15:00:19,936 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.CopyImageVDSCommand] (default 
task-20) [66941705] ++ srcVolUUID=449e8b88-ab34-4cf8-bc91-00128c35dc65
2016-01-26 15:00:19,936 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.CopyImageVDSCommand] (default 
task-20) [66941705] ++ dstImageGUID=b06a9ad5-62ca-478e-9f0c-278feca4eda3
2016-01-26 15:00:19,936 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.CopyImageVDSCommand] (default 
task-20) [66941705] ++ dstVolUUID=136257df-c62b-421b-a12a-dea765b16721
2016-01-26 15:00:19,936 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.CopyImageVDSCommand] (default 
task-20) [66941705] ++ descr=
2016-01-26 15:00:19,936 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.CopyImageVDSCommand] (default 
task-20) [66941705] ++ dstSdUUID=239c7309-7e4c-4545-8137-6bf1d43cad71
2016-01-26 15:00:23,635 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.CopyImageVDSCommand] (default 
task-20) [66941705] FINISH, CopyImageVDSCommand, return: 
b910d97d-a091-4648-8840-e870651745c7, log id: 70cc5e38
2016-01-26 15:00:23,654 INFO 
[org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (default task-20) 
[66941705] CommandMultiAsyncTasks::AttachTask: Attaching task 
'b910d97d-a091-4648-8840-e870651745c7' to command 
'aaac9162-4be3-473f-91f4-491c8eedb4ad'.
2016-01-26 15:00:23,676 INFO 
[org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (default task-20) 
[66941705] Adding task 'b910d97d-a091-4648-8840-e870651745c7' (Parent 
Command 'AddVmFromSnapshot', Parameters Type 
'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters'), polling 
hasn't started yet..
2016-01-26 15:00:23,780 INFO 
[org.ovirt.engine.core.bll.AddGraphicsDeviceCommand] (default task-20) 
[2cab3adb] Running command: AddGraphicsDeviceCommand internal: true. 
Entities affected :  ID: fa0f7dca-19d3-4f55-82c9-b81b235d913a Type: 
VMAction group EDIT_VM_PROPERTIES with role type USER
2016-01-26 15:00:23,871 INFO 
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] 
(default task-20) [2cab3adb] Correlation ID: 30049735, Job ID: 
fe7f7d93-4a22-4bfe-baae-bc2357dc01e9, Call Stack: null, Custom Event ID: 
-1, Message: VM test_clone creation was initiated by 
rfocesq at omme.net@omme.net.
2016-01-26 15:00:23,871 INFO 
[org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (default task-20) 
[2cab3adb] BaseAsyncTask::startPollingTask: Starting to poll task 
'bf3ef9aa-5099-47b6-b954-9a6902eb17c9'.
2016-01-26 15:00:23,872 INFO 
[org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (default task-20) 
[2cab3adb] BaseAsyncTask::startPollingTask: Starting to poll task 
'8347d2c2-1907-431c-baeb-b885ba6f200d'.
2016-01-26 15:00:23,872 INFO 
[org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (default task-20) 
[2cab3adb] BaseAsyncTask::startPollingTask: Starting to poll task 
'b910d97d-a091-4648-8840-e870651745c7'.
2016-01-26 15:00:30,393 INFO 
[org.ovirt.engine.core.bll.tasks.AsyncTaskManager] 
(DefaultQuartzScheduler_Worker-95) [76980f69] Polling and updating Async 
Tasks: 3 tasks, 3 tasks to poll now
2016-01-26 15:00:31,835 ERROR 
[org.ovirt.engine.core.vdsbroker.vdsbroker.HSMGetAllTasksStatusesVDSCommand] 
(DefaultQuartzScheduler_Worker-95) [76980f69] Failed in 
'HSMGetAllTasksStatusesVDS' method
2016-01-26 15:00:31,846 ERROR 
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] 
(DefaultQuartzScheduler_Worker-95) [76980f69] Correlation ID: null, Call 
Stack: null, Custom Event ID: -1, Message: VDSM kvm02 command failed: 
low level Image copy failed
2016-01-26 15:00:31,847 INFO 
[org.ovirt.engine.core.bll.tasks.SPMAsyncTask] 
(DefaultQuartzScheduler_Worker-95) [76980f69] SPMAsyncTask::PollTask: 
Polling task '8347d2c2-1907-431c-baeb-b885ba6f200d' (Parent Command 
'AddVmFromSnapshot', Parameters Type 
'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') returned 
status 'cleaning'.
2016-01-26 15:00:31,847 INFO 
[org.ovirt.engine.core.bll.tasks.SPMAsyncTask] 
(DefaultQuartzScheduler_Worker-95) [76980f69] SPMAsyncTask::PollTask: 
Polling task 'bf3ef9aa-5099-47b6-b954-9a6902eb17c9' (Parent Command 
'AddVmFromSnapshot', Parameters Type 
'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') returned 
status 'finished', result 'cleanSuccess'.
2016-01-26 15:00:31,855 ERROR 
[org.ovirt.engine.core.bll.tasks.SPMAsyncTask] 
(DefaultQuartzScheduler_Worker-95) [76980f69] 
BaseAsyncTask::logEndTaskFailure: Task 
'bf3ef9aa-5099-47b6-b954-9a6902eb17c9' (Parent Command 
'AddVmFromSnapshot', Parameters Type 
'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') ended 
with failure:
-- Result: 'cleanSuccess'
-- Message: 'VDSGenericException: VDSErrorException: Failed to 
HSMGetAllTasksStatusesVDS, error = low level Image copy failed, code = 261',
-- Exception: 'VDSGenericException: VDSErrorException: Failed to 
HSMGetAllTasksStatusesVDS, error = low level Image copy failed, code = 261'
2016-01-26 15:00:31,857 INFO 
[org.ovirt.engine.core.bll.CommandMultiAsyncTasks] 
(DefaultQuartzScheduler_Worker-95) [76980f69] Task with DB Task ID 
'a773241b-1473-4d42-97b3-bc077d2973fd' and VDSM Task ID 
'8347d2c2-1907-431c-baeb-b885ba6f200d' is in state Polling. End action 
for command aaac9162-4be3-473f-91f4-491c8eedb4ad will proceed when all 
the entity's tasks are completed.
2016-01-26 15:00:31,857 INFO 
[org.ovirt.engine.core.bll.tasks.SPMAsyncTask] 
(DefaultQuartzScheduler_Worker-95) [76980f69] SPMAsyncTask::PollTask: 
Polling task 'b910d97d-a091-4648-8840-e870651745c7' (Parent Command 
'AddVmFromSnapshot', Parameters Type 
'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') returned 
status 'running'.
2016-01-26 15:00:31,857 INFO 
[org.ovirt.engine.core.bll.tasks.AsyncTaskManager] 
(DefaultQuartzScheduler_Worker-95) [76980f69] Finished polling Tasks, 
will poll again in 10 seconds.
2016-01-26 15:00:33,309 WARN 
[org.ovirt.engine.core.bll.scheduling.policyunits.EvenGuestDistributionBalancePolicyUnit] 
(DefaultQuartzScheduler_Worker-65) [50bfaa54] There is no host with less 
than 8 running guests
2016-01-26 15:00:33,310 WARN 
[org.ovirt.engine.core.bll.scheduling.policyunits.CpuAndMemoryBalancingPolicyUnit] 
(DefaultQuartzScheduler_Worker-65) [50bfaa54] All hosts are 
over-utilized, can't balance the cluster 'Default' using the primary method
2016-01-26 15:00:42,877 ERROR 
[org.ovirt.engine.core.vdsbroker.vdsbroker.HSMGetAllTasksStatusesVDSCommand] 
(DefaultQuartzScheduler_Worker-21) [2c031c31] Failed in 
'HSMGetAllTasksStatusesVDS' method
2016-01-26 15:00:42,888 ERROR 
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] 
(DefaultQuartzScheduler_Worker-21) [2c031c31] Correlation ID: null, Call 
Stack: null, Custom Event ID: -1, Message: VDSM kvm02 command failed: 
low level Image copy failed
2016-01-26 15:00:42,889 ERROR 
[org.ovirt.engine.core.vdsbroker.vdsbroker.HSMGetAllTasksStatusesVDSCommand] 
(DefaultQuartzScheduler_Worker-21) [2c031c31] Failed in 
'HSMGetAllTasksStatusesVDS' method
2016-01-26 15:00:42,898 ERROR 
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] 
(DefaultQuartzScheduler_Worker-21) [2c031c31] Correlation ID: null, Call 
Stack: null, Custom Event ID: -1, Message: VDSM kvm02 command failed: 
low level Image copy failed
2016-01-26 15:00:42,898 ERROR 
[org.ovirt.engine.core.vdsbroker.vdsbroker.HSMGetAllTasksStatusesVDSCommand] 
(DefaultQuartzScheduler_Worker-21) [2c031c31] Failed in 
'HSMGetAllTasksStatusesVDS' method
2016-01-26 15:00:42,905 ERROR 
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] 
(DefaultQuartzScheduler_Worker-21) [2c031c31] Correlation ID: null, Call 
Stack: null, Custom Event ID: -1, Message: VDSM kvm02 command failed: 
low level Image copy failed
2016-01-26 15:00:42,906 INFO 
[org.ovirt.engine.core.bll.tasks.SPMAsyncTask] 
(DefaultQuartzScheduler_Worker-21) [2c031c31] SPMAsyncTask::PollTask: 
Polling task '8347d2c2-1907-431c-baeb-b885ba6f200d' (Parent Command 
'AddVmFromSnapshot', Parameters Type 
'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') returned 
status 'finished', result 'cleanSuccess'.
2016-01-26 15:00:42,916 ERROR 
[org.ovirt.engine.core.bll.tasks.SPMAsyncTask] 
(DefaultQuartzScheduler_Worker-21) [2c031c31] 
BaseAsyncTask::logEndTaskFailure: Task 
'8347d2c2-1907-431c-baeb-b885ba6f200d' (Parent Command 
'AddVmFromSnapshot', Parameters Type 
'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') ended 
with failure:
-- Result: 'cleanSuccess'
-- Message: 'VDSGenericException: VDSErrorException: Failed to 
HSMGetAllTasksStatusesVDS, error = low level Image copy failed, code = 261',
-- Exception: 'VDSGenericException: VDSErrorException: Failed to 
HSMGetAllTasksStatusesVDS, error = low level Image copy failed, code = 261'
2016-01-26 15:00:42,916 INFO 
[org.ovirt.engine.core.bll.CommandMultiAsyncTasks] 
(DefaultQuartzScheduler_Worker-21) [2c031c31] Task with DB Task ID 
'8c4d9c72-995a-47b6-b8b4-08ce70dbca2e' and VDSM Task ID 
'b910d97d-a091-4648-8840-e870651745c7' is in state Polling. End action 
for command aaac9162-4be3-473f-91f4-491c8eedb4ad will proceed when all 
the entity's tasks are completed.
2016-01-26 15:00:42,922 ERROR 
[org.ovirt.engine.core.bll.tasks.SPMAsyncTask] 
(DefaultQuartzScheduler_Worker-21) [2c031c31] 
BaseAsyncTask::logEndTaskFailure: Task 
'bf3ef9aa-5099-47b6-b954-9a6902eb17c9' (Parent Command 
'AddVmFromSnapshot', Parameters Type 
'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') ended 
with failure:
-- Result: 'cleanSuccess'
-- Message: 'VDSGenericException: VDSErrorException: Failed to 
HSMGetAllTasksStatusesVDS, error = low level Image copy failed, code = 261',
-- Exception: 'VDSGenericException: VDSErrorException: Failed to 
HSMGetAllTasksStatusesVDS, error = low level Image copy failed, code = 261'
2016-01-26 15:00:42,922 INFO 
[org.ovirt.engine.core.bll.CommandMultiAsyncTasks] 
(DefaultQuartzScheduler_Worker-21) [2c031c31] Task with DB Task ID 
'8c4d9c72-995a-47b6-b8b4-08ce70dbca2e' and VDSM Task ID 
'b910d97d-a091-4648-8840-e870651745c7' is in state Polling. End action 
for command aaac9162-4be3-473f-91f4-491c8eedb4ad will proceed when all 
the entity's tasks are completed.
2016-01-26 15:00:42,922 INFO 
[org.ovirt.engine.core.bll.tasks.SPMAsyncTask] 
(DefaultQuartzScheduler_Worker-21) [2c031c31] SPMAsyncTask::PollTask: 
Polling task 'b910d97d-a091-4648-8840-e870651745c7' (Parent Command 
'AddVmFromSnapshot', Parameters Type 
'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') returned 
status 'finished', result 'cleanSuccess'.
2016-01-26 15:00:42,930 ERROR 
[org.ovirt.engine.core.bll.tasks.SPMAsyncTask] 
(DefaultQuartzScheduler_Worker-21) [2c031c31] 
BaseAsyncTask::logEndTaskFailure: Task 
'b910d97d-a091-4648-8840-e870651745c7' (Parent Command 
'AddVmFromSnapshot', Parameters Type 
'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') ended 
with failure:
-- Result: 'cleanSuccess'
-- Message: 'VDSGenericException: VDSErrorException: Failed to 
HSMGetAllTasksStatusesVDS, error = low level Image copy failed, code = 261',
-- Exception: 'VDSGenericException: VDSErrorException: Failed to 
HSMGetAllTasksStatusesVDS, error = low level Image copy failed, code = 261'
2016-01-26 15:00:42,959 INFO 
[org.ovirt.engine.core.bll.tasks.CommandAsyncTask] 
(DefaultQuartzScheduler_Worker-21) [2c031c31] 
CommandAsyncTask::endActionIfNecessary: All tasks of command 
'aaac9162-4be3-473f-91f4-491c8eedb4ad' has ended -> executing 'endAction'
2016-01-26 15:00:42,959 INFO 
[org.ovirt.engine.core.bll.tasks.CommandAsyncTask] 
(DefaultQuartzScheduler_Worker-21) [2c031c31] 
CommandAsyncTask::endAction: Ending action for '3' tasks (command ID: 
'aaac9162-4be3-473f-91f4-491c8eedb4ad'): calling endAction '.
2016-01-26 15:00:42,960 INFO 
[org.ovirt.engine.core.bll.tasks.CommandAsyncTask] 
(org.ovirt.thread.pool-8-thread-46) [2c031c31] 
CommandAsyncTask::endCommandAction [within thread] context: Attempting 
to endAction 'AddVmFromSnapshot', executionIndex: '0'
2016-01-26 15:00:43,014 ERROR 
[org.ovirt.engine.core.bll.AddVmFromSnapshotCommand] 
(org.ovirt.thread.pool-8-thread-46) [30049735] Ending command 
'org.ovirt.engine.core.bll.AddVmFromSnapshotCommand' with failure.
2016-01-26 15:00:43,036 ERROR 
[org.ovirt.engine.core.bll.CopyImageGroupCommand] 
(org.ovirt.thread.pool-8-thread-46) [388cd805] Ending command 
'org.ovirt.engine.core.bll.CopyImageGroupCommand' with failure.
2016-01-26 15:00:43,049 INFO 
[org.ovirt.engine.core.bll.RemoveImageCommand] 
(org.ovirt.thread.pool-8-thread-46) [7c5a150a] Running command: 
RemoveImageCommand internal: true. Entities affected :  ID: 
00000000-0000-0000-0000-000000000000 Type: Storage
2016-01-26 15:00:43,093 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] 
(org.ovirt.thread.pool-8-thread-46) [7c5a150a] START, 
DeleteImageGroupVDSCommand( 
DeleteImageGroupVDSCommandParameters:{runAsync='true', 
storagePoolId='00000001-0001-0001-0001-000000000296', 
ignoreFailoverLimit='false', 
storageDomainId='239c7309-7e4c-4545-8137-6bf1d43cad71', 
imageGroupId='3f83427e-d3a9-4d0a-a176-aa713fbab255', postZeros='false', 
forceDelete='false'}), log id: 5be417ac
2016-01-26 15:00:44,592 ERROR 
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] 
(org.ovirt.thread.pool-8-thread-46) [7c5a150a] Correlation ID: null, 
Call Stack: null, Custom Event ID: -1, Message: VDSM command failed: 
Image does not exist in domain: 
u'image=3f83427e-d3a9-4d0a-a176-aa713fbab255, 
domain=239c7309-7e4c-4545-8137-6bf1d43cad71'
2016-01-26 15:00:44,592 ERROR 
[org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] 
(org.ovirt.thread.pool-8-thread-46) [7c5a150a] Command 
'DeleteImageGroupVDSCommand( 
DeleteImageGroupVDSCommandParameters:{runAsync='true', 
storagePoolId='00000001-0001-0001-0001-000000000296', 
ignoreFailoverLimit='false', 
storageDomainId='239c7309-7e4c-4545-8137-6bf1d43cad71', 
imageGroupId='3f83427e-d3a9-4d0a-a176-aa713fbab255', postZeros='false', 
forceDelete='false'})' execution failed: IRSGenericException: 
IRSErrorException: Image does not exist in domain: 
u'image=3f83427e-d3a9-4d0a-a176-aa713fbab255, 
domain=239c7309-7e4c-4545-8137-6bf1d43cad71'
2016-01-26 15:00:44,592 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] 
(org.ovirt.thread.pool-8-thread-46) [7c5a150a] FINISH, 
DeleteImageGroupVDSCommand, log id: 5be417ac
2016-01-26 15:00:44,593 INFO 
[org.ovirt.engine.core.bll.RemoveImageCommand] 
(org.ovirt.thread.pool-8-thread-46) [7c5a150a] Disk 
'3f83427e-d3a9-4d0a-a176-aa713fbab255' doesn't exist on storage domain 
'239c7309-7e4c-4545-8137-6bf1d43cad71', rolling forward
2016-01-26 15:00:44,790 INFO 
[org.ovirt.engine.core.bll.tasks.AsyncTaskManager] 
(org.ovirt.thread.pool-8-thread-46) [7c5a150a] Removed task 
'0797d4de-2df6-4283-8952-c9d186d2b010' from DataBase
2016-01-26 15:00:44,808 ERROR 
[org.ovirt.engine.core.bll.CopyImageGroupCommand] 
(org.ovirt.thread.pool-8-thread-46) [1a40e7c1] Ending command 
'org.ovirt.engine.core.bll.CopyImageGroupCommand' with failure.
2016-01-26 15:00:44,821 INFO 
[org.ovirt.engine.core.bll.RemoveImageCommand] 
(org.ovirt.thread.pool-8-thread-46) [1a177c73] Running command: 
RemoveImageCommand internal: true. Entities affected :  ID: 
00000000-0000-0000-0000-000000000000 Type: Storage
2016-01-26 15:00:44,869 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] 
(org.ovirt.thread.pool-8-thread-46) [1a177c73] START, 
DeleteImageGroupVDSCommand( 
DeleteImageGroupVDSCommandParameters:{runAsync='true', 
storagePoolId='00000001-0001-0001-0001-000000000296', 
ignoreFailoverLimit='false', 
storageDomainId='239c7309-7e4c-4545-8137-6bf1d43cad71', 
imageGroupId='9a1bd54c-a55a-4edc-b1a4-0d6fcfed8bdc', postZeros='false', 
forceDelete='false'}), log id: 475a2763
2016-01-26 15:00:46,268 ERROR 
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] 
(org.ovirt.thread.pool-8-thread-46) [1a177c73] Correlation ID: null, 
Call Stack: null, Custom Event ID: -1, Message: VDSM command failed: 
Image does not exist in domain: 
u'image=9a1bd54c-a55a-4edc-b1a4-0d6fcfed8bdc, 
domain=239c7309-7e4c-4545-8137-6bf1d43cad71'
2016-01-26 15:00:46,269 ERROR 
[org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] 
(org.ovirt.thread.pool-8-thread-46) [1a177c73] Command 
'DeleteImageGroupVDSCommand( 
DeleteImageGroupVDSCommandParameters:{runAsync='true', 
storagePoolId='00000001-0001-0001-0001-000000000296', 
ignoreFailoverLimit='false', 
storageDomainId='239c7309-7e4c-4545-8137-6bf1d43cad71', 
imageGroupId='9a1bd54c-a55a-4edc-b1a4-0d6fcfed8bdc', postZeros='false', 
forceDelete='false'})' execution failed: IRSGenericException: 
IRSErrorException: Image does not exist in domain: 
u'image=9a1bd54c-a55a-4edc-b1a4-0d6fcfed8bdc, 
domain=239c7309-7e4c-4545-8137-6bf1d43cad71'
2016-01-26 15:00:46,269 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] 
(org.ovirt.thread.pool-8-thread-46) [1a177c73] FINISH, 
DeleteImageGroupVDSCommand, log id: 475a2763
2016-01-26 15:00:46,270 INFO 
[org.ovirt.engine.core.bll.RemoveImageCommand] 
(org.ovirt.thread.pool-8-thread-46) [1a177c73] Disk 
'9a1bd54c-a55a-4edc-b1a4-0d6fcfed8bdc' doesn't exist on storage domain 
'239c7309-7e4c-4545-8137-6bf1d43cad71', rolling forward
2016-01-26 15:00:46,476 INFO 
[org.ovirt.engine.core.bll.tasks.AsyncTaskManager] 
(org.ovirt.thread.pool-8-thread-46) [1a177c73] Removed task 
'b4d1eaf2-6955-41cc-a813-39da5faeca41' from DataBase
2016-01-26 15:00:46,492 ERROR 
[org.ovirt.engine.core.bll.CopyImageGroupCommand] 
(org.ovirt.thread.pool-8-thread-46) [66941705] Ending command 
'org.ovirt.engine.core.bll.CopyImageGroupCommand' with failure.
2016-01-26 15:00:46,502 INFO 
[org.ovirt.engine.core.bll.RemoveImageCommand] 
(org.ovirt.thread.pool-8-thread-46) [4a3987be] Running command: 
RemoveImageCommand internal: true. Entities affected :  ID: 
00000000-0000-0000-0000-000000000000 Type: Storage
2016-01-26 15:00:46,540 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] 
(org.ovirt.thread.pool-8-thread-46) [4a3987be] START, 
DeleteImageGroupVDSCommand( 
DeleteImageGroupVDSCommandParameters:{runAsync='true', 
storagePoolId='00000001-0001-0001-0001-000000000296', 
ignoreFailoverLimit='false', 
storageDomainId='239c7309-7e4c-4545-8137-6bf1d43cad71', 
imageGroupId='b06a9ad5-62ca-478e-9f0c-278feca4eda3', postZeros='false', 
forceDelete='false'}), log id: 5ec9b85c
2016-01-26 15:00:47,792 ERROR 
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] 
(org.ovirt.thread.pool-8-thread-46) [4a3987be] Correlation ID: null, 
Call Stack: null, Custom Event ID: -1, Message: VDSM command failed: 
Image does not exist in domain: 
u'image=b06a9ad5-62ca-478e-9f0c-278feca4eda3, 
domain=239c7309-7e4c-4545-8137-6bf1d43cad71'
2016-01-26 15:00:47,793 ERROR 
[org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] 
(org.ovirt.thread.pool-8-thread-46) [4a3987be] Command 
'DeleteImageGroupVDSCommand( 
DeleteImageGroupVDSCommandParameters:{runAsync='true', 
storagePoolId='00000001-0001-0001-0001-000000000296', 
ignoreFailoverLimit='false', 
storageDomainId='239c7309-7e4c-4545-8137-6bf1d43cad71', 
imageGroupId='b06a9ad5-62ca-478e-9f0c-278feca4eda3', postZeros='false', 
forceDelete='false'})' execution failed: IRSGenericException: 
IRSErrorException: Image does not exist in domain: 
u'image=b06a9ad5-62ca-478e-9f0c-278feca4eda3, 
domain=239c7309-7e4c-4545-8137-6bf1d43cad71'
2016-01-26 15:00:47,793 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] 
(org.ovirt.thread.pool-8-thread-46) [4a3987be] FINISH, 
DeleteImageGroupVDSCommand, log id: 5ec9b85c
2016-01-26 15:00:47,793 INFO 
[org.ovirt.engine.core.bll.RemoveImageCommand] 
(org.ovirt.thread.pool-8-thread-46) [4a3987be] Disk 
'b06a9ad5-62ca-478e-9f0c-278feca4eda3' doesn't exist on storage domain 
'239c7309-7e4c-4545-8137-6bf1d43cad71', rolling forward
2016-01-26 15:00:47,953 INFO 
[org.ovirt.engine.core.bll.tasks.AsyncTaskManager] 
(org.ovirt.thread.pool-8-thread-46) [4a3987be] Removed task 
'fb467301-4397-49db-a200-d623916c8f37' from DataBase
2016-01-26 15:00:48,037 ERROR 
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] 
(org.ovirt.thread.pool-8-thread-46) [] Correlation ID: 30049735, Call 
Stack: null, Custom Event ID: -1, Message: Failed to complete VM 
test_clone creation.
2016-01-26 15:00:48,037 INFO 
[org.ovirt.engine.core.bll.tasks.CommandAsyncTask] 
(org.ovirt.thread.pool-8-thread-46) [] 
CommandAsyncTask::HandleEndActionResult [within thread]: endAction for 
action type 'AddVmFromSnapshot' completed, handling the result.
2016-01-26 15:00:48,037 INFO 
[org.ovirt.engine.core.bll.tasks.CommandAsyncTask] 
(org.ovirt.thread.pool-8-thread-46) [] 
CommandAsyncTask::HandleEndActionResult [within thread]: endAction for 
action type 'AddVmFromSnapshot' succeeded, clearing tasks.
2016-01-26 15:00:48,043 INFO 
[org.ovirt.engine.core.bll.tasks.SPMAsyncTask] 
(org.ovirt.thread.pool-8-thread-46) [] SPMAsyncTask::ClearAsyncTask: 
Attempting to clear task '8347d2c2-1907-431c-baeb-b885ba6f200d'
2016-01-26 15:00:48,045 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] 
(org.ovirt.thread.pool-8-thread-46) [] START, SPMClearTaskVDSCommand( 
SPMTaskGuidBaseVDSCommandParameters:{runAsync='true', 
storagePoolId='00000001-0001-0001-0001-000000000296', 
ignoreFailoverLimit='false', 
taskId='8347d2c2-1907-431c-baeb-b885ba6f200d'}), log id: 29d50ec8
2016-01-26 15:00:48,742 INFO 
[org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] 
(org.ovirt.thread.pool-8-thread-46) [] START, 
HSMClearTaskVDSCommand(HostName = kvm02, 
HSMTaskGuidBaseVDSCommandParameters:{runAsync='true', 
hostId='572aa833-37fb-4c4b-9576-9d367def2d04', 
taskId='8347d2c2-1907-431c-baeb-b885ba6f200d'}), log id: 415f863f
2016-01-26 15:00:49,762 INFO 
[org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] 
(org.ovirt.thread.pool-8-thread-46) [] FINISH, HSMClearTaskVDSCommand, 
log id: 415f863f
2016-01-26 15:00:49,763 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] 
(org.ovirt.thread.pool-8-thread-46) [] FINISH, SPMClearTaskVDSCommand, 
log id: 29d50ec8
2016-01-26 15:00:49,769 INFO 
[org.ovirt.engine.core.bll.tasks.SPMAsyncTask] 
(org.ovirt.thread.pool-8-thread-46) [] BaseAsyncTask::removeTaskFromDB: 
Removed task '8347d2c2-1907-431c-baeb-b885ba6f200d' from DataBase
2016-01-26 15:00:49,770 INFO 
[org.ovirt.engine.core.bll.tasks.SPMAsyncTask] 
(org.ovirt.thread.pool-8-thread-46) [] SPMAsyncTask::ClearAsyncTask: 
Attempting to clear task 'bf3ef9aa-5099-47b6-b954-9a6902eb17c9'
2016-01-26 15:00:49,771 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] 
(org.ovirt.thread.pool-8-thread-46) [] START, SPMClearTaskVDSCommand( 
SPMTaskGuidBaseVDSCommandParameters:{runAsync='true', 
storagePoolId='00000001-0001-0001-0001-000000000296', 
ignoreFailoverLimit='false', 
taskId='bf3ef9aa-5099-47b6-b954-9a6902eb17c9'}), log id: 543d8586
2016-01-26 15:00:49,772 INFO 
[org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] 
(org.ovirt.thread.pool-8-thread-46) [] START, 
HSMClearTaskVDSCommand(HostName = kvm02, 
HSMTaskGuidBaseVDSCommandParameters:{runAsync='true', 
hostId='572aa833-37fb-4c4b-9576-9d367def2d04', 
taskId='bf3ef9aa-5099-47b6-b954-9a6902eb17c9'}), log id: 35bd0ad7
2016-01-26 15:00:50,792 INFO 
[org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] 
(org.ovirt.thread.pool-8-thread-46) [] FINISH, HSMClearTaskVDSCommand, 
log id: 35bd0ad7
2016-01-26 15:00:50,793 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] 
(org.ovirt.thread.pool-8-thread-46) [] FINISH, SPMClearTaskVDSCommand, 
log id: 543d8586
2016-01-26 15:00:50,800 INFO 
[org.ovirt.engine.core.bll.tasks.SPMAsyncTask] 
(org.ovirt.thread.pool-8-thread-46) [] BaseAsyncTask::removeTaskFromDB: 
Removed task 'bf3ef9aa-5099-47b6-b954-9a6902eb17c9' from DataBase
2016-01-26 15:00:50,800 INFO 
[org.ovirt.engine.core.bll.tasks.SPMAsyncTask] 
(org.ovirt.thread.pool-8-thread-46) [] SPMAsyncTask::ClearAsyncTask: 
Attempting to clear task 'b910d97d-a091-4648-8840-e870651745c7'
2016-01-26 15:00:50,802 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] 
(org.ovirt.thread.pool-8-thread-46) [] START, SPMClearTaskVDSCommand( 
SPMTaskGuidBaseVDSCommandParameters:{runAsync='true', 
storagePoolId='00000001-0001-0001-0001-000000000296', 
ignoreFailoverLimit='false', 
taskId='b910d97d-a091-4648-8840-e870651745c7'}), log id: 1ded2669
2016-01-26 15:00:50,803 INFO 
[org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] 
(org.ovirt.thread.pool-8-thread-46) [] START, 
HSMClearTaskVDSCommand(HostName = kvm02, 
HSMTaskGuidBaseVDSCommandParameters:{runAsync='true', 
hostId='572aa833-37fb-4c4b-9576-9d367def2d04', 
taskId='b910d97d-a091-4648-8840-e870651745c7'}), log id: 60352414
2016-01-26 15:00:51,824 INFO 
[org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] 
(org.ovirt.thread.pool-8-thread-46) [] FINISH, HSMClearTaskVDSCommand, 
log id: 60352414
2016-01-26 15:00:51,824 INFO 
[org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] 
(org.ovirt.thread.pool-8-thread-46) [] FINISH, SPMClearTaskVDSCommand, 
log id: 1ded2669
2016-01-26 15:00:51,847 INFO 
[org.ovirt.engine.core.bll.tasks.SPMAsyncTask] 
(org.ovirt.thread.pool-8-thread-46) [] BaseAsyncTask::removeTaskFromDB: 
Removed task 'b910d97d-a091-4648-8840-e870651745c7' from DataBase
2016-01-26 15:00:51,848 INFO 
[org.ovirt.engine.core.bll.tasks.CommandAsyncTask] 
(org.ovirt.thread.pool-8-thread-46) [] 
CommandAsyncTask::HandleEndActionResult [within thread]: Removing 
CommandMultiAsyncTasks object for entity 
'aaac9162-4be3-473f-91f4-491c8eedb4ad'





More information about the Users mailing list