[PATCH 0/1] scsi: core: Restart a stopped queue when sysfs sets a device running

[PATCH 0/1] scsi: core: Restart a stopped queue when sysfs sets a device running

[Brian Bunker]

A SCSI device can be left in SDEV_RUNNING with its request queue stopped
for good. The task that put it there hangs holding the device lock, and
anything else that takes the lock hangs behind it.

This was seen with iSCSI when a session drops again just after
recovering. The error handler offlines a device while its transport has
it blocked, which leaves the queue stopped. iscsid then writes "running"
to the device's state attribute and store_state_field() moves it to
SDEV_RUNNING without restarting the queue. The rescan it starts sends an
INQUIRY that can never be dispatched. When the transport later unblocks
the device, scsi_internal_device_unblock_nowait() skips it because it is
already running, so nothing restarts the queue.

Evidence from a vmcore of a hung initiator (a RHEL 9.6 5.14 kernel; the
code involved is the same in mainline). The device is sd 0:0:0:1, and
iscsid is the task that wrote "running" to it:

  PID: 12087  TASK: ffff9635c9c80000  COMMAND: "iscsid"
   #5 blk_execute_rq
   #6 scsi_execute_cmd
   #7 scsi_vpd_inquiry
  #10 scsi_attach_vpd
  #11 scsi_rescan_device_rh
  #12 store_state_field
  #13 kernfs_fop_write_iter

  sdev_state                   = SDEV_RUNNING
  queue_stopped                = 1
  request_queue->quiesce_depth = 1
  sdev_gendev.mutex.owner      = 0xffff9635c9c80001 (iscsid, plus a flag bit)

The INQUIRY iscsid is waiting on belongs to that device's queue and was
never dispatched:

  state = MQ_RQ_IDLE, start_time_ns = 0, deadline = 0

The other LUNs of the same session were unblocked by the transport and
had their queues restarted:

  lun 1: SDEV_RUNNING            queue_stopped = 1
  lun 2: SDEV_TRANSPORT_OFFLINE  queue_stopped = 0
  ...
  lun 9: SDEV_TRANSPORT_OFFLINE  queue_stopped = 0

(scsi_rescan_device_rh is this distro kernel's name for
scsi_rescan_device().)

The kernel log of the same crash shows the sequence for the stuck device
(sd 0:0:0:1) and its siblings:

  [50958.843822]  connection9:0: detected conn error (1021)
  [50968.259428]  connection9:0: detected conn error (1020)
  [50968.259456] sd 0:0:0:1: Device offlined - not ready after error recovery
  [50978.298947]  session9: session recovery timed out after 10 secs
  [50978.298977] sd 0:0:0:2: rejecting I/O to offline device

The other LUNs are unblocked by the recovery timeout at 50978. The
offlined device is not: by then it had already been written back to
running.

Only a device that the error handler offlined while it was blocked can
end up like this. A device that the transport unblocks normally has its
queue restarted, and sysfs only accepts "running" for a device that is
running or offline.

So in the case above, the error handler offlined the device, iscsid
wrote "running" to it, and only then did the recovery timeout unblock
the session. All three happened within about ten seconds, which is why
this is rare.

The fix restarts the queue in store_state_field() when it moves a device
to SDEV_RUNNING. scsi_start_queue() is a no-op when the queue is not
stopped, so this is harmless for devices that were never blocked.

I do not have a deterministic reproducer. The analysis above comes from
the vmcore, and initiators running with this patch have not hit the hang
again, but with a race this narrow that is not proof the patch fixes it.
Review of the state transitions is welcome.

Brian Bunker (1):
  scsi: core: Restart a stopped queue when sysfs sets a device running

 drivers/scsi/scsi_sysfs.c | 10 +++++++++-
 1 file changed, 9 insertions(+), 1 deletion(-)

-- 
2.56.0

[PATCH 1/1] scsi: core: Restart a stopped queue when sysfs sets a device running

[Brian Bunker]

A device that its transport blocks has its queue stopped. If the SCSI
error handler then gives up on the device, it moves it from SDEV_BLOCK
to SDEV_OFFLINE and leaves the queue stopped. When userspace later
writes "running" to the device's state attribute, store_state_field()
moves it to SDEV_RUNNING, still with the queue stopped, and rescans it.
The rescan takes the device lock and waits for I/O that can never be
dispatched.

Nothing restarts the queue after that. When the transport later
unblocks the device, scsi_internal_device_unblock_nowait() rejects a
device that is already in SDEV_RUNNING and returns before
scsi_start_queue(), so the device is left running with its queue
stopped for good. The task that wrote "running" hangs forever holding
the device lock, and anything else that takes it hangs behind it.

This shows up with iSCSI when a session drops again just after
recovering. iscsid onlines the session's devices after a relogin by
writing "running" to every device it finds offline:

  1. The session is blocked, which blocks the device and stops its
     queue.
  2. The error handler cannot recover the device and moves it from
     SDEV_BLOCK to SDEV_OFFLINE. The queue stays stopped.
  3. iscsid writes "running": SDEV_OFFLINE -> SDEV_RUNNING with the
     queue still stopped, then the rescan sends an INQUIRY that sits
     unsent while holding the device lock.
  4. The session recovery timeout calls scsi_target_unblock(). The
     other devices go from SDEV_BLOCK to SDEV_TRANSPORT_OFFLINE and get
     their queues restarted, but this one is skipped because it is
     already running.

A vmcore from such a hang shows the device in SDEV_RUNNING with
queue_stopped set and the queue's quiesce_depth at 1, the rescan's
INQUIRY never started (MQ_RQ_IDLE, no start time or deadline), and
iscsid owning the device lock while other tasks wait for it.

Restart the queue in store_state_field() when it moves a device to
SDEV_RUNNING. scsi_start_queue() only unquiesces the queue when
queue_stopped is set, so this is a no-op for a device whose queue is
already running, and it keeps a later scsi_start_queue() from the
transport balanced. If the transport is still blocked, its own
readiness checks in queuecommand keep commands from reaching the wire,
as for any other running device.

Fixes: f0f82e2476f6 ("scsi: core: Fix capacity set to zero after offlinining device")
Signed-off-by: Brian Bunker <brian@purestorage.com>
---
 drivers/scsi/scsi_sysfs.c | 10 +++++++++-
 1 file changed, 9 insertions(+), 1 deletion(-)

diff --git a/drivers/scsi/scsi_sysfs.c b/drivers/scsi/scsi_sysfs.c
index fe54792ed69e..f5416a1548bd 100644
--- a/drivers/scsi/scsi_sysfs.c
+++ b/drivers/scsi/scsi_sysfs.c
@@ -811,8 +811,16 @@ store_state_field(struct device *dev, struct device_attribute *attr,
 		ret = 0;
 	} else {
 		ret = scsi_device_set_state(sdev, state);
-		if (ret == 0 && state == SDEV_RUNNING)
+		if (ret == 0 && state == SDEV_RUNNING) {
+			/*
+			 * The device may have been offlined while blocked by
+			 * its transport, so its queue can still be stopped.
+			 * The transport's unblock skips a running device and
+			 * would never restart it, so restart it here.
+			 */
+			scsi_start_queue(sdev);
 			rescan_dev = true;
+		}
 	}
 	mutex_unlock(&sdev->state_mutex);
 
-- 
2.56.0