Bug 920220
| Summary: | [backend] SpmStopVDSCommand didn't stop SPM in VDSM | ||||||
|---|---|---|---|---|---|---|---|
| Product: | Red Hat Enterprise Virtualization Manager | Reporter: | Jakub Libosvar <jlibosva> | ||||
| Component: | ovirt-engine | Assignee: | Liron Aravot <laravot> | ||||
| Status: | CLOSED DUPLICATE | QA Contact: | Jakub Libosvar <jlibosva> | ||||
| Severity: | high | Docs Contact: | |||||
| Priority: | unspecified | ||||||
| Version: | 3.2.0 | CC: | acathrow, amureini, dyasny, hateya, iheim, lpeer, Rhev-m-bugs, yeylon, ykaul | ||||
| Target Milestone: | --- | ||||||
| Target Release: | 3.2.0 | ||||||
| Hardware: | All | ||||||
| OS: | Linux | ||||||
| Whiteboard: | storage | ||||||
| Fixed In Version: | Doc Type: | Bug Fix | |||||
| Doc Text: | Story Points: | --- | |||||
| Clone Of: | Environment: | ||||||
| Last Closed: | 2013-03-13 14:06:03 UTC | Type: | Bug | ||||
| Regression: | --- | Mount Type: | --- | ||||
| Documentation: | --- | CRM: | |||||
| Verified Versions: | Category: | --- | |||||
| oVirt Team: | Storage | RHEL 7.3 requirements from Atomic Host: | |||||
| Cloudforms Team: | --- | Target Upstream Version: | |||||
| Embargoed: | |||||||
| Attachments: |
|
||||||
Liron, we need to understand why spmStop wasn't sent to vdsm. seems like spmStop wasn't sent because there were tasks
Thread-2184::DEBUG::2013-03-11 16:45:32,887::task::1151::TaskManager.Task::(prepare) Task=`fda2214f-30ed-480c-be23-e93cc2a03f95`::finished: {'allTasksStatus': {'fa917046-91b
7-49c3-93ca-825dafcf4473': {'code': 0, 'message': u'1 jobs completed successfully', 'taskState': 'finished', 'taskResult': 'success', 'taskID': 'fa917046-91b7-49c3-93ca-825d
afcf4473'}}}
Thread-2184::DEBUG::2013-03-11 16:45:32,887::task::568::TaskManager.Task::(_updateState) Task=`fda2214f-30ed-480c-be23-e93cc2a03f95`::moving from state preparing -> state fi
nished
Thread-2184::DEBUG::2013-03-11 16:45:32,888::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-2184::DEBUG::2013-03-11 16:45:32,888::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-2184::DEBUG::2013-03-11 16:45:32,888::task::957::TaskManager.Task::(_decref) Task=`fda2214f-30ed-480c-be23-e93cc2a03f95`::ref 0 aborting False
Thread-2185::DEBUG::2013-03-11 16:45:32,929::BindingXMLRPC::161::vds::(wrapper) [10.35.161.50]
Thread-2185::DEBUG::2013-03-11 16:45:33,023::task::568::TaskManager.Task::(_updateState) Task=`6bbd02fa-8b9f-458f-9f25-c20402941f19`::moving from state init -> state prepari
ng
Thread-2185::INFO::2013-03-11 16:45:33,023::logUtils::37::dispatcher::(wrapper) Run and protect: disconnectStoragePool(spUUID='6969f79a-8f74-415c-b2f7-784d050df2f1', hostID=
1, scsiKey='6969f79a-8f74-415c-b2f7-784d050df2f1', remove=False, options=None)
Thread-2185::ERROR::2013-03-11 16:45:33,023::task::833::TaskManager.Task::(_setError) Task=`6bbd02fa-8b9f-458f-9f25-c20402941f19`::Unexpected error
Traceback (most recent call last):
File "/usr/share/vdsm/storage/task.py", line 840, in _run
return fn(*args, **kargs)
File "/usr/share/vdsm/logUtils.py", line 38, in wrapper
res = f(*args, **kwargs)
File "/usr/share/vdsm/storage/hsm.py", line 1011, in disconnectStoragePool
self.validateNotSPM(spUUID)
File "/usr/share/vdsm/storage/hsm.py", line 308, in validateNotSPM
raise se.IsSpm(spUUID)
IsSpm: Operation not allowed while SPM is active: ('6969f79a-8f74-415c-b2f7-784d050df2f1',)
Thread-2185::DEBUG::2013-03-11 16:45:33,024::task::852::TaskManager.Task::(_run) Task=`6bbd02fa-8b9f-458f-9f25-c20402941f19`::Task._run: 6bbd02fa-8b9f-458f-9f25-c20402941f19
('6969f79a-8f74-415c-b2f7-784d050df2f1', 1, '6969f79a-8f74-415c-b2f7-784d050df2f1', False) {} failed - stopping task
Thread-2185::DEBUG::2013-03-11 16:45:33,024::task::1177::TaskManager.Task::(stop) Task=`6bbd02fa-8b9f-458f-9f25-c20402941f19`::stopping in state preparing (force False)
Jakub, can you try again?
The cause is same as in bug 918588. *** This bug has been marked as a duplicate of bug 918588 *** |
Created attachment 708470 [details] logs Description of problem: There was one storage domain in DC, one host. Deactivate domain was called but failed with Operation not allowed while SPM is active Cause is that there was no spmStop in vdsm before disconnectStoragePool Engine: 2013-03-11 16:45:32,723 INFO [org.ovirt.engine.core.bll.storage.DeactivateStorageDomainCommand] (ajp-/127.0.0.1:8702-6) [5c1908b6] Lock Acquired to object EngineLock [exclusiveLocks= key: 6969f79a-8f74-415c-b2f7-784d050df2f1 value: POOL key: 469060ca-251e-4b92-932e-5efc1e55e6ad value: STORAGE , sharedLocks= ] 2013-03-11 16:45:32,758 INFO [org.ovirt.engine.core.bll.storage.DeactivateStorageDomainCommand] (ajp-/127.0.0.1:8702-6) [5c1908b6] Running command: DeactivateStorageDomainCommand internal: false. Entities affected : ID: 469060ca-251e-4b92-932e-5efc1e55e6ad Type: Storage 2013-03-11 16:45:32,803 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.DeactivateStorageDomainVDSCommand] (ajp-/127.0.0.1:8702-6) [5c1908b6] START, DeactivateStorageDomainVDSCommand( storagePoolId = 6969f79a-8f74-415c-b2f7-784d050df2f1, ignoreFailoverLimit = false, compatabilityVersion = null, storageDomainId = 469060ca-251e-4b92-932e-5efc1e55e6ad, masterDomainId = 00000000-0000-0000-0000-000000000000, masterVersion = 1), log id: 789c60f6 2013-03-11 16:45:32,844 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.DeactivateStorageDomainVDSCommand] (ajp-/127.0.0.1:8702-6) [5c1908b6] FINISH, DeactivateStorageDomainVDSCommand, log id: 789c60f6 2013-03-11 16:45:32,845 INFO [org.ovirt.engine.core.bll.storage.DeactivateStorageDomainCommand] (ajp-/127.0.0.1:8702-6) [5c1908b6] Lock freed to object EngineLock [exclusiveLocks= key: 6969f79a-8f74-415c-b2f7-784d050df2f1 value: POOL key: 469060ca-251e-4b92-932e-5efc1e55e6ad value: STORAGE , sharedLocks= ] 2013-03-11 16:45:32,848 INFO [org.ovirt.engine.core.bll.storage.AfterDeactivateSingleAsyncOperation] (pool-3-thread-49) [5c1908b6] After deactivate treatment vds: 10.35.160.61,pool dc_nfs_upgrade_30_32 2013-03-11 16:45:32,850 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SpmStopOnIrsVDSCommand] (ajp-/127.0.0.1:8702-6) [5c1908b6] START, SpmStopOnIrsVDSCommand( storagePoolId = 6969f79a-8f74-415c-b2f7-784d050df2f1, ignoreFailoverLimit = false, compatabilityVersion = null), log id: 2c78a683 2013-03-11 16:45:32,851 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.ResetIrsVDSCommand] (ajp-/127.0.0.1:8702-6) [5c1908b6] START, ResetIrsVDSCommand( storagePoolId = 6969f79a-8f74-415c-b2f7-784d050df2f1, ignoreFailoverLimit = false, compatabilityVersion = null, vdsId = 9c3b2ae4-1c2d-41af-ac7f-0ec49fc992f5, ignoreStopFailed = false), log id: 24fbf944 2013-03-11 16:45:32,855 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStopVDSCommand] (ajp-/127.0.0.1:8702-6) [5c1908b6] START, SpmStopVDSCommand(HostName = 10.35.160.61, HostId = 9c3b2ae4-1c2d-41af-ac7f-0ec49fc992f5, storagePoolId = 6969f79a-8f74-415c-b2f7-784d050df2f1), log id: 46cfbead 2013-03-11 16:45:32,903 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.SpmStopVDSCommand] (ajp-/127.0.0.1:8702-6) [5c1908b6] FINISH, SpmStopVDSCommand, log id: 46cfbead 2013-03-11 16:45:32,903 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.ResetIrsVDSCommand] (ajp-/127.0.0.1:8702-6) [5c1908b6] FINISH, ResetIrsVDSCommand, log id: 24fbf944 2013-03-11 16:45:32,903 INFO [org.ovirt.engine.core.vdsbroker.irsbroker.SpmStopOnIrsVDSCommand] (ajp-/127.0.0.1:8702-6) [5c1908b6] FINISH, SpmStopOnIrsVDSCommand, log id: 2c78a683 2013-03-11 16:45:32,906 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.DisconnectStoragePoolVDSCommand] (ajp-/127.0.0.1:8702-6) [5c1908b6] START, DisconnectStoragePoolVDSCommand(HostName = 10.35.160.61, HostId = 9c3b2ae4-1c2d-41af-ac7f-0ec49fc992f5, storagePoolId = 6969f79a-8f74-415c-b2f7-784d050df2f1, vds_spm_id = 1), log id: 4e3eb463 Vdsm: Thread-2179::INFO::2013-03-11 16:45:32,268::logUtils::39::dispatcher::(wrapper) Run and protect: disconnectStorageServer, Return response: {'statuslist': [{'status': 0, 'id': '79b049f2-560b-491a-b6e7-51ec551c7a97'}]} Thread-2182::INFO::2013-03-11 16:45:32,819::logUtils::37::dispatcher::(wrapper) Run and protect: deactivateStorageDomain(sdUUID='469060ca-251e-4b92-932e-5efc1e55e6ad', spUUID='6969f79a-8f74-415c-b2f7-784d050df2f1', msdUUID='00000000-0000-0000-0000-000000000000', masterVersion=1, options=None) Thread-2182::INFO::2013-03-11 16:45:32,825::logUtils::39::dispatcher::(wrapper) Run and protect: deactivateStorageDomain, Return response: None Thread-2185::INFO::2013-03-11 16:45:33,023::logUtils::37::dispatcher::(wrapper) Run and protect: disconnectStoragePool(spUUID='6969f79a-8f74-415c-b2f7-784d050df2f1', hostID=1, scsiKey='6969f79a-8f74-415c-b2f7-784d050df2f1', remove=False, options=None) Thread-2185::ERROR::2013-03-11 16:45:33,023::task::833::TaskManager.Task::(_setError) Task=`6bbd02fa-8b9f-458f-9f25-c20402941f19`::Unexpected error Traceback (most recent call last): File "/usr/share/vdsm/storage/task.py", line 840, in _run return fn(*args, **kargs) File "/usr/share/vdsm/logUtils.py", line 38, in wrapper res = f(*args, **kwargs) File "/usr/share/vdsm/storage/hsm.py", line 1011, in disconnectStoragePool self.validateNotSPM(spUUID) File "/usr/share/vdsm/storage/hsm.py", line 308, in validateNotSPM raise se.IsSpm(spUUID) IsSpm: Operation not allowed while SPM is active: ('6969f79a-8f74-415c-b2f7-784d050df2f1',) Version-Release number of selected component (if applicable): rhevm-3.2.0-10.10.beta1.el6ev.noarch vdsm-4.10.2-10.0.el6ev.x86_64 How reproducible: Not sure Steps to Reproduce: 1. Deactivate last storage domain 2. 3. Actual results: Expected results: Additional info: DC was created as 3.0 at around 16:31:33, NFS v1 domain was attached and then DC was upgraded to 3.2 and NFS domain to v3. Attaching whole test log