When it happened, the environment is:
Node:
    OS: Fedora 16
    VDSM: from git source(931a43ea0c847e6c843aa14573318e35fc6c043d)
engine-core:
    OS: Fedora 16
    Engine-Core: from git source( d64bc2b8f8ba99593f8cda0e511789c64ffb1be4 )

The attachment is the vdsm log when it happened.However, I couldn't
reproduce it using the same environment now.I will continue to try to
reproduce it. If any update, I comment it.

2011/12/6 Dan Kenigsberg <dan...@redhat.com>

> On Tue, Dec 06, 2011 at 02:10:48PM +0800, Jarod. w wrote:
> > Hi, All
> >
> >     The patch will fix error message "UnboundLocalError: local variable
> > 'path' referenced before assignment" when running vm.
> >
> >     thanks.
> >
> > >From 1f99c4f5b04100231c8712f2caf97d11dcc9eb37 Mon Sep 17 00:00:00 2001
> > From: "jarod.w" <work.iec23...@gmail.com>
> > Date: Tue, 6 Dec 2011 14:00:58 +0800
> > Subject: [PATCH] Fix error message "UnboundLocalError: local variable
> 'path'
> >  referenced before assignment" when running vm.
> >
> > When the drive argument can't be parsed in _prepareVolumePath function,
> the
> > self.log.info statement will report the error in the
> /var/log/vdsm/vdsm.log
> > because the local variable 'path' isn't assigned. The patch adds the else
> > statement to assign the local variable.
> > ---
> >  vdsm/clientIF.py |    3 +++
> >  1 files changed, 3 insertions(+), 0 deletions(-)
> >
> > diff --git a/vdsm/clientIF.py b/vdsm/clientIF.py
> > index 9d6b942..10e3a24 100644
> > --- a/vdsm/clientIF.py
> > +++ b/vdsm/clientIF.py
> > @@ -590,6 +590,9 @@ class clientIF:
> >              path = drive
> >          elif os.path.exists(drive):
> >              path = drive
> > +        else:
> > +            self.log.info("invaild drive : %s" % str(drive) )
> > +            path = ''
> >          self.log.info("prepared volume path: %s" % path)
> >          return path
>
>
> Jarod, your patch seems fine (though using str() is supefluous), but I'm
> interested to know why did the 'drive' argument failed parsing?
>
> I would also appreciate if you send patches for review in gerrit.ovirt.org
> .
>
> Regards,
>
> Dan.
>
Thread-142::DEBUG::2011-12-02 15:59:20,735::clientIF::75::vds::(wrapper) [192.168.0.236]::call create with ({'bridge': 'engine', 'acpiEnable': 'true', 'emulatedMachine': 'rhel6.2.0', 'vmId': 'cdb466ca-e3d8-45fb-a01c-24a2f2bdf72c', 'transparentHugePages': 'true', 'timeOffset': '0', 'cpuType': 'Penryn', 'smp': '1', 'macAddr': '00:1a:4a:16:01:54', 'boot': 'c', 'custom': {}, 'vmType': 'kvm', 'memSize': 1024, 'smpCoresPerSocket': '1', 'vmName': 'onode', 'spiceMonitors': '1', 'nice': '0', 'drives': [{'domainID': 'da74f982-2081-4b9f-89e6-2febdcdc1e97', 'format': 'raw', 'bus': '0', 'boot': 'true', 'volumeID': '684a46c7-e78f-4f37-90a1-a697f873ec7b', 'imageID': '0177e3ec-3bfc-4bc8-9786-88d7e3c8752e', 'poolID': '085f83a8-1001-11e1-b008-67e7d7babce0', 'propagateErrors': 'off', 'if': 'virtio'}], 'cdrom': '/rhev/data-center/085f83a8-1001-11e1-b008-67e7d7babce0/aeb6f289-48a0-4af5-a09c-a119d395bcb3/images/11111111-1111-1111-1111-111111111111/ovirt-node-image.iso', 'nicModel': 'pv', 'keyboardLayout': 'en-us', 'kvmEnable': 'true', 'pitReinjection': 'false', 'displayNetwork': 'engine', 'soundDevice': 'ac97', 'display': 'qxl'},) {}
Thread-142::INFO::2011-12-02 15:59:20,745::clientIF::699::vds::(create) vmContainerLock acquired by vm cdb466ca-e3d8-45fb-a01c-24a2f2bdf72c
Thread-142::DEBUG::2011-12-02 15:59:20,766::clientIF::712::vds::(create) Total desktops after creation of cdb466ca-e3d8-45fb-a01c-24a2f2bdf72c is 1
Thread-143::DEBUG::2011-12-02 15:59:20,766::vm::344::vm.Vm::(_startUnderlyingVm) vmId=`cdb466ca-e3d8-45fb-a01c-24a2f2bdf72c`::Start
Thread-142::DEBUG::2011-12-02 15:59:20,767::clientIF::80::vds::(wrapper) return create with {'status': {'message': 'Done', 'code': 0}, 'vmList': {'cdrom': '/rhev/data-center/085f83a8-1001-11e1-b008-67e7d7babce0/aeb6f289-48a0-4af5-a09c-a119d395bcb3/images/11111111-1111-1111-1111-111111111111/ovirt-node-image.iso', 'bridge': 'engine', 'acpiEnable': 'true', 'emulatedMachine': 'rhel6.2.0', 'vmId': 'cdb466ca-e3d8-45fb-a01c-24a2f2bdf72c', 'pid': '0', 'drives': [{'domainID': 'da74f982-2081-4b9f-89e6-2febdcdc1e97', 'format': 'raw', 'bus': '0', 'boot': 'true', 'volumeID': '684a46c7-e78f-4f37-90a1-a697f873ec7b', 'imageID': '0177e3ec-3bfc-4bc8-9786-88d7e3c8752e', 'poolID': '085f83a8-1001-11e1-b008-67e7d7babce0', 'propagateErrors': 'off', 'if': 'virtio'}], 'transparentHugePages': 'true', 'keyboardLayout': 'en-us', 'displaySecurePort': '-1', 'displayPort': '-1', 'cpuType': 'Penryn', 'custom': {}, 'nicModel': 'pv', 'soundDevice': 'ac97', 'macAddr': '00:1a:4a:16:01:54', 'kvmEnable': 'true', 'pitReinjection': 'false', 'displayNetwork': 'engine', 'boot': 'c', 'smp': '1', 'vmType': 'kvm', 'status': 'WaitForLaunch', 'timeOffset': '0', 'memSize': 1024, 'displayIp': '192.168.1.106', 'clientIp': '', 'smpCoresPerSocket': '1', 'vmName': 'onode', 'display': 'qxl', 'spiceMonitors': '1', 'nice': '0'}}
Thread-143::DEBUG::2011-12-02 15:59:20,767::vm::348::vm.Vm::(_startUnderlyingVm) vmId=`cdb466ca-e3d8-45fb-a01c-24a2f2bdf72c`::_ongoingCreations acquired
Thread-143::INFO::2011-12-02 15:59:20,768::libvirtvm::1075::vm.Vm::(_run) vmId=`cdb466ca-e3d8-45fb-a01c-24a2f2bdf72c`::VM wrapper has started
Thread-143::DEBUG::2011-12-02 15:59:20,769::task::588::TaskManager.Task::(_updateState) Task=`57c547a5-4fd8-4dc8-b2a3-5367b5f1d5e1`::moving from state init -> state preparing
Thread-143::INFO::2011-12-02 15:59:20,769::logUtils::37::dispatcher::(wrapper) Run and protect: public_prepareVolume(sdUUID='da74f982-2081-4b9f-89e6-2febdcdc1e97', spUUID='085f83a8-1001-11e1-b008-67e7d7babce0', imgUUID='0177e3ec-3bfc-4bc8-9786-88d7e3c8752e', volUUID='684a46c7-e78f-4f37-90a1-a697f873ec7b', rw=True, options=None)
Thread-143::DEBUG::2011-12-02 15:59:20,770::resourceManager::174::ResourceManager.Request::(__init__) ResName=`Storage.da74f982-2081-4b9f-89e6-2febdcdc1e97`ReqID=`8a5d194f-8e2b-429d-bd88-526f745f236a`::Request was made in '/usr/share/vdsm/storage/hsm.py' line '2440' at 'public_prepareVolume'
Thread-143::DEBUG::2011-12-02 15:59:20,770::resourceManager::487::ResourceManager::(registerResource) Trying to register resource 'Storage.da74f982-2081-4b9f-89e6-2febdcdc1e97' for lock type 'shared'
Thread-143::DEBUG::2011-12-02 15:59:20,770::resourceManager::528::ResourceManager::(registerResource) Resource 'Storage.da74f982-2081-4b9f-89e6-2febdcdc1e97' is free. Now locking as 'shared' (1 active user)
Thread-143::DEBUG::2011-12-02 15:59:20,771::resourceManager::211::ResourceManager.Request::(grant) ResName=`Storage.da74f982-2081-4b9f-89e6-2febdcdc1e97`ReqID=`8a5d194f-8e2b-429d-bd88-526f745f236a`::Granted request
Thread-143::DEBUG::2011-12-02 15:59:20,771::task::819::TaskManager.Task::(resourceAcquired) Task=`57c547a5-4fd8-4dc8-b2a3-5367b5f1d5e1`::_resourcesAcquired: Storage.da74f982-2081-4b9f-89e6-2febdcdc1e97 (shared)
Thread-143::DEBUG::2011-12-02 15:59:20,771::task::980::TaskManager.Task::(_decref) Task=`57c547a5-4fd8-4dc8-b2a3-5367b5f1d5e1`::ref 1 aborting False
Thread-143::DEBUG::2011-12-02 15:59:20,772::resourceManager::174::ResourceManager.Request::(__init__) ResName=`da74f982-2081-4b9f-89e6-2febdcdc1e97_imageNS.0177e3ec-3bfc-4bc8-9786-88d7e3c8752e`ReqID=`495ecb10-888b-40ea-80c8-bf56825a9f87`::Request was made in '/usr/share/vdsm/storage/hsm.py' line '2445' at 'public_prepareVolume'
Thread-143::DEBUG::2011-12-02 15:59:20,772::resourceManager::487::ResourceManager::(registerResource) Trying to register resource 'da74f982-2081-4b9f-89e6-2febdcdc1e97_imageNS.0177e3ec-3bfc-4bc8-9786-88d7e3c8752e' for lock type 'exclusive'
Thread-143::DEBUG::2011-12-02 15:59:20,775::fileVolume::529::Storage.Volume::(validateVolumePath) validate path for 684a46c7-e78f-4f37-90a1-a697f873ec7b
Thread-143::DEBUG::2011-12-02 15:59:20,778::fileVolume::529::Storage.Volume::(validateVolumePath) validate path for 684a46c7-e78f-4f37-90a1-a697f873ec7b
Thread-143::DEBUG::2011-12-02 15:59:20,780::fileVolume::529::Storage.Volume::(validateVolumePath) validate path for 684a46c7-e78f-4f37-90a1-a697f873ec7b
Thread-143::INFO::2011-12-02 15:59:20,783::image::351::Storage.Image::(getChain) sdUUID=da74f982-2081-4b9f-89e6-2febdcdc1e97 imgUUID=0177e3ec-3bfc-4bc8-9786-88d7e3c8752e chain=[<storage.fileVolume.FileVolume instance at 0x7fb1343093f8>] 
Thread-143::DEBUG::2011-12-02 15:59:20,784::resourceManager::174::ResourceManager.Request::(__init__) ResName=`da74f982-2081-4b9f-89e6-2febdcdc1e97_volumeNS.684a46c7-e78f-4f37-90a1-a697f873ec7b`ReqID=`cb6b0df8-a832-4188-98c3-3ddfecd968da`::Request was made in '/usr/share/vdsm/storage/resourceFactories.py' line '165' at '__getResourceCandidatesList'
Thread-143::DEBUG::2011-12-02 15:59:20,784::resourceManager::487::ResourceManager::(registerResource) Trying to register resource 'da74f982-2081-4b9f-89e6-2febdcdc1e97_volumeNS.684a46c7-e78f-4f37-90a1-a697f873ec7b' for lock type 'exclusive'
Thread-143::DEBUG::2011-12-02 15:59:20,784::resourceManager::528::ResourceManager::(registerResource) Resource 'da74f982-2081-4b9f-89e6-2febdcdc1e97_volumeNS.684a46c7-e78f-4f37-90a1-a697f873ec7b' is free. Now locking as 'exclusive' (1 active user)
Thread-143::DEBUG::2011-12-02 15:59:20,785::resourceManager::211::ResourceManager.Request::(grant) ResName=`da74f982-2081-4b9f-89e6-2febdcdc1e97_volumeNS.684a46c7-e78f-4f37-90a1-a697f873ec7b`ReqID=`cb6b0df8-a832-4188-98c3-3ddfecd968da`::Granted request
Thread-143::DEBUG::2011-12-02 15:59:20,785::resourceManager::528::ResourceManager::(registerResource) Resource 'da74f982-2081-4b9f-89e6-2febdcdc1e97_imageNS.0177e3ec-3bfc-4bc8-9786-88d7e3c8752e' is free. Now locking as 'exclusive' (1 active user)
Thread-143::DEBUG::2011-12-02 15:59:20,785::resourceManager::211::ResourceManager.Request::(grant) ResName=`da74f982-2081-4b9f-89e6-2febdcdc1e97_imageNS.0177e3ec-3bfc-4bc8-9786-88d7e3c8752e`ReqID=`495ecb10-888b-40ea-80c8-bf56825a9f87`::Granted request
Thread-143::DEBUG::2011-12-02 15:59:20,786::fileVolume::529::Storage.Volume::(validateVolumePath) validate path for 684a46c7-e78f-4f37-90a1-a697f873ec7b
Thread-143::INFO::2011-12-02 15:59:20,787::volume::534::Storage.Volume::(prepare) Volume: preparing volume da74f982-2081-4b9f-89e6-2febdcdc1e97/684a46c7-e78f-4f37-90a1-a697f873ec7b
Thread-143::INFO::2011-12-02 15:59:20,794::logUtils::39::dispatcher::(wrapper) Run and protect: public_prepareVolume, Return response: None
Thread-143::DEBUG::2011-12-02 15:59:20,794::task::1174::TaskManager.Task::(prepare) Task=`57c547a5-4fd8-4dc8-b2a3-5367b5f1d5e1`::finished: None
Thread-143::DEBUG::2011-12-02 15:59:20,795::task::588::TaskManager.Task::(_updateState) Task=`57c547a5-4fd8-4dc8-b2a3-5367b5f1d5e1`::moving from state preparing -> state finished
Thread-143::DEBUG::2011-12-02 15:59:20,795::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {'Storage.da74f982-2081-4b9f-89e6-2febdcdc1e97': < ResourceRef 'Storage.da74f982-2081-4b9f-89e6-2febdcdc1e97', isValid: 'True' obj: 'None'>}
Thread-143::DEBUG::2011-12-02 15:59:20,795::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-143::DEBUG::2011-12-02 15:59:20,795::resourceManager::537::ResourceManager::(releaseResource) Trying to release resource 'Storage.da74f982-2081-4b9f-89e6-2febdcdc1e97'
Thread-143::DEBUG::2011-12-02 15:59:20,796::resourceManager::552::ResourceManager::(releaseResource) Released resource 'Storage.da74f982-2081-4b9f-89e6-2febdcdc1e97' (0 active users)
Thread-143::DEBUG::2011-12-02 15:59:20,796::resourceManager::557::ResourceManager::(releaseResource) Resource 'Storage.da74f982-2081-4b9f-89e6-2febdcdc1e97' is free, finding out if anyone is waiting for it.
Thread-143::DEBUG::2011-12-02 15:59:20,796::resourceManager::564::ResourceManager::(releaseResource) No one is waiting for resource 'Storage.da74f982-2081-4b9f-89e6-2febdcdc1e97', Clearing records.
Thread-143::DEBUG::2011-12-02 15:59:20,796::task::980::TaskManager.Task::(_decref) Task=`57c547a5-4fd8-4dc8-b2a3-5367b5f1d5e1`::ref 0 aborting False
Thread-143::DEBUG::2011-12-02 15:59:20,797::task::588::TaskManager.Task::(_updateState) Task=`d7009bea-6277-4306-936a-161d04650182`::moving from state init -> state preparing
Thread-143::INFO::2011-12-02 15:59:20,797::logUtils::37::dispatcher::(wrapper) Run and protect: public_getVolumePath(sdUUID='da74f982-2081-4b9f-89e6-2febdcdc1e97', spUUID='085f83a8-1001-11e1-b008-67e7d7babce0', imgUUID='0177e3ec-3bfc-4bc8-9786-88d7e3c8752e', volUUID='684a46c7-e78f-4f37-90a1-a697f873ec7b', options=None)
Thread-143::DEBUG::2011-12-02 15:59:20,798::resourceManager::174::ResourceManager.Request::(__init__) ResName=`Storage.da74f982-2081-4b9f-89e6-2febdcdc1e97`ReqID=`d879ac9d-e1a0-4403-af5f-e0a49bb727f4`::Request was made in '/usr/share/vdsm/storage/hsm.py' line '2415' at 'public_getVolumePath'
Thread-143::DEBUG::2011-12-02 15:59:20,798::resourceManager::487::ResourceManager::(registerResource) Trying to register resource 'Storage.da74f982-2081-4b9f-89e6-2febdcdc1e97' for lock type 'shared'
Thread-143::DEBUG::2011-12-02 15:59:20,799::resourceManager::528::ResourceManager::(registerResource) Resource 'Storage.da74f982-2081-4b9f-89e6-2febdcdc1e97' is free. Now locking as 'shared' (1 active user)
Thread-143::DEBUG::2011-12-02 15:59:20,799::resourceManager::211::ResourceManager.Request::(grant) ResName=`Storage.da74f982-2081-4b9f-89e6-2febdcdc1e97`ReqID=`d879ac9d-e1a0-4403-af5f-e0a49bb727f4`::Granted request
Thread-143::DEBUG::2011-12-02 15:59:20,800::task::819::TaskManager.Task::(resourceAcquired) Task=`d7009bea-6277-4306-936a-161d04650182`::_resourcesAcquired: Storage.da74f982-2081-4b9f-89e6-2febdcdc1e97 (shared)
Thread-143::DEBUG::2011-12-02 15:59:20,800::task::980::TaskManager.Task::(_decref) Task=`d7009bea-6277-4306-936a-161d04650182`::ref 1 aborting False
Thread-143::DEBUG::2011-12-02 15:59:20,801::fileVolume::529::Storage.Volume::(validateVolumePath) validate path for 684a46c7-e78f-4f37-90a1-a697f873ec7b
Thread-143::INFO::2011-12-02 15:59:20,803::logUtils::39::dispatcher::(wrapper) Run and protect: public_getVolumePath, Return response: {'path': '/rhev/data-center/085f83a8-1001-11e1-b008-67e7d7babce0/da74f982-2081-4b9f-89e6-2febdcdc1e97/images/0177e3ec-3bfc-4bc8-9786-88d7e3c8752e/684a46c7-e78f-4f37-90a1-a697f873ec7b'}
Thread-143::DEBUG::2011-12-02 15:59:20,803::task::1174::TaskManager.Task::(prepare) Task=`d7009bea-6277-4306-936a-161d04650182`::finished: {'path': '/rhev/data-center/085f83a8-1001-11e1-b008-67e7d7babce0/da74f982-2081-4b9f-89e6-2febdcdc1e97/images/0177e3ec-3bfc-4bc8-9786-88d7e3c8752e/684a46c7-e78f-4f37-90a1-a697f873ec7b'}
Thread-143::DEBUG::2011-12-02 15:59:20,804::task::588::TaskManager.Task::(_updateState) Task=`d7009bea-6277-4306-936a-161d04650182`::moving from state preparing -> state finished
Thread-143::DEBUG::2011-12-02 15:59:20,804::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {'Storage.da74f982-2081-4b9f-89e6-2febdcdc1e97': < ResourceRef 'Storage.da74f982-2081-4b9f-89e6-2febdcdc1e97', isValid: 'True' obj: 'None'>}
Thread-143::DEBUG::2011-12-02 15:59:20,804::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-143::DEBUG::2011-12-02 15:59:20,805::resourceManager::537::ResourceManager::(releaseResource) Trying to release resource 'Storage.da74f982-2081-4b9f-89e6-2febdcdc1e97'
Thread-143::DEBUG::2011-12-02 15:59:20,805::resourceManager::552::ResourceManager::(releaseResource) Released resource 'Storage.da74f982-2081-4b9f-89e6-2febdcdc1e97' (0 active users)
Thread-143::DEBUG::2011-12-02 15:59:20,806::resourceManager::557::ResourceManager::(releaseResource) Resource 'Storage.da74f982-2081-4b9f-89e6-2febdcdc1e97' is free, finding out if anyone is waiting for it.
Thread-143::DEBUG::2011-12-02 15:59:20,806::resourceManager::564::ResourceManager::(releaseResource) No one is waiting for resource 'Storage.da74f982-2081-4b9f-89e6-2febdcdc1e97', Clearing records.
Thread-143::DEBUG::2011-12-02 15:59:20,807::task::980::TaskManager.Task::(_decref) Task=`d7009bea-6277-4306-936a-161d04650182`::ref 0 aborting False
Thread-143::INFO::2011-12-02 15:59:20,807::clientIF::593::vds::(_prepareVolumePath) prepared volume path: /rhev/data-center/085f83a8-1001-11e1-b008-67e7d7babce0/da74f982-2081-4b9f-89e6-2febdcdc1e97/images/0177e3ec-3bfc-4bc8-9786-88d7e3c8752e/684a46c7-e78f-4f37-90a1-a697f873ec7b
Thread-143::DEBUG::2011-12-02 15:59:20,808::vm::360::vm.Vm::(_startUnderlyingVm) vmId=`cdb466ca-e3d8-45fb-a01c-24a2f2bdf72c`::_ongoingCreations released
Thread-143::ERROR::2011-12-02 15:59:20,809::vm::384::vm.Vm::(_startUnderlyingVm) vmId=`cdb466ca-e3d8-45fb-a01c-24a2f2bdf72c`::The vm start process failed
Traceback (most recent call last):
  File "/usr/share/vdsm/vm.py", line 350, in _startUnderlyingVm
    self._run()
  File "/usr/share/vdsm/libvirtvm.py", line 1082, in _run
    self.preparePaths()
  File "/usr/share/vdsm/vm.py", line 435, in preparePaths
    self.conf.get('cdrom'))
  File "/usr/share/vdsm/vm.py", line 395, in _prepareVolumePath
    volPath = self.cif._prepareVolumePath(drive)
  File "/usr/share/vdsm/clientIF.py", line 593, in _prepareVolumePath
    self.log.info("prepared volume path: %s" % path)
UnboundLocalError: local variable 'path' referenced before assignment
Thread-143::DEBUG::2011-12-02 15:59:20,813::vm::748::vm.Vm::(setDownStatus) vmId=`cdb466ca-e3d8-45fb-a01c-24a2f2bdf72c`::Changed state to Down: local variable 'path' referenced before assignment
Thread-145::DEBUG::2011-12-02 15:59:21,133::task::588::TaskManager.Task::(_updateState) Task=`1a196002-4df0-48b4-b626-58e356d46d89`::moving from state init -> state preparing
Thread-145::INFO::2011-12-02 15:59:21,134::logUtils::37::dispatcher::(wrapper) Run and protect: public_repoStats(options=None)
Thread-145::INFO::2011-12-02 15:59:21,134::logUtils::39::dispatcher::(wrapper) Run and protect: public_repoStats, Return response: {'aeb6f289-48a0-4af5-a09c-a119d395bcb3': {'delay': '0.00148010253906', 'lastCheck': 1322812755.692468, 'valid': True, 'code': 0}, 'da74f982-2081-4b9f-89e6-2febdcdc1e97': {'delay': '0.00123691558838', 'lastCheck': 1322812755.651677, 'valid': True, 'code': 0}}
Thread-145::DEBUG::2011-12-02 15:59:21,135::task::1174::TaskManager.Task::(prepare) Task=`1a196002-4df0-48b4-b626-58e356d46d89`::finished: {'aeb6f289-48a0-4af5-a09c-a119d395bcb3': {'delay': '0.00148010253906', 'lastCheck': 1322812755.692468, 'valid': True, 'code': 0}, 'da74f982-2081-4b9f-89e6-2febdcdc1e97': {'delay': '0.00123691558838', 'lastCheck': 1322812755.651677, 'valid': True, 'code': 0}}
Thread-145::DEBUG::2011-12-02 15:59:21,135::task::588::TaskManager.Task::(_updateState) Task=`1a196002-4df0-48b4-b626-58e356d46d89`::moving from state preparing -> state finished
Thread-145::DEBUG::2011-12-02 15:59:21,136::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-145::DEBUG::2011-12-02 15:59:21,136::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-145::DEBUG::2011-12-02 15:59:21,136::task::980::TaskManager.Task::(_decref) Task=`1a196002-4df0-48b4-b626-58e356d46d89`::ref 0 aborting False
Thread-147::DEBUG::2011-12-02 15:59:21,161::clientIF::75::vds::(wrapper) [192.168.0.236]::call destroy with ('cdb466ca-e3d8-45fb-a01c-24a2f2bdf72c',) {}
Thread-147::INFO::2011-12-02 15:59:21,161::clientIF::471::vds::(destroy) vmContainerLock acquired by vm cdb466ca-e3d8-45fb-a01c-24a2f2bdf72c
Thread-147::DEBUG::2011-12-02 15:59:21,162::libvirtvm::1358::vm.Vm::(destroy) vmId=`cdb466ca-e3d8-45fb-a01c-24a2f2bdf72c`::destroy Called
Thread-147::INFO::2011-12-02 15:59:21,162::libvirtvm::1318::vm.Vm::(releaseVm) vmId=`cdb466ca-e3d8-45fb-a01c-24a2f2bdf72c`::Release VM resources
Thread-147::WARNING::2011-12-02 15:59:21,162::vm::320::vm.Vm::(_set_lastStatus) vmId=`cdb466ca-e3d8-45fb-a01c-24a2f2bdf72c`::trying to set state to Powering down when already Down
Thread-147::DEBUG::2011-12-02 15:59:21,162::utils::595::Storage.Misc.excCmd::(execCmd) '/usr/bin/sudo -n /sbin/service ksmtuned retune' (cwd None)
Thread-147::DEBUG::2011-12-02 15:59:21,195::utils::595::Storage.Misc.excCmd::(execCmd) FAILED: <err> = 'Unknown operation retune\n'; <rc> = 1
Thread-147::DEBUG::2011-12-02 15:59:21,196::vm::724::vm.Vm::(_cleanup) vmId=`cdb466ca-e3d8-45fb-a01c-24a2f2bdf72c`::Drive /rhev/data-center/085f83a8-1001-11e1-b008-67e7d7babce0/da74f982-2081-4b9f-89e6-2febdcdc1e97/images/0177e3ec-3bfc-4bc8-9786-88d7e3c8752e/684a46c7-e78f-4f37-90a1-a697f873ec7b cleanup
Thread-147::DEBUG::2011-12-02 15:59:21,197::task::588::TaskManager.Task::(_updateState) Task=`6d192ba6-a2c1-44b3-96d6-080d66a61f75`::moving from state init -> state preparing
Thread-147::INFO::2011-12-02 15:59:21,197::logUtils::37::dispatcher::(wrapper) Run and protect: public_teardownVolume(sdUUID='da74f982-2081-4b9f-89e6-2febdcdc1e97', spUUID='085f83a8-1001-11e1-b008-67e7d7babce0', imgUUID='0177e3ec-3bfc-4bc8-9786-88d7e3c8752e', volUUID='684a46c7-e78f-4f37-90a1-a697f873ec7b', rw=False, options=None)
Thread-147::DEBUG::2011-12-02 15:59:21,198::resourceManager::174::ResourceManager.Request::(__init__) ResName=`Storage.da74f982-2081-4b9f-89e6-2febdcdc1e97`ReqID=`69bc1787-8127-432a-8c3e-992768061395`::Request was made in '/usr/share/vdsm/storage/hsm.py' line '2478' at 'public_teardownVolume'
Thread-147::DEBUG::2011-12-02 15:59:21,198::resourceManager::487::ResourceManager::(registerResource) Trying to register resource 'Storage.da74f982-2081-4b9f-89e6-2febdcdc1e97' for lock type 'shared'
Thread-147::DEBUG::2011-12-02 15:59:21,199::resourceManager::528::ResourceManager::(registerResource) Resource 'Storage.da74f982-2081-4b9f-89e6-2febdcdc1e97' is free. Now locking as 'shared' (1 active user)
Thread-147::DEBUG::2011-12-02 15:59:21,199::resourceManager::211::ResourceManager.Request::(grant) ResName=`Storage.da74f982-2081-4b9f-89e6-2febdcdc1e97`ReqID=`69bc1787-8127-432a-8c3e-992768061395`::Granted request
Thread-147::DEBUG::2011-12-02 15:59:21,200::task::819::TaskManager.Task::(resourceAcquired) Task=`6d192ba6-a2c1-44b3-96d6-080d66a61f75`::_resourcesAcquired: Storage.da74f982-2081-4b9f-89e6-2febdcdc1e97 (shared)
Thread-147::DEBUG::2011-12-02 15:59:21,200::task::980::TaskManager.Task::(_decref) Task=`6d192ba6-a2c1-44b3-96d6-080d66a61f75`::ref 1 aborting False
Thread-147::DEBUG::2011-12-02 15:59:21,201::resourceManager::537::ResourceManager::(releaseResource) Trying to release resource 'da74f982-2081-4b9f-89e6-2febdcdc1e97_imageNS.0177e3ec-3bfc-4bc8-9786-88d7e3c8752e'
Thread-147::DEBUG::2011-12-02 15:59:21,201::resourceManager::552::ResourceManager::(releaseResource) Released resource 'da74f982-2081-4b9f-89e6-2febdcdc1e97_imageNS.0177e3ec-3bfc-4bc8-9786-88d7e3c8752e' (0 active users)
Thread-147::DEBUG::2011-12-02 15:59:21,202::resourceManager::557::ResourceManager::(releaseResource) Resource 'da74f982-2081-4b9f-89e6-2febdcdc1e97_imageNS.0177e3ec-3bfc-4bc8-9786-88d7e3c8752e' is free, finding out if anyone is waiting for it.
Thread-147::DEBUG::2011-12-02 15:59:21,202::resourceManager::537::ResourceManager::(releaseResource) Trying to release resource 'da74f982-2081-4b9f-89e6-2febdcdc1e97_volumeNS.684a46c7-e78f-4f37-90a1-a697f873ec7b'
Thread-147::DEBUG::2011-12-02 15:59:21,203::resourceManager::552::ResourceManager::(releaseResource) Released resource 'da74f982-2081-4b9f-89e6-2febdcdc1e97_volumeNS.684a46c7-e78f-4f37-90a1-a697f873ec7b' (0 active users)
Thread-147::DEBUG::2011-12-02 15:59:21,203::resourceManager::557::ResourceManager::(releaseResource) Resource 'da74f982-2081-4b9f-89e6-2febdcdc1e97_volumeNS.684a46c7-e78f-4f37-90a1-a697f873ec7b' is free, finding out if anyone is waiting for it.
Thread-147::DEBUG::2011-12-02 15:59:21,203::resourceManager::564::ResourceManager::(releaseResource) No one is waiting for resource 'da74f982-2081-4b9f-89e6-2febdcdc1e97_volumeNS.684a46c7-e78f-4f37-90a1-a697f873ec7b', Clearing records.
Thread-147::DEBUG::2011-12-02 15:59:21,204::resourceManager::564::ResourceManager::(releaseResource) No one is waiting for resource 'da74f982-2081-4b9f-89e6-2febdcdc1e97_imageNS.0177e3ec-3bfc-4bc8-9786-88d7e3c8752e', Clearing records.
Thread-147::INFO::2011-12-02 15:59:21,204::logUtils::39::dispatcher::(wrapper) Run and protect: public_teardownVolume, Return response: None
Thread-147::DEBUG::2011-12-02 15:59:21,205::task::1174::TaskManager.Task::(prepare) Task=`6d192ba6-a2c1-44b3-96d6-080d66a61f75`::finished: None
Thread-147::DEBUG::2011-12-02 15:59:21,205::task::588::TaskManager.Task::(_updateState) Task=`6d192ba6-a2c1-44b3-96d6-080d66a61f75`::moving from state preparing -> state finished
Thread-147::DEBUG::2011-12-02 15:59:21,206::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {'Storage.da74f982-2081-4b9f-89e6-2febdcdc1e97': < ResourceRef 'Storage.da74f982-2081-4b9f-89e6-2febdcdc1e97', isValid: 'True' obj: 'None'>}
Thread-147::DEBUG::2011-12-02 15:59:21,206::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-147::DEBUG::2011-12-02 15:59:21,206::resourceManager::537::ResourceManager::(releaseResource) Trying to release resource 'Storage.da74f982-2081-4b9f-89e6-2febdcdc1e97'
Thread-147::DEBUG::2011-12-02 15:59:21,207::resourceManager::552::ResourceManager::(releaseResource) Released resource 'Storage.da74f982-2081-4b9f-89e6-2febdcdc1e97' (0 active users)
Thread-147::DEBUG::2011-12-02 15:59:21,207::resourceManager::557::ResourceManager::(releaseResource) Resource 'Storage.da74f982-2081-4b9f-89e6-2febdcdc1e97' is free, finding out if anyone is waiting for it.
Thread-147::DEBUG::2011-12-02 15:59:21,207::resourceManager::564::ResourceManager::(releaseResource) No one is waiting for resource 'Storage.da74f982-2081-4b9f-89e6-2febdcdc1e97', Clearing records.
Thread-147::DEBUG::2011-12-02 15:59:21,207::task::980::TaskManager.Task::(_decref) Task=`6d192ba6-a2c1-44b3-96d6-080d66a61f75`::ref 0 aborting False
Thread-147::DEBUG::2011-12-02 15:59:21,236::libvirtvm::1353::vm.Vm::(deleteVm) vmId=`cdb466ca-e3d8-45fb-a01c-24a2f2bdf72c`::Total desktops after destroy of cdb466ca-e3d8-45fb-a01c-24a2f2bdf72c is 0
Thread-147::DEBUG::2011-12-02 15:59:21,237::clientIF::80::vds::(wrapper) return destroy with {'status': {'message': 'Machine destroyed', 'code': 0}}
_______________________________________________
vdsm-devel mailing list
vdsm-devel@lists.fedorahosted.org
https://fedorahosted.org/mailman/listinfo/vdsm-devel

Reply via email to