[Users] Host migration problem

Thu Sep 20 08:36:10 UTC 2012

Doron Fediuck <dfediuck at redhat.com> написано 20.09.2012 13:40:59:

> От: Doron Fediuck <dfediuck at redhat.com>
> Кому: Dmitriy A Pyryakov <DPyryakov at ekb.beeline.ru>
> Копия: users at ovirt.org, Oved Ourfalli <ovedo at redhat.com>
> Дата: 20.09.2012 13:41
> Тема: Re: [Users] Host migration problem
>
> 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

# echo "select * from vdc_options where option_name like
'%SpiceSecureChannels%'" | psql -d engine -U postgres
 option_id |     option_name     |                   option_value
| version
-----------+---------------------+--------------------------------------------------+---------
       346 | SpiceSecureChannels | smain,sinputs
| 2.2
       347 | SpiceSecureChannels | smain,sinputs
| 3.0
       348 | SpiceSecureChannels |
smain,sinputs,scursor,splayback,srecord,sdisplay | 3.1

> So...
> 1. Please check your cluster version (you should be using 3.1) and
> please report.

Yes, I have only 3.1 version.

> 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)

I set it on each host and restart libvirtd, VMs now can start.
Thank you so much.

> 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.
>
>

> From: "Dmitriy A Pyryakov" <DPyryakov at ekb.beeline.ru>
> To: users at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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::
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.ovirt.org/pipermail/users/attachments/20120920/11097cb8/attachment-0001.html>