RHEL Engineering is moving the tracking of its product development work on RHEL 6 through RHEL 9 to Red Hat Jira (issues.redhat.com). If you're a Red Hat customer, please continue to file support cases via the Red Hat customer portal. If you're not, please head to the "RHEL project" in Red Hat Jira and file new tickets here. Individual Bugzilla bugs in the statuses "NEW", "ASSIGNED", and "POST" are being migrated throughout September 2023. Bugs of Red Hat partners with an assigned Engineering Partner Manager (EPM) are migrated in late September as per pre-agreed dates. Bugs against components "kernel", "kernel-rt", and "kpatch" are only migrated if still in "NEW" or "ASSIGNED". If you cannot log in to RH Jira, please consult article #7032570. That failing, please send an e-mail to the RH Jira admins at rh-issues@redhat.com to troubleshoot your issue as a user management inquiry. The email creates a ServiceNow ticket with Red Hat. Individual Bugzilla bugs that are migrated will be moved to status "CLOSED", resolution "MIGRATED", and set with "MigratedToJIRA" in "Keywords". The link to the successor Jira issue will be found under "Links", have a little "two-footprint" icon next to it, and direct you to the "RHEL project" in Red Hat Jira (issue links are of type "https://issues.redhat.com/browse/RHEL-XXXX", where "X" is a digit). This same link will be available in a blue banner at the top of the page informing you that that bug has been migrated.
Bug 1624670 - iSCSI Login negotiation failed due to CHAP_N values do not match!
Summary: iSCSI Login negotiation failed due to CHAP_N values do not match!
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Red Hat Enterprise Linux 7
Classification: Red Hat
Component: iscsi-initiator-utils
Version: 7.5
Hardware: Unspecified
OS: Unspecified
high
urgent
Target Milestone: rc
: 7.8
Assignee: Chris Leech
QA Contact: Filip Suba
URL:
Whiteboard:
: 1624678 (view as bug list)
Depends On:
Blocks: 1554642 1577173 1597320 1625824 1646945 1654409 1657156 1727425
TreeView+ depends on / blocked
 
Reported: 2018-09-03 02:56 UTC by Xiubo Li
Modified: 2023-09-07 19:21 UTC (History)
6 users (show)

Fixed In Version: iscsi-initiator-utils-6.2.0.874-13.el7
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2020-03-31 20:03:52 UTC
Target Upstream Version:
Embargoed:

Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
Red Hat Product Errata RHBA-2020:1124 0 None None None 2020-03-31 20:04:29 UTC

Description Xiubo Li 2018-09-03 02:56:26 UTC 
Description of problem:

For our CNS product, we can hit the "iSCSI Login negotiation failed" very frequently, and from the target side dmesg logs we can see the following logs:

Sep 02 22:41:50 rhel1 kernel: Selected MD5 Algorithm
Sep 02 22:41:50 rhel1 kernel: [server] Got CHAP_A=5
Sep 02 22:41:50 rhel1 kernel: [server] Sending CHAP_A=5
Sep 02 22:41:50 rhel1 kernel: [server] Sending CHAP_I=72
Sep 02 22:41:50 rhel1 kernel: [server] Sending CHAP_C=0x8c1295d9ee15bbd4c10a87cdb9b55131
Sep 02 22:41:50 rhel1 kernel: Received OK response from LIO Authentication, continuing.
Sep 02 22:41:50 rhel1 kernel: Sending Login Response, Flags: 0x00, ITT: 0x00000000, ExpCmdSN; 0x00000000, MaxCmdSN: 0x00000000, StatSN: 0x8ac1142c, Length:
Sep 02 22:41:50 rhel1 kernel: Entering iscsi_target_sk_data_ready: conn: ffff9be258024000
Sep 02 22:41:50 rhel1 kernel: entering iscsi_target_do_login_rx, conn: ffff9be258024000, kworker/0:2:21036
Sep 02 22:41:50 rhel1 kernel: Entering iscsi_target_sk_data_ready: conn: ffff9be258024000
Sep 02 22:41:50 rhel1 kernel: Got LOGIN_FLAGS_READ_ACTIVE=1, conn: ffff9be258024000 >>>>
Sep 02 22:41:50 rhel1 kernel: Starting login_timer for kworker/0:2/21036
Sep 02 22:41:50 rhel1 kernel: Got Login Command, Flags 0x81, ITT: 0x00000000, CmdSN: 0x00000000, ExpStatSN: 0x2d14c18a, CID: 0, Length: 50
Sep 02 22:41:50 rhel1 kernel: iscsi_target_do_login_rx after rx_login_io, ffff9be258024000, kworker/0:2:21036
Sep 02 22:41:50 rhel1 kernel: CHAP_N[], auth->userid[34dcd8da-7e5f-4028-93b4-3917c2173711]!
Sep 02 22:41:50 rhel1 kernel: CHAP_R[], auth->password[770ae86f-09e9-4faa-9745-fa0f135ec6cf]!
Sep 02 22:41:50 rhel1 kernel: CHAP_N values do not match!
Sep 02 22:41:50 rhel1 kernel: Security negotiation failed.
Sep 02 22:41:50 rhel1 kernel: Added timeout timer to iSCSI login request for 15 seconds.
Sep 02 22:41:50 rhel1 kernel: Moving to TARG_CONN_STATE_XPT_UP.
Sep 02 22:41:50 rhel1 kernel: Entering iscsi_target_restore_sock_callbacks: conn: ffff9be258024000
Sep 02 22:41:50 rhel1 kernel: iSCSI Login negotiation failed.

NOTE: some of the logs are added by myself and some are from the dynamic debuginfo.

The CHAP_N value is NULL.

From the initiator side, after setting the "node.session.auth.username" and "node.session.auth.password", just before login we just list the parameters we set, it shows that "node.session.auth.username" is empty:

...
node.session.queue_depth = 32
node.session.nr_sessions = 1
node.session.auth.authmethod = None
node.session.auth.username = <empty>
node.session.auth.password = ********
node.session.auth.username_in = <empty>
node.session.auth.password_in = <empty>
...

I have tried the newest open-iscsi code from the upstream, still the same.

This will be very easy to reproduce when trying to login multi targets in parallel, more detail and the reproduce scrtipt could be found in https://bugzilla.redhat.com/show_bug.cgi?id=1597320#c26.

Thanks,


Version-Release number of selected component (if applicable):


How reproducible: 30%
Comment 3 Xiubo Li 2018-09-03 10:07:46 UTC 
#iscsiadm -m node -p $N:3260 -T $IQN -I default -o update -n node.session.auth.authmethod -v CHAP
#iscsiadm -m node -p $N:3260 -T $IQN -I default -o update -n node.session.auth.username -v $USER
#iscsiadm -m node -p $N:3260 -T $IQN -I default -o update -n node.session.auth.password -v $PASSWORD

For this, from my debug and through reading the code it seems when updating the parm followed it will overwrite the front one. I have tried to combine the above 3 commands to single one, like:

# iscsiadm -m node -p $N:3260 -T $IQN -I default -o update -n node.session.auth.authmethod -v CHAP -o update -n node.session.auth.username -v $USER -o update -n node.session.auth.password -v $PASSWORD

Test for many times, didn't reproduce it yet.

@Chris It seems buggy when loading -> updating -> storing the node type rec info in parallel. For the workaround will it be work just combining them ?

Thanks,
Comment 5 Chris Leech 2018-09-18 18:17:10 UTC 
(In reply to Xiubo Li from comment #3)
> #iscsiadm -m node -p $N:3260 -T $IQN -I default -o update -n
> node.session.auth.authmethod -v CHAP
> #iscsiadm -m node -p $N:3260 -T $IQN -I default -o update -n
> node.session.auth.username -v $USER
> #iscsiadm -m node -p $N:3260 -T $IQN -I default -o update -n
> node.session.auth.password -v $PASSWORD
> 
> For this, from my debug and through reading the code it seems when updating
> the parm followed it will overwrite the front one. I have tried to combine
> the above 3 commands to single one, like:
> 
> # iscsiadm -m node -p $N:3260 -T $IQN -I default -o update -n
> node.session.auth.authmethod -v CHAP -o update -n node.session.auth.username
> -v $USER -o update -n node.session.auth.password -v $PASSWORD
> 
> Test for many times, didn't reproduce it yet.
> 
> @Chris It seems buggy when loading -> updating -> storing the node type rec
> info in parallel. For the workaround will it be work just combining them ?
> 
> Thanks,

Ug. iscsiadm is getting a file lock while writing out records, but updates are a read-modify-write operation and only the write is locked.  So the parallel requests are reading in the pre-update record and then overwriting each other with the writes.

I'll look at improving the parallel handling of the records, but I think it should be fine if you only have one process per record updating with multiple values.
Comment 7 Amar Tumballi 2018-10-22 09:15:08 UTC 
Chris, just checking if you got any chance to go further with this bug?
Comment 10 Yaniv Kaul 2019-04-22 12:10:57 UTC 
Do we have any updates on this BZ?
Comment 14 Chris Leech 2019-07-05 16:50:53 UTC 
Solution has been agreed to and code merged upstream.
Comment 15 Chris Leech 2019-07-05 18:10:18 UTC 
*** Bug 1624678 has been marked as a duplicate of this bug. ***
Comment 17 Filip Suba 2019-12-06 11:40:45 UTC 
Verified with iscsi-initiator-utils-6.2.0.874-17.el7.
Comment 19 errata-xmlrpc 2020-03-31 20:03:52 UTC 
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHBA-2020:1124
Note You need to log in before you can comment on or make changes to this bug.