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