Hi,
I have an All-in-one installation engine node and an Ovirt node. They
each use local storage and are thus configured in separate Data
Centres. I upgraded both from 3.3.2 to 3.4 and this completed without
error. I completed the engine-setup upgrade and this complete ok. I
rebooted both the servers and the Ovirt engine node worked fine and I
could start it's VMs. The Ovirt Node's datacenter is not activating,
which seems to be due to none of the storage domains coming online.
I've checked and the storage is mounted and available fine on the Ovirt
node.
Looking at the vdsm.log I can see errors stating that it can't find the
storage domain. I have restored the entire node back to the pre-upgrade
state and it works fine. It breaks again when I upgrade it. The
approach I used was to put the Ovirt node in maintenance mode and run
yum update. Anybody have similar issues or understand the log errors below?
Traceback (most recent call last):
File "/usr/share/vdsm/storage/dispatcher.py", line 60, in run
result = ctask.prepare(self.func, *args, **kwargs)
File "/usr/share/vdsm/storage/task.py", line 103, in wrapper
return m(self, *a, **kw)
File "/usr/share/vdsm/storage/task.py", line 1176, in prepare
raise self.error
SecureError: Secured object is not in safe state
Thread-180::DEBUG::2014-04-25
19:58:17,581::BindingXMLRPC::251::vds::(wrapper) client [10.50.0.18]
flowID [21f7a1a7]
Thread-180::DEBUG::2014-04-25
19:58:17,581::task::595::TaskManager.Task::(_updateState)
Task=`545a6b49-bcd5-4e42-b64c-ee99329d3b7a`::moving from state init ->
state preparing
Thread-180::INFO::2014-04-25
19:58:17,582::logUtils::44::dispatcher::(wrapper) Run and protect:
getSpmStatus(spUUID='c713062f-300f-4256-9ac8-2d3fcfcdb002', options=None)
Thread-180::INFO::2014-04-25
19:58:17,582::logUtils::47::dispatcher::(wrapper) Run and protect:
getSpmStatus, Return response: {'spm_st': {'spmId': -1, 'spmStatus':
'Free', 'spmLver': -1}}
Thread-180::DEBUG::2014-04-25
19:58:17,582::task::1185::TaskManager.Task::(prepare)
Task=`545a6b49-bcd5-4e42-b64c-ee99329d3b7a`::finished: {'spm_st':
{'spmId': -1, 'spmStatus': 'Free', 'spmLver': -1}}
Thread-180::DEBUG::2014-04-25
19:58:17,582::task::595::TaskManager.Task::(_updateState)
Task=`545a6b49-bcd5-4e42-b64c-ee99329d3b7a`::moving from state preparing
-> state finished
Thread-180::DEBUG::2014-04-25
19:58:17,582::resourceManager::940::ResourceManager.Owner::(releaseAll)
Owner.releaseAll requests {} resources {}
Thread-180::DEBUG::2014-04-25
19:58:17,582::resourceManager::977::ResourceManager.Owner::(cancelAll)
Owner.cancelAll requests {}
Thread-180::DEBUG::2014-04-25
19:58:17,582::task::990::TaskManager.Task::(_decref)
Task=`545a6b49-bcd5-4e42-b64c-ee99329d3b7a`::ref 0 aborting False
Thread-180::DEBUG::2014-04-25
19:58:17,732::BindingXMLRPC::251::vds::(wrapper) client [10.50.0.18]
flowID [21f7a1a7]
Thread-180::DEBUG::2014-04-25
19:58:17,733::task::595::TaskManager.Task::(_updateState)
Task=`b9623891-cda5-4ac3-b4ab-efde3cc5ac97`::moving from state init ->
state preparing
Thread-180::INFO::2014-04-25
19:58:17,733::logUtils::44::dispatcher::(wrapper) Run and protect:
spmStart(spUUID='c713062f-300f-4256-9ac8-2d3fcfcdb002', prevID=-1,
prevLVER='-1', maxHostID=250, domVersion='3', options=None)
Thread-180::DEBUG::2014-04-25
19:58:17,733::resourceManager::198::ResourceManager.Request::(__init__)
ResName=`Storage.c713062f-300f-4256-9ac8-2d3fcfcdb002`ReqID=`ce97fd39-373c-4464-9921-2180f0f2e2c5`::Request
was made in '/usr/share/vdsm/storage/hsm.py' line '577' at 'spmStart'
Thread-180::DEBUG::2014-04-25
19:58:17,733::resourceManager::542::ResourceManager::(registerResource)
Trying to register resource
'Storage.c713062f-300f-4256-9ac8-2d3fcfcdb002' for lock type 'exclusive'
Thread-180::DEBUG::2014-04-25
19:58:17,733::resourceManager::601::ResourceManager::(registerResource)
Resource 'Storage.c713062f-300f-4256-9ac8-2d3fcfcdb002' is free. Now
locking as 'exclusive' (1 active user)
Thread-180::DEBUG::2014-04-25
19:58:17,733::resourceManager::238::ResourceManager.Request::(grant)
ResName=`Storage.c713062f-300f-4256-9ac8-2d3fcfcdb002`ReqID=`ce97fd39-373c-4464-9921-2180f0f2e2c5`::Granted
request
Thread-180::DEBUG::2014-04-25
19:58:17,734::task::827::TaskManager.Task::(resourceAcquired)
Task=`b9623891-cda5-4ac3-b4ab-efde3cc5ac97`::_resourcesAcquired:
Storage.c713062f-300f-4256-9ac8-2d3fcfcdb002 (exclusive)
Thread-180::DEBUG::2014-04-25
19:58:17,734::task::990::TaskManager.Task::(_decref)
Task=`b9623891-cda5-4ac3-b4ab-efde3cc5ac97`::ref 1 aborting False
Thread-180::INFO::2014-04-25
19:58:17,734::logUtils::47::dispatcher::(wrapper) Run and protect:
spmStart, Return response: None
Thread-180::DEBUG::2014-04-25
19:58:17,734::task::1180::TaskManager.Task::(prepare)
Task=`b9623891-cda5-4ac3-b4ab-efde3cc5ac97`::Prepare: 1 jobs exist, move
to acquiring
Thread-180::DEBUG::2014-04-25
19:58:17,734::task::595::TaskManager.Task::(_updateState)
Task=`b9623891-cda5-4ac3-b4ab-efde3cc5ac97`::moving from state preparing
-> state acquiring
Thread-180::DEBUG::2014-04-25
19:58:17,734::task::595::TaskManager.Task::(_updateState)
Task=`b9623891-cda5-4ac3-b4ab-efde3cc5ac97`::moving from state acquiring
-> state queued
Thread-180::DEBUG::2014-04-25
19:58:17,734::taskManager::50::TaskManager::(_queueTask) queuing task:
b9623891-cda5-4ac3-b4ab-efde3cc5ac97
Thread-180::DEBUG::2014-04-25
19:58:17,734::taskManager::56::TaskManager::(_queueTask) task queued:
b9623891-cda5-4ac3-b4ab-efde3cc5ac97
Thread-180::DEBUG::2014-04-25
19:58:17,734::task::1182::TaskManager.Task::(prepare)
Task=`b9623891-cda5-4ac3-b4ab-efde3cc5ac97`::returning
Thread-180::DEBUG::2014-04-25
19:58:17,735::task::990::TaskManager.Task::(_decref)
Task=`b9623891-cda5-4ac3-b4ab-efde3cc5ac97`::ref 0 aborting False
Thread-2::DEBUG::2014-04-25
19:58:17,735::threadPool::57::Misc.ThreadPool::(setRunningTask) Number
of running tasks: 1
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,735::threadPool::200::Misc.ThreadPool.WorkerThread::(_processNextTask)
Task: b9623891-cda5-4ac3-b4ab-efde3cc5ac97 running: <bound method
Task.commit of <storage.task.Task instance at 0x7f95a41007e8>> with: None
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,735::task::1194::TaskManager.Task::(commit)
Task=`b9623891-cda5-4ac3-b4ab-efde3cc5ac97`::committing task:
b9623891-cda5-4ac3-b4ab-efde3cc5ac97
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,735::task::595::TaskManager.Task::(_updateState)
Task=`b9623891-cda5-4ac3-b4ab-efde3cc5ac97`::moving from state queued ->
state running
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,736::task::905::TaskManager.Task::(_runJobs)
Task=`b9623891-cda5-4ac3-b4ab-efde3cc5ac97`::Task.run: running job 0:
spmStart: <bound method StoragePool.startSpm of <storage.sp.StoragePool
object at 0x7f95a4195cd0>> (args: (-1, '-1', 250, 3) kwargs: {})
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,736::task::331::TaskManager.Task::(run)
Task=`b9623891-cda5-4ac3-b4ab-efde3cc5ac97`::Job.run: running spmStart:
<bound method StoragePool.startSpm of <storage.sp.StoragePool object at
0x7f95a4195cd0>> (args: (-1, '-1', 250, 3) kwargs: {}) callback None
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,736::misc::762::SamplingMethod::(__call__) Trying to enter
sampling method (storage.sp.updateMonitoringThreads)
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,736::misc::764::SamplingMethod::(__call__) Got in to sampling
method
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,746::persistentDict::234::Storage.PersistentDict::(refresh)
read lines (FileMetadataRW)=['CLASS=Data',
'DESCRIPTION=s2data1_s2mgt_boot1', 'IOOPTIMEOUTSEC=10',
'LEASERETRIES=3', 'LEASETIMESEC=60', 'LOCKPOLICY=',
'LOCKRENEWALINTERVALSEC=5', 'MASTER_VERSION=1',
'POOL_DESCRIPTION=BDS_DataCentre2',
'POOL_DOMAINS=7b083758-45f9-4896-913d-11fe02043e6e:Active,e637bb04-a8b7-4c77-809c-d58051494c52:Active,0a897f2e-1b01-4577-9f91-cd136ef4a978:Active,c2c4ade6-049e-4159-a294-a0c151f4983d:Active,9a4a80a1-5377-4a94-ade3-e58183e916ae:Active',
'POOL_SPM_ID=-1', 'POOL_SPM_LVER=0',
'POOL_UUID=c713062f-300f-4256-9ac8-2d3fcfcdb002',
'REMOTE_PATH=/vdsm_store/s2data1_s2mgt_boot1', 'ROLE=Master',
'SDUUID=0a897f2e-1b01-4577-9f91-cd136ef4a978', 'TYPE=LOCALFS',
'VERSION=3', '_SHA_CKSUM=afe618d7596d75d0fb96453bcdd34a1255534454']
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,746::misc::772::SamplingMethod::(__call__) Returning last result
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,746::clusterlock::337::LocalLock::(acquireHostId) Host id for
domain 0a897f2e-1b01-4577-9f91-cd136ef4a978 successfully acquired (id: 1)
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::INFO::2014-04-25
19:58:17,746::clusterlock::365::LocalLock::(acquire) Acquiring local
lock for domain 0a897f2e-1b01-4577-9f91-cd136ef4a978 (id: 1)
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,746::clusterlock::400::LocalLock::(acquire) Local lock for
domain 0a897f2e-1b01-4577-9f91-cd136ef4a978 successfully acquired (id: 1)
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,746::sp::266::Storage.StoragePool::(startSpm) spm lock acquired
successfully
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,756::persistentDict::234::Storage.PersistentDict::(refresh)
read lines (FileMetadataRW)=['CLASS=Data',
'DESCRIPTION=s2data1_s2mgt_boot1', 'IOOPTIMEOUTSEC=10',
'LEASERETRIES=3', 'LEASETIMESEC=60', 'LOCKPOLICY=',
'LOCKRENEWALINTERVALSEC=5', 'MASTER_VERSION=1',
'POOL_DESCRIPTION=BDS_DataCentre2',
'POOL_DOMAINS=7b083758-45f9-4896-913d-11fe02043e6e:Active,e637bb04-a8b7-4c77-809c-d58051494c52:Active,0a897f2e-1b01-4577-9f91-cd136ef4a978:Active,c2c4ade6-049e-4159-a294-a0c151f4983d:Active,9a4a80a1-5377-4a94-ade3-e58183e916ae:Active',
'POOL_SPM_ID=-1', 'POOL_SPM_LVER=0',
'POOL_UUID=c713062f-300f-4256-9ac8-2d3fcfcdb002',
'REMOTE_PATH=/vdsm_store/s2data1_s2mgt_boot1', 'ROLE=Master',
'SDUUID=0a897f2e-1b01-4577-9f91-cd136ef4a978', 'TYPE=LOCALFS',
'VERSION=3', '_SHA_CKSUM=afe618d7596d75d0fb96453bcdd34a1255534454']
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,756::persistentDict::167::Storage.PersistentDict::(transaction)
Starting transaction
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,756::persistentDict::173::Storage.PersistentDict::(transaction)
Flushing changes
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,756::persistentDict::299::Storage.PersistentDict::(flush) about
to write lines (FileMetadataRW)=['CLASS=Data',
'DESCRIPTION=s2data1_s2mgt_boot1', 'IOOPTIMEOUTSEC=10',
'LEASERETRIES=3', 'LEASETIMESEC=60', 'LOCKPOLICY=',
'LOCKRENEWALINTERVALSEC=5', 'MASTER_VERSION=1',
'POOL_DESCRIPTION=BDS_DataCentre2',
'POOL_DOMAINS=7b083758-45f9-4896-913d-11fe02043e6e:Active,e637bb04-a8b7-4c77-809c-d58051494c52:Active,0a897f2e-1b01-4577-9f91-cd136ef4a978:Active,c2c4ade6-049e-4159-a294-a0c151f4983d:Active,9a4a80a1-5377-4a94-ade3-e58183e916ae:Active',
'POOL_SPM_ID=1', 'POOL_SPM_LVER=0',
'POOL_UUID=c713062f-300f-4256-9ac8-2d3fcfcdb002',
'REMOTE_PATH=/vdsm_store/s2data1_s2mgt_boot1', 'ROLE=Master',
'SDUUID=0a897f2e-1b01-4577-9f91-cd136ef4a978', 'TYPE=LOCALFS',
'VERSION=3', '_SHA_CKSUM=68a337432f9f1794a057deb08eb27f6bb3513470']
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,757::persistentDict::175::Storage.PersistentDict::(transaction)
Finished transaction
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,757::resourceManager::198::ResourceManager.Request::(__init__)
ResName=`Storage.upgrade_c713062f-300f-4256-9ac8-2d3fcfcdb002`ReqID=`479828cf-c60b-465a-96f8-edc76af93804`::Request
was made in '/usr/share/vdsm/storage/sp.py' line '425' at '_upgradePool'
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,757::resourceManager::542::ResourceManager::(registerResource)
Trying to register resource
'Storage.upgrade_c713062f-300f-4256-9ac8-2d3fcfcdb002' for lock type
'exclusive'
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,757::resourceManager::601::ResourceManager::(registerResource)
Resource 'Storage.upgrade_c713062f-300f-4256-9ac8-2d3fcfcdb002' is free.
Now locking as 'exclusive' (1 active user)
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,758::resourceManager::238::ResourceManager.Request::(grant)
ResName=`Storage.upgrade_c713062f-300f-4256-9ac8-2d3fcfcdb002`ReqID=`479828cf-c60b-465a-96f8-edc76af93804`::Granted
request
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::INFO::2014-04-25
19:58:17,758::sp::431::Storage.StoragePool::(_upgradePool) Trying to
upgrade master domain `0a897f2e-1b01-4577-9f91-cd136ef4a978`
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,759::resourceManager::198::ResourceManager.Request::(__init__)
ResName=`Storage.0a897f2e-1b01-4577-9f91-cd136ef4a978`ReqID=`cb5a1648-5020-4509-9d9e-60db98cf7c75`::Request
was made in '/usr/share/vdsm/storage/sp.py' line '433' at '_upgradePool'
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,759::resourceManager::542::ResourceManager::(registerResource)
Trying to register resource
'Storage.0a897f2e-1b01-4577-9f91-cd136ef4a978' for lock type 'exclusive'
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,759::resourceManager::601::ResourceManager::(registerResource)
Resource 'Storage.0a897f2e-1b01-4577-9f91-cd136ef4a978' is free. Now
locking as 'exclusive' (1 active user)
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,759::resourceManager::238::ResourceManager.Request::(grant)
ResName=`Storage.0a897f2e-1b01-4577-9f91-cd136ef4a978`ReqID=`cb5a1648-5020-4509-9d9e-60db98cf7c75`::Granted
request
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,761::fileSD::140::Storage.StorageDomain::(__init__) Reading
domain in path
/rhev/data-center/mnt/_vdsm__store_s2data1__s2mgt__boot1/0a897f2e-1b01-4577-9f91-cd136ef4a978
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,761::persistentDict::192::Storage.PersistentDict::(__init__)
Created a persistent dict with FileMetadataRW backend
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,770::persistentDict::234::Storage.PersistentDict::(refresh)
read lines (FileMetadataRW)=['CLASS=Data',
'DESCRIPTION=s2data1_s2mgt_boot1', 'IOOPTIMEOUTSEC=10',
'LEASERETRIES=3', 'LEASETIMESEC=60', 'LOCKPOLICY=',
'LOCKRENEWALINTERVALSEC=5', 'MASTER_VERSION=1',
'POOL_DESCRIPTION=BDS_DataCentre2',
'POOL_DOMAINS=7b083758-45f9-4896-913d-11fe02043e6e:Active,e637bb04-a8b7-4c77-809c-d58051494c52:Active,0a897f2e-1b01-4577-9f91-cd136ef4a978:Active,c2c4ade6-049e-4159-a294-a0c151f4983d:Active,9a4a80a1-5377-4a94-ade3-e58183e916ae:Active',
'POOL_SPM_ID=1', 'POOL_SPM_LVER=0',
'POOL_UUID=c713062f-300f-4256-9ac8-2d3fcfcdb002',
'REMOTE_PATH=/vdsm_store/s2data1_s2mgt_boot1', 'ROLE=Master',
'SDUUID=0a897f2e-1b01-4577-9f91-cd136ef4a978', 'TYPE=LOCALFS',
'VERSION=3', '_SHA_CKSUM=68a337432f9f1794a057deb08eb27f6bb3513470']
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,771::fileSD::575::Storage.StorageDomain::(imageGarbageCollector) Removing
remnants of deleted images []
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::INFO::2014-04-25
19:58:17,771::sd::374::Storage.StorageDomain::(_registerResourceNamespaces)
Resource namespace 0a897f2e-1b01-4577-9f91-cd136ef4a978_imageNS already
registered
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::INFO::2014-04-25
19:58:17,771::sd::382::Storage.StorageDomain::(_registerResourceNamespaces)
Resource namespace 0a897f2e-1b01-4577-9f91-cd136ef4a978_volumeNS already
registered
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,772::resourceManager::616::ResourceManager::(releaseResource)
Trying to release resource 'Storage.0a897f2e-1b01-4577-9f91-cd136ef4a978'
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,772::resourceManager::635::ResourceManager::(releaseResource)
Released resource 'Storage.0a897f2e-1b01-4577-9f91-cd136ef4a978' (0
active users)
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,772::resourceManager::641::ResourceManager::(releaseResource)
Resource 'Storage.0a897f2e-1b01-4577-9f91-cd136ef4a978' is free, finding
out if anyone is waiting for it.
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,772::resourceManager::649::ResourceManager::(releaseResource)
No one is waiting for resource
'Storage.0a897f2e-1b01-4577-9f91-cd136ef4a978', Clearing records.
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,772::sp::436::Storage.StoragePool::(_upgradePool) Marking all
domains for upgrade
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,781::persistentDict::234::Storage.PersistentDict::(refresh)
read lines (FileMetadataRW)=['CLASS=Data',
'DESCRIPTION=s2data1_s2mgt_boot1', 'IOOPTIMEOUTSEC=10',
'LEASERETRIES=3', 'LEASETIMESEC=60', 'LOCKPOLICY=',
'LOCKRENEWALINTERVALSEC=5', 'MASTER_VERSION=1',
'POOL_DESCRIPTION=BDS_DataCentre2',
'POOL_DOMAINS=7b083758-45f9-4896-913d-11fe02043e6e:Active,e637bb04-a8b7-4c77-809c-d58051494c52:Active,0a897f2e-1b01-4577-9f91-cd136ef4a978:Active,c2c4ade6-049e-4159-a294-a0c151f4983d:Active,9a4a80a1-5377-4a94-ade3-e58183e916ae:Active',
'POOL_SPM_ID=1', 'POOL_SPM_LVER=0',
'POOL_UUID=c713062f-300f-4256-9ac8-2d3fcfcdb002',
'REMOTE_PATH=/vdsm_store/s2data1_s2mgt_boot1', 'ROLE=Master',
'SDUUID=0a897f2e-1b01-4577-9f91-cd136ef4a978', 'TYPE=LOCALFS',
'VERSION=3', '_SHA_CKSUM=68a337432f9f1794a057deb08eb27f6bb3513470']
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,782::sp::443::Storage.StoragePool::(_upgradePool) Registering
with state change event
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,782::sp::446::Storage.StoragePool::(_upgradePool) Running
initial domain upgrade threads
Thread-857::DEBUG::2014-04-25
19:58:17,782::sp::152::Storage.StoragePool::(_upgradePoolDomain)
Preparing to upgrade domain 7b083758-45f9-4896-913d-11fe02043e6e
Thread-858::DEBUG::2014-04-25
19:58:17,782::sp::152::Storage.StoragePool::(_upgradePoolDomain)
Preparing to upgrade domain e637bb04-a8b7-4c77-809c-d58051494c52
Thread-857::DEBUG::2014-04-25
19:58:17,782::resourceManager::198::ResourceManager.Request::(__init__)
ResName=`Storage.upgrade_7b083758-45f9-4896-913d-11fe02043e6e`ReqID=`c50b5f1d-d9fd-4317-bc98-4d40fad3e553`::Request
was made in '/usr/share/vdsm/storage/sp.py' line '163' at
'_upgradePoolDomain'
Thread-858::DEBUG::2014-04-25
19:58:17,783::resourceManager::198::ResourceManager.Request::(__init__)
ResName=`Storage.upgrade_e637bb04-a8b7-4c77-809c-d58051494c52`ReqID=`89314c30-0d9e-4b1d-b5f9-1ab61127274d`::Request
was made in '/usr/share/vdsm/storage/sp.py' line '163' at
'_upgradePoolDomain'
Thread-859::DEBUG::2014-04-25
19:58:17,783::sp::152::Storage.StoragePool::(_upgradePoolDomain)
Preparing to upgrade domain c2c4ade6-049e-4159-a294-a0c151f4983d
Thread-857::DEBUG::2014-04-25
19:58:17,783::resourceManager::542::ResourceManager::(registerResource)
Trying to register resource
'Storage.upgrade_7b083758-45f9-4896-913d-11fe02043e6e' for lock type
'exclusive'
Thread-860::ERROR::2014-04-25
19:58:17,783::sdc::137::Storage.StorageDomainCache::(_findDomain)
looking for unfetched domain 9a4a80a1-5377-4a94-ade3-e58183e916ae
Thread-859::DEBUG::2014-04-25
19:58:17,784::resourceManager::198::ResourceManager.Request::(__init__)
ResName=`Storage.upgrade_c2c4ade6-049e-4159-a294-a0c151f4983d`ReqID=`40a09482-c4be-472b-ae79-0b62c4640b5b`::Request
was made in '/usr/share/vdsm/storage/sp.py' line '163' at
'_upgradePoolDomain'
Thread-858::DEBUG::2014-04-25
19:58:17,784::resourceManager::542::ResourceManager::(registerResource)
Trying to register resource
'Storage.upgrade_e637bb04-a8b7-4c77-809c-d58051494c52' for lock type
'exclusive'
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,784::resourceManager::616::ResourceManager::(releaseResource)
Trying to release resource
'Storage.upgrade_c713062f-300f-4256-9ac8-2d3fcfcdb002'
Thread-857::DEBUG::2014-04-25
19:58:17,784::resourceManager::601::ResourceManager::(registerResource)
Resource 'Storage.upgrade_7b083758-45f9-4896-913d-11fe02043e6e' is free.
Now locking as 'exclusive' (1 active user)
Thread-860::ERROR::2014-04-25
19:58:17,784::sdc::154::Storage.StorageDomainCache::(_findUnfetchedDomain)
looking for domain 9a4a80a1-5377-4a94-ade3-e58183e916ae
Thread-859::DEBUG::2014-04-25
19:58:17,784::resourceManager::542::ResourceManager::(registerResource)
Trying to register resource
'Storage.upgrade_c2c4ade6-049e-4159-a294-a0c151f4983d' for lock type
'exclusive'
Thread-857::DEBUG::2014-04-25
19:58:17,785::resourceManager::238::ResourceManager.Request::(grant)
ResName=`Storage.upgrade_7b083758-45f9-4896-913d-11fe02043e6e`ReqID=`c50b5f1d-d9fd-4317-bc98-4d40fad3e553`::Granted
request
Thread-860::DEBUG::2014-04-25
19:58:17,785::lvm::372::OperationMutex::(_reloadvgs) Operation 'lvm
reload operation' got the operation mutex
Thread-858::DEBUG::2014-04-25
19:58:17,785::resourceManager::601::ResourceManager::(registerResource)
Resource 'Storage.upgrade_e637bb04-a8b7-4c77-809c-d58051494c52' is free.
Now locking as 'exclusive' (1 active user)
Thread-857::DEBUG::2014-04-25
19:58:17,786::resourceManager::198::ResourceManager.Request::(__init__)
ResName=`Storage.7b083758-45f9-4896-913d-11fe02043e6e`ReqID=`a81f0cf3-f66a-4620-a380-9776968f5686`::Request
was made in '/usr/share/vdsm/storage/sp.py' line '165' at
'_upgradePoolDomain'
Thread-860::DEBUG::2014-04-25
19:58:17,786::lvm::295::Storage.Misc.excCmd::(cmd) '/usr/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 obtain_device_list_from_udev=0 filter = [
\'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,lv_count,pv_count,pv_name
9a4a80a1-5377-4a94-ade3-e58183e916ae' (cwd None)
Thread-858::DEBUG::2014-04-25
19:58:17,786::resourceManager::238::ResourceManager.Request::(grant)
ResName=`Storage.upgrade_e637bb04-a8b7-4c77-809c-d58051494c52`ReqID=`89314c30-0d9e-4b1d-b5f9-1ab61127274d`::Granted
request
Thread-857::DEBUG::2014-04-25
19:58:17,786::resourceManager::542::ResourceManager::(registerResource)
Trying to register resource
'Storage.7b083758-45f9-4896-913d-11fe02043e6e' for lock type 'exclusive'
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,791::resourceManager::635::ResourceManager::(releaseResource)
Released resource 'Storage.upgrade_c713062f-300f-4256-9ac8-2d3fcfcdb002'
(0 active users)
Thread-858::DEBUG::2014-04-25
19:58:17,791::resourceManager::198::ResourceManager.Request::(__init__)
ResName=`Storage.e637bb04-a8b7-4c77-809c-d58051494c52`ReqID=`c5d0a1e7-9ebd-4175-86dd-30ef0e8f0a5c`::Request
was made in '/usr/share/vdsm/storage/sp.py' line '165' at
'_upgradePoolDomain'
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,791::resourceManager::641::ResourceManager::(releaseResource)
Resource 'Storage.upgrade_c713062f-300f-4256-9ac8-2d3fcfcdb002' is free,
finding out if anyone is waiting for it.
Thread-858::DEBUG::2014-04-25
19:58:17,791::resourceManager::542::ResourceManager::(registerResource)
Trying to register resource
'Storage.e637bb04-a8b7-4c77-809c-d58051494c52' for lock type 'exclusive'
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,792::resourceManager::649::ResourceManager::(releaseResource)
No one is waiting for resource
'Storage.upgrade_c713062f-300f-4256-9ac8-2d3fcfcdb002', Clearing records.
Thread-859::DEBUG::2014-04-25
19:58:17,792::resourceManager::601::ResourceManager::(registerResource)
Resource 'Storage.upgrade_c2c4ade6-049e-4159-a294-a0c151f4983d' is free.
Now locking as 'exclusive' (1 active user)
Thread-859::DEBUG::2014-04-25
19:58:17,792::resourceManager::238::ResourceManager.Request::(grant)
ResName=`Storage.upgrade_c2c4ade6-049e-4159-a294-a0c151f4983d`ReqID=`40a09482-c4be-472b-ae79-0b62c4640b5b`::Granted
request
Thread-857::DEBUG::2014-04-25
19:58:17,793::resourceManager::601::ResourceManager::(registerResource)
Resource 'Storage.7b083758-45f9-4896-913d-11fe02043e6e' is free. Now
locking as 'exclusive' (1 active user)
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,793::sd::623::Storage.StorageDomain::(createMasterTree)
creating vms dir:
/rhev/data-center/mnt/_vdsm__store_s2data1__s2mgt__boot1/0a897f2e-1b01-4577-9f91-cd136ef4a978/master/vms
Thread-859::DEBUG::2014-04-25
19:58:17,793::resourceManager::198::ResourceManager.Request::(__init__)
ResName=`Storage.c2c4ade6-049e-4159-a294-a0c151f4983d`ReqID=`47c69548-2b50-4d71-98f1-4bd3a70edaff`::Request
was made in '/usr/share/vdsm/storage/sp.py' line '165' at
'_upgradePoolDomain'
Thread-859::DEBUG::2014-04-25
19:58:17,793::resourceManager::542::ResourceManager::(registerResource)
Trying to register resource
'Storage.c2c4ade6-049e-4159-a294-a0c151f4983d' for lock type 'exclusive'
Thread-857::DEBUG::2014-04-25
19:58:17,793::resourceManager::238::ResourceManager.Request::(grant)
ResName=`Storage.7b083758-45f9-4896-913d-11fe02043e6e`ReqID=`a81f0cf3-f66a-4620-a380-9776968f5686`::Granted
request
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,794::sd::626::Storage.StorageDomain::(createMasterTree)
creating task dir:
/rhev/data-center/mnt/_vdsm__store_s2data1__s2mgt__boot1/0a897f2e-1b01-4577-9f91-cd136ef4a978/master/tasks
Thread-858::DEBUG::2014-04-25
19:58:17,794::resourceManager::601::ResourceManager::(registerResource)
Resource 'Storage.e637bb04-a8b7-4c77-809c-d58051494c52' is free. Now
locking as 'exclusive' (1 active user)
Thread-857::DEBUG::2014-04-25
19:58:17,794::sp::175::Storage.StoragePool::(_upgradePoolDomain) Domain
`7b083758-45f9-4896-913d-11fe02043e6e` is not a data domain it is an 2
domain, not upgrading
Thread-858::DEBUG::2014-04-25
19:58:17,795::resourceManager::238::ResourceManager.Request::(grant)
ResName=`Storage.e637bb04-a8b7-4c77-809c-d58051494c52`ReqID=`c5d0a1e7-9ebd-4175-86dd-30ef0e8f0a5c`::Granted
request
Thread-860::DEBUG::2014-04-25
19:58:17,800::lvm::295::Storage.Misc.excCmd::(cmd) FAILED: <err> = '
Volume group "9a4a80a1-5377-4a94-ade3-e58183e916ae" not found\n
Skipping volume group 9a4a80a1-5377-4a94-ade3-e58183e916ae\n'; <rc> = 5
Thread-857::DEBUG::2014-04-25
19:58:17,804::resourceManager::616::ResourceManager::(releaseResource)
Trying to release resource 'Storage.7b083758-45f9-4896-913d-11fe02043e6e'
Thread-859::DEBUG::2014-04-25
19:58:17,804::resourceManager::601::ResourceManager::(registerResource)
Resource 'Storage.c2c4ade6-049e-4159-a294-a0c151f4983d' is free. Now
locking as 'exclusive' (1 active user)
Thread-859::DEBUG::2014-04-25
19:58:17,807::resourceManager::238::ResourceManager.Request::(grant)
ResName=`Storage.c2c4ade6-049e-4159-a294-a0c151f4983d`ReqID=`47c69548-2b50-4d71-98f1-4bd3a70edaff`::Granted
request
Thread-860::WARNING::2014-04-25
19:58:17,808::lvm::377::Storage.LVM::(_reloadvgs) lvm vgs failed: 5 []
[' Volume group "9a4a80a1-5377-4a94-ade3-e58183e916ae" not found', '
Skipping volume group 9a4a80a1-5377-4a94-ade3-e58183e916ae']
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,809::persistentDict::234::Storage.PersistentDict::(refresh)
read lines (FileMetadataRW)=['CLASS=Data',
'DESCRIPTION=s2data1_s2mgt_boot1', 'IOOPTIMEOUTSEC=10',
'LEASERETRIES=3', 'LEASETIMESEC=60', 'LOCKPOLICY=',
'LOCKRENEWALINTERVALSEC=5', 'MASTER_VERSION=1',
'POOL_DESCRIPTION=BDS_DataCentre2',
'POOL_DOMAINS=7b083758-45f9-4896-913d-11fe02043e6e:Active,e637bb04-a8b7-4c77-809c-d58051494c52:Active,0a897f2e-1b01-4577-9f91-cd136ef4a978:Active,c2c4ade6-049e-4159-a294-a0c151f4983d:Active,9a4a80a1-5377-4a94-ade3-e58183e916ae:Active',
'POOL_SPM_ID=1', 'POOL_SPM_LVER=0',
'POOL_UUID=c713062f-300f-4256-9ac8-2d3fcfcdb002',
'REMOTE_PATH=/vdsm_store/s2data1_s2mgt_boot1', 'ROLE=Master',
'SDUUID=0a897f2e-1b01-4577-9f91-cd136ef4a978', 'TYPE=LOCALFS',
'VERSION=3', '_SHA_CKSUM=68a337432f9f1794a057deb08eb27f6bb3513470']
Thread-857::DEBUG::2014-04-25
19:58:17,810::resourceManager::635::ResourceManager::(releaseResource)
Released resource 'Storage.7b083758-45f9-4896-913d-11fe02043e6e' (0
active users)
Thread-857::DEBUG::2014-04-25
19:58:17,811::resourceManager::641::ResourceManager::(releaseResource)
Resource 'Storage.7b083758-45f9-4896-913d-11fe02043e6e' is free, finding
out if anyone is waiting for it.
Thread-857::DEBUG::2014-04-25
19:58:17,813::resourceManager::649::ResourceManager::(releaseResource)
No one is waiting for resource
'Storage.7b083758-45f9-4896-913d-11fe02043e6e', Clearing records.
Thread-857::DEBUG::2014-04-25
19:58:17,813::resourceManager::616::ResourceManager::(releaseResource)
Trying to release resource
'Storage.upgrade_7b083758-45f9-4896-913d-11fe02043e6e'
Thread-857::DEBUG::2014-04-25
19:58:17,814::resourceManager::635::ResourceManager::(releaseResource)
Released resource 'Storage.upgrade_7b083758-45f9-4896-913d-11fe02043e6e'
(0 active users)
Thread-857::DEBUG::2014-04-25
19:58:17,814::resourceManager::641::ResourceManager::(releaseResource)
Resource 'Storage.upgrade_7b083758-45f9-4896-913d-11fe02043e6e' is free,
finding out if anyone is waiting for it.
Thread-857::DEBUG::2014-04-25
19:58:17,814::resourceManager::649::ResourceManager::(releaseResource)
No one is waiting for resource
'Storage.upgrade_7b083758-45f9-4896-913d-11fe02043e6e', Clearing records.
Thread-860::DEBUG::2014-04-25
19:58:17,820::lvm::414::OperationMutex::(_reloadvgs) Operation 'lvm
reload operation' released the operation mutex
Thread-858::DEBUG::2014-04-25
19:58:17,826::persistentDict::234::Storage.PersistentDict::(refresh)
read lines (FileMetadataRW)=['CLASS=Data',
'DESCRIPTION=s2data1_s2usr_boot1', 'IOOPTIMEOUTSEC=10',
'LEASERETRIES=3', 'LEASETIMESEC=60', 'LOCKPOLICY=',
'LOCKRENEWALINTERVALSEC=5', 'MASTER_VERSION=0',
'POOL_UUID=c713062f-300f-4256-9ac8-2d3fcfcdb002',
'REMOTE_PATH=/vdsm_store/s2data1_s2usr_boot1', 'ROLE=Regular',
'SDUUID=e637bb04-a8b7-4c77-809c-d58051494c52', 'TYPE=LOCALFS',
'VERSION=3', '_SHA_CKSUM=1f8ddad2bfec7f562b2e20b339649fe8c088a3d9']
Thread-859::DEBUG::2014-04-25
19:58:17,827::persistentDict::234::Storage.PersistentDict::(refresh)
read lines (FileMetadataRW)=['CLASS=Data',
'DESCRIPTION=s2data1_s2mgt_app1', 'IOOPTIMEOUTSEC=10', 'LEASERETRIES=3',
'LEASETIMESEC=60', 'LOCKPOLICY=', 'LOCKRENEWALINTERVALSEC=5',
'MASTER_VERSION=0', 'POOL_UUID=c713062f-300f-4256-9ac8-2d3fcfcdb002',
'REMOTE_PATH=/vdsm_store/s2data1_s2mgt_app1', 'ROLE=Regular',
'SDUUID=c2c4ade6-049e-4159-a294-a0c151f4983d', 'TYPE=LOCALFS',
'VERSION=3', '_SHA_CKSUM=5eda40da414dcb977d9d94d0ed6ad1162a55d69f']
Thread-858::DEBUG::2014-04-25
19:58:17,831::resourceManager::616::ResourceManager::(releaseResource)
Trying to release resource 'Storage.e637bb04-a8b7-4c77-809c-d58051494c52'
Thread-859::DEBUG::2014-04-25
19:58:17,832::resourceManager::616::ResourceManager::(releaseResource)
Trying to release resource 'Storage.c2c4ade6-049e-4159-a294-a0c151f4983d'
Thread-858::DEBUG::2014-04-25
19:58:17,834::resourceManager::635::ResourceManager::(releaseResource)
Released resource 'Storage.e637bb04-a8b7-4c77-809c-d58051494c52' (0
active users)
Thread-858::DEBUG::2014-04-25
19:58:17,836::resourceManager::641::ResourceManager::(releaseResource)
Resource 'Storage.e637bb04-a8b7-4c77-809c-d58051494c52' is free, finding
out if anyone is waiting for it.
Thread-858::DEBUG::2014-04-25
19:58:17,838::resourceManager::649::ResourceManager::(releaseResource)
No one is waiting for resource
'Storage.e637bb04-a8b7-4c77-809c-d58051494c52', Clearing records.
Thread-860::ERROR::2014-04-25
19:58:17,838::sdc::143::Storage.StorageDomainCache::(_findDomain) domain
9a4a80a1-5377-4a94-ade3-e58183e916ae not found
Traceback (most recent call last):
File "/usr/share/vdsm/storage/sdc.py", line 141, in _findDomain
dom = findMethod(sdUUID)
File "/usr/share/vdsm/storage/sdc.py", line 171, in _findUnfetchedDomain
raise se.StorageDomainDoesNotExist(sdUUID)
StorageDomainDoesNotExist: Storage domain does not exist:
('9a4a80a1-5377-4a94-ade3-e58183e916ae',)
Thread-859::DEBUG::2014-04-25
19:58:17,839::resourceManager::635::ResourceManager::(releaseResource)
Released resource 'Storage.c2c4ade6-049e-4159-a294-a0c151f4983d' (0
active users)
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::ERROR::2014-04-25
19:58:17,840::sdc::137::Storage.StorageDomainCache::(_findDomain)
looking for unfetched domain 9a4a80a1-5377-4a94-ade3-e58183e916ae
Thread-859::DEBUG::2014-04-25
19:58:17,840::resourceManager::641::ResourceManager::(releaseResource)
Resource 'Storage.c2c4ade6-049e-4159-a294-a0c151f4983d' is free, finding
out if anyone is waiting for it.
Thread-858::DEBUG::2014-04-25
19:58:17,841::resourceManager::616::ResourceManager::(releaseResource)
Trying to release resource
'Storage.upgrade_e637bb04-a8b7-4c77-809c-d58051494c52'
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::ERROR::2014-04-25
19:58:17,841::sdc::154::Storage.StorageDomainCache::(_findUnfetchedDomain)
looking for domain 9a4a80a1-5377-4a94-ade3-e58183e916ae
Thread-859::DEBUG::2014-04-25
19:58:17,842::resourceManager::649::ResourceManager::(releaseResource)
No one is waiting for resource
'Storage.c2c4ade6-049e-4159-a294-a0c151f4983d', Clearing records.
Thread-858::DEBUG::2014-04-25
19:58:17,843::resourceManager::635::ResourceManager::(releaseResource)
Released resource 'Storage.upgrade_e637bb04-a8b7-4c77-809c-d58051494c52'
(0 active users)
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,843::lvm::372::OperationMutex::(_reloadvgs) Operation 'lvm
reload operation' got the operation mutex
Thread-858::DEBUG::2014-04-25
19:58:17,844::resourceManager::641::ResourceManager::(releaseResource)
Resource 'Storage.upgrade_e637bb04-a8b7-4c77-809c-d58051494c52' is free,
finding out if anyone is waiting for it.
Thread-859::DEBUG::2014-04-25
19:58:17,844::resourceManager::616::ResourceManager::(releaseResource)
Trying to release resource
'Storage.upgrade_c2c4ade6-049e-4159-a294-a0c151f4983d'
Thread-858::DEBUG::2014-04-25
19:58:17,845::resourceManager::649::ResourceManager::(releaseResource)
No one is waiting for resource
'Storage.upgrade_e637bb04-a8b7-4c77-809c-d58051494c52', Clearing records.
Thread-859::DEBUG::2014-04-25
19:58:17,846::resourceManager::635::ResourceManager::(releaseResource)
Released resource 'Storage.upgrade_c2c4ade6-049e-4159-a294-a0c151f4983d'
(0 active users)
Thread-859::DEBUG::2014-04-25
19:58:17,847::resourceManager::641::ResourceManager::(releaseResource)
Resource 'Storage.upgrade_c2c4ade6-049e-4159-a294-a0c151f4983d' is free,
finding out if anyone is waiting for it.
Thread-859::DEBUG::2014-04-25
19:58:17,848::resourceManager::649::ResourceManager::(releaseResource)
No one is waiting for resource
'Storage.upgrade_c2c4ade6-049e-4159-a294-a0c151f4983d', Clearing records.
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,848::lvm::295::Storage.Misc.excCmd::(cmd) '/usr/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 obtain_device_list_from_udev=0 filter = [
\'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,lv_count,pv_count,pv_name
9a4a80a1-5377-4a94-ade3-e58183e916ae' (cwd None)
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,862::lvm::295::Storage.Misc.excCmd::(cmd) FAILED: <err> = '
Volume group "9a4a80a1-5377-4a94-ade3-e58183e916ae" not found\n
Skipping volume group 9a4a80a1-5377-4a94-ade3-e58183e916ae\n'; <rc> = 5
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::WARNING::2014-04-25
19:58:17,863::lvm::377::Storage.LVM::(_reloadvgs) lvm vgs failed: 5 []
[' Volume group "9a4a80a1-5377-4a94-ade3-e58183e916ae" not found', '
Skipping volume group 9a4a80a1-5377-4a94-ade3-e58183e916ae']
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,863::lvm::414::OperationMutex::(_reloadvgs) Operation 'lvm
reload operation' released the operation mutex
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::ERROR::2014-04-25
19:58:17,873::sdc::143::Storage.StorageDomainCache::(_findDomain) domain
9a4a80a1-5377-4a94-ade3-e58183e916ae not found
Traceback (most recent call last):
File "/usr/share/vdsm/storage/sdc.py", line 141, in _findDomain
dom = findMethod(sdUUID)
File "/usr/share/vdsm/storage/sdc.py", line 171, in _findUnfetchedDomain
raise se.StorageDomainDoesNotExist(sdUUID)
StorageDomainDoesNotExist: Storage domain does not exist:
('9a4a80a1-5377-4a94-ade3-e58183e916ae',)
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::ERROR::2014-04-25
19:58:17,874::sp::288::Storage.StoragePool::(startSpm) Backup domain
validation failed
Traceback (most recent call last):
File "/usr/share/vdsm/storage/sp.py", line 285, in startSpm
self.checkBackupDomain(__securityOverride=True)
File "/usr/share/vdsm/storage/securable.py", line 75, in wrapper
return method(self, *args, **kwargs)
File "/usr/share/vdsm/storage/sp.py", line 1409, in checkBackupDomain
dom = sdCache.produce(sdUUID)
File "/usr/share/vdsm/storage/sdc.py", line 98, in produce
domain.getRealDomain()
File "/usr/share/vdsm/storage/sdc.py", line 52, in getRealDomain
return self._cache._realProduce(self._sdUUID)
File "/usr/share/vdsm/storage/sdc.py", line 122, in _realProduce
domain = self._findDomain(sdUUID)
File "/usr/share/vdsm/storage/sdc.py", line 141, in _findDomain
dom = findMethod(sdUUID)
File "/usr/share/vdsm/storage/sdc.py", line 171, in _findUnfetchedDomain
raise se.StorageDomainDoesNotExist(sdUUID)
StorageDomainDoesNotExist: Storage domain does not exist:
('9a4a80a1-5377-4a94-ade3-e58183e916ae',)
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::ERROR::2014-04-25
19:58:17,874::sdc::137::Storage.StorageDomainCache::(_findDomain)
looking for unfetched domain 9a4a80a1-5377-4a94-ade3-e58183e916ae
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::ERROR::2014-04-25
19:58:17,874::sdc::154::Storage.StorageDomainCache::(_findUnfetchedDomain)
looking for domain 9a4a80a1-5377-4a94-ade3-e58183e916ae
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,874::lvm::372::OperationMutex::(_reloadvgs) Operation 'lvm
reload operation' got the operation mutex
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,875::lvm::295::Storage.Misc.excCmd::(cmd) '/usr/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 obtain_device_list_from_udev=0 filter = [
\'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,lv_count,pv_count,pv_name
9a4a80a1-5377-4a94-ade3-e58183e916ae' (cwd None)
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,888::lvm::295::Storage.Misc.excCmd::(cmd) FAILED: <err> = '
Volume group "9a4a80a1-5377-4a94-ade3-e58183e916ae" not found\n
Skipping volume group 9a4a80a1-5377-4a94-ade3-e58183e916ae\n'; <rc> = 5
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::WARNING::2014-04-25
19:58:17,889::lvm::377::Storage.LVM::(_reloadvgs) lvm vgs failed: 5 []
[' Volume group "9a4a80a1-5377-4a94-ade3-e58183e916ae" not found', '
Skipping volume group 9a4a80a1-5377-4a94-ade3-e58183e916ae']
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,889::lvm::414::OperationMutex::(_reloadvgs) Operation 'lvm
reload operation' released the operation mutex
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::ERROR::2014-04-25
19:58:17,899::sdc::143::Storage.StorageDomainCache::(_findDomain) domain
9a4a80a1-5377-4a94-ade3-e58183e916ae not found
Traceback (most recent call last):
File "/usr/share/vdsm/storage/sdc.py", line 141, in _findDomain
dom = findMethod(sdUUID)
File "/usr/share/vdsm/storage/sdc.py", line 171, in _findUnfetchedDomain
raise se.StorageDomainDoesNotExist(sdUUID)
StorageDomainDoesNotExist: Storage domain does not exist:
('9a4a80a1-5377-4a94-ade3-e58183e916ae',)
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::ERROR::2014-04-25
19:58:17,899::sp::329::Storage.StoragePool::(startSpm) Unexpected error
Traceback (most recent call last):
File "/usr/share/vdsm/storage/sp.py", line 296, in startSpm
self._updateDomainsRole()
File "/usr/share/vdsm/storage/securable.py", line 75, in wrapper
return method(self, *args, **kwargs)
File "/usr/share/vdsm/storage/sp.py", line 205, in _updateDomainsRole
domain = sdCache.produce(sdUUID)
File "/usr/share/vdsm/storage/sdc.py", line 98, in produce
domain.getRealDomain()
File "/usr/share/vdsm/storage/sdc.py", line 52, in getRealDomain
return self._cache._realProduce(self._sdUUID)
File "/usr/share/vdsm/storage/sdc.py", line 122, in _realProduce
domain = self._findDomain(sdUUID)
File "/usr/share/vdsm/storage/sdc.py", line 141, in _findDomain
dom = findMethod(sdUUID)
File "/usr/share/vdsm/storage/sdc.py", line 171, in _findUnfetchedDomain
raise se.StorageDomainDoesNotExist(sdUUID)
StorageDomainDoesNotExist: Storage domain does not exist:
('9a4a80a1-5377-4a94-ade3-e58183e916ae',)
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::ERROR::2014-04-25
19:58:17,900::sp::330::Storage.StoragePool::(startSpm) failed: Storage
domain does not exist: ('9a4a80a1-5377-4a94-ade3-e58183e916ae',)
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,900::sp::336::Storage.StoragePool::(_shutDownUpgrade) Shutting
down upgrade process
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,900::resourceManager::198::ResourceManager.Request::(__init__)
ResName=`Storage.upgrade_c713062f-300f-4256-9ac8-2d3fcfcdb002`ReqID=`1d51aee8-4f09-4c7d-9fad-8b13801dce28`::Request
was made in '/usr/share/vdsm/storage/sp.py' line '338' at '_shutDownUpgrade'
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,900::resourceManager::542::ResourceManager::(registerResource)
Trying to register resource
'Storage.upgrade_c713062f-300f-4256-9ac8-2d3fcfcdb002' for lock type
'exclusive'
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,900::resourceManager::601::ResourceManager::(registerResource)
Resource 'Storage.upgrade_c713062f-300f-4256-9ac8-2d3fcfcdb002' is free.
Now locking as 'exclusive' (1 active user)
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,901::resourceManager::238::ResourceManager.Request::(grant)
ResName=`Storage.upgrade_c713062f-300f-4256-9ac8-2d3fcfcdb002`ReqID=`1d51aee8-4f09-4c7d-9fad-8b13801dce28`::Granted
request
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,901::resourceManager::198::ResourceManager.Request::(__init__)
ResName=`Storage.upgrade_9a4a80a1-5377-4a94-ade3-e58183e916ae`ReqID=`7b50d1d9-ac64-4a8a-93df-3faee4744b2b`::Request
was made in '/usr/share/vdsm/storage/sp.py' line '358' at '_shutDownUpgrade'
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,901::resourceManager::542::ResourceManager::(registerResource)
Trying to register resource
'Storage.upgrade_9a4a80a1-5377-4a94-ade3-e58183e916ae' for lock type
'exclusive'
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,901::resourceManager::601::ResourceManager::(registerResource)
Resource 'Storage.upgrade_9a4a80a1-5377-4a94-ade3-e58183e916ae' is free.
Now locking as 'exclusive' (1 active user)
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,901::resourceManager::238::ResourceManager.Request::(grant)
ResName=`Storage.upgrade_9a4a80a1-5377-4a94-ade3-e58183e916ae`ReqID=`7b50d1d9-ac64-4a8a-93df-3faee4744b2b`::Granted
request
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,902::resourceManager::616::ResourceManager::(releaseResource)
Trying to release resource
'Storage.upgrade_9a4a80a1-5377-4a94-ade3-e58183e916ae'
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,902::resourceManager::635::ResourceManager::(releaseResource)
Released resource 'Storage.upgrade_9a4a80a1-5377-4a94-ade3-e58183e916ae'
(0 active users)
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,902::resourceManager::641::ResourceManager::(releaseResource)
Resource 'Storage.upgrade_9a4a80a1-5377-4a94-ade3-e58183e916ae' is free,
finding out if anyone is waiting for it.
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,902::resourceManager::649::ResourceManager::(releaseResource)
No one is waiting for resource
'Storage.upgrade_9a4a80a1-5377-4a94-ade3-e58183e916ae', Clearing records.
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,902::resourceManager::616::ResourceManager::(releaseResource)
Trying to release resource
'Storage.upgrade_c713062f-300f-4256-9ac8-2d3fcfcdb002'
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,902::resourceManager::635::ResourceManager::(releaseResource)
Released resource 'Storage.upgrade_c713062f-300f-4256-9ac8-2d3fcfcdb002'
(0 active users)
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,902::resourceManager::641::ResourceManager::(releaseResource)
Resource 'Storage.upgrade_c713062f-300f-4256-9ac8-2d3fcfcdb002' is free,
finding out if anyone is waiting for it.
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,902::resourceManager::649::ResourceManager::(releaseResource)
No one is waiting for resource
'Storage.upgrade_c713062f-300f-4256-9ac8-2d3fcfcdb002', Clearing records.
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,903::persistentDict::167::Storage.PersistentDict::(transaction)
Starting transaction
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,903::persistentDict::173::Storage.PersistentDict::(transaction)
Flushing changes
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,903::persistentDict::299::Storage.PersistentDict::(flush) about
to write lines (FileMetadataRW)=['CLASS=Data',
'DESCRIPTION=s2data1_s2mgt_boot1', 'IOOPTIMEOUTSEC=10',
'LEASERETRIES=3', 'LEASETIMESEC=60', 'LOCKPOLICY=',
'LOCKRENEWALINTERVALSEC=5', 'MASTER_VERSION=1',
'POOL_DESCRIPTION=BDS_DataCentre2',
'POOL_DOMAINS=7b083758-45f9-4896-913d-11fe02043e6e:Active,e637bb04-a8b7-4c77-809c-d58051494c52:Active,0a897f2e-1b01-4577-9f91-cd136ef4a978:Active,c2c4ade6-049e-4159-a294-a0c151f4983d:Active,9a4a80a1-5377-4a94-ade3-e58183e916ae:Active',
'POOL_SPM_ID=-1', 'POOL_SPM_LVER=0',
'POOL_UUID=c713062f-300f-4256-9ac8-2d3fcfcdb002',
'REMOTE_PATH=/vdsm_store/s2data1_s2mgt_boot1', 'ROLE=Master',
'SDUUID=0a897f2e-1b01-4577-9f91-cd136ef4a978', 'TYPE=LOCALFS',
'VERSION=3', '_SHA_CKSUM=afe618d7596d75d0fb96453bcdd34a1255534454']
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,904::persistentDict::175::Storage.PersistentDict::(transaction)
Finished transaction
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::INFO::2014-04-25
19:58:17,904::clusterlock::409::LocalLock::(release) Releasing local
lock for domain 0a897f2e-1b01-4577-9f91-cd136ef4a978
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,904::clusterlock::422::LocalLock::(release) Local lock for
domain 0a897f2e-1b01-4577-9f91-cd136ef4a978 successfully released
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::ERROR::2014-04-25
19:58:17,905::task::866::TaskManager.Task::(_setError)
Task=`b9623891-cda5-4ac3-b4ab-efde3cc5ac97`::Unexpected error
Traceback (most recent call last):
File "/usr/share/vdsm/storage/task.py", line 873, in _run
return fn(*args, **kargs)
File "/usr/share/vdsm/storage/task.py", line 334, in run
return self.cmd(*self.argslist, **self.argsdict)
File "/usr/share/vdsm/storage/sp.py", line 296, in startSpm
self._updateDomainsRole()
File "/usr/share/vdsm/storage/securable.py", line 75, in wrapper
return method(self, *args, **kwargs)
File "/usr/share/vdsm/storage/sp.py", line 205, in _updateDomainsRole
domain = sdCache.produce(sdUUID)
File "/usr/share/vdsm/storage/sdc.py", line 98, in produce
domain.getRealDomain()
File "/usr/share/vdsm/storage/sdc.py", line 52, in getRealDomain
return self._cache._realProduce(self._sdUUID)
File "/usr/share/vdsm/storage/sdc.py", line 122, in _realProduce
domain = self._findDomain(sdUUID)
File "/usr/share/vdsm/storage/sdc.py", line 141, in _findDomain
dom = findMethod(sdUUID)
File "/usr/share/vdsm/storage/sdc.py", line 171, in _findUnfetchedDomain
raise se.StorageDomainDoesNotExist(sdUUID)
StorageDomainDoesNotExist: Storage domain does not exist:
('9a4a80a1-5377-4a94-ade3-e58183e916ae',)
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,905::task::885::TaskManager.Task::(_run)
Task=`b9623891-cda5-4ac3-b4ab-efde3cc5ac97`::Task._run:
b9623891-cda5-4ac3-b4ab-efde3cc5ac97 () {} failed - stopping task
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,905::task::1211::TaskManager.Task::(stop)
Task=`b9623891-cda5-4ac3-b4ab-efde3cc5ac97`::stopping in state running
(force False)
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,905::task::990::TaskManager.Task::(_decref)
Task=`b9623891-cda5-4ac3-b4ab-efde3cc5ac97`::ref 1 aborting True
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,905::task::916::TaskManager.Task::(_runJobs)
Task=`b9623891-cda5-4ac3-b4ab-efde3cc5ac97`::aborting: Task is aborted:
'Storage domain does not exist' - code 358
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,905::task::990::TaskManager.Task::(_decref)
Task=`b9623891-cda5-4ac3-b4ab-efde3cc5ac97`::ref 0 aborting True
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,906::task::925::TaskManager.Task::(_doAbort)
Task=`b9623891-cda5-4ac3-b4ab-efde3cc5ac97`::Task._doAbort: force False
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,906::resourceManager::977::ResourceManager.Owner::(cancelAll)
Owner.cancelAll requests {}
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,906::task::595::TaskManager.Task::(_updateState)
Task=`b9623891-cda5-4ac3-b4ab-efde3cc5ac97`::moving from state running
-> state aborting
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,906::task::550::TaskManager.Task::(__state_aborting)
Task=`b9623891-cda5-4ac3-b4ab-efde3cc5ac97`::_aborting: recover policy auto
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,906::task::595::TaskManager.Task::(_updateState)
Task=`b9623891-cda5-4ac3-b4ab-efde3cc5ac97`::moving from state aborting
-> state racquiring
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,906::task::595::TaskManager.Task::(_updateState)
Task=`b9623891-cda5-4ac3-b4ab-efde3cc5ac97`::moving from state
racquiring -> state recovering
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,906::task::798::TaskManager.Task::(_recover)
Task=`b9623891-cda5-4ac3-b4ab-efde3cc5ac97`::_recover
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,906::task::805::TaskManager.Task::(_recover)
Task=`b9623891-cda5-4ac3-b4ab-efde3cc5ac97`::running recovery None
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,906::task::786::TaskManager.Task::(_recoverDone)
Task=`b9623891-cda5-4ac3-b4ab-efde3cc5ac97`::Recover Done: state recovering
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,907::task::595::TaskManager.Task::(_updateState)
Task=`b9623891-cda5-4ac3-b4ab-efde3cc5ac97`::moving from state
recovering -> state recovered
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,907::resourceManager::940::ResourceManager.Owner::(releaseAll)
Owner.releaseAll requests {} resources
{'Storage.c713062f-300f-4256-9ac8-2d3fcfcdb002': < ResourceRef
'Storage.c713062f-300f-4256-9ac8-2d3fcfcdb002', isValid: 'True' obj:
'None'>}
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,907::resourceManager::977::ResourceManager.Owner::(cancelAll)
Owner.cancelAll requests {}
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,907::resourceManager::616::ResourceManager::(releaseResource)
Trying to release resource 'Storage.c713062f-300f-4256-9ac8-2d3fcfcdb002'
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,907::resourceManager::635::ResourceManager::(releaseResource)
Released resource 'Storage.c713062f-300f-4256-9ac8-2d3fcfcdb002' (0
active users)
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,907::resourceManager::641::ResourceManager::(releaseResource)
Resource 'Storage.c713062f-300f-4256-9ac8-2d3fcfcdb002' is free, finding
out if anyone is waiting for it.
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,907::resourceManager::649::ResourceManager::(releaseResource)
No one is waiting for resource
'Storage.c713062f-300f-4256-9ac8-2d3fcfcdb002', Clearing records.
b9623891-cda5-4ac3-b4ab-efde3cc5ac97::DEBUG::2014-04-25
19:58:17,907::threadPool::57::Misc.ThreadPool::(setRunningTask) Number
of running tasks: 0
Thread-180::DEBUG::2014-04-25
19:58:18,739::BindingXMLRPC::251::vds::(wrapper) client [10.50.0.18]
flowID [21f7a1a7]
Thread-180::DEBUG::2014-04-25
19:58:18,739::task::595::TaskManager.Task::(_updateState)
Task=`c57b61b2-fa6d-437d-b77f-694dda11efee`::moving from state init ->
state preparing
Thread-180::INFO::2014-04-25
19:58:18,739::logUtils::44::dispatcher::(wrapper) Run and protect:
getTaskStatus(taskID='b9623891-cda5-4ac3-b4ab-efde3cc5ac97',
spUUID=None, options=None)
Thread-180::DEBUG::2014-04-25
19:58:18,740::taskManager::93::TaskManager::(getTaskStatus) Entry.
taskID: b9623891-cda5-4ac3-b4ab-efde3cc5ac97
Thread-180::DEBUG::2014-04-25
19:58:18,740::taskManager::96::TaskManager::(getTaskStatus) Return.
Response: {'code': 358, 'message': 'Storage domain does not exist',
'taskState': 'finished', 'taskResult': 'cleanSuccess', 'taskID':
'b9623891-cda5-4ac3-b4ab-efde3cc5ac97'}
Thread-180::INFO::2014-04-25
19:58:18,740::logUtils::47::dispatcher::(wrapper) Run and protect:
getTaskStatus, Return response: {'taskStatus': {'code': 358, 'message':
'Storage domain does not exist', 'taskState': 'finished', 'taskResult':
'cleanSuccess', 'taskID': 'b9623891-cda5-4ac3-b4ab-efde3cc5ac97'}}
Thread-180::DEBUG::2014-04-25
19:58:18,740::task::1185::TaskManager.Task::(prepare)
Task=`c57b61b2-fa6d-437d-b77f-694dda11efee`::finished: {'taskStatus':
{'code': 358, 'message': 'Storage domain does not exist', 'taskState':
'finished', 'taskResult': 'cleanSuccess', 'taskID':
'b9623891-cda5-4ac3-b4ab-efde3cc5ac97'}}
Thread-180::DEBUG::2014-04-25
19:58:18,740::task::595::TaskManager.Task::(_updateState)
Task=`c57b61b2-fa6d-437d-b77f-694dda11efee`::moving from state preparing
-> state finished
Thread-180::DEBUG::2014-04-25
19:58:18,740::resourceManager::940::ResourceManager.Owner::(releaseAll)
Owner.releaseAll requests {} resources {}
Thread-180::DEBUG::2014-04-25
19:58:18,740::resourceManager::977::ResourceManager.Owner::(cancelAll)
Owner.cancelAll requests {}
Thread-180::DEBUG::2014-04-25
19:58:18,740::task::990::TaskManager.Task::(_decref)
Task=`c57b61b2-fa6d-437d-b77f-694dda11efee`::ref 0 aborting False
Thread-180::DEBUG::2014-04-25
19:58:18,745::BindingXMLRPC::251::vds::(wrapper) client [10.50.0.18]
flowID [21f7a1a7]
Thread-180::DEBUG::2014-04-25
19:58:18,745::task::595::TaskManager.Task::(_updateState)
Task=`e3e1bdc1-e68d-40b1-ada1-229a29416c27`::moving from state init ->
state preparing
Thread-180::INFO::2014-04-25
19:58:18,746::logUtils::44::dispatcher::(wrapper) Run and protect:
getSpmStatus(spUUID='c713062f-300f-4256-9ac8-2d3fcfcdb002', options=None)
Thread-180::INFO::2014-04-25
19:58:18,746::logUtils::47::dispatcher::(wrapper) Run and protect:
getSpmStatus, Return response: {'spm_st': {'spmId': -1, 'spmStatus':
'Free', 'spmLver': -1}}
Thread-180::DEBUG::2014-04-25
19:58:18,746::task::1185::TaskManager.Task::(prepare)
Task=`e3e1bdc1-e68d-40b1-ada1-229a29416c27`::finished: {'spm_st':
{'spmId': -1, 'spmStatus': 'Free', 'spmLver': -1}}
Thread-180::DEBUG::2014-04-25
19:58:18,746::task::595::TaskManager.Task::(_updateState)
Task=`e3e1bdc1-e68d-40b1-ada1-229a29416c27`::moving from state preparing
-> state finished
Thread-180::DEBUG::2014-04-25
19:58:18,746::resourceManager::940::ResourceManager.Owner::(releaseAll)
Owner.releaseAll requests {} resources {}
Thread-180::DEBUG::2014-04-25
19:58:18,746::resourceManager::977::ResourceManager.Owner::(cancelAll)
Owner.cancelAll requests {}
Thread-180::DEBUG::2014-04-25
19:58:18,746::task::990::TaskManager.Task::(_decref)
Task=`e3e1bdc1-e68d-40b1-ada1-229a29416c27`::ref 0 aborting False
Thread-180::DEBUG::2014-04-25
19:58:18,790::BindingXMLRPC::251::vds::(wrapper) client [10.50.0.18]
flowID [21f7a1a7]
Thread-180::DEBUG::2014-04-25
19:58:18,791::task::595::TaskManager.Task::(_updateState)
Task=`bc8109f7-7ca9-4900-afc2-653120a0f0b7`::moving from state init ->
state preparing
Thread-180::INFO::2014-04-25
19:58:18,791::logUtils::44::dispatcher::(wrapper) Run and protect:
clearTask(taskID='b9623891-cda5-4ac3-b4ab-efde3cc5ac97', spUUID=None,
options=None)
Thread-180::DEBUG::2014-04-25
19:58:18,791::taskManager::161::TaskManager::(clearTask) Entry. taskID:
b9623891-cda5-4ac3-b4ab-efde3cc5ac97
Thread-180::DEBUG::2014-04-25
19:58:18,791::taskManager::166::TaskManager::(clearTask) Return.
Thread-180::INFO::2014-04-25
19:58:18,791::logUtils::47::dispatcher::(wrapper) Run and protect:
clearTask, Return response: None
Thread-180::DEBUG::2014-04-25
19:58:18,791::task::1185::TaskManager.Task::(prepare)
Task=`bc8109f7-7ca9-4900-afc2-653120a0f0b7`::finished: None
Thread-180::DEBUG::2014-04-25
19:58:18,791::task::595::TaskManager.Task::(_updateState)
Task=`bc8109f7-7ca9-4900-afc2-653120a0f0b7`::moving from state preparing
-> state finished
Thread-180::DEBUG::2014-04-25
19:58:18,791::resourceManager::940::ResourceManager.Owner::(releaseAll)
Owner.releaseAll requests {} resources {}
Thread-180::DEBUG::2014-04-25
19:58:18,792::resourceManager::977::ResourceManager.Owner::(cancelAll)
Owner.cancelAll requests {}
Thread-180::DEBUG::2014-04-25
19:58:18,792::task::990::TaskManager.Task::(_decref)
Task=`bc8109f7-7ca9-4900-afc2-653120a0f0b7`::ref 0 aborting False
Thread-22::DEBUG::2014-04-25
19:58:24,268::fileSD::225::Storage.Misc.excCmd::(getReadDelay) '/bin/dd
iflag=direct
if=/rhev/data-center/mnt/_vdsm__store_s2data1__s2mgt__boot1/0a897f2e-1b01-4577-9f91-cd136ef4a978/dom_md/metadata
bs=4096 count=1' (cwd None)
Thread-22::DEBUG::2014-04-25
19:58:24,272::fileSD::225::Storage.Misc.excCmd::(getReadDelay) SUCCESS:
<err> = '0+1 records in\n0+1 records out\n665 bytes (665 B) copied,
0.000127032 s, 5.2 MB/s\n'; <rc> = 0
Thread-29::ERROR::2014-04-25
19:58:24,475::sdc::137::Storage.StorageDomainCache::(_findDomain)
looking for unfetched domain 9a4a80a1-5377-4a94-ade3-e58183e916ae
Thread-29::ERROR::2014-04-25
19:58:24,475::sdc::154::Storage.StorageDomainCache::(_findUnfetchedDomain)
looking for domain 9a4a80a1-5377-4a94-ade3-e58183e916ae
Thread-29::DEBUG::2014-04-25
19:58:24,475::lvm::372::OperationMutex::(_reloadvgs) Operation 'lvm
reload operation' got the operation mutex
Thread-29::DEBUG::2014-04-25
19:58:24,476::lvm::295::Storage.Misc.excCmd::(cmd) '/usr/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 obtain_device_list_from_udev=0 filter = [
\'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,lv_count,pv_count,pv_name
9a4a80a1-5377-4a94-ade3-e58183e916ae' (cwd None)
Thread-29::DEBUG::2014-04-25
19:58:24,489::lvm::295::Storage.Misc.excCmd::(cmd) FAILED: <err> = '
Volume group "9a4a80a1-5377-4a94-ade3-e58183e916ae" not found\n
Skipping volume group 9a4a80a1-5377-4a94-ade3-e58183e916ae\n'; <rc> = 5
Thread-29::WARNING::2014-04-25
19:58:24,490::lvm::377::Storage.LVM::(_reloadvgs) lvm vgs failed: 5 []
[' Volume group "9a4a80a1-5377-4a94-ade3-e58183e916ae" not found', '
Skipping volume group 9a4a80a1-5377-4a94-ade3-e58183e916ae']
Thread-29::DEBUG::2014-04-25
19:58:24,490::lvm::414::OperationMutex::(_reloadvgs) Operation 'lvm
reload operation' released the operation mutex
Thread-29::ERROR::2014-04-25
19:58:24,501::sdc::143::Storage.StorageDomainCache::(_findDomain) domain
9a4a80a1-5377-4a94-ade3-e58183e916ae not found
Traceback (most recent call last):
File "/usr/share/vdsm/storage/sdc.py", line 141, in _findDomain
dom = findMethod(sdUUID)
File "/usr/share/vdsm/storage/sdc.py", line 171, in _findUnfetchedDomain
raise se.StorageDomainDoesNotExist(sdUUID)
StorageDomainDoesNotExist: Storage domain does not exist:
('9a4a80a1-5377-4a94-ade3-e58183e916ae',)
Thread-29::ERROR::2014-04-25
19:58:24,501::domainMonitor::239::Storage.DomainMonitorThread::(_monitorDomain)
Error while collecting domain 9a4a80a1-5377-4a94-ade3-e58183e916ae
monitoring information
Traceback (most recent call last):
File "/usr/share/vdsm/storage/domainMonitor.py", line 204, in
_monitorDomain
self.domain = sdCache.produce(self.sdUUID)
File "/usr/share/vdsm/storage/sdc.py", line 98, in produce
domain.getRealDomain()
File "/usr/share/vdsm/storage/sdc.py", line 52, in getRealDomain
return self._cache._realProduce(self._sdUUID)
File "/usr/share/vdsm/storage/sdc.py", line 122, in _realProduce
domain = self._findDomain(sdUUID)
File "/usr/share/vdsm/storage/sdc.py", line 141, in _findDomain
dom = findMethod(sdUUID)
File "/usr/share/vdsm/storage/sdc.py", line 171, in _findUnfetchedDomain
raise se.StorageDomainDoesNotExist(sdUUID)
StorageDomainDoesNotExist: Storage domain does not exist:
('9a4a80a1-5377-4a94-ade3-e58183e916ae',)
Thread-27::DEBUG::2014-04-25
19:58:24,628::fileSD::225::Storage.Misc.excCmd::(getReadDelay) '/bin/dd
iflag=direct
if=/rhev/data-center/mnt/_vdsm__store_s2data1__s2mgt__app1/c2c4ade6-049e-4159-a294-a0c151f4983d/dom_md/metadata
bs=4096 count=1' (cwd None)
Thread-27::DEBUG::2014-04-25
19:58:24,633::fileSD::225::Storage.Misc.excCmd::(getReadDelay) SUCCESS:
<err> = '0+1 records in\n0+1 records out\n367 bytes (367 B) copied,
0.000137914 s, 2.7 MB/s\n'; <rc> = 0
Thread-18::DEBUG::2014-04-25
19:58:24,689::fileSD::225::Storage.Misc.excCmd::(getReadDelay) '/bin/dd
iflag=direct
if=/rhev/data-center/mnt/_vdsm__store_s2data1__s2usr__boot1/e637bb04-a8b7-4c77-809c-d58051494c52/dom_md/metadata
bs=4096 count=1' (cwd None)
Thread-18::DEBUG::2014-04-25
19:58:24,694::fileSD::225::Storage.Misc.excCmd::(getReadDelay) SUCCESS:
<err> = '0+1 records in\n0+1 records out\n369 bytes (369 B) copied,
0.000117437 s, 3.1 MB/s\n'; <rc> = 0
Thread-17::DEBUG::2014-04-25
19:58:25,365::fileSD::225::Storage.Misc.excCmd::(getReadDelay) '/bin/dd
iflag=direct
if=/rhev/data-center/mnt/bdsvn001d:_iso/7b083758-45f9-4896-913d-11fe02043e6e/dom_md/metadata
bs=4096 count=1' (cwd None)
Thread-17::DEBUG::2014-04-25
19:58:25,370::fileSD::225::Storage.Misc.excCmd::(getReadDelay) SUCCESS:
<err> = '0+1 records in\n0+1 records out\n373 bytes (373 B) copied,
0.000802138 s, 465 kB/s\n'; <rc> = 0
Thanks, Paul
