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 1750577 - RHEL 7.7 long I/O stalls with bnx2fc from not masking off scope bits of retry delay value
Summary: RHEL 7.7 long I/O stalls with bnx2fc from not masking off scope bits of retry...
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Red Hat Enterprise Linux 7
Classification: Red Hat
Component: kernel
Version: 7.7
Hardware: All
OS: Linux
urgent
urgent
Target Milestone: rc
: 7.8
Assignee: Nilesh Javali (Marvell)
QA Contact: guazhang@redhat.com
URL:
Whiteboard:
Depends On:
Blocks: 1776290 1795648
TreeView+ depends on / blocked
 
Reported: 2019-09-09 23:02 UTC by Lance Digby
Modified: 2023-12-15 16:45 UTC (History)
13 users (show)

Fixed In Version: kernel-3.10.0-1113.el7
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
: 1776290 1795648 (view as bug list)
Environment:
Last Closed: 2020-03-31 19:30:29 UTC
Target Upstream Version:
Embargoed:


Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
Red Hat Knowledge Base (Solution) 4458211 0 None None None 2019-10-01 18:54:14 UTC
Red Hat Product Errata RHSA-2020:1016 0 None None None 2020-03-31 19:30:59 UTC

Description Lance Digby 2019-09-09 23:02:41 UTC
Description of problem:

This is a RHEL 7.7 version of the RHEL6.10 bz1749512 bug. 

This is the same customer with an identical delay. 

scsi_cmnd's stalled for up to 543 seconds  or just over 9 minutes. 

crash> scsishow --time 
..
scsi_cmnd ffff9913422bfb80 on scsi_device 0xffff98de12dfa000 (3:0:0:14) is unknown, deadline: -440391 cmnd-alloc: -543113 rq-alloc: -543113


Also the first hung_task was reported 418 seconds before the panic. AS this timeout was 120 seconds 418+120 = 538 or just over 9 minutes.

[607630.264537] INFO: task in:imjournal:5089 blocked for more than 120 seconds.
..
.. 418 seconds later 
..
[608048.236401] SysRq : Trigger a crash


From scsishow we see the target3:0:0 was blocked. 

-------------------------------------------------------------------------------
TARGET DEVICE   scsi_target          CHANNEL  ID     TARGET STATUS        TARGET_BUSY     TARGET_BLOCKED 
target3:0:0     ffff98fc61263c00         0     0     STARGET_RUNNING                0                  3  <====

Using the oldest request check the state of the related storage structures and confirmed this is a result of the blocked target. :
scsishow -r 
..
ffff98fcb8ed7a80 (3:0:0:4)     start_time: 4902223086 special: 0xffff9913422bd180
..

crash> struct request.q ffff98fcb8ed7a80
  q = 0xffff98fc7170b990
crash> struct -x request_queue.queue_flags,queuedata 0xffff98fc7170b990
  queue_flags = 0x42112a00
  queuedata = 0xffff98fcad735800
crash> struct scsi_device.sdev_target 0xffff98fcad735800
  sdev_target = 0xffff98fc61263c00
crash> struct scsi_target.target_blocked 0xffff98fc61263c00
    target_blocked = {
      counter = 3                  <<<--- 
    }
crash> 

The fc_rport struct for the port was currently marked as online and not blocked:

crash> struct fc_rport.port_state ffff98fcadf1b000
  port_state = FC_PORTSTATE_ONLINE

A scsi_target's target_blocked state gets set if an HBA driver returns the SCSI_MLQUEUE_TARGET_BUSY error code.  The HBA driver was bnx2fc, which has 2 conditions it will return this code.  If its session is failed for some reason or if the storage had returned a retry delay timestamp.  Checking bnx2fc state:

crash> p ((struct fc_rport *)0xffff98fcadf1b000)->dd_data
$1 = (void *) 0xffff98fcadf1b468

crash> p &((struct fc_rport_libfc_priv *)0xffff98fcadf1b468)[1]
$2 = (struct fc_rport_libfc_priv *) 0xffff98fcadf1b480

crash> px ((struct bnx2fc_rport *)0xffff98fcadf1b480)->flags
$3 = 0x426
crash> 

The BNX2FC_FLAG_SESSION_READY would be value 0x2, which is set in the flags field.  So the busy error was not from a failed session state.  Checking for the retry delay timestamp we find a non-zero timestamp value:

crash> p ((struct bnx2fc_rport *)0xffff98fcadf1b480)->retry_delay_timestamp
$4 = 4903861586
crash> p jiffies
jiffies = $5 = 4902766219
crash> eval 4903861586 - 4902766219
hexadecimal: 10b6c7  
    decimal: 1095367  
      octal: 4133307
     binary: 0000000000000000000000000000000000000000000100001011011011000111
crash> 

So there were still 1095 seconds (over 18 minutes) until this retry delay would be over.  With the oldest commands having been waiting roughly 540 seconds, this would imply the hardware returned the maximum delay value of 0x3fff, which would be a delay of 27 minutes.

So the I/O is being delayed because the storage device requested a delay.   A command was sent to the storage on this FC rport, and the storage returned a code and retry delay timestamp telling the system to delay before resending the I/O to try again.  But the storage returned a huge delay value, and so the I/O to this FC port was being delayed a long time as requested.

Comment 3 Lance Digby 2019-09-09 23:14:32 UTC
Also I verified the patch https://marc.info/?l=linux-scsi&m=156803077422681&w=2 is not in trhe rhel 7.7 bnx2fc code.

Comment 6 Nathaniel Weddle 2019-10-29 14:17:32 UTC
Good morning team, 

I'm requesting a status update on this public bug for our customers please.

Thank you

Comment 7 Nilesh Javali (Marvell) 2019-10-30 08:40:29 UTC
Apologies, I'm in process of posting the patch to RHEL 7.7.z.

Comment 9 Ewan D. Milne 2019-10-31 15:26:41 UTC
This needs an exception to go into 7.8, and it needs zStream approval for 7.7.z.

Comment 13 Jan Stancek 2019-11-24 09:39:10 UTC
Patch(es) committed on kernel-3.10.0-1113.el7

Comment 17 guazhang@redhat.com 2020-01-06 04:35:48 UTC
Hello

I did code review on fixed package and run the regression testing, After check, all modified can be found in source and regression has passed.
so move to verified.

thanks
guazhang

Comment 20 errata-xmlrpc 2020-03-31 19:30:29 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/RHSA-2020:1016


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