------=_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=
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=
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=
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=
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--