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
