<html><body>
<p><tt><font size="2">Doron Fediuck <dfediuck@redhat.com> ΞΑΠΙΣΑΞΟ 20.09.2012 13:40:59:<br>
<br>
> οΤ: Doron Fediuck <dfediuck@redhat.com></font></tt><br>
<tt><font size="2">> λΟΝΥ: Dmitriy A Pyryakov <DPyryakov@ekb.beeline.ru></font></tt><br>
<tt><font size="2">> λΟΠΙΡ: users@ovirt.org, Oved Ourfalli <ovedo@redhat.com></font></tt><br>
<tt><font size="2">> δΑΤΑ: 20.09.2012 13:41</font></tt><br>
<tt><font size="2">> τΕΝΑ: Re: [Users] Host migration problem</font></tt><br>
<tt><font size="2">> <br>
> Hi Dmitriy.<br>
> This is a bit odd, since indeed action asks to secure all spice channels,<br>
> <br>
> <graphics autoport="yes" keymap="en-us" passwd="*****" <br>
> passwdValidTo="1970-01-01T00:00:01" port="-1" tlsPort="-1" type="spice"><br>
> <channel mode="secure" name="main"/><br>
> <channel mode="secure" name="inputs"/><br>
> <channel mode="secure" name="cursor"/><br>
> <channel mode=&quo t;secure" name="playback"/><br>
> <channel mode="secure" name="record"/><br>
> <channel mode="secure" name="display"/><br>
> <br>
> but this is introduced only for development 3.2 clusters.<br>
> You can see it by running: <br>
> echo "select * from vdc_options where option_name like '%<br>
> SpiceSecureChannels%'" | psql -d engine -U postgres<br>
</font></tt><br>
<tt><font size="2"># echo "select * from vdc_options where option_name like '%SpiceSecureChannels%'" | psql -d engine -U postgres</font></tt><br>
<tt><font size="2"> option_id | option_name | option_value | version</font></tt><br>
<tt><font size="2">-----------+---------------------+--------------------------------------------------+---------</font></tt><br>
<tt><font size="2"> 346 | SpiceSecureChannels | smain,sinputs | 2.2</font></tt><br>
<tt><font size="2"> 347 | SpiceSecureChannels | smain,sinputs | 3.0</font></tt><br>
<tt><font size="2"> 348 | SpiceSecureChannels | smain,sinputs,scursor,splayback,srecord,sdisplay | 3.1</font></tt><br>
<br>
<tt><font size="2">> So...<br>
> 1. Please check your cluster version (you should be using 3.1) and <br>
> please report.</font></tt><br>
<br>
<tt><font size="2">Yes, I have only 3.1 version.</font></tt><br>
<tt><font size="2"><br>
> 2. As a temporary workaround, either set libvirt to support spice <br>
> encryption (in<br>
> /etc/libvirt/qemu.conf set spice_tls = 1, but there may be other <br>
> needed settings)</font></tt><br>
<br>
<tt><font size="2">I set it on each host and restart libvirtd, VMs now can start.</font></tt><br>
<tt><font size="2">Thank you so much.</font></tt><br>
<tt><font size="2"><br>
> or you can try to set SpiceSecureChannels to what we have in previous versions<br>
> (smain,sinputs or even nothing just for sanity).<br>
> <br>
> Check and let us know how it works.<br>
> <br>
> <br>
</font></tt><br>
<tt><font size="2">> From: "Dmitriy A Pyryakov" <DPyryakov@ekb.beeline.ru><br>
> To: users@ovirt.org<br>
> Sent: Thursday, September 20, 2012 9:49:24 AM<br>
> Subject: [Users] Host migration problem<br>
</font></tt><br>
<tt><font size="2">> Hello,<br>
> <br>
> Yesturday I broke my two Fedora 17 hosts.<br>
> Today I install two ovirt nodes (first - 2.5.0-2.0.fc17, second - 2.<br>
> 5.1-1.0.fc17). SPM on 2.5.0-2.0.fc17.<br>
> <br>
> Now, I can't run any of my existing virtual machines. Exit message: <br>
> unsupported configuration: spice secure channels set in XML <br>
> configuration, but TLS is disabled in qemu.conf. </font></tt><br>
<tt><font size="2">> <br>
> <br>
> engine.log:</font></tt><br>
<tt><font size="2">> [root@admin ~]# tail -f -n 0 /var/log/ovirt-engine/engine.log<br>
> 2012-09-20 12:42:53,289 INFO <br>
> [org.ovirt.engine.core.vdsbroker.irsbroker.IsValidVDSCommand] <br>
> (ajp--0.0.0.0-8009-10) START, IsValidVDSCommand(storagePoolId = <br>
> 332694bb-364a-434e-b23f-5fef985d3cbd, ignoreFailoverLimit = false, <br>
> compatabilityVersion = null), log id: 7c90c641<br>
> 2012-09-20 12:42:53,294 INFO <br>
> [org.ovirt.engine.core.vdsbroker.irsbroker.IsValidVDSCommand] <br>
> (ajp--0.0.0.0-8009-10) FINISH, IsValidVDSCommand, return: true, log <br>
> id: 7c90c641<br>
> 2012-09-20 12:42:53,332 INFO <br>
> [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] <br>
> (ajp--0.0.0.0-8009-10) START, IsVmDuringInitiatingVDSCommand(vmId = <br>
> 509e608c-e657-473a-b031-f0811da96bde), log id: 243c74f7<br>
> 2012-09-20 12:42:53,334 INFO <br>
> [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] <br>
> (ajp--0.0.0.0-8009-10) FINISH, IsVmDuringInitiatingVDSCommand, <br>
> return: false, log id: 243c74f7<br>
> 2012-09-20 12:42:53,403 INFO <br>
> [org.ovirt.engine.core.bll.RunVmCommand] (pool-3-thread-50) <br>
> [a58d974] Lock Acquired to object EngineLock [exclusiveLocks= key: <br>
> 509e608c-e657-473a-b031-f0811da96bde value: VM<br>
> , sharedLocks= ]<br>
> 2012-09-20 12:42:53,415 INFO <br>
> [org.ovirt.engine.core.bll.RunVmCommand] (pool-3-thread-50) <br>
> [a58d974] Running command: RunVmCommand internal: false. Entities <br>
> affected : ID: 509e608c-e657-473a-b031-f0811da96bde Type: VM<br>
> 2012-09-20 12:42:53,504 INFO <br>
> [org.ovirt.engine.core.vdsbroker.CreateVmVDSCommand] (pool-3-<br>
> thread-50) [a58d974] START, CreateVmVDSCommand(vdsId = <br>
> 0a268762-02d7-11e2-b750-0011856cf23e, vmId=509e608c-e657-473a-b031-<br>
> f0811da96bde, <br>
> vm=org.ovirt.engine.core.common.businessentities.VM@1911737b), log <br>
> id: 77c0e559<br>
> 2012-09-20 12:42:53,529 INFO <br>
> [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand] <br>
> (pool-3-thread-50) [a58d974] START, CreateVDSCommand(vdsId = <br>
> 0a268762-02d7-11e2-b750-0011856cf23e, vmId=509e608c-e657-473a-b031-<br>
> f0811da96bde, <br>
> vm=org.ovirt.engine.core.common.businessentities.VM@1911737b), log id: f48008f<br>
> 2012-09-20 12:42:53,602 INFO <br>
> [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand] <br>
> (pool-3-thread-50) [a58d974] <br>
> org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand <br>
> spiceSslCipherSuite=DEFAULT,memSize=1024,kvmEnable=true,smp=1,emulatedMachine=pc-0.<br>
> 14,vmType=kvm,keyboardLayout=en-<br>
> us,pitReinjection=false,nice=0,display=qxl,smpCoresPerSocket=1,spiceSecureChannels=smain,sinputs,scursor,splayback,srecord,sdisplay,displayNetwork=ovirtmgmt,timeOffset=-1,transparentHugePages=true,vmId=509e608c<br>
> -e657-473a-b031-f0811da96bde,devices=<br>
> [Ljava.util.Map;@760db68c,acpiEnable=true,vmName=CentOS6Thames,cpuType=Conroe,custom=<br>
> {device_bb912edd-9790-43ff-a758-<br>
> f1d9f20cb5f5device_f5c86859-5ae9-4a37-9d34-2b9547609622device_20a11f26-6a39-415d-<br>
> a7bf-95893b9c55b5=VmId=509e608c-e657-473a-b031-<br>
> f0811da96bde,DeviceId=20a11f26-6a39-415d-<br>
> a7bf-95893b9c55b5,Device=unix,Type=channel,BootOrder=0,SpecParams=<br>
> {},Address={port=1, bus=0, controller=0, type=virtio-<br>
> serial},IsManaged=false,IsPlugged=true,IsReadOnly=false,alias= <br>
> channel0, device_bb912edd-9790-43ff-a758-f1d9f20cb5f5=VmId=509e608c-<br>
> e657-473a-b031-f0811da96bde,DeviceId=bb912edd-9790-43ff-a758-<br>
> f1d9f20cb5f5,Device=ide,Type=controller,BootOrder=0,SpecParams=<br>
> {},Address={bus=0x00, domain=0x0000, type=pci, slot=0x01, <br>
> function=0x1},IsManaged=false,IsPlugged=true,IsReadOnly=false,alias=ide0,<br>
> device_bb912edd-9790-43ff-a758-<br>
> f1d9f20cb5f5device_f5c86859-5ae9-4a37-9d34-2b9547609622=VmId=509e608c-<br>
> e657-473a-b031-<br>
> f0811da96bde,DeviceId=f5c86859-5ae9-4a37-9d34-2b9547609622,Devic <br>
> e=virtio-serial,Type=controller,BootOrder=0,SpecParams={},Address=<br>
> {bus=0x00, domain=0x0000, type=pci, slot=0x04, <br>
> function=0x0},IsManaged=false,IsPlugged=true,IsReadOnly=false,alias=virtio-<br>
> serial0, device_bb912edd-9790-43ff-a758-<br>
> f1d9f20cb5f5device_f5c86859-5ae9-4a37-9d34-2b9547609622device_20a11f26-6a39-415d-<br>
> a7bf-95893b9c55b5device_21f255dc-9b3b-48d8-<br>
> b8e4-63c1635e269b=VmId=509e608c-e657-473a-b031-<br>
> f0811da96bde,DeviceId=21f255dc-9b3b-48d8-<br>
> b8e4-63c1635e269b,Device=spicevmc,Type=channel,BootOrder=0,SpecP <br>
> arams={},Address={port=2, bus=0, controller=0, type=virtio-<br>
> serial},IsManaged=false,IsPlugged=true,IsReadOnly=false,alias=channel1,<br>
> device_bb912edd-9790-43ff-a758-<br>
> f1d9f20cb5f5device_f5c86859-5ae9-4a37-9d34-2b9547609622device_20a11f26-6a39-415d-<br>
> a7bf-95893b9c55b5device_21f255dc-9b3b-48d8-<br>
> b8e4-63c1635e269bdevice_d6c2c4d1-da6b-44fe-<br>
> a5aa-508135c7fdfe=VmId=509e608c-e657-473a-b031-<br>
> f0811da96bde,DeviceId=d6c2c4d1-da6b-44fe-<br>
> a5aa-508135c7fdfe,Device=usb,Type=controller,BootOrder=0,SpecParams=<br>
> {},Address={bus=0x0 0, domain=0x0000, type=pci, slot=0x01, <br>
> function=0x2},IsManaged=false,IsPlugged=true,IsReadOnly=false,alias=usb0}<br>
> 2012-09-20 12:42:53,625 INFO <br>
> [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand] <br>
> (pool-3-thread-50) [a58d974] FINISH, CreateVDSCommand, log id: f48008f<br>
> 2012-09-20 12:42:53,659 INFO <br>
> [org.ovirt.engine.core.vdsbroker.CreateVmVDSCommand] (pool-3-<br>
> thread-50) [a58d974] IncreasePendingVms::CreateVmIncreasing vds <br>
> hyper1.ovirt.com pending vcpu count, now 1. Vm: CentOS6Thames<br>
> 2012-09-20 12:42:53,671 INFO <br>
> [org.ovirt.engine.core.vdsbroker.CreateVmVDSCommand] (pool-3-<br>
> thread-50) [a58d974] FINISH, CreateVmVDSCommand, return: <br>
> WaitForLaunch, log id: 77c0e559<br>
> 2012-09-20 12:42:53,684 INFO <br>
> [org.ovirt.engine.core.bll.RunVmCommand] (pool-3-thread-50) <br>
> [a58d974] Lock freed to object EngineLock [exclusiveLocks= key: <br>
> 509e608c-e657-473a-b031-f0811da96bde value: VM<br>
> , sharedLocks= ]<br>
> 2012-09-20 12:42:54,418 INFO <br>
> [org.ovirt.engine.core.vdsbroker.vdsbroker.DestroyVDSCommand] <br>
> (QuartzScheduler_Worker-12) START, DestroyVDSCommand(vdsId = <br>
> 0a268762-02d7-11e2-b750-0011856cf23e, vmId=509e608c-e657-473a-b031-<br>
> f0811da96bde, force=false, secondsToWait=0, gracefully=false), log <br>
> id: 2f059be9<br>
> 2012-09-20 12:42:54,486 INFO <br>
> [org.ovirt.engine.core.vdsbroker.vdsbroker.DestroyVDSCommand] <br>
> (QuartzScheduler_Worker-12) FINISH, DestroyVDSCommand, log id: 2f059be9<br>
> 2012-09-20 12:42:54,520 INFO <br>
> [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] <br>
> (QuartzScheduler_Worker-12) Running on vds during rerun failed vm: null<br>
> 2012-09-20 12:42:54,523 INFO <br>
> [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] <br>
> (QuartzScheduler_Worker-12) vm CentOS6Thames running in db and not <br>
> running in vds - add to rerun treatment. vds hyper1.ovirt.com<br>
> 2012-09-20 12:42:54,536 ERROR <br>
> [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] <br>
> (QuartzScheduler_Worker-12) Rerun vm 509e608c-e657-473a-b031-<br>
> f0811da96bde. Called from vds hyper1.ovirt.com<br>
> 2012-09-20 12:42:54,557 INFO <br>
> [org.ovirt.engine.core.vdsbroker.UpdateVdsDynamicDataVDSCommand] <br>
> (pool-3-thread-50) START, UpdateVdsDynamicDataVDSCommand(vdsId = <br>
> 0a268762-02d7-11e2-b750-0011856cf23e, <br>
> vdsDynamic=org.ovirt.engine.core.common.businessentities.VdsDynamic@db702e05),<br>
> log id: 71c6e6a3<br>
> 2012-09-20 12:42:54,564 INFO <br>
> [org.ovirt.engine.core.vdsbroker.UpdateVdsDynamicDataVDSCommand] <br>
> (pool-3-thread-50) FINISH, UpdateVdsDynamicDataVDSCommand, log id: 71c6e6a3<br>
> 2012-09-20 12:42:54,584 INFO <br>
> [org.ovirt.engine.core.bll.RunVmCommand] (pool-3-thread-50) Lock <br>
> Acquired to object EngineLock [exclusiveLocks= key: 509e608c-<br>
> e657-473a-b031-f0811da96bde value: VM<br>
> , sharedLocks= ]<br>
> 2012-09-20 12:42:54,603 INFO <br>
> [org.ovirt.engine.core.vdsbroker.irsbroker.IsValidVDSCommand] <br>
> (pool-3-thread-50) START, IsValidVDSCommand(storagePoolId = <br>
> 332694bb-364a-434e-b23f-5fef985d3cbd, ignoreFailoverLimit = false, <br>
> compatabilityVersion = null), log id: f1903fc<br>
> 2012-09-20 12:42:54,614 INFO <br>
> [org.ovirt.engine.core.vdsbroker.irsbroker.IsValidVDSCommand] <br>
> (pool-3-thread-50) FINISH, IsValidVDSCommand, return: true, log id: f1903fc<br>
> 2012-09-20 12:42:54,653 INFO <br>
> [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] <br>
> (pool-3-thread-50) START, IsVmDuringInitiatingVDSCommand(vmId = <br>
> 509e608c-e657-473a-b031-f0811da96bde), log id: 5b0d9779<br>
> 2012-09-20 12:42:54,655 INFO <br>
> [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] <br>
> (pool-3-thread-50) FINISH, IsVmDuringInitiatingVDSCommand, return: <br>
> false, log id: 5b0d9779<br>
> 2012-09-20 12:42:54,712 INFO <br>
> [org.ovirt.engine.core.bll.RunVmCommand] (pool-3-thread-50) Running <br>
> command: RunVmCommand internal: false. Entities affected : ID: <br>
> 509e608c-e657-473a-b031-f0811da96bde Type: VM<br>
> 2012-09-20 12:42:54,800 INFO <br>
> [org.ovirt.engine.core.vdsbroker.CreateVmVDSCommand] (pool-3-<br>
> thread-50) START, CreateVmVDSCommand(vdsId = 9840e840-02db-11e2-<br>
> a01a-0011856cf23e, vmId=509e608c-e657-473a-b031-f0811da96bde, <br>
> vm=org.ovirt.engine.core.common.businessentities.VM@4432a01d), log <br>
> id: 554a0742<br>
> 2012-09-20 12:42:54,825 INFO <br>
> [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand] <br>
> (pool-3-thread-50) START, CreateVDSCommand(vdsId = <br>
> 9840e840-02db-11e2-a01a-0011856cf23e, vmId=509e608c-e657-473a-b031-<br>
> f0811da96bde, <br>
> vm=org.ovirt.engine.core.common.businessentities.VM@4432a01d), log <br>
> id: 73615350<br>
> 2012-09-20 12:42:54,912 INFO <br>
> [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand] <br>
> (pool-3-thread-50) <br>
> org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand <br>
> spiceSslCipherSuite=DEFAULT,memSize=1024,kvmEnable=true,smp=1,emulatedMachine=pc-0.<br>
> 14,vmType=kvm,keyboardLayout=en-<br>
> us,pitReinjection=false,nice=0,display=qxl,smpCoresPerSocket=1,spiceSecureChannels=smain,sinputs,scursor,splayback,srecord,sdisplay,displayNetwork=ovirtmgmt,timeOffset=-1,transparentHugePages=true,vmId=509e608c-<br>
> e657-473a -b031-f0811da96bde,devices=<br>
> [Ljava.util.Map;@41d42882,acpiEnable=true,vmName=CentOS6Thames,cpuType=Conroe,custom=<br>
> {device_bb912edd-9790-43ff-a758-<br>
> f1d9f20cb5f5device_f5c86859-5ae9-4a37-9d34-2b9547609622device_20a11f26-6a39-415d-<br>
> a7bf-95893b9c55b5=VmId=509e608c-e657-473a-b031-<br>
> f0811da96bde,DeviceId=20a11f26-6a39-415d-<br>
> a7bf-95893b9c55b5,Device=unix,Type=channel,BootOrder=0,SpecParams=<br>
> {},Address={port=1, bus=0, controller=0, type=virtio-<br>
> serial},IsManaged=false,IsPlugged=true,IsReadOnly=false,alias=channel0,<br>
> device_bb912edd-9790-43ff-a758-f1d9f20cb5f5=VmId=509e608c-e657-473a-<br>
> b031-f0811da96bde,DeviceId=bb912edd-9790-43ff-a758-<br>
> f1d9f20cb5f5,Device=ide,Type=controller,BootOrder=0,SpecParams=<br>
> {},Address={bus=0x00, domain=0x0000, type=pci, slot=0x01, <br>
> function=0x1},IsManaged=false,IsPlugged=true,IsReadOnly=false,alias=ide0,<br>
> device_bb912edd-9790-43ff-a758-<br>
> f1d9f20cb5f5device_f5c86859-5ae9-4a37-9d34-2b9547609622=VmId=509e608c-<br>
> e657-473a-b031-<br>
> f0811da96bde,DeviceId=f5c86859-5ae9-4a37-9d34-2b9547609622,Device=virtio-<br>
> s erial,Type=controller,BootOrder=0,SpecParams={},Address={bus=0x00,<br>
> domain=0x0000, type=pci, slot=0x04, <br>
> function=0x0},IsManaged=false,IsPlugged=true,IsReadOnly=false,alias=virtio-<br>
> serial0, device_bb912edd-9790-43ff-a758-<br>
> f1d9f20cb5f5device_f5c86859-5ae9-4a37-9d34-2b9547609622device_20a11f26-6a39-415d-<br>
> a7bf-95893b9c55b5device_21f255dc-9b3b-48d8-<br>
> b8e4-63c1635e269b=VmId=509e608c-e657-473a-b031-<br>
> f0811da96bde,DeviceId=21f255dc-9b3b-48d8-<br>
> b8e4-63c1635e269b,Device=spicevmc,Type=channel,BootOrder=0,SpecParams=<br>
> {},A ddress={port=2, bus=0, controller=0, type=virtio-<br>
> serial},IsManaged=false,IsPlugged=true,IsReadOnly=false,alias=channel1,<br>
> device_bb912edd-9790-43ff-a758-<br>
> f1d9f20cb5f5device_f5c86859-5ae9-4a37-9d34-2b9547609622device_20a11f26-6a39-415d-<br>
> a7bf-95893b9c55b5device_21f255dc-9b3b-48d8-<br>
> b8e4-63c1635e269bdevice_d6c2c4d1-da6b-44fe-<br>
> a5aa-508135c7fdfe=VmId=509e608c-e657-473a-b031-<br>
> f0811da96bde,DeviceId=d6c2c4d1-da6b-44fe-<br>
> a5aa-508135c7fdfe,Device=usb,Type=controller,BootOrder=0,SpecParams=<br>
> {},Address={bus=0x00, domain= 0x0000, type=pci, slot=0x01, <br>
> function=0x2},IsManaged=false,IsPlugged=true,IsReadOnly=false,alias=usb0}<br>
> 2012-09-20 12:42:54,982 INFO <br>
> [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand] <br>
> (pool-3-thread-50) FINISH, CreateVDSCommand, log id: 73615350<br>
> 2012-09-20 12:42:55,004 INFO <br>
> [org.ovirt.engine.core.vdsbroker.CreateVmVDSCommand] (pool-3-<br>
> thread-50) IncreasePendingVms::CreateVmIncreasing vds <br>
> hyper2.ovirt.com pending vcpu count, now 1. Vm: CentOS6Thames<br>
> 2012-09-20 12:42:55,012 INFO <br>
> [org.ovirt.engine.core.vdsbroker.CreateVmVDSCommand] (pool-3-<br>
> thread-50) FINISH, CreateVmVDSCommand, return: WaitForLaunch, log id: 554a0742<br>
> 2012-09-20 12:42:55,022 INFO <br>
> [org.ovirt.engine.core.bll.RunVmCommand] (pool-3-thread-50) Lock <br>
> freed to object EngineLock [exclusiveLocks= key: 509e608c-e657-473a-<br>
> b031-f0811da96bde value: VM<br>
> , sharedLocks= ]<br>
> 2012-09-20 12:42:56,434 INFO <br>
> [org.ovirt.engine.core.vdsbroker.vdsbroker.DestroyVDSCommand] <br>
> (QuartzScheduler_Worker-32) START, DestroyVDSCommand(vdsId = <br>
> 9840e840-02db-11e2-a01a-0011856cf23e, vmId=509e608c-e657-473a-b031-<br>
> f0811da96bde, force=false, secondsToWait=0, gracefully=false), log <br>
> id: 6b44f6c9<br>
> 2012-09-20 12:42:56,497 INFO <br>
> [org.ovirt.engine.core.vdsbroker.vdsbroker.DestroyVDSCommand] <br>
> (QuartzScheduler_Worker-32) FINISH, DestroyVDSCommand, log id: 6b44f6c9<br>
> 2012-09-20 12:42:56,532 INFO <br>
> [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] <br>
> (QuartzScheduler_Worker-32) Running on vds during rerun failed vm: null<br>
> 2012-09-20 12:42:56,535 INFO <br>
> [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] <br>
> (QuartzScheduler_Worker-32) vm CentOS6Thames running in db and not <br>
> running in vds - add to rerun treatment. vds hyper2.ovirt.com<br>
> 2012-09-20 12:42:56,548 ERROR <br>
> [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] <br>
> (QuartzScheduler_Worker-32) Rerun vm 509e608c-e657-473a-b031-<br>
> f0811da96bde. Called from vds hyper2.ovirt.com<br>
> 2012-09-20 12:42:56,582 INFO <br>
> [org.ovirt.engine.core.vdsbroker.UpdateVdsDynamicDataVDSCommand] <br>
> (pool-3-thread-50) START, UpdateVdsDynamicDataVDSCommand(vdsId = <br>
> 9840e840-02db-11e2-a01a-0011856cf23e, <br>
> vdsDynamic=org.ovirt.engine.core.common.businessentities.VdsDynamic@5f1dd7c7),<br>
> log id: 2a191f9e<br>
> 2012-09-20 12:42:56,596 INFO <br>
> [org.ovirt.engine.core.vdsbroker.UpdateVdsDynamicDataVDSCommand] <br>
> (pool-3-thread-50) FINISH, UpdateVdsDynamicDataVDSCommand, log id: 2a191f9e<br>
> 2012-09-20 12:42:56,616 INFO <br>
> [org.ovirt.engine.core.bll.RunVmCommand] (pool-3-thread-50) Lock <br>
> Acquired to object EngineLock [exclusiveLocks= key: 509e608c-<br>
> e657-473a-b031-f0811da96bde value: VM<br>
> , sharedLocks= ]<br>
> 2012-09-20 12:42:56,632 INFO <br>
> [org.ovirt.engine.core.vdsbroker.irsbroker.IsValidVDSCommand] <br>
> (pool-3-thread-50) START, IsValidVDSCommand(storagePoolId = <br>
> 332694bb-364a-434e-b23f-5fef985d3cbd, ignoreFailoverLimit = false, <br>
> compatabilityVersion = null), log id: 4629f11d<br>
> 2012-09-20 12:42:56,636 INFO <br>
> [org.ovirt.engine.core.vdsbroker.irsbroker.IsValidVDSCommand] <br>
> (pool-3-thread-50) FINISH, IsValidVDSCommand, return: true, log id: 4629f11d<br>
> 2012-09-20 12:42:56,672 INFO <br>
> [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] <br>
> (pool-3-thread-50) START, IsVmDuringInitiatingVDSCommand(vmId = <br>
> 509e608c-e657-473a-b031-f0811da96bde), log id: f3a60e<br>
> 2012-09-20 12:42:56,675 INFO <br>
> [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] <br>
> (pool-3-thread-50) FINISH, IsVmDuringInitiatingVDSCommand, return: <br>
> false, log id: f3a60e<br>
> 2012-09-20 12:42:56,713 WARN <br>
> [org.ovirt.engine.core.bll.RunVmCommand] (pool-3-thread-50) <br>
> CanDoAction of action RunVm failed. <br>
> 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<br>
> 2012-09-20 12:42:56,717 INFO <br>
> [org.ovirt.engine.core.bll.RunVmCommand] (pool-3-thread-50) Lock <br>
> freed to object EngineLock [exclusiveLocks= key: 509e608c-e657-473a-<br>
> b031-f0811da96bde value: VM<br>
> , sharedLocks= ]<br>
> <br>
> vdsm.log:<br>
> Dummy-1960::DEBUG::2012-09-20 06:46:58,959::__init__::<br>
> 1249::Storage.Misc.excCmd::(_log) 'dd if=/rhev/data-center/<br>
> 332694bb-364a-434e-b23f-5fef985d3cbd/mastersd/dom_md/inbox <br>
> iflag=direct,fullblock count=1 bs=1024000' (cwd None)<br>
> Dummy-1960::DEBUG::2012-09-20 06:46:59,043::__init__::<br>
> 1249::Storage.Misc.excCmd::(_log) SUCCESS: <err> = '1+0 records in<br>
> \n1+0 records out\n1024000 bytes (1.0 MB) copied, 0.0488089 s, 21.0 <br>
> MB/s\n'; <rc> = 0<br>
> Dummy-1960::DEBUG::2012-09-20 06:47:01,053::__init__::<br>
> 1249::Storage.Misc.excCmd::(_log) 'dd if=/rhev/data-center/<br>
> 332694bb-364a-434e-b23f-5fef985d3cbd/mastersd/dom_md/inbox <br>
> iflag=direct,fullblock count=1 bs=1024000' (cwd None)<br>
> Dummy-1960::DEBUG::2012-09-20 06:47:01,136::__init__::<br>
> 1249::Storage.Misc.excCmd::(_log) SUCCESS: <err> = '1+0 records in<br>
> \n1+0 records out\n1024000 bytes (1.0 MB) copied, 0.0477826 s, 21.4 <br>
> MB/s\n'; <rc> = 0<br>
> Thread-7807::DEBUG::2012-09-20 06:47:01,991::BindingXMLRPC::<br>
> 859::vds::(wrapper) client [192.168.10.10]::call vmCreate with <br>
> ({'custom': {'device_bb912edd-9790-43ff-a758-<br>
> f1d9f20cb5f5device_f5c86859-5ae9-4a37-9d34-2b9547609622device_20a11f26-6a39-415d-<br>
> a7bf-95893b9c55b5device_21f255dc-9b3b-48d8-<br>
> b8e4-63c1635e269bdevice_d6c2c4d1-da6b-44fe-a5aa-508135c7fdfe': <br>
> 'VmId=509e608c-e657-473a-b031-f0811da96bde,DeviceId=d6c2c4d1-<br>
> da6b-44fe-<br>
> a5aa-508135c7fdfe,Device=usb,Type=controller,BootOrder=0,SpecParams=<br>
> {},Address={bus=0x00, domain=0x0000, type=pci, slot=0x01, <br>
> function=0x2},IsManaged=false,IsPlugged=true,IsReadOnly=false,alias=usb0',<br>
> 'device_bb912edd-9790-43ff-a758-<br>
> f1d9f20cb5f5device_f5c86859-5ae9-4a37-9d34-2b9547609622device_20a11f26-6a39-415d-<br>
> a7bf-95893b9c55b5device_21f255dc-9b3b-48d8-b8e4-63c1635e269b': <br>
> 'VmId=509e608c-e657-473a-b031-<br>
> f0811da96bde,DeviceId=21f255dc-9b3b-48d8-<br>
> b8e4-63c1635e269b,Device=spicevmc,Type=channel,BootOrder=0,SpecParams=<br>
> {},Address={port=2, bus=0, controller=0, type=virtio-<br>
> serial},IsManaged=false,IsPlugged=true,IsReadOnly=false,alias=channel1',<br>
> 'device_bb912edd-9790-43ff-a758-<br>
> f1d9f20cb5f5device_f5c86859-5ae9-4a37-9d34-2b9547609622': <br>
> 'VmId=509e608c-e657-473a-b031-<br>
> f0811da96bde,DeviceId=f5c86859-5ae9-4a37-9d34-2b9547609622,Device=virtio-<br>
> serial,Type=controller,BootOrder=0,SpecParams={},Address={bus=0x00, <br>
> domain=0x0000, type=pci, slot=0x04, <br>
> function=0x0},IsManaged=false,IsPlugged=true,IsReadOnly=false,alias=virtio-<br>
> serial0', 'device_bb912edd-9790-43ff-a758-<br>
> f1d9f20cb5f5device_f5c86859-5ae9-4a37-9d34-2b9547609622device_20a11f26-6a39-415d-<br>
> a7bf-95893b9c55b5': 'VmId=509e608c-e657-473a-b031-<br>
> f0811da96bde,DeviceId=20a11f26-6a39-415d-<br>
> a7bf-95893b9c55b5,Device=unix,Type=channel,BootOrder=0,SpecParams=<br>
> {},Address={port=1, bus=0, controller=0, type=virtio-<br>
> serial},IsManaged=false,IsPlugged=true,IsReadOnly=false,alias=channel0',<br>
> 'device_bb912edd-9790-43ff-a758-f1d9f20cb5f5': 'VmId=509e608c-<br>
> e657-473a-b031-f0811da96bde,DeviceId=bb912edd-9790-43ff-a758-<br>
> f1d9f20cb5f5,Device=ide,Type=controller,BootOrder=0,SpecParams=<br>
> {},Address={bus=0x00, domain=0x0000, type=pci, slot=0x01, <br>
> function=0x1},IsManaged=false,IsPlugged=true,IsReadOnly=false,alias=ide0'},<br>
> 'keyboardLayout': 'en-us', 'kvmEnable': 'true', 'pitReinjection': <br>
> 'false', 'acpiEnable': 'true', 'emulatedMachine': 'pc-0.14', <br>
> 'displayNetwork': 'ovirtmgmt', 'vmId': '509e608c-e657-473a-b031-<br>
> f0811da96bde', 'devices': [{'device': 'qxl', 'specParams': {'vram': <br>
> '65536'}, 'type': 'video', 'deviceId': '20c037f2-11e5-49a5-<br>
> ace7-741023ec0ce9', 'address': {'bus': '0x00', ' slot': '0x02', ' <br>
> domain': '0x0000', ' type': 'pci', ' function': '0x0'}}, {'index': <br>
> '2', 'iface': 'ide', 'specParams': {'path': ''}, 'readonly': 'true',<br>
> 'deviceId': '1ed8a73e-be34-4829-a7e3-151a7a2efedc', 'address': {' <br>
> controller': '0', ' target': '0', 'unit': '0', ' bus': '1', ' type':<br>
> 'drive'}, 'device': 'cdrom', 'path': '', 'type': 'disk'}, {'iface': <br>
> 'virtio', 'format': 'cow', 'type': 'disk', 'poolID': <br>
> '332694bb-364a-434e-b23f-5fef985d3cbd', 'volumeID': <br>
> 'f184ecd1-0001-4739-af71-250b412345d6', 'imageID': <br>
> '0a7013db-68fd-4c42-bc2e-cc8d7a05ca18', 'specParams': {}, <br>
> 'readonly': 'false', 'domainID': '26187d25-<br>
> bfcb-40c7-97d1-667705ad2223', 'deviceId': '0a7013db-68fd-4c42-bc2e-<br>
> cc8d7a05ca18', 'address': {'bus': '0x00', ' slot': '0x05', ' <br>
> domain': '0x0000', ' type': 'pci', ' function': '0x0'}, 'device': <br>
> 'disk', 'shared': 'false', 'propagateErrors': 'off', 'optional': <br>
> 'false'}, {'nicModel': 'pv', 'macAddr': '00:1a:4a:a8:0a:00', <br>
> 'network': 'ovirtmgmt', 'specParams': {}, 'deviceId': <br>
> '7392f689-2ba3-4243-9629-96b192b102a5', 'address': {'bus': '0x00', '<br>
> slot': '0x03', ' domain': '0x0000', ' type': 'pci', ' function': <br>
> '0x0'}, 'device': 'bridge', 'type': 'interface'}, {'device': 'usb', <br>
> 'specParams': {}, 'type': 'controller', 'deviceId': 'd6c2c4d1-<br>
> da6b-44fe-a5aa-508135c7fdfe', 'address': {'bus': '0x00', ' slot': <br>
> '0x01', ' domain': '0x0000', ' type': 'pci', ' function': '0x2'}}, <br>
> {'device': 'memballoon', 'specParams': {'model': 'virtio'}, 'type': <br>
> 'balloon', 'deviceId': 'babd73a4-de64-4dce-91b9-e64c5b46c444'}], <br>
> 'smp': '1', 'vmType': 'kvm', 'timeOffset': '<br>
> -1', 'memSize': 1024, 'spiceSslCipherSuite': 'DEFAULT', 'cpuType': <br>
> 'Conroe', 'spiceSecureChannels': <br>
> 'smain,sinputs,scursor,splayback,srecord,sdisplay', <br>
> 'smpCoresPerSocket': '1', 'vmName': 'CentOS6Thames', 'display': <br>
> 'qxl', 'transparentHugePages': 'true', 'nice': '0'},) {}<br>
> Thread-7807::INFO::2012-09-20 06:47:01,992::API::228::vds::(create) <br>
> vmContainerLock acquired by vm 509e608c-e657-473a-b031-f0811da96bde<br>
> Thread-7808::DEBUG::2012-09-20 06:47:01,996::vm::564::vm.Vm::<br>
> (_startUnderlyingVm) vmId=`509e608c-e657-473a-b031-f0811da96bde`::Start<br>
> Thread-7807::DEBUG::2012-09-20 06:47:01,996::API::244::vds::(create)<br>
> Total desktops after creation of 509e608c-e657-473a-b031-f0811da96bde is 1<br>
> Thread-7808::DEBUG::2012-09-20 06:47:01,997::vm::568::vm.Vm::<br>
> (_startUnderlyingVm) vmId=`509e608c-e657-473a-b031-<br>
> f0811da96bde`::_ongoingCreations acquired<br>
> Thread-7807::DEBUG::2012-09-20 06:47:01,997::BindingXMLRPC::<br>
> 865::vds::(wrapper) return vmCreate with {'status': {'message': <br>
> 'Done', 'code': 0}, 'vmList': {'status': 'WaitForLaunch', <br>
> 'acpiEnable': 'true', 'emulatedMachine': 'pc-0.14', 'vmId': <br>
> '509e608c-e657-473a-b031-f0811da96bde', 'pid': '0', 'timeOffset': <br>
> '-1', 'displayPort': '-1', 'displaySecurePort': '-1', <br>
> 'spiceSslCipherSuite': 'DEFAULT', 'cpuType': 'Conroe', 'custom': <br>
> {'device_bb912edd-9790-43ff-a758-<br>
> f1d9f20cb5f5device_f5c86859-5ae9-4a37-9d34-2b9547609622device_20a11f26-6a39-415d-<br>
> a7bf-95893b9c55b5device_21f255dc-9b3b-48d8-<br>
> b8e4-63c1635e269bdevice_d6c2c4d1-da6b-44fe-a5aa-508135c7fdfe': <br>
> 'VmId=509e608c-e657-473a-b031-f0811da96bde,DeviceId=d6c2c4d1-<br>
> da6b-44fe-<br>
> a5aa-508135c7fdfe,Device=usb,Type=controller,BootOrder=0,SpecParams=<br>
> {},Address={bus=0x00, domain=0x0000, type=pci, slot=0x01, <br>
> function=0x2},IsManaged=false,IsPlugged=true,IsReadOnly=false,alias=usb0',<br>
> 'device_bb912edd-9790-43ff-a758-<br>
> f1d9f20cb5f5device_f5c86859-5ae9-4a37-9d34-2b9547609622device_20a11f26-6a39-415d-<br>
> a7bf-95893b9c55b5device_21f255dc-9b3b-48d8-b8e4-63c1635e269b': <br>
> 'VmId=509e608c-e657-473a-b031-<br>
> f0811da96bde,DeviceId=21f255dc-9b3b-48d8-<br>
> b8e4-63c1635e269b,Device=spicevmc,Type=channel,BootOrder=0,SpecParams=<br>
> {},Address={port=2, bus=0, controller=0, type=virtio-<br>
> serial},IsManaged=false,IsPlugged=true,IsReadOnly=false,alias=channel1',<br>
> 'device_bb912edd-9790-43ff-a758-<br>
> f1d9f20cb5f5device_f5c86859-5ae9-4a37-9d34-2b9547609622': <br>
> 'VmId=509e608c-e657-473a-b031-<br>
> f0811da96bde,DeviceId=f5c86859-5ae9-4a37-9d34-2b9547609622,Device=virtio-<br>
> serial,Type=controller,BootOrder=0,SpecParams={},Address={bus=0x00, <br>
> domain=0x0000, type=pci, slot=0x04, <br>
> function=0x0},IsManaged=false,IsPlugged=true,IsReadOnly=false,alias=virtio-<br>
> serial0', 'device_bb912edd-9790-43ff-a758-<br>
> f1d9f20cb5f5device_f5c86859-5ae9-4a37-9d34-2b9547609622device_20a11f26-6a39-415d-<br>
> a7bf-95893b9c55b5': 'VmId=509e608c-e657-473a-b031-<br>
> f0811da96bde,DeviceId=20a11f26-6a39-415d-<br>
> a7bf-95893b9c55b5,Device=unix,Type=channel,BootOrder=0,SpecParams=<br>
> {},Address={port=1, bus=0, controller=0, type=virtio-<br>
> serial},IsManaged=false,IsPlugged=true,IsReadOnly=false,alias=channel0',<br>
> 'device_bb912edd-9790-43ff-a758-f1d9f20cb5f5': 'VmId=509e608c-<br>
> e657-473a-b031-f0811da96bde,DeviceId=bb912edd-9790-43ff-a758-<br>
> f1d9f20cb5f5,Device=ide,Type=controller,BootOrder=0,SpecParams=<br>
> {},Address={bus=0x00, domain=0x0000, type=pci, slot=0x01, <br>
> function=0x1},IsManaged=false,IsPlugged=true,IsReadOnly=false,alias=ide0'},<br>
> 'clientIp': '', 'nicModel': 'rtl8139,pv', 'keyboardLayout': 'en-us',<br>
> 'kvmEnable': 'true', 'pitReinjection': 'false', <br>
> 'transparentHugePages': 'true', 'displayNetwork': 'ovirtmgmt', <br>
> 'devices': [{'device': 'qxl', 'specParams': {'vram': '65536'}, <br>
> 'type': 'video', 'deviceId': '20c037f2-11e5-49a5-ace7-741023ec0ce9',<br>
> 'address': {'bus': '0x00', ' slot': '0x02', ' domain': '0x0000', ' <br>
> type': 'pci', ' function': '0x0'}}, {'index': '2', 'iface': 'ide', <br>
> 'specParams': {'path': ''}, 'readonly': 'true', 'deviceId': <br>
> '1ed8a73e-be34-4829-a7e3-151a7a2efedc', 'address': {' controller': <br>
> '0', ' target': '0', 'unit': '0', ' bus': '1', ' type': 'drive'}, <br>
> 'device': 'cdrom', 'path': '', 'type': 'disk'}, {'iface': 'virtio', <br>
> 'format': 'cow', 'type': 'disk', 'poolID': '332694bb-364a-434e-<br>
> b23f-5fef985d3cbd', 'volumeID': 'f184ecd1-0001-4739-<br>
> af71-250b412345d6', 'imageID': '0a7013db-68fd-4c42-bc2e-<br>
> cc8d7a05ca18', 'specParams': {}, 'readonly': 'false', 'domainID': <br>
> '26187d25-bfcb-40c7-97d1-667705ad2223', 'deviceId': <br>
> '0a7013db-68fd-4c42-bc2e-cc8d7a05ca18', 'address': {'bus': '0x00', '<br>
> slot': '0x05', ' domain': '0x0000', ' type': 'pci', ' function': <br>
> '0x0'}, 'device': 'disk', 'shared': 'false', 'propagateErrors': <br>
> 'off', 'optional': 'false'}, {'nicModel': 'pv', 'macAddr': '00:1a:<br>
> 4a:a8:0a:00', 'network': 'ovirtmgmt', 'specParams': {}, 'deviceId': <br>
> '7392f689-2ba3-4243-9629-96b192b102a5', 'address': {'bus': '0x00', '<br>
> slot': '0x03', ' domain': '0x0000', ' type': 'pci', ' function': <br>
> '0x0'}, 'device': 'bridge', 'type': 'interface'}, {'device': 'usb', <br>
> 'specParams': {}, 'type': 'controller', 'deviceId': 'd6c2c4d1-<br>
> da6b-44fe-a5aa-508135c7fdfe', 'address': {'b<br>
> us': '0x00', ' slot': '0x01', ' domain': '0x0000', ' type': 'pci', '<br>
> function': '0x2'}}, {'device': 'memballoon', 'specParams': {'model':<br>
> 'virtio'}, 'type': 'balloon', 'deviceId': 'babd73a4-de64-4dce-91b9-<br>
> e64c5b46c444'}], 'smp': '1', 'vmType': 'kvm', 'memSize': 1024, <br>
> 'displayIp': '192.168.10.13', 'spiceSecureChannels': <br>
> 'smain,sinputs,scursor,splayback,srecord,sdisplay', <br>
> 'smpCoresPerSocket': '1', 'vmName': 'CentOS6Thames', 'display': <br>
> 'qxl', 'nice': '0'}}<br>
> Thread-7808::INFO::2012-09-20 06:47:01,997::libvirtvm::1285::vm.Vm::<br>
> (_run) vmId=`509e608c-e657-473a-b031-f0811da96bde`::VM wrapper has started<br>
> Thread-7808::DEBUG::2012-09-20 06:47:02,000::task::<br>
> 588::TaskManager.Task::(_updateState) Task=`b6ef82b2-2986-4b7b-95ba-<br>
> d5f3cac8ad31`::moving from state init -> state preparing<br>
> Thread-7808::INFO::2012-09-20 06:47:02,001::logUtils::<br>
> 37::dispatcher::(wrapper) Run and protect: getVolumeSize<br>
> (sdUUID='26187d25-bfcb-40c7-97d1-667705ad2223', <br>
> spUUID='332694bb-364a-434e-b23f-5fef985d3cbd', <br>
> imgUUID='0a7013db-68fd-4c42-bc2e-cc8d7a05ca18', <br>
> volUUID='f184ecd1-0001-4739-af71-250b412345d6', options=None)<br>
> Thread-7808::DEBUG::2012-09-20 06:47:02,001::resourceManager::<br>
> 175::ResourceManager.Request::(__init__) ResName=`Storage.26187d25-<br>
> bfcb-40c7-97d1-667705ad2223`ReqID=`83dac2e0-3d55-4ef6-<br>
> abf3-7b2561814ab4`::Request was made in '/usr/share/vdsm/storage/<br>
> resourceManager.py' line '485' at 'registerResource'<br>
> Thread-7808::DEBUG::2012-09-20 06:47:02,002::resourceManager::<br>
> 486::ResourceManager::(registerResource) Trying to register resource<br>
> 'Storage.26187d25-bfcb-40c7-97d1-667705ad2223' for lock type 'shared'<br>
> Thread-7808::DEBUG::2012-09-20 06:47:02,002::resourceManager::<br>
> 528::ResourceManager::(registerResource) Resource 'Storage.26187d25-<br>
> bfcb-40c7-97d1-667705ad2223' is free. Now locking as 'shared' (1 active user)<br>
> Thread-7808::DEBUG::2012-09-20 06:47:02,002::resourceManager::<br>
> 212::ResourceManager.Request::(grant) ResName=`Storage.26187d25-<br>
> bfcb-40c7-97d1-667705ad2223`ReqID=`83dac2e0-3d55-4ef6-<br>
> abf3-7b2561814ab4`::Granted request<br>
> Thread-7808::DEBUG::2012-09-20 06:47:02,003::task::<br>
> 817::TaskManager.Task::(resourceAcquired) <br>
> Task=`b6ef82b2-2986-4b7b-95ba-d5f3cac8ad31`::_resourcesAcquired: <br>
> Storage.26187d25-bfcb-40c7-97d1-667705ad2223 (shared)<br>
> Thread-7808::DEBUG::2012-09-20 06:47:02,003::task::<br>
> 978::TaskManager.Task::(_decref) Task=`b6ef82b2-2986-4b7b-95ba-<br>
> d5f3cac8ad31`::ref 1 aborting False<br>
> Thread-7808::INFO::2012-09-20 06:47:02,004::logUtils::<br>
> 39::dispatcher::(wrapper) Run and protect: getVolumeSize, Return <br>
> response: {'truesize': '13958643712', 'apparentsize': '13958643712'}<br>
> Thread-7808::DEBUG::2012-09-20 06:47:02,004::task::<br>
> 1172::TaskManager.Task::(prepare) Task=`b6ef82b2-2986-4b7b-95ba-<br>
> d5f3cac8ad31`::finished: {'truesize': '13958643712', 'apparentsize':<br>
> '13958643712'}<br>
> Thread-7808::DEBUG::2012-09-20 06:47:02,004::task::<br>
> 588::TaskManager.Task::(_updateState) Task=`b6ef82b2-2986-4b7b-95ba-<br>
> d5f3cac8ad31`::moving from state preparing -> state finished<br>
> Thread-7808::DEBUG::2012-09-20 06:47:02,004::resourceManager::<br>
> 809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests <br>
> {} resources {'Storage.26187d25-bfcb-40c7-97d1-667705ad2223': < <br>
> ResourceRef 'Storage.26187d25-bfcb-40c7-97d1-667705ad2223', isValid:<br>
> 'True' obj: 'None'>}<br>
> Thread-7808::DEBUG::2012-09-20 06:47:02,004::resourceManager::<br>
> 844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}<br>
> Thread-7808::DEBUG::2012-09-20 06:47:02,005::resourceManager::<br>
> 538::ResourceManager::(releaseResource) Trying to release resource <br>
> 'Storage.26187d25-bfcb-40c7-97d1-667705ad2223'<br>
> Thread-7808::DEBUG::2012-09-20 06:47:02,005::resourceManager::<br>
> 553::ResourceManager::(releaseResource) Released resource 'Storage.<br>
> 26187d25-bfcb-40c7-97d1-667705ad2223' (0 active users)<br>
> Thread-7808::DEBUG::2012-09-20 06:47:02,005::resourceManager::<br>
> 558::ResourceManager::(releaseResource) Resource 'Storage.26187d25-<br>
> bfcb-40c7-97d1-667705ad2223' is free, finding out if anyone is waiting for it.<br>
> Thread-7808::DEBUG::2012-09-20 06:47:02,005::resourceManager::<br>
> 565::ResourceManager::(releaseResource) No one is waiting for <br>
> resource 'Storage.26187d25-bfcb-40c7-97d1-667705ad2223', Clearing records.<br>
> Thread-7808::DEBUG::2012-09-20 06:47:02,005::task::<br>
> 978::TaskManager.Task::(_decref) Task=`b6ef82b2-2986-4b7b-95ba-<br>
> d5f3cac8ad31`::ref 0 aborting False<br>
> Thread-7808::INFO::2012-09-20 06:47:02,006::clientIF::274::vds::<br>
> (prepareVolumePath) prepared volume path:<br>
> Thread-7808::DEBUG::2012-09-20 06:47:02,006::task::<br>
> 588::TaskManager.Task::(_updateState) <br>
> Task=`83579cfe-4384-4b76-8bb0-979ed2b60739`::moving from state init <br>
> -> state preparing<br>
> Thread-7808::INFO::2012-09-20 06:47:02,006::logUtils::<br>
> 37::dispatcher::(wrapper) Run and protect: prepareImage<br>
> (sdUUID='26187d25-bfcb-40c7-97d1-667705ad2223', <br>
> spUUID='332694bb-364a-434e-b23f-5fef985d3cbd', <br>
> imgUUID='0a7013db-68fd-4c42-bc2e-cc8d7a05ca18', <br>
> volUUID='f184ecd1-0001-4739-af71-250b412345d6')<br>
> Thread-7808::DEBUG::2012-09-20 06:47:02,007::resourceManager::<br>
> 175::ResourceManager.Request::(__init__) ResName=`Storage.26187d25-<br>
> bfcb-40c7-97d1-667705ad2223`ReqID=`c22e6209-<br>
> b86d-448c-8884-372ce9a589c4`::Request was made in '/usr/share/vdsm/<br>
> storage/resourceManager.py' line '485' at 'registerResource'<br>
> Thread-7808::DEBUG::2012-09-20 06:47:02,007::resourceManager::<br>
> 486::ResourceManager::(registerResource) Trying to register resource<br>
> 'Storage.26187d25-bfcb-40c7-97d1-667705ad2223' for lock type 'shared'<br>
> Thread-7808::DEBUG::2012-09-20 06:47:02,007::resourceManager::<br>
> 528::ResourceManager::(registerResource) Resource</font></tt><tt><font size="2"> 'Storage.26187d25-<br>
> bfcb-40c7-97d1-667705ad2223' is free. Now locking as 'shared' (1 active user)<br>
> Thread-7808::DEBUG::2012-09-20 06:47:02,007::resourceManager::<br>
> 212::ResourceManager.Request::(grant) ResName=`Storage.26187d25-<br>
> bfcb-40c7-97d1-667705ad2223`ReqID=`c22e6209-<br>
> b86d-448c-8884-372ce9a589c4`::Granted request<br>
> Thread-7808::DEBUG::2012-09-20 06:47:02,008::task::<br>
> 817::TaskManager.Task::(resourceAcquired) <br>
> Task=`83579cfe-4384-4b76-8bb0-979ed2b60739`::_resourcesAcquired: <br>
> Storage.26187d25-bfcb-40c7-97d1-667705ad2223 (shared)<br>
> Thread-7808::DEBUG::2012-09-20 06:47:02,008::task::<br>
> 978::TaskManager.Task::(_decref) <br>
> Task=`83579cfe-4384-4b76-8bb0-979ed2b60739`::ref 1 aborting False<br>
> Thread-7808::DEBUG::2012-09-20 06:47:02,008::__init__::<br>
> 1249::Storage.Misc.excCmd::(_log) '/usr/bin/dd iflag=direct skip=4 <br>
> bs=512 if=/dev/26187d25-bfcb-40c7-97d1-667705ad2223/metadata <br>
> count=1' (cwd None)<br>
> Thread-7808::DEBUG::2012-09-20 06:47:02,023::__init__::<br>
> 1249::Storage.Misc.excCmd::(_log) SUCCESS: <err> = '1+0 records in<br>
> \n1+0 records out\n512 bytes (512 B) copied, 0.000766795 s, 668 kB/s<br>
> \n'; <rc> = 0<br>
> Thread-7808::DEBUG::2012-09-20 06:47:02,023::misc::<br>
> 314::Storage.Misc::(validateDDBytes) err: ['1+0 records in', '1+0 <br>
> records out', '512 bytes (512 B) copied, 0.000766795 s, 668 kB/s'], size: 512<br>
> Thread-7808::INFO::2012-09-20 06:47:02,023::image::<br>
> 357::Storage.Image::(getChain) sdUUID=26187d25-<br>
> bfcb-40c7-97d1-667705ad2223 imgUUID=0a7013db-68fd-4c42-bc2e-<br>
> cc8d7a05ca18 chain=<br>
> Thread-7808::INFO::2012-09-20 06:47:02,024::logUtils::<br>
> 39::dispatcher::(wrapper) Run and protect: prepareImage, Return <br>
> response: {'path': '/rhev/data-center/332694bb-364a-434e-<br>
> b23f-5fef985d3cbd/26187d25-bfcb-40c7-97d1-667705ad2223/images/<br>
> 0a7013db-68fd-4c42-bc2e-cc8d7a05ca18/f184ecd1-0001-4739-<br>
> af71-250b412345d6', 'chain': [{'path': '/rhev/data-center/<br>
> 332694bb-364a-434e-b23f-5fef985d3cbd/26187d25-<br>
> bfcb-40c7-97d1-667705ad2223/images/0a7013db-68fd-4c42-bc2e-<br>
> cc8d7a05ca18/f184ecd1-0001-4739-af71-250b412345d6', 'domainID': <br>
> '26187d25-bfcb-40c7-97d1-667705ad2223', 'volumeID': <br>
> 'f184ecd1-0001-4739-af71-250b412345d6', 'imageID': <br>
> '0a7013db-68fd-4c42-bc2e-cc8d7a05ca18'}]}<br>
> Thread-7808::DEBUG::2012-09-20 06:47:02,024::task::<br>
> 1172::TaskManager.Task::(prepare) <br>
> Task=`83579cfe-4384-4b76-8bb0-979ed2b60739`::finished: {'path': '/<br>
> rhev/data-center/332694bb-364a-434e-b23f-5fef985d3cbd/26187d25-<br>
> bfcb-40c7-97d1-667705ad2223/images/0a7013db-68fd-4c42-bc2e-<br>
> cc8d7a05ca18/f184ecd1-0001-4739-af71-250b412345d6', 'chain': <br>
> [{'path': '/rhev/data-center/332694bb-364a-434e-b23f-5fef985d3cbd/<br>
> 26187d25-bfcb-40c7-97d1-667705ad2223/images/0a7013db-68fd-4c42-bc2e-<br>
> cc8d7a05ca18/f184ecd1-0001-4739-af71-250b412345d6', 'domainID': <br>
> '26187d25-bfcb-40c7-97d1-667705ad2223', 'volumeID': <br>
> 'f184ecd1-0001-4739-af71-250b412345d6', 'imageID': <br>
> '0a7013db-68fd-4c42-bc2e-cc8d7a05ca18'}]}<br>
> Thread-7808::DEBUG::2012-09-20 06:47:02,024::task::<br>
> 588::TaskManager.Task::(_updateState) <br>
> Task=`83579cfe-4384-4b76-8bb0-979ed2b60739`::moving from state <br>
> preparing -> state finished<br>
> Thread-7808::DEBUG::2012-09-20 06:47:02,025::resourceManager::<br>
> 809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests <br>
> {} resources {'Storage.26187d25-bfcb-40c7-97d1-667705ad2223': < <br>
> ResourceRef 'Storage.26187d25-bfcb-40c7-97d1-667705ad2223', isValid:<br>
> 'True' obj: 'None'>}<br>
> Thread-7808::DEBUG::2012-09-20 06:47:02,025::resourceManager::<br>
> 844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}<br>
> Thread-7808::DEBUG::2012-09-20 06:47:02,025::resourceManager::<br>
> 538::ResourceManager::(releaseResource) Trying to release resource <br>
> 'Storage.26187d25-bfcb-40c7-97d1-667705ad2223'<br>
> Thread-7808::DEBUG::2012-09-20 06:47:02,025::resourceManager::<br>
> 553::ResourceManager::(releaseResource) Released resource 'Storage.<br>
> 26187d25-bfcb-40c7-97d1-667705ad2223' (0 active users)<br>
> Thread-7808::DEBUG::2012-09-20 06:47:02,026::resourceManager::<br>
> 558::ResourceManager::(releaseResource) Resource 'Storage.26187d25-<br>
> bfcb-40c7-97d1-667705ad2223' is free, finding out if anyone is waiting for it.<br>
> Thread-7808::DEBUG::2012-09-20 06:47:02,026::resourceManager::<br>
> 565::ResourceManager::(releaseResource) No one is waiting for <br>
> resource 'Storage.26187d25-bfcb-40c7-97d1-667705ad2223', Clearing records.<br>
> Thread-7808::DEBUG::2012-09-20 06:47:02,026::task::<br>
> 978::TaskManager.Task::(_decref) <br>
> Task=`83579cfe-4384-4b76-8bb0-979ed2b60739`::ref 0 aborting False<br>
> Thread-7808::INFO::2012-09-20 06:47:02,026::clientIF::274::vds::<br>
> (prepareVolumePath) prepared volume path: /rhev/data-center/<br>
> 332694bb-364a-434e-b23f-5fef985d3cbd/26187d25-<br>
> bfcb-40c7-97d1-667705ad2223/images/0a7013db-68fd-4c42-bc2e-<br>
> cc8d7a05ca18/f184ecd1-0001-4739-af71-250b412345d6<br>
> Thread-7808::DEBUG::2012-09-20 06:47:02,037::libvirtvm::<br>
> 1338::vm.Vm::(_run) vmId=`509e608c-e657-473a-b031-f0811da96bde`::<?<br>
> xml version="1.0" encoding="utf-8"?><br>
> <domain type="kvm"><br>
> <name>CentOS6Thames</name><br>
> <uuid>509e608c-e657-473a-b031-f0811da96bde</uuid><br>
> <memory>1048576</memory><br>
> <currentMemory>1048576</currentMemory><br>
> <vcpu>1</vcpu><br>
> <devices><br>
> <channel type="unix"><br>
> <target name="com.redhat.rhevm.vdsm" type="virtio"/><br>
> <source mode="bind" path="/var/lib/libvirt/qemu/channels/<br>
> CentOS6Thames.com.redhat.rhevm.vdsm"/><br>
> </channel><br>
> <input bus="ps2" type="mouse"/><br>
> <channel type="spicevmc"><br>
> <target name="com.redhat.spice.0" type="virtio"/><br>
> </channel><br>
> <graphics autoport="yes" keymap="en-us" passwd="*****" <br>
> passwdValidTo="1970-01-01T00:00:01" port="-1" tlsPort="-1" type="spice"><br>
> <channel mode="secure" name="main"/><br>
> <channel mode="secure" name="inputs"/><br>
> <channel mode="secure" name="cursor"/><br>
> <channel mode=&quo t;secure" name="playback"/><br>
> <channel mode="secure" name="record"/><br>
> <channel mode="secure" name="display"/><br>
> <listen network="vdsm-ovirtmgmt" type="network"/><br>
> </graphics><br>
> <console type="pty"><br>
> <target port="0" type="virtio"/><br>
> </console><br>
> <controller type="usb"><br>
> <address domain="0x0000" function="0x2" slot="0x01" type="pci" bus="0x00"/><br>
> </controller><br>
> <video><br>
> <address domain="0x0000" function="0x0" slot="0x02" type="pci" bus="0x00"/><br>
> <model heads="1" type="qxl" vram="65536"/><br>
> </video><br>
> <interface type="bridge"><br>
> <address domain="0x0000" function="0x0" slot="0x03" type="pci" bus="0x00"/><br>
> <mac address="00:1a:4a:a8:0a:00"/><br>
> <model type="virtio"/><br>
> <source bridge="ovirtmgmt"/><br>
> </interface><br>
> <memballoon model="virtio"/><br>
> <disk device="cdrom" snapshot="no" type="file"><br>
> <address bus="1" controller="0" target="0" type="drive" unit="0"/><br>
> <source file="" startupPolicy="optional"/><br>
> <target bus="ide" dev="hdc"/><br>
> <readonly/><br>
> <serial></serial><br>
> </disk><br>
> <disk device="disk" snapshot="no" type="block"><br>
> <address domain="0x0000" function="0x0" slot="0x05" type="pci" bus="0x00"/><br>
> <source dev="/rhev/data-center/332694bb-364a-434e-b23f-5fef985d3cbd/<br>
> 26187d25-bfcb-40c7-97d1-667705ad2223/images/0a7013db-68fd-4c42-bc2e-<br>
> cc8d7a05ca18/f184ecd1-0001-4739-af71-250b412345d6"/><br>
> <target bus="virtio" dev="vda"/><br>
> <serial>0a7013db-68fd-4c42-bc2e-cc8d7a05ca18</serial><br>
> <driver cache="none" error_policy="stop" io="native" name="qemu" <br>
> type="qcow2"/><br>
> </disk><br>
> </devices><br>
> <os><br>
> <type arch="x86_64" machine="pc-0.14">hvm</type><br>
> <smbios mode="sysinfo"/><br>
> </os><br>
> <sysinfo type="smbios"><br>
> <system><br>
> <entry name="manufacturer">Red Hat</entry><br>
> <entry name="product">RHEV Hypervisor</entry><br>
> <entry name="version">17-1</entry><br>
> <entry name="serial">31323334-3535-4C44-3643-4D5633393936_00:19:bb:<br>
> 39:97:4a</entry><br>
> <entry name="uuid">509e608c-e657-473a-b031-f0811da96bde</entry><br>
> </system><br>
> </sysinfo><br>
> <clock adjustment="-1" offset="variable"><br>
> <timer name="rtc" tickpolicy="catchup"/><br>
> </clock><br>
> <features><br>
> <acpi/><br>
> </features><br>
> <cpu match="exact"><br>
> <model>Conroe</model><br>
> <topology cores="1" sockets="1" threads="1"/><br>
> </cpu><br>
> </domain><br>
> <br>
> Thread-7808::DEBUG::2012-09-20 06:47:02,426::vm::580::vm.Vm::<br>
> (_startUnderlyingVm) vmId=`509e608c-e657-473a-b031-<br>
> f0811da96bde`::_ongoingCreations released<br>
> Thread-7808::ERROR::2012-09-20 06:47:02,427::vm::604::vm.Vm::<br>
> (_startUnderlyingVm) vmId=`509e608c-e657-473a-b031-<br>
> f0811da96bde`::The vm start process failed<br>
> Traceback (most recent call last):<br>
> File "/usr/share/vdsm/vm.py", line 570, in _startUnderlyingVm<br>
> File "/usr/share/vdsm/libvirtvm.py", line 1364, in _run<br>
> File "/usr/lib/python2.7/site-packages/vdsm/libvirtconnection.py", <br>
> line 82, in wrapper<br>
> File "/usr/lib64/python2.7/site-packages/libvirt.py", line 2420, in createXML<br>
> libvirtError: unsupported configuration: spice secure channels set <br>
> in XML configuration, but TLS is disabled in qemu.conf<br>
> Thread-7808::DEBUG::2012-09-20 06:47:02,430::vm::920::vm.Vm::<br>
> (setDownStatus) vmId=`509e608c-e657-473a-b031-f0811da96bde`::Changed<br>
> state to Down: unsupported configuration: spice secure channels set <br>
> in XML configuration, but TLS is disabled in qemu.conf</font></tt><br>
<tt><font size="2">> Dummy-1960::DEBUG::2012-09-20 06:47:03,145::__init__::<br>
> 1249::Storage.Misc.excCmd::(_log) 'dd if=/rhev/data-center/<br>
> 332694bb-364a-434e-b23f-5fef985d3cbd/mastersd/dom_md/inbox <br>
> iflag=direct,fullblock count=1 bs=1024000' (cwd None)<br>
> Dummy-1960::DEBUG::2012-09-20 06:47:03,230::__init__::<br>
> 1249::Storage.Misc.excCmd::(_log) SUCCESS: <err> = '1+0 records in<br>
> \n1+0 records out\n1024000 bytes (1.0 MB) copied, 0.0496138 s, 20.6 <br>
> MB/s\n'; <rc> = 0<br>
> Thread-7810::DEBUG::2012-09-20 06:47:03,560::BindingXMLRPC::<br>
> 156::vds::(wrapper) [192.168.10.10]<br>
> Thread-7810::DEBUG::2012-09-20 06:47:03,561::task::<br>
> 588::TaskManager.Task::(_updateState) <br>
> Task=`9bc08c7e-010f-45c2-940a-3fd8361785d5`::moving from state init <br>
> -> state preparing<br>
> Thread-7810::INFO::2012-09-20 06:47:03,561::logUtils::<br>
> 37::dispatcher::(wrapper) Run and protect: getSpmStatus<br>
> (spUUID='332694bb-364a-434e-b23f-5fef985d3cbd', options=None)<br>
> Thread-7810::INFO::2012-09-20 06:47:03,562::logUtils::<br>
> 39::dispatcher::(wrapper) Run and protect: getSpmStatus, Return <br>
> response: {'spm_st': {'spmId': 3, 'spmStatus': 'SPM', 'spmLver': 0}}<br>
> Thread-7810::DEBUG::2012-09-20 06:47:03,562::task::<br>
> 1172::TaskManager.Task::(prepare) <br>
> Task=`9bc08c7e-010f-45c2-940a-3fd8361785d5`::finished: {'spm_st': <br>
> {'spmId': 3, 'spmStatus': 'SPM', 'spmLver': 0}}<br>
> Thread-7810::DEBUG::2012-09-20 06:47:03,562::task::<br>
> 588::TaskManager.Task::(_updateState) <br>
> Task=`9bc08c7e-010f-45c2-940a-3fd8361785d5`::moving from state <br>
> preparing -> state finished<br>
> Thread-7810::DEBUG::2012-09-20 06:47:03,562::resourceManager::<br>
> 809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests <br>
> {} resources {}<br>
> Thread-7810::DEBUG::2012-09-20 06:47:03,562::resourceManager::<br>
> 844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}<br>
> Thread-7810::DEBUG::2012-09-20 06:47:03,563::task::<br>
> 978::TaskManager.Task::(_decref) <br>
> Task=`9bc08c7e-010f-45c2-940a-3fd8361785d5`::ref 0 aborting False<br>
> Thread-7812::DEBUG::2012-09-20 06:47:03,595::BindingXMLRPC::<br>
> 156::vds::(wrapper) [192.168.10.10]<br>
> Thread-7812::DEBUG::2012-09-20 06:47:03,595::task::<br>
> 588::TaskManager.Task::(_updateState) Task=`8e330204-753f-422d-b286-<br>
> a360410806be`::moving from state init -> state preparing<br>
> Thread-7812::INFO::2012-09-20 06:47:03,596::logUtils::<br>
> 37::dispatcher::(wrapper) Run and protect: getStoragePoolInfo<br>
> (spUUID='332694bb-364a-434e-b23f-5fef985d3cbd', options=None)<br>
> Thread-7812::DEBUG::2012-09-20 06:47:03,596::resourceManager::<br>
> 175::ResourceManager.Request::(__init__) ResName=`Storage.<br>
> 332694bb-364a-434e-b23f-5fef985d3cbd`ReqID=`a7222834-3565-4e28-<br>
> a15f-72692ef664c6`::Request was made in '/usr/share/vdsm/storage/<br>
> resourceManager.py' line '485' at 'registerResource'<br>
> Thread-7812::DEBUG::2012-09-20 06:47:03,596::resourceManager::<br>
> 486::ResourceManager::(registerResource) Trying to register resource<br>
> 'Storage.332694bb-364a-434e-b23f-5fef985d3cbd' for lock type 'shared'<br>
> Thread-7812::DEBUG::2012-09-20 06:47:03,597::resourceManager::<br>
> 528::ResourceManager::(registerResource) Resource 'Storage.<br>
> 332694bb-364a-434e-b23f-5fef985d3cbd' is free. Now locking as <br>
> 'shared' (1 active user)<br>
> Thread-7812::DEBUG::2012-09-20 06:47:03,597::resourceManager::<br>
> 212::ResourceManager.Request::(grant) ResName=`Storage.<br>
> 332694bb-364a-434e-b23f-5fef985d3cbd`ReqID=`a7222834-3565-4e28-<br>
> a15f-72692ef664c6`::Granted request<br>
> Thread-7812::DEBUG::2012-09-20 06:47:03,597::task::<br>
> 817::TaskManager.Task::(resourceAcquired) Task=`8e330204-753f-422d-<br>
> b286-a360410806be`::_resourcesAcquired: Storage.332694bb-364a-434e-<br>
> b23f-5fef985d3cbd (shared)<br>
> Thread-7812::DEBUG::2012-09-20 06:47:03,598::task::<br>
> 978::TaskManager.Task::(_decref) Task=`8e330204-753f-422d-b286-<br>
> a360410806be`::ref 1 aborting False<br>
> Thread-7813::DEBUG::2012-09-20 06:47:03,598::BindingXMLRPC::<br>
> 859::vds::(wrapper) client [192.168.10.10]::call vmGetStats with <br>
> ('509e608c-e657-473a-b031-f0811da96bde',) {}<br>
> Thread-7812::INFO::2012-09-20 06:47:03,599::logUtils::<br>
> 39::dispatcher::(wrapper) Run and protect: getStoragePoolInfo, <br>
> Return response: {'info': {'spm_id': 3, 'master_uuid': '26187d25-<br>
> bfcb-40c7-97d1-667705ad2223', 'name': 'Valeka', 'version': '2', <br>
> 'domains': u'26187d25-bfcb-40c7-97d1-667705ad2223:Active,<br>
> 90104c3d-837b-47dd-8c82-dda92eec30d9:Active', 'pool_status': <br>
> 'connected', 'isoprefix': u'/rhev/data-center/332694bb-364a-434e-<br>
> b23f-5fef985d3cbd/90104c3d-837b-47dd-8c82-dda92eec30d9/images/<br>
> 11111111-1111-1111-1111-111111111111', 'type': 'ISCSI', <br>
> 'master_ver': 1, 'lver': 0}, 'dominfo': {u'26187d25-<br>
> bfcb-40c7-97d1-667705ad2223': {'status': u'Active', 'diskfree': <br>
> '1674097721344', 'alerts': [], 'disktotal': '1799591297024'}, <br>
> u'90104c3d-837b-47dd-8c82-dda92eec30d9': {'status': u'Active', <br>
> 'diskfree': '423518535680', 'alerts': [], 'disktotal': '492264226816'}}}<br>
> Thread-7813::DEBUG::2012-09-20 06:47:03,600::BindingXMLRPC::<br>
> 865::vds::(wrapper) return vmGetStats with {'status': {'message': <br>
> 'Done', 'code': 0}, 'statsList': [{'status': 'Down', 'hash': '0', <br>
> 'exitMessage': 'unsupported configuration: spice secure channels set<br>
> in XML configuration, but TLS is disabled in qemu.conf', 'vmId': <br>
> '509e608c-e657-473a-b031-f0811da96bde', 'timeOffset': '-1', 'exitCode': 1}]}<br>
> Thread-7812::DEBUG::2012-09-20 06:47:03,600::task::<br>
> 1172::TaskManager.Task::(prepare) Task=`8e330204-753f-422d-b286-<br>
> a360410806be`::finished: {'info': {'spm_id': 3, 'master_uuid': <br>
> '26187d25-bfcb-40c7-97d1-667705ad2223', 'name': 'Valeka', 'version':<br>
> '2', 'domains': u'26187d25-bfcb-40c7-97d1-667705ad2223:Active,<br>
> 90104c3d-837b-47dd-8c82-dda92eec30d9:Active', 'pool_status': <br>
> 'connected', 'isoprefix': u'/rhev/data-center/332694bb-364a-434e-<br>
> b23f-5fef985d3cbd/90104c3d-837b-47dd-8c82-dda92eec30d9/images/<br>
> 11111111-1111-1111-1111-111111111111', 'type': 'ISCSI', <br>
> 'master_ver': 1, 'lver': 0}, 'dominfo': {u'26187d25-<br>
> bfcb-40c7-97d1-667705ad2223': {'status': u'Active', 'diskfree': <br>
> '1674097721344', 'alerts': [], 'disktotal': '1799591297024'}, <br>
> u'90104c3d-837b-47dd-8c82-dda92eec30d9': {'status': u'Active', <br>
> 'diskfree': '423518535680', 'alerts': [], 'disktotal': '492264226816'}}}<br>
> Thread-7812::DEBUG::2012-09-20 06:47:03,601::task::<br>
> 588::TaskManager.Task::(_updateState) Task=`8e330204-753f-422d-b286-<br>
> a360410806be`::moving from state preparing -> state finished<br>
> Thread-7812::DEBUG::2012-09-20 06:47:03,601::resourceManager::<br>
> 809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests <br>
> {} resources {'Storage.332694bb-364a-434e-b23f-5fef985d3cbd': < <br>
> ResourceRef 'Storage.332694bb-364a-434e-b23f-5fef985d3cbd', isValid:<br>
> 'True' obj: 'None'>}<br>
> Thread-7812::DEBUG::2012-09-20 06:47:03,601::resourceManager::<br>
> 844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}<br>
> Thread-7812::DEBUG::2012-09-20 06:47:03,602::resourceManager::<br>
> 538::ResourceManager::(releaseResource) Trying to release resource <br>
> 'Storage.332694bb-364a-434e-b23f-5fef985d3cbd'<br>
> Thread-7812::DEBUG::2012-09-20 06:47:03,602::resourceManager::<br>
> 553::ResourceManager::(releaseResource) Released resource 'Storage.<br>
> 332694bb-364a-434e-b23f-5fef985d3cbd' (0 active users)<br>
> Thread-7812::DEBUG::2012-09-20 06:47:03,602::resourceManager::<br>
> 558::ResourceManager::(releaseResource) Resource 'Storage.<br>
> 332694bb-364a-434e-b23f-5fef985d3cbd' is free, finding out if anyone<br>
> is waiting for it.<br>
> Thread-7812::DEBUG::2012-09-20 06:47:03,602::resourceManager::<br>
> 565::ResourceManager::(releaseResource) No one is waiting for <br>
> resource 'Storage.332694bb-364a-434e-b23f-5fef985d3cbd', Clearing records.<br>
> Thread-7812::DEBUG::2012-09-20 06:47:03,602::task::<br>
> 978::TaskManager.Task::(_decref) Task=`8e330204-753f-422d-b286-<br>
> a360410806be`::ref 0 aborting False<br>
> Thread-7814::DEBUG::2012-09-20 06:47:03,658::BindingXMLRPC::<br>
> 859::vds::(wrapper) client [192.168.10.10]::call vmDestroy with <br>
> ('509e608c-e657-473a-b031-f0811da96bde',) {}<br>
> Thread-7814::INFO::2012-09-20 06:47:03,658::API::317::vds::(destroy)<br>
> vmContainerLock acquired by vm 509e608c-e657-473a-b031-f0811da96bde<br>
> Thread-7814::DEBUG::2012-09-20 06:47:03,658::libvirtvm::<br>
> 2085::vm.Vm::(destroy) vmId=`509e608c-e657-473a-b031-<br>
> f0811da96bde`::destroy Called<br>
> Thread-7814::INFO::2012-09-20 06:47:03,658::libvirtvm::2040::vm.Vm::<br>
> (releaseVm) vmId=`509e608c-e657-473a-b031-f0811da96bde`::Release VM resources<br>
> Thread-7814::WARNING::2012-09-20 06:47:03,659::vm::328::vm.Vm::<br>
> (_set_lastStatus) vmId=`509e608c-e657-473a-b031-<br>
> f0811da96bde`::trying to set state to Powering down when already Down<br>
> Thread-7814::DEBUG::2012-09-20 06:47:03,659::__init__::<br>
> 1249::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /usr/sbin/<br>
> service ksmtuned retune' (cwd None)<br>
> Thread-7814::DEBUG::2012-09-20 06:47:03,696::__init__::<br>
> 1249::Storage.Misc.excCmd::(_log) FAILED: <err> = 'Redirecting to /<br>
> bin/systemctl retune ksmtuned.service\nUnknown operation retune\n'; <rc> = 1<br>
> Thread-7814::DEBUG::2012-09-20 06:47:03,697::task::<br>
> 588::TaskManager.Task::(_updateState) Task=`e97820bb-547d-4e7a-9249-<br>
> ece94285bac8`::moving from state init -> state preparing<br>
> Thread-7814::INFO::2012-09-20 06:47:03,698::logUtils::<br>
> 37::dispatcher::(wrapper) Run and protect: inappropriateDevices<br>
> (thiefId='509e608c-e657-473a-b031-f0811da96bde')<br>
> Thread-7814::INFO::2012-09-20 06:47:03,699::logUtils::<br>
> 39::dispatcher::(wrapper) Run and protect: inappropriateDevices, <br>
> Return response: None<br>
> Thread-7814::DEBUG::2012-09-20 06:47:03,699::task::<br>
> 1172::TaskManager.Task::(prepare) Task=`e97820bb-547d-4e7a-9249-<br>
> ece94285bac8`::finished: None<br>
> Thread-7814::DEBUG::2012-09-20 06:47:03,700::task::<br>
> 588::TaskManager.Task::(_updateState) Task=`e97820bb-547d-4e7a-9249-<br>
> ece94285bac8`::moving from state preparing -> state finished<br>
> Thread-7814::DEBUG::2012-09-20 06:47:03,700::resourceManager::<br>
> 809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests <br>
> {} resources {}<br>
> Thread-7814::DEBUG::2012-09-20 06:47:03,700::resourceManager::<br>
> 844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}<br>
> Thread-7814::DEBUG::2012-09-20 06:47:03,700::task::<br>
> 978::TaskManager.Task::(_decref) Task=`e97820bb-547d-4e7a-9249-<br>
> ece94285bac8`::ref 0 aborting False<br>
> Thread-7814::DEBUG::2012-09-20 06:47:03,700::libvirtvm::<br>
> 2080::vm.Vm::(deleteVm) vmId=`509e608c-e657-473a-b031-<br>
> f0811da96bde`::Total desktops after destroy of 509e608c-e657-473a-<br>
> b031-f0811da96bde is 0<br>
> Thread-7814::DEBUG::2012-09-20 06:47:03,701::BindingXMLRPC::<br>
> 865::vds::(wrapper) return vmDestroy with {'status': {'message': <br>
> 'Machine destroyed', 'code': 0}}<br>
> Thread-481::DEBUG::2012-09-20 06:47:04,302::__init__::<br>
> 1249::Storage.Misc.excCmd::(_log) '/usr/bin/dd iflag=direct if=/dev/<br>
> 26187d25-bfcb-40c7-97d1-667705ad2223/metadata bs=4096 count=1' (cwd None)<br>
> Thread-481::DEBUG::2012-09-20 06:47:04,317::__init__::<br>
> 1249::Storage.Misc.excCmd::(_log) SUCCESS: <err> = '1+0 records in<br>
> \n1+0 records out\n4096 bytes (4.1 kB) copied, 0.000843551 s, 4.9 <br>
> MB/s\n'; <rc> = 0<br>
> Dummy-1960::DEBUG::2012-09-20 06:47:05,239::__init__::<br>
> 1249::Storage.Misc.excCmd::(_log) 'dd if=/rhev/data-center/<br>
> 332694bb-364a-434e-b23f-5fef985d3cbd/mastersd/dom_md/inbox <br>
> iflag=direct,fullblock count=1 bs=1024000' (cwd None)<br>
> Dummy-1960::DEBUG::2012-09-20 06:47:05,323::__init__::<br>
> 1249::Storage.Misc.excCmd::(_log) SUCCESS: <err> = '1+0 records in<br>
> \n1+0 records out\n1024000 bytes (1.0 MB) copied, 0.0476578 s, 21.5 <br>
> MB/s\n'; <rc> = 0<br>
> Thread-7815::DEBUG::2012-09-20 06:47:05,819::task::<br>
> 588::TaskManager.Task::(_updateState) Task=`ef5f39d0-241c-44b5-a771-<br>
> da364468b498`::moving from state init -> state preparing<br>
> Thread-7815::INFO::2012-09-20 06:47:05,819::logUtils::<br>
> 37::dispatcher::(wrapper) Run and protect: repoStats(options=None)<br>
> Thread-7815::INFO::2012-09-20 06:47:05,820::logUtils::<br>
> 39::dispatcher::(wrapper) Run and protect: repoStats, Return <br>
> response: {'26187d25-bfcb-40c7-97d1-667705ad2223': {'delay': '0.<br>
> 0156102180481', 'lastCheck': 1348123624.512314, 'code': 0, 'valid': <br>
> True}, '90104c3d-837b-47dd-8c82-dda92eec30d9': {'delay': '0.<br>
> 0011830329895', 'lastCheck': 1348123617.41074, 'code': 0, 'valid': True}}<br>
> Thread-7815::DEBUG::2012-09-20 06:47:05,820::task::<br>
> 1172::TaskManager.Task::(prepare) Task=`ef5f39d0-241c-44b5-a771-<br>
> da364468b498`::finished: {'26187d25-bfcb-40c7-97d1-667705ad2223': <br>
> {'delay': '0.0156102180481', 'lastCheck': 1348123624.512314, 'code':<br>
> 0, 'valid': True}, '90104c3d-837b-47dd-8c82-dda92eec30d9': {'delay':<br>
> '0.0011830329895', 'lastCheck': 1348123617.41074, 'code': 0, 'valid': True}}<br>
> Thread-7815::DEBUG::2012-09-20 06:47:05,820::task::<br>
> 588::TaskManager.Task::(_updateState) Task=`ef5f39d0-241c-44b5-a771-<br>
> da364468b498`::moving from state preparing -> state finished<br>
> Thread-7815::DEBUG::2012-09-20 06:47:05,820::resourceManager::<br>
> 809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests <br>
> {} resources {}<br>
> Thread-7815::DEBUG::2012-09-20 06:47:05,821::resourceManager::<br>
> 844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}<br>
> Thread-7815::DEBUG::2012-09-20 06:47:05,821::task::<br>
> 978::TaskManager.Task::(_decref) Task=`ef5f39d0-241c-44b5-a771-<br>
> da364468b498`::ref 0 aborting False<br>
> Dummy-1960::DEBUG::2012-09-20 06:47:07,332::__init__::<br>
> 1249::Storage.Misc.excCmd::(_log) 'dd if=/rhev/data-center/<br>
> 332694bb-364a-434e-b23f-5fef985d3cbd/mastersd/dom_md/inbox <br>
> iflag=direct,fullblock count=1 bs=1024000' (cwd None)<br>
> Dummy-1960::DEBUG::2012-09-20 06:47:07,458::__init__::<br>
> 1249::Storage.Misc.excCmd::(_log) SUCCESS: <err> = '1+0 records in<br>
> \n1+0 records out\n1024000 bytes (1.0 MB) copied, 0.0478973 s, 21.4 <br>
> MB/s\n'; <rc> = 0<br>
> Dummy-1960::DEBUG::2012-09-20 06:47:09,502::__init__::<br>
> 1249::Storage.Misc.excCmd::(_log) 'dd if=/rhev/data-center/<br>
> 332694bb-364a-434e-b23f-5fef985d3cbd/mastersd/dom_md/inbox <br>
> iflag=direct,fullblock count=1 bs=1024000' (cwd None)<br>
> Dummy-1960::DEBUG::2012-09-20 06:47:09,586::__init__::<br>
> 1249::Storage.Misc.excCmd::(_log) SUCCESS: <err> = '1+0 records in<br>
> \n1+0 records out\n1024000 bytes (1.0 MB) copied, 0.0485543 s, 21.1 <br>
> MB/s\n'; <rc> = 0<br>
> <br>
> If I try to create new server I have the same error message.<br>
> <br>
> - -<br>
> Dmitriy Pyryakov </font></tt><br>
<tt><font size="2">> VimpelCom Ltd.</font></tt><br>
<tt><font size="2">> <br>
> _______________________________________________<br>
> Users mailing list<br>
> Users@ovirt.org<br>
> <a href="http://lists.ovirt.org/mailman/listinfo/users">http://lists.ovirt.org/mailman/listinfo/users</a></font></tt></body></html>