674822 – connectStorageServer tries to delete scsi target that was returned as not exist

Bug 674822 - connectStorageServer tries to delete scsi target that was returned as not exist

Summary: connectStorageServer tries to delete scsi target that was returned as not exist

Keywords:
Status:	CLOSED CURRENTRELEASE
Alias:	None
Product:	oVirt
Classification:	Retired
Component:	vdsm
Sub Component:
Version:	unspecified
Hardware:	Unspecified
OS:	Unspecified
Priority:	unspecified
Severity:	medium
Target Milestone:	---
Target Release:	3.3.4
Assignee:	Ayal Baron
QA Contact:
Docs Contact:
URL:
Whiteboard:	storage
Depends On:
Blocks:
TreeView+	depends on / blocked

Reported:	2011-02-03 13:11 UTC by Rami Vaknin
Modified:	2014-07-20 06:12 UTC (History)
CC List:	10 users (show)
Fixed In Version:
Doc Type:	Enhancement
Doc Text:
Clone Of:
Environment:	RHEVM 2.3 with RHEL6 hosts
Last Closed:	2013-09-04 22:46:56 UTC
oVirt Team:	---
Embargoed:
Dependent Products:

Attachments	(Terms of Use)
VDSM Log (518.00 KB, application/x-compressed-tar) 2011-02-03 13:11 UTC, Rami Vaknin	no flags	Details
View All

Description Rami Vaknin 2011-02-03 13:11:21 UTC

Created attachment 476776 [details]
VDSM Log

/usr/bin/sudo -n /sbin/iscsiadm -m node -T iqn.2011-01.com:Rami-04-40G -o update -n node.session.auth.authmethod -v CHAP
Thread-709::DEBUG::2011-02-03 14:23:12,163::iscsi::395::Storage.Misc.excCmd::(addiSCSINode) FAILED: <err> = 'iscsiadm: no records found!\n'; <rc> = 255
/usr/bin/sudo -n /sbin/iscsiadm -m node -o delete -T iqn.2011-01.com:Rami-04-40G -p 10.35.64.10:3260


How to reproduce:
1. Define host with iscsi Lun
2. Remove the Lun from the storage server itself
3. Enter the host into Maintenance and Activate it (in order to invoke connectStoragePool)


From VDSM log:

Thread-709::INFO::2011-02-03 14:23:11,971::dispatcher::94::Storage.Dispatcher.Protect::(run) Run and protect: connectStorageServer, args: (domType=3, spUUID=1af052ad-9b2c-4fa7-b445-9d64c71511ac, conList=[{'connection': '10.35.64.10
', 'iqn': 'iqn.2011-01.com:Rami-04-40G', 'portal': '1', 'user': '(null)', 'password': '******', 'id': 'b5fd4c37-413a-4ce5-9ce3-b691b6c8abb2', 'port': '3260'}])
Thread-709::DEBUG::2011-02-03 14:23:11,972::task::491::TaskManager.Task::(_debug) Task bab41350-5f71-4288-a3b0-b3af1f00b459: moving from state init -> state preparing
Thread-709::INFO::2011-02-03 14:23:11,972::storage_connection::78::Storage.ServerConnection::(connect) Request to connect ISCSI storage server
Thread-709::INFO::2011-02-03 14:23:11,972::storage_connection::41::Storage.ServerConnection::(__validateConnectionParams) conList=[{'connection': '10.35.64.10', 'iqn': 'iqn.2011-01.com:Rami-04-40G', 'portal': '1', 'user': '(null)',
 'password': '******', 'id': 'b5fd4c37-413a-4ce5-9ce3-b691b6c8abb2', 'port': '3260'}]
Thread-709::DEBUG::2011-02-03 14:23:11,973::iscsi::369::Storage.Misc.excCmd::(_configureAuthInformation) '/usr/bin/sudo -n /sbin/iscsiadm -m discoverydb -t sendtargets -p 10.35.64.10:3260 -o new' (cwd None)
Thread-709::DEBUG::2011-02-03 14:23:11,987::iscsi::369::Storage.Misc.excCmd::(_configureAuthInformation) SUCCESS: <err> = ''; <rc> = 0
Thread-709::DEBUG::2011-02-03 14:23:11,988::iscsi::369::Storage.Misc.excCmd::(_configureAuthInformation) '/usr/bin/sudo -n /sbin/iscsiadm -m discoverydb -t sendtargets -p 10.35.64.10:3260 -o update -n discovery.sendtargets.auth.aut
hmethod -v CHAP' (cwd None)
Thread-709::DEBUG::2011-02-03 14:23:12,002::iscsi::369::Storage.Misc.excCmd::(_configureAuthInformation) SUCCESS: <err> = ''; <rc> = 0
Thread-709::DEBUG::2011-02-03 14:23:12,003::iscsi::369::Storage.Misc.excCmd::(_configureAuthInformation) '/sbin/iscsiadm -m discoverydb -t sendtargets -p 10.35.64.10:3260 -o update -n discovery.sendtargets.auth.password -v ******' (cwd None)
Thread-709::DEBUG::2011-02-03 14:23:12,016::iscsi::369::Storage.Misc.excCmd::(_configureAuthInformation) SUCCESS: <err> = ''; <rc> = 0
Thread-709::DEBUG::2011-02-03 14:23:12,017::iscsi::369::Storage.Misc.excCmd::(_configureAuthInformation) '/usr/bin/sudo -n /sbin/iscsiadm -m discoverydb -t sendtargets -p 10.35.64.10:3260 -o update -n discovery.sendtargets.auth.username -v (null)' (cwd None)
Thread-709::DEBUG::2011-02-03 14:23:12,031::iscsi::369::Storage.Misc.excCmd::(_configureAuthInformation) SUCCESS: <err> = ''; <rc> = 0
Thread-709::DEBUG::2011-02-03 14:23:12,032::iscsi::318::Storage.Misc.excCmd::(addiSCSIPortal) '/usr/bin/sudo -n /sbin/iscsiadm -m discoverydb -t sendtargets -p 10.35.64.10:3260 --discover' (cwd None)
Thread-709::DEBUG::2011-02-03 14:23:12,135::iscsi::318::Storage.Misc.excCmd::(addiSCSIPortal) SUCCESS: <err> = ''; <rc> = 0
Thread-709::DEBUG::2011-02-03 14:23:12,136::iscsi::395::Storage.Misc.excCmd::(addiSCSINode) '/usr/bin/sudo -n /sbin/iscsiadm -m node -T iqn.2011-01.com:Rami-04-40G -o update -n node.session.auth.authmethod -v CHAP' (cwd None)
Thread-709::DEBUG::2011-02-03 14:23:12,163::iscsi::395::Storage.Misc.excCmd::(addiSCSINode) FAILED: <err> = 'iscsiadm: no records found!\n'; <rc> = 255
Thread-709::DEBUG::2011-02-03 14:23:12,164::misc::1008::SamplingMethod::(__call__) Trying to enter sampling method (storage.iscsi._getiSCSISessionList)
Thread-709::DEBUG::2011-02-03 14:23:12,164::misc::1010::SamplingMethod::(__call__) Got in to sampling method
Thread-709::DEBUG::2011-02-03 14:23:12,164::iscsi::485::Storage.Misc.excCmd::(_getiSCSISessionList) '/usr/bin/sudo -n /sbin/iscsiadm -m session' (cwd None)
Thread-709::DEBUG::2011-02-03 14:23:12,178::iscsi::485::Storage.Misc.excCmd::(_getiSCSISessionList) SUCCESS: <err> = ''; <rc> = 0
Thread-709::DEBUG::2011-02-03 14:23:12,178::misc::1018::SamplingMethod::(__call__) Returning last result
Thread-709::DEBUG::2011-02-03 14:23:12,179::iscsi::540::Storage.iScsi::(checkSessionList) checkSession: dest ['connection: 10.35.64.10', 'iqn: iqn.2011-01.com:Rami-04-40G', 'portal: 1', 'user: (null)', 'port: 3260']
Thread-709::DEBUG::2011-02-03 14:23:12,179::iscsi::523::Storage.iScsi::(sameSession) enta key iqn v iqn.2011-01.com:Rami-05-60G != entb v iqn.2011-01.com:Rami-04-40G
Thread-709::DEBUG::2011-02-03 14:23:12,179::iscsi::460::Storage.Misc.excCmd::(remiSCSINode) '/usr/bin/sudo -n /sbin/iscsiadm -m node -o delete -T iqn.2011-01.com:Rami-04-40G -p 10.35.64.10:3260' (cwd None)
Thread-709::DEBUG::2011-02-03 14:23:12,205::iscsi::460::Storage.Misc.excCmd::(remiSCSINode) FAILED: <err> = 'iscsiadm: no records found!\n'; <rc> = 255
Thread-709::ERROR::2011-02-03 14:23:12,206::iscsi::434::Storage.iScsi::(addiSCSINode) Could not connect to iscsi node
Traceback (most recent call last):
  File "/usr/share/vdsm/storage/iscsi.py", line 397, in addiSCSINode
    raise se.SetiSCSIAuthError(portal)
SetiSCSIAuthError: Set iSCSI authentication error: ('10.35.64.10:3260',)
Thread-709::ERROR::2011-02-03 14:23:12,206::storage_connection::212::Storage.ServerConnection::(__connectiSCSIServer) Error during storage connection: rc=461

Comment 2 Ayal Baron 2011-02-03 19:26:10 UTC

What's the bug here?

Comment 3 Moran Goldboim 2011-02-03 21:00:26 UTC

can you please explain the logic behind deleting a lun which wasn't found 10ms  beforehand

Comment 4 Rami Vaknin 2011-02-03 21:06:20 UTC

The bug is about an iscsiadm delete command that was performed without any reason.

This iscsi delete command was performed on the iqn.2011-01.com:Rami-04-40G Lun which does not exist anymore.
The return value and the error message of the last iscsiadm update command already indicated that there is no such Lun anymore, so obviously the iscsiadm delete command returned with error message.

Comment 9 Ayal Baron 2013-09-04 22:46:56 UTC

This was solved by http://gerrit.ovirt.org/#/c/2750/

Note You need to log in before you can comment on or make changes to this bug.