Attachment 653581 Details for Bug 880555 – Latest vdsm.log

Latest vdsm.log

latest_vdsm.log (text/x-log), 14.40 KB, created by Valentin Bajrami on 2012-11-28 15:07:52 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Valentin Bajrami

Created: 2012-11-28 15:07:52 UTC

Size: 14.40 KB

patch

obsolete

>Thread-513::DEBUG::2012-11-28 16:04:53,999::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-513::DEBUG::2012-11-28 16:04:54,000::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-513::DEBUG::2012-11-28 16:04:54,000::task::978::TaskManager.Task::(_decref) Task=`c8467ec1-5bc9-4f84-828a-c9b568165ad8`::ref 0 aborting False
>Thread-24::ERROR::2012-11-28 16:04:54,366::domainMonitor::120::Storage.DomainMonitor::(_monitorDomain) Error while collecting domain `0149d080-a94c-446d-969c-eef7da5f6706` monitoring information
>Traceback (most recent call last):
>  File "/usr/share/vdsm/storage/domainMonitor.py", line 103, in _monitorDomain
>    domain.selftest()
>  File "/usr/share/vdsm/storage/nfsSD.py", line 103, in selftest
>    fileSD.FileStorageDomain.selftest(self)
>  File "/usr/share/vdsm/storage/fileSD.py", line 399, in selftest
>    self.oop.os.statvfs(self.domaindir)
>  File "/usr/share/vdsm/storage/processPool.py", line 63, in wrapper
>    return self.runExternally(func, *args, **kwds)
>  File "/usr/share/vdsm/storage/processPool.py", line 74, in runExternally
>    return self._procPool.runExternally(*args, **kwargs)
>  File "/usr/share/vdsm/storage/processPool.py", line 161, in runExternally
>    raise Timeout("Operation Stuck")
>Timeout: Operation Stuck
>Thread-23::ERROR::2012-11-28 16:04:54,391::domainMonitor::120::Storage.DomainMonitor::(_monitorDomain) Error while collecting domain `3d40cf03-891e-471e-93ce-7e7970f73723` monitoring information
>Traceback (most recent call last):
>  File "/usr/share/vdsm/storage/domainMonitor.py", line 103, in _monitorDomain
>    domain.selftest()
>  File "/usr/share/vdsm/storage/nfsSD.py", line 103, in selftest
>    fileSD.FileStorageDomain.selftest(self)
>  File "/usr/share/vdsm/storage/fileSD.py", line 399, in selftest
>    self.oop.os.statvfs(self.domaindir)
>  File "/usr/share/vdsm/storage/processPool.py", line 63, in wrapper
>    return self.runExternally(func, *args, **kwds)
>  File "/usr/share/vdsm/storage/processPool.py", line 74, in runExternally
>    return self._procPool.runExternally(*args, **kwargs)
>  File "/usr/share/vdsm/storage/processPool.py", line 161, in runExternally
>    raise Timeout("Operation Stuck")
>Timeout: Operation Stuck
>Thread-517::DEBUG::2012-11-28 16:04:56,087::BindingXMLRPC::156::vds::(wrapper) [192.168.2.113]
>Thread-517::DEBUG::2012-11-28 16:04:56,088::task::588::TaskManager.Task::(_updateState) Task=`e11eab59-1054-451b-b005-d8db19310f02`::moving from state init -> state preparing
>Thread-517::INFO::2012-11-28 16:04:56,088::logUtils::37::dispatcher::(wrapper) Run and protect: getSpmStatus(spUUID='25f8442c-bb4e-4f72-a66a-35715f149300', options=None)
>Thread-517::ERROR::2012-11-28 16:04:56,088::hsm::538::Storage.HSM::(getSpmStatus) Unexpected error
>Traceback (most recent call last):
>  File "/usr/share/vdsm/storage/hsm.py", line 530, in getSpmStatus
>    status = {'spmStatus':pool.getSpmRole(), 'spmLver': pool.getSpmLver(), 'spmId':pool.getSpmId()}
>  File "/usr/share/vdsm/storage/sp.py", line 133, in getSpmLver
>    return self.getMetaParam(PMDK_LVER)
>  File "/usr/share/vdsm/storage/sp.py", line 1434, in getMetaParam
>    return self._metadata[key]
>  File "/usr/share/vdsm/storage/persistentDict.py", line 85, in __getitem__
>    return dec(self._dict[key])
>  File "/usr/share/vdsm/storage/persistentDict.py", line 195, in __getitem__
>    raise KeyError(key)
>KeyError: 'POOL_SPM_LVER'
>Thread-517::ERROR::2012-11-28 16:04:56,088::task::853::TaskManager.Task::(_setError) Task=`e11eab59-1054-451b-b005-d8db19310f02`::Unexpected error
>Traceback (most recent call last):
>  File "/usr/share/vdsm/storage/task.py", line 861, in _run
>    return fn(*args, **kargs)
>  File "/usr/share/vdsm/logUtils.py", line 38, in wrapper
>    res = f(*args, **kwargs)
>  File "/usr/share/vdsm/storage/hsm.py", line 539, in getSpmStatus
>    raise se.MetaDataParamError("Version or spm id invalid")
>MetaDataParamError: Meta Data parameter invalid: ('Version or spm id invalid',)
>Thread-517::DEBUG::2012-11-28 16:04:56,089::task::872::TaskManager.Task::(_run) Task=`e11eab59-1054-451b-b005-d8db19310f02`::Task._run: e11eab59-1054-451b-b005-d8db19310f02 ('25f8442c-bb4e-4f72-a66a-35715f149300',) {} failed - stopping task
>Thread-517::DEBUG::2012-11-28 16:04:56,089::task::1199::TaskManager.Task::(stop) Task=`e11eab59-1054-451b-b005-d8db19310f02`::stopping in state preparing (force False)
>Thread-517::DEBUG::2012-11-28 16:04:56,089::task::978::TaskManager.Task::(_decref) Task=`e11eab59-1054-451b-b005-d8db19310f02`::ref 1 aborting True
>Thread-517::INFO::2012-11-28 16:04:56,089::task::1157::TaskManager.Task::(prepare) Task=`e11eab59-1054-451b-b005-d8db19310f02`::aborting: Task is aborted: 'Meta Data parameter invalid' - code 755
>Thread-517::DEBUG::2012-11-28 16:04:56,089::task::1162::TaskManager.Task::(prepare) Task=`e11eab59-1054-451b-b005-d8db19310f02`::Prepare: aborted: Meta Data parameter invalid
>Thread-517::DEBUG::2012-11-28 16:04:56,090::task::978::TaskManager.Task::(_decref) Task=`e11eab59-1054-451b-b005-d8db19310f02`::ref 0 aborting True
>Thread-517::DEBUG::2012-11-28 16:04:56,090::task::913::TaskManager.Task::(_doAbort) Task=`e11eab59-1054-451b-b005-d8db19310f02`::Task._doAbort: force False
>Thread-517::DEBUG::2012-11-28 16:04:56,090::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-517::DEBUG::2012-11-28 16:04:56,090::task::588::TaskManager.Task::(_updateState) Task=`e11eab59-1054-451b-b005-d8db19310f02`::moving from state preparing -> state aborting
>Thread-517::DEBUG::2012-11-28 16:04:56,090::task::537::TaskManager.Task::(__state_aborting) Task=`e11eab59-1054-451b-b005-d8db19310f02`::_aborting: recover policy none
>Thread-517::DEBUG::2012-11-28 16:04:56,090::task::588::TaskManager.Task::(_updateState) Task=`e11eab59-1054-451b-b005-d8db19310f02`::moving from state aborting -> state failed
>Thread-517::DEBUG::2012-11-28 16:04:56,091::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-517::DEBUG::2012-11-28 16:04:56,091::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-517::ERROR::2012-11-28 16:04:56,091::dispatcher::66::Storage.Dispatcher.Protect::(run) {'status': {'message': "Meta Data parameter invalid: ('Version or spm id invalid',)", 'code': 755}}
>Thread-520::DEBUG::2012-11-28 16:05:00,119::BindingXMLRPC::156::vds::(wrapper) [192.168.2.113]
>Thread-520::DEBUG::2012-11-28 16:05:00,119::task::588::TaskManager.Task::(_updateState) Task=`bea463a8-60aa-488f-ac1a-4ae6eed639cc`::moving from state init -> state preparing
>Thread-520::INFO::2012-11-28 16:05:00,119::logUtils::37::dispatcher::(wrapper) Run and protect: validateStorageServerConnection(domType=1, spUUID='00000000-0000-0000-0000-000000000000', conList=[{'connection': '192.168.2.93:/srv/data', 'iqn': '', 'portal': '', 'user': '', 'password': '******', 'id': '45d36912-f3f1-4fbb-add4-8fcde4c96269', 'port': ''}], options=None)
>Thread-520::INFO::2012-11-28 16:05:00,119::logUtils::39::dispatcher::(wrapper) Run and protect: validateStorageServerConnection, Return response: {'statuslist': [{'status': 0, 'id': '45d36912-f3f1-4fbb-add4-8fcde4c96269'}]}
>Thread-520::DEBUG::2012-11-28 16:05:00,119::task::1172::TaskManager.Task::(prepare) Task=`bea463a8-60aa-488f-ac1a-4ae6eed639cc`::finished: {'statuslist': [{'status': 0, 'id': '45d36912-f3f1-4fbb-add4-8fcde4c96269'}]}
>Thread-520::DEBUG::2012-11-28 16:05:00,120::task::588::TaskManager.Task::(_updateState) Task=`bea463a8-60aa-488f-ac1a-4ae6eed639cc`::moving from state preparing -> state finished
>Thread-520::DEBUG::2012-11-28 16:05:00,120::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-520::DEBUG::2012-11-28 16:05:00,120::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-520::DEBUG::2012-11-28 16:05:00,120::task::978::TaskManager.Task::(_decref) Task=`bea463a8-60aa-488f-ac1a-4ae6eed639cc`::ref 0 aborting False
>Thread-521::DEBUG::2012-11-28 16:05:00,136::BindingXMLRPC::156::vds::(wrapper) [192.168.2.113]
>Thread-521::DEBUG::2012-11-28 16:05:00,137::task::588::TaskManager.Task::(_updateState) Task=`7ebc72aa-7e76-4a93-9245-b9046d33a2d1`::moving from state init -> state preparing
>Thread-521::INFO::2012-11-28 16:05:00,137::logUtils::37::dispatcher::(wrapper) Run and protect: connectStorageServer(domType=1, spUUID='00000000-0000-0000-0000-000000000000', conList=[{'connection': '192.168.2.93:/srv/data', 'iqn': '', 'portal': '', 'user': '', 'password': '******', 'id': '45d36912-f3f1-4fbb-add4-8fcde4c96269', 'port': ''}], options=None)
>Thread-521::DEBUG::2012-11-28 16:05:00,143::lvm::457::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' got the operation mutex
>Thread-521::DEBUG::2012-11-28 16:05:00,144::lvm::459::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' released the operation mutex
>Thread-521::DEBUG::2012-11-28 16:05:00,144::lvm::469::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' got the operation mutex
>Thread-521::DEBUG::2012-11-28 16:05:00,145::lvm::471::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' released the operation mutex
>Thread-521::DEBUG::2012-11-28 16:05:00,145::lvm::490::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' got the operation mutex
>Thread-521::DEBUG::2012-11-28 16:05:00,145::lvm::492::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' released the operation mutex
>Thread-521::INFO::2012-11-28 16:05:00,145::logUtils::39::dispatcher::(wrapper) Run and protect: connectStorageServer, Return response: {'statuslist': [{'status': 0, 'id': '45d36912-f3f1-4fbb-add4-8fcde4c96269'}]}
>Thread-521::DEBUG::2012-11-28 16:05:00,145::task::1172::TaskManager.Task::(prepare) Task=`7ebc72aa-7e76-4a93-9245-b9046d33a2d1`::finished: {'statuslist': [{'status': 0, 'id': '45d36912-f3f1-4fbb-add4-8fcde4c96269'}]}
>Thread-521::DEBUG::2012-11-28 16:05:00,145::task::588::TaskManager.Task::(_updateState) Task=`7ebc72aa-7e76-4a93-9245-b9046d33a2d1`::moving from state preparing -> state finished
>Thread-521::DEBUG::2012-11-28 16:05:00,145::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-521::DEBUG::2012-11-28 16:05:00,145::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-521::DEBUG::2012-11-28 16:05:00,145::task::978::TaskManager.Task::(_decref) Task=`7ebc72aa-7e76-4a93-9245-b9046d33a2d1`::ref 0 aborting False
>Thread-523::DEBUG::2012-11-28 16:05:00,166::BindingXMLRPC::156::vds::(wrapper) [192.168.2.113]
>Thread-523::DEBUG::2012-11-28 16:05:00,167::task::588::TaskManager.Task::(_updateState) Task=`66fe399b-2c8e-4ffa-a0c4-3e540f09376e`::moving from state init -> state preparing
>Thread-523::INFO::2012-11-28 16:05:00,167::logUtils::37::dispatcher::(wrapper) Run and protect: getSpmStatus(spUUID='25f8442c-bb4e-4f72-a66a-35715f149300', options=None)
>Thread-523::ERROR::2012-11-28 16:05:00,167::hsm::538::Storage.HSM::(getSpmStatus) Unexpected error
>Traceback (most recent call last):
>  File "/usr/share/vdsm/storage/hsm.py", line 530, in getSpmStatus
>    status = {'spmStatus':pool.getSpmRole(), 'spmLver': pool.getSpmLver(), 'spmId':pool.getSpmId()}
>  File "/usr/share/vdsm/storage/sp.py", line 133, in getSpmLver
>    return self.getMetaParam(PMDK_LVER)
>  File "/usr/share/vdsm/storage/sp.py", line 1434, in getMetaParam
>    return self._metadata[key]
>  File "/usr/share/vdsm/storage/persistentDict.py", line 85, in __getitem__
>    return dec(self._dict[key])
>  File "/usr/share/vdsm/storage/persistentDict.py", line 195, in __getitem__
>    raise KeyError(key)
>KeyError: 'POOL_SPM_LVER'
>Thread-523::ERROR::2012-11-28 16:05:00,168::task::853::TaskManager.Task::(_setError) Task=`66fe399b-2c8e-4ffa-a0c4-3e540f09376e`::Unexpected error
>Traceback (most recent call last):
>  File "/usr/share/vdsm/storage/task.py", line 861, in _run
>    return fn(*args, **kargs)
>  File "/usr/share/vdsm/logUtils.py", line 38, in wrapper
>    res = f(*args, **kwargs)
>  File "/usr/share/vdsm/storage/hsm.py", line 539, in getSpmStatus
>    raise se.MetaDataParamError("Version or spm id invalid")
>MetaDataParamError: Meta Data parameter invalid: ('Version or spm id invalid',)
>Thread-523::DEBUG::2012-11-28 16:05:00,168::task::872::TaskManager.Task::(_run) Task=`66fe399b-2c8e-4ffa-a0c4-3e540f09376e`::Task._run: 66fe399b-2c8e-4ffa-a0c4-3e540f09376e ('25f8442c-bb4e-4f72-a66a-35715f149300',) {} failed - stopping task
>Thread-523::DEBUG::2012-11-28 16:05:00,168::task::1199::TaskManager.Task::(stop) Task=`66fe399b-2c8e-4ffa-a0c4-3e540f09376e`::stopping in state preparing (force False)
>Thread-523::DEBUG::2012-11-28 16:05:00,168::task::978::TaskManager.Task::(_decref) Task=`66fe399b-2c8e-4ffa-a0c4-3e540f09376e`::ref 1 aborting True
>Thread-523::INFO::2012-11-28 16:05:00,168::task::1157::TaskManager.Task::(prepare) Task=`66fe399b-2c8e-4ffa-a0c4-3e540f09376e`::aborting: Task is aborted: 'Meta Data parameter invalid' - code 755
>Thread-523::DEBUG::2012-11-28 16:05:00,168::task::1162::TaskManager.Task::(prepare) Task=`66fe399b-2c8e-4ffa-a0c4-3e540f09376e`::Prepare: aborted: Meta Data parameter invalid
>Thread-523::DEBUG::2012-11-28 16:05:00,169::task::978::TaskManager.Task::(_decref) Task=`66fe399b-2c8e-4ffa-a0c4-3e540f09376e`::ref 0 aborting True
>Thread-523::DEBUG::2012-11-28 16:05:00,169::task::913::TaskManager.Task::(_doAbort) Task=`66fe399b-2c8e-4ffa-a0c4-3e540f09376e`::Task._doAbort: force False
>Thread-523::DEBUG::2012-11-28 16:05:00,169::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-523::DEBUG::2012-11-28 16:05:00,169::task::588::TaskManager.Task::(_updateState) Task=`66fe399b-2c8e-4ffa-a0c4-3e540f09376e`::moving from state preparing -> state aborting
>Thread-523::DEBUG::2012-11-28 16:05:00,169::task::537::TaskManager.Task::(__state_aborting) Task=`66fe399b-2c8e-4ffa-a0c4-3e540f09376e`::_aborting: recover policy none
>Thread-523::DEBUG::2012-11-28 16:05:00,169::task::588::TaskManager.Task::(_updateState) Task=`66fe399b-2c8e-4ffa-a0c4-3e540f09376e`::moving from state aborting -> state failed
>Thread-523::DEBUG::2012-11-28 16:05:00,170::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
>Thread-523::DEBUG::2012-11-28 16:05:00,170::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
>Thread-523::ERROR::2012-11-28 16:05:00,170::dispatcher::66::Storage.Dispatcher.Protect::(run) {'status': {'message': "Meta Data parameter invalid: ('Version or spm id invalid',)", 'code': 755}}
>

Actions: View

Attachments on bug 880555: 652563 | 652564 | 653581