Re: [ovirt-users] Storage Domain Not Found After upgrade from 3.3.2 to 3.4

Monday, 28 April 2014

Hi Paul,

I am still looking into this log, but from a quick first assessment, it looks like (for
some reason I don't know yet...) there is a storage domain that is missing. This is
visible in the following error traceback in the vdsm log:

Thread-29::ERROR::2014-04-27
12:43:05,825::domainMonitor::239::Storage.DomainMonitorThread::(_monitorDomain) Error
while collecting domain 9a4a80a1-5377-4a94-ade3-e58183e916ae m
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',)

However, I do not see any information in the vdsm log itself about what this domain is
(yet - it may be there and I am still looking). The reason vdsm is trying to access this
storage domain (9a4a80a1-5377-4a94-ade3-e58183e916ae) is that it appears to be part of the
storage pool (datacenter) according to the pool's metadata, as seen in the following
lines from the initial connection to the datacenter, when vdsm first starts up:

Thread-13::DEBUG::2014-04-27
12:42:05,604::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,0a897ff2e-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']

Is it possible you had another domain attached to this datacenter before the upgrade that
is somehow on the root vg partitions and gets destroyed along the upgrade process, and
then reverting brings them back?

If you have this system currently back to 3.3.2 it should be up, could you run the
following commands on the ovirt-node:

vdsClient -s 0 getStorageDomainsList    <- This lists all storage domains' ids that
vdsm (the ovirt-node) can currently see (hopefully the domain in question's ID should
be listed there)

vdsClient -s 0 getStorageDomainInfo 9a4a80a1-5377-4a94-ade3-e58183e916ae  <- displays
information about the storage domain. If this succeeds we should know a bit more about the
domain

Thanks,
Gadi Ickowicz

----- Original Message -----
From: regpm(a)mccleary.me.uk
To: "Gadi Ickowicz" <gickowic(a)redhat.com&gt;, users(a)ovirt.org
Sent: Sunday, April 27, 2014 3:10:27 PM
Subject: Re: [ovirt-users] Storage Domain Not Found After upgrade from 3.3.2 to	3.4

Hi,

Yes, you're correct, Gadi.  I have a single Ovirt engine, which has two 
Datacenters; one is local storage on the Engine server and the other is 
local storage on the Ovirt Node.  I've renamed the servers in the 
attached vdsm log output (from the ovirt-node) to ovirt-engine 
(10.50.0.18) and ovirt-node (10.50.0.19).

BDS_DataCentre1 is on the ovirt-engine server and this works fine after 
the upgrade.
BDS_DataCentre2 is on the ovirt-node and this is the one that fails to 
activate due to the storage domains not being accessible.

The Master storage domain on the ovirt-node is s2data1_s2mgt_boot1. 
There are two other storage domains as well: s2data1_s2mgt_app1 and 
s2data1_s2usr_boot1.  The underlying filesystems are mounted fine, and 
as I said, if I restore the server (root vg partitions; the storage 
domain filesystems are not touched) then it works fine again.  So the 
upgrade is not playing nicely for some reason, but it's not clear to me 
from the log what the issue is.

Thanks,

Paul

On 27/04/2014 07:56, Gadi Ickowicz wrote:
...
 Hi,

 Could you please attach the vdsm log as a file (it is easier to read) for the failing
node?

 Also - I am a bit confused regarding what exactly your setup is - Do you have only a
single engine (the all-in-one) and 2 dcs, one for the all in one and one for the oVirt
node, which is the one that is failing?

 Thanks,
 Gadi Ickowicz

 ----- Original Message -----
 From: regpm(a)mccleary.me.uk
 To: users(a)ovirt.org
 Sent: Friday, April 25, 2014 10:46:35 PM
 Subject: [ovirt-users] Storage Domain Not Found After upgrade from 3.3.2 to	3.4

 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
 _______________________________________________
 Users mailing list
 Users(a)ovirt.org
 http://lists.ovirt.org/mailman/listinfo/users 

2024

2023

2022

2021

2020

2019

2018

2017

2016

2015

2014

2013

2012

2011

Re: [ovirt-users] Storage Domain Not Found After upgrade from 3.3.2 to 3.4