Attachment 942690 Details for Bug 1147971 – engine log

engine log

engine.log (text/plain), 213.82 KB, created by Nir Soffer on 2014-09-30 12:35:29 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Nir Soffer

Created: 2014-09-30 12:35:29 UTC

Size: 213.82 KB

patch

obsolete

>2014-09-29 16:41:30,266 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.GetHardwareInfoVDSCommand] (DefaultQuartzScheduler_Worker-35) START, GetHardwareInfoVDSCommand(HostName = voodoo6, HostId = 45462850-a02c-4eeb-8527-292e15e5cb54, vds=Host[voodoo6,45462850-a02c-4eeb-8527-292e15e5cb54]), log id: 4d153a55
>2014-09-29 16:41:30,301 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.GetHardwareInfoVDSCommand] (DefaultQuartzScheduler_Worker-35) FINISH, GetHardwareInfoVDSCommand, log id: 4d153a55
>2014-09-29 16:41:30,321 INFO  [org.ovirt.engine.core.bll.HandleVdsCpuFlagsOrClusterChangedCommand] (DefaultQuartzScheduler_Worker-35) [303d9af1] Running command: HandleVdsCpuFlagsOrClusterChangedCommand internal: true. Entities affected :  ID: 45462850-a02c-4eeb-8527-292e15e5cb54 Type: VDS
>2014-09-29 16:41:30,335 INFO  [org.ovirt.engine.core.bll.InitVdsOnUpCommand] (DefaultQuartzScheduler_Worker-35) [1cd102b8] Running command: InitVdsOnUpCommand internal: true. Entities affected :  ID: b86b687a-d073-497a-ac8a-249025419a3e Type: StoragePool
>2014-09-29 16:41:30,345 INFO  [org.ovirt.engine.core.bll.storage.ConnectHostToStoragePoolServersCommand] (DefaultQuartzScheduler_Worker-35) [394876e9] Running command: ConnectHostToStoragePoolServersCommand internal: true. Entities affected :  ID: b86b687a-d073-497a-ac8a-249025419a3e Type: StoragePool
>2014-09-29 16:41:30,357 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand] (DefaultQuartzScheduler_Worker-35) [394876e9] START, ConnectStorageServerVDSCommand(HostName = voodoo6, HostId = 45462850-a02c-4eeb-8527-292e15e5cb54, storagePoolId = b86b687a-d073-497a-ac8a-249025419a3e, storageType = ISCSI, connectionList = [{ id: af150e8e-4d74-4810-b8bf-0c6a19637dbf, connection: 10.35.16.25, iqn: iqn.1994-05.com.redhat:nsoffer-target1, vfsType: null, mountOptions: null, nfsVersion: null, nfsRetrans: null, nfsTimeo: null };{ id: e8d58651-6414-4fc2-b281-2141cc97829b, connection: 10.35.0.98, iqn: iqn.1994-05.com.redhat:target6, vfsType: null, mountOptions: null, nfsVersion: null, nfsRetrans: null, nfsTimeo: null };{ id: 8f399b5f-1237-479e-82e6-eedb202b66fd, connection: 10.35.16.25, iqn: iqn.1994-05.com.redhat:nsoffer-target2, vfsType: null, mountOptions: null, nfsVersion: null, nfsRetrans: null, nfsTimeo: null };]), log id: 21ad4639
>2014-09-29 16:41:32,780 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand] (DefaultQuartzScheduler_Worker-35) [394876e9] FINISH, ConnectStorageServerVDSCommand, return: {e8d58651-6414-4fc2-b281-2141cc97829b=0, af150e8e-4d74-4810-b8bf-0c6a19637dbf=0, 8f399b5f-1237-479e-82e6-eedb202b66fd=0}, log id: 21ad4639
>2014-09-29 16:41:32,781 INFO  [org.ovirt.engine.core.bll.storage.ConnectHostToStoragePoolServersCommand] (DefaultQuartzScheduler_Worker-35) [394876e9] Host voodoo6 storage connection was succeeded 
>2014-09-29 16:41:32,791 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStoragePoolVDSCommand] (org.ovirt.thread.pool-8-thread-38) START, ConnectStoragePoolVDSCommand(HostName = voodoo6, HostId = 45462850-a02c-4eeb-8527-292e15e5cb54, vdsId = 45462850-a02c-4eeb-8527-292e15e5cb54, storagePoolId = b86b687a-d073-497a-ac8a-249025419a3e, masterVersion = 5), log id: 1e7f764
>2014-09-29 16:41:36,961 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStoragePoolVDSCommand] (org.ovirt.thread.pool-8-thread-38) FINISH, ConnectStoragePoolVDSCommand, log id: 1e7f764
>2014-09-29 16:41:36,987 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.SetMOMPolicyParametersVDSCommand] (DefaultQuartzScheduler_Worker-35) [394876e9] START, SetMOMPolicyParametersVDSCommand(HostName = voodoo6, HostId = 45462850-a02c-4eeb-8527-292e15e5cb54), log id: 773f1526
>2014-09-29 16:41:37,043 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.SetMOMPolicyParametersVDSCommand] (DefaultQuartzScheduler_Worker-35) [394876e9] FINISH, SetMOMPolicyParametersVDSCommand, log id: 773f1526
>2014-09-29 16:41:37,095 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-35) [394876e9] Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: Status of host voodoo6 was set to Up.
>2014-09-29 16:41:37,101 WARN  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-35) [394876e9] Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: Failed to verify Power Management configuration for Host voodoo6.
>2014-09-29 16:41:37,112 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-35) [394876e9] Correlation ID: 1cd102b8, Call Stack: null, Custom Event ID: -1, Message: Unrecognized audit log type has been used.
>2014-09-29 16:41:37,132 INFO  [org.ovirt.engine.core.bll.HandleVdsVersionCommand] (DefaultQuartzScheduler_Worker-35) [5a29dd96] Running command: HandleVdsVersionCommand internal: true. Entities affected :  ID: 45462850-a02c-4eeb-8527-292e15e5cb54 Type: VDS
>2014-09-29 16:41:37,138 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.IrsProxyData] (org.ovirt.thread.pool-8-thread-11) Domain 51752c8f-bbe3-4754-866b-a0afd2a1f59d:sasha-el7 recovered from problem. vds: voodoo6
>2014-09-29 16:41:37,138 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.IrsProxyData] (org.ovirt.thread.pool-8-thread-11) Domain 51752c8f-bbe3-4754-866b-a0afd2a1f59d:sasha-el7 has recovered from problem. No active host in the DC is reporting it as problematic, so clearing the domain recovery timer.
>2014-09-29 16:41:37,140 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.IrsProxyData] (org.ovirt.thread.pool-8-thread-11) Domain ff559f46-c495-4f6b-901c-2a624042a050:jumbo-el7 recovered from problem. vds: voodoo6
>2014-09-29 16:41:37,140 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.IrsProxyData] (org.ovirt.thread.pool-8-thread-11) Domain ff559f46-c495-4f6b-901c-2a624042a050:jumbo-el7 has recovered from problem. No active host in the DC is reporting it as problematic, so clearing the domain recovery timer.
>2014-09-29 16:41:43,280 WARN  [org.ovirt.engine.core.vdsbroker.irsbroker.IrsProxyData] (org.ovirt.thread.pool-8-thread-48) domain 51752c8f-bbe3-4754-866b-a0afd2a1f59d:sasha-el7 in problem. vds: voodoo6
>2014-09-29 16:41:43,281 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.IrsProxyData] (org.ovirt.thread.pool-8-thread-48) Host 45462850-a02c-4eeb-8527-292e15e5cb54 has reported new storage access problem to the following domains 51752c8f-bbe3-4754-866b-a0afd2a1f59d marking it for storage connections and pool metadata refresh (report id: c2360b61-3b75-4851-83b1-948deee7ab7f)
>2014-09-29 16:41:45,321 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.IrsProxyData] (DefaultQuartzScheduler_Worker-49) [17acc57] Running storage connections refresh for hosts [45462850-a02c-4eeb-8527-292e15e5cb54]
>2014-09-29 16:41:45,323 INFO  [org.ovirt.engine.core.bll.storage.ConnectHostToStoragePoolServersCommand] (org.ovirt.thread.pool-8-thread-2) [6886d3ea] Running command: ConnectHostToStoragePoolServersCommand internal: true. Entities affected :  ID: b86b687a-d073-497a-ac8a-249025419a3e Type: StoragePool
>2014-09-29 16:41:45,517 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand] (org.ovirt.thread.pool-8-thread-2) [6886d3ea] START, ConnectStorageServerVDSCommand(HostName = voodoo6, HostId = 45462850-a02c-4eeb-8527-292e15e5cb54, storagePoolId = b86b687a-d073-497a-ac8a-249025419a3e, storageType = ISCSI, connectionList = [{ id: 8f399b5f-1237-479e-82e6-eedb202b66fd, connection: 10.35.16.25, iqn: iqn.1994-05.com.redhat:nsoffer-target2, vfsType: null, mountOptions: null, nfsVersion: null, nfsRetrans: null, nfsTimeo: null };{ id: af150e8e-4d74-4810-b8bf-0c6a19637dbf, connection: 10.35.16.25, iqn: iqn.1994-05.com.redhat:nsoffer-target1, vfsType: null, mountOptions: null, nfsVersion: null, nfsRetrans: null, nfsTimeo: null };{ id: e8d58651-6414-4fc2-b281-2141cc97829b, connection: 10.35.0.98, iqn: iqn.1994-05.com.redhat:target6, vfsType: null, mountOptions: null, nfsVersion: null, nfsRetrans: null, nfsTimeo: null };]), log id: 1cac33e6
>2014-09-29 16:41:48,694 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand] (org.ovirt.thread.pool-8-thread-2) [6886d3ea] FINISH, ConnectStorageServerVDSCommand, return: {e8d58651-6414-4fc2-b281-2141cc97829b=0, af150e8e-4d74-4810-b8bf-0c6a19637dbf=0, 8f399b5f-1237-479e-82e6-eedb202b66fd=0}, log id: 1cac33e6
>2014-09-29 16:41:48,695 INFO  [org.ovirt.engine.core.bll.storage.ConnectHostToStoragePoolServersCommand] (org.ovirt.thread.pool-8-thread-2) [6886d3ea] Host voodoo6 storage connection was succeeded 
>2014-09-29 16:41:48,696 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.IrsProxyData] (DefaultQuartzScheduler_Worker-49) [17acc57] Submitting to the event queue pool refresh for hosts [45462850-a02c-4eeb-8527-292e15e5cb54]
>2014-09-29 16:41:48,732 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.IrsProxyData] (org.ovirt.thread.pool-8-thread-46) Running storage pool metadata refresh for hosts {1}
>2014-09-29 16:41:48,735 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStoragePoolVDSCommand] (org.ovirt.thread.pool-8-thread-35) START, ConnectStoragePoolVDSCommand(HostName = voodoo6, HostId = 45462850-a02c-4eeb-8527-292e15e5cb54, vdsId = 45462850-a02c-4eeb-8527-292e15e5cb54, storagePoolId = b86b687a-d073-497a-ac8a-249025419a3e, masterVersion = 5), log id: 18069eeb
>2014-09-29 16:41:50,034 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStoragePoolVDSCommand] (org.ovirt.thread.pool-8-thread-35) FINISH, ConnectStoragePoolVDSCommand, log id: 18069eeb
>2014-09-29 16:41:56,139 INFO  [org.ovirt.engine.core.bll.OvfDataUpdater] (DefaultQuartzScheduler_Worker-10) [3baa3606] Attempting to update VMs/Templates Ovf.
>2014-09-29 16:41:56,238 INFO  [org.ovirt.engine.core.bll.ProcessOvfUpdateForStorageDomainCommand] (DefaultQuartzScheduler_Worker-10) [6b373cdf] Lock Acquired to object EngineLock [exclusiveLocks= key: ff559f46-c495-4f6b-901c-2a624042a050 value: STORAGE
>key: 563f9e47-9f0e-4d8c-862a-0cd2b86f5d90 value: DISK
>key: 4924a620-9443-4780-81f6-0cc702bdd967 value: DISK
>, sharedLocks= key: b86b687a-d073-497a-ac8a-249025419a3e value: OVF_UPDATE
>]
>2014-09-29 16:41:56,240 INFO  [org.ovirt.engine.core.bll.ProcessOvfUpdateForStorageDomainCommand] (DefaultQuartzScheduler_Worker-10) [6b373cdf] Running command: ProcessOvfUpdateForStorageDomainCommand internal: true. Entities affected :  ID: ff559f46-c495-4f6b-901c-2a624042a050 Type: Storage
>2014-09-29 16:41:56,251 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler_Worker-10) [6b373cdf] START, SetVolumeDescriptionVDSCommand( storagePoolId = b86b687a-d073-497a-ac8a-249025419a3e, ignoreFailoverLimit = false, storageDomainId = ff559f46-c495-4f6b-901c-2a624042a050, imageGroupId = 4924a620-9443-4780-81f6-0cc702bdd967, imageId = 3149a0f8-82d3-43a4-b7e6-d6033485afb0), log id: 6ec3997a
>2014-09-29 16:41:56,251 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler_Worker-10) [6b373cdf] -- executeIrsBrokerCommand: calling 'setVolumeDescription' 
>2014-09-29 16:41:56,252 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler_Worker-10) [6b373cdf] -- setVolumeDescription parameters:
>                spUUID=b86b687a-d073-497a-ac8a-249025419a3e
>                sdUUID=ff559f46-c495-4f6b-901c-2a624042a050
>                imageGroupGUID=4924a620-9443-4780-81f6-0cc702bdd967
>                volUUID=3149a0f8-82d3-43a4-b7e6-d6033485afb0
>                description={"Updated":false,"Disk Description":"OVF_STORE","Storage Domains":[{"uuid":"ff559f46-c495-4f6b-901c-2a624042a050"}],"Last Updated":"Mon Sep 29 15:41:32 IDT 2014"}
>
>2014-09-29 16:41:56,391 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler_Worker-10) [6b373cdf] FINISH, SetVolumeDescriptionVDSCommand, log id: 6ec3997a
>2014-09-29 16:41:56,476 INFO  [org.ovirt.engine.core.bll.UploadStreamCommand] (DefaultQuartzScheduler_Worker-10) [5c6a6c47] Running command: UploadStreamCommand internal: true. Entities affected :  ID: ff559f46-c495-4f6b-901c-2a624042a050 Type: Storage
>2014-09-29 16:41:56,478 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.UploadStreamVDSCommand] (DefaultQuartzScheduler_Worker-10) [5c6a6c47] START, UploadStreamVDSCommand(HostName = voodoo1, HostId = 114c2cc6-5123-45bc-8900-5c875b0543c4), log id: 7c71bf58
>2014-09-29 16:41:56,479 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.UploadStreamVDSCommand] (DefaultQuartzScheduler_Worker-10) [5c6a6c47] -- executeVdsBrokerCommand: 
>2014-09-29 16:41:56,480 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.UploadStreamVDSCommand] (DefaultQuartzScheduler_Worker-10) [5c6a6c47] -- parameters:
>                spUUID=b86b687a-d073-497a-ac8a-249025419a3e
>                sdUUID=ff559f46-c495-4f6b-901c-2a624042a050
>                imageGUID=4924a620-9443-4780-81f6-0cc702bdd967
>                volUUID=3149a0f8-82d3-43a4-b7e6-d6033485afb0
>                size=30,720
>
>2014-09-29 16:41:58,307 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.UploadStreamVDSCommand] (DefaultQuartzScheduler_Worker-10) [5c6a6c47] FINISH, UploadStreamVDSCommand, log id: 7c71bf58
>2014-09-29 16:41:58,309 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (DefaultQuartzScheduler_Worker-10) [5c6a6c47] CommandAsyncTask::Adding CommandMultiAsyncTasks object for command bac9bcb0-2b47-4846-9dcc-7d675ca5ea13
>2014-09-29 16:41:58,310 INFO  [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (DefaultQuartzScheduler_Worker-10) [5c6a6c47] CommandMultiAsyncTasks::AttachTask: Attaching task 84121992-0279-4de1-b965-f5e2ea9dd71e to command bac9bcb0-2b47-4846-9dcc-7d675ca5ea13.
>2014-09-29 16:41:58,356 INFO  [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (DefaultQuartzScheduler_Worker-10) [5c6a6c47] Adding task 84121992-0279-4de1-b965-f5e2ea9dd71e (Parent Command ProcessOvfUpdateForStorageDomain, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters), polling hasn't started yet..
>2014-09-29 16:41:58,373 INFO  [org.ovirt.engine.core.bll.UploadStreamCommand] (DefaultQuartzScheduler_Worker-10) [5c6a6c47] Lock freed to object EngineLock [exclusiveLocks= key: ff559f46-c495-4f6b-901c-2a624042a050 value: STORAGE
>key: 563f9e47-9f0e-4d8c-862a-0cd2b86f5d90 value: DISK
>key: 4924a620-9443-4780-81f6-0cc702bdd967 value: DISK
>, sharedLocks= key: b86b687a-d073-497a-ac8a-249025419a3e value: OVF_UPDATE
>]
>2014-09-29 16:41:58,381 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler_Worker-10) [5c6a6c47] START, SetVolumeDescriptionVDSCommand( storagePoolId = b86b687a-d073-497a-ac8a-249025419a3e, ignoreFailoverLimit = false, storageDomainId = ff559f46-c495-4f6b-901c-2a624042a050, imageGroupId = 4924a620-9443-4780-81f6-0cc702bdd967, imageId = 3149a0f8-82d3-43a4-b7e6-d6033485afb0), log id: 516f9ec1
>2014-09-29 16:41:58,383 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler_Worker-10) [5c6a6c47] -- executeIrsBrokerCommand: calling 'setVolumeDescription' 
>2014-09-29 16:41:58,383 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler_Worker-10) [5c6a6c47] -- setVolumeDescription parameters:
>                spUUID=b86b687a-d073-497a-ac8a-249025419a3e
>                sdUUID=ff559f46-c495-4f6b-901c-2a624042a050
>                imageGroupGUID=4924a620-9443-4780-81f6-0cc702bdd967
>                volUUID=3149a0f8-82d3-43a4-b7e6-d6033485afb0
>                description={"Updated":true,"Disk Description":"OVF_STORE","Storage Domains":[{"uuid":"ff559f46-c495-4f6b-901c-2a624042a050"}],"Last Updated":"Mon Sep 29 16:41:56 IDT 2014","Size":30720}
>
>2014-09-29 16:41:58,525 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler_Worker-10) [5c6a6c47] FINISH, SetVolumeDescriptionVDSCommand, log id: 516f9ec1
>2014-09-29 16:41:58,542 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler_Worker-10) [5c6a6c47] START, SetVolumeDescriptionVDSCommand( storagePoolId = b86b687a-d073-497a-ac8a-249025419a3e, ignoreFailoverLimit = false, storageDomainId = ff559f46-c495-4f6b-901c-2a624042a050, imageGroupId = 563f9e47-9f0e-4d8c-862a-0cd2b86f5d90, imageId = 75b7d7b4-5c1a-48fe-a079-0f6529bd8968), log id: 2ac614cc
>2014-09-29 16:41:58,543 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler_Worker-10) [5c6a6c47] -- executeIrsBrokerCommand: calling 'setVolumeDescription' 
>2014-09-29 16:41:58,544 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler_Worker-10) [5c6a6c47] -- setVolumeDescription parameters:
>                spUUID=b86b687a-d073-497a-ac8a-249025419a3e
>                sdUUID=ff559f46-c495-4f6b-901c-2a624042a050
>                imageGroupGUID=563f9e47-9f0e-4d8c-862a-0cd2b86f5d90
>                volUUID=75b7d7b4-5c1a-48fe-a079-0f6529bd8968
>                description={"Updated":false,"Disk Description":"OVF_STORE","Storage Domains":[{"uuid":"ff559f46-c495-4f6b-901c-2a624042a050"}],"Last Updated":"Mon Sep 29 15:41:32 IDT 2014"}
>
>2014-09-29 16:41:58,723 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler_Worker-10) [5c6a6c47] FINISH, SetVolumeDescriptionVDSCommand, log id: 2ac614cc
>2014-09-29 16:41:58,812 INFO  [org.ovirt.engine.core.bll.UploadStreamCommand] (DefaultQuartzScheduler_Worker-10) [28a9d892] Running command: UploadStreamCommand internal: true. Entities affected :  ID: ff559f46-c495-4f6b-901c-2a624042a050 Type: Storage
>2014-09-29 16:41:58,814 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.UploadStreamVDSCommand] (DefaultQuartzScheduler_Worker-10) [28a9d892] START, UploadStreamVDSCommand(HostName = voodoo1, HostId = 114c2cc6-5123-45bc-8900-5c875b0543c4), log id: 5347af10
>2014-09-29 16:41:58,815 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.UploadStreamVDSCommand] (DefaultQuartzScheduler_Worker-10) [28a9d892] -- executeVdsBrokerCommand: 
>2014-09-29 16:41:58,816 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.UploadStreamVDSCommand] (DefaultQuartzScheduler_Worker-10) [28a9d892] -- parameters:
>                spUUID=b86b687a-d073-497a-ac8a-249025419a3e
>                sdUUID=ff559f46-c495-4f6b-901c-2a624042a050
>                imageGUID=563f9e47-9f0e-4d8c-862a-0cd2b86f5d90
>                volUUID=75b7d7b4-5c1a-48fe-a079-0f6529bd8968
>                size=30,720
>
>2014-09-29 16:42:04,569 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.UploadStreamVDSCommand] (DefaultQuartzScheduler_Worker-10) [28a9d892] FINISH, UploadStreamVDSCommand, log id: 5347af10
>2014-09-29 16:42:04,570 INFO  [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (DefaultQuartzScheduler_Worker-10) [28a9d892] CommandMultiAsyncTasks::AttachTask: Attaching task 79d1f109-dcea-4a48-a15b-2168ab706665 to command bac9bcb0-2b47-4846-9dcc-7d675ca5ea13.
>2014-09-29 16:42:04,634 INFO  [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (DefaultQuartzScheduler_Worker-10) [28a9d892] Adding task 79d1f109-dcea-4a48-a15b-2168ab706665 (Parent Command ProcessOvfUpdateForStorageDomain, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters), polling hasn't started yet..
>2014-09-29 16:42:04,651 WARN  [org.ovirt.engine.core.bll.lock.InMemoryLockManager] (DefaultQuartzScheduler_Worker-10) [28a9d892] Trying to release a shared lock for key: b86b687a-d073-497a-ac8a-249025419a3eOVF_UPDATE , but lock does not exist
>2014-09-29 16:42:04,652 WARN  [org.ovirt.engine.core.bll.lock.InMemoryLockManager] (DefaultQuartzScheduler_Worker-10) [28a9d892] Trying to release exclusive lock which does not exist, lock key: ff559f46-c495-4f6b-901c-2a624042a050STORAGE
>2014-09-29 16:42:04,653 WARN  [org.ovirt.engine.core.bll.lock.InMemoryLockManager] (DefaultQuartzScheduler_Worker-10) [28a9d892] Trying to release exclusive lock which does not exist, lock key: 563f9e47-9f0e-4d8c-862a-0cd2b86f5d90DISK
>2014-09-29 16:42:04,653 WARN  [org.ovirt.engine.core.bll.lock.InMemoryLockManager] (DefaultQuartzScheduler_Worker-10) [28a9d892] Trying to release exclusive lock which does not exist, lock key: 4924a620-9443-4780-81f6-0cc702bdd967DISK
>2014-09-29 16:42:04,654 INFO  [org.ovirt.engine.core.bll.UploadStreamCommand] (DefaultQuartzScheduler_Worker-10) [28a9d892] Lock freed to object EngineLock [exclusiveLocks= key: ff559f46-c495-4f6b-901c-2a624042a050 value: STORAGE
>key: 563f9e47-9f0e-4d8c-862a-0cd2b86f5d90 value: DISK
>key: 4924a620-9443-4780-81f6-0cc702bdd967 value: DISK
>, sharedLocks= key: b86b687a-d073-497a-ac8a-249025419a3e value: OVF_UPDATE
>]
>2014-09-29 16:42:04,656 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler_Worker-10) [28a9d892] START, SetVolumeDescriptionVDSCommand( storagePoolId = b86b687a-d073-497a-ac8a-249025419a3e, ignoreFailoverLimit = false, storageDomainId = ff559f46-c495-4f6b-901c-2a624042a050, imageGroupId = 563f9e47-9f0e-4d8c-862a-0cd2b86f5d90, imageId = 75b7d7b4-5c1a-48fe-a079-0f6529bd8968), log id: 5777cc42
>2014-09-29 16:42:04,657 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler_Worker-10) [28a9d892] -- executeIrsBrokerCommand: calling 'setVolumeDescription' 
>2014-09-29 16:42:04,658 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler_Worker-10) [28a9d892] -- setVolumeDescription parameters:
>                spUUID=b86b687a-d073-497a-ac8a-249025419a3e
>                sdUUID=ff559f46-c495-4f6b-901c-2a624042a050
>                imageGroupGUID=563f9e47-9f0e-4d8c-862a-0cd2b86f5d90
>                volUUID=75b7d7b4-5c1a-48fe-a079-0f6529bd8968
>                description={"Updated":true,"Disk Description":"OVF_STORE","Storage Domains":[{"uuid":"ff559f46-c495-4f6b-901c-2a624042a050"}],"Last Updated":"Mon Sep 29 16:41:56 IDT 2014","Size":30720}
>
>2014-09-29 16:42:04,805 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SetVolumeDescriptionVDSCommand] (DefaultQuartzScheduler_Worker-10) [28a9d892] FINISH, SetVolumeDescriptionVDSCommand, log id: 5777cc42
>2014-09-29 16:42:04,834 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-10) [28a9d892] BaseAsyncTask::startPollingTask: Starting to poll task 84121992-0279-4de1-b965-f5e2ea9dd71e.
>2014-09-29 16:42:04,834 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-10) [28a9d892] BaseAsyncTask::startPollingTask: Starting to poll task 79d1f109-dcea-4a48-a15b-2168ab706665.
>2014-09-29 16:42:13,455 INFO  [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (DefaultQuartzScheduler_Worker-41) [285269ea] Polling and updating Async Tasks: 8 tasks, 2 tasks to poll now
>2014-09-29 16:42:13,476 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-41) [285269ea] SPMAsyncTask::PollTask: Polling task 79d1f109-dcea-4a48-a15b-2168ab706665 (Parent Command ProcessOvfUpdateForStorageDomain, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) returned status finished, result 'success'.
>2014-09-29 16:42:13,477 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-41) [285269ea] BaseAsyncTask::onTaskEndSuccess: Task 79d1f109-dcea-4a48-a15b-2168ab706665 (Parent Command ProcessOvfUpdateForStorageDomain, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) ended successfully.
>2014-09-29 16:42:13,477 INFO  [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (DefaultQuartzScheduler_Worker-41) [285269ea] Task with DB Task ID af740bd9-468f-4e92-8be1-7a709ad1d4ba and VDSM Task ID 84121992-0279-4de1-b965-f5e2ea9dd71e is in state Polling. End action for command bac9bcb0-2b47-4846-9dcc-7d675ca5ea13 will proceed when all the entitys tasks are completed.
>2014-09-29 16:42:13,478 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-41) [285269ea] SPMAsyncTask::PollTask: Polling task 84121992-0279-4de1-b965-f5e2ea9dd71e (Parent Command ProcessOvfUpdateForStorageDomain, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) returned status finished, result 'success'.
>2014-09-29 16:42:13,479 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-41) [285269ea] BaseAsyncTask::onTaskEndSuccess: Task 84121992-0279-4de1-b965-f5e2ea9dd71e (Parent Command ProcessOvfUpdateForStorageDomain, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) ended successfully.
>2014-09-29 16:42:13,479 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (DefaultQuartzScheduler_Worker-41) [285269ea] CommandAsyncTask::endActionIfNecessary: All tasks of command bac9bcb0-2b47-4846-9dcc-7d675ca5ea13 has ended -> executing endAction
>2014-09-29 16:42:13,479 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (DefaultQuartzScheduler_Worker-41) [285269ea] CommandAsyncTask::endAction: Ending action for 2 tasks (command ID: bac9bcb0-2b47-4846-9dcc-7d675ca5ea13): calling endAction .
>2014-09-29 16:42:13,480 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-27) [285269ea] CommandAsyncTask::endCommandAction [within thread] context: Attempting to endAction ProcessOvfUpdateForStorageDomain, executionIndex: 0
>2014-09-29 16:42:13,539 INFO  [org.ovirt.engine.core.bll.ProcessOvfUpdateForStorageDomainCommand] (org.ovirt.thread.pool-8-thread-27) [6b373cdf] Ending command successfully: org.ovirt.engine.core.bll.ProcessOvfUpdateForStorageDomainCommand
>2014-09-29 16:42:13,539 WARN  [org.ovirt.engine.core.bll.lock.InMemoryLockManager] (org.ovirt.thread.pool-8-thread-27) [6b373cdf] Trying to release a shared lock for key: b86b687a-d073-497a-ac8a-249025419a3eOVF_UPDATE , but lock does not exist
>2014-09-29 16:42:13,540 WARN  [org.ovirt.engine.core.bll.lock.InMemoryLockManager] (org.ovirt.thread.pool-8-thread-27) [6b373cdf] Trying to release exclusive lock which does not exist, lock key: ff559f46-c495-4f6b-901c-2a624042a050STORAGE
>2014-09-29 16:42:13,540 WARN  [org.ovirt.engine.core.bll.lock.InMemoryLockManager] (org.ovirt.thread.pool-8-thread-27) [6b373cdf] Trying to release exclusive lock which does not exist, lock key: 563f9e47-9f0e-4d8c-862a-0cd2b86f5d90DISK
>2014-09-29 16:42:13,540 WARN  [org.ovirt.engine.core.bll.lock.InMemoryLockManager] (org.ovirt.thread.pool-8-thread-27) [6b373cdf] Trying to release exclusive lock which does not exist, lock key: 4924a620-9443-4780-81f6-0cc702bdd967DISK
>2014-09-29 16:42:13,541 INFO  [org.ovirt.engine.core.bll.ProcessOvfUpdateForStorageDomainCommand] (org.ovirt.thread.pool-8-thread-27) [6b373cdf] Lock freed to object EngineLock [exclusiveLocks= key: ff559f46-c495-4f6b-901c-2a624042a050 value: STORAGE
>key: 563f9e47-9f0e-4d8c-862a-0cd2b86f5d90 value: DISK
>key: 4924a620-9443-4780-81f6-0cc702bdd967 value: DISK
>, sharedLocks= key: b86b687a-d073-497a-ac8a-249025419a3e value: OVF_UPDATE
>]
>2014-09-29 16:42:13,541 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-27) [6b373cdf] CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type ProcessOvfUpdateForStorageDomain completed, handling the result.
>2014-09-29 16:42:13,542 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-27) [6b373cdf] CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type ProcessOvfUpdateForStorageDomain succeeded, clearing tasks.
>2014-09-29 16:42:13,542 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (org.ovirt.thread.pool-8-thread-27) [6b373cdf] SPMAsyncTask::ClearAsyncTask: Attempting to clear task 79d1f109-dcea-4a48-a15b-2168ab706665
>2014-09-29 16:42:13,542 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-27) [6b373cdf] START, SPMClearTaskVDSCommand( storagePoolId = b86b687a-d073-497a-ac8a-249025419a3e, ignoreFailoverLimit = false, taskId = 79d1f109-dcea-4a48-a15b-2168ab706665), log id: 5bc98e8a
>2014-09-29 16:42:13,543 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-27) [6b373cdf] START, HSMClearTaskVDSCommand(HostName = voodoo1, HostId = 114c2cc6-5123-45bc-8900-5c875b0543c4, taskId=79d1f109-dcea-4a48-a15b-2168ab706665), log id: dad351a
>2014-09-29 16:42:13,571 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-27) [6b373cdf] FINISH, HSMClearTaskVDSCommand, log id: dad351a
>2014-09-29 16:42:13,571 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-27) [6b373cdf] FINISH, SPMClearTaskVDSCommand, log id: 5bc98e8a
>2014-09-29 16:42:13,580 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (org.ovirt.thread.pool-8-thread-27) [6b373cdf] BaseAsyncTask::removeTaskFromDB: Removed task 79d1f109-dcea-4a48-a15b-2168ab706665 from DataBase
>2014-09-29 16:42:13,580 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (org.ovirt.thread.pool-8-thread-27) [6b373cdf] SPMAsyncTask::ClearAsyncTask: Attempting to clear task 84121992-0279-4de1-b965-f5e2ea9dd71e
>2014-09-29 16:42:13,581 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-27) [6b373cdf] START, SPMClearTaskVDSCommand( storagePoolId = b86b687a-d073-497a-ac8a-249025419a3e, ignoreFailoverLimit = false, taskId = 84121992-0279-4de1-b965-f5e2ea9dd71e), log id: ec72a40
>2014-09-29 16:42:13,582 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-27) [6b373cdf] START, HSMClearTaskVDSCommand(HostName = voodoo1, HostId = 114c2cc6-5123-45bc-8900-5c875b0543c4, taskId=84121992-0279-4de1-b965-f5e2ea9dd71e), log id: 35a6d754
>2014-09-29 16:42:13,645 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-27) [6b373cdf] FINISH, HSMClearTaskVDSCommand, log id: 35a6d754
>2014-09-29 16:42:13,646 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-27) [6b373cdf] FINISH, SPMClearTaskVDSCommand, log id: ec72a40
>2014-09-29 16:42:13,663 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (org.ovirt.thread.pool-8-thread-27) [6b373cdf] BaseAsyncTask::removeTaskFromDB: Removed task 84121992-0279-4de1-b965-f5e2ea9dd71e from DataBase
>2014-09-29 16:42:13,663 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-27) [6b373cdf] CommandAsyncTask::HandleEndActionResult [within thread]: Removing CommandMultiAsyncTasks object for entity bac9bcb0-2b47-4846-9dcc-7d675ca5ea13
>2014-09-29 16:42:13,692 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.IrsProxyData] (org.ovirt.thread.pool-8-thread-42) Host 45462850-a02c-4eeb-8527-292e15e5cb54 no longer storage access problem to any relevant domain  clearing its report (report id: c2360b61-3b75-4851-83b1-948deee7ab7f)
>2014-09-29 16:42:13,693 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.IrsProxyData] (org.ovirt.thread.pool-8-thread-42) Domain 51752c8f-bbe3-4754-866b-a0afd2a1f59d:sasha-el7 recovered from problem. vds: voodoo6
>2014-09-29 16:42:13,694 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.IrsProxyData] (org.ovirt.thread.pool-8-thread-42) Domain 51752c8f-bbe3-4754-866b-a0afd2a1f59d:sasha-el7 has recovered from problem. No active host in the DC is reporting it as problematic, so clearing the domain recovery timer.
>2014-09-29 16:42:20,035 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.IrsProxyData] (DefaultQuartzScheduler_Worker-22) No hosts has reported storage access problem to domains, clearing the handled hosts reports map
>2014-09-29 16:43:23,900 INFO  [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (DefaultQuartzScheduler_Worker-52) [3c5a94f0] Setting new tasks map. The map contains now 6 tasks
>2014-09-29 16:48:40,642 INFO  [org.ovirt.engine.core.bll.ForceSelectSPMCommand] (ajp--127.0.0.1-8702-3) [76909ee0] Running command: ForceSelectSPMCommand internal: false. Entities affected :  ID: 45462850-a02c-4eeb-8527-292e15e5cb54 Type: VDSAction group MANIPULATE_HOST with role type ADMIN
>2014-09-29 16:48:40,642 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SpmStopOnIrsVDSCommand] (ajp--127.0.0.1-8702-3) [76909ee0] START, SpmStopOnIrsVDSCommand( storagePoolId = b86b687a-d073-497a-ac8a-249025419a3e, ignoreFailoverLimit = false), log id: 240123df
>2014-09-29 16:48:40,643 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.ResetIrsVDSCommand] (ajp--127.0.0.1-8702-3) [76909ee0] START, ResetIrsVDSCommand( storagePoolId = b86b687a-d073-497a-ac8a-249025419a3e, ignoreFailoverLimit = false, vdsId = 114c2cc6-5123-45bc-8900-5c875b0543c4, ignoreStopFailed = false), log id: 46da17f0
>2014-09-29 16:48:40,645 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStopVDSCommand] (ajp--127.0.0.1-8702-3) [76909ee0] START, SpmStopVDSCommand(HostName = voodoo1, HostId = 114c2cc6-5123-45bc-8900-5c875b0543c4, storagePoolId = b86b687a-d073-497a-ac8a-249025419a3e), log id: 4616375a
>2014-09-29 16:48:40,660 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStopVDSCommand] (ajp--127.0.0.1-8702-3) [76909ee0] SpmStopVDSCommand::Not stopping SPM on vds voodoo1, pool id b86b687a-d073-497a-ac8a-249025419a3e as there are uncleared tasks
>2014-09-29 16:48:40,660 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStopVDSCommand] (ajp--127.0.0.1-8702-3) [76909ee0] FINISH, SpmStopVDSCommand, log id: 4616375a
>2014-09-29 16:48:40,661 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.ResetIrsVDSCommand] (ajp--127.0.0.1-8702-3) [76909ee0] FINISH, ResetIrsVDSCommand, log id: 46da17f0
>2014-09-29 16:48:40,661 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SpmStopOnIrsVDSCommand] (ajp--127.0.0.1-8702-3) [76909ee0] FINISH, SpmStopOnIrsVDSCommand, log id: 240123df
>2014-09-29 16:48:40,667 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-3) [76909ee0] Correlation ID: 76909ee0, Job ID: 15f83881-92fa-4d92-9022-400ec06ec3d4, Call Stack: null, Custom Event ID: -1, Message: Failed to force select voodoo6 as the SPM due to a failure to stop the current SPM.
>2014-09-29 16:48:40,675 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-3) [76909ee0] Correlation ID: 76909ee0, Job ID: 15f83881-92fa-4d92-9022-400ec06ec3d4, Call Stack: null, Custom Event ID: -1, Message: Unrecognized audit log type has been used.
>2014-09-29 16:49:09,004 INFO  [org.ovirt.engine.core.bll.RunVmCommand] (ajp--127.0.0.1-8702-1) [d9916ee] Lock Acquired to object EngineLock [exclusiveLocks= key: 4a0d069d-be19-4585-bb79-859ca23a5339 value: VM
>, sharedLocks= ]
>2014-09-29 16:49:09,030 WARN  [org.ovirt.engine.core.bll.RunVmCommand] (ajp--127.0.0.1-8702-1) [d9916ee] CanDoAction of action RunVm failed. Reasons:VAR__ACTION__RUN,VAR__TYPE__VM,ACTION_TYPE_FAILED_VM_IS_DURING_SNAPSHOT
>2014-09-29 16:49:09,030 INFO  [org.ovirt.engine.core.bll.RunVmCommand] (ajp--127.0.0.1-8702-1) [d9916ee] Lock freed to object EngineLock [exclusiveLocks= key: 4a0d069d-be19-4585-bb79-859ca23a5339 value: VM
>, sharedLocks= ]
>2014-09-29 16:50:36,773 INFO  [org.ovirt.engine.core.bll.ShutdownVmCommand] (org.ovirt.thread.pool-8-thread-11) [6525534] Running command: ShutdownVmCommand internal: false. Entities affected :  ID: 98e6058d-cf96-4929-b118-4fc5542a30ba Type: VMAction group VM_BASIC_OPERATIONS with role type USER
>2014-09-29 16:50:36,775 INFO  [org.ovirt.engine.core.bll.ShutdownVmCommand] (org.ovirt.thread.pool-8-thread-11) [6525534] Entered (VM vm02).
>2014-09-29 16:50:36,775 INFO  [org.ovirt.engine.core.bll.ShutdownVmCommand] (org.ovirt.thread.pool-8-thread-11) [6525534] Sending shutdown command for VM vm02.
>2014-09-29 16:50:36,776 INFO  [org.ovirt.engine.core.vdsbroker.DestroyVmVDSCommand] (org.ovirt.thread.pool-8-thread-11) [6525534] START, DestroyVmVDSCommand(HostName = voodoo1, HostId = 114c2cc6-5123-45bc-8900-5c875b0543c4, vmId=98e6058d-cf96-4929-b118-4fc5542a30ba, force=false, secondsToWait=30, gracefully=true, reason=), log id: 7675c276
>2014-09-29 16:50:36,779 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.DestroyVDSCommand] (org.ovirt.thread.pool-8-thread-11) [6525534] START, DestroyVDSCommand(HostName = voodoo1, HostId = 114c2cc6-5123-45bc-8900-5c875b0543c4, vmId=98e6058d-cf96-4929-b118-4fc5542a30ba, force=false, secondsToWait=30, gracefully=true, reason=), log id: 54c69b24
>2014-09-29 16:50:36,793 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.DestroyVDSCommand] (org.ovirt.thread.pool-8-thread-11) [6525534] FINISH, DestroyVDSCommand, log id: 54c69b24
>2014-09-29 16:50:36,806 INFO  [org.ovirt.engine.core.vdsbroker.DestroyVmVDSCommand] (org.ovirt.thread.pool-8-thread-11) [6525534] FINISH, DestroyVmVDSCommand, return: PoweringDown, log id: 7675c276
>2014-09-29 16:50:36,815 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-8-thread-11) [6525534] Correlation ID: 6525534, Job ID: 4d93ce3f-a21d-4adf-8c90-e14c7c00ca5c, Call Stack: null, Custom Event ID: -1, Message: VM shutdown initiated by admin on VM vm02 (Host: voodoo1) (Reason: Not Specified).
>2014-09-29 16:50:42,073 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.DestroyVDSCommand] (DefaultQuartzScheduler_Worker-84) START, DestroyVDSCommand(HostName = voodoo1, HostId = 114c2cc6-5123-45bc-8900-5c875b0543c4, vmId=98e6058d-cf96-4929-b118-4fc5542a30ba, force=false, secondsToWait=0, gracefully=false, reason=), log id: 4ccefd80
>2014-09-29 16:50:42,127 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.DestroyVDSCommand] (DefaultQuartzScheduler_Worker-84) FINISH, DestroyVDSCommand, log id: 4ccefd80
>2014-09-29 16:50:42,182 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-84) Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: VM vm02 is down. Exit message: Admin shut down from the engine
>2014-09-29 16:50:42,186 INFO  [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-84) VM vm02 (98e6058d-cf96-4929-b118-4fc5542a30ba) is running in db and not running in VDS voodoo1
>2014-09-29 16:50:42,187 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.FullListVdsCommand] (DefaultQuartzScheduler_Worker-84) START, FullListVdsCommand(HostName = voodoo1, HostId = 114c2cc6-5123-45bc-8900-5c875b0543c4, vds=Host[voodoo1,114c2cc6-5123-45bc-8900-5c875b0543c4], vmIds=[98e6058d-cf96-4929-b118-4fc5542a30ba]), log id: 6f269d68
>2014-09-29 16:50:42,205 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.FullListVdsCommand] (DefaultQuartzScheduler_Worker-84) FINISH, FullListVdsCommand, return: [], log id: 6f269d68
>2014-09-29 16:50:42,239 INFO  [org.ovirt.engine.core.bll.ProcessDownVmCommand] (org.ovirt.thread.pool-8-thread-4) [4647df01] Running command: ProcessDownVmCommand internal: true.
>2014-09-29 16:50:57,937 INFO  [org.ovirt.engine.core.bll.RemoveSnapshotCommand] (ajp--127.0.0.1-8702-6) [535e4d36] Lock Acquired to object EngineLock [exclusiveLocks= key: 98e6058d-cf96-4929-b118-4fc5542a30ba value: VM
>, sharedLocks= ]
>2014-09-29 16:50:57,977 INFO  [org.ovirt.engine.core.bll.RemoveSnapshotCommand] (ajp--127.0.0.1-8702-6) [535e4d36] Running command: RemoveSnapshotCommand internal: false. Entities affected :  ID: 98e6058d-cf96-4929-b118-4fc5542a30ba Type: VMAction group MANIPULATE_VM_SNAPSHOTS with role type USER
>2014-09-29 16:50:57,985 INFO  [org.ovirt.engine.core.bll.RemoveSnapshotCommand] (ajp--127.0.0.1-8702-6) [535e4d36] Lock freed to object EngineLock [exclusiveLocks= key: 98e6058d-cf96-4929-b118-4fc5542a30ba value: VM
>, sharedLocks= ]
>2014-09-29 16:50:57,990 INFO  [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskCommand] (ajp--127.0.0.1-8702-6) [5ec4482f] Running command: RemoveSnapshotSingleDiskCommand internal: true. Entities affected :  ID: 00000000-0000-0000-0000-000000000000 Type: Storage
>2014-09-29 16:50:58,037 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.MergeSnapshotsVDSCommand] (ajp--127.0.0.1-8702-6) [5ec4482f] START, MergeSnapshotsVDSCommand( storagePoolId = b86b687a-d073-497a-ac8a-249025419a3e, ignoreFailoverLimit = false, storageDomainId = ff559f46-c495-4f6b-901c-2a624042a050, imageGroupId = a75c1851-bddb-4339-bee2-f22b4b1268ac, imageId = 7d6fc245-5c10-41e8-b6b0-75ff3880a99f, imageId2 = 9d74263f-76a8-4c33-94f7-454e06934207, vmId = 98e6058d-cf96-4929-b118-4fc5542a30ba, postZero = false), log id: 782e5a7a
>2014-09-29 16:50:58,097 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.MergeSnapshotsVDSCommand] (ajp--127.0.0.1-8702-6) [5ec4482f] FINISH, MergeSnapshotsVDSCommand, log id: 782e5a7a
>2014-09-29 16:50:58,111 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (ajp--127.0.0.1-8702-6) [5ec4482f] CommandAsyncTask::Adding CommandMultiAsyncTasks object for command 3da8b1a3-49c9-410f-9d01-728415b438d3
>2014-09-29 16:50:58,111 INFO  [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (ajp--127.0.0.1-8702-6) [5ec4482f] CommandMultiAsyncTasks::AttachTask: Attaching task f9babdc0-fabe-4f02-8e22-c59a4692abce to command 3da8b1a3-49c9-410f-9d01-728415b438d3.
>2014-09-29 16:50:58,143 INFO  [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (ajp--127.0.0.1-8702-6) [5ec4482f] Adding task f9babdc0-fabe-4f02-8e22-c59a4692abce (Parent Command RemoveSnapshot, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters), polling hasn't started yet..
>2014-09-29 16:50:58,209 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-6) [5ec4482f] Correlation ID: 535e4d36, Job ID: 3a93bc58-01aa-4c74-8d7e-a3d49166ca9d, Call Stack: null, Custom Event ID: -1, Message: Snapshot 'Auto-generated for Live Storage Migration' deletion for VM 'vm02' was initiated by admin.
>2014-09-29 16:50:58,210 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (ajp--127.0.0.1-8702-6) [5ec4482f] BaseAsyncTask::startPollingTask: Starting to poll task f9babdc0-fabe-4f02-8e22-c59a4692abce.
>2014-09-29 16:51:03,494 INFO  [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (DefaultQuartzScheduler_Worker-14) Polling and updating Async Tasks: 7 tasks, 1 tasks to poll now
>2014-09-29 16:51:03,511 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-14) SPMAsyncTask::PollTask: Polling task f9babdc0-fabe-4f02-8e22-c59a4692abce (Parent Command RemoveSnapshot, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) returned status running.
>2014-09-29 16:51:03,512 INFO  [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (DefaultQuartzScheduler_Worker-14) Finished polling Tasks, will poll again in 10 seconds.
>2014-09-29 16:51:05,415 INFO  [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-60) Waiting on Live Merge child commands to complete
>2014-09-29 16:51:15,415 INFO  [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-24) Waiting on Live Merge child commands to complete
>2014-09-29 16:51:25,416 INFO  [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-80) Waiting on Live Merge child commands to complete
>2014-09-29 16:51:35,417 INFO  [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-39) Waiting on Live Merge child commands to complete
>2014-09-29 16:51:45,418 INFO  [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-15) Waiting on Live Merge child commands to complete
>2014-09-29 16:51:55,418 INFO  [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-35) [5a29dd96] Waiting on Live Merge child commands to complete
>2014-09-29 16:52:05,419 INFO  [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-56) Waiting on Live Merge child commands to complete
>2014-09-29 16:52:15,421 INFO  [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-13) Waiting on Live Merge child commands to complete
>2014-09-29 16:52:25,421 INFO  [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-3) Waiting on Live Merge child commands to complete
>2014-09-29 16:52:35,422 INFO  [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-97) [fe9277d] Waiting on Live Merge child commands to complete
>2014-09-29 16:52:45,422 INFO  [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-46) [6a080e3d] Waiting on Live Merge child commands to complete
>2014-09-29 16:52:55,423 INFO  [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-51) Waiting on Live Merge child commands to complete
>2014-09-29 16:53:03,797 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-26) SPMAsyncTask::PollTask: Polling task f9babdc0-fabe-4f02-8e22-c59a4692abce (Parent Command RemoveSnapshot, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) returned status finished, result 'success'.
>2014-09-29 16:53:03,817 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-26) BaseAsyncTask::onTaskEndSuccess: Task f9babdc0-fabe-4f02-8e22-c59a4692abce (Parent Command RemoveSnapshot, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) ended successfully.
>2014-09-29 16:53:03,819 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (DefaultQuartzScheduler_Worker-26) CommandAsyncTask::endActionIfNecessary: All tasks of command 3da8b1a3-49c9-410f-9d01-728415b438d3 has ended -> executing endAction
>2014-09-29 16:53:03,820 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (DefaultQuartzScheduler_Worker-26) CommandAsyncTask::endAction: Ending action for 1 tasks (command ID: 3da8b1a3-49c9-410f-9d01-728415b438d3): calling endAction .
>2014-09-29 16:53:03,821 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-27) CommandAsyncTask::endCommandAction [within thread] context: Attempting to endAction RemoveSnapshot, executionIndex: 0
>2014-09-29 16:53:03,859 INFO  [org.ovirt.engine.core.bll.RemoveSnapshotCommand] (org.ovirt.thread.pool-8-thread-27) [535e4d36] Ending command successfully: org.ovirt.engine.core.bll.RemoveSnapshotCommand
>2014-09-29 16:53:03,875 INFO  [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskCommand] (org.ovirt.thread.pool-8-thread-27) [5ec4482f] Ending command successfully: org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskCommand
>2014-09-29 16:53:03,883 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (org.ovirt.thread.pool-8-thread-27) [5ec4482f] START, GetImageInfoVDSCommand( storagePoolId = b86b687a-d073-497a-ac8a-249025419a3e, ignoreFailoverLimit = false, storageDomainId = ff559f46-c495-4f6b-901c-2a624042a050, imageGroupId = a75c1851-bddb-4339-bee2-f22b4b1268ac, imageId = 9d74263f-76a8-4c33-94f7-454e06934207), log id: 6bb116a8
>2014-09-29 16:53:05,026 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (org.ovirt.thread.pool-8-thread-27) [5ec4482f] FINISH, GetImageInfoVDSCommand, return: org.ovirt.engine.core.common.businessentities.DiskImage@2d5acc1e, log id: 6bb116a8
>2014-09-29 16:53:05,085 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-8-thread-27) Correlation ID: 535e4d36, Call Stack: null, Custom Event ID: -1, Message: Snapshot 'Auto-generated for Live Storage Migration' deletion for VM 'vm02' has been completed.
>2014-09-29 16:53:05,086 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-27) CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type RemoveSnapshot completed, handling the result.
>2014-09-29 16:53:05,087 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-27) CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type RemoveSnapshot succeeded, clearing tasks.
>2014-09-29 16:53:05,101 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (org.ovirt.thread.pool-8-thread-27) SPMAsyncTask::ClearAsyncTask: Attempting to clear task f9babdc0-fabe-4f02-8e22-c59a4692abce
>2014-09-29 16:53:05,102 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-27) START, SPMClearTaskVDSCommand( storagePoolId = b86b687a-d073-497a-ac8a-249025419a3e, ignoreFailoverLimit = false, taskId = f9babdc0-fabe-4f02-8e22-c59a4692abce), log id: 25550b8b
>2014-09-29 16:53:05,105 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-27) START, HSMClearTaskVDSCommand(HostName = voodoo1, HostId = 114c2cc6-5123-45bc-8900-5c875b0543c4, taskId=f9babdc0-fabe-4f02-8e22-c59a4692abce), log id: 7268e5d2
>2014-09-29 16:53:05,133 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-27) FINISH, HSMClearTaskVDSCommand, log id: 7268e5d2
>2014-09-29 16:53:05,133 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-27) FINISH, SPMClearTaskVDSCommand, log id: 25550b8b
>2014-09-29 16:53:05,143 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (org.ovirt.thread.pool-8-thread-27) BaseAsyncTask::removeTaskFromDB: Removed task f9babdc0-fabe-4f02-8e22-c59a4692abce from DataBase
>2014-09-29 16:53:05,144 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-27) CommandAsyncTask::HandleEndActionResult [within thread]: Removing CommandMultiAsyncTasks object for entity 3da8b1a3-49c9-410f-9d01-728415b438d3
>2014-09-29 16:54:23,908 INFO  [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (DefaultQuartzScheduler_Worker-48) Setting new tasks map. The map contains now 6 tasks
>2014-09-29 16:55:30,409 INFO  [org.ovirt.engine.core.bll.ForceSelectSPMCommand] (ajp--127.0.0.1-8702-5) [10f21e26] Running command: ForceSelectSPMCommand internal: false. Entities affected :  ID: 45462850-a02c-4eeb-8527-292e15e5cb54 Type: VDSAction group MANIPULATE_HOST with role type ADMIN
>2014-09-29 16:55:30,409 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SpmStopOnIrsVDSCommand] (ajp--127.0.0.1-8702-5) [10f21e26] START, SpmStopOnIrsVDSCommand( storagePoolId = b86b687a-d073-497a-ac8a-249025419a3e, ignoreFailoverLimit = false), log id: 3a3395d4
>2014-09-29 16:55:30,410 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.ResetIrsVDSCommand] (ajp--127.0.0.1-8702-5) [10f21e26] START, ResetIrsVDSCommand( storagePoolId = b86b687a-d073-497a-ac8a-249025419a3e, ignoreFailoverLimit = false, vdsId = 114c2cc6-5123-45bc-8900-5c875b0543c4, ignoreStopFailed = false), log id: 10b1af26
>2014-09-29 16:55:30,411 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStopVDSCommand] (ajp--127.0.0.1-8702-5) [10f21e26] START, SpmStopVDSCommand(HostName = voodoo1, HostId = 114c2cc6-5123-45bc-8900-5c875b0543c4, storagePoolId = b86b687a-d073-497a-ac8a-249025419a3e), log id: ae2a471
>2014-09-29 16:55:30,426 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStopVDSCommand] (ajp--127.0.0.1-8702-5) [10f21e26] SpmStopVDSCommand::Not stopping SPM on vds voodoo1, pool id b86b687a-d073-497a-ac8a-249025419a3e as there are uncleared tasks
>2014-09-29 16:55:30,427 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStopVDSCommand] (ajp--127.0.0.1-8702-5) [10f21e26] FINISH, SpmStopVDSCommand, log id: ae2a471
>2014-09-29 16:55:30,427 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.ResetIrsVDSCommand] (ajp--127.0.0.1-8702-5) [10f21e26] FINISH, ResetIrsVDSCommand, log id: 10b1af26
>2014-09-29 16:55:30,427 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SpmStopOnIrsVDSCommand] (ajp--127.0.0.1-8702-5) [10f21e26] FINISH, SpmStopOnIrsVDSCommand, log id: 3a3395d4
>2014-09-29 16:55:30,434 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-5) [10f21e26] Correlation ID: 10f21e26, Job ID: fe685e6e-ad91-4e1e-8c11-a0ce99bcae21, Call Stack: null, Custom Event ID: -1, Message: Failed to force select voodoo6 as the SPM due to a failure to stop the current SPM.
>2014-09-29 16:55:30,442 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-5) [10f21e26] Correlation ID: 10f21e26, Job ID: fe685e6e-ad91-4e1e-8c11-a0ce99bcae21, Call Stack: null, Custom Event ID: -1, Message: Unrecognized audit log type has been used.
>2014-09-29 17:03:01,530 INFO  [org.ovirt.engine.core.bll.ForceSelectSPMCommand] (ajp--127.0.0.1-8702-7) [4349da9e] Running command: ForceSelectSPMCommand internal: false. Entities affected :  ID: 45462850-a02c-4eeb-8527-292e15e5cb54 Type: VDSAction group MANIPULATE_HOST with role type ADMIN
>2014-09-29 17:03:01,530 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SpmStopOnIrsVDSCommand] (ajp--127.0.0.1-8702-7) [4349da9e] START, SpmStopOnIrsVDSCommand( storagePoolId = b86b687a-d073-497a-ac8a-249025419a3e, ignoreFailoverLimit = false), log id: 505cdb68
>2014-09-29 17:03:01,531 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.ResetIrsVDSCommand] (ajp--127.0.0.1-8702-7) [4349da9e] START, ResetIrsVDSCommand( storagePoolId = b86b687a-d073-497a-ac8a-249025419a3e, ignoreFailoverLimit = false, vdsId = 114c2cc6-5123-45bc-8900-5c875b0543c4, ignoreStopFailed = false), log id: 1072e739
>2014-09-29 17:03:01,533 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStopVDSCommand] (ajp--127.0.0.1-8702-7) [4349da9e] START, SpmStopVDSCommand(HostName = voodoo1, HostId = 114c2cc6-5123-45bc-8900-5c875b0543c4, storagePoolId = b86b687a-d073-497a-ac8a-249025419a3e), log id: 4d4f9e40
>2014-09-29 17:03:01,554 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStopVDSCommand] (ajp--127.0.0.1-8702-7) [4349da9e] SpmStopVDSCommand::Stopping SPM on vds voodoo1, pool id b86b687a-d073-497a-ac8a-249025419a3e
>2014-09-29 17:03:01,784 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStopVDSCommand] (ajp--127.0.0.1-8702-7) [4349da9e] FINISH, SpmStopVDSCommand, log id: 4d4f9e40
>2014-09-29 17:03:01,796 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.ResetIrsVDSCommand] (ajp--127.0.0.1-8702-7) [4349da9e] FINISH, ResetIrsVDSCommand, log id: 1072e739
>2014-09-29 17:03:01,797 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SpmStopOnIrsVDSCommand] (ajp--127.0.0.1-8702-7) [4349da9e] FINISH, SpmStopOnIrsVDSCommand, log id: 505cdb68
>2014-09-29 17:03:01,813 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-7) [4349da9e] Correlation ID: 4349da9e, Job ID: 5316fedb-73e3-420b-b207-0b47c70af519, Call Stack: null, Custom Event ID: -1, Message: Host voodoo6 was force selected by admin
>2014-09-29 17:03:01,821 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-7) [4349da9e] Correlation ID: 4349da9e, Job ID: 5316fedb-73e3-420b-b207-0b47c70af519, Call Stack: null, Custom Event ID: -1, Message: Unrecognized audit log type has been used.
>2014-09-29 17:03:05,304 INFO  [org.ovirt.engine.core.bll.storage.SetStoragePoolStatusCommand] (DefaultQuartzScheduler_Worker-84) [3956bf8d] Running command: SetStoragePoolStatusCommand internal: true. Entities affected :  ID: b86b687a-d073-497a-ac8a-249025419a3e Type: StoragePool
>2014-09-29 17:03:05,305 INFO  [org.ovirt.engine.core.vdsbroker.storage.StoragePoolDomainHelper] (DefaultQuartzScheduler_Worker-84) [3956bf8d] Storage Pool b86b687a-d073-497a-ac8a-249025419a3e - Updating Storage Domain ff559f46-c495-4f6b-901c-2a624042a050 status from Active to Unknown, reason : null
>2014-09-29 17:03:05,305 INFO  [org.ovirt.engine.core.vdsbroker.storage.StoragePoolDomainHelper] (DefaultQuartzScheduler_Worker-84) [3956bf8d] Storage Pool b86b687a-d073-497a-ac8a-249025419a3e - Updating Storage Domain 51752c8f-bbe3-4754-866b-a0afd2a1f59d status from Active to Unknown, reason : null
>2014-09-29 17:03:05,325 WARN  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-84) [3956bf8d] Correlation ID: 3956bf8d, Call Stack: null, Custom Event ID: -1, Message: Invalid status on Data Center iscsi-el7. Setting status to Non Responsive.
>2014-09-29 17:03:05,360 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.IrsProxyData] (DefaultQuartzScheduler_Worker-84) [3956bf8d] hostFromVds::selectedVds - voodoo6, spmStatus Free, storage pool iscsi-el7
>2014-09-29 17:03:05,367 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.IrsProxyData] (DefaultQuartzScheduler_Worker-84) [3956bf8d] starting spm on vds voodoo6, storage pool iscsi-el7, prevId -1, LVER -1
>2014-09-29 17:03:05,368 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStartVDSCommand] (DefaultQuartzScheduler_Worker-84) [3956bf8d] START, SpmStartVDSCommand(HostName = voodoo6, HostId = 45462850-a02c-4eeb-8527-292e15e5cb54, storagePoolId = b86b687a-d073-497a-ac8a-249025419a3e, prevId=-1, prevLVER=-1, storagePoolFormatType=V3, recoveryMode=Manual, SCSIFencing=false), log id: 2af1e60e
>2014-09-29 17:03:05,382 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStartVDSCommand] (DefaultQuartzScheduler_Worker-84) [3956bf8d] spmStart polling started: taskId = 7b7bdbde-f4bf-4f72-8f46-5d0dc08227cb
>2014-09-29 17:03:08,428 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStartVDSCommand] (DefaultQuartzScheduler_Worker-84) [3956bf8d] spmStart polling ended: taskId = 7b7bdbde-f4bf-4f72-8f46-5d0dc08227cb task status = finished
>2014-09-29 17:03:08,458 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStartVDSCommand] (DefaultQuartzScheduler_Worker-84) [3956bf8d] spmStart polling ended, spm status: SPM
>2014-09-29 17:03:08,459 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (DefaultQuartzScheduler_Worker-84) [3956bf8d] START, HSMClearTaskVDSCommand(HostName = voodoo6, HostId = 45462850-a02c-4eeb-8527-292e15e5cb54, taskId=7b7bdbde-f4bf-4f72-8f46-5d0dc08227cb), log id: 67b18df0
>2014-09-29 17:03:08,473 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (DefaultQuartzScheduler_Worker-84) [3956bf8d] FINISH, HSMClearTaskVDSCommand, log id: 67b18df0
>2014-09-29 17:03:08,473 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStartVDSCommand] (DefaultQuartzScheduler_Worker-84) [3956bf8d] FINISH, SpmStartVDSCommand, return: org.ovirt.engine.core.common.businessentities.SpmStatusResult@4007a89e, log id: 2af1e60e
>2014-09-29 17:03:08,514 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.IrsProxyData] (DefaultQuartzScheduler_Worker-84) [3956bf8d] Initialize Irs proxy from vds: voodoo6.tlv.redhat.com
>2014-09-29 17:03:08,522 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-84) [3956bf8d] Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: Storage Pool Manager runs on Host voodoo6 (Address: voodoo6.tlv.redhat.com).
>2014-09-29 17:03:08,528 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMGetAllTasksInfoVDSCommand] (org.ovirt.thread.pool-8-thread-4) [3956bf8d] START, SPMGetAllTasksInfoVDSCommand( storagePoolId = b86b687a-d073-497a-ac8a-249025419a3e, ignoreFailoverLimit = false), log id: 10fc1e24
>2014-09-29 17:03:08,598 INFO  [org.ovirt.engine.core.bll.storage.SyncLunsInfoForBlockStorageDomainCommand] (org.ovirt.thread.pool-8-thread-20) [1b849727] Running command: SyncLunsInfoForBlockStorageDomainCommand internal: true. Entities affected :  ID: ff559f46-c495-4f6b-901c-2a624042a050 Type: Storage
>2014-09-29 17:03:08,601 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.GetVGInfoVDSCommand] (org.ovirt.thread.pool-8-thread-20) [1b849727] START, GetVGInfoVDSCommand(HostName = voodoo6, HostId = 45462850-a02c-4eeb-8527-292e15e5cb54, VGID=1B1oT5-JcGj-Ru1I-v3Ni-yden-Du9b-I9fSu8), log id: 322a15a3
>2014-09-29 17:03:08,614 INFO  [org.ovirt.engine.core.bll.storage.SyncLunsInfoForBlockStorageDomainCommand] (org.ovirt.thread.pool-8-thread-40) [5120af2d] Running command: SyncLunsInfoForBlockStorageDomainCommand internal: true. Entities affected :  ID: 51752c8f-bbe3-4754-866b-a0afd2a1f59d Type: Storage
>2014-09-29 17:03:08,617 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.GetVGInfoVDSCommand] (org.ovirt.thread.pool-8-thread-40) [5120af2d] START, GetVGInfoVDSCommand(HostName = voodoo6, HostId = 45462850-a02c-4eeb-8527-292e15e5cb54, VGID=HOsL3c-AN3Q-ipn9-AL3N-80vL-cvUv-AMTJ41), log id: 1270d1fe
>2014-09-29 17:03:08,622 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMGetAllTasksInfoVDSCommand] (org.ovirt.thread.pool-8-thread-4) [3956bf8d] -- executeIrsBrokerCommand: Attempting on storage pool b86b687a-d073-497a-ac8a-249025419a3e
>2014-09-29 17:03:08,624 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMGetAllTasksInfoVDSCommand] (org.ovirt.thread.pool-8-thread-4) [3956bf8d] START, HSMGetAllTasksInfoVDSCommand(HostName = voodoo6, HostId = 45462850-a02c-4eeb-8527-292e15e5cb54), log id: 36d84e2b
>2014-09-29 17:03:09,942 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.GetVGInfoVDSCommand] (org.ovirt.thread.pool-8-thread-20) [1b849727] FINISH, GetVGInfoVDSCommand, return: [LUNs [id=1IET_00060007, physicalVolumeId=QfuzQ5-Ml7u-kFUc-gdmr-rfmS-Aefp-3HODNb, volumeGroupId=1B1oT5-JcGj-Ru1I-v3Ni-yden-Du9b-I9fSu8, serial=SRed_Cat_VIRTUAL-DISK, lunMapping=7, vendorId=Red Cat, productId=VIRTUAL-DISK, _lunConnections=[{ id: null, connection: 10.35.0.98, iqn: iqn.1994-05.com.redhat:target6, vfsType: null, mountOptions: null, nfsVersion: null, nfsRetrans: null, nfsTimeo: null };], deviceSize=20, vendorName=Red Cat, pathsDictionary={sdv=true}, lunType=ISCSI, status=null, diskId=null, diskAlias=null, storageDomainId=ff559f46-c495-4f6b-901c-2a624042a050, storageDomainName=null], LUNs [id=1IET_00060009, physicalVolumeId=pGRciD-wcLp-X1ME-MijE-P1B9-7XWo-ycTXdG, volumeGroupId=1B1oT5-JcGj-Ru1I-v3Ni-yden-Du9b-I9fSu8, serial=SRed_Cat_VIRTUAL-DISK, lunMapping=9, vendorId=Red Cat, productId=VIRTUAL-DISK, _lunConnections=[{ id: null, connection: 10.35.0.98, iqn: iqn.1994-05.com.redhat:target6, vfsType: null, mountOptions: null, nfsVersion: null, nfsRetrans: null, nfsTimeo: null };], deviceSize=20, vendorName=Red Cat, pathsDictionary={sdx=true}, lunType=ISCSI, status=null, diskId=null, diskAlias=null, storageDomainId=ff559f46-c495-4f6b-901c-2a624042a050, storageDomainName=null]], log id: 322a15a3
>2014-09-29 17:03:09,957 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMGetAllTasksInfoVDSCommand] (org.ovirt.thread.pool-8-thread-4) [3956bf8d] FINISH, HSMGetAllTasksInfoVDSCommand, return: [], log id: 36d84e2b
>2014-09-29 17:03:09,958 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMGetAllTasksInfoVDSCommand] (org.ovirt.thread.pool-8-thread-4) [3956bf8d] FINISH, SPMGetAllTasksInfoVDSCommand, return: [], log id: 10fc1e24
>2014-09-29 17:03:09,958 INFO  [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (org.ovirt.thread.pool-8-thread-4) [3956bf8d] Discovered no tasks on Storage Pool iscsi-el7
>2014-09-29 17:03:13,884 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.GetVGInfoVDSCommand] (org.ovirt.thread.pool-8-thread-40) [5120af2d] FINISH, GetVGInfoVDSCommand, return: [LUNs [id=3600144f09dbd0500000053a84e730003, physicalVolumeId=tJlPY9-uDSu-Uq0G-THq3-FtDg-zUgX-fDeE1m, volumeGroupId=HOsL3c-AN3Q-ipn9-AL3N-80vL-cvUv-AMTJ41, serial=SNEXENTA_COMSTAR_5H49HFEFE, lunMapping=77, vendorId=NEXENTA, productId=COMSTAR, _lunConnections=[{ id: null, connection: 10.35.16.25, iqn: iqn.1994-05.com.redhat:nsoffer-target1, vfsType: null, mountOptions: null, nfsVersion: null, nfsRetrans: null, nfsTimeo: null };], deviceSize=10, vendorName=NEXENTA, pathsDictionary={sdo=true}, lunType=ISCSI, status=null, diskId=null, diskAlias=null, storageDomainId=51752c8f-bbe3-4754-866b-a0afd2a1f59d, storageDomainName=null], LUNs [id=3600144f09dbd0500000053a85076000a, physicalVolumeId=R9WKM6-qyr0-z7nV-dloM-fQQR-4UJ8-9NS9mQ, volumeGroupId=HOsL3c-AN3Q-ipn9-AL3N-80vL-cvUv-AMTJ41, serial=SNEXENTA_COMSTAR_5H49HFEFE, lunMapping=11, vendorId=NEXENTA, productId=COMSTAR, _lunConnections=[{ id: null, connection: 10.35.16.25, iqn: iqn.1994-05.com.redhat:nsoffer-target1, vfsType: null, mountOptions: null, nfsVersion: null, nfsRetrans: null, nfsTimeo: null };], deviceSize=10, vendorName=NEXENTA, pathsDictionary={sdl=true}, lunType=ISCSI, status=null, diskId=null, diskAlias=null, storageDomainId=51752c8f-bbe3-4754-866b-a0afd2a1f59d, storageDomainName=null], LUNs [id=3600144f09dbd0500000053a85401000d, physicalVolumeId=Ry22bc-y09g-FYBU-Cgkh-64hy-uXi6-bGvLqc, volumeGroupId=HOsL3c-AN3Q-ipn9-AL3N-80vL-cvUv-AMTJ41, serial=SNEXENTA_COMSTAR_5H49HFEFE, lunMapping=6, vendorId=NEXENTA, productId=COMSTAR, _lunConnections=[{ id: null, connection: 10.35.16.25, iqn: iqn.1994-05.com.redhat:nsoffer-target2, vfsType: null, mountOptions: null, nfsVersion: null, nfsRetrans: null, nfsTimeo: null };], deviceSize=10, vendorName=NEXENTA, pathsDictionary={sdaf=true}, lunType=ISCSI, status=null, diskId=null, diskAlias=null, storageDomainId=51752c8f-bbe3-4754-866b-a0afd2a1f59d, storageDomainName=null], LUNs [id=3600144f09dbd0500000053a853ed000c, physicalVolumeId=2HKkka-UNX6-RvQt-xZkJ-tpXN-1wMa-W3EJ8k, volumeGroupId=HOsL3c-AN3Q-ipn9-AL3N-80vL-cvUv-AMTJ41, serial=SNEXENTA_COMSTAR_5H49HFEFE, lunMapping=5, vendorId=NEXENTA, productId=COMSTAR, _lunConnections=[{ id: null, connection: 10.35.16.25, iqn: iqn.1994-05.com.redhat:nsoffer-target2, vfsType: null, mountOptions: null, nfsVersion: null, nfsRetrans: null, nfsTimeo: null };], deviceSize=10, vendorName=NEXENTA, pathsDictionary={sdae=true}, lunType=ISCSI, status=null, diskId=null, diskAlias=null, storageDomainId=51752c8f-bbe3-4754-866b-a0afd2a1f59d, storageDomainName=null]], log id: 1270d1fe
>2014-09-29 17:08:10,035 INFO  [org.ovirt.engine.core.bll.RemoveSnapshotCommand] (ajp--127.0.0.1-8702-3) [29b2cb69] Lock Acquired to object EngineLock [exclusiveLocks= key: 4a0d069d-be19-4585-bb79-859ca23a5339 value: VM
>, sharedLocks= ]
>2014-09-29 17:08:10,131 INFO  [org.ovirt.engine.core.bll.RemoveSnapshotCommand] (ajp--127.0.0.1-8702-3) [29b2cb69] Running command: RemoveSnapshotCommand internal: false. Entities affected :  ID: 4a0d069d-be19-4585-bb79-859ca23a5339 Type: VMAction group MANIPULATE_VM_SNAPSHOTS with role type USER
>2014-09-29 17:08:10,139 INFO  [org.ovirt.engine.core.bll.RemoveSnapshotCommand] (ajp--127.0.0.1-8702-3) [29b2cb69] Lock freed to object EngineLock [exclusiveLocks= key: 4a0d069d-be19-4585-bb79-859ca23a5339 value: VM
>, sharedLocks= ]
>2014-09-29 17:08:10,149 INFO  [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskCommand] (ajp--127.0.0.1-8702-3) [4e446d3c] Running command: RemoveSnapshotSingleDiskCommand internal: true. Entities affected :  ID: 00000000-0000-0000-0000-000000000000 Type: Storage
>2014-09-29 17:08:10,191 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.MergeSnapshotsVDSCommand] (ajp--127.0.0.1-8702-3) [4e446d3c] START, MergeSnapshotsVDSCommand( storagePoolId = b86b687a-d073-497a-ac8a-249025419a3e, ignoreFailoverLimit = false, storageDomainId = ff559f46-c495-4f6b-901c-2a624042a050, imageGroupId = 5ce6b00c-3ab5-4e3e-87d6-5006e4b636d8, imageId = abca31cb-1404-4f98-bc48-3df523397359, imageId2 = c57c2ee7-0e30-4baa-a15f-7881cb20f701, vmId = 4a0d069d-be19-4585-bb79-859ca23a5339, postZero = false), log id: 38fc4c77
>2014-09-29 17:08:10,250 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.MergeSnapshotsVDSCommand] (ajp--127.0.0.1-8702-3) [4e446d3c] FINISH, MergeSnapshotsVDSCommand, log id: 38fc4c77
>2014-09-29 17:08:10,265 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (ajp--127.0.0.1-8702-3) [4e446d3c] CommandAsyncTask::Adding CommandMultiAsyncTasks object for command 59909284-9061-4b3d-b9de-aa72de2e9c06
>2014-09-29 17:08:10,265 INFO  [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (ajp--127.0.0.1-8702-3) [4e446d3c] CommandMultiAsyncTasks::AttachTask: Attaching task 58a17102-663f-44d0-8d47-b4e04b77b5fb to command 59909284-9061-4b3d-b9de-aa72de2e9c06.
>2014-09-29 17:08:10,363 INFO  [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (ajp--127.0.0.1-8702-3) [4e446d3c] Adding task 58a17102-663f-44d0-8d47-b4e04b77b5fb (Parent Command RemoveSnapshot, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters), polling hasn't started yet..
>2014-09-29 17:08:10,487 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-3) [4e446d3c] Correlation ID: 29b2cb69, Job ID: 8c59a464-0837-4ae8-9010-b9817a2535f4, Call Stack: null, Custom Event ID: -1, Message: Snapshot 'Auto-generated for Live Storage Migration' deletion for VM 'vm01' was initiated by admin.
>2014-09-29 17:08:10,488 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (ajp--127.0.0.1-8702-3) [4e446d3c] BaseAsyncTask::startPollingTask: Starting to poll task 58a17102-663f-44d0-8d47-b4e04b77b5fb.
>2014-09-29 17:08:13,850 INFO  [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (DefaultQuartzScheduler_Worker-13) Polling and updating Async Tasks: 7 tasks, 1 tasks to poll now
>2014-09-29 17:08:13,863 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-13) SPMAsyncTask::PollTask: Polling task 58a17102-663f-44d0-8d47-b4e04b77b5fb (Parent Command RemoveSnapshot, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) returned status running.
>2014-09-29 17:08:13,864 INFO  [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (DefaultQuartzScheduler_Worker-13) Finished polling Tasks, will poll again in 10 seconds.
>2014-09-29 17:08:15,455 INFO  [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-87) Waiting on Live Merge child commands to complete
>2014-09-29 17:08:25,455 INFO  [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-32) Waiting on Live Merge child commands to complete
>2014-09-29 17:08:35,456 INFO  [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-10) [28a9d892] Waiting on Live Merge child commands to complete
>2014-09-29 17:08:45,458 INFO  [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-41) [285269ea] Waiting on Live Merge child commands to complete
>2014-09-29 17:08:55,460 INFO  [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-73) Waiting on Live Merge child commands to complete
>2014-09-29 17:09:05,461 INFO  [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-13) Waiting on Live Merge child commands to complete
>2014-09-29 17:09:15,463 INFO  [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-26) Waiting on Live Merge child commands to complete
>2014-09-29 17:09:25,464 INFO  [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-5) Waiting on Live Merge child commands to complete
>2014-09-29 17:09:35,465 INFO  [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-67) [c05df18] Waiting on Live Merge child commands to complete
>2014-09-29 17:09:45,466 INFO  [org.ovirt.engine.core.bll.RemoveSnapshotCommandCallback] (DefaultQuartzScheduler_Worker-63) Waiting on Live Merge child commands to complete
>2014-09-29 17:09:54,591 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-68) SPMAsyncTask::PollTask: Polling task 58a17102-663f-44d0-8d47-b4e04b77b5fb (Parent Command RemoveSnapshot, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) returned status finished, result 'success'.
>2014-09-29 17:09:54,603 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-68) BaseAsyncTask::onTaskEndSuccess: Task 58a17102-663f-44d0-8d47-b4e04b77b5fb (Parent Command RemoveSnapshot, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) ended successfully.
>2014-09-29 17:09:54,604 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (DefaultQuartzScheduler_Worker-68) CommandAsyncTask::endActionIfNecessary: All tasks of command 59909284-9061-4b3d-b9de-aa72de2e9c06 has ended -> executing endAction
>2014-09-29 17:09:54,605 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (DefaultQuartzScheduler_Worker-68) CommandAsyncTask::endAction: Ending action for 1 tasks (command ID: 59909284-9061-4b3d-b9de-aa72de2e9c06): calling endAction .
>2014-09-29 17:09:54,607 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-17) CommandAsyncTask::endCommandAction [within thread] context: Attempting to endAction RemoveSnapshot, executionIndex: 0
>2014-09-29 17:09:54,636 INFO  [org.ovirt.engine.core.bll.RemoveSnapshotCommand] (org.ovirt.thread.pool-8-thread-17) [29b2cb69] Ending command successfully: org.ovirt.engine.core.bll.RemoveSnapshotCommand
>2014-09-29 17:09:54,661 INFO  [org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskCommand] (org.ovirt.thread.pool-8-thread-17) [4e446d3c] Ending command successfully: org.ovirt.engine.core.bll.RemoveSnapshotSingleDiskCommand
>2014-09-29 17:09:54,667 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (org.ovirt.thread.pool-8-thread-17) [4e446d3c] START, GetImageInfoVDSCommand( storagePoolId = b86b687a-d073-497a-ac8a-249025419a3e, ignoreFailoverLimit = false, storageDomainId = ff559f46-c495-4f6b-901c-2a624042a050, imageGroupId = 5ce6b00c-3ab5-4e3e-87d6-5006e4b636d8, imageId = c57c2ee7-0e30-4baa-a15f-7881cb20f701), log id: 4dc81af9
>2014-09-29 17:09:54,689 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (org.ovirt.thread.pool-8-thread-17) [4e446d3c] FINISH, GetImageInfoVDSCommand, return: org.ovirt.engine.core.common.businessentities.DiskImage@d8a0fcd8, log id: 4dc81af9
>2014-09-29 17:09:54,719 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-8-thread-17) Correlation ID: 29b2cb69, Call Stack: null, Custom Event ID: -1, Message: Snapshot 'Auto-generated for Live Storage Migration' deletion for VM 'vm01' has been completed.
>2014-09-29 17:09:54,721 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-17) CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type RemoveSnapshot completed, handling the result.
>2014-09-29 17:09:54,721 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-17) CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type RemoveSnapshot succeeded, clearing tasks.
>2014-09-29 17:09:54,736 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (org.ovirt.thread.pool-8-thread-17) SPMAsyncTask::ClearAsyncTask: Attempting to clear task 58a17102-663f-44d0-8d47-b4e04b77b5fb
>2014-09-29 17:09:54,737 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-17) START, SPMClearTaskVDSCommand( storagePoolId = b86b687a-d073-497a-ac8a-249025419a3e, ignoreFailoverLimit = false, taskId = 58a17102-663f-44d0-8d47-b4e04b77b5fb), log id: 5b4da024
>2014-09-29 17:09:54,740 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-17) START, HSMClearTaskVDSCommand(HostName = voodoo6, HostId = 45462850-a02c-4eeb-8527-292e15e5cb54, taskId=58a17102-663f-44d0-8d47-b4e04b77b5fb), log id: 454cca50
>2014-09-29 17:09:54,759 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-17) FINISH, HSMClearTaskVDSCommand, log id: 454cca50
>2014-09-29 17:09:54,760 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-17) FINISH, SPMClearTaskVDSCommand, log id: 5b4da024
>2014-09-29 17:09:54,769 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (org.ovirt.thread.pool-8-thread-17) BaseAsyncTask::removeTaskFromDB: Removed task 58a17102-663f-44d0-8d47-b4e04b77b5fb from DataBase
>2014-09-29 17:09:54,770 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-17) CommandAsyncTask::HandleEndActionResult [within thread]: Removing CommandMultiAsyncTasks object for entity 59909284-9061-4b3d-b9de-aa72de2e9c06
>2014-09-29 17:11:20,800 INFO  [org.ovirt.engine.core.bll.RunVmCommand] (ajp--127.0.0.1-8702-5) [692b2dd] Lock Acquired to object EngineLock [exclusiveLocks= key: 98e6058d-cf96-4929-b118-4fc5542a30ba value: VM
>, sharedLocks= ]
>2014-09-29 17:11:20,824 INFO  [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (ajp--127.0.0.1-8702-5) [692b2dd] START, IsVmDuringInitiatingVDSCommand( vmId = 98e6058d-cf96-4929-b118-4fc5542a30ba), log id: 3e89e511
>2014-09-29 17:11:20,825 INFO  [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (ajp--127.0.0.1-8702-5) [692b2dd] FINISH, IsVmDuringInitiatingVDSCommand, return: false, log id: 3e89e511
>2014-09-29 17:11:20,926 INFO  [org.ovirt.engine.core.bll.RunVmCommand] (org.ovirt.thread.pool-8-thread-33) [692b2dd] Running command: RunVmCommand internal: false. Entities affected :  ID: 98e6058d-cf96-4929-b118-4fc5542a30ba Type: VMAction group VM_BASIC_OPERATIONS with role type USER
>2014-09-29 17:11:20,982 INFO  [org.ovirt.engine.core.vdsbroker.UpdateVmDynamicDataVDSCommand] (org.ovirt.thread.pool-8-thread-33) [692b2dd] START, UpdateVmDynamicDataVDSCommand(HostName = voodoo1, HostId = 114c2cc6-5123-45bc-8900-5c875b0543c4, vmDynamic=org.ovirt.engine.core.common.businessentities.VmDynamic@8bab4b8d), log id: 4fff2215
>2014-09-29 17:11:20,992 INFO  [org.ovirt.engine.core.vdsbroker.UpdateVmDynamicDataVDSCommand] (org.ovirt.thread.pool-8-thread-33) [692b2dd] FINISH, UpdateVmDynamicDataVDSCommand, log id: 4fff2215
>2014-09-29 17:11:20,998 INFO  [org.ovirt.engine.core.vdsbroker.CreateVmVDSCommand] (org.ovirt.thread.pool-8-thread-33) [692b2dd] START, CreateVmVDSCommand(HostName = voodoo1, HostId = 114c2cc6-5123-45bc-8900-5c875b0543c4, vmId=98e6058d-cf96-4929-b118-4fc5542a30ba, vm=VM [vm02]), log id: 7445c3d2
>2014-09-29 17:11:21,001 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand] (org.ovirt.thread.pool-8-thread-33) [692b2dd] START, CreateVDSCommand(HostName = voodoo1, HostId = 114c2cc6-5123-45bc-8900-5c875b0543c4, vmId=98e6058d-cf96-4929-b118-4fc5542a30ba, vm=VM [vm02]), log id: d410783
>2014-09-29 17:11:21,028 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand] (org.ovirt.thread.pool-8-thread-33) [692b2dd] org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand kvmEnable=true,keyboardLayout=en-us,nice=0,pitReinjection=false,displayNetwork=ovirtmgmt,copyPasteEnable=true,timeOffset=0,transparentHugePages=true,vmId=98e6058d-cf96-4929-b118-4fc5542a30ba,acpiEnable=true,custom={device_d2818bc2-2c12-4788-9d49-c385d7268081device_2fb999e9-19a6-4a3a-922a-51ecccc4d622=VmDevice {vmId=98e6058d-cf96-4929-b118-4fc5542a30ba, deviceId=2fb999e9-19a6-4a3a-922a-51ecccc4d622, device=unix, type=CHANNEL, bootOrder=0, specParams={}, address={port=1, bus=0, controller=0, type=virtio-serial}, managed=false, plugged=true, readOnly=false, deviceAlias=channel0, customProperties={}, snapshotId=null}, device_d2818bc2-2c12-4788-9d49-c385d7268081device_2fb999e9-19a6-4a3a-922a-51ecccc4d622device_34b9a4bc-f1b6-4c5e-9140-d49944ff28a0device_a0df18cb-58ac-40b2-bf7f-78761532029f=VmDevice {vmId=98e6058d-cf96-4929-b118-4fc5542a30ba, deviceId=a0df18cb-58ac-40b2-bf7f-78761532029f, device=spicevmc, type=CHANNEL, bootOrder=0, specParams={}, address={port=3, bus=0, controller=0, type=virtio-serial}, managed=false, plugged=true, readOnly=false, deviceAlias=channel2, customProperties={}, snapshotId=null}, device_d2818bc2-2c12-4788-9d49-c385d7268081=VmDevice {vmId=98e6058d-cf96-4929-b118-4fc5542a30ba, deviceId=d2818bc2-2c12-4788-9d49-c385d7268081, device=ide, type=CONTROLLER, bootOrder=0, specParams={}, address={bus=0x00, domain=0x0000, type=pci, slot=0x01, function=0x1}, managed=false, plugged=true, readOnly=false, deviceAlias=ide0, customProperties={}, snapshotId=null}, device_d2818bc2-2c12-4788-9d49-c385d7268081device_2fb999e9-19a6-4a3a-922a-51ecccc4d622device_34b9a4bc-f1b6-4c5e-9140-d49944ff28a0=VmDevice {vmId=98e6058d-cf96-4929-b118-4fc5542a30ba, deviceId=34b9a4bc-f1b6-4c5e-9140-d49944ff28a0, device=unix, type=CHANNEL, bootOrder=0, specParams={}, address={port=2, bus=0, controller=0, type=virtio-serial}, managed=false, plugged=true, readOnly=false, deviceAlias=channel1, customProperties={}, snapshotId=null}},spiceSslCipherSuite=DEFAULT,memSize=1024,smp=1,emulatedMachine=rhel6.5.0,vmType=kvm,memGuaranteedSize=512,display=qxl,smartcardEnable=false,bootMenuEnable=false,spiceSecureChannels=smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard,smpCoresPerSocket=1,numaTune={mode=preferred},maxVCpus=16,devices=[{address={bus=0x00, domain=0x0000, slot=0x02, type=pci, function=0x0}, specParams={ram=65536, vram=32768, heads=1}, device=qxl, type=video, deviceId=66082070-f00f-4d07-bacb-43d8e2311847}, {shared=false, iface=ide, index=2, address={unit=0, bus=1, target=0, controller=0, type=drive}, specParams={path=}, path=, device=cdrom, type=disk, readonly=true, deviceId=15d068ca-1248-4901-b157-33d493251ed2}, {shared=false, index=0, volumeID=9d74263f-76a8-4c33-94f7-454e06934207, propagateErrors=off, format=cow, type=disk, iface=virtio, bootOrder=1, address={bus=0x00, domain=0x0000, slot=0x06, type=pci, function=0x0}, domainID=ff559f46-c495-4f6b-901c-2a624042a050, imageID=a75c1851-bddb-4339-bee2-f22b4b1268ac, specParams={}, optional=false, device=disk, poolID=b86b687a-d073-497a-ac8a-249025419a3e, readonly=false, deviceId=a75c1851-bddb-4339-bee2-f22b4b1268ac}, {nicModel=pv, address={bus=0x00, domain=0x0000, slot=0x03, type=pci, function=0x0}, specParams={outbound={}, inbound={}}, macAddr=00:1a:4a:ab:e1:02, device=bridge, linkActive=true, type=interface, filter=vdsm-no-mac-spoofing, network=ovirtmgmt, deviceId=f9a1519b-60eb-4a9d-b41d-7f9f10a1ea59}, {address={bus=0x00, domain=0x0000, slot=0x07, type=pci, function=0x0}, specParams={model=virtio}, device=memballoon, type=balloon, deviceId=73815461-75e5-4050-b055-b28e29a643a2}, {index=0, model=virtio-scsi, address={bus=0x00, domain=0x0000, slot=0x04, type=pci, function=0x0}, specParams={}, device=scsi, type=controller, deviceId=00c4ce82-0c2f-4848-bdd1-d50174d711ea}, {address={bus=0x00, domain=0x0000, slot=0x05, type=pci, function=0x0}, specParams={}, device=virtio-serial, type=controller, deviceId=9c5f352a-6aba-4ec3-bff9-085e37365e5e}],vmName=vm02,cpuType=Haswell,fileTransferEnable=true
>2014-09-29 17:11:21,108 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand] (org.ovirt.thread.pool-8-thread-33) [692b2dd] FINISH, CreateVDSCommand, log id: d410783
>2014-09-29 17:11:21,125 INFO  [org.ovirt.engine.core.vdsbroker.CreateVmVDSCommand] (org.ovirt.thread.pool-8-thread-33) [692b2dd] FINISH, CreateVmVDSCommand, return: WaitForLaunch, log id: 7445c3d2
>2014-09-29 17:11:21,125 INFO  [org.ovirt.engine.core.bll.RunVmCommand] (org.ovirt.thread.pool-8-thread-33) [692b2dd] Lock freed to object EngineLock [exclusiveLocks= key: 98e6058d-cf96-4929-b118-4fc5542a30ba value: VM
>, sharedLocks= ]
>2014-09-29 17:11:21,133 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-8-thread-33) [692b2dd] Correlation ID: 692b2dd, Job ID: 36614b09-45e9-4dff-a90f-13697b94867e, Call Stack: null, Custom Event ID: -1, Message: VM vm02 was started by admin (Host: voodoo1).
>2014-09-29 17:11:23,323 INFO  [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-67) [c05df18] VM vm02 98e6058d-cf96-4929-b118-4fc5542a30ba moved from WaitForLaunch --> PoweringUp
>2014-09-29 17:11:23,323 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.FullListVdsCommand] (DefaultQuartzScheduler_Worker-67) [c05df18] START, FullListVdsCommand(HostName = voodoo1, HostId = 114c2cc6-5123-45bc-8900-5c875b0543c4, vds=Host[voodoo1,114c2cc6-5123-45bc-8900-5c875b0543c4], vmIds=[98e6058d-cf96-4929-b118-4fc5542a30ba]), log id: 2ef76b3d
>2014-09-29 17:11:23,340 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.FullListVdsCommand] (DefaultQuartzScheduler_Worker-67) [c05df18] FINISH, FullListVdsCommand, return: [{displaySecurePort=5901, kvmEnable=true, nicModel=rtl8139,pv, keyboardLayout=en-us, guestDiskMapping={}, displayIp=10.35.0.100, pauseCode=NOERR, pitReinjection=false, nice=0, displayNetwork=ovirtmgmt, copyPasteEnable=true, timeOffset=0, transparentHugePages=true, vmId=98e6058d-cf96-4929-b118-4fc5542a30ba, acpiEnable=true, custom={device_d2818bc2-2c12-4788-9d49-c385d7268081device_2fb999e9-19a6-4a3a-922a-51ecccc4d622=VmDevice {vmId=98e6058d-cf96-4929-b118-4fc5542a30ba, deviceId=2fb999e9-19a6-4a3a-922a-51ecccc4d622, device=unix, type=CHANNEL, bootOrder=0, specParams={}, address={port=1, bus=0, controller=0, type=virtio-serial}, managed=false, plugged=true, readOnly=false, deviceAlias=channel0, customProperties={}, snapshotId=null}, device_d2818bc2-2c12-4788-9d49-c385d7268081device_2fb999e9-19a6-4a3a-922a-51ecccc4d622device_34b9a4bc-f1b6-4c5e-9140-d49944ff28a0device_a0df18cb-58ac-40b2-bf7f-78761532029f=VmDevice {vmId=98e6058d-cf96-4929-b118-4fc5542a30ba, deviceId=a0df18cb-58ac-40b2-bf7f-78761532029f, device=spicevmc, type=CHANNEL, bootOrder=0, specParams={}, address={port=3, bus=0, controller=0, type=virtio-serial}, managed=false, plugged=true, readOnly=false, deviceAlias=channel2, customProperties={}, snapshotId=null}, device_d2818bc2-2c12-4788-9d49-c385d7268081=VmDevice {vmId=98e6058d-cf96-4929-b118-4fc5542a30ba, deviceId=d2818bc2-2c12-4788-9d49-c385d7268081, device=ide, type=CONTROLLER, bootOrder=0, specParams={}, address={bus=0x00, domain=0x0000, type=pci, slot=0x01, function=0x1}, managed=false, plugged=true, readOnly=false, deviceAlias=ide0, customProperties={}, snapshotId=null}, device_d2818bc2-2c12-4788-9d49-c385d7268081device_2fb999e9-19a6-4a3a-922a-51ecccc4d622device_34b9a4bc-f1b6-4c5e-9140-d49944ff28a0=VmDevice {vmId=98e6058d-cf96-4929-b118-4fc5542a30ba, deviceId=34b9a4bc-f1b6-4c5e-9140-d49944ff28a0, device=unix, type=CHANNEL, bootOrder=0, specParams={}, address={port=2, bus=0, controller=0, type=virtio-serial}, managed=false, plugged=true, readOnly=false, deviceAlias=channel1, customProperties={}, snapshotId=null}}, spiceSslCipherSuite=DEFAULT, memSize=1024, smp=1, displayPort=5900, emulatedMachine=rhel6.5.0, vmType=kvm, status=Up, memGuaranteedSize=512, display=qxl, pid=19499, smartcardEnable=false, bootMenuEnable=false, spiceSecureChannels=smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard, numaTune={mode=preferred}, smpCoresPerSocket=1, maxVCpus=16, clientIp=, devices=[Ljava.lang.Object;@1c545cfd, vmName=vm02, fileTransferEnable=true, cpuType=Haswell}], log id: 2ef76b3d
>2014-09-29 17:11:23,347 INFO  [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-67) [c05df18] Received a spice Device without an address when processing VM 98e6058d-cf96-4929-b118-4fc5542a30ba devices, skipping device: {port=5900, specParams={spiceSecureChannels=smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard, keyMap=en-us, displayNetwork=ovirtmgmt, copyPasteEnable=true, displayIp=10.35.0.100}, device=spice, tlsPort=5901, type=graphics}
>2014-09-29 17:11:23,661 INFO  [org.ovirt.engine.core.bll.RunVmCommand] (ajp--127.0.0.1-8702-5) [7b736f3f] Lock Acquired to object EngineLock [exclusiveLocks= key: 4a0d069d-be19-4585-bb79-859ca23a5339 value: VM
>, sharedLocks= ]
>2014-09-29 17:11:23,677 INFO  [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (ajp--127.0.0.1-8702-5) [7b736f3f] START, IsVmDuringInitiatingVDSCommand( vmId = 4a0d069d-be19-4585-bb79-859ca23a5339), log id: 278e5c70
>2014-09-29 17:11:23,677 INFO  [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (ajp--127.0.0.1-8702-5) [7b736f3f] FINISH, IsVmDuringInitiatingVDSCommand, return: false, log id: 278e5c70
>2014-09-29 17:11:23,734 INFO  [org.ovirt.engine.core.bll.RunVmCommand] (org.ovirt.thread.pool-8-thread-29) [7b736f3f] Running command: RunVmCommand internal: false. Entities affected :  ID: 4a0d069d-be19-4585-bb79-859ca23a5339 Type: VMAction group VM_BASIC_OPERATIONS with role type USER
>2014-09-29 17:11:23,792 INFO  [org.ovirt.engine.core.vdsbroker.UpdateVmDynamicDataVDSCommand] (org.ovirt.thread.pool-8-thread-29) [7b736f3f] START, UpdateVmDynamicDataVDSCommand(HostName = voodoo6, HostId = 45462850-a02c-4eeb-8527-292e15e5cb54, vmDynamic=org.ovirt.engine.core.common.businessentities.VmDynamic@d63ed2ea), log id: 4c8c8499
>2014-09-29 17:11:23,802 INFO  [org.ovirt.engine.core.vdsbroker.UpdateVmDynamicDataVDSCommand] (org.ovirt.thread.pool-8-thread-29) [7b736f3f] FINISH, UpdateVmDynamicDataVDSCommand, log id: 4c8c8499
>2014-09-29 17:11:23,808 INFO  [org.ovirt.engine.core.vdsbroker.CreateVmVDSCommand] (org.ovirt.thread.pool-8-thread-29) [7b736f3f] START, CreateVmVDSCommand(HostName = voodoo6, HostId = 45462850-a02c-4eeb-8527-292e15e5cb54, vmId=4a0d069d-be19-4585-bb79-859ca23a5339, vm=VM [vm01]), log id: 1d851b91
>2014-09-29 17:11:23,812 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand] (org.ovirt.thread.pool-8-thread-29) [7b736f3f] START, CreateVDSCommand(HostName = voodoo6, HostId = 45462850-a02c-4eeb-8527-292e15e5cb54, vmId=4a0d069d-be19-4585-bb79-859ca23a5339, vm=VM [vm01]), log id: 20f321c7
>2014-09-29 17:11:23,843 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand] (org.ovirt.thread.pool-8-thread-29) [7b736f3f] org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand kvmEnable=true,keyboardLayout=en-us,nice=0,pitReinjection=false,displayNetwork=ovirtmgmt,copyPasteEnable=true,timeOffset=0,transparentHugePages=true,vmId=4a0d069d-be19-4585-bb79-859ca23a5339,acpiEnable=true,custom={device_64047579-69d3-4791-8f6c-360ffb30997cdevice_cd58bbcd-db7e-4bb5-81a9-ef1bebf7c5e4device_99455cfc-ff6a-4805-82b6-9e71c2f2cc96=VmDevice {vmId=4a0d069d-be19-4585-bb79-859ca23a5339, deviceId=99455cfc-ff6a-4805-82b6-9e71c2f2cc96, device=unix, type=CHANNEL, bootOrder=0, specParams={}, address={port=2, bus=0, controller=0, type=virtio-serial}, managed=false, plugged=true, readOnly=false, deviceAlias=channel1, customProperties={}, snapshotId=null}, device_64047579-69d3-4791-8f6c-360ffb30997c=VmDevice {vmId=4a0d069d-be19-4585-bb79-859ca23a5339, deviceId=64047579-69d3-4791-8f6c-360ffb30997c, device=ide, type=CONTROLLER, bootOrder=0, specParams={}, address={bus=0x00, domain=0x0000, type=pci, slot=0x01, function=0x1}, managed=false, plugged=true, readOnly=false, deviceAlias=ide0, customProperties={}, snapshotId=null}, device_64047579-69d3-4791-8f6c-360ffb30997cdevice_cd58bbcd-db7e-4bb5-81a9-ef1bebf7c5e4=VmDevice {vmId=4a0d069d-be19-4585-bb79-859ca23a5339, deviceId=cd58bbcd-db7e-4bb5-81a9-ef1bebf7c5e4, device=unix, type=CHANNEL, bootOrder=0, specParams={}, address={port=1, bus=0, controller=0, type=virtio-serial}, managed=false, plugged=true, readOnly=false, deviceAlias=channel0, customProperties={}, snapshotId=null}, device_64047579-69d3-4791-8f6c-360ffb30997cdevice_cd58bbcd-db7e-4bb5-81a9-ef1bebf7c5e4device_99455cfc-ff6a-4805-82b6-9e71c2f2cc96device_7b412bf2-1cca-4af6-b5a4-35f8182f3559=VmDevice {vmId=4a0d069d-be19-4585-bb79-859ca23a5339, deviceId=7b412bf2-1cca-4af6-b5a4-35f8182f3559, device=spicevmc, type=CHANNEL, bootOrder=0, specParams={}, address={port=3, bus=0, controller=0, type=virtio-serial}, managed=false, plugged=true, readOnly=false, deviceAlias=channel2, customProperties={}, snapshotId=null}},spiceSslCipherSuite=DEFAULT,memSize=1024,smp=1,emulatedMachine=rhel6.5.0,vmType=kvm,memGuaranteedSize=512,display=qxl,smartcardEnable=false,bootMenuEnable=false,spiceSecureChannels=smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard,smpCoresPerSocket=1,numaTune={mode=preferred},maxVCpus=16,devices=[{address={bus=0x00, domain=0x0000, slot=0x02, type=pci, function=0x0}, specParams={ram=65536, vram=32768, heads=1}, device=qxl, type=video, deviceId=cddf475f-90f0-479e-bd72-5197661ff052}, {shared=false, iface=ide, index=2, address={unit=0, bus=1, target=0, controller=0, type=drive}, specParams={path=}, path=, device=cdrom, type=disk, readonly=true, deviceId=836b9082-8d93-4797-b52f-999ed2db0e12}, {shared=false, index=0, volumeID=c57c2ee7-0e30-4baa-a15f-7881cb20f701, propagateErrors=off, format=cow, type=disk, iface=virtio, bootOrder=1, address={bus=0x00, domain=0x0000, slot=0x06, type=pci, function=0x0}, domainID=ff559f46-c495-4f6b-901c-2a624042a050, imageID=5ce6b00c-3ab5-4e3e-87d6-5006e4b636d8, specParams={}, optional=false, device=disk, poolID=b86b687a-d073-497a-ac8a-249025419a3e, readonly=false, deviceId=5ce6b00c-3ab5-4e3e-87d6-5006e4b636d8}, {nicModel=pv, address={bus=0x00, domain=0x0000, slot=0x03, type=pci, function=0x0}, specParams={outbound={}, inbound={}}, macAddr=00:1a:4a:ab:e1:01, device=bridge, linkActive=true, type=interface, filter=vdsm-no-mac-spoofing, network=ovirtmgmt, deviceId=39b845e0-5ce4-49ca-908a-e7bd96749cf5}, {address={bus=0x00, domain=0x0000, slot=0x07, type=pci, function=0x0}, specParams={model=virtio}, device=memballoon, type=balloon, deviceId=7468a4b4-6347-4e72-8d55-ea1e8c6f10c8}, {index=0, model=virtio-scsi, address={bus=0x00, domain=0x0000, slot=0x04, type=pci, function=0x0}, specParams={}, device=scsi, type=controller, deviceId=897b6427-6ea4-4815-8a1b-21e4c3a82ab8}, {address={bus=0x00, domain=0x0000, slot=0x05, type=pci, function=0x0}, specParams={}, device=virtio-serial, type=controller, deviceId=9da0147d-ca25-4a54-bf3b-46ae5d980ecc}],vmName=vm01,cpuType=Haswell,fileTransferEnable=true
>2014-09-29 17:11:23,915 INFO  [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (DefaultQuartzScheduler_Worker-68) Setting new tasks map. The map contains now 6 tasks
>2014-09-29 17:11:23,971 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand] (org.ovirt.thread.pool-8-thread-29) [7b736f3f] FINISH, CreateVDSCommand, log id: 20f321c7
>2014-09-29 17:11:23,991 INFO  [org.ovirt.engine.core.vdsbroker.CreateVmVDSCommand] (org.ovirt.thread.pool-8-thread-29) [7b736f3f] FINISH, CreateVmVDSCommand, return: WaitForLaunch, log id: 1d851b91
>2014-09-29 17:11:23,991 INFO  [org.ovirt.engine.core.bll.RunVmCommand] (org.ovirt.thread.pool-8-thread-29) [7b736f3f] Lock freed to object EngineLock [exclusiveLocks= key: 4a0d069d-be19-4585-bb79-859ca23a5339 value: VM
>, sharedLocks= ]
>2014-09-29 17:11:23,999 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-8-thread-29) [7b736f3f] Correlation ID: 7b736f3f, Job ID: 8ebd4374-1eff-4a35-bc87-674ad2776c1e, Call Stack: null, Custom Event ID: -1, Message: VM vm01 was started by admin (Host: voodoo6).
>2014-09-29 17:11:24,190 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.FullListVdsCommand] (DefaultQuartzScheduler_Worker-90) [1dc56264] START, FullListVdsCommand(HostName = voodoo6, HostId = 45462850-a02c-4eeb-8527-292e15e5cb54, vds=Host[voodoo6,45462850-a02c-4eeb-8527-292e15e5cb54], vmIds=[4a0d069d-be19-4585-bb79-859ca23a5339]), log id: 6c6adffd
>2014-09-29 17:11:24,208 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.FullListVdsCommand] (DefaultQuartzScheduler_Worker-90) [1dc56264] FINISH, FullListVdsCommand, return: [{displaySecurePort=-1, kvmEnable=true, nicModel=rtl8139,pv, keyboardLayout=en-us, guestDiskMapping={}, displayIp=10.35.0.110, pitReinjection=false, nice=0, displayNetwork=ovirtmgmt, copyPasteEnable=true, timeOffset=0, transparentHugePages=true, vmId=4a0d069d-be19-4585-bb79-859ca23a5339, acpiEnable=true, custom={device_64047579-69d3-4791-8f6c-360ffb30997cdevice_cd58bbcd-db7e-4bb5-81a9-ef1bebf7c5e4device_99455cfc-ff6a-4805-82b6-9e71c2f2cc96=VmDevice {vmId=4a0d069d-be19-4585-bb79-859ca23a5339, deviceId=99455cfc-ff6a-4805-82b6-9e71c2f2cc96, device=unix, type=CHANNEL, bootOrder=0, specParams={}, address={port=2, bus=0, controller=0, type=virtio-serial}, managed=false, plugged=true, readOnly=false, deviceAlias=channel1, customProperties={}, snapshotId=null}, device_64047579-69d3-4791-8f6c-360ffb30997c=VmDevice {vmId=4a0d069d-be19-4585-bb79-859ca23a5339, deviceId=64047579-69d3-4791-8f6c-360ffb30997c, device=ide, type=CONTROLLER, bootOrder=0, specParams={}, address={bus=0x00, domain=0x0000, type=pci, slot=0x01, function=0x1}, managed=false, plugged=true, readOnly=false, deviceAlias=ide0, customProperties={}, snapshotId=null}, device_64047579-69d3-4791-8f6c-360ffb30997cdevice_cd58bbcd-db7e-4bb5-81a9-ef1bebf7c5e4=VmDevice {vmId=4a0d069d-be19-4585-bb79-859ca23a5339, deviceId=cd58bbcd-db7e-4bb5-81a9-ef1bebf7c5e4, device=unix, type=CHANNEL, bootOrder=0, specParams={}, address={port=1, bus=0, controller=0, type=virtio-serial}, managed=false, plugged=true, readOnly=false, deviceAlias=channel0, customProperties={}, snapshotId=null}, device_64047579-69d3-4791-8f6c-360ffb30997cdevice_cd58bbcd-db7e-4bb5-81a9-ef1bebf7c5e4device_99455cfc-ff6a-4805-82b6-9e71c2f2cc96device_7b412bf2-1cca-4af6-b5a4-35f8182f3559=VmDevice {vmId=4a0d069d-be19-4585-bb79-859ca23a5339, deviceId=7b412bf2-1cca-4af6-b5a4-35f8182f3559, device=spicevmc, type=CHANNEL, bootOrder=0, specParams={}, address={port=3, bus=0, controller=0, type=virtio-serial}, managed=false, plugged=true, readOnly=false, deviceAlias=channel2, customProperties={}, snapshotId=null}}, spiceSslCipherSuite=DEFAULT, memSize=1024, smp=1, displayPort=-1, vmType=kvm, emulatedMachine=rhel6.5.0, status=WaitForLaunch, memGuaranteedSize=512, display=qxl, pid=0, smartcardEnable=false, bootMenuEnable=false, spiceSecureChannels=smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard, numaTune={mode=preferred}, smpCoresPerSocket=1, maxVCpus=16, clientIp=, devices=[Ljava.lang.Object;@409056cf, vmName=vm01, fileTransferEnable=true, cpuType=Haswell}], log id: 6c6adffd
>2014-09-29 17:11:24,213 INFO  [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-90) [1dc56264] Received a spice Device without an address when processing VM 4a0d069d-be19-4585-bb79-859ca23a5339 devices, skipping device: {specParams={spiceSecureChannels=smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard, keyMap=en-us, displayNetwork=ovirtmgmt, copyPasteEnable=true, displayIp=10.35.0.110}, device=spice, type=graphics}
>2014-09-29 17:11:27,343 INFO  [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-81) [7bd133cc] VM vm01 4a0d069d-be19-4585-bb79-859ca23a5339 moved from WaitForLaunch --> PoweringUp
>2014-09-29 17:11:27,344 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.FullListVdsCommand] (DefaultQuartzScheduler_Worker-81) [7bd133cc] START, FullListVdsCommand(HostName = voodoo6, HostId = 45462850-a02c-4eeb-8527-292e15e5cb54, vds=Host[voodoo6,45462850-a02c-4eeb-8527-292e15e5cb54], vmIds=[4a0d069d-be19-4585-bb79-859ca23a5339]), log id: 652bc0fa
>2014-09-29 17:11:27,373 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.FullListVdsCommand] (DefaultQuartzScheduler_Worker-81) [7bd133cc] FINISH, FullListVdsCommand, return: [{displaySecurePort=5900, kvmEnable=true, nicModel=rtl8139,pv, keyboardLayout=en-us, guestDiskMapping={}, displayIp=10.35.0.110, pauseCode=NOERR, pitReinjection=false, nice=0, displayNetwork=ovirtmgmt, copyPasteEnable=true, timeOffset=0, transparentHugePages=true, vmId=4a0d069d-be19-4585-bb79-859ca23a5339, acpiEnable=true, custom={device_64047579-69d3-4791-8f6c-360ffb30997cdevice_cd58bbcd-db7e-4bb5-81a9-ef1bebf7c5e4device_99455cfc-ff6a-4805-82b6-9e71c2f2cc96=VmDevice {vmId=4a0d069d-be19-4585-bb79-859ca23a5339, deviceId=99455cfc-ff6a-4805-82b6-9e71c2f2cc96, device=unix, type=CHANNEL, bootOrder=0, specParams={}, address={port=2, bus=0, controller=0, type=virtio-serial}, managed=false, plugged=true, readOnly=false, deviceAlias=channel1, customProperties={}, snapshotId=null}, device_64047579-69d3-4791-8f6c-360ffb30997c=VmDevice {vmId=4a0d069d-be19-4585-bb79-859ca23a5339, deviceId=64047579-69d3-4791-8f6c-360ffb30997c, device=ide, type=CONTROLLER, bootOrder=0, specParams={}, address={bus=0x00, domain=0x0000, type=pci, slot=0x01, function=0x1}, managed=false, plugged=true, readOnly=false, deviceAlias=ide0, customProperties={}, snapshotId=null}, device_64047579-69d3-4791-8f6c-360ffb30997cdevice_cd58bbcd-db7e-4bb5-81a9-ef1bebf7c5e4=VmDevice {vmId=4a0d069d-be19-4585-bb79-859ca23a5339, deviceId=cd58bbcd-db7e-4bb5-81a9-ef1bebf7c5e4, device=unix, type=CHANNEL, bootOrder=0, specParams={}, address={port=1, bus=0, controller=0, type=virtio-serial}, managed=false, plugged=true, readOnly=false, deviceAlias=channel0, customProperties={}, snapshotId=null}, device_64047579-69d3-4791-8f6c-360ffb30997cdevice_cd58bbcd-db7e-4bb5-81a9-ef1bebf7c5e4device_99455cfc-ff6a-4805-82b6-9e71c2f2cc96device_7b412bf2-1cca-4af6-b5a4-35f8182f3559=VmDevice {vmId=4a0d069d-be19-4585-bb79-859ca23a5339, deviceId=7b412bf2-1cca-4af6-b5a4-35f8182f3559, device=spicevmc, type=CHANNEL, bootOrder=0, specParams={}, address={port=3, bus=0, controller=0, type=virtio-serial}, managed=false, plugged=true, readOnly=false, deviceAlias=channel2, customProperties={}, snapshotId=null}}, spiceSslCipherSuite=DEFAULT, memSize=1024, smp=1, displayPort=-1, emulatedMachine=rhel6.5.0, vmType=kvm, status=Up, memGuaranteedSize=512, display=qxl, pid=7954, smartcardEnable=false, bootMenuEnable=false, spiceSecureChannels=smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard, numaTune={mode=preferred}, smpCoresPerSocket=1, maxVCpus=16, clientIp=, devices=[Ljava.lang.Object;@1b8a90fa, vmName=vm01, fileTransferEnable=true, cpuType=Haswell}], log id: 652bc0fa
>2014-09-29 17:11:27,379 INFO  [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-81) [7bd133cc] Received a spice Device without an address when processing VM 4a0d069d-be19-4585-bb79-859ca23a5339 devices, skipping device: {specParams={spiceSecureChannels=smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard, keyMap=en-us, displayNetwork=ovirtmgmt, copyPasteEnable=true, displayIp=10.35.0.110}, device=spice, tlsPort=5900, type=graphics}
>2014-09-29 17:11:32,927 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-19) Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: The Balloon device on VM vm02 on host voodoo1 is inflated but the device cannot be controlled (guest agent is down).
>2014-09-29 17:11:36,687 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-49) [17acc57] Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: The Balloon device on VM vm01 on host voodoo6 is inflated but the device cannot be controlled (guest agent is down).
>2014-09-29 17:12:22,721 INFO  [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-48) VM vm02 98e6058d-cf96-4929-b118-4fc5542a30ba moved from PoweringUp --> Up
>2014-09-29 17:12:22,826 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-48) Correlation ID: 692b2dd, Job ID: 36614b09-45e9-4dff-a90f-13697b94867e, Call Stack: null, Custom Event ID: -1, Message: VM vm02 started on Host voodoo1
>2014-09-29 17:12:26,359 INFO  [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-45) VM vm01 4a0d069d-be19-4585-bb79-859ca23a5339 moved from PoweringUp --> Up
>2014-09-29 17:12:26,453 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-45) Correlation ID: 7b736f3f, Job ID: 8ebd4374-1eff-4a35-bc87-674ad2776c1e, Call Stack: null, Custom Event ID: -1, Message: VM vm01 started on Host voodoo6
>2014-09-29 17:13:28,493 INFO  [org.ovirt.engine.core.bll.MoveDisksCommand] (ajp--127.0.0.1-8702-5) [6cb596e5] Running command: MoveDisksCommand internal: false. Entities affected :  ID: 5ce6b00c-3ab5-4e3e-87d6-5006e4b636d8 Type: DiskAction group CONFIGURE_DISK_STORAGE with role type USER
>2014-09-29 17:13:28,520 INFO  [org.ovirt.engine.core.bll.lsm.LiveMigrateVmDisksCommand] (ajp--127.0.0.1-8702-5) [6cb596e5] Lock Acquired to object EngineLock [exclusiveLocks= key: 5ce6b00c-3ab5-4e3e-87d6-5006e4b636d8 value: DISK
>, sharedLocks= key: 4a0d069d-be19-4585-bb79-859ca23a5339 value: VM
>]
>2014-09-29 17:13:28,587 INFO  [org.ovirt.engine.core.bll.lsm.LiveMigrateVmDisksCommand] (org.ovirt.thread.pool-8-thread-27) [6cb596e5] Running command: LiveMigrateVmDisksCommand Task handler: LiveSnapshotTaskHandler internal: false. Entities affected :  ID: 5ce6b00c-3ab5-4e3e-87d6-5006e4b636d8 Type: DiskAction group CONFIGURE_DISK_STORAGE with role type USER,  ID: 51752c8f-bbe3-4754-866b-a0afd2a1f59d Type: StorageAction group CREATE_DISK with role type USER
>2014-09-29 17:13:28,598 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-5) Correlation ID: 6cb596e5, Call Stack: null, Custom Event ID: -1, Message: Unrecognized audit log type has been used.
>2014-09-29 17:13:28,627 INFO  [org.ovirt.engine.core.bll.CreateAllSnapshotsFromVmCommand] (org.ovirt.thread.pool-8-thread-27) Command 4a9b19cb-08f6-4c6a-b51f-6d42bc4a1abe persisting async task placeholder for child command 1b02d3dc-24bf-46b8-b290-0e342b3a462c
>2014-09-29 17:13:28,705 INFO  [org.ovirt.engine.core.bll.CreateAllSnapshotsFromVmCommand] (org.ovirt.thread.pool-8-thread-27) Running command: CreateAllSnapshotsFromVmCommand internal: true. Entities affected :  ID: 4a0d069d-be19-4585-bb79-859ca23a5339 Type: VMAction group MANIPULATE_VM_SNAPSHOTS with role type USER
>2014-09-29 17:13:28,730 INFO  [org.ovirt.engine.core.bll.CreateSnapshotCommand] (org.ovirt.thread.pool-8-thread-27) [11d90ff6] Running command: CreateSnapshotCommand internal: true. Entities affected :  ID: 00000000-0000-0000-0000-000000000000 Type: Storage
>2014-09-29 17:13:28,733 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CreateSnapshotVDSCommand] (org.ovirt.thread.pool-8-thread-27) [11d90ff6] START, CreateSnapshotVDSCommand( storagePoolId = b86b687a-d073-497a-ac8a-249025419a3e, ignoreFailoverLimit = false, storageDomainId = ff559f46-c495-4f6b-901c-2a624042a050, imageGroupId = 5ce6b00c-3ab5-4e3e-87d6-5006e4b636d8, imageSizeInBytes = 4294967296, volumeFormat = COW, newImageId = 5cc6af83-7679-4a9b-8085-ba27e0a58a07, newImageDescription = , imageId = c57c2ee7-0e30-4baa-a15f-7881cb20f701, sourceImageGroupId = 5ce6b00c-3ab5-4e3e-87d6-5006e4b636d8), log id: 66d0508a
>2014-09-29 17:13:28,735 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CreateSnapshotVDSCommand] (org.ovirt.thread.pool-8-thread-27) [11d90ff6] -- executeIrsBrokerCommand: calling 'createVolume' with two new parameters: description and UUID
>2014-09-29 17:13:28,794 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CreateSnapshotVDSCommand] (org.ovirt.thread.pool-8-thread-27) [11d90ff6] FINISH, CreateSnapshotVDSCommand, return: 5cc6af83-7679-4a9b-8085-ba27e0a58a07, log id: 66d0508a
>2014-09-29 17:13:28,928 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-27) [11d90ff6] CommandAsyncTask::Adding CommandMultiAsyncTasks object for command 98b4565b-23ae-4919-bcdf-3fd0fd62b857
>2014-09-29 17:13:28,929 INFO  [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (org.ovirt.thread.pool-8-thread-27) [11d90ff6] CommandMultiAsyncTasks::AttachTask: Attaching task 161f420d-696e-4e6e-8c55-bd0660dcf220 to command 98b4565b-23ae-4919-bcdf-3fd0fd62b857.
>2014-09-29 17:13:29,119 INFO  [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (org.ovirt.thread.pool-8-thread-27) [11d90ff6] Adding task 161f420d-696e-4e6e-8c55-bd0660dcf220 (Parent Command LiveMigrateVmDisks, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters), polling hasn't started yet..
>2014-09-29 17:13:29,195 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-8-thread-27) Correlation ID: 12c7e819, Job ID: 2a34bf8d-78bd-47e7-84f3-41a1a6782452, Call Stack: null, Custom Event ID: -1, Message: Snapshot 'Auto-generated for Live Storage Migration' creation for VM 'vm01' was initiated by admin.
>2014-09-29 17:13:29,219 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (org.ovirt.thread.pool-8-thread-27) BaseAsyncTask::startPollingTask: Starting to poll task 161f420d-696e-4e6e-8c55-bd0660dcf220.
>2014-09-29 17:13:34,616 INFO  [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (DefaultQuartzScheduler_Worker-51) Polling and updating Async Tasks: 7 tasks, 1 tasks to poll now
>2014-09-29 17:13:34,626 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-51) SPMAsyncTask::PollTask: Polling task 161f420d-696e-4e6e-8c55-bd0660dcf220 (Parent Command LiveMigrateVmDisks, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) returned status running.
>2014-09-29 17:13:34,627 INFO  [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (DefaultQuartzScheduler_Worker-51) Finished polling Tasks, will poll again in 10 seconds.
>2014-09-29 17:13:44,643 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-68) SPMAsyncTask::PollTask: Polling task 161f420d-696e-4e6e-8c55-bd0660dcf220 (Parent Command LiveMigrateVmDisks, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) returned status finished, result 'success'.
>2014-09-29 17:13:44,718 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-68) BaseAsyncTask::onTaskEndSuccess: Task 161f420d-696e-4e6e-8c55-bd0660dcf220 (Parent Command LiveMigrateVmDisks, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) ended successfully.
>2014-09-29 17:13:44,719 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (DefaultQuartzScheduler_Worker-68) CommandAsyncTask::endActionIfNecessary: All tasks of command 98b4565b-23ae-4919-bcdf-3fd0fd62b857 has ended -> executing endAction
>2014-09-29 17:13:44,720 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (DefaultQuartzScheduler_Worker-68) CommandAsyncTask::endAction: Ending action for 1 tasks (command ID: 98b4565b-23ae-4919-bcdf-3fd0fd62b857): calling endAction .
>2014-09-29 17:13:44,721 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-16) CommandAsyncTask::endCommandAction [within thread] context: Attempting to endAction LiveMigrateVmDisks, executionIndex: 0
>2014-09-29 17:13:44,868 INFO  [org.ovirt.engine.core.bll.lsm.LiveMigrateVmDisksCommand] (org.ovirt.thread.pool-8-thread-16) Ending command successfully: org.ovirt.engine.core.bll.lsm.LiveMigrateVmDisksCommand
>2014-09-29 17:13:44,873 INFO  [org.ovirt.engine.core.bll.CreateAllSnapshotsFromVmCommand] (org.ovirt.thread.pool-8-thread-16) Ending command successfully: org.ovirt.engine.core.bll.CreateAllSnapshotsFromVmCommand
>2014-09-29 17:13:44,888 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.SnapshotVDSCommand] (org.ovirt.thread.pool-8-thread-16) START, SnapshotVDSCommand(HostName = voodoo6, HostId = 45462850-a02c-4eeb-8527-292e15e5cb54, vmId=4a0d069d-be19-4585-bb79-859ca23a5339), log id: 124d65dd
>2014-09-29 17:13:55,051 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.SnapshotVDSCommand] (org.ovirt.thread.pool-8-thread-16) FINISH, SnapshotVDSCommand, log id: 124d65dd
>2014-09-29 17:13:55,095 INFO  [org.ovirt.engine.core.bll.CreateSnapshotCommand] (org.ovirt.thread.pool-8-thread-16) [11d90ff6] Ending command successfully: org.ovirt.engine.core.bll.CreateSnapshotCommand
>2014-09-29 17:13:55,099 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (org.ovirt.thread.pool-8-thread-16) [11d90ff6] START, GetImageInfoVDSCommand( storagePoolId = b86b687a-d073-497a-ac8a-249025419a3e, ignoreFailoverLimit = false, storageDomainId = ff559f46-c495-4f6b-901c-2a624042a050, imageGroupId = 5ce6b00c-3ab5-4e3e-87d6-5006e4b636d8, imageId = 5cc6af83-7679-4a9b-8085-ba27e0a58a07), log id: 34064d9b
>2014-09-29 17:13:55,126 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (org.ovirt.thread.pool-8-thread-16) [11d90ff6] FINISH, GetImageInfoVDSCommand, return: org.ovirt.engine.core.common.businessentities.DiskImage@771a2e7b, log id: 34064d9b
>2014-09-29 17:13:55,161 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-8-thread-16) Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: Snapshot 'Auto-generated for Live Storage Migration' creation for VM 'vm01' has been completed.
>2014-09-29 17:13:55,188 INFO  [org.ovirt.engine.core.bll.lsm.LiveMigrateVmDisksCommand] (org.ovirt.thread.pool-8-thread-16) Running command: LiveMigrateVmDisksCommand Task handler: LiveMigrateDisksTaskHandler internal: false. Entities affected :  ID: 51752c8f-bbe3-4754-866b-a0afd2a1f59d Type: StorageAction group CREATE_DISK with role type USER
>2014-09-29 17:13:55,272 INFO  [org.ovirt.engine.core.bll.lsm.LiveMigrateDiskCommand] (org.ovirt.thread.pool-8-thread-16) [1a1c7952] Lock Acquired to object EngineLock [exclusiveLocks= , sharedLocks= key: 4a0d069d-be19-4585-bb79-859ca23a5339 value: VM
>]
>2014-09-29 17:13:55,294 INFO  [org.ovirt.engine.core.bll.lsm.LiveMigrateDiskCommand] (org.ovirt.thread.pool-8-thread-16) [1a1c7952] Running command: LiveMigrateDiskCommand Task handler: CreateImagePlaceholderTaskHandler internal: true. Entities affected :  ID: 5ce6b00c-3ab5-4e3e-87d6-5006e4b636d8 Type: DiskAction group CONFIGURE_DISK_STORAGE with role type USER,  ID: 51752c8f-bbe3-4754-866b-a0afd2a1f59d Type: StorageAction group CREATE_DISK with role type USER
>2014-09-29 17:13:55,319 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CloneImageGroupStructureVDSCommand] (org.ovirt.thread.pool-8-thread-16) [1a1c7952] START, CloneImageGroupStructureVDSCommand( storagePoolId = b86b687a-d073-497a-ac8a-249025419a3e, ignoreFailoverLimit = false, storageDomainId = ff559f46-c495-4f6b-901c-2a624042a050, imageGroupId = 5ce6b00c-3ab5-4e3e-87d6-5006e4b636d8, dstDomainId = 51752c8f-bbe3-4754-866b-a0afd2a1f59d), log id: 3bd38e0a
>2014-09-29 17:13:55,377 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CloneImageGroupStructureVDSCommand] (org.ovirt.thread.pool-8-thread-16) [1a1c7952] FINISH, CloneImageGroupStructureVDSCommand, log id: 3bd38e0a
>2014-09-29 17:13:55,460 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-16) [1a1c7952] CommandAsyncTask::Adding CommandMultiAsyncTasks object for command db9381b1-a4ea-4e57-be12-9f9d2c69dd38
>2014-09-29 17:13:55,461 INFO  [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (org.ovirt.thread.pool-8-thread-16) [1a1c7952] CommandMultiAsyncTasks::AttachTask: Attaching task ca48835c-44c2-4197-ba5b-0ac895da0791 to command db9381b1-a4ea-4e57-be12-9f9d2c69dd38.
>2014-09-29 17:13:55,542 INFO  [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (org.ovirt.thread.pool-8-thread-16) [1a1c7952] Adding task ca48835c-44c2-4197-ba5b-0ac895da0791 (Parent Command LiveMigrateDisk, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters), polling hasn't started yet..
>2014-09-29 17:13:55,575 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-8-thread-16) [1a1c7952] Correlation ID: 1a1c7952, Job ID: 6aa37836-e37e-441c-a71d-b411b2a7edd7, Call Stack: null, Custom Event ID: -1, Message: User admin moving disk vm01_Disk1 to domain sasha-el7.
>2014-09-29 17:13:55,576 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (org.ovirt.thread.pool-8-thread-16) [1a1c7952] BaseAsyncTask::startPollingTask: Starting to poll task ca48835c-44c2-4197-ba5b-0ac895da0791.
>2014-09-29 17:13:55,579 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (org.ovirt.thread.pool-8-thread-16) [1a1c7952] BaseAsyncTask::startPollingTask: Starting to poll task ca48835c-44c2-4197-ba5b-0ac895da0791.
>2014-09-29 17:13:55,579 ERROR [org.ovirt.engine.core.bll.lsm.LiveMigrateVmDisksCommand] (org.ovirt.thread.pool-8-thread-16) [1a1c7952] Reverting task unknown, handler: org.ovirt.engine.core.bll.lsm.LiveSnapshotTaskHandler
>2014-09-29 17:13:55,581 INFO  [org.ovirt.engine.core.utils.transaction.TransactionSupport] (org.ovirt.thread.pool-8-thread-16) [1a1c7952] transaction rolled back
>2014-09-29 17:13:55,581 INFO  [org.ovirt.engine.core.bll.lsm.LiveMigrateVmDisksCommand] (org.ovirt.thread.pool-8-thread-16) [1a1c7952] Lock freed to object EngineLock [exclusiveLocks= key: 5ce6b00c-3ab5-4e3e-87d6-5006e4b636d8 value: DISK
>, sharedLocks= key: 4a0d069d-be19-4585-bb79-859ca23a5339 value: VM
>]
>2014-09-29 17:13:55,582 ERROR [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-16) [1a1c7952] [within thread]: endAction for action type LiveMigrateVmDisks threw an exception.: java.lang.NullPointerException
>	at org.ovirt.engine.core.bll.CommandBase.buildCommandEntity(CommandBase.java:2190) [bll.jar:]
>	at org.ovirt.engine.core.bll.CommandBase.setCommandExecuted(CommandBase.java:2235) [bll.jar:]
>	at org.ovirt.engine.core.bll.CommandBase.executeWithoutTransaction(CommandBase.java:1184) [bll.jar:]
>	at org.ovirt.engine.core.bll.CommandBase.executeActionInTransactionScope(CommandBase.java:1306) [bll.jar:]
>	at org.ovirt.engine.core.bll.CommandBase.runInTransaction(CommandBase.java:1931) [bll.jar:]
>	at org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInSuppressed(TransactionSupport.java:174) [utils.jar:]
>	at org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInScope(TransactionSupport.java:116) [utils.jar:]
>	at org.ovirt.engine.core.bll.CommandBase.execute(CommandBase.java:1330) [bll.jar:]
>	at org.ovirt.engine.core.bll.CommandBase.internalEndSuccessfully(CommandBase.java:614) [bll.jar:]
>	at org.ovirt.engine.core.bll.CommandBase.endActionInTransactionScope(CommandBase.java:562) [bll.jar:]
>	at org.ovirt.engine.core.bll.CommandBase.runInTransaction(CommandBase.java:1933) [bll.jar:]
>	at org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInNewTransaction(TransactionSupport.java:210) [utils.jar:]
>	at org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInRequired(TransactionSupport.java:149) [utils.jar:]
>	at org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInScope(TransactionSupport.java:118) [utils.jar:]
>	at org.ovirt.engine.core.bll.CommandBase.endAction(CommandBase.java:493) [bll.jar:]
>	at org.ovirt.engine.core.bll.lsm.LiveMigrateVmDisksCommand.endAction(LiveMigrateVmDisksCommand.java:97) [bll.jar:]
>	at org.ovirt.engine.core.bll.tasks.DecoratedCommand.endAction(DecoratedCommand.java:17) [bll.jar:]
>	at org.ovirt.engine.core.bll.tasks.CoCoAsyncTaskHelper.endAction(CoCoAsyncTaskHelper.java:335) [bll.jar:]
>	at org.ovirt.engine.core.bll.tasks.CommandCoordinatorImpl.endAction(CommandCoordinatorImpl.java:383) [bll.jar:]
>	at org.ovirt.engine.core.bll.tasks.CommandAsyncTask.endCommandAction(CommandAsyncTask.java:149) [bll.jar:]
>	at org.ovirt.engine.core.bll.tasks.CommandAsyncTask.access$000(CommandAsyncTask.java:28) [bll.jar:]
>	at org.ovirt.engine.core.bll.tasks.CommandAsyncTask$1.run(CommandAsyncTask.java:109) [bll.jar:]
>	at org.ovirt.engine.core.utils.threadpool.ThreadPoolUtil$InternalWrapperRunnable.run(ThreadPoolUtil.java:90) [utils.jar:]
>	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) [rt.jar:1.7.0_65]
>	at java.util.concurrent.FutureTask.run(FutureTask.java:262) [rt.jar:1.7.0_65]
>	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [rt.jar:1.7.0_65]
>	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [rt.jar:1.7.0_65]
>	at java.lang.Thread.run(Thread.java:745) [rt.jar:1.7.0_65]
>
>2014-09-29 17:13:55,590 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-16) [1a1c7952] CommandAsyncTask::HandleEndActionResult: endAction for action type LiveMigrateVmDisks threw an unrecoverable RuntimeException the task will be cleared.
>2014-09-29 17:13:55,600 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (org.ovirt.thread.pool-8-thread-16) [1a1c7952] BaseAsyncTask::removeTaskFromDB: Removed task 161f420d-696e-4e6e-8c55-bd0660dcf220 from DataBase
>2014-09-29 17:13:55,601 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-16) [1a1c7952] CommandAsyncTask::HandleEndActionRuntimeException: Removing CommandMultiAsyncTasks object for entity 98b4565b-23ae-4919-bcdf-3fd0fd62b857
>2014-09-29 17:13:57,806 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.FullListVdsCommand] (DefaultQuartzScheduler_Worker-53) START, FullListVdsCommand(HostName = voodoo6, HostId = 45462850-a02c-4eeb-8527-292e15e5cb54, vds=Host[voodoo6,45462850-a02c-4eeb-8527-292e15e5cb54], vmIds=[4a0d069d-be19-4585-bb79-859ca23a5339]), log id: 3003bb02
>2014-09-29 17:13:57,825 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.FullListVdsCommand] (DefaultQuartzScheduler_Worker-53) FINISH, FullListVdsCommand, return: [{displaySecurePort=5900, kvmEnable=true, nicModel=rtl8139,pv, keyboardLayout=en-us, guestDiskMapping={}, displayIp=10.35.0.110, pauseCode=NOERR, pitReinjection=false, nice=0, displayNetwork=ovirtmgmt, copyPasteEnable=true, timeOffset=0, transparentHugePages=true, vmId=4a0d069d-be19-4585-bb79-859ca23a5339, acpiEnable=true, custom={device_64047579-69d3-4791-8f6c-360ffb30997cdevice_cd58bbcd-db7e-4bb5-81a9-ef1bebf7c5e4device_99455cfc-ff6a-4805-82b6-9e71c2f2cc96=VmDevice {vmId=4a0d069d-be19-4585-bb79-859ca23a5339, deviceId=99455cfc-ff6a-4805-82b6-9e71c2f2cc96, device=unix, type=CHANNEL, bootOrder=0, specParams={}, address={port=2, bus=0, controller=0, type=virtio-serial}, managed=false, plugged=true, readOnly=false, deviceAlias=channel1, customProperties={}, snapshotId=null}, device_64047579-69d3-4791-8f6c-360ffb30997c=VmDevice {vmId=4a0d069d-be19-4585-bb79-859ca23a5339, deviceId=64047579-69d3-4791-8f6c-360ffb30997c, device=ide, type=CONTROLLER, bootOrder=0, specParams={}, address={bus=0x00, domain=0x0000, type=pci, slot=0x01, function=0x1}, managed=false, plugged=true, readOnly=false, deviceAlias=ide0, customProperties={}, snapshotId=null}, device_64047579-69d3-4791-8f6c-360ffb30997cdevice_cd58bbcd-db7e-4bb5-81a9-ef1bebf7c5e4=VmDevice {vmId=4a0d069d-be19-4585-bb79-859ca23a5339, deviceId=cd58bbcd-db7e-4bb5-81a9-ef1bebf7c5e4, device=unix, type=CHANNEL, bootOrder=0, specParams={}, address={port=1, bus=0, controller=0, type=virtio-serial}, managed=false, plugged=true, readOnly=false, deviceAlias=channel0, customProperties={}, snapshotId=null}, device_64047579-69d3-4791-8f6c-360ffb30997cdevice_cd58bbcd-db7e-4bb5-81a9-ef1bebf7c5e4device_99455cfc-ff6a-4805-82b6-9e71c2f2cc96device_7b412bf2-1cca-4af6-b5a4-35f8182f3559=VmDevice {vmId=4a0d069d-be19-4585-bb79-859ca23a5339, deviceId=7b412bf2-1cca-4af6-b5a4-35f8182f3559, device=spicevmc, type=CHANNEL, bootOrder=0, specParams={}, address={port=3, bus=0, controller=0, type=virtio-serial}, managed=false, plugged=true, readOnly=false, deviceAlias=channel2, customProperties={}, snapshotId=null}}, spiceSslCipherSuite=DEFAULT, memSize=1024, smp=1, displayPort=-1, emulatedMachine=rhel6.5.0, vmType=kvm, status=Up, memGuaranteedSize=512, display=qxl, pid=7954, smartcardEnable=false, bootMenuEnable=false, spiceSecureChannels=smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard, numaTune={mode=preferred}, smpCoresPerSocket=1, maxVCpus=16, clientIp=, devices=[Ljava.lang.Object;@47848f1f, vmName=vm01, fileTransferEnable=true, cpuType=Haswell}], log id: 3003bb02
>2014-09-29 17:13:57,835 INFO  [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-53) Received a spice Device without an address when processing VM 4a0d069d-be19-4585-bb79-859ca23a5339 devices, skipping device: {specParams={spiceSecureChannels=smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard, keyMap=en-us, displayNetwork=ovirtmgmt, copyPasteEnable=true, displayIp=10.35.0.110}, device=spice, tlsPort=5900, type=graphics}
>2014-09-29 17:14:04,721 INFO  [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (DefaultQuartzScheduler_Worker-50) Polling and updating Async Tasks: 8 tasks, 1 tasks to poll now
>2014-09-29 17:14:04,736 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-50) SPMAsyncTask::PollTask: Polling task ca48835c-44c2-4197-ba5b-0ac895da0791 (Parent Command LiveMigrateDisk, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) returned status running.
>2014-09-29 17:14:04,738 INFO  [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (DefaultQuartzScheduler_Worker-50) Finished polling Tasks, will poll again in 10 seconds.
>2014-09-29 17:14:14,752 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-10) [28a9d892] SPMAsyncTask::PollTask: Polling task ca48835c-44c2-4197-ba5b-0ac895da0791 (Parent Command LiveMigrateDisk, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) returned status finished, result 'success'.
>2014-09-29 17:14:14,783 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-10) [28a9d892] BaseAsyncTask::onTaskEndSuccess: Task ca48835c-44c2-4197-ba5b-0ac895da0791 (Parent Command LiveMigrateDisk, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) ended successfully.
>2014-09-29 17:14:14,784 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (DefaultQuartzScheduler_Worker-10) [28a9d892] CommandAsyncTask::endActionIfNecessary: All tasks of command db9381b1-a4ea-4e57-be12-9f9d2c69dd38 has ended -> executing endAction
>2014-09-29 17:14:14,785 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (DefaultQuartzScheduler_Worker-10) [28a9d892] CommandAsyncTask::endAction: Ending action for 1 tasks (command ID: db9381b1-a4ea-4e57-be12-9f9d2c69dd38): calling endAction .
>2014-09-29 17:14:14,787 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-49) [28a9d892] CommandAsyncTask::endCommandAction [within thread] context: Attempting to endAction LiveMigrateDisk, executionIndex: 0
>2014-09-29 17:14:14,873 INFO  [org.ovirt.engine.core.bll.lsm.LiveMigrateDiskCommand] (org.ovirt.thread.pool-8-thread-49) [1a1c7952] Ending command successfully: org.ovirt.engine.core.bll.lsm.LiveMigrateDiskCommand
>2014-09-29 17:14:14,882 INFO  [org.ovirt.engine.core.bll.lsm.LiveMigrateDiskCommand] (org.ovirt.thread.pool-8-thread-49) [1a1c7952] Running command: LiveMigrateDiskCommand Task handler: VmReplicateDiskStartTaskHandler internal: false. Entities affected :  ID: 5ce6b00c-3ab5-4e3e-87d6-5006e4b636d8 Type: DiskAction group CONFIGURE_DISK_STORAGE with role type USER,  ID: 51752c8f-bbe3-4754-866b-a0afd2a1f59d Type: StorageAction group CREATE_DISK with role type USER
>2014-09-29 17:14:14,883 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.VmReplicateDiskStartVDSCommand] (org.ovirt.thread.pool-8-thread-49) [1a1c7952] START, VmReplicateDiskStartVDSCommand(HostName = voodoo6, HostId = 45462850-a02c-4eeb-8527-292e15e5cb54, vmId=4a0d069d-be19-4585-bb79-859ca23a5339), log id: 4e12f0b3
>2014-09-29 17:14:15,136 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.VmReplicateDiskStartVDSCommand] (org.ovirt.thread.pool-8-thread-49) [1a1c7952] FINISH, VmReplicateDiskStartVDSCommand, log id: 4e12f0b3
>2014-09-29 17:14:15,155 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SyncImageGroupDataVDSCommand] (org.ovirt.thread.pool-8-thread-49) [1a1c7952] START, SyncImageGroupDataVDSCommand( storagePoolId = b86b687a-d073-497a-ac8a-249025419a3e, ignoreFailoverLimit = false, storageDomainId = ff559f46-c495-4f6b-901c-2a624042a050, imageGroupId = 5ce6b00c-3ab5-4e3e-87d6-5006e4b636d8, dstDomainId = 51752c8f-bbe3-4754-866b-a0afd2a1f59d, syncType=INTERNAL), log id: 781ad881
>2014-09-29 17:14:15,215 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SyncImageGroupDataVDSCommand] (org.ovirt.thread.pool-8-thread-49) [1a1c7952] FINISH, SyncImageGroupDataVDSCommand, log id: 781ad881
>2014-09-29 17:14:15,231 INFO  [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (org.ovirt.thread.pool-8-thread-49) [1a1c7952] CommandMultiAsyncTasks::AttachTask: Attaching task bb77466f-d95e-4c04-b35d-48922b7f0fc7 to command db9381b1-a4ea-4e57-be12-9f9d2c69dd38.
>2014-09-29 17:14:15,246 INFO  [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (org.ovirt.thread.pool-8-thread-49) [1a1c7952] Adding task bb77466f-d95e-4c04-b35d-48922b7f0fc7 (Parent Command LiveMigrateDisk, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters), polling hasn't started yet..
>2014-09-29 17:14:15,296 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-8-thread-49) [1a1c7952] Correlation ID: 1a1c7952, Call Stack: null, Custom Event ID: -1, Message: Unrecognized audit log type has been used.
>2014-09-29 17:14:15,297 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (org.ovirt.thread.pool-8-thread-49) [1a1c7952] BaseAsyncTask::startPollingTask: Starting to poll task bb77466f-d95e-4c04-b35d-48922b7f0fc7.
>2014-09-29 17:14:15,304 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-8-thread-49) [1a1c7952] Correlation ID: 1a1c7952, Call Stack: null, Custom Event ID: -1, Message: Unrecognized audit log type has been used.
>2014-09-29 17:14:15,305 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-49) [1a1c7952] CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type LiveMigrateDisk completed, handling the result.
>2014-09-29 17:14:15,306 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-49) [1a1c7952] CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type LiveMigrateDisk succeeded, clearing tasks.
>2014-09-29 17:14:15,307 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (org.ovirt.thread.pool-8-thread-49) [1a1c7952] SPMAsyncTask::ClearAsyncTask: Attempting to clear task ca48835c-44c2-4197-ba5b-0ac895da0791
>2014-09-29 17:14:15,308 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-49) [1a1c7952] START, SPMClearTaskVDSCommand( storagePoolId = b86b687a-d073-497a-ac8a-249025419a3e, ignoreFailoverLimit = false, taskId = ca48835c-44c2-4197-ba5b-0ac895da0791), log id: 348b52a7
>2014-09-29 17:14:15,311 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-49) [1a1c7952] START, HSMClearTaskVDSCommand(HostName = voodoo6, HostId = 45462850-a02c-4eeb-8527-292e15e5cb54, taskId=ca48835c-44c2-4197-ba5b-0ac895da0791), log id: 26df6ce4
>2014-09-29 17:14:15,370 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-49) [1a1c7952] FINISH, HSMClearTaskVDSCommand, log id: 26df6ce4
>2014-09-29 17:14:15,370 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-49) [1a1c7952] FINISH, SPMClearTaskVDSCommand, log id: 348b52a7
>2014-09-29 17:14:15,379 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (org.ovirt.thread.pool-8-thread-49) [1a1c7952] BaseAsyncTask::removeTaskFromDB: Removed task ca48835c-44c2-4197-ba5b-0ac895da0791 from DataBase
>2014-09-29 17:14:15,380 INFO  [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (org.ovirt.thread.pool-8-thread-49) [1a1c7952] [within thread]: Some of the tasks related to command id db9381b1-a4ea-4e57-be12-9f9d2c69dd38 were not cleared yet (Task id bb77466f-d95e-4c04-b35d-48922b7f0fc7 is in state Polling).
>2014-09-29 17:14:24,787 INFO  [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (DefaultQuartzScheduler_Worker-58) Polling and updating Async Tasks: 9 tasks, 1 tasks to poll now
>2014-09-29 17:14:24,802 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-58) SPMAsyncTask::PollTask: Polling task bb77466f-d95e-4c04-b35d-48922b7f0fc7 (Parent Command LiveMigrateDisk, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) returned status running.
>2014-09-29 17:14:24,803 INFO  [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (DefaultQuartzScheduler_Worker-58) Finished polling Tasks, will poll again in 10 seconds.
>2014-09-29 17:15:23,916 INFO  [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (DefaultQuartzScheduler_Worker-18) [5289002e] Setting new tasks map. The map contains now 8 tasks
>2014-09-29 17:15:24,929 INFO  [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (DefaultQuartzScheduler_Worker-45) Polling and updating Async Tasks: 8 tasks, 1 tasks to poll now
>2014-09-29 17:15:24,946 INFO  [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (DefaultQuartzScheduler_Worker-45) Finished polling Tasks, will poll again in 10 seconds.
>2014-09-29 17:17:55,455 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-52) [3c5a94f0] SPMAsyncTask::PollTask: Polling task bb77466f-d95e-4c04-b35d-48922b7f0fc7 (Parent Command LiveMigrateDisk, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) returned status finished, result 'success'.
>2014-09-29 17:17:55,466 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-52) [3c5a94f0] BaseAsyncTask::onTaskEndSuccess: Task bb77466f-d95e-4c04-b35d-48922b7f0fc7 (Parent Command LiveMigrateDisk, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) ended successfully.
>2014-09-29 17:17:55,468 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (DefaultQuartzScheduler_Worker-52) [3c5a94f0] CommandAsyncTask::endActionIfNecessary: All tasks of command db9381b1-a4ea-4e57-be12-9f9d2c69dd38 has ended -> executing endAction
>2014-09-29 17:17:55,469 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (DefaultQuartzScheduler_Worker-52) [3c5a94f0] CommandAsyncTask::endAction: Ending action for 1 tasks (command ID: db9381b1-a4ea-4e57-be12-9f9d2c69dd38): calling endAction .
>2014-09-29 17:17:55,470 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-18) [3c5a94f0] CommandAsyncTask::endCommandAction [within thread] context: Attempting to endAction LiveMigrateDisk, executionIndex: 1
>2014-09-29 17:17:55,553 INFO  [org.ovirt.engine.core.bll.lsm.LiveMigrateDiskCommand] (org.ovirt.thread.pool-8-thread-18) [1a1c7952] Ending command successfully: org.ovirt.engine.core.bll.lsm.LiveMigrateDiskCommand
>2014-09-29 17:17:55,554 INFO  [org.ovirt.engine.core.bll.lsm.LiveMigrateDiskCommand] (org.ovirt.thread.pool-8-thread-18) [1a1c7952] Running command: LiveMigrateDiskCommand Task handler: VmReplicateDiskFinishTaskHandler internal: false. Entities affected :  ID: 5ce6b00c-3ab5-4e3e-87d6-5006e4b636d8 Type: DiskAction group CONFIGURE_DISK_STORAGE with role type USER,  ID: 51752c8f-bbe3-4754-866b-a0afd2a1f59d Type: StorageAction group CREATE_DISK with role type USER
>2014-09-29 17:17:55,874 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.VmReplicateDiskFinishVDSCommand] (org.ovirt.thread.pool-8-thread-18) [1a1c7952] START, VmReplicateDiskFinishVDSCommand(HostName = voodoo6, HostId = 45462850-a02c-4eeb-8527-292e15e5cb54, vmId=4a0d069d-be19-4585-bb79-859ca23a5339), log id: 3861ec04
>2014-09-29 17:18:01,381 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.VmReplicateDiskFinishVDSCommand] (org.ovirt.thread.pool-8-thread-18) [1a1c7952] FINISH, VmReplicateDiskFinishVDSCommand, log id: 3861ec04
>2014-09-29 17:18:01,390 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (org.ovirt.thread.pool-8-thread-18) [1a1c7952] START, GetImageInfoVDSCommand( storagePoolId = b86b687a-d073-497a-ac8a-249025419a3e, ignoreFailoverLimit = false, storageDomainId = 51752c8f-bbe3-4754-866b-a0afd2a1f59d, imageGroupId = 5ce6b00c-3ab5-4e3e-87d6-5006e4b636d8, imageId = 5cc6af83-7679-4a9b-8085-ba27e0a58a07), log id: 3ac81bc9
>2014-09-29 17:18:02,486 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.FullListVdsCommand] (DefaultQuartzScheduler_Worker-56) START, FullListVdsCommand(HostName = voodoo6, HostId = 45462850-a02c-4eeb-8527-292e15e5cb54, vds=Host[voodoo6,45462850-a02c-4eeb-8527-292e15e5cb54], vmIds=[4a0d069d-be19-4585-bb79-859ca23a5339]), log id: d44182b
>2014-09-29 17:18:02,508 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.FullListVdsCommand] (DefaultQuartzScheduler_Worker-56) FINISH, FullListVdsCommand, return: [{displaySecurePort=5900, kvmEnable=true, nicModel=rtl8139,pv, keyboardLayout=en-us, guestDiskMapping={}, displayIp=10.35.0.110, pitReinjection=false, nice=0, displayNetwork=ovirtmgmt, copyPasteEnable=true, timeOffset=0, transparentHugePages=true, vmId=4a0d069d-be19-4585-bb79-859ca23a5339, acpiEnable=true, custom={device_64047579-69d3-4791-8f6c-360ffb30997cdevice_cd58bbcd-db7e-4bb5-81a9-ef1bebf7c5e4device_99455cfc-ff6a-4805-82b6-9e71c2f2cc96=VmDevice {vmId=4a0d069d-be19-4585-bb79-859ca23a5339, deviceId=99455cfc-ff6a-4805-82b6-9e71c2f2cc96, device=unix, type=CHANNEL, bootOrder=0, specParams={}, address={port=2, bus=0, controller=0, type=virtio-serial}, managed=false, plugged=true, readOnly=false, deviceAlias=channel1, customProperties={}, snapshotId=null}, device_64047579-69d3-4791-8f6c-360ffb30997c=VmDevice {vmId=4a0d069d-be19-4585-bb79-859ca23a5339, deviceId=64047579-69d3-4791-8f6c-360ffb30997c, device=ide, type=CONTROLLER, bootOrder=0, specParams={}, address={bus=0x00, domain=0x0000, type=pci, slot=0x01, function=0x1}, managed=false, plugged=true, readOnly=false, deviceAlias=ide0, customProperties={}, snapshotId=null}, device_64047579-69d3-4791-8f6c-360ffb30997cdevice_cd58bbcd-db7e-4bb5-81a9-ef1bebf7c5e4=VmDevice {vmId=4a0d069d-be19-4585-bb79-859ca23a5339, deviceId=cd58bbcd-db7e-4bb5-81a9-ef1bebf7c5e4, device=unix, type=CHANNEL, bootOrder=0, specParams={}, address={port=1, bus=0, controller=0, type=virtio-serial}, managed=false, plugged=true, readOnly=false, deviceAlias=channel0, customProperties={}, snapshotId=null}, device_64047579-69d3-4791-8f6c-360ffb30997cdevice_cd58bbcd-db7e-4bb5-81a9-ef1bebf7c5e4device_99455cfc-ff6a-4805-82b6-9e71c2f2cc96device_7b412bf2-1cca-4af6-b5a4-35f8182f3559=VmDevice {vmId=4a0d069d-be19-4585-bb79-859ca23a5339, deviceId=7b412bf2-1cca-4af6-b5a4-35f8182f3559, device=spicevmc, type=CHANNEL, bootOrder=0, specParams={}, address={port=3, bus=0, controller=0, type=virtio-serial}, managed=false, plugged=true, readOnly=false, deviceAlias=channel2, customProperties={}, snapshotId=null}}, spiceSslCipherSuite=DEFAULT, memSize=1024, smp=1, displayPort=-1, vmType=kvm, emulatedMachine=rhel6.5.0, status=Up, memGuaranteedSize=512, display=qxl, pid=7954, smartcardEnable=false, bootMenuEnable=false, spiceSecureChannels=smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard, numaTune={mode=preferred}, smpCoresPerSocket=1, maxVCpus=16, clientIp=, devices=[Ljava.lang.Object;@718eb5da, vmName=vm01, fileTransferEnable=true, cpuType=Haswell}], log id: d44182b
>2014-09-29 17:18:02,512 INFO  [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-56) Received a spice Device without an address when processing VM 4a0d069d-be19-4585-bb79-859ca23a5339 devices, skipping device: {specParams={spiceSecureChannels=smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard, keyMap=en-us, displayNetwork=ovirtmgmt, copyPasteEnable=true, displayIp=10.35.0.110}, device=spice, tlsPort=5900, type=graphics}
>2014-09-29 17:18:04,896 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (org.ovirt.thread.pool-8-thread-18) [1a1c7952] FINISH, GetImageInfoVDSCommand, return: org.ovirt.engine.core.common.businessentities.DiskImage@adb3a945, log id: 3ac81bc9
>2014-09-29 17:18:04,933 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (org.ovirt.thread.pool-8-thread-18) [1a1c7952] START, GetImageInfoVDSCommand( storagePoolId = b86b687a-d073-497a-ac8a-249025419a3e, ignoreFailoverLimit = false, storageDomainId = 51752c8f-bbe3-4754-866b-a0afd2a1f59d, imageGroupId = 5ce6b00c-3ab5-4e3e-87d6-5006e4b636d8, imageId = c57c2ee7-0e30-4baa-a15f-7881cb20f701), log id: 5f6f20f7
>2014-09-29 17:18:04,960 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (org.ovirt.thread.pool-8-thread-18) [1a1c7952] FINISH, GetImageInfoVDSCommand, return: org.ovirt.engine.core.common.businessentities.DiskImage@8f3a77a2, log id: 5f6f20f7
>2014-09-29 17:18:05,011 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] (org.ovirt.thread.pool-8-thread-18) [1a1c7952] START, DeleteImageGroupVDSCommand( storagePoolId = b86b687a-d073-497a-ac8a-249025419a3e, ignoreFailoverLimit = false, storageDomainId = ff559f46-c495-4f6b-901c-2a624042a050, imageGroupId = 5ce6b00c-3ab5-4e3e-87d6-5006e4b636d8, postZeros = false, forceDelete = false), log id: 339d62d8
>2014-09-29 17:18:05,402 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] (org.ovirt.thread.pool-8-thread-18) [1a1c7952] FINISH, DeleteImageGroupVDSCommand, log id: 339d62d8
>2014-09-29 17:18:05,423 INFO  [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (org.ovirt.thread.pool-8-thread-18) [1a1c7952] CommandMultiAsyncTasks::AttachTask: Attaching task 6b22ee80-5179-41e0-b230-624ef01a53b1 to command db9381b1-a4ea-4e57-be12-9f9d2c69dd38.
>2014-09-29 17:18:05,438 INFO  [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (org.ovirt.thread.pool-8-thread-18) [1a1c7952] Adding task 6b22ee80-5179-41e0-b230-624ef01a53b1 (Parent Command LiveMigrateDisk, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters), polling hasn't started yet..
>2014-09-29 17:18:05,480 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-8-thread-18) [1a1c7952] Correlation ID: 1a1c7952, Call Stack: null, Custom Event ID: -1, Message: Unrecognized audit log type has been used.
>2014-09-29 17:18:05,481 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (org.ovirt.thread.pool-8-thread-18) [1a1c7952] BaseAsyncTask::startPollingTask: Starting to poll task 6b22ee80-5179-41e0-b230-624ef01a53b1.
>2014-09-29 17:18:05,488 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-8-thread-18) [1a1c7952] Correlation ID: 1a1c7952, Call Stack: null, Custom Event ID: -1, Message: Unrecognized audit log type has been used.
>2014-09-29 17:18:05,489 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-18) [1a1c7952] CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type LiveMigrateDisk completed, handling the result.
>2014-09-29 17:18:05,490 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-18) [1a1c7952] CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type LiveMigrateDisk succeeded, clearing tasks.
>2014-09-29 17:18:05,491 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (org.ovirt.thread.pool-8-thread-18) [1a1c7952] SPMAsyncTask::ClearAsyncTask: Attempting to clear task bb77466f-d95e-4c04-b35d-48922b7f0fc7
>2014-09-29 17:18:05,491 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-18) [1a1c7952] START, SPMClearTaskVDSCommand( storagePoolId = b86b687a-d073-497a-ac8a-249025419a3e, ignoreFailoverLimit = false, taskId = bb77466f-d95e-4c04-b35d-48922b7f0fc7), log id: 6edacefa
>2014-09-29 17:18:06,128 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-18) [1a1c7952] START, HSMClearTaskVDSCommand(HostName = voodoo6, HostId = 45462850-a02c-4eeb-8527-292e15e5cb54, taskId=bb77466f-d95e-4c04-b35d-48922b7f0fc7), log id: 4da03bb1
>2014-09-29 17:18:06,143 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-18) [1a1c7952] FINISH, HSMClearTaskVDSCommand, log id: 4da03bb1
>2014-09-29 17:18:06,144 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-18) [1a1c7952] FINISH, SPMClearTaskVDSCommand, log id: 6edacefa
>2014-09-29 17:18:06,159 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (org.ovirt.thread.pool-8-thread-18) [1a1c7952] BaseAsyncTask::removeTaskFromDB: Removed task bb77466f-d95e-4c04-b35d-48922b7f0fc7 from DataBase
>2014-09-29 17:18:06,159 INFO  [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (org.ovirt.thread.pool-8-thread-18) [1a1c7952] [within thread]: Some of the tasks related to command id db9381b1-a4ea-4e57-be12-9f9d2c69dd38 were not cleared yet (Task id 6b22ee80-5179-41e0-b230-624ef01a53b1 is in state Polling).
>2014-09-29 17:18:15,471 INFO  [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (DefaultQuartzScheduler_Worker-64) [2441a1d5] Polling and updating Async Tasks: 9 tasks, 1 tasks to poll now
>2014-09-29 17:18:15,484 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-64) [2441a1d5] SPMAsyncTask::PollTask: Polling task 6b22ee80-5179-41e0-b230-624ef01a53b1 (Parent Command LiveMigrateDisk, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) returned status finished, result 'success'.
>2014-09-29 17:18:15,566 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-64) [2441a1d5] BaseAsyncTask::onTaskEndSuccess: Task 6b22ee80-5179-41e0-b230-624ef01a53b1 (Parent Command LiveMigrateDisk, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) ended successfully.
>2014-09-29 17:18:15,567 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (DefaultQuartzScheduler_Worker-64) [2441a1d5] CommandAsyncTask::endActionIfNecessary: All tasks of command db9381b1-a4ea-4e57-be12-9f9d2c69dd38 has ended -> executing endAction
>2014-09-29 17:18:15,568 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (DefaultQuartzScheduler_Worker-64) [2441a1d5] CommandAsyncTask::endAction: Ending action for 1 tasks (command ID: db9381b1-a4ea-4e57-be12-9f9d2c69dd38): calling endAction .
>2014-09-29 17:18:15,569 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-15) [2441a1d5] CommandAsyncTask::endCommandAction [within thread] context: Attempting to endAction LiveMigrateDisk, executionIndex: 2
>2014-09-29 17:18:15,606 INFO  [org.ovirt.engine.core.bll.lsm.LiveMigrateDiskCommand] (org.ovirt.thread.pool-8-thread-15) [1a1c7952] Ending command successfully: org.ovirt.engine.core.bll.lsm.LiveMigrateDiskCommand
>2014-09-29 17:18:15,607 INFO  [org.ovirt.engine.core.bll.lsm.LiveMigrateDiskCommand] (org.ovirt.thread.pool-8-thread-15) [1a1c7952] Lock freed to object EngineLock [exclusiveLocks= , sharedLocks= key: 4a0d069d-be19-4585-bb79-859ca23a5339 value: VM
>]
>2014-09-29 17:18:15,635 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-8-thread-15) [1a1c7952] Correlation ID: 1a1c7952, Call Stack: null, Custom Event ID: -1, Message: User admin finished moving disk vm01_Disk1 to domain sasha-el7.
>2014-09-29 17:18:15,636 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-15) [1a1c7952] CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type LiveMigrateDisk completed, handling the result.
>2014-09-29 17:18:15,637 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-15) [1a1c7952] CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type LiveMigrateDisk succeeded, clearing tasks.
>2014-09-29 17:18:15,651 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (org.ovirt.thread.pool-8-thread-15) [1a1c7952] SPMAsyncTask::ClearAsyncTask: Attempting to clear task 6b22ee80-5179-41e0-b230-624ef01a53b1
>2014-09-29 17:18:15,652 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-15) [1a1c7952] START, SPMClearTaskVDSCommand( storagePoolId = b86b687a-d073-497a-ac8a-249025419a3e, ignoreFailoverLimit = false, taskId = 6b22ee80-5179-41e0-b230-624ef01a53b1), log id: a7c5e26
>2014-09-29 17:18:15,655 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-15) [1a1c7952] START, HSMClearTaskVDSCommand(HostName = voodoo6, HostId = 45462850-a02c-4eeb-8527-292e15e5cb54, taskId=6b22ee80-5179-41e0-b230-624ef01a53b1), log id: 6b09162a
>2014-09-29 17:18:15,674 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-15) [1a1c7952] FINISH, HSMClearTaskVDSCommand, log id: 6b09162a
>2014-09-29 17:18:15,675 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-15) [1a1c7952] FINISH, SPMClearTaskVDSCommand, log id: a7c5e26
>2014-09-29 17:18:15,684 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (org.ovirt.thread.pool-8-thread-15) [1a1c7952] BaseAsyncTask::removeTaskFromDB: Removed task 6b22ee80-5179-41e0-b230-624ef01a53b1 from DataBase
>2014-09-29 17:18:15,685 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-15) [1a1c7952] CommandAsyncTask::HandleEndActionResult [within thread]: Removing CommandMultiAsyncTasks object for entity db9381b1-a4ea-4e57-be12-9f9d2c69dd38
>2014-09-29 17:19:23,921 INFO  [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (DefaultQuartzScheduler_Worker-35) [5a29dd96] Setting new tasks map. The map contains now 7 tasks
>2014-09-29 17:24:03,016 INFO  [org.ovirt.engine.core.bll.MoveDisksCommand] (ajp--127.0.0.1-8702-11) [1e8cc64c] Running command: MoveDisksCommand internal: false. Entities affected :  ID: a75c1851-bddb-4339-bee2-f22b4b1268ac Type: DiskAction group CONFIGURE_DISK_STORAGE with role type USER
>2014-09-29 17:24:03,060 INFO  [org.ovirt.engine.core.bll.lsm.LiveMigrateVmDisksCommand] (ajp--127.0.0.1-8702-11) [1e8cc64c] Lock Acquired to object EngineLock [exclusiveLocks= key: a75c1851-bddb-4339-bee2-f22b4b1268ac value: DISK
>, sharedLocks= key: 98e6058d-cf96-4929-b118-4fc5542a30ba value: VM
>]
>2014-09-29 17:24:03,103 INFO  [org.ovirt.engine.core.bll.lsm.LiveMigrateVmDisksCommand] (org.ovirt.thread.pool-8-thread-49) [1e8cc64c] Running command: LiveMigrateVmDisksCommand Task handler: LiveSnapshotTaskHandler internal: false. Entities affected :  ID: a75c1851-bddb-4339-bee2-f22b4b1268ac Type: DiskAction group CONFIGURE_DISK_STORAGE with role type USER,  ID: 51752c8f-bbe3-4754-866b-a0afd2a1f59d Type: StorageAction group CREATE_DISK with role type USER
>2014-09-29 17:24:03,121 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-11) Correlation ID: 1e8cc64c, Call Stack: null, Custom Event ID: -1, Message: Unrecognized audit log type has been used.
>2014-09-29 17:24:03,155 INFO  [org.ovirt.engine.core.bll.CreateAllSnapshotsFromVmCommand] (org.ovirt.thread.pool-8-thread-49) Command 3a516405-8a3b-418a-8068-77ff198ef2ba persisting async task placeholder for child command 672abc18-3584-45c2-805a-53184ac5bad3
>2014-09-29 17:24:03,229 INFO  [org.ovirt.engine.core.bll.CreateAllSnapshotsFromVmCommand] (org.ovirt.thread.pool-8-thread-49) Running command: CreateAllSnapshotsFromVmCommand internal: true. Entities affected :  ID: 98e6058d-cf96-4929-b118-4fc5542a30ba Type: VMAction group MANIPULATE_VM_SNAPSHOTS with role type USER
>2014-09-29 17:24:03,254 INFO  [org.ovirt.engine.core.bll.CreateSnapshotCommand] (org.ovirt.thread.pool-8-thread-49) [f31a7d7] Running command: CreateSnapshotCommand internal: true. Entities affected :  ID: 00000000-0000-0000-0000-000000000000 Type: Storage
>2014-09-29 17:24:03,256 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CreateSnapshotVDSCommand] (org.ovirt.thread.pool-8-thread-49) [f31a7d7] START, CreateSnapshotVDSCommand( storagePoolId = b86b687a-d073-497a-ac8a-249025419a3e, ignoreFailoverLimit = false, storageDomainId = ff559f46-c495-4f6b-901c-2a624042a050, imageGroupId = a75c1851-bddb-4339-bee2-f22b4b1268ac, imageSizeInBytes = 4294967296, volumeFormat = COW, newImageId = f6d11460-fcd1-4b40-8e50-56a2ad6347a5, newImageDescription = , imageId = 9d74263f-76a8-4c33-94f7-454e06934207, sourceImageGroupId = a75c1851-bddb-4339-bee2-f22b4b1268ac), log id: 5d7e79d6
>2014-09-29 17:24:03,258 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CreateSnapshotVDSCommand] (org.ovirt.thread.pool-8-thread-49) [f31a7d7] -- executeIrsBrokerCommand: calling 'createVolume' with two new parameters: description and UUID
>2014-09-29 17:24:03,314 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CreateSnapshotVDSCommand] (org.ovirt.thread.pool-8-thread-49) [f31a7d7] FINISH, CreateSnapshotVDSCommand, return: f6d11460-fcd1-4b40-8e50-56a2ad6347a5, log id: 5d7e79d6
>2014-09-29 17:24:03,321 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-49) [f31a7d7] CommandAsyncTask::Adding CommandMultiAsyncTasks object for command 10c9c0f3-b697-4203-8718-ac705b8d43eb
>2014-09-29 17:24:03,322 INFO  [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (org.ovirt.thread.pool-8-thread-49) [f31a7d7] CommandMultiAsyncTasks::AttachTask: Attaching task 186121fa-8604-462b-a8d3-c09adf830775 to command 10c9c0f3-b697-4203-8718-ac705b8d43eb.
>2014-09-29 17:24:03,345 INFO  [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (org.ovirt.thread.pool-8-thread-49) [f31a7d7] Adding task 186121fa-8604-462b-a8d3-c09adf830775 (Parent Command LiveMigrateVmDisks, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters), polling hasn't started yet..
>2014-09-29 17:24:03,429 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-8-thread-49) Correlation ID: 213a25b8, Job ID: 39ebfe06-f858-417f-aca2-d3c95a4d19bc, Call Stack: null, Custom Event ID: -1, Message: Snapshot 'Auto-generated for Live Storage Migration' creation for VM 'vm02' was initiated by admin.
>2014-09-29 17:24:03,454 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (org.ovirt.thread.pool-8-thread-49) BaseAsyncTask::startPollingTask: Starting to poll task 186121fa-8604-462b-a8d3-c09adf830775.
>2014-09-29 17:24:05,573 INFO  [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (DefaultQuartzScheduler_Worker-86) Polling and updating Async Tasks: 8 tasks, 1 tasks to poll now
>2014-09-29 17:24:05,586 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-86) SPMAsyncTask::PollTask: Polling task 186121fa-8604-462b-a8d3-c09adf830775 (Parent Command LiveMigrateVmDisks, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) returned status finished, result 'success'.
>2014-09-29 17:24:05,599 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-86) BaseAsyncTask::onTaskEndSuccess: Task 186121fa-8604-462b-a8d3-c09adf830775 (Parent Command LiveMigrateVmDisks, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) ended successfully.
>2014-09-29 17:24:05,599 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (DefaultQuartzScheduler_Worker-86) CommandAsyncTask::endActionIfNecessary: All tasks of command 10c9c0f3-b697-4203-8718-ac705b8d43eb has ended -> executing endAction
>2014-09-29 17:24:05,600 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (DefaultQuartzScheduler_Worker-86) CommandAsyncTask::endAction: Ending action for 1 tasks (command ID: 10c9c0f3-b697-4203-8718-ac705b8d43eb): calling endAction .
>2014-09-29 17:24:05,601 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-17) CommandAsyncTask::endCommandAction [within thread] context: Attempting to endAction LiveMigrateVmDisks, executionIndex: 0
>2014-09-29 17:24:05,623 INFO  [org.ovirt.engine.core.bll.lsm.LiveMigrateVmDisksCommand] (org.ovirt.thread.pool-8-thread-17) Ending command successfully: org.ovirt.engine.core.bll.lsm.LiveMigrateVmDisksCommand
>2014-09-29 17:24:05,628 INFO  [org.ovirt.engine.core.bll.CreateAllSnapshotsFromVmCommand] (org.ovirt.thread.pool-8-thread-17) Ending command successfully: org.ovirt.engine.core.bll.CreateAllSnapshotsFromVmCommand
>2014-09-29 17:24:05,645 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.SnapshotVDSCommand] (org.ovirt.thread.pool-8-thread-17) START, SnapshotVDSCommand(HostName = voodoo1, HostId = 114c2cc6-5123-45bc-8900-5c875b0543c4, vmId=98e6058d-cf96-4929-b118-4fc5542a30ba), log id: 16176420
>2014-09-29 17:24:16,273 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.SnapshotVDSCommand] (org.ovirt.thread.pool-8-thread-17) FINISH, SnapshotVDSCommand, log id: 16176420
>2014-09-29 17:24:16,316 INFO  [org.ovirt.engine.core.bll.CreateSnapshotCommand] (org.ovirt.thread.pool-8-thread-17) [f31a7d7] Ending command successfully: org.ovirt.engine.core.bll.CreateSnapshotCommand
>2014-09-29 17:24:16,326 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (org.ovirt.thread.pool-8-thread-17) [f31a7d7] START, GetImageInfoVDSCommand( storagePoolId = b86b687a-d073-497a-ac8a-249025419a3e, ignoreFailoverLimit = false, storageDomainId = ff559f46-c495-4f6b-901c-2a624042a050, imageGroupId = a75c1851-bddb-4339-bee2-f22b4b1268ac, imageId = f6d11460-fcd1-4b40-8e50-56a2ad6347a5), log id: 1ac00e9b
>2014-09-29 17:24:16,483 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (org.ovirt.thread.pool-8-thread-17) [f31a7d7] FINISH, GetImageInfoVDSCommand, return: org.ovirt.engine.core.common.businessentities.DiskImage@67e25c1, log id: 1ac00e9b
>2014-09-29 17:24:16,523 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-8-thread-17) Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: Snapshot 'Auto-generated for Live Storage Migration' creation for VM 'vm02' has been completed.
>2014-09-29 17:24:16,549 INFO  [org.ovirt.engine.core.bll.lsm.LiveMigrateVmDisksCommand] (org.ovirt.thread.pool-8-thread-17) Running command: LiveMigrateVmDisksCommand Task handler: LiveMigrateDisksTaskHandler internal: false. Entities affected :  ID: 51752c8f-bbe3-4754-866b-a0afd2a1f59d Type: StorageAction group CREATE_DISK with role type USER
>2014-09-29 17:24:16,585 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.FullListVdsCommand] (DefaultQuartzScheduler_Worker-1) START, FullListVdsCommand(HostName = voodoo1, HostId = 114c2cc6-5123-45bc-8900-5c875b0543c4, vds=Host[voodoo1,114c2cc6-5123-45bc-8900-5c875b0543c4], vmIds=[98e6058d-cf96-4929-b118-4fc5542a30ba]), log id: 1ba7a7bb
>2014-09-29 17:24:16,604 INFO  [org.ovirt.engine.core.bll.lsm.LiveMigrateDiskCommand] (org.ovirt.thread.pool-8-thread-17) [141d3551] Lock Acquired to object EngineLock [exclusiveLocks= , sharedLocks= key: 98e6058d-cf96-4929-b118-4fc5542a30ba value: VM
>]
>2014-09-29 17:24:16,608 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.FullListVdsCommand] (DefaultQuartzScheduler_Worker-1) FINISH, FullListVdsCommand, return: [{displaySecurePort=5901, kvmEnable=true, nicModel=rtl8139,pv, keyboardLayout=en-us, guestDiskMapping={}, displayIp=10.35.0.100, pauseCode=NOERR, pitReinjection=false, nice=0, displayNetwork=ovirtmgmt, copyPasteEnable=true, timeOffset=0, transparentHugePages=true, vmId=98e6058d-cf96-4929-b118-4fc5542a30ba, acpiEnable=true, custom={device_d2818bc2-2c12-4788-9d49-c385d7268081device_2fb999e9-19a6-4a3a-922a-51ecccc4d622=VmDevice {vmId=98e6058d-cf96-4929-b118-4fc5542a30ba, deviceId=2fb999e9-19a6-4a3a-922a-51ecccc4d622, device=unix, type=CHANNEL, bootOrder=0, specParams={}, address={port=1, bus=0, controller=0, type=virtio-serial}, managed=false, plugged=true, readOnly=false, deviceAlias=channel0, customProperties={}, snapshotId=null}, device_d2818bc2-2c12-4788-9d49-c385d7268081device_2fb999e9-19a6-4a3a-922a-51ecccc4d622device_34b9a4bc-f1b6-4c5e-9140-d49944ff28a0device_a0df18cb-58ac-40b2-bf7f-78761532029f=VmDevice {vmId=98e6058d-cf96-4929-b118-4fc5542a30ba, deviceId=a0df18cb-58ac-40b2-bf7f-78761532029f, device=spicevmc, type=CHANNEL, bootOrder=0, specParams={}, address={port=3, bus=0, controller=0, type=virtio-serial}, managed=false, plugged=true, readOnly=false, deviceAlias=channel2, customProperties={}, snapshotId=null}, device_d2818bc2-2c12-4788-9d49-c385d7268081=VmDevice {vmId=98e6058d-cf96-4929-b118-4fc5542a30ba, deviceId=d2818bc2-2c12-4788-9d49-c385d7268081, device=ide, type=CONTROLLER, bootOrder=0, specParams={}, address={bus=0x00, domain=0x0000, type=pci, slot=0x01, function=0x1}, managed=false, plugged=true, readOnly=false, deviceAlias=ide0, customProperties={}, snapshotId=null}, device_d2818bc2-2c12-4788-9d49-c385d7268081device_2fb999e9-19a6-4a3a-922a-51ecccc4d622device_34b9a4bc-f1b6-4c5e-9140-d49944ff28a0=VmDevice {vmId=98e6058d-cf96-4929-b118-4fc5542a30ba, deviceId=34b9a4bc-f1b6-4c5e-9140-d49944ff28a0, device=unix, type=CHANNEL, bootOrder=0, specParams={}, address={port=2, bus=0, controller=0, type=virtio-serial}, managed=false, plugged=true, readOnly=false, deviceAlias=channel1, customProperties={}, snapshotId=null}}, spiceSslCipherSuite=DEFAULT, memSize=1024, smp=1, displayPort=5900, emulatedMachine=rhel6.5.0, vmType=kvm, status=Up, memGuaranteedSize=512, display=qxl, pid=19499, smartcardEnable=false, bootMenuEnable=false, spiceSecureChannels=smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard, numaTune={mode=preferred}, smpCoresPerSocket=1, maxVCpus=16, clientIp=, devices=[Ljava.lang.Object;@298f2a23, vmName=vm02, fileTransferEnable=true, cpuType=Haswell}], log id: 1ba7a7bb
>2014-09-29 17:24:16,615 INFO  [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-1) Received a spice Device without an address when processing VM 98e6058d-cf96-4929-b118-4fc5542a30ba devices, skipping device: {port=5900, specParams={spiceSecureChannels=smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard, keyMap=en-us, displayNetwork=ovirtmgmt, copyPasteEnable=true, displayIp=10.35.0.100}, device=spice, tlsPort=5901, type=graphics}
>2014-09-29 17:24:16,622 INFO  [org.ovirt.engine.core.bll.lsm.LiveMigrateDiskCommand] (org.ovirt.thread.pool-8-thread-17) [141d3551] Running command: LiveMigrateDiskCommand Task handler: CreateImagePlaceholderTaskHandler internal: true. Entities affected :  ID: a75c1851-bddb-4339-bee2-f22b4b1268ac Type: DiskAction group CONFIGURE_DISK_STORAGE with role type USER,  ID: 51752c8f-bbe3-4754-866b-a0afd2a1f59d Type: StorageAction group CREATE_DISK with role type USER
>2014-09-29 17:24:16,672 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CloneImageGroupStructureVDSCommand] (org.ovirt.thread.pool-8-thread-17) [141d3551] START, CloneImageGroupStructureVDSCommand( storagePoolId = b86b687a-d073-497a-ac8a-249025419a3e, ignoreFailoverLimit = false, storageDomainId = ff559f46-c495-4f6b-901c-2a624042a050, imageGroupId = a75c1851-bddb-4339-bee2-f22b4b1268ac, dstDomainId = 51752c8f-bbe3-4754-866b-a0afd2a1f59d), log id: 35028d54
>2014-09-29 17:24:16,739 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.CloneImageGroupStructureVDSCommand] (org.ovirt.thread.pool-8-thread-17) [141d3551] FINISH, CloneImageGroupStructureVDSCommand, log id: 35028d54
>2014-09-29 17:24:16,747 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-17) [141d3551] CommandAsyncTask::Adding CommandMultiAsyncTasks object for command 86dc3612-6c7d-4c29-ad0e-0521cd68a92f
>2014-09-29 17:24:16,747 INFO  [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (org.ovirt.thread.pool-8-thread-17) [141d3551] CommandMultiAsyncTasks::AttachTask: Attaching task d73b8c67-48a4-40d6-b89f-be5776bf794b to command 86dc3612-6c7d-4c29-ad0e-0521cd68a92f.
>2014-09-29 17:24:16,771 INFO  [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (org.ovirt.thread.pool-8-thread-17) [141d3551] Adding task d73b8c67-48a4-40d6-b89f-be5776bf794b (Parent Command LiveMigrateDisk, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters), polling hasn't started yet..
>2014-09-29 17:24:16,805 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-8-thread-17) [141d3551] Correlation ID: 141d3551, Job ID: ac500afb-79af-4d4d-89e4-8074bd63b68c, Call Stack: null, Custom Event ID: -1, Message: User admin moving disk vm02_Disk1 to domain sasha-el7.
>2014-09-29 17:24:16,805 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (org.ovirt.thread.pool-8-thread-17) [141d3551] BaseAsyncTask::startPollingTask: Starting to poll task d73b8c67-48a4-40d6-b89f-be5776bf794b.
>2014-09-29 17:24:16,806 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (org.ovirt.thread.pool-8-thread-17) [141d3551] BaseAsyncTask::startPollingTask: Starting to poll task d73b8c67-48a4-40d6-b89f-be5776bf794b.
>2014-09-29 17:24:16,807 ERROR [org.ovirt.engine.core.bll.lsm.LiveMigrateVmDisksCommand] (org.ovirt.thread.pool-8-thread-17) [141d3551] Reverting task unknown, handler: org.ovirt.engine.core.bll.lsm.LiveSnapshotTaskHandler
>2014-09-29 17:24:16,808 INFO  [org.ovirt.engine.core.utils.transaction.TransactionSupport] (org.ovirt.thread.pool-8-thread-17) [141d3551] transaction rolled back
>2014-09-29 17:24:16,808 INFO  [org.ovirt.engine.core.bll.lsm.LiveMigrateVmDisksCommand] (org.ovirt.thread.pool-8-thread-17) [141d3551] Lock freed to object EngineLock [exclusiveLocks= key: a75c1851-bddb-4339-bee2-f22b4b1268ac value: DISK
>, sharedLocks= key: 98e6058d-cf96-4929-b118-4fc5542a30ba value: VM
>]
>2014-09-29 17:24:16,808 ERROR [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-17) [141d3551] [within thread]: endAction for action type LiveMigrateVmDisks threw an exception.: java.lang.NullPointerException
>	at org.ovirt.engine.core.bll.CommandBase.buildCommandEntity(CommandBase.java:2190) [bll.jar:]
>	at org.ovirt.engine.core.bll.CommandBase.setCommandExecuted(CommandBase.java:2235) [bll.jar:]
>	at org.ovirt.engine.core.bll.CommandBase.executeWithoutTransaction(CommandBase.java:1184) [bll.jar:]
>	at org.ovirt.engine.core.bll.CommandBase.executeActionInTransactionScope(CommandBase.java:1306) [bll.jar:]
>	at org.ovirt.engine.core.bll.CommandBase.runInTransaction(CommandBase.java:1931) [bll.jar:]
>	at org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInSuppressed(TransactionSupport.java:174) [utils.jar:]
>	at org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInScope(TransactionSupport.java:116) [utils.jar:]
>	at org.ovirt.engine.core.bll.CommandBase.execute(CommandBase.java:1330) [bll.jar:]
>	at org.ovirt.engine.core.bll.CommandBase.internalEndSuccessfully(CommandBase.java:614) [bll.jar:]
>	at org.ovirt.engine.core.bll.CommandBase.endActionInTransactionScope(CommandBase.java:562) [bll.jar:]
>	at org.ovirt.engine.core.bll.CommandBase.runInTransaction(CommandBase.java:1933) [bll.jar:]
>	at org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInNewTransaction(TransactionSupport.java:210) [utils.jar:]
>	at org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInRequired(TransactionSupport.java:149) [utils.jar:]
>	at org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInScope(TransactionSupport.java:118) [utils.jar:]
>	at org.ovirt.engine.core.bll.CommandBase.endAction(CommandBase.java:493) [bll.jar:]
>	at org.ovirt.engine.core.bll.lsm.LiveMigrateVmDisksCommand.endAction(LiveMigrateVmDisksCommand.java:97) [bll.jar:]
>	at org.ovirt.engine.core.bll.tasks.DecoratedCommand.endAction(DecoratedCommand.java:17) [bll.jar:]
>	at org.ovirt.engine.core.bll.tasks.CoCoAsyncTaskHelper.endAction(CoCoAsyncTaskHelper.java:335) [bll.jar:]
>	at org.ovirt.engine.core.bll.tasks.CommandCoordinatorImpl.endAction(CommandCoordinatorImpl.java:383) [bll.jar:]
>	at org.ovirt.engine.core.bll.tasks.CommandAsyncTask.endCommandAction(CommandAsyncTask.java:149) [bll.jar:]
>	at org.ovirt.engine.core.bll.tasks.CommandAsyncTask.access$000(CommandAsyncTask.java:28) [bll.jar:]
>	at org.ovirt.engine.core.bll.tasks.CommandAsyncTask$1.run(CommandAsyncTask.java:109) [bll.jar:]
>	at org.ovirt.engine.core.utils.threadpool.ThreadPoolUtil$InternalWrapperRunnable.run(ThreadPoolUtil.java:90) [utils.jar:]
>	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) [rt.jar:1.7.0_65]
>	at java.util.concurrent.FutureTask.run(FutureTask.java:262) [rt.jar:1.7.0_65]
>	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [rt.jar:1.7.0_65]
>	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [rt.jar:1.7.0_65]
>	at java.lang.Thread.run(Thread.java:745) [rt.jar:1.7.0_65]
>
>2014-09-29 17:24:16,812 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-17) [141d3551] CommandAsyncTask::HandleEndActionResult: endAction for action type LiveMigrateVmDisks threw an unrecoverable RuntimeException the task will be cleared.
>2014-09-29 17:24:16,821 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (org.ovirt.thread.pool-8-thread-17) [141d3551] BaseAsyncTask::removeTaskFromDB: Removed task 186121fa-8604-462b-a8d3-c09adf830775 from DataBase
>2014-09-29 17:24:16,822 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-17) [141d3551] CommandAsyncTask::HandleEndActionRuntimeException: Removing CommandMultiAsyncTasks object for entity 10c9c0f3-b697-4203-8718-ac705b8d43eb
>2014-09-29 17:24:25,603 INFO  [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (DefaultQuartzScheduler_Worker-89) Polling and updating Async Tasks: 9 tasks, 1 tasks to poll now
>2014-09-29 17:24:25,620 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-89) SPMAsyncTask::PollTask: Polling task d73b8c67-48a4-40d6-b89f-be5776bf794b (Parent Command LiveMigrateDisk, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) returned status running.
>2014-09-29 17:24:25,620 INFO  [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (DefaultQuartzScheduler_Worker-89) Finished polling Tasks, will poll again in 10 seconds.
>2014-09-29 17:24:35,634 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-37) [1120373] SPMAsyncTask::PollTask: Polling task d73b8c67-48a4-40d6-b89f-be5776bf794b (Parent Command LiveMigrateDisk, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) returned status finished, result 'success'.
>2014-09-29 17:24:35,657 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-37) [1120373] BaseAsyncTask::onTaskEndSuccess: Task d73b8c67-48a4-40d6-b89f-be5776bf794b (Parent Command LiveMigrateDisk, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) ended successfully.
>2014-09-29 17:24:35,658 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (DefaultQuartzScheduler_Worker-37) [1120373] CommandAsyncTask::endActionIfNecessary: All tasks of command 86dc3612-6c7d-4c29-ad0e-0521cd68a92f has ended -> executing endAction
>2014-09-29 17:24:35,658 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (DefaultQuartzScheduler_Worker-37) [1120373] CommandAsyncTask::endAction: Ending action for 1 tasks (command ID: 86dc3612-6c7d-4c29-ad0e-0521cd68a92f): calling endAction .
>2014-09-29 17:24:35,659 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-2) [1120373] CommandAsyncTask::endCommandAction [within thread] context: Attempting to endAction LiveMigrateDisk, executionIndex: 0
>2014-09-29 17:24:35,682 INFO  [org.ovirt.engine.core.bll.lsm.LiveMigrateDiskCommand] (org.ovirt.thread.pool-8-thread-2) [141d3551] Ending command successfully: org.ovirt.engine.core.bll.lsm.LiveMigrateDiskCommand
>2014-09-29 17:24:35,690 INFO  [org.ovirt.engine.core.bll.lsm.LiveMigrateDiskCommand] (org.ovirt.thread.pool-8-thread-2) [141d3551] Running command: LiveMigrateDiskCommand Task handler: VmReplicateDiskStartTaskHandler internal: false. Entities affected :  ID: a75c1851-bddb-4339-bee2-f22b4b1268ac Type: DiskAction group CONFIGURE_DISK_STORAGE with role type USER,  ID: 51752c8f-bbe3-4754-866b-a0afd2a1f59d Type: StorageAction group CREATE_DISK with role type USER
>2014-09-29 17:24:35,693 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.VmReplicateDiskStartVDSCommand] (org.ovirt.thread.pool-8-thread-2) [141d3551] START, VmReplicateDiskStartVDSCommand(HostName = voodoo1, HostId = 114c2cc6-5123-45bc-8900-5c875b0543c4, vmId=98e6058d-cf96-4929-b118-4fc5542a30ba), log id: 7be93548
>2014-09-29 17:24:36,235 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.VmReplicateDiskStartVDSCommand] (org.ovirt.thread.pool-8-thread-2) [141d3551] FINISH, VmReplicateDiskStartVDSCommand, log id: 7be93548
>2014-09-29 17:24:36,328 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SyncImageGroupDataVDSCommand] (org.ovirt.thread.pool-8-thread-2) [141d3551] START, SyncImageGroupDataVDSCommand( storagePoolId = b86b687a-d073-497a-ac8a-249025419a3e, ignoreFailoverLimit = false, storageDomainId = ff559f46-c495-4f6b-901c-2a624042a050, imageGroupId = a75c1851-bddb-4339-bee2-f22b4b1268ac, dstDomainId = 51752c8f-bbe3-4754-866b-a0afd2a1f59d, syncType=INTERNAL), log id: 7c7cbdaa
>2014-09-29 17:24:36,383 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SyncImageGroupDataVDSCommand] (org.ovirt.thread.pool-8-thread-2) [141d3551] FINISH, SyncImageGroupDataVDSCommand, log id: 7c7cbdaa
>2014-09-29 17:24:36,395 INFO  [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (org.ovirt.thread.pool-8-thread-2) [141d3551] CommandMultiAsyncTasks::AttachTask: Attaching task 0dc68bba-1b9b-4f5f-8811-ba9db222b633 to command 86dc3612-6c7d-4c29-ad0e-0521cd68a92f.
>2014-09-29 17:24:36,410 INFO  [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (org.ovirt.thread.pool-8-thread-2) [141d3551] Adding task 0dc68bba-1b9b-4f5f-8811-ba9db222b633 (Parent Command LiveMigrateDisk, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters), polling hasn't started yet..
>2014-09-29 17:24:36,458 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-8-thread-2) [141d3551] Correlation ID: 141d3551, Call Stack: null, Custom Event ID: -1, Message: Unrecognized audit log type has been used.
>2014-09-29 17:24:36,459 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (org.ovirt.thread.pool-8-thread-2) [141d3551] BaseAsyncTask::startPollingTask: Starting to poll task 0dc68bba-1b9b-4f5f-8811-ba9db222b633.
>2014-09-29 17:24:36,466 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-8-thread-2) [141d3551] Correlation ID: 141d3551, Call Stack: null, Custom Event ID: -1, Message: Unrecognized audit log type has been used.
>2014-09-29 17:24:36,467 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-2) [141d3551] CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type LiveMigrateDisk completed, handling the result.
>2014-09-29 17:24:36,468 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-2) [141d3551] CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type LiveMigrateDisk succeeded, clearing tasks.
>2014-09-29 17:24:36,469 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (org.ovirt.thread.pool-8-thread-2) [141d3551] SPMAsyncTask::ClearAsyncTask: Attempting to clear task d73b8c67-48a4-40d6-b89f-be5776bf794b
>2014-09-29 17:24:36,469 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-2) [141d3551] START, SPMClearTaskVDSCommand( storagePoolId = b86b687a-d073-497a-ac8a-249025419a3e, ignoreFailoverLimit = false, taskId = d73b8c67-48a4-40d6-b89f-be5776bf794b), log id: 6e7aedfc
>2014-09-29 17:24:36,472 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-2) [141d3551] START, HSMClearTaskVDSCommand(HostName = voodoo6, HostId = 45462850-a02c-4eeb-8527-292e15e5cb54, taskId=d73b8c67-48a4-40d6-b89f-be5776bf794b), log id: 489e740e
>2014-09-29 17:24:36,494 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-2) [141d3551] FINISH, HSMClearTaskVDSCommand, log id: 489e740e
>2014-09-29 17:24:36,495 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-2) [141d3551] FINISH, SPMClearTaskVDSCommand, log id: 6e7aedfc
>2014-09-29 17:24:36,508 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (org.ovirt.thread.pool-8-thread-2) [141d3551] BaseAsyncTask::removeTaskFromDB: Removed task d73b8c67-48a4-40d6-b89f-be5776bf794b from DataBase
>2014-09-29 17:24:36,509 INFO  [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (org.ovirt.thread.pool-8-thread-2) [141d3551] [within thread]: Some of the tasks related to command id 86dc3612-6c7d-4c29-ad0e-0521cd68a92f were not cleared yet (Task id 0dc68bba-1b9b-4f5f-8811-ba9db222b633 is in state Polling).
>2014-09-29 17:24:45,659 INFO  [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (DefaultQuartzScheduler_Worker-5) Polling and updating Async Tasks: 10 tasks, 1 tasks to poll now
>2014-09-29 17:24:45,675 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-5) SPMAsyncTask::PollTask: Polling task 0dc68bba-1b9b-4f5f-8811-ba9db222b633 (Parent Command LiveMigrateDisk, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) returned status running.
>2014-09-29 17:24:45,676 INFO  [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (DefaultQuartzScheduler_Worker-5) Finished polling Tasks, will poll again in 10 seconds.
>2014-09-29 17:25:53,926 INFO  [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (DefaultQuartzScheduler_Worker-34) Setting new tasks map. The map contains now 9 tasks
>2014-09-29 17:25:56,620 INFO  [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (DefaultQuartzScheduler_Worker-44) Polling and updating Async Tasks: 9 tasks, 1 tasks to poll now
>2014-09-29 17:25:56,768 INFO  [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (DefaultQuartzScheduler_Worker-44) Finished polling Tasks, will poll again in 10 seconds.
>2014-09-29 17:27:07,954 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-72) SPMAsyncTask::PollTask: Polling task 0dc68bba-1b9b-4f5f-8811-ba9db222b633 (Parent Command LiveMigrateDisk, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) returned status finished, result 'success'.
>2014-09-29 17:27:07,965 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-72) BaseAsyncTask::onTaskEndSuccess: Task 0dc68bba-1b9b-4f5f-8811-ba9db222b633 (Parent Command LiveMigrateDisk, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) ended successfully.
>2014-09-29 17:27:07,967 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (DefaultQuartzScheduler_Worker-72) CommandAsyncTask::endActionIfNecessary: All tasks of command 86dc3612-6c7d-4c29-ad0e-0521cd68a92f has ended -> executing endAction
>2014-09-29 17:27:07,968 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (DefaultQuartzScheduler_Worker-72) CommandAsyncTask::endAction: Ending action for 1 tasks (command ID: 86dc3612-6c7d-4c29-ad0e-0521cd68a92f): calling endAction .
>2014-09-29 17:27:07,969 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-45) CommandAsyncTask::endCommandAction [within thread] context: Attempting to endAction LiveMigrateDisk, executionIndex: 1
>2014-09-29 17:27:07,992 INFO  [org.ovirt.engine.core.bll.lsm.LiveMigrateDiskCommand] (org.ovirt.thread.pool-8-thread-45) [141d3551] Ending command successfully: org.ovirt.engine.core.bll.lsm.LiveMigrateDiskCommand
>2014-09-29 17:27:07,992 INFO  [org.ovirt.engine.core.bll.lsm.LiveMigrateDiskCommand] (org.ovirt.thread.pool-8-thread-45) [141d3551] Running command: LiveMigrateDiskCommand Task handler: VmReplicateDiskFinishTaskHandler internal: false. Entities affected :  ID: a75c1851-bddb-4339-bee2-f22b4b1268ac Type: DiskAction group CONFIGURE_DISK_STORAGE with role type USER,  ID: 51752c8f-bbe3-4754-866b-a0afd2a1f59d Type: StorageAction group CREATE_DISK with role type USER
>2014-09-29 17:27:08,016 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.VmReplicateDiskFinishVDSCommand] (org.ovirt.thread.pool-8-thread-45) [141d3551] START, VmReplicateDiskFinishVDSCommand(HostName = voodoo1, HostId = 114c2cc6-5123-45bc-8900-5c875b0543c4, vmId=98e6058d-cf96-4929-b118-4fc5542a30ba), log id: 15b0b9bd
>2014-09-29 17:27:10,431 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.VmReplicateDiskFinishVDSCommand] (org.ovirt.thread.pool-8-thread-45) [141d3551] FINISH, VmReplicateDiskFinishVDSCommand, log id: 15b0b9bd
>2014-09-29 17:27:10,439 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (org.ovirt.thread.pool-8-thread-45) [141d3551] START, GetImageInfoVDSCommand( storagePoolId = b86b687a-d073-497a-ac8a-249025419a3e, ignoreFailoverLimit = false, storageDomainId = 51752c8f-bbe3-4754-866b-a0afd2a1f59d, imageGroupId = a75c1851-bddb-4339-bee2-f22b4b1268ac, imageId = f6d11460-fcd1-4b40-8e50-56a2ad6347a5), log id: 685e3c42
>2014-09-29 17:27:11,768 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (org.ovirt.thread.pool-8-thread-45) [141d3551] FINISH, GetImageInfoVDSCommand, return: org.ovirt.engine.core.common.businessentities.DiskImage@3d17a08b, log id: 685e3c42
>2014-09-29 17:27:11,801 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (org.ovirt.thread.pool-8-thread-45) [141d3551] START, GetImageInfoVDSCommand( storagePoolId = b86b687a-d073-497a-ac8a-249025419a3e, ignoreFailoverLimit = false, storageDomainId = 51752c8f-bbe3-4754-866b-a0afd2a1f59d, imageGroupId = a75c1851-bddb-4339-bee2-f22b4b1268ac, imageId = 9d74263f-76a8-4c33-94f7-454e06934207), log id: 18bc6a6c
>2014-09-29 17:27:11,828 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.GetImageInfoVDSCommand] (org.ovirt.thread.pool-8-thread-45) [141d3551] FINISH, GetImageInfoVDSCommand, return: org.ovirt.engine.core.common.businessentities.DiskImage@e3f446e8, log id: 18bc6a6c
>2014-09-29 17:27:11,874 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] (org.ovirt.thread.pool-8-thread-45) [141d3551] START, DeleteImageGroupVDSCommand( storagePoolId = b86b687a-d073-497a-ac8a-249025419a3e, ignoreFailoverLimit = false, storageDomainId = ff559f46-c495-4f6b-901c-2a624042a050, imageGroupId = a75c1851-bddb-4339-bee2-f22b4b1268ac, postZeros = false, forceDelete = false), log id: 73d99cc4
>2014-09-29 17:27:13,264 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] (org.ovirt.thread.pool-8-thread-45) [141d3551] FINISH, DeleteImageGroupVDSCommand, log id: 73d99cc4
>2014-09-29 17:27:13,301 INFO  [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (org.ovirt.thread.pool-8-thread-45) [141d3551] CommandMultiAsyncTasks::AttachTask: Attaching task 0834bf39-9cb1-4d9c-a82d-54e2db8abb0a to command 86dc3612-6c7d-4c29-ad0e-0521cd68a92f.
>2014-09-29 17:27:13,324 INFO  [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (org.ovirt.thread.pool-8-thread-45) [141d3551] Adding task 0834bf39-9cb1-4d9c-a82d-54e2db8abb0a (Parent Command LiveMigrateDisk, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters), polling hasn't started yet..
>2014-09-29 17:27:13,374 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-8-thread-45) [141d3551] Correlation ID: 141d3551, Call Stack: null, Custom Event ID: -1, Message: Unrecognized audit log type has been used.
>2014-09-29 17:27:13,375 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (org.ovirt.thread.pool-8-thread-45) [141d3551] BaseAsyncTask::startPollingTask: Starting to poll task 0834bf39-9cb1-4d9c-a82d-54e2db8abb0a.
>2014-09-29 17:27:13,382 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-8-thread-45) [141d3551] Correlation ID: 141d3551, Call Stack: null, Custom Event ID: -1, Message: Unrecognized audit log type has been used.
>2014-09-29 17:27:13,383 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-45) [141d3551] CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type LiveMigrateDisk completed, handling the result.
>2014-09-29 17:27:13,384 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-45) [141d3551] CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type LiveMigrateDisk succeeded, clearing tasks.
>2014-09-29 17:27:13,385 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (org.ovirt.thread.pool-8-thread-45) [141d3551] SPMAsyncTask::ClearAsyncTask: Attempting to clear task 0dc68bba-1b9b-4f5f-8811-ba9db222b633
>2014-09-29 17:27:13,386 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-45) [141d3551] START, SPMClearTaskVDSCommand( storagePoolId = b86b687a-d073-497a-ac8a-249025419a3e, ignoreFailoverLimit = false, taskId = 0dc68bba-1b9b-4f5f-8811-ba9db222b633), log id: 5e317eaa
>2014-09-29 17:27:13,387 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-45) [141d3551] START, HSMClearTaskVDSCommand(HostName = voodoo6, HostId = 45462850-a02c-4eeb-8527-292e15e5cb54, taskId=0dc68bba-1b9b-4f5f-8811-ba9db222b633), log id: 372fb36
>2014-09-29 17:27:13,406 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-45) [141d3551] FINISH, HSMClearTaskVDSCommand, log id: 372fb36
>2014-09-29 17:27:13,407 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-45) [141d3551] FINISH, SPMClearTaskVDSCommand, log id: 5e317eaa
>2014-09-29 17:27:13,415 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (org.ovirt.thread.pool-8-thread-45) [141d3551] BaseAsyncTask::removeTaskFromDB: Removed task 0dc68bba-1b9b-4f5f-8811-ba9db222b633 from DataBase
>2014-09-29 17:27:13,416 INFO  [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (org.ovirt.thread.pool-8-thread-45) [141d3551] [within thread]: Some of the tasks related to command id 86dc3612-6c7d-4c29-ad0e-0521cd68a92f were not cleared yet (Task id 0834bf39-9cb1-4d9c-a82d-54e2db8abb0a is in state Polling).
>2014-09-29 17:27:17,970 INFO  [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (DefaultQuartzScheduler_Worker-67) [c05df18] Polling and updating Async Tasks: 10 tasks, 1 tasks to poll now
>2014-09-29 17:27:18,416 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-67) [c05df18] SPMAsyncTask::PollTask: Polling task 0834bf39-9cb1-4d9c-a82d-54e2db8abb0a (Parent Command LiveMigrateDisk, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) returned status finished, result 'success'.
>2014-09-29 17:27:18,427 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler_Worker-67) [c05df18] BaseAsyncTask::onTaskEndSuccess: Task 0834bf39-9cb1-4d9c-a82d-54e2db8abb0a (Parent Command LiveMigrateDisk, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) ended successfully.
>2014-09-29 17:27:18,428 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (DefaultQuartzScheduler_Worker-67) [c05df18] CommandAsyncTask::endActionIfNecessary: All tasks of command 86dc3612-6c7d-4c29-ad0e-0521cd68a92f has ended -> executing endAction
>2014-09-29 17:27:18,429 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (DefaultQuartzScheduler_Worker-67) [c05df18] CommandAsyncTask::endAction: Ending action for 1 tasks (command ID: 86dc3612-6c7d-4c29-ad0e-0521cd68a92f): calling endAction .
>2014-09-29 17:27:18,430 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-6) [c05df18] CommandAsyncTask::endCommandAction [within thread] context: Attempting to endAction LiveMigrateDisk, executionIndex: 2
>2014-09-29 17:27:18,463 INFO  [org.ovirt.engine.core.bll.lsm.LiveMigrateDiskCommand] (org.ovirt.thread.pool-8-thread-6) [141d3551] Ending command successfully: org.ovirt.engine.core.bll.lsm.LiveMigrateDiskCommand
>2014-09-29 17:27:18,464 INFO  [org.ovirt.engine.core.bll.lsm.LiveMigrateDiskCommand] (org.ovirt.thread.pool-8-thread-6) [141d3551] Lock freed to object EngineLock [exclusiveLocks= , sharedLocks= key: 98e6058d-cf96-4929-b118-4fc5542a30ba value: VM
>]
>2014-09-29 17:27:18,485 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-8-thread-6) [141d3551] Correlation ID: 141d3551, Call Stack: null, Custom Event ID: -1, Message: User admin finished moving disk vm02_Disk1 to domain sasha-el7.
>2014-09-29 17:27:18,485 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-6) [141d3551] CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type LiveMigrateDisk completed, handling the result.
>2014-09-29 17:27:18,486 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-6) [141d3551] CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type LiveMigrateDisk succeeded, clearing tasks.
>2014-09-29 17:27:18,493 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (org.ovirt.thread.pool-8-thread-6) [141d3551] SPMAsyncTask::ClearAsyncTask: Attempting to clear task 0834bf39-9cb1-4d9c-a82d-54e2db8abb0a
>2014-09-29 17:27:18,494 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-6) [141d3551] START, SPMClearTaskVDSCommand( storagePoolId = b86b687a-d073-497a-ac8a-249025419a3e, ignoreFailoverLimit = false, taskId = 0834bf39-9cb1-4d9c-a82d-54e2db8abb0a), log id: 4013d39c
>2014-09-29 17:27:18,496 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-6) [141d3551] START, HSMClearTaskVDSCommand(HostName = voodoo6, HostId = 45462850-a02c-4eeb-8527-292e15e5cb54, taskId=0834bf39-9cb1-4d9c-a82d-54e2db8abb0a), log id: 55a9c7a1
>2014-09-29 17:27:18,514 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-6) [141d3551] FINISH, HSMClearTaskVDSCommand, log id: 55a9c7a1
>2014-09-29 17:27:18,514 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.SPMClearTaskVDSCommand] (org.ovirt.thread.pool-8-thread-6) [141d3551] FINISH, SPMClearTaskVDSCommand, log id: 4013d39c
>2014-09-29 17:27:18,526 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (org.ovirt.thread.pool-8-thread-6) [141d3551] BaseAsyncTask::removeTaskFromDB: Removed task 0834bf39-9cb1-4d9c-a82d-54e2db8abb0a from DataBase
>2014-09-29 17:27:18,527 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-8-thread-6) [141d3551] CommandAsyncTask::HandleEndActionResult [within thread]: Removing CommandMultiAsyncTasks object for entity 86dc3612-6c7d-4c29-ad0e-0521cd68a92f
>2014-09-29 17:27:20,859 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.FullListVdsCommand] (DefaultQuartzScheduler_Worker-84) [3956bf8d] START, FullListVdsCommand(HostName = voodoo1, HostId = 114c2cc6-5123-45bc-8900-5c875b0543c4, vds=Host[voodoo1,114c2cc6-5123-45bc-8900-5c875b0543c4], vmIds=[98e6058d-cf96-4929-b118-4fc5542a30ba]), log id: 7c056cc1
>2014-09-29 17:27:20,877 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.FullListVdsCommand] (DefaultQuartzScheduler_Worker-84) [3956bf8d] FINISH, FullListVdsCommand, return: [{displaySecurePort=5901, kvmEnable=true, nicModel=rtl8139,pv, keyboardLayout=en-us, guestDiskMapping={}, displayIp=10.35.0.100, pitReinjection=false, nice=0, displayNetwork=ovirtmgmt, copyPasteEnable=true, timeOffset=0, transparentHugePages=true, vmId=98e6058d-cf96-4929-b118-4fc5542a30ba, acpiEnable=true, custom={device_d2818bc2-2c12-4788-9d49-c385d7268081device_2fb999e9-19a6-4a3a-922a-51ecccc4d622=VmDevice {vmId=98e6058d-cf96-4929-b118-4fc5542a30ba, deviceId=2fb999e9-19a6-4a3a-922a-51ecccc4d622, device=unix, type=CHANNEL, bootOrder=0, specParams={}, address={port=1, bus=0, controller=0, type=virtio-serial}, managed=false, plugged=true, readOnly=false, deviceAlias=channel0, customProperties={}, snapshotId=null}, device_d2818bc2-2c12-4788-9d49-c385d7268081device_2fb999e9-19a6-4a3a-922a-51ecccc4d622device_34b9a4bc-f1b6-4c5e-9140-d49944ff28a0device_a0df18cb-58ac-40b2-bf7f-78761532029f=VmDevice {vmId=98e6058d-cf96-4929-b118-4fc5542a30ba, deviceId=a0df18cb-58ac-40b2-bf7f-78761532029f, device=spicevmc, type=CHANNEL, bootOrder=0, specParams={}, address={port=3, bus=0, controller=0, type=virtio-serial}, managed=false, plugged=true, readOnly=false, deviceAlias=channel2, customProperties={}, snapshotId=null}, device_d2818bc2-2c12-4788-9d49-c385d7268081=VmDevice {vmId=98e6058d-cf96-4929-b118-4fc5542a30ba, deviceId=d2818bc2-2c12-4788-9d49-c385d7268081, device=ide, type=CONTROLLER, bootOrder=0, specParams={}, address={bus=0x00, domain=0x0000, type=pci, slot=0x01, function=0x1}, managed=false, plugged=true, readOnly=false, deviceAlias=ide0, customProperties={}, snapshotId=null}, device_d2818bc2-2c12-4788-9d49-c385d7268081device_2fb999e9-19a6-4a3a-922a-51ecccc4d622device_34b9a4bc-f1b6-4c5e-9140-d49944ff28a0=VmDevice {vmId=98e6058d-cf96-4929-b118-4fc5542a30ba, deviceId=34b9a4bc-f1b6-4c5e-9140-d49944ff28a0, device=unix, type=CHANNEL, bootOrder=0, specParams={}, address={port=2, bus=0, controller=0, type=virtio-serial}, managed=false, plugged=true, readOnly=false, deviceAlias=channel1, customProperties={}, snapshotId=null}}, spiceSslCipherSuite=DEFAULT, memSize=1024, smp=1, displayPort=5900, vmType=kvm, emulatedMachine=rhel6.5.0, status=Up, memGuaranteedSize=512, display=qxl, pid=19499, smartcardEnable=false, bootMenuEnable=false, spiceSecureChannels=smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard, numaTune={mode=preferred}, smpCoresPerSocket=1, maxVCpus=16, clientIp=, devices=[Ljava.lang.Object;@48273283, vmName=vm02, fileTransferEnable=true, cpuType=Haswell}], log id: 7c056cc1
>2014-09-29 17:27:20,881 INFO  [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-84) [3956bf8d] Received a spice Device without an address when processing VM 98e6058d-cf96-4929-b118-4fc5542a30ba devices, skipping device: {port=5900, specParams={spiceSecureChannels=smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard, keyMap=en-us, displayNetwork=ovirtmgmt, copyPasteEnable=true, displayIp=10.35.0.100}, device=spice, tlsPort=5901, type=graphics}
>2014-09-29 17:28:23,928 INFO  [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (DefaultQuartzScheduler_Worker-20) Setting new tasks map. The map contains now 8 tasks
>2014-09-29 17:31:11,007 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStatusVDSCommand] (DefaultQuartzScheduler_Worker-32) Command SpmStatusVDSCommand(HostName = voodoo6, HostId = 45462850-a02c-4eeb-8527-292e15e5cb54, storagePoolId = b86b687a-d073-497a-ac8a-249025419a3e) execution failed. Exception: VDSNetworkException: java.net.UnknownHostException: voodoo6.tlv.redhat.com
>2014-09-29 17:31:11,009 INFO  [org.ovirt.engine.core.bll.storage.SetStoragePoolStatusCommand] (DefaultQuartzScheduler_Worker-32) [1b1e6dfc] Running command: SetStoragePoolStatusCommand internal: true. Entities affected :  ID: b86b687a-d073-497a-ac8a-249025419a3e Type: StoragePool
>2014-09-29 17:31:11,011 INFO  [org.ovirt.engine.core.vdsbroker.storage.StoragePoolDomainHelper] (DefaultQuartzScheduler_Worker-32) [1b1e6dfc] Storage Pool b86b687a-d073-497a-ac8a-249025419a3e - Updating Storage Domain ff559f46-c495-4f6b-901c-2a624042a050 status from Active to Unknown, reason : null
>2014-09-29 17:31:11,013 INFO  [org.ovirt.engine.core.vdsbroker.storage.StoragePoolDomainHelper] (DefaultQuartzScheduler_Worker-32) [1b1e6dfc] Storage Pool b86b687a-d073-497a-ac8a-249025419a3e - Updating Storage Domain 51752c8f-bbe3-4754-866b-a0afd2a1f59d status from Active to Unknown, reason : null
>2014-09-29 17:31:11,256 WARN  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-32) [1b1e6dfc] Correlation ID: 1b1e6dfc, Call Stack: null, Custom Event ID: -1, Message: Invalid status on Data Center iscsi-el7. Setting Data Center status to Non Responsive (On host voodoo6, Error: Network error during communication with the Host.).
>2014-09-29 17:34:17,270 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.GetStatsVDSCommand] (DefaultQuartzScheduler_Worker-76) [297c555e] Command GetStatsVDSCommand(HostName = voodoo1, HostId = 114c2cc6-5123-45bc-8900-5c875b0543c4, vds=Host[voodoo1,114c2cc6-5123-45bc-8900-5c875b0543c4]) execution failed. Exception: VDSNetworkException: java.util.concurrent.TimeoutException
>2014-09-29 17:34:17,275 WARN  [org.ovirt.engine.core.vdsbroker.VdsManager] (DefaultQuartzScheduler_Worker-76) [297c555e] Host voodoo1 is not responding. It will stay in Connecting state for a grace period of 60 seconds and after that an attempt to fence the host will be issued.
>2014-09-29 17:34:17,294 WARN  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-76) [297c555e] Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: Host voodoo1 is not responding. It will stay in Connecting state for a grace period of 60 seconds and after that an attempt to fence the host will be issued.
>2014-09-29 17:34:17,295 ERROR [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-76) [297c555e] vds::refreshVdsStats Failed getVdsStats,  vds = 114c2cc6-5123-45bc-8900-5c875b0543c4 : voodoo1, error = VDSNetworkException: java.util.concurrent.TimeoutException
>2014-09-29 17:34:17,296 ERROR [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-76) [297c555e] Failure to refresh Vds runtime info: org.ovirt.engine.core.vdsbroker.vdsbroker.VDSNetworkException: java.util.concurrent.TimeoutException
>	at org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerCommand.createNetworkException(VdsBrokerCommand.java:126) [vdsbroker.jar:]
>	at org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerCommand.executeVDSCommand(VdsBrokerCommand.java:101) [vdsbroker.jar:]
>	at org.ovirt.engine.core.vdsbroker.VDSCommandBase.executeCommand(VDSCommandBase.java:56) [vdsbroker.jar:]
>	at org.ovirt.engine.core.dal.VdcCommandBase.execute(VdcCommandBase.java:31) [dal.jar:]
>	at org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo.refreshVdsStats(VdsUpdateRunTimeInfo.java:680) [vdsbroker.jar:]
>	at org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo.refreshVdsRunTimeInfo(VdsUpdateRunTimeInfo.java:634) [vdsbroker.jar:]
>	at org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo.refresh(VdsUpdateRunTimeInfo.java:486) [vdsbroker.jar:]
>	at org.ovirt.engine.core.vdsbroker.VdsManager.onTimer(VdsManager.java:236) [vdsbroker.jar:]
>	at sun.reflect.GeneratedMethodAccessor6.invoke(Unknown Source) [:1.7.0_65]
>	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.7.0_65]
>	at java.lang.reflect.Method.invoke(Method.java:606) [rt.jar:1.7.0_65]
>	at org.ovirt.engine.core.utils.timer.JobWrapper.execute(JobWrapper.java:60) [scheduler.jar:]
>	at org.quartz.core.JobRunShell.run(JobRunShell.java:213) [quartz.jar:]
>	at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:557) [quartz.jar:]
>Caused by: java.util.concurrent.TimeoutException
>	at java.util.concurrent.FutureTask.get(FutureTask.java:201) [rt.jar:1.7.0_65]
>	at org.ovirt.engine.core.vdsbroker.xmlrpc.XmlRpcUtils$AsyncProxy.invoke(XmlRpcUtils.java:200) [vdsbroker.jar:]
>	at com.sun.proxy.$Proxy88.getVdsStats(Unknown Source)
>	at org.ovirt.engine.core.vdsbroker.vdsbroker.VdsServerWrapper.getVdsStats(VdsServerWrapper.java:174) [vdsbroker.jar:]
>	at org.ovirt.engine.core.vdsbroker.vdsbroker.GetStatsVDSCommand.executeVdsBrokerCommand(GetStatsVDSCommand.java:23) [vdsbroker.jar:]
>	at org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerCommand.executeVDSCommand(VdsBrokerCommand.java:96) [vdsbroker.jar:]
>	... 12 more
>
>2014-09-29 17:34:17,312 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.ListVDSCommand] (DefaultQuartzScheduler_Worker-25) [54f6689a] Command ListVDSCommand(HostName = voodoo6, HostId = 45462850-a02c-4eeb-8527-292e15e5cb54, vds=Host[voodoo6,45462850-a02c-4eeb-8527-292e15e5cb54]) execution failed. Exception: VDSNetworkException: java.util.concurrent.TimeoutException
>2014-09-29 17:34:17,313 WARN  [org.ovirt.engine.core.vdsbroker.VdsManager] (DefaultQuartzScheduler_Worker-25) [54f6689a] Host voodoo6 is not responding. It will stay in Connecting state for a grace period of 80 seconds and after that an attempt to fence the host will be issued.
>2014-09-29 17:34:17,320 WARN  [org.ovirt.engine.core.vdsbroker.VdsManager] (DefaultQuartzScheduler_Worker-76) [297c555e] Failed to refresh VDS , vds = 114c2cc6-5123-45bc-8900-5c875b0543c4 : voodoo1, VDS Network Error, continuing.
>java.util.concurrent.TimeoutException
>2014-09-29 17:34:17,327 WARN  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-25) [54f6689a] Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: Host voodoo6 is not responding. It will stay in Connecting state for a grace period of 80 seconds and after that an attempt to fence the host will be issued.
>2014-09-29 17:34:17,328 ERROR [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-25) [54f6689a] Failure to refresh Vds runtime info: org.ovirt.engine.core.vdsbroker.vdsbroker.VDSNetworkException: java.util.concurrent.TimeoutException
>	at org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerCommand.createNetworkException(VdsBrokerCommand.java:126) [vdsbroker.jar:]
>	at org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerCommand.executeVDSCommand(VdsBrokerCommand.java:101) [vdsbroker.jar:]
>	at org.ovirt.engine.core.vdsbroker.VDSCommandBase.executeCommand(VDSCommandBase.java:56) [vdsbroker.jar:]
>	at org.ovirt.engine.core.dal.VdcCommandBase.execute(VdcCommandBase.java:31) [dal.jar:]
>	at org.ovirt.engine.core.vdsbroker.ResourceManager.runVdsCommand(ResourceManager.java:413) [vdsbroker.jar:]
>	at org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo.fetchRunningVms(VdsUpdateRunTimeInfo.java:982) [vdsbroker.jar:]
>	at org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo.refreshVmStats(VdsUpdateRunTimeInfo.java:931) [vdsbroker.jar:]
>	at org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo.refreshVdsRunTimeInfo(VdsUpdateRunTimeInfo.java:649) [vdsbroker.jar:]
>	at org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo.refresh(VdsUpdateRunTimeInfo.java:486) [vdsbroker.jar:]
>	at org.ovirt.engine.core.vdsbroker.VdsManager.onTimer(VdsManager.java:236) [vdsbroker.jar:]
>	at sun.reflect.GeneratedMethodAccessor6.invoke(Unknown Source) [:1.7.0_65]
>	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.7.0_65]
>	at java.lang.reflect.Method.invoke(Method.java:606) [rt.jar:1.7.0_65]
>	at org.ovirt.engine.core.utils.timer.JobWrapper.execute(JobWrapper.java:60) [scheduler.jar:]
>	at org.quartz.core.JobRunShell.run(JobRunShell.java:213) [quartz.jar:]
>	at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:557) [quartz.jar:]
>Caused by: java.util.concurrent.TimeoutException
>	at java.util.concurrent.FutureTask.get(FutureTask.java:201) [rt.jar:1.7.0_65]
>	at org.ovirt.engine.core.vdsbroker.xmlrpc.XmlRpcUtils$AsyncProxy.invoke(XmlRpcUtils.java:200) [vdsbroker.jar:]
>	at com.sun.proxy.$Proxy88.list(Unknown Source)
>	at org.ovirt.engine.core.vdsbroker.vdsbroker.VdsServerWrapper.list(VdsServerWrapper.java:128) [vdsbroker.jar:]
>	at org.ovirt.engine.core.vdsbroker.vdsbroker.ListVDSCommand.executeVdsBrokerCommand(ListVDSCommand.java:23) [vdsbroker.jar:]
>	at org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerCommand.executeVDSCommand(VdsBrokerCommand.java:96) [vdsbroker.jar:]
>	... 14 more
>
>2014-09-29 17:34:17,345 WARN  [org.ovirt.engine.core.vdsbroker.VdsManager] (DefaultQuartzScheduler_Worker-25) [54f6689a] Failed to refresh VDS , vds = 45462850-a02c-4eeb-8527-292e15e5cb54 : voodoo6, VDS Network Error, continuing.
>java.util.concurrent.TimeoutException
>2014-09-29 17:34:18,224 ERROR [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand] (DefaultQuartzScheduler_Worker-32) [1b1e6dfc] IrsBroker::Failed::GetStoragePoolInfoVDS due to: TimeoutException: 
>2014-09-29 17:34:20,456 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.GetHardwareInfoVDSCommand] (DefaultQuartzScheduler_Worker-81) [7bd133cc] START, GetHardwareInfoVDSCommand(HostName = voodoo6, HostId = 45462850-a02c-4eeb-8527-292e15e5cb54, vds=Host[voodoo6,45462850-a02c-4eeb-8527-292e15e5cb54]), log id: 9681393
>2014-09-29 17:34:20,464 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.GetHardwareInfoVDSCommand] (DefaultQuartzScheduler_Worker-21) START, GetHardwareInfoVDSCommand(HostName = voodoo1, HostId = 114c2cc6-5123-45bc-8900-5c875b0543c4, vds=Host[voodoo1,114c2cc6-5123-45bc-8900-5c875b0543c4]), log id: ff133b8
>2014-09-29 17:34:20,466 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.GetHardwareInfoVDSCommand] (DefaultQuartzScheduler_Worker-81) [7bd133cc] FINISH, GetHardwareInfoVDSCommand, log id: 9681393
>2014-09-29 17:34:20,519 INFO  [org.ovirt.engine.core.bll.HandleVdsCpuFlagsOrClusterChangedCommand] (DefaultQuartzScheduler_Worker-81) [25d43bff] Running command: HandleVdsCpuFlagsOrClusterChangedCommand internal: true. Entities affected :  ID: 45462850-a02c-4eeb-8527-292e15e5cb54 Type: VDS
>2014-09-29 17:34:20,522 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.GetHardwareInfoVDSCommand] (DefaultQuartzScheduler_Worker-21) FINISH, GetHardwareInfoVDSCommand, log id: ff133b8
>2014-09-29 17:34:20,531 INFO  [org.ovirt.engine.core.bll.InitVdsOnUpCommand] (DefaultQuartzScheduler_Worker-81) [78290e34] Running command: InitVdsOnUpCommand internal: true. Entities affected :  ID: b86b687a-d073-497a-ac8a-249025419a3e Type: StoragePool
>2014-09-29 17:34:20,551 INFO  [org.ovirt.engine.core.bll.storage.ConnectHostToStoragePoolServersCommand] (DefaultQuartzScheduler_Worker-81) [96c326b] Running command: ConnectHostToStoragePoolServersCommand internal: true. Entities affected :  ID: b86b687a-d073-497a-ac8a-249025419a3e Type: StoragePool
>2014-09-29 17:34:20,566 INFO  [org.ovirt.engine.core.bll.HandleVdsCpuFlagsOrClusterChangedCommand] (DefaultQuartzScheduler_Worker-21) [616a44b] Running command: HandleVdsCpuFlagsOrClusterChangedCommand internal: true. Entities affected :  ID: 114c2cc6-5123-45bc-8900-5c875b0543c4 Type: VDS
>2014-09-29 17:34:20,568 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand] (DefaultQuartzScheduler_Worker-81) [96c326b] START, ConnectStorageServerVDSCommand(HostName = voodoo6, HostId = 45462850-a02c-4eeb-8527-292e15e5cb54, storagePoolId = b86b687a-d073-497a-ac8a-249025419a3e, storageType = ISCSI, connectionList = [{ id: af150e8e-4d74-4810-b8bf-0c6a19637dbf, connection: 10.35.16.25, iqn: iqn.1994-05.com.redhat:nsoffer-target1, vfsType: null, mountOptions: null, nfsVersion: null, nfsRetrans: null, nfsTimeo: null };{ id: e8d58651-6414-4fc2-b281-2141cc97829b, connection: 10.35.0.98, iqn: iqn.1994-05.com.redhat:target6, vfsType: null, mountOptions: null, nfsVersion: null, nfsRetrans: null, nfsTimeo: null };{ id: 8f399b5f-1237-479e-82e6-eedb202b66fd, connection: 10.35.16.25, iqn: iqn.1994-05.com.redhat:nsoffer-target2, vfsType: null, mountOptions: null, nfsVersion: null, nfsRetrans: null, nfsTimeo: null };]), log id: 41dc4ab0
>2014-09-29 17:34:20,580 INFO  [org.ovirt.engine.core.bll.InitVdsOnUpCommand] (DefaultQuartzScheduler_Worker-21) [655c45c1] Running command: InitVdsOnUpCommand internal: true. Entities affected :  ID: b86b687a-d073-497a-ac8a-249025419a3e Type: StoragePool
>2014-09-29 17:34:20,592 INFO  [org.ovirt.engine.core.bll.storage.ConnectHostToStoragePoolServersCommand] (DefaultQuartzScheduler_Worker-21) [b4d50b] Running command: ConnectHostToStoragePoolServersCommand internal: true. Entities affected :  ID: b86b687a-d073-497a-ac8a-249025419a3e Type: StoragePool
>2014-09-29 17:34:20,611 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand] (DefaultQuartzScheduler_Worker-21) [b4d50b] START, ConnectStorageServerVDSCommand(HostName = voodoo1, HostId = 114c2cc6-5123-45bc-8900-5c875b0543c4, storagePoolId = b86b687a-d073-497a-ac8a-249025419a3e, storageType = ISCSI, connectionList = [{ id: af150e8e-4d74-4810-b8bf-0c6a19637dbf, connection: 10.35.16.25, iqn: iqn.1994-05.com.redhat:nsoffer-target1, vfsType: null, mountOptions: null, nfsVersion: null, nfsRetrans: null, nfsTimeo: null };{ id: e8d58651-6414-4fc2-b281-2141cc97829b, connection: 10.35.0.98, iqn: iqn.1994-05.com.redhat:target6, vfsType: null, mountOptions: null, nfsVersion: null, nfsRetrans: null, nfsTimeo: null };{ id: 8f399b5f-1237-479e-82e6-eedb202b66fd, connection: 10.35.16.25, iqn: iqn.1994-05.com.redhat:nsoffer-target2, vfsType: null, mountOptions: null, nfsVersion: null, nfsRetrans: null, nfsTimeo: null };]), log id: d748bee
>2014-09-29 17:34:20,770 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand] (DefaultQuartzScheduler_Worker-21) [b4d50b] FINISH, ConnectStorageServerVDSCommand, return: {e8d58651-6414-4fc2-b281-2141cc97829b=0, af150e8e-4d74-4810-b8bf-0c6a19637dbf=0, 8f399b5f-1237-479e-82e6-eedb202b66fd=0}, log id: d748bee
>2014-09-29 17:34:20,771 INFO  [org.ovirt.engine.core.bll.storage.ConnectHostToStoragePoolServersCommand] (DefaultQuartzScheduler_Worker-21) [b4d50b] Host voodoo1 storage connection was succeeded 
>2014-09-29 17:34:20,779 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStoragePoolVDSCommand] (org.ovirt.thread.pool-8-thread-33) START, ConnectStoragePoolVDSCommand(HostName = voodoo1, HostId = 114c2cc6-5123-45bc-8900-5c875b0543c4, vdsId = 114c2cc6-5123-45bc-8900-5c875b0543c4, storagePoolId = b86b687a-d073-497a-ac8a-249025419a3e, masterVersion = 5), log id: 241984b8
>2014-09-29 17:34:20,835 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand] (DefaultQuartzScheduler_Worker-81) [96c326b] FINISH, ConnectStorageServerVDSCommand, return: {e8d58651-6414-4fc2-b281-2141cc97829b=0, af150e8e-4d74-4810-b8bf-0c6a19637dbf=0, 8f399b5f-1237-479e-82e6-eedb202b66fd=0}, log id: 41dc4ab0
>2014-09-29 17:34:20,836 INFO  [org.ovirt.engine.core.bll.storage.ConnectHostToStoragePoolServersCommand] (DefaultQuartzScheduler_Worker-81) [96c326b] Host voodoo6 storage connection was succeeded 
>2014-09-29 17:34:21,672 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStoragePoolVDSCommand] (org.ovirt.thread.pool-8-thread-33) FINISH, ConnectStoragePoolVDSCommand, log id: 241984b8
>2014-09-29 17:34:21,689 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.SetMOMPolicyParametersVDSCommand] (DefaultQuartzScheduler_Worker-21) [b4d50b] START, SetMOMPolicyParametersVDSCommand(HostName = voodoo1, HostId = 114c2cc6-5123-45bc-8900-5c875b0543c4), log id: 10e92f6
>2014-09-29 17:34:21,695 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStoragePoolVDSCommand] (org.ovirt.thread.pool-8-thread-6) START, ConnectStoragePoolVDSCommand(HostName = voodoo6, HostId = 45462850-a02c-4eeb-8527-292e15e5cb54, vdsId = 45462850-a02c-4eeb-8527-292e15e5cb54, storagePoolId = b86b687a-d073-497a-ac8a-249025419a3e, masterVersion = 5), log id: 6e1aa216
>2014-09-29 17:34:21,771 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.SetMOMPolicyParametersVDSCommand] (DefaultQuartzScheduler_Worker-21) [b4d50b] FINISH, SetMOMPolicyParametersVDSCommand, log id: 10e92f6
>2014-09-29 17:34:21,825 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-21) [b4d50b] Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: Status of host voodoo1 was set to Up.
>2014-09-29 17:34:21,837 WARN  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-21) [b4d50b] Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: Failed to verify Power Management configuration for Host voodoo1.
>2014-09-29 17:34:21,850 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-21) [b4d50b] Correlation ID: 655c45c1, Call Stack: null, Custom Event ID: -1, Message: Unrecognized audit log type has been used.
>2014-09-29 17:34:21,888 INFO  [org.ovirt.engine.core.bll.HandleVdsVersionCommand] (DefaultQuartzScheduler_Worker-21) [1c68f3a1] Running command: HandleVdsVersionCommand internal: true. Entities affected :  ID: 114c2cc6-5123-45bc-8900-5c875b0543c4 Type: VDS
>2014-09-29 17:34:28,329 INFO  [org.ovirt.engine.core.bll.storage.SyncLunsInfoForBlockStorageDomainCommand] (org.ovirt.thread.pool-8-thread-18) [682134c7] Running command: SyncLunsInfoForBlockStorageDomainCommand internal: true. Entities affected :  ID: ff559f46-c495-4f6b-901c-2a624042a050 Type: Storage
>2014-09-29 17:34:28,335 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.GetVGInfoVDSCommand] (org.ovirt.thread.pool-8-thread-18) [682134c7] START, GetVGInfoVDSCommand(HostName = voodoo6, HostId = 45462850-a02c-4eeb-8527-292e15e5cb54, VGID=1B1oT5-JcGj-Ru1I-v3Ni-yden-Du9b-I9fSu8), log id: 7e13fde1
>2014-09-29 17:34:28,354 INFO  [org.ovirt.engine.core.bll.storage.SyncLunsInfoForBlockStorageDomainCommand] (org.ovirt.thread.pool-8-thread-28) [752fdd19] Running command: SyncLunsInfoForBlockStorageDomainCommand internal: true. Entities affected :  ID: 51752c8f-bbe3-4754-866b-a0afd2a1f59d Type: Storage
>2014-09-29 17:34:28,359 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.GetVGInfoVDSCommand] (org.ovirt.thread.pool-8-thread-28) [752fdd19] START, GetVGInfoVDSCommand(HostName = voodoo6, HostId = 45462850-a02c-4eeb-8527-292e15e5cb54, VGID=HOsL3c-AN3Q-ipn9-AL3N-80vL-cvUv-AMTJ41), log id: 5a06c01a
>2014-09-29 17:34:28,497 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStoragePoolVDSCommand] (org.ovirt.thread.pool-8-thread-6) FINISH, ConnectStoragePoolVDSCommand, log id: 6e1aa216
>2014-09-29 17:34:34,216 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.GetVGInfoVDSCommand] (org.ovirt.thread.pool-8-thread-18) [682134c7] FINISH, GetVGInfoVDSCommand, return: [LUNs [id=1IET_00060007, physicalVolumeId=QfuzQ5-Ml7u-kFUc-gdmr-rfmS-Aefp-3HODNb, volumeGroupId=1B1oT5-JcGj-Ru1I-v3Ni-yden-Du9b-I9fSu8, serial=SRed_Cat_VIRTUAL-DISK, lunMapping=7, vendorId=Red Cat, productId=VIRTUAL-DISK, _lunConnections=[{ id: null, connection: 10.35.0.98, iqn: iqn.1994-05.com.redhat:target6, vfsType: null, mountOptions: null, nfsVersion: null, nfsRetrans: null, nfsTimeo: null };], deviceSize=20, vendorName=Red Cat, pathsDictionary={sdv=true}, lunType=ISCSI, status=null, diskId=null, diskAlias=null, storageDomainId=ff559f46-c495-4f6b-901c-2a624042a050, storageDomainName=null], LUNs [id=1IET_00060009, physicalVolumeId=pGRciD-wcLp-X1ME-MijE-P1B9-7XWo-ycTXdG, volumeGroupId=1B1oT5-JcGj-Ru1I-v3Ni-yden-Du9b-I9fSu8, serial=SRed_Cat_VIRTUAL-DISK, lunMapping=9, vendorId=Red Cat, productId=VIRTUAL-DISK, _lunConnections=[{ id: null, connection: 10.35.0.98, iqn: iqn.1994-05.com.redhat:target6, vfsType: null, mountOptions: null, nfsVersion: null, nfsRetrans: null, nfsTimeo: null };], deviceSize=20, vendorName=Red Cat, pathsDictionary={sdx=true}, lunType=ISCSI, status=null, diskId=null, diskAlias=null, storageDomainId=ff559f46-c495-4f6b-901c-2a624042a050, storageDomainName=null]], log id: 7e13fde1
>2014-09-29 17:34:34,432 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.SetMOMPolicyParametersVDSCommand] (DefaultQuartzScheduler_Worker-81) [96c326b] START, SetMOMPolicyParametersVDSCommand(HostName = voodoo6, HostId = 45462850-a02c-4eeb-8527-292e15e5cb54), log id: 52dda140
>2014-09-29 17:34:34,492 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.SetMOMPolicyParametersVDSCommand] (DefaultQuartzScheduler_Worker-81) [96c326b] FINISH, SetMOMPolicyParametersVDSCommand, log id: 52dda140
>2014-09-29 17:34:34,548 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-81) [96c326b] Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: Status of host voodoo6 was set to Up.
>2014-09-29 17:34:34,554 WARN  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-81) [96c326b] Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: Failed to verify Power Management configuration for Host voodoo6.
>2014-09-29 17:34:34,565 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-81) [96c326b] Correlation ID: 78290e34, Call Stack: null, Custom Event ID: -1, Message: Unrecognized audit log type has been used.
>2014-09-29 17:34:34,594 INFO  [org.ovirt.engine.core.bll.HandleVdsVersionCommand] (DefaultQuartzScheduler_Worker-81) [65fecfb8] Running command: HandleVdsVersionCommand internal: true. Entities affected :  ID: 45462850-a02c-4eeb-8527-292e15e5cb54 Type: VDS
>2014-09-29 17:34:34,648 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.GetVGInfoVDSCommand] (org.ovirt.thread.pool-8-thread-28) [752fdd19] FINISH, GetVGInfoVDSCommand, return: [LUNs [id=3600144f09dbd0500000053a84e730003, physicalVolumeId=tJlPY9-uDSu-Uq0G-THq3-FtDg-zUgX-fDeE1m, volumeGroupId=HOsL3c-AN3Q-ipn9-AL3N-80vL-cvUv-AMTJ41, serial=SNEXENTA_COMSTAR_5H49HFEFE, lunMapping=77, vendorId=NEXENTA, productId=COMSTAR, _lunConnections=[{ id: null, connection: 10.35.16.25, iqn: iqn.1994-05.com.redhat:nsoffer-target1, vfsType: null, mountOptions: null, nfsVersion: null, nfsRetrans: null, nfsTimeo: null };], deviceSize=10, vendorName=NEXENTA, pathsDictionary={sdo=true}, lunType=ISCSI, status=null, diskId=null, diskAlias=null, storageDomainId=51752c8f-bbe3-4754-866b-a0afd2a1f59d, storageDomainName=null], LUNs [id=3600144f09dbd0500000053a85076000a, physicalVolumeId=R9WKM6-qyr0-z7nV-dloM-fQQR-4UJ8-9NS9mQ, volumeGroupId=HOsL3c-AN3Q-ipn9-AL3N-80vL-cvUv-AMTJ41, serial=SNEXENTA_COMSTAR_5H49HFEFE, lunMapping=11, vendorId=NEXENTA, productId=COMSTAR, _lunConnections=[{ id: null, connection: 10.35.16.25, iqn: iqn.1994-05.com.redhat:nsoffer-target1, vfsType: null, mountOptions: null, nfsVersion: null, nfsRetrans: null, nfsTimeo: null };], deviceSize=10, vendorName=NEXENTA, pathsDictionary={sdl=true}, lunType=ISCSI, status=null, diskId=null, diskAlias=null, storageDomainId=51752c8f-bbe3-4754-866b-a0afd2a1f59d, storageDomainName=null], LUNs [id=3600144f09dbd0500000053a85401000d, physicalVolumeId=Ry22bc-y09g-FYBU-Cgkh-64hy-uXi6-bGvLqc, volumeGroupId=HOsL3c-AN3Q-ipn9-AL3N-80vL-cvUv-AMTJ41, serial=SNEXENTA_COMSTAR_5H49HFEFE, lunMapping=6, vendorId=NEXENTA, productId=COMSTAR, _lunConnections=[{ id: null, connection: 10.35.16.25, iqn: iqn.1994-05.com.redhat:nsoffer-target2, vfsType: null, mountOptions: null, nfsVersion: null, nfsRetrans: null, nfsTimeo: null };], deviceSize=10, vendorName=NEXENTA, pathsDictionary={sdaf=true}, lunType=ISCSI, status=null, diskId=null, diskAlias=null, storageDomainId=51752c8f-bbe3-4754-866b-a0afd2a1f59d, storageDomainName=null], LUNs [id=3600144f09dbd0500000053a853ed000c, physicalVolumeId=2HKkka-UNX6-RvQt-xZkJ-tpXN-1wMa-W3EJ8k, volumeGroupId=HOsL3c-AN3Q-ipn9-AL3N-80vL-cvUv-AMTJ41, serial=SNEXENTA_COMSTAR_5H49HFEFE, lunMapping=5, vendorId=NEXENTA, productId=COMSTAR, _lunConnections=[{ id: null, connection: 10.35.16.25, iqn: iqn.1994-05.com.redhat:nsoffer-target2, vfsType: null, mountOptions: null, nfsVersion: null, nfsRetrans: null, nfsTimeo: null };], deviceSize=10, vendorName=NEXENTA, pathsDictionary={sdae=true}, lunType=ISCSI, status=null, diskId=null, diskAlias=null, storageDomainId=51752c8f-bbe3-4754-866b-a0afd2a1f59d, storageDomainName=null]], log id: 5a06c01a

Actions: View

Attachments on bug 1147971: 942690 | 942691