Re: [ovirt-users] "Could not connect host to Data Center" after rebooting, how to resolve?

Hi, Could you please attach the vdsm logs for the host for the time around the logs you pasted from the engine.log? Thanks, Gadi Ickowicz

vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:00,043::BindingXMLRPC::251::vds::(wrapper) client [192.168.1.44] flowID [61130377] vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:00,044::task::595::TaskManager.Task::(_updateState) Task=`217a7d59-fe83-4be5-b7e5-ce19c17a8d82`::moving from state init -> state preparing vdsm.log.11:Thread-23::INFO::2014-04-30 15:50:00,044::logUtils::44::dispatcher::(wrapper) Run and protect: connectStorageServer(domType=1, spUUID='00000000-0000-0000-0000-000000000000', conList=[{'connection': '192.168.1.44:/raid/ovirt/data', 'iqn': '', 'portal': '', 'user': '', 'password': '******', 'id': '3021c4ab-5cb8-455b-be5f-2c79b0e3b23b', 'port': ''}], options=None) vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:00,048::hsm::2317::Storage.HSM::(__prefetchDomains) nfs local path: /rhev/data-center/mnt/192.168.1.44:_raid_ovirt_data vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:00,049::hsm::2341::Storage.HSM::(__prefetchDomains) Found SD uuids: ('6bee0e2d-961c-453d-a266-e4623f91e162',) vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:00,050::hsm::2397::Storage.HSM::(connectStorageServer) knownSDs: {6bee0e2d-961c-453d-a266-e4623f91e162: storage.nfsSD.findDomain, 5e8c1e89-f2b8-492c-adb8-e9a9e15a79ee: storage.nfsSD.findDomain} vdsm.log.11:Thread-23::INFO::2014-04-30 15:50:00,050::logUtils::47::dispatcher::(wrapper) Run and protect: connectStorageServer, Return response: {'statuslist': [{'status': 0, 'id': '3021c4ab-5cb8-455b-be5f-2c79b0e3b23b'}]} vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:00,050::task::1185::TaskManager.Task::(prepare) Task=`217a7d59-fe83-4be5-b7e5-ce19c17a8d82`::finished: {'statuslist': [{'status': 0, 'id': '3021c4ab-5cb8-455b-be5f-2c79b0e3b23b'}]} vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:00,050::task::595::TaskManager.Task::(_updateState) Task=`217a7d59-fe83-4be5-b7e5-ce19c17a8d82`::moving from state preparing -> state finished vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:00,050::resourceManager::940::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:00,051::resourceManager::977::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:00,051::task::990::TaskManager.Task::(_decref) Task=`217a7d59-fe83-4be5-b7e5-ce19c17a8d82`::ref 0 aborting False vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:00,098::BindingXMLRPC::251::vds::(wrapper) client [192.168.1.44] flowID [2e8f350] vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:00,098::task::595::TaskManager.Task::(_updateState) Task=`dc6f1b1a-1162-4a3d-865d-d9ad9c3603f8`::moving from state init -> state preparing vdsm.log.11:Thread-23::INFO::2014-04-30 15:50:00,099::logUtils::44::dispatcher::(wrapper) Run and protect: connectStorageServer(domType=1, spUUID='00000000-0000-0000-0000-000000000000', conList=[{'connection': '192.168.1.44:/raid/ovirt/iso', 'iqn': '', 'portal': '', 'user': '', 'password': '******', 'id': '87de82d7-bc85-41ab-9ca7-3b39a75be919', 'port': ''}], options=None) vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:00,104::hsm::2317::Storage.HSM::(__prefetchDomains) nfs local path: /rhev/data-center/mnt/192.168.1.44:_raid_ovirt_iso vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:00,105::hsm::2341::Storage.HSM::(__prefetchDomains) Found SD uuids: ('5e8c1e89-f2b8-492c-adb8-e9a9e15a79ee',) vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:00,105::hsm::2397::Storage.HSM::(connectStorageServer) knownSDs: {6bee0e2d-961c-453d-a266-e4623f91e162: storage.nfsSD.findDomain, 5e8c1e89-f2b8-492c-adb8-e9a9e15a79ee: storage.nfsSD.findDomain} vdsm.log.11:Thread-23::INFO::2014-04-30 15:50:00,105::logUtils::47::dispatcher::(wrapper) Run and protect: connectStorageServer, Return response: {'statuslist': [{'status': 0, 'id': '87de82d7-bc85-41ab-9ca7-3b39a75be919'}]} vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:00,106::task::1185::TaskManager.Task::(prepare) Task=`dc6f1b1a-1162-4a3d-865d-d9ad9c3603f8`::finished: {'statuslist': [{'status': 0, 'id': '87de82d7-bc85-41ab-9ca7-3b39a75be919'}]} vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:00,106::task::595::TaskManager.Task::(_updateState) Task=`dc6f1b1a-1162-4a3d-865d-d9ad9c3603f8`::moving from state preparing -> state finished vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:00,106::resourceManager::940::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:00,106::resourceManager::977::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:00,107::task::990::TaskManager.Task::(_decref) Task=`dc6f1b1a-1162-4a3d-865d-d9ad9c3603f8`::ref 0 aborting False vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:05,841::task::595::TaskManager.Task::(_updateState) Task=`885311ca-275f-4bdc-9cab-88e91a8ac7c2`::moving from state init -> state preparing vdsm.log.11:Thread-23::INFO::2014-04-30 15:50:05,841::logUtils::44::dispatcher::(wrapper) Run and protect: repoStats(options=None) vdsm.log.11:Thread-23::INFO::2014-04-30 15:50:05,842::logUtils::47::dispatcher::(wrapper) Run and protect: repoStats, Return response: {} vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:05,842::task::1185::TaskManager.Task::(prepare) Task=`885311ca-275f-4bdc-9cab-88e91a8ac7c2`::finished: {} vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:05,842::task::595::TaskManager.Task::(_updateState) Task=`885311ca-275f-4bdc-9cab-88e91a8ac7c2`::moving from state preparing -> state finished vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:05,842::resourceManager::940::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:05,842::resourceManager::977::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:05,843::task::990::TaskManager.Task::(_decref) Task=`885311ca-275f-4bdc-9cab-88e91a8ac7c2`::ref 0 aborting False vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,149::BindingXMLRPC::251::vds::(wrapper) client [192.168.1.44] vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,150::task::595::TaskManager.Task::(_updateState) Task=`e4c461f3-6608-43a1-9a48-5a771ac7989c`::moving from state init -> state preparing vdsm.log.11:Thread-23::INFO::2014-04-30 15:50:07,150::logUtils::44::dispatcher::(wrapper) Run and protect: getSpmStatus(spUUID='00000002-0002-0002-0002-0000000000ec', options=None) vdsm.log.11:Thread-23::ERROR::2014-04-30 15:50:07,150::task::866::TaskManager.Task::(_setError) Task=`e4c461f3-6608-43a1-9a48-5a771ac7989c`::Unexpected error vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,158::task::885::TaskManager.Task::(_run) Task=`e4c461f3-6608-43a1-9a48-5a771ac7989c`::Task._run: e4c461f3-6608-43a1-9a48-5a771ac7989c ('00000002-0002-0002-0002-0000000000ec',) {} failed - stopping task vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,158::task::1211::TaskManager.Task::(stop) Task=`e4c461f3-6608-43a1-9a48-5a771ac7989c`::stopping in state preparing (force False) vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,159::task::990::TaskManager.Task::(_decref) Task=`e4c461f3-6608-43a1-9a48-5a771ac7989c`::ref 1 aborting True vdsm.log.11:Thread-23::INFO::2014-04-30 15:50:07,159::task::1168::TaskManager.Task::(prepare) Task=`e4c461f3-6608-43a1-9a48-5a771ac7989c`::aborting: Task is aborted: 'Unknown pool id, pool not connected' - code 309 vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,159::task::1173::TaskManager.Task::(prepare) Task=`e4c461f3-6608-43a1-9a48-5a771ac7989c`::Prepare: aborted: Unknown pool id, pool not connected vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,159::task::990::TaskManager.Task::(_decref) Task=`e4c461f3-6608-43a1-9a48-5a771ac7989c`::ref 0 aborting True vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,159::task::925::TaskManager.Task::(_doAbort) Task=`e4c461f3-6608-43a1-9a48-5a771ac7989c`::Task._doAbort: force False vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,160::resourceManager::977::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,160::task::595::TaskManager.Task::(_updateState) Task=`e4c461f3-6608-43a1-9a48-5a771ac7989c`::moving from state preparing -> state aborting vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,160::task::550::TaskManager.Task::(__state_aborting) Task=`e4c461f3-6608-43a1-9a48-5a771ac7989c`::_aborting: recover policy none vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,160::task::595::TaskManager.Task::(_updateState) Task=`e4c461f3-6608-43a1-9a48-5a771ac7989c`::moving from state aborting -> state failed vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,160::resourceManager::940::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,160::resourceManager::977::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} vdsm.log.11:Thread-23::ERROR::2014-04-30 15:50:07,161::dispatcher::65::Storage.Dispatcher.Protect::(run) {'status': {'message': "Unknown pool id, pool not connected: ('00000002-0002-0002-0002-0000000000ec',)", 'code': 309}} vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,177::BindingXMLRPC::251::vds::(wrapper) client [192.168.1.44] vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,177::task::595::TaskManager.Task::(_updateState) Task=`ec07873a-5498-42ff-9403-3ad83f4b08c0`::moving from state init -> state preparing vdsm.log.11:Thread-23::INFO::2014-04-30 15:50:07,177::logUtils::44::dispatcher::(wrapper) Run and protect: getAllTasksStatuses(spUUID=None, options=None) vdsm.log.11:Thread-23::ERROR::2014-04-30 15:50:07,178::task::866::TaskManager.Task::(_setError) Task=`ec07873a-5498-42ff-9403-3ad83f4b08c0`::Unexpected error vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,178::task::885::TaskManager.Task::(_run) Task=`ec07873a-5498-42ff-9403-3ad83f4b08c0`::Task._run: ec07873a-5498-42ff-9403-3ad83f4b08c0 () {} failed - stopping task vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,178::task::1211::TaskManager.Task::(stop) Task=`ec07873a-5498-42ff-9403-3ad83f4b08c0`::stopping in state preparing (force False) vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,178::task::990::TaskManager.Task::(_decref) Task=`ec07873a-5498-42ff-9403-3ad83f4b08c0`::ref 1 aborting True vdsm.log.11:Thread-23::INFO::2014-04-30 15:50:07,178::task::1168::TaskManager.Task::(prepare) Task=`ec07873a-5498-42ff-9403-3ad83f4b08c0`::aborting: Task is aborted: 'Not SPM' - code 654 vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,179::task::1173::TaskManager.Task::(prepare) Task=`ec07873a-5498-42ff-9403-3ad83f4b08c0`::Prepare: aborted: Not SPM vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,179::task::990::TaskManager.Task::(_decref) Task=`ec07873a-5498-42ff-9403-3ad83f4b08c0`::ref 0 aborting True vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,179::task::925::TaskManager.Task::(_doAbort) Task=`ec07873a-5498-42ff-9403-3ad83f4b08c0`::Task._doAbort: force False vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,179::resourceManager::977::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,179::task::595::TaskManager.Task::(_updateState) Task=`ec07873a-5498-42ff-9403-3ad83f4b08c0`::moving from state preparing -> state aborting vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,180::task::550::TaskManager.Task::(__state_aborting) Task=`ec07873a-5498-42ff-9403-3ad83f4b08c0`::_aborting: recover policy none vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,180::task::595::TaskManager.Task::(_updateState) Task=`ec07873a-5498-42ff-9403-3ad83f4b08c0`::moving from state aborting -> state failed vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,180::resourceManager::940::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,180::resourceManager::977::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} vdsm.log.11:Thread-23::ERROR::2014-04-30 15:50:07,180::dispatcher::65::Storage.Dispatcher.Protect::(run) {'status': {'message': 'Not SPM: ()', 'code': 654}} vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,244::BindingXMLRPC::251::vds::(wrapper) client [192.168.1.44] vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,244::task::595::TaskManager.Task::(_updateState) Task=`e4168665-b47d-45f9-8901-727761acbefb`::moving from state init -> state preparing vdsm.log.11:Thread-23::INFO::2014-04-30 15:50:07,245::logUtils::44::dispatcher::(wrapper) Run and protect: getSpmStatus(spUUID='00000002-0002-0002-0002-0000000000ec', options=None) vdsm.log.11:Thread-23::ERROR::2014-04-30 15:50:07,245::task::866::TaskManager.Task::(_setError) Task=`e4168665-b47d-45f9-8901-727761acbefb`::Unexpected error vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,245::task::885::TaskManager.Task::(_run) Task=`e4168665-b47d-45f9-8901-727761acbefb`::Task._run: e4168665-b47d-45f9-8901-727761acbefb ('00000002-0002-0002-0002-0000000000ec',) {} failed - stopping task vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,246::task::1211::TaskManager.Task::(stop) Task=`e4168665-b47d-45f9-8901-727761acbefb`::stopping in state preparing (force False) vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,246::task::990::TaskManager.Task::(_decref) Task=`e4168665-b47d-45f9-8901-727761acbefb`::ref 1 aborting True vdsm.log.11:Thread-23::INFO::2014-04-30 15:50:07,246::task::1168::TaskManager.Task::(prepare) Task=`e4168665-b47d-45f9-8901-727761acbefb`::aborting: Task is aborted: 'Unknown pool id, pool not connected' - code 309 vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,246::task::1173::TaskManager.Task::(prepare) Task=`e4168665-b47d-45f9-8901-727761acbefb`::Prepare: aborted: Unknown pool id, pool not connected vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,246::task::990::TaskManager.Task::(_decref) Task=`e4168665-b47d-45f9-8901-727761acbefb`::ref 0 aborting True vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,246::task::925::TaskManager.Task::(_doAbort) Task=`e4168665-b47d-45f9-8901-727761acbefb`::Task._doAbort: force False vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,247::resourceManager::977::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,247::task::595::TaskManager.Task::(_updateState) Task=`e4168665-b47d-45f9-8901-727761acbefb`::moving from state preparing -> state aborting vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,247::task::550::TaskManager.Task::(__state_aborting) Task=`e4168665-b47d-45f9-8901-727761acbefb`::_aborting: recover policy none vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,247::task::595::TaskManager.Task::(_updateState) Task=`e4168665-b47d-45f9-8901-727761acbefb`::moving from state aborting -> state failed vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,247::resourceManager::940::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {} vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,247::resourceManager::977::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {} vdsm.log.11:Thread-23::ERROR::2014-04-30 15:50:07,248::dispatcher::65::Storage.Dispatcher.Protect::(run) {'status': {'message': "Unknown pool id, pool not connected: ('00000002-0002-0002-0002-0000000000ec',)", 'code': 309}} vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,311::BindingXMLRPC::251::vds::(wrapper) client [192.168.1.44] vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,312::task::595::TaskManager.Task::(_updateState) Task=`b9440814-a49e-446f-bfee-05f3bb3f73fd`::moving from state init -> state preparing vdsm.log.11:Thread-23::INFO::2014-04-30 15:50:07,312::logUtils::44::dispatcher::(wrapper) Run and protect: connectStoragePool(spUUID='00000002-0002-0002-0002-0000000000ec', hostID=1, msdUUID='6bee0e2d-961c-453d-a266-e4623f91e162', masterVersion=1, domainsMap=None, options=None) vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,313::resourceManager::198::ResourceManager.Request::(__init__) ResName=`Storage.HsmDomainMonitorLock`ReqID=`bc44804a-eafd-4c6d-9362-4d1b58dbc332`::Request was made in '/usr/share/vdsm/storage/hsm.py' line '1007' at 'connectStoragePool' vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,313::resourceManager::542::ResourceManager::(registerResource) Trying to register resource 'Storage.HsmDomainMonitorLock' for lock type 'exclusive' vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,313::resourceManager::601::ResourceManager::(registerResource) Resource 'Storage.HsmDomainMonitorLock' is free. Now locking as 'exclusive' (1 active user) vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,313::resourceManager::238::ResourceManager.Request::(grant) ResName=`Storage.HsmDomainMonitorLock`ReqID=`bc44804a-eafd-4c6d-9362-4d1b58dbc332`::Granted request vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,314::resourceManager::198::ResourceManager.Request::(__init__) ResName=`Storage.00000002-0002-0002-0002-0000000000ec`ReqID=`92d7be18-2aaf-402d-a185-c36818ee5aa4`::Request was made in '/usr/share/vdsm/storage/hsm.py' line '1055' at '_connectStoragePool' vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,314::resourceManager::542::ResourceManager::(registerResource) Trying to register resource 'Storage.00000002-0002-0002-0002-0000000000ec' for lock type 'exclusive' pe 'exclusive' vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,314::resourceManager::601::ResourceManager::(registerResource) Resource 'Storage.00000002-0002-0002-0002-0000000000ec' is free. Now locking as 'exclusive' (1 active user) vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,315::resourceManager::238::ResourceManager.Request::(grant) ResName=`Storage.00000002-0002-0002-0002-0000000000ec`ReqID=`92d7be18-2aaf-402d-a185-c36818ee5aa4`::Granted request vdsm.log.11:Thread-23::INFO::2014-04-30 15:50:07,316::sp::133::Storage.StoragePool::(setBackend) updating pool 00000002-0002-0002-0002-0000000000ec backend from type NoneType instance 0x3cd1372210 to type StoragePoolDiskBackend instance 0x7f84e8062fc8 vdsm.log.11:Thread-23::INFO::2014-04-30 15:50:07,316::sp::618::Storage.StoragePool::(connect) Connect host #1 to the storage pool 00000002-0002-0002-0002-0000000000ec with master domain: 6bee0e2d-961c-453d-a266-e4623f91e162 (ver = 1) vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,317::lvm::496::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' got the operation mutex vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,317::lvm::498::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' released the operation mutex vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,317::lvm::507::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' got the operation mutex vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,317::lvm::509::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' released the operation mutex vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,318::lvm::527::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' got the operation mutex vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,318::lvm::529::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' released the operation mutex vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,318::misc::762::SamplingMethod::(__call__) Trying to enter sampling method (storage.sdc.refreshStorage) vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,318::misc::764::SamplingMethod::(__call__) Got in to sampling method vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,318::misc::762::SamplingMethod::(__call__) Trying to enter sampling method (storage.iscsi.rescan) vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,318::misc::764::SamplingMethod::(__call__) Got in to sampling method vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,319::iscsi::393::Storage.ISCSI::(rescan) Performing SCSI scan, this will take up to 30 seconds vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,319::iscsiadm::92::Storage.Misc.excCmd::(_runCmd) '/usr/bin/sudo -n /sbin/iscsiadm -m session -R' (cwd None) vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,343::misc::772::SamplingMethod::(__call__) Returning last result vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,343::multipath::110::Storage.Misc.excCmd::(rescan) '/usr/bin/sudo -n /sbin/multipath -r' (cwd None) vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,364::multipath::110::Storage.Misc.excCmd::(rescan) SUCCESS: <err> = ''; <rc> = 0 vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,365::lvm::496::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' got the operation mutex vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,365::lvm::498::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' released the operation mutex vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,366::lvm::507::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' got the operation mutex vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,366::lvm::509::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' released the operation mutex vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,366::lvm::527::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' got the operation mutex vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,367::lvm::529::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' released the operation mutex vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,367::misc::772::SamplingMethod::(__call__) Returning last result vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,383::fileSD::140::Storage.StorageDomain::(__init__) Reading domain in path /rhev/data-center/mnt/192.168.1.44:_raid_ovirt_data/6bee0e2d-961c-453d-a266-e4623f91e162 vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,384::persistentDict::192::Storage.PersistentDict::(__init__) Created a persistent dict with FileMetadataRW backend vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,392::persistentDict::234::Storage.PersistentDict::(refresh) read lines (FileMetadataRW)=[] vdsm.log.11:Thread-23::WARNING::2014-04-30 15:50:07,392::persistentDict::256::Storage.PersistentDict::(refresh) data has no embedded checksum - trust it as it is vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,393::resourceManager::616::ResourceManager::(releaseResource) Trying to release resource 'Storage.00000002-0002-0002-0002-0000000000ec' vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,393::resourceManager::635::ResourceManager::(releaseResource) Released resource 'Storage.00000002-0002-0002-0002-0000000000ec' (0 active users) vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,393::resourceManager::641::ResourceManager::(releaseResource) Resource 'Storage.00000002-0002-0002-0002-0000000000ec' is free, finding out if anyone is waiting for it. vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,393::resourceManager::649::ResourceManager::(releaseResource) No one is waiting for resource 'Storage.00000002-0002-0002-0002-0000000000ec', Clearing records. vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,394::resourceManager::616::ResourceManager::(releaseResource) Trying to release resource 'Storage.HsmDomainMonitorLock' vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,394::resourceManager::635::ResourceManager::(releaseResource) Released resource 'Storage.HsmDomainMonitorLock' (0 active users) vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,394::resourceManager::641::ResourceManager::(releaseResource) Resource 'Storage.HsmDomainMonitorLock' is free, finding out if anyone is waiting for it. vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,395::resourceManager::649::ResourceManager::(releaseResource) No one is waiting for resource 'Storage.HsmDomainMonitorLock', Clearing records. vdsm.log.11:Thread-23::ERROR::2014-04-30 15:50:07,395::task::866::TaskManager.Task::(_setError) Task=`b9440814-a49e-446f-bfee-05f3bb3f73fd`::Unexpected error vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,396::task::885::TaskManager.Task::(_run) Task=`b9440814-a49e-446f-bfee-05f3bb3f73fd`::Task._run: b9440814-a49e-446f-bfee-05f3bb3f73fd ('00000002-0002-0002-0002-0000000000ec', 1, '6bee0e2d-961c-453d-a266-e4623f91e162', 1, None) {} failed - stopping task vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,396::task::1211::TaskManager.Task::(stop) Task=`b9440814-a49e-446f-bfee-05f3bb3f73fd`::stopping in state preparing (force False) vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,396::task::990::TaskManager.Task::(_decref) Task=`b9440814-a49e-446f-bfee-05f3bb3f73fd`::ref 1 aborting True vdsm.log.11:Thread-23::INFO::2014-04-30 15:50:07,397::task::1168::TaskManager.Task::(prepare) Task=`b9440814-a49e-446f-bfee-05f3bb3f73fd`::aborting: Task is aborted: u"'VERSION'" - code 100 vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,397::task::1173::TaskManager.Task::(prepare) Task=`b9440814-a49e-446f-bfee-05f3bb3f73fd`::Prepare: aborted: 'VERSION' vdsm.log.11:Thread-23::DEBUG::2014-04-30 15:50:07,397::task::990::TaskManager.Task::(_decref) Task=`b9440814-a49e-446f-bfee-05f3bb3f73fd`::ref 0 aborting True

vdsm.log.11:Thread-23::ERROR::2014-04-30 15:50:07,150::task::866::TaskManager.Task::(_setError) Task=`e4c461f3-6608-43a1-9a48-5a771ac7989c`::Unexpected error vdsm.log.11:Thread-23::ERROR::2014-04-30 15:50:07,161::dispatcher::65::Storage.Dispatcher.Protect::(run) {'status': {'message': "Unknown pool id, pool not connected: ('00000002-0002-0002-0002-0000000000ec',)", 'code': 309}} vdsm.log.11:Thread-23::ERROR::2014-04-30 15:50:07,178::task::866::TaskManager.Task::(_setError) Task=`ec07873a-5498-42ff-9403-3ad83f4b08c0`::Unexpected error vdsm.log.11:Thread-23::ERROR::2014-04-30 15:50:07,180::dispatcher::65::Storage.Dispatcher.Protect::(run) {'status': {'message': 'Not SPM: ()', 'code': 654}} vdsm.log.11:Thread-23::ERROR::2014-04-30 15:50:07,245::task::866::TaskManager.Task::(_setError) Task=`e4168665-b47d-45f9-8901-727761acbefb`::Unexpected error vdsm.log.11:Thread-23::ERROR::2014-04-30 15:50:07,248::dispatcher::65::Storage.Dispatcher.Protect::(run) {'status': {'message': "Unknown pool id, pool not connected: ('00000002-0002-0002-0002-0000000000ec',)", 'code': 309}} vdsm.log.11:Thread-23::WARNING::2014-04-30 15:50:07,392::persistentDict::256::Storage.PersistentDict::(refresh) data has no embedded checksum - trust it as it is vdsm.log.11:Thread-23::ERROR::2014-04-30 15:50:07,395::task::866::TaskManager.Task::(_setError) Task=`b9440814-a49e-446f-bfee-05f3bb3f73fd`::Unexpected error vdsm.log.11:Thread-23::ERROR::2014-04-30 15:50:07,399::dispatcher::68::Storage.Dispatcher.Protect::(run) 'VERSION' vdsm.log.11:Thread-23::ERROR::2014-04-30 15:50:17,462::task::866::TaskManager.Task::(_setError) Task=`c107a3de-819b-44c5-8739-f31ea6cc3b91`::Unexpected error vdsm.log.11:Thread-23::ERROR::2014-04-30 15:50:17,465::dispatcher::65::Storage.Dispatcher.Protect::(run) {'status': {'message': "Unknown pool id, pool not connected: ('00000002-0002-0002-0002-0000000000ec',)", 'code': 309}} vdsm.log.11:Thread-23::ERROR::2014-04-30 15:50:17,493::task::866::TaskManager.Task::(_setError) Task=`df7f16b1-72fe-43e9-ab76-7b59a694819e`::Unexpected error vdsm.log.11:Thread-23::ERROR::2014-04-30 15:50:17,496::dispatcher::65::Storage.Dispatcher.Protect::(run) {'status': {'message': 'Not SPM: ()', 'code': 654}} vdsm.log.11:Thread-23::ERROR::2014-04-30 15:50:17,558::task::866::TaskManager.Task::(_setError) Task=`68c69145-33b5-4fcb-8c91-47b27edf2d98`::Unexpected error vdsm.log.11:Thread-23::ERROR::2014-04-30 15:50:17,561::dispatcher::65::Storage.Dispatcher.Protect::(run) {'status': {'message': "Unknown pool id, pool not connected: ('00000002-0002-0002-0002-0000000000ec',)", 'code': 309}} vdsm.log.11:Thread-23::WARNING::2014-04-30 15:50:17,694::persistentDict::256::Storage.PersistentDict::(refresh) data has no embedded checksum - trust it as it is vdsm.log.11:Thread-23::ERROR::2014-04-30 15:50:17,697::task::866::TaskManager.Task::(_setError) Task=`f807fd52-5495-4633-8615-b0923ff16e1d`::Unexpected error vdsm.log.11:Thread-23::ERROR::2014-04-30 15:50:17,701::dispatcher::68::Storage.Dispatcher.Protect::(run) 'VERSION' vdsm.log.11:Thread-23::ERROR::2014-04-30 15:50:27,765::task::866::TaskManager.Task::(_setError) Task=`5a0268e4-58e4-4e5f-a87a-89da345d373e`::Unexpected error vdsm.log.11:Thread-23::ERROR::2014-04-30 15:50:27,768::dispatcher::65::Storage.Dispatcher.Protect::(run) {'status': {'message': "Unknown pool id, pool not connected: ('00000002-0002-0002-0002-0000000000ec',)", 'code': 309}} vdsm.log.11:Thread-23::ERROR::2014-04-30 15:50:27,786::task::866::TaskManager.Task::(_setError) Task=`7e2d100d-3670-4b91-b861-9fbd43c5b110`::Unexpected error vdsm.log.11:Thread-23::ERROR::2014-04-30 15:50:27,789::dispatcher::65::Storage.Dispatcher.Protect::(run) {'status': {'message': 'Not SPM: ()', 'code': 654}} vdsm.log.11:Thread-23::ERROR::2014-04-30 15:50:27,860::task::866::TaskManager.Task::(_setError) Task=`833a9952-107a-437a-bc93-99849e0e0612`::Unexpected error vdsm.log.11:Thread-23::ERROR::2014-04-30 15:50:27,865::dispatcher::65::Storage.Dispatcher.Protect::(run) {'status': {'message': "Unknown pool id, pool not connected: ('00000002-0002-0002-0002-0000000000ec',)", 'code': 309}} vdsm.log.11:Thread-23::WARNING::2014-04-30 15:50:28,010::persistentDict::256::Storage.PersistentDict::(refresh) data has no embedded checksum - trust it as it is vdsm.log.11:Thread-23::ERROR::2014-04-30 15:50:28,013::task::866::TaskManager.Task::(_setError) Task=`e999e46e-9a5f-43ba-881d-145c38fcb18f`::Unexpected error vdsm.log.11:Thread-23::ERROR::2014-04-30 15:50:28,017::dispatcher::68::Storage.Dispatcher.Protect::(run) 'VERSION' vdsm.log.11:Thread-23::ERROR::2014-04-30 15:50:38,078::task::866::TaskManager.Task::(_setError) Task=`7d632291-beb9-4bec-9d14-ce9b7d240e49`::Unexpected error vdsm.log.11:Thread-23::ERROR::2014-04-30 15:50:38,082::dispatcher::65::Storage.Dispatcher.Protect::(run) {'status': {'message': "Unknown pool id, pool not connected: ('00000002-0002-0002-0002-0000000000ec',)", 'code': 309}} vdsm.log.11:Thread-23::ERROR::2014-04-30 15:50:38,097::task::866::TaskManager.Task::(_setError) Task=`1f7a2469-c5f5-460f-a09e-3ff7f666dfe1`::Unexpected error vdsm.log.11:Thread-23::ERROR::2014-04-30 15:50:38,101::dispatcher::65::Storage.Dispatcher.Protect::(run) {'status': {'message': 'Not SPM: ()', 'code': 654}} vdsm.log.11:Thread-23::ERROR::2014-04-30 15:50:38,163::task::866::TaskManager.Task::(_setError) Task=`a793071a-13e2-4c66-8c63-34501c7becec`::Unexpected error vdsm.log.11:Thread-23::ERROR::2014-04-30 15:50:38,166::dispatcher::65::Storage.Dispatcher.Protect::(run) {'status': {'message': "Unknown pool id, pool not connected: ('00000002-0002-0002-0002-0000000000ec',)", 'code': 309}}