New EH command timeout handler

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<[email protected]>

---
  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(-)

drivers/scsi/scsi.c +1 -0

index ebe3b0a..06257cf 100644
@@ -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);

drivers/scsi/scsi_error.c +9 -0

index e76e895..835f7e4 100644
@@ -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);

drivers/scsi/scsi_error.c +29 -0

+		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;
+	}
+

drivers/scsi/scsi_error.c +38 -12

+		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

drivers/scsi/scsi_priv.h +2 -0

index 8f9a0ca..f079a59 100644
@@ -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);

include/scsi/scsi_cmnd.h +2 -0

index de5f5d8..a2f062e 100644
@@ -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);

Hi, Hannes:

Quoted 69 lines · 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<[email protected]>

---
  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(-)

drivers/scsi/scsi.c +1 -0

index ebe3b0a..06257cf 100644
@@ -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);

drivers/scsi/scsi_error.c +1 -0

index e76e895..835f7e4 100644
@@ -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)

drivers/scsi/scsi_error.c +13 -0

@@ -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);

drivers/scsi/scsi_error.c static int scsi_host_eh_past_deadline(struct Scsi_Host *shost) · line 123

Quoted 5 lines

drivers/scsi/scsi_error.c +5 -0

+    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));

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.

Hi, Hannes:

Quoted 16 lines · Hannes Reinecke

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

Quoted 6 lines

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

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?

Quoted 40 lines · Ren Mingxin

Quoted 16 lines · Hannes Reinecke

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

Quoted 6 lines

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

Quoted 3 lines

    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).

[ .. ]

Quoted 25 lines

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

Quoted 7 lines

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.

Hi, Hannes:

Quoted 45 lines · Hannes Reinecke

Quoted 40 lines · Ren Mingxin

Quoted 16 lines · Hannes Reinecke

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

Quoted 6 lines

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

Quoted 3 lines

    real    0m27.860s
    user    0m0.001s
    sys     0m0.000s

Quoted 7 lines

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.

From 2d0851bea02e3d15bf403e6800cc7164f2e211f2 Mon Sep 17 00:00:00 2001

Quoted 54 lines · Ren Mingxin

Quoted 52 lines · Hannes Reinecke

Quoted 40 lines · Ren Mingxin

Quoted 16 lines · Hannes Reinecke

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

Quoted 6 lines

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

Quoted 3 lines

     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).

Quoted 4 lines

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.

Quoted 55 lines · Hannes Reinecke

Quoted 54 lines · Ren Mingxin

Quoted 52 lines · Hannes Reinecke

Quoted 40 lines · Ren Mingxin

Quoted 16 lines · Hannes Reinecke

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

Quoted 6 lines

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

Quoted 3 lines

     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).

Quoted 7 lines

Quoted 4 lines

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

Hi, Hannes:

Quoted 83 lines · Ren Mingxin

Quoted 59 lines · Hannes Reinecke

Quoted 58 lines · Ren Mingxin

Quoted 56 lines · Hannes Reinecke

Quoted 42 lines · Ren Mingxin

Quoted 16 lines · Hannes Reinecke

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

Quoted 6 lines

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

Quoted 3 lines

     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).

Quoted 8 lines

Quoted 5 lines

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

Quoted 12 lines

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?