[Users] Issues with NFS domains and kernel-3.5.0-2.f17
ovirt at qip.ru
ovirt at qip.ru
Tue Aug 21 08:28:56 UTC 2012
problem also exist with 3.5.2-1.fc17.x86_64 kernel
# uname -a
Linux kvm04 3.5.2-1.fc17.x86_64 #1 SMP Wed Aug 15 16:09:27 UTC 2012 x86_64 x86_64 x86_64 GNU/Linux
# rpm -q vdsm
vdsm-4.10.0-0.331.git69d730d.fc17.x86_64
iso nfs domain d2221cee-7146-4197-aecf-0dfad32b54ea mounted correctly under /rhev/data-center/mnt/ but can't attach to DC
here is a part of vdsm.log
Thread-37506::DEBUG::2012-08-21 10:23:31,463::task::568::TaskManager.Task::(_updateState) Task=`d2436317-5e3f-4bf1-8414-b3e771a04b76`::moving from state init -> state preparing
Thread-37506::INFO::2012-08-21 10:23:31,464::logUtils::37::dispatcher::(wrapper) Run and protect: getStoragePoolInfo(spUUID='8800e8fa-bcee-11e1-9c2b-000c290cc066', options=None)
Thread-37506::DEBUG::2012-08-21 10:23:31,464::resourceManager::175::ResourceManager.Request::(__init__) ResName=`Storage.8800e8fa-bcee-11e1-9c2b-000c290cc066`ReqID=`9698fc65-ad15-4c61-af01-1ce4ad627447`::Request was made in '/usr/share/vdsm/storage/resourceManager.py' line '485' at 'registerResource'
Thread-37506::DEBUG::2012-08-21 10:23:31,464::resourceManager::486::ResourceManager::(registerResource) Trying to register resource 'Storage.8800e8fa-bcee-11e1-9c2b-000c290cc066' for lock type 'shared'
Thread-37506::DEBUG::2012-08-21 10:23:31,465::resourceManager::528::ResourceManager::(registerResource) Resource 'Storage.8800e8fa-bcee-11e1-9c2b-000c290cc066' is free. Now locking as 'shared' (1 active user)
Thread-37506::DEBUG::2012-08-21 10:23:31,465::resourceManager::212::ResourceManager.Request::(grant) ResName=`Storage.8800e8fa-bcee-11e1-9c2b-000c290cc066`ReqID=`9698fc65-ad15-4c61-af01-1ce4ad627447`::Granted request
Thread-37506::DEBUG::2012-08-21 10:23:31,466::task::794::TaskManager.Task::(resourceAcquired) Task=`d2436317-5e3f-4bf1-8414-b3e771a04b76`::_resourcesAcquired: Storage.8800e8fa-bcee-11e1-9c2b-000c290cc066 (shared)
Thread-37506::DEBUG::2012-08-21 10:23:31,466::task::957::TaskManager.Task::(_decref) Task=`d2436317-5e3f-4bf1-8414-b3e771a04b76`::ref 1 aborting False
Thread-37506::DEBUG::2012-08-21 10:23:31,466::lvm::368::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' got the operation mutex
Thread-37506::DEBUG::2012-08-21 10:23:31,470::__init__::1249::Storage.Misc.excCmd::(_log) '/bin/sudo -n /sbin/lvm vgs --config " devices { preferred_names = [\\"^/dev/mapper/\\"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 filter = [ \\"a%1ATA_KINGSTON_SV100S232G_50026B7221046658|1p_ISCSI_0_lun1|1p_ISCSI_0_lun2|1p_ISCSI_0_lun3%\\", \\"r%.*%\\" ] } global { locking_type=1 prioritise_write_locks=1 wait_for_locks=1 } backup { retain_min = 50 retain_days = 0 } " --noheadings --units b --nosuffix --separator | -o uuid,name,attr,size,free,extent_size,extent_count,free_count,tags,vg_mda_size,vg_mda_free e57827fe-f368-4e96-b57c-f14d52cfccb7' (cwd None)
Thread-37506::DEBUG::2012-08-21 10:23:31,564::__init__::1249::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
Thread-37506::DEBUG::2012-08-21 10:23:31,566::lvm::397::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' released the operation mutex
Thread-37506::DEBUG::2012-08-21 10:23:31,567::misc::1061::SamplingMethod::(__call__) Trying to enter sampling method (storage.sdc.refreshStorage)
Dummy-86::DEBUG::2012-08-21 10:23:31,773::__init__::1249::Storage.Misc.excCmd::(_log) 'dd if=/rhev/data-center/8800e8fa-bcee-11e1-9c2b-000c290cc066/mastersd/dom_md/inbox iflag=direct,fullblock count=1 bs=1024000' (cwd None)
Dummy-86::DEBUG::2012-08-21 10:23:31,833::__init__::1249::Storage.Misc.excCmd::(_log) SUCCESS: <err> = '1+0 records in\n1+0 records out\n1024000 bytes (1.0 MB) copied, 0.0375137 s, 27.3 MB/s\n'; <rc> = 0
Thread-37502::DEBUG::2012-08-21 10:23:33,317::__init__::1249::Storage.Misc.excCmd::(_log) '/bin/sudo -n /sbin/multipath' (cwd None)
Thread-37502::DEBUG::2012-08-21 10:23:33,360::__init__::1249::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
Thread-37502::DEBUG::2012-08-21 10:23:33,361::lvm::477::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' got the operation mutex
Thread-37502::DEBUG::2012-08-21 10:23:33,361::lvm::479::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' released the operation mutex
Thread-37502::DEBUG::2012-08-21 10:23:33,362::lvm::488::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' got the operation mutex
Thread-37502::DEBUG::2012-08-21 10:23:33,362::lvm::490::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' released the operation mutex
Thread-37502::DEBUG::2012-08-21 10:23:33,362::lvm::508::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' got the operation mutex
Thread-37502::DEBUG::2012-08-21 10:23:33,363::lvm::510::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' released the operation mutex
Thread-37502::DEBUG::2012-08-21 10:23:33,363::misc::1071::SamplingMethod::(__call__) Returning last result
Thread-37506::DEBUG::2012-08-21 10:23:33,363::misc::1063::SamplingMethod::(__call__) Got in to sampling method
Thread-37502::DEBUG::2012-08-21 10:23:33,363::lvm::368::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' got the operation mutex
Thread-37506::DEBUG::2012-08-21 10:23:33,364::misc::1061::SamplingMethod::(__call__) Trying to enter sampling method (storage.iscsi.rescan)
Thread-37506::DEBUG::2012-08-21 10:23:33,364::misc::1063::SamplingMethod::(__call__) Got in to sampling method
Thread-37506::DEBUG::2012-08-21 10:23:33,365::__init__::1249::Storage.Misc.excCmd::(_log) '/bin/sudo -n /sbin/iscsiadm -m session -R' (cwd None)
Thread-37502::DEBUG::2012-08-21 10:23:33,374::__init__::1249::Storage.Misc.excCmd::(_log) '/bin/sudo -n /sbin/lvm vgs --config " devices { preferred_names = [\\"^/dev/mapper/\\"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 filter = [ \\"a%1ATA_KINGSTON_SV100S232G_50026B7221046658|1p_ISCSI_0_lun1|1p_ISCSI_0_lun2|1p_ISCSI_0_lun3%\\", \\"r%.*%\\" ] } global { locking_type=1 prioritise_write_locks=1 wait_for_locks=1 } backup { retain_min = 50 retain_days = 0 } " --noheadings --units b --nosuffix --separator | -o uuid,name,attr,size,free,extent_size,extent_count,free_count,tags,vg_mda_size,vg_mda_free' (cwd None)
Thread-37506::DEBUG::2012-08-21 10:23:33,391::__init__::1249::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
Thread-37506::DEBUG::2012-08-21 10:23:33,391::misc::1071::SamplingMethod::(__call__) Returning last result
Thread-37502::DEBUG::2012-08-21 10:23:33,488::__init__::1249::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
Thread-37502::DEBUG::2012-08-21 10:23:33,492::lvm::397::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' released the operation mutex
Dummy-86::DEBUG::2012-08-21 10:23:33,842::__init__::1249::Storage.Misc.excCmd::(_log) 'dd if=/rhev/data-center/8800e8fa-bcee-11e1-9c2b-000c290cc066/mastersd/dom_md/inbox iflag=direct,fullblock count=1 bs=1024000' (cwd None)
Dummy-86::DEBUG::2012-08-21 10:23:33,903::__init__::1249::Storage.Misc.excCmd::(_log) SUCCESS: <err> = '1+0 records in\n1+0 records out\n1024000 bytes (1.0 MB) copied, 0.0377754 s, 27.1 MB/s\n'; <rc> = 0
Thread-37506::DEBUG::2012-08-21 10:23:35,711::__init__::1249::Storage.Misc.excCmd::(_log) '/bin/sudo -n /sbin/multipath' (cwd None)
Thread-37506::DEBUG::2012-08-21 10:23:35,752::__init__::1249::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
Thread-37506::DEBUG::2012-08-21 10:23:35,753::lvm::477::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' got the operation mutex
Thread-37506::DEBUG::2012-08-21 10:23:35,753::lvm::479::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' released the operation mutex
Thread-37506::DEBUG::2012-08-21 10:23:35,754::lvm::488::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' got the operation mutex
Thread-37506::DEBUG::2012-08-21 10:23:35,754::lvm::490::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' released the operation mutex
Thread-37506::DEBUG::2012-08-21 10:23:35,754::lvm::508::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' got the operation mutex
Thread-37506::DEBUG::2012-08-21 10:23:35,755::lvm::510::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' released the operation mutex
Thread-37506::DEBUG::2012-08-21 10:23:35,755::misc::1071::SamplingMethod::(__call__) Returning last result
Thread-37506::INFO::2012-08-21 10:23:35,756::logUtils::39::dispatcher::(wrapper) Run and protect: getStoragePoolInfo, Return response: {'info': {'spm_id': 1, 'master_uuid': 'e57827fe-f368-4e96-b57c-f14d52cfccb7', 'name': 'Default', 'version': '2', 'domains': 'e57827fe-f368-4e96-b57c-f14d52cfccb7:Active', 'pool_status': 'connected', 'isoprefix': '', 'type': 'ISCSI', 'master_ver': 3, 'lver': 16}, 'dominfo': {'e57827fe-f368-4e96-b57c-f14d52cfccb7': {'status': 'Active', 'diskfree': '495800287232', 'alerts': [], 'disktotal': '536468258816'}}}
Thread-37506::DEBUG::2012-08-21 10:23:35,756::task::1151::TaskManager.Task::(prepare) Task=`d2436317-5e3f-4bf1-8414-b3e771a04b76`::finished: {'info': {'spm_id': 1, 'master_uuid': 'e57827fe-f368-4e96-b57c-f14d52cfccb7', 'name': 'Default', 'version': '2', 'domains': 'e57827fe-f368-4e96-b57c-f14d52cfccb7:Active', 'pool_status': 'connected', 'isoprefix': '', 'type': 'ISCSI', 'master_ver': 3, 'lver': 16}, 'dominfo': {'e57827fe-f368-4e96-b57c-f14d52cfccb7': {'status': 'Active', 'diskfree': '495800287232', 'alerts': [], 'disktotal': '536468258816'}}}
Thread-37506::DEBUG::2012-08-21 10:23:35,756::task::568::TaskManager.Task::(_updateState) Task=`d2436317-5e3f-4bf1-8414-b3e771a04b76`::moving from state preparing -> state finished
Thread-37506::DEBUG::2012-08-21 10:23:35,757::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {'Storage.8800e8fa-bcee-11e1-9c2b-000c290cc066': < ResourceRef 'Storage.8800e8fa-bcee-11e1-9c2b-000c290cc066', isValid: 'True' obj: 'None'>}
Thread-37502::DEBUG::2012-08-21 10:23:35,757::lvm::368::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' got the operation mutex
Thread-37506::DEBUG::2012-08-21 10:23:35,758::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-37506::DEBUG::2012-08-21 10:23:35,759::resourceManager::538::ResourceManager::(releaseResource) Trying to release resource 'Storage.8800e8fa-bcee-11e1-9c2b-000c290cc066'
Thread-37506::DEBUG::2012-08-21 10:23:35,760::resourceManager::553::ResourceManager::(releaseResource) Released resource 'Storage.8800e8fa-bcee-11e1-9c2b-000c290cc066' (0 active users)
Thread-37506::DEBUG::2012-08-21 10:23:35,760::resourceManager::558::ResourceManager::(releaseResource) Resource 'Storage.8800e8fa-bcee-11e1-9c2b-000c290cc066' is free, finding out if anyone is waiting for it.
Thread-37506::DEBUG::2012-08-21 10:23:35,761::resourceManager::565::ResourceManager::(releaseResource) No one is waiting for resource 'Storage.8800e8fa-bcee-11e1-9c2b-000c290cc066', Clearing records.
Thread-37506::DEBUG::2012-08-21 10:23:35,761::task::957::TaskManager.Task::(_decref) Task=`d2436317-5e3f-4bf1-8414-b3e771a04b76`::ref 0 aborting False
Thread-37502::DEBUG::2012-08-21 10:23:35,766::__init__::1249::Storage.Misc.excCmd::(_log) '/bin/sudo -n /sbin/lvm vgs --config " devices { preferred_names = [\\"^/dev/mapper/\\"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 filter = [ \\"a%1ATA_KINGSTON_SV100S232G_50026B7221046658|1p_ISCSI_0_lun1|1p_ISCSI_0_lun2|1p_ISCSI_0_lun3%\\", \\"r%.*%\\" ] } global { locking_type=1 prioritise_write_locks=1 wait_for_locks=1 } backup { retain_min = 50 retain_days = 0 } " --noheadings --units b --nosuffix --separator | -o uuid,name,attr,size,free,extent_size,extent_count,free_count,tags,vg_mda_size,vg_mda_free d2221cee-7146-4197-aecf-0dfad32b54ea' (cwd None)
Thread-37502::DEBUG::2012-08-21 10:23:35,874::__init__::1249::Storage.Misc.excCmd::(_log) FAILED: <err> = ' Volume group "d2221cee-7146-4197-aecf-0dfad32b54ea" not found\n'; <rc> = 5
Thread-37502::WARNING::2012-08-21 10:23:35,877::lvm::373::Storage.LVM::(_reloadvgs) lvm vgs failed: 5 [] [' Volume group "d2221cee-7146-4197-aecf-0dfad32b54ea" not found']
Thread-37502::DEBUG::2012-08-21 10:23:35,878::lvm::397::OperationMutex::(_reloadvgs) Operation 'lvm reload operation' released the operation mutex
Thread-37502::DEBUG::2012-08-21 10:23:35,888::fileSD::107::Storage.StorageDomain::(__init__) Reading domain in path /rhev/data-center/mnt/192.168.130.41:_var_spool_ISO/d2221cee-7146-4197-aecf-0dfad32b54ea
Thread-37502::DEBUG::2012-08-21 10:23:35,888::persistentDict::192::Storage.PersistentDict::(__init__) Created a persistent dict with FileMetadataRW backend
Dummy-86::DEBUG::2012-08-21 10:23:35,912::__init__::1249::Storage.Misc.excCmd::(_log) 'dd if=/rhev/data-center/8800e8fa-bcee-11e1-9c2b-000c290cc066/mastersd/dom_md/inbox iflag=direct,fullblock count=1 bs=1024000' (cwd None)
Thread-37502::WARNING::2012-08-21 10:23:35,969::remoteFileHandler::185::Storage.CrabRPCProxy::(callCrabRPCFunction) Problem with handler, treating as timeout
Traceback (most recent call last):
File "/usr/share/vdsm/storage/remoteFileHandler.py", line 177, in callCrabRPCFunction
rawLength = self._recvAll(LENGTH_STRUCT_LENGTH, timeout)
File "/usr/share/vdsm/storage/remoteFileHandler.py", line 146, in _recvAll
timeLeft):
File "/usr/lib64/python2.7/contextlib.py", line 84, in helper
return GeneratorContextManager(func(*args, **kwds))
File "/usr/share/vdsm/storage/remoteFileHandler.py", line 133, in _poll
raise Timeout()
Timeout
Dummy-86::DEBUG::2012-08-21 10:23:35,972::__init__::1249::Storage.Misc.excCmd::(_log) SUCCESS: <err> = '1+0 records in\n1+0 records out\n1024000 bytes (1.0 MB) copied, 0.034715 s, 29.5 MB/s\n'; <rc> = 0
Thread-37502::ERROR::2012-08-21 10:23:35,972::sdc::145::Storage.StorageDomainCache::(_findDomain) Error while looking for domain `d2221cee-7146-4197-aecf-0dfad32b54ea`
Traceback (most recent call last):
File "/usr/share/vdsm/storage/sdc.py", line 140, in _findDomain
return mod.findDomain(sdUUID)
File "/usr/share/vdsm/storage/nfsSD.py", line 131, in findDomain
return NfsStorageDomain(NfsStorageDomain.findDomainPath(sdUUID))
File "/usr/share/vdsm/storage/fileSD.py", line 113, in __init__
sdUUID = metadata[sd.DMDK_SDUUID]
File "/usr/share/vdsm/storage/persistentDict.py", line 89, in __getitem__
return dec(self._dict[key])
File "/usr/share/vdsm/storage/persistentDict.py", line 199, in __getitem__
with self._accessWrapper():
File "/usr/lib64/python2.7/contextlib.py", line 17, in __enter__
return self.gen.next()
File "/usr/share/vdsm/storage/persistentDict.py", line 152, in _accessWrapper
self.refresh()
File "/usr/share/vdsm/storage/persistentDict.py", line 230, in refresh
lines = self._metaRW.readlines()
File "/usr/share/vdsm/storage/fileSD.py", line 82, in readlines
return misc.stripNewLines(self._oop.directReadLines(self._metafile))
File "/usr/share/vdsm/storage/remoteFileHandler.py", line 282, in callCrabRPCFunction
raise Timeout("Operation stuck on remote handler")
Timeout: Operation stuck on remote handler
Thread-37502::ERROR::2012-08-21 10:23:35,982::hsm::2347::Storage.HSM::(getStorageDomainsList) Unexpected error
Traceback (most recent call last):
File "/usr/share/vdsm/storage/hsm.py", line 2333, in getStorageDomainsList
dom = sdCache.produce(sdUUID=sdUUID)
File "/usr/share/vdsm/storage/sdc.py", line 110, in produce
dom.getRealDomain()
File "/usr/share/vdsm/storage/sdc.py", line 51, in getRealDomain
return self._cache._realProduce(self._sdUUID)
File "/usr/share/vdsm/storage/sdc.py", line 123, in _realProduce
dom = self._findDomain(sdUUID)
File "/usr/share/vdsm/storage/sdc.py", line 147, in _findDomain
raise se.StorageDomainDoesNotExist(sdUUID)
StorageDomainDoesNotExist: Storage domain does not exist: ('d2221cee-7146-4197-aecf-0dfad32b54ea',)
Втр 07 Авг 2012 22:47:38 +0400, Jason Brooks <jbrooks at redhat.com> написал:
> Hi all--
>
> Is anyone else running ovirt hosts on fedora kernel version 3.5.0-2.f17?
>
> That's the current fedora kernel, and I'm finding that nfs domain cannot attach with that kernel running: https://bugzilla.redhat.com/show_bug.cgi?id=845660.
>
> I'm working around the issue by running the previous fedora kernel.
>
> Regards, Jason
> _______________________________________________
> Users mailing list
> Users at ovirt.org
> http://lists.ovirt.org/mailman/listinfo/users
--
More information about the Users
mailing list