Re: [Users] Host migration problem

------=_Part_2519270_1306423749.1348126859097
Content-Type: text/plain; charset=utf-8
Content-Transfer-Encoding: 7bit

Hi Dmitriy. 
This is a bit odd, since indeed action asks to secure all spice channels, 

<graphics autoport="yes" keymap="en-us" passwd="*****" passwdValidTo="1970-01-01T00:00:01" port="-1" tlsPort="-1" type="spice"> 
<channel mode="secure" name="main"/> 
<channel mode="secure" name="inputs"/> 
<channel mode="secure" name="cursor"/> 
<channel mode=&quo t;secure" name="playback"/> 
<channel mode="secure" name="record"/> 
<channel mode="secure" name="display"/> 

but this is introduced only for development 3.2 clusters. 
You can see it by running: 
echo "select * from vdc_options where option_name like '%SpiceSecureChannels%'" | psql -d engine -U postgres 

So... 
1. Please check your cluster version (you should be using 3.1) and please report. 
2. As a temporary workaround, either set libvirt to support spice encryption (in 
/etc/libvirt/qemu.conf set spice_tls = 1, but there may be other needed settings) 
or you can try to set SpiceSecureChannels to what we have in previous versions 
(smain,sinputs or even nothing just for sanity) . 

Check and let us know how it works. 

----- Original Message -----

> From: "Dmitriy A Pyryakov" <DPyryakov@ekb.beeline.ru>
> To: users@ovirt.org
> Sent: Thursday, September 20, 2012 9:49:24 AM
> Subject: [Users] Host migration problem

> Hello,

> Yesturday I broke my two Fedora 17 hosts.
> Today I install two ovirt nodes (first - 2.5.0-2.0.fc17, second -
> 2.5.1-1.0.fc17). SPM on 2.5.0-2.0.fc17.

> Now, I can't run any of my existing virtual machines. Exit message:
> unsupported configuration: spice secure channels set in XML
> configuration, but TLS is disabled in qemu.conf.

> engine.log: [root@admin ~]# tail -f -n 0
> /var/log/ovirt-engine/engine.log
> 2012-09-20 12:42:53,289 INFO
> [org.ovirt.engine.core.vdsbroker.irsbroker.IsValidVDSCommand]
> (ajp--0.0.0.0-8009-10) START, IsValidVDSCommand(storagePoolId =
> 332694bb-364a-434e-b23f-5fef985d3cbd, ignoreFailoverLimit = false,
> compatabilityVersion = null), log id: 7c90c641
> 2012-09-20 12:42:53,294 INFO
> [org.ovirt.engine.core.vdsbroker.irsbroker.IsValidVDSCommand]
> (ajp--0.0.0.0-8009-10) FINISH, IsValidVDSCommand, return: true, log
> id: 7c90c641
> 2012-09-20 12:42:53,332 INFO
> [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand]
> (ajp--0.0.0.0-8009-10) START, IsVmDuringInitiatingVDSCommand(vmId =
> 509e608c-e657-473a-b031-f0811da96bde), log id: 243c74f7
> 2012-09-20 12:42:53,334 INFO
> [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand]
> (ajp--0.0.0.0-8009-10) FINISH, IsVmDuringInitiatingVDSCommand,
> return: false, log id: 243c74f7
> 2012-09-20 12:42:53,403 INFO [org.ovirt.engine.core.bll.RunVmCommand]
> (pool-3-thread-50) [a58d974] Lock Acquired to object EngineLock
> [exclusiveLocks= key: 509e608c-e657-473a-b031-f0811da96bde value: VM
> , sharedLocks= ]
> 2012-09-20 12:42:53,415 INFO [org.ovirt.engine.core.bll.RunVmCommand]
> (pool-3-thread-50) [a58d974] Running command: RunVmCommand internal:
> false. Entities affected : ID: 509e608c-e657-473a-b031-f0811da96bde
> Type: VM
> 2012-09-20 12:42:53,504 INFO
> [org.ovirt.engine.core.vdsbroker.CreateVmVDSCommand]
> (pool-3-thread-50) [a58d974] START, CreateVmVDSCommand(vdsId =
> 0a268762-02d7-11e2-b750-0011856cf23e,
> vmId=509e608c-e657-473a-b031-f0811da96bde,
> vm=org.ovirt.engine.core.common.businessentities.VM@1911737b), log
> id: 77c0e559
> 2012-09-20 12:42:53,529 INFO
> [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand]
> (pool-3-thread-50) [a58d974] START, CreateVDSCommand(vdsId =
> 0a268762-02d7-11e2-b750-0011856cf23e,
> vmId=509e608c-e657-473a-b031-f0811da96bde,
> vm=org.ovirt.engine.core.common.businessentities.VM@1911737b), log
> id: f48008f
> 2012-09-20 12:42:53,602 INFO
> [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand]
> (pool-3-thread-50) [a58d974]
> org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand
> spiceSslCipherSuite=DEFAULT,memSize=1024,kvmEnable=true,smp=1,emulatedMachine=pc-0.14,vmType=kvm,keyboardLayout=en-us,pitReinjection=false,nice=0,display=qxl,smpCoresPerSocket=1,spiceSecureChannels=smain,sinputs,scursor,splayback,srecord,sdisplay,displayNetwork=ovirtmgmt,timeOffset=-1,transparentHugePages=true,vmId=509e608c
> -e657-473a-b031-f0811da96bde,devices=[Ljava.util.Map;@760db68c,acpiEnable=true,vmName=CentOS6Thames,cpuType=Conroe,custom={device_bb912edd-9790-43ff-a758-f1d9f20cb5f5device_f5c86859-5ae9-4a37-9d34-2b9547609622device_20a11f26-6a39-415d-a7bf-95893b9c55b5=VmId=509e608c-e657-473a-b031-f0811da96bde,DeviceId=20a11f26-6a39-415d-a7bf-95893b9c55b5,Device=unix,Type=channel,BootOrder=0,SpecParams={},Address={port=1,
> bus=0, controller=0,
> type=virtio-serial},IsManaged=false,IsPlugged=true,IsReadOnly=false,alias=
> channel0,
> device_bb912edd-9790-43ff-a758-f1d9f20cb5f5=VmId=509e608c-e657-473a-b031-f0811da96bde,DeviceId=bb912edd-9790-43ff-a758-f1d9f20cb5f5,Device=ide,Type=controller,BootOrder=0,SpecParams={},Address={bus=0x00,
> domain=0x0000, type=pci, slot=0x01,
> function=0x1},IsManaged=false,IsPlugged=true,IsReadOnly=false,alias=ide0,
> device_bb912edd-9790-43ff-a758-f1d9f20cb5f5device_f5c86859-5ae9-4a37-9d34-2b9547609622=VmId=509e608c-e657-473a-b031-f0811da96bde,DeviceId=f5c86859-5ae9-4a37-9d34-2b9547609622,Devic
> e=virtio-serial,Type=controller,BootOrder=0,SpecParams={},Address={bus=0x00,
> domain=0x0000, type=pci, slot=0x04,
> function=0x0},IsManaged=false,IsPlugged=true,IsReadOnly=false,alias=virtio-serial0,
> device_bb912edd-9790-43ff-a758-f1d9f20cb5f5device_f5c86859-5ae9-4a37-9d34-2b9547609622device_20a11f26-6a39-415d-a7bf-95893b9c55b5device_21f255dc-9b3b-48d8-b8e4-63c1635e269b=VmId=509e608c-e657-473a-b031-f0811da96bde,DeviceId=21f255dc-9b3b-48d8-b8e4-63c1635e269b,Device=spicevmc,Type=channel,BootOrder=0,SpecP
> arams={},Address={port=2, bus=0, controller=0,
> type=virtio-serial},IsManaged=false,IsPlugged=true,IsReadOnly=false,alias=channel1,
> device_bb912edd-9790-43ff-a758-f1d9f20cb5f5device_f5c86859-5ae9-4a37-9d34-2b9547609622device_20a11f26-6a39-415d-a7bf-95893b9c55b5device_21f255dc-9b3b-48d8-b8e4-63c1635e269bdevice_d6c2c4d1-da6b-44fe-a5aa-508135c7fdfe=VmId=509e608c-e657-473a-b031-f0811da96bde,DeviceId=d6c2c4d1-da6b-44fe-a5aa-508135c7fdfe,Device=usb,Type=controller,BootOrder=0,SpecParams={},Address={bus=0x0
> 0, domain=0x0000, type=pci, slot=0x01,
> function=0x2},IsManaged=false,IsPlugged=true,IsReadOnly=false,alias=usb0}
> 2012-09-20 12:42:53,625 INFO
> [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand]
> (pool-3-thread-50) [a58d974] FINISH, CreateVDSCommand, log id:
> f48008f
> 2012-09-20 12:42:53,659 INFO
> [org.ovirt.engine.core.vdsbroker.CreateVmVDSCommand]
> (pool-3-thread-50) [a58d974] IncreasePendingVms::CreateVmIncreasing
> vds hyper1.ovirt.com pending vcpu count, now 1. Vm: CentOS6Thames
> 2012-09-20 12:42:53,671 INFO
> [org.ovirt.engine.core.vdsbroker.CreateVmVDSCommand]
> (pool-3-thread-50) [a58d974] FINISH, CreateVmVDSCommand, return:
> WaitForLaunch, log id: 77c0e559
> 2012-09-20 12:42:53,684 INFO [org.ovirt.engine.core.bll.RunVmCommand]
> (pool-3-thread-50) [a58d974] Lock freed to object EngineLock
> [exclusiveLocks= key: 509e608c-e657-473a-b031-f0811da96bde value: VM
> , sharedLocks= ]
> 2012-09-20 12:42:54,418 INFO
> [org.ovirt.engine.core.vdsbroker.vdsbroker.DestroyVDSCommand]
> (QuartzScheduler_Worker-12) START, DestroyVDSCommand(vdsId =
> 0a268762-02d7-11e2-b750-0011856cf23e,
> vmId=509e608c-e657-473a-b031-f0811da96bde, force=false,
> secondsToWait=0, gracefully=false), log id: 2f059be9
> 2012-09-20 12:42:54,486 INFO
> [org.ovirt.engine.core.vdsbroker.vdsbroker.DestroyVDSCommand]
> (QuartzScheduler_Worker-12) FINISH, DestroyVDSCommand, log id:
> 2f059be9
> 2012-09-20 12:42:54,520 INFO
> [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo]
> (QuartzScheduler_Worker-12) Running on vds during rerun failed vm:
> null
> 2012-09-20 12:42:54,523 INFO
> [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo]
> (QuartzScheduler_Worker-12) vm CentOS6Thames running in db and not
> running in vds - add to rerun treatment. vds hyper1.ovirt.com
> 2012-09-20 12:42:54,536 ERROR
> [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo]
> (QuartzScheduler_Worker-12) Rerun vm
> 509e608c-e657-473a-b031-f0811da96bde. Called from vds
> hyper1.ovirt.com
> 2012-09-20 12:42:54,557 INFO
> [org.ovirt.engine.core.vdsbroker.UpdateVdsDynamicDataVDSCommand]
> (pool-3-thread-50) START, UpdateVdsDynamicDataVDSCommand(vdsId =
> 0a268762-02d7-11e2-b750-0011856cf23e,
> vdsDynamic=org.ovirt.engine.core.common.businessentities.VdsDynamic@db702e05),
> log id: 71c6e6a3
> 2012-09-20 12:42:54,564 INFO
> [org.ovirt.engine.core.vdsbroker.UpdateVdsDynamicDataVDSCommand]
> (pool-3-thread-50) FINISH, UpdateVdsDynamicDataVDSCommand, log id:
> 71c6e6a3
> 2012-09-20 12:42:54,584 INFO [org.ovirt.engine.core.bll.RunVmCommand]
> (pool-3-thread-50) Lock Acquired to object EngineLock
> [exclusiveLocks= key: 509e608c-e657-473a-b031-f0811da96bde value: VM
> , sharedLocks= ]
> 2012-09-20 12:42:54,603 INFO
> [org.ovirt.engine.core.vdsbroker.irsbroker.IsValidVDSCommand]
> (pool-3-thread-50) START, IsValidVDSCommand(storagePoolId =
> 332694bb-364a-434e-b23f-5fef985d3cbd, ignoreFailoverLimit = false,
> compatabilityVersion = null), log id: f1903fc
> 2012-09-20 12:42:54,614 INFO
> [org.ovirt.engine.core.vdsbroker.irsbroker.IsValidVDSCommand]
> (pool-3-thread-50) FINISH, IsValidVDSCommand, return: true, log id:
> f1903fc
> 2012-09-20 12:42:54,653 INFO
> [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand]
> (pool-3-thread-50) START, IsVmDuringInitiatingVDSCommand(vmId =
> 509e608c-e657-473a-b031-f0811da96bde), log id: 5b0d9779
> 2012-09-20 12:42:54,655 INFO
> [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand]
> (pool-3-thread-50) FINISH, IsVmDuringInitiatingVDSCommand, return:
> false, log id: 5b0d9779
> 2012-09-20 12:42:54,712 INFO [org.ovirt.engine.core.bll.RunVmCommand]
> (pool-3-thread-50) Running command: RunVmCommand internal: false.
> Entities affected : ID: 509e608c-e657-473a-b031-f0811da96bde Type:
> VM
> 2012-09-20 12:42:54,800 INFO
> [org.ovirt.engine.core.vdsbroker.CreateVmVDSCommand]
> (pool-3-thread-50) START, CreateVmVDSCommand(vdsId =
> 9840e840-02db-11e2-a01a-0011856cf23e,
> vmId=509e608c-e657-473a-b031-f0811da96bde,
> vm=org.ovirt.engine.core.common.businessentities.VM@4432a01d), log
> id: 554a0742
> 2012-09-20 12:42:54,825 INFO
> [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand]
> (pool-3-thread-50) START, CreateVDSCommand(vdsId =
> 9840e840-02db-11e2-a01a-0011856cf23e,
> vmId=509e608c-e657-473a-b031-f0811da96bde,
> vm=org.ovirt.engine.core.common.businessentities.VM@4432a01d), log
> id: 73615350
> 2012-09-20 12:42:54,912 INFO
> [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand]
> (pool-3-thread-50)
> org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand
> spiceSslCipherSuite=DEFAULT,memSize=1024,kvmEnable=true,smp=1,emulatedMachine=pc-0.14,vmType=kvm,keyboardLayout=en-us,pitReinjection=false,nice=0,display=qxl,smpCoresPerSocket=1,spiceSecureChannels=smain,sinputs,scursor,splayback,srecord,sdisplay,displayNetwork=ovirtmgmt,timeOffset=-1,transparentHugePages=true,vmId=509e608c-e657-473a
> -b031-f0811da96bde,devices=[Ljava.util.Map;@41d42882,acpiEnable=true,vmName=CentOS6Thames,cpuType=Conroe,custom={device_bb912edd-9790-43ff-a758-f1d9f20cb5f5device_f5c86859-5ae9-4a37-9d34-2b9547609622device_20a11f26-6a39-415d-a7bf-95893b9c55b5=VmId=509e608c-e657-473a-b031-f0811da96bde,DeviceId=20a11f26-6a39-415d-a7bf-95893b9c55b5,Device=unix,Type=channel,BootOrder=0,SpecParams={},Address={port=1,
> bus=0, controller=0,
> type=virtio-serial},IsManaged=false,IsPlugged=true,IsReadOnly=false,alias=channel0,
> device_bb912edd-9790-43ff-a758-f1d9f20cb5f5=VmId=509e608c-e657-473a-b031-f0811da96bde,DeviceId=bb912edd-9790-43ff-a758-f1d9f20cb5f5,Device=ide,Type=controller,BootOrder=0,SpecParams={},Address={bus=0x00,
> domain=0x0000, type=pci, slot=0x01,
> function=0x1},IsManaged=false,IsPlugged=true,IsReadOnly=false,alias=ide0,
> device_bb912edd-9790-43ff-a758-f1d9f20cb5f5device_f5c86859-5ae9-4a37-9d34-2b9547609622=VmId=509e608c-e657-473a-b031-f0811da96bde,DeviceId=f5c86859-5ae9-4a37-9d34-2b9547609622,Device=virtio-s
> erial,Type=controller,BootOrder=0,SpecParams={},Address={bus=0x00,
> domain=0x0000, type=pci, slot=0x04,
> function=0x0},IsManaged=false,IsPlugged=true,IsReadOnly=false,alias=virtio-serial0,
> device_bb912edd-9790-43ff-a758-f1d9f20cb5f5device_f5c86859-5ae9-4a37-9d34-2b9547609622device_20a11f26-6a39-415d-a7bf-95893b9c55b5device_21f255dc-9b3b-48d8-b8e4-63c1635e269b=VmId=509e608c-e657-473a-b031-f0811da96bde,DeviceId=21f255dc-9b3b-48d8-b8e4-63c1635e269b,Device=spicevmc,Type=channel,BootOrder=0,SpecParams={},A
> ddress={port=2, bus=0, controller=0,
> type=virtio-serial},IsManaged=false,IsPlugged=true,IsReadOnly=false,alias=channel1,
> device_bb912edd-9790-43ff-a758-f1d9f20cb5f5device_f5c86859-5ae9-4a37-9d34-2b9547609622device_20a11f26-6a39-415d-a7bf-95893b9c55b5device_21f255dc-9b3b-48d8-b8e4-63c1635e269bdevice_d6c2c4d1-da6b-44fe-a5aa-508135c7fdfe=VmId=509e608c-e657-473a-b031-f0811da96bde,DeviceId=d6c2c4d1-da6b-44fe-a5aa-508135c7fdfe,Device=usb,Type=controller,BootOrder=0,SpecParams={},Address={bus=0x00,
> domain= 0x0000, type=pci, slot=0x01,
> function=0x2},IsManaged=false,IsPlugged=true,IsReadOnly=false,alias=usb0}
> 2012-09-20 12:42:54,982 INFO
> [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand]
> (pool-3-thread-50) FINISH, CreateVDSCommand, log id: 73615350
> 2012-09-20 12:42:55,004 INFO
> [org.ovirt.engine.core.vdsbroker.CreateVmVDSCommand]
> (pool-3-thread-50) IncreasePendingVms::CreateVmIncreasing vds
> hyper2.ovirt.com pending vcpu count, now 1. Vm: CentOS6Thames
> 2012-09-20 12:42:55,012 INFO
> [org.ovirt.engine.core.vdsbroker.CreateVmVDSCommand]
> (pool-3-thread-50) FINISH, CreateVmVDSCommand, return:
> WaitForLaunch, log id: 554a0742
> 2012-09-20 12:42:55,022 INFO [org.ovirt.engine.core.bll.RunVmCommand]
> (pool-3-thread-50) Lock freed to object EngineLock [exclusiveLocks=
> key: 509e608c-e657-473a-b031-f0811da96bde value: VM
> , sharedLocks= ]
> 2012-09-20 12:42:56,434 INFO
> [org.ovirt.engine.core.vdsbroker.vdsbroker.DestroyVDSCommand]
> (QuartzScheduler_Worker-32) START, DestroyVDSCommand(vdsId =
> 9840e840-02db-11e2-a01a-0011856cf23e,
> vmId=509e608c-e657-473a-b031-f0811da96bde, force=false,
> secondsToWait=0, gracefully=false), log id: 6b44f6c9
> 2012-09-20 12:42:56,497 INFO
> [org.ovirt.engine.core.vdsbroker.vdsbroker.DestroyVDSCommand]
> (QuartzScheduler_Worker-32) FINISH, DestroyVDSCommand, log id:
> 6b44f6c9
> 2012-09-20 12:42:56,532 INFO
> [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo]
> (QuartzScheduler_Worker-32) Running on vds during rerun failed vm:
> null
> 2012-09-20 12:42:56,535 INFO
> [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo]
> (QuartzScheduler_Worker-32) vm CentOS6Thames running in db and not
> running in vds - add to rerun treatment. vds hyper2.ovirt.com
> 2012-09-20 12:42:56,548 ERROR
> [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo]
> (QuartzScheduler_Worker-32) Rerun vm
> 509e608c-e657-473a-b031-f0811da96bde. Called from vds
> hyper2.ovirt.com
> 2012-09-20 12:42:56,582 INFO
> [org.ovirt.engine.core.vdsbroker.UpdateVdsDynamicDataVDSCommand]
> (pool-3-thread-50) START, UpdateVdsDynamicDataVDSCommand(vdsId =
> 9840e840-02db-11e2-a01a-0011856cf23e,
> vdsDynamic=org.ovirt.engine.core.common.businessentities.VdsDynamic@5f1dd7c7),
> log id: 2a191f9e
> 2012-09-20 12:42:56,596 INFO
> [org.ovirt.engine.core.vdsbroker.UpdateVdsDynamicDataVDSCommand]
> (pool-3-thread-50) FINISH, UpdateVdsDynamicDataVDSCommand, log id:
> 2a191f9e
> 2012-09-20 12:42:56,616 INFO [org.ovirt.engine.core.bll.RunVmCommand]
> (pool-3-thread-50) Lock Acquired to object EngineLock
> [exclusiveLocks= key: 509e608c-e657-473a-b031-f0811da96bde value: VM
> , sharedLocks= ]
> 2012-09-20 12:42:56,632 INFO
> [org.ovirt.engine.core.vdsbroker.irsbroker.IsValidVDSCommand]
> (pool-3-thread-50) START, IsValidVDSCommand(storagePoolId =
> 332694bb-364a-434e-b23f-5fef985d3cbd, ignoreFailoverLimit = false,
> compatabilityVersion = null), log id: 4629f11d
> 2012-09-20 12:42:56,636 INFO
> [org.ovirt.engine.core.vdsbroker.irsbroker.IsValidVDSCommand]
> (pool-3-thread-50) FINISH, IsValidVDSCommand, return: true, log id:
> 4629f11d
> 2012-09-20 12:42:56,672 INFO
> [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand]
> (pool-3-thread-50) START, IsVmDuringInitiatingVDSCommand(vmId =
> 509e608c-e657-473a-b031-f0811da96bde), log id: f3a60e
> 2012-09-20 12:42:56,675 INFO
> [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand]
> (pool-3-thread-50) FINISH, IsVmDuringInitiatingVDSCommand, return:
> false, log id: f3a60e
> 2012-09-20 12:42:56,713 WARN [org.ovirt.engine.core.bll.RunVmCommand]
> (pool-3-thread-50) CanDoAction of action RunVm failed.
> Reasons:VAR__ACTION__RUN,VAR__TYPE__VM,VAR__ACTION__RUN,VAR__TYPE__VM,VAR__ACTION__RUN,VAR__TYPE__VM,VAR__ACTION__RUN,VAR__TYPE__VM,ACTION_TYPE_FAILED_VDS_VM_CLUSTER
> 2012-09-20 12:42:56,717 INFO [org.ovirt.engine.core.bll.RunVmCommand]
> (pool-3-thread-50) Lock freed to object EngineLock [exclusiveLocks=
> key: 509e608c-e657-473a-b031-f0811da96bde value: VM
> , sharedLocks= ]

> vdsm.log:
> Dummy-1960::DEBUG::2012-09-20
> 06:46:58,959::__init__::1249::Storage.Misc.excCmd::(_log) 'dd
> if=/rhev/data-center/332694bb-364a-434e-b23f-5fef985d3cbd/mastersd/dom_md/inbox
> iflag=direct,fullblock count=1 bs=1024000' (cwd None)
> Dummy-1960::DEBUG::2012-09-20
> 06:46:59,043::__init__::1249::Storage.Misc.excCmd::(_log) SUCCESS:
> <err> = '1+0 records in\n1+0 records out\n1024000 bytes (1.0 MB)
> copied, 0.0488089 s, 21.0 MB/s\n'; <rc> = 0
> Dummy-1960::DEBUG::2012-09-20
> 06:47:01,053::__init__::1249::Storage.Misc.excCmd::(_log) 'dd
> if=/rhev/data-center/332694bb-364a-434e-b23f-5fef985d3cbd/mastersd/dom_md/inbox
> iflag=direct,fullblock count=1 bs=1024000' (cwd None)
> Dummy-1960::DEBUG::2012-09-20
> 06:47:01,136::__init__::1249::Storage.Misc.excCmd::(_log) SUCCESS:
> <err> = '1+0 records in\n1+0 records out\n1024000 bytes (1.0 MB)
> copied, 0.0477826 s, 21.4 MB/s\n'; <rc> = 0
> Thread-7807::DEBUG::2012-09-20
> 06:47:01,991::BindingXMLRPC::859::vds::(wrapper) client
> [192.168.10.10]::call vmCreate with ({'custom':
> {'device_bb912edd-9790-43ff-a758-f1d9f20cb5f5device_f5c86859-5ae9-4a37-9d34-2b9547609622device_20a11f26-6a39-415d-a7bf-95893b9c55b5device_21f255dc-9b3b-48d8-b8e4-63c1635e269bdevice_d6c2c4d1-da6b-44fe-a5aa-508135c7fdfe':
> 'VmId=509e608c-e657-473a-b031-f0811da96bde,DeviceId=d6c2c4d1-da6b-44fe-a5aa-508135c7fdfe,Device=usb,Type=controller,BootOrder=0,SpecParams={},Address={bus=0x00,
> domain=0x0000, type=pci, slot=0x01,
> function=0x2},IsManaged=false,IsPlugged=true,IsReadOnly=false,alias=usb0',
> 'device_bb912edd-9790-43ff-a758-f1d9f20cb5f5device_f5c86859-5ae9-4a37-9d34-2b9547609622device_20a11f26-6a39-415d-a7bf-95893b9c55b5device_21f255dc-9b3b-48d8-b8e4-63c1635e269b':
> 'VmId=509e608c-e657-473a-b031-f0811da96bde,DeviceId=21f255dc-9b3b-48d8-b8e4-63c1635e269b,Device=spicevmc,Type=channel,BootOrder=0,SpecParams={},Address={port=2,
> bus=0, controller=0,
> type=virtio-serial},IsManaged=false,IsPlugged=true,IsReadOnly=false,alias=channel1',
> 'device_bb912edd-9790-43ff-a758-f1d9f20cb5f5device_f5c86859-5ae9-4a37-9d34-2b9547609622':
> 'VmId=509e608c-e657-473a-b031-f0811da96bde,DeviceId=f5c86859-5ae9-4a37-9d34-2b9547609622,Device=virtio-serial,Type=controller,BootOrder=0,SpecParams={},Address={bus=0x00,
> domain=0x0000, type=pci, slot=0x04,
> function=0x0},IsManaged=false,IsPlugged=true,IsReadOnly=false,alias=virtio-serial0',
> 'device_bb912edd-9790-43ff-a758-f1d9f20cb5f5device_f5c86859-5ae9-4a37-9d34-2b9547609622device_20a11f26-6a39-415d-a7bf-95893b9c55b5':
> 'VmId=509e608c-e657-473a-b031-f0811da96bde,DeviceId=20a11f26-6a39-415d-a7bf-95893b9c55b5,Device=unix,Type=channel,BootOrder=0,SpecParams={},Address={port=1,
> bus=0, controller=0,
> type=virtio-serial},IsManaged=false,IsPlugged=true,IsReadOnly=false,alias=channel0',
> 'device_bb912edd-9790-43ff-a758-f1d9f20cb5f5':
> 'VmId=509e608c-e657-473a-b031-f0811da96bde,DeviceId=bb912edd-9790-43ff-a758-f1d9f20cb5f5,Device=ide,Type=controller,BootOrder=0,SpecParams={},Address={bus=0x00,
> domain=0x0000, type=pci, slot=0x01,
> function=0x1},IsManaged=false,IsPlugged=true,IsReadOnly=false,alias=ide0'},
> 'keyboardLayout': 'en-us', 'kvmEnable': 'true', 'pitReinjection':
> 'false', 'acpiEnable': 'true', 'emulatedMachine': 'pc-0.14',
> 'displayNetwork': 'ovirtmgmt', 'vmId':
> '509e608c-e657-473a-b031-f0811da96bde', 'devices': [{'device':
> 'qxl', 'specParams': {'vram': '65536'}, 'type': 'video', 'deviceId':
> '20c037f2-11e5-49a5-ace7-741023ec0ce9', 'address': {'bus': '0x00', '
> slot': '0x02', ' domain': '0x0000', ' type': 'pci', ' function':
> '0x0'}}, {'index': '2', 'iface': 'ide', 'specParams': {'path': ''},
> 'readonly': 'true', 'deviceId':
> '1ed8a73e-be34-4829-a7e3-151a7a2efedc', 'address': {' controller':
> '0', ' target': '0', 'unit': '0', ' bus': '1', ' type': 'drive'},
> 'device': 'cdrom', 'path': '', 'type': 'disk'}, {'iface': 'virtio',
> 'format': 'cow', 'type': 'disk', 'poolID':
> '332694bb-364a-434e-b23f-5fef985d3cbd', 'volumeID':
> 'f184ecd1-0001-4739-af71-250b412345d6', 'imageID':
> '0a7013db-68fd-4c42-bc2e-cc8d7a05ca18', 'specParams': {},
> 'readonly': 'false', 'domainID':
> '26187d25-bfcb-40c7-97d1-667705ad2223', 'deviceId':
> '0a7013db-68fd-4c42-bc2e-cc8d7a05ca18', 'address': {'bus': '0x00', '
> slot': '0x05', ' domain': '0x0000', ' type': 'pci', ' function':
> '0x0'}, 'device': 'disk', 'shared': 'false', 'propagateErrors':
> 'off', 'optional': 'false'}, {'nicModel': 'pv', 'macAddr':
> '00:1a:4a:a8:0a:00', 'network': 'ovirtmgmt', 'specParams': {},
> 'deviceId': '7392f689-2ba3-4243-9629-96b192b102a5', 'address':
> {'bus': '0x00', ' slot': '0x03', ' domain': '0x0000', ' type':
> 'pci', ' function': '0x0'}, 'device': 'bridge', 'type':
> 'interface'}, {'device': 'usb', 'specParams': {}, 'type':
> 'controller', 'deviceId': 'd6c2c4d1-da6b-44fe-a5aa-508135c7fdfe',
> 'address': {'bus': '0x00', ' slot': '0x01', ' domain': '0x0000', '
> type': 'pci', ' function': '0x2'}}, {'device': 'memballoon',
> 'specParams': {'model': 'virtio'}, 'type': 'balloon', 'deviceId':
> 'babd73a4-de64-4dce-91b9-e64c5b46c444'}], 'smp': '1', 'vmType':
> 'kvm', 'timeOffset': '
> -1', 'memSize': 1024, 'spiceSslCipherSuite': 'DEFAULT', 'cpuType':
> 'Conroe', 'spiceSecureChannels':
> 'smain,sinputs,scursor,splayback,srecord,sdisplay',
> 'smpCoresPerSocket': '1', 'vmName': 'CentOS6Thames', 'display':
> 'qxl', 'transparentHugePages': 'true', 'nice': '0'},) {}
> Thread-7807::INFO::2012-09-20 06:47:01,992::API::228::vds::(create)
> vmContainerLock acquired by vm 509e608c-e657-473a-b031-f0811da96bde
> Thread-7808::DEBUG::2012-09-20
> 06:47:01,996::vm::564::vm.Vm::(_startUnderlyingVm)
> vmId=`509e608c-e657-473a-b031-f0811da96bde`::Start
> Thread-7807::DEBUG::2012-09-20 06:47:01,996::API::244::vds::(create)
> Total desktops after creation of
> 509e608c-e657-473a-b031-f0811da96bde is 1
> Thread-7808::DEBUG::2012-09-20
> 06:47:01,997::vm::568::vm.Vm::(_startUnderlyingVm)
> vmId=`509e608c-e657-473a-b031-f0811da96bde`::_ongoingCreations
> acquired
> Thread-7807::DEBUG::2012-09-20
> 06:47:01,997::BindingXMLRPC::865::vds::(wrapper) return vmCreate
> with {'status': {'message': 'Done', 'code': 0}, 'vmList': {'status':
> 'WaitForLaunch', 'acpiEnable': 'true', 'emulatedMachine': 'pc-0.14',
> 'vmId': '509e608c-e657-473a-b031-f0811da96bde', 'pid': '0',
> 'timeOffset': '-1', 'displayPort': '-1', 'displaySecurePort': '-1',
> 'spiceSslCipherSuite': 'DEFAULT', 'cpuType': 'Conroe', 'custom':
> {'device_bb912edd-9790-43ff-a758-f1d9f20cb5f5device_f5c86859-5ae9-4a37-9d34-2b9547609622device_20a11f26-6a39-415d-a7bf-95893b9c55b5device_21f255dc-9b3b-48d8-b8e4-63c1635e269bdevice_d6c2c4d1-da6b-44fe-a5aa-508135c7fdfe':
> 'VmId=509e608c-e657-473a-b031-f0811da96bde,DeviceId=d6c2c4d1-da6b-44fe-a5aa-508135c7fdfe,Device=usb,Type=controller,BootOrder=0,SpecParams={},Address={bus=0x00,
> domain=0x0000, type=pci, slot=0x01,
> function=0x2},IsManaged=false,IsPlugged=true,IsReadOnly=false,alias=usb0',
> 'device_bb912edd-9790-43ff-a758-f1d9f20cb5f5device_f5c86859-5ae9-4a37-9d34-2b9547609622device_20a11f26-6a39-415d-a7bf-95893b9c55b5device_21f255dc-9b3b-48d8-b8e4-63c1635e269b':
> 'VmId=509e608c-e657-473a-b031-f0811da96bde,DeviceId=21f255dc-9b3b-48d8-b8e4-63c1635e269b,Device=spicevmc,Type=channel,BootOrder=0,SpecParams={},Address={port=2,
> bus=0, controller=0,
> type=virtio-serial},IsManaged=false,IsPlugged=true,IsReadOnly=false,alias=channel1',
> 'device_bb912edd-9790-43ff-a758-f1d9f20cb5f5device_f5c86859-5ae9-4a37-9d34-2b9547609622':
> 'VmId=509e608c-e657-473a-b031-f0811da96bde,DeviceId=f5c86859-5ae9-4a37-9d34-2b9547609622,Device=virtio-serial,Type=controller,BootOrder=0,SpecParams={},Address={bus=0x00,
> domain=0x0000, type=pci, slot=0x04,
> function=0x0},IsManaged=false,IsPlugged=true,IsReadOnly=false,alias=virtio-serial0',
> 'device_bb912edd-9790-43ff-a758-f1d9f20cb5f5device_f5c86859-5ae9-4a37-9d34-2b9547609622device_20a11f26-6a39-415d-a7bf-95893b9c55b5':
> 'VmId=509e608c-e657-473a-b031-f0811da96bde,DeviceId=20a11f26-6a39-415d-a7bf-95893b9c55b5,Device=unix,Type=channel,BootOrder=0,SpecParams={},Address={port=1,
> bus=0, controller=0,
> type=virtio-serial},IsManaged=false,IsPlugged=true,IsReadOnly=false,alias=channel0',
> 'device_bb912edd-9790-43ff-a758-f1d9f20cb5f5':
> 'VmId=509e608c-e657-473a-b031-f0811da96bde,DeviceId=bb912edd-9790-43ff-a758-f1d9f20cb5f5,Device=ide,Type=controller,BootOrder=0,SpecParams={},Address={bus=0x00,
> domain=0x0000, type=pci, slot=0x01,
> function=0x1},IsManaged=false,IsPlugged=true,IsReadOnly=false,alias=ide0'},
> 'clientIp': '', 'nicModel': 'rtl8139,pv', 'keyboardLayout': 'en-us',
> 'kvmEnable': 'true', 'pitReinjection': 'false',
> 'transparentHugePages': 'true', 'displayNetwork': 'ovirtmgmt',
> 'devices': [{'device': 'qxl', 'specParams': {'vram': '65536'},
> 'type': 'video', 'deviceId': '20c037f2-11e5-49a5-ace7-741023ec0ce9',
> 'address': {'bus': '0x00', ' slot': '0x02', ' domain': '0x0000', '
> type': 'pci', ' function': '0x0'}}, {'index': '2', 'iface': 'ide',
> 'specParams': {'path': ''}, 'readonly': 'true', 'deviceId':
> '1ed8a73e-be34-4829-a7e3-151a7a2efedc', 'address': {' controller':
> '0', ' target': '0', 'unit': '0', ' bus': '1', ' type': 'drive'},
> 'device': 'cdrom', 'path': '', 'type': 'disk'}, {'iface': 'virtio',
> 'format': 'cow', 'type': 'disk', 'poolID':
> '332694bb-364a-434e-b23f-5fef985d3cbd', 'volumeID':
> 'f184ecd1-0001-4739-af71-250b412345d6', 'imageID':
> '0a7013db-68fd-4c42-bc2e-cc8d7a05ca18', 'specParams': {},
> 'readonly': 'false', 'domainID':
> '26187d25-bfcb-40c7-97d1-667705ad2223', 'deviceId':
> '0a7013db-68fd-4c42-bc2e-cc8d7a05ca18', 'address': {'bus': '0x00', '
> slot': '0x05', ' domain': '0x0000', ' type': 'pci', ' function':
> '0x0'}, 'device': 'disk', 'shared': 'false', 'propagateErrors':
> 'off', 'optional': 'false'}, {'nicModel': 'pv', 'macAddr':
> '00:1a:4a:a8:0a:00', 'network': 'ovirtmgmt', 'specParams': {},
> 'deviceId': '7392f689-2ba3-4243-9629-96b192b102a5', 'address':
> {'bus': '0x00', ' slot': '0x03', ' domain': '0x0000', ' type':
> 'pci', ' function': '0x0'}, 'device': 'bridge', 'type':
> 'interface'}, {'device': 'usb', 'specParams': {}, 'type':
> 'controller', 'deviceId': 'd6c2c4d1-da6b-44fe-a5aa-508135c7fdfe',
> 'address': {'b
> us': '0x00', ' slot': '0x01', ' domain': '0x0000', ' type': 'pci', '
> function': '0x2'}}, {'device': 'memballoon', 'specParams': {'model':
> 'virtio'}, 'type': 'balloon', 'deviceId':
> 'babd73a4-de64-4dce-91b9-e64c5b46c444'}], 'smp': '1', 'vmType':
> 'kvm', 'memSize': 1024, 'displayIp': '192.168.10.13',
> 'spiceSecureChannels':
> 'smain,sinputs,scursor,splayback,srecord,sdisplay',
> 'smpCoresPerSocket': '1', 'vmName': 'CentOS6Thames', 'display':
> 'qxl', 'nice': '0'}}
> Thread-7808::INFO::2012-09-20
> 06:47:01,997::libvirtvm::1285::vm.Vm::(_run)
> vmId=`509e608c-e657-473a-b031-f0811da96bde`::VM wrapper has started
> Thread-7808::DEBUG::2012-09-20
> 06:47:02,000::task::588::TaskManager.Task::(_updateState)
> Task=`b6ef82b2-2986-4b7b-95ba-d5f3cac8ad31`::moving from state init
> -> state preparing
> Thread-7808::INFO::2012-09-20
> 06:47:02,001::logUtils::37::dispatcher::(wrapper) Run and protect:
> getVolumeSize(sdUUID='26187d25-bfcb-40c7-97d1-667705ad2223',
> spUUID='332694bb-364a-434e-b23f-5fef985d3cbd',
> imgUUID='0a7013db-68fd-4c42-bc2e-cc8d7a05ca18',
> volUUID='f184ecd1-0001-4739-af71-250b412345d6', options=None)
> Thread-7808::DEBUG::2012-09-20
> 06:47:02,001::resourceManager::175::ResourceManager.Request::(__init__)
> ResName=`Storage.26187d25-bfcb-40c7-97d1-667705ad2223`ReqID=`83dac2e0-3d55-4ef6-abf3-7b2561814ab4`::Request
> was made in '/usr/share/vdsm/storage/resourceManager.py' line '485'
> at 'registerResource'
> Thread-7808::DEBUG::2012-09-20
> 06:47:02,002::resourceManager::486::ResourceManager::(registerResource)
> Trying to register resource
> 'Storage.26187d25-bfcb-40c7-97d1-667705ad2223' for lock type
> 'shared'
> Thread-7808::DEBUG::2012-09-20
> 06:47:02,002::resourceManager::528::ResourceManager::(registerResource)
> Resource 'Storage.26187d25-bfcb-40c7-97d1-667705ad2223' is free. Now
> locking as 'shared' (1 active user)
> Thread-7808::DEBUG::2012-09-20
> 06:47:02,002::resourceManager::212::ResourceManager.Request::(grant)
> ResName=`Storage.26187d25-bfcb-40c7-97d1-667705ad2223`ReqID=`83dac2e0-3d55-4ef6-abf3-7b2561814ab4`::Granted
> request
> Thread-7808::DEBUG::2012-09-20
> 06:47:02,003::task::817::TaskManager.Task::(resourceAcquired)
> Task=`b6ef82b2-2986-4b7b-95ba-d5f3cac8ad31`::_resourcesAcquired:
> Storage.26187d25-bfcb-40c7-97d1-667705ad2223 (shared)
> Thread-7808::DEBUG::2012-09-20
> 06:47:02,003::task::978::TaskManager.Task::(_decref)
> Task=`b6ef82b2-2986-4b7b-95ba-d5f3cac8ad31`::ref 1 aborting False
> Thread-7808::INFO::2012-09-20
> 06:47:02,004::logUtils::39::dispatcher::(wrapper) Run and protect:
> getVolumeSize, Return response: {'truesize': '13958643712',
> 'apparentsize': '13958643712'}
> Thread-7808::DEBUG::2012-09-20
> 06:47:02,004::task::1172::TaskManager.Task::(prepare)
> Task=`b6ef82b2-2986-4b7b-95ba-d5f3cac8ad31`::finished: {'truesize':
> '13958643712', 'apparentsize': '13958643712'}
> Thread-7808::DEBUG::2012-09-20
> 06:47:02,004::task::588::TaskManager.Task::(_updateState)
> Task=`b6ef82b2-2986-4b7b-95ba-d5f3cac8ad31`::moving from state
> preparing -> state finished
> Thread-7808::DEBUG::2012-09-20
> 06:47:02,004::resourceManager::809::ResourceManager.Owner::(releaseAll)
> Owner.releaseAll requests {} resources
> {'Storage.26187d25-bfcb-40c7-97d1-667705ad2223': < ResourceRef
> 'Storage.26187d25-bfcb-40c7-97d1-667705ad2223', isValid: 'True' obj:
> 'None'>}
> Thread-7808::DEBUG::2012-09-20
> 06:47:02,004::resourceManager::844::ResourceManager.Owner::(cancelAll)
> Owner.cancelAll requests {}
> Thread-7808::DEBUG::2012-09-20
> 06:47:02,005::resourceManager::538::ResourceManager::(releaseResource)
> Trying to release resource
> 'Storage.26187d25-bfcb-40c7-97d1-667705ad2223'
> Thread-7808::DEBUG::2012-09-20
> 06:47:02,005::resourceManager::553::ResourceManager::(releaseResource)
> Released resource 'Storage.26187d25-bfcb-40c7-97d1-667705ad2223' (0
> active users)
> Thread-7808::DEBUG::2012-09-20
> 06:47:02,005::resourceManager::558::ResourceManager::(releaseResource)
> Resource 'Storage.26187d25-bfcb-40c7-97d1-667705ad2223' is free,
> finding out if anyone is waiting for it.
> Thread-7808::DEBUG::2012-09-20
> 06:47:02,005::resourceManager::565::ResourceManager::(releaseResource)
> No one is waiting for resource
> 'Storage.26187d25-bfcb-40c7-97d1-667705ad2223', Clearing records.
> Thread-7808::DEBUG::2012-09-20
> 06:47:02,005::task::978::TaskManager.Task::(_decref)
> Task=`b6ef82b2-2986-4b7b-95ba-d5f3cac8ad31`::ref 0 aborting False
> Thread-7808::INFO::2012-09-20
> 06:47:02,006::clientIF::274::vds::(prepareVolumePath) prepared
> volume path:
> Thread-7808::DEBUG::2012-09-20
> 06:47:02,006::task::588::TaskManager.Task::(_updateState)
> Task=`83579cfe-4384-4b76-8bb0-979ed2b60739`::moving from state init
> -> state preparing
> Thread-7808::INFO::2012-09-20
> 06:47:02,006::logUtils::37::dispatcher::(wrapper) Run and protect:
> prepareImage(sdUUID='26187d25-bfcb-40c7-97d1-667705ad2223',
> spUUID='332694bb-364a-434e-b23f-5fef985d3cbd',
> imgUUID='0a7013db-68fd-4c42-bc2e-cc8d7a05ca18',
> volUUID='f184ecd1-0001-4739-af71-250b412345d6')
> Thread-7808::DEBUG::2012-09-20
> 06:47:02,007::resourceManager::175::ResourceManager.Request::(__init__)
> ResName=`Storage.26187d25-bfcb-40c7-97d1-667705ad2223`ReqID=`c22e6209-b86d-448c-8884-372ce9a589c4`::Request
> was made in '/usr/share/vdsm/storage/resourceManager.py' line '485'
> at 'registerResource'
> Thread-7808::DEBUG::2012-09-20
> 06:47:02,007::resourceManager::486::ResourceManager::(registerResource)
> Trying to register resource
> 'Storage.26187d25-bfcb-40c7-97d1-667705ad2223' for lock type
> 'shared'
> Thread-7808::DEBUG::2012-09-20
> 06:47:02,007::resourceManager::528::ResourceManager::(registerResource)
> Resource 'Storage.26187d25-bfcb-40c7-97d1-667705ad2223' is free. Now
> locking as 'shared' (1 active user)
> Thread-7808::DEBUG::2012-09-20
> 06:47:02,007::resourceManager::212::ResourceManager.Request::(grant)
> ResName=`Storage.26187d25-bfcb-40c7-97d1-667705ad2223`ReqID=`c22e6209-b86d-448c-8884-372ce9a589c4`::Granted
> request
> Thread-7808::DEBUG::2012-09-20
> 06:47:02,008::task::817::TaskManager.Task::(resourceAcquired)
> Task=`83579cfe-4384-4b76-8bb0-979ed2b60739`::_resourcesAcquired:
> Storage.26187d25-bfcb-40c7-97d1-667705ad2223 (shared)
> Thread-7808::DEBUG::2012-09-20
> 06:47:02,008::task::978::TaskManager.Task::(_decref)
> Task=`83579cfe-4384-4b76-8bb0-979ed2b60739`::ref 1 aborting False
> Thread-7808::DEBUG::2012-09-20
> 06:47:02,008::__init__::1249::Storage.Misc.excCmd::(_log)
> '/usr/bin/dd iflag=direct skip=4 bs=512
> if=/dev/26187d25-bfcb-40c7-97d1-667705ad2223/metadata count=1' (cwd
> None)
> Thread-7808::DEBUG::2012-09-20
> 06:47:02,023::__init__::1249::Storage.Misc.excCmd::(_log) SUCCESS:
> <err> = '1+0 records in\n1+0 records out\n512 bytes (512 B) copied,
> 0.000766795 s, 668 kB/s\n'; <rc> = 0
> Thread-7808::DEBUG::2012-09-20
> 06:47:02,023::misc::314::Storage.Misc::(validateDDBytes) err: ['1+0
> records in', '1+0 records out', '512 bytes (512 B) copied,
> 0.000766795 s, 668 kB/s'], size: 512
> Thread-7808::INFO::2012-09-20
> 06:47:02,023::image::357::Storage.Image::(getChain)
> sdUUID=26187d25-bfcb-40c7-97d1-667705ad2223
> imgUUID=0a7013db-68fd-4c42-bc2e-cc8d7a05ca18 chain=
> Thread-7808::INFO::2012-09-20
> 06:47:02,024::logUtils::39::dispatcher::(wrapper) Run and protect:
> prepareImage, Return response: {'path':
> '/rhev/data-center/332694bb-364a-434e-b23f-5fef985d3cbd/26187d25-bfcb-40c7-97d1-667705ad2223/images/0a7013db-68fd-4c42-bc2e-cc8d7a05ca18/f184ecd1-0001-4739-af71-250b412345d6',
> 'chain': [{'path':
> '/rhev/data-center/332694bb-364a-434e-b23f-5fef985d3cbd/26187d25-bfcb-40c7-97d1-667705ad2223/images/0a7013db-68fd-4c42-bc2e-cc8d7a05ca18/f184ecd1-0001-4739-af71-250b412345d6',
> 'domainID': '26187d25-bfcb-40c7-97d1-667705ad2223', 'volumeID':
> 'f184ecd1-0001-4739-af71-250b412345d6', 'imageID':
> '0a7013db-68fd-4c42-bc2e-cc8d7a05ca18'}]}
> Thread-7808::DEBUG::2012-09-20
> 06:47:02,024::task::1172::TaskManager.Task::(prepare)
> Task=`83579cfe-4384-4b76-8bb0-979ed2b60739`::finished: {'path':
> '/rhev/data-center/332694bb-364a-434e-b23f-5fef985d3cbd/26187d25-bfcb-40c7-97d1-667705ad2223/images/0a7013db-68fd-4c42-bc2e-cc8d7a05ca18/f184ecd1-0001-4739-af71-250b412345d6',
> 'chain': [{'path':
> '/rhev/data-center/332694bb-364a-434e-b23f-5fef985d3cbd/26187d25-bfcb-40c7-97d1-667705ad2223/images/0a7013db-68fd-4c42-bc2e-cc8d7a05ca18/f184ecd1-0001-4739-af71-250b412345d6',
> 'domainID': '26187d25-bfcb-40c7-97d1-667705ad2223', 'volumeID':
> 'f184ecd1-0001-4739-af71-250b412345d6', 'imageID':
> '0a7013db-68fd-4c42-bc2e-cc8d7a05ca18'}]}
> Thread-7808::DEBUG::2012-09-20
> 06:47:02,024::task::588::TaskManager.Task::(_updateState)
> Task=`83579cfe-4384-4b76-8bb0-979ed2b60739`::moving from state
> preparing -> state finished
> Thread-7808::DEBUG::2012-09-20
> 06:47:02,025::resourceManager::809::ResourceManager.Owner::(releaseAll)
> Owner.releaseAll requests {} resources
> {'Storage.26187d25-bfcb-40c7-97d1-667705ad2223': < ResourceRef
> 'Storage.26187d25-bfcb-40c7-97d1-667705ad2223', isValid: 'True' obj:
> 'None'>}
> Thread-7808::DEBUG::2012-09-20
> 06:47:02,025::resourceManager::844::ResourceManager.Owner::(cancelAll)
> Owner.cancelAll requests {}
> Thread-7808::DEBUG::2012-09-20
> 06:47:02,025::resourceManager::538::ResourceManager::(releaseResource)
> Trying to release resource
> 'Storage.26187d25-bfcb-40c7-97d1-667705ad2223'
> Thread-7808::DEBUG::2012-09-20
> 06:47:02,025::resourceManager::553::ResourceManager::(releaseResource)
> Released resource 'Storage.26187d25-bfcb-40c7-97d1-667705ad2223' (0
> active users)
> Thread-7808::DEBUG::2012-09-20
> 06:47:02,026::resourceManager::558::ResourceManager::(releaseResource)
> Resource 'Storage.26187d25-bfcb-40c7-97d1-667705ad2223' is free,
> finding out if anyone is waiting for it.
> Thread-7808::DEBUG::2012-09-20
> 06:47:02,026::resourceManager::565::ResourceManager::(releaseResource)
> No one is waiting for resource
> 'Storage.26187d25-bfcb-40c7-97d1-667705ad2223', Clearing records.
> Thread-7808::DEBUG::2012-09-20
> 06:47:02,026::task::978::TaskManager.Task::(_decref)
> Task=`83579cfe-4384-4b76-8bb0-979ed2b60739`::ref 0 aborting False
> Thread-7808::INFO::2012-09-20
> 06:47:02,026::clientIF::274::vds::(prepareVolumePath) prepared
> volume path:
> /rhev/data-center/332694bb-364a-434e-b23f-5fef985d3cbd/26187d25-bfcb-40c7-97d1-667705ad2223/images/0a7013db-68fd-4c42-bc2e-cc8d7a05ca18/f184ecd1-0001-4739-af71-250b412345d6
> Thread-7808::DEBUG::2012-09-20
> 06:47:02,037::libvirtvm::1338::vm.Vm::(_run)
> vmId=`509e608c-e657-473a-b031-f0811da96bde`::<?xml version="1.0"
> encoding="utf-8"?>
> <domain type="kvm">
> <name>CentOS6Thames</name>
> <uuid>509e608c-e657-473a-b031-f0811da96bde</uuid>
> <memory>1048576</memory>
> <currentMemory>1048576</currentMemory>
> <vcpu>1</vcpu>
> <devices>
> <channel type="unix">
> <target name="com.redhat.rhevm.vdsm" type="virtio"/>
> <source mode="bind"
> path="/var/lib/libvirt/qemu/channels/CentOS6Thames.com.redhat.rhevm.vdsm"/>
> </channel>
> <input bus="ps2" type="mouse"/>
> <channel type="spicevmc">
> <target name="com.redhat.spice.0" type="virtio"/>
> </channel>
> <graphics autoport="yes" keymap="en-us" passwd="*****"
> passwdValidTo="1970-01-01T00:00:01" port="-1" tlsPort="-1"
> type="spice">
> <channel mode="secure" name="main"/>
> <channel mode="secure" name="inputs"/>
> <channel mode="secure" name="cursor"/>
> <channel mode=&quo t;secure" name="playback"/>
> <channel mode="secure" name="record"/>
> <channel mode="secure" name="display"/>
> <listen network="vdsm-ovirtmgmt" type="network"/>
> </graphics>
> <console type="pty">
> <target port="0" type="virtio"/>
> </console>
> <controller type="usb">
> <address domain="0x0000" function="0x2" slot="0x01" type="pci"
> bus="0x00"/>
> </controller>
> <video>
> <address domain="0x0000" function="0x0" slot="0x02" type="pci"
> bus="0x00"/>
> <model heads="1" type="qxl" vram="65536"/>
> </video>
> <interface type="bridge">
> <address domain="0x0000" function="0x0" slot="0x03" type="pci"
> bus="0x00"/>
> <mac address="00:1a:4a:a8:0a:00"/>
> <model type="virtio"/>
> <source bridge="ovirtmgmt"/>
> </interface>
> <memballoon model="virtio"/>
> <disk device="cdrom" snapshot="no" type="file">
> <address bus="1" controller="0" target="0" type="drive" unit="0"/>
> <source file="" startupPolicy="optional"/>
> <target bus="ide" dev="hdc"/>
> <readonly/>
> <serial></serial>
> </disk>
> <disk device="disk" snapshot="no" type="block">
> <address domain="0x0000" function="0x0" slot="0x05" type="pci"
> bus="0x00"/>
> <source
> dev="/rhev/data-center/332694bb-364a-434e-b23f-5fef985d3cbd/26187d25-bfcb-40c7-97d1-667705ad2223/images/0a7013db-68fd-4c42-bc2e-cc8d7a05ca18/f184ecd1-0001-4739-af71-250b412345d6"/>
> <target bus="virtio" dev="vda"/>
> <serial>0a7013db-68fd-4c42-bc2e-cc8d7a05ca18</serial>
> <driver cache="none" error_policy="stop" io="native" name="qemu"
> type="qcow2"/>
> </disk>
> </devices>
> <os>
> <type arch="x86_64" machine="pc-0.14">hvm</type>
> <smbios mode="sysinfo"/>
> </os>
> <sysinfo type="smbios">
> <system>
> <entry name="manufacturer">Red Hat</entry>
> <entry name="product">RHEV Hypervisor</entry>
> <entry name="version">17-1</entry>
> <entry
> name="serial">31323334-3535-4C44-3643-4D5633393936_00:19:bb:39:97:4a</entry>
> <entry name="uuid">509e608c-e657-473a-b031-f0811da96bde</entry>
> </system>
> </sysinfo>
> <clock adjustment="-1" offset="variable">
> <timer name="rtc" tickpolicy="catchup"/>
> </clock>
> <features>
> <acpi/>
> </features>
> <cpu match="exact">
> <model>Conroe</model>
> <topology cores="1" sockets="1" threads="1"/>
> </cpu>
> </domain>

> Thread-7808::DEBUG::2012-09-20
> 06:47:02,426::vm::580::vm.Vm::(_startUnderlyingVm)
> vmId=`509e608c-e657-473a-b031-f0811da96bde`::_ongoingCreations
> released
> Thread-7808::ERROR::2012-09-20
> 06:47:02,427::vm::604::vm.Vm::(_startUnderlyingVm)
> vmId=`509e608c-e657-473a-b031-f0811da96bde`::The vm start process
> failed
> Traceback (most recent call last):
> File "/usr/share/vdsm/vm.py", line 570, in _startUnderlyingVm
> File "/usr/share/vdsm/libvirtvm.py", line 1364, in _run
> File "/usr/lib/python2.7/site-packages/vdsm/libvirtconnection.py",
> line 82, in wrapper
> File "/usr/lib64/python2.7/site-packages/libvirt.py", line 2420, in
> createXML
> libvirtError: unsupported configuration: spice secure channels set in
> XML configuration, but TLS is disabled in qemu.conf
> Thread-7808::DEBUG::2012-09-20
> 06:47:02,430::vm::920::vm.Vm::(setDownStatus)
> vmId=`509e608c-e657-473a-b031-f0811da96bde`::Changed state to Down:
> unsupported configuration: spice secure channels set in XML
> configuration, but TLS is disabled in qemu.conf
> Dummy-1960::DEBUG::2012-09-20
> 06:47:03,145::__init__::1249::Storage.Misc.excCmd::(_log) 'dd
> if=/rhev/data-center/332694bb-364a-434e-b23f-5fef985d3cbd/mastersd/dom_md/inbox
> iflag=direct,fullblock count=1 bs=1024000' (cwd None)
> Dummy-1960::DEBUG::2012-09-20
> 06:47:03,230::__init__::1249::Storage.Misc.excCmd::(_log) SUCCESS:
> <err> = '1+0 records in\n1+0 records out\n1024000 bytes (1.0 MB)
> copied, 0.0496138 s, 20.6 MB/s\n'; <rc> = 0
> Thread-7810::DEBUG::2012-09-20
> 06:47:03,560::BindingXMLRPC::156::vds::(wrapper) [192.168.10.10]
> Thread-7810::DEBUG::2012-09-20
> 06:47:03,561::task::588::TaskManager.Task::(_updateState)
> Task=`9bc08c7e-010f-45c2-940a-3fd8361785d5`::moving from state init
> -> state preparing
> Thread-7810::INFO::2012-09-20
> 06:47:03,561::logUtils::37::dispatcher::(wrapper) Run and protect:
> getSpmStatus(spUUID='332694bb-364a-434e-b23f-5fef985d3cbd',
> options=None)
> Thread-7810::INFO::2012-09-20
> 06:47:03,562::logUtils::39::dispatcher::(wrapper) Run and protect:
> getSpmStatus, Return response: {'spm_st': {'spmId': 3, 'spmStatus':
> 'SPM', 'spmLver': 0}}
> Thread-7810::DEBUG::2012-09-20
> 06:47:03,562::task::1172::TaskManager.Task::(prepare)
> Task=`9bc08c7e-010f-45c2-940a-3fd8361785d5`::finished: {'spm_st':
> {'spmId': 3, 'spmStatus': 'SPM', 'spmLver': 0}}
> Thread-7810::DEBUG::2012-09-20
> 06:47:03,562::task::588::TaskManager.Task::(_updateState)
> Task=`9bc08c7e-010f-45c2-940a-3fd8361785d5`::moving from state
> preparing -> state finished
> Thread-7810::DEBUG::2012-09-20
> 06:47:03,562::resourceManager::809::ResourceManager.Owner::(releaseAll)
> Owner.releaseAll requests {} resources {}
> Thread-7810::DEBUG::2012-09-20
> 06:47:03,562::resourceManager::844::ResourceManager.Owner::(cancelAll)
> Owner.cancelAll requests {}
> Thread-7810::DEBUG::2012-09-20
> 06:47:03,563::task::978::TaskManager.Task::(_decref)
> Task=`9bc08c7e-010f-45c2-940a-3fd8361785d5`::ref 0 aborting False
> Thread-7812::DEBUG::2012-09-20
> 06:47:03,595::BindingXMLRPC::156::vds::(wrapper) [192.168.10.10]
> Thread-7812::DEBUG::2012-09-20
> 06:47:03,595::task::588::TaskManager.Task::(_updateState)
> Task=`8e330204-753f-422d-b286-a360410806be`::moving from state init
> -> state preparing
> Thread-7812::INFO::2012-09-20
> 06:47:03,596::logUtils::37::dispatcher::(wrapper) Run and protect:
> getStoragePoolInfo(spUUID='332694bb-364a-434e-b23f-5fef985d3cbd',
> options=None)
> Thread-7812::DEBUG::2012-09-20
> 06:47:03,596::resourceManager::175::ResourceManager.Request::(__init__)
> ResName=`Storage.332694bb-364a-434e-b23f-5fef985d3cbd`ReqID=`a7222834-3565-4e28-a15f-72692ef664c6`::Request
> was made in '/usr/share/vdsm/storage/resourceManager.py' line '485'
> at 'registerResource'
> Thread-7812::DEBUG::2012-09-20
> 06:47:03,596::resourceManager::486::ResourceManager::(registerResource)
> Trying to register resource
> 'Storage.332694bb-364a-434e-b23f-5fef985d3cbd' for lock type
> 'shared'
> Thread-7812::DEBUG::2012-09-20
> 06:47:03,597::resourceManager::528::ResourceManager::(registerResource)
> Resource 'Storage.332694bb-364a-434e-b23f-5fef985d3cbd' is free. Now
> locking as 'shared' (1 active user)
> Thread-7812::DEBUG::2012-09-20
> 06:47:03,597::resourceManager::212::ResourceManager.Request::(grant)
> ResName=`Storage.332694bb-364a-434e-b23f-5fef985d3cbd`ReqID=`a7222834-3565-4e28-a15f-72692ef664c6`::Granted
> request
> Thread-7812::DEBUG::2012-09-20
> 06:47:03,597::task::817::TaskManager.Task::(resourceAcquired)
> Task=`8e330204-753f-422d-b286-a360410806be`::_resourcesAcquired:
> Storage.332694bb-364a-434e-b23f-5fef985d3cbd (shared)
> Thread-7812::DEBUG::2012-09-20
> 06:47:03,598::task::978::TaskManager.Task::(_decref)
> Task=`8e330204-753f-422d-b286-a360410806be`::ref 1 aborting False
> Thread-7813::DEBUG::2012-09-20
> 06:47:03,598::BindingXMLRPC::859::vds::(wrapper) client
> [192.168.10.10]::call vmGetStats with
> ('509e608c-e657-473a-b031-f0811da96bde',) {}
> Thread-7812::INFO::2012-09-20
> 06:47:03,599::logUtils::39::dispatcher::(wrapper) Run and protect:
> getStoragePoolInfo, Return response: {'info': {'spm_id': 3,
> 'master_uuid': '26187d25-bfcb-40c7-97d1-667705ad2223', 'name':
> 'Valeka', 'version': '2', 'domains':
> u'26187d25-bfcb-40c7-97d1-667705ad2223:Active,90104c3d-837b-47dd-8c82-dda92eec30d9:Active',
> 'pool_status': 'connected', 'isoprefix':
> u'/rhev/data-center/332694bb-364a-434e-b23f-5fef985d3cbd/90104c3d-837b-47dd-8c82-dda92eec30d9/images/11111111-1111-1111-1111-111111111111',
> 'type': 'ISCSI', 'master_ver': 1, 'lver': 0}, 'dominfo':
> {u'26187d25-bfcb-40c7-97d1-667705ad2223': {'status': u'Active',
> 'diskfree': '1674097721344', 'alerts': [], 'disktotal':
> '1799591297024'}, u'90104c3d-837b-47dd-8c82-dda92eec30d9':
> {'status': u'Active', 'diskfree': '423518535680', 'alerts': [],
> 'disktotal': '492264226816'}}}
> Thread-7813::DEBUG::2012-09-20
> 06:47:03,600::BindingXMLRPC::865::vds::(wrapper) return vmGetStats
> with {'status': {'message': 'Done', 'code': 0}, 'statsList':
> [{'status': 'Down', 'hash': '0', 'exitMessage': 'unsupported
> configuration: spice secure channels set in XML configuration, but
> TLS is disabled in qemu.conf', 'vmId':
> '509e608c-e657-473a-b031-f0811da96bde', 'timeOffset': '-1',
> 'exitCode': 1}]}
> Thread-7812::DEBUG::2012-09-20
> 06:47:03,600::task::1172::TaskManager.Task::(prepare)
> Task=`8e330204-753f-422d-b286-a360410806be`::finished: {'info':
> {'spm_id': 3, 'master_uuid': '26187d25-bfcb-40c7-97d1-667705ad2223',
> 'name': 'Valeka', 'version': '2', 'domains':
> u'26187d25-bfcb-40c7-97d1-667705ad2223:Active,90104c3d-837b-47dd-8c82-dda92eec30d9:Active',
> 'pool_status': 'connected', 'isoprefix':
> u'/rhev/data-center/332694bb-364a-434e-b23f-5fef985d3cbd/90104c3d-837b-47dd-8c82-dda92eec30d9/images/11111111-1111-1111-1111-111111111111',
> 'type': 'ISCSI', 'master_ver': 1, 'lver': 0}, 'dominfo':
> {u'26187d25-bfcb-40c7-97d1-667705ad2223': {'status': u'Active',
> 'diskfree': '1674097721344', 'alerts': [], 'disktotal':
> '1799591297024'}, u'90104c3d-837b-47dd-8c82-dda92eec30d9':
> {'status': u'Active', 'diskfree': '423518535680', 'alerts': [],
> 'disktotal': '492264226816'}}}
> Thread-7812::DEBUG::2012-09-20
> 06:47:03,601::task::588::TaskManager.Task::(_updateState)
> Task=`8e330204-753f-422d-b286-a360410806be`::moving from state
> preparing -> state finished
> Thread-7812::DEBUG::2012-09-20
> 06:47:03,601::resourceManager::809::ResourceManager.Owner::(releaseAll)
> Owner.releaseAll requests {} resources
> {'Storage.332694bb-364a-434e-b23f-5fef985d3cbd': < ResourceRef
> 'Storage.332694bb-364a-434e-b23f-5fef985d3cbd', isValid: 'True' obj:
> 'None'>}
> Thread-7812::DEBUG::2012-09-20
> 06:47:03,601::resourceManager::844::ResourceManager.Owner::(cancelAll)
> Owner.cancelAll requests {}
> Thread-7812::DEBUG::2012-09-20
> 06:47:03,602::resourceManager::538::ResourceManager::(releaseResource)
> Trying to release resource
> 'Storage.332694bb-364a-434e-b23f-5fef985d3cbd'
> Thread-7812::DEBUG::2012-09-20
> 06:47:03,602::resourceManager::553::ResourceManager::(releaseResource)
> Released resource 'Storage.332694bb-364a-434e-b23f-5fef985d3cbd' (0
> active users)
> Thread-7812::DEBUG::2012-09-20
> 06:47:03,602::resourceManager::558::ResourceManager::(releaseResource)
> Resource 'Storage.332694bb-364a-434e-b23f-5fef985d3cbd' is free,
> finding out if anyone is waiting for it.
> Thread-7812::DEBUG::2012-09-20
> 06:47:03,602::resourceManager::565::ResourceManager::(releaseResource)
> No one is waiting for resource
> 'Storage.332694bb-364a-434e-b23f-5fef985d3cbd', Clearing records.
> Thread-7812::DEBUG::2012-09-20
> 06:47:03,602::task::978::TaskManager.Task::(_decref)
> Task=`8e330204-753f-422d-b286-a360410806be`::ref 0 aborting False
> Thread-7814::DEBUG::2012-09-20
> 06:47:03,658::BindingXMLRPC::859::vds::(wrapper) client
> [192.168.10.10]::call vmDestroy with
> ('509e608c-e657-473a-b031-f0811da96bde',) {}
> Thread-7814::INFO::2012-09-20 06:47:03,658::API::317::vds::(destroy)
> vmContainerLock acquired by vm 509e608c-e657-473a-b031-f0811da96bde
> Thread-7814::DEBUG::2012-09-20
> 06:47:03,658::libvirtvm::2085::vm.Vm::(destroy)
> vmId=`509e608c-e657-473a-b031-f0811da96bde`::destroy Called
> Thread-7814::INFO::2012-09-20
> 06:47:03,658::libvirtvm::2040::vm.Vm::(releaseVm)
> vmId=`509e608c-e657-473a-b031-f0811da96bde`::Release VM resources
> Thread-7814::WARNING::2012-09-20
> 06:47:03,659::vm::328::vm.Vm::(_set_lastStatus)
> vmId=`509e608c-e657-473a-b031-f0811da96bde`::trying to set state to
> Powering down when already Down
> Thread-7814::DEBUG::2012-09-20
> 06:47:03,659::__init__::1249::Storage.Misc.excCmd::(_log)
> '/usr/bin/sudo -n /usr/sbin/service ksmtuned retune' (cwd None)
> Thread-7814::DEBUG::2012-09-20
> 06:47:03,696::__init__::1249::Storage.Misc.excCmd::(_log) FAILED:
> <err> = 'Redirecting to /bin/systemctl retune
> ksmtuned.service\nUnknown operation retune\n'; <rc> = 1
> Thread-7814::DEBUG::2012-09-20
> 06:47:03,697::task::588::TaskManager.Task::(_updateState)
> Task=`e97820bb-547d-4e7a-9249-ece94285bac8`::moving from state init
> -> state preparing
> Thread-7814::INFO::2012-09-20
> 06:47:03,698::logUtils::37::dispatcher::(wrapper) Run and protect:
> inappropriateDevices(thiefId='509e608c-e657-473a-b031-f0811da96bde')
> Thread-7814::INFO::2012-09-20
> 06:47:03,699::logUtils::39::dispatcher::(wrapper) Run and protect:
> inappropriateDevices, Return response: None
> Thread-7814::DEBUG::2012-09-20
> 06:47:03,699::task::1172::TaskManager.Task::(prepare)
> Task=`e97820bb-547d-4e7a-9249-ece94285bac8`::finished: None
> Thread-7814::DEBUG::2012-09-20
> 06:47:03,700::task::588::TaskManager.Task::(_updateState)
> Task=`e97820bb-547d-4e7a-9249-ece94285bac8`::moving from state
> preparing -> state finished
> Thread-7814::DEBUG::2012-09-20
> 06:47:03,700::resourceManager::809::ResourceManager.Owner::(releaseAll)
> Owner.releaseAll requests {} resources {}
> Thread-7814::DEBUG::2012-09-20
> 06:47:03,700::resourceManager::844::ResourceManager.Owner::(cancelAll)
> Owner.cancelAll requests {}
> Thread-7814::DEBUG::2012-09-20
> 06:47:03,700::task::978::TaskManager.Task::(_decref)
> Task=`e97820bb-547d-4e7a-9249-ece94285bac8`::ref 0 aborting False
> Thread-7814::DEBUG::2012-09-20
> 06:47:03,700::libvirtvm::2080::vm.Vm::(deleteVm)
> vmId=`509e608c-e657-473a-b031-f0811da96bde`::Total desktops after
> destroy of 509e608c-e657-473a-b031-f0811da96bde is 0
> Thread-7814::DEBUG::2012-09-20
> 06:47:03,701::BindingXMLRPC::865::vds::(wrapper) return vmDestroy
> with {'status': {'message': 'Machine destroyed', 'code': 0}}
> Thread-481::DEBUG::2012-09-20
> 06:47:04,302::__init__::1249::Storage.Misc.excCmd::(_log)
> '/usr/bin/dd iflag=direct
> if=/dev/26187d25-bfcb-40c7-97d1-667705ad2223/metadata bs=4096
> count=1' (cwd None)
> Thread-481::DEBUG::2012-09-20
> 06:47:04,317::__init__::1249::Storage.Misc.excCmd::(_log) SUCCESS:
> <err> = '1+0 records in\n1+0 records out\n4096 bytes (4.1 kB)
> copied, 0.000843551 s, 4.9 MB/s\n'; <rc> = 0
> Dummy-1960::DEBUG::2012-09-20
> 06:47:05,239::__init__::1249::Storage.Misc.excCmd::(_log) 'dd
> if=/rhev/data-center/332694bb-364a-434e-b23f-5fef985d3cbd/mastersd/dom_md/inbox
> iflag=direct,fullblock count=1 bs=1024000' (cwd None)
> Dummy-1960::DEBUG::2012-09-20
> 06:47:05,323::__init__::1249::Storage.Misc.excCmd::(_log) SUCCESS:
> <err> = '1+0 records in\n1+0 records out\n1024000 bytes (1.0 MB)
> copied, 0.0476578 s, 21.5 MB/s\n'; <rc> = 0
> Thread-7815::DEBUG::2012-09-20
> 06:47:05,819::task::588::TaskManager.Task::(_updateState)
> Task=`ef5f39d0-241c-44b5-a771-da364468b498`::moving from state init
> -> state preparing
> Thread-7815::INFO::2012-09-20
> 06:47:05,819::logUtils::37::dispatcher::(wrapper) Run and protect:
> repoStats(options=None)
> Thread-7815::INFO::2012-09-20
> 06:47:05,820::logUtils::39::dispatcher::(wrapper) Run and protect:
> repoStats, Return response: {'26187d25-bfcb-40c7-97d1-667705ad2223':
> {'delay': '0.0156102180481', 'lastCheck': 1348123624.512314, 'code':
> 0, 'valid': True}, '90104c3d-837b-47dd-8c82-dda92eec30d9': {'delay':
> '0.0011830329895', 'lastCheck': 1348123617.41074, 'code': 0,
> 'valid': True}}
> Thread-7815::DEBUG::2012-09-20
> 06:47:05,820::task::1172::TaskManager.Task::(prepare)
> Task=`ef5f39d0-241c-44b5-a771-da364468b498`::finished:
> {'26187d25-bfcb-40c7-97d1-667705ad2223': {'delay':
> '0.0156102180481', 'lastCheck': 1348123624.512314, 'code': 0,
> 'valid': True}, '90104c3d-837b-47dd-8c82-dda92eec30d9': {'delay':
> '0.0011830329895', 'lastCheck': 1348123617.41074, 'code': 0,
> 'valid': True}}
> Thread-7815::DEBUG::2012-09-20
> 06:47:05,820::task::588::TaskManager.Task::(_updateState)
> Task=`ef5f39d0-241c-44b5-a771-da364468b498`::moving from state
> preparing -> state finished
> Thread-7815::DEBUG::2012-09-20
> 06:47:05,820::resourceManager::809::ResourceManager.Owner::(releaseAll)
> Owner.releaseAll requests {} resources {}
> Thread-7815::DEBUG::2012-09-20
> 06:47:05,821::resourceManager::844::ResourceManager.Owner::(cancelAll)
> Owner.cancelAll requests {}
> Thread-7815::DEBUG::2012-09-20
> 06:47:05,821::task::978::TaskManager.Task::(_decref)
> Task=`ef5f39d0-241c-44b5-a771-da364468b498`::ref 0 aborting False
> Dummy-1960::DEBUG::2012-09-20
> 06:47:07,332::__init__::1249::Storage.Misc.excCmd::(_log) 'dd
> if=/rhev/data-center/332694bb-364a-434e-b23f-5fef985d3cbd/mastersd/dom_md/inbox
> iflag=direct,fullblock count=1 bs=1024000' (cwd None)
> Dummy-1960::DEBUG::2012-09-20
> 06:47:07,458::__init__::1249::Storage.Misc.excCmd::(_log) SUCCESS:
> <err> = '1+0 records in\n1+0 records out\n1024000 bytes (1.0 MB)
> copied, 0.0478973 s, 21.4 MB/s\n'; <rc> = 0
> Dummy-1960::DEBUG::2012-09-20
> 06:47:09,502::__init__::1249::Storage.Misc.excCmd::(_log) 'dd
> if=/rhev/data-center/332694bb-364a-434e-b23f-5fef985d3cbd/mastersd/dom_md/inbox
> iflag=direct,fullblock count=1 bs=1024000' (cwd None)
> Dummy-1960::DEBUG::2012-09-20
> 06:47:09,586::__init__::1249::Storage.Misc.excCmd::(_log) SUCCESS:
> <err> = '1+0 records in\n1+0 records out\n1024000 bytes (1.0 MB)
> copied, 0.0485543 s, 21.1 MB/s\n'; <rc> = 0

> If I try to create new server I have the same error message.

> - -
> Dmitriy Pyryakov

> VimpelCom Ltd.
> _______________________________________________
> Users mailing list
> Users@ovirt.org
> http://lists.ovirt.org/mailman/listinfo/users

------=_Part_2519270_1306423749.1348126859097
Content-Type: text/html; charset=utf-8
Content-Transfer-Encoding: quoted-printable

<html><head><style type=3D'text/css'>p { margin: 0; }</style></head><body><=
div style=3D'font-family: times new roman,new york,times,serif; font-size: =
12pt; color: #000000'>Hi Dmitriy.<br>This is a bit odd, since indeed action=
 asks to secure all spice channels,<br><br><font size=3D"2" face=3D"sans-se=
rif"><graphics autoport=3D"yes"=20
keymap=3D"en-us" passwd=3D"*****" passwdValidTo=3D"1970-01-01T00:00:01"=20
port=3D"-1" tlsPort=3D"-1" type=3D"spice"></font><br>
<font size=3D"2" face=3D"sans-serif">                        <channel mo=
de=3D"secure" name=3D"main"/></font><br>
<font size=3D"2" face=3D"sans-serif">                        <channel mo=
de=3D"secure" name=3D"inputs"/></font><br>
<font size=3D"2" face=3D"sans-serif">                        <channel mo=
de=3D"secure" name=3D"cursor"/></font><br>
<font size=3D"2" face=3D"sans-serif">                        <channel mo=
de=3D&quo
t;secure" name=3D"playback"/></font><br>
<font size=3D"2" face=3D"sans-serif">                        <channel mo=
de=3D"secure" name=3D"record"/></font><br>
<font size=3D"2" face=3D"sans-serif">                        <channel mo=
de=3D"secure" name=3D"display"/></font><br><br>but this is introduced on=
ly for development 3.2 clusters.<br>You can see it by running: <br>echo "se=
lect * from vdc_options where option_name like '%SpiceSecureChannels%'" | p=
sql -d engine -U postgres<br><br>So...<br>1. Please check your cluster vers=
ion (you should be using 3.1) and please report.<br>2. As a temporary worka=
round, either set libvirt to support spice encryption (in<br>/etc/libvirt/q=
emu.conf set spice_tls =3D 1, but there may be other needed settings)<br>or=
 you can try to set SpiceSecureChannels to what we have in previous version=
s<br>(smain,sinputs or even nothing just for sanity).<br><br>Check and let =
us know how it works.<br><br><br><hr id=3D"zwchr"><blockquote style=3D"bord=
er-left:2px solid rgb(16, 16, 255);margin-left:5px;padding-left:5px;color:#=
000;font-weight:normal;font-style:normal;text-decoration:none;font-family:H=
elvetica,Arial,sans-serif;font-size:12pt;"><b>From: </b>"Dmitriy A Pyryakov=
" <DPyryakov@ekb.beeline.ru><br><b>To: </b>users@ovirt.org<br><b>Sent=
: </b>Thursday, September 20, 2012 9:49:24 AM<br><b>Subject: </b>[Users] Ho=
st migration problem<br><br>
<p><font size=3D"2" face=3D"sans-serif">Hello,</font><br>
<br>
<font size=3D"2" face=3D"sans-serif">Yesturday I broke my two Fedora 17  ho=
sts.</font><br>
<font size=3D"2" face=3D"sans-serif">Today I install two ovirt nodes (first=
 - 2.5.0-2.0.fc17, second - 2.5.1-1.0.fc17). SPM on 2.5.0-2.0.fc17.</font><=
br>
<br>
<font size=3D"2" face=3D"sans-serif">Now, I can't run any of my existing vi=
rtual machines. Exit message: unsupported configuration: spice secure chann=
els set in XML configuration, but TLS is disabled in qemu.conf.</font>
</p><ul style=3D"padding-left: 0pt"><font size=3D"2" face=3D"sans-serif"><b=
r>
</font><br>
<font size=3D"2" face=3D"sans-serif">engine.log:</font></ul>
<font size=3D"2" face=3D"sans-serif">[root@admin ~]# tail -f -n 0 /var/log/=
ovirt-engine/engine.log</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:53,289 INFO  [org.ovi=
rt.engine.core.vdsbroker.irsbroker.IsValidVDSCommand] (ajp--0.0.0.0-8009-10=
) START, IsValidVDSCommand(storagePoolId =3D 332694bb-364a-434e-b23f-5fef98=
5d3cbd, ignoreFailoverLimit =3D false, compatabilityVersion =3D null), log =
id: 7c90c641</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:53,294 INFO  [org.ovi=
rt.engine.core.vdsbroker.irsbroker.IsValidVDSCommand] (ajp--0.0.0.0-8009-10=
) FINISH, IsValidVDSCommand, return: true, log id: 7c90c641</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:53,332 INFO  [org.ovi=
rt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (ajp--0.0.0.0-8009=
-10) START, IsVmDuringInitiatingVDSCommand(vmId =3D 509e608c-e657-473a-b031=
-f0811da96bde), log id: 243c74f7</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:53,334 INFO  [org.ovi=
rt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (ajp--0.0.0.0-8009=
-10) FINISH, IsVmDuringInitiatingVDSCommand, return: false, log id: 243c74f=
7</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:53,403 INFO  [org.ovi=
rt.engine.core.bll.RunVmCommand] (pool-3-thread-50) [a58d974] Lock Acquired=
 to object EngineLock [exclusiveLocks=3D key: 509e608c-e657-473a-b031-f0811=
da96bde value: VM</font><br>
<font size=3D"2" face=3D"sans-serif">, sharedLocks=3D ]</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:53,415 INFO  [org.ovi=
rt.engine.core.bll.RunVmCommand] (pool-3-thread-50) [a58d974] Running comma=
nd: RunVmCommand internal: false. Entities affected :  ID: 509e608c-e657-47=
3a-b031-f0811da96bde Type: VM</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:53,504 INFO  [org.ovi=
rt.engine.core.vdsbroker.CreateVmVDSCommand] (pool-3-thread-50) [a58d974] S=
TART, CreateVmVDSCommand(vdsId =3D 0a268762-02d7-11e2-b750-0011856cf23e, vm=
Id=3D509e608c-e657-473a-b031-f0811da96bde, vm=3Dorg.ovirt.engine.core.commo=
n.businessentities.VM@1911737b), log id: 77c0e559</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:53,529 INFO  [org.ovi=
rt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand] (pool-3-thread-50) [a5=
8d974] START, CreateVDSCommand(vdsId =3D 0a268762-02d7-11e2-b750-0011856cf2=
3e, vmId=3D509e608c-e657-473a-b031-f0811da96bde, vm=3Dorg.ovirt.engine.core=
.common.businessentities.VM@1911737b), log id: f48008f</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:53,602 INFO  [org.ovi=
rt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand] (pool-3-thread-50) [a5=
8d974] org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand spiceSslC=
ipherSuite=3DDEFAULT,memSize=3D1024,kvmEnable=3Dtrue,smp=3D1,emulatedMachin=
e=3Dpc-0.14,vmType=3Dkvm,keyboardLayout=3Den-us,pitReinjection=3Dfalse,nice=
=3D0,display=3Dqxl,smpCoresPerSocket=3D1,spiceSecureChannels=3Dsmain,sinput=
s,scursor,splayback,srecord,sdisplay,displayNetwork=3Dovirtmgmt,timeOffset=
=3D-1,transparentHugePages=3Dtrue,vmId=3D509e608c                          =
  -e657-473a-b031-f0811da96bde,devices=3D[Ljava.util.Map;@760db68c,acpiEnab=
le=3Dtrue,vmName=3DCentOS6Thames,cpuType=3DConroe,custom=3D{device_bb912edd=
-9790-43ff-a758-f1d9f20cb5f5device_f5c86859-5ae9-4a37-9d34-2b9547609622devi=
ce_20a11f26-6a39-415d-a7bf-95893b9c55b5=3DVmId=3D509e608c-e657-473a-b031-f0=
811da96bde,DeviceId=3D20a11f26-6a39-415d-a7bf-95893b9c55b5,Device=3Dunix,Ty=
pe=3Dchannel,BootOrder=3D0,SpecParams=3D{},Address=3D{port=3D1, bus=3D0, co=
ntroller=3D0, type=3Dvirtio-serial},IsManaged=3Dfalse,IsPlugged=3Dtrue,IsRe=
adOnly=3Dfalse,alias=3D                            channel0, device_bb912ed=
d-9790-43ff-a758-f1d9f20cb5f5=3DVmId=3D509e608c-e657-473a-b031-f0811da96bde=
,DeviceId=3Dbb912edd-9790-43ff-a758-f1d9f20cb5f5,Device=3Dide,Type=3Dcontro=
ller,BootOrder=3D0,SpecParams=3D{},Address=3D{bus=3D0x00, domain=3D0x0000, =
type=3Dpci, slot=3D0x01, function=3D0x1},IsManaged=3Dfalse,IsPlugged=3Dtrue=
,IsReadOnly=3Dfalse,alias=3Dide0, device_bb912edd-9790-43ff-a758-f1d9f20cb5=
f5device_f5c86859-5ae9-4a37-9d34-2b9547609622=3DVmId=3D509e608c-e657-473a-b=
031-f0811da96bde,DeviceId=3Df5c86859-5ae9-4a37-9d34-2b9547609622,Devic     =
                       e=3Dvirtio-serial,Type=3Dcontroller,BootOrder=3D0,Sp=
ecParams=3D{},Address=3D{bus=3D0x00, domain=3D0x0000, type=3Dpci, slot=3D0x=
04, function=3D0x0},IsManaged=3Dfalse,IsPlugged=3Dtrue,IsReadOnly=3Dfalse,a=
lias=3Dvirtio-serial0, device_bb912edd-9790-43ff-a758-f1d9f20cb5f5device_f5=
c86859-5ae9-4a37-9d34-2b9547609622device_20a11f26-6a39-415d-a7bf-95893b9c55=
b5device_21f255dc-9b3b-48d8-b8e4-63c1635e269b=3DVmId=3D509e608c-e657-473a-b=
031-f0811da96bde,DeviceId=3D21f255dc-9b3b-48d8-b8e4-63c1635e269b,Device=3Ds=
picevmc,Type=3Dchannel,BootOrder=3D0,SpecP                            arams=
=3D{},Address=3D{port=3D2, bus=3D0, controller=3D0, type=3Dvirtio-serial},I=
sManaged=3Dfalse,IsPlugged=3Dtrue,IsReadOnly=3Dfalse,alias=3Dchannel1, devi=
ce_bb912edd-9790-43ff-a758-f1d9f20cb5f5device_f5c86859-5ae9-4a37-9d34-2b954=
7609622device_20a11f26-6a39-415d-a7bf-95893b9c55b5device_21f255dc-9b3b-48d8=
-b8e4-63c1635e269bdevice_d6c2c4d1-da6b-44fe-a5aa-508135c7fdfe=3DVmId=3D509e=
608c-e657-473a-b031-f0811da96bde,DeviceId=3Dd6c2c4d1-da6b-44fe-a5aa-508135c=
7fdfe,Device=3Dusb,Type=3Dcontroller,BootOrder=3D0,SpecParams=3D{},Address=
=3D{bus=3D0x0                            0, domain=3D0x0000, type=3Dpci, sl=
ot=3D0x01, function=3D0x2},IsManaged=3Dfalse,IsPlugged=3Dtrue,IsReadOnly=3D=
false,alias=3Dusb0}</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:53,625 INFO  [org.ovi=
rt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand] (pool-3-thread-50) [a5=
8d974] FINISH, CreateVDSCommand, log id: f48008f</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:53,659 INFO  [org.ovi=
rt.engine.core.vdsbroker.CreateVmVDSCommand] (pool-3-thread-50) [a58d974] I=
ncreasePendingVms::CreateVmIncreasing vds hyper1.ovirt.com pending vcpu cou=
nt, now 1. Vm: CentOS6Thames</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:53,671 INFO  [org.ovi=
rt.engine.core.vdsbroker.CreateVmVDSCommand] (pool-3-thread-50) [a58d974] F=
INISH, CreateVmVDSCommand, return: WaitForLaunch, log id: 77c0e559</font><b=
r>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:53,684 INFO  [org.ovi=
rt.engine.core.bll.RunVmCommand] (pool-3-thread-50) [a58d974] Lock freed to=
 object EngineLock [exclusiveLocks=3D key: 509e608c-e657-473a-b031-f0811da9=
6bde value: VM</font><br>
<font size=3D"2" face=3D"sans-serif">, sharedLocks=3D ]</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:54,418 INFO  [org.ovi=
rt.engine.core.vdsbroker.vdsbroker.DestroyVDSCommand] (QuartzScheduler_Work=
er-12) START, DestroyVDSCommand(vdsId =3D 0a268762-02d7-11e2-b750-0011856cf=
23e, vmId=3D509e608c-e657-473a-b031-f0811da96bde, force=3Dfalse, secondsToW=
ait=3D0, gracefully=3Dfalse), log id: 2f059be9</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:54,486 INFO  [org.ovi=
rt.engine.core.vdsbroker.vdsbroker.DestroyVDSCommand] (QuartzScheduler_Work=
er-12) FINISH, DestroyVDSCommand, log id: 2f059be9</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:54,520 INFO  [org.ovi=
rt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (QuartzScheduler_Worker-12) =
Running on vds during rerun failed vm: null</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:54,523 INFO  [org.ovi=
rt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (QuartzScheduler_Worker-12) =
vm CentOS6Thames running in db and not running in vds - add to rerun treatm=
ent. vds hyper1.ovirt.com</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:54,536 ERROR [org.ovi=
rt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (QuartzScheduler_Worker-12) =
Rerun vm 509e608c-e657-473a-b031-f0811da96bde. Called from vds hyper1.ovirt=
.com</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:54,557 INFO  [org.ovi=
rt.engine.core.vdsbroker.UpdateVdsDynamicDataVDSCommand] (pool-3-thread-50)=
 START, UpdateVdsDynamicDataVDSCommand(vdsId =3D 0a268762-02d7-11e2-b750-00=
11856cf23e, vdsDynamic=3Dorg.ovirt.engine.core.common.businessentities.VdsD=
ynamic@db702e05), log id: 71c6e6a3</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:54,564 INFO  [org.ovi=
rt.engine.core.vdsbroker.UpdateVdsDynamicDataVDSCommand] (pool-3-thread-50)=
 FINISH, UpdateVdsDynamicDataVDSCommand, log id: 71c6e6a3</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:54,584 INFO  [org.ovi=
rt.engine.core.bll.RunVmCommand] (pool-3-thread-50) Lock Acquired to object=
 EngineLock [exclusiveLocks=3D key: 509e608c-e657-473a-b031-f0811da96bde va=
lue: VM</font><br>
<font size=3D"2" face=3D"sans-serif">, sharedLocks=3D ]</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:54,603 INFO  [org.ovi=
rt.engine.core.vdsbroker.irsbroker.IsValidVDSCommand] (pool-3-thread-50) ST=
ART, IsValidVDSCommand(storagePoolId =3D 332694bb-364a-434e-b23f-5fef985d3c=
bd, ignoreFailoverLimit =3D false, compatabilityVersion =3D null), log id: =
f1903fc</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:54,614 INFO  [org.ovi=
rt.engine.core.vdsbroker.irsbroker.IsValidVDSCommand] (pool-3-thread-50) FI=
NISH, IsValidVDSCommand, return: true, log id: f1903fc</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:54,653 INFO  [org.ovi=
rt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (pool-3-thread-50)=
 START, IsVmDuringInitiatingVDSCommand(vmId =3D 509e608c-e657-473a-b031-f08=
11da96bde), log id: 5b0d9779</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:54,655 INFO  [org.ovi=
rt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (pool-3-thread-50)=
 FINISH, IsVmDuringInitiatingVDSCommand, return: false, log id: 5b0d9779</f=
ont><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:54,712 INFO  [org.ovi=
rt.engine.core.bll.RunVmCommand] (pool-3-thread-50) Running command: RunVmC=
ommand internal: false. Entities affected :  ID: 509e608c-e657-473a-b031-f0=
811da96bde Type: VM</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:54,800 INFO  [org.ovi=
rt.engine.core.vdsbroker.CreateVmVDSCommand] (pool-3-thread-50) START, Crea=
teVmVDSCommand(vdsId =3D 9840e840-02db-11e2-a01a-0011856cf23e, vmId=3D509e6=
08c-e657-473a-b031-f0811da96bde, vm=3Dorg.ovirt.engine.core.common.business=
entities.VM@4432a01d), log id: 554a0742</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:54,825 INFO  [org.ovi=
rt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand] (pool-3-thread-50) STA=
RT, CreateVDSCommand(vdsId =3D 9840e840-02db-11e2-a01a-0011856cf23e, vmId=
=3D509e608c-e657-473a-b031-f0811da96bde, vm=3Dorg.ovirt.engine.core.common.=
businessentities.VM@4432a01d), log id: 73615350</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:54,912 INFO  [org.ovi=
rt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand] (pool-3-thread-50) org=
.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand spiceSslCipherSuite=
=3DDEFAULT,memSize=3D1024,kvmEnable=3Dtrue,smp=3D1,emulatedMachine=3Dpc-0.1=
4,vmType=3Dkvm,keyboardLayout=3Den-us,pitReinjection=3Dfalse,nice=3D0,displ=
ay=3Dqxl,smpCoresPerSocket=3D1,spiceSecureChannels=3Dsmain,sinputs,scursor,=
splayback,srecord,sdisplay,displayNetwork=3Dovirtmgmt,timeOffset=3D-1,trans=
parentHugePages=3Dtrue,vmId=3D509e608c-e657-473a                           =
 -b031-f0811da96bde,devices=3D[Ljava.util.Map;@41d42882,acpiEnable=3Dtrue,v=
mName=3DCentOS6Thames,cpuType=3DConroe,custom=3D{device_bb912edd-9790-43ff-=
a758-f1d9f20cb5f5device_f5c86859-5ae9-4a37-9d34-2b9547609622device_20a11f26=
-6a39-415d-a7bf-95893b9c55b5=3DVmId=3D509e608c-e657-473a-b031-f0811da96bde,=
DeviceId=3D20a11f26-6a39-415d-a7bf-95893b9c55b5,Device=3Dunix,Type=3Dchanne=
l,BootOrder=3D0,SpecParams=3D{},Address=3D{port=3D1, bus=3D0, controller=3D=
0, type=3Dvirtio-serial},IsManaged=3Dfalse,IsPlugged=3Dtrue,IsReadOnly=3Dfa=
lse,alias=3Dchannel0,                             device_bb912edd-9790-43ff=
-a758-f1d9f20cb5f5=3DVmId=3D509e608c-e657-473a-b031-f0811da96bde,DeviceId=
=3Dbb912edd-9790-43ff-a758-f1d9f20cb5f5,Device=3Dide,Type=3Dcontroller,Boot=
Order=3D0,SpecParams=3D{},Address=3D{bus=3D0x00, domain=3D0x0000, type=3Dpc=
i, slot=3D0x01, function=3D0x1},IsManaged=3Dfalse,IsPlugged=3Dtrue,IsReadOn=
ly=3Dfalse,alias=3Dide0, device_bb912edd-9790-43ff-a758-f1d9f20cb5f5device_=
f5c86859-5ae9-4a37-9d34-2b9547609622=3DVmId=3D509e608c-e657-473a-b031-f0811=
da96bde,DeviceId=3Df5c86859-5ae9-4a37-9d34-2b9547609622,Device=3Dvirtio-s  =
                          erial,Type=3Dcontroller,BootOrder=3D0,SpecParams=
=3D{},Address=3D{bus=3D0x00, domain=3D0x0000, type=3Dpci, slot=3D0x04, func=
tion=3D0x0},IsManaged=3Dfalse,IsPlugged=3Dtrue,IsReadOnly=3Dfalse,alias=3Dv=
irtio-serial0, device_bb912edd-9790-43ff-a758-f1d9f20cb5f5device_f5c86859-5=
ae9-4a37-9d34-2b9547609622device_20a11f26-6a39-415d-a7bf-95893b9c55b5device=
_21f255dc-9b3b-48d8-b8e4-63c1635e269b=3DVmId=3D509e608c-e657-473a-b031-f081=
1da96bde,DeviceId=3D21f255dc-9b3b-48d8-b8e4-63c1635e269b,Device=3Dspicevmc,=
Type=3Dchannel,BootOrder=3D0,SpecParams=3D{},A                            d=
dress=3D{port=3D2, bus=3D0, controller=3D0, type=3Dvirtio-serial},IsManaged=
=3Dfalse,IsPlugged=3Dtrue,IsReadOnly=3Dfalse,alias=3Dchannel1, device_bb912=
edd-9790-43ff-a758-f1d9f20cb5f5device_f5c86859-5ae9-4a37-9d34-2b9547609622d=
evice_20a11f26-6a39-415d-a7bf-95893b9c55b5device_21f255dc-9b3b-48d8-b8e4-63=
c1635e269bdevice_d6c2c4d1-da6b-44fe-a5aa-508135c7fdfe=3DVmId=3D509e608c-e65=
7-473a-b031-f0811da96bde,DeviceId=3Dd6c2c4d1-da6b-44fe-a5aa-508135c7fdfe,De=
vice=3Dusb,Type=3Dcontroller,BootOrder=3D0,SpecParams=3D{},Address=3D{bus=
=3D0x00, domain=3D                            0x0000, type=3Dpci, slot=3D0x=
01, function=3D0x2},IsManaged=3Dfalse,IsPlugged=3Dtrue,IsReadOnly=3Dfalse,a=
lias=3Dusb0}</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:54,982 INFO  [org.ovi=
rt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand] (pool-3-thread-50) FIN=
ISH, CreateVDSCommand, log id: 73615350</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:55,004 INFO  [org.ovi=
rt.engine.core.vdsbroker.CreateVmVDSCommand] (pool-3-thread-50) IncreasePen=
dingVms::CreateVmIncreasing vds hyper2.ovirt.com pending vcpu count, now 1.=
 Vm: CentOS6Thames</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:55,012 INFO  [org.ovi=
rt.engine.core.vdsbroker.CreateVmVDSCommand] (pool-3-thread-50) FINISH, Cre=
ateVmVDSCommand, return: WaitForLaunch, log id: 554a0742</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:55,022 INFO  [org.ovi=
rt.engine.core.bll.RunVmCommand] (pool-3-thread-50) Lock freed to object En=
gineLock [exclusiveLocks=3D key: 509e608c-e657-473a-b031-f0811da96bde value=
: VM</font><br>
<font size=3D"2" face=3D"sans-serif">, sharedLocks=3D ]</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:56,434 INFO  [org.ovi=
rt.engine.core.vdsbroker.vdsbroker.DestroyVDSCommand] (QuartzScheduler_Work=
er-32) START, DestroyVDSCommand(vdsId =3D 9840e840-02db-11e2-a01a-0011856cf=
23e, vmId=3D509e608c-e657-473a-b031-f0811da96bde, force=3Dfalse, secondsToW=
ait=3D0, gracefully=3Dfalse), log id: 6b44f6c9</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:56,497 INFO  [org.ovi=
rt.engine.core.vdsbroker.vdsbroker.DestroyVDSCommand] (QuartzScheduler_Work=
er-32) FINISH, DestroyVDSCommand, log id: 6b44f6c9</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:56,532 INFO  [org.ovi=
rt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (QuartzScheduler_Worker-32) =
Running on vds during rerun failed vm: null</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:56,535 INFO  [org.ovi=
rt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (QuartzScheduler_Worker-32) =
vm CentOS6Thames running in db and not running in vds - add to rerun treatm=
ent. vds hyper2.ovirt.com</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:56,548 ERROR [org.ovi=
rt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (QuartzScheduler_Worker-32) =
Rerun vm 509e608c-e657-473a-b031-f0811da96bde. Called from vds hyper2.ovirt=
.com</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:56,582 INFO  [org.ovi=
rt.engine.core.vdsbroker.UpdateVdsDynamicDataVDSCommand] (pool-3-thread-50)=
 START, UpdateVdsDynamicDataVDSCommand(vdsId =3D 9840e840-02db-11e2-a01a-00=
11856cf23e, vdsDynamic=3Dorg.ovirt.engine.core.common.businessentities.VdsD=
ynamic@5f1dd7c7), log id: 2a191f9e</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:56,596 INFO  [org.ovi=
rt.engine.core.vdsbroker.UpdateVdsDynamicDataVDSCommand] (pool-3-thread-50)=
 FINISH, UpdateVdsDynamicDataVDSCommand, log id: 2a191f9e</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:56,616 INFO  [org.ovi=
rt.engine.core.bll.RunVmCommand] (pool-3-thread-50) Lock Acquired to object=
 EngineLock [exclusiveLocks=3D key: 509e608c-e657-473a-b031-f0811da96bde va=
lue: VM</font><br>
<font size=3D"2" face=3D"sans-serif">, sharedLocks=3D ]</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:56,632 INFO  [org.ovi=
rt.engine.core.vdsbroker.irsbroker.IsValidVDSCommand] (pool-3-thread-50) ST=
ART, IsValidVDSCommand(storagePoolId =3D 332694bb-364a-434e-b23f-5fef985d3c=
bd, ignoreFailoverLimit =3D false, compatabilityVersion =3D null), log id: =
4629f11d</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:56,636 INFO  [org.ovi=
rt.engine.core.vdsbroker.irsbroker.IsValidVDSCommand] (pool-3-thread-50) FI=
NISH, IsValidVDSCommand, return: true, log id: 4629f11d</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:56,672 INFO  [org.ovi=
rt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (pool-3-thread-50)=
 START, IsVmDuringInitiatingVDSCommand(vmId =3D 509e608c-e657-473a-b031-f08=
11da96bde), log id: f3a60e</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:56,675 INFO  [org.ovi=
rt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (pool-3-thread-50)=
 FINISH, IsVmDuringInitiatingVDSCommand, return: false, log id: f3a60e</fon=
t><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:56,713 WARN  [org.ovi=
rt.engine.core.bll.RunVmCommand] (pool-3-thread-50) CanDoAction of action R=
unVm failed. Reasons:VAR__ACTION__RUN,VAR__TYPE__VM,VAR__ACTION__RUN,VAR__T=
YPE__VM,VAR__ACTION__RUN,VAR__TYPE__VM,VAR__ACTION__RUN,VAR__TYPE__VM,ACTIO=
N_TYPE_FAILED_VDS_VM_CLUSTER</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:56,717 INFO  [org.ovi=
rt.engine.core.bll.RunVmCommand] (pool-3-thread-50) Lock freed to object En=
gineLock [exclusiveLocks=3D key: 509e608c-e657-473a-b031-f0811da96bde value=
: VM</font><br>
<font size=3D"2" face=3D"sans-serif">, sharedLocks=3D ]</font><br>
<br>
<font size=3D"2" face=3D"sans-serif">vdsm.log:</font><br>
<font size=3D"2" face=3D"sans-serif">Dummy-1960::DEBUG::2012-09-20 06:46:58=
,959::__init__::1249::Storage.Misc.excCmd::(_log) 'dd if=3D/rhev/data-cente=
r/332694bb-364a-434e-b23f-5fef985d3cbd/mastersd/dom_md/inbox iflag=3Ddirect=
,fullblock count=3D1 bs=3D1024000' (cwd None)</font><br>
<font size=3D"2" face=3D"sans-serif">Dummy-1960::DEBUG::2012-09-20 06:46:59=
,043::__init__::1249::Storage.Misc.excCmd::(_log) SUCCESS: <err> =3D =
'1+0 records in\n1+0 records out\n1024000 bytes (1.0 MB) copied, 0.0488089 =
s, 21.0 MB/s\n'; <rc> =3D 0</font><br>
<font size=3D"2" face=3D"sans-serif">Dummy-1960::DEBUG::2012-09-20 06:47:01=
,053::__init__::1249::Storage.Misc.excCmd::(_log) 'dd if=3D/rhev/data-cente=
r/332694bb-364a-434e-b23f-5fef985d3cbd/mastersd/dom_md/inbox iflag=3Ddirect=
,fullblock count=3D1 bs=3D1024000' (cwd None)</font><br>
<font size=3D"2" face=3D"sans-serif">Dummy-1960::DEBUG::2012-09-20 06:47:01=
,136::__init__::1249::Storage.Misc.excCmd::(_log) SUCCESS: <err> =3D =
'1+0 records in\n1+0 records out\n1024000 bytes (1.0 MB) copied, 0.0477826 =
s, 21.4 MB/s\n'; <rc> =3D 0</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7807::DEBUG::2012-09-20 06:47:0=
1,991::BindingXMLRPC::859::vds::(wrapper) client [192.168.10.10]::call vmCr=
eate with ({'custom': {'device_bb912edd-9790-43ff-a758-f1d9f20cb5f5device_f=
5c86859-5ae9-4a37-9d34-2b9547609622device_20a11f26-6a39-415d-a7bf-95893b9c5=
5b5device_21f255dc-9b3b-48d8-b8e4-63c1635e269bdevice_d6c2c4d1-da6b-44fe-a5a=
a-508135c7fdfe': 'VmId=3D509e608c-e657-473a-b031-f0811da96bde,DeviceId=3Dd6=
c2c4d1-da6b-44fe-a5aa-508135c7fdfe,Device=3Dusb,Type=3Dcontroller,BootOrder=
=3D0,SpecParams=3D{},Address=3D{bus=3D0x00, domain=3D0x0000, type=3Dpci, sl=
ot=3D0x01, function=3D0x2},IsManaged=3Dfalse,IsPlugged=3Dtrue,IsReadOnly=3D=
false,alias=3Dusb0', 'device_bb912edd-9790-43ff-a758-f1d9f20cb5f5device_f5c=
86859-5ae9-4a37-9d34-2b9547609622device_20a11f26-6a39-415d-a7bf-95893b9c55b=
5device_21f255dc-9b3b-48d8-b8e4-63c1635e269b': 'VmId=3D509e608c-e657-473a-b=
031-f0811da96bde,DeviceId=3D21f255dc-9b3b-48d8-b8e4-63c1635e269b,Device=3Ds=
picevmc,Type=3Dchannel,BootOrder=3D0,SpecParams=3D{},Address=3D{port=3D2, b=
us=3D0, controller=3D0, type=3Dvirtio-serial},IsManaged=3Dfalse,IsPlugged=
=3Dtrue,IsReadOnly=3Dfalse,alias=3Dchannel1', 'device_bb912edd-9790-43ff-a7=
58-f1d9f20cb5f5device_f5c86859-5ae9-4a37-9d34-2b9547609622': 'VmId=3D509e60=
8c-e657-473a-b031-f0811da96bde,DeviceId=3Df5c86859-5ae9-4a37-9d34-2b9547609=
622,Device=3Dvirtio-serial,Type=3Dcontroller,BootOrder=3D0,SpecParams=3D{},=
Address=3D{bus=3D0x00, domain=3D0x0000, type=3Dpci, slot=3D0x04, function=
=3D0x0},IsManaged=3Dfalse,IsPlugged=3Dtrue,IsReadOnly=3Dfalse,alias=3Dvirti=
o-serial0', 'device_bb912edd-9790-43ff-a758-f1d9f20cb5f5device_f5c86859-5ae=
9-4a37-9d34-2b9547609622device_20a11f26-6a39-415d-a7bf-95893b9c55b5': 'VmId=
=3D509e608c-e657-473a-b031-f0811da96bde,DeviceId=3D20a11f26-6a39-415d-a7bf-=
95893b9c55b5,Device=3Dunix,Type=3Dchannel,BootOrder=3D0,SpecParams=3D{},Add=
ress=3D{port=3D1, bus=3D0, controller=3D0, type=3Dvirtio-serial},IsManaged=
=3Dfalse,IsPlugged=3Dtrue,IsReadOnly=3Dfalse,alias=3Dchannel0', 'device_bb9=
12edd-9790-43ff-a758-f1d9f20cb5f5': 'VmId=3D509e608c-e657-473a-b031-f0811da=
96bde,DeviceId=3Dbb912edd-9790-43ff-a758-f1d9f20cb5f5,Device=3Dide,Type=3Dc=
ontroller,BootOrder=3D0,SpecParams=3D{},Address=3D{bus=3D0x00, domain=3D0x0=
000, type=3Dpci, slot=3D0x01, function=3D0x1},IsManaged=3Dfalse,IsPlugged=
=3Dtrue,IsReadOnly=3Dfalse,alias=3Dide0'}, 'keyboardLayout': 'en-us', 'kvmE=
nable': 'true', 'pitReinjection': 'false', 'acpiEnable': 'true', 'emulatedM=
achine': 'pc-0.14', 'displayNetwork': 'ovirtmgmt', 'vmId': '509e608c-e657-4=
73a-b031-f0811da96bde', 'devices': [{'device': 'qxl', 'specParams': {'vram'=
: '65536'}, 'type': 'video', 'deviceId': '20c037f2-11e5-49a5-ace7-741023ec0=
ce9', 'address': {'bus': '0x00', ' slot': '0x02', ' domain': '0x0000', ' ty=
pe': 'pci', ' function': '0x0'}}, {'index': '2', 'iface': 'ide', 'specParam=
s': {'path': ''}, 'readonly': 'true', 'deviceId': '1ed8a73e-be34-4829-a7e3-=
151a7a2efedc', 'address': {' controller': '0', ' target': '0', 'unit': '0',=
 ' bus': '1', ' type': 'drive'}, 'device': 'cdrom', 'path': '', 'type': 'di=
sk'}, {'iface': 'virtio', 'format': 'cow', 'type': 'disk', 'poolID': '33269=
4bb-364a-434e-b23f-5fef985d3cbd', 'volumeID': 'f184ecd1-0001-4739-af71-250b=
412345d6', 'imageID': '0a7013db-68fd-4c42-bc2e-cc8d7a05ca18', 'specParams':=
 {}, 'readonly': 'false', 'domainID': '26187d25-bfcb-40c7-97d1-667705ad2223=
', 'deviceId': '0a7013db-68fd-4c42-bc2e-cc8d7a05ca18', 'address': {'bus': '=
0x00', ' slot': '0x05', ' domain': '0x0000', ' type': 'pci', ' function': '=
0x0'}, 'device': 'disk', 'shared': 'false', 'propagateErrors': 'off', 'opti=
onal': 'false'}, {'nicModel': 'pv', 'macAddr': '00:1a:4a:a8:0a:00', 'networ=
k': 'ovirtmgmt', 'specParams': {}, 'deviceId': '7392f689-2ba3-4243-9629-96b=
192b102a5', 'address': {'bus': '0x00', ' slot': '0x03', ' domain': '0x0000'=
, ' type': 'pci', ' function': '0x0'}, 'device': 'bridge', 'type': 'interfa=
ce'}, {'device': 'usb', 'specParams': {}, 'type': 'controller', 'deviceId':=
 'd6c2c4d1-da6b-44fe-a5aa-508135c7fdfe', 'address': {'bus': '0x00', ' slot'=
: '0x01', ' domain': '0x0000', ' type': 'pci', ' function': '0x2'}}, {'devi=
ce': 'memballoon', 'specParams': {'model': 'virtio'}, 'type': 'balloon', 'd=
eviceId': 'babd73a4-de64-4dce-91b9-e64c5b46c444'}], 'smp': '1', 'vmType': '=
kvm', 'timeOffset': '</font><br>
<font size=3D"2" face=3D"sans-serif">-1', 'memSize': 1024, 'spiceSslCipherS=
uite': 'DEFAULT', 'cpuType': 'Conroe', 'spiceSecureChannels': 'smain,sinput=
s,scursor,splayback,srecord,sdisplay', 'smpCoresPerSocket': '1', 'vmName': =
'CentOS6Thames', 'display': 'qxl', 'transparentHugePages': 'true', 'nice': =
'0'},) {}</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7807::INFO::2012-09-20 06:47:01=
,992::API::228::vds::(create) vmContainerLock acquired by vm 509e608c-e657-=
473a-b031-f0811da96bde</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:47:0=
1,996::vm::564::vm.Vm::(_startUnderlyingVm) vmId=3D`509e608c-e657-473a-b031=
-f0811da96bde`::Start</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7807::DEBUG::2012-09-20 06:47:0=
1,996::API::244::vds::(create) Total desktops after creation of 509e608c-e6=
57-473a-b031-f0811da96bde is 1</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:47:0=
1,997::vm::568::vm.Vm::(_startUnderlyingVm) vmId=3D`509e608c-e657-473a-b031=
-f0811da96bde`::_ongoingCreations acquired</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7807::DEBUG::2012-09-20 06:47:0=
1,997::BindingXMLRPC::865::vds::(wrapper) return vmCreate with {'status': {=
'message': 'Done', 'code': 0}, 'vmList': {'status': 'WaitForLaunch', 'acpiE=
nable': 'true', 'emulatedMachine': 'pc-0.14', 'vmId': '509e608c-e657-473a-b=
031-f0811da96bde', 'pid': '0', 'timeOffset': '-1', 'displayPort': '-1', 'di=
splaySecurePort': '-1', 'spiceSslCipherSuite': 'DEFAULT', 'cpuType': 'Conro=
e', 'custom': {'device_bb912edd-9790-43ff-a758-f1d9f20cb5f5device_f5c86859-=
5ae9-4a37-9d34-2b9547609622device_20a11f26-6a39-415d-a7bf-95893b9c55b5devic=
e_21f255dc-9b3b-48d8-b8e4-63c1635e269bdevice_d6c2c4d1-da6b-44fe-a5aa-508135=
c7fdfe': 'VmId=3D509e608c-e657-473a-b031-f0811da96bde,DeviceId=3Dd6c2c4d1-d=
a6b-44fe-a5aa-508135c7fdfe,Device=3Dusb,Type=3Dcontroller,BootOrder=3D0,Spe=
cParams=3D{},Address=3D{bus=3D0x00, domain=3D0x0000, type=3Dpci, slot=3D0x0=
1, function=3D0x2},IsManaged=3Dfalse,IsPlugged=3Dtrue,IsReadOnly=3Dfalse,al=
ias=3Dusb0', 'device_bb912edd-9790-43ff-a758-f1d9f20cb5f5device_f5c86859-5a=
e9-4a37-9d34-2b9547609622device_20a11f26-6a39-415d-a7bf-95893b9c55b5device_=
21f255dc-9b3b-48d8-b8e4-63c1635e269b': 'VmId=3D509e608c-e657-473a-b031-f081=
1da96bde,DeviceId=3D21f255dc-9b3b-48d8-b8e4-63c1635e269b,Device=3Dspicevmc,=
Type=3Dchannel,BootOrder=3D0,SpecParams=3D{},Address=3D{port=3D2, bus=3D0, =
controller=3D0, type=3Dvirtio-serial},IsManaged=3Dfalse,IsPlugged=3Dtrue,Is=
ReadOnly=3Dfalse,alias=3Dchannel1', 'device_bb912edd-9790-43ff-a758-f1d9f20=
cb5f5device_f5c86859-5ae9-4a37-9d34-2b9547609622': 'VmId=3D509e608c-e657-47=
3a-b031-f0811da96bde,DeviceId=3Df5c86859-5ae9-4a37-9d34-2b9547609622,Device=
=3Dvirtio-serial,Type=3Dcontroller,BootOrder=3D0,SpecParams=3D{},Address=3D=
{bus=3D0x00, domain=3D0x0000, type=3Dpci, slot=3D0x04, function=3D0x0},IsMa=
naged=3Dfalse,IsPlugged=3Dtrue,IsReadOnly=3Dfalse,alias=3Dvirtio-serial0', =
'device_bb912edd-9790-43ff-a758-f1d9f20cb5f5device_f5c86859-5ae9-4a37-9d34-=
2b9547609622device_20a11f26-6a39-415d-a7bf-95893b9c55b5': 'VmId=3D509e608c-=
e657-473a-b031-f0811da96bde,DeviceId=3D20a11f26-6a39-415d-a7bf-95893b9c55b5=
,Device=3Dunix,Type=3Dchannel,BootOrder=3D0,SpecParams=3D{},Address=3D{port=
=3D1, bus=3D0, controller=3D0, type=3Dvirtio-serial},IsManaged=3Dfalse,IsPl=
ugged=3Dtrue,IsReadOnly=3Dfalse,alias=3Dchannel0', 'device_bb912edd-9790-43=
ff-a758-f1d9f20cb5f5': 'VmId=3D509e608c-e657-473a-b031-f0811da96bde,DeviceI=
d=3Dbb912edd-9790-43ff-a758-f1d9f20cb5f5,Device=3Dide,Type=3Dcontroller,Boo=
tOrder=3D0,SpecParams=3D{},Address=3D{bus=3D0x00, domain=3D0x0000, type=3Dp=
ci, slot=3D0x01, function=3D0x1},IsManaged=3Dfalse,IsPlugged=3Dtrue,IsReadO=
nly=3Dfalse,alias=3Dide0'}, 'clientIp': '', 'nicModel': 'rtl8139,pv', 'keyb=
oardLayout': 'en-us', 'kvmEnable': 'true', 'pitReinjection': 'false', 'tran=
sparentHugePages': 'true', 'displayNetwork': 'ovirtmgmt', 'devices': [{'dev=
ice': 'qxl', 'specParams': {'vram': '65536'}, 'type': 'video', 'deviceId': =
'20c037f2-11e5-49a5-ace7-741023ec0ce9', 'address': {'bus': '0x00', ' slot':=
 '0x02', ' domain': '0x0000', ' type': 'pci', ' function': '0x0'}}, {'index=
': '2', 'iface': 'ide', 'specParams': {'path': ''}, 'readonly': 'true', 'de=
viceId': '1ed8a73e-be34-4829-a7e3-151a7a2efedc', 'address': {' controller':=
 '0', ' target': '0', 'unit': '0', ' bus': '1', ' type': 'drive'}, 'device'=
: 'cdrom', 'path': '', 'type': 'disk'}, {'iface': 'virtio', 'format': 'cow'=
, 'type': 'disk', 'poolID': '332694bb-364a-434e-b23f-5fef985d3cbd', 'volume=
ID': 'f184ecd1-0001-4739-af71-250b412345d6', 'imageID': '0a7013db-68fd-4c42=
-bc2e-cc8d7a05ca18', 'specParams': {}, 'readonly': 'false', 'domainID': '26=
187d25-bfcb-40c7-97d1-667705ad2223', 'deviceId': '0a7013db-68fd-4c42-bc2e-c=
c8d7a05ca18', 'address': {'bus': '0x00', ' slot': '0x05', ' domain': '0x000=
0', ' type': 'pci', ' function': '0x0'}, 'device': 'disk', 'shared': 'false=
', 'propagateErrors': 'off', 'optional': 'false'}, {'nicModel': 'pv', 'macA=
ddr': '00:1a:4a:a8:0a:00', 'network': 'ovirtmgmt', 'specParams': {}, 'devic=
eId': '7392f689-2ba3-4243-9629-96b192b102a5', 'address': {'bus': '0x00', ' =
slot': '0x03', ' domain': '0x0000', ' type': 'pci', ' function': '0x0'}, 'd=
evice': 'bridge', 'type': 'interface'}, {'device': 'usb', 'specParams': {},=
 'type': 'controller', 'deviceId': 'd6c2c4d1-da6b-44fe-a5aa-508135c7fdfe', =
'address': {'b</font><br>
<font size=3D"2" face=3D"sans-serif">us': '0x00', ' slot': '0x01', ' domain=
': '0x0000', ' type': 'pci', ' function': '0x2'}}, {'device': 'memballoon',=
 'specParams': {'model': 'virtio'}, 'type': 'balloon', 'deviceId': 'babd73a=
4-de64-4dce-91b9-e64c5b46c444'}], 'smp': '1', 'vmType': 'kvm', 'memSize': 1=
024, 'displayIp': '192.168.10.13', 'spiceSecureChannels': 'smain,sinputs,sc=
ursor,splayback,srecord,sdisplay', 'smpCoresPerSocket': '1', 'vmName': 'Cen=
tOS6Thames', 'display': 'qxl', 'nice': '0'}}</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::INFO::2012-09-20 06:47:01=
,997::libvirtvm::1285::vm.Vm::(_run) vmId=3D`509e608c-e657-473a-b031-f0811d=
a96bde`::VM wrapper has started</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:47:0=
2,000::task::588::TaskManager.Task::(_updateState) Task=3D`b6ef82b2-2986-4b=
7b-95ba-d5f3cac8ad31`::moving from state init -> state preparing</font><=
br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::INFO::2012-09-20 06:47:02=
,001::logUtils::37::dispatcher::(wrapper) Run and protect: getVolumeSize(sd=
UUID=3D'26187d25-bfcb-40c7-97d1-667705ad2223', spUUID=3D'332694bb-364a-434e=
-b23f-5fef985d3cbd', imgUUID=3D'0a7013db-68fd-4c42-bc2e-cc8d7a05ca18', volU=
UID=3D'f184ecd1-0001-4739-af71-250b412345d6', options=3DNone)</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:47:0=
2,001::resourceManager::175::ResourceManager.Request::(__init__) ResName=3D=
`Storage.26187d25-bfcb-40c7-97d1-667705ad2223`ReqID=3D`83dac2e0-3d55-4ef6-a=
bf3-7b2561814ab4`::Request was made in '/usr/share/vdsm/storage/resourceMan=
ager.py' line '485' at 'registerResource'</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:47:0=
2,002::resourceManager::486::ResourceManager::(registerResource) Trying to =
register resource 'Storage.26187d25-bfcb-40c7-97d1-667705ad2223' for lock t=
ype 'shared'</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:47:0=
2,002::resourceManager::528::ResourceManager::(registerResource) Resource '=
Storage.26187d25-bfcb-40c7-97d1-667705ad2223' is free. Now locking as 'shar=
ed' (1 active user)</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:47:0=
2,002::resourceManager::212::ResourceManager.Request::(grant) ResName=3D`St=
orage.26187d25-bfcb-40c7-97d1-667705ad2223`ReqID=3D`83dac2e0-3d55-4ef6-abf3=
-7b2561814ab4`::Granted request</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:47:0=
2,003::task::817::TaskManager.Task::(resourceAcquired) Task=3D`b6ef82b2-298=
6-4b7b-95ba-d5f3cac8ad31`::_resourcesAcquired: Storage.26187d25-bfcb-40c7-9=
7d1-667705ad2223 (shared)</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:47:0=
2,003::task::978::TaskManager.Task::(_decref) Task=3D`b6ef82b2-2986-4b7b-95=
ba-d5f3cac8ad31`::ref 1 aborting False</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::INFO::2012-09-20 06:47:02=
,004::logUtils::39::dispatcher::(wrapper) Run and protect: getVolumeSize, R=
eturn response: {'truesize': '13958643712', 'apparentsize': '13958643712'}<=
/font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:47:0=
2,004::task::1172::TaskManager.Task::(prepare) Task=3D`b6ef82b2-2986-4b7b-9=
5ba-d5f3cac8ad31`::finished: {'truesize': '13958643712', 'apparentsize': '1=
3958643712'}</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:47:0=
2,004::task::588::TaskManager.Task::(_updateState) Task=3D`b6ef82b2-2986-4b=
7b-95ba-d5f3cac8ad31`::moving from state preparing -> state finished</fo=
nt><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:47:0=
2,004::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.rele=
aseAll requests {} resources {'Storage.26187d25-bfcb-40c7-97d1-667705ad2223=
': < ResourceRef 'Storage.26187d25-bfcb-40c7-97d1-667705ad2223', isValid=
: 'True' obj: 'None'>}</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:47:0=
2,004::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cance=
lAll requests {}</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:47:0=
2,005::resourceManager::538::ResourceManager::(releaseResource) Trying to r=
elease resource 'Storage.26187d25-bfcb-40c7-97d1-667705ad2223'</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:47:0=
2,005::resourceManager::553::ResourceManager::(releaseResource) Released re=
source 'Storage.26187d25-bfcb-40c7-97d1-667705ad2223' (0 active users)</fon=
t><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:47:0=
2,005::resourceManager::558::ResourceManager::(releaseResource) Resource 'S=
torage.26187d25-bfcb-40c7-97d1-667705ad2223' is free, finding out if anyone=
 is waiting for it.</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:47:0=
2,005::resourceManager::565::ResourceManager::(releaseResource) No one is w=
aiting for resource 'Storage.26187d25-bfcb-40c7-97d1-667705ad2223', Clearin=
g records.</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:47:0=
2,005::task::978::TaskManager.Task::(_decref) Task=3D`b6ef82b2-2986-4b7b-95=
ba-d5f3cac8ad31`::ref 0 aborting False</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::INFO::2012-09-20 06:47:02=
,006::clientIF::274::vds::(prepareVolumePath) prepared volume path:</font><=
br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:47:0=
2,006::task::588::TaskManager.Task::(_updateState) Task=3D`83579cfe-4384-4b=
76-8bb0-979ed2b60739`::moving from state init -> state preparing</font><=
br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::INFO::2012-09-20 06:47:02=
,006::logUtils::37::dispatcher::(wrapper) Run and protect: prepareImage(sdU=
UID=3D'26187d25-bfcb-40c7-97d1-667705ad2223', spUUID=3D'332694bb-364a-434e-=
b23f-5fef985d3cbd', imgUUID=3D'0a7013db-68fd-4c42-bc2e-cc8d7a05ca18', volUU=
ID=3D'f184ecd1-0001-4739-af71-250b412345d6')</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:47:0=
2,007::resourceManager::175::ResourceManager.Request::(__init__) ResName=3D=
`Storage.26187d25-bfcb-40c7-97d1-667705ad2223`ReqID=3D`c22e6209-b86d-448c-8=
884-372ce9a589c4`::Request was made in '/usr/share/vdsm/storage/resourceMan=
ager.py' line '485' at 'registerResource'</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:47:0=
2,007::resourceManager::486::ResourceManager::(registerResource) Trying to =
register resource 'Storage.26187d25-bfcb-40c7-97d1-667705ad2223' for lock t=
ype 'shared'</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:47:0=
2,007::resourceManager::528::ResourceManager::(registerResource) Resource '=
Storage.26187d25-bfcb-40c7-97d1-667705ad2223' is free. Now locking as 'shar=
ed' (1 active user)</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:47:0=
2,007::resourceManager::212::ResourceManager.Request::(grant) ResName=3D`St=
orage.26187d25-bfcb-40c7-97d1-667705ad2223`ReqID=3D`c22e6209-b86d-448c-8884=
-372ce9a589c4`::Granted request</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:47:0=
2,008::task::817::TaskManager.Task::(resourceAcquired) Task=3D`83579cfe-438=
4-4b76-8bb0-979ed2b60739`::_resourcesAcquired: Storage.26187d25-bfcb-40c7-9=
7d1-667705ad2223 (shared)</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:47:0=
2,008::task::978::TaskManager.Task::(_decref) Task=3D`83579cfe-4384-4b76-8b=
b0-979ed2b60739`::ref 1 aborting False</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:47:0=
2,008::__init__::1249::Storage.Misc.excCmd::(_log) '/usr/bin/dd iflag=3Ddir=
ect skip=3D4 bs=3D512 if=3D/dev/26187d25-bfcb-40c7-97d1-667705ad2223/metada=
ta count=3D1' (cwd None)</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:47:0=
2,023::__init__::1249::Storage.Misc.excCmd::(_log) SUCCESS: <err> =3D=
 '1+0 records in\n1+0 records out\n512 bytes (512 B) copied, 0.000766795 s,=
 668 kB/s\n'; <rc> =3D 0</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:47:0=
2,023::misc::314::Storage.Misc::(validateDDBytes) err: ['1+0 records in', '=
1+0 records out', '512 bytes (512 B) copied, 0.000766795 s, 668 kB/s'], siz=
e: 512</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::INFO::2012-09-20 06:47:02=
,023::image::357::Storage.Image::(getChain) sdUUID=3D26187d25-bfcb-40c7-97d=
1-667705ad2223 imgUUID=3D0a7013db-68fd-4c42-bc2e-cc8d7a05ca18 chain=3D</fon=
t><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::INFO::2012-09-20 06:47:02=
,024::logUtils::39::dispatcher::(wrapper) Run and protect: prepareImage, Re=
turn response: {'path': '/rhev/data-center/332694bb-364a-434e-b23f-5fef985d=
3cbd/26187d25-bfcb-40c7-97d1-667705ad2223/images/0a7013db-68fd-4c42-bc2e-cc=
8d7a05ca18/f184ecd1-0001-4739-af71-250b412345d6', 'chain': [{'path': '/rhev=
/data-center/332694bb-364a-434e-b23f-5fef985d3cbd/26187d25-bfcb-40c7-97d1-6=
67705ad2223/images/0a7013db-68fd-4c42-bc2e-cc8d7a05ca18/f184ecd1-0001-4739-=
af71-250b412345d6', 'domainID': '26187d25-bfcb-40c7-97d1-667705ad2223', 'vo=
lumeID': 'f184ecd1-0001-4739-af71-250b412345d6', 'imageID': '0a7013db-68fd-=
4c42-bc2e-cc8d7a05ca18'}]}</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:47:0=
2,024::task::1172::TaskManager.Task::(prepare) Task=3D`83579cfe-4384-4b76-8=
bb0-979ed2b60739`::finished: {'path': '/rhev/data-center/332694bb-364a-434e=
-b23f-5fef985d3cbd/26187d25-bfcb-40c7-97d1-667705ad2223/images/0a7013db-68f=
d-4c42-bc2e-cc8d7a05ca18/f184ecd1-0001-4739-af71-250b412345d6', 'chain': [{=
'path': '/rhev/data-center/332694bb-364a-434e-b23f-5fef985d3cbd/26187d25-bf=
cb-40c7-97d1-667705ad2223/images/0a7013db-68fd-4c42-bc2e-cc8d7a05ca18/f184e=
cd1-0001-4739-af71-250b412345d6', 'domainID': '26187d25-bfcb-40c7-97d1-6677=
05ad2223', 'volumeID': 'f184ecd1-0001-4739-af71-250b412345d6', 'imageID': '=
0a7013db-68fd-4c42-bc2e-cc8d7a05ca18'}]}</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:47:0=
2,024::task::588::TaskManager.Task::(_updateState) Task=3D`83579cfe-4384-4b=
76-8bb0-979ed2b60739`::moving from state preparing -> state finished</fo=
nt><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:47:0=
2,025::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.rele=
aseAll requests {} resources {'Storage.26187d25-bfcb-40c7-97d1-667705ad2223=
': < ResourceRef 'Storage.26187d25-bfcb-40c7-97d1-667705ad2223', isValid=
: 'True' obj: 'None'>}</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:47:0=
2,025::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cance=
lAll requests {}</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:47:0=
2,025::resourceManager::538::ResourceManager::(releaseResource) Trying to r=
elease resource 'Storage.26187d25-bfcb-40c7-97d1-667705ad2223'</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:47:0=
2,025::resourceManager::553::ResourceManager::(releaseResource) Released re=
source 'Storage.26187d25-bfcb-40c7-97d1-667705ad2223' (0 active users)</fon=
t><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:47:0=
2,026::resourceManager::558::ResourceManager::(releaseResource) Resource 'S=
torage.26187d25-bfcb-40c7-97d1-667705ad2223' is free, finding out if anyone=
 is waiting for it.</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:47:0=
2,026::resourceManager::565::ResourceManager::(releaseResource) No one is w=
aiting for resource 'Storage.26187d25-bfcb-40c7-97d1-667705ad2223', Clearin=
g records.</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:47:0=
2,026::task::978::TaskManager.Task::(_decref) Task=3D`83579cfe-4384-4b76-8b=
b0-979ed2b60739`::ref 0 aborting False</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::INFO::2012-09-20 06:47:02=
,026::clientIF::274::vds::(prepareVolumePath) prepared volume path: /rhev/d=
ata-center/332694bb-364a-434e-b23f-5fef985d3cbd/26187d25-bfcb-40c7-97d1-667=
705ad2223/images/0a7013db-68fd-4c42-bc2e-cc8d7a05ca18/f184ecd1-0001-4739-af=
71-250b412345d6</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:47:0=
2,037::libvirtvm::1338::vm.Vm::(_run) vmId=3D`509e608c-e657-473a-b031-f0811=
da96bde`::<?xml version=3D"1.0" encoding=3D"utf-8"?></font><br>
<font size=3D"2" face=3D"sans-serif"><domain type=3D"kvm"></font><br>
<font size=3D"2" face=3D"sans-serif">        <name>CentOS6Thames</=
name></font><br>
<font size=3D"2" face=3D"sans-serif">        <uuid>509e608c-e657-473a=
-b031-f0811da96bde</uuid></font><br>
<font size=3D"2" face=3D"sans-serif">        <memory>1048576</memo=
ry></font><br>
<font size=3D"2" face=3D"sans-serif">        <currentMemory>1048576&l=
t;/currentMemory></font><br>
<font size=3D"2" face=3D"sans-serif">        <vcpu>1</vcpu></fo=
nt><br>
<font size=3D"2" face=3D"sans-serif">        <devices></font><br>
<font size=3D"2" face=3D"sans-serif">                <channel type=3D"un=
ix"></font><br>
<font size=3D"2" face=3D"sans-serif">                        <target nam=
e=3D"com.redhat.rhevm.vdsm" type=3D"virtio"/></font><br>
<font size=3D"2" face=3D"sans-serif">                        <source mod=
e=3D"bind" path=3D"/var/lib/libvirt/qemu/channels/CentOS6Thames.com.redhat.=
rhevm.vdsm"/></font><br>
<font size=3D"2" face=3D"sans-serif">                </channel></font=
><br>
<font size=3D"2" face=3D"sans-serif">                <input bus=3D"ps2" =
type=3D"mouse"/></font><br>
<font size=3D"2" face=3D"sans-serif">                <channel type=3D"sp=
icevmc"></font><br>
<font size=3D"2" face=3D"sans-serif">                        <target nam=
e=3D"com.redhat.spice.0" type=3D"virtio"/></font><br>
<font size=3D"2" face=3D"sans-serif">                </channel></font=
><br>
<font size=3D"2" face=3D"sans-serif">                <graphics autoport=
=3D"yes" keymap=3D"en-us" passwd=3D"*****" passwdValidTo=3D"1970-01-01T00:0=
0:01" port=3D"-1" tlsPort=3D"-1" type=3D"spice"></font><br>
<font size=3D"2" face=3D"sans-serif">                        <channel mo=
de=3D"secure" name=3D"main"/></font><br>
<font size=3D"2" face=3D"sans-serif">                        <channel mo=
de=3D"secure" name=3D"inputs"/></font><br>
<font size=3D"2" face=3D"sans-serif">                        <channel mo=
de=3D"secure" name=3D"cursor"/></font><br>
<font size=3D"2" face=3D"sans-serif">                        <channel mo=
de=3D&quo
t;secure" name=3D"playback"/></font><br>
<font size=3D"2" face=3D"sans-serif">                        <channel mo=
de=3D"secure" name=3D"record"/></font><br>
<font size=3D"2" face=3D"sans-serif">                        <channel mo=
de=3D"secure" name=3D"display"/></font><br>
<font size=3D"2" face=3D"sans-serif">                        <listen net=
work=3D"vdsm-ovirtmgmt" type=3D"network"/></font><br>
<font size=3D"2" face=3D"sans-serif">                </graphics></fon=
t><br>
<font size=3D"2" face=3D"sans-serif">                <console type=3D"pt=
y"></font><br>
<font size=3D"2" face=3D"sans-serif">                        <target por=
t=3D"0" type=3D"virtio"/></font><br>
<font size=3D"2" face=3D"sans-serif">                </console></font=
><br>
<font size=3D"2" face=3D"sans-serif">                <controller type=3D=
"usb"></font><br>
<font size=3D"2" face=3D"sans-serif">                        <address  d=
omain=3D"0x0000"  function=3D"0x2"  slot=3D"0x01"  type=3D"pci" bus=3D"0x00=
"/></font><br>
<font size=3D"2" face=3D"sans-serif">                </controller></f=
ont><br>
<font size=3D"2" face=3D"sans-serif">                <video></font><b=
r>
<font size=3D"2" face=3D"sans-serif">                        <address  d=
omain=3D"0x0000"  function=3D"0x0"  slot=3D"0x02"  type=3D"pci" bus=3D"0x00=
"/></font><br>
<font size=3D"2" face=3D"sans-serif">                        <model head=
s=3D"1" type=3D"qxl" vram=3D"65536"/></font><br>
<font size=3D"2" face=3D"sans-serif">                </video></font><=
br>
<font size=3D"2" face=3D"sans-serif">                <interface type=3D"=
bridge"></font><br>
<font size=3D"2" face=3D"sans-serif">                        <address  d=
omain=3D"0x0000"  function=3D"0x0"  slot=3D"0x03"  type=3D"pci" bus=3D"0x00=
"/></font><br>
<font size=3D"2" face=3D"sans-serif">                        <mac addres=
s=3D"00:1a:4a:a8:0a:00"/></font><br>
<font size=3D"2" face=3D"sans-serif">                        <model type=
=3D"virtio"/></font><br>
<font size=3D"2" face=3D"sans-serif">                        <source bri=
dge=3D"ovirtmgmt"/></font><br>
<font size=3D"2" face=3D"sans-serif">                </interface></fo=
nt><br>
<font size=3D"2" face=3D"sans-serif">                <memballoon model=
=3D"virtio"/></font><br>
<font size=3D"2" face=3D"sans-serif">                <disk device=3D"cdr=
om" snapshot=3D"no" type=3D"file"></font><br>
<font size=3D"2" face=3D"sans-serif">                        <address  b=
us=3D"1"  controller=3D"0"  target=3D"0"  type=3D"drive" unit=3D"0"/></f=
ont><br>
<font size=3D"2" face=3D"sans-serif">                        <source fil=
e=3D"" startupPolicy=3D"optional"/></font><br>
<font size=3D"2" face=3D"sans-serif">                        <target bus=
=3D"ide" dev=3D"hdc"/></font><br>
<font size=3D"2" face=3D"sans-serif">                        <readonly/&=
gt;</font><br>
<font size=3D"2" face=3D"sans-serif">                        <serial>=
</serial></font><br>
<font size=3D"2" face=3D"sans-serif">                </disk></font><b=
r>
<font size=3D"2" face=3D"sans-serif">                <disk device=3D"dis=
k" snapshot=3D"no" type=3D"block"></font><br>
<font size=3D"2" face=3D"sans-serif">                        <address  d=
omain=3D"0x0000"  function=3D"0x0"  slot=3D"0x05"  type=3D"pci" bus=3D"0x00=
"/></font><br>
<font size=3D"2" face=3D"sans-serif">                        <source dev=
=3D"/rhev/data-center/332694bb-364a-434e-b23f-5fef985d3cbd/26187d25-bfcb-40=
c7-97d1-667705ad2223/images/0a7013db-68fd-4c42-bc2e-cc8d7a05ca18/f184ecd1-0=
001-4739-af71-250b412345d6"/></font><br>
<font size=3D"2" face=3D"sans-serif">                        <target bus=
=3D"virtio" dev=3D"vda"/></font><br>
<font size=3D"2" face=3D"sans-serif">                        <serial>=
0a7013db-68fd-4c42-bc2e-cc8d7a05ca18</serial></font><br>
<font size=3D"2" face=3D"sans-serif">                        <driver cac=
he=3D"none" error_policy=3D"stop" io=3D"native" name=3D"qemu" type=3D"qcow2=
"/></font><br>
<font size=3D"2" face=3D"sans-serif">                </disk></font><b=
r>
<font size=3D"2" face=3D"sans-serif">        </devices></font><br>
<font size=3D"2" face=3D"sans-serif">        <os></font><br>
<font size=3D"2" face=3D"sans-serif">                <type arch=3D"x86_6=
4" machine=3D"pc-0.14">hvm</type></font><br>
<font size=3D"2" face=3D"sans-serif">                <smbios mode=3D"sys=
info"/></font><br>
<font size=3D"2" face=3D"sans-serif">        </os></font><br>
<font size=3D"2" face=3D"sans-serif">        <sysinfo type=3D"smbios">=
;</font><br>
<font size=3D"2" face=3D"sans-serif">                <system></font><=
br>
<font size=3D"2" face=3D"sans-serif">                        <entry name=
=3D"manufacturer">Red Hat</entry></font><br>
<font size=3D"2" face=3D"sans-serif">                        <entry name=
=3D"product">RHEV Hypervisor</entry></font><br>
<font size=3D"2" face=3D"sans-serif">                        <entry name=
=3D"version">17-1</entry></font><br>
<font size=3D"2" face=3D"sans-serif">                        <entry name=
=3D"serial">31323334-3535-4C44-3643-4D5633393936_00:19:bb:39:97:4a</e=
ntry></font><br>
<font size=3D"2" face=3D"sans-serif">                        <entry name=
=3D"uuid">509e608c-e657-473a-b031-f0811da96bde</entry></font><br>
<font size=3D"2" face=3D"sans-serif">                </system></font>=
<br>
<font size=3D"2" face=3D"sans-serif">        </sysinfo></font><br>
<font size=3D"2" face=3D"sans-serif">        <clock adjustment=3D"-1" of=
fset=3D"variable"></font><br>
<font size=3D"2" face=3D"sans-serif">                <timer name=3D"rtc"=
 tickpolicy=3D"catchup"/></font><br>
<font size=3D"2" face=3D"sans-serif">        </clock></font><br>
<font size=3D"2" face=3D"sans-serif">        <features></font><br>
<font size=3D"2" face=3D"sans-serif">                <acpi/></font><b=
r>
<font size=3D"2" face=3D"sans-serif">        </features></font><br>
<font size=3D"2" face=3D"sans-serif">        <cpu match=3D"exact"></f=
ont><br>
<font size=3D"2" face=3D"sans-serif">                <model>Conroe<=
;/model></font><br>
<font size=3D"2" face=3D"sans-serif">                <topology cores=3D"=
1" sockets=3D"1" threads=3D"1"/></font><br>
<font size=3D"2" face=3D"sans-serif">        </cpu></font><br>
<font size=3D"2" face=3D"sans-serif"></domain></font><br>
<br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:47:0=
2,426::vm::580::vm.Vm::(_startUnderlyingVm) vmId=3D`509e608c-e657-473a-b031=
-f0811da96bde`::_ongoingCreations released</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::ERROR::2012-09-20 06:47:0=
2,427::vm::604::vm.Vm::(_startUnderlyingVm) vmId=3D`509e608c-e657-473a-b031=
-f0811da96bde`::The vm start process failed</font><br>
<font size=3D"2" face=3D"sans-serif">Traceback (most recent call last):</fo=
nt><br>
<font size=3D"2" face=3D"sans-serif">  File "/usr/share/vdsm/vm.py", line 5=
70, in _startUnderlyingVm</font><br>
<font size=3D"2" face=3D"sans-serif">  File "/usr/share/vdsm/libvirtvm.py",=
 line 1364, in _run</font><br>
<font size=3D"2" face=3D"sans-serif">  File "/usr/lib/python2.7/site-packag=
es/vdsm/libvirtconnection.py", line 82, in wrapper</font><br>
<font size=3D"2" face=3D"sans-serif">  File "/usr/lib64/python2.7/site-pack=
ages/libvirt.py", line 2420, in createXML</font><br>
<font size=3D"2" face=3D"sans-serif">libvirtError: unsupported configuratio=
n: spice secure channels set in XML configuration, but TLS is disabled in q=
emu.conf</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:47:0=
2,430::vm::920::vm.Vm::(setDownStatus) vmId=3D`509e608c-e657-473a-b031-f081=
1da96bde`::Changed state to Down: unsupported configuration: spice secure c=
hannels set in XML configuration, but TLS is disabled in qemu.conf</font><b=
r>
<font size=3D"2" face=3D"sans-serif">Dummy-1960::DEBUG::2012-09-20 06:47:03=
,145::__init__::1249::Storage.Misc.excCmd::(_log) 'dd if=3D/rhev/data-cente=
r/332694bb-364a-434e-b23f-5fef985d3cbd/mastersd/dom_md/inbox iflag=3Ddirect=
,fullblock count=3D1 bs=3D1024000' (cwd None)</font><br>
<font size=3D"2" face=3D"sans-serif">Dummy-1960::DEBUG::2012-09-20 06:47:03=
,230::__init__::1249::Storage.Misc.excCmd::(_log) SUCCESS: <err> =3D =
'1+0 records in\n1+0 records out\n1024000 bytes (1.0 MB) copied, 0.0496138 =
s, 20.6 MB/s\n'; <rc> =3D 0</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7810::DEBUG::2012-09-20 06:47:0=
3,560::BindingXMLRPC::156::vds::(wrapper) [192.168.10.10]</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7810::DEBUG::2012-09-20 06:47:0=
3,561::task::588::TaskManager.Task::(_updateState) Task=3D`9bc08c7e-010f-45=
c2-940a-3fd8361785d5`::moving from state init -> state preparing</font><=
br>
<font size=3D"2" face=3D"sans-serif">Thread-7810::INFO::2012-09-20 06:47:03=
,561::logUtils::37::dispatcher::(wrapper) Run and protect: getSpmStatus(spU=
UID=3D'332694bb-364a-434e-b23f-5fef985d3cbd', options=3DNone)</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7810::INFO::2012-09-20 06:47:03=
,562::logUtils::39::dispatcher::(wrapper) Run and protect: getSpmStatus, Re=
turn response: {'spm_st': {'spmId': 3, 'spmStatus': 'SPM', 'spmLver': 0}}</=
font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7810::DEBUG::2012-09-20 06:47:0=
3,562::task::1172::TaskManager.Task::(prepare) Task=3D`9bc08c7e-010f-45c2-9=
40a-3fd8361785d5`::finished: {'spm_st': {'spmId': 3, 'spmStatus': 'SPM', 's=
pmLver': 0}}</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7810::DEBUG::2012-09-20 06:47:0=
3,562::task::588::TaskManager.Task::(_updateState) Task=3D`9bc08c7e-010f-45=
c2-940a-3fd8361785d5`::moving from state preparing -> state finished</fo=
nt><br>
<font size=3D"2" face=3D"sans-serif">Thread-7810::DEBUG::2012-09-20 06:47:0=
3,562::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.rele=
aseAll requests {} resources {}</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7810::DEBUG::2012-09-20 06:47:0=
3,562::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cance=
lAll requests {}</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7810::DEBUG::2012-09-20 06:47:0=
3,563::task::978::TaskManager.Task::(_decref) Task=3D`9bc08c7e-010f-45c2-94=
0a-3fd8361785d5`::ref 0 aborting False</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7812::DEBUG::2012-09-20 06:47:0=
3,595::BindingXMLRPC::156::vds::(wrapper) [192.168.10.10]</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7812::DEBUG::2012-09-20 06:47:0=
3,595::task::588::TaskManager.Task::(_updateState) Task=3D`8e330204-753f-42=
2d-b286-a360410806be`::moving from state init -> state preparing</font><=
br>
<font size=3D"2" face=3D"sans-serif">Thread-7812::INFO::2012-09-20 06:47:03=
,596::logUtils::37::dispatcher::(wrapper) Run and protect: getStoragePoolIn=
fo(spUUID=3D'332694bb-364a-434e-b23f-5fef985d3cbd', options=3DNone)</font><=
br>
<font size=3D"2" face=3D"sans-serif">Thread-7812::DEBUG::2012-09-20 06:47:0=
3,596::resourceManager::175::ResourceManager.Request::(__init__) ResName=3D=
`Storage.332694bb-364a-434e-b23f-5fef985d3cbd`ReqID=3D`a7222834-3565-4e28-a=
15f-72692ef664c6`::Request was made in '/usr/share/vdsm/storage/resourceMan=
ager.py' line '485' at 'registerResource'</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7812::DEBUG::2012-09-20 06:47:0=
3,596::resourceManager::486::ResourceManager::(registerResource) Trying to =
register resource 'Storage.332694bb-364a-434e-b23f-5fef985d3cbd' for lock t=
ype 'shared'</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7812::DEBUG::2012-09-20 06:47:0=
3,597::resourceManager::528::ResourceManager::(registerResource) Resource '=
Storage.332694bb-364a-434e-b23f-5fef985d3cbd' is free. Now locking as 'shar=
ed' (1 active user)</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7812::DEBUG::2012-09-20 06:47:0=
3,597::resourceManager::212::ResourceManager.Request::(grant) ResName=3D`St=
orage.332694bb-364a-434e-b23f-5fef985d3cbd`ReqID=3D`a7222834-3565-4e28-a15f=
-72692ef664c6`::Granted request</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7812::DEBUG::2012-09-20 06:47:0=
3,597::task::817::TaskManager.Task::(resourceAcquired) Task=3D`8e330204-753=
f-422d-b286-a360410806be`::_resourcesAcquired: Storage.332694bb-364a-434e-b=
23f-5fef985d3cbd (shared)</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7812::DEBUG::2012-09-20 06:47:0=
3,598::task::978::TaskManager.Task::(_decref) Task=3D`8e330204-753f-422d-b2=
86-a360410806be`::ref 1 aborting False</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7813::DEBUG::2012-09-20 06:47:0=
3,598::BindingXMLRPC::859::vds::(wrapper) client [192.168.10.10]::call vmGe=
tStats with ('509e608c-e657-473a-b031-f0811da96bde',) {}</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7812::INFO::2012-09-20 06:47:03=
,599::logUtils::39::dispatcher::(wrapper) Run and protect: getStoragePoolIn=
fo, Return response: {'info': {'spm_id': 3, 'master_uuid': '26187d25-bfcb-4=
0c7-97d1-667705ad2223', 'name': 'Valeka', 'version': '2', 'domains': u'2618=
7d25-bfcb-40c7-97d1-667705ad2223:Active,90104c3d-837b-47dd-8c82-dda92eec30d=
9:Active', 'pool_status': 'connected', 'isoprefix': u'/rhev/data-center/332=
694bb-364a-434e-b23f-5fef985d3cbd/90104c3d-837b-47dd-8c82-dda92eec30d9/imag=
es/11111111-1111-1111-1111-111111111111', 'type': 'ISCSI', 'master_ver': 1,=
 'lver': 0}, 'dominfo': {u'26187d25-bfcb-40c7-97d1-667705ad2223': {'status'=
: u'Active', 'diskfree': '1674097721344', 'alerts': [], 'disktotal': '17995=
91297024'}, u'90104c3d-837b-47dd-8c82-dda92eec30d9': {'status': u'Active', =
'diskfree': '423518535680', 'alerts': [], 'disktotal': '492264226816'}}}</f=
ont><br>
<font size=3D"2" face=3D"sans-serif">Thread-7813::DEBUG::2012-09-20 06:47:0=
3,600::BindingXMLRPC::865::vds::(wrapper) return vmGetStats with {'status':=
 {'message': 'Done', 'code': 0}, 'statsList': [{'status': 'Down', 'hash': '=
0', 'exitMessage': 'unsupported configuration: spice secure channels set in=
 XML configuration, but TLS is disabled in qemu.conf', 'vmId': '509e608c-e6=
57-473a-b031-f0811da96bde', 'timeOffset': '-1', 'exitCode': 1}]}</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7812::DEBUG::2012-09-20 06:47:0=
3,600::task::1172::TaskManager.Task::(prepare) Task=3D`8e330204-753f-422d-b=
286-a360410806be`::finished: {'info': {'spm_id': 3, 'master_uuid': '26187d2=
5-bfcb-40c7-97d1-667705ad2223', 'name': 'Valeka', 'version': '2', 'domains'=
: u'26187d25-bfcb-40c7-97d1-667705ad2223:Active,90104c3d-837b-47dd-8c82-dda=
92eec30d9:Active', 'pool_status': 'connected', 'isoprefix': u'/rhev/data-ce=
nter/332694bb-364a-434e-b23f-5fef985d3cbd/90104c3d-837b-47dd-8c82-dda92eec3=
0d9/images/11111111-1111-1111-1111-111111111111', 'type': 'ISCSI', 'master_=
ver': 1, 'lver': 0}, 'dominfo': {u'26187d25-bfcb-40c7-97d1-667705ad2223': {=
'status': u'Active', 'diskfree': '1674097721344', 'alerts': [], 'disktotal'=
: '1799591297024'}, u'90104c3d-837b-47dd-8c82-dda92eec30d9': {'status': u'A=
ctive', 'diskfree': '423518535680', 'alerts': [], 'disktotal': '49226422681=
6'}}}</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7812::DEBUG::2012-09-20 06:47:0=
3,601::task::588::TaskManager.Task::(_updateState) Task=3D`8e330204-753f-42=
2d-b286-a360410806be`::moving from state preparing -> state finished</fo=
nt><br>
<font size=3D"2" face=3D"sans-serif">Thread-7812::DEBUG::2012-09-20 06:47:0=
3,601::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.rele=
aseAll requests {} resources {'Storage.332694bb-364a-434e-b23f-5fef985d3cbd=
': < ResourceRef 'Storage.332694bb-364a-434e-b23f-5fef985d3cbd', isValid=
: 'True' obj: 'None'>}</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7812::DEBUG::2012-09-20 06:47:0=
3,601::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cance=
lAll requests {}</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7812::DEBUG::2012-09-20 06:47:0=
3,602::resourceManager::538::ResourceManager::(releaseResource) Trying to r=
elease resource 'Storage.332694bb-364a-434e-b23f-5fef985d3cbd'</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7812::DEBUG::2012-09-20 06:47:0=
3,602::resourceManager::553::ResourceManager::(releaseResource) Released re=
source 'Storage.332694bb-364a-434e-b23f-5fef985d3cbd' (0 active users)</fon=
t><br>
<font size=3D"2" face=3D"sans-serif">Thread-7812::DEBUG::2012-09-20 06:47:0=
3,602::resourceManager::558::ResourceManager::(releaseResource) Resource 'S=
torage.332694bb-364a-434e-b23f-5fef985d3cbd' is free, finding out if anyone=
 is waiting for it.</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7812::DEBUG::2012-09-20 06:47:0=
3,602::resourceManager::565::ResourceManager::(releaseResource) No one is w=
aiting for resource 'Storage.332694bb-364a-434e-b23f-5fef985d3cbd', Clearin=
g records.</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7812::DEBUG::2012-09-20 06:47:0=
3,602::task::978::TaskManager.Task::(_decref) Task=3D`8e330204-753f-422d-b2=
86-a360410806be`::ref 0 aborting False</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7814::DEBUG::2012-09-20 06:47:0=
3,658::BindingXMLRPC::859::vds::(wrapper) client [192.168.10.10]::call vmDe=
stroy with ('509e608c-e657-473a-b031-f0811da96bde',) {}</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7814::INFO::2012-09-20 06:47:03=
,658::API::317::vds::(destroy) vmContainerLock acquired by vm 509e608c-e657=
-473a-b031-f0811da96bde</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7814::DEBUG::2012-09-20 06:47:0=
3,658::libvirtvm::2085::vm.Vm::(destroy) vmId=3D`509e608c-e657-473a-b031-f0=
811da96bde`::destroy Called</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7814::INFO::2012-09-20 06:47:03=
,658::libvirtvm::2040::vm.Vm::(releaseVm) vmId=3D`509e608c-e657-473a-b031-f=
0811da96bde`::Release VM resources</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7814::WARNING::2012-09-20 06:47=
:03,659::vm::328::vm.Vm::(_set_lastStatus) vmId=3D`509e608c-e657-473a-b031-=
f0811da96bde`::trying to set state to Powering down when already Down</font=
><br>
<font size=3D"2" face=3D"sans-serif">Thread-7814::DEBUG::2012-09-20 06:47:0=
3,659::__init__::1249::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /usr/s=
bin/service ksmtuned retune' (cwd None)</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7814::DEBUG::2012-09-20 06:47:0=
3,696::__init__::1249::Storage.Misc.excCmd::(_log) FAILED: <err> =3D =
'Redirecting to /bin/systemctl retune  ksmtuned.service\nUnknown operation =
retune\n'; <rc> =3D 1</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7814::DEBUG::2012-09-20 06:47:0=
3,697::task::588::TaskManager.Task::(_updateState) Task=3D`e97820bb-547d-4e=
7a-9249-ece94285bac8`::moving from state init -> state preparing</font><=
br>
<font size=3D"2" face=3D"sans-serif">Thread-7814::INFO::2012-09-20 06:47:03=
,698::logUtils::37::dispatcher::(wrapper) Run and protect: inappropriateDev=
ices(thiefId=3D'509e608c-e657-473a-b031-f0811da96bde')</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7814::INFO::2012-09-20 06:47:03=
,699::logUtils::39::dispatcher::(wrapper) Run and protect: inappropriateDev=
ices, Return response: None</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7814::DEBUG::2012-09-20 06:47:0=
3,699::task::1172::TaskManager.Task::(prepare) Task=3D`e97820bb-547d-4e7a-9=
249-ece94285bac8`::finished: None</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7814::DEBUG::2012-09-20 06:47:0=
3,700::task::588::TaskManager.Task::(_updateState) Task=3D`e97820bb-547d-4e=
7a-9249-ece94285bac8`::moving from state preparing -> state finished</fo=
nt><br>
<font size=3D"2" face=3D"sans-serif">Thread-7814::DEBUG::2012-09-20 06:47:0=
3,700::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.rele=
aseAll requests {} resources {}</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7814::DEBUG::2012-09-20 06:47:0=
3,700::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cance=
lAll requests {}</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7814::DEBUG::2012-09-20 06:47:0=
3,700::task::978::TaskManager.Task::(_decref) Task=3D`e97820bb-547d-4e7a-92=
49-ece94285bac8`::ref 0 aborting False</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7814::DEBUG::2012-09-20 06:47:0=
3,700::libvirtvm::2080::vm.Vm::(deleteVm) vmId=3D`509e608c-e657-473a-b031-f=
0811da96bde`::Total desktops after destroy of 509e608c-e657-473a-b031-f0811=
da96bde is 0</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7814::DEBUG::2012-09-20 06:47:0=
3,701::BindingXMLRPC::865::vds::(wrapper) return vmDestroy with {'status': =
{'message': 'Machine destroyed', 'code': 0}}</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-481::DEBUG::2012-09-20 06:47:04=
,302::__init__::1249::Storage.Misc.excCmd::(_log) '/usr/bin/dd iflag=3Ddire=
ct if=3D/dev/26187d25-bfcb-40c7-97d1-667705ad2223/metadata bs=3D4096 count=
=3D1' (cwd None)</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-481::DEBUG::2012-09-20 06:47:04=
,317::__init__::1249::Storage.Misc.excCmd::(_log) SUCCESS: <err> =3D =
'1+0 records in\n1+0 records out\n4096 bytes (4.1 kB) copied, 0.000843551 s=
, 4.9 MB/s\n'; <rc> =3D 0</font><br>
<font size=3D"2" face=3D"sans-serif">Dummy-1960::DEBUG::2012-09-20 06:47:05=
,239::__init__::1249::Storage.Misc.excCmd::(_log) 'dd if=3D/rhev/data-cente=
r/332694bb-364a-434e-b23f-5fef985d3cbd/mastersd/dom_md/inbox iflag=3Ddirect=
,fullblock count=3D1 bs=3D1024000' (cwd None)</font><br>
<font size=3D"2" face=3D"sans-serif">Dummy-1960::DEBUG::2012-09-20 06:47:05=
,323::__init__::1249::Storage.Misc.excCmd::(_log) SUCCESS: <err> =3D =
'1+0 records in\n1+0 records out\n1024000 bytes (1.0 MB) copied, 0.0476578 =
s, 21.5 MB/s\n'; <rc> =3D 0</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7815::DEBUG::2012-09-20 06:47:0=
5,819::task::588::TaskManager.Task::(_updateState) Task=3D`ef5f39d0-241c-44=
b5-a771-da364468b498`::moving from state init -> state preparing</font><=
br>
<font size=3D"2" face=3D"sans-serif">Thread-7815::INFO::2012-09-20 06:47:05=
,819::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(option=
s=3DNone)</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7815::INFO::2012-09-20 06:47:05=
,820::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Retur=
n response: {'26187d25-bfcb-40c7-97d1-667705ad2223': {'delay': '0.015610218=
0481', 'lastCheck': 1348123624.512314, 'code': 0, 'valid': True}, '90104c3d=
-837b-47dd-8c82-dda92eec30d9': {'delay': '0.0011830329895', 'lastCheck': 13=
48123617.41074, 'code': 0, 'valid': True}}</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7815::DEBUG::2012-09-20 06:47:0=
5,820::task::1172::TaskManager.Task::(prepare) Task=3D`ef5f39d0-241c-44b5-a=
771-da364468b498`::finished: {'26187d25-bfcb-40c7-97d1-667705ad2223': {'del=
ay': '0.0156102180481', 'lastCheck': 1348123624.512314, 'code': 0, 'valid':=
 True}, '90104c3d-837b-47dd-8c82-dda92eec30d9': {'delay': '0.0011830329895'=
, 'lastCheck': 1348123617.41074, 'code': 0, 'valid': True}}</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7815::DEBUG::2012-09-20 06:47:0=
5,820::task::588::TaskManager.Task::(_updateState) Task=3D`ef5f39d0-241c-44=
b5-a771-da364468b498`::moving from state preparing -> state finished</fo=
nt><br>
<font size=3D"2" face=3D"sans-serif">Thread-7815::DEBUG::2012-09-20 06:47:0=
5,820::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.rele=
aseAll requests {} resources {}</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7815::DEBUG::2012-09-20 06:47:0=
5,821::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cance=
lAll requests {}</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7815::DEBUG::2012-09-20 06:47:0=
5,821::task::978::TaskManager.Task::(_decref) Task=3D`ef5f39d0-241c-44b5-a7=
71-da364468b498`::ref 0 aborting False</font><br>
<font size=3D"2" face=3D"sans-serif">Dummy-1960::DEBUG::2012-09-20 06:47:07=
,332::__init__::1249::Storage.Misc.excCmd::(_log) 'dd if=3D/rhev/data-cente=
r/332694bb-364a-434e-b23f-5fef985d3cbd/mastersd/dom_md/inbox iflag=3Ddirect=
,fullblock count=3D1 bs=3D1024000' (cwd None)</font><br>
<font size=3D"2" face=3D"sans-serif">Dummy-1960::DEBUG::2012-09-20 06:47:07=
,458::__init__::1249::Storage.Misc.excCmd::(_log) SUCCESS: <err> =3D =
'1+0 records in\n1+0 records out\n1024000 bytes (1.0 MB) copied, 0.0478973 =
s, 21.4 MB/s\n'; <rc> =3D 0</font><br>
<font size=3D"2" face=3D"sans-serif">Dummy-1960::DEBUG::2012-09-20 06:47:09=
,502::__init__::1249::Storage.Misc.excCmd::(_log) 'dd if=3D/rhev/data-cente=
r/332694bb-364a-434e-b23f-5fef985d3cbd/mastersd/dom_md/inbox iflag=3Ddirect=
,fullblock count=3D1 bs=3D1024000' (cwd None)</font><br>
<font size=3D"2" face=3D"sans-serif">Dummy-1960::DEBUG::2012-09-20 06:47:09=
,586::__init__::1249::Storage.Misc.excCmd::(_log) SUCCESS: <err> =3D =
'1+0 records in\n1+0 records out\n1024000 bytes (1.0 MB) copied, 0.0485543 =
s, 21.1 MB/s\n'; <rc> =3D 0</font><br>
<br>
<font size=3D"2" face=3D"sans-serif">If I try to create new server I have t=
he same error message.</font><br>
<font size=3D"2" face=3D"sans-serif"><br>
- -<br>
Dmitriy Pyryakov</font>
<ul style=3D"padding-left: 0pt"><font size=3D"2" face=3D"sans-serif">Vimpel=
Com Ltd.</font></ul>
<br>_______________________________________________<br>Users mailing list<b=
r>Users@ovirt.org<br>http://lists.ovirt.org/mailman/listinfo/users<br></blo=
ckquote><br></div></body></html>
------=_Part_2519270_1306423749.1348126859097--