Gadi Ickowicz schreef op 1-5-2014 7:54:
> 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
>
Sure I wasn't even aware of the /var/log/vdsm directory...
> 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
When looking for messages with ERROR or WARNING tags:
> 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}}
>
>
Thank you very much already.
Boudewijn Ector
_______________________________________________
Users mailing list
Users@ovirt.org
http://lists.ovirt.org/mailman/listinfo/users
