Any idea what is happening?<br><br>Thanks<br><br>Jose<br><br>the vdsm.log = :<br><br>Thread-2405::DEBUG::2013-01-30 16:42:21,532::resourceManager::212:= :ResourceManager.Request::(grant) ResName=3D`Storage.7b44684c-5f34-11e2-beb= a-00138fbe3093`ReqID=3D`e9aefcf3-b4ed-4d7c-9d95-723f824c30ee`::Granted requ= est<br>Thread-2405::DEBUG::2013-01-30 16:42:21,532::task::817::TaskManager.= Task::(resourceAcquired) Task=3D`c581aa06-4e50-41dd-a836-756827865cc6`::_re=

Thread-788::DEBUG::2013-01-30 16:42:28,909::task::978::TaskManager.Task::(= _decref) Task=3D`aec127b3-b02b-4bc3-b0e9-542c90b4c91e`::ref 1 aborting Fals= e<br>Thread-788::DEBUG::2013-01-30 16:42:28,911::fileVolume::535::Storage.V=

------=_Part_476_18436217.1359564233863 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: quoted-printable Hi,=20 I'm testing oVirt 3.1, with one node 2.5.5-0.1fc17 and a NAS built with ope= nfiler 2.99, working on a Gigabit net.=20 I configured a NFS share on openfiler, and everything looks nice.=20 I'm installing a Windows 2008 R2 as a VM, time to time i get a warning mess= age: ! VM is not responding, but the windows installation keeps going, a bi= t slow.=20 Any idea what is happening?=20 Thanks=20 Jose=20 the vdsm.log :=20 Thread-2405::DEBUG::2013-01-30 16:42:21,532::resourceManager::212::Resource= Manager.Request::(grant) ResName=3D`Storage.7b44684c-5f34-11e2-beba-00138fb= e3093`ReqID=3D`e9aefcf3-b4ed-4d7c-9d95-723f824c30ee`::Granted request=20 Thread-2405::DEBUG::2013-01-30 16:42:21,532::task::817::TaskManager.Task::(= resourceAcquired) Task=3D`c581aa06-4e50-41dd-a836-756827865cc6`::_resources= Acquired: Storage.7b44684c-5f34-11e2-beba-00138fbe3093 (shared)=20 Thread-2405::DEBUG::2013-01-30 16:42:21,532::task::978::TaskManager.Task::(= _decref) Task=3D`c581aa06-4e50-41dd-a836-756827865cc6`::ref 1 aborting Fals= e=20 Thread-2405::INFO::2013-01-30 16:42:21,664::logUtils::39::dispatcher::(wrap= per) Run and protect: getStoragePoolInfo, Return response: {'info': {'spm_i= d': 1, 'master_uuid': 'cc060953-baf5-4b86-a66c-2f135b8fbb30', 'name': 'aclo= udDC', 'version': '0', 'domains': '39484795-666f-44b3-9cf5-21bbb02531ad:Act= ive,0b6a87e8-53d9-46f3-bc81-20aab92f08aa:Active,cc060953-baf5-4b86-a66c-2f1= 35b8fbb30:Active', 'pool_status': 'connected', 'isoprefix': '/rhev/data-cen= ter/7b44684c-5f34-11e2-beba-00138fbe3093/0b6a87e8-53d9-46f3-bc81-20aab92f08= aa/images/11111111-1111-1111-1111-111111111111', 'type': 'NFS', 'master_ver= ': 10575, 'lver': 4}, 'dominfo': {'0b6a87e8-53d9-46f3-bc81-20aab92f08aa': {= 'status': 'Active', 'diskfree': '17986224128', 'alerts': [], 'disktotal': '= 23648534528'}, '39484795-666f-44b3-9cf5-21bbb02531ad': {'status': 'Active',= 'diskfree': '467744063488', 'alerts': [], 'disktotal': '476676358144'}, 'c= c060953-baf5-4b86-a66c-2f135b8fbb30': {'status': 'Active', 'diskfree': '313= 802031104', 'alerts': [], 'disktotal': '982927736832'}}}=20 Thread-2405::DEBUG::2013-01-30 16:42:21,664::task::1172::TaskManager.Task::= (prepare) Task=3D`c581aa06-4e50-41dd-a836-756827865cc6`::finished: {'info':= {'spm_id': 1, 'master_uuid': 'cc060953-baf5-4b86-a66c-2f135b8fbb30', 'name= ': 'acloudDC', 'version': '0', 'domains': '39484795-666f-44b3-9cf5-21bbb025= 31ad:Active,0b6a87e8-53d9-46f3-bc81-20aab92f08aa:Active,cc060953-baf5-4b86-= a66c-2f135b8fbb30:Active', 'pool_status': 'connected', 'isoprefix': '/rhev/= data-center/7b44684c-5f34-11e2-beba-00138fbe3093/0b6a87e8-53d9-46f3-bc81-20= aab92f08aa/images/11111111-1111-1111-1111-111111111111', 'type': 'NFS', 'ma= ster_ver': 10575, 'lver': 4}, 'dominfo': {'0b6a87e8-53d9-46f3-bc81-20aab92f= 08aa': {'status': 'Active', 'diskfree': '17986224128', 'alerts': [], 'diskt= otal': '23648534528'}, '39484795-666f-44b3-9cf5-21bbb02531ad': {'status': '= Active', 'diskfree': '467744063488', 'alerts': [], 'disktotal': '4766763581= 44'}, 'cc060953-baf5-4b86-a66c-2f135b8fbb30': {'status': 'Active', 'diskfre= e': '313802031104', 'alerts': [], 'disktotal': '982927736832'}}}=20 Thread-2405::DEBUG::2013-01-30 16:42:21,664::task::588::TaskManager.Task::(= _updateState) Task=3D`c581aa06-4e50-41dd-a836-756827865cc6`::moving from st= ate preparing -> state finished=20 Thread-2405::DEBUG::2013-01-30 16:42:21,664::resourceManager::809::Resource= Manager.Owner::(releaseAll) Owner.releaseAll requests {} resources {'Storag= e.7b44684c-5f34-11e2-beba-00138fbe3093': < ResourceRef 'Storage.7b44684c-5f= 34-11e2-beba-00138fbe3093', isValid: 'True' obj: 'None'>}=20 Thread-2405::DEBUG::2013-01-30 16:42:21,664::resourceManager::844::Resource= Manager.Owner::(cancelAll) Owner.cancelAll requests {}=20 Thread-2405::DEBUG::2013-01-30 16:42:21,665::resourceManager::538::Resource= Manager::(releaseResource) Trying to release resource 'Storage.7b44684c-5f3= 4-11e2-beba-00138fbe3093'=20 Thread-2405::DEBUG::2013-01-30 16:42:21,665::resourceManager::553::Resource= Manager::(releaseResource) Released resource 'Storage.7b44684c-5f34-11e2-be= ba-00138fbe3093' (0 active users)=20 Thread-2405::DEBUG::2013-01-30 16:42:21,665::resourceManager::558::Resource= Manager::(releaseResource) Resource 'Storage.7b44684c-5f34-11e2-beba-00138f= be3093' is free, finding out if anyone is waiting for it.=20 Thread-2405::DEBUG::2013-01-30 16:42:21,665::resourceManager::565::Resource= Manager::(releaseResource) No one is waiting for resource 'Storage.7b44684c= -5f34-11e2-beba-00138fbe3093', Clearing records.=20 Thread-2405::DEBUG::2013-01-30 16:42:21,665::task::978::TaskManager.Task::(= _decref) Task=3D`c581aa06-4e50-41dd-a836-756827865cc6`::ref 0 aborting Fals= e=20 Thread-2406::DEBUG::2013-01-30 16:42:23,304::task::588::TaskManager.Task::(= _updateState) Task=3D`8926a671-3076-42e5-8521-f8ec6ba67748`::moving from st= ate init -> state preparing=20 Thread-2406::INFO::2013-01-30 16:42:23,304::logUtils::37::dispatcher::(wrap= per) Run and protect: repoStats(options=3DNone)=20 Thread-2406::INFO::2013-01-30 16:42:23,304::logUtils::39::dispatcher::(wrap= per) Run and protect: repoStats, Return response: {'39484795-666f-44b3-9cf5= -21bbb02531ad': {'delay': '0.00179004669189', 'lastCheck': 1359564135.40165= , 'code': 0, 'valid': True}, '0b6a87e8-53d9-46f3-bc81-20aab92f08aa': {'dela= y': '0.00332403182983', 'lastCheck': 1359564141.220177, 'code': 0, 'valid':= True}, 'cc060953-baf5-4b86-a66c-2f135b8fbb30': {'delay': '0.00157809257507= ', 'lastCheck': 1359564143.248153, 'code': 0, 'valid': True}}=20 Thread-2406::DEBUG::2013-01-30 16:42:23,305::task::1172::TaskManager.Task::= (prepare) Task=3D`8926a671-3076-42e5-8521-f8ec6ba67748`::finished: {'394847= 95-666f-44b3-9cf5-21bbb02531ad': {'delay': '0.00179004669189', 'lastCheck':= 1359564135.40165, 'code': 0, 'valid': True}, '0b6a87e8-53d9-46f3-bc81-20aa= b92f08aa': {'delay': '0.00332403182983', 'lastCheck': 1359564141.220177, 'c= ode': 0, 'valid': True}, 'cc060953-baf5-4b86-a66c-2f135b8fbb30': {'delay': = '0.00157809257507', 'lastCheck': 1359564143.248153, 'code': 0, 'valid': Tru= e}}=20 Thread-2406::DEBUG::2013-01-30 16:42:23,305::task::588::TaskManager.Task::(= _updateState) Task=3D`8926a671-3076-42e5-8521-f8ec6ba67748`::moving from st= ate preparing -> state finished=20 Thread-2406::DEBUG::2013-01-30 16:42:23,305::resourceManager::809::Resource= Manager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}=20 Thread-2406::DEBUG::2013-01-30 16:42:23,305::resourceManager::844::Resource= Manager.Owner::(cancelAll) Owner.cancelAll requests {}=20 Thread-2406::DEBUG::2013-01-30 16:42:23,305::task::978::TaskManager.Task::(= _decref) Task=3D`8926a671-3076-42e5-8521-f8ec6ba67748`::ref 0 aborting Fals= e=20 Thread-2407::DEBUG::2013-01-30 16:42:23,368::libvirtvm::240::vm.Vm::(_getDi= skStats) vmId=3D`35fb5c70-3ac8-4b5e-8e48-8cffe9fdcf53`::Disk hdc stats not = available=20 Thread-2407::DEBUG::2013-01-30 16:42:23,368::libvirtvm::240::vm.Vm::(_getDi= skStats) vmId=3D`35fb5c70-3ac8-4b5e-8e48-8cffe9fdcf53`::Disk fda stats not = available=20 VM Channels Listener::DEBUG::2013-01-30 16:42:27,492::vmChannels::60::vds::= (_handle_timeouts) Timeout on fileno 18.=20 Thread-788::DEBUG::2013-01-30 16:42:28,907::task::588::TaskManager.Task::(_= updateState) Task=3D`aec127b3-b02b-4bc3-b0e9-542c90b4c91e`::moving from sta= te init -> state preparing=20 Thread-788::INFO::2013-01-30 16:42:28,907::logUtils::37::dispatcher::(wrapp= er) Run and protect: getVolumeSize(sdUUID=3D'39484795-666f-44b3-9cf5-21bbb0= 2531ad', spUUID=3D'7b44684c-5f34-11e2-beba-00138fbe3093', imgUUID=3D'2ff4c7= 43-6e5a-42af-8b99-131c8849bd3f', volUUID=3D'7304b24f-5c4d-41b3-b12f-b916bc9= f4299', options=3DNone)=20 Thread-788::DEBUG::2013-01-30 16:42:28,908::resourceManager::175::ResourceM= anager.Request::(__init__) ResName=3D`Storage.39484795-666f-44b3-9cf5-21bbb= 02531ad`ReqID=3D`9ba33a25-cdd2-4fc0-9f50-55a82178ad48`::Request was made in= '/usr/share/vdsm/storage/resourceManager.py' line '485' at 'registerResour= ce'=20 Thread-788::DEBUG::2013-01-30 16:42:28,908::resourceManager::486::ResourceM= anager::(registerResource) Trying to register resource 'Storage.39484795-66= 6f-44b3-9cf5-21bbb02531ad' for lock type 'shared'=20 Thread-788::DEBUG::2013-01-30 16:42:28,908::resourceManager::528::ResourceM= anager::(registerResource) Resource 'Storage.39484795-666f-44b3-9cf5-21bbb0= 2531ad' is free. Now locking as 'shared' (1 active user)=20 Thread-788::DEBUG::2013-01-30 16:42:28,908::resourceManager::212::ResourceM= anager.Request::(grant) ResName=3D`Storage.39484795-666f-44b3-9cf5-21bbb025= 31ad`ReqID=3D`9ba33a25-cdd2-4fc0-9f50-55a82178ad48`::Granted request=20 Thread-788::DEBUG::2013-01-30 16:42:28,908::task::817::TaskManager.Task::(r= esourceAcquired) Task=3D`aec127b3-b02b-4bc3-b0e9-542c90b4c91e`::_resourcesA= cquired: Storage.39484795-666f-44b3-9cf5-21bbb02531ad (shared)=20 Thread-788::DEBUG::2013-01-30 16:42:28,909::task::978::TaskManager.Task::(_= decref) Task=3D`aec127b3-b02b-4bc3-b0e9-542c90b4c91e`::ref 1 aborting False= =20 Thread-788::DEBUG::2013-01-30 16:42:28,911::fileVolume::535::Storage.Volume= ::(validateVolumePath) validate path for 7304b24f-5c4d-41b3-b12f-b916bc9f42= 99=20 Thread-788::DEBUG::2013-01-30 16:42:28,913::fileVolume::535::Storage.Volume= ::(validateVolumePath) validate path for 7304b24f-5c4d-41b3-b12f-b916bc9f42= 99=20 Thread-788::INFO::2013-01-30 16:42:28,914::logUtils::39::dispatcher::(wrapp= er) Run and protect: getVolumeSize, Return response: {'truesize': '32562257= 92', 'apparentsize': '107374182400'}=20 Thread-788::DEBUG::2013-01-30 16:42:28,914::task::1172::TaskManager.Task::(= prepare) Task=3D`aec127b3-b02b-4bc3-b0e9-542c90b4c91e`::finished: {'truesiz= e': '3256225792', 'apparentsize': '107374182400'}=20 Thread-788::DEBUG::2013-01-30 16:42:28,915::task::588::TaskManager.Task::(_= updateState) Task=3D`aec127b3-b02b-4bc3-b0e9-542c90b4c91e`::moving from sta= te preparing -> state finished=20 Thread-788::DEBUG::2013-01-30 16:42:28,915::resourceManager::809::ResourceM= anager.Owner::(releaseAll) Owner.releaseAll requests {} resources {'Storage= .39484795-666f-44b3-9cf5-21bbb02531ad': < ResourceRef 'Storage.39484795-666= f-44b3-9cf5-21bbb02531ad', isValid: 'True' obj: 'None'>}=20 Thread-788::DEBUG::2013-01-30 16:42:28,915::resourceManager::844::ResourceM= anager.Owner::(cancelAll) Owner.cancelAll requests {}=20 Thread-788::DEBUG::2013-01-30 16:42:28,915::resourceManager::538::ResourceM= anager::(releaseResource) Trying to release resource 'Storage.39484795-666f= -44b3-9cf5-21bbb02531ad'=20 Thread-788::DEBUG::2013-01-30 16:42:28,915::resourceManager::553::ResourceM= anager::(releaseResource) Released resource 'Storage.39484795-666f-44b3-9cf= 5-21bbb02531ad' (0 active users)=20 Thread-788::DEBUG::2013-01-30 16:42:28,915::resourceManager::558::ResourceM= anager::(releaseResource) Resource 'Storage.39484795-666f-44b3-9cf5-21bbb02= 531ad' is free, finding out if anyone is waiting for it.=20 Thread-788::DEBUG::2013-01-30 16:42:28,915::resourceManager::565::ResourceM= anager::(releaseResource) No one is waiting for resource 'Storage.39484795-= 666f-44b3-9cf5-21bbb02531ad', Clearing records.=20 Thread-788::DEBUG::2013-01-30 16:42:28,915::task::978::TaskManager.Task::(_= decref) Task=3D`aec127b3-b02b-4bc3-b0e9-542c90b4c91e`::ref 0 aborting False= =20 VM Channels Listener::DEBUG::2013-01-30 16:42:29,494::vmChannels::60::vds::= (_handle_timeouts) Timeout on fileno 322.=20 Thread-2412::DEBUG::2013-01-30 16:42:31,843::BindingXMLRPC::156::vds::(wrap= per) [192.168.5.180]=20 Thread-2412::DEBUG::2013-01-30 16:42:31,843::task::588::TaskManager.Task::(= _updateState) Task=3D`4095451f-5992-4276-8bbc-3cbd5c192905`::moving from st= ate init -> state preparing=20 Thread-2412::INFO::2013-01-30 16:42:31,844::logUtils::37::dispatcher::(wrap= per) Run and protect: getSpmStatus(spUUID=3D'7b44684c-5f34-11e2-beba-00138f= be3093', options=3DNone)=20 Thread-2412::INFO::2013-01-30 16:42:31,844::logUtils::39::dispatcher::(wrap= per) Run and protect: getSpmStatus, Return response: {'spm_st': {'spmId': 1= , 'spmStatus': 'SPM', 'spmLver': 4}}=20 Thread-2412::DEBUG::2013-01-30 16:42:31,844::task::1172::TaskManager.Task::= (prepare) Task=3D`4095451f-5992-4276-8bbc-3cbd5c192905`::finished: {'spm_st= ': {'spmId': 1, 'spmStatus': 'SPM', 'spmLver': 4}}=20 Thread-2412::DEBUG::2013-01-30 16:42:31,844::task::588::TaskManager.Task::(= _updateState) Task=3D`4095451f-5992-4276-8bbc-3cbd5c192905`::moving from st= ate preparing -> state finished=20 Thread-2412::DEBUG::2013-01-30 16:42:31,844::resourceManager::809::Resource= Manager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}=20 Thread-2412::DEBUG::2013-01-30 16:42:31,844::resourceManager::844::Resource= Manager.Owner::(cancelAll) Owner.cancelAll requests {}=20 Thread-2412::DEBUG::2013-01-30 16:42:31,844::task::978::TaskManager.Task::(= _decref) Task=3D`4095451f-5992-4276-8bbc-3cbd5c192905`::ref 0 aborting Fals= e=20 Thread-2413::DEBUG::2013-01-30 16:42:31,936::BindingXMLRPC::156::vds::(wrap= per) [192.168.5.180]=20 Thread-2413::DEBUG::2013-01-30 16:42:31,937::task::588::TaskManager.Task::(= _updateState) Task=3D`42cacf2e-311a-4ca4-8158-6b3dd8f00a94`::moving from st= ate init -> state preparing=20 Thread-2413::INFO::2013-01-30 16:42:31,937::logUtils::37::dispatcher::(wrap= per) Run and protect: getStoragePoolInfo(spUUID=3D'7b44684c-5f34-11e2-beba-= 00138fbe3093', options=3DNone)=20 Thread-2413::DEBUG::2013-01-30 16:42:31,937::resourceManager::175::Resource= Manager.Request::(__init__) ResName=3D`Storage.7b44684c-5f34-11e2-beba-0013= 8fbe3093`ReqID=3D`e72c6606-db58-41d0-8072-c4fff9e0e417`::Request was made i= n '/usr/share/vdsm/storage/resourceManager.py' line '485' at 'registerResou= rce'=20 Thread-2413::DEBUG::2013-01-30 16:42:31,937::resourceManager::486::Resource= Manager::(registerResource) Trying to register resource 'Storage.7b44684c-5= f34-11e2-beba-00138fbe3093' for lock type 'shared'=20 Thread-2413::DEBUG::2013-01-30 16:42:31,937::resourceManager::528::Resource= Manager::(registerResource) Resource 'Storage.7b44684c-5f34-11e2-beba-00138= fbe3093' is free. Now locking as 'shared' (1 active user)=20 Thread-2413::DEBUG::2013-01-30 16:42:31,938::resourceManager::212::Resource= Manager.Request::(grant) ResName=3D`Storage.7b44684c-5f34-11e2-beba-00138fb= e3093`ReqID=3D`e72c6606-db58-41d0-8072-c4fff9e0e417`::Granted request=20 Thread-2413::DEBUG::2013-01-30 16:42:31,939::task::817::TaskManager.Task::(= resourceAcquired) Task=3D`42cacf2e-311a-4ca4-8158-6b3dd8f00a94`::_resources= Acquired: Storage.7b44684c-5f34-11e2-beba-00138fbe3093 (shared)=20 Thread-2413::DEBUG::2013-01-30 16:42:31,939::task::978::TaskManager.Task::(= _decref) Task=3D`42cacf2e-311a-4ca4-8158-6b3dd8f00a94`::ref 1 aborting Fals= e=20 Thread-2413::INFO::2013-01-30 16:42:32,073::logUtils::39::dispatcher::(wrap= per) Run and protect: getStoragePoolInfo, Return response: {'info': {'spm_i= d': 1, 'master_uuid': 'cc060953-baf5-4b86-a66c-2f135b8fbb30', 'name': 'aclo= udDC', 'version': '0', 'domains': '39484795-666f-44b3-9cf5-21bbb02531ad:Act= ive,0b6a87e8-53d9-46f3-bc81-20aab92f08aa:Active,cc060953-baf5-4b86-a66c-2f1= 35b8fbb30:Active', 'pool_status': 'connected', 'isoprefix': '/rhev/data-cen= ter/7b44684c-5f34-11e2-beba-00138fbe3093/0b6a87e8-53d9-46f3-bc81-20aab92f08= aa/images/11111111-1111-1111-1111-111111111111', 'type': 'NFS', 'master_ver= ': 10575, 'lver': 4}, 'dominfo': {'0b6a87e8-53d9-46f3-bc81-20aab92f08aa': {= 'status': 'Active', 'diskfree': '17986224128', 'alerts': [], 'disktotal': '= 23648534528'}, '39484795-666f-44b3-9cf5-21bbb02531ad': {'status': 'Active',= 'diskfree': '467744063488', 'alerts': [], 'disktotal': '476676358144'}, 'c= c060953-baf5-4b86-a66c-2f135b8fbb30': {'status': 'Active', 'diskfree': '313= 801244672', 'alerts': [], 'disktotal': '982927736832'}}}=20 Thread-2413::DEBUG::2013-01-30 16:42:32,073::task::1172::TaskManager.Task::= (prepare) Task=3D`42cacf2e-311a-4ca4-8158-6b3dd8f00a94`::finished: {'info':= {'spm_id': 1, 'master_uuid': 'cc060953-baf5-4b86-a66c-2f135b8fbb30', 'name= ': 'acloudDC', 'version': '0', 'domains': '39484795-666f-44b3-9cf5-21bbb025= 31ad:Active,0b6a87e8-53d9-46f3-bc81-20aab92f08aa:Active,cc060953-baf5-4b86-= a66c-2f135b8fbb30:Active', 'pool_status': 'connected', 'isoprefix': '/rhev/= data-center/7b44684c-5f34-11e2-beba-00138fbe3093/0b6a87e8-53d9-46f3-bc81-20= aab92f08aa/images/11111111-1111-1111-1111-111111111111', 'type': 'NFS', 'ma= ster_ver': 10575, 'lver': 4}, 'dominfo': {'0b6a87e8-53d9-46f3-bc81-20aab92f= 08aa': {'status': 'Active', 'diskfree': '17986224128', 'alerts': [], 'diskt= otal': '23648534528'}, '39484795-666f-44b3-9cf5-21bbb02531ad': {'status': '= Active', 'diskfree': '467744063488', 'alerts': [], 'disktotal': '4766763581= 44'}, 'cc060953-baf5-4b86-a66c-2f135b8fbb30': {'status': 'Active', 'diskfre= e': '313801244672', 'alerts': [], 'disktotal': '982927736832'}}}=20 Thread-2413::DEBUG::2013-01-30 16:42:32,073::task::588::TaskManager.Task::(= _updateState) Task=3D`42cacf2e-311a-4ca4-8158-6b3dd8f00a94`::moving from st= ate preparing -> state finished=20 Thread-2413::DEBUG::2013-01-30 16:42:32,073::resourceManager::809::Resource= Manager.Owner::(releaseAll) Owner.releaseAll requests {} resources {'Storag= e.7b44684c-5f34-11e2-beba-00138fbe3093': < ResourceRef 'Storage.7b44684c-5f= 34-11e2-beba-00138fbe3093', isValid: 'True' obj: 'None'>}=20 Thread-2413::DEBUG::2013-01-30 16:42:32,073::resourceManager::844::Resource= Manager.Owner::(cancelAll) Owner.cancelAll requests {}=20 Thread-2413::DEBUG::2013-01-30 16:42:32,074::resourceManager::538::Resource= Manager::(releaseResource) Trying to release resource 'Storage.7b44684c-5f3= 4-11e2-beba-00138fbe3093'=20 Thread-2413::DEBUG::2013-01-30 16:42:32,074::resourceManager::553::Resource= Manager::(releaseResource) Released resource 'Storage.7b44684c-5f34-11e2-be= ba-00138fbe3093' (0 active users)=20 Thread-2413::DEBUG::2013-01-30 16:42:32,074::resourceManager::558::Resource= Manager::(releaseResource) Resource 'Storage.7b44684c-5f34-11e2-beba-00138f= be3093' is free, finding out if anyone is waiting for it.=20 Thread-2413::DEBUG::2013-01-30 16:42:32,074::resourceManager::565::Resource= Manager::(releaseResource) No one is waiting for resource 'Storage.7b44684c= -5f34-11e2-beba-00138fbe3093', Clearing records.=20 Thread-2413::DEBUG::2013-01-30 16:42:32,075::task::978::TaskManager.Task::(= _decref) Task=3D`42cacf2e-311a-4ca4-8158-6b3dd8f00a94`::ref 0 aborting Fals= e=20 Thread-2414::DEBUG::2013-01-30 16:42:33,894::task::588::TaskManager.Task::(= _updateState) Task=3D`e5af4772-7be5-43c0-a907-8a3f3fe0cebd`::moving from st= ate init -> state preparing=20 Thread-2414::INFO::2013-01-30 16:42:33,894::logUtils::37::dispatcher::(wrap= per) Run and protect: repoStats(options=3DNone)=20 Thread-2414::INFO::2013-01-30 16:42:33,894::logUtils::39::dispatcher::(wrap= per) Run and protect: repoStats, Return response: {'39484795-666f-44b3-9cf5= -21bbb02531ad': {'delay': '0.00196099281311', 'lastCheck': 1359564145.53994= , 'code': 0, 'valid': True}, '0b6a87e8-53d9-46f3-bc81-20aab92f08aa': {'dela= y': '0.00284719467163', 'lastCheck': 1359564151.359623, 'code': 0, 'valid':= True}, 'cc060953-baf5-4b86-a66c-2f135b8fbb30': {'delay': '0.0015709400177'= , 'lastCheck': 1359564153.38349, 'code': 0, 'valid': True}}=20 Thread-2414::DEBUG::2013-01-30 16:42:33,895::task::1172::TaskManager.Task::= (prepare) Task=3D`e5af4772-7be5-43c0-a907-8a3f3fe0cebd`::finished: {'394847= 95-666f-44b3-9cf5-21bbb02531ad': {'delay': '0.00196099281311', 'lastCheck':= 1359564145.53994, 'code': 0, 'valid': True}, '0b6a87e8-53d9-46f3-bc81-20aa= b92f08aa': {'delay': '0.00284719467163', 'lastCheck': 1359564151.359623, 'c= ode': 0, 'valid': True}, 'cc060953-baf5-4b86-a66c-2f135b8fbb30': {'delay': = '0.0015709400177', 'lastCheck': 1359564153.38349, 'code': 0, 'valid': True}= }=20 Thread-2414::DEBUG::2013-01-30 16:42:33,895::task::588::TaskManager.Task::(= _updateState) Task=3D`e5af4772-7be5-43c0-a907-8a3f3fe0cebd`::moving from st= ate preparing -> state finished=20 Thread-2414::DEBUG::2013-01-30 16:42:33,895::resourceManager::809::Resource= Manager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}=20 Thread-2414::DEBUG::2013-01-30 16:42:33,895::resourceManager::844::Resource= Manager.Owner::(cancelAll) Owner.cancelAll requests {}=20 Thread-2414::DEBUG::2013-01-30 16:42:33,895::task::978::TaskManager.Task::(= _decref) Task=3D`e5af4772-7be5-43c0-a907-8a3f3fe0cebd`::ref 0 aborting Fals= e=20 Thread-2415::DEBUG::2013-01-30 16:42:33,996::libvirtvm::240::vm.Vm::(_getDi= skStats) vmId=3D`35fb5c70-3ac8-4b5e-8e48-8cffe9fdcf53`::Disk hdc stats not = available=20 Thread-2415::DEBUG::2013-01-30 16:42:33,997::libvirtvm::240::vm.Vm::(_getDi= skStats) vmId=3D`35fb5c70-3ac8-4b5e-8e48-8cffe9fdcf53`::Disk fda stats not = available=20 Thread-424::DEBUG::2013-01-30 16:42:34,508::task::588::TaskManager.Task::(_= updateState) Task=3D`413cbd4e-2ddc-4a21-9526-39e970dc48d3`::moving from sta= te init -> state preparing=20 Thread-424::INFO::2013-01-30 16:42:34,509::logUtils::37::dispatcher::(wrapp= er) Run and protect: getVolumeSize(sdUUID=3D'39484795-666f-44b3-9cf5-21bbb0= 2531ad', spUUID=3D'7b44684c-5f34-11e2-beba-00138fbe3093', imgUUID=3D'c7524c= bd-5f92-41ba-a9e9-8724dd2c4c11', volUUID=3D'5904f9d7-09c3-404d-8887-71a32ff= 96735', options=3DNone)=20 Thread-424::DEBUG::2013-01-30 16:42:34,509::resourceManager::175::ResourceM= anager.Request::(__init__) ResName=3D`Storage.39484795-666f-44b3-9cf5-21bbb= 02531ad`ReqID=3D`e4e2d280-6941-469f-be31-ac06bfb73f99`::Request was made in= '/usr/share/vdsm/storage/resourceManager.py' line '485' at 'registerResour= ce'=20 Thread-424::DEBUG::2013-01-30 16:42:34,509::resourceManager::486::ResourceM= anager::(registerResource) Trying to register resource 'Storage.39484795-66= 6f-44b3-9cf5-21bbb02531ad' for lock type 'shared'=20 Thread-424::DEBUG::2013-01-30 16:42:34,509::resourceManager::528::ResourceM= anager::(registerResource) Resource 'Storage.39484795-666f-44b3-9cf5-21bbb0= 2531ad' is free. Now locking as 'shared' (1 active user)=20 Thread-424::DEBUG::2013-01-30 16:42:34,509::resourceManager::212::ResourceM= anager.Request::(grant) ResName=3D`Storage.39484795-666f-44b3-9cf5-21bbb025= 31ad`ReqID=3D`e4e2d280-6941-469f-be31-ac06bfb73f99`::Granted request=20 Thread-424::DEBUG::2013-01-30 16:42:34,509::task::817::TaskManager.Task::(r= esourceAcquired) Task=3D`413cbd4e-2ddc-4a21-9526-39e970dc48d3`::_resourcesA= cquired: Storage.39484795-666f-44b3-9cf5-21bbb02531ad (shared)=20 Thread-424::DEBUG::2013-01-30 16:42:34,510::task::978::TaskManager.Task::(_= decref) Task=3D`413cbd4e-2ddc-4a21-9526-39e970dc48d3`::ref 1 aborting False= =20 Thread-424::DEBUG::2013-01-30 16:42:34,511::fileVolume::535::Storage.Volume= ::(validateVolumePath) validate path for 5904f9d7-09c3-404d-8887-71a32ff967= 35=20 ---------------------------------------------=20 Logicworks Tecnologias de Inform=C3=A1tica=20 http://www.logicworks.pt=20 ------=_Part_476_18436217.1359564233863 Content-Type: text/html; charset=utf-8 Content-Transfer-Encoding: quoted-printable <html><head><style type=3D'text/css'>p { margin: 0; }</style></head><body><= div style=3D'font-family: verdana,helvetica,sans-serif; font-size: 10pt; co= lor: #330066'>Hi,<br><br>I'm testing oVirt 3.1, with one node 2.5.5-0.1fc17= and a NAS built with openfiler 2.99, working on a Gigabit net.<br>I config= ured a NFS share on openfiler, and everything looks nice.<br>I'm installing= a Windows 2008 R2 as a VM, time to time i get a warning message: ! VM is n= ot responding, but the windows installation keeps going, a bit slow.<br><br= sourcesAcquired: Storage.7b44684c-5f34-11e2-beba-00138fbe3093 (shared)<br>T= hread-2405::DEBUG::2013-01-30 16:42:21,532::task::978::TaskManager.Task::(_= decref) Task=3D`c581aa06-4e50-41dd-a836-756827865cc6`::ref 1 aborting False= <br>Thread-2405::INFO::2013-01-30 16:42:21,664::logUtils::39::dispatcher::(= wrapper) Run and protect: getStoragePoolInfo, Return response: {'info': {'s= pm_id': 1, 'master_uuid': 'cc060953-baf5-4b86-a66c-2f135b8fbb30', 'name': '= acloudDC', 'version': '0', 'domains': '39484795-666f-44b3-9cf5-21bbb02531ad= :Active,0b6a87e8-53d9-46f3-bc81-20aab92f08aa:Active,cc060953-baf5-4b86-a66c= -2f135b8fbb30:Active', 'pool_status': 'connected', 'isoprefix': '/rhev/data= -center/7b44684c-5f34-11e2-beba-00138fbe3093/0b6a87e8-53d9-46f3-bc81-20aab9= 2f08aa/images/11111111-1111-1111-1111-111111111111', 'type': 'NFS', 'master= _ver': 10575, 'lver': 4}, 'dominfo': {'0b6a87e8-53d9-46f3-bc81-20aab92f08aa= ': {'status': 'Active', 'diskfree': '17986224128', 'alerts': [], 'disktotal= ': '23648534528'}, '39484795-666f-44b3-9cf5-21bbb02531ad': {'status': 'Acti= ve', 'diskfree': '467744063488', 'alerts': [], 'disktotal': '476676358144'}= , 'cc060953-baf5-4b86-a66c-2f135b8fbb30': {'status': 'Active', 'diskfree': = '313802031104', 'alerts': [], 'disktotal': '982927736832'}}}<br>Thread-2405= ::DEBUG::2013-01-30 16:42:21,664::task::1172::TaskManager.Task::(prepare) T= ask=3D`c581aa06-4e50-41dd-a836-756827865cc6`::finished: {'info': {'spm_id':= 1, 'master_uuid': 'cc060953-baf5-4b86-a66c-2f135b8fbb30', 'name': 'acloudD= C', 'version': '0', 'domains': '39484795-666f-44b3-9cf5-21bbb02531ad:Active= ,0b6a87e8-53d9-46f3-bc81-20aab92f08aa:Active,cc060953-baf5-4b86-a66c-2f135b= 8fbb30:Active', 'pool_status': 'connected', 'isoprefix': '/rhev/data-center= /7b44684c-5f34-11e2-beba-00138fbe3093/0b6a87e8-53d9-46f3-bc81-20aab92f08aa/= images/11111111-1111-1111-1111-111111111111', 'type': 'NFS', 'master_ver': = 10575, 'lver': 4}, 'dominfo': {'0b6a87e8-53d9-46f3-bc81-20aab92f08aa': {'st= atus': 'Active', 'diskfree': '17986224128', 'alerts': [], 'disktotal': '236= 48534528'}, '39484795-666f-44b3-9cf5-21bbb02531ad': {'status': 'Active', 'd= iskfree': '467744063488', 'alerts': [], 'disktotal': '476676358144'}, 'cc06= 0953-baf5-4b86-a66c-2f135b8fbb30': {'status': 'Active', 'diskfree': '313802= 031104', 'alerts': [], 'disktotal': '982927736832'}}}<br>Thread-2405::DEBUG= ::2013-01-30 16:42:21,664::task::588::TaskManager.Task::(_updateState) Task= =3D`c581aa06-4e50-41dd-a836-756827865cc6`::moving from state preparing ->= ; state finished<br>Thread-2405::DEBUG::2013-01-30 16:42:21,664::resourceMa= nager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {= } resources {'Storage.7b44684c-5f34-11e2-beba-00138fbe3093': < ResourceR= ef 'Storage.7b44684c-5f34-11e2-beba-00138fbe3093', isValid: 'True' obj: 'No= ne'>}<br>Thread-2405::DEBUG::2013-01-30 16:42:21,664::resourceManager::8= 44::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}<br>Threa= d-2405::DEBUG::2013-01-30 16:42:21,665::resourceManager::538::ResourceManag= er::(releaseResource) Trying to release resource 'Storage.7b44684c-5f34-11e= 2-beba-00138fbe3093'<br>Thread-2405::DEBUG::2013-01-30 16:42:21,665::resour= ceManager::553::ResourceManager::(releaseResource) Released resource 'Stora= ge.7b44684c-5f34-11e2-beba-00138fbe3093' (0 active users)<br>Thread-2405::D= EBUG::2013-01-30 16:42:21,665::resourceManager::558::ResourceManager::(rele= aseResource) Resource 'Storage.7b44684c-5f34-11e2-beba-00138fbe3093' is fre= e, finding out if anyone is waiting for it.<br>Thread-2405::DEBUG::2013-01-= 30 16:42:21,665::resourceManager::565::ResourceManager::(releaseResource) N= o one is waiting for resource 'Storage.7b44684c-5f34-11e2-beba-00138fbe3093= ', Clearing records.<br>Thread-2405::DEBUG::2013-01-30 16:42:21,665::task::= 978::TaskManager.Task::(_decref) Task=3D`c581aa06-4e50-41dd-a836-756827865c= c6`::ref 0 aborting False<br>Thread-2406::DEBUG::2013-01-30 16:42:23,304::t= ask::588::TaskManager.Task::(_updateState) Task=3D`8926a671-3076-42e5-8521-= f8ec6ba67748`::moving from state init -> state preparing<br>Thread-2406:= :INFO::2013-01-30 16:42:23,304::logUtils::37::dispatcher::(wrapper) Run and= protect: repoStats(options=3DNone)<br>Thread-2406::INFO::2013-01-30 16:42:= 23,304::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats, Ret= urn response: {'39484795-666f-44b3-9cf5-21bbb02531ad': {'delay': '0.0017900= 4669189', 'lastCheck': 1359564135.40165, 'code': 0, 'valid': True}, '0b6a87= e8-53d9-46f3-bc81-20aab92f08aa': {'delay': '0.00332403182983', 'lastCheck':= 1359564141.220177, 'code': 0, 'valid': True}, 'cc060953-baf5-4b86-a66c-2f1= 35b8fbb30': {'delay': '0.00157809257507', 'lastCheck': 1359564143.248153, '= code': 0, 'valid': True}}<br>Thread-2406::DEBUG::2013-01-30 16:42:23,305::t= ask::1172::TaskManager.Task::(prepare) Task=3D`8926a671-3076-42e5-8521-f8ec= 6ba67748`::finished: {'39484795-666f-44b3-9cf5-21bbb02531ad': {'delay': '0.= 00179004669189', 'lastCheck': 1359564135.40165, 'code': 0, 'valid': True}, = '0b6a87e8-53d9-46f3-bc81-20aab92f08aa': {'delay': '0.00332403182983', 'last= Check': 1359564141.220177, 'code': 0, 'valid': True}, 'cc060953-baf5-4b86-a= 66c-2f135b8fbb30': {'delay': '0.00157809257507', 'lastCheck': 1359564143.24= 8153, 'code': 0, 'valid': True}}<br>Thread-2406::DEBUG::2013-01-30 16:42:23= ,305::task::588::TaskManager.Task::(_updateState) Task=3D`8926a671-3076-42e= 5-8521-f8ec6ba67748`::moving from state preparing -> state finished<br>T= hread-2406::DEBUG::2013-01-30 16:42:23,305::resourceManager::809::ResourceM= anager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}<br>Thr= ead-2406::DEBUG::2013-01-30 16:42:23,305::resourceManager::844::ResourceMan= ager.Owner::(cancelAll) Owner.cancelAll requests {}<br>Thread-2406::DEBUG::= 2013-01-30 16:42:23,305::task::978::TaskManager.Task::(_decref) Task=3D`892= 6a671-3076-42e5-8521-f8ec6ba67748`::ref 0 aborting False<br>Thread-2407::DE= BUG::2013-01-30 16:42:23,368::libvirtvm::240::vm.Vm::(_getDiskStats) vmId= =3D`35fb5c70-3ac8-4b5e-8e48-8cffe9fdcf53`::Disk hdc stats not available<br>= Thread-2407::DEBUG::2013-01-30 16:42:23,368::libvirtvm::240::vm.Vm::(_getDi= skStats) vmId=3D`35fb5c70-3ac8-4b5e-8e48-8cffe9fdcf53`::Disk fda stats not = available<br>VM Channels Listener::DEBUG::2013-01-30 16:42:27,492::vmChanne= ls::60::vds::(_handle_timeouts) Timeout on fileno 18.<br>Thread-788::DEBUG:= :2013-01-30 16:42:28,907::task::588::TaskManager.Task::(_updateState) Task= =3D`aec127b3-b02b-4bc3-b0e9-542c90b4c91e`::moving from state init -> sta= te preparing<br>Thread-788::INFO::2013-01-30 16:42:28,907::logUtils::37::di= spatcher::(wrapper) Run and protect: getVolumeSize(sdUUID=3D'39484795-666f-= 44b3-9cf5-21bbb02531ad', spUUID=3D'7b44684c-5f34-11e2-beba-00138fbe3093', i= mgUUID=3D'2ff4c743-6e5a-42af-8b99-131c8849bd3f', volUUID=3D'7304b24f-5c4d-4= 1b3-b12f-b916bc9f4299', options=3DNone)<br>Thread-788::DEBUG::2013-01-30 16= :42:28,908::resourceManager::175::ResourceManager.Request::(__init__) ResNa= me=3D`Storage.39484795-666f-44b3-9cf5-21bbb02531ad`ReqID=3D`9ba33a25-cdd2-4= fc0-9f50-55a82178ad48`::Request was made in '/usr/share/vdsm/storage/resour= ceManager.py' line '485' at 'registerResource'<br>Thread-788::DEBUG::2013-0= 1-30 16:42:28,908::resourceManager::486::ResourceManager::(registerResource= ) Trying to register resource 'Storage.39484795-666f-44b3-9cf5-21bbb02531ad= ' for lock type 'shared'<br>Thread-788::DEBUG::2013-01-30 16:42:28,908::res= ourceManager::528::ResourceManager::(registerResource) Resource 'Storage.39= 484795-666f-44b3-9cf5-21bbb02531ad' is free. Now locking as 'shared' (1 act= ive user)<br>Thread-788::DEBUG::2013-01-30 16:42:28,908::resourceManager::2= 12::ResourceManager.Request::(grant) ResName=3D`Storage.39484795-666f-44b3-= 9cf5-21bbb02531ad`ReqID=3D`9ba33a25-cdd2-4fc0-9f50-55a82178ad48`::Granted r= equest<br>Thread-788::DEBUG::2013-01-30 16:42:28,908::task::817::TaskManage= r.Task::(resourceAcquired) Task=3D`aec127b3-b02b-4bc3-b0e9-542c90b4c91e`::_= resourcesAcquired: Storage.39484795-666f-44b3-9cf5-21bbb02531ad (shared)<br= olume::(validateVolumePath) validate path for 7304b24f-5c4d-41b3-b12f-b916b= c9f4299<br>Thread-788::DEBUG::2013-01-30 16:42:28,913::fileVolume::535::Sto= rage.Volume::(validateVolumePath) validate path for 7304b24f-5c4d-41b3-b12f= -b916bc9f4299<br>Thread-788::INFO::2013-01-30 16:42:28,914::logUtils::39::d= ispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'tru= esize': '3256225792', 'apparentsize': '107374182400'}<br>Thread-788::DEBUG:= :2013-01-30 16:42:28,914::task::1172::TaskManager.Task::(prepare) Task=3D`a= ec127b3-b02b-4bc3-b0e9-542c90b4c91e`::finished: {'truesize': '3256225792', = 'apparentsize': '107374182400'}<br>Thread-788::DEBUG::2013-01-30 16:42:28,9= 15::task::588::TaskManager.Task::(_updateState) Task=3D`aec127b3-b02b-4bc3-= b0e9-542c90b4c91e`::moving from state preparing -> state finished<br>Thr= ead-788::DEBUG::2013-01-30 16:42:28,915::resourceManager::809::ResourceMana= ger.Owner::(releaseAll) Owner.releaseAll requests {} resources {'Storage.39= 484795-666f-44b3-9cf5-21bbb02531ad': < ResourceRef 'Storage.39484795-666= f-44b3-9cf5-21bbb02531ad', isValid: 'True' obj: 'None'>}<br>Thread-788::= DEBUG::2013-01-30 16:42:28,915::resourceManager::844::ResourceManager.Owner= ::(cancelAll) Owner.cancelAll requests {}<br>Thread-788::DEBUG::2013-01-30 = 16:42:28,915::resourceManager::538::ResourceManager::(releaseResource) Tryi= ng to release resource 'Storage.39484795-666f-44b3-9cf5-21bbb02531ad'<br>Th= read-788::DEBUG::2013-01-30 16:42:28,915::resourceManager::553::ResourceMan= ager::(releaseResource) Released resource 'Storage.39484795-666f-44b3-9cf5-= 21bbb02531ad' (0 active users)<br>Thread-788::DEBUG::2013-01-30 16:42:28,91= 5::resourceManager::558::ResourceManager::(releaseResource) Resource 'Stora= ge.39484795-666f-44b3-9cf5-21bbb02531ad' is free, finding out if anyone is = waiting for it.<br>Thread-788::DEBUG::2013-01-30 16:42:28,915::resourceMana= ger::565::ResourceManager::(releaseResource) No one is waiting for resource= 'Storage.39484795-666f-44b3-9cf5-21bbb02531ad', Clearing records.<br>Threa= d-788::DEBUG::2013-01-30 16:42:28,915::task::978::TaskManager.Task::(_decre= f) Task=3D`aec127b3-b02b-4bc3-b0e9-542c90b4c91e`::ref 0 aborting False<br>V= M Channels Listener::DEBUG::2013-01-30 16:42:29,494::vmChannels::60::vds::(= _handle_timeouts) Timeout on fileno 322.<br>Thread-2412::DEBUG::2013-01-30 = 16:42:31,843::BindingXMLRPC::156::vds::(wrapper) [192.168.5.180]<br>Thread-= 2412::DEBUG::2013-01-30 16:42:31,843::task::588::TaskManager.Task::(_update= State) Task=3D`4095451f-5992-4276-8bbc-3cbd5c192905`::moving from state ini= t -> state preparing<br>Thread-2412::INFO::2013-01-30 16:42:31,844::logU= tils::37::dispatcher::(wrapper) Run and protect: getSpmStatus(spUUID=3D'7b4= 4684c-5f34-11e2-beba-00138fbe3093', options=3DNone)<br>Thread-2412::INFO::2= 013-01-30 16:42:31,844::logUtils::39::dispatcher::(wrapper) Run and protect= : getSpmStatus, Return response: {'spm_st': {'spmId': 1, 'spmStatus': 'SPM'= , 'spmLver': 4}}<br>Thread-2412::DEBUG::2013-01-30 16:42:31,844::task::1172= ::TaskManager.Task::(prepare) Task=3D`4095451f-5992-4276-8bbc-3cbd5c192905`= ::finished: {'spm_st': {'spmId': 1, 'spmStatus': 'SPM', 'spmLver': 4}}<br>T= hread-2412::DEBUG::2013-01-30 16:42:31,844::task::588::TaskManager.Task::(_= updateState) Task=3D`4095451f-5992-4276-8bbc-3cbd5c192905`::moving from sta= te preparing -> state finished<br>Thread-2412::DEBUG::2013-01-30 16:42:3= 1,844::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.rele= aseAll requests {} resources {}<br>Thread-2412::DEBUG::2013-01-30 16:42:31,= 844::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelA= ll requests {}<br>Thread-2412::DEBUG::2013-01-30 16:42:31,844::task::978::T= askManager.Task::(_decref) Task=3D`4095451f-5992-4276-8bbc-3cbd5c192905`::r= ef 0 aborting False<br>Thread-2413::DEBUG::2013-01-30 16:42:31,936::Binding= XMLRPC::156::vds::(wrapper) [192.168.5.180]<br>Thread-2413::DEBUG::2013-01-= 30 16:42:31,937::task::588::TaskManager.Task::(_updateState) Task=3D`42cacf= 2e-311a-4ca4-8158-6b3dd8f00a94`::moving from state init -> state prepari= ng<br>Thread-2413::INFO::2013-01-30 16:42:31,937::logUtils::37::dispatcher:= :(wrapper) Run and protect: getStoragePoolInfo(spUUID=3D'7b44684c-5f34-11e2= -beba-00138fbe3093', options=3DNone)<br>Thread-2413::DEBUG::2013-01-30 16:4= 2:31,937::resourceManager::175::ResourceManager.Request::(__init__) ResName= =3D`Storage.7b44684c-5f34-11e2-beba-00138fbe3093`ReqID=3D`e72c6606-db58-41d= 0-8072-c4fff9e0e417`::Request was made in '/usr/share/vdsm/storage/resource= Manager.py' line '485' at 'registerResource'<br>Thread-2413::DEBUG::2013-01= -30 16:42:31,937::resourceManager::486::ResourceManager::(registerResource)= Trying to register resource 'Storage.7b44684c-5f34-11e2-beba-00138fbe3093'= for lock type 'shared'<br>Thread-2413::DEBUG::2013-01-30 16:42:31,937::res= ourceManager::528::ResourceManager::(registerResource) Resource 'Storage.7b= 44684c-5f34-11e2-beba-00138fbe3093' is free. Now locking as 'shared' (1 act= ive user)<br>Thread-2413::DEBUG::2013-01-30 16:42:31,938::resourceManager::= 212::ResourceManager.Request::(grant) ResName=3D`Storage.7b44684c-5f34-11e2= -beba-00138fbe3093`ReqID=3D`e72c6606-db58-41d0-8072-c4fff9e0e417`::Granted = request<br>Thread-2413::DEBUG::2013-01-30 16:42:31,939::task::817::TaskMana= ger.Task::(resourceAcquired) Task=3D`42cacf2e-311a-4ca4-8158-6b3dd8f00a94`:= :_resourcesAcquired: Storage.7b44684c-5f34-11e2-beba-00138fbe3093 (shared)<= br>Thread-2413::DEBUG::2013-01-30 16:42:31,939::task::978::TaskManager.Task= ::(_decref) Task=3D`42cacf2e-311a-4ca4-8158-6b3dd8f00a94`::ref 1 aborting F= alse<br>Thread-2413::INFO::2013-01-30 16:42:32,073::logUtils::39::dispatche= r::(wrapper) Run and protect: getStoragePoolInfo, Return response: {'info':= {'spm_id': 1, 'master_uuid': 'cc060953-baf5-4b86-a66c-2f135b8fbb30', 'name= ': 'acloudDC', 'version': '0', 'domains': '39484795-666f-44b3-9cf5-21bbb025= 31ad:Active,0b6a87e8-53d9-46f3-bc81-20aab92f08aa:Active,cc060953-baf5-4b86-= a66c-2f135b8fbb30:Active', 'pool_status': 'connected', 'isoprefix': '/rhev/= data-center/7b44684c-5f34-11e2-beba-00138fbe3093/0b6a87e8-53d9-46f3-bc81-20= aab92f08aa/images/11111111-1111-1111-1111-111111111111', 'type': 'NFS', 'ma= ster_ver': 10575, 'lver': 4}, 'dominfo': {'0b6a87e8-53d9-46f3-bc81-20aab92f= 08aa': {'status': 'Active', 'diskfree': '17986224128', 'alerts': [], 'diskt= otal': '23648534528'}, '39484795-666f-44b3-9cf5-21bbb02531ad': {'status': '= Active', 'diskfree': '467744063488', 'alerts': [], 'disktotal': '4766763581= 44'}, 'cc060953-baf5-4b86-a66c-2f135b8fbb30': {'status': 'Active', 'diskfre= e': '313801244672', 'alerts': [], 'disktotal': '982927736832'}}}<br>Thread-= 2413::DEBUG::2013-01-30 16:42:32,073::task::1172::TaskManager.Task::(prepar= e) Task=3D`42cacf2e-311a-4ca4-8158-6b3dd8f00a94`::finished: {'info': {'spm_= id': 1, 'master_uuid': 'cc060953-baf5-4b86-a66c-2f135b8fbb30', 'name': 'acl= oudDC', 'version': '0', 'domains': '39484795-666f-44b3-9cf5-21bbb02531ad:Ac= tive,0b6a87e8-53d9-46f3-bc81-20aab92f08aa:Active,cc060953-baf5-4b86-a66c-2f= 135b8fbb30:Active', 'pool_status': 'connected', 'isoprefix': '/rhev/data-ce= nter/7b44684c-5f34-11e2-beba-00138fbe3093/0b6a87e8-53d9-46f3-bc81-20aab92f0= 8aa/images/11111111-1111-1111-1111-111111111111', 'type': 'NFS', 'master_ve= r': 10575, 'lver': 4}, 'dominfo': {'0b6a87e8-53d9-46f3-bc81-20aab92f08aa': = {'status': 'Active', 'diskfree': '17986224128', 'alerts': [], 'disktotal': = '23648534528'}, '39484795-666f-44b3-9cf5-21bbb02531ad': {'status': 'Active'= , 'diskfree': '467744063488', 'alerts': [], 'disktotal': '476676358144'}, '= cc060953-baf5-4b86-a66c-2f135b8fbb30': {'status': 'Active', 'diskfree': '31= 3801244672', 'alerts': [], 'disktotal': '982927736832'}}}<br>Thread-2413::D= EBUG::2013-01-30 16:42:32,073::task::588::TaskManager.Task::(_updateState) = Task=3D`42cacf2e-311a-4ca4-8158-6b3dd8f00a94`::moving from state preparing = -> state finished<br>Thread-2413::DEBUG::2013-01-30 16:42:32,073::resour= ceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll reques= ts {} resources {'Storage.7b44684c-5f34-11e2-beba-00138fbe3093': < Resou= rceRef 'Storage.7b44684c-5f34-11e2-beba-00138fbe3093', isValid: 'True' obj:= 'None'>}<br>Thread-2413::DEBUG::2013-01-30 16:42:32,073::resourceManage= r::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}<br>T= hread-2413::DEBUG::2013-01-30 16:42:32,074::resourceManager::538::ResourceM= anager::(releaseResource) Trying to release resource 'Storage.7b44684c-5f34= -11e2-beba-00138fbe3093'<br>Thread-2413::DEBUG::2013-01-30 16:42:32,074::re= sourceManager::553::ResourceManager::(releaseResource) Released resource 'S= torage.7b44684c-5f34-11e2-beba-00138fbe3093' (0 active users)<br>Thread-241= 3::DEBUG::2013-01-30 16:42:32,074::resourceManager::558::ResourceManager::(= releaseResource) Resource 'Storage.7b44684c-5f34-11e2-beba-00138fbe3093' is= free, finding out if anyone is waiting for it.<br>Thread-2413::DEBUG::2013= -01-30 16:42:32,074::resourceManager::565::ResourceManager::(releaseResourc= e) No one is waiting for resource 'Storage.7b44684c-5f34-11e2-beba-00138fbe= 3093', Clearing records.<br>Thread-2413::DEBUG::2013-01-30 16:42:32,075::ta= sk::978::TaskManager.Task::(_decref) Task=3D`42cacf2e-311a-4ca4-8158-6b3dd8= f00a94`::ref 0 aborting False<br>Thread-2414::DEBUG::2013-01-30 16:42:33,89= 4::task::588::TaskManager.Task::(_updateState) Task=3D`e5af4772-7be5-43c0-a= 907-8a3f3fe0cebd`::moving from state init -> state preparing<br>Thread-2= 414::INFO::2013-01-30 16:42:33,894::logUtils::37::dispatcher::(wrapper) Run= and protect: repoStats(options=3DNone)<br>Thread-2414::INFO::2013-01-30 16= :42:33,894::logUtils::39::dispatcher::(wrapper) Run and protect: repoStats,= Return response: {'39484795-666f-44b3-9cf5-21bbb02531ad': {'delay': '0.001= 96099281311', 'lastCheck': 1359564145.53994, 'code': 0, 'valid': True}, '0b= 6a87e8-53d9-46f3-bc81-20aab92f08aa': {'delay': '0.00284719467163', 'lastChe= ck': 1359564151.359623, 'code': 0, 'valid': True}, 'cc060953-baf5-4b86-a66c= -2f135b8fbb30': {'delay': '0.0015709400177', 'lastCheck': 1359564153.38349,= 'code': 0, 'valid': True}}<br>Thread-2414::DEBUG::2013-01-30 16:42:33,895:= :task::1172::TaskManager.Task::(prepare) Task=3D`e5af4772-7be5-43c0-a907-8a= 3f3fe0cebd`::finished: {'39484795-666f-44b3-9cf5-21bbb02531ad': {'delay': '= 0.00196099281311', 'lastCheck': 1359564145.53994, 'code': 0, 'valid': True}= , '0b6a87e8-53d9-46f3-bc81-20aab92f08aa': {'delay': '0.00284719467163', 'la= stCheck': 1359564151.359623, 'code': 0, 'valid': True}, 'cc060953-baf5-4b86= -a66c-2f135b8fbb30': {'delay': '0.0015709400177', 'lastCheck': 1359564153.3= 8349, 'code': 0, 'valid': True}}<br>Thread-2414::DEBUG::2013-01-30 16:42:33= ,895::task::588::TaskManager.Task::(_updateState) Task=3D`e5af4772-7be5-43c= 0-a907-8a3f3fe0cebd`::moving from state preparing -> state finished<br>T= hread-2414::DEBUG::2013-01-30 16:42:33,895::resourceManager::809::ResourceM= anager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}<br>Thr= ead-2414::DEBUG::2013-01-30 16:42:33,895::resourceManager::844::ResourceMan= ager.Owner::(cancelAll) Owner.cancelAll requests {}<br>Thread-2414::DEBUG::= 2013-01-30 16:42:33,895::task::978::TaskManager.Task::(_decref) Task=3D`e5a= f4772-7be5-43c0-a907-8a3f3fe0cebd`::ref 0 aborting False<br>Thread-2415::DE= BUG::2013-01-30 16:42:33,996::libvirtvm::240::vm.Vm::(_getDiskStats) vmId= =3D`35fb5c70-3ac8-4b5e-8e48-8cffe9fdcf53`::Disk hdc stats not available<br>= Thread-2415::DEBUG::2013-01-30 16:42:33,997::libvirtvm::240::vm.Vm::(_getDi= skStats) vmId=3D`35fb5c70-3ac8-4b5e-8e48-8cffe9fdcf53`::Disk fda stats not = available<br>Thread-424::DEBUG::2013-01-30 16:42:34,508::task::588::TaskMan= ager.Task::(_updateState) Task=3D`413cbd4e-2ddc-4a21-9526-39e970dc48d3`::mo= ving from state init -> state preparing<br>Thread-424::INFO::2013-01-30 = 16:42:34,509::logUtils::37::dispatcher::(wrapper) Run and protect: getVolum= eSize(sdUUID=3D'39484795-666f-44b3-9cf5-21bbb02531ad', spUUID=3D'7b44684c-5= f34-11e2-beba-00138fbe3093', imgUUID=3D'c7524cbd-5f92-41ba-a9e9-8724dd2c4c1= 1', volUUID=3D'5904f9d7-09c3-404d-8887-71a32ff96735', options=3DNone)<br>Th= read-424::DEBUG::2013-01-30 16:42:34,509::resourceManager::175::ResourceMan= ager.Request::(__init__) ResName=3D`Storage.39484795-666f-44b3-9cf5-21bbb02= 531ad`ReqID=3D`e4e2d280-6941-469f-be31-ac06bfb73f99`::Request was made in '= /usr/share/vdsm/storage/resourceManager.py' line '485' at 'registerResource= '<br>Thread-424::DEBUG::2013-01-30 16:42:34,509::resourceManager::486::Reso= urceManager::(registerResource) Trying to register resource 'Storage.394847= 95-666f-44b3-9cf5-21bbb02531ad' for lock type 'shared'<br>Thread-424::DEBUG= ::2013-01-30 16:42:34,509::resourceManager::528::ResourceManager::(register= Resource) Resource 'Storage.39484795-666f-44b3-9cf5-21bbb02531ad' is free. = Now locking as 'shared' (1 active user)<br>Thread-424::DEBUG::2013-01-30 16= :42:34,509::resourceManager::212::ResourceManager.Request::(grant) ResName= =3D`Storage.39484795-666f-44b3-9cf5-21bbb02531ad`ReqID=3D`e4e2d280-6941-469= f-be31-ac06bfb73f99`::Granted request<br>Thread-424::DEBUG::2013-01-30 16:4= 2:34,509::task::817::TaskManager.Task::(resourceAcquired) Task=3D`413cbd4e-= 2ddc-4a21-9526-39e970dc48d3`::_resourcesAcquired: Storage.39484795-666f-44b= 3-9cf5-21bbb02531ad (shared)<br>Thread-424::DEBUG::2013-01-30 16:42:34,510:= :task::978::TaskManager.Task::(_decref) Task=3D`413cbd4e-2ddc-4a21-9526-39e= 970dc48d3`::ref 1 aborting False<br>Thread-424::DEBUG::2013-01-30 16:42:34,= 511::fileVolume::535::Storage.Volume::(validateVolumePath) validate path fo= r 5904f9d7-09c3-404d-8887-71a32ff96735<br><br><br><div><span name=3D"x"></s= pan><span style=3D"color: rgb(253, 188, 85);">-----------------------------= ----------------</span><br style=3D"color: rgb(253, 188, 85);"><span style= =3D"color: rgb(253, 188, 85);">Logicworks Tecnologias de Inform=C3=A1tica</= span><br style=3D"color: rgb(253, 188, 85);"><a href=3D"http://www.logicwor= ks.pt"><span style=3D"color: rgb(253, 188, 85);">http://www.logicworks.pt</= span></a><span name=3D"x"></span><br></div></div></body></html> ------=_Part_476_18436217.1359564233863--