Thread-207004::DEBUG::2012-03-19 11:42:00,118::task::588::TaskManager.Task::(_updateState) Task=`2400e6bd-8315-4739-bffd-dd2e2ce279fb`::moving from state init -> state preparing
Thread-207004::INFO::2012-03-19 11:42:00,118::logUtils::37::dispatcher::(wrapper) Run and protect: repoStats(options=None)
Thread-207004::INFO::2012-03-19 11:42:00,119::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Return response: {'ff81a0d4-b132-4d9b-972a-1a75319fd061': {'delay': '0.00105905532837', 'lastCheck': 1332157311.048554, 'code': 0, 'valid': True}}
Thread-207004::DEBUG::2012-03-19 11:42:00,120::task::1174::TaskManager.Task::(prepare) Task=`2400e6bd-8315-4739-bffd-dd2e2ce279fb`::finished: {'ff81a0d4-b132-4d9b-972a-1a75319fd061': {'delay': '0.00105905532837', 'lastCheck': 1332157311.048554, 'code': 0, 'valid': True}}
Thread-207004::DEBUG::2012-03-19 11:42:00,120::task::588::TaskManager.Task::(_updateState) Task=`2400e6bd-8315-4739-bffd-dd2e2ce279fb`::moving from state preparing -> state finished
Thread-207004::DEBUG::2012-03-19 11:42:00,120::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-207004::DEBUG::2012-03-19 11:42:00,121::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-207004::DEBUG::2012-03-19 11:42:00,121::task::980::TaskManager.Task::(_decref) Task=`2400e6bd-8315-4739-bffd-dd2e2ce279fb`::ref 0 aborting False
Thread-207006::DEBUG::2012-03-19 11:42:01,816::clientIF::261::Storage.Dispatcher.Protect::(wrapper) [10.87.2.64]
Thread-207006::DEBUG::2012-03-19 11:42:01,817::task::588::TaskManager.Task::(_updateState) Task=`7c7e1613-bbf9-4c13-acf5-b0014323a441`::moving from state init -> state preparing
Thread-207006::INFO::2012-03-19 11:42:01,818::logUtils::37::dispatcher::(wrapper) Run and protect: getSpmStatus(spUUID='bd32c872-be13-43f5-8d24-0c19213740ac', options=None)
Thread-207006::INFO::2012-03-19 11:42:01,818::logUtils::39::dispatcher::(wrapper) Run and protect: getSpmStatus, Return response: {'spm_st': {'spmId': 1, 'spmStatus': 'SPM', 'spmLver': 1}}
Thread-207006::DEBUG::2012-03-19 11:42:01,819::task::1174::TaskManager.Task::(prepare) Task=`7c7e1613-bbf9-4c13-acf5-b0014323a441`::finished: {'spm_st': {'spmId': 1, 'spmStatus': 'SPM', 'spmLver': 1}}
Thread-207006::DEBUG::2012-03-19 11:42:01,819::task::588::TaskManager.Task::(_updateState) Task=`7c7e1613-bbf9-4c13-acf5-b0014323a441`::moving from state preparing -> state finished
Thread-207006::DEBUG::2012-03-19 11:42:01,820::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-207006::DEBUG::2012-03-19 11:42:01,820::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-207006::DEBUG::2012-03-19 11:42:01,821::task::980::TaskManager.Task::(_decref) Task=`7c7e1613-bbf9-4c13-acf5-b0014323a441`::ref 0 aborting False
Thread-207007::DEBUG::2012-03-19 11:42:01,829::clientIF::261::Storage.Dispatcher.Protect::(wrapper) [10.87.2.64]
Thread-207007::DEBUG::2012-03-19 11:42:01,830::task::588::TaskManager.Task::(_updateState) Task=`d219fc91-ddbc-453f-a1c3-240c8cdc1c5a`::moving from state init -> state preparing
Thread-207007::INFO::2012-03-19 11:42:01,830::logUtils::37::dispatcher::(wrapper) Run and protect: getStoragePoolInfo(spUUID='bd32c872-be13-43f5-8d24-0c19213740ac', options=None)
Thread-207007::DEBUG::2012-03-19 11:42:01,831::resourceManager::175::ResourceManager.Request::(__init__) ResName=`Storage.bd32c872-be13-43f5-8d24-0c19213740ac`ReqID=`c7793ddc-1e27-4a63-878a-5aa152ed003f`::Request was made in '/usr/share/vdsm/storage/hsm.py' line '1878' at 'getStoragePoolInfo'
Thread-207007::DEBUG::2012-03-19 11:42:01,832::resourceManager::483::ResourceManager::(registerResource) Trying to register resource 'Storage.bd32c872-be13-43f5-8d24-0c19213740ac' for lock type 'shared'
Thread-207007::DEBUG::2012-03-19 11:42:01,832::resourceManager::525::ResourceManager::(registerResource) Resource 'Storage.bd32c872-be13-43f5-8d24-0c19213740ac' is free. Now locking as 'shared' (1 active user)
Thread-207007::DEBUG::2012-03-19 11:42:01,833::resourceManager::212::ResourceManager.Request::(grant) ResName=`Storage.bd32c872-be13-43f5-8d24-0c19213740ac`ReqID=`c7793ddc-1e27-4a63-878a-5aa152ed003f`::Granted request
Thread-207007::DEBUG::2012-03-19 11:42:01,834::task::819::TaskManager.Task::(resourceAcquired) Task=`d219fc91-ddbc-453f-a1c3-240c8cdc1c5a`::_resourcesAcquired: Storage.bd32c872-be13-43f5-8d24-0c19213740ac (shared)
Thread-207007::DEBUG::2012-03-19 11:42:01,834::task::980::TaskManager.Task::(_decref) Task=`d219fc91-ddbc-453f-a1c3-240c8cdc1c5a`::ref 1 aborting False
Thread-207007::INFO::2012-03-19 11:42:01,835::logUtils::39::dispatcher::(wrapper) Run and protect: getStoragePoolInfo, Return response: {'info': {'spm_id': 1, 'master_uuid': 'ff81a0d4-b132-4d9b-972a-1a75319fd061', 'name': 'BJN', 'version': '0', 'domains': 'ff81a0d4-b132-4d9b-972a-1a75319fd061:Active', 'pool_status': 'connected', 'isoprefix': '', 'type': 'LOCALFS', 'master_ver': 1, 'lver': 1}, 'dominfo': {'ff81a0d4-b132-4d9b-972a-1a75319fd061': {'status': 'Active', 'diskfree': '183965011968', 'alerts': [], 'disktotal': '242793185280'}}}
Thread-207007::DEBUG::2012-03-19 11:42:01,836::task::1174::TaskManager.Task::(prepare) Task=`d219fc91-ddbc-453f-a1c3-240c8cdc1c5a`::finished: {'info': {'spm_id': 1, 'master_uuid': 'ff81a0d4-b132-4d9b-972a-1a75319fd061', 'name': 'BJN', 'version': '0', 'domains': 'ff81a0d4-b132-4d9b-972a-1a75319fd061:Active', 'pool_status': 'connected', 'isoprefix': '', 'type': 'LOCALFS', 'master_ver': 1, 'lver': 1}, 'dominfo': {'ff81a0d4-b132-4d9b-972a-1a75319fd061': {'status': 'Active', 'diskfree': '183965011968', 'alerts': [], 'disktotal': '242793185280'}}}
Thread-207007::DEBUG::2012-03-19 11:42:01,836::task::588::TaskManager.Task::(_updateState) Task=`d219fc91-ddbc-453f-a1c3-240c8cdc1c5a`::moving from state preparing -> state finished
Thread-207007::DEBUG::2012-03-19 11:42:01,837::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {'Storage.bd32c872-be13-43f5-8d24-0c19213740ac': < ResourceRef 'Storage.bd32c872-be13-43f5-8d24-0c19213740ac', isValid: 'True' obj: 'None'>}
Thread-207007::DEBUG::2012-03-19 11:42:01,837::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-207007::DEBUG::2012-03-19 11:42:01,837::resourceManager::535::ResourceManager::(releaseResource) Trying to release resource 'Storage.bd32c872-be13-43f5-8d24-0c19213740ac'
Thread-207007::DEBUG::2012-03-19 11:42:01,837::resourceManager::550::ResourceManager::(releaseResource) Released resource 'Storage.bd32c872-be13-43f5-8d24-0c19213740ac' (0 active users)
Thread-207007::DEBUG::2012-03-19 11:42:01,838::resourceManager::555::ResourceManager::(releaseResource) Resource 'Storage.bd32c872-be13-43f5-8d24-0c19213740ac' is free, finding out if anyone is waiting for it.
Thread-207007::DEBUG::2012-03-19 11:42:01,838::resourceManager::562::ResourceManager::(releaseResource) No one is waiting for resource 'Storage.bd32c872-be13-43f5-8d24-0c19213740ac', Clearing records.
Thread-207007::DEBUG::2012-03-19 11:42:01,838::task::980::TaskManager.Task::(_decref) Task=`d219fc91-ddbc-453f-a1c3-240c8cdc1c5a`::ref 0 aborting False
Thread-207009::DEBUG::2012-03-19 11:42:02,540::clientIF::261::Storage.Dispatcher.Protect::(wrapper) [10.87.2.64]
Thread-207009::DEBUG::2012-03-19 11:42:02,540::task::588::TaskManager.Task::(_updateState) Task=`064fa82b-30a5-4d9d-8850-bfa5480ecbad`::moving from state init -> state preparing
Thread-207009::INFO::2012-03-19 11:42:02,541::logUtils::37::dispatcher::(wrapper) Run and protect: removeVM(spUUID='bd32c872-be13-43f5-8d24-0c19213740ac', vmList='53bd1fc6-fc8c-4aef-bfdc-f1b44401ebb2', sdUUID=None, options=None)
Thread-207009::DEBUG::2012-03-19 11:42:02,542::resourceManager::175::ResourceManager.Request::(__init__) ResName=`Storage.bd32c872-be13-43f5-8d24-0c19213740ac`ReqID=`3e2d07fc-105d-452b-b2ff-5694a00cf23d`::Request was made in '/usr/share/vdsm/storage/hsm.py' line '1022' at 'removeVM'
Thread-207009::DEBUG::2012-03-19 11:42:02,542::resourceManager::483::ResourceManager::(registerResource) Trying to register resource 'Storage.bd32c872-be13-43f5-8d24-0c19213740ac' for lock type 'shared'
Thread-207009::DEBUG::2012-03-19 11:42:02,543::resourceManager::525::ResourceManager::(registerResource) Resource 'Storage.bd32c872-be13-43f5-8d24-0c19213740ac' is free. Now locking as 'shared' (1 active user)
Thread-207009::DEBUG::2012-03-19 11:42:02,543::resourceManager::212::ResourceManager.Request::(grant) ResName=`Storage.bd32c872-be13-43f5-8d24-0c19213740ac`ReqID=`3e2d07fc-105d-452b-b2ff-5694a00cf23d`::Granted request
Thread-207009::DEBUG::2012-03-19 11:42:02,544::task::819::TaskManager.Task::(resourceAcquired) Task=`064fa82b-30a5-4d9d-8850-bfa5480ecbad`::_resourcesAcquired: Storage.bd32c872-be13-43f5-8d24-0c19213740ac (shared)
Thread-207009::DEBUG::2012-03-19 11:42:02,544::task::980::TaskManager.Task::(_decref) Task=`064fa82b-30a5-4d9d-8850-bfa5480ecbad`::ref 1 aborting False
Thread-207009::INFO::2012-03-19 11:42:02,545::sp::1215::Storage.StoragePool::(removeVM) spUUID=bd32c872-be13-43f5-8d24-0c19213740ac vmList=53bd1fc6-fc8c-4aef-bfdc-f1b44401ebb2 sdUUID=None
Thread-207009::INFO::2012-03-19 11:42:02,545::logUtils::39::dispatcher::(wrapper) Run and protect: removeVM, Return response: None
Thread-207009::DEBUG::2012-03-19 11:42:02,546::task::1174::TaskManager.Task::(prepare) Task=`064fa82b-30a5-4d9d-8850-bfa5480ecbad`::finished: None
Thread-207009::DEBUG::2012-03-19 11:42:02,546::task::588::TaskManager.Task::(_updateState) Task=`064fa82b-30a5-4d9d-8850-bfa5480ecbad`::moving from state preparing -> state finished
Thread-207009::DEBUG::2012-03-19 11:42:02,547::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {'Storage.bd32c872-be13-43f5-8d24-0c19213740ac': < ResourceRef 'Storage.bd32c872-be13-43f5-8d24-0c19213740ac', isValid: 'True' obj: 'None'>}
Thread-207009::DEBUG::2012-03-19 11:42:02,547::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-207009::DEBUG::2012-03-19 11:42:02,547::resourceManager::535::ResourceManager::(releaseResource) Trying to release resource 'Storage.bd32c872-be13-43f5-8d24-0c19213740ac'
Thread-207009::DEBUG::2012-03-19 11:42:02,548::resourceManager::550::ResourceManager::(releaseResource) Released resource 'Storage.bd32c872-be13-43f5-8d24-0c19213740ac' (0 active users)
Thread-207009::DEBUG::2012-03-19 11:42:02,548::resourceManager::555::ResourceManager::(releaseResource) Resource 'Storage.bd32c872-be13-43f5-8d24-0c19213740ac' is free, finding out if anyone is waiting for it.
Thread-207009::DEBUG::2012-03-19 11:42:02,548::resourceManager::562::ResourceManager::(releaseResource) No one is waiting for resource 'Storage.bd32c872-be13-43f5-8d24-0c19213740ac', Clearing records.
Thread-207009::DEBUG::2012-03-19 11:42:02,548::task::980::TaskManager.Task::(_decref) Task=`064fa82b-30a5-4d9d-8850-bfa5480ecbad`::ref 0 aborting False
Thread-207010::DEBUG::2012-03-19 11:42:02,564::clientIF::261::Storage.Dispatcher.Protect::(wrapper) [10.87.2.64]
Thread-207010::DEBUG::2012-03-19 11:42:02,565::task::588::TaskManager.Task::(_updateState) Task=`2204b852-1d53-4387-a6c6-11bb802a6be5`::moving from state init -> state preparing
Thread-207010::INFO::2012-03-19 11:42:02,566::logUtils::37::dispatcher::(wrapper) Run and protect: deleteImage(sdUUID='ff81a0d4-b132-4d9b-972a-1a75319fd061', spUUID='bd32c872-be13-43f5-8d24-0c19213740ac', imgUUID='c0219347-b425-4ee6-a6e1-c0fdd1a8a71d', postZero='false', force='false')
Thread-207010::INFO::2012-03-19 11:42:02,566::fileSD::195::Storage.StorageDomain::(validate) sdUUID=ff81a0d4-b132-4d9b-972a-1a75319fd061
Thread-207010::DEBUG::2012-03-19 11:42:02,568::persistentDict::216::Storage.PersistentDict::(refresh) read lines (FileMetadataRW)=['CLASS=Data', 'DESCRIPTION=DATA15', 'IOOPTIMEOUTSEC=10', 'LEASERETRIES=3', 'LEASETIMESEC=60', 'LOCKPOLICY=', 'LOCKRENEWALINTERVALSEC=5', 'MASTER_VERSION=1', 'POOL_DESCRIPTION=BJN', 'POOL_DOMAINS=ff81a0d4-b132-4d9b-972a-1a75319fd061:Active', 'POOL_SPM_ID=1', 'POOL_SPM_LVER=1', 'POOL_UUID=bd32c872-be13-43f5-8d24-0c19213740ac', 'REMOTE_PATH=/data/images/rhev', 'ROLE=Master', 'SDUUID=ff81a0d4-b132-4d9b-972a-1a75319fd061', 'TYPE=LOCALFS', 'VERSION=0', '_SHA_CKSUM=bde6e7cbfb5f3ce946dfa50fd4fa98dd666024f7']
Thread-207010::DEBUG::2012-03-19 11:42:02,569::resourceManager::175::ResourceManager.Request::(__init__) ResName=`Storage.c0219347-b425-4ee6-a6e1-c0fdd1a8a71d`ReqID=`d2952675-fba9-4195-a6d1-56851c34724e`::Request was made in '/usr/share/vdsm/storage/hsm.py' line '1171' at 'deleteImage'
Thread-207010::DEBUG::2012-03-19 11:42:02,570::resourceManager::483::ResourceManager::(registerResource) Trying to register resource 'Storage.c0219347-b425-4ee6-a6e1-c0fdd1a8a71d' for lock type 'shared'
Thread-207010::DEBUG::2012-03-19 11:42:02,570::resourceManager::525::ResourceManager::(registerResource) Resource 'Storage.c0219347-b425-4ee6-a6e1-c0fdd1a8a71d' is free. Now locking as 'shared' (1 active user)
Thread-207010::DEBUG::2012-03-19 11:42:02,571::resourceManager::212::ResourceManager.Request::(grant) ResName=`Storage.c0219347-b425-4ee6-a6e1-c0fdd1a8a71d`ReqID=`d2952675-fba9-4195-a6d1-56851c34724e`::Granted request
Thread-207010::DEBUG::2012-03-19 11:42:02,571::task::819::TaskManager.Task::(resourceAcquired) Task=`2204b852-1d53-4387-a6c6-11bb802a6be5`::_resourcesAcquired: Storage.c0219347-b425-4ee6-a6e1-c0fdd1a8a71d (shared)
Thread-207010::DEBUG::2012-03-19 11:42:02,572::task::980::TaskManager.Task::(_decref) Task=`2204b852-1d53-4387-a6c6-11bb802a6be5`::ref 1 aborting False
Thread-207010::DEBUG::2012-03-19 11:42:02,573::resourceManager::175::ResourceManager.Request::(__init__) ResName=`Storage.ff81a0d4-b132-4d9b-972a-1a75319fd061`ReqID=`0ee97736-d921-4633-aad3-001afe623a71`::Request was made in '/usr/share/vdsm/storage/hsm.py' line '1173' at 'deleteImage'
Thread-207010::DEBUG::2012-03-19 11:42:02,573::resourceManager::483::ResourceManager::(registerResource) Trying to register resource 'Storage.ff81a0d4-b132-4d9b-972a-1a75319fd061' for lock type 'shared'
Thread-207010::DEBUG::2012-03-19 11:42:02,574::resourceManager::525::ResourceManager::(registerResource) Resource 'Storage.ff81a0d4-b132-4d9b-972a-1a75319fd061' is free. Now locking as 'shared' (1 active user)
Thread-207010::DEBUG::2012-03-19 11:42:02,574::resourceManager::212::ResourceManager.Request::(grant) ResName=`Storage.ff81a0d4-b132-4d9b-972a-1a75319fd061`ReqID=`0ee97736-d921-4633-aad3-001afe623a71`::Granted request
Thread-207010::DEBUG::2012-03-19 11:42:02,576::task::819::TaskManager.Task::(resourceAcquired) Task=`2204b852-1d53-4387-a6c6-11bb802a6be5`::_resourcesAcquired: Storage.ff81a0d4-b132-4d9b-972a-1a75319fd061 (shared)
Thread-207010::DEBUG::2012-03-19 11:42:02,576::task::980::TaskManager.Task::(_decref) Task=`2204b852-1d53-4387-a6c6-11bb802a6be5`::ref 1 aborting False
Thread-207010::DEBUG::2012-03-19 11:42:02,579::fileVolume::537::Storage.Volume::(validateVolumePath) validate path for c0cbe099-aa2d-444e-a734-1de7d9171498
Thread-207010::ERROR::2012-03-19 11:42:02,580::task::855::TaskManager.Task::(_setError) Task=`2204b852-1d53-4387-a6c6-11bb802a6be5`::Unexpected error
Traceback (most recent call last):
  File "/usr/share/vdsm/storage/task.py", line 863, in _run
  File "/usr/share/vdsm/logUtils.py", line 38, in wrapper
  File "/usr/share/vdsm/storage/hsm.py", line 1176, in deleteImage
  File "/usr/share/vdsm/storage/securable.py", line 80, in wrapper
  File "/usr/share/vdsm/storage/sp.py", line 1890, in validateDelete
  File "/usr/share/vdsm/storage/image.py", line 175, in validateDelete
  File "/usr/share/vdsm/storage/fileVolume.py", line 382, in getImageVolumes
  File "/usr/share/vdsm/storage/fileSD.py", line 160, in produceVolume
  File "/usr/share/vdsm/storage/fileVolume.py", line 64, in __init__
  File "/usr/share/vdsm/storage/volume.py", line 120, in __init__
  File "/usr/share/vdsm/storage/volume.py", line 127, in validate
  File "/usr/share/vdsm/storage/fileVolume.py", line 542, in validateVolumePath
VolumeDoesNotExist: Volume does not exist: ('c0cbe099-aa2d-444e-a734-1de7d9171498',)
Thread-207010::DEBUG::2012-03-19 11:42:02,581::task::874::TaskManager.Task::(_run) Task=`2204b852-1d53-4387-a6c6-11bb802a6be5`::Task._run: 2204b852-1d53-4387-a6c6-11bb802a6be5 ('ff81a0d4-b132-4d9b-972a-1a75319fd061', 'bd32c872-be13-43f5-8d24-0c19213740ac', 'c0219347-b425-4ee6-a6e1-c0fdd1a8a71d', 'false', 'false') {} failed - stopping task
Thread-207010::DEBUG::2012-03-19 11:42:02,581::task::1201::TaskManager.Task::(stop) Task=`2204b852-1d53-4387-a6c6-11bb802a6be5`::stopping in state preparing (force False)
Thread-207010::DEBUG::2012-03-19 11:42:02,582::task::980::TaskManager.Task::(_decref) Task=`2204b852-1d53-4387-a6c6-11bb802a6be5`::ref 1 aborting True
Thread-207010::INFO::2012-03-19 11:42:02,582::task::1159::TaskManager.Task::(prepare) Task=`2204b852-1d53-4387-a6c6-11bb802a6be5`::aborting: Task is aborted: 'Volume does not exist' - code 201
Thread-207010::DEBUG::2012-03-19 11:42:02,582::task::1164::TaskManager.Task::(prepare) Task=`2204b852-1d53-4387-a6c6-11bb802a6be5`::Prepare: aborted: Volume does not exist
Thread-207010::DEBUG::2012-03-19 11:42:02,583::task::980::TaskManager.Task::(_decref) Task=`2204b852-1d53-4387-a6c6-11bb802a6be5`::ref 0 aborting True
Thread-207010::DEBUG::2012-03-19 11:42:02,583::task::915::TaskManager.Task::(_doAbort) Task=`2204b852-1d53-4387-a6c6-11bb802a6be5`::Task._doAbort: force False
Thread-207010::DEBUG::2012-03-19 11:42:02,584::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-207010::DEBUG::2012-03-19 11:42:02,584::task::588::TaskManager.Task::(_updateState) Task=`2204b852-1d53-4387-a6c6-11bb802a6be5`::moving from state preparing -> state aborting
Thread-207010::DEBUG::2012-03-19 11:42:02,585::task::537::TaskManager.Task::(__state_aborting) Task=`2204b852-1d53-4387-a6c6-11bb802a6be5`::_aborting: recover policy none
Thread-207010::DEBUG::2012-03-19 11:42:02,585::task::588::TaskManager.Task::(_updateState) Task=`2204b852-1d53-4387-a6c6-11bb802a6be5`::moving from state aborting -> state failed
Thread-207010::DEBUG::2012-03-19 11:42:02,586::resourceManager::806::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {'Storage.ff81a0d4-b132-4d9b-972a-1a75319fd061': < ResourceRef 'Storage.ff81a0d4-b132-4d9b-972a-1a75319fd061', isValid: 'True' obj: 'None'>, 'Storage.c0219347-b425-4ee6-a6e1-c0fdd1a8a71d': < ResourceRef 'Storage.c0219347-b425-4ee6-a6e1-c0fdd1a8a71d', isValid: 'True' obj: 'None'>}
Thread-207010::DEBUG::2012-03-19 11:42:02,586::resourceManager::841::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-207010::DEBUG::2012-03-19 11:42:02,587::resourceManager::535::ResourceManager::(releaseResource) Trying to release resource 'Storage.ff81a0d4-b132-4d9b-972a-1a75319fd061'
Thread-207010::DEBUG::2012-03-19 11:42:02,587::resourceManager::550::ResourceManager::(releaseResource) Released resource 'Storage.ff81a0d4-b132-4d9b-972a-1a75319fd061' (0 active users)
Thread-207010::DEBUG::2012-03-19 11:42:02,588::resourceManager::555::ResourceManager::(releaseResource) Resource 'Storage.ff81a0d4-b132-4d9b-972a-1a75319fd061' is free, finding out if anyone is waiting for it.
Thread-207010::DEBUG::2012-03-19 11:42:02,588::resourceManager::562::ResourceManager::(releaseResource) No one is waiting for resource 'Storage.ff81a0d4-b132-4d9b-972a-1a75319fd061', Clearing records.
Thread-207010::DEBUG::2012-03-19 11:42:02,589::resourceManager::535::ResourceManager::(releaseResource) Trying to release resource 'Storage.c0219347-b425-4ee6-a6e1-c0fdd1a8a71d'
Thread-207010::DEBUG::2012-03-19 11:42:02,590::resourceManager::550::ResourceManager::(releaseResource) Released resource 'Storage.c0219347-b425-4ee6-a6e1-c0fdd1a8a71d' (0 active users)
Thread-207010::DEBUG::2012-03-19 11:42:02,590::resourceManager::555::ResourceManager::(releaseResource) Resource 'Storage.c0219347-b425-4ee6-a6e1-c0fdd1a8a71d' is free, finding out if anyone is waiting for it.
Thread-207010::DEBUG::2012-03-19 11:42:02,590::resourceManager::562::ResourceManager::(releaseResource) No one is waiting for resource 'Storage.c0219347-b425-4ee6-a6e1-c0fdd1a8a71d', Clearing records.
Thread-207010::ERROR::2012-03-19 11:42:02,591::dispatcher::90::Storage.Dispatcher.Protect::(run) {'status': {'message': "Volume does not exist: ('c0cbe099-aa2d-444e-a734-1de7d9171498',)", 'code': 201}}