Thread-91::DEBUG::2013-12-30 11:20:06,851::fileSD::239::Storage.Misc.excCmd::(getReadDelay) '/usr/bin/dd iflag=direct if=/rhev/data-center/mnt/_data_images_rhev/66e0b27c-dcbb-4b6e-9a58-8213e8380c65/dom_md/metadata bs=4096 count=1' (cwd None) Thread-91::DEBUG::2013-12-30 11:20:07,102::fileSD::239::Storage.Misc.excCmd::(getReadDelay) SUCCESS: = '0+1 records in\n0+1 records out\n502 bytes (502 B) copied, 0.0171847 s, 29.2 kB/s\n'; = 0 Thread-1826::DEBUG::2013-12-30 11:20:08,983::BindingXMLRPC::177::vds::(wrapper) client [10.3.72.248] Thread-1826::DEBUG::2013-12-30 11:20:08,983::task::579::TaskManager.Task::(_updateState) Task=`a3cc3899-001a-46b9-b836-ac51ca61f304`::moving from state init -> state preparing Thread-1826::INFO::2013-12-30 11:20:08,987::logUtils::44::dispatcher::(wrapper) Run and protect: getSpmStatus(spUUID='b709443b-9933-46aa-86cd-c687bb8953f8', options=None) Thread-1826::INFO::2013-12-30 11:20:08,991::logUtils::47::dispatcher::(wrapper) Run and protect: getSpmStatus, Return response: {'spm_st': {'spmId': 1, 'spmStatus': 'SPM', 'spmLver': 3}} Thread-1826::DEBUG::2013-12-30 11:20:08,992::task::1168::TaskManager.Task::(prepare) Task=`a3cc3899-001a-46b9-b836-ac51ca61f304`::finished: {'spm_st': {'spmId': 1, 'spmStatus': 'SPM', 'spmLver': 3}} Thread-1826::DEBUG::2013-12-30 11:20:08,992::task::579::TaskManager.Task::(_updateState) Task=`a3cc3899-001a-46b9-b836-ac51ca61f304`::moving from state preparing -> state finished Thread-1826::DEBUG::2013-12-30 11:20:08,995::resourceManager::939::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} Thread-1826::DEBUG::2013-12-30 11:20:08,995::resourceManager::976::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} Thread-1826::DEBUG::2013-12-30 11:20:09,000::task::974::TaskManager.Task::(_decref) Task=`a3cc3899-001a-46b9-b836-ac51ca61f304`::ref 0 aborting False Thread-1827::DEBUG::2013-12-30 11:20:09,162::BindingXMLRPC::177::vds::(wrapper) client [10.3.72.248] Thread-1827::DEBUG::2013-12-30 11:20:09,165::task::579::TaskManager.Task::(_updateState) Task=`e132331d-813e-4f27-a952-e104077eb354`::moving from state init -> state preparing Thread-1827::INFO::2013-12-30 11:20:09,169::logUtils::44::dispatcher::(wrapper) Run and protect: getStoragePoolInfo(spUUID='b709443b-9933-46aa-86cd-c687bb8953f8', options=None) Thread-1827::DEBUG::2013-12-30 11:20:09,170::resourceManager::197::ResourceManager.Request::(__init__) ResName=`Storage.b709443b-9933-46aa-86cd-c687bb8953f8`ReqID=`83675d9e-fa54-4e99-a942-9106702338cd`::Request was made in '/usr/share/vdsm/storage/hsm.py' line '2547' at 'getStoragePoolInfo' Thread-1827::DEBUG::2013-12-30 11:20:09,171::resourceManager::541::ResourceManager::(registerResource) Trying to register resource 'Storage.b709443b-9933-46aa-86cd-c687bb8953f8' for lock type 'shared' Thread-1827::DEBUG::2013-12-30 11:20:09,174::resourceManager::600::ResourceManager::(registerResource) Resource 'Storage.b709443b-9933-46aa-86cd-c687bb8953f8' is free. Now locking as 'shared' (1 active user) Thread-1827::DEBUG::2013-12-30 11:20:09,174::resourceManager::237::ResourceManager.Request::(grant) ResName=`Storage.b709443b-9933-46aa-86cd-c687bb8953f8`ReqID=`83675d9e-fa54-4e99-a942-9106702338cd`::Granted request Thread-1827::DEBUG::2013-12-30 11:20:09,179::task::811::TaskManager.Task::(resourceAcquired) Task=`e132331d-813e-4f27-a952-e104077eb354`::_resourcesAcquired: Storage.b709443b-9933-46aa-86cd-c687bb8953f8 (shared) Thread-1827::DEBUG::2013-12-30 11:20:09,179::task::974::TaskManager.Task::(_decref) Task=`e132331d-813e-4f27-a952-e104077eb354`::ref 1 aborting False Thread-1827::INFO::2013-12-30 11:20:09,187::logUtils::47::dispatcher::(wrapper) Run and protect: getStoragePoolInfo, Return response: {'info': {'spm_id': 1, 'master_uuid': '66e0b27c-dcbb-4b6e-9a58-8213e8380c65', 'name': 'DataCenter', 'version': '3', 'domains': '66e0b27c-dcbb-4b6e-9a58-8213e8380c65:Active,e15927a5-1c3c-4e49-8a19-3790f411ddb8:Active', 'pool_status': 'connected', 'isoprefix': '/rhev/data-center/mnt/ovirt-manager.local:_var_lib_exports_iso/e15927a5-1c3c-4e49-8a19-3790f411ddb8/images/11111111-1111-1111-1111-111111111111', 'type': 'LOCALFS', 'master_ver': 1, 'lver': 3}, 'dominfo': {'66e0b27c-dcbb-4b6e-9a58-8213e8380c65': {'status': 'Active', 'diskfree': '145247465472', 'alerts': [], 'version': 3, 'disktotal': '153115471872'}, 'e15927a5-1c3c-4e49-8a19-3790f411ddb8': {'status': 'Active', 'diskfree': '34715729920', 'alerts': [], 'version': 0, 'disktotal': '48081403904'}}} @ @ @ "vdsm.log" 37895L, 7363141C