[Users] Host migration problem

20 Sep 2012

      --0__=C9BBF0ECDFB7B2218f9e8a93df938690918cC9BBF0ECDFB7B221
Content-type: text/plain; charset=US-ASCII
Content-transfer-encoding: quoted-printable

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 configurati=
on,
but TLS is disabled in qemu.conf.

engine.log:
[root@admin ~]# tail -f -n 0 /var/log/ovirt-engine/engine.log
2012-09-20 12:42:53,289 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.IsValidVDSCommand]
(ajp--0.0.0.0-8009-10) START, IsValidVDSCommand(storagePoolId =3D
332694bb-364a-434e-b23f-5fef985d3cbd, ignoreFailoverLimit =3D false,
compatabilityVersion =3D 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 =3D
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=3D key: 509e608c-e657-473a-b031-f0811da96bde value: VM
, sharedLocks=3D ]
2012-09-20 12:42:53,415 INFO  [org.ovirt.engine.core.bll.RunVmCommand]
(pool-3-thread-50) [a58d974] Running command: RunVmCommand internal: fa=
lse.
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 =3D
0a268762-02d7-11e2-b750-0011856cf23e,
vmId=3D509e608c-e657-473a-b031-f0811da96bde,
vm=3Dorg.ovirt.engine.core.common.businessentities.VM@1911737b), log id=
:
77c0e559
2012-09-20 12:42:53,529 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand]
(pool-3-thread-50) [a58d974] START, CreateVDSCommand(vdsId =3D
0a268762-02d7-11e2-b750-0011856cf23e,
vmId=3D509e608c-e657-473a-b031-f0811da96bde,
vm=3Dorg.ovirt.engine.core.common.businessentities.VM@1911737b), log id=
:
f48008f
2012-09-20 12:42:53,602 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand]
(pool-3-thread-50) [a58d974]
org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand
spiceSslCipherSuite=3DDEFAULT,memSize=3D1024,kvmEnable=3Dtrue,smp=3D1,e=
mulatedMachine=3Dpc-0.14,vmType=3Dkvm,keyboardLayout=3Den-us,pitReinjec=
tion=3Dfalse,nice=3D0,display=3Dqxl,smpCoresPerSocket=3D1,spiceSecureCh=
annels=3Dsmain,sinputs,scursor,splayback,srecord,sdisplay,displayNetwor=
k=3Dovirtmgmt,timeOffset=3D-1,transparentHugePages=3Dtrue,vmId=3D509e60=
8c
                            -e657-473a-b031-f0811da96bde,devices=3D
[Ljava.util.Map;@760db68c,acpiEnable=3Dtrue,vmName=3DCentOS6Thames,cpuT=
ype=3DConroe,custom=3D
{device_bb912edd-9790-43ff-a758-f1d9f20cb5f5device_f5c86859-5ae9-4a37-9=
d34-2b9547609622device_20a11f26-6a39-415d-a7bf-95893b9c55b5=3DVmId=3D50=
9e608c-e657-473a-b031-f0811da96bde,DeviceId=3D20a11f26-6a39-415d-a7bf-9=
5893b9c55b5,Device=3Dunix,Type=3Dchannel,BootOrder=3D0,SpecParams=3D
{},Address=3D{port=3D1, bus=3D0, controller=3D0,
type=3Dvirtio-serial},IsManaged=3Dfalse,IsPlugged=3Dtrue,IsReadOnly=3Df=
alse,alias=3D
channel0,
device_bb912edd-9790-43ff-a758-f1d9f20cb5f5=3DVmId=3D509e608c-e657-473a=
-b031-f0811da96bde,DeviceId=3Dbb912edd-9790-43ff-a758-f1d9f20cb5f5,Devi=
ce=3Dide,Type=3Dcontroller,BootOrder=3D0,SpecParams=3D
{},Address=3D{bus=3D0x00, domain=3D0x0000, type=3Dpci, slot=3D0x01,
function=3D0x1},IsManaged=3Dfalse,IsPlugged=3Dtrue,IsReadOnly=3Dfalse,a=
lias=3Dide0,
device_bb912edd-9790-43ff-a758-f1d9f20cb5f5device_f5c86859-5ae9-4a37-9d=
34-2b9547609622=3DVmId=3D509e608c-e657-473a-b031-f0811da96bde,DeviceId=3D=
f5c86859-5ae9-4a37-9d34-2b9547609622,Devic

e=3Dvirtio-serial,Type=3Dcontroller,BootOrder=3D0,SpecParams=3D{},Addre=
ss=3D
{bus=3D0x00, domain=3D0x0000, type=3Dpci, slot=3D0x04,
function=3D0x0},IsManaged=3Dfalse,IsPlugged=3Dtrue,IsReadOnly=3Dfalse,a=
lias=3Dvirtio-serial0,

device_bb912edd-9790-43ff-a758-f1d9f20cb5f5device_f5c86859-5ae9-4a37-9d=
34-2b9547609622device_20a11f26-6a39-415d-a7bf-95893b9c55b5device_21f255=
dc-9b3b-48d8-b8e4-63c1635e269b=3DVmId=3D509e608c-e657-473a-b031-f0811da=
96bde,DeviceId=3D21f255dc-9b3b-48d8-b8e4-63c1635e269b,Device=3Dspicevmc=
,Type=3Dchannel,BootOrder=3D0,SpecP
                            arams=3D{},Address=3D{port=3D2, bus=3D0, co=
ntroller=3D0,
type=3Dvirtio-serial},IsManaged=3Dfalse,IsPlugged=3Dtrue,IsReadOnly=3Df=
alse,alias=3Dchannel1,

device_bb912edd-9790-43ff-a758-f1d9f20cb5f5device_f5c86859-5ae9-4a37-9d=
34-2b9547609622device_20a11f26-6a39-415d-a7bf-95893b9c55b5device_21f255=
dc-9b3b-48d8-b8e4-63c1635e269bdevice_d6c2c4d1-da6b-44fe-a5aa-508135c7fd=
fe=3DVmId=3D509e608c-e657-473a-b031-f0811da96bde,DeviceId=3Dd6c2c4d1-da=
6b-44fe-a5aa-508135c7fdfe,Device=3Dusb,Type=3Dcontroller,BootOrder=3D0,=
SpecParams=3D
{},Address=3D{bus=3D0x0                            0, domain=3D0x0000, =
type=3Dpci,
slot=3D0x01,
function=3D0x2},IsManaged=3Dfalse,IsPlugged=3Dtrue,IsReadOnly=3Dfalse,a=
lias=3Dusb0}
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=3D key: 509e608c-e657-473a-b031-f0811da96bde value: VM
, sharedLocks=3D ]
2012-09-20 12:42:54,418 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.DestroyVDSCommand]
(QuartzScheduler_Worker-12) START, DestroyVDSCommand(vdsId =3D
0a268762-02d7-11e2-b750-0011856cf23e,
vmId=3D509e608c-e657-473a-b031-f0811da96bde, force=3Dfalse, secondsToWa=
it=3D0,
gracefully=3Dfalse), 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 runn=
ing
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-f0811da96b=
de.
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 =3D
0a268762-02d7-11e2-b750-0011856cf23e,
vdsDynamic=3Dorg.ovirt.engine.core.common.businessentities.VdsDynamic@d=
b702e05),
 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: 71c6=
e6a3
2012-09-20 12:42:54,584 INFO  [org.ovirt.engine.core.bll.RunVmCommand]
(pool-3-thread-50) Lock Acquired to object EngineLock [exclusiveLocks=3D=
 key:
509e608c-e657-473a-b031-f0811da96bde value: VM
, sharedLocks=3D ]
2012-09-20 12:42:54,603 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.IsValidVDSCommand]
(pool-3-thread-50) START, IsValidVDSCommand(storagePoolId =3D
332694bb-364a-434e-b23f-5fef985d3cbd, ignoreFailoverLimit =3D false,
compatabilityVersion =3D 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: f19=
03fc
2012-09-20 12:42:54,653 INFO
[org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand]
(pool-3-thread-50) START, IsVmDuringInitiatingVDSCommand(vmId =3D
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: fals=
e,
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. Entit=
ies
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 =3D 9840e840-02db-11e2-a01a-0011856cf23=
e,
vmId=3D509e608c-e657-473a-b031-f0811da96bde,
vm=3Dorg.ovirt.engine.core.common.businessentities.VM@4432a01d), log id=
:
554a0742
2012-09-20 12:42:54,825 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand]
(pool-3-thread-50) START, CreateVDSCommand(vdsId =3D
9840e840-02db-11e2-a01a-0011856cf23e,
vmId=3D509e608c-e657-473a-b031-f0811da96bde,
vm=3Dorg.ovirt.engine.core.common.businessentities.VM@4432a01d), log id=
:
73615350
2012-09-20 12:42:54,912 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand]
(pool-3-thread-50)
org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand
spiceSslCipherSuite=3DDEFAULT,memSize=3D1024,kvmEnable=3Dtrue,smp=3D1,e=
mulatedMachine=3Dpc-0.14,vmType=3Dkvm,keyboardLayout=3Den-us,pitReinjec=
tion=3Dfalse,nice=3D0,display=3Dqxl,smpCoresPerSocket=3D1,spiceSecureCh=
annels=3Dsmain,sinputs,scursor,splayback,srecord,sdisplay,displayNetwor=
k=3Dovirtmgmt,timeOffset=3D-1,transparentHugePages=3Dtrue,vmId=3D509e60=
8c-e657-473a
                            -b031-f0811da96bde,devices=3D
[Ljava.util.Map;@41d42882,acpiEnable=3Dtrue,vmName=3DCentOS6Thames,cpuT=
ype=3DConroe,custom=3D
{device_bb912edd-9790-43ff-a758-f1d9f20cb5f5device_f5c86859-5ae9-4a37-9=
d34-2b9547609622device_20a11f26-6a39-415d-a7bf-95893b9c55b5=3DVmId=3D50=
9e608c-e657-473a-b031-f0811da96bde,DeviceId=3D20a11f26-6a39-415d-a7bf-9=
5893b9c55b5,Device=3Dunix,Type=3Dchannel,BootOrder=3D0,SpecParams=3D
{},Address=3D{port=3D1, bus=3D0, controller=3D0,
type=3Dvirtio-serial},IsManaged=3Dfalse,IsPlugged=3Dtrue,IsReadOnly=3Df=
alse,alias=3Dchannel0,

device_bb912edd-9790-43ff-a758-f1d9f20cb5f5=3DVmId=3D509e608c-e657-473a=
-b031-f0811da96bde,DeviceId=3Dbb912edd-9790-43ff-a758-f1d9f20cb5f5,Devi=
ce=3Dide,Type=3Dcontroller,BootOrder=3D0,SpecParams=3D
{},Address=3D{bus=3D0x00, domain=3D0x0000, type=3Dpci, slot=3D0x01,
function=3D0x1},IsManaged=3Dfalse,IsPlugged=3Dtrue,IsReadOnly=3Dfalse,a=
lias=3Dide0,
device_bb912edd-9790-43ff-a758-f1d9f20cb5f5device_f5c86859-5ae9-4a37-9d=
34-2b9547609622=3DVmId=3D509e608c-e657-473a-b031-f0811da96bde,DeviceId=3D=
f5c86859-5ae9-4a37-9d34-2b9547609622,Device=3Dvirtio-s
                            erial,Type=3Dcontroller,BootOrder=3D0,SpecP=
arams=3D
{},Address=3D{bus=3D0x00, domain=3D0x0000, type=3Dpci, slot=3D0x04,
function=3D0x0},IsManaged=3Dfalse,IsPlugged=3Dtrue,IsReadOnly=3Dfalse,a=
lias=3Dvirtio-serial0,

device_bb912edd-9790-43ff-a758-f1d9f20cb5f5device_f5c86859-5ae9-4a37-9d=
34-2b9547609622device_20a11f26-6a39-415d-a7bf-95893b9c55b5device_21f255=
dc-9b3b-48d8-b8e4-63c1635e269b=3DVmId=3D509e608c-e657-473a-b031-f0811da=
96bde,DeviceId=3D21f255dc-9b3b-48d8-b8e4-63c1635e269b,Device=3Dspicevmc=
,Type=3Dchannel,BootOrder=3D0,SpecParams=3D
{},A                            ddress=3D{port=3D2, bus=3D0, controller=
=3D0,
type=3Dvirtio-serial},IsManaged=3Dfalse,IsPlugged=3Dtrue,IsReadOnly=3Df=
alse,alias=3Dchannel1,

device_bb912edd-9790-43ff-a758-f1d9f20cb5f5device_f5c86859-5ae9-4a37-9d=
34-2b9547609622device_20a11f26-6a39-415d-a7bf-95893b9c55b5device_21f255=
dc-9b3b-48d8-b8e4-63c1635e269bdevice_d6c2c4d1-da6b-44fe-a5aa-508135c7fd=
fe=3DVmId=3D509e608c-e657-473a-b031-f0811da96bde,DeviceId=3Dd6c2c4d1-da=
6b-44fe-a5aa-508135c7fdfe,Device=3Dusb,Type=3Dcontroller,BootOrder=3D0,=
SpecParams=3D
{},Address=3D{bus=3D0x00, domain=3D                            0x0000, =
type=3Dpci,
slot=3D0x01,
function=3D0x2},IsManaged=3Dfalse,IsPlugged=3Dtrue,IsReadOnly=3Dfalse,a=
lias=3Dusb0}
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 vcp=
u
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=3D k=
ey:
509e608c-e657-473a-b031-f0811da96bde value: VM
, sharedLocks=3D ]
2012-09-20 12:42:56,434 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.DestroyVDSCommand]
(QuartzScheduler_Worker-32) START, DestroyVDSCommand(vdsId =3D
9840e840-02db-11e2-a01a-0011856cf23e,
vmId=3D509e608c-e657-473a-b031-f0811da96bde, force=3Dfalse, secondsToWa=
it=3D0,
gracefully=3Dfalse), 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 runn=
ing
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-f0811da96b=
de.
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 =3D
9840e840-02db-11e2-a01a-0011856cf23e,
vdsDynamic=3Dorg.ovirt.engine.core.common.businessentities.VdsDynamic@5=
f1dd7c7),
 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: 2a19=
1f9e
2012-09-20 12:42:56,616 INFO  [org.ovirt.engine.core.bll.RunVmCommand]
(pool-3-thread-50) Lock Acquired to object EngineLock [exclusiveLocks=3D=
 key:
509e608c-e657-473a-b031-f0811da96bde value: VM
, sharedLocks=3D ]
2012-09-20 12:42:56,632 INFO
[org.ovirt.engine.core.vdsbroker.irsbroker.IsValidVDSCommand]
(pool-3-thread-50) START, IsValidVDSCommand(storagePoolId =3D
332694bb-364a-434e-b23f-5fef985d3cbd, ignoreFailoverLimit =3D false,
compatabilityVersion =3D 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 =3D
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: fals=
e,
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,V=
AR__ACTION__RUN,VAR__TYPE__VM,VAR__ACTION__RUN,VAR__TYPE__VM,ACTION_TYP=
E_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=3D k=
ey:
509e608c-e657-473a-b031-f0811da96bde value: VM
, sharedLocks=3D ]

vdsm.log:
Dummy-1960::DEBUG::2012-09-20
06:46:58,959::__init__::1249::Storage.Misc.excCmd::(_log) 'dd
if=3D/rhev/data-center/332694bb-364a-434e-b23f-5fef985d3cbd/mastersd/do=
m_md/inbox
 iflag=3Ddirect,fullblock count=3D1 bs=3D1024000' (cwd None)
Dummy-1960::DEBUG::2012-09-20
06:46:59,043::__init__::1249::Storage.Misc.excCmd::(_log) SUCCESS: <err=
...
=3D
'1+0 records in\n1+0 records out\n1024000 bytes (1.0 MB) copied, 0.0488=
089
s, 21.0 MB/s\n'; <rc> =3D 0
Dummy-1960::DEBUG::2012-09-20
06:47:01,053::__init__::1249::Storage.Misc.excCmd::(_log) 'dd
if=3D/rhev/data-center/332694bb-364a-434e-b23f-5fef985d3cbd/mastersd/do=
m_md/inbox
 iflag=3Ddirect,fullblock count=3D1 bs=3D1024000' (cwd None)
Dummy-1960::DEBUG::2012-09-20
06:47:01,136::__init__::1249::Storage.Misc.excCmd::(_log) SUCCESS: <err=
=3D
'1+0 records in\n1+0 records out\n1024000 bytes (1.0 MB) copied, 0.0477=
826
s, 21.4 MB/s\n'; <rc> =3D 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_21f2=
55dc-9b3b-48d8-b8e4-63c1635e269bdevice_d6c2c4d1-da6b-44fe-a5aa-508135c7=
fdfe':
'VmId=3D509e608c-e657-473a-b031-f0811da96bde,DeviceId=3Dd6c2c4d1-da6b-4=
4fe-a5aa-508135c7fdfe,Device=3Dusb,Type=3Dcontroller,BootOrder=3D0,Spec=
Params=3D
{},Address=3D{bus=3D0x00, domain=3D0x0000, type=3Dpci, slot=3D0x01,
function=3D0x2},IsManaged=3Dfalse,IsPlugged=3Dtrue,IsReadOnly=3Dfalse,a=
lias=3Dusb0',
'device_bb912edd-9790-43ff-a758-f1d9f20cb5f5device_f5c86859-5ae9-4a37-9=
d34-2b9547609622device_20a11f26-6a39-415d-a7bf-95893b9c55b5device_21f25=
5dc-9b3b-48d8-b8e4-63c1635e269b':

'VmId=3D509e608c-e657-473a-b031-f0811da96bde,DeviceId=3D21f255dc-9b3b-4=
8d8-b8e4-63c1635e269b,Device=3Dspicevmc,Type=3Dchannel,BootOrder=3D0,Sp=
ecParams=3D
{},Address=3D{port=3D2, bus=3D0, controller=3D0,
type=3Dvirtio-serial},IsManaged=3Dfalse,IsPlugged=3Dtrue,IsReadOnly=3Df=
alse,alias=3Dchannel1',

'device_bb912edd-9790-43ff-a758-f1d9f20cb5f5device_f5c86859-5ae9-4a37-9=
d34-2b9547609622':

'VmId=3D509e608c-e657-473a-b031-f0811da96bde,DeviceId=3Df5c86859-5ae9-4=
a37-9d34-2b9547609622,Device=3Dvirtio-serial,Type=3Dcontroller,BootOrde=
r=3D0,SpecParams=3D
{},Address=3D{bus=3D0x00, domain=3D0x0000, type=3Dpci, slot=3D0x04,
function=3D0x0},IsManaged=3Dfalse,IsPlugged=3Dtrue,IsReadOnly=3Dfalse,a=
lias=3Dvirtio-serial0',

'device_bb912edd-9790-43ff-a758-f1d9f20cb5f5device_f5c86859-5ae9-4a37-9=
d34-2b9547609622device_20a11f26-6a39-415d-a7bf-95893b9c55b5':

'VmId=3D509e608c-e657-473a-b031-f0811da96bde,DeviceId=3D20a11f26-6a39-4=
15d-a7bf-95893b9c55b5,Device=3Dunix,Type=3Dchannel,BootOrder=3D0,SpecPa=
rams=3D
{},Address=3D{port=3D1, bus=3D0, controller=3D0,
type=3Dvirtio-serial},IsManaged=3Dfalse,IsPlugged=3Dtrue,IsReadOnly=3Df=
alse,alias=3Dchannel0',
 'device_bb912edd-9790-43ff-a758-f1d9f20cb5f5':
'VmId=3D509e608c-e657-473a-b031-f0811da96bde,DeviceId=3Dbb912edd-9790-4=
3ff-a758-f1d9f20cb5f5,Device=3Dide,Type=3Dcontroller,BootOrder=3D0,Spec=
Params=3D
{},Address=3D{bus=3D0x00, domain=3D0x0000, type=3Dpci, slot=3D0x01,
function=3D0x1},IsManaged=3Dfalse,IsPlugged=3Dtrue,IsReadOnly=3Dfalse,a=
lias=3Dide0'},
'keyboardLayout': 'en-us', 'kvmEnable': 'true', 'pitReinjection': 'fals=
e',
'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', ' functio=
n':
'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'}, {'ifac=
e':
'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', ' sl=
ot':
'0x05', ' domain': '0x0000', ' type': 'pci', ' function': '0x0'}, 'devi=
ce':
'disk', 'shared': 'false', 'propagateErrors': 'off', 'optional': 'false=
'},
{'nicModel': 'pv', 'macAddr': '00:1a:4a:a8:0a:00', 'network': 'ovirtmgm=
t',
'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', ' sl=
ot':
'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=3D`509e608c-e657-473a-b031-f0811da96bde`::Start
Thread-7807::DEBUG::2012-09-20 06:47:01,996::API::244::vds::(create) To=
tal
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=3D`509e608c-e657-473a-b031-f0811da96bde`::_ongoingCreations acquir=
ed
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_21f2=
55dc-9b3b-48d8-b8e4-63c1635e269bdevice_d6c2c4d1-da6b-44fe-a5aa-508135c7=
fdfe':

'VmId=3D509e608c-e657-473a-b031-f0811da96bde,DeviceId=3Dd6c2c4d1-da6b-4=
4fe-a5aa-508135c7fdfe,Device=3Dusb,Type=3Dcontroller,BootOrder=3D0,Spec=
Params=3D
{},Address=3D{bus=3D0x00, domain=3D0x0000, type=3Dpci, slot=3D0x01,
function=3D0x2},IsManaged=3Dfalse,IsPlugged=3Dtrue,IsReadOnly=3Dfalse,a=
lias=3Dusb0',
'device_bb912edd-9790-43ff-a758-f1d9f20cb5f5device_f5c86859-5ae9-4a37-9=
d34-2b9547609622device_20a11f26-6a39-415d-a7bf-95893b9c55b5device_21f25=
5dc-9b3b-48d8-b8e4-63c1635e269b':

'VmId=3D509e608c-e657-473a-b031-f0811da96bde,DeviceId=3D21f255dc-9b3b-4=
8d8-b8e4-63c1635e269b,Device=3Dspicevmc,Type=3Dchannel,BootOrder=3D0,Sp=
ecParams=3D
{},Address=3D{port=3D2, bus=3D0, controller=3D0,
type=3Dvirtio-serial},IsManaged=3Dfalse,IsPlugged=3Dtrue,IsReadOnly=3Df=
alse,alias=3Dchannel1',

'device_bb912edd-9790-43ff-a758-f1d9f20cb5f5device_f5c86859-5ae9-4a37-9=
d34-2b9547609622':

'VmId=3D509e608c-e657-473a-b031-f0811da96bde,DeviceId=3Df5c86859-5ae9-4=
a37-9d34-2b9547609622,Device=3Dvirtio-serial,Type=3Dcontroller,BootOrde=
r=3D0,SpecParams=3D
{},Address=3D{bus=3D0x00, domain=3D0x0000, type=3Dpci, slot=3D0x04,
function=3D0x0},IsManaged=3Dfalse,IsPlugged=3Dtrue,IsReadOnly=3Dfalse,a=
lias=3Dvirtio-serial0',

'device_bb912edd-9790-43ff-a758-f1d9f20cb5f5device_f5c86859-5ae9-4a37-9=
d34-2b9547609622device_20a11f26-6a39-415d-a7bf-95893b9c55b5':

'VmId=3D509e608c-e657-473a-b031-f0811da96bde,DeviceId=3D20a11f26-6a39-4=
15d-a7bf-95893b9c55b5,Device=3Dunix,Type=3Dchannel,BootOrder=3D0,SpecPa=
rams=3D
{},Address=3D{port=3D1, bus=3D0, controller=3D0,
type=3Dvirtio-serial},IsManaged=3Dfalse,IsPlugged=3Dtrue,IsReadOnly=3Df=
alse,alias=3Dchannel0',
 'device_bb912edd-9790-43ff-a758-f1d9f20cb5f5':
'VmId=3D509e608c-e657-473a-b031-f0811da96bde,DeviceId=3Dbb912edd-9790-4=
3ff-a758-f1d9f20cb5f5,Device=3Dide,Type=3Dcontroller,BootOrder=3D0,Spec=
Params=3D
{},Address=3D{bus=3D0x00, domain=3D0x0000, type=3Dpci, slot=3D0x01,
function=3D0x1},IsManaged=3Dfalse,IsPlugged=3Dtrue,IsReadOnly=3Dfalse,a=
lias=3Dide0'},
'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', ' sl=
ot':
'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', ' sl=
ot':
'0x05', ' domain': '0x0000', ' type': 'pci', ' function': '0x0'}, 'devi=
ce':
'disk', 'shared': 'false', 'propagateErrors': 'off', 'optional': 'false=
'},
{'nicModel': 'pv', 'macAddr': '00:1a:4a:a8:0a:00', 'network': 'ovirtmgm=
t',
'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::(_r=
un)
vmId=3D`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=3D`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=3D'26187d25-bfcb-40c7-97d1-667705ad2223',
spUUID=3D'332694bb-364a-434e-b23f-5fef985d3cbd',
imgUUID=3D'0a7013db-68fd-4c42-bc2e-cc8d7a05ca18',
volUUID=3D'f184ecd1-0001-4739-af71-250b412345d6', options=3DNone)
Thread-7808::DEBUG::2012-09-20
06:47:02,001::resourceManager::175::ResourceManager.Request::(__init__)=

ResName=3D`Storage.26187d25-bfcb-40c7-97d1-667705ad2223`ReqID=3D`83dac2=
e0-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-667705ad22=
23'
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=3D`Storage.26187d25-bfcb-40c7-97d1-667705ad2223`ReqID=3D`83dac2=
e0-3d55-4ef6-abf3-7b2561814ab4`::Granted
 request
Thread-7808::DEBUG::2012-09-20
06:47:02,003::task::817::TaskManager.Task::(resourceAcquired)
Task=3D`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=3D`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', 'apparentsi=
ze':
'13958643712'}
Thread-7808::DEBUG::2012-09-20
06:47:02,004::task::1172::TaskManager.Task::(prepare)
Task=3D`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=3D`b6ef82b2-2986-4b7b-95ba-d5f3cac8ad31`::moving from state prepar=
ing ->
state finished
Thread-7808::DEBUG::2012-09-20
06:47:02,004::resourceManager::809::ResourceManager.Owner::(releaseAll)=

Owner.releaseAll requests {} resources
{'Storage.26187d25-bfcb-40c7-97d1-667705ad2223': < ResourceRef
'Storage.26187d25-bfcb-40c7-97d1-667705ad2223', isValid: 'True' obj:
'None'>}
Thread-7808::DEBUG::2012-09-20
06:47:02,004::resourceManager::844::ResourceManager.Owner::(cancelAll)
Owner.cancelAll requests {}
Thread-7808::DEBUG::2012-09-20
06:47:02,005::resourceManager::538::ResourceManager::(releaseResource)
Trying to release resource 'Storage.26187d25-bfcb-40c7-97d1-667705ad222=
3'
Thread-7808::DEBUG::2012-09-20
06:47:02,005::resourceManager::553::ResourceManager::(releaseResource)
Released resource 'Storage.26187d25-bfcb-40c7-97d1-667705ad2223' (0 act=
ive
users)
Thread-7808::DEBUG::2012-09-20
06:47:02,005::resourceManager::558::ResourceManager::(releaseResource)
Resource 'Storage.26187d25-bfcb-40c7-97d1-667705ad2223' is free, findin=
g
out if anyone is waiting for it.
Thread-7808::DEBUG::2012-09-20
06:47:02,005::resourceManager::565::ResourceManager::(releaseResource) =
No
one is waiting for resource 'Storage.26187d25-bfcb-40c7-97d1-667705ad22=
23',
Clearing records.
Thread-7808::DEBUG::2012-09-20
06:47:02,005::task::978::TaskManager.Task::(_decref)
Task=3D`b6ef82b2-2986-4b7b-95ba-d5f3cac8ad31`::ref 0 aborting False
Thread-7808::INFO::2012-09-20
06:47:02,006::clientIF::274::vds::(prepareVolumePath) prepared volume p=
ath:
Thread-7808::DEBUG::2012-09-20
06:47:02,006::task::588::TaskManager.Task::(_updateState)
Task=3D`83579cfe-4384-4b76-8bb0-979ed2b60739`::moving from state init -=
...
state preparing
Thread-7808::INFO::2012-09-20
06:47:02,006::logUtils::37::dispatcher::(wrapper) Run and protect:
prepareImage(sdUUID=3D'26187d25-bfcb-40c7-97d1-667705ad2223',
spUUID=3D'332694bb-364a-434e-b23f-5fef985d3cbd',
imgUUID=3D'0a7013db-68fd-4c42-bc2e-cc8d7a05ca18',
volUUID=3D'f184ecd1-0001-4739-af71-250b412345d6')
Thread-7808::DEBUG::2012-09-20
06:47:02,007::resourceManager::175::ResourceManager.Request::(__init__)=

ResName=3D`Storage.26187d25-bfcb-40c7-97d1-667705ad2223`ReqID=3D`c22e62=
09-b86d-448c-8884-372ce9a589c4`::Request
 was made in '/usr/share/vdsm/storage/resourceManager.py' line '485' at=

'registerResource'
Thread-7808::DEBUG::2012-09-20
06:47:02,007::resourceManager::486::ResourceManager::(registerResource)=

Trying to register resource 'Storage.26187d25-bfcb-40c7-97d1-667705ad22=
23'
for lock type 'shared'
Thread-7808::DEBUG::2012-09-20
06:47:02,007::resourceManager::528::ResourceManager::(registerResource)=

Resource 'Storage.26187d25-bfcb-40c7-97d1-667705ad2223' is free. Now
locking as 'shared' (1 active user)
Thread-7808::DEBUG::2012-09-20
06:47:02,007::resourceManager::212::ResourceManager.Request::(grant)
ResName=3D`Storage.26187d25-bfcb-40c7-97d1-667705ad2223`ReqID=3D`c22e62=
09-b86d-448c-8884-372ce9a589c4`::Granted
 request
Thread-7808::DEBUG::2012-09-20
06:47:02,008::task::817::TaskManager.Task::(resourceAcquired)
Task=3D`83579cfe-4384-4b76-8bb0-979ed2b60739`::_resourcesAcquired:
Storage.26187d25-bfcb-40c7-97d1-667705ad2223 (shared)
Thread-7808::DEBUG::2012-09-20
06:47:02,008::task::978::TaskManager.Task::(_decref)
Task=3D`83579cfe-4384-4b76-8bb0-979ed2b60739`::ref 1 aborting False
Thread-7808::DEBUG::2012-09-20
06:47:02,008::__init__::1249::Storage.Misc.excCmd::(_log) '/usr/bin/dd
iflag=3Ddirect skip=3D4 bs=3D512
if=3D/dev/26187d25-bfcb-40c7-97d1-667705ad2223/metadata count=3D1' (cwd=
 None)
Thread-7808::DEBUG::2012-09-20
06:47:02,023::__init__::1249::Storage.Misc.excCmd::(_log) SUCCESS: <err=
...
=3D
'1+0 records in\n1+0 records out\n512 bytes (512 B) copied, 0.000766795=
 s,
668 kB/s\n'; <rc> =3D 0
Thread-7808::DEBUG::2012-09-20=
06:47:02,023::misc::314::Storage.Misc::(validateDDBytes) err: ['1+0 rec=
ords
in', '1+0 records out', '512 bytes (512 B) copied, 0.000766795 s, 668
kB/s'], size: 512
Thread-7808::INFO::2012-09-20
06:47:02,023::image::357::Storage.Image::(getChain)
sdUUID=3D26187d25-bfcb-40c7-97d1-667705ad2223
imgUUID=3D0a7013db-68fd-4c42-bc2e-cc8d7a05ca18 chain=3D
[<storage.blockVolume.BlockVolume instance at 0x7ff9fc0feb90>]
Thread-7808::INFO::2012-09-20
06:47:02,024::logUtils::39::dispatcher::(wrapper) Run and protect:
prepareImage, Return response: {'path':
'/rhev/data-center/332694bb-364a-434e-b23f-5fef985d3cbd/26187d25-bfcb-4=
0c7-97d1-667705ad2223/images/0a7013db-68fd-4c42-bc2e-cc8d7a05ca18/f184e=
cd1-0001-4739-af71-250b412345d6',
 'chain': [{'path':
'/rhev/data-center/332694bb-364a-434e-b23f-5fef985d3cbd/26187d25-bfcb-4=
0c7-97d1-667705ad2223/images/0a7013db-68fd-4c42-bc2e-cc8d7a05ca18/f184e=
cd1-0001-4739-af71-250b412345d6',
 'domainID': '26187d25-bfcb-40c7-97d1-667705ad2223', 'volumeID':
'f184ecd1-0001-4739-af71-250b412345d6', 'imageID':
'0a7013db-68fd-4c42-bc2e-cc8d7a05ca18'}]}
Thread-7808::DEBUG::2012-09-20
06:47:02,024::task::1172::TaskManager.Task::(prepare)
Task=3D`83579cfe-4384-4b76-8bb0-979ed2b60739`::finished: {'path':
'/rhev/data-center/332694bb-364a-434e-b23f-5fef985d3cbd/26187d25-bfcb-4=
0c7-97d1-667705ad2223/images/0a7013db-68fd-4c42-bc2e-cc8d7a05ca18/f184e=
cd1-0001-4739-af71-250b412345d6',
 'chain': [{'path':
'/rhev/data-center/332694bb-364a-434e-b23f-5fef985d3cbd/26187d25-bfcb-4=
0c7-97d1-667705ad2223/images/0a7013db-68fd-4c42-bc2e-cc8d7a05ca18/f184e=
cd1-0001-4739-af71-250b412345d6',
 'domainID': '26187d25-bfcb-40c7-97d1-667705ad2223', 'volumeID':
'f184ecd1-0001-4739-af71-250b412345d6', 'imageID':
'0a7013db-68fd-4c42-bc2e-cc8d7a05ca18'}]}
Thread-7808::DEBUG::2012-09-20
06:47:02,024::task::588::TaskManager.Task::(_updateState)
Task=3D`83579cfe-4384-4b76-8bb0-979ed2b60739`::moving from state prepar=
ing ->
state finished
Thread-7808::DEBUG::2012-09-20
06:47:02,025::resourceManager::809::ResourceManager.Owner::(releaseAll)=

Owner.releaseAll requests {} resources
{'Storage.26187d25-bfcb-40c7-97d1-667705ad2223': < ResourceRef
'Storage.26187d25-bfcb-40c7-97d1-667705ad2223', isValid: 'True' obj:
'None'>}
Thread-7808::DEBUG::2012-09-20
06:47:02,025::resourceManager::844::ResourceManager.Owner::(cancelAll)
Owner.cancelAll requests {}
Thread-7808::DEBUG::2012-09-20
06:47:02,025::resourceManager::538::ResourceManager::(releaseResource)
Trying to release resource 'Storage.26187d25-bfcb-40c7-97d1-667705ad222=
3'
Thread-7808::DEBUG::2012-09-20
06:47:02,025::resourceManager::553::ResourceManager::(releaseResource)
Released resource 'Storage.26187d25-bfcb-40c7-97d1-667705ad2223' (0 act=
ive
users)
Thread-7808::DEBUG::2012-09-20
06:47:02,026::resourceManager::558::ResourceManager::(releaseResource)
Resource 'Storage.26187d25-bfcb-40c7-97d1-667705ad2223' is free, findin=
g
out if anyone is waiting for it.
Thread-7808::DEBUG::2012-09-20
06:47:02,026::resourceManager::565::ResourceManager::(releaseResource) =
No
one is waiting for resource 'Storage.26187d25-bfcb-40c7-97d1-667705ad22=
23',
Clearing records.
Thread-7808::DEBUG::2012-09-20
06:47:02,026::task::978::TaskManager.Task::(_decref)
Task=3D`83579cfe-4384-4b76-8bb0-979ed2b60739`::ref 0 aborting False
Thread-7808::INFO::2012-09-20
06:47:02,026::clientIF::274::vds::(prepareVolumePath) prepared volume
path: /rhev/data-center/332694bb-364a-434e-b23f-5fef985d3cbd/26187d25-b=
fcb-40c7-97d1-667705ad2223/images/0a7013db-68fd-4c42-bc2e-cc8d7a05ca18/=
f184ecd1-0001-4739-af71-250b412345d6
Thread-7808::DEBUG::2012-09-20 06:47:02,037::libvirtvm::1338::vm.Vm::(_=
run)
vmId=3D`509e608c-e657-473a-b031-f0811da96bde`::<?xml version=3D"1.0"
encoding=3D"utf-8"?>
<domain type=3D"kvm">
        <name>CentOS6Thames</name>
        <uuid>509e608c-e657-473a-b031-f0811da96bde</uuid>
        <memory>1048576</memory>
        <currentMemory>1048576</currentMemory>
        <vcpu>1</vcpu>
        <devices>
                <channel type=3D"unix">
                        <target name=3D"com.redhat.rhevm.vdsm"
type=3D"virtio"/>
                        <source mode=3D"bind"
path=3D"/var/lib/libvirt/qemu/channels/CentOS6Thames.com.redhat.rhevm.v=
dsm"/>
                </channel>
                <input bus=3D"ps2" type=3D"mouse"/>
                <channel type=3D"spicevmc">
                        <target name=3D"com.redhat.spice.0" type=3D"vir=
tio"/>
                </channel>
                <graphics autoport=3D"yes" keymap=3D"en-us" passwd=3D"*=
****"
passwdValidTo=3D"1970-01-01T00:00:01" port=3D"-1" tlsPort=3D"-1" type=3D=
"spice">
                        <channel mode=3D"secure" name=3D"main"/>
                        <channel mode=3D"secure" name=3D"inputs"/>
                        <channel mode=3D"secure" name=3D"cursor"/>
                        <channel mode=3D"secure" name=3D"playback"/>
                        <channel mode=3D"secure" name=3D"record"/>
                        <channel mode=3D"secure" name=3D"display"/>
                        <listen network=3D"vdsm-ovirtmgmt" type=3D"netw=
ork"/>
                </graphics>
                <console type=3D"pty">
                        <target port=3D"0" type=3D"virtio"/>
                </console>
                <controller type=3D"usb">
                        <address  domain=3D"0x0000"  function=3D"0x2"
slot=3D"0x01"  type=3D"pci" bus=3D"0x00"/>
                </controller>
                <video>
                        <address  domain=3D"0x0000"  function=3D"0x0"
slot=3D"0x02"  type=3D"pci" bus=3D"0x00"/>
                        <model heads=3D"1" type=3D"qxl" vram=3D"65536"/=
...
</video>
                <interface type=3D"bridge">
                        <address  domain=3D"0x0000"  function=3D"0x0"
slot=3D"0x03"  type=3D"pci" bus=3D"0x00"/>
                        <mac address=3D"00:1a:4a:a8:0a:00"/>
                        <model type=3D"virtio"/>
                        <source bridge=3D"ovirtmgmt"/>
                </interface>
                <memballoon model=3D"virtio"/>
                <disk device=3D"cdrom" snapshot=3D"no" type=3D"file">
                        <address  bus=3D"1"  controller=3D"0"  target=3D=
"0"
type=3D"drive" unit=3D"0"/>
                        <source file=3D"" startupPolicy=3D"optional"/>
                        <target bus=3D"ide" dev=3D"hdc"/>
                        <readonly/>
                        <serial></serial>
                </disk>
                <disk device=3D"disk" snapshot=3D"no" type=3D"block">
                        <address  domain=3D"0x0000"  function=3D"0x0"
slot=3D"0x05"  type=3D"pci" bus=3D"0x00"/>
                        <source
dev=3D"/rhev/data-center/332694bb-364a-434e-b23f-5fef985d3cbd/26187d25-=
bfcb-40c7-97d1-667705ad2223/images/0a7013db-68fd-4c42-bc2e-cc8d7a05ca18=
/f184ecd1-0001-4739-af71-250b412345d6"/>
                        <target bus=3D"virtio" dev=3D"vda"/>

<serial>0a7013db-68fd-4c42-bc2e-cc8d7a05ca18</serial>
                        <driver cache=3D"none" error_policy=3D"stop"
io=3D"native" name=3D"qemu" type=3D"qcow2"/>
                </disk>
        </devices>
        <os>
                <type arch=3D"x86_64" machine=3D"pc-0.14">hvm</type>
                <smbios mode=3D"sysinfo"/>
        </os>
        <sysinfo type=3D"smbios">
                <system>
                        <entry name=3D"manufacturer">Red Hat</entry>
                        <entry name=3D"product">RHEV Hypervisor</entry>=

                        <entry name=3D"version">17-1</entry>
                        <entry
name=3D"serial">31323334-3535-4C44-3643-4D5633393936_00:19:bb:39:97:4a<=
/entry>
                        <entry
name=3D"uuid">509e608c-e657-473a-b031-f0811da96bde</entry>
                </system>
        </sysinfo>
        <clock adjustment=3D"-1" offset=3D"variable">
                <timer name=3D"rtc" tickpolicy=3D"catchup"/>
        </clock>
        <features>
                <acpi/>
        </features>
        <cpu match=3D"exact">
                <model>Conroe</model>
                <topology cores=3D"1" sockets=3D"1" threads=3D"1"/>
        </cpu>
</domain>

Thread-7808::DEBUG::2012-09-20
06:47:02,426::vm::580::vm.Vm::(_startUnderlyingVm)
vmId=3D`509e608c-e657-473a-b031-f0811da96bde`::_ongoingCreations releas=
ed
Thread-7808::ERROR::2012-09-20
06:47:02,427::vm::604::vm.Vm::(_startUnderlyingVm)
vmId=3D`509e608c-e657-473a-b031-f0811da96bde`::The vm start process fai=
led
Traceback (most recent call last):
  File "/usr/share/vdsm/vm.py", line 570, in _startUnderlyingVm
  File "/usr/share/vdsm/libvirtvm.py", line 1364, in _run
  File "/usr/lib/python2.7/site-packages/vdsm/libvirtconnection.py", li=
ne
82, in wrapper
  File "/usr/lib64/python2.7/site-packages/libvirt.py", line 2420, in
createXML
libvirtError: unsupported configuration: spice secure channels set in X=
ML
configuration, but TLS is disabled in qemu.conf
Thread-7808::DEBUG::2012-09-20
06:47:02,430::vm::920::vm.Vm::(setDownStatus)
vmId=3D`509e608c-e657-473a-b031-f0811da96bde`::Changed state to Down:
unsupported configuration: spice secure channels set in XML configurati=
on,
but TLS is disabled in qemu.conf
Dummy-1960::DEBUG::2012-09-20
06:47:03,145::__init__::1249::Storage.Misc.excCmd::(_log) 'dd
if=3D/rhev/data-center/332694bb-364a-434e-b23f-5fef985d3cbd/mastersd/do=
m_md/inbox
 iflag=3Ddirect,fullblock count=3D1 bs=3D1024000' (cwd None)
Dummy-1960::DEBUG::2012-09-20
06:47:03,230::__init__::1249::Storage.Misc.excCmd::(_log) SUCCESS: <err=
...
=3D
'1+0 records in\n1+0 records out\n1024000 bytes (1.0 MB) copied, 0.0496=
138
s, 20.6 MB/s\n'; <rc> =3D 0
Thread-7810::DEBUG::2012-09-20
06:47:03,560::BindingXMLRPC::156::vds::(wrapper) [192.168.10.10]
Thread-7810::DEBUG::2012-09-20
06:47:03,561::task::588::TaskManager.Task::(_updateState)
Task=3D`9bc08c7e-010f-45c2-940a-3fd8361785d5`::moving from state init -=
state preparing
Thread-7810::INFO::2012-09-20
06:47:03,561::logUtils::37::dispatcher::(wrapper) Run and protect:
getSpmStatus(spUUID=3D'332694bb-364a-434e-b23f-5fef985d3cbd', options=3D=
None)
Thread-7810::INFO::2012-09-20
06:47:03,562::logUtils::39::dispatcher::(wrapper) Run and protect:
getSpmStatus, Return response: {'spm_st': {'spmId': 3, 'spmStatus': 'SP=
M',
'spmLver': 0}}
Thread-7810::DEBUG::2012-09-20
06:47:03,562::task::1172::TaskManager.Task::(prepare)
Task=3D`9bc08c7e-010f-45c2-940a-3fd8361785d5`::finished: {'spm_st': {'s=
pmId':
3, 'spmStatus': 'SPM', 'spmLver': 0}}
Thread-7810::DEBUG::2012-09-20
06:47:03,562::task::588::TaskManager.Task::(_updateState)
Task=3D`9bc08c7e-010f-45c2-940a-3fd8361785d5`::moving from state prepar=
ing ->
state finished
Thread-7810::DEBUG::2012-09-20
06:47:03,562::resourceManager::809::ResourceManager.Owner::(releaseAll)=

Owner.releaseAll requests {} resources {}
Thread-7810::DEBUG::2012-09-20
06:47:03,562::resourceManager::844::ResourceManager.Owner::(cancelAll)
Owner.cancelAll requests {}
Thread-7810::DEBUG::2012-09-20
06:47:03,563::task::978::TaskManager.Task::(_decref)
Task=3D`9bc08c7e-010f-45c2-940a-3fd8361785d5`::ref 0 aborting False
Thread-7812::DEBUG::2012-09-20
06:47:03,595::BindingXMLRPC::156::vds::(wrapper) [192.168.10.10]
Thread-7812::DEBUG::2012-09-20
06:47:03,595::task::588::TaskManager.Task::(_updateState)
Task=3D`8e330204-753f-422d-b286-a360410806be`::moving from state init -=
...
state preparing
Thread-7812::INFO::2012-09-20
06:47:03,596::logUtils::37::dispatcher::(wrapper) Run and protect:
getStoragePoolInfo(spUUID=3D'332694bb-364a-434e-b23f-5fef985d3cbd',
options=3DNone)
Thread-7812::DEBUG::2012-09-20
06:47:03,596::resourceManager::175::ResourceManager.Request::(__init__)=

ResName=3D`Storage.332694bb-364a-434e-b23f-5fef985d3cbd`ReqID=3D`a72228=
34-3565-4e28-a15f-72692ef664c6`::Request
 was made in '/usr/share/vdsm/storage/resourceManager.py' line '485' at=

'registerResource'
Thread-7812::DEBUG::2012-09-20
06:47:03,596::resourceManager::486::ResourceManager::(registerResource)=

Trying to register resource 'Storage.332694bb-364a-434e-b23f-5fef985d3c=
bd'
for lock type 'shared'
Thread-7812::DEBUG::2012-09-20
06:47:03,597::resourceManager::528::ResourceManager::(registerResource)=

Resource 'Storage.332694bb-364a-434e-b23f-5fef985d3cbd' is free. Now
locking as 'shared' (1 active user)
Thread-7812::DEBUG::2012-09-20
06:47:03,597::resourceManager::212::ResourceManager.Request::(grant)
ResName=3D`Storage.332694bb-364a-434e-b23f-5fef985d3cbd`ReqID=3D`a72228=
34-3565-4e28-a15f-72692ef664c6`::Granted
 request
Thread-7812::DEBUG::2012-09-20
06:47:03,597::task::817::TaskManager.Task::(resourceAcquired)
Task=3D`8e330204-753f-422d-b286-a360410806be`::_resourcesAcquired:
Storage.332694bb-364a-434e-b23f-5fef985d3cbd (shared)
Thread-7812::DEBUG::2012-09-20
06:47:03,598::task::978::TaskManager.Task::(_decref)
Task=3D`8e330204-753f-422d-b286-a360410806be`::ref 1 aborting False
Thread-7813::DEBUG::2012-09-20
06:47:03,598::BindingXMLRPC::859::vds::(wrapper) client
[192.168.10.10]::call vmGetStats with
('509e608c-e657-473a-b031-f0811da96bde',) {}
Thread-7812::INFO::2012-09-20
06:47:03,599::logUtils::39::dispatcher::(wrapper) Run and protect:
getStoragePoolInfo, Return response: {'info': {'spm_id': 3, 'master_uui=
d':
'26187d25-bfcb-40c7-97d1-667705ad2223', 'name': 'Valeka', 'version': '2=
',
'domains':
u'26187d25-bfcb-40c7-97d1-667705ad2223:Active,90104c3d-837b-47dd-8c82-d=
da92eec30d9:Active',
 'pool_status': 'connected', 'isoprefix':
u'/rhev/data-center/332694bb-364a-434e-b23f-5fef985d3cbd/90104c3d-837b-=
47dd-8c82-dda92eec30d9/images/11111111-1111-1111-1111-111111111111',
 'type': 'ISCSI', 'master_ver': 1, 'lver': 0}, 'dominfo':
{u'26187d25-bfcb-40c7-97d1-667705ad2223': {'status': u'Active', 'diskfr=
ee':
'1674097721344', 'alerts': [], 'disktotal': '1799591297024'},
u'90104c3d-837b-47dd-8c82-dda92eec30d9': {'status': u'Active', 'diskfre=
e':
'423518535680', 'alerts': [], 'disktotal': '492264226816'}}}
Thread-7813::DEBUG::2012-09-20
06:47:03,600::BindingXMLRPC::865::vds::(wrapper) return vmGetStats with=

{'status': {'message': 'Done', 'code': 0}, 'statsList': [{'status': 'Do=
wn',
'hash': '0', 'exitMessage': 'unsupported configuration: spice secure
channels set in XML configuration, but TLS is disabled in qemu.conf',
'vmId': '509e608c-e657-473a-b031-f0811da96bde', 'timeOffset': '-1',
'exitCode': 1}]}
Thread-7812::DEBUG::2012-09-20
06:47:03,600::task::1172::TaskManager.Task::(prepare)
Task=3D`8e330204-753f-422d-b286-a360410806be`::finished: {'info': {'spm=
_id':
3, 'master_uuid': '26187d25-bfcb-40c7-97d1-667705ad2223', 'name': 'Vale=
ka',
'version': '2', 'domains':
u'26187d25-bfcb-40c7-97d1-667705ad2223:Active,90104c3d-837b-47dd-8c82-d=
da92eec30d9:Active',
 'pool_status': 'connected', 'isoprefix':
u'/rhev/data-center/332694bb-364a-434e-b23f-5fef985d3cbd/90104c3d-837b-=
47dd-8c82-dda92eec30d9/images/11111111-1111-1111-1111-111111111111',
 'type': 'ISCSI', 'master_ver': 1, 'lver': 0}, 'dominfo':
{u'26187d25-bfcb-40c7-97d1-667705ad2223': {'status': u'Active', 'diskfr=
ee':
'1674097721344', 'alerts': [], 'disktotal': '1799591297024'},
u'90104c3d-837b-47dd-8c82-dda92eec30d9': {'status': u'Active', 'diskfre=
e':
'423518535680', 'alerts': [], 'disktotal': '492264226816'}}}
Thread-7812::DEBUG::2012-09-20
06:47:03,601::task::588::TaskManager.Task::(_updateState)
Task=3D`8e330204-753f-422d-b286-a360410806be`::moving from state prepar=
ing ->
state finished
Thread-7812::DEBUG::2012-09-20
06:47:03,601::resourceManager::809::ResourceManager.Owner::(releaseAll)=

Owner.releaseAll requests {} resources
{'Storage.332694bb-364a-434e-b23f-5fef985d3cbd': < ResourceRef
'Storage.332694bb-364a-434e-b23f-5fef985d3cbd', isValid: 'True' obj:
'None'>}
Thread-7812::DEBUG::2012-09-20
06:47:03,601::resourceManager::844::ResourceManager.Owner::(cancelAll)
Owner.cancelAll requests {}
Thread-7812::DEBUG::2012-09-20
06:47:03,602::resourceManager::538::ResourceManager::(releaseResource)
Trying to release resource 'Storage.332694bb-364a-434e-b23f-5fef985d3cb=
d'
Thread-7812::DEBUG::2012-09-20
06:47:03,602::resourceManager::553::ResourceManager::(releaseResource)
Released resource 'Storage.332694bb-364a-434e-b23f-5fef985d3cbd' (0 act=
ive
users)
Thread-7812::DEBUG::2012-09-20
06:47:03,602::resourceManager::558::ResourceManager::(releaseResource)
Resource 'Storage.332694bb-364a-434e-b23f-5fef985d3cbd' is free, findin=
g
out if anyone is waiting for it.
Thread-7812::DEBUG::2012-09-20
06:47:03,602::resourceManager::565::ResourceManager::(releaseResource) =
No
one is waiting for resource 'Storage.332694bb-364a-434e-b23f-5fef985d3c=
bd',
Clearing records.
Thread-7812::DEBUG::2012-09-20
06:47:03,602::task::978::TaskManager.Task::(_decref)
Task=3D`8e330204-753f-422d-b286-a360410806be`::ref 0 aborting False
Thread-7814::DEBUG::2012-09-20
06:47:03,658::BindingXMLRPC::859::vds::(wrapper) client
[192.168.10.10]::call vmDestroy with
('509e608c-e657-473a-b031-f0811da96bde',) {}
Thread-7814::INFO::2012-09-20 06:47:03,658::API::317::vds::(destroy)
vmContainerLock acquired by vm 509e608c-e657-473a-b031-f0811da96bde
Thread-7814::DEBUG::2012-09-20
06:47:03,658::libvirtvm::2085::vm.Vm::(destroy)
vmId=3D`509e608c-e657-473a-b031-f0811da96bde`::destroy Called
Thread-7814::INFO::2012-09-20
06:47:03,658::libvirtvm::2040::vm.Vm::(releaseVm)
vmId=3D`509e608c-e657-473a-b031-f0811da96bde`::Release VM resources
Thread-7814::WARNING::2012-09-20
06:47:03,659::vm::328::vm.Vm::(_set_lastStatus)
vmId=3D`509e608c-e657-473a-b031-f0811da96bde`::trying to set state to
Powering down when already Down
Thread-7814::DEBUG::2012-09-20
06:47:03,659::__init__::1249::Storage.Misc.excCmd::(_log) '/usr/bin/sud=
o
-n /usr/sbin/service ksmtuned retune' (cwd None)
Thread-7814::DEBUG::2012-09-20
06:47:03,696::__init__::1249::Storage.Misc.excCmd::(_log) FAILED: <err>=
 =3D
'Redirecting to /bin/systemctl retune  ksmtuned.service\nUnknown operat=
ion
retune\n'; <rc> =3D 1
Thread-7814::DEBUG::2012-09-20
06:47:03,697::task::588::TaskManager.Task::(_updateState)
Task=3D`e97820bb-547d-4e7a-9249-ece94285bac8`::moving from state init -=
...
state preparing
Thread-7814::INFO::2012-09-20
06:47:03,698::logUtils::37::dispatcher::(wrapper) Run and protect:
inappropriateDevices(thiefId=3D'509e608c-e657-473a-b031-f0811da96bde')
Thread-7814::INFO::2012-09-20
06:47:03,699::logUtils::39::dispatcher::(wrapper) Run and protect:
inappropriateDevices, Return response: None
Thread-7814::DEBUG::2012-09-20
06:47:03,699::task::1172::TaskManager.Task::(prepare)
Task=3D`e97820bb-547d-4e7a-9249-ece94285bac8`::finished: None
Thread-7814::DEBUG::2012-09-20
06:47:03,700::task::588::TaskManager.Task::(_updateState)
Task=3D`e97820bb-547d-4e7a-9249-ece94285bac8`::moving from state prepar=
ing ->
state finished
Thread-7814::DEBUG::2012-09-20
06:47:03,700::resourceManager::809::ResourceManager.Owner::(releaseAll)=

Owner.releaseAll requests {} resources {}
Thread-7814::DEBUG::2012-09-20
06:47:03,700::resourceManager::844::ResourceManager.Owner::(cancelAll)
Owner.cancelAll requests {}
Thread-7814::DEBUG::2012-09-20
06:47:03,700::task::978::TaskManager.Task::(_decref)
Task=3D`e97820bb-547d-4e7a-9249-ece94285bac8`::ref 0 aborting False
Thread-7814::DEBUG::2012-09-20
06:47:03,700::libvirtvm::2080::vm.Vm::(deleteVm)
vmId=3D`509e608c-e657-473a-b031-f0811da96bde`::Total desktops after des=
troy
of 509e608c-e657-473a-b031-f0811da96bde is 0
Thread-7814::DEBUG::2012-09-20
06:47:03,701::BindingXMLRPC::865::vds::(wrapper) return vmDestroy with
{'status': {'message': 'Machine destroyed', 'code': 0}}
Thread-481::DEBUG::2012-09-20
06:47:04,302::__init__::1249::Storage.Misc.excCmd::(_log) '/usr/bin/dd
iflag=3Ddirect if=3D/dev/26187d25-bfcb-40c7-97d1-667705ad2223/metadata =
bs=3D4096
count=3D1' (cwd None)
Thread-481::DEBUG::2012-09-20
06:47:04,317::__init__::1249::Storage.Misc.excCmd::(_log) SUCCESS: <err=
...
=3D
'1+0 records in\n1+0 records out\n4096 bytes (4.1 kB) copied, 0.0008435=
51
s, 4.9 MB/s\n'; <rc> =3D 0
Dummy-1960::DEBUG::2012-09-20
06:47:05,239::__init__::1249::Storage.Misc.excCmd::(_log) 'dd
if=3D/rhev/data-center/332694bb-364a-434e-b23f-5fef985d3cbd/mastersd/do=
m_md/inbox
 iflag=3Ddirect,fullblock count=3D1 bs=3D1024000' (cwd None)
Dummy-1960::DEBUG::2012-09-20
06:47:05,323::__init__::1249::Storage.Misc.excCmd::(_log) SUCCESS: <err=
=3D
'1+0 records in\n1+0 records out\n1024000 bytes (1.0 MB) copied, 0.0476=
578
s, 21.5 MB/s\n'; <rc> =3D 0
Thread-7815::DEBUG::2012-09-20
06:47:05,819::task::588::TaskManager.Task::(_updateState)
Task=3D`ef5f39d0-241c-44b5-a771-da364468b498`::moving from state init -=
state preparing
Thread-7815::INFO::2012-09-20
06:47:05,819::logUtils::37::dispatcher::(wrapper) Run and protect:
repoStats(options=3DNone)
Thread-7815::INFO::2012-09-20
06:47:05,820::logUtils::39::dispatcher::(wrapper) Run and protect:
repoStats, Return response: {'26187d25-bfcb-40c7-97d1-667705ad2223':
{'delay': '0.0156102180481', 'lastCheck': 1348123624.512314, 'code': 0,=

'valid': True}, '90104c3d-837b-47dd-8c82-dda92eec30d9': {'delay':
'0.0011830329895', 'lastCheck': 1348123617.41074, 'code': 0, 'valid':
True}}
Thread-7815::DEBUG::2012-09-20
06:47:05,820::task::1172::TaskManager.Task::(prepare)
Task=3D`ef5f39d0-241c-44b5-a771-da364468b498`::finished:
{'26187d25-bfcb-40c7-97d1-667705ad2223': {'delay': '0.0156102180481',
'lastCheck': 1348123624.512314, 'code': 0, 'valid': True},
'90104c3d-837b-47dd-8c82-dda92eec30d9': {'delay': '0.0011830329895',
'lastCheck': 1348123617.41074, 'code': 0, 'valid': True}}
Thread-7815::DEBUG::2012-09-20
06:47:05,820::task::588::TaskManager.Task::(_updateState)
Task=3D`ef5f39d0-241c-44b5-a771-da364468b498`::moving from state prepar=
ing ->
state finished
Thread-7815::DEBUG::2012-09-20
06:47:05,820::resourceManager::809::ResourceManager.Owner::(releaseAll)=

Owner.releaseAll requests {} resources {}
Thread-7815::DEBUG::2012-09-20
06:47:05,821::resourceManager::844::ResourceManager.Owner::(cancelAll)
Owner.cancelAll requests {}
Thread-7815::DEBUG::2012-09-20
06:47:05,821::task::978::TaskManager.Task::(_decref)
Task=3D`ef5f39d0-241c-44b5-a771-da364468b498`::ref 0 aborting False
Dummy-1960::DEBUG::2012-09-20
06:47:07,332::__init__::1249::Storage.Misc.excCmd::(_log) 'dd
if=3D/rhev/data-center/332694bb-364a-434e-b23f-5fef985d3cbd/mastersd/do=
m_md/inbox
 iflag=3Ddirect,fullblock count=3D1 bs=3D1024000' (cwd None)
Dummy-1960::DEBUG::2012-09-20
06:47:07,458::__init__::1249::Storage.Misc.excCmd::(_log) SUCCESS: <err=
...
=3D
'1+0 records in\n1+0 records out\n1024000 bytes (1.0 MB) copied, 0.0478=
973
s, 21.4 MB/s\n'; <rc> =3D 0
Dummy-1960::DEBUG::2012-09-20
06:47:09,502::__init__::1249::Storage.Misc.excCmd::(_log) 'dd
if=3D/rhev/data-center/332694bb-364a-434e-b23f-5fef985d3cbd/mastersd/do=
m_md/inbox
 iflag=3Ddirect,fullblock count=3D1 bs=3D1024000' (cwd None)
Dummy-1960::DEBUG::2012-09-20
06:47:09,586::__init__::1249::Storage.Misc.excCmd::(_log) SUCCESS: <err=
=3D
'1+0 records in\n1+0 records out\n1024000 bytes (1.0 MB) copied, 0.0485=
543
s, 21.1 MB/s\n'; <rc> =3D 0
If I try to create new server I have the same error message.

- -
Dmitriy Pyryakov
VimpelCom Ltd.=

--0__=C9BBF0ECDFB7B2218f9e8a93df938690918cC9BBF0ECDFB7B221
Content-type: text/html; charset=US-ASCII
Content-Disposition: inline
Content-transfer-encoding: quoted-printable

<html><body>
<p><font size=3D"2" face=3D"sans-serif">Hello,</font><br>
<br>
<font size=3D"2" face=3D"sans-serif">Yesturday I broke my two Fedora 17=
  hosts.</font><br>
<font size=3D"2" face=3D"sans-serif">Today I install two ovirt nodes (f=
irst - 2.5.0-2.0.fc17, second - 2.5.1-1.0.fc17). SPM on 2.5.0-2.0.fc17.=
</font><br>
<br>
<font size=3D"2" face=3D"sans-serif">Now, I can't run any of my existin=
g virtual machines. Exit message: unsupported configuration: spice secu=
re channels set in XML configuration, but TLS is disabled in qemu.conf.=
</font>
<ul style=3D"padding-left: 0pt"><font size=3D"2" face=3D"sans-serif"><b=
r>
</font><br>
<font size=3D"2" face=3D"sans-serif">engine.log:</font></ul>
<font size=3D"2" face=3D"sans-serif">[root@admin ~]# tail -f -n 0 /var/=
log/ovirt-engine/engine.log</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:53,289 INFO  [org=
.ovirt.engine.core.vdsbroker.irsbroker.IsValidVDSCommand] (ajp--0.0.0.0=
-8009-10) START, IsValidVDSCommand(storagePoolId =3D 332694bb-364a-434e=
-b23f-5fef985d3cbd, ignoreFailoverLimit =3D false, compatabilityVersion=
 =3D null), log id: 7c90c641</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:53,294 INFO  [org=
.ovirt.engine.core.vdsbroker.irsbroker.IsValidVDSCommand] (ajp--0.0.0.0=
-8009-10) FINISH, IsValidVDSCommand, return: true, log id: 7c90c641</fo=
nt><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:53,332 INFO  [org=
.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (ajp--0.0.=
0.0-8009-10) START, IsVmDuringInitiatingVDSCommand(vmId =3D 509e608c-e6=
57-473a-b031-f0811da96bde), log id: 243c74f7</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:53,334 INFO  [org=
.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (ajp--0.0.=
0.0-8009-10) FINISH, IsVmDuringInitiatingVDSCommand, return: false, log=
 id: 243c74f7</font><br>
<font size=3D"2" face=3D"sans-serif">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=3D key: 509e608c-e657-473=
a-b031-f0811da96bde value: VM</font><br>
<font size=3D"2" face=3D"sans-serif">, sharedLocks=3D ]</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:53,415 INFO  [org=
.ovirt.engine.core.bll.RunVmCommand] (pool-3-thread-50) [a58d974] Runni=
ng command: RunVmCommand internal: false. Entities affected :  ID: 509e=
608c-e657-473a-b031-f0811da96bde Type: VM</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:53,504 INFO  [org=
.ovirt.engine.core.vdsbroker.CreateVmVDSCommand] (pool-3-thread-50) [a5=
8d974] START, CreateVmVDSCommand(vdsId =3D 0a268762-02d7-11e2-b750-0011=
856cf23e, vmId=3D509e608c-e657-473a-b031-f0811da96bde, vm=3Dorg.ovirt.e=
ngine.core.common.businessentities.VM@1911737b), log id: 77c0e559</font=
...
<br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:53,529 INFO  [org=
.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand] (pool-3-thread=
-50) [a58d974] START, CreateVDSCommand(vdsId =3D 0a268762-02d7-11e2-b75=
0-0011856cf23e, vmId=3D509e608c-e657-473a-b031-f0811da96bde, vm=3Dorg.o=
virt.engine.core.common.businessentities.VM@1911737b), log id: f48008f<=
/font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:53,602 INFO  [org=
.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand] (pool-3-thread=
-50) [a58d974] org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSComma=
nd spiceSslCipherSuite=3DDEFAULT,memSize=3D1024,kvmEnable=3Dtrue,smp=3D=
1,emulatedMachine=3Dpc-0.14,vmType=3Dkvm,keyboardLayout=3Den-us,pitRein=
jection=3Dfalse,nice=3D0,display=3Dqxl,smpCoresPerSocket=3D1,spiceSecur=
eChannels=3Dsmain,sinputs,scursor,splayback,srecord,sdisplay,displayNet=
work=3Dovirtmgmt,timeOffset=3D-1,transparentHugePages=3Dtrue,vmId=3D509=
e608c                            -e657-473a-b031-f0811da96bde,devices=3D=
[Ljava.util.Map;@760db68c,acpiEnable=3Dtrue,vmName=3DCentOS6Thames,cpuT=
ype=3DConroe,custom=3D{device_bb912edd-9790-43ff-a758-f1d9f20cb5f5devic=
e_f5c86859-5ae9-4a37-9d34-2b9547609622device_20a11f26-6a39-415d-a7bf-95=
893b9c55b5=3DVmId=3D509e608c-e657-473a-b031-f0811da96bde,DeviceId=3D20a=
11f26-6a39-415d-a7bf-95893b9c55b5,Device=3Dunix,Type=3Dchannel,BootOrde=
r=3D0,SpecParams=3D{},Address=3D{port=3D1, bus=3D0, controller=3D0, typ=
e=3Dvirtio-serial},IsManaged=3Dfalse,IsPlugged=3Dtrue,IsReadOnly=3Dfals=
e,alias=3D                            channel0, device_bb912edd-9790-43=
ff-a758-f1d9f20cb5f5=3DVmId=3D509e608c-e657-473a-b031-f0811da96bde,Devi=
ceId=3Dbb912edd-9790-43ff-a758-f1d9f20cb5f5,Device=3Dide,Type=3Dcontrol=
ler,BootOrder=3D0,SpecParams=3D{},Address=3D{bus=3D0x00, domain=3D0x000=
0, type=3Dpci, slot=3D0x01, function=3D0x1},IsManaged=3Dfalse,IsPlugged=
=3Dtrue,IsReadOnly=3Dfalse,alias=3Dide0, device_bb912edd-9790-43ff-a758=
-f1d9f20cb5f5device_f5c86859-5ae9-4a37-9d34-2b9547609622=3DVmId=3D509e6=
08c-e657-473a-b031-f0811da96bde,DeviceId=3Df5c86859-5ae9-4a37-9d34-2b95=
47609622,Devic                            e=3Dvirtio-serial,Type=3Dcont=
roller,BootOrder=3D0,SpecParams=3D{},Address=3D{bus=3D0x00, domain=3D0x=
0000, type=3Dpci, slot=3D0x04, function=3D0x0},IsManaged=3Dfalse,IsPlug=
ged=3Dtrue,IsReadOnly=3Dfalse,alias=3Dvirtio-serial0, device_bb912edd-9=
790-43ff-a758-f1d9f20cb5f5device_f5c86859-5ae9-4a37-9d34-2b9547609622de=
vice_20a11f26-6a39-415d-a7bf-95893b9c55b5device_21f255dc-9b3b-48d8-b8e4=
-63c1635e269b=3DVmId=3D509e608c-e657-473a-b031-f0811da96bde,DeviceId=3D=
21f255dc-9b3b-48d8-b8e4-63c1635e269b,Device=3Dspicevmc,Type=3Dchannel,B=
ootOrder=3D0,SpecP                            arams=3D{},Address=3D{por=
t=3D2, bus=3D0, controller=3D0, type=3Dvirtio-serial},IsManaged=3Dfalse=
,IsPlugged=3Dtrue,IsReadOnly=3Dfalse,alias=3Dchannel1, device_bb912edd-=
9790-43ff-a758-f1d9f20cb5f5device_f5c86859-5ae9-4a37-9d34-2b9547609622d=
evice_20a11f26-6a39-415d-a7bf-95893b9c55b5device_21f255dc-9b3b-48d8-b8e=
4-63c1635e269bdevice_d6c2c4d1-da6b-44fe-a5aa-508135c7fdfe=3DVmId=3D509e=
608c-e657-473a-b031-f0811da96bde,DeviceId=3Dd6c2c4d1-da6b-44fe-a5aa-508=
135c7fdfe,Device=3Dusb,Type=3Dcontroller,BootOrder=3D0,SpecParams=3D{},=
Address=3D{bus=3D0x0                            0, domain=3D0x0000, typ=
e=3Dpci, slot=3D0x01, function=3D0x2},IsManaged=3Dfalse,IsPlugged=3Dtru=
e,IsReadOnly=3Dfalse,alias=3Dusb0}</font><br>
<font size=3D"2" face=3D"sans-serif">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</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:53,659 INFO  [org=
.ovirt.engine.core.vdsbroker.CreateVmVDSCommand] (pool-3-thread-50) [a5=
8d974] IncreasePendingVms::CreateVmIncreasing vds hyper1.ovirt.com pend=
ing vcpu count, now 1. Vm: CentOS6Thames</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:53,671 INFO  [org=
.ovirt.engine.core.vdsbroker.CreateVmVDSCommand] (pool-3-thread-50) [a5=
8d974] FINISH, CreateVmVDSCommand, return: WaitForLaunch, log id: 77c0e=
559</font><br>
<font size=3D"2" face=3D"sans-serif">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=3D key: 509e608c-e657-473a-b=
031-f0811da96bde value: VM</font><br>
<font size=3D"2" face=3D"sans-serif">, sharedLocks=3D ]</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:54,418 INFO  [org=
.ovirt.engine.core.vdsbroker.vdsbroker.DestroyVDSCommand] (QuartzSchedu=
ler_Worker-12) START, DestroyVDSCommand(vdsId =3D 0a268762-02d7-11e2-b7=
50-0011856cf23e, vmId=3D509e608c-e657-473a-b031-f0811da96bde, force=3Df=
alse, secondsToWait=3D0, gracefully=3Dfalse), log id: 2f059be9</font><b=
r>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:54,486 INFO  [org=
.ovirt.engine.core.vdsbroker.vdsbroker.DestroyVDSCommand] (QuartzSchedu=
ler_Worker-12) FINISH, DestroyVDSCommand, log id: 2f059be9</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:54,520 INFO  [org=
.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (QuartzScheduler_Wor=
ker-12) Running on vds during rerun failed vm: null</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:54,523 INFO  [org=
.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (QuartzScheduler_Wor=
ker-12) vm CentOS6Thames running in db and not running in vds - add to =
rerun treatment. vds hyper1.ovirt.com</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:54,536 ERROR [org=
.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (QuartzScheduler_Wor=
ker-12) Rerun vm 509e608c-e657-473a-b031-f0811da96bde. Called from vds =
hyper1.ovirt.com</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:54,557 INFO  [org=
.ovirt.engine.core.vdsbroker.UpdateVdsDynamicDataVDSCommand] (pool-3-th=
read-50) START, UpdateVdsDynamicDataVDSCommand(vdsId =3D 0a268762-02d7-=
11e2-b750-0011856cf23e, vdsDynamic=3Dorg.ovirt.engine.core.common.busin=
essentities.VdsDynamic@db702e05), log id: 71c6e6a3</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:54,564 INFO  [org=
.ovirt.engine.core.vdsbroker.UpdateVdsDynamicDataVDSCommand] (pool-3-th=
read-50) FINISH, UpdateVdsDynamicDataVDSCommand, log id: 71c6e6a3</font=
<br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:54,584 INFO  [org=
.ovirt.engine.core.bll.RunVmCommand] (pool-3-thread-50) Lock Acquired t=
o object EngineLock [exclusiveLocks=3D key: 509e608c-e657-473a-b031-f08=
11da96bde value: VM</font><br>
<font size=3D"2" face=3D"sans-serif">, sharedLocks=3D ]</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:54,603 INFO  [org=
.ovirt.engine.core.vdsbroker.irsbroker.IsValidVDSCommand] (pool-3-threa=
d-50) START, IsValidVDSCommand(storagePoolId =3D 332694bb-364a-434e-b23=
f-5fef985d3cbd, ignoreFailoverLimit =3D false, compatabilityVersion =3D=
 null), log id: f1903fc</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:54,614 INFO  [org=
.ovirt.engine.core.vdsbroker.irsbroker.IsValidVDSCommand] (pool-3-threa=
d-50) FINISH, IsValidVDSCommand, return: true, log id: f1903fc</font><b=
r>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:54,653 INFO  [org=
.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (pool-3-th=
read-50) START, IsVmDuringInitiatingVDSCommand(vmId =3D 509e608c-e657-4=
73a-b031-f0811da96bde), log id: 5b0d9779</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:54,655 INFO  [org=
.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (pool-3-th=
read-50) FINISH, IsVmDuringInitiatingVDSCommand, return: false, log id:=
 5b0d9779</font><br>
<font size=3D"2" face=3D"sans-serif">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</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:54,800 INFO  [org=
.ovirt.engine.core.vdsbroker.CreateVmVDSCommand] (pool-3-thread-50) STA=
RT, CreateVmVDSCommand(vdsId =3D 9840e840-02db-11e2-a01a-0011856cf23e, =
vmId=3D509e608c-e657-473a-b031-f0811da96bde, vm=3Dorg.ovirt.engine.core=
.common.businessentities.VM@4432a01d), log id: 554a0742</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:54,825 INFO  [org=
.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand] (pool-3-thread=
-50) START, CreateVDSCommand(vdsId =3D 9840e840-02db-11e2-a01a-0011856c=
f23e, vmId=3D509e608c-e657-473a-b031-f0811da96bde, vm=3Dorg.ovirt.engin=
e.core.common.businessentities.VM@4432a01d), log id: 73615350</font><br=
...
<br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:56,616 INFO  [org=
.ovirt.engine.core.bll.RunVmCommand] (pool-3-thread-50) Lock Acquired t=
o object EngineLock [exclusiveLocks=3D key: 509e608c-e657-473a-b031-f08=
11da96bde value: VM</font><br>
<font size=3D"2" face=3D"sans-serif">, sharedLocks=3D ]</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:56,632 INFO  [org=
.ovirt.engine.core.vdsbroker.irsbroker.IsValidVDSCommand] (pool-3-threa=
d-50) START, IsValidVDSCommand(storagePoolId =3D 332694bb-364a-434e-b23=
f-5fef985d3cbd, ignoreFailoverLimit =3D false, compatabilityVersion =3D=
 null), log id: 4629f11d</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:56,636 INFO  [org=
.ovirt.engine.core.vdsbroker.irsbroker.IsValidVDSCommand] (pool-3-threa=
d-50) FINISH, IsValidVDSCommand, return: true, log id: 4629f11d</font><=
br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:56,672 INFO  [org=
.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (pool-3-th=
read-50) START, IsVmDuringInitiatingVDSCommand(vmId =3D 509e608c-e657-4=
73a-b031-f0811da96bde), log id: f3a60e</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:56,675 INFO  [org=
.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (pool-3-th=
read-50) FINISH, IsVmDuringInitiatingVDSCommand, return: false, log id:=
 f3a60e</font><br>
<font size=3D"2" face=3D"sans-serif">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</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:56,717 INFO  [org=
.ovirt.engine.core.bll.RunVmCommand] (pool-3-thread-50) Lock freed to o=
bject EngineLock [exclusiveLocks=3D key: 509e608c-e657-473a-b031-f0811d=
a96bde value: VM</font><br>
<font size=3D"2" face=3D"sans-serif">, sharedLocks=3D ]</font><br>
<br>
<font size=3D"2" face=3D"sans-serif">vdsm.log:</font><br>
<font size=3D"2" face=3D"sans-serif">Dummy-1960::DEBUG::2012-09-20 06:4=
6:58,959::__init__::1249::Storage.Misc.excCmd::(_log) 'dd if=3D/rhev/da=
ta-center/332694bb-364a-434e-b23f-5fef985d3cbd/mastersd/dom_md/inbox if=
lag=3Ddirect,fullblock count=3D1 bs=3D1024000' (cwd None)</font><br>
<font size=3D"2" face=3D"sans-serif">Dummy-1960::DEBUG::2012-09-20 06:4=
6:59,043::__init__::1249::Storage.Misc.excCmd::(_log) SUCCESS: <err&=
gt; =3D '1+0 records in\n1+0 records out\n1024000 bytes (1.0 MB) copied=
, 0.0488089 s, 21.0 MB/s\n'; <rc> =3D 0</font><br>
<font size=3D"2" face=3D"sans-serif">Dummy-1960::DEBUG::2012-09-20 06:4=
7:01,053::__init__::1249::Storage.Misc.excCmd::(_log) 'dd if=3D/rhev/da=
ta-center/332694bb-364a-434e-b23f-5fef985d3cbd/mastersd/dom_md/inbox if=
lag=3Ddirect,fullblock count=3D1 bs=3D1024000' (cwd None)</font><br>
<font size=3D"2" face=3D"sans-serif">Dummy-1960::DEBUG::2012-09-20 06:4=
7:01,136::__init__::1249::Storage.Misc.excCmd::(_log) SUCCESS: <err&=
gt; =3D '1+0 records in\n1+0 records out\n1024000 bytes (1.0 MB) copied=
, 0.0477826 s, 21.4 MB/s\n'; <rc> =3D 0</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7807::DEBUG::2012-09-20 06:=
47:01,991::BindingXMLRPC::859::vds::(wrapper) client [192.168.10.10]::c=
all vmCreate with ({'custom': {'device_bb912edd-9790-43ff-a758-f1d9f20c=
b5f5device_f5c86859-5ae9-4a37-9d34-2b9547609622device_20a11f26-6a39-415=
d-a7bf-95893b9c55b5device_21f255dc-9b3b-48d8-b8e4-63c1635e269bdevice_d6=
c2c4d1-da6b-44fe-a5aa-508135c7fdfe': 'VmId=3D509e608c-e657-473a-b031-f0=
811da96bde,DeviceId=3Dd6c2c4d1-da6b-44fe-a5aa-508135c7fdfe,Device=3Dusb=
,Type=3Dcontroller,BootOrder=3D0,SpecParams=3D{},Address=3D{bus=3D0x00,=
 domain=3D0x0000, type=3Dpci, slot=3D0x01, function=3D0x2},IsManaged=3D=
false,IsPlugged=3Dtrue,IsReadOnly=3Dfalse,alias=3Dusb0', 'device_bb912e=
<font size=3D"2" face=3D"sans-serif">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 spiceSs=
lCipherSuite=3DDEFAULT,memSize=3D1024,kvmEnable=3Dtrue,smp=3D1,emulated=
Machine=3Dpc-0.14,vmType=3Dkvm,keyboardLayout=3Den-us,pitReinjection=3D=
false,nice=3D0,display=3Dqxl,smpCoresPerSocket=3D1,spiceSecureChannels=3D=
smain,sinputs,scursor,splayback,srecord,sdisplay,displayNetwork=3Dovirt=
mgmt,timeOffset=3D-1,transparentHugePages=3Dtrue,vmId=3D509e608c-e657-4=
73a                            -b031-f0811da96bde,devices=3D[Ljava.util=
.Map;@41d42882,acpiEnable=3Dtrue,vmName=3DCentOS6Thames,cpuType=3DConro=
e,custom=3D{device_bb912edd-9790-43ff-a758-f1d9f20cb5f5device_f5c86859-=
5ae9-4a37-9d34-2b9547609622device_20a11f26-6a39-415d-a7bf-95893b9c55b5=3D=
VmId=3D509e608c-e657-473a-b031-f0811da96bde,DeviceId=3D20a11f26-6a39-41=
5d-a7bf-95893b9c55b5,Device=3Dunix,Type=3Dchannel,BootOrder=3D0,SpecPar=
ams=3D{},Address=3D{port=3D1, bus=3D0, controller=3D0, type=3Dvirtio-se=
rial},IsManaged=3Dfalse,IsPlugged=3Dtrue,IsReadOnly=3Dfalse,alias=3Dcha=
nnel0,                             device_bb912edd-9790-43ff-a758-f1d9f=
20cb5f5=3DVmId=3D509e608c-e657-473a-b031-f0811da96bde,DeviceId=3Dbb912e=
dd-9790-43ff-a758-f1d9f20cb5f5,Device=3Dide,Type=3Dcontroller,BootOrder=
=3D0,SpecParams=3D{},Address=3D{bus=3D0x00, domain=3D0x0000, type=3Dpci=
, slot=3D0x01, function=3D0x1},IsManaged=3Dfalse,IsPlugged=3Dtrue,IsRea=
dOnly=3Dfalse,alias=3Dide0, device_bb912edd-9790-43ff-a758-f1d9f20cb5f5=
device_f5c86859-5ae9-4a37-9d34-2b9547609622=3DVmId=3D509e608c-e657-473a=
-b031-f0811da96bde,DeviceId=3Df5c86859-5ae9-4a37-9d34-2b9547609622,Devi=
ce=3Dvirtio-s                            erial,Type=3Dcontroller,BootOr=
der=3D0,SpecParams=3D{},Address=3D{bus=3D0x00, domain=3D0x0000, type=3D=
pci, slot=3D0x04, function=3D0x0},IsManaged=3Dfalse,IsPlugged=3Dtrue,Is=
ReadOnly=3Dfalse,alias=3Dvirtio-serial0, device_bb912edd-9790-43ff-a758=
-f1d9f20cb5f5device_f5c86859-5ae9-4a37-9d34-2b9547609622device_20a11f26=
-6a39-415d-a7bf-95893b9c55b5device_21f255dc-9b3b-48d8-b8e4-63c1635e269b=
=3DVmId=3D509e608c-e657-473a-b031-f0811da96bde,DeviceId=3D21f255dc-9b3b=
-48d8-b8e4-63c1635e269b,Device=3Dspicevmc,Type=3Dchannel,BootOrder=3D0,=
SpecParams=3D{},A                            ddress=3D{port=3D2, bus=3D=
0, controller=3D0, type=3Dvirtio-serial},IsManaged=3Dfalse,IsPlugged=3D=
true,IsReadOnly=3Dfalse,alias=3Dchannel1, device_bb912edd-9790-43ff-a75=
8-f1d9f20cb5f5device_f5c86859-5ae9-4a37-9d34-2b9547609622device_20a11f2=
6-6a39-415d-a7bf-95893b9c55b5device_21f255dc-9b3b-48d8-b8e4-63c1635e269=
bdevice_d6c2c4d1-da6b-44fe-a5aa-508135c7fdfe=3DVmId=3D509e608c-e657-473=
a-b031-f0811da96bde,DeviceId=3Dd6c2c4d1-da6b-44fe-a5aa-508135c7fdfe,Dev=
ice=3Dusb,Type=3Dcontroller,BootOrder=3D0,SpecParams=3D{},Address=3D{bu=
s=3D0x00, domain=3D                            0x0000, type=3Dpci, slot=
=3D0x01, function=3D0x2},IsManaged=3Dfalse,IsPlugged=3Dtrue,IsReadOnly=3D=
false,alias=3Dusb0}</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:54,982 INFO  [org=
.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand] (pool-3-thread=
-50) FINISH, CreateVDSCommand, log id: 73615350</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:55,004 INFO  [org=
.ovirt.engine.core.vdsbroker.CreateVmVDSCommand] (pool-3-thread-50) Inc=
reasePendingVms::CreateVmIncreasing vds hyper2.ovirt.com pending vcpu c=
ount, now 1. Vm: CentOS6Thames</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:55,012 INFO  [org=
.ovirt.engine.core.vdsbroker.CreateVmVDSCommand] (pool-3-thread-50) FIN=
ISH, CreateVmVDSCommand, return: WaitForLaunch, log id: 554a0742</font>=
<br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:55,022 INFO  [org=
.ovirt.engine.core.bll.RunVmCommand] (pool-3-thread-50) Lock freed to o=
bject EngineLock [exclusiveLocks=3D key: 509e608c-e657-473a-b031-f0811d=
a96bde value: VM</font><br>
<font size=3D"2" face=3D"sans-serif">, sharedLocks=3D ]</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:56,434 INFO  [org=
.ovirt.engine.core.vdsbroker.vdsbroker.DestroyVDSCommand] (QuartzSchedu=
ler_Worker-32) START, DestroyVDSCommand(vdsId =3D 9840e840-02db-11e2-a0=
1a-0011856cf23e, vmId=3D509e608c-e657-473a-b031-f0811da96bde, force=3Df=
alse, secondsToWait=3D0, gracefully=3Dfalse), log id: 6b44f6c9</font><b=
r>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:56,497 INFO  [org=
.ovirt.engine.core.vdsbroker.vdsbroker.DestroyVDSCommand] (QuartzSchedu=
ler_Worker-32) FINISH, DestroyVDSCommand, log id: 6b44f6c9</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:56,532 INFO  [org=
.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (QuartzScheduler_Wor=
ker-32) Running on vds during rerun failed vm: null</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:56,535 INFO  [org=
.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (QuartzScheduler_Wor=
ker-32) vm CentOS6Thames running in db and not running in vds - add to =
rerun treatment. vds hyper2.ovirt.com</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:56,548 ERROR [org=
.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (QuartzScheduler_Wor=
ker-32) Rerun vm 509e608c-e657-473a-b031-f0811da96bde. Called from vds =
hyper2.ovirt.com</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:56,582 INFO  [org=
.ovirt.engine.core.vdsbroker.UpdateVdsDynamicDataVDSCommand] (pool-3-th=
read-50) START, UpdateVdsDynamicDataVDSCommand(vdsId =3D 9840e840-02db-=
11e2-a01a-0011856cf23e, vdsDynamic=3Dorg.ovirt.engine.core.common.busin=
essentities.VdsDynamic@5f1dd7c7), log id: 2a191f9e</font><br>
<font size=3D"2" face=3D"sans-serif">2012-09-20 12:42:56,596 INFO  [org=
.ovirt.engine.core.vdsbroker.UpdateVdsDynamicDataVDSCommand] (pool-3-th=
read-50) FINISH, UpdateVdsDynamicDataVDSCommand, log id: 2a191f9e</font=
dd-9790-43ff-a758-f1d9f20cb5f5device_f5c86859-5ae9-4a37-9d34-2b95476096=
22device_20a11f26-6a39-415d-a7bf-95893b9c55b5device_21f255dc-9b3b-48d8-=
b8e4-63c1635e269b': 'VmId=3D509e608c-e657-473a-b031-f0811da96bde,Device=
Id=3D21f255dc-9b3b-48d8-b8e4-63c1635e269b,Device=3Dspicevmc,Type=3Dchan=
nel,BootOrder=3D0,SpecParams=3D{},Address=3D{port=3D2, bus=3D0, control=
ler=3D0, type=3Dvirtio-serial},IsManaged=3Dfalse,IsPlugged=3Dtrue,IsRea=
dOnly=3Dfalse,alias=3Dchannel1', 'device_bb912edd-9790-43ff-a758-f1d9f2=
0cb5f5device_f5c86859-5ae9-4a37-9d34-2b9547609622': 'VmId=3D509e608c-e6=
57-473a-b031-f0811da96bde,DeviceId=3Df5c86859-5ae9-4a37-9d34-2b95476096=
22,Device=3Dvirtio-serial,Type=3Dcontroller,BootOrder=3D0,SpecParams=3D=
{},Address=3D{bus=3D0x00, domain=3D0x0000, type=3Dpci, slot=3D0x04, fun=
ction=3D0x0},IsManaged=3Dfalse,IsPlugged=3Dtrue,IsReadOnly=3Dfalse,alia=
s=3Dvirtio-serial0', 'device_bb912edd-9790-43ff-a758-f1d9f20cb5f5device=
_f5c86859-5ae9-4a37-9d34-2b9547609622device_20a11f26-6a39-415d-a7bf-958=
93b9c55b5': 'VmId=3D509e608c-e657-473a-b031-f0811da96bde,DeviceId=3D20a=
11f26-6a39-415d-a7bf-95893b9c55b5,Device=3Dunix,Type=3Dchannel,BootOrde=
r=3D0,SpecParams=3D{},Address=3D{port=3D1, bus=3D0, controller=3D0, typ=
e=3Dvirtio-serial},IsManaged=3Dfalse,IsPlugged=3Dtrue,IsReadOnly=3Dfals=
e,alias=3Dchannel0', 'device_bb912edd-9790-43ff-a758-f1d9f20cb5f5': 'Vm=
Id=3D509e608c-e657-473a-b031-f0811da96bde,DeviceId=3Dbb912edd-9790-43ff=
-a758-f1d9f20cb5f5,Device=3Dide,Type=3Dcontroller,BootOrder=3D0,SpecPar=
ams=3D{},Address=3D{bus=3D0x00, domain=3D0x0000, type=3Dpci, slot=3D0x0=
1, function=3D0x1},IsManaged=3Dfalse,IsPlugged=3Dtrue,IsReadOnly=3Dfals=
e,alias=3Dide0'}, 'keyboardLayout': 'en-us', 'kvmEnable': 'true', 'pitR=
einjection': 'false', 'acpiEnable': 'true', 'emulatedMachine': 'pc-0.14=
', 'displayNetwork': 'ovirtmgmt', 'vmId': '509e608c-e657-473a-b031-f081=
1da96bde', 'devices': [{'device': 'qxl', 'specParams': {'vram': '65536'=
}, 'type': 'video', 'deviceId': '20c037f2-11e5-49a5-ace7-741023ec0ce9',=
 'address': {'bus': '0x00', ' slot': '0x02', ' domain': '0x0000', ' typ=
e': 'pci', ' function': '0x0'}}, {'index': '2', 'iface': 'ide', 'specPa=
rams': {'path': ''}, 'readonly': 'true', 'deviceId': '1ed8a73e-be34-482=
9-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': 'f184e=
cd1-0001-4739-af71-250b412345d6', 'imageID': '0a7013db-68fd-4c42-bc2e-c=
c8d7a05ca18', 'specParams': {}, 'readonly': 'false', 'domainID': '26187=
d25-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', 'specPa=
rams': {}, 'deviceId': '7392f689-2ba3-4243-9629-96b192b102a5', 'address=
': {'bus': '0x00', ' slot': '0x03', ' domain': '0x0000', ' type': 'pci'=
, ' function': '0x0'}, 'device': 'bridge', 'type': 'interface'}, {'devi=
ce': 'usb', 'specParams': {}, 'type': 'controller', 'deviceId': 'd6c2c4=
d1-da6b-44fe-a5aa-508135c7fdfe', 'address': {'bus': '0x00', ' slot': '0=
x01', ' domain': '0x0000', ' type': 'pci', ' function': '0x2'}}, {'devi=
ce': 'memballoon', 'specParams': {'model': 'virtio'}, 'type': 'balloon'=
, 'deviceId': 'babd73a4-de64-4dce-91b9-e64c5b46c444'}], 'smp': '1', 'vm=
Type': 'kvm', 'timeOffset': '</font><br>
<font size=3D"2" face=3D"sans-serif">-1', 'memSize': 1024, 'spiceSslCip=
herSuite': 'DEFAULT', 'cpuType': 'Conroe', 'spiceSecureChannels': 'smai=
n,sinputs,scursor,splayback,srecord,sdisplay', 'smpCoresPerSocket': '1'=
, 'vmName': 'CentOS6Thames', 'display': 'qxl', 'transparentHugePages': =
'true', 'nice': '0'},) {}</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7807::INFO::2012-09-20 06:4=
7:01,992::API::228::vds::(create) vmContainerLock acquired by vm 509e60=
8c-e657-473a-b031-f0811da96bde</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:=
47:01,996::vm::564::vm.Vm::(_startUnderlyingVm) vmId=3D`509e608c-e657-4=
73a-b031-f0811da96bde`::Start</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7807::DEBUG::2012-09-20 06:=
47:01,996::API::244::vds::(create) Total desktops after creation of 509=
e608c-e657-473a-b031-f0811da96bde is 1</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:=
47:01,997::vm::568::vm.Vm::(_startUnderlyingVm) vmId=3D`509e608c-e657-4=
73a-b031-f0811da96bde`::_ongoingCreations acquired</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7807::DEBUG::2012-09-20 06:=
47:01,997::BindingXMLRPC::865::vds::(wrapper) return vmCreate with {'st=
atus': {'message': 'Done', 'code': 0}, 'vmList': {'status': 'WaitForLau=
nch', 'acpiEnable': 'true', 'emulatedMachine': 'pc-0.14', 'vmId': '509e=
608c-e657-473a-b031-f0811da96bde', 'pid': '0', 'timeOffset': '-1', 'dis=
playPort': '-1', 'displaySecurePort': '-1', 'spiceSslCipherSuite': 'DEF=
AULT', 'cpuType': 'Conroe', 'custom': {'device_bb912edd-9790-43ff-a758-=
f1d9f20cb5f5device_f5c86859-5ae9-4a37-9d34-2b9547609622device_20a11f26-=
6a39-415d-a7bf-95893b9c55b5device_21f255dc-9b3b-48d8-b8e4-63c1635e269bd=
evice_d6c2c4d1-da6b-44fe-a5aa-508135c7fdfe': 'VmId=3D509e608c-e657-473a=
-b031-f0811da96bde,DeviceId=3Dd6c2c4d1-da6b-44fe-a5aa-508135c7fdfe,Devi=
ce=3Dusb,Type=3Dcontroller,BootOrder=3D0,SpecParams=3D{},Address=3D{bus=
=3D0x00, domain=3D0x0000, type=3Dpci, slot=3D0x01, function=3D0x2},IsMa=
naged=3Dfalse,IsPlugged=3Dtrue,IsReadOnly=3Dfalse,alias=3Dusb0', 'devic=
e_bb912edd-9790-43ff-a758-f1d9f20cb5f5device_f5c86859-5ae9-4a37-9d34-2b=
9547609622device_20a11f26-6a39-415d-a7bf-95893b9c55b5device_21f255dc-9b=
3b-48d8-b8e4-63c1635e269b': 'VmId=3D509e608c-e657-473a-b031-f0811da96bd=
e,DeviceId=3D21f255dc-9b3b-48d8-b8e4-63c1635e269b,Device=3Dspicevmc,Typ=
e=3Dchannel,BootOrder=3D0,SpecParams=3D{},Address=3D{port=3D2, bus=3D0,=
 controller=3D0, type=3Dvirtio-serial},IsManaged=3Dfalse,IsPlugged=3Dtr=
ue,IsReadOnly=3Dfalse,alias=3Dchannel1', 'device_bb912edd-9790-43ff-a75=
8-f1d9f20cb5f5device_f5c86859-5ae9-4a37-9d34-2b9547609622': 'VmId=3D509=
e608c-e657-473a-b031-f0811da96bde,DeviceId=3Df5c86859-5ae9-4a37-9d34-2b=
9547609622,Device=3Dvirtio-serial,Type=3Dcontroller,BootOrder=3D0,SpecP=
arams=3D{},Address=3D{bus=3D0x00, domain=3D0x0000, type=3Dpci, slot=3D0=
x04, function=3D0x0},IsManaged=3Dfalse,IsPlugged=3Dtrue,IsReadOnly=3Dfa=
lse,alias=3Dvirtio-serial0', 'device_bb912edd-9790-43ff-a758-f1d9f20cb5=
f5device_f5c86859-5ae9-4a37-9d34-2b9547609622device_20a11f26-6a39-415d-=
a7bf-95893b9c55b5': 'VmId=3D509e608c-e657-473a-b031-f0811da96bde,Device=
Id=3D20a11f26-6a39-415d-a7bf-95893b9c55b5,Device=3Dunix,Type=3Dchannel,=
BootOrder=3D0,SpecParams=3D{},Address=3D{port=3D1, bus=3D0, controller=3D=
0, type=3Dvirtio-serial},IsManaged=3Dfalse,IsPlugged=3Dtrue,IsReadOnly=3D=
false,alias=3Dchannel0', 'device_bb912edd-9790-43ff-a758-f1d9f20cb5f5':=
 'VmId=3D509e608c-e657-473a-b031-f0811da96bde,DeviceId=3Dbb912edd-9790-=
43ff-a758-f1d9f20cb5f5,Device=3Dide,Type=3Dcontroller,BootOrder=3D0,Spe=
cParams=3D{},Address=3D{bus=3D0x00, domain=3D0x0000, type=3Dpci, slot=3D=
0x01, function=3D0x1},IsManaged=3Dfalse,IsPlugged=3Dtrue,IsReadOnly=3Df=
alse,alias=3Dide0'}, 'clientIp': '', 'nicModel': 'rtl8139,pv', 'keyboar=
dLayout': 'en-us', 'kvmEnable': 'true', 'pitReinjection': 'false', 'tra=
nsparentHugePages': 'true', 'displayNetwork': 'ovirtmgmt', 'devices': [=
{'device': 'qxl', 'specParams': {'vram': '65536'}, 'type': 'video', 'de=
viceId': '20c037f2-11e5-49a5-ace7-741023ec0ce9', 'address': {'bus': '0x=
00', ' slot': '0x02', ' domain': '0x0000', ' type': 'pci', ' function':=
 '0x0'}}, {'index': '2', 'iface': 'ide', 'specParams': {'path': ''}, 'r=
eadonly': '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-250b=
412345d6', 'imageID': '0a7013db-68fd-4c42-bc2e-cc8d7a05ca18', 'specPara=
ms': {}, 'readonly': 'false', 'domainID': '26187d25-bfcb-40c7-97d1-6677=
05ad2223', 'deviceId': '0a7013db-68fd-4c42-bc2e-cc8d7a05ca18', 'address=
': {'bus': '0x00', ' slot': '0x05', ' domain': '0x0000', ' type': 'pci'=
, ' function': '0x0'}, 'device': 'disk', 'shared': 'false', 'propagateE=
rrors': 'off', 'optional': 'false'}, {'nicModel': 'pv', 'macAddr': '00:=
1a:4a:a8:0a:00', 'network': 'ovirtmgmt', 'specParams': {}, 'deviceId': =
'7392f689-2ba3-4243-9629-96b192b102a5', 'address': {'bus': '0x00', ' sl=
ot': '0x03', ' domain': '0x0000', ' type': 'pci', ' function': '0x0'}, =
'device': 'bridge', 'type': 'interface'}, {'device': 'usb', 'specParams=
': {}, 'type': 'controller', 'deviceId': 'd6c2c4d1-da6b-44fe-a5aa-50813=
5c7fdfe', 'address': {'b</font><br>
<font size=3D"2" face=3D"sans-serif">us': '0x00', ' slot': '0x01', ' do=
main': '0x0000', ' type': 'pci', ' function': '0x2'}}, {'device': 'memb=
alloon', 'specParams': {'model': 'virtio'}, 'type': 'balloon', 'deviceI=
d': 'babd73a4-de64-4dce-91b9-e64c5b46c444'}], 'smp': '1', 'vmType': 'kv=
m', 'memSize': 1024, 'displayIp': '192.168.10.13', 'spiceSecureChannels=
': 'smain,sinputs,scursor,splayback,srecord,sdisplay', 'smpCoresPerSock=
et': '1', 'vmName': 'CentOS6Thames', 'display': 'qxl', 'nice': '0'}}</f=
ont><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::INFO::2012-09-20 06:4=
7:01,997::libvirtvm::1285::vm.Vm::(_run) vmId=3D`509e608c-e657-473a-b03=
1-f0811da96bde`::VM wrapper has started</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:=
47:02,000::task::588::TaskManager.Task::(_updateState) Task=3D`b6ef82b2=
-2986-4b7b-95ba-d5f3cac8ad31`::moving from state init -> state prepa=
ring</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::INFO::2012-09-20 06:4=
7:02,001::logUtils::37::dispatcher::(wrapper) Run and protect: getVolum=
eSize(sdUUID=3D'26187d25-bfcb-40c7-97d1-667705ad2223', spUUID=3D'332694=
bb-364a-434e-b23f-5fef985d3cbd', imgUUID=3D'0a7013db-68fd-4c42-bc2e-cc8=
d7a05ca18', volUUID=3D'f184ecd1-0001-4739-af71-250b412345d6', options=3D=
None)</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:=
47:02,001::resourceManager::175::ResourceManager.Request::(__init__) Re=
sName=3D`Storage.26187d25-bfcb-40c7-97d1-667705ad2223`ReqID=3D`83dac2e0=
-3d55-4ef6-abf3-7b2561814ab4`::Request was made in '/usr/share/vdsm/sto=
rage/resourceManager.py' line '485' at 'registerResource'</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:=
47:02,002::resourceManager::486::ResourceManager::(registerResource) Tr=
ying to register resource 'Storage.26187d25-bfcb-40c7-97d1-667705ad2223=
' for lock type 'shared'</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:=
47:02,002::resourceManager::528::ResourceManager::(registerResource) Re=
source 'Storage.26187d25-bfcb-40c7-97d1-667705ad2223' is free. Now lock=
ing as 'shared' (1 active user)</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:=
47:02,002::resourceManager::212::ResourceManager.Request::(grant) ResNa=
me=3D`Storage.26187d25-bfcb-40c7-97d1-667705ad2223`ReqID=3D`83dac2e0-3d=
55-4ef6-abf3-7b2561814ab4`::Granted request</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:=
47:02,003::task::817::TaskManager.Task::(resourceAcquired) Task=3D`b6ef=
82b2-2986-4b7b-95ba-d5f3cac8ad31`::_resourcesAcquired: Storage.26187d25=
-bfcb-40c7-97d1-667705ad2223 (shared)</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:=
47:02,003::task::978::TaskManager.Task::(_decref) Task=3D`b6ef82b2-2986=
-4b7b-95ba-d5f3cac8ad31`::ref 1 aborting False</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::INFO::2012-09-20 06:4=
7:02,004::logUtils::39::dispatcher::(wrapper) Run and protect: getVolum=
eSize, Return response: {'truesize': '13958643712', 'apparentsize': '13=
958643712'}</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:=
47:02,004::task::1172::TaskManager.Task::(prepare) Task=3D`b6ef82b2-298=
6-4b7b-95ba-d5f3cac8ad31`::finished: {'truesize': '13958643712', 'appar=
entsize': '13958643712'}</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:=
47:02,004::task::588::TaskManager.Task::(_updateState) Task=3D`b6ef82b2=
-2986-4b7b-95ba-d5f3cac8ad31`::moving from state preparing -> state =
finished</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:=
47:02,004::resourceManager::809::ResourceManager.Owner::(releaseAll) Ow=
ner.releaseAll requests {} resources {'Storage.26187d25-bfcb-40c7-97d1-=
667705ad2223': < ResourceRef 'Storage.26187d25-bfcb-40c7-97d1-667705=
ad2223', isValid: 'True' obj: 'None'>}</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:=
47:02,004::resourceManager::844::ResourceManager.Owner::(cancelAll) Own=
er.cancelAll requests {}</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:=
47:02,005::resourceManager::538::ResourceManager::(releaseResource) Try=
ing to release resource 'Storage.26187d25-bfcb-40c7-97d1-667705ad2223'<=
/font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:=
47:02,005::resourceManager::553::ResourceManager::(releaseResource) Rel=
eased resource 'Storage.26187d25-bfcb-40c7-97d1-667705ad2223' (0 active=
 users)</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:=
47:02,005::resourceManager::558::ResourceManager::(releaseResource) Res=
ource 'Storage.26187d25-bfcb-40c7-97d1-667705ad2223' is free, finding o=
ut if anyone is waiting for it.</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:=
47:02,005::resourceManager::565::ResourceManager::(releaseResource) No =
one is waiting for resource 'Storage.26187d25-bfcb-40c7-97d1-667705ad22=
23', Clearing records.</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:=
47:02,005::task::978::TaskManager.Task::(_decref) Task=3D`b6ef82b2-2986=
-4b7b-95ba-d5f3cac8ad31`::ref 0 aborting False</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::INFO::2012-09-20 06:4=
7:02,006::clientIF::274::vds::(prepareVolumePath) prepared volume path:=
</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:=
47:02,006::task::588::TaskManager.Task::(_updateState) Task=3D`83579cfe=
-4384-4b76-8bb0-979ed2b60739`::moving from state init -> state prepa=
ring</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::INFO::2012-09-20 06:4=
7:02,006::logUtils::37::dispatcher::(wrapper) Run and protect: prepareI=
mage(sdUUID=3D'26187d25-bfcb-40c7-97d1-667705ad2223', spUUID=3D'332694b=
b-364a-434e-b23f-5fef985d3cbd', imgUUID=3D'0a7013db-68fd-4c42-bc2e-cc8d=
7a05ca18', volUUID=3D'f184ecd1-0001-4739-af71-250b412345d6')</font><br>=

<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:=
47:02,007::resourceManager::175::ResourceManager.Request::(__init__) Re=
sName=3D`Storage.26187d25-bfcb-40c7-97d1-667705ad2223`ReqID=3D`c22e6209=
-b86d-448c-8884-372ce9a589c4`::Request was made in '/usr/share/vdsm/sto=
rage/resourceManager.py' line '485' at 'registerResource'</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:=
47:02,007::resourceManager::486::ResourceManager::(registerResource) Tr=
ying to register resource 'Storage.26187d25-bfcb-40c7-97d1-667705ad2223=
' for lock type 'shared'</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:=
47:02,007::resourceManager::528::ResourceManager::(registerResource) Re=
source 'Storage.26187d25-bfcb-40c7-97d1-667705ad2223' is free. Now lock=
ing as 'shared' (1 active user)</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:=
47:02,007::resourceManager::212::ResourceManager.Request::(grant) ResNa=
me=3D`Storage.26187d25-bfcb-40c7-97d1-667705ad2223`ReqID=3D`c22e6209-b8=
6d-448c-8884-372ce9a589c4`::Granted request</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:=
47:02,008::task::817::TaskManager.Task::(resourceAcquired) Task=3D`8357=
9cfe-4384-4b76-8bb0-979ed2b60739`::_resourcesAcquired: Storage.26187d25=
-bfcb-40c7-97d1-667705ad2223 (shared)</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:=
47:02,008::task::978::TaskManager.Task::(_decref) Task=3D`83579cfe-4384=
-4b76-8bb0-979ed2b60739`::ref 1 aborting False</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:=
47:02,008::__init__::1249::Storage.Misc.excCmd::(_log) '/usr/bin/dd ifl=
ag=3Ddirect skip=3D4 bs=3D512 if=3D/dev/26187d25-bfcb-40c7-97d1-667705a=
d2223/metadata count=3D1' (cwd None)</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:=
47:02,023::__init__::1249::Storage.Misc.excCmd::(_log) SUCCESS: <err=
> =3D '1+0 records in\n1+0 records out\n512 bytes (512 B) copied, 0.=
000766795 s, 668 kB/s\n'; <rc> =3D 0</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:=
47:02,023::misc::314::Storage.Misc::(validateDDBytes) err: ['1+0 record=
s in', '1+0 records out', '512 bytes (512 B) copied, 0.000766795 s, 668=
 kB/s'], size: 512</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::INFO::2012-09-20 06:4=
7:02,023::image::357::Storage.Image::(getChain) sdUUID=3D26187d25-bfcb-=
40c7-97d1-667705ad2223 imgUUID=3D0a7013db-68fd-4c42-bc2e-cc8d7a05ca18 c=
hain=3D<storage.blockVolume.BlockVolume instance at 0x7ff9fc0feb90></fo=
nt><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::INFO::2012-09-20 06:4=
7:02,024::logUtils::39::dispatcher::(wrapper) Run and protect: prepareI=
mage, Return response: {'path': '/rhev/data-center/332694bb-364a-434e-b=
23f-5fef985d3cbd/26187d25-bfcb-40c7-97d1-667705ad2223/images/0a7013db-6=
8fd-4c42-bc2e-cc8d7a05ca18/f184ecd1-0001-4739-af71-250b412345d6', 'chai=
n': [{'path': '/rhev/data-center/332694bb-364a-434e-b23f-5fef985d3cbd/2=
6187d25-bfcb-40c7-97d1-667705ad2223/images/0a7013db-68fd-4c42-bc2e-cc8d=
7a05ca18/f184ecd1-0001-4739-af71-250b412345d6', 'domainID': '26187d25-b=
fcb-40c7-97d1-667705ad2223', 'volumeID': 'f184ecd1-0001-4739-af71-250b4=
12345d6', 'imageID': '0a7013db-68fd-4c42-bc2e-cc8d7a05ca18'}]}</font><b=
r>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:=
47:02,024::task::1172::TaskManager.Task::(prepare) Task=3D`83579cfe-438=
4-4b76-8bb0-979ed2b60739`::finished: {'path': '/rhev/data-center/332694=
bb-364a-434e-b23f-5fef985d3cbd/26187d25-bfcb-40c7-97d1-667705ad2223/ima=
ges/0a7013db-68fd-4c42-bc2e-cc8d7a05ca18/f184ecd1-0001-4739-af71-250b41=
2345d6', 'chain': [{'path': '/rhev/data-center/332694bb-364a-434e-b23f-=
5fef985d3cbd/26187d25-bfcb-40c7-97d1-667705ad2223/images/0a7013db-68fd-=
4c42-bc2e-cc8d7a05ca18/f184ecd1-0001-4739-af71-250b412345d6', 'domainID=
': '26187d25-bfcb-40c7-97d1-667705ad2223', 'volumeID': 'f184ecd1-0001-4=
739-af71-250b412345d6', 'imageID': '0a7013db-68fd-4c42-bc2e-cc8d7a05ca1=
8'}]}</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:=
47:02,024::task::588::TaskManager.Task::(_updateState) Task=3D`83579cfe=
-4384-4b76-8bb0-979ed2b60739`::moving from state preparing -> state =
finished</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:=
47:02,025::resourceManager::809::ResourceManager.Owner::(releaseAll) Ow=
ner.releaseAll requests {} resources {'Storage.26187d25-bfcb-40c7-97d1-=
667705ad2223': < ResourceRef 'Storage.26187d25-bfcb-40c7-97d1-667705=
ad2223', isValid: 'True' obj: 'None'>}</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:=
47:02,025::resourceManager::844::ResourceManager.Owner::(cancelAll) Own=
er.cancelAll requests {}</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:=
47:02,025::resourceManager::538::ResourceManager::(releaseResource) Try=
ing to release resource 'Storage.26187d25-bfcb-40c7-97d1-667705ad2223'<=
/font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:=
47:02,025::resourceManager::553::ResourceManager::(releaseResource) Rel=
eased resource 'Storage.26187d25-bfcb-40c7-97d1-667705ad2223' (0 active=
 users)</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:=
47:02,026::resourceManager::558::ResourceManager::(releaseResource) Res=
ource 'Storage.26187d25-bfcb-40c7-97d1-667705ad2223' is free, finding o=
ut if anyone is waiting for it.</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:=
47:02,026::resourceManager::565::ResourceManager::(releaseResource) No =
one is waiting for resource 'Storage.26187d25-bfcb-40c7-97d1-667705ad22=
23', Clearing records.</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:=
47:02,026::task::978::TaskManager.Task::(_decref) Task=3D`83579cfe-4384=
-4b76-8bb0-979ed2b60739`::ref 0 aborting False</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::INFO::2012-09-20 06:4=
7:02,026::clientIF::274::vds::(prepareVolumePath) prepared volume path:=
 /rhev/data-center/332694bb-364a-434e-b23f-5fef985d3cbd/26187d25-bfcb-4=
0c7-97d1-667705ad2223/images/0a7013db-68fd-4c42-bc2e-cc8d7a05ca18/f184e=
cd1-0001-4739-af71-250b412345d6</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:=
47:02,037::libvirtvm::1338::vm.Vm::(_run) vmId=3D`509e608c-e657-473a-b0=
31-f0811da96bde`::<?xml version=3D"1.0" encoding=3D"u=
tf-8"?></font><br>
<font size=3D"2" face=3D"sans-serif"><domain type=3D"kvm"&=
gt;</font><br>
<font size=3D"2" face=3D"sans-serif">        <name>CentOS6Thames&=
lt;/name></font><br>
<font size=3D"2" face=3D"sans-serif">        <uuid>509e608c-e657-=
473a-b031-f0811da96bde</uuid></font><br>
<font size=3D"2" face=3D"sans-serif">        <memory>1048576</=
memory></font><br>
<font size=3D"2" face=3D"sans-serif">        <currentMemory>10485=
76</currentMemory></font><br>
<font size=3D"2" face=3D"sans-serif">        <vcpu>1</vcpu>=
</font><br>
<font size=3D"2" face=3D"sans-serif">        <devices></font><br>=

<font size=3D"2" face=3D"sans-serif">                <channel type=3D=
"unix"></font><br>
<font size=3D"2" face=3D"sans-serif">                        <target=
 name=3D"com.redhat.rhevm.vdsm" type=3D"virtio"/>=
;</font><br>
<font size=3D"2" face=3D"sans-serif">                        <source=
 mode=3D"bind" path=3D"/var/lib/libvirt/qemu/channels/Ce=
ntOS6Thames.com.redhat.rhevm.vdsm"/></font><br>
<font size=3D"2" face=3D"sans-serif">                </channel></=
font><br>
<font size=3D"2" face=3D"sans-serif">                <input bus=3D&q=
uot;ps2" type=3D"mouse"/></font><br>
<font size=3D"2" face=3D"sans-serif">                <channel type=3D=
"spicevmc"></font><br>
<font size=3D"2" face=3D"sans-serif">                        <target=
 name=3D"com.redhat.spice.0" type=3D"virtio"/></=
font><br>
<font size=3D"2" face=3D"sans-serif">                </channel></=
font><br>
<font size=3D"2" face=3D"sans-serif">                <graphics autop=
ort=3D"yes" keymap=3D"en-us" passwd=3D"*****&q=
uot; passwdValidTo=3D"1970-01-01T00:00:01" port=3D"-1&qu=
ot; tlsPort=3D"-1" type=3D"spice"></font><br>
<font size=3D"2" face=3D"sans-serif">                        <channe=
l mode=3D"secure" name=3D"main"/></font><br>
<font size=3D"2" face=3D"sans-serif">                        <channe=
l mode=3D"secure" name=3D"inputs"/></font><br>
<font size=3D"2" face=3D"sans-serif">                        <channe=
l mode=3D"secure" name=3D"cursor"/></font><br>
<font size=3D"2" face=3D"sans-serif">                        <channe=
l mode=3D&quo
t;secure" name=3D"playback"/></font><br>
<font size=3D"2" face=3D"sans-serif">                        <channe=
l mode=3D"secure" name=3D"record"/></font><br>
<font size=3D"2" face=3D"sans-serif">                        <channe=
l mode=3D"secure" name=3D"display"/></font><br>
<font size=3D"2" face=3D"sans-serif">                        <listen=
 network=3D"vdsm-ovirtmgmt" type=3D"network"/></=
font><br>
<font size=3D"2" face=3D"sans-serif">                </graphics><=
/font><br>
<font size=3D"2" face=3D"sans-serif">                <console type=3D=
"pty"></font><br>
<font size=3D"2" face=3D"sans-serif">                        <target=
 port=3D"0" type=3D"virtio"/></font><br>
<font size=3D"2" face=3D"sans-serif">                </console></=
font><br>
<font size=3D"2" face=3D"sans-serif">                <controller typ=
e=3D"usb"></font><br>
<font size=3D"2" face=3D"sans-serif">                        <addres=
s  domain=3D"0x0000"  function=3D"0x2"  slot=3D&quo=
t;0x01"  type=3D"pci" bus=3D"0x00"/></font>=
<br>
<font size=3D"2" face=3D"sans-serif">                </controller>=
;</font><br>
<font size=3D"2" face=3D"sans-serif">                <video></fon=
t><br>
<font size=3D"2" face=3D"sans-serif">                        <addres=
s  domain=3D"0x0000"  function=3D"0x0"  slot=3D&quo=
t;0x02"  type=3D"pci" bus=3D"0x00"/></font>=
<br>
<font size=3D"2" face=3D"sans-serif">                        <model =
heads=3D"1" type=3D"qxl" vram=3D"65536"/&=
gt;</font><br>
<font size=3D"2" face=3D"sans-serif">                </video></fo=
nt><br>
<font size=3D"2" face=3D"sans-serif">                <interface type=
=3D"bridge"></font><br>
<font size=3D"2" face=3D"sans-serif">                        <addres=
s  domain=3D"0x0000"  function=3D"0x0"  slot=3D&quo=
t;0x03"  type=3D"pci" bus=3D"0x00"/></font>=
<br>
<font size=3D"2" face=3D"sans-serif">                        <mac ad=
dress=3D"00:1a:4a:a8:0a:00"/></font><br>
<font size=3D"2" face=3D"sans-serif">                        <model =
type=3D"virtio"/></font><br>
<font size=3D"2" face=3D"sans-serif">                        <source=
 bridge=3D"ovirtmgmt"/></font><br>
<font size=3D"2" face=3D"sans-serif">                </interface>=
</font><br>
<font size=3D"2" face=3D"sans-serif">                <memballoon mod=
el=3D"virtio"/></font><br>
<font size=3D"2" face=3D"sans-serif">                <disk device=3D=
"cdrom" snapshot=3D"no" type=3D"file">=
</font><br>
<font size=3D"2" face=3D"sans-serif">                        <addres=
s  bus=3D"1"  controller=3D"0"  target=3D"0&qu=
ot;  type=3D"drive" unit=3D"0"/></font><br>
<font size=3D"2" face=3D"sans-serif">                        <source=
 file=3D"" startupPolicy=3D"optional"/></font><b=
r>
<font size=3D"2" face=3D"sans-serif">                        <target=
 bus=3D"ide" dev=3D"hdc"/></font><br>
<font size=3D"2" face=3D"sans-serif">                        <readon=
ly/></font><br>
<font size=3D"2" face=3D"sans-serif">                        <serial=
></serial></font><br>
<font size=3D"2" face=3D"sans-serif">                </disk></fon=
t><br>
<font size=3D"2" face=3D"sans-serif">                <disk device=3D=
"disk" snapshot=3D"no" type=3D"block">=
</font><br>
<font size=3D"2" face=3D"sans-serif">                        <addres=
s  domain=3D"0x0000"  function=3D"0x0"  slot=3D&quo=
t;0x05"  type=3D"pci" bus=3D"0x00"/></font>=
<br>
<font size=3D"2" face=3D"sans-serif">                        <source=
 dev=3D"/rhev/data-center/332694bb-364a-434e-b23f-5fef985d3cbd/261=
87d25-bfcb-40c7-97d1-667705ad2223/images/0a7013db-68fd-4c42-bc2e-cc8d7a=
05ca18/f184ecd1-0001-4739-af71-250b412345d6"/></font><br>
<font size=3D"2" face=3D"sans-serif">                        <target=
 bus=3D"virtio" dev=3D"vda"/></font><br>
<font size=3D"2" face=3D"sans-serif">                        <serial=
>0a7013db-68fd-4c42-bc2e-cc8d7a05ca18</serial></font><br>
<font size=3D"2" face=3D"sans-serif">                        <driver=
 cache=3D"none" error_policy=3D"stop" io=3D"na=
tive" name=3D"qemu" type=3D"qcow2"/></font>=
<br>
<font size=3D"2" face=3D"sans-serif">                </disk></fon=
t><br>
<font size=3D"2" face=3D"sans-serif">        </devices></font><br=
...
<font size=3D"2" face=3D"sans-serif">        <os></font><br>
<font size=3D"2" face=3D"sans-serif">                <type arch=3D&q=
uot;x86_64" machine=3D"pc-0.14">hvm</type></fon=
t><br>
<font size=3D"2" face=3D"sans-serif">                <smbios mode=3D=
"sysinfo"/></font><br>
<font size=3D"2" face=3D"sans-serif">        </os></font><br>
<font size=3D"2" face=3D"sans-serif">        <sysinfo type=3D"s=
mbios"></font><br>
<font size=3D"2" face=3D"sans-serif">                <system></fo=
nt><br>
<font size=3D"2" face=3D"sans-serif">                        <entry =
name=3D"manufacturer">Red Hat</entry></font><br>
<font size=3D"2" face=3D"sans-serif">                        <entry =
name=3D"product">RHEV Hypervisor</entry></font><br>
<font size=3D"2" face=3D"sans-serif">                        <entry =
name=3D"version">17-1</entry></font><br>
<font size=3D"2" face=3D"sans-serif">                        <entry =
name=3D"serial">31323334-3535-4C44-3643-4D5633393936_00:19=
:bb:39:97:4a</entry></font><br>
<font size=3D"2" face=3D"sans-serif">                        <entry =
name=3D"uuid">509e608c-e657-473a-b031-f0811da96bde</ent=
ry></font><br>
<font size=3D"2" face=3D"sans-serif">                </system></f=
ont><br>
<font size=3D"2" face=3D"sans-serif">        </sysinfo></font><br=
...
<font size=3D"2" face=3D"sans-serif">        <clock adjustment=3D&qu=
ot;-1" offset=3D"variable"></font><br>
<font size=3D"2" face=3D"sans-serif">                <timer name=3D&=
quot;rtc" tickpolicy=3D"catchup"/></font><br>
<font size=3D"2" face=3D"sans-serif">        </clock></font><br>
<font size=3D"2" face=3D"sans-serif">        <features></font><br=
...
<font size=3D"2" face=3D"sans-serif">                <acpi/></fon=
t><br>
<font size=3D"2" face=3D"sans-serif">        </features></font><b=
r>
<font size=3D"2" face=3D"sans-serif">        <cpu match=3D"exac=
t"></font><br>
<font size=3D"2" face=3D"sans-serif">                <model>Conro=
e</model></font><br>
<font size=3D"2" face=3D"sans-serif">                <topology cores=
=3D"1" sockets=3D"1" threads=3D"1"/></=
font><br>
<font size=3D"2" face=3D"sans-serif">        </cpu></font><br>
<font size=3D"2" face=3D"sans-serif"></domain></font><br>
<br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:=
47:02,426::vm::580::vm.Vm::(_startUnderlyingVm) vmId=3D`509e608c-e657-4=
73a-b031-f0811da96bde`::_ongoingCreations released</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::ERROR::2012-09-20 06:=
47:02,427::vm::604::vm.Vm::(_startUnderlyingVm) vmId=3D`509e608c-e657-4=
73a-b031-f0811da96bde`::The vm start process failed</font><br>
<font size=3D"2" face=3D"sans-serif">Traceback (most recent call last):=
</font><br>
<font size=3D"2" face=3D"sans-serif">  File "/usr/share/vdsm/vm.py=
", line 570, in _startUnderlyingVm</font><br>
<font size=3D"2" face=3D"sans-serif">  File "/usr/share/vdsm/libvi=
rtvm.py", line 1364, in _run</font><br>
<font size=3D"2" face=3D"sans-serif">  File "/usr/lib/python2.7/si=
te-packages/vdsm/libvirtconnection.py", line 82, in wrapper</font>=
<br>
<font size=3D"2" face=3D"sans-serif">  File "/usr/lib64/python2.7/=
site-packages/libvirt.py", line 2420, in createXML</font><br>
<font size=3D"2" face=3D"sans-serif">libvirtError: unsupported configur=
ation: spice secure channels set in XML configuration, but TLS is disab=
led in qemu.conf</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7808::DEBUG::2012-09-20 06:=
47:02,430::vm::920::vm.Vm::(setDownStatus) vmId=3D`509e608c-e657-473a-b=
031-f0811da96bde`::Changed state to Down: unsupported configuration: sp=
ice secure channels set in XML configuration, but TLS is disabled in qe=
mu.conf</font><br>
<font size=3D"2" face=3D"sans-serif">Dummy-1960::DEBUG::2012-09-20 06:4=
7:03,145::__init__::1249::Storage.Misc.excCmd::(_log) 'dd if=3D/rhev/da=
ta-center/332694bb-364a-434e-b23f-5fef985d3cbd/mastersd/dom_md/inbox if=
lag=3Ddirect,fullblock count=3D1 bs=3D1024000' (cwd None)</font><br>
<font size=3D"2" face=3D"sans-serif">Dummy-1960::DEBUG::2012-09-20 06:4=
7:03,230::__init__::1249::Storage.Misc.excCmd::(_log) SUCCESS: <err&=
gt; =3D '1+0 records in\n1+0 records out\n1024000 bytes (1.0 MB) copied=
, 0.0496138 s, 20.6 MB/s\n'; <rc> =3D 0</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7810::DEBUG::2012-09-20 06:=
47:03,560::BindingXMLRPC::156::vds::(wrapper) [192.168.10.10]</font><br=
...
<font size=3D"2" face=3D"sans-serif">Thread-7810::DEBUG::2012-09-20 06:=
47:03,561::task::588::TaskManager.Task::(_updateState) Task=3D`9bc08c7e=
-010f-45c2-940a-3fd8361785d5`::moving from state init -> state prepa=
ring</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7810::INFO::2012-09-20 06:4=
7:03,561::logUtils::37::dispatcher::(wrapper) Run and protect: getSpmSt=
atus(spUUID=3D'332694bb-364a-434e-b23f-5fef985d3cbd', options=3DNone)</=
font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7810::INFO::2012-09-20 06:4=
7:03,562::logUtils::39::dispatcher::(wrapper) Run and protect: getSpmSt=
atus, Return response: {'spm_st': {'spmId': 3, 'spmStatus': 'SPM', 'spm=
Lver': 0}}</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7810::DEBUG::2012-09-20 06:=
47:03,562::task::1172::TaskManager.Task::(prepare) Task=3D`9bc08c7e-010=
f-45c2-940a-3fd8361785d5`::finished: {'spm_st': {'spmId': 3, 'spmStatus=
': 'SPM', 'spmLver': 0}}</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7810::DEBUG::2012-09-20 06:=
47:03,562::task::588::TaskManager.Task::(_updateState) Task=3D`9bc08c7e=
-010f-45c2-940a-3fd8361785d5`::moving from state preparing -> state =
finished</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7810::DEBUG::2012-09-20 06:=
47:03,562::resourceManager::809::ResourceManager.Owner::(releaseAll) Ow=
ner.releaseAll requests {} resources {}</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7810::DEBUG::2012-09-20 06:=
47:03,562::resourceManager::844::ResourceManager.Owner::(cancelAll) Own=
er.cancelAll requests {}</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7810::DEBUG::2012-09-20 06:=
47:03,563::task::978::TaskManager.Task::(_decref) Task=3D`9bc08c7e-010f=
-45c2-940a-3fd8361785d5`::ref 0 aborting False</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7812::DEBUG::2012-09-20 06:=
47:03,595::BindingXMLRPC::156::vds::(wrapper) [192.168.10.10]</font><br=
...
<font size=3D"2" face=3D"sans-serif">Thread-7812::DEBUG::2012-09-20 06:=
47:03,595::task::588::TaskManager.Task::(_updateState) Task=3D`8e330204=
-753f-422d-b286-a360410806be`::moving from state init -> state prepa=
ring</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7812::INFO::2012-09-20 06:4=
7:03,596::logUtils::37::dispatcher::(wrapper) Run and protect: getStora=
gePoolInfo(spUUID=3D'332694bb-364a-434e-b23f-5fef985d3cbd', options=3DN=
one)</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7812::DEBUG::2012-09-20 06:=
47:03,596::resourceManager::175::ResourceManager.Request::(__init__) Re=
sName=3D`Storage.332694bb-364a-434e-b23f-5fef985d3cbd`ReqID=3D`a7222834=
-3565-4e28-a15f-72692ef664c6`::Request was made in '/usr/share/vdsm/sto=
rage/resourceManager.py' line '485' at 'registerResource'</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7812::DEBUG::2012-09-20 06:=
47:03,596::resourceManager::486::ResourceManager::(registerResource) Tr=
ying to register resource 'Storage.332694bb-364a-434e-b23f-5fef985d3cbd=
' for lock type 'shared'</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7812::DEBUG::2012-09-20 06:=
47:03,597::resourceManager::528::ResourceManager::(registerResource) Re=
source 'Storage.332694bb-364a-434e-b23f-5fef985d3cbd' is free. Now lock=
ing as 'shared' (1 active user)</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7812::DEBUG::2012-09-20 06:=
47:03,597::resourceManager::212::ResourceManager.Request::(grant) ResNa=
me=3D`Storage.332694bb-364a-434e-b23f-5fef985d3cbd`ReqID=3D`a7222834-35=
65-4e28-a15f-72692ef664c6`::Granted request</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7812::DEBUG::2012-09-20 06:=
47:03,597::task::817::TaskManager.Task::(resourceAcquired) Task=3D`8e33=
0204-753f-422d-b286-a360410806be`::_resourcesAcquired: Storage.332694bb=
-364a-434e-b23f-5fef985d3cbd (shared)</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7812::DEBUG::2012-09-20 06:=
47:03,598::task::978::TaskManager.Task::(_decref) Task=3D`8e330204-753f=
-422d-b286-a360410806be`::ref 1 aborting False</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7813::DEBUG::2012-09-20 06:=
47:03,598::BindingXMLRPC::859::vds::(wrapper) client [192.168.10.10]::c=
all vmGetStats with ('509e608c-e657-473a-b031-f0811da96bde',) {}</font>=
<br>
<font size=3D"2" face=3D"sans-serif">Thread-7812::INFO::2012-09-20 06:4=
7:03,599::logUtils::39::dispatcher::(wrapper) Run and protect: getStora=
gePoolInfo, Return response: {'info': {'spm_id': 3, 'master_uuid': '261=
87d25-bfcb-40c7-97d1-667705ad2223', 'name': 'Valeka', 'version': '2', '=
domains': u'26187d25-bfcb-40c7-97d1-667705ad2223:Active,90104c3d-837b-4=
7dd-8c82-dda92eec30d9:Active', 'pool_status': 'connected', 'isoprefix':=
 u'/rhev/data-center/332694bb-364a-434e-b23f-5fef985d3cbd/90104c3d-837b=
-47dd-8c82-dda92eec30d9/images/11111111-1111-1111-1111-111111111111', '=
type': 'ISCSI', 'master_ver': 1, 'lver': 0}, 'dominfo': {u'26187d25-bfc=
b-40c7-97d1-667705ad2223': {'status': u'Active', 'diskfree': '167409772=
1344', 'alerts': [], 'disktotal': '1799591297024'}, u'90104c3d-837b-47d=
d-8c82-dda92eec30d9': {'status': u'Active', 'diskfree': '423518535680',=
 'alerts': [], 'disktotal': '492264226816'}}}</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7813::DEBUG::2012-09-20 06:=
47:03,600::BindingXMLRPC::865::vds::(wrapper) return vmGetStats with {'=
status': {'message': 'Done', 'code': 0}, 'statsList': [{'status': 'Down=
', 'hash': '0', 'exitMessage': 'unsupported configuration: spice secure=
 channels set in XML configuration, but TLS is disabled in qemu.conf', =
'vmId': '509e608c-e657-473a-b031-f0811da96bde', 'timeOffset': '-1', 'ex=
itCode': 1}]}</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7812::DEBUG::2012-09-20 06:=
47:03,600::task::1172::TaskManager.Task::(prepare) Task=3D`8e330204-753=
f-422d-b286-a360410806be`::finished: {'info': {'spm_id': 3, 'master_uui=
d': '26187d25-bfcb-40c7-97d1-667705ad2223', 'name': 'Valeka', 'version'=
: '2', 'domains': u'26187d25-bfcb-40c7-97d1-667705ad2223:Active,90104c3=
d-837b-47dd-8c82-dda92eec30d9:Active', 'pool_status': 'connected', 'iso=
prefix': u'/rhev/data-center/332694bb-364a-434e-b23f-5fef985d3cbd/90104=
c3d-837b-47dd-8c82-dda92eec30d9/images/11111111-1111-1111-1111-11111111=
1111', 'type': 'ISCSI', 'master_ver': 1, 'lver': 0}, 'dominfo': {u'2618=
7d25-bfcb-40c7-97d1-667705ad2223': {'status': u'Active', 'diskfree': '1=
674097721344', 'alerts': [], 'disktotal': '1799591297024'}, u'90104c3d-=
837b-47dd-8c82-dda92eec30d9': {'status': u'Active', 'diskfree': '423518=
535680', 'alerts': [], 'disktotal': '492264226816'}}}</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7812::DEBUG::2012-09-20 06:=
47:03,601::task::588::TaskManager.Task::(_updateState) Task=3D`8e330204=
-753f-422d-b286-a360410806be`::moving from state preparing -> state =
finished</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7812::DEBUG::2012-09-20 06:=
47:03,601::resourceManager::809::ResourceManager.Owner::(releaseAll) Ow=
ner.releaseAll requests {} resources {'Storage.332694bb-364a-434e-b23f-=
5fef985d3cbd': < ResourceRef 'Storage.332694bb-364a-434e-b23f-5fef98=
5d3cbd', isValid: 'True' obj: 'None'>}</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7812::DEBUG::2012-09-20 06:=
47:03,601::resourceManager::844::ResourceManager.Owner::(cancelAll) Own=
er.cancelAll requests {}</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7812::DEBUG::2012-09-20 06:=
47:03,602::resourceManager::538::ResourceManager::(releaseResource) Try=
ing to release resource 'Storage.332694bb-364a-434e-b23f-5fef985d3cbd'<=
/font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7812::DEBUG::2012-09-20 06:=
47:03,602::resourceManager::553::ResourceManager::(releaseResource) Rel=
eased resource 'Storage.332694bb-364a-434e-b23f-5fef985d3cbd' (0 active=
 users)</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7812::DEBUG::2012-09-20 06:=
47:03,602::resourceManager::558::ResourceManager::(releaseResource) Res=
ource 'Storage.332694bb-364a-434e-b23f-5fef985d3cbd' is free, finding o=
ut if anyone is waiting for it.</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7812::DEBUG::2012-09-20 06:=
47:03,602::resourceManager::565::ResourceManager::(releaseResource) No =
one is waiting for resource 'Storage.332694bb-364a-434e-b23f-5fef985d3c=
bd', Clearing records.</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7812::DEBUG::2012-09-20 06:=
47:03,602::task::978::TaskManager.Task::(_decref) Task=3D`8e330204-753f=
-422d-b286-a360410806be`::ref 0 aborting False</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7814::DEBUG::2012-09-20 06:=
47:03,658::BindingXMLRPC::859::vds::(wrapper) client [192.168.10.10]::c=
all vmDestroy with ('509e608c-e657-473a-b031-f0811da96bde',) {}</font><=
br>
<font size=3D"2" face=3D"sans-serif">Thread-7814::INFO::2012-09-20 06:4=
7:03,658::API::317::vds::(destroy) vmContainerLock acquired by vm 509e6=
08c-e657-473a-b031-f0811da96bde</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7814::DEBUG::2012-09-20 06:=
47:03,658::libvirtvm::2085::vm.Vm::(destroy) vmId=3D`509e608c-e657-473a=
-b031-f0811da96bde`::destroy Called</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7814::INFO::2012-09-20 06:4=
7:03,658::libvirtvm::2040::vm.Vm::(releaseVm) vmId=3D`509e608c-e657-473=
a-b031-f0811da96bde`::Release VM resources</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7814::WARNING::2012-09-20 0=
6:47:03,659::vm::328::vm.Vm::(_set_lastStatus) vmId=3D`509e608c-e657-47=
3a-b031-f0811da96bde`::trying to set state to Powering down when alread=
y Down</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7814::DEBUG::2012-09-20 06:=
47:03,659::__init__::1249::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -=
n /usr/sbin/service ksmtuned retune' (cwd None)</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7814::DEBUG::2012-09-20 06:=
47:03,696::__init__::1249::Storage.Misc.excCmd::(_log) FAILED: <err&=
gt; =3D 'Redirecting to /bin/systemctl retune  ksmtuned.service\nUnknow=
n operation retune\n'; <rc> =3D 1</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7814::DEBUG::2012-09-20 06:=
47:03,697::task::588::TaskManager.Task::(_updateState) Task=3D`e97820bb=
-547d-4e7a-9249-ece94285bac8`::moving from state init -> state prepa=
ring</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7814::INFO::2012-09-20 06:4=
7:03,698::logUtils::37::dispatcher::(wrapper) Run and protect: inapprop=
riateDevices(thiefId=3D'509e608c-e657-473a-b031-f0811da96bde')</font><b=
r>
<font size=3D"2" face=3D"sans-serif">Thread-7814::INFO::2012-09-20 06:4=
7:03,699::logUtils::39::dispatcher::(wrapper) Run and protect: inapprop=
riateDevices, Return response: None</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7814::DEBUG::2012-09-20 06:=
47:03,699::task::1172::TaskManager.Task::(prepare) Task=3D`e97820bb-547=
d-4e7a-9249-ece94285bac8`::finished: None</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7814::DEBUG::2012-09-20 06:=
47:03,700::task::588::TaskManager.Task::(_updateState) Task=3D`e97820bb=
-547d-4e7a-9249-ece94285bac8`::moving from state preparing -> state =
finished</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7814::DEBUG::2012-09-20 06:=
47:03,700::resourceManager::809::ResourceManager.Owner::(releaseAll) Ow=
ner.releaseAll requests {} resources {}</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7814::DEBUG::2012-09-20 06:=
47:03,700::resourceManager::844::ResourceManager.Owner::(cancelAll) Own=
er.cancelAll requests {}</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7814::DEBUG::2012-09-20 06:=
47:03,700::task::978::TaskManager.Task::(_decref) Task=3D`e97820bb-547d=
-4e7a-9249-ece94285bac8`::ref 0 aborting False</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7814::DEBUG::2012-09-20 06:=
47:03,700::libvirtvm::2080::vm.Vm::(deleteVm) vmId=3D`509e608c-e657-473=
a-b031-f0811da96bde`::Total desktops after destroy of 509e608c-e657-473=
a-b031-f0811da96bde is 0</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7814::DEBUG::2012-09-20 06:=
47:03,701::BindingXMLRPC::865::vds::(wrapper) return vmDestroy with {'s=
tatus': {'message': 'Machine destroyed', 'code': 0}}</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-481::DEBUG::2012-09-20 06:4=
7:04,302::__init__::1249::Storage.Misc.excCmd::(_log) '/usr/bin/dd ifla=
g=3Ddirect if=3D/dev/26187d25-bfcb-40c7-97d1-667705ad2223/metadata bs=3D=
4096 count=3D1' (cwd None)</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-481::DEBUG::2012-09-20 06:4=
7:04,317::__init__::1249::Storage.Misc.excCmd::(_log) SUCCESS: <err&=
gt; =3D '1+0 records in\n1+0 records out\n4096 bytes (4.1 kB) copied, 0=
.000843551 s, 4.9 MB/s\n'; <rc> =3D 0</font><br>
<font size=3D"2" face=3D"sans-serif">Dummy-1960::DEBUG::2012-09-20 06:4=
7:05,239::__init__::1249::Storage.Misc.excCmd::(_log) 'dd if=3D/rhev/da=
ta-center/332694bb-364a-434e-b23f-5fef985d3cbd/mastersd/dom_md/inbox if=
lag=3Ddirect,fullblock count=3D1 bs=3D1024000' (cwd None)</font><br>
<font size=3D"2" face=3D"sans-serif">Dummy-1960::DEBUG::2012-09-20 06:4=
7:05,323::__init__::1249::Storage.Misc.excCmd::(_log) SUCCESS: <err&=
gt; =3D '1+0 records in\n1+0 records out\n1024000 bytes (1.0 MB) copied=
, 0.0476578 s, 21.5 MB/s\n'; <rc> =3D 0</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7815::DEBUG::2012-09-20 06:=
47:05,819::task::588::TaskManager.Task::(_updateState) Task=3D`ef5f39d0=
-241c-44b5-a771-da364468b498`::moving from state init -> state prepa=
ring</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7815::INFO::2012-09-20 06:4=
7:05,819::logUtils::37::dispatcher::(wrapper) Run and protect: repoStat=
s(options=3DNone)</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7815::INFO::2012-09-20 06:4=
7:05,820::logUtils::39::dispatcher::(wrapper) Run and protect: repoStat=
s, Return response: {'26187d25-bfcb-40c7-97d1-667705ad2223': {'delay': =
'0.0156102180481', 'lastCheck': 1348123624.512314, 'code': 0, 'valid': =
True}, '90104c3d-837b-47dd-8c82-dda92eec30d9': {'delay': '0.00118303298=
95', 'lastCheck': 1348123617.41074, 'code': 0, 'valid': True}}</font><b=
r>
<font size=3D"2" face=3D"sans-serif">Thread-7815::DEBUG::2012-09-20 06:=
47:05,820::task::1172::TaskManager.Task::(prepare) Task=3D`ef5f39d0-241=
c-44b5-a771-da364468b498`::finished: {'26187d25-bfcb-40c7-97d1-667705ad=
2223': {'delay': '0.0156102180481', 'lastCheck': 1348123624.512314, 'co=
de': 0, 'valid': True}, '90104c3d-837b-47dd-8c82-dda92eec30d9': {'delay=
': '0.0011830329895', 'lastCheck': 1348123617.41074, 'code': 0, 'valid'=
: True}}</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7815::DEBUG::2012-09-20 06:=
47:05,820::task::588::TaskManager.Task::(_updateState) Task=3D`ef5f39d0=
-241c-44b5-a771-da364468b498`::moving from state preparing -> state =
finished</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7815::DEBUG::2012-09-20 06:=
47:05,820::resourceManager::809::ResourceManager.Owner::(releaseAll) Ow=
ner.releaseAll requests {} resources {}</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7815::DEBUG::2012-09-20 06:=
47:05,821::resourceManager::844::ResourceManager.Owner::(cancelAll) Own=
er.cancelAll requests {}</font><br>
<font size=3D"2" face=3D"sans-serif">Thread-7815::DEBUG::2012-09-20 06:=
47:05,821::task::978::TaskManager.Task::(_decref) Task=3D`ef5f39d0-241c=
-44b5-a771-da364468b498`::ref 0 aborting False</font><br>
<font size=3D"2" face=3D"sans-serif">Dummy-1960::DEBUG::2012-09-20 06:4=
7:07,332::__init__::1249::Storage.Misc.excCmd::(_log) 'dd if=3D/rhev/da=
ta-center/332694bb-364a-434e-b23f-5fef985d3cbd/mastersd/dom_md/inbox if=
lag=3Ddirect,fullblock count=3D1 bs=3D1024000' (cwd None)</font><br>
<font size=3D"2" face=3D"sans-serif">Dummy-1960::DEBUG::2012-09-20 06:4=
7:07,458::__init__::1249::Storage.Misc.excCmd::(_log) SUCCESS: <err&=
gt; =3D '1+0 records in\n1+0 records out\n1024000 bytes (1.0 MB) copied=
, 0.0478973 s, 21.4 MB/s\n'; <rc> =3D 0</font><br>
<font size=3D"2" face=3D"sans-serif">Dummy-1960::DEBUG::2012-09-20 06:4=
7:09,502::__init__::1249::Storage.Misc.excCmd::(_log) 'dd if=3D/rhev/da=
ta-center/332694bb-364a-434e-b23f-5fef985d3cbd/mastersd/dom_md/inbox if=
lag=3Ddirect,fullblock count=3D1 bs=3D1024000' (cwd None)</font><br>
<font size=3D"2" face=3D"sans-serif">Dummy-1960::DEBUG::2012-09-20 06:4=
7:09,586::__init__::1249::Storage.Misc.excCmd::(_log) SUCCESS: <err&=
gt; =3D '1+0 records in\n1+0 records out\n1024000 bytes (1.0 MB) copied=
, 0.0485543 s, 21.1 MB/s\n'; <rc> =3D 0</font><br>
<br>
<font size=3D"2" face=3D"sans-serif">If I try to create new server I ha=
ve the same error message.</font><br>
<font size=3D"2" face=3D"sans-serif"><br>
- -<br>
Dmitriy Pyryakov</font>
<ul style=3D"padding-left: 0pt"><font size=3D"2" face=3D"sans-serif">Vi=
mpelCom Ltd.</font></ul>
</body></html>=

--0__=C9BBF0ECDFB7B2218f9e8a93df938690918cC9BBF0ECDFB7B221--

[Users] Host migration problem

Dmitriy A Pyryakov