Note: This bug is displayed in read-only format because the product is no longer active in Red Hat Bugzilla.

Bug 809497

Summary:	[ovirt] [vdsm] connectStroragServer will fail if iscsi session already exists
Product:	[Retired] oVirt	Reporter:	Haim <hateya>
Component:	vdsm	Assignee:	Saggi Mizrahi <smizrahi>
Status:	CLOSED WONTFIX	QA Contact:
Severity:	medium	Docs Contact:
Priority:	unspecified
Version:	unspecified	CC:	abaron, acathrow, amureini, bazulay, dyasny, hateya, iheim, mgoldboi, xuhj, yeylon, ykaul
Target Milestone:	---
Target Release:	3.3.4
Hardware:	Unspecified
OS:	Unspecified
Whiteboard:	storage
Fixed In Version:		Doc Type:	Bug Fix
Doc Text:		Story Points:	---
Clone Of:		Environment:
Last Closed:	2013-03-12 09:37:55 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:

Description Haim 2012-04-03 14:21:37 UTC

Description of problem:

connectStorageServer will fail (return non-zero return code) if iscsi connection already exists.

Thread-668::ERROR::2012-04-03 17:05:39,863::hsm::1902::Storage.HSM::(connectStorageServer) Could not connect to storageServer
Traceback (most recent call last):
  File "/usr/share/vdsm/storage/hsm.py", line 1899, in connectStorageServer
    conObj.connect()
  File "/usr/share/vdsm/storage/storageServer.py", line 287, in connect
    iscsi.addIscsiNode(self._iface, self._target, self._cred)
  File "/usr/share/vdsm/storage/iscsi.py", line 124, in addIscsiNode
    iscsiadm.node_update(iface.name, portalStr, targetName, "node.startup", "manual")
  File "/usr/share/vdsm/storage/iscsiadm.py", line 192, in node_update
    raise IscsiNodeError(rc, out, err)
IscsiNodeError: (6, [], ['iscsiadm: iface iter could not stat /var/lib/iscsi/nodes/iqn.2008-05.com.xtremio:001b21b54535/10.35.116.151,3260.', 'iscsiadm: Could not execute opera
tion on all records: encountered iSCSI database failure'])


BUG::2012-04-03 17:05:38,496::BindingXMLRPC::167::vds::(wrapper) [10.35.97.30]
Thread-668::DEBUG::2012-04-03 17:05:38,497::task::588::TaskManager.Task::(_updateState) Task=`78ad5174-ddba-47a9-b0ca-c064a654f402`::moving from state init -> state preparing
Thread-668::INFO::2012-04-03 17:05:38,497::logUtils::37::dispatcher::(wrapper) Run and protect: connectStorageServer(domType=3, spUUID='552256b8-3266-4930-9d13-f9c7ff636f35', conList=[{'connection': '10.35.115.150', 'iqn': 'iqn.2008-05.com.xtremio:001b21b545c0', 'portal': '1', 'user': '', 'password': '******', 'id': 'f5acc189-9cfb-44c8-83c9-f83347574615', 'port': '3260'}, {'connection': '10.35.116.150', 'iqn': 'iqn.2008-05.com.xtremio:001b21b545c1', 'portal': '1', 'user': '', 'password': '******', 'id': 'c96bf901-16e6-43ba-a168-77a51d7e7481', 'port': '3260'}, {'connection': '10.35.116.151', 'iqn': 'iqn.2008-05.com.xtremio:001b21b54535', 'portal': '1', 'user': '', 'password': '******', 'id': 'c262316d-6456-4505-8b14-f3529e304e2a', 'port': '3260'}, {'connection': '10.35.115.151', 'iqn': 'iqn.2008-05.com.xtremio:001b21b54534', 'portal': '1', 'user': '', 'password': '******', 'id': '4e423450-de8b-4ed4-9a3a-67f7efb7afa8', 'port': '3260'}], options=None)
Thread-668::DEBUG::2012-04-03 17:05:38,498::__init__::1241::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/iscsiadm -m node -T iqn.2008-05.com.xtremio:001b21b545c0 -I default -p 10.35.115.150:3260 --op=new' (cwd None)
Thread-668::DEBUG::2012-04-03 17:05:38,518::__init__::1241::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
Thread-668::DEBUG::2012-04-03 17:05:38,519::__init__::1241::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/iscsiadm -m node -T iqn.2008-05.com.xtremio:001b21b545c0 -I default -p 10.35.115.150:3260 -n node.startup -v manual --op=update' (cwd None)
Thread-668::DEBUG::2012-04-03 17:05:38,571::__init__::1241::Storage.Misc.excCmd::(_log) FAILED: <err> = 'iscsiadm: iface iter could not stat /var/lib/iscsi/nodes/iqn.2008-05.com.xtremio:001b21b545c0/10.35.115.150,3260.\niscsiadm: Could not execute operation on all records: encountered iSCSI database failure\n'; <rc> = 6
Thread-668::DEBUG::2012-04-03 17:05:38,572::__init__::1241::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/iscsiadm -m iface' (cwd None)
Thread-668::DEBUG::2012-04-03 17:05:38,591::__init__::1241::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
Thread-668::DEBUG::2012-04-03 17:05:38,592::__init__::1241::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/iscsiadm -m node -T iqn.2008-05.com.xtremio:001b21b545c0 -I default -p 10.35.115.150:3260 -u' (cwd None)
Thread-668::DEBUG::2012-04-03 17:05:39,120::__init__::1241::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
Thread-668::DEBUG::2012-04-03 17:05:39,122::__init__::1241::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/iscsiadm -m node -T iqn.2008-05.com.xtremio:001b21b545c0 -I default -p 10.35.115.150:3260 --op=delete' (cwd None)
Thread-668::DEBUG::2012-04-03 17:05:39,145::__init__::1241::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
Thread-668::ERROR::2012-04-03 17:05:39,146::hsm::1902::Storage.HSM::(connectStorageServer) Could not connect to storageServer
Thread-668::DEBUG::2012-04-03 17:05:39,150::__init__::1241::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/iscsiadm -m node -T iqn.2008-05.com.xtremio:001b21b545c1 -I default -p 10.35.116.150:3260 --op=new' (cwd None)
Thread-668::DEBUG::2012-04-03 17:05:39,170::__init__::1241::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
Thread-668::DEBUG::2012-04-03 17:05:39,171::__init__::1241::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/iscsiadm -m node -T iqn.2008-05.com.xtremio:001b21b545c1 -I default -p 10.35.116.150:3260 -n node.startup -v manual --op=update' (cwd None)
Thread-668::DEBUG::2012-04-03 17:05:39,228::__init__::1241::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
Thread-668::DEBUG::2012-04-03 17:05:39,229::__init__::1241::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/iscsiadm -m node -T iqn.2008-05.com.xtremio:001b21b545c1 -I default -p 10.35.116.150:3260 -l' (cwd None)
Thread-668::DEBUG::2012-04-03 17:05:39,250::__init__::1241::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
Thread-668::DEBUG::2012-04-03 17:05:39,251::__init__::1241::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/iscsiadm -m node -T iqn.2008-05.com.xtremio:001b21b54535 -I default -p 10.35.116.151:3260 --op=new' (cwd None)
Thread-668::DEBUG::2012-04-03 17:05:39,271::__init__::1241::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
Thread-668::DEBUG::2012-04-03 17:05:39,271::__init__::1241::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/iscsiadm -m node -T iqn.2008-05.com.xtremio:001b21b54535 -I default -p 10.35.116.151:3260 -n node.startup -v manual --op=update' (cwd None)
Thread-668::DEBUG::2012-04-03 17:05:39,290::__init__::1241::Storage.Misc.excCmd::(_log) FAILED: <err> = 'iscsiadm: iface iter could not stat /var/lib/iscsi/nodes/iqn.2008-05.com.xtremio:001b21b54535/10.35.116.151,3260.\niscsiadm: Could not execute operation on all records: encountered iSCSI database failure\n'; <rc> = 6
Thread-668::DEBUG::2012-04-03 17:05:39,291::__init__::1241::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/iscsiadm -m iface' (cwd None)
Thread-668::DEBUG::2012-04-03 17:05:39,310::__init__::1241::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
Thread-668::DEBUG::2012-04-03 17:05:39,311::__init__::1241::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/iscsiadm -m node -T iqn.2008-05.com.xtremio:001b21b54535 -I default -p 10.35.116.151:3260 -u' (cwd None)
Thread-668::DEBUG::2012-04-03 17:05:39,839::__init__::1241::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
Thread-668::DEBUG::2012-04-03 17:05:39,840::__init__::1241::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/iscsiadm -m node -T iqn.2008-05.com.xtremio:001b21b54535 -I default -p 10.35.116.151:3260 --op=delete' (cwd None)
Thread-668::DEBUG::2012-04-03 17:05:39,862::__init__::1241::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
Thread-668::ERROR::2012-04-03 17:05:39,863::hsm::1902::Storage.HSM::(connectStorageServer) Could not connect to storageServer
Thread-668::DEBUG::2012-04-03 17:05:39,864::__init__::1241::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/iscsiadm -m node -T iqn.2008-05.com.xtremio:001b21b54534 -I default -p 10.35.115.151:3260 --op=new' (cwd None)
Thread-668::DEBUG::2012-04-03 17:05:39,883::__init__::1241::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
Thread-668::DEBUG::2012-04-03 17:05:39,883::__init__::1241::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/iscsiadm -m node -T iqn.2008-05.com.xtremio:001b21b54534 -I default -p 10.35.115.151:3260 -n node.startup -v manual --op=update' (cwd None)
Thread-668::DEBUG::2012-04-03 17:05:39,917::__init__::1241::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
Thread-668::DEBUG::2012-04-03 17:05:39,918::__init__::1241::Storage.Misc.excCmd::(_log) '/usr/bin/sudo -n /sbin/iscsiadm -m node -T iqn.2008-05.com.xtremio:001b21b54534 -I default -p 10.35.115.151:3260 -l' (cwd None)
Thread-668::DEBUG::2012-04-03 17:05:39,938::__init__::1241::Storage.Misc.excCmd::(_log) SUCCESS: <err> = ''; <rc> = 0
Thread-668::DEBUG::2012-04-03 17:05:39,939::lvm::474::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' got the operation mutex
Thread-668::DEBUG::2012-04-03 17:05:39,939::lvm::476::OperationMutex::(_invalidateAllPvs) Operation 'lvm invalidate operation' released the operation mutex
Thread-668::DEBUG::2012-04-03 17:05:39,940::lvm::486::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' got the operation mutex
Thread-668::DEBUG::2012-04-03 17:05:39,940::lvm::488::OperationMutex::(_invalidateAllVgs) Operation 'lvm invalidate operation' released the operation mutex
Thread-668::DEBUG::2012-04-03 17:05:39,941::lvm::507::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' got the operation mutex
Thread-668::DEBUG::2012-04-03 17:05:39,941::lvm::509::OperationMutex::(_invalidateAllLvs) Operation 'lvm invalidate operation' released the operation mutex
Thread-668::INFO::2012-04-03 17:05:39,942::logUtils::39::dispatcher::(wrapper) Run and protect: connectStorageServer, Return response: {'statuslist': [{'status': 465, 'id': 'f5acc189-9cfb-44c8-83c9-f83347574615'}, {'status': 0, 'id': 'c96bf901-16e6-43ba-a168-77a51d7e7481'}, {'status': 465, 'id': 'c262316d-6456-4505-8b14-f3529e304e2a'}, {'status': 0, 'id': '4e423450-de8b-4ed4-9a3a-67f7efb7afa8'}]}
Thread-668::DEBUG::2012-04-03 17:05:39,942::task::1172::TaskManager.Task::(prepare) Task=`78ad5174-ddba-47a9-b0ca-c064a654f402`::finished: {'statuslist': [{'status': 465, 'id': 'f5acc189-9cfb-44c8-83c9-f83347574615'}, {'status': 0, 'id': 'c96bf901-16e6-43ba-a168-77a51d7e7481'}, {'status': 465, 'id': 'c262316d-6456-4505-8b14-f3529e304e2a'}, {'status': 0, 'id': '4e423450-de8b-4ed4-9a3a-67f7efb7afa8'}]}
Thread-668::DEBUG::2012-04-03 17:05:39,943::task::588::TaskManager.Task::(_updateState) Task=`78ad5174-ddba-47a9-b0ca-c064a654f402`::moving from state preparing -> state finished
Thread-668::DEBUG::2012-04-03 17:05:39,943::resourceManager::809::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-668::DEBUG::2012-04-03 17:05:39,943::resourceManager::844::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-668::DEBUG::2012-04-03 17:05:39,943::task::978::TaskManager.Task::(_decref) Task=`78ad5174-ddba-47a9-b0ca-c064a654f402`::ref 0 aborting False

Comment 1 Xu He Jie 2012-07-05 05:51:58 UTC

post http://gerrit.ovirt.org/#/c/5957/

Comment 2 Itamar Heim 2013-03-12 09:37:55 UTC

Closing old bugs. If this issue is still relevant/important in current version, please re-open the bug.