[Users] Migration and creating VM failing

24 Jul 2013

      Hello,

we have one node based on centos 6.4 and using ovirt-stable chanel and 
it can not start VM or accept migration. (May I try updating to ovirt 
3.3 beta?)

Here is log:

Thread-2973::DEBUG::2013-07-24 
18:37:20,415::task::568::TaskManager.Task::(_updateState) 
Task=`9b957784-995f-48bd-b181-a23b991787e1`::moving from state init -> 
state preparing
Thread-2973::INFO::2013-07-24 
18:37:20,416::logUtils::41::dispatcher::(wrapper) Run and protect: 
repoStats(options=None)
Thread-2973::INFO::2013-07-24 
18:37:20,416::logUtils::44::dispatcher::(wrapper) Run and protect: 
repoStats, Return response: {u'0ee30f68-c222-44c0-85e6-2ae246f4c1ec': 
{'delay': '0.0137450695038', 'lastCheck': '7.3', 'code': 0, 'valid': 
True}, u'a8c13187-d9d1-46b8-abe3-c322970d9d4d': {'delay': 
'0.00467395782471', 'lastCheck': '5.4', 'code': 0, 'valid': True}}
Thread-2973::DEBUG::2013-07-24 
18:37:20,416::task::1151::TaskManager.Task::(prepare) 
Task=`9b957784-995f-48bd-b181-a23b991787e1`::finished: 
{u'0ee30f68-c222-44c0-85e6-2ae246f4c1ec': {'delay': '0.0137450695038', 
'lastCheck': '7.3', 'code': 0, 'valid': True}, 
u'a8c13187-d9d1-46b8-abe3-c322970d9d4d': {'delay': '0.00467395782471', 
'lastCheck': '5.4', 'code': 0, 'valid': True}}
Thread-2973::DEBUG::2013-07-24 
18:37:20,416::task::568::TaskManager.Task::(_updateState) 
Task=`9b957784-995f-48bd-b181-a23b991787e1`::moving from state preparing 
-> state finished
Thread-2973::DEBUG::2013-07-24 
18:37:20,417::resourceManager::830::ResourceManager.Owner::(releaseAll) 
Owner.releaseAll requests {} resources {}
Thread-2973::DEBUG::2013-07-24 
18:37:20,417::resourceManager::864::ResourceManager.Owner::(cancelAll) 
Owner.cancelAll requests {}
Thread-2973::DEBUG::2013-07-24 
18:37:20,417::task::957::TaskManager.Task::(_decref) 
Task=`9b957784-995f-48bd-b181-a23b991787e1`::ref 0 aborting False
Thread-68::DEBUG::2013-07-24 
18:37:23,123::misc::84::Storage.Misc.excCmd::(<lambda>) '/bin/dd 
iflag=direct if=/dev/0ee30f68-c222-44c0-85e6-2ae246f4c1ec/metadata 
bs=4096 count=1' (cwd None)
Thread-68::DEBUG::2013-07-24 
18:37:23,135::misc::84::Storage.Misc.excCmd::(<lambda>) SUCCESS: <err> = 
'1+0 records in\n1+0 records out\n4096 bytes (4.1 kB) copied, 
0.000485541 s, 8.4 MB/s\n'; <rc> = 0
Thread-2979::DEBUG::2013-07-24 
18:37:30,600::task::568::TaskManager.Task::(_updateState) 
Task=`12b753a3-ca6e-48e2-9888-2e9c71f0c490`::moving from state init -> 
state preparing
Thread-2979::INFO::2013-07-24 
18:37:30,601::logUtils::41::dispatcher::(wrapper) Run and protect: 
repoStats(options=None)
Thread-2979::INFO::2013-07-24 
18:37:30,601::logUtils::44::dispatcher::(wrapper) Run and protect: 
repoStats, Return response: {u'0ee30f68-c222-44c0-85e6-2ae246f4c1ec': 
{'delay': '0.0136978626251', 'lastCheck': '7.5', 'code': 0, 'valid': 
True}, u'a8c13187-d9d1-46b8-abe3-c322970d9d4d': {'delay': 
'0.00459504127502', 'lastCheck': '5.6', 'code': 0, 'valid': True}}
Thread-2979::DEBUG::2013-07-24 
18:37:30,601::task::1151::TaskManager.Task::(prepare) 
Task=`12b753a3-ca6e-48e2-9888-2e9c71f0c490`::finished: 
{u'0ee30f68-c222-44c0-85e6-2ae246f4c1ec': {'delay': '0.0136978626251', 
'lastCheck': '7.5', 'code': 0, 'valid': True}, 
u'a8c13187-d9d1-46b8-abe3-c322970d9d4d': {'delay': '0.00459504127502', 
'lastCheck': '5.6', 'code': 0, 'valid': True}}
Thread-2979::DEBUG::2013-07-24 
18:37:30,601::task::568::TaskManager.Task::(_updateState) 
Task=`12b753a3-ca6e-48e2-9888-2e9c71f0c490`::moving from state preparing 
-> state finished
Thread-2979::DEBUG::2013-07-24 
18:37:30,601::resourceManager::830::ResourceManager.Owner::(releaseAll) 
Owner.releaseAll requests {} resources {}
Thread-2979::DEBUG::2013-07-24 
18:37:30,601::resourceManager::864::ResourceManager.Owner::(cancelAll) 
Owner.cancelAll requests {}
Thread-2979::DEBUG::2013-07-24 
18:37:30,602::task::957::TaskManager.Task::(_decref) 
Task=`12b753a3-ca6e-48e2-9888-2e9c71f0c490`::ref 0 aborting False
Thread-68::DEBUG::2013-07-24 
18:37:33,140::misc::84::Storage.Misc.excCmd::(<lambda>) '/bin/dd 
iflag=direct if=/dev/0ee30f68-c222-44c0-85e6-2ae246f4c1ec/metadata 
bs=4096 count=1' (cwd None)
Thread-68::DEBUG::2013-07-24 
18:37:33,151::misc::84::Storage.Misc.excCmd::(<lambda>) SUCCESS: <err> = 
'1+0 records in\n1+0 records out\n4096 bytes (4.1 kB) copied, 0.0004116 
s, 10.0 MB/s\n'; <rc> = 0
Thread-2983::DEBUG::2013-07-24 
18:37:35,734::BindingXMLRPC::913::vds::(wrapper) client 
[192.168.3.207]::call vmGetStats with 
('03ac5be8-75fc-43df-9fb8-c8e8af30ae84',) {}
Thread-2983::DEBUG::2013-07-24 
18:37:35,734::BindingXMLRPC::920::vds::(wrapper) return vmGetStats with 
{'status': {'message': 'Virtual machine does not exist', 'code': 1}}
Thread-2984::DEBUG::2013-07-24 
18:37:35,880::BindingXMLRPC::913::vds::(wrapper) client 
[192.168.3.207]::call vmMigrationCreate with ({'username': 'Unknown', 
'acpiEnable': 'true', 'emulatedMachine': 'pc-0.14', 
'afterMigrationStatus': 'Up', 'vmId': 
'03ac5be8-75fc-43df-9fb8-c8e8af30ae84', 'transparentHugePages': 'true', 
'displaySecurePort': '5913', 'timeOffset': '-43200', 'cpuType': 
'Opteron_G3', 'custom': {'device_d7b86bcd-13fe-4259-b7a1-0e6243bf8aca': 
'VmDevice {vmId=03ac5be8-75fc-43df-9fb8-c8e8af30ae84, 
deviceId=d7b86bcd-13fe-4259-b7a1-0e6243bf8aca, device=ide, 
type=controller, bootOrder=0, specParams={}, address={bus=0x00, 
domain=0x0000, type=pci, slot=0x01, function=0x1}, managed=false, 
plugged=true, readOnly=false, deviceAlias=ide0}', 
'device_d7b86bcd-13fe-4259-b7a1-0e6243bf8acadevice_d15dafa0-a1ae-4637-bd9b-6708a31f7e41device_f68176fc-0731-4d98-9f35-b31140dcf568device_e9769f4d-b137-4560-8eed-230655922bfadevice_4b6fd867-b4f3-47f6-b6ef-1f3cd0ed9c34': 
'VmDevice {vmId=03ac5be8-75fc-43df-9fb8-c8e8af30ae84, 
deviceId=4b6fd867-b4f3-47f6-b6ef-1f3cd0ed9c34, device=spicevmc, 
type=channel, bootOrder=0, specParams={}, address={port=3, bus=0, 
controller=0, type=virtio-serial}, managed=false, plugged=true, 
readOnly=false, deviceAlias=channel2}', 
'device_d7b86bcd-13fe-4259-b7a1-0e6243bf8acadevice_d15dafa0-a1ae-4637-bd9b-6708a31f7e41device_f68176fc-0731-4d98-9f35-b31140dcf568device_e9769f4d-b137-4560-8eed-230655922bfa': 
'VmDevice {vmId=03ac5be8-75fc-43df-9fb8-c8e8af30ae84, 
deviceId=e9769f4d-b137-4560-8eed-230655922bfa, device=unix, 
type=channel, bootOrder=0, specParams={}, address={port=2, bus=0, 
controller=0, type=virtio-serial}, managed=false, plugged=true, 
readOnly=false, deviceAlias=channel1}', 
'device_d7b86bcd-13fe-4259-b7a1-0e6243bf8acadevice_d15dafa0-a1ae-4637-bd9b-6708a31f7e41device_f68176fc-0731-4d98-9f35-b31140dcf568': 
'VmDevice {vmId=03ac5be8-75fc-43df-9fb8-c8e8af30ae84, 
deviceId=f68176fc-0731-4d98-9f35-b31140dcf568, device=unix, 
type=channel, bootOrder=0, specParams={}, address={port=1, bus=0, 
controller=0, type=virtio-serial}, managed=false, plugged=true, 
readOnly=false, deviceAlias=channel0}', 
'device_d7b86bcd-13fe-4259-b7a1-0e6243bf8acadevice_d15dafa0-a1ae-4637-bd9b-6708a31f7e41': 
'VmDevice {vmId=03ac5be8-75fc-43df-9fb8-c8e8af30ae84, 
deviceId=d15dafa0-a1ae-4637-bd9b-6708a31f7e41, device=virtio-serial, 
type=controller, bootOrder=0, specParams={}, address={bus=0x00, 
domain=0x0000, type=pci, slot=0x04, function=0x0}, managed=false, 
plugged=true, readOnly=false, deviceAlias=virtio-serial0}'}, 
'migrationDest': 'libvirt', 'smp': '2', 'vmType': 'kvm', 
'spiceSslCipherSuite': 'DEFAULT', '_srcDomXML': "<domain type='kvm' 
id='18'>\n  <name>ipa2.nbu.cz</name>\n 
<uuid>03ac5be8-75fc-43df-9fb8-c8e8af30ae84</uuid>\n <memory 
unit='KiB'>2097152</memory>\n  <currentMemory 
unit='KiB'>2097152</currentMemory>\n  <vcpu 
placement='static'>2</vcpu>\n  <cputune>\n <shares>1020</shares>\n  
</cputune>\n  <sysinfo type='smbios'>\n    <system>\n      <entry 
name='manufacturer'>oVirt</entry>\n      <entry name='product'>oVirt 
Node</entry>\n      <entry 
name='version'>2.6.1-20120228.fc18</entry>\n      <entry 
name='serial'>35373031-3032-435A-4339-343331444B46</entry>\n <entry 
name='uuid'>03ac5be8-75fc-43df-9fb8-c8e8af30ae84</entry>\n </system>\n  
</sysinfo>\n  <os>\n    <type arch='x86_64' 
machine='pc-0.14'>hvm</type>\n    <boot dev='hd'/>\n    <smbios 
mode='sysinfo'/>\n  </os>\n <features>\n    <acpi/>\n  </features>\n  
<cpu mode='custom' match='exact'>\n    <model 
fallback='allow'>Opteron_G3</model>\n    <topology sockets='2' cores='1' 
threads='1'/>\n  </cpu>\n  <clock offset='variable' adjustment='-43200' 
basis='utc'>\n    <timer name='rtc' tickpolicy='catchup'/>\n  </clock>\n 
<on_poweroff>destroy</on_poweroff>\n <on_reboot>restart</on_reboot>\n 
<on_crash>destroy</on_crash>\n  <devices>\n 
<emulator>/usr/bin/qemu-kvm</emulator>\n    <disk type='file' 
device='cdrom'>\n      <driver name='qemu' type='raw'/>\n      <source 
startupPolicy='optional'/>\n      <target dev='hdc' bus='ide'/>\n      
<readonly/>\n <serial></serial>\n      <alias name='ide0-1-0'/>\n      
<address type='drive' controller='0' bus='1' target='0' unit='0'/>\n    
</disk>\n    <disk type='block' device='disk' snapshot='no'>\n      
<driver name='qemu' type='qcow2' cache='none' error_policy='stop' 
io='native'/>\n      <source 
dev='/rhev/data-center/5849b030-626e-47cb-ad90-3ce782d831b3/0ee30f68-c222-44c0-85e6-2ae246f4c1ec/images/975f7398-866e-43f6-8579-1552be81519d/ebce7305-2586-4c5d-bc02-08cc4743a983'/>\n 
<target dev='vda' bus='virtio'/>\n 
<serial>975f7398-866e-43f6-8579-1552be81519d</serial>\n <alias 
name='virtio-disk0'/>\n      <address type='pci' domain='0x0000' 
bus='0x00' slot='0x05' function='0x0'/>\n </disk>\n    <controller 
type='usb' index='0'>\n <alias name='usb0'/>\n      <address type='pci' 
domain='0x0000' bus='0x00' slot='0x01' function='0x2'/>\n 
</controller>\n    <controller type='ide' index='0'>\n      <alias 
name='ide0'/>\n      <address type='pci' domain='0x0000' bus='0x00' 
slot='0x01' function='0x1'/>\n    </controller>\n    <controller 
type='virtio-serial' index='0'>\n      <alias 
name='virtio-serial0'/>\n      <address type='pci' domain='0x0000' 
bus='0x00' slot='0x04' function='0x0'/>\n </controller>\n    <interface 
type='bridge'>\n <mac address='00:1a:4a:a8:03:9e'/>\n      <source 
bridge='ovirtmgmt'/>\n      <target dev='vnet7'/>\n <model 
type='virtio'/>\n      <filterref filter='vdsm-no-mac-spoofing'/>\n      
<link state='up'/>\n      <alias name='net0'/>\n      <address 
type='pci' domain='0x0000' bus='0x00' slot='0x03' function='0x0'/>\n    
</interface>\n    <channel type='unix'>\n      <source mode='bind' 
path='/var/lib/libvirt/qemu/channels/ipa2.nbu.cz.com.redhat.rhevm.vdsm'/>\n 
<target type='virtio' name='com.redhat.rhevm.vdsm'/>\n <alias 
name='channel0'/>\n      <address type='virtio-serial' controller='0' 
bus='0' port='1'/>\n </channel>\n    <channel type='unix'>\n      
<source mode='bind' 
path='/var/lib/libvirt/qemu/channels/ipa2.nbu.cz.org.qemu.guest_agent.0'/>\n 
<target type='virtio' name='org.qemu.guest_agent.0'/>\n <alias 
name='channel1'/>\n      <address type='virtio-serial' controller='0' 
bus='0' port='2'/>\n </channel>\n    <channel type='spicevmc'>\n <target 
type='virtio' name='com.redhat.spice.0'/>\n <alias 
name='channel2'/>\n      <address type='virtio-serial' controller='0' 
bus='0' port='3'/>\n </channel>\n    <input type='mouse' bus='ps2'/>\n 
<graphics type='spice' port='5912' tlsPort='5913' autoport='yes' 
listen='0' keymap='en-us' passwdValidTo='1970-01-01T00:00:01'>\n      
<listen type='address' address='0'/>\n      <channel name='main' 
mode='secure'/>\n      <channel name='display' mode='secure'/>\n      
<channel name='inputs' mode='secure'/>\n      <channel name='cursor' 
mode='secure'/>\n      <channel name='playback' mode='secure'/>\n      
<channel name='record' mode='secure'/>\n      <channel name='smartcard' 
mode='secure'/>\n      <channel name='usbredir' mode='secure'/>\n    
</graphics>\n    <video>\n <model type='qxl' vram='65536' 
heads='1'/>\n      <alias name='video0'/>\n      <address type='pci' 
domain='0x0000' bus='0x00' slot='0x02' function='0x0'/>\n    </video>\n 
<memballoon model='virtio'>\n      <alias name='balloon0'/>\n      
<address type='pci' domain='0x0000' bus='0x00' slot='0x06' 
function='0x0'/>\n </memballoon>\n  </devices>\n  <seclabel 
type='dynamic' model='selinux' relabel='yes'>\n 
<label>system_u:system_r:svirt_t:s0:c333,c972</label>\n 
<imagelabel>system_u:object_r:svirt_image_t:s0:c333,c972</imagelabel>\n 
</seclabel>\n</domain>\n", 'memSize': 2048, 'elapsedTimeOffset': 
23573.797423124313, 'vmName': 'ipa2.nbu.cz', 'nice': '0', 'status': 
'Up', 'clientIp': '', 'displayIp': '0', 'displayPort': '5912', 
'smpCoresPerSocket': '1', 'smartcardEnable': 'false', 'guestIPs': '', 
'nicModel': 'rtl8139,pv', 'keyboardLayout': 'en-us', 'kvmEnable': 
'true', 'pitReinjection': 'false', 'devices': [{'specParams': {'vram': 
'65536'}, 'alias': 'video0', 'deviceId': 
'a74682a1-e49b-4c3c-a65a-679036bbd6f6', 'address': {'slot': '0x02', 
'bus': '0x00', 'domain': '0x0000', 'type': 'pci', 'function': '0x0'}, 
'device': 'qxl', 'type': 'video'}, {'nicModel': 'pv', 'macAddr': 
'00:1a:4a:a8:03:9e', 'linkActive': True, 'network': 'ovirtmgmt', 
'specParams': {}, 'filter': 'vdsm-no-mac-spoofing', 'alias': 'net0', 
'deviceId': '405d2d7f-cbe4-4a8c-aeaa-b6d11c0739fd', 'address': {'slot': 
'0x03', 'bus': '0x00', 'domain': '0x0000', 'type': 'pci', 'function': 
'0x0'}, 'device': 'bridge', 'type': 'interface', 'name': 'vnet7'}, 
{'index': '2', 'iface': 'ide', 'name': 'hdc', 'alias': 'ide0-1-0', 
'shared': 'false', 'specParams': {'path': ''}, 'readonly': 'True', 
'deviceId': 'f3399625-142a-44ed-897d-01b2fad56a89', 'address': {'bus': 
'1', 'controller': '0', 'type': 'drive', 'target': '0', 'unit': '0'}, 
'device': 'cdrom', 'path': '', 'type': 'disk'}, {'address': {'slot': 
'0x05', 'bus': '0x00', 'domain': '0x0000', 'type': 'pci', 'function': 
'0x0'}, 'index': 0, 'iface': 'virtio', 'apparentsize': '7516192768', 
'alias': 'virtio-disk0', 'imageID': 
'975f7398-866e-43f6-8579-1552be81519d', 'readonly': 'False', 'shared': 
'false', 'truesize': '7516192768', 'type': 'disk', 'domainID': 
'0ee30f68-c222-44c0-85e6-2ae246f4c1ec', 'reqsize': '0', 'format': 'cow', 
'deviceId': '975f7398-866e-43f6-8579-1552be81519d', 'poolID': 
'5849b030-626e-47cb-ad90-3ce782d831b3', 'device': 'disk', 'path': 
'/rhev/data-center/5849b030-626e-47cb-ad90-3ce782d831b3/0ee30f68-c222-44c0-85e6-2ae246f4c1ec/images/975f7398-866e-43f6-8579-1552be81519d/ebce7305-2586-4c5d-bc02-08cc4743a983', 
'propagateErrors': 'off', 'optional': 'false', 'name': 'vda', 
'volumeID': 'ebce7305-2586-4c5d-bc02-08cc4743a983', 'specParams': {}, 
'volumeChain': [{'path': 
'/rhev/data-center/5849b030-626e-47cb-ad90-3ce782d831b3/0ee30f68-c222-44c0-85e6-2ae246f4c1ec/images/975f7398-866e-43f6-8579-1552be81519d/ebce7305-2586-4c5d-bc02-08cc4743a983', 
'domainID': '0ee30f68-c222-44c0-85e6-2ae246f4c1ec', 'volumeID': 
'ebce7305-2586-4c5d-bc02-08cc4743a983', 'imageID': 
'975f7398-866e-43f6-8579-1552be81519d'}]}, {'target': 2097152, 
'specParams': {'model': 'virtio'}, 'alias': 'balloon0', 'deviceId': 
'c25a298c-698f-41ff-8968-12e6ed9b14fe', 'address': {'slot': '0x06', 
'bus': '0x00', 'domain': '0x0000', 'type': 'pci', 'function': '0x0'}, 
'device': 'memballoon', 'type': 'balloon'}, {'device': 'usb', 'alias': 
'usb0', 'type': 'controller', 'address': {'slot': '0x01', 'bus': '0x00', 
'domain': '0x0000', 'type': 'pci', 'function': '0x2'}}, {'device': 
'ide', 'alias': 'ide0', 'type': 'controller', 'address': {'slot': 
'0x01', 'bus': '0x00', 'domain': '0x0000', 'type': 'pci', 'function': 
'0x1'}}, {'device': 'virtio-serial', 'alias': 'virtio-serial0', 'type': 
'controller', 'address': {'slot': '0x04', 'bus': '0x00', 'domain': 
'0x0000', 'type': 'pci', 'function': '0x0'}}, {'device': 'unix', 
'alias': 'channel0', 'type': 'channel', 'address': {'bus': '0', 
'controller': '0', 'type': 'virtio-serial', 'port': '1'}}, {'device': 
'unix', 'alias': 'channel1', 'type': 'channel', 'address': {'bus': '0', 
'controller': '0', 'type': 'virtio-serial', 'port': '2'}}, {'device': 
'spicevmc', 'alias': 'channel2', 'type': 'channel', 'address': {'bus': 
'0', 'controller': '0', 'type': 'virtio-serial', 'port': '3'}}], 
'spiceSecureChannels': 
'smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard', 
'display': 'qxl'},) {}
Thread-2984::DEBUG::2013-07-24 
18:37:35,880::API::489::vds::(migrationCreate) Migration create
Thread-2984::INFO::2013-07-24 
18:37:35,880::API::626::vds::(_getNetworkIp) network None: using 0
Thread-2984::INFO::2013-07-24 
18:37:35,881::clientIF::334::vds::(createVm) vmContainerLock acquired by 
vm 03ac5be8-75fc-43df-9fb8-c8e8af30ae84
Thread-2984::DEBUG::2013-07-24 
18:37:35,885::clientIF::348::vds::(createVm) Total desktops after 
creation of 03ac5be8-75fc-43df-9fb8-c8e8af30ae84 is 1
Thread-2985::DEBUG::2013-07-24 
18:37:35,885::vm::671::vm.Vm::(_startUnderlyingVm) 
vmId=`03ac5be8-75fc-43df-9fb8-c8e8af30ae84`::Start
Thread-2984::DEBUG::2013-07-24 
18:37:35,886::libvirtvm::3107::vm.Vm::(waitForMigrationDestinationPrepare) 
vmId=`03ac5be8-75fc-43df-9fb8-c8e8af30ae84`::migration destination: 
waiting for VM creation
Thread-2985::DEBUG::2013-07-24 
18:37:35,886::vm::675::vm.Vm::(_startUnderlyingVm) 
vmId=`03ac5be8-75fc-43df-9fb8-c8e8af30ae84`::_ongoingCreations acquired
Thread-2985::INFO::2013-07-24 
18:37:35,887::libvirtvm::1463::vm.Vm::(_run) 
vmId=`03ac5be8-75fc-43df-9fb8-c8e8af30ae84`::VM wrapper has started
Thread-2984::DEBUG::2013-07-24 
18:37:35,887::libvirtvm::3113::vm.Vm::(waitForMigrationDestinationPrepare) 
vmId=`03ac5be8-75fc-43df-9fb8-c8e8af30ae84`::migration destination: 
waiting 36s for path preparation
Thread-2985::WARNING::2013-07-24 
18:37:35,887::vm::459::vm.Vm::(getConfDevices) 
vmId=`03ac5be8-75fc-43df-9fb8-c8e8af30ae84`::Unknown type found, device: 
'{'device': 'unix', 'alias': 'channel0', 'type': 'channel', 'address': 
{'bus': '0', 'controller': '0', 'type': 'virtio-serial', 'port': '1'}}' 
found
Thread-2985::WARNING::2013-07-24 
18:37:35,888::vm::459::vm.Vm::(getConfDevices) 
vmId=`03ac5be8-75fc-43df-9fb8-c8e8af30ae84`::Unknown type found, device: 
'{'device': 'unix', 'alias': 'channel1', 'type': 'channel', 'address': 
{'bus': '0', 'controller': '0', 'type': 'virtio-serial', 'port': '2'}}' 
found
Thread-2985::WARNING::2013-07-24 
18:37:35,888::vm::459::vm.Vm::(getConfDevices) 
vmId=`03ac5be8-75fc-43df-9fb8-c8e8af30ae84`::Unknown type found, device: 
'{'device': 'spicevmc', 'alias': 'channel2', 'type': 'channel', 
'address': {'bus': '0', 'controller': '0', 'type': 'virtio-serial', 
'port': '3'}}' found
Thread-2985::DEBUG::2013-07-24 
18:37:35,889::task::568::TaskManager.Task::(_updateState) 
Task=`925d13e4-6995-4f8e-9359-6fdb1be2873f`::moving from state init -> 
state preparing
Thread-2985::INFO::2013-07-24 
18:37:35,889::logUtils::41::dispatcher::(wrapper) Run and protect: 
getVolumeSize(sdUUID='0ee30f68-c222-44c0-85e6-2ae246f4c1ec', 
spUUID='5849b030-626e-47cb-ad90-3ce782d831b3', 
imgUUID='975f7398-866e-43f6-8579-1552be81519d', 
volUUID='ebce7305-2586-4c5d-bc02-08cc4743a983', options=None)
Thread-2985::INFO::2013-07-24 
18:37:35,889::logUtils::44::dispatcher::(wrapper) Run and protect: 
getVolumeSize, Return response: {'truesize': '7516192768', 
'apparentsize': '7516192768'}
Thread-2985::DEBUG::2013-07-24 
18:37:35,889::task::1151::TaskManager.Task::(prepare) 
Task=`925d13e4-6995-4f8e-9359-6fdb1be2873f`::finished: {'truesize': 
'7516192768', 'apparentsize': '7516192768'}
Thread-2985::DEBUG::2013-07-24 
18:37:35,890::task::568::TaskManager.Task::(_updateState) 
Task=`925d13e4-6995-4f8e-9359-6fdb1be2873f`::moving from state preparing 
-> state finished
Thread-2985::DEBUG::2013-07-24 
18:37:35,890::resourceManager::830::ResourceManager.Owner::(releaseAll) 
Owner.releaseAll requests {} resources {}
Thread-2985::DEBUG::2013-07-24 
18:37:35,890::resourceManager::864::ResourceManager.Owner::(cancelAll) 
Owner.cancelAll requests {}
Thread-2985::DEBUG::2013-07-24 
18:37:35,890::task::957::TaskManager.Task::(_decref) 
Task=`925d13e4-6995-4f8e-9359-6fdb1be2873f`::ref 0 aborting False
Thread-2985::INFO::2013-07-24 
18:37:35,890::clientIF::316::vds::(prepareVolumePath) prepared volume path:
Thread-2985::DEBUG::2013-07-24 
18:37:35,890::task::568::TaskManager.Task::(_updateState) 
Task=`5011aeeb-7b97-474b-b559-d29f3f6e7a22`::moving from state init -> 
state preparing
Thread-2985::INFO::2013-07-24 
18:37:35,891::logUtils::41::dispatcher::(wrapper) Run and protect: 
prepareImage(sdUUID='0ee30f68-c222-44c0-85e6-2ae246f4c1ec', 
spUUID='5849b030-626e-47cb-ad90-3ce782d831b3', 
imgUUID='975f7398-866e-43f6-8579-1552be81519d', 
volUUID='ebce7305-2586-4c5d-bc02-08cc4743a983')
Thread-2985::DEBUG::2013-07-24 
18:37:35,891::resourceManager::190::ResourceManager.Request::(__init__) 
ResName=`Storage.0ee30f68-c222-44c0-85e6-2ae246f4c1ec`ReqID=`39a62be2-0ecd-4be8-a5e9-00824ea4fa50`::Request 
was made in '/usr/share/vdsm/storage/resourceManager.py' line '189' at 
'__init__'
Thread-2985::DEBUG::2013-07-24 
18:37:35,891::resourceManager::504::ResourceManager::(registerResource) 
Trying to register resource 
'Storage.0ee30f68-c222-44c0-85e6-2ae246f4c1ec' for lock type 'shared'
Thread-2985::DEBUG::2013-07-24 
18:37:35,891::resourceManager::547::ResourceManager::(registerResource) 
Resource 'Storage.0ee30f68-c222-44c0-85e6-2ae246f4c1ec' is free. Now 
locking as 'shared' (1 active user)
Thread-2985::DEBUG::2013-07-24 
18:37:35,892::resourceManager::227::ResourceManager.Request::(grant) 
ResName=`Storage.0ee30f68-c222-44c0-85e6-2ae246f4c1ec`ReqID=`39a62be2-0ecd-4be8-a5e9-00824ea4fa50`::Granted 
request
Thread-2985::DEBUG::2013-07-24 
18:37:35,892::task::794::TaskManager.Task::(resourceAcquired) 
Task=`5011aeeb-7b97-474b-b559-d29f3f6e7a22`::_resourcesAcquired: 
Storage.0ee30f68-c222-44c0-85e6-2ae246f4c1ec (shared)
Thread-2985::DEBUG::2013-07-24 
18:37:35,892::task::957::TaskManager.Task::(_decref) 
Task=`5011aeeb-7b97-474b-b559-d29f3f6e7a22`::ref 1 aborting False
Thread-2985::DEBUG::2013-07-24 
18:37:35,895::misc::84::Storage.Misc.excCmd::(<lambda>) '/bin/dd 
iflag=direct skip=8 bs=512 
if=/dev/0ee30f68-c222-44c0-85e6-2ae246f4c1ec/metadata count=1' (cwd None)
Thread-2985::DEBUG::2013-07-24 
18:37:35,904::misc::84::Storage.Misc.excCmd::(<lambda>) SUCCESS: <err> = 
'1+0 records in\n1+0 records out\n512 bytes (512 B) copied, 0.000358208 
s, 1.4 MB/s\n'; <rc> = 0
Thread-2985::DEBUG::2013-07-24 
18:37:35,905::misc::325::Storage.Misc::(validateDDBytes) err: ['1+0 
records in', '1+0 records out', '512 bytes (512 B) copied, 0.000358208 
s, 1.4 MB/s'], size: 512
Thread-2985::INFO::2013-07-24 
18:37:35,905::image::344::Storage.Image::(getChain) 
sdUUID=0ee30f68-c222-44c0-85e6-2ae246f4c1ec 
imgUUID=975f7398-866e-43f6-8579-1552be81519d 
chain=[<storage.blockVolume.BlockVolume object at 0x7fa284398950>]
Thread-2985::DEBUG::2013-07-24 
18:37:35,906::misc::84::Storage.Misc.excCmd::(<lambda>) '/usr/bin/sudo 
-n /sbin/lvm lvchange --config " devices { preferred_names = 
[\\"^/dev/mapper/\\"] ignore_suspended_devices=1 write_cache_state=0 
disable_after_error_count=3 filter = [ 
\\"a%360a9800042415569305d434565795a44|36782bcb045a7ef0015bbfa3e18b4758e%\\", 
\\"r%.*%\\" ] }  global {  locking_type=1  prioritise_write_locks=1 
wait_for_locks=1 }  backup {  retain_min = 50  retain_days = 0 } " 
--autobackup n --available y 
0ee30f68-c222-44c0-85e6-2ae246f4c1ec/ebce7305-2586-4c5d-bc02-08cc4743a983' 
(cwd None)
Thread-2985::DEBUG::2013-07-24 
18:37:36,271::misc::84::Storage.Misc.excCmd::(<lambda>) SUCCESS: <err> = 
''; <rc> = 0
Thread-2985::DEBUG::2013-07-24 
18:37:36,272::lvm::493::OperationMutex::(_invalidatelvs) Operation 'lvm 
invalidate operation' got the operation mutex
Thread-2985::DEBUG::2013-07-24 
18:37:36,272::lvm::505::OperationMutex::(_invalidatelvs) Operation 'lvm 
invalidate operation' released the operation mutex
Thread-2985::INFO::2013-07-24 
18:37:36,273::logUtils::44::dispatcher::(wrapper) Run and protect: 
prepareImage, Return response: {'path': 
'/rhev/data-center/5849b030-626e-47cb-ad90-3ce782d831b3/0ee30f68-c222-44c0-85e6-2ae246f4c1ec/images/975f7398-866e-43f6-8579-1552be81519d/ebce7305-2586-4c5d-bc02-08cc4743a983', 
'chain': [{'path': 
'/rhev/data-center/5849b030-626e-47cb-ad90-3ce782d831b3/0ee30f68-c222-44c0-85e6-2ae246f4c1ec/images/975f7398-866e-43f6-8579-1552be81519d/ebce7305-2586-4c5d-bc02-08cc4743a983', 
'domainID': '0ee30f68-c222-44c0-85e6-2ae246f4c1ec', 'volumeID': 
'ebce7305-2586-4c5d-bc02-08cc4743a983', 'imageID': 
'975f7398-866e-43f6-8579-1552be81519d'}]}
Thread-2985::DEBUG::2013-07-24 
18:37:36,273::task::1151::TaskManager.Task::(prepare) 
Task=`5011aeeb-7b97-474b-b559-d29f3f6e7a22`::finished: {'path': 
'/rhev/data-center/5849b030-626e-47cb-ad90-3ce782d831b3/0ee30f68-c222-44c0-85e6-2ae246f4c1ec/images/975f7398-866e-43f6-8579-1552be81519d/ebce7305-2586-4c5d-bc02-08cc4743a983', 
'chain': [{'path': 
'/rhev/data-center/5849b030-626e-47cb-ad90-3ce782d831b3/0ee30f68-c222-44c0-85e6-2ae246f4c1ec/images/975f7398-866e-43f6-8579-1552be81519d/ebce7305-2586-4c5d-bc02-08cc4743a983', 
'domainID': '0ee30f68-c222-44c0-85e6-2ae246f4c1ec', 'volumeID': 
'ebce7305-2586-4c5d-bc02-08cc4743a983', 'imageID': 
'975f7398-866e-43f6-8579-1552be81519d'}]}
Thread-2985::DEBUG::2013-07-24 
18:37:36,273::task::568::TaskManager.Task::(_updateState) 
Task=`5011aeeb-7b97-474b-b559-d29f3f6e7a22`::moving from state preparing 
-> state finished
Thread-2985::DEBUG::2013-07-24 
18:37:36,273::resourceManager::830::ResourceManager.Owner::(releaseAll) 
Owner.releaseAll requests {} resources 
{'Storage.0ee30f68-c222-44c0-85e6-2ae246f4c1ec': < ResourceRef 
'Storage.0ee30f68-c222-44c0-85e6-2ae246f4c1ec', isValid: 'True' obj: 
'None'>}
Thread-2985::DEBUG::2013-07-24 
18:37:36,274::resourceManager::864::ResourceManager.Owner::(cancelAll) 
Owner.cancelAll requests {}
Thread-2985::DEBUG::2013-07-24 
18:37:36,274::resourceManager::557::ResourceManager::(releaseResource) 
Trying to release resource 'Storage.0ee30f68-c222-44c0-85e6-2ae246f4c1ec'
Thread-2985::DEBUG::2013-07-24 
18:37:36,274::resourceManager::573::ResourceManager::(releaseResource) 
Released resource 'Storage.0ee30f68-c222-44c0-85e6-2ae246f4c1ec' (0 
active users)
Thread-2985::DEBUG::2013-07-24 
18:37:36,274::resourceManager::578::ResourceManager::(releaseResource) 
Resource 'Storage.0ee30f68-c222-44c0-85e6-2ae246f4c1ec' is free, finding 
out if anyone is waiting for it.
Thread-2985::DEBUG::2013-07-24 
18:37:36,274::resourceManager::585::ResourceManager::(releaseResource) 
No one is waiting for resource 
'Storage.0ee30f68-c222-44c0-85e6-2ae246f4c1ec', Clearing records.
Thread-2985::DEBUG::2013-07-24 
18:37:36,275::task::957::TaskManager.Task::(_decref) 
Task=`5011aeeb-7b97-474b-b559-d29f3f6e7a22`::ref 0 aborting False
Thread-2985::INFO::2013-07-24 
18:37:36,275::clientIF::316::vds::(prepareVolumePath) prepared volume 
path: 
/rhev/data-center/5849b030-626e-47cb-ad90-3ce782d831b3/0ee30f68-c222-44c0-85e6-2ae246f4c1ec/images/975f7398-866e-43f6-8579-1552be81519d/ebce7305-2586-4c5d-bc02-08cc4743a983
Thread-2985::DEBUG::2013-07-24 
18:37:36,282::vm::692::vm.Vm::(_startUnderlyingVm) 
vmId=`03ac5be8-75fc-43df-9fb8-c8e8af30ae84`::_ongoingCreations released
Thread-2984::DEBUG::2013-07-24 
18:37:36,282::API::502::vds::(migrationCreate) Destination VM creation 
succeeded
Thread-2985::DEBUG::2013-07-24 
18:37:36,284::libvirtvm::1901::vm.Vm::(_waitForIncomingMigrationFinish) 
vmId=`03ac5be8-75fc-43df-9fb8-c8e8af30ae84`::Waiting 300 seconds for end 
of migration
Thread-2984::DEBUG::2013-07-24 
18:37:36,285::BindingXMLRPC::920::vds::(wrapper) return 
vmMigrationCreate with {'status': {'message': 'Done', 'code': 0}, 
'migrationPort': 0, 'params': {'status': 'Migration Destination', 
'acpiEnable': 'true', 'emulatedMachine': 'pc-0.14', 
'afterMigrationStatus': 'Up', 'spiceSecureChannels': 
'smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard', 
'pid': '0', 'transparentHugePages': 'true', 'displaySecurePort': '-1', 
'timeOffset': '-43200', 'cpuType': 'Opteron_G3', 'smp': '2', 
'migrationDest': 'libvirt', 'custom': 
{'device_d7b86bcd-13fe-4259-b7a1-0e6243bf8aca': 'VmDevice 
{vmId=03ac5be8-75fc-43df-9fb8-c8e8af30ae84, 
deviceId=d7b86bcd-13fe-4259-b7a1-0e6243bf8aca, device=ide, 
type=controller, bootOrder=0, specParams={}, address={bus=0x00, 
domain=0x0000, type=pci, slot=0x01, function=0x1}, managed=false, 
plugged=true, readOnly=false, deviceAlias=ide0}', 
'device_d7b86bcd-13fe-4259-b7a1-0e6243bf8acadevice_d15dafa0-a1ae-4637-bd9b-6708a31f7e41device_f68176fc-0731-4d98-9f35-b31140dcf568device_e9769f4d-b137-4560-8eed-230655922bfadevice_4b6fd867-b4f3-47f6-b6ef-1f3cd0ed9c34': 
'VmDevice {vmId=03ac5be8-75fc-43df-9fb8-c8e8af30ae84, 
deviceId=4b6fd867-b4f3-47f6-b6ef-1f3cd0ed9c34, device=spicevmc, 
type=channel, bootOrder=0, specParams={}, address={port=3, bus=0, 
controller=0, type=virtio-serial}, managed=false, plugged=true, 
readOnly=false, deviceAlias=channel2}', 
'device_d7b86bcd-13fe-4259-b7a1-0e6243bf8acadevice_d15dafa0-a1ae-4637-bd9b-6708a31f7e41device_f68176fc-0731-4d98-9f35-b31140dcf568device_e9769f4d-b137-4560-8eed-230655922bfa': 
'VmDevice {vmId=03ac5be8-75fc-43df-9fb8-c8e8af30ae84, 
deviceId=e9769f4d-b137-4560-8eed-230655922bfa, device=unix, 
type=channel, bootOrder=0, specParams={}, address={port=2, bus=0, 
controller=0, type=virtio-serial}, managed=false, plugged=true, 
readOnly=false, deviceAlias=channel1}', 
'device_d7b86bcd-13fe-4259-b7a1-0e6243bf8acadevice_d15dafa0-a1ae-4637-bd9b-6708a31f7e41device_f68176fc-0731-4d98-9f35-b31140dcf568': 
'VmDevice {vmId=03ac5be8-75fc-43df-9fb8-c8e8af30ae84, 
deviceId=f68176fc-0731-4d98-9f35-b31140dcf568, device=unix, 
type=channel, bootOrder=0, specParams={}, address={port=1, bus=0, 
controller=0, type=virtio-serial}, managed=false, plugged=true, 
readOnly=false, deviceAlias=channel0}', 
'device_d7b86bcd-13fe-4259-b7a1-0e6243bf8acadevice_d15dafa0-a1ae-4637-bd9b-6708a31f7e41': 
'VmDevice {vmId=03ac5be8-75fc-43df-9fb8-c8e8af30ae84, 
deviceId=d15dafa0-a1ae-4637-bd9b-6708a31f7e41, device=virtio-serial, 
type=controller, bootOrder=0, specParams={}, address={bus=0x00, 
domain=0x0000, type=pci, slot=0x04, function=0x0}, managed=false, 
plugged=true, readOnly=false, deviceAlias=virtio-serial0}'}, 'vmType': 
'kvm', 'spiceSslCipherSuite': 'DEFAULT', 'memSize': 2048, 'vmName': 
'ipa2.nbu.cz', 'nice': '0', 'username': 'Unknown', 'vmId': 
'03ac5be8-75fc-43df-9fb8-c8e8af30ae84', 'displayIp': '0', 
'keyboardLayout': 'en-us', 'displayPort': '-1', 'smartcardEnable': 
'false', 'guestIPs': '', 'nicModel': 'rtl8139,pv', 'smpCoresPerSocket': 
'1', 'kvmEnable': 'true', 'pitReinjection': 'false', 'devices': 
[{'device': 'unix', 'alias': 'channel0', 'type': 'channel', 'address': 
{'bus': '0', 'controller': '0', 'type': 'virtio-serial', 'port': '1'}}, 
{'device': 'unix', 'alias': 'channel1', 'type': 'channel', 'address': 
{'bus': '0', 'controller': '0', 'type': 'virtio-serial', 'port': '2'}}, 
{'device': 'spicevmc', 'alias': 'channel2', 'type': 'channel', 
'address': {'bus': '0', 'controller': '0', 'type': 'virtio-serial', 
'port': '3'}}, {'device': 'usb', 'alias': 'usb0', 'type': 'controller', 
'address': {'slot': '0x01', 'bus': '0x00', 'domain': '0x0000', 'type': 
'pci', 'function': '0x2'}}, {'device': 'ide', 'alias': 'ide0', 'type': 
'controller', 'address': {'slot': '0x01', 'bus': '0x00', 'domain': 
'0x0000', 'type': 'pci', 'function': '0x1'}}, {'device': 
'virtio-serial', 'alias': 'virtio-serial0', 'type': 'controller', 
'address': {'slot': '0x04', 'bus': '0x00', 'domain': '0x0000', 'type': 
'pci', 'function': '0x0'}}, {'specParams': {'vram': '65536'}, 'alias': 
'video0', 'deviceId': 'a74682a1-e49b-4c3c-a65a-679036bbd6f6', 'address': 
{'slot': '0x02', 'bus': '0x00', 'domain': '0x0000', 'type': 'pci', 
'function': '0x0'}, 'device': 'qxl', 'type': 'video'}, {'nicModel': 
'pv', 'macAddr': '00:1a:4a:a8:03:9e', 'linkActive': True, 'network': 
'ovirtmgmt', 'specParams': {}, 'filter': 'vdsm-no-mac-spoofing', 
'alias': 'net0', 'deviceId': '405d2d7f-cbe4-4a8c-aeaa-b6d11c0739fd', 
'address': {'slot': '0x03', 'bus': '0x00', 'domain': '0x0000', 'type': 
'pci', 'function': '0x0'}, 'device': 'bridge', 'type': 'interface', 
'name': 'vnet7'}, {'index': '2', 'iface': 'ide', 'name': 'hdc', 'alias': 
'ide0-1-0', 'shared': 'false', 'specParams': {'path': ''}, 'readonly': 
'True', 'deviceId': 'f3399625-142a-44ed-897d-01b2fad56a89', 'address': 
{'bus': '1', 'controller': '0', 'type': 'drive', 'target': '0', 'unit': 
'0'}, 'device': 'cdrom', 'path': '', 'type': 'disk'}, {'address': 
{'slot': '0x05', 'bus': '0x00', 'domain': '0x0000', 'type': 'pci', 
'function': '0x0'}, 'index': 0, 'iface': 'virtio', 'apparentsize': 
'7516192768', 'alias': 'virtio-disk0', 'imageID': 
'975f7398-866e-43f6-8579-1552be81519d', 'readonly': 'False', 'shared': 
'false', 'truesize': '7516192768', 'type': 'disk', 'domainID': 
'0ee30f68-c222-44c0-85e6-2ae246f4c1ec', 'reqsize': '0', 'format': 'cow', 
'deviceId': '975f7398-866e-43f6-8579-1552be81519d', 'poolID': 
'5849b030-626e-47cb-ad90-3ce782d831b3', 'device': 'disk', 'path': 
'/rhev/data-center/5849b030-626e-47cb-ad90-3ce782d831b3/0ee30f68-c222-44c0-85e6-2ae246f4c1ec/images/975f7398-866e-43f6-8579-1552be81519d/ebce7305-2586-4c5d-bc02-08cc4743a983', 
'propagateErrors': 'off', 'optional': 'false', 'name': 'vda', 
'volumeID': 'ebce7305-2586-4c5d-bc02-08cc4743a983', 'specParams': {}, 
'volumeChain': [{'path': 
'/rhev/data-center/5849b030-626e-47cb-ad90-3ce782d831b3/0ee30f68-c222-44c0-85e6-2ae246f4c1ec/images/975f7398-866e-43f6-8579-1552be81519d/ebce7305-2586-4c5d-bc02-08cc4743a983', 
'domainID': '0ee30f68-c222-44c0-85e6-2ae246f4c1ec', 'volumeID': 
'ebce7305-2586-4c5d-bc02-08cc4743a983', 'imageID': 
'975f7398-866e-43f6-8579-1552be81519d'}]}, {'target': 2097152, 
'specParams': {'model': 'virtio'}, 'alias': 'balloon0', 'deviceId': 
'c25a298c-698f-41ff-8968-12e6ed9b14fe', 'address': {'slot': '0x06', 
'bus': '0x00', 'domain': '0x0000', 'type': 'pci', 'function': '0x0'}, 
'device': 'memballoon', 'type': 'balloon'}], 'clientIp': '', 'display': 
'qxl'}}
Thread-2987::DEBUG::2013-07-24 
18:37:36,505::BindingXMLRPC::913::vds::(wrapper) client 
[192.168.3.207]::call vmDestroy with 
('03ac5be8-75fc-43df-9fb8-c8e8af30ae84',) {}
Thread-2987::INFO::2013-07-24 18:37:36,505::API::310::vds::(destroy) 
vmContainerLock acquired by vm 03ac5be8-75fc-43df-9fb8-c8e8af30ae84
Thread-2987::DEBUG::2013-07-24 
18:37:36,505::libvirtvm::2639::vm.Vm::(destroy) 
vmId=`03ac5be8-75fc-43df-9fb8-c8e8af30ae84`::destroy Called
Thread-2987::INFO::2013-07-24 
18:37:36,505::libvirtvm::2588::vm.Vm::(releaseVm) 
vmId=`03ac5be8-75fc-43df-9fb8-c8e8af30ae84`::Release VM resources
Thread-2985::ERROR::2013-07-24 
18:37:36,507::vm::716::vm.Vm::(_startUnderlyingVm) 
vmId=`03ac5be8-75fc-43df-9fb8-c8e8af30ae84`::The vm start process failed
Traceback (most recent call last):
   File "/usr/share/vdsm/vm.py", line 696, in _startUnderlyingVm
     self._waitForIncomingMigrationFinish()
   File "/usr/share/vdsm/libvirtvm.py", line 1907, in 
_waitForIncomingMigrationFinish
     self._connection.lookupByUUIDString(self.id),
   File "/usr/lib64/python2.6/site-packages/vdsm/libvirtconnection.py", 
line 111, in wrapper
     ret = f(*args, **kwargs)
   File "/usr/lib64/python2.6/site-packages/libvirt.py", line 2838, in 
lookupByUUIDString
     if ret is None:raise libvirtError('virDomainLookupByUUIDString() 
failed', conn=self)
libvirtError: Domain not found: no domain with matching uuid 
'03ac5be8-75fc-43df-9fb8-c8e8af30ae84'
Thread-2985::DEBUG::2013-07-24 
18:37:36,508::vm::1065::vm.Vm::(setDownStatus) 
vmId=`03ac5be8-75fc-43df-9fb8-c8e8af30ae84`::Changed state to Down: 
Domain not found: no domain with matching uuid 
'03ac5be8-75fc-43df-9fb8-c8e8af30ae84'
Thread-2987::DEBUG::2013-07-24 
18:37:36,509::task::568::TaskManager.Task::(_updateState) 
Task=`43d36e49-25bf-4280-a469-aa944d7f8939`::moving from state init -> 
state preparing
Thread-2987::INFO::2013-07-24 
18:37:36,510::logUtils::41::dispatcher::(wrapper) Run and protect: 
inappropriateDevices(thiefId='03ac5be8-75fc-43df-9fb8-c8e8af30ae84')
Thread-2987::INFO::2013-07-24 
18:37:36,511::logUtils::44::dispatcher::(wrapper) Run and protect: 
inappropriateDevices, Return response: None
Thread-2987::DEBUG::2013-07-24 
18:37:36,512::task::1151::TaskManager.Task::(prepare) 
Task=`43d36e49-25bf-4280-a469-aa944d7f8939`::finished: None
Thread-2987::DEBUG::2013-07-24 
18:37:36,512::task::568::TaskManager.Task::(_updateState) 
Task=`43d36e49-25bf-4280-a469-aa944d7f8939`::moving from state preparing 
-> state finished
Thread-2987::DEBUG::2013-07-24 
18:37:36,512::resourceManager::830::ResourceManager.Owner::(releaseAll) 
Owner.releaseAll requests {} resources {}
Thread-2987::DEBUG::2013-07-24 
18:37:36,512::resourceManager::864::ResourceManager.Owner::(cancelAll) 
Owner.cancelAll requests {}
Thread-2987::DEBUG::2013-07-24 
18:37:36,512::task::957::TaskManager.Task::(_decref) 
Task=`43d36e49-25bf-4280-a469-aa944d7f8939`::ref 0 aborting False
Thread-2987::DEBUG::2013-07-24 
18:37:36,513::libvirtvm::2633::vm.Vm::(deleteVm) 
vmId=`03ac5be8-75fc-43df-9fb8-c8e8af30ae84`::Total desktops after 
destroy of 03ac5be8-75fc-43df-9fb8-c8e8af30ae84 is 0
Thread-2987::DEBUG::2013-07-24 
18:37:36,513::BindingXMLRPC::920::vds::(wrapper) return vmDestroy with 
{'status': {'message': 'Machine destroyed', 'code': 0}}
Thread-2990::DEBUG::2013-07-24 
18:37:40,815::task::568::TaskManager.Task::(_updateState) 
Task=`27887d84-ac21-4eda-b04d-d5e23ab9c183`::moving from state init -> 
state preparing
Thread-2990::INFO::2013-07-24 
18:37:40,815::logUtils::41::dispatcher::(wrapper) Run and protect: 
repoStats(options=None)
Thread-2990::INFO::2013-07-24 
18:37:40,815::logUtils::44::dispatcher::(wrapper) Run and protect: 
repoStats, Return response: {u'0ee30f68-c222-44c0-85e6-2ae246f4c1ec': 
{'delay': '0.0135831832886', 'lastCheck': '7.7', 'code': 0, 'valid': 
True}, u'a8c13187-d9d1-46b8-abe3-c322970d9d4d': {'delay': 
'0.00499796867371', 'lastCheck': '5.8', 'code': 0, 'valid': True}}
Thread-2990::DEBUG::2013-07-24 
18:37:40,815::task::1151::TaskManager.Task::(prepare) 
Task=`27887d84-ac21-4eda-b04d-d5e23ab9c183`::finished: 
{u'0ee30f68-c222-44c0-85e6-2ae246f4c1ec': {'delay': '0.0135831832886', 
'lastCheck': '7.7', 'code': 0, 'valid': True}, 
u'a8c13187-d9d1-46b8-abe3-c322970d9d4d': {'delay': '0.00499796867371', 
'lastCheck': '5.8', 'code': 0, 'valid': True}}
Thread-2990::DEBUG::2013-07-24 
18:37:40,815::task::568::TaskManager.Task::(_updateState) 
Task=`27887d84-ac21-4eda-b04d-d5e23ab9c183`::moving from state preparing 
-> state finished
Thread-2990::DEBUG::2013-07-24 
18:37:40,816::resourceManager::830::ResourceManager.Owner::(releaseAll) 
Owner.releaseAll requests {} resources {}
Thread-2990::DEBUG::2013-07-24 
18:37:40,816::resourceManager::864::ResourceManager.Owner::(cancelAll) 
Owner.cancelAll requests {}
Thread-2990::DEBUG::2013-07-24 
18:37:40,816::task::957::TaskManager.Task::(_decref) 
Task=`27887d84-ac21-4eda-b04d-d5e23ab9c183`::ref 0 aborting False

[Users] Migration and creating VM failing

Jakub Bittner