<div dir="ltr">Whatever it was, today it's working with ovirt-engine and vdsm from master.</div><div class="gmail_extra"><br><div class="gmail_quote">On Tue, Mar 8, 2016 at 3:18 PM, Sandro Bonazzola <span dir="ltr"><<a href="mailto:sbonazzo@redhat.com" target="_blank">sbonazzo@redhat.com</a>></span> wrote:<br><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex"><div dir="ltr"><br><div class="gmail_extra"><br><div class="gmail_quote"><span class="">On Tue, Mar 8, 2016 at 3:12 PM, Nir Soffer <span dir="ltr"><<a href="mailto:nsoffer@redhat.com" target="_blank">nsoffer@redhat.com</a>></span> wrote:<br><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left-width:1px;border-left-color:rgb(204,204,204);border-left-style:solid;padding-left:1ex">Please attach vdsm logs showing this flow.<br>
<div><div><br></div></div></blockquote><div><br></div></span><div>corresponding vdsm log:</div><div><br></div><div><div><br></div><div>jsonrpc.Executor/3::DEBUG::2016-03-08 15:04:28,449::__init__::509::jsonrpc.JsonRpcServer::(_serveRequest) Calling 'StoragePool.connectStorageServer' in bridge with {u'connectionParams': [{u'id': u'51ffb87c-c595-4792-b915-50af506dbf67', u'connection': u'mididell.home:/var/lib/exports/iso-20160308130525', u'iqn': u'', u'user': u'', u'password': '********', u'port': u''}], u'storagepoolID': u'00000000-0000-0000-0000-000000000000', u'domainType': 1}</div><div>jsonrpc.Executor/3::DEBUG::2016-03-08 15:04:28,449::task::596::Storage.TaskManager.Task::(_updateState) Task=`648c9930-4b67-4f18-aa87-4548c7fae4cb`::moving from state init -> state preparing</div><div>jsonrpc.Executor/3::INFO::2016-03-08 15:04:28,449::logUtils::49::dispatcher::(wrapper) Run and protect: connectStorageServer(domType=1, spUUID=u'00000000-0000-0000-0000-000000000000', conList=[{u'id': u'51ffb87c-c595-4792-b915-50af506dbf67', u'connection': u'mididell.home:/var/lib/exports/iso-20160308130525', u'iqn': u'', u'user': u'', u'password': '********', u'port': u''}], options=None)</div><div>jsonrpc.Executor/3::DEBUG::2016-03-08 15:04:28,451::hsm::2412::Storage.HSM::(__prefetchDomains) nfs local path: /rhev/data-center/mnt/mididell.home:_var_lib_exports_iso-20160308130525</div><div>jsonrpc.Executor/3::DEBUG::2016-03-08 15:04:28,451::hsm::2436::Storage.HSM::(__prefetchDomains) Found SD uuids: (u'bd9860d2-756b-42bd-9cf6-08c0e96d70dc',)</div><div>jsonrpc.Executor/3::DEBUG::2016-03-08 15:04:28,451::hsm::2496::Storage.HSM::(connectStorageServer) knownSDs: {bd9860d2-756b-42bd-9cf6-08c0e96d70dc: storage.nfsSD.findDomain, 8dc79844-210c-4bb1-acae-3c3e55d4fa3c: storage.localFsSD.findDomain}</div><div>jsonrpc.Executor/3::INFO::2016-03-08 15:04:28,451::logUtils::52::dispatcher::(wrapper) Run and protect: connectStorageServer, Return response: {'statuslist': [{'status': 0, 'id': u'51ffb87c-c595-4792-b915-50af506dbf67'}]}</div><div>jsonrpc.Executor/3::DEBUG::2016-03-08 15:04:28,452::task::1192::Storage.TaskManager.Task::(prepare) Task=`648c9930-4b67-4f18-aa87-4548c7fae4cb`::finished: {'statuslist': [{'status': 0, 'id': u'51ffb87c-c595-4792-b915-50af506dbf67'}]}</div><div>jsonrpc.Executor/3::DEBUG::2016-03-08 15:04:28,452::task::596::Storage.TaskManager.Task::(_updateState) Task=`648c9930-4b67-4f18-aa87-4548c7fae4cb`::moving from state preparing -> state finished</div><div>jsonrpc.Executor/3::DEBUG::2016-03-08 15:04:28,452::resourceManager::951::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}</div><div>jsonrpc.Executor/3::DEBUG::2016-03-08 15:04:28,452::resourceManager::988::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}</div><div>jsonrpc.Executor/3::DEBUG::2016-03-08 15:04:28,452::task::994::Storage.TaskManager.Task::(_decref) Task=`648c9930-4b67-4f18-aa87-4548c7fae4cb`::ref 0 aborting False</div><div>jsonrpc.Executor/3::DEBUG::2016-03-08 15:04:28,452::__init__::539::jsonrpc.JsonRpcServer::(_serveRequest) Return 'StoragePool.connectStorageServer' in bridge with [{'status': 0, 'id': u'51ffb87c-c595-4792-b915-50af506dbf67'}]</div><div>jsonrpc.Executor/4::DEBUG::2016-03-08 15:04:29,456::__init__::509::jsonrpc.JsonRpcServer::(_serveRequest) Calling 'StorageDomain.attach' in bridge with {u'storagepoolID': u'07b2decc-9d40-4df6-bfa1-0da26f95df53', u'storagedomainID': u'bd9860d2-756b-42bd-9cf6-08c0e96d70dc'}</div><div>jsonrpc.Executor/4::DEBUG::2016-03-08 15:04:29,456::task::596::Storage.TaskManager.Task::(_updateState) Task=`c24beaf3-733e-45b2-9c0b-31dce0e7d4a8`::moving from state init -> state preparing</div><div>jsonrpc.Executor/4::INFO::2016-03-08 15:04:29,456::logUtils::49::dispatcher::(wrapper) Run and protect: attachStorageDomain(sdUUID=u'bd9860d2-756b-42bd-9cf6-08c0e96d70dc', spUUID=u'07b2decc-9d40-4df6-bfa1-0da26f95df53', options=None)</div><div>jsonrpc.Executor/4::DEBUG::2016-03-08 15:04:29,457::resourceManager::200::Storage.ResourceManager.Request::(__init__) ResName=`Storage.07b2decc-9d40-4df6-bfa1-0da26f95df53`ReqID=`0c01819d-8d3f-400b-a798-660babb497df`::Request was made in '/usr/share/vdsm/storage/hsm.py' line '1208' at 'attachStorageDomain'</div><div>jsonrpc.Executor/4::DEBUG::2016-03-08 15:04:29,457::resourceManager::553::Storage.ResourceManager::(registerResource) Trying to register resource 'Storage.07b2decc-9d40-4df6-bfa1-0da26f95df53' for lock type 'exclusive'</div><div>jsonrpc.Executor/4::DEBUG::2016-03-08 15:04:29,457::resourceManager::612::Storage.ResourceManager::(registerResource) Resource 'Storage.07b2decc-9d40-4df6-bfa1-0da26f95df53' is free. Now locking as 'exclusive' (1 active user)</div><div>jsonrpc.Executor/4::DEBUG::2016-03-08 15:04:29,457::resourceManager::240::Storage.ResourceManager.Request::(grant) ResName=`Storage.07b2decc-9d40-4df6-bfa1-0da26f95df53`ReqID=`0c01819d-8d3f-400b-a798-660babb497df`::Granted request</div><div>jsonrpc.Executor/4::DEBUG::2016-03-08 15:04:29,457::task::828::Storage.TaskManager.Task::(resourceAcquired) Task=`c24beaf3-733e-45b2-9c0b-31dce0e7d4a8`::_resourcesAcquired: Storage.07b2decc-9d40-4df6-bfa1-0da26f95df53 (exclusive)</div><div>jsonrpc.Executor/4::DEBUG::2016-03-08 15:04:29,457::task::994::Storage.TaskManager.Task::(_decref) Task=`c24beaf3-733e-45b2-9c0b-31dce0e7d4a8`::ref 1 aborting False</div><div>jsonrpc.Executor/4::DEBUG::2016-03-08 15:04:29,457::resourceManager::200::Storage.ResourceManager.Request::(__init__) ResName=`Storage.bd9860d2-756b-42bd-9cf6-08c0e96d70dc`ReqID=`46ee6ea9-6dd4-4823-b894-dfd971c748ce`::Request was made in '/usr/share/vdsm/storage/hsm.py' line '1209' at 'attachStorageDomain'</div><div>jsonrpc.Executor/4::DEBUG::2016-03-08 15:04:29,457::resourceManager::553::Storage.ResourceManager::(registerResource) Trying to register resource 'Storage.bd9860d2-756b-42bd-9cf6-08c0e96d70dc' for lock type 'exclusive'</div><div>jsonrpc.Executor/4::DEBUG::2016-03-08 15:04:29,457::resourceManager::612::Storage.ResourceManager::(registerResource) Resource 'Storage.bd9860d2-756b-42bd-9cf6-08c0e96d70dc' is free. Now locking as 'exclusive' (1 active user)</div><div>jsonrpc.Executor/4::DEBUG::2016-03-08 15:04:29,457::resourceManager::240::Storage.ResourceManager.Request::(grant) ResName=`Storage.bd9860d2-756b-42bd-9cf6-08c0e96d70dc`ReqID=`46ee6ea9-6dd4-4823-b894-dfd971c748ce`::Granted request</div><div>jsonrpc.Executor/4::DEBUG::2016-03-08 15:04:29,457::task::828::Storage.TaskManager.Task::(resourceAcquired) Task=`c24beaf3-733e-45b2-9c0b-31dce0e7d4a8`::_resourcesAcquired: Storage.bd9860d2-756b-42bd-9cf6-08c0e96d70dc (exclusive)</div><div>jsonrpc.Executor/4::DEBUG::2016-03-08 15:04:29,458::task::994::Storage.TaskManager.Task::(_decref) Task=`c24beaf3-733e-45b2-9c0b-31dce0e7d4a8`::ref 1 aborting False</div><div>jsonrpc.Executor/4::INFO::2016-03-08 15:04:29,458::sp::921::Storage.StoragePool::(attachSD) sdUUID=bd9860d2-756b-42bd-9cf6-08c0e96d70dc spUUID=07b2decc-9d40-4df6-bfa1-0da26f95df53</div><div>jsonrpc.Executor/4::DEBUG::2016-03-08 15:04:29,458::misc::700::Storage.SamplingMethod::(__call__) Trying to enter sampling method (storage.sdc.refreshStorage)</div><div>jsonrpc.Executor/4::DEBUG::2016-03-08 15:04:29,458::misc::703::Storage.SamplingMethod::(__call__) Got in to sampling method</div><div>jsonrpc.Executor/4::DEBUG::2016-03-08 15:04:29,458::misc::700::Storage.SamplingMethod::(__call__) Trying to enter sampling method (storage.iscsi.rescan)</div><div>jsonrpc.Executor/4::DEBUG::2016-03-08 15:04:29,458::misc::703::Storage.SamplingMethod::(__call__) Got in to sampling method</div><div>jsonrpc.Executor/4::DEBUG::2016-03-08 15:04:29,458::iscsi::434::Storage.ISCSI::(rescan) Performing SCSI scan, this will take up to 30 seconds</div><div>jsonrpc.Executor/4::DEBUG::2016-03-08 15:04:29,458::iscsiadm::97::Storage.Misc.excCmd::(_runCmd) /usr/bin/taskset --cpu-list 0-7 /usr/bin/sudo -n /usr/sbin/iscsiadm -m session -R (cwd None)</div><div>jsonrpc.Executor/4::DEBUG::2016-03-08 15:04:29,467::misc::710::Storage.SamplingMethod::(__call__) Returning last result</div><div>jsonrpc.Executor/4::DEBUG::2016-03-08 15:04:29,467::misc::700::Storage.SamplingMethod::(__call__) Trying to enter sampling method (storage.hba.rescan)</div><div>jsonrpc.Executor/4::DEBUG::2016-03-08 15:04:29,467::misc::703::Storage.SamplingMethod::(__call__) Got in to sampling method</div><div>jsonrpc.Executor/4::DEBUG::2016-03-08 15:04:29,467::hba::56::Storage.HBA::(rescan) Starting scan</div><div>jsonrpc.Executor/4::DEBUG::2016-03-08 15:04:29,493::hba::62::Storage.HBA::(rescan) Scan finished</div><div>jsonrpc.Executor/4::DEBUG::2016-03-08 15:04:29,493::misc::710::Storage.SamplingMethod::(__call__) Returning last result</div><div>jsonrpc.Executor/4::DEBUG::2016-03-08 15:04:29,493::multipath::78::Storage.Misc.excCmd::(rescan) /usr/bin/taskset --cpu-list 0-7 /usr/bin/sudo -n /usr/sbin/multipath (cwd None)</div><div>jsonrpc.Executor/4::DEBUG::2016-03-08 15:04:29,532::multipath::78::Storage.Misc.excCmd::(rescan) SUCCESS: <err> = ''; <rc> = 0</div><div>jsonrpc.Executor/4::DEBUG::2016-03-08 15:04:29,532::commands::70::root::(execCmd) /usr/bin/taskset --cpu-list 0-7 /sbin/udevadm settle --timeout=5 (cwd None)</div><div>jsonrpc.Executor/4::DEBUG::2016-03-08 15:04:29,540::commands::88::root::(execCmd) SUCCESS: <err> = ''; <rc> = 0</div><div>jsonrpc.Executor/4::DEBUG::2016-03-08 15:04:29,541::lvm::497::Storage.OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' got the operation mutex</div><div>jsonrpc.Executor/4::DEBUG::2016-03-08 15:04:29,541::lvm::499::Storage.OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' released the operation mutex</div><div>jsonrpc.Executor/4::DEBUG::2016-03-08 15:04:29,541::lvm::508::Storage.OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' got the operation mutex</div><div>jsonrpc.Executor/4::DEBUG::2016-03-08 15:04:29,541::lvm::510::Storage.OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' released the operation mutex</div><div>jsonrpc.Executor/4::DEBUG::2016-03-08 15:04:29,541::lvm::528::Storage.OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' got the operation mutex</div><div>jsonrpc.Executor/4::DEBUG::2016-03-08 15:04:29,541::lvm::530::Storage.OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' released the operation mutex</div><div>jsonrpc.Executor/4::DEBUG::2016-03-08 15:04:29,541::misc::710::Storage.SamplingMethod::(__call__) Returning last result</div><div>jsonrpc.Executor/4::DEBUG::2016-03-08 15:04:29,544::fileSD::159::Storage.StorageDomainManifest::(__init__) Reading domain in path /rhev/data-center/mnt/mididell.home:_var_lib_exports_iso-20160308130525/bd9860d2-756b-42bd-9cf6-08c0e96d70dc</div><div>jsonrpc.Executor/4::DEBUG::2016-03-08 15:04:29,544::persistentDict::192::Storage.PersistentDict::(__init__) Created a persistent dict with FileMetadataRW backend</div><div>jsonrpc.Executor/4::DEBUG::2016-03-08 15:04:29,545::persistentDict::234::Storage.PersistentDict::(refresh) read lines (FileMetadataRW)=[]</div><div>jsonrpc.Executor/4::DEBUG::2016-03-08 15:04:29,545::persistentDict::252::Storage.PersistentDict::(refresh) Empty metadata</div><div>jsonrpc.Executor/4::ERROR::2016-03-08 15:04:29,545::task::867::Storage.TaskManager.Task::(_setError) Task=`c24beaf3-733e-45b2-9c0b-31dce0e7d4a8`::Unexpected error</div><div>Traceback (most recent call last):</div><div> File "/usr/share/vdsm/storage/task.py", line 874, in _run</div><div> return fn(*args, **kargs)</div><div> File "/usr/lib/python2.7/site-packages/vdsm/logUtils.py", line 50, in wrapper</div><div> res = f(*args, **kwargs)</div><div> File "/usr/share/vdsm/storage/hsm.py", line 1211, in attachStorageDomain</div><div> pool.attachSD(sdUUID)</div><div> File "/usr/share/vdsm/storage/securable.py", line 77, in wrapper</div><div> return method(self, *args, **kwargs)</div><div> File "/usr/share/vdsm/storage/sp.py", line 928, in attachSD</div><div> dom = sdCache.produce(sdUUID)</div><div> File "/usr/share/vdsm/storage/sdc.py", line 100, in produce</div><div> domain.getRealDomain()</div><div> File "/usr/share/vdsm/storage/sdc.py", line 52, in getRealDomain</div><div> return self._cache._realProduce(self._sdUUID)</div><div> File "/usr/share/vdsm/storage/sdc.py", line 124, in _realProduce</div><div> domain = self._findDomain(sdUUID)</div><div> File "/usr/share/vdsm/storage/sdc.py", line 143, in _findDomain</div><div> dom = findMethod(sdUUID)</div><div> File "/usr/share/vdsm/storage/nfsSD.py", line 122, in findDomain</div><div> return NfsStorageDomain(NfsStorageDomain.findDomainPath(sdUUID))</div><div> File "/usr/share/vdsm/storage/fileSD.py", line 330, in __init__</div><div> manifest = self.manifestClass(domainPath)</div><div> File "/usr/share/vdsm/storage/fileSD.py", line 168, in __init__</div><div> sd.StorageDomainManifest.__init__(self, sdUUID, domaindir, metadata)</div><div> File "/usr/share/vdsm/storage/sd.py", line 310, in __init__</div><div> self._domainLock = self._makeDomainLock()</div><div> File "/usr/share/vdsm/storage/sd.py", line 439, in _makeDomainLock</div><div> domVersion = self.getVersion()</div><div> File "/usr/share/vdsm/storage/sd.py", line 359, in getVersion</div><div> return self.getMetaParam(DMDK_VERSION)</div><div> File "/usr/share/vdsm/storage/sd.py", line 356, in getMetaParam</div><div> return self._metadata[key]</div><div> File "/usr/share/vdsm/storage/persistentDict.py", line 89, in __getitem__</div><div> return dec(self._dict[key])</div><div> File "/usr/share/vdsm/storage/persistentDict.py", line 201, in __getitem__</div><div> raise KeyError(key)</div><div>KeyError: 'VERSION'</div><div>jsonrpc.Executor/4::DEBUG::2016-03-08 15:04:29,545::task::886::Storage.TaskManager.Task::(_run) Task=`c24beaf3-733e-45b2-9c0b-31dce0e7d4a8`::Task._run: c24beaf3-733e-45b2-9c0b-31dce0e7d4a8 (u'bd9860d2-756b-42bd-9cf6-08c0e96d70dc', u'07b2decc-9d40-4df6-bfa1-0da26f95df53') {} failed - stopping task</div><div>jsonrpc.Executor/4::DEBUG::2016-03-08 15:04:29,545::task::1247::Storage.TaskManager.Task::(stop) Task=`c24beaf3-733e-45b2-9c0b-31dce0e7d4a8`::stopping in state preparing (force False)</div><div>jsonrpc.Executor/4::DEBUG::2016-03-08 15:04:29,545::task::994::Storage.TaskManager.Task::(_decref) Task=`c24beaf3-733e-45b2-9c0b-31dce0e7d4a8`::ref 1 aborting True</div><div>jsonrpc.Executor/4::INFO::2016-03-08 15:04:29,545::task::1172::Storage.TaskManager.Task::(prepare) Task=`c24beaf3-733e-45b2-9c0b-31dce0e7d4a8`::aborting: Task is aborted: u"'VERSION'" - code 100</div><div>jsonrpc.Executor/4::DEBUG::2016-03-08 15:04:29,545::task::1177::Storage.TaskManager.Task::(prepare) Task=`c24beaf3-733e-45b2-9c0b-31dce0e7d4a8`::Prepare: aborted: 'VERSION'</div><div>jsonrpc.Executor/4::DEBUG::2016-03-08 15:04:29,546::task::994::Storage.TaskManager.Task::(_decref) Task=`c24beaf3-733e-45b2-9c0b-31dce0e7d4a8`::ref 0 aborting True</div><div>jsonrpc.Executor/4::DEBUG::2016-03-08 15:04:29,546::task::929::Storage.TaskManager.Task::(_doAbort) Task=`c24beaf3-733e-45b2-9c0b-31dce0e7d4a8`::Task._doAbort: force False</div><div>jsonrpc.Executor/4::DEBUG::2016-03-08 15:04:29,546::resourceManager::988::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}</div><div>jsonrpc.Executor/4::DEBUG::2016-03-08 15:04:29,546::task::596::Storage.TaskManager.Task::(_updateState) Task=`c24beaf3-733e-45b2-9c0b-31dce0e7d4a8`::moving from state preparing -> state aborting</div><div>jsonrpc.Executor/4::DEBUG::2016-03-08 15:04:29,546::task::551::Storage.TaskManager.Task::(__state_aborting) Task=`c24beaf3-733e-45b2-9c0b-31dce0e7d4a8`::_aborting: recover policy none</div><div>jsonrpc.Executor/4::DEBUG::2016-03-08 15:04:29,546::task::596::Storage.TaskManager.Task::(_updateState) Task=`c24beaf3-733e-45b2-9c0b-31dce0e7d4a8`::moving from state aborting -> state failed</div><div>jsonrpc.Executor/4::DEBUG::2016-03-08 15:04:29,546::resourceManager::951::Storage.ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {u'Storage.07b2decc-9d40-4df6-bfa1-0da26f95df53': < ResourceRef 'Storage.07b2decc-9d40-4df6-bfa1-0da26f95df53', isValid: 'True' obj: 'None'>, u'Storage.bd9860d2-756b-42bd-9cf6-08c0e96d70dc': < ResourceRef 'Storage.bd9860d2-756b-42bd-9cf6-08c0e96d70dc', isValid: 'True' obj: 'None'>}</div><div>jsonrpc.Executor/4::DEBUG::2016-03-08 15:04:29,546::resourceManager::988::Storage.ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}</div><div>jsonrpc.Executor/4::DEBUG::2016-03-08 15:04:29,546::resourceManager::627::Storage.ResourceManager::(releaseResource) Trying to release resource 'Storage.07b2decc-9d40-4df6-bfa1-0da26f95df53'</div><div>jsonrpc.Executor/4::DEBUG::2016-03-08 15:04:29,546::resourceManager::646::Storage.ResourceManager::(releaseResource) Released resource 'Storage.07b2decc-9d40-4df6-bfa1-0da26f95df53' (0 active users)</div><div>jsonrpc.Executor/4::DEBUG::2016-03-08 15:04:29,546::resourceManager::652::Storage.ResourceManager::(releaseResource) Resource 'Storage.07b2decc-9d40-4df6-bfa1-0da26f95df53' is free, finding out if anyone is waiting for it.</div><div>jsonrpc.Executor/4::DEBUG::2016-03-08 15:04:29,546::resourceManager::660::Storage.ResourceManager::(releaseResource) No one is waiting for resource 'Storage.07b2decc-9d40-4df6-bfa1-0da26f95df53', Clearing records.</div><div>jsonrpc.Executor/4::DEBUG::2016-03-08 15:04:29,546::resourceManager::627::Storage.ResourceManager::(releaseResource) Trying to release resource 'Storage.bd9860d2-756b-42bd-9cf6-08c0e96d70dc'</div><div>jsonrpc.Executor/4::DEBUG::2016-03-08 15:04:29,546::resourceManager::646::Storage.ResourceManager::(releaseResource) Released resource 'Storage.bd9860d2-756b-42bd-9cf6-08c0e96d70dc' (0 active users)</div><div>jsonrpc.Executor/4::DEBUG::2016-03-08 15:04:29,546::resourceManager::652::Storage.ResourceManager::(releaseResource) Resource 'Storage.bd9860d2-756b-42bd-9cf6-08c0e96d70dc' is free, finding out if anyone is waiting for it.</div><div>jsonrpc.Executor/4::DEBUG::2016-03-08 15:04:29,546::resourceManager::660::Storage.ResourceManager::(releaseResource) No one is waiting for resource 'Storage.bd9860d2-756b-42bd-9cf6-08c0e96d70dc', Clearing records.</div><div>jsonrpc.Executor/4::ERROR::2016-03-08 15:04:29,547::dispatcher::79::Storage.Dispatcher::(wrapper) 'VERSION'</div><div>Traceback (most recent call last):</div><div> File "/usr/share/vdsm/storage/dispatcher.py", line 71, in wrapper</div><div> result = ctask.prepare(func, *args, **kwargs)</div><div> File "/usr/share/vdsm/storage/task.py", line 105, in wrapper</div><div> return m(self, *a, **kw)</div><div> File "/usr/share/vdsm/storage/task.py", line 1180, in prepare</div><div> raise self.error</div><div>KeyError: 'VERSION'</div><div>Thread-41::DEBUG::2016-03-08 15:04:30,110::fileSD::174::Storage.Misc.excCmd::(getReadDelay) /usr/bin/taskset --cpu-list 0-7 /usr/bin/dd if=/rhev/data-center/mnt/_var_lib_images-20160308135819/8dc79844-210c-4bb1-acae-3c3e55d4fa3c/dom_md/metadata iflag=direct of=/dev/null bs=4096 count=1 (cwd None)</div><div>Thread-41::DEBUG::2016-03-08 15:04:30,114::fileSD::174::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n484 bytes (484 B) copied, 0.000216157 s, 2.2 MB/s\n'; <rc> = 0</div><div>jsonrpc.Executor/6::DEBUG::2016-03-08 15:04:37,311::__init__::509::jsonrpc.JsonRpcServer::(_serveRequest) Calling 'StoragePool.getSpmStatus' in bridge with {u'storagepoolID': u'07b2decc-9d40-4df6-bfa1-0da26f95df53'}</div></div><div><div class="h5"><div><br></div><div><br></div><div><br></div><div><br></div><div><br></div><div><br></div><div><br></div><div><br></div><div> </div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left-width:1px;border-left-color:rgb(204,204,204);border-left-style:solid;padding-left:1ex"><div><div>
On Tue, Mar 8, 2016 at 4:07 PM, Sandro Bonazzola <<a href="mailto:sbonazzo@redhat.com" target="_blank">sbonazzo@redhat.com</a>> wrote:<br>
> Hi, trying to attach an iso domain to engine master:<br>
><br>
> 2016-03-08 15:04:28,386 INFO<br>
> [org.ovirt.engine.core.bll.storage.domain.AttachStorageDomainToPoolCommand]<br>
> (default task-50) [477da39f] Lock Acquired to object<br>
> 'EngineLock:{exclusiveLocks='[bd9860d2-756b-42bd-9cf<br>
> 6-08c0e96d70dc=<STORAGE, ACTION_TYPE_FAILED_OBJECT_LOCKED>]',<br>
> sharedLocks='null'}'<br>
> 2016-03-08 15:04:28,433 INFO<br>
> [org.ovirt.engine.core.bll.storage.domain.AttachStorageDomainToPoolCommand]<br>
> (org.ovirt.thread.pool-10-thread-42) [477da39f] Running command:<br>
> AttachStorageDomainToPoolCommand interna<br>
> l: false. Entities affected : ID: bd9860d2-756b-42bd-9cf6-08c0e96d70dc<br>
> Type: StorageAction group MANIPULATE_STORAGE_DOMAIN with role type ADMIN,<br>
> ID: 07b2decc-9d40-4df6-bfa1-0da26f95df53 Type: StoragePoolAction<br>
> group MANIPULATE_STORAGE_DOMAIN with role type ADMIN<br>
> 2016-03-08 15:04:28,445 INFO<br>
> [org.ovirt.engine.core.bll.storage.connection.ConnectStorageToVdsCommand]<br>
> (org.ovirt.thread.pool-10-thread-43) [72ff69e2] Running command:<br>
> ConnectStorageToVdsCommand internal: true.<br>
> Entities affected : ID: aaa00000-0000-0000-0000-123456789aaa Type:<br>
> SystemAction group CREATE_STORAGE_DOMAIN with role type ADMIN<br>
> 2016-03-08 15:04:28,447 INFO<br>
> [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand]<br>
> (org.ovirt.thread.pool-10-thread-43) [72ff69e2] START,<br>
> ConnectStorageServerVDSCommand(HostName = local_hos<br>
> t, StorageServerConnectionManagementVDSParameters:{runAsync='true',<br>
> hostId='384c1ab4-e03b-46ff-8e32-8a8b3650235b',<br>
> storagePoolId='00000000-0000-0000-0000-000000000000', storageType='NFS',<br>
> connectionList='[Storag<br>
> eServerConnections:{id='51ffb87c-c595-4792-b915-50af506dbf67',<br>
> connection='mididell.home:/var/lib/exports/iso-20160308130525', iqn='null',<br>
> vfsType='null', mountOptions='null', nfsVersion='null', nfsRetrans='null<br>
> ', nfsTimeo='null', iface='null', netIfaceName='null'}]'}), log id: 2e547cc1<br>
> 2016-03-08 15:04:29,454 INFO<br>
> [org.ovirt.engine.core.vdsbroker.vdsbroker.ConnectStorageServerVDSCommand]<br>
> (org.ovirt.thread.pool-10-thread-43) [72ff69e2] FINISH,<br>
> ConnectStorageServerVDSCommand, return: {51ffb87c-<br>
> c595-4792-b915-50af506dbf67=0}, log id: 2e547cc1<br>
> 2016-03-08 15:04:29,455 INFO<br>
> [org.ovirt.engine.core.vdsbroker.irsbroker.AttachStorageDomainVDSCommand]<br>
> (org.ovirt.thread.pool-10-thread-42) [477da39f] START,<br>
> AttachStorageDomainVDSCommand( AttachStorageDomainVD<br>
> SCommandParameters:{runAsync='true',<br>
> storagePoolId='07b2decc-9d40-4df6-bfa1-0da26f95df53',<br>
> ignoreFailoverLimit='false',<br>
> storageDomainId='bd9860d2-756b-42bd-9cf6-08c0e96d70dc'}), log id: 5bc96473<br>
> 2016-03-08 15:04:30,549 ERROR<br>
> [org.ovirt.engine.core.vdsbroker.irsbroker.AttachStorageDomainVDSCommand]<br>
> (org.ovirt.thread.pool-10-thread-42) [477da39f] Failed in<br>
> 'AttachStorageDomainVDS' method<br>
> 2016-03-08 15:04:30,558 ERROR<br>
> [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]<br>
> (org.ovirt.thread.pool-10-thread-42) [477da39f] Correlation ID: null, Call<br>
> Stack: null, Custom Event ID: -1, M<br>
> essage: VDSM command failed: Error in storage domain action:<br>
> (u'sdUUID=bd9860d2-756b-42bd-9cf6-08c0e96d70dc,<br>
> spUUID=07b2decc-9d40-4df6-bfa1-0da26f95df53',)<br>
> 2016-03-08 15:04:30,558 ERROR<br>
> [org.ovirt.engine.core.vdsbroker.irsbroker.AttachStorageDomainVDSCommand]<br>
> (org.ovirt.thread.pool-10-thread-42) [477da39f] Command<br>
> 'AttachStorageDomainVDSCommand( AttachStorageDomain<br>
> VDSCommandParameters:{runAsync='true',<br>
> storagePoolId='07b2decc-9d40-4df6-bfa1-0da26f95df53',<br>
> ignoreFailoverLimit='false',<br>
> storageDomainId='bd9860d2-756b-42bd-9cf6-08c0e96d70dc'})' execution failed:<br>
> IRSGenericExc<br>
> eption: IRSErrorException: Failed to AttachStorageDomainVDS, error = Error<br>
> in storage domain action: (u'sdUUID=bd9860d2-756b-42bd-9cf6-08c0e96d70dc,<br>
> spUUID=07b2decc-9d40-4df6-bfa1-0da26f95df53',), code = 350<br>
> 2016-03-08 15:04:30,558 INFO<br>
> [org.ovirt.engine.core.vdsbroker.irsbroker.AttachStorageDomainVDSCommand]<br>
> (org.ovirt.thread.pool-10-thread-42) [477da39f] FINISH,<br>
> AttachStorageDomainVDSCommand, log id: 5bc96473<br>
> 2016-03-08 15:04:30,558 ERROR<br>
> [org.ovirt.engine.core.bll.storage.domain.AttachStorageDomainToPoolCommand]<br>
> (org.ovirt.thread.pool-10-thread-42) [477da39f] Command<br>
> 'org.ovirt.engine.core.bll.storage.domain.AttachS<br>
> torageDomainToPoolCommand' failed: EngineException:<br>
> org.ovirt.engine.core.vdsbroker.irsbroker.IrsOperationFailedNoFailoverException:<br>
> IRSGenericException: IRSErrorException: Failed to AttachStorageDomainVDS,<br>
> erro<br>
> r = Error in storage domain action:<br>
> (u'sdUUID=bd9860d2-756b-42bd-9cf6-08c0e96d70dc,<br>
> spUUID=07b2decc-9d40-4df6-bfa1-0da26f95df53',), code = 350 (Failed with<br>
> error StorageDomainActionError and code 350)<br>
> 2016-03-08 15:04:30,559 INFO<br>
> [org.ovirt.engine.core.bll.storage.domain.AttachStorageDomainToPoolCommand]<br>
> (org.ovirt.thread.pool-10-thread-42) [477da39f] Command<br>
> [id=6426d8ba-223f-401d-8fed-c537620bd4c3]: Compensating NEW_ENTITY_ID of<br>
> org.ovirt.engine.core.common.businessentities.StoragePoolIsoMap; snapshot:<br>
> StoragePoolIsoMapId:{storagePoolId='07b2decc-9d40-4df6-bfa1-0da26f95df53',<br>
> storageId='bd9860d2-756b-42bd-9cf6-08c0e96d70dc'}.<br>
> 2016-03-08 15:04:30,575 ERROR<br>
> [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]<br>
> (org.ovirt.thread.pool-10-thread-42) [477da39f] Correlation ID: 477da39f,<br>
> Job ID: 13fbe031-0c58-4fff-bc38-324cce2e4c3f, Call Stack: null, Custom Event<br>
> ID: -1, Message: Failed to attach Storage Domain ISO_DOMAIN to Data Center<br>
> local_datacenter. (User: admin@internal)<br>
> 2016-03-08 15:04:30,584 INFO<br>
> [org.ovirt.engine.core.bll.storage.domain.AttachStorageDomainToPoolCommand]<br>
> (org.ovirt.thread.pool-10-thread-42) [477da39f] Lock freed to object<br>
> 'EngineLock:{exclusiveLocks='[bd9860d2-756b-42bd-9cf6-08c0e96d70dc=<STORAGE,<br>
> ACTION_TYPE_FAILED_OBJECT_LOCKED>]', sharedLocks='null'}'<br>
><br>
> Any hint on what can be the reason?<br>
><br>
> # rpm -qv ovirt-engine<br>
> ovirt-engine-4.0.0-0.0.master.20160307171512.git398703d.el7.centos.noarch<br>
><br>
> --<br>
> Sandro Bonazzola<br>
> Better technology. Faster innovation. Powered by community collaboration.<br>
> See how it works at <a href="http://redhat.com" rel="noreferrer" target="_blank">redhat.com</a><br>
><br>
</div></div>> _______________________________________________<br>
> Devel mailing list<br>
> <a href="mailto:Devel@ovirt.org" target="_blank">Devel@ovirt.org</a><br>
> <a href="http://lists.ovirt.org/mailman/listinfo/devel" rel="noreferrer" target="_blank">http://lists.ovirt.org/mailman/listinfo/devel</a><br>
</blockquote></div></div></div><div><div class="h5"><br><br clear="all"><div><br></div>-- <br><div><div dir="ltr"><div><div dir="ltr">Sandro Bonazzola<br>Better technology. Faster innovation. Powered by community collaboration.<br>See how it works at <a href="http://redhat.com" target="_blank">redhat.com</a><br></div></div></div></div>
</div></div></div></div>
</blockquote></div><br><br clear="all"><div><br></div>-- <br><div class="gmail_signature"><div dir="ltr"><div><div dir="ltr">Sandro Bonazzola<br>Better technology. Faster innovation. Powered by community collaboration.<br>See how it works at <a href="http://redhat.com" target="_blank">redhat.com</a><br></div></div></div></div>
</div>