[Users] ovirt not seeing a VM has started.
Itamar Heim
iheim at redhat.com
Tue Oct 30 07:47:01 UTC 2012
On 10/30/2012 08:40 AM, Roy Golan wrote:
> On 10/30/2012 04:05 AM, Daniel Rowe wrote:
>
> please paste /var/log/engine/engine.log from the ovirt machine as well.
and output of 'vdsClient -s 0 getAllVmStats' from vdsm node
>
>> Hi
>>
>> I have my oVirt setup to the point where I can add VM.
>>
>> I am using Gluster and to get it to be able to add VMs I had to run
>> "setsebool -P virt_use_fusefs=on" once I did this it seems to work
>> fine for added VMs.
>>
>> I have added a Fedora 17 vm, when I start the VM in oVirt, the
>> management interface never see it as started, just always has the hour
>> glass next to it.
>>
>> If I do a PS on the node I can see the VM is indeed started and can
>> see the qemu-kvm process for that VM.
>>
>> There are no deny messages in audit.log on the node.
>>
>> The message log on the node has this message: "VM start: vdsm vm.Vm
>> WARNING vmId=`4abdba0d-aa1f-48f1-8160-3cde63165057`::_readPauseCode
>> unsupported by libvirt vm".
>>
>> Not sure if this is related.
>>
>> The vdsm log when I click on the run VM:
>>
>> Thread-1539::DEBUG::2012-10-30
>> 09:56:09,203::BindingXMLRPC::859::vds::(wrapper) client
>> [192.168.1.10]::call vmCreate with ({'custom': {'viodiskcache':
>> 'writeback'}, 'keyboardLayout': 'en-us', 'kvmEnable': 'true',
>> 'pitReinjection': 'false', 'acpiEnable': 'true', 'emulatedMachine':
>> 'pc-0.14', 'vmId': '4abdba0d-aa1f-48f1-8160-3cde63165057', 'devices':
>> [{'device': 'qxl', 'specParams': {'vram': '65536'}, 'type': 'video',
>> 'deviceId': '25ada4cb-1108-491b-8d2c-c05cb353cc99'}, {'index': '2',
>> 'iface': 'ide', 'bootOrder': '1', 'specParams': {'path':
>> 'Fedora-17-x86_64-DVD.iso'}, 'readonly': 'true', 'deviceId':
>> '1b62fc2d-88e5-42e0-9666-3de861a71c44', 'device': 'cdrom', 'path':
>> '/rhev/data-center/640fa36c-1da8-11e2-86f7-1078d2e9dece/65f95655-5bbe-47e4-8d3a-6e2ffc5c7761/images/11111111-1111-1111-1111-111111111111/Fedora-17-x86_64-DVD.iso',
>>
>> 'type': 'disk'}, {'index': 0, 'iface': 'virtio', 'format': 'raw',
>> 'type': 'disk', 'volumeID': '12413fe4-a694-439b-95d8-40d5a576dada',
>> 'imageID': '025d5960-23db-4e07-98c8-4c9682155eb1', 'specParams': {},
>> 'readonly': 'false', 'domainID':
>> 'e552b5fd-30fb-4e18-8bc4-26517f11a283', 'deviceId':
>> '025d5960-23db-4e07-98c8-4c9682155eb1', 'poolID':
>> '640fa36c-1da8-11e2-86f7-1078d2e9dece', 'device': 'disk', 'shared':
>> 'false', 'propagateErrors': 'off', 'optional': 'false'}, {'nicModel':
>> 'pv', 'macAddr': '00:1a:4a:70:83:00', 'network': 'ovirtmgmt',
>> 'specParams': {}, 'deviceId': '80841d17-f758-46c8-84bc-0346072c4156',
>> 'device': 'bridge', 'type': 'interface'}, {'device': 'memballoon',
>> 'specParams': {'model': 'virtio'}, 'type': 'balloon', 'deviceId':
>> '09f59ef5-b17f-49ea-99e6-8ee7bcca64a1'}], 'smp': '2', 'vmType': 'kvm',
>> 'timeOffset': '0', 'memSize': 1024, 'spiceSslCipherSuite': 'DEFAULT',
>> 'cpuType': 'Conroe', 'spiceSecureChannels':
>> 'smain,sinputs,scursor,splayback,srecord,sdisplay',
>> 'smpCoresPerSocket': '2', 'vmName': 'bsdlinux04vm', 'display': 'qxl',
>> 'transparentHugePages': 'true', 'nice': '0'},) {} flowID [8a5456c]
>> Thread-1539::INFO::2012-10-30
>> 09:56:09,203::API::601::vds::(_getNetworkIp) network None: using 0
>> Thread-1539::INFO::2012-10-30 09:56:09,204::API::228::vds::(create)
>> vmContainerLock acquired by vm 4abdba0d-aa1f-48f1-8160-3cde63165057
>> Thread-1540::DEBUG::2012-10-30
>> 09:56:09,207::vm::564::vm.Vm::(_startUnderlyingVm)
>> vmId=`4abdba0d-aa1f-48f1-8160-3cde63165057`::Start
>> Thread-1539::DEBUG::2012-10-30 09:56:09,207::API::244::vds::(create)
>> Total desktops after creation of 4abdba0d-aa1f-48f1-8160-3cde63165057
>> is 1
>> Thread-1539::DEBUG::2012-10-30
>> 09:56:09,208::BindingXMLRPC::865::vds::(wrapper) return vmCreate with
>> {'status': {'message': 'Done', 'code': 0}, 'vmList': {'status':
>> 'WaitForLaunch', 'acpiEnable': 'true', 'emulatedMachine': 'pc-0.14',
>> 'vmId': '4abdba0d-aa1f-48f1-8160-3cde63165057', 'pid': '0',
>> 'timeOffset': '0', 'displayPort': '-1', 'displaySecurePort': '-1',
>> 'spiceSslCipherSuite': 'DEFAULT', 'cpuType': 'Conroe', 'custom':
>> {'viodiskcache': 'writeback'}, 'clientIp': '', 'nicModel':
>> 'rtl8139,pv', 'keyboardLayout': 'en-us', 'kvmEnable': 'true',
>> 'pitReinjection': 'false', 'transparentHugePages': 'true', 'devices':
>> [{'device': 'qxl', 'specParams': {'vram': '65536'}, 'type': 'video',
>> 'deviceId': '25ada4cb-1108-491b-8d2c-c05cb353cc99'}, {'index': '2',
>> 'iface': 'ide', 'bootOrder': '1', 'specParams': {'path':
>> 'Fedora-17-x86_64-DVD.iso'}, 'readonly': 'true', 'deviceId':
>> '1b62fc2d-88e5-42e0-9666-3de861a71c44', 'device': 'cdrom', 'path':
>> '/rhev/data-center/640fa36c-1da8-11e2-86f7-1078d2e9dece/65f95655-5bbe-47e4-8d3a-6e2ffc5c7761/images/11111111-1111-1111-1111-111111111111/Fedora-17-x86_64-DVD.iso',
>>
>> 'type': 'disk'}, {'index': 0, 'iface': 'virtio', 'format': 'raw',
>> 'type': 'disk', 'volumeID': '12413fe4-a694-439b-95d8-40d5a576dada',
>> 'imageID': '025d5960-23db-4e07-98c8-4c9682155eb1', 'specParams': {},
>> 'readonly': 'false', 'domainID':
>> 'e552b5fd-30fb-4e18-8bc4-26517f11a283', 'deviceId':
>> '025d5960-23db-4e07-98c8-4c9682155eb1', 'poolID':
>> '640fa36c-1da8-11e2-86f7-1078d2e9dece', 'device': 'disk', 'shared':
>> 'false', 'propagateErrors': 'off', 'optional': 'false'}, {'nicModel':
>> 'pv', 'macAddr': '00:1a:4a:70:83:00', 'network': 'ovirtmgmt',
>> 'specParams': {}, 'deviceId': '80841d17-f758-46c8-84bc-0346072c4156',
>> 'device': 'bridge', 'type': 'interface'}, {'device': 'memballoon',
>> 'specParams': {'model': 'virtio'}, 'type': 'balloon', 'deviceId':
>> '09f59ef5-b17f-49ea-99e6-8ee7bcca64a1'}], 'smp': '2', 'vmType': 'kvm',
>> 'memSize': 1024, 'displayIp': '0', 'spiceSecureChannels':
>> 'smain,sinputs,scursor,splayback,srecord,sdisplay',
>> 'smpCoresPerSocket': '2', 'vmName': 'bsdlinux04vm', 'display': 'qxl',
>> 'nice': '0'}}
>> Thread-1540::DEBUG::2012-10-30
>> 09:56:09,208::vm::568::vm.Vm::(_startUnderlyingVm)
>> vmId=`4abdba0d-aa1f-48f1-8160-3cde63165057`::_ongoingCreations
>> acquired
>> Thread-1540::INFO::2012-10-30
>> 09:56:09,210::libvirtvm::1285::vm.Vm::(_run)
>> vmId=`4abdba0d-aa1f-48f1-8160-3cde63165057`::VM wrapper has started
>> Thread-1540::DEBUG::2012-10-30
>> 09:56:09,211::task::588::TaskManager.Task::(_updateState)
>> Task=`f91ddc64-360b-4f33-bb53-9c6436a6a6d4`::moving from state init ->
>> state preparing
>> Thread-1540::INFO::2012-10-30
>> 09:56:09,211::logUtils::37::dispatcher::(wrapper) Run and protect:
>> getVolumeSize(sdUUID='e552b5fd-30fb-4e18-8bc4-26517f11a283',
>> spUUID='640fa36c-1da8-11e2-86f7-1078d2e9dece',
>> imgUUID='025d5960-23db-4e07-98c8-4c9682155eb1',
>> volUUID='12413fe4-a694-439b-95d8-40d5a576dada', options=None)
>> Thread-1540::DEBUG::2012-10-30
>> 09:56:09,212::resourceManager::175::ResourceManager.Request::(__init__)
>> ResName=`Storage.e552b5fd-30fb-4e18-8bc4-26517f11a283`ReqID=`a4d63aa4-f9af-48c3-b57f-68149d3ea523`::Request
>>
>> was made in '/usr/share/vdsm/storage/resourceManager.py' line '485' at
>> 'registerResource'
>> Thread-1540::DEBUG::2012-10-30
>> 09:56:09,212::resourceManager::486::ResourceManager::(registerResource)
>> Trying to register resource
>> 'Storage.e552b5fd-30fb-4e18-8bc4-26517f11a283' for lock type 'shared'
>> Thread-1540::DEBUG::2012-10-30
>> 09:56:09,212::resourceManager::528::ResourceManager::(registerResource)
>> Resource 'Storage.e552b5fd-30fb-4e18-8bc4-26517f11a283' is free. Now
>> locking as 'shared' (1 active user)
>> Thread-1540::DEBUG::2012-10-30
>> 09:56:09,213::resourceManager::212::ResourceManager.Request::(grant)
>> ResName=`Storage.e552b5fd-30fb-4e18-8bc4-26517f11a283`ReqID=`a4d63aa4-f9af-48c3-b57f-68149d3ea523`::Granted
>>
>> request
>> Thread-1540::DEBUG::2012-10-30
>> 09:56:09,213::task::817::TaskManager.Task::(resourceAcquired)
>> Task=`f91ddc64-360b-4f33-bb53-9c6436a6a6d4`::_resourcesAcquired:
>> Storage.e552b5fd-30fb-4e18-8bc4-26517f11a283 (shared)
>> Thread-1540::DEBUG::2012-10-30
>> 09:56:09,213::task::978::TaskManager.Task::(_decref)
>> Task=`f91ddc64-360b-4f33-bb53-9c6436a6a6d4`::ref 1 aborting False
>> Thread-1540::DEBUG::2012-10-30
>> 09:56:09,216::fileVolume::535::Storage.Volume::(validateVolumePath)
>> validate path for 12413fe4-a694-439b-95d8-40d5a576dada
>> Thread-1540::DEBUG::2012-10-30
>> 09:56:09,220::fileVolume::535::Storage.Volume::(validateVolumePath)
>> validate path for 12413fe4-a694-439b-95d8-40d5a576dada
>> Thread-1540::INFO::2012-10-30
>> 09:56:09,221::logUtils::39::dispatcher::(wrapper) Run and protect:
>> getVolumeSize, Return response: {'truesize': '0', 'apparentsize':
>> '8589934592'}
>> Thread-1540::DEBUG::2012-10-30
>> 09:56:09,221::task::1172::TaskManager.Task::(prepare)
>> Task=`f91ddc64-360b-4f33-bb53-9c6436a6a6d4`::finished: {'truesize':
>> '0', 'apparentsize': '8589934592'}
>> Thread-1540::DEBUG::2012-10-30
>> 09:56:09,222::task::588::TaskManager.Task::(_updateState)
>> Task=`f91ddc64-360b-4f33-bb53-9c6436a6a6d4`::moving from state
>> preparing -> state finished
>> Thread-1540::DEBUG::2012-10-30
>> 09:56:09,222::resourceManager::809::ResourceManager.Owner::(releaseAll)
>> Owner.releaseAll requests {} resources
>> {'Storage.e552b5fd-30fb-4e18-8bc4-26517f11a283': < ResourceRef
>> 'Storage.e552b5fd-30fb-4e18-8bc4-26517f11a283', isValid: 'True' obj:
>> 'None'>}
>> Thread-1540::DEBUG::2012-10-30
>> 09:56:09,222::resourceManager::844::ResourceManager.Owner::(cancelAll)
>> Owner.cancelAll requests {}
>> Thread-1540::DEBUG::2012-10-30
>> 09:56:09,222::resourceManager::538::ResourceManager::(releaseResource)
>> Trying to release resource
>> 'Storage.e552b5fd-30fb-4e18-8bc4-26517f11a283'
>> Thread-1540::DEBUG::2012-10-30
>> 09:56:09,223::resourceManager::553::ResourceManager::(releaseResource)
>> Released resource 'Storage.e552b5fd-30fb-4e18-8bc4-26517f11a283' (0
>> active users)
>> Thread-1540::DEBUG::2012-10-30
>> 09:56:09,223::resourceManager::558::ResourceManager::(releaseResource)
>> Resource 'Storage.e552b5fd-30fb-4e18-8bc4-26517f11a283' is free,
>> finding out if anyone is waiting for it.
>> Thread-1540::DEBUG::2012-10-30
>> 09:56:09,223::resourceManager::565::ResourceManager::(releaseResource)
>> No one is waiting for resource
>> 'Storage.e552b5fd-30fb-4e18-8bc4-26517f11a283', Clearing records.
>> Thread-1540::DEBUG::2012-10-30
>> 09:56:09,223::task::978::TaskManager.Task::(_decref)
>> Task=`f91ddc64-360b-4f33-bb53-9c6436a6a6d4`::ref 0 aborting False
>> Thread-1540::INFO::2012-10-30
>> 09:56:09,224::clientIF::274::vds::(prepareVolumePath) prepared volume
>> path:
>> /rhev/data-center/640fa36c-1da8-11e2-86f7-1078d2e9dece/65f95655-5bbe-47e4-8d3a-6e2ffc5c7761/images/11111111-1111-1111-1111-111111111111/Fedora-17-x86_64-DVD.iso
>>
>> Thread-1540::DEBUG::2012-10-30
>> 09:56:09,224::task::588::TaskManager.Task::(_updateState)
>> Task=`c1701ef5-96d8-4036-a5cb-7a285152d84f`::moving from state init ->
>> state preparing
>> Thread-1540::INFO::2012-10-30
>> 09:56:09,224::logUtils::37::dispatcher::(wrapper) Run and protect:
>> prepareImage(sdUUID='e552b5fd-30fb-4e18-8bc4-26517f11a283',
>> spUUID='640fa36c-1da8-11e2-86f7-1078d2e9dece',
>> imgUUID='025d5960-23db-4e07-98c8-4c9682155eb1',
>> volUUID='12413fe4-a694-439b-95d8-40d5a576dada')
>> Thread-1540::DEBUG::2012-10-30
>> 09:56:09,225::resourceManager::175::ResourceManager.Request::(__init__)
>> ResName=`Storage.e552b5fd-30fb-4e18-8bc4-26517f11a283`ReqID=`1fd9533e-6b8a-458d-a4d2-001f0cc93ac2`::Request
>>
>> was made in '/usr/share/vdsm/storage/resourceManager.py' line '485' at
>> 'registerResource'
>> Thread-1540::DEBUG::2012-10-30
>> 09:56:09,225::resourceManager::486::ResourceManager::(registerResource)
>> Trying to register resource
>> 'Storage.e552b5fd-30fb-4e18-8bc4-26517f11a283' for lock type 'shared'
>> Thread-1540::DEBUG::2012-10-30
>> 09:56:09,225::resourceManager::528::ResourceManager::(registerResource)
>> Resource 'Storage.e552b5fd-30fb-4e18-8bc4-26517f11a283' is free. Now
>> locking as 'shared' (1 active user)
>> Thread-1540::DEBUG::2012-10-30
>> 09:56:09,225::resourceManager::212::ResourceManager.Request::(grant)
>> ResName=`Storage.e552b5fd-30fb-4e18-8bc4-26517f11a283`ReqID=`1fd9533e-6b8a-458d-a4d2-001f0cc93ac2`::Granted
>>
>> request
>> Thread-1540::DEBUG::2012-10-30
>> 09:56:09,226::task::817::TaskManager.Task::(resourceAcquired)
>> Task=`c1701ef5-96d8-4036-a5cb-7a285152d84f`::_resourcesAcquired:
>> Storage.e552b5fd-30fb-4e18-8bc4-26517f11a283 (shared)
>> Thread-1540::DEBUG::2012-10-30
>> 09:56:09,226::task::978::TaskManager.Task::(_decref)
>> Task=`c1701ef5-96d8-4036-a5cb-7a285152d84f`::ref 1 aborting False
>> Thread-1540::DEBUG::2012-10-30
>> 09:56:09,227::fileVolume::535::Storage.Volume::(validateVolumePath)
>> validate path for 12413fe4-a694-439b-95d8-40d5a576dada
>> Thread-1540::INFO::2012-10-30
>> 09:56:09,234::image::357::Storage.Image::(getChain)
>> sdUUID=e552b5fd-30fb-4e18-8bc4-26517f11a283
>> imgUUID=025d5960-23db-4e07-98c8-4c9682155eb1
>> chain=[<storage.fileVolume.FileVolume instance at 0x7f82442cb0e0>]
>> Thread-1540::INFO::2012-10-30
>> 09:56:09,237::logUtils::39::dispatcher::(wrapper) Run and protect:
>> prepareImage, Return response: {'path':
>> '/rhev/data-center/640fa36c-1da8-11e2-86f7-1078d2e9dece/e552b5fd-30fb-4e18-8bc4-26517f11a283/images/025d5960-23db-4e07-98c8-4c9682155eb1/12413fe4-a694-439b-95d8-40d5a576dada',
>>
>> 'chain': [{'path':
>> '/rhev/data-center/640fa36c-1da8-11e2-86f7-1078d2e9dece/e552b5fd-30fb-4e18-8bc4-26517f11a283/images/025d5960-23db-4e07-98c8-4c9682155eb1/12413fe4-a694-439b-95d8-40d5a576dada',
>>
>> 'domainID': 'e552b5fd-30fb-4e18-8bc4-26517f11a283', 'volumeID':
>> '12413fe4-a694-439b-95d8-40d5a576dada', 'imageID':
>> '025d5960-23db-4e07-98c8-4c9682155eb1'}]}
>> Thread-1540::DEBUG::2012-10-30
>> 09:56:09,237::task::1172::TaskManager.Task::(prepare)
>> Task=`c1701ef5-96d8-4036-a5cb-7a285152d84f`::finished: {'path':
>> '/rhev/data-center/640fa36c-1da8-11e2-86f7-1078d2e9dece/e552b5fd-30fb-4e18-8bc4-26517f11a283/images/025d5960-23db-4e07-98c8-4c9682155eb1/12413fe4-a694-439b-95d8-40d5a576dada',
>>
>> 'chain': [{'path':
>> '/rhev/data-center/640fa36c-1da8-11e2-86f7-1078d2e9dece/e552b5fd-30fb-4e18-8bc4-26517f11a283/images/025d5960-23db-4e07-98c8-4c9682155eb1/12413fe4-a694-439b-95d8-40d5a576dada',
>>
>> 'domainID': 'e552b5fd-30fb-4e18-8bc4-26517f11a283', 'volumeID':
>> '12413fe4-a694-439b-95d8-40d5a576dada', 'imageID':
>> '025d5960-23db-4e07-98c8-4c9682155eb1'}]}
>> Thread-1540::DEBUG::2012-10-30
>> 09:56:09,237::task::588::TaskManager.Task::(_updateState)
>> Task=`c1701ef5-96d8-4036-a5cb-7a285152d84f`::moving from state
>> preparing -> state finished
>> Thread-1540::DEBUG::2012-10-30
>> 09:56:09,237::resourceManager::809::ResourceManager.Owner::(releaseAll)
>> Owner.releaseAll requests {} resources
>> {'Storage.e552b5fd-30fb-4e18-8bc4-26517f11a283': < ResourceRef
>> 'Storage.e552b5fd-30fb-4e18-8bc4-26517f11a283', isValid: 'True' obj:
>> 'None'>}
>> Thread-1540::DEBUG::2012-10-30
>> 09:56:09,237::resourceManager::844::ResourceManager.Owner::(cancelAll)
>> Owner.cancelAll requests {}
>> Thread-1540::DEBUG::2012-10-30
>> 09:56:09,238::resourceManager::538::ResourceManager::(releaseResource)
>> Trying to release resource
>> 'Storage.e552b5fd-30fb-4e18-8bc4-26517f11a283'
>> Thread-1540::DEBUG::2012-10-30
>> 09:56:09,238::resourceManager::553::ResourceManager::(releaseResource)
>> Released resource 'Storage.e552b5fd-30fb-4e18-8bc4-26517f11a283' (0
>> active users)
>> Thread-1540::DEBUG::2012-10-30
>> 09:56:09,238::resourceManager::558::ResourceManager::(releaseResource)
>> Resource 'Storage.e552b5fd-30fb-4e18-8bc4-26517f11a283' is free,
>> finding out if anyone is waiting for it.
>> Thread-1540::DEBUG::2012-10-30
>> 09:56:09,238::resourceManager::565::ResourceManager::(releaseResource)
>> No one is waiting for resource
>> 'Storage.e552b5fd-30fb-4e18-8bc4-26517f11a283', Clearing records.
>> Thread-1540::DEBUG::2012-10-30
>> 09:56:09,239::task::978::TaskManager.Task::(_decref)
>> Task=`c1701ef5-96d8-4036-a5cb-7a285152d84f`::ref 0 aborting False
>> Thread-1540::INFO::2012-10-30
>> 09:56:09,239::clientIF::274::vds::(prepareVolumePath) prepared volume
>> path:
>> /rhev/data-center/640fa36c-1da8-11e2-86f7-1078d2e9dece/e552b5fd-30fb-4e18-8bc4-26517f11a283/images/025d5960-23db-4e07-98c8-4c9682155eb1/12413fe4-a694-439b-95d8-40d5a576dada
>>
>> Thread-1540::DEBUG::2012-10-30
>> 09:56:09,249::__init__::1249::Storage.Misc.excCmd::(_log)
>> '/usr/libexec/vdsm/hooks/before_vm_start/50_hugepages' (cwd None)
>> Thread-1540::DEBUG::2012-10-30
>> 09:56:09,375::__init__::1249::Storage.Misc.excCmd::(_log) SUCCESS:
>> <err> = ''; <rc> = 0
>> Thread-1540::INFO::2012-10-30
>> 09:56:09,376::hooks::72::root::(_runHooksDir)
>> Thread-1540::DEBUG::2012-10-30
>> 09:56:09,376::libvirtvm::1338::vm.Vm::(_run)
>> vmId=`4abdba0d-aa1f-48f1-8160-3cde63165057`::<?xml version="1.0"
>> encoding="utf-8"?>
>> <domain type="kvm">
>> <name>bsdlinux04vm</name>
>> <uuid>4abdba0d-aa1f-48f1-8160-3cde63165057</uuid>
>> <memory>1048576</memory>
>> <currentMemory>1048576</currentMemory>
>> <vcpu>2</vcpu>
>> <devices>
>> <channel type="unix">
>> <target name="com.redhat.rhevm.vdsm" type="virtio"/>
>> <source mode="bind"
>> path="/var/lib/libvirt/qemu/channels/bsdlinux04vm.com.redhat.rhevm.vdsm"/>
>>
>> </channel>
>> <input bus="ps2" type="mouse"/>
>> <channel type="spicevmc">
>> <target name="com.redhat.spice.0" type="virtio"/>
>> </channel>
>> <graphics autoport="yes" keymap="en-us" listen="0" passwd="*****"
>> passwdValidTo="1970-01-01T00:00:01" port="-1" tlsPort="-1"
>> type="spice">
>> <channel mode="secure" name="main"/>
>> <channel mode="secure" name="inputs"/>
>> <channel mode="secure" name="cursor"/>
>> <channel mode="secure" name="playback"/>
>> <channel mode="secure" name="record"/>
>> <channel mode="secure" name="display"/>
>> </graphics>
>> <console type="pty">
>> <target port="0" type="virtio"/>
>> </console>
>> <video>
>> <model heads="1" type="qxl" vram="65536"/>
>> </video>
>> <interface type="bridge">
>> <mac address="00:1a:4a:70:83:00"/>
>> <model type="virtio"/>
>> <source bridge="ovirtmgmt"/>
>> </interface>
>> <memballoon model="virtio"/>
>> <disk device="cdrom" snapshot="no" type="file">
>> <source
>> file="/rhev/data-center/640fa36c-1da8-11e2-86f7-1078d2e9dece/65f95655-5bbe-47e4-8d3a-6e2ffc5c7761/images/11111111-1111-1111-1111-111111111111/Fedora-17-x86_64-DVD.iso"
>>
>> startupPolicy="optional"/>
>> <target bus="ide" dev="hdc"/>
>> <readonly/>
>> <serial></serial>
>> <boot order="1"/>
>> </disk>
>> <disk device="disk" snapshot="no" type="file">
>> <source
>> file="/rhev/data-center/640fa36c-1da8-11e2-86f7-1078d2e9dece/e552b5fd-30fb-4e18-8bc4-26517f11a283/images/025d5960-23db-4e07-98c8-4c9682155eb1/12413fe4-a694-439b-95d8-40d5a576dada"/>
>>
>> <target bus="virtio" dev="vda"/>
>> <serial>025d5960-23db-4e07-98c8-4c9682155eb1</serial>
>> <driver cache="writeback" error_policy="stop" io="threads"
>> name="qemu" type="raw"/>
>> </disk>
>> </devices>
>> <os>
>> <type arch="x86_64" machine="pc-0.14">hvm</type>
>> <smbios mode="sysinfo"/>
>> </os>
>> <sysinfo type="smbios">
>> <system>
>> <entry name="manufacturer">Red Hat</entry>
>> <entry name="product">RHEV Hypervisor</entry>
>> <entry name="version">17-1</entry>
>> <entry
>> name="serial">4C4C4544-0059-4810-8034-B7C04F463253_d4:ae:52:a3:1c:1e</entry>
>>
>> <entry
>> name="uuid">4abdba0d-aa1f-48f1-8160-3cde63165057</entry>
>> </system>
>> </sysinfo>
>> <clock adjustment="0" offset="variable">
>> <timer name="rtc" tickpolicy="catchup"/>
>> </clock>
>> <features>
>> <acpi/>
>> </features>
>> <cpu match="exact">
>> <model>Conroe</model>
>> <topology cores="2" sockets="1" threads="1"/>
>> </cpu>
>> </domain>
>>
>> libvirtEventLoop::DEBUG::2012-10-30
>> 09:56:10,075::libvirtvm::2409::vm.Vm::(_onLibvirtLifecycleEvent)
>> vmId=`4abdba0d-aa1f-48f1-8160-3cde63165057`::event Started detail 0
>> opaque None
>> Thread-1540::DEBUG::2012-10-30
>> 09:56:10,188::utils::329::vm.Vm::(start)
>> vmId=`4abdba0d-aa1f-48f1-8160-3cde63165057`::Start statistics
>> collection
>> Thread-1542::DEBUG::2012-10-30 09:56:10,188::utils::358::vm.Vm::(run)
>> vmId=`4abdba0d-aa1f-48f1-8160-3cde63165057`::Stats thread started
>> Thread-1542::DEBUG::2012-10-30
>> 09:56:10,189::task::588::TaskManager.Task::(
>> _updateState) Task=`6a004d5d-63a9-4ffb-a887-8f7d5c6179c7`::moving from
>> state init -> state preparing
>> Thread-1542::INFO::2012-10-30
>> 09:56:10,190::logUtils::37::dispatcher::(wrapper) Run and protect:
>> getVolumeSize(sdUUID='e552b5fd-30fb-4e18-8bc4-26517f11a283',
>> spUUID='640fa36c-1da8-11e2-86f7-1078d2e9dece',
>> imgUUID='025d5960-23db-4e07-98c8-4c9682155eb1',
>> volUUID='12413fe4-a694-439b-95d8-40d5a576dada', options=None)
>> Thread-1542::DEBUG::2012-10-30
>> 09:56:10,191::resourceManager::175::ResourceManager.Request::(__init__)
>> ResName=`Storage.e552b5fd-30fb-4e18-8bc4-26517f11a283`ReqID=`057d2200-a704-4de4-a45b-2771d72f30bb`::Request
>>
>> was made in '/usr/share/vdsm/storage/resourceManager.py' line '485' at
>> 'registerResource'
>> Thread-1542::DEBUG::2012-10-30
>> 09:56:10,191::resourceManager::486::ResourceManager::(registerResource)
>> Trying to register resource
>> 'Storage.e552b5fd-30fb-4e18-8bc4-26517f11a283' for lock type 'shared'
>> Thread-1540::DEBUG::2012-10-30
>> 09:56:10,192::vmChannels::144::vds::(register) Add fileno 18 to
>> listener's channels.
>> Thread-1542::DEBUG::2012-10-30
>> 09:56:10,192::resourceManager::528::ResourceManager::(registerResource)
>> Resource 'Storage.e552b5fd-30fb-4e18-8bc4-26517f11a283' is free. Now
>> locking as 'shared' (1 active user)
>> Thread-1542::DEBUG::2012-10-30
>> 09:56:10,193::resourceManager::212::ResourceManager.Request::(grant)
>> ResName=`Storage.e552b5fd-30fb-4e18-8bc4-26517f11a283`ReqID=`057d2200-a704-4de4-a45b-2771d72f30bb`::Granted
>>
>> request
>> Thread-1542::DEBUG::2012-10-30
>> 09:56:10,193::task::817::TaskManager.Task::(resourceAcquired)
>> Task=`6a004d5d-63a9-4ffb-a887-8f7d5c6179c7`::_resourcesAcquired:
>> Storage.e552b5fd-30fb-4e18-8bc4-26517f11a283 (shared)
>> Thread-1542::DEBUG::2012-10-30
>> 09:56:10,193::task::978::TaskManager.Task::(_decref)
>> Task=`6a004d5d-63a9-4ffb-a887-8f7d5c6179c7`::ref 1 aborting False
>> Thread-1542::DEBUG::2012-10-30
>> 09:56:10,195::fileVolume::535::Storage.Volume::(validateVolumePath)
>> validate path for 12413fe4-a694-439b-95d8-40d5a576dada
>> Thread-1540::WARNING::2012-10-30
>> 09:56:10,196::libvirtvm::1547::vm.Vm::(_readPauseCode)
>> vmId=`4abdba0d-aa1f-48f1-8160-3cde63165057`::_readPauseCode
>> unsupported by libvirt vm
>> Thread-1542::DEBUG::2012-10-30
>> 09:56:10,199::fileVolume::535::Storage.Volume::(validateVolumePath)
>> validate path for 12413fe4-a694-439b-95d8-40d5a576dada
>> Thread-1542::INFO::2012-10-30
>> 09:56:10,200::logUtils::39::dispatcher::(wrapper) Run and protect:
>> getVolumeSize, Return response: {'truesize': '0', 'apparentsize':
>> '8589934592'}
>> Thread-1542::DEBUG::2012-10-30
>> 09:56:10,200::task::1172::TaskManager.Task::(prepare)
>> Task=`6a004d5d-63a9-4ffb-a887-8f7d5c6179c7`::finished: {'truesize':
>> '0', 'apparentsize': '8589934592'}
>> Thread-1542::DEBUG::2012-10-30
>> 09:56:10,201::task::588::TaskManager.Task::(_updateState)
>> Task=`6a004d5d-63a9-4ffb-a887-8f7d5c6179c7`::moving from state
>> preparing -> state finished
>> Thread-1542::DEBUG::2012-10-30
>> 09:56:10,201::resourceManager::809::ResourceManager.Owner::(releaseAll)
>> Owner.releaseAll requests {} resources
>> {'Storage.e552b5fd-30fb-4e18-8bc4-26517f11a283': < ResourceRef
>> 'Storage.e552b5fd-30fb-4e18-8bc4-26517f11a283', isValid: 'True' obj:
>> 'None'>}
>> Thread-1542::DEBUG::2012-10-30
>> 09:56:10,201::resourceManager::844::ResourceManager.Owner::(cancelAll)
>> Owner.cancelAll requests {}
>> Thread-1542::DEBUG::2012-10-30
>> 09:56:10,201::resourceManager::538::ResourceManager::(releaseResource)
>> Trying to release resource
>> 'Storage.e552b5fd-30fb-4e18-8bc4-26517f11a283'
>> Thread-1542::DEBUG::2012-10-30
>> 09:56:10,202::resourceManager::553::ResourceManager::(releaseResource)
>> Released resource 'Storage.e552b5fd-30fb-4e18-8bc4-26517f11a283' (0
>> active users)
>> Thread-1542::DEBUG::2012-10-30
>> 09:56:10,202::resourceManager::558::ResourceManager::(releaseResource)
>> Resource 'Storage.e552b5fd-30fb-4e18-8bc4-26517f11a283' is free,
>> finding out if anyone is waiting for it.
>> Thread-1542::DEBUG::2012-10-30
>> 09:56:10,203::resourceManager::565::ResourceManager::(releaseResource)
>> No one is waiting for resource
>> 'Storage.e552b5fd-30fb-4e18-8bc4-26517f11a283', Clearing records.
>> Thread-1542::DEBUG::2012-10-30
>> 09:56:10,203::task::978::TaskManager.Task::(_decref)
>> Task=`6a004d5d-63a9-4ffb-a887-8f7d5c6179c7`::ref 0 aborting False
>> Thread-1540::DEBUG::2012-10-30
>> 09:56:10,206::__init__::1249::Storage.Misc.excCmd::(_log)
>> '/usr/bin/sudo -n /usr/sbin/service ksmtuned retune' (cwd None)
>> Thread-1540::DEBUG::2012-10-30
>> 09:56:10,241::__init__::1249::Storage.Misc.excCmd::(_log) FAILED:
>> <err> = "Redirecting to /bin/systemctl retune
>> ksmtuned.service\nUnknown operation 'retune'.\n"; <rc> = 1
>> Thread-1540::DEBUG::2012-10-30 09:56:10,242::vm::580::vm.Vm::(_startUnde
>> rlyingVm) vmId=`4abdba0d-aa1f-48f1-8160-3cde63165057`::_ongoingCreations
>> released
>> VM Channels Listener::DEBUG::2012-10-30
>> 09:56:10,376::vmChannels::71::vds::(_do_add_channels) fileno 18 was
>> added to unconnected channels.
>> VM Channels Listener::DEBUG::2012-10-30
>> 09:56:10,376::vmChannels::103::vds::(_handle_unconnected) Trying to
>> connect fileno 18.
>> VM Channels Listener::DEBUG::2012-10-30
>> 09:56:10,376::guestIF::81::vm.Vm::(_connect)
>> vmId=`4abdba0d-aa1f-48f1-8160-3cde63165057`::Attempting connection to
>> /var/lib/libvirt/qemu/channels/bsdlinux04vm.com.redhat.rhevm.vdsm
>> VM Channels Listener::DEBUG::2012-10-30
>> 09:56:10,377::guestIF::83::vm.Vm::(_connect)
>> vmId=`4abdba0d-aa1f-48f1-8160-3cde63165057`::Connected to
>> /var/lib/libvirt/qemu/channels/bsdlinux04vm.com.redhat.rhevm.vdsm
>> VM Channels Listener::DEBUG::2012-10-30
>> 09:56:10,377::vmChannels::106::vds::(_handle_unconnected) Connect
>> fileno 18 was succeed.
>> Thread-1543::DEBUG::2012-10-30
>> 09:56:14,759::BindingXMLRPC::156::vds::(wrapper) [192.168.1.10]
>> Thread-1543::DEBUG::2012-10-30
>> 09:56:14,760::task::588::TaskManager.Task::(_updateState)
>> Task=`3379e8b3-bf70-49d0-b643-0bb17de93846`::moving from state init ->
>> state preparing
>> Thread-1543::INFO::2012-10-30
>> 09:56:14,760::logUtils::37::dispatcher::(wrapper) Run and protect:
>> getSpmStatus(spUUID='640fa36c-1da8-11e2-86f7-1078d2e9dece',
>> options=None)
>> Thread-1543::INFO::2012-10-30
>> 09:56:14,761::logUtils::39::dispatcher::(wrapper) Run and protect:
>> getSpmStatus, Return response: {'spm_st': {'spmId': 1, 'spmStatus':
>> 'SPM', 'spmLver': 1}}
>> Thread-1543::DEBUG::2012-10-30
>> 09:56:14,761::task::1172::TaskManager.Task::(prepare)
>> Task=`3379e8b3-bf70-49d0-b643-0bb17de93846`::finished: {'spm_st':
>> {'spmId': 1, 'spmStatus': 'SPM', 'spmLver': 1}}
>> Thread-1543::DEBUG::2012-10-30
>> 09:56:14,761::task::588::TaskManager.Task::(_updateState)
>> Task=`3379e8b3-bf70-49d0-b643-0bb17de93846`::moving from state
>> preparing -> state finished
>> Thread-1543::DEBUG::2012-10-30
>> 09:56:14,761::resourceManager::809::ResourceManager.Owner::(releaseAll)
>> Owner.releaseAll requests {} resources {}
>> Thread-1543::DEBUG::2012-10-30
>> 09:56:14,762::resourceManager::844::ResourceManager.Owner::(cancelAll)
>> Owner.cancelAll requests {}
>> Thread-1543::DEBUG::2012-10-30
>> 09:56:14,762::task::978::TaskManager.Task::(_decref)
>> Task=`3379e8b3-bf70-49d0-b643-0bb17de93846`::ref 0 aborting False
>> Thread-1544::DEBUG::2012-10-30
>> 09:56:14,781::BindingXMLRPC::156::vds::(wrapper) [192.168.1.10]
>> Thread-1544::DEBUG::2012-10-30
>> 09:56:14,782::task::588::TaskManager.Task::(_updateState)
>> Task=`f7a0fd20-fddb-48f7-832e-ed230b49d4f0`::moving from state init ->
>> state preparing
>> Thread-1544::INFO::2012-10-30
>> 09:56:14,782::logUtils::37::dispatcher::(wrapper) Run and protect:
>> getStoragePoolInfo(spUUID='640fa36c-1da8-11e2-86f7-1078d2e9dece',
>> options=None)
>> Thread-1544::DEBUG::2012-10-30
>> 09:56:14,782::resourceManager::175::ResourceManager.Request::(__init__)
>> ResName=`Storage.640fa36c-1da8-11e2-86f7-1078d2e9dece`ReqID=`7e21374b-d582-451f-b37a-ee1ea2f206f1`::Request
>>
>> was made in '/usr/share/vdsm/storage/resourceManager.py' line '485' at
>> 'registerResource'
>> Thread-1544::DEBUG::2012-10-30
>> 09:56:14,783::resourceManager::486::ResourceManager::(registerResource)
>> Trying to register resource
>> 'Storage.640fa36c-1da8-11e2-86f7-1078d2e9dece' for lock type 'shared'
>> Thread-1544::DEBUG::2012-10-30
>> 09:56:14,783::resourceManager::528::ResourceManager::(registerResource)
>> Resource 'Storage.640fa36c-1da8-11e2-86f7-1078d2e9dece' is free. Now
>> locking as 'shared' (1 active user)
>> Thread-1544::DEBUG::2012-10-30
>> 09:56:14,783::resourceManager::212::ResourceManager.Request::(grant)
>> ResName=`Storage.640fa36c-1da8-11e2-86f7-1078d2e9dece`ReqID=`7e21374b-d582-451f-b37a-ee1ea2f206f1`::Granted
>>
>> request
>> Thread-1544::DEBUG::2012-10-30
>> 09:56:14,784::task::817::TaskManager.Task::(resourceAcquired)
>> Task=`f7a0fd20-fddb-48f7-832e-ed230b49d4f0`::_resourcesAcquired:
>> Storage.640fa36c-1da8-11e2-86f7-1078d2e9dece (shared)
>> Thread-1544::DEBUG::2012-10-30
>> 09:56:14,784::task::978::TaskManager.Task::(_decref)
>> Task=`f7a0fd20-fddb-48f7-832e-ed230b49d4f0`::ref 1 aborting False
>> Thread-1544::INFO::2012-10-30
>> 09:56:14,793::logUtils::39::dispatcher::(wrapper) Run and protect:
>> getStoragePoolInfo, Return response: {'info': {'spm_id': 1,
>> 'master_uuid': 'e552b5fd-30fb-4e18-8bc4-26517f11a283', 'name':
>> 'Default', 'version': '0', 'domains':
>> '65f95655-5bbe-47e4-8d3a-6e2ffc5c7761:Active,e552b5fd-30fb-4e18-8bc4-26517f11a283:Active',
>>
>> 'pool_status': 'connected', 'isoprefix':
>> '/rhev/data-center/640fa36c-1da8-11e2-86f7-1078d2e9dece/65f95655-5bbe-47e4-8d3a-6e2ffc5c7761/images/11111111-1111-1111-1111-111111111111',
>>
>> 'type': 'SHAREDFS', 'master_ver': 1, 'lver': 1}, 'dominfo':
>> {'65f95655-5bbe-47e4-8d3a-6e2ffc5c7761': {'status': 'Active',
>> 'diskfree': '382827757568', 'alerts': [], 'disktotal':
>> '424540110848'}, 'e552b5fd-30fb-4e18-8bc4-26517f11a283': {'status':
>> 'Active', 'diskfree': '2099627163648', 'alerts': [], 'disktotal':
>> '2212208836608'}}}
>> Thread-1544::DEBUG::2012-10-30
>> 09:56:14,793::task::1172::TaskManager.Task::(prepare)
>> Task=`f7a0fd20-fddb-48f7-832e-ed230b49d4f0`::finished: {'info':
>> {'spm_id': 1, 'master_uuid': 'e552b5fd-30fb-4e18-8bc4-26517f11a283',
>> 'name': 'Default', 'version': '0', 'domains':
>> '65f95655-5bbe-47e4-8d3a-6e2ffc5c7761:Active,e552b5fd-30fb-4e18-8bc4-26517f11a283:Active',
>>
>> 'pool_status': 'connected', 'isoprefix':
>> '/rhev/data-center/640fa36c-1da8-11e2-86f7-1078d2e9dece/65f95655-5bbe-47e4-8d3a-6e2ffc5c7761/images/11111111-1111-1111-1111-111111111111',
>>
>> 'type': 'SHAREDFS', 'master_ver': 1, 'lver': 1}, 'dominfo':
>> {'65f95655-5bbe-47e4-8d3a-6e2ffc5c7761': {'status': 'Active',
>> 'diskfree': '382827757568', 'alerts': [], 'disktotal':
>> '424540110848'}, 'e552b5fd-30fb-4e18-8bc4-26517f11a283': {'status':
>> 'Active', 'diskfree': '2099627163648', 'alerts': [], 'disktotal':
>> '2212208836608'}}}
>> Thread-1544::DEBUG::2012-10-30
>> 09:56:14,794::task::588::TaskManager.Task::(_updateState)
>> Task=`f7a0fd20-fddb-48f7-832e-ed230b49d4f0`::moving from state
>> preparing -> state finished
>> Thread-1544::DEBUG::2012-10-30
>> 09:56:14,794::resourceManager::809::ResourceManager.Owner::(releaseAll)
>> Owner.releaseAll requests {} resources
>> {'Storage.640fa36c-1da8-11e2-86f7-1078d2e9dece': < ResourceRef
>> 'Storage.640fa36c-1da8-11e2-86f7-1078d2e9dece', isValid: 'True' obj:
>> 'None'>}
>> Thread-1544::DEBUG::2012-10-30
>> 09:56:14,794::resourceManager::844::ResourceManager.Owner::(cancelAll)
>> Owner.cancelAll requests {}
>> Thread-1544::DEBUG::2012-10-30
>> 09:56:14,794::resourceManager::538::ResourceManager::(releaseResource)
>> Trying to release resource
>> 'Storage.640fa36c-1da8-11e2-86f7-1078d2e9dece'
>> Thread-1544::DEBUG::2012-10-30
>> 09:56:14,795::resourceManager::553::ResourceManager::(releaseResource)
>> Released resource 'Storage.640fa36c-1da8-11e2-86f7-1078d2e9dece' (0
>> active users)
>> Thread-1544::DEBUG::2012-10-30
>> 09:56:14,795::resourceManager::558::ResourceManager::(releaseResource)
>> Resource 'Storage.640fa36c-1da8-11e2-86f7-1078d2e9dece' is free,
>> finding out if anyone is waiting for it.
>> Thread-1544::DEBUG::2012-10-30
>> 09:56:14,795::resourceManager::565::ResourceManager::(releaseResource)
>> No one is waiting for resource
>> 'Storage.640fa36c-1da8-11e2-86f7-1078d2e9dece', Clearing records.
>> Thread-1544::DEBUG::2012-10-30
>> 09:56:14,795::task::978::TaskManager.Task::(_decref)
>> Task=`f7a0fd20-fddb-48f7-832e-ed230b49d4f0`::ref 0 aborting False
>> Thread-1545::DEBUG::2012-10-30
>> 09:56:24,820::BindingXMLRPC::156::vds::(wrapper) [192.168.1.10]
>> Thread-1545::DEBUG::2012-10-30
>> 09:56:24,820::task::588::TaskManager.Task::(_updateState)
>> Task=`911438a8-fbf0-456f-b979-9e361bda85f2`::moving from state init ->
>> state preparing
>> Thread-1545::INFO::2012-10-30
>> 09:56:24,821::logUtils::37::dispatcher::(wrapper) Run and protect:
>> getSpmStatus(spUUID='640fa36c-1da8-11e2-86f7-1078d2e9dece',
>> options=None)
>> Thread-1545::INFO::2012-10-30
>> 09:56:24,821::logUtils::39::dispatcher::(wrapper) Run and protect:
>> getSpmStatus, Return response: {'spm_st': {'spmId': 1, 'spmStatus':
>> 'SPM', 'spmLver': 1}}
>> Thread-1545::DEBUG::2012-10-30
>> 09:56:24,821::task::1172::TaskManager.Task::(prepare)
>> Task=`911438a8-fbf0-456f-b979-9e361bda85f2`::finished: {'spm_st':
>> {'spmId': 1, 'spmStatus': 'SPM', 'spmLver': 1}}
>> Thread-1545::DEBUG::2012-10-30
>> 09:56:24,822::task::588::TaskManager.Task::(_updateState)
>> Task=`911438a8-fbf0-456f-b979-9e361bda85f2`::moving from state
>> preparing -> state finished
>> Thread-1545::DEBUG::2012-10-30
>> 09:56:24,822::resourceManager::809::ResourceManager.Owner::(releaseAll)
>> Owner.releaseAll requests {} resources {}
>> Thread-1545::DEBUG::2012-10-30
>> 09:56:24,822::resourceManager::844::ResourceManager.Owner::(cancelAll)
>> Owner.cancelAll requests {}
>> Thread-1545::DEBUG::2012-10-30
>> 09:56:24,822::task::978::TaskManager.Task::(_decref)
>> Task=`911438a8-fbf0-456f-b979-9e361bda85f2`::ref 0 aborting False
>> Thread-1546::DEBUG::2012-10-30
>> 09:56:24,840::BindingXMLRPC::156::vds::(wrapper) [192.168.1.10]
>> Thread-1546::DEBUG::2012-10-30
>> 09:56:24,841::task::588::TaskManager.Task::(_updateState)
>> Task=`fbf6f12b-58f8-45bf-b34f-5fa3ae93123c`::moving from state init ->
>> state preparing
>> Thread-1546::INFO::2012-10-30
>> 09:56:24,841::logUtils::37::dispatcher::(wrapper) Run and protect:
>> getStoragePoolInfo(spUUID='640fa36c-1da8-11e2-86f7-1078d2e9dece',
>> options=None)
>> Thread-1546::DEBUG::2012-10-30
>> 09:56:24,841::resourceManager::175::ResourceManager.Request::(__init__)
>> ResName=`Storage.640fa36c-1da8-11e2-86f7-1078d2e9dece`ReqID=`c8c2813e-c44c-44f2-b1dd-0f797ecadce3`::Request
>>
>> was made in '/usr/share/vdsm/storage/resourceManager.py' line '485' at
>> 'registerResource'
>> Thread-1546::DEBUG::2012-10-30
>> 09:56:24,842::resourceManager::486::ResourceManager::(registerResource)
>> Trying to register resource
>> 'Storage.640fa36c-1da8-11e2-86f7-1078d2e9dece' for lock type 'shared'
>> Thread-1546::DEBUG::2012-10-30
>> 09:56:24,842::resourceManager::528::ResourceManager::(registerResource)
>> Resource 'Storage.640fa36c-1da8-11e2-86f7-1078d2e9dece' is free. Now
>> locking as 'shared' (1 active user)
>> Thread-1546::DEBUG::2012-10-30
>> 09:56:24,842::resourceManager::212::ResourceManager.Request::(grant)
>> ResName=`Storage.640fa36c-1da8-11e2-86f7-1078d2e9dece`ReqID=`c8c2813e-c44c-44f2-b1dd-0f797ecadce3`::Granted
>>
>> request
>> Thread-1546::DEBUG::2012-10-30
>> 09:56:24,843::task::817::TaskManager.Task::(resourceAcquired)
>> Task=`fbf6f12b-58f8-45bf-b34f-5fa3ae93123c`::_resourcesAcquired:
>> Storage.640fa36c-1da8-11e2-86f7-1078d2e9dece (shared)
>> Thread-1546::DEBUG::2012-10-30
>> 09:56:24,843::task::978::TaskManager.Task::(_decref)
>> Task=`fbf6f12b-58f8-45bf-b34f-5fa3ae93123c`::ref 1 aborting False
>> Thread-1546::INFO::2012-10-30
>> 09:56:24,852::logUtils::39::dispatcher::(wrapper) Run and protect:
>> getStoragePoolInfo, Return response: {'info': {'spm_id': 1,
>> 'master_uuid': 'e552b5fd-30fb-4e18-8bc4-26517f11a283', 'name':
>> 'Default', 'version': '0', 'domains':
>> '65f95655-5bbe-47e4-8d3a-6e2ffc5c7761:Active,e552b5fd-30fb-4e18-8bc4-26517f11a283:Active',
>>
>> 'pool_status': 'connected', 'isoprefix':
>> '/rhev/data-center/640fa36c-1da8-11e2-86f7-1078d2e9dece/65f95655-5bbe-47e4-8d3a-6e2ffc5c7761/images/11111111-1111-1111-1111-111111111111',
>>
>> 'type': 'SHAREDFS', 'master_ver': 1, 'lver': 1}, 'dominfo':
>> {'65f95655-5bbe-47e4-8d3a-6e2ffc5c7761': {'status': 'Active',
>> 'diskfree': '382827757568', 'alerts': [], 'disktotal':
>> '424540110848'}, 'e552b5fd-30fb-4e18-8bc4-26517f11a283': {'status':
>> 'Active', 'diskfree': '2099627163648', 'alerts': [], 'disktotal':
>> '2212208836608'}}}
>> Thread-1546::DEBUG::2012-10-30
>> 09:56:24,853::task::1172::TaskManager.Task::(prepare)
>> Task=`fbf6f12b-58f8-45bf-b34f-5fa3ae93123c`::finished: {'info':
>> {'spm_id': 1, 'master_uuid': 'e552b5fd-30fb-4e18-8bc4-26517f11a283',
>> 'name': 'Default', 'version': '0', 'domains':
>> '65f95655-5bbe-47e4-8d3a-6e2ffc5c7761:Active,e552b5fd-30fb-4e18-8bc4-26517f11a283:Active',
>>
>> 'pool_status': 'connected', 'isoprefix':
>> '/rhev/data-center/640fa36c-1da8-11e2-86f7-1078d2e9dece/65f95655-5bbe-47e4-8d3a-6e2ffc5c7761/images/11111111-1111-1111-1111-111111111111',
>>
>> 'type': 'SHAREDFS', 'master_ver': 1, 'lver': 1}, 'dominfo':
>> {'65f95655-5bbe-47e4-8d3a-6e2ffc5c7761': {'status': 'Active',
>> 'diskfree': '382827757568', 'alerts': [], 'disktotal':
>> '424540110848'}, 'e552b5fd-30fb-4e18-8bc4-26517f11a283': {'status':
>> 'Active', 'diskfree': '2099627163648', 'alerts': [], 'disktotal':
>> '2212208836608'}}}
>> Thread-1546::DEBUG::2012-10-30
>> 09:56:24,853::task::588::TaskManager.Task::(_updateState)
>> Task=`fbf6f12b-58f8-45bf-b34f-5fa3ae93123c`::moving from state
>> preparing -> state finished
>> Thread-1546::DEBUG::2012-10-30
>> 09:56:24,853::resourceManager::809::ResourceManager.Owner::(releaseAll)
>> Owner.releaseAll requests {} resources
>> {'Storage.640fa36c-1da8-11e2-86f7-1078d2e9dece': < ResourceRef
>> 'Storage.640fa36c-1da8-11e2-86f7-1078d2e9dece', isValid: 'True' obj:
>> 'None'>}
>> Thread-1546::DEBUG::2012-10-30
>> 09:56:24,853::resourceManager::844::ResourceManager.Owner::(cancelAll)
>> Owner.cancelAll requests {}
>> Thread-1546::DEBUG::2012-10-30
>> 09:56:24,854::resourceManager::538::ResourceManager::(releaseResource)
>> Trying to release resource
>> 'Storage.640fa36c-1da8-11e2-86f7-1078d2e9dece'
>> Thread-1546::DEBUG::2012-10-30
>> 09:56:24,854::resourceManager::553::ResourceManager::(releaseResource)
>> Released resource 'Storage.640fa36c-1da8-11e2-86f7-1078d2e9dece' (0
>> active users)
>> Thread-1546::DEBUG::2012-10-30
>> 09:56:24,854::resourceManager::558::ResourceManager::(releaseResource)
>> Resource 'Storage.640fa36c-1da8-11e2-86f7-1078d2e9dece' is free,
>> finding out if anyone is waiting for it.
>> Thread-1546::DEBUG::2012-10-30
>> 09:56:24,854::resourceManager::565::ResourceManager::(releaseResource)
>> No one is waiting for resource
>> 'Storage.640fa36c-1da8-11e2-86f7-1078d2e9dece', Clearing records.
>> Thread-1546::DEBUG::2012-10-30
>> 09:56:24,855::task::978::TaskManager.Task::(_decref)
>> Task=`fbf6f12b-58f8-45bf-b34f-5fa3ae93123c`::ref 0 aborting False
>>
>>
>> Regards
>> Daniel Rowe
>> _______________________________________________
>> Users mailing list
>> Users at ovirt.org
>> http://lists.ovirt.org/mailman/listinfo/users
>
> _______________________________________________
> Users mailing list
> Users at ovirt.org
> http://lists.ovirt.org/mailman/listinfo/users
More information about the Users
mailing list