[ovirt-users] VM storage issue after snapshot deletion
Ollie Armstrong
ollie at fubra.com
Fri Aug 5 09:39:08 UTC 2016
Hi everyone.
I'm having an issue with a VM after initiating a snapshot deletion.
Shortly after the deletion started the VM was paused and has not
recovered since, this was over 12 hours ago.
I've dug into the logs and here's some things that jumped out at me:
engine.log
Message: VM XXXXXX has been paused due to unknown storage error.
vdsm.log
Improbable extension request for volume
cb180795-1da8-4a4c-90a9-b42d00485018 on domain
0243ebd9-fd3f-4674-b4e7-05af734280e7, pausing the VM to avoid
corruptions (capacity: 53687091200, allocated: 5750586880, physical:
1073741824, next physical size: 2147483648)
The vdsm.log line I've quoted is repeated approximately every 2
seconds from the first occurrence and is still going. I've attached
engine.log and uploaded vdsm.log to my server [1] as it was 10M. The
VM in question has the ID 184f89f4-8427-4a28-8787-8912f5c5f038.
The VM is still paused and cannot be resumed, seemingly as a
precaution to avoid corruption.
Is there anything I can do to recover the data on the disk? All help
is greatly appreciated.
I'm running oVirt 3.6.6.2-1 on CentOS 7.
Cheers,
Ollie
[1] https://ollie.io/vdsm.log
-------------- next part --------------
2016-08-04 16:25:12,089 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommand] (default task-1) [5af01e6f] Lock Acquired to object 'EngineLock:{exclusiveLocks='[b0bbb15d-a4a9-4618-addf-2f1126b5329f=<VM, ACTION_TYPE_FAILED_OBJECT_LOCKED>]', sharedLocks='null'}'
2016-08-04 16:25:12,379 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommand] (default task-1) [5af01e6f] Running command: RemoveSnapshotCommand internal: false. Entities affected : ID: b0bbb15d-a4a9-4618-addf-2f1126b5329f Type: VMAction group MANIPULATE_VM_SNAPSHOTS with role type USER
2016-08-04 16:25:12,443 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommand] (default task-1) [5af01e6f] Lock freed to object 'EngineLock:{exclusiveLocks='[b0bbb15d-a4a9-4618-addf-2f1126b5329f=<VM, ACTION_TYPE_FAILED_OBJECT_LOCKED>]', sharedLocks='null'}'
2016-08-04 16:25:12,743 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (pool-7-thread-4) [68e30f6] Running command: RemoveSnapshotSingleDiskLiveCommand internal: true. Entities affected : ID: 00000000-0000-0000-0000-000000000000 Type: Storage
2016-08-04 16:25:12,779 INFO [org.ovirt.engine.core.bll.RemoveMemoryVolumesCommand] (pool-7-thread-3) [55999e4] Running command: RemoveMemoryVolumesCommand internal: true.
2016-08-04 16:25:12,854 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (default task-1) [] Correlation ID: 5af01e6f, Job ID: 7849d658-1f5e-410f-a486-a17dc97d9dd6, Call Stack: null, Custom Event ID: -1, Message: Snapshot 'before-ipa-client' deletion for VM 'insanesql2' was initiated by admin at internal.
2016-08-04 16:25:12,888 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] (pool-7-thread-3) [55999e4] START, DeleteImageGroupVDSCommand( DeleteImageGroupVDSCommandParameters:{runAsync='true', storagePoolId='00000001-0001-0001-0001-000000000059', ignoreFailoverLimit='false', storageDomainId='4a993755-97e9-429c-ad64-96a6aabd2bc6', imageGroupId='f3b41d7d-ec8d-4607-8283-5ef45bce6465', postZeros='false', forceDelete='false'}), log id: 3892e799
2016-08-04 16:25:14,622 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] (pool-7-thread-3) [55999e4] FINISH, DeleteImageGroupVDSCommand, log id: 3892e799
2016-08-04 16:25:14,625 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (pool-7-thread-3) [55999e4] CommandAsyncTask::Adding CommandMultiAsyncTasks object for command 'a4f85f6a-6611-4c4e-8728-b212c307946a'
2016-08-04 16:25:14,625 INFO [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (pool-7-thread-3) [55999e4] CommandMultiAsyncTasks::AttachTask: Attaching task '006cb3d9-2a2c-41b4-867f-71c2d2c82180' to command 'a4f85f6a-6611-4c4e-8728-b212c307946a'.
2016-08-04 16:25:14,688 INFO [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (pool-7-thread-3) [55999e4] Adding task '006cb3d9-2a2c-41b4-867f-71c2d2c82180' (Parent Command 'RemoveMemoryVolumes', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters'), polling hasn't started yet..
2016-08-04 16:25:14,761 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] (pool-7-thread-3) [55999e4] START, DeleteImageGroupVDSCommand( DeleteImageGroupVDSCommandParameters:{runAsync='true', storagePoolId='00000001-0001-0001-0001-000000000059', ignoreFailoverLimit='false', storageDomainId='4a993755-97e9-429c-ad64-96a6aabd2bc6', imageGroupId='b656f279-6f45-43cf-8226-d960ad09be0b', postZeros='false', forceDelete='false'}), log id: 179dd30b
2016-08-04 16:25:14,784 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-72) [68e30f6] Executing Live Merge command step 'EXTEND'
2016-08-04 16:25:14,825 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-72) [] Waiting on Live Merge child commands to complete
2016-08-04 16:25:14,838 INFO [org.ovirt.engine.core.bll.MergeExtendCommand] (pool-7-thread-8) [2f30f4fc] Running command: MergeExtendCommand internal: true. Entities affected : ID: 4a993755-97e9-429c-ad64-96a6aabd2bc6 Type: Storage
2016-08-04 16:25:14,838 INFO [org.ovirt.engine.core.bll.MergeExtendCommand] (pool-7-thread-8) [2f30f4fc] Base and top image sizes are the same; no image size update required
2016-08-04 16:25:16,448 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] (pool-7-thread-3) [55999e4] FINISH, DeleteImageGroupVDSCommand, log id: 179dd30b
2016-08-04 16:25:16,467 INFO [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (pool-7-thread-3) [55999e4] CommandMultiAsyncTasks::AttachTask: Attaching task '3a83616d-5640-4112-a099-1f2dcc599a1f' to command 'a4f85f6a-6611-4c4e-8728-b212c307946a'.
2016-08-04 16:25:16,505 INFO [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (pool-7-thread-3) [55999e4] Adding task '3a83616d-5640-4112-a099-1f2dcc599a1f' (Parent Command 'RemoveMemoryVolumes', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters'), polling hasn't started yet..
2016-08-04 16:25:16,578 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (pool-7-thread-3) [55999e4] BaseAsyncTask::startPollingTask: Starting to poll task '006cb3d9-2a2c-41b4-867f-71c2d2c82180'.
2016-08-04 16:25:16,578 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (pool-7-thread-3) [55999e4] BaseAsyncTask::startPollingTask: Starting to poll task '3a83616d-5640-4112-a099-1f2dcc599a1f'.
2016-08-04 16:25:16,885 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-43) [68e30f6] Executing Live Merge command step 'MERGE'
2016-08-04 16:25:16,951 INFO [org.ovirt.engine.core.bll.MergeCommand] (pool-7-thread-6) [2812157e] Running command: MergeCommand internal: true. Entities affected : ID: 4a993755-97e9-429c-ad64-96a6aabd2bc6 Type: Storage
2016-08-04 16:25:16,952 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand] (pool-7-thread-6) [2812157e] START, MergeVDSCommand(HostName = host01, MergeVDSCommandParameters:{runAsync='true', hostId='06eb2185-fa65-4ca7-ac6d-279d3ed2ffe5', vmId='b0bbb15d-a4a9-4618-addf-2f1126b5329f', storagePoolId='00000001-0001-0001-0001-000000000059', storageDomainId='4a993755-97e9-429c-ad64-96a6aabd2bc6', imageGroupId='b5074e82-10a6-4033-918f-2ff49d7a2f81', imageId='7623bb55-212c-4849-8cad-5b9e7d76f14b', baseImageId='6525cd3a-88db-46f1-995b-2368fc9cc4e4', topImageId='7623bb55-212c-4849-8cad-5b9e7d76f14b', bandwidth='0'}), log id: 47817000
2016-08-04 16:25:18,017 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand] (pool-7-thread-6) [2812157e] FINISH, MergeVDSCommand, return: 19d293b8-ab41-4ab0-b0f4-5da9b54e078f, log id: 47817000
2016-08-04 16:25:18,022 INFO [org.ovirt.engine.core.bll.MergeCommand] (pool-7-thread-6) [2812157e] Stored placeholder for job id '19d293b8-ab41-4ab0-b0f4-5da9b54e078f'
2016-08-04 16:25:18,961 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-80) [68e30f6] Waiting on Live Merge command step 'MERGE' to complete
2016-08-04 16:25:18,961 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-80) [68e30f6] Waiting on Live Merge child commands to complete
2016-08-04 16:25:19,969 INFO [org.ovirt.engine.core.bll.MergeCommandCallback] (DefaultQuartzScheduler_Worker-83) [2812157e] Waiting on merge command to complete
2016-08-04 16:25:22,991 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-20) [68e30f6] Waiting on Live Merge command step 'MERGE' to complete
2016-08-04 16:25:23,453 WARN [org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerObjectsBuilder] (DefaultQuartzScheduler_Worker-79) [2a2a8597] Invalid or unknown guest architecture type '' received from guest agent
2016-08-04 16:25:24,015 INFO [org.ovirt.engine.core.bll.MergeCommandCallback] (DefaultQuartzScheduler_Worker-84) [2812157e] Waiting on merge command to complete
2016-08-04 16:25:25,342 INFO [org.ovirt.engine.core.vdsbroker.VmAnalyzer] (DefaultQuartzScheduler_Worker-60) [5a785306] VM job '19d293b8-ab41-4ab0-b0f4-5da9b54e078f': In progress, updating
2016-08-04 16:25:25,630 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-10) [34a83044] Task id '006cb3d9-2a2c-41b4-867f-71c2d2c82180' is in pre-polling period and should not be polled. Pre-polling period is 60000 millis.
2016-08-04 16:25:25,630 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-10) [34a83044] Task id '3a83616d-5640-4112-a099-1f2dcc599a1f' is in pre-polling period and should not be polled. Pre-polling period is 60000 millis.
2016-08-04 16:25:27,203 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-61) [71801ac4] Waiting on Live Merge child commands to complete
2016-08-04 16:25:31,237 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-19) [68e30f6] Waiting on Live Merge command step 'MERGE' to complete
2016-08-04 16:25:32,243 INFO [org.ovirt.engine.core.bll.MergeCommandCallback] (DefaultQuartzScheduler_Worker-44) [2812157e] Waiting on merge command to complete
2016-08-04 16:25:35,631 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-95) [2ce25660] Task id '006cb3d9-2a2c-41b4-867f-71c2d2c82180' is in pre-polling period and should not be polled. Pre-polling period is 60000 millis.
2016-08-04 16:25:35,631 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-95) [2ce25660] Task id '3a83616d-5640-4112-a099-1f2dcc599a1f' is in pre-polling period and should not be polled. Pre-polling period is 60000 millis.
2016-08-04 16:25:37,246 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-43) [] Waiting on Live Merge child commands to complete
2016-08-04 16:25:38,839 WARN [org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerObjectsBuilder] (DefaultQuartzScheduler_Worker-26) [2c3f8ac7] Invalid or unknown guest architecture type '' received from guest agent
2016-08-04 16:25:40,695 INFO [org.ovirt.engine.core.vdsbroker.VmAnalyzer] (DefaultQuartzScheduler_Worker-38) [34a83044] VM job '19d293b8-ab41-4ab0-b0f4-5da9b54e078f': In progress, updating
2016-08-04 16:25:41,272 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-40) [68e30f6] Waiting on Live Merge command step 'MERGE' to complete
2016-08-04 16:25:42,285 INFO [org.ovirt.engine.core.bll.MergeCommandCallback] (DefaultQuartzScheduler_Worker-96) [2812157e] Waiting on merge command to complete
2016-08-04 16:25:45,632 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-69) [2c3f8ac7] Task id '006cb3d9-2a2c-41b4-867f-71c2d2c82180' is in pre-polling period and should not be polled. Pre-polling period is 60000 millis.
2016-08-04 16:25:45,632 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-69) [2c3f8ac7] Task id '3a83616d-5640-4112-a099-1f2dcc599a1f' is in pre-polling period and should not be polled. Pre-polling period is 60000 millis.
2016-08-04 16:25:47,036 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommand] (default task-11) [38889b3e] Lock Acquired to object 'EngineLock:{exclusiveLocks='[184f89f4-8427-4a28-8787-8912f5c5f038=<VM, ACTION_TYPE_FAILED_OBJECT_LOCKED>]', sharedLocks='null'}'
2016-08-04 16:25:47,284 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommand] (default task-11) [38889b3e] Running command: RemoveSnapshotCommand internal: false. Entities affected : ID: 184f89f4-8427-4a28-8787-8912f5c5f038 Type: VMAction group MANIPULATE_VM_SNAPSHOTS with role type USER
2016-08-04 16:25:47,302 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-47) [1359b200] Waiting on Live Merge child commands to complete
2016-08-04 16:25:47,312 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommand] (default task-11) [38889b3e] Lock freed to object 'EngineLock:{exclusiveLocks='[184f89f4-8427-4a28-8787-8912f5c5f038=<VM, ACTION_TYPE_FAILED_OBJECT_LOCKED>]', sharedLocks='null'}'
2016-08-04 16:25:47,375 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (pool-7-thread-10) [c62bf6a] Running command: RemoveSnapshotSingleDiskLiveCommand internal: true. Entities affected : ID: 00000000-0000-0000-0000-000000000000 Type: Storage
2016-08-04 16:25:47,402 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (pool-7-thread-1) [76a027e3] Running command: RemoveSnapshotSingleDiskLiveCommand internal: true. Entities affected : ID: 00000000-0000-0000-0000-000000000000 Type: Storage
2016-08-04 16:25:47,416 INFO [org.ovirt.engine.core.bll.RemoveMemoryVolumesCommand] (pool-7-thread-2) [16ff4a8] Running command: RemoveMemoryVolumesCommand internal: true.
2016-08-04 16:25:47,461 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (default task-11) [] Correlation ID: 38889b3e, Job ID: 809df857-b2c7-403c-88b3-03ce611f2a97, Call Stack: null, Custom Event ID: -1, Message: Snapshot 'before-ipa-client' deletion for VM 'linkdb.mch.catn.com' was initiated by admin at internal.
2016-08-04 16:25:47,495 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] (pool-7-thread-2) [16ff4a8] START, DeleteImageGroupVDSCommand( DeleteImageGroupVDSCommandParameters:{runAsync='true', storagePoolId='00000001-0001-0001-0001-000000000059', ignoreFailoverLimit='false', storageDomainId='0243ebd9-fd3f-4674-b4e7-05af734280e7', imageGroupId='f11f3eac-c931-4635-81e6-e02d63e079fb', postZeros='false', forceDelete='false'}), log id: 56ca0a72
2016-08-04 16:25:48,319 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-64) [c62bf6a] Executing Live Merge command step 'EXTEND'
2016-08-04 16:25:48,364 INFO [org.ovirt.engine.core.bll.MergeExtendCommand] (pool-7-thread-5) [3a095284] Running command: MergeExtendCommand internal: true. Entities affected : ID: 0243ebd9-fd3f-4674-b4e7-05af734280e7 Type: Storage
2016-08-04 16:25:48,364 INFO [org.ovirt.engine.core.bll.MergeExtendCommand] (pool-7-thread-5) [3a095284] Base and top image sizes are the same; no image size update required
2016-08-04 16:25:48,371 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-64) [76a027e3] Executing Live Merge command step 'EXTEND'
2016-08-04 16:25:48,416 INFO [org.ovirt.engine.core.bll.MergeExtendCommand] (pool-7-thread-7) [57441709] Running command: MergeExtendCommand internal: true. Entities affected : ID: 0243ebd9-fd3f-4674-b4e7-05af734280e7 Type: Storage
2016-08-04 16:25:48,416 INFO [org.ovirt.engine.core.bll.MergeExtendCommand] (pool-7-thread-7) [57441709] Base and top image sizes are the same; no image size update required
2016-08-04 16:25:49,469 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-98) [] Waiting on Live Merge child commands to complete
2016-08-04 16:25:49,495 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-98) [76a027e3] Executing Live Merge command step 'MERGE'
2016-08-04 16:25:49,762 INFO [org.ovirt.engine.core.bll.MergeCommand] (pool-7-thread-9) [2ed02b01] Running command: MergeCommand internal: true. Entities affected : ID: 0243ebd9-fd3f-4674-b4e7-05af734280e7 Type: Storage
2016-08-04 16:25:49,765 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand] (pool-7-thread-9) [2ed02b01] START, MergeVDSCommand(HostName = host01, MergeVDSCommandParameters:{runAsync='true', hostId='06eb2185-fa65-4ca7-ac6d-279d3ed2ffe5', vmId='184f89f4-8427-4a28-8787-8912f5c5f038', storagePoolId='00000001-0001-0001-0001-000000000059', storageDomainId='0243ebd9-fd3f-4674-b4e7-05af734280e7', imageGroupId='9ac87749-388c-4a47-a779-86049966a647', imageId='cb180795-1da8-4a4c-90a9-b42d00485018', baseImageId='d9e812e9-19fd-4b45-a806-23513f13dd2d', topImageId='cb180795-1da8-4a4c-90a9-b42d00485018', bandwidth='0'}), log id: 3380ad78
2016-08-04 16:25:50,685 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-13) [c62bf6a] Executing Live Merge command step 'MERGE'
2016-08-04 16:25:50,777 INFO [org.ovirt.engine.core.bll.MergeCommand] (pool-7-thread-4) [33328a2b] Running command: MergeCommand internal: true. Entities affected : ID: 0243ebd9-fd3f-4674-b4e7-05af734280e7 Type: Storage
2016-08-04 16:25:50,778 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand] (pool-7-thread-4) [33328a2b] START, MergeVDSCommand(HostName = host01, MergeVDSCommandParameters:{runAsync='true', hostId='06eb2185-fa65-4ca7-ac6d-279d3ed2ffe5', vmId='184f89f4-8427-4a28-8787-8912f5c5f038', storagePoolId='00000001-0001-0001-0001-000000000059', storageDomainId='0243ebd9-fd3f-4674-b4e7-05af734280e7', imageGroupId='06a3338e-83a4-4ea0-b71e-83d8b6f08aac', imageId='21244552-0416-47af-909f-b66c6ff08418', baseImageId='bfdaee52-07fa-449a-b570-81f83d8099e1', topImageId='21244552-0416-47af-909f-b66c6ff08418', bandwidth='0'}), log id: 5cf03e1d
2016-08-04 16:25:51,176 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] (pool-7-thread-2) [16ff4a8] FINISH, DeleteImageGroupVDSCommand, log id: 56ca0a72
2016-08-04 16:25:51,179 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (pool-7-thread-2) [16ff4a8] CommandAsyncTask::Adding CommandMultiAsyncTasks object for command '0e512a43-ba26-4e93-a187-06fb8526e035'
2016-08-04 16:25:51,179 INFO [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (pool-7-thread-2) [16ff4a8] CommandMultiAsyncTasks::AttachTask: Attaching task '6150bc0e-3ac7-4ee4-a1ba-8106261eb5f4' to command '0e512a43-ba26-4e93-a187-06fb8526e035'.
2016-08-04 16:25:51,191 INFO [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (pool-7-thread-2) [16ff4a8] Adding task '6150bc0e-3ac7-4ee4-a1ba-8106261eb5f4' (Parent Command 'RemoveMemoryVolumes', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters'), polling hasn't started yet..
2016-08-04 16:25:51,205 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] (pool-7-thread-2) [16ff4a8] START, DeleteImageGroupVDSCommand( DeleteImageGroupVDSCommandParameters:{runAsync='true', storagePoolId='00000001-0001-0001-0001-000000000059', ignoreFailoverLimit='false', storageDomainId='0243ebd9-fd3f-4674-b4e7-05af734280e7', imageGroupId='12953827-b0ba-4b78-8655-5fad87976528', postZeros='false', forceDelete='false'}), log id: 24fa83a2
2016-08-04 16:25:51,206 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand] (pool-7-thread-9) [2ed02b01] FINISH, MergeVDSCommand, return: ecb7267c-2d51-425c-a924-07fa109e1a5e, log id: 3380ad78
2016-08-04 16:25:51,209 INFO [org.ovirt.engine.core.bll.MergeCommand] (pool-7-thread-9) [2ed02b01] Stored placeholder for job id 'ecb7267c-2d51-425c-a924-07fa109e1a5e'
2016-08-04 16:25:51,742 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-53) [68e30f6] Waiting on Live Merge command step 'MERGE' to complete
2016-08-04 16:25:51,753 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-53) [76a027e3] Waiting on Live Merge command step 'MERGE' to complete
2016-08-04 16:25:52,762 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-19) [c62bf6a] Waiting on Live Merge command step 'MERGE' to complete
2016-08-04 16:25:52,770 INFO [org.ovirt.engine.core.bll.MergeCommandCallback] (DefaultQuartzScheduler_Worker-19) [2ed02b01] Waiting on merge command to complete
2016-08-04 16:25:52,775 INFO [org.ovirt.engine.core.bll.MergeCommandCallback] (DefaultQuartzScheduler_Worker-19) [2812157e] Waiting on merge command to complete
2016-08-04 16:25:53,776 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-57) [e97ce78] Waiting on Live Merge child commands to complete
2016-08-04 16:25:54,245 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] (pool-7-thread-2) [16ff4a8] FINISH, DeleteImageGroupVDSCommand, log id: 24fa83a2
2016-08-04 16:25:54,247 INFO [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (pool-7-thread-2) [16ff4a8] CommandMultiAsyncTasks::AttachTask: Attaching task 'ce1e1711-5d15-4aa1-8494-e25d91923cf8' to command '0e512a43-ba26-4e93-a187-06fb8526e035'.
2016-08-04 16:25:54,276 INFO [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (pool-7-thread-2) [16ff4a8] Adding task 'ce1e1711-5d15-4aa1-8494-e25d91923cf8' (Parent Command 'RemoveMemoryVolumes', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters'), polling hasn't started yet..
2016-08-04 16:25:54,295 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (pool-7-thread-2) [16ff4a8] BaseAsyncTask::startPollingTask: Starting to poll task '6150bc0e-3ac7-4ee4-a1ba-8106261eb5f4'.
2016-08-04 16:25:54,295 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (pool-7-thread-2) [16ff4a8] BaseAsyncTask::startPollingTask: Starting to poll task 'ce1e1711-5d15-4aa1-8494-e25d91923cf8'.
2016-08-04 16:25:54,302 WARN [org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerObjectsBuilder] (DefaultQuartzScheduler_Worker-31) [71801ac4] Invalid or unknown guest architecture type '' received from guest agent
2016-08-04 16:25:55,633 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-32) [2ce25660] Task id '006cb3d9-2a2c-41b4-867f-71c2d2c82180' is in pre-polling period and should not be polled. Pre-polling period is 60000 millis.
2016-08-04 16:25:55,633 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-32) [2ce25660] Task id 'ce1e1711-5d15-4aa1-8494-e25d91923cf8' is in pre-polling period and should not be polled. Pre-polling period is 60000 millis.
2016-08-04 16:25:55,633 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-32) [2ce25660] Task id '6150bc0e-3ac7-4ee4-a1ba-8106261eb5f4' is in pre-polling period and should not be polled. Pre-polling period is 60000 millis.
2016-08-04 16:25:55,633 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-32) [2ce25660] Task id '3a83616d-5640-4112-a099-1f2dcc599a1f' is in pre-polling period and should not be polled. Pre-polling period is 60000 millis.
2016-08-04 16:25:55,804 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-72) [76a027e3] Waiting on Live Merge command step 'MERGE' to complete
2016-08-04 16:25:56,254 INFO [org.ovirt.engine.core.vdsbroker.VmAnalyzer] (DefaultQuartzScheduler_Worker-95) [2ce25660] VM job '19d293b8-ab41-4ab0-b0f4-5da9b54e078f': In progress, updating
2016-08-04 16:25:56,294 INFO [org.ovirt.engine.core.vdsbroker.VmAnalyzer] (DefaultQuartzScheduler_Worker-95) [2ce25660] VM job 'ecb7267c-2d51-425c-a924-07fa109e1a5e': In progress, updating
2016-08-04 16:25:56,305 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.FullListVDSCommand] (DefaultQuartzScheduler_Worker-95) [2ce25660] START, FullListVDSCommand(HostName = , FullListVDSCommandParameters:{runAsync='true', hostId='06eb2185-fa65-4ca7-ac6d-279d3ed2ffe5', vds='Host[,06eb2185-fa65-4ca7-ac6d-279d3ed2ffe5]', vmIds='[184f89f4-8427-4a28-8787-8912f5c5f038]'}), log id: 156b6236
2016-08-04 16:25:56,324 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.FullListVDSCommand] (DefaultQuartzScheduler_Worker-95) [2ce25660] FINISH, FullListVDSCommand, return: [{acpiEnable=true, emulatedMachine=pc-i440fx-rhel7.2.0, tabletEnable=true, pid=7058, memGuaranteedSize=256, transparentHugePages=true, displayPort=5905, displaySecurePort=-1, spiceSslCipherSuite=DEFAULT, cpuType=Westmere, smp=1, pauseCode=NOERR, guestNumaNodes=[Ljava.lang.Object;@12aceb43, smartcardEnable=false, custom={device_906e2f3e-d7d0-4552-981d-02653e5e969f=VmDevice:{id='VmDeviceId:{deviceId='906e2f3e-d7d0-4552-981d-02653e5e969f', vmId='184f89f4-8427-4a28-8787-8912f5c5f038'}', 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='ide', customProperties='[]', snapshotId='null', logicalName='null', usingScsiReservation='false'}, device_906e2f3e-d7d0-4552-981d-02653e5e969fdevice_6cf91500-0cea-45f8-983d-0925ac5181c5device_2699bee8-965b-4c0e-b275-bcc5433bb396=VmDevice:{id='VmDeviceId:{deviceId='2699bee8-965b-4c0e-b275-bcc5433bb396', vmId='184f89f4-8427-4a28-8787-8912f5c5f038'}', 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_906e2f3e-d7d0-4552-981d-02653e5e969fdevice_6cf91500-0cea-45f8-983d-0925ac5181c5=VmDevice:{id='VmDeviceId:{deviceId='6cf91500-0cea-45f8-983d-0925ac5181c5', vmId='184f89f4-8427-4a28-8787-8912f5c5f038'}', 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'}}, vmType=kvm, memSize=1024, smpCoresPerSocket=1, vmName=linkdb.mch.catn.com, nice=0, status=Up, maxMemSize=4194304, bootMenuEnable=false, vmId=184f89f4-8427-4a28-8787-8912f5c5f038, displayIp=0, smpThreadsPerCore=1, guestDiskMapping={06a3338e-83a4-4ea0-b={name=/dev/vdb}, 9ac87749-388c-4a47-a={name=/dev/vda}, QEMU_DVD-ROM_QM00003={name=/dev/sr0}}, spiceSecureChannels=smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard, nicModel=rtl8139,pv, keyboardLayout=en-us, kvmEnable=true, pitReinjection=false, devices=[Ljava.lang.Object;@4f41814c, display=vnc, timeOffset=0, maxVCpus=16, clientIp=, statusTime=5789377900, maxMemSlots=16}], log id: 156b6236
2016-08-04 16:25:56,332 INFO [org.ovirt.engine.core.vdsbroker.VmsMonitoring] (DefaultQuartzScheduler_Worker-95) [2ce25660] Received a vnc Device without an address when processing VM 184f89f4-8427-4a28-8787-8912f5c5f038 devices, skipping device: {specParams={displayIp=0}, deviceType=graphics, deviceId=1969c6e0-3c4d-44cb-9f6c-b5e3b2dc7202, device=vnc, type=graphics, port=5905}
2016-08-04 16:25:56,813 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-11) [c62bf6a] Waiting on Live Merge command step 'MERGE' to complete
2016-08-04 16:25:56,817 INFO [org.ovirt.engine.core.bll.MergeCommandCallback] (DefaultQuartzScheduler_Worker-11) [2ed02b01] Waiting on merge command to complete
2016-08-04 16:25:57,818 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-1) [] Waiting on Live Merge child commands to complete
2016-08-04 16:26:01,852 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-88) [68e30f6] Waiting on Live Merge command step 'MERGE' to complete
2016-08-04 16:26:01,853 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-88) [68e30f6] Waiting on Live Merge child commands to complete
2016-08-04 16:26:02,861 INFO [org.ovirt.engine.core.bll.MergeCommandCallback] (DefaultQuartzScheduler_Worker-15) [2812157e] Waiting on merge command to complete
2016-08-04 16:26:03,868 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-96) [76a027e3] Waiting on Live Merge command step 'MERGE' to complete
2016-08-04 16:26:04,889 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-12) [c62bf6a] Waiting on Live Merge command step 'MERGE' to complete
2016-08-04 16:26:04,894 INFO [org.ovirt.engine.core.bll.MergeCommandCallback] (DefaultQuartzScheduler_Worker-12) [2ed02b01] Waiting on merge command to complete
2016-08-04 16:26:05,642 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-7) [] Task id '006cb3d9-2a2c-41b4-867f-71c2d2c82180' is in pre-polling period and should not be polled. Pre-polling period is 60000 millis.
2016-08-04 16:26:05,642 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-7) [] Task id 'ce1e1711-5d15-4aa1-8494-e25d91923cf8' is in pre-polling period and should not be polled. Pre-polling period is 60000 millis.
2016-08-04 16:26:05,642 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-7) [] Task id '6150bc0e-3ac7-4ee4-a1ba-8106261eb5f4' is in pre-polling period and should not be polled. Pre-polling period is 60000 millis.
2016-08-04 16:26:05,642 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-7) [] Task id '3a83616d-5640-4112-a099-1f2dcc599a1f' is in pre-polling period and should not be polled. Pre-polling period is 60000 millis.
2016-08-04 16:26:07,909 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-10) [34a83044] Waiting on Live Merge child commands to complete
2016-08-04 16:26:09,846 WARN [org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerObjectsBuilder] (DefaultQuartzScheduler_Worker-48) [34a83044] Invalid or unknown guest architecture type '' received from guest agent
2016-08-04 16:26:11,631 INFO [org.ovirt.engine.core.vdsbroker.VmAnalyzer] (DefaultQuartzScheduler_Worker-56) [2a2a8597] VM job '19d293b8-ab41-4ab0-b0f4-5da9b54e078f': In progress (no change)
2016-08-04 16:26:11,684 INFO [org.ovirt.engine.core.vdsbroker.VmAnalyzer] (DefaultQuartzScheduler_Worker-56) [2a2a8597] VM job 'ecb7267c-2d51-425c-a924-07fa109e1a5e': In progress (no change)
2016-08-04 16:26:11,925 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-53) [68e30f6] Waiting on Live Merge command step 'MERGE' to complete
2016-08-04 16:26:11,925 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-53) [68e30f6] Waiting on Live Merge child commands to complete
2016-08-04 16:26:12,931 INFO [org.ovirt.engine.core.bll.MergeCommandCallback] (DefaultQuartzScheduler_Worker-85) [2812157e] Waiting on merge command to complete
2016-08-04 16:26:13,964 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-36) [76a027e3] Waiting on Live Merge command step 'MERGE' to complete
2016-08-04 16:26:14,973 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-35) [c62bf6a] Waiting on Live Merge command step 'MERGE' to complete
2016-08-04 16:26:14,978 INFO [org.ovirt.engine.core.bll.MergeCommandCallback] (DefaultQuartzScheduler_Worker-35) [2ed02b01] Waiting on merge command to complete
2016-08-04 16:26:15,643 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-22) [71801ac4] Task id '006cb3d9-2a2c-41b4-867f-71c2d2c82180' has passed pre-polling period time and should be polled. Pre-polling period is 60000 millis.
2016-08-04 16:26:15,643 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-22) [71801ac4] Task id '006cb3d9-2a2c-41b4-867f-71c2d2c82180' has passed pre-polling period time and should be polled. Pre-polling period is 60000 millis.
2016-08-04 16:26:15,643 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-22) [71801ac4] Task id 'ce1e1711-5d15-4aa1-8494-e25d91923cf8' is in pre-polling period and should not be polled. Pre-polling period is 60000 millis.
2016-08-04 16:26:15,643 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-22) [71801ac4] Task id '6150bc0e-3ac7-4ee4-a1ba-8106261eb5f4' is in pre-polling period and should not be polled. Pre-polling period is 60000 millis.
2016-08-04 16:26:15,643 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-22) [71801ac4] Task id '3a83616d-5640-4112-a099-1f2dcc599a1f' has passed pre-polling period time and should be polled. Pre-polling period is 60000 millis.
2016-08-04 16:26:15,643 INFO [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (DefaultQuartzScheduler_Worker-22) [71801ac4] Polling and updating Async Tasks: 4 tasks, 2 tasks to poll now
2016-08-04 16:26:15,643 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-22) [71801ac4] Task id '006cb3d9-2a2c-41b4-867f-71c2d2c82180' has passed pre-polling period time and should be polled. Pre-polling period is 60000 millis.
2016-08-04 16:26:15,644 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-22) [71801ac4] Task id 'ce1e1711-5d15-4aa1-8494-e25d91923cf8' is in pre-polling period and should not be polled. Pre-polling period is 60000 millis.
2016-08-04 16:26:15,644 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-22) [71801ac4] Task id '6150bc0e-3ac7-4ee4-a1ba-8106261eb5f4' is in pre-polling period and should not be polled. Pre-polling period is 60000 millis.
2016-08-04 16:26:15,644 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-22) [71801ac4] Task id '3a83616d-5640-4112-a099-1f2dcc599a1f' has passed pre-polling period time and should be polled. Pre-polling period is 60000 millis.
2016-08-04 16:26:16,193 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-22) [71801ac4] Task id '006cb3d9-2a2c-41b4-867f-71c2d2c82180' has passed pre-polling period time and should be polled. Pre-polling period is 60000 millis.
2016-08-04 16:26:16,193 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-22) [71801ac4] SPMAsyncTask::PollTask: Polling task '006cb3d9-2a2c-41b4-867f-71c2d2c82180' (Parent Command 'RemoveMemoryVolumes', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') returned status 'finished', result 'success'.
2016-08-04 16:26:16,194 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-22) [71801ac4] BaseAsyncTask::onTaskEndSuccess: Task '006cb3d9-2a2c-41b4-867f-71c2d2c82180' (Parent Command 'RemoveMemoryVolumes', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') ended successfully.
2016-08-04 16:26:16,194 INFO [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (DefaultQuartzScheduler_Worker-22) [71801ac4] Task with DB Task ID '609b20c3-ebb6-49d7-bef7-b1cc2a1908a1' and VDSM Task ID '3a83616d-5640-4112-a099-1f2dcc599a1f' is in state Polling. End action for command a4f85f6a-6611-4c4e-8728-b212c307946a will proceed when all the entity's tasks are completed.
2016-08-04 16:26:16,194 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-22) [71801ac4] Task id 'ce1e1711-5d15-4aa1-8494-e25d91923cf8' is in pre-polling period and should not be polled. Pre-polling period is 60000 millis.
2016-08-04 16:26:16,194 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-22) [71801ac4] Task id '6150bc0e-3ac7-4ee4-a1ba-8106261eb5f4' is in pre-polling period and should not be polled. Pre-polling period is 60000 millis.
2016-08-04 16:26:16,194 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-22) [71801ac4] Task id '3a83616d-5640-4112-a099-1f2dcc599a1f' has passed pre-polling period time and should be polled. Pre-polling period is 60000 millis.
2016-08-04 16:26:16,195 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-22) [71801ac4] SPMAsyncTask::PollTask: Polling task '3a83616d-5640-4112-a099-1f2dcc599a1f' (Parent Command 'RemoveMemoryVolumes', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') returned status 'finished', result 'success'.
2016-08-04 16:26:16,195 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-22) [71801ac4] BaseAsyncTask::onTaskEndSuccess: Task '3a83616d-5640-4112-a099-1f2dcc599a1f' (Parent Command 'RemoveMemoryVolumes', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') ended successfully.
2016-08-04 16:26:16,208 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (DefaultQuartzScheduler_Worker-22) [71801ac4] CommandAsyncTask::endActionIfNecessary: All tasks of command 'a4f85f6a-6611-4c4e-8728-b212c307946a' has ended -> executing 'endAction'
2016-08-04 16:26:16,208 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (DefaultQuartzScheduler_Worker-22) [71801ac4] CommandAsyncTask::endAction: Ending action for '2' tasks (command ID: 'a4f85f6a-6611-4c4e-8728-b212c307946a'): calling endAction '.
2016-08-04 16:26:16,208 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-22) [71801ac4] Task id 'ce1e1711-5d15-4aa1-8494-e25d91923cf8' is in pre-polling period and should not be polled. Pre-polling period is 60000 millis.
2016-08-04 16:26:16,209 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-22) [71801ac4] Task id '6150bc0e-3ac7-4ee4-a1ba-8106261eb5f4' is in pre-polling period and should not be polled. Pre-polling period is 60000 millis.
2016-08-04 16:26:16,209 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-5) [71801ac4] CommandAsyncTask::endCommandAction [within thread] context: Attempting to endAction 'RemoveMemoryVolumes', executionIndex: '0'
2016-08-04 16:26:16,217 INFO [org.ovirt.engine.core.bll.RemoveMemoryVolumesCommand] (org.ovirt.thread.pool-8-thread-5) [55999e4] Ending command 'org.ovirt.engine.core.bll.RemoveMemoryVolumesCommand' successfully.
2016-08-04 16:26:16,218 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-5) [55999e4] CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type 'RemoveMemoryVolumes' completed, handling the result.
2016-08-04 16:26:16,218 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-5) [55999e4] CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type 'RemoveMemoryVolumes' succeeded, clearing tasks.
2016-08-04 16:26:16,218 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (org.ovirt.thread.pool-8-thread-5) [55999e4] SPMAsyncTask::ClearAsyncTask: Attempting to clear task '006cb3d9-2a2c-41b4-867f-71c2d2c82180'
2016-08-04 16:26:16,220 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-5) [55999e4] START, SPMClearTaskVDSCommand( SPMTaskGuidBaseVDSCommandParameters:{runAsync='true', storagePoolId='00000001-0001-0001-0001-000000000059', ignoreFailoverLimit='false', taskId='006cb3d9-2a2c-41b4-867f-71c2d2c82180'}), log id: 1a17273a
2016-08-04 16:26:16,221 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-5) [55999e4] START, HSMClearTaskVDSCommand(HostName = host04, HSMTaskGuidBaseVDSCommandParameters:{runAsync='true', hostId='662a3ac1-19b4-4dde-9558-ebaeed4b8439', taskId='006cb3d9-2a2c-41b4-867f-71c2d2c82180'}), log id: 63622966
2016-08-04 16:26:16,312 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-5) [55999e4] FINISH, HSMClearTaskVDSCommand, log id: 63622966
2016-08-04 16:26:16,312 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-5) [55999e4] FINISH, SPMClearTaskVDSCommand, log id: 1a17273a
2016-08-04 16:26:16,323 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (org.ovirt.thread.pool-8-thread-5) [55999e4] BaseAsyncTask::removeTaskFromDB: Removed task '006cb3d9-2a2c-41b4-867f-71c2d2c82180' from DataBase
2016-08-04 16:26:16,324 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (org.ovirt.thread.pool-8-thread-5) [55999e4] SPMAsyncTask::ClearAsyncTask: Attempting to clear task '3a83616d-5640-4112-a099-1f2dcc599a1f'
2016-08-04 16:26:16,325 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-5) [55999e4] START, SPMClearTaskVDSCommand( SPMTaskGuidBaseVDSCommandParameters:{runAsync='true', storagePoolId='00000001-0001-0001-0001-000000000059', ignoreFailoverLimit='false', taskId='3a83616d-5640-4112-a099-1f2dcc599a1f'}), log id: b4e01f0
2016-08-04 16:26:16,326 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-5) [55999e4] START, HSMClearTaskVDSCommand(HostName = host04, HSMTaskGuidBaseVDSCommandParameters:{runAsync='true', hostId='662a3ac1-19b4-4dde-9558-ebaeed4b8439', taskId='3a83616d-5640-4112-a099-1f2dcc599a1f'}), log id: 3c2ee0d4
2016-08-04 16:26:16,592 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-5) [55999e4] FINISH, HSMClearTaskVDSCommand, log id: 3c2ee0d4
2016-08-04 16:26:16,593 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-5) [55999e4] FINISH, SPMClearTaskVDSCommand, log id: b4e01f0
2016-08-04 16:26:16,598 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (org.ovirt.thread.pool-8-thread-5) [55999e4] BaseAsyncTask::removeTaskFromDB: Removed task '3a83616d-5640-4112-a099-1f2dcc599a1f' from DataBase
2016-08-04 16:26:16,598 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-5) [55999e4] CommandAsyncTask::HandleEndActionResult [within thread]: Removing CommandMultiAsyncTasks object for entity 'a4f85f6a-6611-4c4e-8728-b212c307946a'
2016-08-04 16:26:17,041 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.MergeVDSCommand] (pool-7-thread-4) [33328a2b] FINISH, MergeVDSCommand, return: 1d057684-bf68-4345-b3da-a4ca31312953, log id: 5cf03e1d
2016-08-04 16:26:17,047 INFO [org.ovirt.engine.core.bll.MergeCommand] (pool-7-thread-4) [33328a2b] Stored placeholder for job id '1d057684-bf68-4345-b3da-a4ca31312953'
2016-08-04 16:26:17,979 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-95) [2ce25660] Waiting on Live Merge child commands to complete
2016-08-04 16:26:21,992 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-14) [68e30f6] Waiting on Live Merge command step 'MERGE' to complete
2016-08-04 16:26:21,992 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-14) [68e30f6] Waiting on Live Merge child commands to complete
2016-08-04 16:26:22,998 INFO [org.ovirt.engine.core.bll.MergeCommandCallback] (DefaultQuartzScheduler_Worker-83) [2812157e] Waiting on merge command to complete
2016-08-04 16:26:24,009 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-40) [76a027e3] Waiting on Live Merge command step 'MERGE' to complete
2016-08-04 16:26:25,018 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-30) [c62bf6a] Waiting on Live Merge command step 'MERGE' to complete
2016-08-04 16:26:25,024 INFO [org.ovirt.engine.core.bll.MergeCommandCallback] (DefaultQuartzScheduler_Worker-30) [2ed02b01] Waiting on merge command to complete
2016-08-04 16:26:25,284 WARN [org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerObjectsBuilder] (DefaultQuartzScheduler_Worker-77) [e97ce78] Invalid or unknown guest architecture type '' received from guest agent
2016-08-04 16:26:26,030 INFO [org.ovirt.engine.core.bll.MergeCommandCallback] (DefaultQuartzScheduler_Worker-7) [33328a2b] Waiting on merge command to complete
2016-08-04 16:26:26,210 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-17) [e97ce78] Task id 'ce1e1711-5d15-4aa1-8494-e25d91923cf8' is in pre-polling period and should not be polled. Pre-polling period is 60000 millis.
2016-08-04 16:26:26,210 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-17) [e97ce78] Task id '6150bc0e-3ac7-4ee4-a1ba-8106261eb5f4' is in pre-polling period and should not be polled. Pre-polling period is 60000 millis.
2016-08-04 16:26:26,952 INFO [org.ovirt.engine.core.vdsbroker.VmAnalyzer] (DefaultQuartzScheduler_Worker-5) [4f20d956] VM job '19d293b8-ab41-4ab0-b0f4-5da9b54e078f': In progress, updating
2016-08-04 16:26:27,004 INFO [org.ovirt.engine.core.vdsbroker.VmAnalyzer] (DefaultQuartzScheduler_Worker-5) [4f20d956] VM '184f89f4-8427-4a28-8787-8912f5c5f038'(linkdb.mch.catn.com) moved from 'Up' --> 'Paused'
2016-08-04 16:26:27,069 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-5) [4f20d956] Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: VM linkdb.mch.catn.com has been paused.
2016-08-04 16:26:27,193 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-5) [4f20d956] Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: VM linkdb.mch.catn.com has been paused due to unknown storage error.
2016-08-04 16:26:27,198 INFO [org.ovirt.engine.core.vdsbroker.VmAnalyzer] (DefaultQuartzScheduler_Worker-5) [4f20d956] VM job '1d057684-bf68-4345-b3da-a4ca31312953': In progress, updating
2016-08-04 16:26:27,198 INFO [org.ovirt.engine.core.vdsbroker.VmAnalyzer] (DefaultQuartzScheduler_Worker-5) [4f20d956] VM job 'ecb7267c-2d51-425c-a924-07fa109e1a5e': In progress (no change)
2016-08-04 16:26:27,212 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.FullListVDSCommand] (DefaultQuartzScheduler_Worker-5) [4f20d956] START, FullListVDSCommand(HostName = , FullListVDSCommandParameters:{runAsync='true', hostId='06eb2185-fa65-4ca7-ac6d-279d3ed2ffe5', vds='Host[,06eb2185-fa65-4ca7-ac6d-279d3ed2ffe5]', vmIds='[184f89f4-8427-4a28-8787-8912f5c5f038]'}), log id: e6b85cf
2016-08-04 16:26:28,031 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-89) [71801ac4] Waiting on Live Merge child commands to complete
2016-08-04 16:26:28,227 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.FullListVDSCommand] (DefaultQuartzScheduler_Worker-5) [4f20d956] FINISH, FullListVDSCommand, return: [{acpiEnable=true, emulatedMachine=pc-i440fx-rhel7.2.0, tabletEnable=true, pid=7058, memGuaranteedSize=256, transparentHugePages=true, displayPort=5905, displaySecurePort=-1, spiceSslCipherSuite=DEFAULT, cpuType=Westmere, smp=1, pauseCode=EOTHER, guestNumaNodes=[Ljava.lang.Object;@1aa30203, smartcardEnable=false, custom={device_906e2f3e-d7d0-4552-981d-02653e5e969f=VmDevice:{id='VmDeviceId:{deviceId='906e2f3e-d7d0-4552-981d-02653e5e969f', vmId='184f89f4-8427-4a28-8787-8912f5c5f038'}', 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='ide', customProperties='[]', snapshotId='null', logicalName='null', usingScsiReservation='false'}, device_906e2f3e-d7d0-4552-981d-02653e5e969fdevice_6cf91500-0cea-45f8-983d-0925ac5181c5device_2699bee8-965b-4c0e-b275-bcc5433bb396=VmDevice:{id='VmDeviceId:{deviceId='2699bee8-965b-4c0e-b275-bcc5433bb396', vmId='184f89f4-8427-4a28-8787-8912f5c5f038'}', 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_906e2f3e-d7d0-4552-981d-02653e5e969fdevice_6cf91500-0cea-45f8-983d-0925ac5181c5=VmDevice:{id='VmDeviceId:{deviceId='6cf91500-0cea-45f8-983d-0925ac5181c5', vmId='184f89f4-8427-4a28-8787-8912f5c5f038'}', 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'}}, vmType=kvm, memSize=1024, smpCoresPerSocket=1, vmName=linkdb.mch.catn.com, nice=0, status=Paused, maxMemSize=4194304, bootMenuEnable=false, vmId=184f89f4-8427-4a28-8787-8912f5c5f038, displayIp=0, smpThreadsPerCore=1, guestDiskMapping={06a3338e-83a4-4ea0-b={name=/dev/vdb}, 9ac87749-388c-4a47-a={name=/dev/vda}, QEMU_DVD-ROM_QM00003={name=/dev/sr0}}, spiceSecureChannels=smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard, nicModel=rtl8139,pv, keyboardLayout=en-us, kvmEnable=true, pitReinjection=false, devices=[Ljava.lang.Object;@6cb35622, display=vnc, timeOffset=0, maxVCpus=16, clientIp=, statusTime=5789408810, maxMemSlots=16}], log id: e6b85cf
2016-08-04 16:26:28,237 INFO [org.ovirt.engine.core.vdsbroker.VmsMonitoring] (DefaultQuartzScheduler_Worker-5) [4f20d956] Received a vnc Device without an address when processing VM 184f89f4-8427-4a28-8787-8912f5c5f038 devices, skipping device: {specParams={displayIp=0}, deviceType=graphics, deviceId=1969c6e0-3c4d-44cb-9f6c-b5e3b2dc7202, device=vnc, type=graphics, port=5905}
2016-08-04 16:26:32,048 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-73) [68e30f6] Waiting on Live Merge command step 'MERGE' to complete
2016-08-04 16:26:32,048 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-73) [68e30f6] Waiting on Live Merge child commands to complete
2016-08-04 16:26:33,055 INFO [org.ovirt.engine.core.bll.MergeCommandCallback] (DefaultQuartzScheduler_Worker-9) [2812157e] Waiting on merge command to complete
2016-08-04 16:26:34,066 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-4) [76a027e3] Waiting on Live Merge command step 'MERGE' to complete
2016-08-04 16:26:35,110 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-23) [c62bf6a] Waiting on Live Merge command step 'MERGE' to complete
2016-08-04 16:26:35,130 INFO [org.ovirt.engine.core.bll.MergeCommandCallback] (DefaultQuartzScheduler_Worker-23) [2ed02b01] Waiting on merge command to complete
2016-08-04 16:26:36,145 INFO [org.ovirt.engine.core.bll.MergeCommandCallback] (DefaultQuartzScheduler_Worker-57) [33328a2b] Waiting on merge command to complete
2016-08-04 16:26:36,211 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-63) [34a83044] Task id 'ce1e1711-5d15-4aa1-8494-e25d91923cf8' is in pre-polling period and should not be polled. Pre-polling period is 60000 millis.
2016-08-04 16:26:36,211 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-63) [34a83044] Task id '6150bc0e-3ac7-4ee4-a1ba-8106261eb5f4' is in pre-polling period and should not be polled. Pre-polling period is 60000 millis.
2016-08-04 16:26:38,147 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-76) [2ce25660] Waiting on Live Merge child commands to complete
2016-08-04 16:26:40,674 WARN [org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerObjectsBuilder] (DefaultQuartzScheduler_Worker-16) [2c3f8ac7] Invalid or unknown guest architecture type '' received from guest agent
2016-08-04 16:26:42,172 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-94) [68e30f6] Waiting on Live Merge command step 'MERGE' to complete
2016-08-04 16:26:42,172 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-94) [68e30f6] Waiting on Live Merge child commands to complete
2016-08-04 16:26:43,183 INFO [org.ovirt.engine.core.bll.MergeCommandCallback] (DefaultQuartzScheduler_Worker-80) [2812157e] Waiting on merge command to complete
2016-08-04 16:26:43,741 INFO [org.ovirt.engine.core.vdsbroker.VmAnalyzer] (DefaultQuartzScheduler_Worker-66) [6af4b2dd] VM job '19d293b8-ab41-4ab0-b0f4-5da9b54e078f': In progress, updating
2016-08-04 16:26:43,785 INFO [org.ovirt.engine.core.vdsbroker.VmAnalyzer] (DefaultQuartzScheduler_Worker-66) [6af4b2dd] VM job 'ecb7267c-2d51-425c-a924-07fa109e1a5e': In progress (no change)
2016-08-04 16:26:43,786 INFO [org.ovirt.engine.core.vdsbroker.VmAnalyzer] (DefaultQuartzScheduler_Worker-66) [6af4b2dd] VM job '1d057684-bf68-4345-b3da-a4ca31312953': Deleting
2016-08-04 16:26:43,797 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.FullListVDSCommand] (DefaultQuartzScheduler_Worker-66) [6af4b2dd] START, FullListVDSCommand(HostName = , FullListVDSCommandParameters:{runAsync='true', hostId='06eb2185-fa65-4ca7-ac6d-279d3ed2ffe5', vds='Host[,06eb2185-fa65-4ca7-ac6d-279d3ed2ffe5]', vmIds='[b0bbb15d-a4a9-4618-addf-2f1126b5329f]'}), log id: 53e44bfc
2016-08-04 16:26:44,204 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-83) [76a027e3] Waiting on Live Merge command step 'MERGE' to complete
2016-08-04 16:26:44,359 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.FullListVDSCommand] (DefaultQuartzScheduler_Worker-66) [6af4b2dd] FINISH, FullListVDSCommand, return: [{acpiEnable=true, emulatedMachine=pc-i440fx-rhel7.2.0, afterMigrationStatus=, tabletEnable=true, pid=26944, memGuaranteedSize=21845, transparentHugePages=true, displaySecurePort=-1, spiceSslCipherSuite=DEFAULT, cpuType=Westmere, smp=2, guestNumaNodes=[Ljava.lang.Object;@6ef71ca1, custom={device_4cf3ca68-b4f8-4c9e-ae85-f5f0c648b437=VmDevice:{id='VmDeviceId:{deviceId='4cf3ca68-b4f8-4c9e-ae85-f5f0c648b437', vmId='b0bbb15d-a4a9-4618-addf-2f1126b5329f'}', 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='ide', customProperties='[]', snapshotId='null', logicalName='null', usingScsiReservation='false'}, device_4cf3ca68-b4f8-4c9e-ae85-f5f0c648b437device_e52e195e-289d-49ef-a3f5-6ed5dd503764device_80154ca0-119f-4597-a6f9-62b5621e1e36=VmDevice:{id='VmDeviceId:{deviceId='80154ca0-119f-4597-a6f9-62b5621e1e36', vmId='b0bbb15d-a4a9-4618-addf-2f1126b5329f'}', 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_4cf3ca68-b4f8-4c9e-ae85-f5f0c648b437device_e52e195e-289d-49ef-a3f5-6ed5dd503764=VmDevice:{id='VmDeviceId:{deviceId='e52e195e-289d-49ef-a3f5-6ed5dd503764', vmId='b0bbb15d-a4a9-4618-addf-2f1126b5329f'}', 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'}}, vmType=kvm, smpThreadsPerCore=1, memSize=32768, smpCoresPerSocket=1, vmName=insanesql2, nice=0, status=Up, maxMemSize=4194304, bootMenuEnable=false, guestDiskMapping={b5074e82-10a6-4033-9={name=/dev/vda}, QEMU_DVD-ROM_QM00003={name=/dev/sr0}}, vmId=b0bbb15d-a4a9-4618-addf-2f1126b5329f, displayIp=0, displayPort=5923, smartcardEnable=false, spiceSecureChannels=smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard, maxMemSlots=16, nicModel=rtl8139,pv, keyboardLayout=en-us, kvmEnable=true, pitReinjection=false, devices=[Ljava.lang.Object;@1d8717b4, timeOffset=0, maxVCpus=16, clientIp=, statusTime=5789425400, display=vnc}], log id: 53e44bfc
2016-08-04 16:26:44,369 INFO [org.ovirt.engine.core.vdsbroker.VmsMonitoring] (DefaultQuartzScheduler_Worker-66) [6af4b2dd] Received a memballoon Device without an address when processing VM b0bbb15d-a4a9-4618-addf-2f1126b5329f devices, skipping device: {target=33554432, alias=balloon0, specParams={model=none}, deviceType=balloon, device=memballoon, type=balloon}
2016-08-04 16:26:44,370 INFO [org.ovirt.engine.core.vdsbroker.VmsMonitoring] (DefaultQuartzScheduler_Worker-66) [6af4b2dd] Received a vnc Device without an address when processing VM b0bbb15d-a4a9-4618-addf-2f1126b5329f devices, skipping device: {specParams={displayIp=0}, deviceType=graphics, deviceId=b1e82417-c1a1-449c-9ab9-b752bdeb7e11, device=vnc, type=graphics, port=5923}
2016-08-04 16:26:45,240 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-40) [c62bf6a] Waiting on Live Merge command step 'MERGE' to complete
2016-08-04 16:26:45,246 INFO [org.ovirt.engine.core.bll.MergeCommandCallback] (DefaultQuartzScheduler_Worker-40) [2ed02b01] Waiting on merge command to complete
2016-08-04 16:26:46,212 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-2) [e5a96ee] Task id 'ce1e1711-5d15-4aa1-8494-e25d91923cf8' is in pre-polling period and should not be polled. Pre-polling period is 60000 millis.
2016-08-04 16:26:46,212 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-2) [e5a96ee] Task id '6150bc0e-3ac7-4ee4-a1ba-8106261eb5f4' is in pre-polling period and should not be polled. Pre-polling period is 60000 millis.
2016-08-04 16:26:46,276 INFO [org.ovirt.engine.core.bll.MergeCommandCallback] (DefaultQuartzScheduler_Worker-12) [33328a2b] Merge command has completed for images 'bfdaee52-07fa-449a-b570-81f83d8099e1'..'21244552-0416-47af-909f-b66c6ff08418'
2016-08-04 16:26:48,313 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-79) [c62bf6a] Executing Live Merge command step 'MERGE_STATUS'
2016-08-04 16:26:48,348 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-79) [] Waiting on Live Merge child commands to complete
2016-08-04 16:26:48,360 INFO [org.ovirt.engine.core.bll.MergeStatusCommand] (pool-7-thread-8) [2225264d] Running command: MergeStatusCommand internal: true. Entities affected : ID: 0243ebd9-fd3f-4674-b4e7-05af734280e7 Type: Storage
2016-08-04 16:26:48,471 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.FullListVDSCommand] (pool-7-thread-8) [2225264d] START, FullListVDSCommand(HostName = host01, FullListVDSCommandParameters:{runAsync='true', hostId='06eb2185-fa65-4ca7-ac6d-279d3ed2ffe5', vds='Host[host01,06eb2185-fa65-4ca7-ac6d-279d3ed2ffe5]', vmIds='[184f89f4-8427-4a28-8787-8912f5c5f038]'}), log id: 377c9026
2016-08-04 16:26:49,494 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.FullListVDSCommand] (pool-7-thread-8) [2225264d] FINISH, FullListVDSCommand, return: [{acpiEnable=true, emulatedMachine=pc-i440fx-rhel7.2.0, tabletEnable=true, pid=7058, memGuaranteedSize=256, transparentHugePages=true, displayPort=5905, displaySecurePort=-1, spiceSslCipherSuite=DEFAULT, cpuType=Westmere, smp=1, pauseCode=EOTHER, guestNumaNodes=[Ljava.lang.Object;@31bcd500, smartcardEnable=false, custom={device_906e2f3e-d7d0-4552-981d-02653e5e969f=VmDevice:{id='VmDeviceId:{deviceId='906e2f3e-d7d0-4552-981d-02653e5e969f', vmId='184f89f4-8427-4a28-8787-8912f5c5f038'}', 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='ide', customProperties='[]', snapshotId='null', logicalName='null', usingScsiReservation='false'}, device_906e2f3e-d7d0-4552-981d-02653e5e969fdevice_6cf91500-0cea-45f8-983d-0925ac5181c5device_2699bee8-965b-4c0e-b275-bcc5433bb396=VmDevice:{id='VmDeviceId:{deviceId='2699bee8-965b-4c0e-b275-bcc5433bb396', vmId='184f89f4-8427-4a28-8787-8912f5c5f038'}', 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_906e2f3e-d7d0-4552-981d-02653e5e969fdevice_6cf91500-0cea-45f8-983d-0925ac5181c5=VmDevice:{id='VmDeviceId:{deviceId='6cf91500-0cea-45f8-983d-0925ac5181c5', vmId='184f89f4-8427-4a28-8787-8912f5c5f038'}', 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'}}, vmType=kvm, memSize=1024, smpCoresPerSocket=1, vmName=linkdb.mch.catn.com, nice=0, status=Paused, maxMemSize=4194304, bootMenuEnable=false, vmId=184f89f4-8427-4a28-8787-8912f5c5f038, displayIp=0, smpThreadsPerCore=1, guestDiskMapping={06a3338e-83a4-4ea0-b={name=/dev/vdb}, 9ac87749-388c-4a47-a={name=/dev/vda}, QEMU_DVD-ROM_QM00003={name=/dev/sr0}}, spiceSecureChannels=smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard, nicModel=rtl8139,pv, keyboardLayout=en-us, kvmEnable=true, pitReinjection=false, devices=[Ljava.lang.Object;@6ac18b0d, display=vnc, timeOffset=0, maxVCpus=16, clientIp=, statusTime=5789430080, maxMemSlots=16}], log id: 377c9026
2016-08-04 16:26:49,506 INFO [org.ovirt.engine.core.bll.MergeStatusCommand] (pool-7-thread-8) [2225264d] Successfully removed volume(s): [21244552-0416-47af-909f-b66c6ff08418]
2016-08-04 16:26:49,506 INFO [org.ovirt.engine.core.bll.MergeStatusCommand] (pool-7-thread-8) [2225264d] Volume merge type 'COMMIT'
2016-08-04 16:26:50,370 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-78) [c62bf6a] Waiting on Live Merge command step 'MERGE_STATUS' to finalize
2016-08-04 16:26:51,427 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-60) [c62bf6a] Executing Live Merge command step 'DESTROY_IMAGE'
2016-08-04 16:26:51,501 INFO [org.ovirt.engine.core.bll.DestroyImageCommand] (pool-7-thread-3) [cbbc0c5] Running command: DestroyImageCommand internal: true. Entities affected : ID: 0243ebd9-fd3f-4674-b4e7-05af734280e7 Type: Storage
2016-08-04 16:26:51,513 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.DestroyImageVDSCommand] (pool-7-thread-3) [cbbc0c5] START, DestroyImageVDSCommand( DestroyImageVDSCommandParameters:{runAsync='true', storagePoolId='00000001-0001-0001-0001-000000000059', ignoreFailoverLimit='false', storageDomainId='0243ebd9-fd3f-4674-b4e7-05af734280e7', imageGroupId='06a3338e-83a4-4ea0-b71e-83d8b6f08aac', imageId='00000000-0000-0000-0000-000000000000', imageList='[21244552-0416-47af-909f-b66c6ff08418]', postZero='false', force='false'}), log id: 1e1f8565
2016-08-04 16:26:52,354 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.DestroyImageVDSCommand] (pool-7-thread-3) [cbbc0c5] FINISH, DestroyImageVDSCommand, log id: 1e1f8565
2016-08-04 16:26:52,356 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (pool-7-thread-3) [cbbc0c5] CommandAsyncTask::Adding CommandMultiAsyncTasks object for command '611364cf-9372-4ea8-a456-69e1cdbe74d3'
2016-08-04 16:26:52,356 INFO [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (pool-7-thread-3) [cbbc0c5] CommandMultiAsyncTasks::AttachTask: Attaching task '44773061-8a4b-40b6-888d-2815da23ccee' to command '611364cf-9372-4ea8-a456-69e1cdbe74d3'.
2016-08-04 16:26:52,380 INFO [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (pool-7-thread-3) [cbbc0c5] Adding task '44773061-8a4b-40b6-888d-2815da23ccee' (Parent Command 'DestroyImage', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters'), polling hasn't started yet..
2016-08-04 16:26:52,380 INFO [org.ovirt.engine.core.bll.DestroyImageCommand] (pool-7-thread-3) [cbbc0c5] Successfully started task to remove orphaned volumes resulting from live merge
2016-08-04 16:26:52,390 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (pool-7-thread-3) [cbbc0c5] BaseAsyncTask::startPollingTask: Starting to poll task '44773061-8a4b-40b6-888d-2815da23ccee'.
2016-08-04 16:26:52,518 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-98) [68e30f6] Waiting on Live Merge command step 'MERGE' to complete
2016-08-04 16:26:52,518 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-98) [68e30f6] Waiting on Live Merge child commands to complete
2016-08-04 16:26:53,528 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-73) [c62bf6a] Waiting on Live Merge command step 'DESTROY_IMAGE' to complete
2016-08-04 16:26:53,536 INFO [org.ovirt.engine.core.bll.MergeCommandCallback] (DefaultQuartzScheduler_Worker-73) [2812157e] Waiting on merge command to complete
2016-08-04 16:26:54,542 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-53) [76a027e3] Waiting on Live Merge command step 'MERGE' to complete
2016-08-04 16:26:55,547 INFO [org.ovirt.engine.core.bll.MergeCommandCallback] (DefaultQuartzScheduler_Worker-100) [2ed02b01] Waiting on merge command to complete
2016-08-04 16:26:56,191 WARN [org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerObjectsBuilder] (DefaultQuartzScheduler_Worker-19) [2812157e] Invalid or unknown guest architecture type '' received from guest agent
2016-08-04 16:26:56,214 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-35) [2ed02b01] Task id 'ce1e1711-5d15-4aa1-8494-e25d91923cf8' has passed pre-polling period time and should be polled. Pre-polling period is 60000 millis.
2016-08-04 16:26:56,214 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-35) [2ed02b01] Task id 'ce1e1711-5d15-4aa1-8494-e25d91923cf8' has passed pre-polling period time and should be polled. Pre-polling period is 60000 millis.
2016-08-04 16:26:56,214 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-35) [2ed02b01] Task id '6150bc0e-3ac7-4ee4-a1ba-8106261eb5f4' has passed pre-polling period time and should be polled. Pre-polling period is 60000 millis.
2016-08-04 16:26:56,214 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-35) [2ed02b01] Task id '44773061-8a4b-40b6-888d-2815da23ccee' is in pre-polling period and should not be polled. Pre-polling period is 60000 millis.
2016-08-04 16:26:56,214 INFO [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (DefaultQuartzScheduler_Worker-35) [2ed02b01] Polling and updating Async Tasks: 5 tasks, 2 tasks to poll now
2016-08-04 16:26:56,214 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-35) [2ed02b01] Task id 'ce1e1711-5d15-4aa1-8494-e25d91923cf8' has passed pre-polling period time and should be polled. Pre-polling period is 60000 millis.
2016-08-04 16:26:56,214 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-35) [2ed02b01] Task id '6150bc0e-3ac7-4ee4-a1ba-8106261eb5f4' has passed pre-polling period time and should be polled. Pre-polling period is 60000 millis.
2016-08-04 16:26:56,214 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-35) [2ed02b01] Task id '44773061-8a4b-40b6-888d-2815da23ccee' is in pre-polling period and should not be polled. Pre-polling period is 60000 millis.
2016-08-04 16:26:56,426 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-35) [2ed02b01] Task id 'ce1e1711-5d15-4aa1-8494-e25d91923cf8' has passed pre-polling period time and should be polled. Pre-polling period is 60000 millis.
2016-08-04 16:26:56,426 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-35) [2ed02b01] SPMAsyncTask::PollTask: Polling task 'ce1e1711-5d15-4aa1-8494-e25d91923cf8' (Parent Command 'RemoveMemoryVolumes', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') returned status 'finished', result 'success'.
2016-08-04 16:26:56,426 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-35) [2ed02b01] BaseAsyncTask::onTaskEndSuccess: Task 'ce1e1711-5d15-4aa1-8494-e25d91923cf8' (Parent Command 'RemoveMemoryVolumes', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') ended successfully.
2016-08-04 16:26:56,427 INFO [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (DefaultQuartzScheduler_Worker-35) [2ed02b01] Task with DB Task ID '8a978fa7-ea5a-4876-822b-15c241ed7bf1' and VDSM Task ID '6150bc0e-3ac7-4ee4-a1ba-8106261eb5f4' is in state Polling. End action for command 0e512a43-ba26-4e93-a187-06fb8526e035 will proceed when all the entity's tasks are completed.
2016-08-04 16:26:56,427 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-35) [2ed02b01] Task id '6150bc0e-3ac7-4ee4-a1ba-8106261eb5f4' has passed pre-polling period time and should be polled. Pre-polling period is 60000 millis.
2016-08-04 16:26:56,427 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-35) [2ed02b01] SPMAsyncTask::PollTask: Polling task '6150bc0e-3ac7-4ee4-a1ba-8106261eb5f4' (Parent Command 'RemoveMemoryVolumes', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') returned status 'finished', result 'success'.
2016-08-04 16:26:56,427 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-35) [2ed02b01] BaseAsyncTask::onTaskEndSuccess: Task '6150bc0e-3ac7-4ee4-a1ba-8106261eb5f4' (Parent Command 'RemoveMemoryVolumes', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') ended successfully.
2016-08-04 16:26:56,431 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (DefaultQuartzScheduler_Worker-35) [2ed02b01] CommandAsyncTask::endActionIfNecessary: All tasks of command '0e512a43-ba26-4e93-a187-06fb8526e035' has ended -> executing 'endAction'
2016-08-04 16:26:56,431 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (DefaultQuartzScheduler_Worker-35) [2ed02b01] CommandAsyncTask::endAction: Ending action for '2' tasks (command ID: '0e512a43-ba26-4e93-a187-06fb8526e035'): calling endAction '.
2016-08-04 16:26:56,432 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-35) [2ed02b01] Task id '44773061-8a4b-40b6-888d-2815da23ccee' is in pre-polling period and should not be polled. Pre-polling period is 60000 millis.
2016-08-04 16:26:56,432 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-35) [2ed02b01] Task id '44773061-8a4b-40b6-888d-2815da23ccee' is in pre-polling period and should not be polled. Pre-polling period is 60000 millis.
2016-08-04 16:26:56,432 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-4) [2ed02b01] CommandAsyncTask::endCommandAction [within thread] context: Attempting to endAction 'RemoveMemoryVolumes', executionIndex: '0'
2016-08-04 16:26:56,438 INFO [org.ovirt.engine.core.bll.RemoveMemoryVolumesCommand] (org.ovirt.thread.pool-8-thread-4) [16ff4a8] Ending command 'org.ovirt.engine.core.bll.RemoveMemoryVolumesCommand' successfully.
2016-08-04 16:26:56,439 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-4) [16ff4a8] CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type 'RemoveMemoryVolumes' completed, handling the result.
2016-08-04 16:26:56,439 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-4) [16ff4a8] CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type 'RemoveMemoryVolumes' succeeded, clearing tasks.
2016-08-04 16:26:56,439 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (org.ovirt.thread.pool-8-thread-4) [16ff4a8] SPMAsyncTask::ClearAsyncTask: Attempting to clear task 'ce1e1711-5d15-4aa1-8494-e25d91923cf8'
2016-08-04 16:26:56,440 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-4) [16ff4a8] START, SPMClearTaskVDSCommand( SPMTaskGuidBaseVDSCommandParameters:{runAsync='true', storagePoolId='00000001-0001-0001-0001-000000000059', ignoreFailoverLimit='false', taskId='ce1e1711-5d15-4aa1-8494-e25d91923cf8'}), log id: 3ab3c759
2016-08-04 16:26:56,441 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-4) [16ff4a8] START, HSMClearTaskVDSCommand(HostName = host04, HSMTaskGuidBaseVDSCommandParameters:{runAsync='true', hostId='662a3ac1-19b4-4dde-9558-ebaeed4b8439', taskId='ce1e1711-5d15-4aa1-8494-e25d91923cf8'}), log id: 3e623413
2016-08-04 16:26:57,476 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-4) [16ff4a8] FINISH, HSMClearTaskVDSCommand, log id: 3e623413
2016-08-04 16:26:57,477 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-4) [16ff4a8] FINISH, SPMClearTaskVDSCommand, log id: 3ab3c759
2016-08-04 16:26:57,482 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (org.ovirt.thread.pool-8-thread-4) [16ff4a8] BaseAsyncTask::removeTaskFromDB: Removed task 'ce1e1711-5d15-4aa1-8494-e25d91923cf8' from DataBase
2016-08-04 16:26:57,482 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (org.ovirt.thread.pool-8-thread-4) [16ff4a8] SPMAsyncTask::ClearAsyncTask: Attempting to clear task '6150bc0e-3ac7-4ee4-a1ba-8106261eb5f4'
2016-08-04 16:26:57,483 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-4) [16ff4a8] START, SPMClearTaskVDSCommand( SPMTaskGuidBaseVDSCommandParameters:{runAsync='true', storagePoolId='00000001-0001-0001-0001-000000000059', ignoreFailoverLimit='false', taskId='6150bc0e-3ac7-4ee4-a1ba-8106261eb5f4'}), log id: 4682f79
2016-08-04 16:26:57,483 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-4) [16ff4a8] START, HSMClearTaskVDSCommand(HostName = host04, HSMTaskGuidBaseVDSCommandParameters:{runAsync='true', hostId='662a3ac1-19b4-4dde-9558-ebaeed4b8439', taskId='6150bc0e-3ac7-4ee4-a1ba-8106261eb5f4'}), log id: 64561508
2016-08-04 16:26:57,554 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-3) [c62bf6a] Waiting on Live Merge command step 'DESTROY_IMAGE' to complete
2016-08-04 16:26:58,414 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-4) [16ff4a8] FINISH, HSMClearTaskVDSCommand, log id: 64561508
2016-08-04 16:26:58,414 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-4) [16ff4a8] FINISH, SPMClearTaskVDSCommand, log id: 4682f79
2016-08-04 16:26:58,419 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (org.ovirt.thread.pool-8-thread-4) [16ff4a8] BaseAsyncTask::removeTaskFromDB: Removed task '6150bc0e-3ac7-4ee4-a1ba-8106261eb5f4' from DataBase
2016-08-04 16:26:58,419 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-4) [16ff4a8] CommandAsyncTask::HandleEndActionResult [within thread]: Removing CommandMultiAsyncTasks object for entity '0e512a43-ba26-4e93-a187-06fb8526e035'
2016-08-04 16:26:58,555 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-99) [1fb2b5b9] Waiting on Live Merge child commands to complete
2016-08-04 16:26:59,570 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerObjectsBuilder] (DefaultQuartzScheduler_Worker-32) [2ce25660] Failed to parse 'writeRate' value '6415479979' to integer: For input string: "6415479979"
2016-08-04 16:26:59,763 INFO [org.ovirt.engine.core.vdsbroker.VmAnalyzer] (DefaultQuartzScheduler_Worker-32) [2ce25660] VM job '19d293b8-ab41-4ab0-b0f4-5da9b54e078f': Deleting
2016-08-04 16:26:59,824 INFO [org.ovirt.engine.core.vdsbroker.VmAnalyzer] (DefaultQuartzScheduler_Worker-32) [2ce25660] VM job 'ecb7267c-2d51-425c-a924-07fa109e1a5e': In progress (no change)
2016-08-04 16:27:02,565 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-43) [68e30f6] Waiting on Live Merge command step 'MERGE' to complete
2016-08-04 16:27:02,565 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-43) [68e30f6] Waiting on Live Merge child commands to complete
2016-08-04 16:27:03,581 INFO [org.ovirt.engine.core.bll.MergeCommandCallback] (DefaultQuartzScheduler_Worker-26) [2812157e] Merge command has completed for images '6525cd3a-88db-46f1-995b-2368fc9cc4e4'..'7623bb55-212c-4849-8cad-5b9e7d76f14b'
2016-08-04 16:27:04,592 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-14) [76a027e3] Waiting on Live Merge command step 'MERGE' to complete
2016-08-04 16:27:05,609 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-62) [c62bf6a] Waiting on Live Merge command step 'DESTROY_IMAGE' to complete
2016-08-04 16:27:05,614 INFO [org.ovirt.engine.core.bll.MergeCommandCallback] (DefaultQuartzScheduler_Worker-62) [2ed02b01] Waiting on merge command to complete
2016-08-04 16:27:05,636 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-62) [68e30f6] Executing Live Merge command step 'MERGE_STATUS'
2016-08-04 16:27:05,683 INFO [org.ovirt.engine.core.bll.MergeStatusCommand] (pool-7-thread-6) [2f4dd4f6] Running command: MergeStatusCommand internal: true. Entities affected : ID: 4a993755-97e9-429c-ad64-96a6aabd2bc6 Type: Storage
2016-08-04 16:27:05,787 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.FullListVDSCommand] (pool-7-thread-6) [2f4dd4f6] START, FullListVDSCommand(HostName = host01, FullListVDSCommandParameters:{runAsync='true', hostId='06eb2185-fa65-4ca7-ac6d-279d3ed2ffe5', vds='Host[host01,06eb2185-fa65-4ca7-ac6d-279d3ed2ffe5]', vmIds='[b0bbb15d-a4a9-4618-addf-2f1126b5329f]'}), log id: 30f479a7
2016-08-04 16:27:05,816 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.FullListVDSCommand] (pool-7-thread-6) [2f4dd4f6] FINISH, FullListVDSCommand, return: [{acpiEnable=true, emulatedMachine=pc-i440fx-rhel7.2.0, afterMigrationStatus=, tabletEnable=true, pid=26944, memGuaranteedSize=21845, transparentHugePages=true, displaySecurePort=-1, spiceSslCipherSuite=DEFAULT, cpuType=Westmere, smp=2, guestNumaNodes=[Ljava.lang.Object;@15b14f41, custom={device_4cf3ca68-b4f8-4c9e-ae85-f5f0c648b437=VmDevice:{id='VmDeviceId:{deviceId='4cf3ca68-b4f8-4c9e-ae85-f5f0c648b437', vmId='b0bbb15d-a4a9-4618-addf-2f1126b5329f'}', 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='ide', customProperties='[]', snapshotId='null', logicalName='null', usingScsiReservation='false'}, device_4cf3ca68-b4f8-4c9e-ae85-f5f0c648b437device_e52e195e-289d-49ef-a3f5-6ed5dd503764device_80154ca0-119f-4597-a6f9-62b5621e1e36=VmDevice:{id='VmDeviceId:{deviceId='80154ca0-119f-4597-a6f9-62b5621e1e36', vmId='b0bbb15d-a4a9-4618-addf-2f1126b5329f'}', 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_4cf3ca68-b4f8-4c9e-ae85-f5f0c648b437device_e52e195e-289d-49ef-a3f5-6ed5dd503764=VmDevice:{id='VmDeviceId:{deviceId='e52e195e-289d-49ef-a3f5-6ed5dd503764', vmId='b0bbb15d-a4a9-4618-addf-2f1126b5329f'}', 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'}}, vmType=kvm, smpThreadsPerCore=1, memSize=32768, smpCoresPerSocket=1, vmName=insanesql2, nice=0, status=Up, maxMemSize=4194304, bootMenuEnable=false, guestDiskMapping={b5074e82-10a6-4033-9={name=/dev/vda}, QEMU_DVD-ROM_QM00003={name=/dev/sr0}}, vmId=b0bbb15d-a4a9-4618-addf-2f1126b5329f, displayIp=0, displayPort=5923, smartcardEnable=false, spiceSecureChannels=smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard, maxMemSlots=16, nicModel=rtl8139,pv, keyboardLayout=en-us, kvmEnable=true, pitReinjection=false, devices=[Ljava.lang.Object;@7f551a86, timeOffset=0, maxVCpus=16, clientIp=, statusTime=5789447380, display=vnc}], log id: 30f479a7
2016-08-04 16:27:05,821 INFO [org.ovirt.engine.core.bll.MergeStatusCommand] (pool-7-thread-6) [2f4dd4f6] Successfully removed volume(s): [7623bb55-212c-4849-8cad-5b9e7d76f14b]
2016-08-04 16:27:05,821 INFO [org.ovirt.engine.core.bll.MergeStatusCommand] (pool-7-thread-6) [2f4dd4f6] Volume merge type 'COMMIT'
2016-08-04 16:27:06,434 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-38) [34a83044] Task id '44773061-8a4b-40b6-888d-2815da23ccee' is in pre-polling period and should not be polled. Pre-polling period is 60000 millis.
2016-08-04 16:27:07,681 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-2) [68e30f6] Waiting on Live Merge command step 'MERGE_STATUS' to finalize
2016-08-04 16:27:08,706 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-25) [68e30f6] Executing Live Merge command step 'DESTROY_IMAGE'
2016-08-04 16:27:08,725 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-25) [] Waiting on Live Merge child commands to complete
2016-08-04 16:27:08,740 INFO [org.ovirt.engine.core.bll.DestroyImageCommand] (pool-7-thread-10) [311f4019] Running command: DestroyImageCommand internal: true. Entities affected : ID: 4a993755-97e9-429c-ad64-96a6aabd2bc6 Type: Storage
2016-08-04 16:27:08,754 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.DestroyImageVDSCommand] (pool-7-thread-10) [311f4019] START, DestroyImageVDSCommand( DestroyImageVDSCommandParameters:{runAsync='true', storagePoolId='00000001-0001-0001-0001-000000000059', ignoreFailoverLimit='false', storageDomainId='4a993755-97e9-429c-ad64-96a6aabd2bc6', imageGroupId='b5074e82-10a6-4033-918f-2ff49d7a2f81', imageId='00000000-0000-0000-0000-000000000000', imageList='[7623bb55-212c-4849-8cad-5b9e7d76f14b]', postZero='false', force='false'}), log id: 2c48071a
2016-08-04 16:27:09,434 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.DestroyImageVDSCommand] (pool-7-thread-10) [311f4019] FINISH, DestroyImageVDSCommand, log id: 2c48071a
2016-08-04 16:27:09,436 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (pool-7-thread-10) [311f4019] CommandAsyncTask::Adding CommandMultiAsyncTasks object for command '19f69a52-c0e5-4364-9fb6-cdcb03778364'
2016-08-04 16:27:09,436 INFO [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (pool-7-thread-10) [311f4019] CommandMultiAsyncTasks::AttachTask: Attaching task '661f0366-6b14-47d5-81ef-ce8447689bec' to command '19f69a52-c0e5-4364-9fb6-cdcb03778364'.
2016-08-04 16:27:09,682 INFO [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (pool-7-thread-10) [311f4019] Adding task '661f0366-6b14-47d5-81ef-ce8447689bec' (Parent Command 'DestroyImage', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters'), polling hasn't started yet..
2016-08-04 16:27:09,683 INFO [org.ovirt.engine.core.bll.DestroyImageCommand] (pool-7-thread-10) [311f4019] Successfully started task to remove orphaned volumes resulting from live merge
2016-08-04 16:27:09,692 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (pool-7-thread-10) [311f4019] BaseAsyncTask::startPollingTask: Starting to poll task '661f0366-6b14-47d5-81ef-ce8447689bec'.
2016-08-04 16:27:10,749 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-27) [68e30f6] Waiting on Live Merge command step 'DESTROY_IMAGE' to complete
2016-08-04 16:27:11,560 WARN [org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerObjectsBuilder] (DefaultQuartzScheduler_Worker-10) [34a83044] Invalid or unknown guest architecture type '' received from guest agent
2016-08-04 16:27:12,750 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-45) [1359b200] Waiting on Live Merge child commands to complete
2016-08-04 16:27:14,760 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-47) [68e30f6] Waiting on Live Merge command step 'DESTROY_IMAGE' to complete
2016-08-04 16:27:14,769 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-47) [76a027e3] Waiting on Live Merge command step 'MERGE' to complete
2016-08-04 16:27:15,137 INFO [org.ovirt.engine.core.vdsbroker.VmAnalyzer] (DefaultQuartzScheduler_Worker-13) [] VM job 'ecb7267c-2d51-425c-a924-07fa109e1a5e': In progress (no change)
2016-08-04 16:27:15,775 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-85) [c62bf6a] Waiting on Live Merge command step 'DESTROY_IMAGE' to complete
2016-08-04 16:27:15,778 INFO [org.ovirt.engine.core.bll.MergeCommandCallback] (DefaultQuartzScheduler_Worker-85) [2ed02b01] Waiting on merge command to complete
2016-08-04 16:27:16,435 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-23) [2ed02b01] Task id '661f0366-6b14-47d5-81ef-ce8447689bec' is in pre-polling period and should not be polled. Pre-polling period is 60000 millis.
2016-08-04 16:27:16,435 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-23) [2ed02b01] Task id '44773061-8a4b-40b6-888d-2815da23ccee' is in pre-polling period and should not be polled. Pre-polling period is 60000 millis.
2016-08-04 16:27:18,779 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-57) [33328a2b] Waiting on Live Merge child commands to complete
2016-08-04 16:27:21,639 INFO [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (DefaultQuartzScheduler_Worker-44) [2812157e] Setting new tasks map. The map contains now 4 tasks
2016-08-04 16:27:22,791 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-91) [68e30f6] Waiting on Live Merge command step 'DESTROY_IMAGE' to complete
2016-08-04 16:27:22,791 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-91) [68e30f6] Waiting on Live Merge child commands to complete
2016-08-04 16:27:24,800 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-6) [76a027e3] Waiting on Live Merge command step 'MERGE' to complete
2016-08-04 16:27:25,814 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-81) [c62bf6a] Waiting on Live Merge command step 'DESTROY_IMAGE' to complete
2016-08-04 16:27:25,821 INFO [org.ovirt.engine.core.bll.MergeCommandCallback] (DefaultQuartzScheduler_Worker-81) [2ed02b01] Waiting on merge command to complete
2016-08-04 16:27:26,435 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-82) [1359b200] Task id '661f0366-6b14-47d5-81ef-ce8447689bec' is in pre-polling period and should not be polled. Pre-polling period is 60000 millis.
2016-08-04 16:27:26,436 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-82) [1359b200] Task id '44773061-8a4b-40b6-888d-2815da23ccee' is in pre-polling period and should not be polled. Pre-polling period is 60000 millis.
2016-08-04 16:27:27,006 WARN [org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerObjectsBuilder] (DefaultQuartzScheduler_Worker-83) [76a027e3] Invalid or unknown guest architecture type '' received from guest agent
2016-08-04 16:27:28,824 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-12) [33328a2b] Waiting on Live Merge child commands to complete
2016-08-04 16:27:30,502 INFO [org.ovirt.engine.core.vdsbroker.VmAnalyzer] (DefaultQuartzScheduler_Worker-20) [68e30f6] VM job 'ecb7267c-2d51-425c-a924-07fa109e1a5e': In progress (no change)
2016-08-04 16:27:32,852 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-64) [68e30f6] Waiting on Live Merge command step 'DESTROY_IMAGE' to complete
2016-08-04 16:27:32,852 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-64) [68e30f6] Waiting on Live Merge child commands to complete
2016-08-04 16:27:34,901 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-98) [76a027e3] Waiting on Live Merge command step 'MERGE' to complete
2016-08-04 16:27:35,936 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-56) [c62bf6a] Waiting on Live Merge command step 'DESTROY_IMAGE' to complete
2016-08-04 16:27:35,943 INFO [org.ovirt.engine.core.bll.MergeCommandCallback] (DefaultQuartzScheduler_Worker-56) [2ed02b01] Waiting on merge command to complete
2016-08-04 16:27:36,437 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-34) [6d5fd68c] Task id '661f0366-6b14-47d5-81ef-ce8447689bec' is in pre-polling period and should not be polled. Pre-polling period is 60000 millis.
2016-08-04 16:27:36,437 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-34) [6d5fd68c] Task id '44773061-8a4b-40b6-888d-2815da23ccee' is in pre-polling period and should not be polled. Pre-polling period is 60000 millis.
2016-08-04 16:27:38,945 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-35) [2ed02b01] Waiting on Live Merge child commands to complete
2016-08-04 16:27:42,381 WARN [org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerObjectsBuilder] (DefaultQuartzScheduler_Worker-44) [2812157e] Invalid or unknown guest architecture type '' received from guest agent
2016-08-04 16:27:42,959 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-28) [68e30f6] Waiting on Live Merge command step 'DESTROY_IMAGE' to complete
2016-08-04 16:27:42,960 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-28) [68e30f6] Waiting on Live Merge child commands to complete
2016-08-04 16:27:44,980 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-16) [76a027e3] Waiting on Live Merge command step 'MERGE' to complete
2016-08-04 16:27:46,003 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-26) [c62bf6a] Waiting on Live Merge command step 'DESTROY_IMAGE' to complete
2016-08-04 16:27:46,008 INFO [org.ovirt.engine.core.bll.MergeCommandCallback] (DefaultQuartzScheduler_Worker-26) [2ed02b01] Waiting on merge command to complete
2016-08-04 16:27:46,181 INFO [org.ovirt.engine.core.vdsbroker.VmAnalyzer] (DefaultQuartzScheduler_Worker-94) [68e30f6] VM job 'ecb7267c-2d51-425c-a924-07fa109e1a5e': In progress (no change)
2016-08-04 16:27:46,439 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-37) [2ce25660] Task id '661f0366-6b14-47d5-81ef-ce8447689bec' is in pre-polling period and should not be polled. Pre-polling period is 60000 millis.
2016-08-04 16:27:46,439 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-37) [2ce25660] Task id '44773061-8a4b-40b6-888d-2815da23ccee' is in pre-polling period and should not be polled. Pre-polling period is 60000 millis.
2016-08-04 16:27:49,011 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-40) [2ed02b01] Waiting on Live Merge child commands to complete
2016-08-04 16:27:53,028 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-5) [68e30f6] Waiting on Live Merge command step 'DESTROY_IMAGE' to complete
2016-08-04 16:27:53,028 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-5) [68e30f6] Waiting on Live Merge child commands to complete
2016-08-04 16:27:55,050 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-10) [76a027e3] Waiting on Live Merge command step 'MERGE' to complete
2016-08-04 16:27:56,081 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-49) [c62bf6a] Waiting on Live Merge command step 'DESTROY_IMAGE' to complete
2016-08-04 16:27:56,087 INFO [org.ovirt.engine.core.bll.MergeCommandCallback] (DefaultQuartzScheduler_Worker-49) [2ed02b01] Waiting on merge command to complete
2016-08-04 16:27:56,439 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-56) [2ed02b01] Task id '661f0366-6b14-47d5-81ef-ce8447689bec' is in pre-polling period and should not be polled. Pre-polling period is 60000 millis.
2016-08-04 16:27:56,439 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-56) [2ed02b01] Task id '44773061-8a4b-40b6-888d-2815da23ccee' has passed pre-polling period time and should be polled. Pre-polling period is 60000 millis.
2016-08-04 16:27:56,440 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-56) [2ed02b01] Task id '661f0366-6b14-47d5-81ef-ce8447689bec' is in pre-polling period and should not be polled. Pre-polling period is 60000 millis.
2016-08-04 16:27:56,440 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-56) [2ed02b01] Task id '44773061-8a4b-40b6-888d-2815da23ccee' has passed pre-polling period time and should be polled. Pre-polling period is 60000 millis.
2016-08-04 16:27:56,440 INFO [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (DefaultQuartzScheduler_Worker-56) [2ed02b01] Polling and updating Async Tasks: 4 tasks, 1 tasks to poll now
2016-08-04 16:27:56,440 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-56) [2ed02b01] Task id '661f0366-6b14-47d5-81ef-ce8447689bec' is in pre-polling period and should not be polled. Pre-polling period is 60000 millis.
2016-08-04 16:27:56,440 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-56) [2ed02b01] Task id '44773061-8a4b-40b6-888d-2815da23ccee' has passed pre-polling period time and should be polled. Pre-polling period is 60000 millis.
2016-08-04 16:27:57,140 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-56) [2ed02b01] Task id '661f0366-6b14-47d5-81ef-ce8447689bec' is in pre-polling period and should not be polled. Pre-polling period is 60000 millis.
2016-08-04 16:27:57,140 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-56) [2ed02b01] Task id '44773061-8a4b-40b6-888d-2815da23ccee' has passed pre-polling period time and should be polled. Pre-polling period is 60000 millis.
2016-08-04 16:27:57,141 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-56) [2ed02b01] SPMAsyncTask::PollTask: Polling task '44773061-8a4b-40b6-888d-2815da23ccee' (Parent Command 'DestroyImage', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') returned status 'finished', result 'success'.
2016-08-04 16:27:57,149 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-56) [2ed02b01] BaseAsyncTask::onTaskEndSuccess: Task '44773061-8a4b-40b6-888d-2815da23ccee' (Parent Command 'DestroyImage', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') ended successfully.
2016-08-04 16:27:57,159 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (DefaultQuartzScheduler_Worker-56) [2ed02b01] CommandAsyncTask::endActionIfNecessary: All tasks of command '611364cf-9372-4ea8-a456-69e1cdbe74d3' has ended -> executing 'endAction'
2016-08-04 16:27:57,159 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (DefaultQuartzScheduler_Worker-56) [2ed02b01] CommandAsyncTask::endAction: Ending action for '1' tasks (command ID: '611364cf-9372-4ea8-a456-69e1cdbe74d3'): calling endAction '.
2016-08-04 16:27:57,160 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-56) [2ed02b01] Task id '661f0366-6b14-47d5-81ef-ce8447689bec' is in pre-polling period and should not be polled. Pre-polling period is 60000 millis.
2016-08-04 16:27:57,160 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-38) [2ed02b01] CommandAsyncTask::endCommandAction [within thread] context: Attempting to endAction 'DestroyImage', executionIndex: '0'
2016-08-04 16:27:57,168 INFO [org.ovirt.engine.core.bll.DestroyImageCommand] (org.ovirt.thread.pool-8-thread-38) [cbbc0c5] Ending command 'org.ovirt.engine.core.bll.DestroyImageCommand' successfully.
2016-08-04 16:27:57,170 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-38) [cbbc0c5] CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type 'DestroyImage' completed, handling the result.
2016-08-04 16:27:57,171 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-38) [cbbc0c5] CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type 'DestroyImage' succeeded, clearing tasks.
2016-08-04 16:27:57,171 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (org.ovirt.thread.pool-8-thread-38) [cbbc0c5] SPMAsyncTask::ClearAsyncTask: Attempting to clear task '44773061-8a4b-40b6-888d-2815da23ccee'
2016-08-04 16:27:57,173 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-38) [cbbc0c5] START, SPMClearTaskVDSCommand( SPMTaskGuidBaseVDSCommandParameters:{runAsync='true', storagePoolId='00000001-0001-0001-0001-000000000059', ignoreFailoverLimit='false', taskId='44773061-8a4b-40b6-888d-2815da23ccee'}), log id: 66a7d3b
2016-08-04 16:27:57,174 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-38) [cbbc0c5] START, HSMClearTaskVDSCommand(HostName = host04, HSMTaskGuidBaseVDSCommandParameters:{runAsync='true', hostId='662a3ac1-19b4-4dde-9558-ebaeed4b8439', taskId='44773061-8a4b-40b6-888d-2815da23ccee'}), log id: 6dfa36cd
2016-08-04 16:27:57,679 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-38) [cbbc0c5] FINISH, HSMClearTaskVDSCommand, log id: 6dfa36cd
2016-08-04 16:27:57,679 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-38) [cbbc0c5] FINISH, SPMClearTaskVDSCommand, log id: 66a7d3b
2016-08-04 16:27:57,685 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (org.ovirt.thread.pool-8-thread-38) [cbbc0c5] BaseAsyncTask::removeTaskFromDB: Removed task '44773061-8a4b-40b6-888d-2815da23ccee' from DataBase
2016-08-04 16:27:57,685 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-38) [cbbc0c5] CommandAsyncTask::HandleEndActionResult [within thread]: Removing CommandMultiAsyncTasks object for entity '611364cf-9372-4ea8-a456-69e1cdbe74d3'
2016-08-04 16:27:57,743 WARN [org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerObjectsBuilder] (DefaultQuartzScheduler_Worker-13) [] Invalid or unknown guest architecture type '' received from guest agent
2016-08-04 16:27:59,088 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-8) [] Waiting on Live Merge child commands to complete
2016-08-04 16:28:01,510 INFO [org.ovirt.engine.core.vdsbroker.VmAnalyzer] (DefaultQuartzScheduler_Worker-22) [71801ac4] VM job 'ecb7267c-2d51-425c-a924-07fa109e1a5e': In progress (no change)
2016-08-04 16:28:03,118 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-32) [68e30f6] Waiting on Live Merge command step 'DESTROY_IMAGE' to complete
2016-08-04 16:28:03,118 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-32) [68e30f6] Waiting on Live Merge child commands to complete
2016-08-04 16:28:05,135 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-93) [76a027e3] Waiting on Live Merge command step 'MERGE' to complete
2016-08-04 16:28:06,146 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-6) [c62bf6a] Executing Live Merge command step 'DESTROY_IMAGE_CHECK'
2016-08-04 16:28:06,192 INFO [org.ovirt.engine.core.bll.MergeCommandCallback] (DefaultQuartzScheduler_Worker-6) [2ed02b01] Waiting on merge command to complete
2016-08-04 16:28:06,196 INFO [org.ovirt.engine.core.bll.DestroyImageCheckCommand] (pool-7-thread-1) [7d205f35] Running command: DestroyImageCheckCommand internal: true.
2016-08-04 16:28:06,199 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SPMGetVolumeInfoVDSCommand] (pool-7-thread-1) [7d205f35] START, SPMGetVolumeInfoVDSCommand( SPMGetVolumeInfoVDSCommandParameters:{expectedEngineErrors='[VolumeDoesNotExist]', runAsync='true', storagePoolId='00000001-0001-0001-0001-000000000059', ignoreFailoverLimit='false', storageDomainId='0243ebd9-fd3f-4674-b4e7-05af734280e7', imageGroupId='06a3338e-83a4-4ea0-b71e-83d8b6f08aac', imageId='21244552-0416-47af-909f-b66c6ff08418'}), log id: 47afb72e
2016-08-04 16:28:06,200 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SPMGetVolumeInfoVDSCommand] (pool-7-thread-1) [7d205f35] Executing GetVolumeInfo using the current SPM
2016-08-04 16:28:06,200 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.GetVolumeInfoVDSCommand] (pool-7-thread-1) [7d205f35] START, GetVolumeInfoVDSCommand(HostName = host04, GetVolumeInfoVDSCommandParameters:{expectedEngineErrors='[VolumeDoesNotExist]', runAsync='true', hostId='662a3ac1-19b4-4dde-9558-ebaeed4b8439', storagePoolId='00000001-0001-0001-0001-000000000059', storageDomainId='0243ebd9-fd3f-4674-b4e7-05af734280e7', imageGroupId='06a3338e-83a4-4ea0-b71e-83d8b6f08aac', imageId='21244552-0416-47af-909f-b66c6ff08418'}), log id: 2f0ff1c6
2016-08-04 16:28:07,153 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.GetVolumeInfoVDSCommand] (pool-7-thread-1) [7d205f35] Failed in 'GetVolumeInfoVDS' method
2016-08-04 16:28:07,154 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.GetVolumeInfoVDSCommand] (pool-7-thread-1) [7d205f35] Command 'org.ovirt.engine.core.vdsbroker.vdsbroker.GetVolumeInfoVDSCommand' return value '
VolumeInfoReturnForXmlRpc:{status='StatusForXmlRpc [code=201, message=Volume does not exist: (u'21244552-0416-47af-909f-b66c6ff08418',)]'}
'
2016-08-04 16:28:07,154 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.GetVolumeInfoVDSCommand] (pool-7-thread-1) [7d205f35] HostName = host04
2016-08-04 16:28:07,154 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.GetVolumeInfoVDSCommand] (pool-7-thread-1) [7d205f35] Command 'GetVolumeInfoVDSCommand(HostName = host04, GetVolumeInfoVDSCommandParameters:{expectedEngineErrors='[VolumeDoesNotExist]', runAsync='true', hostId='662a3ac1-19b4-4dde-9558-ebaeed4b8439', storagePoolId='00000001-0001-0001-0001-000000000059', storageDomainId='0243ebd9-fd3f-4674-b4e7-05af734280e7', imageGroupId='06a3338e-83a4-4ea0-b71e-83d8b6f08aac', imageId='21244552-0416-47af-909f-b66c6ff08418'})' execution failed: VDSGenericException: VDSErrorException: Failed to GetVolumeInfoVDS, error = Volume does not exist: (u'21244552-0416-47af-909f-b66c6ff08418',), code = 201
2016-08-04 16:28:07,154 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.GetVolumeInfoVDSCommand] (pool-7-thread-1) [7d205f35] FINISH, GetVolumeInfoVDSCommand, log id: 2f0ff1c6
2016-08-04 16:28:07,154 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SPMGetVolumeInfoVDSCommand] (pool-7-thread-1) [7d205f35] FINISH, SPMGetVolumeInfoVDSCommand, log id: 47afb72e
2016-08-04 16:28:07,155 INFO [org.ovirt.engine.core.bll.DestroyImageCheckCommand] (pool-7-thread-1) [7d205f35] Requested images were successfully removed
2016-08-04 16:28:07,160 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-42) [4c5e5541] Task id '661f0366-6b14-47d5-81ef-ce8447689bec' is in pre-polling period and should not be polled. Pre-polling period is 60000 millis.
2016-08-04 16:28:09,195 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-88) [68e30f6] Waiting on Live Merge child commands to complete
2016-08-04 16:28:13,174 WARN [org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerObjectsBuilder] (DefaultQuartzScheduler_Worker-46) [34a83044] Invalid or unknown guest architecture type '' received from guest agent
2016-08-04 16:28:13,215 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-71) [68e30f6] Waiting on Live Merge command step 'DESTROY_IMAGE' to complete
2016-08-04 16:28:13,215 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-71) [68e30f6] Waiting on Live Merge child commands to complete
2016-08-04 16:28:15,226 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-10) [76a027e3] Waiting on Live Merge command step 'MERGE' to complete
2016-08-04 16:28:16,248 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-61) [c62bf6a] Executing Live Merge command step 'COMPLETE'
2016-08-04 16:28:16,279 INFO [org.ovirt.engine.core.bll.MergeCommandCallback] (DefaultQuartzScheduler_Worker-61) [2ed02b01] Waiting on merge command to complete
2016-08-04 16:28:16,824 INFO [org.ovirt.engine.core.vdsbroker.VmAnalyzer] (DefaultQuartzScheduler_Worker-54) [34a83044] VM job 'ecb7267c-2d51-425c-a924-07fa109e1a5e': In progress (no change)
2016-08-04 16:28:17,161 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-73) [2812157e] Task id '661f0366-6b14-47d5-81ef-ce8447689bec' has passed pre-polling period time and should be polled. Pre-polling period is 60000 millis.
2016-08-04 16:28:17,161 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-73) [2812157e] Task id '661f0366-6b14-47d5-81ef-ce8447689bec' has passed pre-polling period time and should be polled. Pre-polling period is 60000 millis.
2016-08-04 16:28:17,161 INFO [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (DefaultQuartzScheduler_Worker-73) [2812157e] Polling and updating Async Tasks: 4 tasks, 1 tasks to poll now
2016-08-04 16:28:17,161 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-73) [2812157e] Task id '661f0366-6b14-47d5-81ef-ce8447689bec' has passed pre-polling period time and should be polled. Pre-polling period is 60000 millis.
2016-08-04 16:28:17,299 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (DefaultQuartzScheduler_Worker-47) [c62bf6a] START, GetImageInfoVDSCommand( GetImageInfoVDSCommandParameters:{runAsync='true', storagePoolId='00000001-0001-0001-0001-000000000059', ignoreFailoverLimit='false', storageDomainId='0243ebd9-fd3f-4674-b4e7-05af734280e7', imageGroupId='06a3338e-83a4-4ea0-b71e-83d8b6f08aac', imageId='bfdaee52-07fa-449a-b570-81f83d8099e1'}), log id: 7e8a6e0e
2016-08-04 16:28:18,172 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-73) [2812157e] Task id '661f0366-6b14-47d5-81ef-ce8447689bec' has passed pre-polling period time and should be polled. Pre-polling period is 60000 millis.
2016-08-04 16:28:18,172 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-73) [2812157e] SPMAsyncTask::PollTask: Polling task '661f0366-6b14-47d5-81ef-ce8447689bec' (Parent Command 'DestroyImage', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') returned status 'finished', result 'success'.
2016-08-04 16:28:18,172 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-73) [2812157e] BaseAsyncTask::onTaskEndSuccess: Task '661f0366-6b14-47d5-81ef-ce8447689bec' (Parent Command 'DestroyImage', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') ended successfully.
2016-08-04 16:28:18,175 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (DefaultQuartzScheduler_Worker-73) [2812157e] CommandAsyncTask::endActionIfNecessary: All tasks of command '19f69a52-c0e5-4364-9fb6-cdcb03778364' has ended -> executing 'endAction'
2016-08-04 16:28:18,175 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (DefaultQuartzScheduler_Worker-73) [2812157e] CommandAsyncTask::endAction: Ending action for '1' tasks (command ID: '19f69a52-c0e5-4364-9fb6-cdcb03778364'): calling endAction '.
2016-08-04 16:28:18,175 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-2) [2812157e] CommandAsyncTask::endCommandAction [within thread] context: Attempting to endAction 'DestroyImage', executionIndex: '0'
2016-08-04 16:28:18,179 INFO [org.ovirt.engine.core.bll.DestroyImageCommand] (org.ovirt.thread.pool-8-thread-2) [311f4019] Ending command 'org.ovirt.engine.core.bll.DestroyImageCommand' successfully.
2016-08-04 16:28:18,180 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-2) [311f4019] CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type 'DestroyImage' completed, handling the result.
2016-08-04 16:28:18,180 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-2) [311f4019] CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type 'DestroyImage' succeeded, clearing tasks.
2016-08-04 16:28:18,180 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (org.ovirt.thread.pool-8-thread-2) [311f4019] SPMAsyncTask::ClearAsyncTask: Attempting to clear task '661f0366-6b14-47d5-81ef-ce8447689bec'
2016-08-04 16:28:18,182 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-2) [311f4019] START, SPMClearTaskVDSCommand( SPMTaskGuidBaseVDSCommandParameters:{runAsync='true', storagePoolId='00000001-0001-0001-0001-000000000059', ignoreFailoverLimit='false', taskId='661f0366-6b14-47d5-81ef-ce8447689bec'}), log id: 549f6404
2016-08-04 16:28:19,150 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (DefaultQuartzScheduler_Worker-47) [c62bf6a] FINISH, GetImageInfoVDSCommand, return: org.ovirt.engine.core.common.businessentities.storage.DiskImage at a5e81a32, log id: 7e8a6e0e
2016-08-04 16:28:19,157 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-2) [311f4019] START, HSMClearTaskVDSCommand(HostName = host04, HSMTaskGuidBaseVDSCommandParameters:{runAsync='true', hostId='662a3ac1-19b4-4dde-9558-ebaeed4b8439', taskId='661f0366-6b14-47d5-81ef-ce8447689bec'}), log id: 77dd7eb3
2016-08-04 16:28:19,629 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-47) [c62bf6a] Successfully merged snapshot '50428e7e-beb6-4054-a703-6a997c33cb91' images '21244552-0416-47af-909f-b66c6ff08418'..'bfdaee52-07fa-449a-b570-81f83d8099e1'
2016-08-04 16:28:19,639 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-47) [c62bf6a] Waiting on Live Merge child commands to complete
2016-08-04 16:28:20,176 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-2) [311f4019] FINISH, HSMClearTaskVDSCommand, log id: 77dd7eb3
2016-08-04 16:28:20,176 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-2) [311f4019] FINISH, SPMClearTaskVDSCommand, log id: 549f6404
2016-08-04 16:28:20,182 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (org.ovirt.thread.pool-8-thread-2) [311f4019] BaseAsyncTask::removeTaskFromDB: Removed task '661f0366-6b14-47d5-81ef-ce8447689bec' from DataBase
2016-08-04 16:28:20,182 INFO [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-2) [311f4019] CommandAsyncTask::HandleEndActionResult [within thread]: Removing CommandMultiAsyncTasks object for entity '19f69a52-c0e5-4364-9fb6-cdcb03778364'
2016-08-04 16:28:21,640 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-92) [2a2a8597] Waiting on Live Merge child commands to complete
2016-08-04 16:28:21,640 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-92) [2a2a8597] Waiting on Live Merge child commands to complete
2016-08-04 16:28:21,640 INFO [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (DefaultQuartzScheduler_Worker-59) [] Setting new tasks map. The map contains now 2 tasks
2016-08-04 16:28:25,651 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-11) [68e30f6] Executing Live Merge command step 'DESTROY_IMAGE_CHECK'
2016-08-04 16:28:25,677 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-11) [] Waiting on Live Merge child commands to complete
2016-08-04 16:28:25,686 INFO [org.ovirt.engine.core.bll.DestroyImageCheckCommand] (pool-7-thread-5) [70d3c481] Running command: DestroyImageCheckCommand internal: true.
2016-08-04 16:28:25,690 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SPMGetVolumeInfoVDSCommand] (pool-7-thread-5) [70d3c481] START, SPMGetVolumeInfoVDSCommand( SPMGetVolumeInfoVDSCommandParameters:{expectedEngineErrors='[VolumeDoesNotExist]', runAsync='true', storagePoolId='00000001-0001-0001-0001-000000000059', ignoreFailoverLimit='false', storageDomainId='4a993755-97e9-429c-ad64-96a6aabd2bc6', imageGroupId='b5074e82-10a6-4033-918f-2ff49d7a2f81', imageId='7623bb55-212c-4849-8cad-5b9e7d76f14b'}), log id: 2e77dc31
2016-08-04 16:28:25,690 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SPMGetVolumeInfoVDSCommand] (pool-7-thread-5) [70d3c481] Executing GetVolumeInfo using the current SPM
2016-08-04 16:28:25,691 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.GetVolumeInfoVDSCommand] (pool-7-thread-5) [70d3c481] START, GetVolumeInfoVDSCommand(HostName = host04, GetVolumeInfoVDSCommandParameters:{expectedEngineErrors='[VolumeDoesNotExist]', runAsync='true', hostId='662a3ac1-19b4-4dde-9558-ebaeed4b8439', storagePoolId='00000001-0001-0001-0001-000000000059', storageDomainId='4a993755-97e9-429c-ad64-96a6aabd2bc6', imageGroupId='b5074e82-10a6-4033-918f-2ff49d7a2f81', imageId='7623bb55-212c-4849-8cad-5b9e7d76f14b'}), log id: 34d40c11
2016-08-04 16:28:26,075 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.GetVolumeInfoVDSCommand] (pool-7-thread-5) [70d3c481] Failed in 'GetVolumeInfoVDS' method
2016-08-04 16:28:26,076 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.GetVolumeInfoVDSCommand] (pool-7-thread-5) [70d3c481] Command 'org.ovirt.engine.core.vdsbroker.vdsbroker.GetVolumeInfoVDSCommand' return value '
VolumeInfoReturnForXmlRpc:{status='StatusForXmlRpc [code=201, message=Volume does not exist: (u'7623bb55-212c-4849-8cad-5b9e7d76f14b',)]'}
'
2016-08-04 16:28:26,076 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.GetVolumeInfoVDSCommand] (pool-7-thread-5) [70d3c481] HostName = host04
2016-08-04 16:28:26,077 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.GetVolumeInfoVDSCommand] (pool-7-thread-5) [70d3c481] Command 'GetVolumeInfoVDSCommand(HostName = host04, GetVolumeInfoVDSCommandParameters:{expectedEngineErrors='[VolumeDoesNotExist]', runAsync='true', hostId='662a3ac1-19b4-4dde-9558-ebaeed4b8439', storagePoolId='00000001-0001-0001-0001-000000000059', storageDomainId='4a993755-97e9-429c-ad64-96a6aabd2bc6', imageGroupId='b5074e82-10a6-4033-918f-2ff49d7a2f81', imageId='7623bb55-212c-4849-8cad-5b9e7d76f14b'})' execution failed: VDSGenericException: VDSErrorException: Failed to GetVolumeInfoVDS, error = Volume does not exist: (u'7623bb55-212c-4849-8cad-5b9e7d76f14b',), code = 201
2016-08-04 16:28:26,077 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.GetVolumeInfoVDSCommand] (pool-7-thread-5) [70d3c481] FINISH, GetVolumeInfoVDSCommand, log id: 34d40c11
2016-08-04 16:28:26,077 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SPMGetVolumeInfoVDSCommand] (pool-7-thread-5) [70d3c481] FINISH, SPMGetVolumeInfoVDSCommand, log id: 2e77dc31
2016-08-04 16:28:26,077 INFO [org.ovirt.engine.core.bll.DestroyImageCheckCommand] (pool-7-thread-5) [70d3c481] Requested images were successfully removed
2016-08-04 16:28:27,708 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-41) [76a027e3] Waiting on Live Merge command step 'MERGE' to complete
2016-08-04 16:28:28,521 WARN [org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerObjectsBuilder] (DefaultQuartzScheduler_Worker-26) [2ed02b01] Invalid or unknown guest architecture type '' received from guest agent
2016-08-04 16:28:28,714 INFO [org.ovirt.engine.core.bll.MergeCommandCallback] (DefaultQuartzScheduler_Worker-94) [2ed02b01] Waiting on merge command to complete
2016-08-04 16:28:31,717 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-96) [76a027e3] Waiting on Live Merge child commands to complete
2016-08-04 16:28:32,193 INFO [org.ovirt.engine.core.vdsbroker.VmAnalyzer] (DefaultQuartzScheduler_Worker-15) [2812157e] VM job 'ecb7267c-2d51-425c-a924-07fa109e1a5e': In progress (no change)
2016-08-04 16:28:33,719 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-17) [e97ce78] Waiting on Live Merge child commands to complete
2016-08-04 16:28:35,763 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-2) [68e30f6] Executing Live Merge command step 'COMPLETE'
2016-08-04 16:28:36,814 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (DefaultQuartzScheduler_Worker-55) [68e30f6] START, GetImageInfoVDSCommand( GetImageInfoVDSCommandParameters:{runAsync='true', storagePoolId='00000001-0001-0001-0001-000000000059', ignoreFailoverLimit='false', storageDomainId='4a993755-97e9-429c-ad64-96a6aabd2bc6', imageGroupId='b5074e82-10a6-4033-918f-2ff49d7a2f81', imageId='6525cd3a-88db-46f1-995b-2368fc9cc4e4'}), log id: 2c44f0bc
2016-08-04 16:28:37,149 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (DefaultQuartzScheduler_Worker-55) [68e30f6] FINISH, GetImageInfoVDSCommand, return: org.ovirt.engine.core.common.businessentities.storage.DiskImage at 99ecda5e, log id: 2c44f0bc
2016-08-04 16:28:37,528 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-55) [68e30f6] Successfully merged snapshot '2767884d-9b46-48df-8397-8632874e1c60' images '7623bb55-212c-4849-8cad-5b9e7d76f14b'..'6525cd3a-88db-46f1-995b-2368fc9cc4e4'
2016-08-04 16:28:37,539 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-55) [5af01e6f] All Live Merge child commands have completed, status 'SUCCEEDED'
2016-08-04 16:28:38,564 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-54) [76a027e3] Waiting on Live Merge command step 'MERGE' to complete
2016-08-04 16:28:38,656 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommand] (DefaultQuartzScheduler_Worker-54) [5af01e6f] Ending command 'org.ovirt.engine.core.bll.RemoveSnapshotCommand' successfully.
2016-08-04 16:28:38,717 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-54) [5af01e6f] Correlation ID: 5af01e6f, Job ID: 7849d658-1f5e-410f-a486-a17dc97d9dd6, Call Stack: null, Custom Event ID: -1, Message: Snapshot 'before-ipa-client' deletion for VM 'insanesql2' has been completed.
2016-08-04 16:28:39,750 INFO [org.ovirt.engine.core.bll.MergeCommandCallback] (DefaultQuartzScheduler_Worker-34) [2ed02b01] Waiting on merge command to complete
2016-08-04 16:28:43,897 WARN [org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerObjectsBuilder] (DefaultQuartzScheduler_Worker-63) [34a83044] Invalid or unknown guest architecture type '' received from guest agent
2016-08-04 16:28:44,755 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-76) [2ce25660] Waiting on Live Merge child commands to complete
2016-08-04 16:28:47,516 INFO [org.ovirt.engine.core.vdsbroker.VmAnalyzer] (DefaultQuartzScheduler_Worker-44) [2812157e] VM job 'ecb7267c-2d51-425c-a924-07fa109e1a5e': In progress (no change)
2016-08-04 16:28:48,776 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-41) [76a027e3] Waiting on Live Merge command step 'MERGE' to complete
2016-08-04 16:28:49,782 INFO [org.ovirt.engine.core.bll.MergeCommandCallback] (DefaultQuartzScheduler_Worker-43) [2ed02b01] Waiting on merge command to complete
2016-08-04 16:28:54,786 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-25) [] Waiting on Live Merge child commands to complete
2016-08-04 16:28:58,811 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-60) [76a027e3] Waiting on Live Merge command step 'MERGE' to complete
2016-08-04 16:28:59,244 WARN [org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerObjectsBuilder] (DefaultQuartzScheduler_Worker-90) [2ce25660] Invalid or unknown guest architecture type '' received from guest agent
2016-08-04 16:28:59,817 INFO [org.ovirt.engine.core.bll.MergeCommandCallback] (DefaultQuartzScheduler_Worker-48) [2ed02b01] Waiting on merge command to complete
2016-08-04 16:29:02,800 INFO [org.ovirt.engine.core.vdsbroker.VmAnalyzer] (DefaultQuartzScheduler_Worker-13) [] VM job 'ecb7267c-2d51-425c-a924-07fa109e1a5e': In progress (no change)
2016-08-04 16:29:04,820 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-21) [4f20d956] Waiting on Live Merge child commands to complete
2016-08-04 16:29:08,847 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-1) [76a027e3] Waiting on Live Merge command step 'MERGE' to complete
2016-08-04 16:29:09,853 INFO [org.ovirt.engine.core.bll.MergeCommandCallback] (DefaultQuartzScheduler_Worker-16) [2ed02b01] Waiting on merge command to complete
2016-08-04 16:29:14,701 WARN [org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerObjectsBuilder] (DefaultQuartzScheduler_Worker-24) [421bc3fb] Invalid or unknown guest architecture type '' received from guest agent
2016-08-04 16:29:14,855 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-25) [] Waiting on Live Merge child commands to complete
2016-08-04 16:29:18,069 INFO [org.ovirt.engine.core.vdsbroker.VmAnalyzer] (DefaultQuartzScheduler_Worker-97) [] VM job 'ecb7267c-2d51-425c-a924-07fa109e1a5e': In progress (no change)
2016-08-04 16:29:18,874 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-18) [76a027e3] Waiting on Live Merge command step 'MERGE' to complete
2016-08-04 16:29:19,879 INFO [org.ovirt.engine.core.bll.MergeCommandCallback] (DefaultQuartzScheduler_Worker-54) [2ed02b01] Waiting on merge command to complete
2016-08-04 16:29:21,643 INFO [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (DefaultQuartzScheduler_Worker-47) [c62bf6a] Setting new tasks map. The map contains now 0 tasks
2016-08-04 16:29:21,643 INFO [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (DefaultQuartzScheduler_Worker-47) [c62bf6a] Cleared all tasks of pool '00000001-0001-0001-0001-000000000059'.
2016-08-04 16:29:24,886 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-19) [2812157e] Waiting on Live Merge child commands to complete
2016-08-04 16:29:28,901 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-67) [76a027e3] Waiting on Live Merge command step 'MERGE' to complete
2016-08-04 16:29:29,906 INFO [org.ovirt.engine.core.bll.MergeCommandCallback] (DefaultQuartzScheduler_Worker-16) [2ed02b01] Waiting on merge command to complete
2016-08-04 16:29:29,968 WARN [org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerObjectsBuilder] (DefaultQuartzScheduler_Worker-51) [55957a79] Invalid or unknown guest architecture type '' received from guest agent
2016-08-04 16:29:33,431 INFO [org.ovirt.engine.core.vdsbroker.VmAnalyzer] (DefaultQuartzScheduler_Worker-66) [6af4b2dd] VM job 'ecb7267c-2d51-425c-a924-07fa109e1a5e': In progress (no change)
2016-08-04 16:29:34,915 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-38) [34a83044] Waiting on Live Merge child commands to complete
2016-08-04 16:29:38,940 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-10) [76a027e3] Waiting on Live Merge command step 'MERGE' to complete
2016-08-04 16:29:39,948 INFO [org.ovirt.engine.core.bll.MergeCommandCallback] (DefaultQuartzScheduler_Worker-18) [2ed02b01] Waiting on merge command to complete
2016-08-04 16:29:44,951 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-92) [2a2a8597] Waiting on Live Merge child commands to complete
2016-08-04 16:29:45,351 WARN [org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerObjectsBuilder] (DefaultQuartzScheduler_Worker-19) [2812157e] Invalid or unknown guest architecture type '' received from guest agent
2016-08-04 16:29:48,785 INFO [org.ovirt.engine.core.vdsbroker.VmAnalyzer] (DefaultQuartzScheduler_Worker-68) [53e58337] VM job 'ecb7267c-2d51-425c-a924-07fa109e1a5e': In progress (no change)
2016-08-04 16:29:48,967 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-65) [76a027e3] Waiting on Live Merge command step 'MERGE' to complete
2016-08-04 16:29:49,974 INFO [org.ovirt.engine.core.bll.MergeCommandCallback] (DefaultQuartzScheduler_Worker-1) [2ed02b01] Waiting on merge command to complete
2016-08-04 16:29:54,974 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-83) [76a027e3] Waiting on Live Merge child commands to complete
2016-08-04 16:29:58,990 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-5) [76a027e3] Waiting on Live Merge command step 'MERGE' to complete
2016-08-04 16:29:59,996 INFO [org.ovirt.engine.core.bll.MergeCommandCallback] (DefaultQuartzScheduler_Worker-27) [2ed02b01] Waiting on merge command to complete
2016-08-04 16:30:00,708 WARN [org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerObjectsBuilder] (DefaultQuartzScheduler_Worker-61) [2ed02b01] Invalid or unknown guest architecture type '' received from guest agent
2016-08-04 16:30:04,253 INFO [org.ovirt.engine.core.vdsbroker.VmAnalyzer] (DefaultQuartzScheduler_Worker-53) [76a027e3] VM job 'ecb7267c-2d51-425c-a924-07fa109e1a5e': In progress (no change)
2016-08-04 16:30:05,000 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-4) [76a027e3] Waiting on Live Merge child commands to complete
2016-08-04 16:30:09,038 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-11) [76a027e3] Waiting on Live Merge command step 'MERGE' to complete
2016-08-04 16:30:10,043 INFO [org.ovirt.engine.core.bll.MergeCommandCallback] (DefaultQuartzScheduler_Worker-72) [2ed02b01] Waiting on merge command to complete
2016-08-04 16:30:15,046 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-88) [68e30f6] Waiting on Live Merge child commands to complete
2016-08-04 16:30:16,078 WARN [org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerObjectsBuilder] (DefaultQuartzScheduler_Worker-40) [2ed02b01] Invalid or unknown guest architecture type '' received from guest agent
2016-08-04 16:30:19,072 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-71) [76a027e3] Waiting on Live Merge command step 'MERGE' to complete
2016-08-04 16:30:19,623 INFO [org.ovirt.engine.core.vdsbroker.VmAnalyzer] (DefaultQuartzScheduler_Worker-89) [71801ac4] VM job 'ecb7267c-2d51-425c-a924-07fa109e1a5e': In progress (no change)
2016-08-04 16:30:20,076 INFO [org.ovirt.engine.core.bll.MergeCommandCallback] (DefaultQuartzScheduler_Worker-2) [2ed02b01] Waiting on merge command to complete
2016-08-04 16:30:25,079 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-70) [2a2a8597] Waiting on Live Merge child commands to complete
2016-08-04 16:30:29,098 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-8) [76a027e3] Waiting on Live Merge command step 'MERGE' to complete
2016-08-04 16:30:30,104 INFO [org.ovirt.engine.core.bll.MergeCommandCallback] (DefaultQuartzScheduler_Worker-50) [2ed02b01] Waiting on merge command to complete
2016-08-04 16:30:31,414 WARN [org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerObjectsBuilder] (DefaultQuartzScheduler_Worker-67) [76a027e3] Invalid or unknown guest architecture type '' received from guest agent
2016-08-04 16:30:34,936 INFO [org.ovirt.engine.core.vdsbroker.VmAnalyzer] (DefaultQuartzScheduler_Worker-81) [2ed02b01] VM job 'ecb7267c-2d51-425c-a924-07fa109e1a5e': In progress (no change)
2016-08-04 16:30:35,106 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-94) [2ed02b01] Waiting on Live Merge child commands to complete
2016-08-04 16:30:39,130 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-7) [76a027e3] Waiting on Live Merge command step 'MERGE' to complete
2016-08-04 16:30:40,135 INFO [org.ovirt.engine.core.bll.MergeCommandCallback] (DefaultQuartzScheduler_Worker-46) [2ed02b01] Waiting on merge command to complete
2016-08-04 16:30:45,148 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-74) [13737860] Waiting on Live Merge child commands to complete
2016-08-04 16:30:46,779 WARN [org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerObjectsBuilder] (DefaultQuartzScheduler_Worker-100) [2ed02b01] Invalid or unknown guest architecture type '' received from guest agent
2016-08-04 16:30:49,162 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-31) [76a027e3] Waiting on Live Merge command step 'MERGE' to complete
2016-08-04 16:30:50,168 INFO [org.ovirt.engine.core.bll.MergeCommandCallback] (DefaultQuartzScheduler_Worker-99) [2ed02b01] Waiting on merge command to complete
2016-08-04 16:30:50,242 INFO [org.ovirt.engine.core.vdsbroker.VmAnalyzer] (DefaultQuartzScheduler_Worker-3) [c62bf6a] VM job 'ecb7267c-2d51-425c-a924-07fa109e1a5e': In progress (no change)
2016-08-04 16:30:55,170 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-42) [4c5e5541] Waiting on Live Merge child commands to complete
2016-08-04 16:30:59,196 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-30) [76a027e3] Waiting on Live Merge command step 'MERGE' to complete
2016-08-04 16:31:00,205 INFO [org.ovirt.engine.core.bll.MergeCommandCallback] (DefaultQuartzScheduler_Worker-39) [2ed02b01] Waiting on merge command to complete
2016-08-04 16:31:02,085 WARN [org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerObjectsBuilder] (DefaultQuartzScheduler_Worker-78) [c62bf6a] Invalid or unknown guest architecture type '' received from guest agent
2016-08-04 16:31:05,207 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-45) [1359b200] Waiting on Live Merge child commands to complete
2016-08-04 16:31:05,541 INFO [org.ovirt.engine.core.vdsbroker.VmAnalyzer] (DefaultQuartzScheduler_Worker-34) [2ed02b01] VM job 'ecb7267c-2d51-425c-a924-07fa109e1a5e': In progress (no change)
2016-08-04 16:31:09,222 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-59) [76a027e3] Waiting on Live Merge command step 'MERGE' to complete
2016-08-04 16:31:10,232 INFO [org.ovirt.engine.core.bll.MergeCommandCallback] (DefaultQuartzScheduler_Worker-63) [2ed02b01] Waiting on merge command to complete
2016-08-04 16:31:15,234 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-51) [55957a79] Waiting on Live Merge child commands to complete
2016-08-04 16:31:17,374 WARN [org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerObjectsBuilder] (DefaultQuartzScheduler_Worker-83) [76a027e3] Invalid or unknown guest architecture type '' received from guest agent
2016-08-04 16:31:19,251 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-52) [76a027e3] Waiting on Live Merge command step 'MERGE' to complete
2016-08-04 16:31:20,255 INFO [org.ovirt.engine.core.bll.MergeCommandCallback] (DefaultQuartzScheduler_Worker-30) [2ed02b01] Waiting on merge command to complete
2016-08-04 16:31:20,868 INFO [org.ovirt.engine.core.vdsbroker.VmAnalyzer] (DefaultQuartzScheduler_Worker-24) [421bc3fb] VM job 'ecb7267c-2d51-425c-a924-07fa109e1a5e': In progress (no change)
2016-08-04 16:31:25,258 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-55) [5af01e6f] Waiting on Live Merge child commands to complete
2016-08-04 16:31:29,327 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-4) [76a027e3] Waiting on Live Merge command step 'MERGE' to complete
2016-08-04 16:31:30,334 INFO [org.ovirt.engine.core.bll.MergeCommandCallback] (DefaultQuartzScheduler_Worker-57) [2ed02b01] Waiting on merge command to complete
2016-08-04 16:31:32,696 WARN [org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerObjectsBuilder] (DefaultQuartzScheduler_Worker-50) [2ed02b01] Invalid or unknown guest architecture type '' received from guest agent
2016-08-04 16:31:35,338 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-93) [76a027e3] Waiting on Live Merge child commands to complete
2016-08-04 16:31:36,256 INFO [org.ovirt.engine.core.vdsbroker.VmAnalyzer] (DefaultQuartzScheduler_Worker-87) [6ad8520b] VM job 'ecb7267c-2d51-425c-a924-07fa109e1a5e': In progress (no change)
2016-08-04 16:31:39,498 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-29) [76a027e3] Waiting on Live Merge command step 'MERGE' to complete
2016-08-04 16:31:40,508 INFO [org.ovirt.engine.core.bll.MergeCommandCallback] (DefaultQuartzScheduler_Worker-52) [2ed02b01] Waiting on merge command to complete
2016-08-04 16:31:45,513 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-27) [2ed02b01] Waiting on Live Merge child commands to complete
2016-08-04 16:31:48,076 WARN [org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerObjectsBuilder] (DefaultQuartzScheduler_Worker-73) [2812157e] Invalid or unknown guest architecture type '' received from guest agent
2016-08-04 16:31:49,524 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-53) [76a027e3] Waiting on Live Merge command step 'MERGE' to complete
2016-08-04 16:31:50,532 INFO [org.ovirt.engine.core.bll.MergeCommandCallback] (DefaultQuartzScheduler_Worker-100) [2ed02b01] Waiting on merge command to complete
2016-08-04 16:31:51,630 INFO [org.ovirt.engine.core.vdsbroker.VmAnalyzer] (DefaultQuartzScheduler_Worker-63) [2ed02b01] VM job 'ecb7267c-2d51-425c-a924-07fa109e1a5e': In progress (no change)
2016-08-04 16:31:55,536 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-22) [71801ac4] Waiting on Live Merge child commands to complete
2016-08-04 16:31:59,566 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-62) [76a027e3] Waiting on Live Merge command step 'MERGE' to complete
2016-08-04 16:32:00,572 INFO [org.ovirt.engine.core.bll.MergeCommandCallback] (DefaultQuartzScheduler_Worker-29) [2ed02b01] Waiting on merge command to complete
2016-08-04 16:32:03,417 WARN [org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerObjectsBuilder] (DefaultQuartzScheduler_Worker-71) [76a027e3] Invalid or unknown guest architecture type '' received from guest agent
2016-08-04 16:32:05,584 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-20) [68e30f6] Waiting on Live Merge child commands to complete
2016-08-04 16:32:07,036 INFO [org.ovirt.engine.core.vdsbroker.VmAnalyzer] (DefaultQuartzScheduler_Worker-54) [2ed02b01] VM job 'ecb7267c-2d51-425c-a924-07fa109e1a5e': In progress (no change)
2016-08-04 16:32:09,609 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-36) [76a027e3] Waiting on Live Merge command step 'MERGE' to complete
2016-08-04 16:32:10,616 INFO [org.ovirt.engine.core.bll.MergeCommandCallback] (DefaultQuartzScheduler_Worker-4) [2ed02b01] Waiting on merge command to complete
2016-08-04 16:32:15,618 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-50) [2ed02b01] Waiting on Live Merge child commands to complete
2016-08-04 16:32:18,820 WARN [org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerObjectsBuilder] (DefaultQuartzScheduler_Worker-41) [76a027e3] Invalid or unknown guest architecture type '' received from guest agent
2016-08-04 16:32:19,644 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-62) [76a027e3] Waiting on Live Merge command step 'MERGE' to complete
2016-08-04 16:32:20,654 INFO [org.ovirt.engine.core.bll.MergeCommandCallback] (DefaultQuartzScheduler_Worker-88) [2ed02b01] Waiting on merge command to complete
2016-08-04 16:32:22,351 INFO [org.ovirt.engine.core.vdsbroker.VmAnalyzer] (DefaultQuartzScheduler_Worker-40) [2ed02b01] VM job 'ecb7267c-2d51-425c-a924-07fa109e1a5e': In progress (no change)
2016-08-04 16:32:25,658 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-5) [76a027e3] Waiting on Live Merge child commands to complete
2016-08-04 16:32:29,693 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-45) [76a027e3] Waiting on Live Merge command step 'MERGE' to complete
2016-08-04 16:32:30,702 INFO [org.ovirt.engine.core.bll.MergeCommandCallback] (DefaultQuartzScheduler_Worker-47) [2ed02b01] Waiting on merge command to complete
2016-08-04 16:32:34,184 WARN [org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerObjectsBuilder] (DefaultQuartzScheduler_Worker-19) [2812157e] Invalid or unknown guest architecture type '' received from guest agent
2016-08-04 16:32:35,704 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-72) [2ed02b01] Waiting on Live Merge child commands to complete
2016-08-04 16:32:37,795 INFO [org.ovirt.engine.core.vdsbroker.VmAnalyzer] (DefaultQuartzScheduler_Worker-28) [68e30f6] VM job 'ecb7267c-2d51-425c-a924-07fa109e1a5e': In progress (no change)
2016-08-04 16:32:39,729 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-42) [76a027e3] Waiting on Live Merge command step 'MERGE' to complete
2016-08-04 16:32:40,735 INFO [org.ovirt.engine.core.bll.MergeCommandCallback] (DefaultQuartzScheduler_Worker-14) [2ed02b01] Waiting on merge command to complete
2016-08-04 16:32:45,739 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-77) [e97ce78] Waiting on Live Merge child commands to complete
2016-08-04 16:32:49,532 WARN [org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerObjectsBuilder] (DefaultQuartzScheduler_Worker-90) [2ce25660] Invalid or unknown guest architecture type '' received from guest agent
2016-08-04 16:32:49,779 INFO [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskLiveCommand] (DefaultQuartzScheduler_Worker-48) [76a027e3] Waiting on Live Merge command step 'MERGE' to complete
2016-08-04 16:32:50,784 INFO [org.ovirt.engine.core.bll.MergeCommandCallback] (DefaultQuartzScheduler_Worker-34) [2ed02b01] Waiting on merge command to complete
2016-08-04 16:32:53,045 INFO [org.ovirt.engine.core.vdsbroker.VmAnalyzer] (DefaultQuartzScheduler_Worker-4) [2ed02b01] VM job 'ecb7267c-2d51-425c-a924-07fa109e1a5e': In progress (no change)
2016-08-04 16:32:55,789 INFO [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-99) [2ed02b01] Waiting on Live Merge child commands to complete
More information about the Users
mailing list