[PATCHv3 0/9] New EH command timeout handler

[PATCHv3 0/9] New EH command timeout handler

[Hannes Reinecke]

This patchset implements a new SCSI EH command timeout handler
which will be sending command aborts inline without actually
engaging SCSI EH.
SCSI EH will only be invoked if command abort fails.

In addition the commands will be returned directly
if the command abort succeeded, cutting down recovery
times dramatically.

With the original SCSI EH I got:
# time dd if=/dev/zero of=/dev/dm-2 bs=4k count=4k oflag=direct
4096+0 records in
4096+0 records out
16777216 bytes (17 MB) copied, 142.652 s, 118 kB/s

real	2m22.657s
user	0m0.013s
sys	0m0.145s

With this patchset I got:
# time dd if=/dev/zero of=/dev/dm-2 bs=4k count=4k oflag=direct
4096+0 records in
4096+0 records out
16777216 bytes (17 MB) copied, 52.1579 s, 322 kB/s

real	0m52.163s
user	0m0.012s
sys	0m0.145s

Test was to disable RSCN on the target port, disable the
target port, and then start the 'dd' command as indicated.

As a proof-of-concept I've also enabled the new timeout
handler for virtio, so that things can be tested out
more easily.
As requested I've also hooked in the new SCSI timeout
handler to SAS.

Changes to the original version:
- Use a private list in scsi_eh_abort_handler to avoid
  list starvation (pointed out by Joern Engel)
- Terminate command aborts when the first abort fails
- Do not attempt command aborts if the host is already in recovery
  or if the device is removed.
- Flush abort workqueue if the device is removed.

Changes to v2:
- Removed eh_entry initialisation
- Convert to per-command workqueue

Comments etc are welcome.


Hannes Reinecke (9):
  scsi: Fix erratic device offline during EH
  blk-timeout: add BLK_EH_SCHEDULED return code
  scsi: improved eh timeout handler
  virtio_scsi: Enable new EH timeout handler
  libsas: Enable new EH timeout handler
  mptsas: Enable new EH timeout handler
  mpt2sas: Enable new EH timeout handler
  mpt3sas: Enable new EH timeout handler
  scsi_transport_fc: Enable new EH timeout handler

 drivers/message/fusion/mptsas.c      |   3 +-
 drivers/message/fusion/mptscsih.c    |   7 ++
 drivers/message/fusion/mptscsih.h    |   1 +
 drivers/scsi/libsas/sas_scsi_host.c  |   2 +-
 drivers/scsi/mpt2sas/mpt2sas_scsih.c |  13 ++-
 drivers/scsi/mpt3sas/mpt3sas_scsih.c |  11 +++
 drivers/scsi/scsi.c                  |   1 +
 drivers/scsi/scsi_error.c            | 171 ++++++++++++++++++++++++++++++-----
 drivers/scsi/scsi_priv.h             |   2 +
 drivers/scsi/scsi_transport_fc.c     |   2 +-
 drivers/scsi/virtio_scsi.c           |   8 ++
 include/linux/blkdev.h               |   1 +
 include/scsi/scsi_cmnd.h             |   2 +
 13 files changed, 199 insertions(+), 25 deletions(-)

-- 
1.7.12.4

[PATCH 1/9] scsi: Fix erratic device offline during EH

[Hannes Reinecke]

Commit 18a4d0a22ed6c54b67af7718c305cd010f09ddf8
(Handle disk devices which can not process medium access commands)
was introduced to offline any device which cannot process medium
access commands.
However, commit 3eef6257de48ff84a5d98ca533685df8a3beaeb8
(Reduce error recovery time by reducing use of TURs) reduced
the number of TURs by sending it only on the first failing
command, which might or might not be a medium access command.
So in combination this results in an erratic device offlining
during EH; if the command where the TUR was sent upon happens
to be a medium access command the device will be set offline,
if not everything proceeds as normal.

So instead of checking the EH command in the ->eh_action
callback we should rather call ->eh_action when we're
about to finish the command _and_ have sent a TUR previously.
This should then set the device offline as advertised.

Cc: Martin K. Petersen <martin.petersen@oracle.com>
Cc: Ewan Milne <emilne@redhat.com>
Signed-off-by: Hannes Reinecke <hare@suse.de>
---
 drivers/scsi/scsi_error.c | 28 +++++++++++++++++++---------
 1 file changed, 19 insertions(+), 9 deletions(-)

diff --git a/drivers/scsi/scsi_error.c b/drivers/scsi/scsi_error.c
index 7f794d4..d708067 100644
--- a/drivers/scsi/scsi_error.c
+++ b/drivers/scsi/scsi_error.c
@@ -885,12 +885,6 @@ retry:
 
 	scsi_eh_restore_cmnd(scmd, &ses);
 
-	if (scmd->request->cmd_type != REQ_TYPE_BLOCK_PC) {
-		struct scsi_driver *sdrv = scsi_cmd_to_driver(scmd);
-		if (sdrv->eh_action)
-			rtn = sdrv->eh_action(scmd, cmnd, cmnd_size, rtn);
-	}
-
 	return rtn;
 }
 
@@ -908,6 +902,18 @@ static int scsi_request_sense(struct scsi_cmnd *scmd)
 	return scsi_send_eh_cmnd(scmd, NULL, 0, SENSE_TIMEOUT, ~0);
 }
 
+static int scsi_eh_action(struct scsi_cmnd *scmd, int rtn)
+{
+	static unsigned char tur_command[6] = {TEST_UNIT_READY, 0, 0, 0, 0, 0};
+
+	if (scmd->request->cmd_type != REQ_TYPE_BLOCK_PC) {
+		struct scsi_driver *sdrv = scsi_cmd_to_driver(scmd);
+		if (sdrv->eh_action)
+			rtn = sdrv->eh_action(scmd, tur_command, 6, rtn);
+	}
+	return rtn;
+}
+
 /**
  * scsi_eh_finish_cmd - Handle a cmd that eh is finished with.
  * @scmd:	Original SCSI cmd that eh has finished.
@@ -1085,7 +1091,9 @@ static int scsi_eh_test_devices(struct list_head *cmd_list,
 
 		list_for_each_entry_safe(scmd, next, cmd_list, eh_entry)
 			if (scmd->device == sdev) {
-				if (finish_cmds)
+				if (finish_cmds &&
+				    (try_stu ||
+				     scsi_eh_action(scmd, SUCCESS) == SUCCESS))
 					scsi_eh_finish_cmd(scmd, done_q);
 				else
 					list_move_tail(&scmd->eh_entry, work_q);
@@ -1224,7 +1232,8 @@ static int scsi_eh_stu(struct Scsi_Host *shost,
 			    !scsi_eh_tur(stu_scmd)) {
 				list_for_each_entry_safe(scmd, next,
 							  work_q, eh_entry) {
-					if (scmd->device == sdev)
+					if (scmd->device == sdev &&
+					    scsi_eh_action(scmd, SUCCESS) == SUCCESS)
 						scsi_eh_finish_cmd(scmd, done_q);
 				}
 			}
@@ -1291,7 +1300,8 @@ static int scsi_eh_bus_device_reset(struct Scsi_Host *shost,
 			    !scsi_eh_tur(bdr_scmd)) {
 				list_for_each_entry_safe(scmd, next,
 							 work_q, eh_entry) {
-					if (scmd->device == sdev)
+					if (scmd->device == sdev &&
+					    scsi_eh_action(scmd, rtn) != FAILED)
 						scsi_eh_finish_cmd(scmd,
 								   done_q);
 				}
-- 
1.7.12.4

[PATCH 2/9] blk-timeout: add BLK_EH_SCHEDULED return code

[Hannes Reinecke]

Add a 'BLK_EH_SCHEDULED' return code for blk-timeout to indicate
that a delayed error recovery has been initiated.

Signed-off-by: Hannes Reinecke <hare@suse.de>
---
 drivers/scsi/scsi_error.c | 4 ++++
 include/linux/blkdev.h    | 1 +
 2 files changed, 5 insertions(+)

diff --git a/drivers/scsi/scsi_error.c b/drivers/scsi/scsi_error.c
index d708067..e76e895 100644
--- a/drivers/scsi/scsi_error.c
+++ b/drivers/scsi/scsi_error.c
@@ -163,6 +163,10 @@ enum blk_eh_timer_return scsi_times_out(struct request *req)
 	else if (host->hostt->eh_timed_out)
 		rtn = host->hostt->eh_timed_out(scmd);
 
+	/* Check for asynchronous command aborts */
+	if (rtn == BLK_EH_SCHEDULED)
+		return BLK_EH_NOT_HANDLED;
+
 	scmd->result |= DID_TIME_OUT << 16;
 
 	if (unlikely(rtn == BLK_EH_NOT_HANDLED &&
diff --git a/include/linux/blkdev.h b/include/linux/blkdev.h
index 2fdb4a4..d846e2b 100644
--- a/include/linux/blkdev.h
+++ b/include/linux/blkdev.h
@@ -238,6 +238,7 @@ enum blk_eh_timer_return {
 	BLK_EH_NOT_HANDLED,
 	BLK_EH_HANDLED,
 	BLK_EH_RESET_TIMER,
+	BLK_EH_SCHEDULED,
 };
 
 typedef enum blk_eh_timer_return (rq_timed_out_fn)(struct request *);
-- 
1.7.12.4

[PATCH 3/9] scsi: improved eh timeout handler

[Hannes Reinecke]

When a command runs into a timeout we need to send an 'ABORT TASK'
TMF. This is typically done by the 'eh_abort_handler' LLDD callback.

Conceptually, however, this function is a normal SCSI command, so
there is no need to enter the error handler.

This patch implements a new scsi_abort_command() function which
invokes an asynchronous function scsi_eh_abort_handler() to
abort the commands via the usual 'eh_abort_handler'.

If abort succeeds the command is either retried or terminated,
depending on the number of allowed retries. However, 'eh_eflags'
records the abort, so if the retry would fail again the
command is pushed onto the error handler without trying to
abort it (again); it'll be cleared up from SCSI EH.

Signed-off-by: Hannes Reinecke <hare@suse.de>
---
 drivers/scsi/scsi.c       |   1 +
 drivers/scsi/scsi_error.c | 139 ++++++++++++++++++++++++++++++++++++++++++----
 drivers/scsi/scsi_priv.h  |   2 +
 include/scsi/scsi_cmnd.h  |   2 +
 4 files changed, 132 insertions(+), 12 deletions(-)

diff --git a/drivers/scsi/scsi.c b/drivers/scsi/scsi.c
index ebe3b0a..06257cf 100644
--- a/drivers/scsi/scsi.c
+++ b/drivers/scsi/scsi.c
@@ -297,6 +297,7 @@ struct scsi_cmnd *scsi_get_command(struct scsi_device *dev, gfp_t gfp_mask)
 
 		cmd->device = dev;
 		INIT_LIST_HEAD(&cmd->list);
+		INIT_WORK(&cmd->abort_work, scmd_eh_abort_handler);
 		spin_lock_irqsave(&dev->list_lock, flags);
 		list_add_tail(&cmd->list, &dev->cmd_list);
 		spin_unlock_irqrestore(&dev->list_lock, flags);
diff --git a/drivers/scsi/scsi_error.c b/drivers/scsi/scsi_error.c
index e76e895..835f7e4 100644
--- a/drivers/scsi/scsi_error.c
+++ b/drivers/scsi/scsi_error.c
@@ -55,6 +55,7 @@ static void scsi_eh_done(struct scsi_cmnd *scmd);
 #define HOST_RESET_SETTLE_TIME  (10)
 
 static int scsi_eh_try_stu(struct scsi_cmnd *scmd);
+static int scsi_try_to_abort_cmd(struct scsi_host_template *, struct scsi_cmnd *);
 
 /* called with shost->host_lock held */
 void scsi_eh_wakeup(struct Scsi_Host *shost)
@@ -102,6 +103,111 @@ static int scsi_host_eh_past_deadline(struct Scsi_Host *shost)
 }
 
 /**
+ * scmd_eh_abort_handler - Handle command aborts
+ * @work:	command to be aborted.
+ */
+void
+scmd_eh_abort_handler(struct work_struct *work)
+{
+	struct scsi_cmnd *scmd =
+		container_of(work, struct scsi_cmnd, abort_work);
+	struct scsi_device *sdev = scmd->device;
+	unsigned long flags;
+	int rtn;
+
+	spin_lock_irqsave(sdev->host->host_lock, flags);
+	if (scsi_host_eh_past_deadline(sdev->host)) {
+		spin_unlock_irqrestore(sdev->host->host_lock, flags);
+		SCSI_LOG_ERROR_RECOVERY(3,
+			scmd_printk(KERN_INFO, scmd,
+				    "eh timeout, not aborting\n"));
+	} else {
+		spin_unlock_irqrestore(sdev->host->host_lock, flags);
+		SCSI_LOG_ERROR_RECOVERY(3,
+			scmd_printk(KERN_INFO, scmd,
+				    "aborting command %p\n", scmd));
+		rtn = scsi_try_to_abort_cmd(sdev->host->hostt, scmd);
+		if (rtn == SUCCESS) {
+			scmd->result |= DID_TIME_OUT << 16;
+			if (!scsi_noretry_cmd(scmd) &&
+			    (++scmd->retries <= scmd->allowed)) {
+				SCSI_LOG_ERROR_RECOVERY(3,
+					scmd_printk(KERN_WARNING, scmd,
+						    "retry aborted command\n"));
+				scsi_queue_insert(scmd, SCSI_MLQUEUE_EH_RETRY);
+			} else {
+				SCSI_LOG_ERROR_RECOVERY(3,
+					scmd_printk(KERN_WARNING, scmd,
+						    "finish aborted command\n"));
+				scsi_finish_command(scmd);
+			}
+			return;
+		}
+		SCSI_LOG_ERROR_RECOVERY(3,
+			scmd_printk(KERN_INFO, scmd,
+				    "abort command failed, rtn %d\n", rtn));
+	}
+
+	if (scsi_eh_scmd_add(scmd, 0)) {
+		SCSI_LOG_ERROR_RECOVERY(3,
+			scmd_printk(KERN_WARNING, scmd,
+				    "terminate aborted command\n"));
+		scmd->result |= DID_TIME_OUT << 16;
+		scsi_finish_command(scmd);
+	}
+}
+
+/**
+ * scsi_abort_command - schedule a command abort
+ * @scmd:	scmd to abort.
+ *
+ * We only need to abort commands after a command timeout
+ */
+enum blk_eh_timer_return
+scsi_abort_command(struct scsi_cmnd *scmd)
+{
+	struct scsi_device *sdev = scmd->device;
+	struct Scsi_Host *shost = sdev->host;
+	unsigned long flags;
+
+	if (scmd->eh_eflags & SCSI_EH_ABORT_SCHEDULED) {
+		/*
+		 * command abort timed out.
+		 */
+		SCSI_LOG_ERROR_RECOVERY(3,
+			scmd_printk(KERN_INFO, scmd,
+				    "scmd %p abort timeout\n", scmd));
+		cancel_work_sync(&scmd->abort_work);
+		return BLK_EH_NOT_HANDLED;
+	}
+
+	/*
+	 * Do not try a command abort if
+	 * SCSI EH has already started.
+	 */
+	spin_lock_irqsave(shost->host_lock, flags);
+	if (scsi_host_in_recovery(shost)) {
+		spin_unlock_irqrestore(shost->host_lock, flags);
+		SCSI_LOG_ERROR_RECOVERY(3,
+			scmd_printk(KERN_INFO, scmd,
+				    "host in recovery, not aborting\n"));
+		return BLK_EH_NOT_HANDLED;
+	}
+
+	if (shost->eh_deadline && !shost->last_reset)
+		shost->last_reset = jiffies;
+	spin_unlock_irqrestore(shost->host_lock, flags);
+
+	scmd->eh_eflags |= SCSI_EH_ABORT_SCHEDULED;
+	SCSI_LOG_ERROR_RECOVERY(3,
+		scmd_printk(KERN_INFO, scmd,
+			    "scmd %p abort scheduled\n", scmd));
+	schedule_work(&scmd->abort_work);
+	return BLK_EH_SCHEDULED;
+}
+EXPORT_SYMBOL_GPL(scsi_abort_command);
+
+/**
  * scsi_eh_scmd_add - add scsi cmd to error handling.
  * @scmd:	scmd to run eh on.
  * @eh_flag:	optional SCSI_EH flag.
@@ -127,6 +233,8 @@ int scsi_eh_scmd_add(struct scsi_cmnd *scmd, int eh_flag)
 		shost->last_reset = jiffies;
 
 	ret = 1;
+	if (scmd->eh_eflags & SCSI_EH_ABORT_SCHEDULED)
+		eh_flag &= ~SCSI_EH_CANCEL_CMD;
 	scmd->eh_eflags |= eh_flag;
 	list_add_tail(&scmd->eh_entry, &shost->eh_cmd_q);
 	shost->host_failed++;
@@ -1532,6 +1640,8 @@ int scsi_noretry_cmd(struct scsi_cmnd *scmd)
 	switch (host_byte(scmd->result)) {
 	case DID_OK:
 		break;
+	case DID_TIME_OUT:
+		goto check_type;
 	case DID_BUS_BUSY:
 		return (scmd->request->cmd_flags & REQ_FAILFAST_TRANSPORT);
 	case DID_PARITY:
@@ -1545,18 +1655,19 @@ int scsi_noretry_cmd(struct scsi_cmnd *scmd)
 		return (scmd->request->cmd_flags & REQ_FAILFAST_DRIVER);
 	}
 
-	switch (status_byte(scmd->result)) {
-	case CHECK_CONDITION:
-		/*
-		 * assume caller has checked sense and determinted
-		 * the check condition was retryable.
-		 */
-		if (scmd->request->cmd_flags & REQ_FAILFAST_DEV ||
-		    scmd->request->cmd_type == REQ_TYPE_BLOCK_PC)
-			return 1;
-	}
+	switch (status_byte(scmd->result) != CHECK_CONDITION)
+		return 0;
 
-	return 0;
+check_type:
+	/*
+	 * assume caller has checked sense and determinted
+	 * the check condition was retryable.
+	 */
+	if (scmd->request->cmd_flags & REQ_FAILFAST_DEV ||
+	    scmd->request->cmd_type == REQ_TYPE_BLOCK_PC)
+		return 1;
+	else
+		return 0;
 }
 
 /**
@@ -1606,9 +1717,13 @@ int scsi_decide_disposition(struct scsi_cmnd *scmd)
 		 * looks good.  drop through, and check the next byte.
 		 */
 		break;
+	case DID_ABORT:
+		if (scmd->eh_eflags & SCSI_EH_ABORT_SCHEDULED) {
+			scmd->result |= DID_TIME_OUT << 16;
+			return SUCCESS;
+		}
 	case DID_NO_CONNECT:
 	case DID_BAD_TARGET:
-	case DID_ABORT:
 		/*
 		 * note - this means that we just report the status back
 		 * to the top level driver, not that we actually think
diff --git a/drivers/scsi/scsi_priv.h b/drivers/scsi/scsi_priv.h
index 8f9a0ca..f079a59 100644
--- a/drivers/scsi/scsi_priv.h
+++ b/drivers/scsi/scsi_priv.h
@@ -19,6 +19,7 @@ struct scsi_nl_hdr;
  * Scsi Error Handler Flags
  */
 #define SCSI_EH_CANCEL_CMD	0x0001	/* Cancel this cmd */
+#define SCSI_EH_ABORT_SCHEDULED	0x0002	/* Abort has been scheduled */
 
 #define SCSI_SENSE_VALID(scmd) \
 	(((scmd)->sense_buffer[0] & 0x70) == 0x70)
@@ -66,6 +67,7 @@ extern int __init scsi_init_devinfo(void);
 extern void scsi_exit_devinfo(void);
 
 /* scsi_error.c */
+extern void scmd_eh_abort_handler(struct work_struct *work);
 extern enum blk_eh_timer_return scsi_times_out(struct request *req);
 extern int scsi_error_handler(void *host);
 extern int scsi_decide_disposition(struct scsi_cmnd *cmd);
diff --git a/include/scsi/scsi_cmnd.h b/include/scsi/scsi_cmnd.h
index de5f5d8..a2f062e 100644
--- a/include/scsi/scsi_cmnd.h
+++ b/include/scsi/scsi_cmnd.h
@@ -55,6 +55,7 @@ struct scsi_cmnd {
 	struct scsi_device *device;
 	struct list_head list;  /* scsi_cmnd participates in queue lists */
 	struct list_head eh_entry; /* entry for the host eh_cmd_q */
+	struct work_struct abort_work;
 	int eh_eflags;		/* Used by error handlr */
 
 	/*
@@ -144,6 +145,7 @@ extern void scsi_put_command(struct scsi_cmnd *);
 extern void __scsi_put_command(struct Scsi_Host *, struct scsi_cmnd *,
 			       struct device *);
 extern void scsi_finish_command(struct scsi_cmnd *cmd);
+extern enum blk_eh_timer_return scsi_abort_command(struct scsi_cmnd *cmd);
 
 extern void *scsi_kmap_atomic_sg(struct scatterlist *sg, int sg_count,
 				 size_t *offset, size_t *len);
-- 
1.7.12.4

[PATCH 4/9] virtio_scsi: Enable new EH timeout handler

[Hannes Reinecke]

Signed-off-by: Hannes Reinecke <hare@suse.de>
Acked-by: Paolo Bonzini <pbonzini@redhat.com>
---
 drivers/scsi/virtio_scsi.c | 8 ++++++++
 1 file changed, 8 insertions(+)

diff --git a/drivers/scsi/virtio_scsi.c b/drivers/scsi/virtio_scsi.c
index 2168258..f23b9ef 100644
--- a/drivers/scsi/virtio_scsi.c
+++ b/drivers/scsi/virtio_scsi.c
@@ -630,6 +630,12 @@ static int virtscsi_device_reset(struct scsi_cmnd *sc)
 	return virtscsi_tmf(vscsi, cmd);
 }
 
+static enum blk_eh_timer_return virtscsi_timedout(struct scsi_cmnd *scmd)
+{
+	scsi_abort_command(scmd);
+	return BLK_EH_SCHEDULED;
+}
+
 static int virtscsi_abort(struct scsi_cmnd *sc)
 {
 	struct virtio_scsi *vscsi = shost_priv(sc->device->host);
@@ -683,6 +689,7 @@ static struct scsi_host_template virtscsi_host_template_single = {
 	.queuecommand = virtscsi_queuecommand_single,
 	.eh_abort_handler = virtscsi_abort,
 	.eh_device_reset_handler = virtscsi_device_reset,
+	.eh_timed_out = virtscsi_timedout,
 
 	.can_queue = 1024,
 	.dma_boundary = UINT_MAX,
@@ -699,6 +706,7 @@ static struct scsi_host_template virtscsi_host_template_multi = {
 	.queuecommand = virtscsi_queuecommand_multi,
 	.eh_abort_handler = virtscsi_abort,
 	.eh_device_reset_handler = virtscsi_device_reset,
+	.eh_timed_out = virtscsi_timedout,
 
 	.can_queue = 1024,
 	.dma_boundary = UINT_MAX,
-- 
1.7.12.4

[PATCH 5/9] libsas: Enable new EH timeout handler

[Hannes Reinecke]

Signed-off-by: Hannes Reinecke <hare@suse.de>
---
 drivers/scsi/libsas/sas_scsi_host.c | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/drivers/scsi/libsas/sas_scsi_host.c b/drivers/scsi/libsas/sas_scsi_host.c
index 6e795a1..9d5bd29 100644
--- a/drivers/scsi/libsas/sas_scsi_host.c
+++ b/drivers/scsi/libsas/sas_scsi_host.c
@@ -864,7 +864,7 @@ enum blk_eh_timer_return sas_scsi_timed_out(struct scsi_cmnd *cmd)
 {
 	scmd_printk(KERN_DEBUG, cmd, "command %p timed out\n", cmd);
 
-	return BLK_EH_NOT_HANDLED;
+	return scsi_abort_command(cmd);
 }
 
 int sas_ioctl(struct scsi_device *sdev, int cmd, void __user *arg)
-- 
1.7.12.4

[PATCH 6/9] mptsas: Enable new EH timeout handler

[Hannes Reinecke]

Signed-off-by: Hannes Reinecke <hare@suse.de>
---
 drivers/message/fusion/mptsas.c   | 3 ++-
 drivers/message/fusion/mptscsih.c | 7 +++++++
 drivers/message/fusion/mptscsih.h | 1 +
 3 files changed, 10 insertions(+), 1 deletion(-)

diff --git a/drivers/message/fusion/mptsas.c b/drivers/message/fusion/mptsas.c
index dd239bd..b3c87b2 100644
--- a/drivers/message/fusion/mptsas.c
+++ b/drivers/message/fusion/mptsas.c
@@ -1986,7 +1986,8 @@ static struct scsi_host_template mptsas_driver_template = {
 	.slave_configure		= mptsas_slave_configure,
 	.target_destroy			= mptsas_target_destroy,
 	.slave_destroy			= mptscsih_slave_destroy,
-	.change_queue_depth 		= mptscsih_change_queue_depth,
+	.change_queue_depth		= mptscsih_change_queue_depth,
+	.eh_timed_out			= mptscsih_timed_out,
 	.eh_abort_handler		= mptscsih_abort,
 	.eh_device_reset_handler	= mptscsih_dev_reset,
 	.eh_host_reset_handler		= mptscsih_host_reset,
diff --git a/drivers/message/fusion/mptscsih.c b/drivers/message/fusion/mptscsih.c
index 727819c..e743e84 100644
--- a/drivers/message/fusion/mptscsih.c
+++ b/drivers/message/fusion/mptscsih.c
@@ -1679,6 +1679,13 @@ mptscsih_get_tm_timeout(MPT_ADAPTER *ioc)
 	}
 }
 
+enum blk_eh_timer_return
+mptscsih_timed_out(struct scsi_cmnd *SCpnt)
+{
+	return scsi_abort_command(SCpnt);
+}
+EXPORT_SYMBOL(mptscsih_timed_out);
+
 /*=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=*/
 /**
  *	mptscsih_abort - Abort linux scsi_cmnd routine, new_eh variant
diff --git a/drivers/message/fusion/mptscsih.h b/drivers/message/fusion/mptscsih.h
index 83f5031..3f2dd05 100644
--- a/drivers/message/fusion/mptscsih.h
+++ b/drivers/message/fusion/mptscsih.h
@@ -118,6 +118,7 @@ extern int mptscsih_IssueTaskMgmt(MPT_SCSI_HOST *hd, u8 type, u8 channel,
 	u8 id, int lun, int ctx2abort, ulong timeout);
 extern void mptscsih_slave_destroy(struct scsi_device *device);
 extern int mptscsih_slave_configure(struct scsi_device *device);
+enum blk_eh_timer_return mptscsih_timed_out(struct scsi_cmnd *SCpnt);
 extern int mptscsih_abort(struct scsi_cmnd * SCpnt);
 extern int mptscsih_dev_reset(struct scsi_cmnd * SCpnt);
 extern int mptscsih_bus_reset(struct scsi_cmnd * SCpnt);
-- 
1.7.12.4

[PATCH 7/9] mpt2sas: Enable new EH timeout handler

[Hannes Reinecke]

Signed-off-by: Hannes Reinecke <hare@suse.de>
---
 drivers/scsi/mpt2sas/mpt2sas_scsih.c | 13 ++++++++++++-
 1 file changed, 12 insertions(+), 1 deletion(-)

diff --git a/drivers/scsi/mpt2sas/mpt2sas_scsih.c b/drivers/scsi/mpt2sas/mpt2sas_scsih.c
index c6bdc92..a557e74 100644
--- a/drivers/scsi/mpt2sas/mpt2sas_scsih.c
+++ b/drivers/scsi/mpt2sas/mpt2sas_scsih.c
@@ -2565,6 +2565,16 @@ _scsih_tm_display_info(struct MPT2SAS_ADAPTER *ioc, struct scsi_cmnd *scmd)
 }
 
 /**
+ * _scsih_timed_out - eh timeout handler
+ * @scmd: pointer to scsi command object
+ */
+static enum blk_eh_timer_return
+_scsih_timed_out(struct scsi_cmnd *scmd)
+{
+	return scsi_abort_command(scmd);
+}
+
+/**
  * _scsih_abort - eh threads main abort routine
  * @scmd: pointer to scsi command object
  *
@@ -7513,8 +7523,9 @@ static struct scsi_host_template scsih_driver_template = {
 	.slave_destroy			= _scsih_slave_destroy,
 	.scan_finished			= _scsih_scan_finished,
 	.scan_start			= _scsih_scan_start,
-	.change_queue_depth 		= _scsih_change_queue_depth,
+	.change_queue_depth		= _scsih_change_queue_depth,
 	.change_queue_type		= _scsih_change_queue_type,
+	.eh_timed_out			= _scsih_timed_out,
 	.eh_abort_handler		= _scsih_abort,
 	.eh_device_reset_handler	= _scsih_dev_reset,
 	.eh_target_reset_handler	= _scsih_target_reset,
-- 
1.7.12.4

[PATCH 8/9] mpt3sas: Enable new EH timeout handler

[Hannes Reinecke]

Signed-off-by: Hannes Reinecke <hare@suse.de>
---
 drivers/scsi/mpt3sas/mpt3sas_scsih.c | 11 +++++++++++
 1 file changed, 11 insertions(+)

diff --git a/drivers/scsi/mpt3sas/mpt3sas_scsih.c b/drivers/scsi/mpt3sas/mpt3sas_scsih.c
index dcbf7c8..3a35ddc 100644
--- a/drivers/scsi/mpt3sas/mpt3sas_scsih.c
+++ b/drivers/scsi/mpt3sas/mpt3sas_scsih.c
@@ -2228,6 +2228,16 @@ _scsih_tm_display_info(struct MPT3SAS_ADAPTER *ioc, struct scsi_cmnd *scmd)
 }
 
 /**
+ * _scsih_timed_out - eh timeout handler
+ * @scmd: pointer to scsi command object
+ */
+static enum blk_eh_timer_return
+_scsih_timed_out(struct scsi_cmnd *scmd)
+{
+	return scsi_abort_command(scmd);
+}
+
+/**
  * _scsih_abort - eh threads main abort routine
  * @scmd: pointer to scsi command object
  *
@@ -7230,6 +7240,7 @@ static struct scsi_host_template scsih_driver_template = {
 	.scan_start			= _scsih_scan_start,
 	.change_queue_depth		= _scsih_change_queue_depth,
 	.change_queue_type		= _scsih_change_queue_type,
+	.eh_timed_out			= _scsih_timed_out,
 	.eh_abort_handler		= _scsih_abort,
 	.eh_device_reset_handler	= _scsih_dev_reset,
 	.eh_target_reset_handler	= _scsih_target_reset,
-- 
1.7.12.4

[PATCH 9/9] scsi_transport_fc: Enable new EH timeout handler

[Hannes Reinecke]

Signed-off-by: Hannes Reinecke <hare@suse.de>
---
 drivers/scsi/scsi_transport_fc.c | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/drivers/scsi/scsi_transport_fc.c b/drivers/scsi/scsi_transport_fc.c
index e106c27..1e1de9f 100644
--- a/drivers/scsi/scsi_transport_fc.c
+++ b/drivers/scsi/scsi_transport_fc.c
@@ -2079,7 +2079,7 @@ fc_timed_out(struct scsi_cmnd *scmd)
 	if (rport->port_state == FC_PORTSTATE_BLOCKED)
 		return BLK_EH_RESET_TIMER;
 
-	return BLK_EH_NOT_HANDLED;
+	return scsi_abort_command(scmd);
 }
 
 /*
-- 
1.7.12.4

Re: [PATCHv3 0/9] New EH command timeout handler

[Ren Mingxin]

Hi, Hannes:

On 07/01/2013 10:24 PM, Hannes Reinecke wrote:
> With the original SCSI EH I got:
> # time dd if=/dev/zero of=/dev/dm-2 bs=4k count=4k oflag=direct
> 4096+0 records in
> 4096+0 records out
> 16777216 bytes (17 MB) copied, 142.652 s, 118 kB/s
>
> real	2m22.657s
> user	0m0.013s
> sys	0m0.145s
>
> With this patchset I got:
> # time dd if=/dev/zero of=/dev/dm-2 bs=4k count=4k oflag=direct
> 4096+0 records in
> 4096+0 records out
> 16777216 bytes (17 MB) copied, 52.1579 s, 322 kB/s
>
> real	0m52.163s
> user	0m0.012s
> sys	0m0.145s
>
> Test was to disable RSCN on the target port, disable the
> target port, and then start the 'dd' command as indicated.

Do you mean disabling RSCN/port is enough? I'm afraid I couldn't
reproduce the problem by your steps. Both with and without your
patchset are the same 'dd' result: 27s. Please let me know where I
neglected or mistook:

1) I made a dm-multipath target 'dm-0' whose grouping policy was
    failover;
2) Disable RSCN/port via brocade fc switch:
    SW300:root> portcfg rscnsupr 15 --enable; portDisable 15
3) Start the 'dd' command:
    # time dd if=/dev/zero of=/dev/dm-0 bs=4k count=4k oflag=direct
    dd: writing `/dev/sde': Input/output error
    1+0 records in
    0+0 records out
    0 bytes (0 B) copied, 27.8588 s, 0.0 kB/s

    real    0m27.860s
    user    0m0.001s
    sys     0m0.000s
#) Corresponding logs in /var/log/messages
Jul  9 14:56:06 build kernel: lpfc 0000:0d:00.1: 1:1305 Link Down Event 
x4 received Data: x4 x20 x110 x0 x0
Jul  9 14:56:36 build kernel: rport-3:0-2: blocked FC remote port time 
out: removing target and saving binding
Jul  9 14:56:36 build kernel: sd 3:0:0:0: rejecting I/O to offline device
Jul  9 14:56:36 build kernel: lpfc 0000:0d:00.1: 1:(0):0203 Devloss 
timeout on WWPN 20:41:00:0b:5d:6a:14:e7 NPort x620700 Data: x0 x8 x0
Jul  9 14:56:36 build kernel: sd 3:0:0:0: [sde] Synchronizing SCSI cache
Jul  9 14:56:36 build kernel: sd 3:0:0:0: [sde]
Jul  9 14:56:36 build kernel: Result: hostbyte=DID_NO_CONNECT 
driverbyte=DRIVER_OK
Jul  9 14:56:36 build kernel: sd 3:0:0:1: [sdf] Synchronizing SCSI cache
Jul  9 14:56:36 build kernel: sd 3:0:0:1: [sdf]
Jul  9 14:56:36 build kernel: Result: hostbyte=DID_NO_CONNECT 
driverbyte=DRIVER_OK
Jul  9 14:56:36 build multipathd: sdf: remove path (uevent)
Jul  9 14:56:36 build multipathd: mpatha: load table [0 104857600 
multipath 1 queue_if_no_path 0 1 1 round-robin 0 1 1 8:112 1]
Jul  9 14:56:36 build multipathd: sdf: path removed from map mpatha
Jul  9 14:56:36 build udevd-work[8420]: error opening 
ATTR{/sys/devices/pci0000:00/0000:00:03.0/0000:01:00.0/0000:02:01.0/0000:0a:00.0/0000:0b:01.0/0000:0d:00.1/host3/rport-3:0-2/target3:0:0/3:0:0:0/block/sde/queue/iosched/slice_idle} 
for writing: No such file or directory
Jul  9 14:56:36 build udevd-work[8420]: error opening 
ATTR{/sys/devices/pci0000:00/0000:00:03.0/0000:01:00.0/0000:02:01.0/0000:0a:00.0/0000:0b:01.0/0000:0d:00.1/host3/rport-3:0-2/target3:0:0/3:0:0:0/block/sde/queue/iosched/quantum} 
for writing: No such file or directory
Jul  9 14:56:36 build multipathd: sde: remove path (uevent)
Jul  9 14:56:36 build multipathd: mpathb: load table [0 104857600 
multipath 1 queue_if_no_path 0 1 1 round-robin 0 1 1 8:96 1]
Jul  9 14:56:36 build multipathd: sde: path removed from map mpathb
* there are two disks sde and sdf connected via port 15

Another question:

I also tried to produce timeouts by modifying Yasui's module(please
see APPENDIX A):
http://www.spinics.net/lists/linux-scsi/msg35091.html

But I got a bug with your this patchset by follwing steps(there was
not such bug without your patchset):

# grep lpfc_template /proc/kallsyms
ffffffffa00f9240 d lpfc_template    [lpfc]
# multipath -ll
...
mpathb (36000b5d0006a0000006a14e7000c0000) dm-1 FUJITSU,ETERNUS_DX400
size=50G features='1 queue_if_no_path' hwhandler='0' wp=rw
|-+- policy='round-robin 0' prio=130 status=active
| `- 2:0:0:1 sdf 8:80  active ready running
`-+- policy='round-robin 0' prio=130 status=enabled
   `- 3:0:0:1 sdh 8:112 active ready running
# insmod scsi_tmo_mod.ko param=0xffffffffa00f9240,2:0:0:1; time dd 
if=/dev/zero of=/dev/dm-1 bs=4k count=4k oflag=direct
4096+0 records in
4096+0 records out
16777216 bytes (17 MB) copied, 151.194 s, 111 kB/s

real    2m31.195s
user    0m0.004s
sys    0m0.111s

Please see logs in APPENDIX B. Do you think this bug is irrelevant to
your patchset?

Thanks,
Ren

APPENDIX A:

/*
  * scsi timeout injection module
  */
#include <linux/module.h>
#include <scsi/scsi_cmnd.h>
#include <scsi/scsi_host.h>
#include <scsi/scsi_device.h>

static struct scsi_host_template *sht;
static char config[32];

static struct target {
         short host;
         uint channel;
         uint id;
         uint lun;
} st;

static int (*org_qc)(struct Scsi_Host *, struct scsi_cmnd *);


static inline int check_dev(struct target *st, struct scsi_cmnd *cmd)
{
         return (st->host == cmd->device->host->host_no &&
                 st->channel == cmd->device->channel &&
                 st->id == cmd->device->id &&
                 st->lun == cmd->device->lun);
}

static int dbg_qc(struct Scsi_Host *shost, struct scsi_cmnd *cmd)
{
         int ret = 0;

         preempt_disable();
         if (check_dev(&st, cmd))
                 goto done;
         ret = org_qc(shost, cmd);
done:
         preempt_enable();
         return ret;
}

static int __init scsi_timeout_module_init(void)
{
         int ret;

         ret = sscanf(config, "%lx,%hd:%d:%d:%d",
                      (ulong *)&sht,
&st.host, &st.channel, &st.id, &st.lun);
         if (ret != 5) {
                 printk(KERN_INFO "scsi_timeout_module: invalid options\n");
                 return -1;
         }

         org_qc = sht->queuecommand;
         sht->queuecommand = dbg_qc;

         printk(KERN_INFO
                "scsi timeout injection: %hd:%d:%d:%d\n",
                st.host, st.channel, st.id, st.lun);

         return 0;
}

static void __exit scsi_timeout_module_exit(void)
{
         sht->queuecommand = org_qc;
         synchronize_sched();
}

module_init(scsi_timeout_module_init);
module_exit(scsi_timeout_module_exit);
module_param_string(param, config, 32, 0);

MODULE_AUTHOR("Takahiro Yasui <tyasui@xxxxxxxxxx>");
MODULE_LICENSE("GPL");

APPENDIX B:

Jul 11 11:51:06 build kernel: scsi timeout injection: 2:0:0:1
Jul 11 11:51:37 build kernel: sd 2:0:0:1: [sdf] scmd ffff88046a8af200 
abort scheduled
Jul 11 11:51:37 build kernel: sd 2:0:0:1: [sdf] aborting command 
ffff88046a8af200
Jul 11 11:51:37 build kernel: sd 2:0:0:1: [sdf] retry aborted command
Jul 11 11:51:45 build kernel: sd 2:0:0:1: [sdf] scmd ffff88046a8181c0 
abort scheduled
Jul 11 11:51:45 build kernel: sd 2:0:0:1: [sdf] aborting command 
ffff88046a8181c0
Jul 11 11:51:45 build kernel: sd 2:0:0:1: [sdf] finish aborted command
Jul 11 11:52:16 build kernel: sd 2:0:0:1: [sdf] scmd ffff88046a8af200 
abort timeout
Jul 11 11:52:16 build kernel: BUG: scheduling while atomic: 
swapper/2/0/0x10000100
Jul 11 11:52:16 build kernel: Modules linked in: scsi_tmo_mod(OF) 
ip6table_filter ip6_tables ebtable_nat ebtables nf_conntrack_ipv4 
nf_defrag_ipv4 xt_state nf_conntrack ipt_REJECT xt_CHECKSUM 
iptable_mangle iptable_filter ip_tables bridge autofs4 sunrpc 8021q garp 
stp llc ipv6 ext3 jbd dm_mirror dm_region_hash dm_log dm_round_robin 
dm_multipath vhost_net macvtap macvlan tun uinput raid1 iTCO_wdt 
iTCO_vendor_support coretemp kvm_intel kvm crc32c_intel microcode pcspkr 
i2c_i801 lpc_ich mfd_core ioatdma i7core_edac edac_core sg e1000e dm_mod 
igb dca i2c_algo_bit i2c_core ptp pps_core ext4(F) jbd2(F) mbcache(F) 
sd_mod(F) lpfc(F) scsi_transport_fc(F) scsi_tgt(F) crc_t10dif(F) 
mptsas(F) mptscsih(F) mptbase(F) scsi_transport_sas(F) [last unloaded: 
speedstep_lib]
Jul 11 11:52:16 build kernel: CPU: 2 PID: 0 Comm: swapper/2 Tainted: 
GF          O 3.10.0hannes+ #9
Jul 11 11:52:16 build kernel: Hardware name: ...
Jul 11 11:52:16 build kernel: 0000000000000002 ffff88047ee43b88 
ffffffff8153aac4 ffff88047ee43b98
Jul 11 11:52:16 build kernel: ffffffff8107389d ffff88047ee43c28 
ffffffff8153c746 ffff88046ee0bfd8
Jul 11 11:52:16 build kernel: 0000000000012d00 ffff88046ee0a010 
0000000000012d00 0000000000012d00
Jul 11 11:52:16 build kernel: Call Trace:
Jul 11 11:52:16 build kernel: <IRQ>  [<ffffffff8153aac4>] 
dump_stack+0x19/0x1d
Jul 11 11:52:16 build kernel: [<ffffffff8107389d>] __schedule_bug+0x4d/0x60
Jul 11 11:52:16 build kernel: [<ffffffff8153c746>] __schedule+0x646/0x6f0
Jul 11 11:52:16 build kernel: [<ffffffff81081daa>] ? 
enqueue_entity+0x22a/0x920
Jul 11 11:52:16 build kernel: [<ffffffff8107749a>] __cond_resched+0x2a/0x40
Jul 11 11:52:16 build kernel: [<ffffffff8153c880>] _cond_resched+0x30/0x40
Jul 11 11:52:16 build kernel: [<ffffffff8105fecc>] 
start_flush_work+0x2c/0x140
Jul 11 11:52:16 build kernel: [<ffffffff8105fffa>] flush_work+0x1a/0x40
Jul 11 11:52:16 build kernel: [<ffffffff8106027e>] 
__cancel_work_timer+0x7e/0x110
Jul 11 11:52:16 build kernel: [<ffffffff81060340>] 
cancel_work_sync+0x10/0x20
Jul 11 11:52:16 build kernel: [<ffffffff813799f6>] 
scsi_abort_command+0x36/0x220
Jul 11 11:52:16 build kernel: [<ffffffffa005f9eb>] 
fc_timed_out+0x3b/0x40 [scsi_transport_fc]
Jul 11 11:52:16 build kernel: [<ffffffff8137a257>] scsi_times_out+0x67/0x120
Jul 11 11:52:16 build kernel: [<ffffffff8123980b>] 
blk_rq_timed_out+0x1b/0x70
Jul 11 11:52:16 build kernel: [<ffffffff812399f0>] 
blk_rq_timed_out_timer+0x100/0x150
Jul 11 11:52:16 build kernel: [<ffffffff8105f610>] ? 
__queue_work+0x360/0x360
Jul 11 11:52:16 build kernel: [<ffffffff812398f0>] ? 
blk_abort_request+0x40/0x40
Jul 11 11:52:16 build kernel: [<ffffffff810511f9>] call_timer_fn+0x49/0x120
Jul 11 11:52:16 build kernel: [<ffffffff810517f5>] 
run_timer_softirq+0x225/0x290
Jul 11 11:52:16 build kernel: [<ffffffff812398f0>] ? 
blk_abort_request+0x40/0x40
Jul 11 11:52:16 build kernel: [<ffffffff81049a4f>] __do_softirq+0xef/0x260
Jul 11 11:52:16 build kernel: [<ffffffff81049cb5>] irq_exit+0xb5/0xc0
Jul 11 11:52:16 build kernel: [<ffffffff8154822e>] 
smp_apic_timer_interrupt+0x6e/0x99
Jul 11 11:52:16 build kernel: [<ffffffff8154744a>] 
apic_timer_interrupt+0x6a/0x70
Jul 11 11:52:16 build kernel: <EOI>  [<ffffffff8109b5f2>] ? 
clockevents_notify+0x52/0x150
Jul 11 11:52:16 build kernel: [<ffffffff8142da03>] ? 
cpuidle_enter_state+0x53/0xd0
Jul 11 11:52:16 build kernel: [<ffffffff8142d9ff>] ? 
cpuidle_enter_state+0x4f/0xd0
Jul 11 11:52:16 build kernel: [<ffffffff8142de2f>] 
cpuidle_idle_call+0xcf/0x160
Jul 11 11:52:16 build kernel: [<ffffffff8100ab1e>] arch_cpu_idle+0xe/0x30
Jul 11 11:52:16 build kernel: [<ffffffff81093275>] cpu_idle_loop+0x65/0x1f0
Jul 11 11:52:16 build kernel: [<ffffffff81093470>] 
cpu_startup_entry+0x70/0x80
Jul 11 11:52:16 build kernel: [<ffffffff81532cf7>] start_secondary+0xc7/0xc9
Jul 11 11:52:16 build kernel: sd 2:0:0:1: [sdf] host in recovery, not 
aborting
Jul 11 11:52:16 build kernel: scsi_eh_2: waking up 0/2/2
Jul 11 11:52:16 build kernel: sd 2:0:0:1: scsi_eh_prt_fail_stats: cmds 
failed: 1, cancel: 1
Jul 11 11:52:16 build kernel: Total of 2 commands on 1 devices require 
eh work
Jul 11 11:52:16 build kernel: sd 2:0:0:1: [sdf] scsi_eh_2: requesting sense
Jul 11 11:52:26 build kernel: scsi_send_eh_cmnd: scmd: ffff88046a8af200, 
timeleft: 0
Jul 11 11:52:26 build kernel: scsi_eh_2: aborting cmd:0xffff88046ce48980
Jul 11 11:52:36 build kernel: scsi_send_eh_cmnd: scmd: ffff88046ce48980, 
timeleft: 0
Jul 11 11:52:36 build kernel: scsi_eh_tur: scmd ffff88046ce48980 rtn 2003
Jul 11 11:52:36 build kernel: scsi_eh_2: Sending BDR sdev: 
0xffff88046a84b000
Jul 11 11:52:36 build kernel: lpfc 0000:0d:00.0: 0:(0):0713 SCSI layer 
issued Device Reset (0, 1) return x2002
Jul 11 11:52:46 build kernel: scsi_send_eh_cmnd: scmd: ffff88046a8af200, 
timeleft: 0
Jul 11 11:52:46 build kernel: scsi_eh_tur: scmd ffff88046a8af200 rtn 2003
Jul 11 11:52:46 build kernel: scsi_eh_2: Sending target reset to target 0
Jul 11 11:52:46 build kernel: lpfc 0000:0d:00.0: 0:(0):0723 SCSI layer 
issued Target Reset (0, 1) return x2002
Jul 11 11:52:56 build kernel: scsi_send_eh_cmnd: scmd: ffff88046a8af200, 
timeleft: 0
Jul 11 11:52:56 build kernel: scsi_eh_tur: scmd ffff88046a8af200 rtn 2003
Jul 11 11:52:56 build kernel: scsi_eh_2: Sending BRST chan: 0
Jul 11 11:52:56 build kernel: scsi_try_bus_reset: Snd Bus RST
Jul 11 11:52:56 build kernel: lpfc 0000:0d:00.0: 0:(0):0714 SCSI layer 
issued Bus Reset Data: x2002
Jul 11 11:53:16 build kernel: scsi_send_eh_cmnd: scmd: ffff88046a8af200, 
timeleft: 0
Jul 11 11:53:16 build kernel: scsi_eh_tur: scmd ffff88046a8af200 rtn 2003
Jul 11 11:53:16 build kernel: scsi_eh_2: Sending HRST
Jul 11 11:53:16 build kernel: scsi_try_host_reset: Snd Host RST
Jul 11 11:53:16 build kernel: lpfc 0000:0d:00.0: 0:(0):3172 SCSI layer 
issued Host Reset Data:
Jul 11 11:53:17 build kernel: lpfc 0000:0d:00.0: 0:1303 Link Up Event x1 
received Data: x1 xf7 x20 x0 x0 x0 0
Jul 11 11:53:37 build kernel: scsi_send_eh_cmnd: scmd: ffff88046a8af200, 
timeleft: 0
Jul 11 11:53:37 build kernel: scsi_eh_tur: scmd ffff88046a8af200 rtn 2003
Jul 11 11:53:37 build kernel: sd 2:0:0:1: Device offlined - not ready 
after error recovery
Jul 11 11:53:37 build kernel: sd 2:0:0:1: Device offlined - not ready 
after error recovery
Jul 11 11:53:37 build kernel: scsi_eh_2: flush finish cmd: ffff88046a8af200
Jul 11 11:53:37 build kernel: sd 2:0:0:1: [sdf] Unhandled error code
Jul 11 11:53:37 build kernel: sd 2:0:0:1: [sdf]
Jul 11 11:53:37 build kernel: Result: hostbyte=DID_TIME_OUT 
driverbyte=DRIVER_OK
Jul 11 11:53:37 build kernel: sd 2:0:0:1: [sdf] CDB:
Jul 11 11:53:37 build kernel: Write(10): 2a 00 00 00 00 00 00 00 08 00
Jul 11 11:53:37 build kernel: end_request: I/O error, dev sdf, sector 0
Jul 11 11:53:37 build kernel: scsi_eh_2: flush finish cmd: ffff88046ce48980
Jul 11 11:53:37 build kernel: device-mapper: multipath: Failing path 8:80.
Jul 11 11:53:37 build kernel: scsi_eh_2 waking up host to restart
Jul 11 11:53:37 build kernel: scsi_eh_2: sleeping
Jul 11 11:53:37 build multipathd: 8:80: mark as failed
Jul 11 11:53:37 build multipathd: mpathb: remaining active paths: 1
Jul 11 11:53:37 build multipathd: mpathb: switch to path group #2
Jul 11 11:53:48 build kernel: rport-2:0-4: blocked FC remote port time 
out: removing rport

Re: [PATCHv3 0/9] New EH command timeout handler

[Hannes Reinecke]

On 07/12/2013 06:14 AM, Ren Mingxin wrote:
> Hi, Hannes:
> 
> On 07/01/2013 10:24 PM, Hannes Reinecke wrote:
>> With the original SCSI EH I got:
>> # time dd if=/dev/zero of=/dev/dm-2 bs=4k count=4k oflag=direct
>> 4096+0 records in
>> 4096+0 records out
>> 16777216 bytes (17 MB) copied, 142.652 s, 118 kB/s
>>
>> real    2m22.657s
>> user    0m0.013s
>> sys    0m0.145s
>>
>> With this patchset I got:
>> # time dd if=/dev/zero of=/dev/dm-2 bs=4k count=4k oflag=direct
>> 4096+0 records in
>> 4096+0 records out
>> 16777216 bytes (17 MB) copied, 52.1579 s, 322 kB/s
>>
>> real    0m52.163s
>> user    0m0.012s
>> sys    0m0.145s
>>
>> Test was to disable RSCN on the target port, disable the
>> target port, and then start the 'dd' command as indicated.
> 
> Do you mean disabling RSCN/port is enough? I'm afraid I couldn't
> reproduce the problem by your steps. Both with and without your
> patchset are the same 'dd' result: 27s. Please let me know where I
> neglected or mistook:
> 
> 1) I made a dm-multipath target 'dm-0' whose grouping policy was
>    failover;
> 2) Disable RSCN/port via brocade fc switch:
>    SW300:root> portcfg rscnsupr 15 --enable; portDisable 15
> 3) Start the 'dd' command:
>    # time dd if=/dev/zero of=/dev/dm-0 bs=4k count=4k oflag=direct
>    dd: writing `/dev/sde': Input/output error
>    1+0 records in
>    0+0 records out
>    0 bytes (0 B) copied, 27.8588 s, 0.0 kB/s
> 
>    real    0m27.860s
>    user    0m0.001s
>    sys     0m0.000s

You are aware that you have to disable RSCNs on the _target_ port,
right?
Disabling RSCNs on the _initiator_ ports is a well-tested case, and
the one which actually makes sense (and is even implemented in
QLogic switches).
Disabling RSCNs for the _target_ port, OTOH, has a very questionable
nature (hence QLogic switches don't even allow you to do this).

[ .. ]

> Another question:
> 
> I also tried to produce timeouts by modifying Yasui's module(please
> see APPENDIX A):
> http://www.spinics.net/lists/linux-scsi/msg35091.html
> 
> But I got a bug with your this patchset by follwing steps(there was
> not such bug without your patchset):
> 
> # grep lpfc_template /proc/kallsyms
> ffffffffa00f9240 d lpfc_template    [lpfc]
> # multipath -ll
> ...
> mpathb (36000b5d0006a0000006a14e7000c0000) dm-1 FUJITSU,ETERNUS_DX400
> size=50G features='1 queue_if_no_path' hwhandler='0' wp=rw
> |-+- policy='round-robin 0' prio=130 status=active
> | `- 2:0:0:1 sdf 8:80  active ready running
> `-+- policy='round-robin 0' prio=130 status=enabled
>   `- 3:0:0:1 sdh 8:112 active ready running
> # insmod scsi_tmo_mod.ko param=0xffffffffa00f9240,2:0:0:1; time dd
> if=/dev/zero of=/dev/dm-1 bs=4k count=4k oflag=direct
> 4096+0 records in
> 4096+0 records out
> 16777216 bytes (17 MB) copied, 151.194 s, 111 kB/s
> 
> real    2m31.195s
> user    0m0.004s
> sys    0m0.111s
> 
> Please see logs in APPENDIX B. Do you think this bug is irrelevant to
> your patchset?
> 
Hmm. No, sadly not.

'cancel_work_sync' cannot be called from an interrupt context;
guess I'll need to convert it to delayed work.

Thanks for testing; will be updating the patchset.

Cheers,

Hannes
-- 
Dr. Hannes Reinecke		      zSeries & Storage
hare@suse.de			      +49 911 74053 688
SUSE LINUX Products GmbH, Maxfeldstr. 5, 90409 Nürnberg
GF: J. Hawn, J. Guild, F. Imendörffer, HRB 16746 (AG Nürnberg)
--
To unsubscribe from this list: send the line "unsubscribe linux-scsi" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: [PATCHv3 0/9] New EH command timeout handler

[Ren Mingxin]

Hi, Hannes:

On 07/12/2013 02:09 PM, Hannes Reinecke wrote:
> On 07/12/2013 06:14 AM, Ren Mingxin wrote:
>> On 07/01/2013 10:24 PM, Hannes Reinecke wrote:
>>> With the original SCSI EH I got:
>>> # time dd if=/dev/zero of=/dev/dm-2 bs=4k count=4k oflag=direct
>>> 4096+0 records in
>>> 4096+0 records out
>>> 16777216 bytes (17 MB) copied, 142.652 s, 118 kB/s
>>>
>>> real    2m22.657s
>>> user    0m0.013s
>>> sys    0m0.145s
>>>
>>> With this patchset I got:
>>> # time dd if=/dev/zero of=/dev/dm-2 bs=4k count=4k oflag=direct
>>> 4096+0 records in
>>> 4096+0 records out
>>> 16777216 bytes (17 MB) copied, 52.1579 s, 322 kB/s
>>>
>>> real    0m52.163s
>>> user    0m0.012s
>>> sys    0m0.145s
>>>
>>> Test was to disable RSCN on the target port, disable the
>>> target port, and then start the 'dd' command as indicated.
>>
>> Do you mean disabling RSCN/port is enough? I'm afraid I couldn't
>> reproduce the problem by your steps. Both with and without your
>> patchset are the same 'dd' result: 27s. Please let me know where I
>> neglected or mistook:
>>
>> 1) I made a dm-multipath target 'dm-0' whose grouping policy was
>>     failover;
>> 2) Disable RSCN/port via brocade fc switch:
>>     SW300:root>  portcfg rscnsupr 15 --enable; portDisable 15
>> 3) Start the 'dd' command:
>>     # time dd if=/dev/zero of=/dev/dm-0 bs=4k count=4k oflag=direct
>>     dd: writing `/dev/sde': Input/output error
>>     1+0 records in
>>     0+0 records out
>>     0 bytes (0 B) copied, 27.8588 s, 0.0 kB/s
>>
>>     real    0m27.860s
>>     user    0m0.001s
>>     sys     0m0.000s
>
> You are aware that you have to disable RSCNs on the _target_ port,
> right?
> Disabling RSCNs on the _initiator_ ports is a well-tested case, and
> the one which actually makes sense (and is even implemented in
> QLogic switches).
> Disabling RSCNs for the _target_ port, OTOH, has a very questionable
> nature (hence QLogic switches don't even allow you to do this).

You're right. By disabling RSCNs on target port, I've reproduced this
problem. Thank you so much. But I've encountered the bug I said
before. I'll test again with your new patchset once you send.

Thanks,
Ren

>
>
> [ .. ]
>
>> Another question:
>>
>> I also tried to produce timeouts by modifying Yasui's module(please
>> see APPENDIX A):
>> http://www.spinics.net/lists/linux-scsi/msg35091.html
>>
>> But I got a bug with your this patchset by follwing steps(there was
>> not such bug without your patchset):
>>
>> # grep lpfc_template /proc/kallsyms
>> ffffffffa00f9240 d lpfc_template    [lpfc]
>> # multipath -ll
>> ...
>> mpathb (36000b5d0006a0000006a14e7000c0000) dm-1 FUJITSU,ETERNUS_DX400
>> size=50G features='1 queue_if_no_path' hwhandler='0' wp=rw
>> |-+- policy='round-robin 0' prio=130 status=active
>> | `- 2:0:0:1 sdf 8:80  active ready running
>> `-+- policy='round-robin 0' prio=130 status=enabled
>>    `- 3:0:0:1 sdh 8:112 active ready running
>> # insmod scsi_tmo_mod.ko param=0xffffffffa00f9240,2:0:0:1; time dd
>> if=/dev/zero of=/dev/dm-1 bs=4k count=4k oflag=direct
>> 4096+0 records in
>> 4096+0 records out
>> 16777216 bytes (17 MB) copied, 151.194 s, 111 kB/s
>>
>> real    2m31.195s
>> user    0m0.004s
>> sys    0m0.111s
>>
>> Please see logs in APPENDIX B. Do you think this bug is irrelevant to
>> your patchset?
>>
> Hmm. No, sadly not.
>
> 'cancel_work_sync' cannot be called from an interrupt context;
> guess I'll need to convert it to delayed work.
>
> Thanks for testing; will be updating the patchset.

Re: [PATCHv3 0/9] New EH command timeout handler

[Hannes Reinecke]

[-- Attachment #1: Type: text/plain, Size: 2586 bytes --]

On 07/12/2013 12:00 PM, Ren Mingxin wrote:
> Hi, Hannes:
> 
> On 07/12/2013 02:09 PM, Hannes Reinecke wrote:
>> On 07/12/2013 06:14 AM, Ren Mingxin wrote:
>>> On 07/01/2013 10:24 PM, Hannes Reinecke wrote:
>>>> With the original SCSI EH I got:
>>>> # time dd if=/dev/zero of=/dev/dm-2 bs=4k count=4k oflag=direct
>>>> 4096+0 records in
>>>> 4096+0 records out
>>>> 16777216 bytes (17 MB) copied, 142.652 s, 118 kB/s
>>>>
>>>> real    2m22.657s
>>>> user    0m0.013s
>>>> sys    0m0.145s
>>>>
>>>> With this patchset I got:
>>>> # time dd if=/dev/zero of=/dev/dm-2 bs=4k count=4k oflag=direct
>>>> 4096+0 records in
>>>> 4096+0 records out
>>>> 16777216 bytes (17 MB) copied, 52.1579 s, 322 kB/s
>>>>
>>>> real    0m52.163s
>>>> user    0m0.012s
>>>> sys    0m0.145s
>>>>
>>>> Test was to disable RSCN on the target port, disable the
>>>> target port, and then start the 'dd' command as indicated.
>>>
>>> Do you mean disabling RSCN/port is enough? I'm afraid I couldn't
>>> reproduce the problem by your steps. Both with and without your
>>> patchset are the same 'dd' result: 27s. Please let me know where I
>>> neglected or mistook:
>>>
>>> 1) I made a dm-multipath target 'dm-0' whose grouping policy was
>>>     failover;
>>> 2) Disable RSCN/port via brocade fc switch:
>>>     SW300:root>  portcfg rscnsupr 15 --enable; portDisable 15
>>> 3) Start the 'dd' command:
>>>     # time dd if=/dev/zero of=/dev/dm-0 bs=4k count=4k oflag=direct
>>>     dd: writing `/dev/sde': Input/output error
>>>     1+0 records in
>>>     0+0 records out
>>>     0 bytes (0 B) copied, 27.8588 s, 0.0 kB/s
>>>
>>>     real    0m27.860s
>>>     user    0m0.001s
>>>     sys     0m0.000s
>>
>> You are aware that you have to disable RSCNs on the _target_ port,
>> right?
>> Disabling RSCNs on the _initiator_ ports is a well-tested case, and
>> the one which actually makes sense (and is even implemented in
>> QLogic switches).
>> Disabling RSCNs for the _target_ port, OTOH, has a very questionable
>> nature (hence QLogic switches don't even allow you to do this).
> 
> You're right. By disabling RSCNs on target port, I've reproduced this
> problem. Thank you so much. But I've encountered the bug I said
> before. I'll test again with your new patchset once you send.
> 

Could you check with the attached patch? That should convert it to
delayed_work and avoid this issue.

Cheers,

Hannes
-- 
Dr. Hannes Reinecke		      zSeries & Storage
hare@suse.de			      +49 911 74053 688
SUSE LINUX Products GmbH, Maxfeldstr. 5, 90409 Nürnberg
GF: J. Hawn, J. Guild, F. Imendörffer, HRB 16746 (AG Nürnberg)

[-- Attachment #2: scsi-use-delayed_work-for-cancel.patch --]
[-- Type: text/x-patch, Size: 2883 bytes --]

>From 2d0851bea02e3d15bf403e6800cc7164f2e211f2 Mon Sep 17 00:00:00 2001
From: Hannes Reinecke <hare@suse.de>
Date: Fri, 12 Jul 2013 12:06:19 +0200
Subject: [PATCH] scsi: use delayed_work to trigger aborts

Command aborts are invoked from an interrupt, so we cannot use
cancel_work_sync() when an outstanding abort needs to be cancelled.
So convert the mechanism to delayed_work, which can be cancelled
even from an interrupt context.

Signed-off-by: Hannes Reinecke <hare@suse.de>

diff --git a/drivers/scsi/scsi.c b/drivers/scsi/scsi.c
index a62ae84..13a3418 100644
--- a/drivers/scsi/scsi.c
+++ b/drivers/scsi/scsi.c
@@ -297,7 +297,7 @@ struct scsi_cmnd *scsi_get_command(struct scsi_device *dev, gfp_t gfp_mask)
 
 		cmd->device = dev;
 		INIT_LIST_HEAD(&cmd->list);
-		INIT_WORK(&cmd->abort_work, scmd_eh_abort_handler);
+		INIT_DELAYED_WORK(&cmd->abort_work, scmd_eh_abort_handler);
 		spin_lock_irqsave(&dev->list_lock, flags);
 		list_add_tail(&cmd->list, &dev->cmd_list);
 		spin_unlock_irqrestore(&dev->list_lock, flags);
@@ -354,6 +354,8 @@ void scsi_put_command(struct scsi_cmnd *cmd)
 	list_del_init(&cmd->list);
 	spin_unlock_irqrestore(&cmd->device->list_lock, flags);
 
+	cancel_delayed_work_sync(&cmd->abort_work);
+
 	__scsi_put_command(cmd->device->host, cmd, &sdev->sdev_gendev);
 }
 EXPORT_SYMBOL(scsi_put_command);
diff --git a/drivers/scsi/scsi_error.c b/drivers/scsi/scsi_error.c
index 28c272f..cd443b2 100644
--- a/drivers/scsi/scsi_error.c
+++ b/drivers/scsi/scsi_error.c
@@ -187,7 +187,7 @@ void
 scmd_eh_abort_handler(struct work_struct *work)
 {
 	struct scsi_cmnd *scmd =
-		container_of(work, struct scsi_cmnd, abort_work);
+		container_of(work, struct scsi_cmnd, abort_work.work);
 	struct scsi_device *sdev = scmd->device;
 	unsigned long flags;
 	int rtn;
@@ -254,7 +254,7 @@ scsi_abort_command(struct scsi_cmnd *scmd)
 		SCSI_LOG_ERROR_RECOVERY(3,
 			scmd_printk(KERN_INFO, scmd,
 				    "scmd %p abort timeout\n", scmd));
-		cancel_work_sync(&scmd->abort_work);
+		cancel_delayed_work(&scmd->abort_work);
 		return BLK_EH_NOT_HANDLED;
 	}
 
@@ -279,7 +279,7 @@ scsi_abort_command(struct scsi_cmnd *scmd)
 	SCSI_LOG_ERROR_RECOVERY(3,
 		scmd_printk(KERN_INFO, scmd,
 			    "scmd %p abort scheduled\n", scmd));
-	schedule_work(&scmd->abort_work);
+	schedule_delayed_work(&scmd->abort_work, HZ / 100);
 	return BLK_EH_SCHEDULED;
 }
 EXPORT_SYMBOL_GPL(scsi_abort_command);
diff --git a/include/scsi/scsi_cmnd.h b/include/scsi/scsi_cmnd.h
index a2f062e..e3137e3 100644
--- a/include/scsi/scsi_cmnd.h
+++ b/include/scsi/scsi_cmnd.h
@@ -55,7 +55,7 @@ struct scsi_cmnd {
 	struct scsi_device *device;
 	struct list_head list;  /* scsi_cmnd participates in queue lists */
 	struct list_head eh_entry; /* entry for the host eh_cmd_q */
-	struct work_struct abort_work;
+	struct delayed_work abort_work;
 	int eh_eflags;		/* Used by error handlr */
 
 	/*

Re: [PATCHv3 0/9] New EH command timeout handler

[Ren Mingxin]

Hi, Hannes:

On 07/12/2013 06:27 PM, Hannes Reinecke wrote:
> On 07/12/2013 12:00 PM, Ren Mingxin wrote:
>> On 07/12/2013 02:09 PM, Hannes Reinecke wrote:
>>> On 07/12/2013 06:14 AM, Ren Mingxin wrote:
>>>> On 07/01/2013 10:24 PM, Hannes Reinecke wrote:
>>>>> With the original SCSI EH I got:
>>>>> # time dd if=/dev/zero of=/dev/dm-2 bs=4k count=4k oflag=direct
>>>>> 4096+0 records in
>>>>> 4096+0 records out
>>>>> 16777216 bytes (17 MB) copied, 142.652 s, 118 kB/s
>>>>>
>>>>> real    2m22.657s
>>>>> user    0m0.013s
>>>>> sys    0m0.145s
>>>>>
>>>>> With this patchset I got:
>>>>> # time dd if=/dev/zero of=/dev/dm-2 bs=4k count=4k oflag=direct
>>>>> 4096+0 records in
>>>>> 4096+0 records out
>>>>> 16777216 bytes (17 MB) copied, 52.1579 s, 322 kB/s
>>>>>
>>>>> real    0m52.163s
>>>>> user    0m0.012s
>>>>> sys    0m0.145s
>>>>>
>>>>> Test was to disable RSCN on the target port, disable the
>>>>> target port, and then start the 'dd' command as indicated.
>>>>
>>>> Do you mean disabling RSCN/port is enough? I'm afraid I couldn't
>>>> reproduce the problem by your steps. Both with and without your
>>>> patchset are the same 'dd' result: 27s. Please let me know where I
>>>> neglected or mistook:
>>>>
>>>> 1) I made a dm-multipath target 'dm-0' whose grouping policy was
>>>>      failover;
>>>> 2) Disable RSCN/port via brocade fc switch:
>>>>      SW300:root>   portcfg rscnsupr 15 --enable; portDisable 15
>>>> 3) Start the 'dd' command:
>>>>      # time dd if=/dev/zero of=/dev/dm-0 bs=4k count=4k oflag=direct
>>>>      dd: writing `/dev/sde': Input/output error
>>>>      1+0 records in
>>>>      0+0 records out
>>>>      0 bytes (0 B) copied, 27.8588 s, 0.0 kB/s
>>>>
>>>>      real    0m27.860s
>>>>      user    0m0.001s
>>>>      sys     0m0.000s
>>>
>>> You are aware that you have to disable RSCNs on the _target_ port,
>>> right?
>>> Disabling RSCNs on the _initiator_ ports is a well-tested case, and
>>> the one which actually makes sense (and is even implemented in
>>> QLogic switches).
>>> Disabling RSCNs for the _target_ port, OTOH, has a very questionable
>>> nature (hence QLogic switches don't even allow you to do this).
>>
>> You're right. By disabling RSCNs on target port, I've reproduced this
>> problem. Thank you so much. But I've encountered the bug I said
>> before. I'll test again with your new patchset once you send.
>>
>
> Could you check with the attached patch? That should convert it to
> delayed_work and avoid this issue.

Unfortunately, the login prompt couldn't be entered in and BUGs were
printed ceaselessly while os booting with this patch. The BUGs are
like below:

BUG: scheduling while atomic: swapper/0/0/0x10000100
Modules linked in: mptsas(F+) mptscsih(F) mptbase(F) scsi_transport_sas(F)
CPU: 0 PID: 0 Comm: swapper/0 Tainted: GF            3.10.0hannes+ #10
Hardware name: FUJITSU-SV PRIMEQUEST 1800E/SB-8GDIMM-CN, BIOS PRIMEQUEST 
1000 Series BIOS Version 1.39 11/16/2012
  0000000000000000 ffff88047ee03b68 ffffffff8153ada4 ffff88047ee03b78
  ffffffff8107389d ffff88047ee03c08 ffffffff8153ca26 ffffffff81a01fd8
  0000000000012d00 ffffffff81a00010 0000000000012d00 0000000000012d00
Call Trace:
<IRQ>  [<ffffffff8153ada4>] dump_stack+0x19/0x1d
  [<ffffffff8107389d>] __schedule_bug+0x4d/0x60
  [<ffffffff8153ca26>] __schedule+0x646/0x6f0
  [<ffffffff8107749a>] __cond_resched+0x2a/0x40
  [<ffffffff8153cb60>] _cond_resched+0x30/0x40
  [<ffffffff8105fecc>] start_flush_work+0x2c/0x140
  [<ffffffff8105fffa>] flush_work+0x1a/0x40
  [<ffffffff8105fb39>] ? try_to_grab_pending+0x109/0x190
  [<ffffffff8106027e>] __cancel_work_timer+0x7e/0x110
  [<ffffffff81060323>] cancel_delayed_work_sync+0x13/0x20
  [<ffffffff81374ec5>] scsi_put_command+0x65/0xa0
  [<ffffffff8137d5aa>] scsi_next_command+0x3a/0x60
  [<ffffffff8137dedb>] scsi_end_request+0xab/0xb0
  [<ffffffff8137e1ef>] scsi_io_completion+0x9f/0x670
  [<ffffffff813744e4>] scsi_finish_command+0xd4/0x140
  [<ffffffff8137e927>] scsi_softirq_done+0x147/0x170
  [<ffffffff81239534>] blk_done_softirq+0x74/0x90
  [<ffffffff81049a4f>] __do_softirq+0xef/0x260
  [<ffffffff81049cb5>] irq_exit+0xb5/0xc0
  [<ffffffff81548406>] do_IRQ+0x66/0xe0
  [<ffffffff8153e5ea>] common_interrupt+0x6a/0x6a
<EOI>  [<ffffffff8109b5f2>] ? clockevents_notify+0x52/0x150
  [<ffffffff8142dce3>] ? cpuidle_enter_state+0x53/0xd0
  [<ffffffff8142dcdf>] ? cpuidle_enter_state+0x4f/0xd0
  [<ffffffff8142e10f>] cpuidle_idle_call+0xcf/0x160
  [<ffffffff8100ab1e>] arch_cpu_idle+0xe/0x30
  [<ffffffff81093275>] cpu_idle_loop+0x65/0x1f0
  [<ffffffff81093470>] cpu_startup_entry+0x70/0x80
  [<ffffffff81529427>] rest_init+0x77/0x80
  [<ffffffff81b0e1bb>] start_kernel+0x41a/0x427
  [<ffffffff81b0dbbf>] ? repair_env_string+0x5b/0x5b
  [<ffffffff81b0d5a1>] x86_64_start_reservations+0x2a/0x2c
  [<ffffffff81b0d6d2>] x86_64_start_kernel+0x12f/0x136

If there is any info I havn't expatiated, please let me know.

Thanks,
Ren

Re: [PATCHv3 0/9] New EH command timeout handler

[Ren Mingxin]

Hi, Hannes:

On 07/15/2013 02:05 PM, Ren Mingxin wrote:
> On 07/12/2013 06:27 PM, Hannes Reinecke wrote:
>> On 07/12/2013 12:00 PM, Ren Mingxin wrote:
>>> On 07/12/2013 02:09 PM, Hannes Reinecke wrote:
>>>> On 07/12/2013 06:14 AM, Ren Mingxin wrote:
>>>>> On 07/01/2013 10:24 PM, Hannes Reinecke wrote:
>>>>>> With the original SCSI EH I got:
>>>>>> # time dd if=/dev/zero of=/dev/dm-2 bs=4k count=4k oflag=direct
>>>>>> 4096+0 records in
>>>>>> 4096+0 records out
>>>>>> 16777216 bytes (17 MB) copied, 142.652 s, 118 kB/s
>>>>>>
>>>>>> real    2m22.657s
>>>>>> user    0m0.013s
>>>>>> sys    0m0.145s
>>>>>>
>>>>>> With this patchset I got:
>>>>>> # time dd if=/dev/zero of=/dev/dm-2 bs=4k count=4k oflag=direct
>>>>>> 4096+0 records in
>>>>>> 4096+0 records out
>>>>>> 16777216 bytes (17 MB) copied, 52.1579 s, 322 kB/s
>>>>>>
>>>>>> real    0m52.163s
>>>>>> user    0m0.012s
>>>>>> sys    0m0.145s
>>>>>>
>>>>>> Test was to disable RSCN on the target port, disable the
>>>>>> target port, and then start the 'dd' command as indicated.
>>>>>
>>>>> Do you mean disabling RSCN/port is enough? I'm afraid I couldn't
>>>>> reproduce the problem by your steps. Both with and without your
>>>>> patchset are the same 'dd' result: 27s. Please let me know where I
>>>>> neglected or mistook:
>>>>>
>>>>> 1) I made a dm-multipath target 'dm-0' whose grouping policy was
>>>>>      failover;
>>>>> 2) Disable RSCN/port via brocade fc switch:
>>>>>      SW300:root>   portcfg rscnsupr 15 --enable; portDisable 15
>>>>> 3) Start the 'dd' command:
>>>>>      # time dd if=/dev/zero of=/dev/dm-0 bs=4k count=4k oflag=direct
>>>>>      dd: writing `/dev/sde': Input/output error
>>>>>      1+0 records in
>>>>>      0+0 records out
>>>>>      0 bytes (0 B) copied, 27.8588 s, 0.0 kB/s
>>>>>
>>>>>      real    0m27.860s
>>>>>      user    0m0.001s
>>>>>      sys     0m0.000s
>>>>
>>>> You are aware that you have to disable RSCNs on the _target_ port,
>>>> right?
>>>> Disabling RSCNs on the _initiator_ ports is a well-tested case, and
>>>> the one which actually makes sense (and is even implemented in
>>>> QLogic switches).
>>>> Disabling RSCNs for the _target_ port, OTOH, has a very questionable
>>>> nature (hence QLogic switches don't even allow you to do this).
>>>
>>> You're right. By disabling RSCNs on target port, I've reproduced this
>>> problem. Thank you so much. But I've encountered the bug I said
>>> before. I'll test again with your new patchset once you send.
>>>
>>
>> Could you check with the attached patch? That should convert it to
>> delayed_work and avoid this issue.
>
> Unfortunately, the login prompt couldn't be entered in and BUGs were
> printed ceaselessly while os booting with this patch. The BUGs are
> like below:
>
> BUG: scheduling while atomic: swapper/0/0/0x10000100
> Modules linked in: mptsas(F+) mptscsih(F) mptbase(F) 
> scsi_transport_sas(F)
> CPU: 0 PID: 0 Comm: swapper/0 Tainted: GF            3.10.0hannes+ #10
> Hardware name: FUJITSU-SV PRIMEQUEST 1800E/SB-8GDIMM-CN, BIOS 
> PRIMEQUEST 1000 Series BIOS Version 1.39 11/16/2012
>  0000000000000000 ffff88047ee03b68 ffffffff8153ada4 ffff88047ee03b78
>  ffffffff8107389d ffff88047ee03c08 ffffffff8153ca26 ffffffff81a01fd8
>  0000000000012d00 ffffffff81a00010 0000000000012d00 0000000000012d00
> Call Trace:
> <IRQ>  [<ffffffff8153ada4>] dump_stack+0x19/0x1d
>  [<ffffffff8107389d>] __schedule_bug+0x4d/0x60
>  [<ffffffff8153ca26>] __schedule+0x646/0x6f0
>  [<ffffffff8107749a>] __cond_resched+0x2a/0x40
>  [<ffffffff8153cb60>] _cond_resched+0x30/0x40
>  [<ffffffff8105fecc>] start_flush_work+0x2c/0x140
>  [<ffffffff8105fffa>] flush_work+0x1a/0x40
>  [<ffffffff8105fb39>] ? try_to_grab_pending+0x109/0x190
>  [<ffffffff8106027e>] __cancel_work_timer+0x7e/0x110
>  [<ffffffff81060323>] cancel_delayed_work_sync+0x13/0x20
>  [<ffffffff81374ec5>] scsi_put_command+0x65/0xa0

This bug is caused by the sync function 'cancel_delayed_work_sync'
which is invoked in the interrupt context. By replacing it by non-
sync function 'cancel_delayed_work' in 'scsi_put_command' can avoid.

Do you think there is such need to sync in the function 'scsi_put_
command'? Since SCSI command block will be freed here, it is NOT
necessary to wait for the abort work to finish on it, yes?

Thanks,
Ren

>  [<ffffffff8137d5aa>] scsi_next_command+0x3a/0x60
>  [<ffffffff8137dedb>] scsi_end_request+0xab/0xb0
>  [<ffffffff8137e1ef>] scsi_io_completion+0x9f/0x670
>  [<ffffffff813744e4>] scsi_finish_command+0xd4/0x140
>  [<ffffffff8137e927>] scsi_softirq_done+0x147/0x170
>  [<ffffffff81239534>] blk_done_softirq+0x74/0x90
>  [<ffffffff81049a4f>] __do_softirq+0xef/0x260
>  [<ffffffff81049cb5>] irq_exit+0xb5/0xc0
>  [<ffffffff81548406>] do_IRQ+0x66/0xe0
>  [<ffffffff8153e5ea>] common_interrupt+0x6a/0x6a
> <EOI>  [<ffffffff8109b5f2>] ? clockevents_notify+0x52/0x150
>  [<ffffffff8142dce3>] ? cpuidle_enter_state+0x53/0xd0
>  [<ffffffff8142dcdf>] ? cpuidle_enter_state+0x4f/0xd0
>  [<ffffffff8142e10f>] cpuidle_idle_call+0xcf/0x160
>  [<ffffffff8100ab1e>] arch_cpu_idle+0xe/0x30
>  [<ffffffff81093275>] cpu_idle_loop+0x65/0x1f0
>  [<ffffffff81093470>] cpu_startup_entry+0x70/0x80
>  [<ffffffff81529427>] rest_init+0x77/0x80
>  [<ffffffff81b0e1bb>] start_kernel+0x41a/0x427
>  [<ffffffff81b0dbbf>] ? repair_env_string+0x5b/0x5b
>  [<ffffffff81b0d5a1>] x86_64_start_reservations+0x2a/0x2c
>  [<ffffffff81b0d6d2>] x86_64_start_kernel+0x12f/0x136

Re: [PATCHv3 0/9] New EH command timeout handler

[Hannes Reinecke]

On 08/07/2013 12:08 PM, Ren Mingxin wrote:
> Hi, Hannes:
> 
> On 07/15/2013 02:05 PM, Ren Mingxin wrote:
>> On 07/12/2013 06:27 PM, Hannes Reinecke wrote:
>>> On 07/12/2013 12:00 PM, Ren Mingxin wrote:
>>>> On 07/12/2013 02:09 PM, Hannes Reinecke wrote:
>>>>> On 07/12/2013 06:14 AM, Ren Mingxin wrote:
>>>>>> On 07/01/2013 10:24 PM, Hannes Reinecke wrote:
>>>>>>> With the original SCSI EH I got:
>>>>>>> # time dd if=/dev/zero of=/dev/dm-2 bs=4k count=4k oflag=direct
>>>>>>> 4096+0 records in
>>>>>>> 4096+0 records out
>>>>>>> 16777216 bytes (17 MB) copied, 142.652 s, 118 kB/s
>>>>>>>
>>>>>>> real    2m22.657s
>>>>>>> user    0m0.013s
>>>>>>> sys    0m0.145s
>>>>>>>
>>>>>>> With this patchset I got:
>>>>>>> # time dd if=/dev/zero of=/dev/dm-2 bs=4k count=4k oflag=direct
>>>>>>> 4096+0 records in
>>>>>>> 4096+0 records out
>>>>>>> 16777216 bytes (17 MB) copied, 52.1579 s, 322 kB/s
>>>>>>>
>>>>>>> real    0m52.163s
>>>>>>> user    0m0.012s
>>>>>>> sys    0m0.145s
>>>>>>>
>>>>>>> Test was to disable RSCN on the target port, disable the
>>>>>>> target port, and then start the 'dd' command as indicated.
>>>>>>
>>>>>> Do you mean disabling RSCN/port is enough? I'm afraid I couldn't
>>>>>> reproduce the problem by your steps. Both with and without your
>>>>>> patchset are the same 'dd' result: 27s. Please let me know
>>>>>> where I
>>>>>> neglected or mistook:
>>>>>>
>>>>>> 1) I made a dm-multipath target 'dm-0' whose grouping policy was
>>>>>>      failover;
>>>>>> 2) Disable RSCN/port via brocade fc switch:
>>>>>>      SW300:root>   portcfg rscnsupr 15 --enable; portDisable 15
>>>>>> 3) Start the 'dd' command:
>>>>>>      # time dd if=/dev/zero of=/dev/dm-0 bs=4k count=4k
>>>>>> oflag=direct
>>>>>>      dd: writing `/dev/sde': Input/output error
>>>>>>      1+0 records in
>>>>>>      0+0 records out
>>>>>>      0 bytes (0 B) copied, 27.8588 s, 0.0 kB/s
>>>>>>
>>>>>>      real    0m27.860s
>>>>>>      user    0m0.001s
>>>>>>      sys     0m0.000s
>>>>>
>>>>> You are aware that you have to disable RSCNs on the _target_ port,
>>>>> right?
>>>>> Disabling RSCNs on the _initiator_ ports is a well-tested case,
>>>>> and
>>>>> the one which actually makes sense (and is even implemented in
>>>>> QLogic switches).
>>>>> Disabling RSCNs for the _target_ port, OTOH, has a very
>>>>> questionable
>>>>> nature (hence QLogic switches don't even allow you to do this).
>>>>
>>>> You're right. By disabling RSCNs on target port, I've reproduced
>>>> this
>>>> problem. Thank you so much. But I've encountered the bug I said
>>>> before. I'll test again with your new patchset once you send.
>>>>
>>>
>>> Could you check with the attached patch? That should convert it to
>>> delayed_work and avoid this issue.
>>
>> Unfortunately, the login prompt couldn't be entered in and BUGs were
>> printed ceaselessly while os booting with this patch. The BUGs are
>> like below:
>>
>> BUG: scheduling while atomic: swapper/0/0/0x10000100
>> Modules linked in: mptsas(F+) mptscsih(F) mptbase(F)
>> scsi_transport_sas(F)
>> CPU: 0 PID: 0 Comm: swapper/0 Tainted: GF            3.10.0hannes+
>> #10
>> Hardware name: FUJITSU-SV PRIMEQUEST 1800E/SB-8GDIMM-CN, BIOS
>> PRIMEQUEST 1000 Series BIOS Version 1.39 11/16/2012
>>  0000000000000000 ffff88047ee03b68 ffffffff8153ada4 ffff88047ee03b78
>>  ffffffff8107389d ffff88047ee03c08 ffffffff8153ca26 ffffffff81a01fd8
>>  0000000000012d00 ffffffff81a00010 0000000000012d00 0000000000012d00
>> Call Trace:
>> <IRQ>  [<ffffffff8153ada4>] dump_stack+0x19/0x1d
>>  [<ffffffff8107389d>] __schedule_bug+0x4d/0x60
>>  [<ffffffff8153ca26>] __schedule+0x646/0x6f0
>>  [<ffffffff8107749a>] __cond_resched+0x2a/0x40
>>  [<ffffffff8153cb60>] _cond_resched+0x30/0x40
>>  [<ffffffff8105fecc>] start_flush_work+0x2c/0x140
>>  [<ffffffff8105fffa>] flush_work+0x1a/0x40
>>  [<ffffffff8105fb39>] ? try_to_grab_pending+0x109/0x190
>>  [<ffffffff8106027e>] __cancel_work_timer+0x7e/0x110
>>  [<ffffffff81060323>] cancel_delayed_work_sync+0x13/0x20
>>  [<ffffffff81374ec5>] scsi_put_command+0x65/0xa0
> 
> This bug is caused by the sync function 'cancel_delayed_work_sync'
> which is invoked in the interrupt context. By replacing it by non-
> sync function 'cancel_delayed_work' in 'scsi_put_command' can avoid.
> 
> Do you think there is such need to sync in the function 'scsi_put_
> command'? Since SCSI command block will be freed here, it is NOT
> necessary to wait for the abort work to finish on it, yes?
> 
You are right, cancel_delayed_work() should be sufficient here.

I'll give it a spin and repost the patchset.

Cheers,

Hannes
-- 
Dr. Hannes Reinecke		      zSeries & Storage
hare@suse.de			      +49 911 74053 688
SUSE LINUX Products GmbH, Maxfeldstr. 5, 90409 Nürnberg
GF: J. Hawn, J. Guild, F. Imendörffer, HRB 16746 (AG Nürnberg)
--
To unsubscribe from this list: send the line "unsubscribe linux-scsi" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: [PATCH 3/9] scsi: improved eh timeout handler

[Ren Mingxin]

Hi, Hannes:

On 07/01/2013 10:24 PM, Hannes Reinecke wrote:
> When a command runs into a timeout we need to send an 'ABORT TASK'
> TMF. This is typically done by the 'eh_abort_handler' LLDD callback.
>
> Conceptually, however, this function is a normal SCSI command, so
> there is no need to enter the error handler.
>
> This patch implements a new scsi_abort_command() function which
> invokes an asynchronous function scsi_eh_abort_handler() to
> abort the commands via the usual 'eh_abort_handler'.
>
> If abort succeeds the command is either retried or terminated,
> depending on the number of allowed retries. However, 'eh_eflags'
> records the abort, so if the retry would fail again the
> command is pushed onto the error handler without trying to
> abort it (again); it'll be cleared up from SCSI EH.
>
> Signed-off-by: Hannes Reinecke<hare@suse.de>
> ---
>   drivers/scsi/scsi.c       |   1 +
>   drivers/scsi/scsi_error.c | 139 ++++++++++++++++++++++++++++++++++++++++++----
>   drivers/scsi/scsi_priv.h  |   2 +
>   include/scsi/scsi_cmnd.h  |   2 +
>   4 files changed, 132 insertions(+), 12 deletions(-)
>
> diff --git a/drivers/scsi/scsi.c b/drivers/scsi/scsi.c
> index ebe3b0a..06257cf 100644
> --- a/drivers/scsi/scsi.c
> +++ b/drivers/scsi/scsi.c
> @@ -297,6 +297,7 @@ struct scsi_cmnd *scsi_get_command(struct scsi_device *dev, gfp_t gfp_mask)
>
>   		cmd->device = dev;
>   		INIT_LIST_HEAD(&cmd->list);
> +		INIT_WORK(&cmd->abort_work, scmd_eh_abort_handler);
>   		spin_lock_irqsave(&dev->list_lock, flags);
>   		list_add_tail(&cmd->list,&dev->cmd_list);
>   		spin_unlock_irqrestore(&dev->list_lock, flags);
> diff --git a/drivers/scsi/scsi_error.c b/drivers/scsi/scsi_error.c
> index e76e895..835f7e4 100644
> --- a/drivers/scsi/scsi_error.c
> +++ b/drivers/scsi/scsi_error.c
> @@ -55,6 +55,7 @@ static void scsi_eh_done(struct scsi_cmnd *scmd);
>   #define HOST_RESET_SETTLE_TIME  (10)
>
>   static int scsi_eh_try_stu(struct scsi_cmnd *scmd);
> +static int scsi_try_to_abort_cmd(struct scsi_host_template *, struct scsi_cmnd *);
>
>   /* called with shost->host_lock held */
>   void scsi_eh_wakeup(struct Scsi_Host *shost)
> @@ -102,6 +103,111 @@ static int scsi_host_eh_past_deadline(struct Scsi_Host *shost)
>   }
>
>   /**
> + * scmd_eh_abort_handler - Handle command aborts
> + * @work:	command to be aborted.
> + */
> +void
> +scmd_eh_abort_handler(struct work_struct *work)
> +{
> +	struct scsi_cmnd *scmd =
> +		container_of(work, struct scsi_cmnd, abort_work);
> +	struct scsi_device *sdev = scmd->device;
> +	unsigned long flags;
> +	int rtn;
> +
> +	spin_lock_irqsave(sdev->host->host_lock, flags);
> +	if (scsi_host_eh_past_deadline(sdev->host)) {
> +		spin_unlock_irqrestore(sdev->host->host_lock, flags);
> +		SCSI_LOG_ERROR_RECOVERY(3,
> +			scmd_printk(KERN_INFO, scmd,
> +				    "eh timeout, not aborting\n"));

Command address should be also printed for debugging conveniently:
+"eh timeout, not aborting command %p\n", scmd));

>
> +	} else {
> +		spin_unlock_irqrestore(sdev->host->host_lock, flags);
> +		SCSI_LOG_ERROR_RECOVERY(3,
> +			scmd_printk(KERN_INFO, scmd,
> +				    "aborting command %p\n", scmd));
> +		rtn = scsi_try_to_abort_cmd(sdev->host->hostt, scmd);
> +		if (rtn == SUCCESS) {
> +			scmd->result |= DID_TIME_OUT<<  16;
> +			if (!scsi_noretry_cmd(scmd)&&

I think 'scsi_device_online(scmd->device)' is also necessary here.

>
> +			    (++scmd->retries<= scmd->allowed)) {
> +				SCSI_LOG_ERROR_RECOVERY(3,
> +					scmd_printk(KERN_WARNING, scmd,
> +						    "retry aborted command\n"));

Command address should be also printed here.

>
> +				scsi_queue_insert(scmd, SCSI_MLQUEUE_EH_RETRY);
> +			} else {
> +				SCSI_LOG_ERROR_RECOVERY(3,
> +					scmd_printk(KERN_WARNING, scmd,
> +						    "finish aborted command\n"));

Command address should be also printed here.

>
> +				scsi_finish_command(scmd);
> +			}
> +			return;
> +		}
> +		SCSI_LOG_ERROR_RECOVERY(3,
> +			scmd_printk(KERN_INFO, scmd,
> +				    "abort command failed, rtn %d\n", rtn));

Command address should be also printed here.

>
> +	}
> +
> +	if (scsi_eh_scmd_add(scmd, 0)) {
> +		SCSI_LOG_ERROR_RECOVERY(3,
> +			scmd_printk(KERN_WARNING, scmd,
> +				    "terminate aborted command\n"));

Command address should be also printed here.

>
> +		scmd->result |= DID_TIME_OUT<<  16;
> +		scsi_finish_command(scmd);
> +	}
> +}
> +
> +/**
> + * scsi_abort_command - schedule a command abort
> + * @scmd:	scmd to abort.
> + *
> + * We only need to abort commands after a command timeout
> + */
> +enum blk_eh_timer_return
> +scsi_abort_command(struct scsi_cmnd *scmd)
> +{
> +	struct scsi_device *sdev = scmd->device;
> +	struct Scsi_Host *shost = sdev->host;
> +	unsigned long flags;
> +
> +	if (scmd->eh_eflags&  SCSI_EH_ABORT_SCHEDULED) {
> +		/*
> +		 * command abort timed out.
> +		 */
> +		SCSI_LOG_ERROR_RECOVERY(3,
> +			scmd_printk(KERN_INFO, scmd,
> +				    "scmd %p abort timeout\n", scmd));
> +		cancel_work_sync(&scmd->abort_work);
> +		return BLK_EH_NOT_HANDLED;
> +	}
> +
> +	/*
> +	 * Do not try a command abort if
> +	 * SCSI EH has already started.
> +	 */
> +	spin_lock_irqsave(shost->host_lock, flags);
> +	if (scsi_host_in_recovery(shost)) {
> +		spin_unlock_irqrestore(shost->host_lock, flags);
> +		SCSI_LOG_ERROR_RECOVERY(3,
> +			scmd_printk(KERN_INFO, scmd,
> +				    "host in recovery, not aborting\n"));

Command address should be also printed here.

Thanks,
Ren

>
> +		return BLK_EH_NOT_HANDLED;
> +	}
> +
> +	if (shost->eh_deadline&&  !shost->last_reset)
> +		shost->last_reset = jiffies;
> +	spin_unlock_irqrestore(shost->host_lock, flags);
> +
> +	scmd->eh_eflags |= SCSI_EH_ABORT_SCHEDULED;
> +	SCSI_LOG_ERROR_RECOVERY(3,
> +		scmd_printk(KERN_INFO, scmd,
> +			    "scmd %p abort scheduled\n", scmd));
> +	schedule_work(&scmd->abort_work);
> +	return BLK_EH_SCHEDULED;
> +}
> +EXPORT_SYMBOL_GPL(scsi_abort_command);
> +
> +/**
>    * scsi_eh_scmd_add - add scsi cmd to error handling.
>    * @scmd:	scmd to run eh on.
>    * @eh_flag:	optional SCSI_EH flag.
> @@ -127,6 +233,8 @@ int scsi_eh_scmd_add(struct scsi_cmnd *scmd, int eh_flag)
>   		shost->last_reset = jiffies;
>
>   	ret = 1;
> +	if (scmd->eh_eflags&  SCSI_EH_ABORT_SCHEDULED)
> +		eh_flag&= ~SCSI_EH_CANCEL_CMD;
>   	scmd->eh_eflags |= eh_flag;
>   	list_add_tail(&scmd->eh_entry,&shost->eh_cmd_q);
>   	shost->host_failed++;
> @@ -1532,6 +1640,8 @@ int scsi_noretry_cmd(struct scsi_cmnd *scmd)
>   	switch (host_byte(scmd->result)) {
>   	case DID_OK:
>   		break;
> +	case DID_TIME_OUT:
> +		goto check_type;
>   	case DID_BUS_BUSY:
>   		return (scmd->request->cmd_flags&  REQ_FAILFAST_TRANSPORT);
>   	case DID_PARITY:
> @@ -1545,18 +1655,19 @@ int scsi_noretry_cmd(struct scsi_cmnd *scmd)
>   		return (scmd->request->cmd_flags&  REQ_FAILFAST_DRIVER);
>   	}
>
> -	switch (status_byte(scmd->result)) {
> -	case CHECK_CONDITION:
> -		/*
> -		 * assume caller has checked sense and determinted
> -		 * the check condition was retryable.
> -		 */
> -		if (scmd->request->cmd_flags&  REQ_FAILFAST_DEV ||
> -		    scmd->request->cmd_type == REQ_TYPE_BLOCK_PC)
> -			return 1;
> -	}
> +	switch (status_byte(scmd->result) != CHECK_CONDITION)
> +		return 0;
>
> -	return 0;
> +check_type:
> +	/*
> +	 * assume caller has checked sense and determinted
> +	 * the check condition was retryable.
> +	 */
> +	if (scmd->request->cmd_flags&  REQ_FAILFAST_DEV ||
> +	    scmd->request->cmd_type == REQ_TYPE_BLOCK_PC)
> +		return 1;
> +	else
> +		return 0;
>   }
>
>   /**
> @@ -1606,9 +1717,13 @@ int scsi_decide_disposition(struct scsi_cmnd *scmd)
>   		 * looks good.  drop through, and check the next byte.
>   		 */
>   		break;
> +	case DID_ABORT:
> +		if (scmd->eh_eflags&  SCSI_EH_ABORT_SCHEDULED) {
> +			scmd->result |= DID_TIME_OUT<<  16;
> +			return SUCCESS;
> +		}
>   	case DID_NO_CONNECT:
>   	case DID_BAD_TARGET:
> -	case DID_ABORT:
>   		/*
>   		 * note - this means that we just report the status back
>   		 * to the top level driver, not that we actually think
> diff --git a/drivers/scsi/scsi_priv.h b/drivers/scsi/scsi_priv.h
> index 8f9a0ca..f079a59 100644
> --- a/drivers/scsi/scsi_priv.h
> +++ b/drivers/scsi/scsi_priv.h
> @@ -19,6 +19,7 @@ struct scsi_nl_hdr;
>    * Scsi Error Handler Flags
>    */
>   #define SCSI_EH_CANCEL_CMD	0x0001	/* Cancel this cmd */
> +#define SCSI_EH_ABORT_SCHEDULED	0x0002	/* Abort has been scheduled */
>
>   #define SCSI_SENSE_VALID(scmd) \
>   	(((scmd)->sense_buffer[0]&  0x70) == 0x70)
> @@ -66,6 +67,7 @@ extern int __init scsi_init_devinfo(void);
>   extern void scsi_exit_devinfo(void);
>
>   /* scsi_error.c */
> +extern void scmd_eh_abort_handler(struct work_struct *work);
>   extern enum blk_eh_timer_return scsi_times_out(struct request *req);
>   extern int scsi_error_handler(void *host);
>   extern int scsi_decide_disposition(struct scsi_cmnd *cmd);
> diff --git a/include/scsi/scsi_cmnd.h b/include/scsi/scsi_cmnd.h
> index de5f5d8..a2f062e 100644
> --- a/include/scsi/scsi_cmnd.h
> +++ b/include/scsi/scsi_cmnd.h
> @@ -55,6 +55,7 @@ struct scsi_cmnd {
>   	struct scsi_device *device;
>   	struct list_head list;  /* scsi_cmnd participates in queue lists */
>   	struct list_head eh_entry; /* entry for the host eh_cmd_q */
> +	struct work_struct abort_work;
>   	int eh_eflags;		/* Used by error handlr */
>
>   	/*
> @@ -144,6 +145,7 @@ extern void scsi_put_command(struct scsi_cmnd *);
>   extern void __scsi_put_command(struct Scsi_Host *, struct scsi_cmnd *,
>   			       struct device *);
>   extern void scsi_finish_command(struct scsi_cmnd *cmd);
> +extern enum blk_eh_timer_return scsi_abort_command(struct scsi_cmnd *cmd);
>
>   extern void *scsi_kmap_atomic_sg(struct scatterlist *sg, int sg_count,
>   				 size_t *offset, size_t *len);

Re: [PATCH 3/9] scsi: improved eh timeout handler

[Hannes Reinecke]

On 08/22/2013 10:51 AM, Ren Mingxin wrote:
> Hi, Hannes:
>
> On 07/01/2013 10:24 PM, Hannes Reinecke wrote:
>> When a command runs into a timeout we need to send an 'ABORT TASK'
>> TMF. This is typically done by the 'eh_abort_handler' LLDD callback.
>>
>> Conceptually, however, this function is a normal SCSI command, so
>> there is no need to enter the error handler.
>>
>> This patch implements a new scsi_abort_command() function which
>> invokes an asynchronous function scsi_eh_abort_handler() to
>> abort the commands via the usual 'eh_abort_handler'.
>>
>> If abort succeeds the command is either retried or terminated,
>> depending on the number of allowed retries. However, 'eh_eflags'
>> records the abort, so if the retry would fail again the
>> command is pushed onto the error handler without trying to
>> abort it (again); it'll be cleared up from SCSI EH.
>>
>> Signed-off-by: Hannes Reinecke<hare@suse.de>
>> ---
>>   drivers/scsi/scsi.c       |   1 +
>>   drivers/scsi/scsi_error.c | 139
>> ++++++++++++++++++++++++++++++++++++++++++----
>>   drivers/scsi/scsi_priv.h  |   2 +
>>   include/scsi/scsi_cmnd.h  |   2 +
>>   4 files changed, 132 insertions(+), 12 deletions(-)
>>
>> diff --git a/drivers/scsi/scsi.c b/drivers/scsi/scsi.c
>> index ebe3b0a..06257cf 100644
>> --- a/drivers/scsi/scsi.c
>> +++ b/drivers/scsi/scsi.c
>> @@ -297,6 +297,7 @@ struct scsi_cmnd *scsi_get_command(struct
>> scsi_device *dev, gfp_t gfp_mask)
>>
>>           cmd->device = dev;
>>           INIT_LIST_HEAD(&cmd->list);
>> +        INIT_WORK(&cmd->abort_work, scmd_eh_abort_handler);
>>           spin_lock_irqsave(&dev->list_lock, flags);
>>           list_add_tail(&cmd->list,&dev->cmd_list);
>>           spin_unlock_irqrestore(&dev->list_lock, flags);
>> diff --git a/drivers/scsi/scsi_error.c b/drivers/scsi/scsi_error.c
>> index e76e895..835f7e4 100644
>> --- a/drivers/scsi/scsi_error.c
>> +++ b/drivers/scsi/scsi_error.c
>> @@ -55,6 +55,7 @@ static void scsi_eh_done(struct scsi_cmnd *scmd);
>>   #define HOST_RESET_SETTLE_TIME  (10)
>>
>>   static int scsi_eh_try_stu(struct scsi_cmnd *scmd);
>> +static int scsi_try_to_abort_cmd(struct scsi_host_template *, struct
>> scsi_cmnd *);
>>
>>   /* called with shost->host_lock held */
>>   void scsi_eh_wakeup(struct Scsi_Host *shost)
>> @@ -102,6 +103,111 @@ static int scsi_host_eh_past_deadline(struct
>> Scsi_Host *shost)
>>   }
>>
>>   /**
>> + * scmd_eh_abort_handler - Handle command aborts
>> + * @work:    command to be aborted.
>> + */
>> +void
>> +scmd_eh_abort_handler(struct work_struct *work)
>> +{
>> +    struct scsi_cmnd *scmd =
>> +        container_of(work, struct scsi_cmnd, abort_work);
>> +    struct scsi_device *sdev = scmd->device;
>> +    unsigned long flags;
>> +    int rtn;
>> +
>> +    spin_lock_irqsave(sdev->host->host_lock, flags);
>> +    if (scsi_host_eh_past_deadline(sdev->host)) {
>> +        spin_unlock_irqrestore(sdev->host->host_lock, flags);
>> +        SCSI_LOG_ERROR_RECOVERY(3,
>> +            scmd_printk(KERN_INFO, scmd,
>> +                    "eh timeout, not aborting\n"));
>
> Command address should be also printed for debugging conveniently:
> +"eh timeout, not aborting command %p\n", scmd));
>
Hmm. Okay, I could. Will be preparing an updated patchset.

Cheers,

Hannes
-- 
Dr. Hannes Reinecke		      zSeries & Storage
hare@suse.de			      +49 911 74053 688
SUSE LINUX Products GmbH, Maxfeldstr. 5, 90409 Nürnberg
GF: J. Hawn, J. Guild, F. Imendörffer, HRB 16746 (AG Nürnberg)
--
To unsubscribe from this list: send the line "unsubscribe linux-scsi" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html