linux-kernel.vger.kernel.org archive mirror
 help / color / mirror / Atom feed
* [SCSI][REGRESSION][BISECTED] Disk errors loop forever in 2.6.29
@ 2009-02-19 13:53 Sitsofe Wheeler
  2009-02-19 14:58 ` Ingo Molnar
  2009-02-19 15:02 ` Alan Stern
  0 siblings, 2 replies; 8+ messages in thread
From: Sitsofe Wheeler @ 2009-02-19 13:53 UTC (permalink / raw)
  To: linux-kernel; +Cc: Alan Stern, James Bottomley

Hi,

There appears to be a regression from 2.6.28 in how disk errors are
handled in 2.6.29rc5 - rather than trying and eventually giving up, it
appears to try (and report) forever. 

Here is the output where it aborts in 2.6.28:

ata2.01: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6
ata2.01: BMDMA stat 0x65
ata2.01: cmd c8/00:00:f7:e2:9c/00:00:00:00:00/f1 tag 0 dma 131072 in
         res 00/00:00:00:00:00/00:00:00:00:00/00 Emask 0x2 (HSM violation)
ata2: soft resetting link
ata2.00: configured for UDMA/66
ata2.01: configured for UDMA/66
ata2: EH complete
ata2.01: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6
ata2.01: BMDMA stat 0x65
ata2.01: cmd c8/00:00:f7:e2:9c/00:00:00:00:00/f1 tag 0 dma 131072 in
         res 00/00:00:00:00:00/00:00:00:00:00/00 Emask 0x2 (HSM violation)
ata2: soft resetting link
ata2.00: configured for UDMA/66
ata2.01: configured for UDMA/66
ata2: EH complete
sd 1:0:0:0: [sda] 7880544 512-byte hardware sectors: (4.03 GB/3.75 GiB)
ata2.01: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6
ata2.01: BMDMA stat 0x65
ata2.01: cmd c8/00:00:f7:e2:9c/00:00:00:00:00/f1 tag 0 dma 131072 in
         res 00/00:00:00:00:00/00:00:00:00:00/00 Emask 0x2 (HSM violation)
ata2: soft resetting link
ata2.00: configured for UDMA/66
ata2.01: configured for UDMA/66
ata2: EH complete
sd 1:0:0:0: [sda] Write Protect is off
sd 1:0:0:0: [sda] Mode Sense: 00 3a 00 00
ata2.01: limiting speed to UDMA/44:PIO4
ata2.01: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6
ata2.01: BMDMA stat 0x65
ata2.01: cmd c8/00:00:f7:e2:9c/00:00:00:00:00/f1 tag 0 dma 131072 in
         res 00/00:00:00:00:00/00:00:00:00:00/00 Emask 0x2 (HSM violation)
ata2: soft resetting link
ata2.00: configured for UDMA/66
ata2.01: configured for UDMA/44
ata2: EH complete
ata2.01: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6
ata2.01: BMDMA stat 0x65
ata2.01: cmd c8/00:00:f7:e2:9c/00:00:00:00:00/f1 tag 0 dma 131072 in
         res 00/00:00:00:00:00/00:00:00:00:00/00 Emask 0x2 (HSM violation)
ata2: soft resetting link
ata2.00: configured for UDMA/66
ata2.01: configured for UDMA/44
ata2: EH complete
sd 1:0:0:0: [sda] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA
sda: detected capacity change from 0 to 4034838528
ata2.01: limiting speed to UDMA/33:PIO4
ata2.01: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6
ata2.01: BMDMA stat 0x65
ata2.01: cmd c8/00:00:f7:e2:9c/00:00:00:00:00/f1 tag 0 dma 131072 in
         res 00/00:00:00:00:00/00:00:00:00:00/00 Emask 0x2 (HSM violation)
ata2: soft resetting link
ata2.00: configured for UDMA/66
ata2.01: configured for UDMA/33
sd 1:0:1:0: [sdb] Result: hostbyte=0x00 driverbyte=0x08
sd 1:0:1:0: [sdb] Sense Key : 0xb [current] [descriptor]
Descriptor sense data with sense descriptors (in hex):
        72 0b 00 00 00 00 00 0c 00 0a 80 00 00 00 00 00 
        00 00 00 00 
sd 1:0:1:0: [sdb] ASC=0x0 ASCQ=0x0
end_request: I/O error, dev sdb, sector 27058935
Buffer I/O error on device sdb2, logical block 444480
Buffer I/O error on device sdb2, logical block 444481
Buffer I/O error on device sdb2, logical block 444482
Buffer I/O error on device sdb2, logical block 444483
Buffer I/O error on device sdb2, logical block 444484
Buffer I/O error on device sdb2, logical block 444485
Buffer I/O error on device sdb2, logical block 444486
Buffer I/O error on device sdb2, logical block 444487
Buffer I/O error on device sdb2, logical block 444488
Buffer I/O error on device sdb2, logical block 444489
ata2: EH complete

It never gets to end_request on 2.6.29. I've bisected the problem down
to the following:

[b60af5b0adf0da24c673598c8d3fb4d4189a15ce] [SCSI] simplify scsi_io_completion()

Author: Alan Stern <stern@rowland.harvard.edu>
Date:   Mon Nov 3 15:56:47 2008 -0500

    [SCSI] simplify scsi_io_completion()
    
    This patch (as1142b) consolidates a lot of repetitious code in
    scsi_io_completion().  It also fixes a few comments.  Most
    importantly, however, it clearly distinguishes among the three sorts
    of retries that can be done when a command fails to complete:
    
        Unprepare the request and resubmit it, so that a new
        command will be created for it.
    
        Requeue the request directly so that it will be retried
        immediately using the same command.
    
        Requeue the request so that it will be retried following
        a short delay.
    
        Complete the remainder of the request with an I/O error.
    
    [jejb: Updates
	 1. For several error conditions, we would now print the sense twice
            in slightly different ways, so unify the location of sense
            printing.
         2. I added more descriptions to actual failure conditions for
            better debugging
         3. according to spec, ABORTED_COMMAND is supposed to be retried
            (except on DIF failure).  Our old behaviour of erroring it looks
            to be a bug.
         4. I'd prefer not to default initialise the action variable because
            that ensures that every leg of the error handler has an
            associated action and the compiler will warn if someone later
            accidentally misses one or removes one.
    ]
    Signed-off-by: Alan Stern <stern@rowland.harvard.edu>
    Signed-off-by: James Bottomley <James.Bottomley@HansenPartnership.com>

Reverting this made the endless looping go away. Here is the bisection
log:

git-bisect start
# bad: [38c8e6180939e5619140b2e9e479cb26029ff8b1] do_mpage_readpage():
# don't submit lots of small bios on boundary
git-bisect bad 38c8e6180939e5619140b2e9e479cb26029ff8b1
# good: [4a6908a3a050aacc9c3a2f36b276b46c0629ad91] Linux 2.6.28
git-bisect good 4a6908a3a050aacc9c3a2f36b276b46c0629ad91
# good: [3c92ec8ae91ecf59d88c798301833d7cf83f2179] Merge branch 'next'
# of git://git.kernel.org/pub/scm/linux/kernel/git/paulus/powerpc
git-bisect good 3c92ec8ae91ecf59d88c798301833d7cf83f2179
# bad: [590cf28580c999c8ba70dc39b40bab09d69e2630] Merge
# git://git.kernel.org/pub/scm/linux/kernel/git/jejb/scsi-misc-2.6
git-bisect bad 590cf28580c999c8ba70dc39b40bab09d69e2630
# good: [14a3c4ab0e58d143c7928c9eb2f2610205e13bf2] Merge branch 'devel'
# of master.kernel.org:/home/rmk/linux-2.6-arm
git-bisect good 14a3c4ab0e58d143c7928c9eb2f2610205e13bf2
# good: [121520a7084b48cb26437c6e89d4b491c3e4d4d5] V4L/DVB (9853):
# gspca: Webcam 093a:2622 added in pac7311.
git-bisect good 121520a7084b48cb26437c6e89d4b491c3e4d4d5
# good: [9414de39e8e07d90bdb6524be501fae0e013d37b] V4L/DVB (10079):
# sh_mobile_ceu: use new pixel format translation code
git-bisect good 9414de39e8e07d90bdb6524be501fae0e013d37b
# bad: [dedbc2b3cb8404c618975bd2811c7605a4ccb51e] [SCSI] zfcp: Simplify
# SBAL allocation to fix sparse warnings
git-bisect bad dedbc2b3cb8404c618975bd2811c7605a4ccb51e
# bad: [ae15f80172d95f978b60d40408353943d5bc099b] [SCSI] libiscsi:
# handle init task failures.
git-bisect bad ae15f80172d95f978b60d40408353943d5bc099b
# good: [dd7c34e9a27be521d480e5b84c84e92de2ea7b95] [SCSI] fusion: use
# ARRAY_SIZE
git-bisect good dd7c34e9a27be521d480e5b84c84e92de2ea7b95
# bad: [b29f841378460c37e99a2398d0015d9bd7901a09] [SCSI] remove timeout
# from struct scsi_device
git-bisect bad b29f841378460c37e99a2398d0015d9bd7901a09
# good: [67e6d58d812ec3e95918266076d4c836cdec849a] [SCSI] ibmvfc: Driver
# version 1.0.4
git-bisect good 67e6d58d812ec3e95918266076d4c836cdec849a
# bad: [09e13e91670b69736b5da0a869a076a55a326394] [SCSI] m68k: mac_esp
# asm fix
git-bisect bad 09e13e91670b69736b5da0a869a076a55a326394
# bad: [749af3d54a6d5619088ecadb1010c6ab7766f519] [SCSI] qla2xxx: Code
# changes for vport bus reset
git-bisect bad 749af3d54a6d5619088ecadb1010c6ab7766f519
# bad: [b60af5b0adf0da24c673598c8d3fb4d4189a15ce] [SCSI] simplify
# scsi_io_completion()
git-bisect bad b60af5b0adf0da24c673598c8d3fb4d4189a15ce

-- 
Sitsofe | http://sucs.org/~sits/

^ permalink raw reply	[flat|nested] 8+ messages in thread

* Re: [SCSI][REGRESSION][BISECTED] Disk errors loop forever in 2.6.29
  2009-02-19 13:53 [SCSI][REGRESSION][BISECTED] Disk errors loop forever in 2.6.29 Sitsofe Wheeler
@ 2009-02-19 14:58 ` Ingo Molnar
  2009-02-19 15:02 ` Alan Stern
  1 sibling, 0 replies; 8+ messages in thread
From: Ingo Molnar @ 2009-02-19 14:58 UTC (permalink / raw)
  To: Sitsofe Wheeler; +Cc: linux-kernel, Alan Stern, James Bottomley


* Sitsofe Wheeler <sitsofe@yahoo.com> wrote:

> Hi,
> 
> There appears to be a regression from 2.6.28 in how disk errors are
> handled in 2.6.29rc5 - rather than trying and eventually giving up, it
> appears to try (and report) forever. 
> 
> Here is the output where it aborts in 2.6.28:
> 
> ata2.01: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6
> ata2.01: BMDMA stat 0x65
> ata2.01: cmd c8/00:00:f7:e2:9c/00:00:00:00:00/f1 tag 0 dma 131072 in
>          res 00/00:00:00:00:00/00:00:00:00:00/00 Emask 0x2 (HSM violation)
> ata2: soft resetting link
> ata2.00: configured for UDMA/66
> ata2.01: configured for UDMA/66
> ata2: EH complete
> ata2.01: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6
> ata2.01: BMDMA stat 0x65
> ata2.01: cmd c8/00:00:f7:e2:9c/00:00:00:00:00/f1 tag 0 dma 131072 in
>          res 00/00:00:00:00:00/00:00:00:00:00/00 Emask 0x2 (HSM violation)
> ata2: soft resetting link
> ata2.00: configured for UDMA/66
> ata2.01: configured for UDMA/66
> ata2: EH complete
> sd 1:0:0:0: [sda] 7880544 512-byte hardware sectors: (4.03 GB/3.75 GiB)
> ata2.01: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6
> ata2.01: BMDMA stat 0x65
> ata2.01: cmd c8/00:00:f7:e2:9c/00:00:00:00:00/f1 tag 0 dma 131072 in
>          res 00/00:00:00:00:00/00:00:00:00:00/00 Emask 0x2 (HSM violation)
> ata2: soft resetting link
> ata2.00: configured for UDMA/66
> ata2.01: configured for UDMA/66
> ata2: EH complete
> sd 1:0:0:0: [sda] Write Protect is off
> sd 1:0:0:0: [sda] Mode Sense: 00 3a 00 00
> ata2.01: limiting speed to UDMA/44:PIO4
> ata2.01: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6
> ata2.01: BMDMA stat 0x65
> ata2.01: cmd c8/00:00:f7:e2:9c/00:00:00:00:00/f1 tag 0 dma 131072 in
>          res 00/00:00:00:00:00/00:00:00:00:00/00 Emask 0x2 (HSM violation)
> ata2: soft resetting link
> ata2.00: configured for UDMA/66
> ata2.01: configured for UDMA/44
> ata2: EH complete
> ata2.01: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6
> ata2.01: BMDMA stat 0x65
> ata2.01: cmd c8/00:00:f7:e2:9c/00:00:00:00:00/f1 tag 0 dma 131072 in
>          res 00/00:00:00:00:00/00:00:00:00:00/00 Emask 0x2 (HSM violation)
> ata2: soft resetting link
> ata2.00: configured for UDMA/66
> ata2.01: configured for UDMA/44
> ata2: EH complete
> sd 1:0:0:0: [sda] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA
> sda: detected capacity change from 0 to 4034838528
> ata2.01: limiting speed to UDMA/33:PIO4
> ata2.01: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6
> ata2.01: BMDMA stat 0x65
> ata2.01: cmd c8/00:00:f7:e2:9c/00:00:00:00:00/f1 tag 0 dma 131072 in
>          res 00/00:00:00:00:00/00:00:00:00:00/00 Emask 0x2 (HSM violation)
> ata2: soft resetting link
> ata2.00: configured for UDMA/66
> ata2.01: configured for UDMA/33
> sd 1:0:1:0: [sdb] Result: hostbyte=0x00 driverbyte=0x08
> sd 1:0:1:0: [sdb] Sense Key : 0xb [current] [descriptor]
> Descriptor sense data with sense descriptors (in hex):
>         72 0b 00 00 00 00 00 0c 00 0a 80 00 00 00 00 00 
>         00 00 00 00 
> sd 1:0:1:0: [sdb] ASC=0x0 ASCQ=0x0
> end_request: I/O error, dev sdb, sector 27058935
> Buffer I/O error on device sdb2, logical block 444480
> Buffer I/O error on device sdb2, logical block 444481
> Buffer I/O error on device sdb2, logical block 444482
> Buffer I/O error on device sdb2, logical block 444483
> Buffer I/O error on device sdb2, logical block 444484
> Buffer I/O error on device sdb2, logical block 444485
> Buffer I/O error on device sdb2, logical block 444486
> Buffer I/O error on device sdb2, logical block 444487
> Buffer I/O error on device sdb2, logical block 444488
> Buffer I/O error on device sdb2, logical block 444489
> ata2: EH complete
> 
> It never gets to end_request on 2.6.29. I've bisected the problem down
> to the following:
> 
> [b60af5b0adf0da24c673598c8d3fb4d4189a15ce] [SCSI] simplify scsi_io_completion()
> 
> Author: Alan Stern <stern@rowland.harvard.edu>
> Date:   Mon Nov 3 15:56:47 2008 -0500
> 
>     [SCSI] simplify scsi_io_completion()

i had SCSI problems with that area of the code, and the patch 
below fixed it. Maybe it fixes your problem too.

	Ingo

----------------------->
>From 7e4cbd14b28546e6f758d01b0d7f3f4647fada52 Mon Sep 17 00:00:00 2001
From: Alan Stern <stern@rowland.harvard.edu>
Date: Tue, 17 Feb 2009 15:10:21 -0500
Subject: [PATCH] fix "scsi: aic7xxx hang since v2.6.28-rc1"

This patch (as1144c) removes scsi_end_request().  The routine had only
one caller, so it is moved inline and simplified.

In addition, if no forward progress has been made then the patch
decrements a request's retry counter before unpreparing and requeuing
it, to avoid infinite retry loops.

Signed-off-by: Alan Stern <stern@rowland.harvard.edu>
Cc: James Bottomley <James.Bottomley@HansenPartnership.com>
Cc: Jens Axboe <jens.axboe@oracle.com>
Cc: "Rafael J. Wysocki" <rjw@sisk.pl>
Signed-off-by: Ingo Molnar <mingo@elte.hu>
---
 drivers/scsi/scsi_lib.c |   94 ++++++++++-------------------------------------
 1 files changed, 20 insertions(+), 74 deletions(-)

diff --git a/drivers/scsi/scsi_lib.c b/drivers/scsi/scsi_lib.c
index 940dc32..d4c6ac3 100644
--- a/drivers/scsi/scsi_lib.c
+++ b/drivers/scsi/scsi_lib.c
@@ -703,71 +703,6 @@ void scsi_run_host_queues(struct Scsi_Host *shost)
 
 static void __scsi_release_buffers(struct scsi_cmnd *, int);
 
-/*
- * Function:    scsi_end_request()
- *
- * Purpose:     Post-processing of completed commands (usually invoked at end
- *		of upper level post-processing and scsi_io_completion).
- *
- * Arguments:   cmd	 - command that is complete.
- *              error    - 0 if I/O indicates success, < 0 for I/O error.
- *              bytes    - number of bytes of completed I/O
- *		requeue  - indicates whether we should requeue leftovers.
- *
- * Lock status: Assumed that lock is not held upon entry.
- *
- * Returns:     cmd if requeue required, NULL otherwise.
- *
- * Notes:       This is called for block device requests in order to
- *              mark some number of sectors as complete.
- * 
- *		We are guaranteeing that the request queue will be goosed
- *		at some point during this call.
- * Notes:	If cmd was requeued, upon return it will be a stale pointer.
- */
-static struct scsi_cmnd *scsi_end_request(struct scsi_cmnd *cmd, int error,
-					  int bytes, int requeue)
-{
-	struct request_queue *q = cmd->device->request_queue;
-	struct request *req = cmd->request;
-
-	/*
-	 * If there are blocks left over at the end, set up the command
-	 * to queue the remainder of them.
-	 */
-	if (blk_end_request(req, error, bytes)) {
-		int leftover = (req->hard_nr_sectors << 9);
-
-		if (blk_pc_request(req))
-			leftover = req->data_len;
-
-		/* kill remainder if no retrys */
-		if (error && scsi_noretry_cmd(cmd))
-			blk_end_request(req, error, leftover);
-		else {
-			if (requeue) {
-				/*
-				 * Bleah.  Leftovers again.  Stick the
-				 * leftovers in the front of the
-				 * queue, and goose the queue again.
-				 */
-				scsi_release_buffers(cmd);
-				scsi_requeue_command(q, cmd);
-				cmd = NULL;
-			}
-			return cmd;
-		}
-	}
-
-	/*
-	 * This will goose the queue request function at the end, so we don't
-	 * need to worry about launching another command.
-	 */
-	__scsi_release_buffers(cmd, 0);
-	scsi_next_command(cmd);
-	return NULL;
-}
-
 static inline unsigned int scsi_sgtable_index(unsigned short nents)
 {
 	unsigned int index;
@@ -929,7 +864,6 @@ static void scsi_end_bidi_request(struct scsi_cmnd *cmd)
 void scsi_io_completion(struct scsi_cmnd *cmd, unsigned int good_bytes)
 {
 	int result = cmd->result;
-	int this_count;
 	struct request_queue *q = cmd->device->request_queue;
 	struct request *req = cmd->request;
 	int error = 0;
@@ -980,18 +914,30 @@ void scsi_io_completion(struct scsi_cmnd *cmd, unsigned int good_bytes)
 	SCSI_LOG_HLCOMPLETE(1, printk("%ld sectors total, "
 				      "%d bytes done.\n",
 				      req->nr_sectors, good_bytes));
-
-	/* A number of bytes were successfully read.  If there
-	 * are leftovers and there is some kind of error
-	 * (result != 0), retry the rest.
-	 */
-	if (scsi_end_request(cmd, error, good_bytes, result == 0) == NULL)
+	if (blk_end_request(req, error, good_bytes) == 0) {
+		/* This request is completely finished; start the next one */
+		scsi_next_command(cmd);
 		return;
-	this_count = blk_rq_bytes(req);
+	}
 
 	error = -EIO;
 
-	if (host_byte(result) == DID_RESET) {
+	/* The request isn't finished yet.  Figure out what to do next. */
+	if (result == 0) {
+		/* No error, so carry out the remainder of the request.
+		 * Failure to make forward progress counts against the
+		 * the number of retries.
+		 */
+		if (good_bytes > 0 || --req->retries >= 0)
+			action = ACTION_REPREP;
+		else {
+			action = ACTION_FAIL;
+			description = "Retries exhausted";
+		}
+	} else if (error && scsi_noretry_cmd(cmd)) {
+		/* Retrys are disallowed, so kill the remainder. */
+		action = ACTION_FAIL;
+	} else if (host_byte(result) == DID_RESET) {
 		/* Third party bus reset or reset for error recovery
 		 * reasons.  Just retry the command and see what
 		 * happens.

^ permalink raw reply related	[flat|nested] 8+ messages in thread

* Re: [SCSI][REGRESSION][BISECTED] Disk errors loop forever in 2.6.29
  2009-02-19 13:53 [SCSI][REGRESSION][BISECTED] Disk errors loop forever in 2.6.29 Sitsofe Wheeler
  2009-02-19 14:58 ` Ingo Molnar
@ 2009-02-19 15:02 ` Alan Stern
  2009-02-19 16:52   ` Sitsofe Wheeler
  1 sibling, 1 reply; 8+ messages in thread
From: Alan Stern @ 2009-02-19 15:02 UTC (permalink / raw)
  To: Sitsofe Wheeler; +Cc: linux-kernel, James Bottomley

On Thu, 19 Feb 2009, Sitsofe Wheeler wrote:

> Hi,
> 
> There appears to be a regression from 2.6.28 in how disk errors are
> handled in 2.6.29rc5 - rather than trying and eventually giving up, it
> appears to try (and report) forever. 

See this thread and patch:

	http://marc.info/?l=linux-kernel&m=123490148422684&w=2

Alan Stern


^ permalink raw reply	[flat|nested] 8+ messages in thread

* Re: [SCSI][REGRESSION][BISECTED] Disk errors loop forever in 2.6.29
  2009-02-19 15:02 ` Alan Stern
@ 2009-02-19 16:52   ` Sitsofe Wheeler
  2009-02-19 18:41     ` James Bottomley
  0 siblings, 1 reply; 8+ messages in thread
From: Sitsofe Wheeler @ 2009-02-19 16:52 UTC (permalink / raw)
  To: Alan Stern; +Cc: linux-kernel, James Bottomley, rjw, Ingo Molnar, linux-scsi

> From: Alan Stern <stern@rowland.harvard.edu>
>
> On Thu, 19 Feb 2009, Sitsofe Wheeler wrote:
> 
> > Hi,
> > 
> > There appears to be a regression from 2.6.28 in how disk errors are
> > handled in 2.6.29rc5 - rather than trying and eventually giving up, it
> > appears to try (and report) forever. 
> 
> See this thread and patch:
> 
>     http://marc.info/?l=linux-kernel&m=123490148422684&w=2

The patch there (actually I downloaded it from http://patchwork.kernel.org/patch/7989/ )
did not make any diference. I fear my disk will soon have torn itself to bits but until then I
can trigger the error at will so I can test any patches that are suggested...



      

^ permalink raw reply	[flat|nested] 8+ messages in thread

* Re: [SCSI][REGRESSION][BISECTED] Disk errors loop forever in 2.6.29
  2009-02-19 16:52   ` Sitsofe Wheeler
@ 2009-02-19 18:41     ` James Bottomley
  0 siblings, 0 replies; 8+ messages in thread
From: James Bottomley @ 2009-02-19 18:41 UTC (permalink / raw)
  To: Sitsofe Wheeler; +Cc: Alan Stern, linux-kernel, rjw, Ingo Molnar, linux-scsi

On Thu, 2009-02-19 at 08:52 -0800, Sitsofe Wheeler wrote:
> > From: Alan Stern <stern@rowland.harvard.edu>
> >
> > On Thu, 19 Feb 2009, Sitsofe Wheeler wrote:
> > 
> > > Hi,
> > > 
> > > There appears to be a regression from 2.6.28 in how disk errors are
> > > handled in 2.6.29rc5 - rather than trying and eventually giving up, it
> > > appears to try (and report) forever. 
> > 
> > See this thread and patch:
> > 
> >     http://marc.info/?l=linux-kernel&m=123490148422684&w=2
> 
> The patch there (actually I downloaded it from http://patchwork.kernel.org/patch/7989/ )
> did not make any diference. I fear my disk will soon have torn itself to bits but until then I
> can trigger the error at will so I can test any patches that are suggested...

Can you try this patch ... it was something I meant to get into 2.6.29
but forgot about.  The key problem that you seem to be hitting is that
the requeue evades the timeout check.  Moving the timeout check to block
should fix that.

James

---

>From 5546538f37a1f4319ec4dbdb6f2e7261ce986e61 Mon Sep 17 00:00:00 2001
From: James Bottomley <James.Bottomley@HansenPartnership.com>
Date: Tue, 16 Dec 2008 17:00:44 -0500
Subject: block: move SCSI timeout check into block

We can eliminate the SCSI command timed out check entirely if the block
layer does this for us.  The way to do this in block is to check how
long the request has been outstanding if a requeue is requested and
ending it if we've gone over retries * timeout.

This will also eliminate many cases in SCSI where we evade the command
timeout for various reasons (like initial success converted to requeue)

Signed-off-by: James Bottomley <James.Bottomley@HansenPartnership.com>
---
 block/blk-core.c |   10 +++++++++-
 1 files changed, 9 insertions(+), 1 deletions(-)

diff --git a/block/blk-core.c b/block/blk-core.c
index 29bcfac..3928ec8 100644
--- a/block/blk-core.c
+++ b/block/blk-core.c
@@ -937,6 +937,8 @@ EXPORT_SYMBOL(blk_start_queueing);
  */
 void blk_requeue_request(struct request_queue *q, struct request *rq)
 {
+	unsigned long wait_for = (rq->retries + 1) * rq->timeout;
+
 	blk_delete_timer(rq);
 	blk_clear_rq_complete(rq);
 	trace_block_rq_requeue(q, rq);
@@ -944,7 +946,13 @@ void blk_requeue_request(struct request_queue *q, struct request *rq)
 	if (blk_rq_tagged(rq))
 		blk_queue_end_tag(q, rq);
 
-	elv_requeue_request(q, rq);
+	if (time_before(rq->start_time + wait_for, jiffies)) {
+		printk(KERN_ERR "%s: timing out command, waited %lus\n",
+		       rq->rq_disk ? rq->rq_disk->disk_name : "?",
+		       wait_for/HZ);
+		blk_end_request(rq, -EIO, blk_rq_bytes(rq));
+	} else
+		elv_requeue_request(q, rq);
 }
 EXPORT_SYMBOL(blk_requeue_request);
 
-- 
1.5.6.6




^ permalink raw reply related	[flat|nested] 8+ messages in thread

* Re: [SCSI][REGRESSION][BISECTED] Disk errors loop forever in 2.6.29
  2009-02-19 21:48 ` James Bottomley
@ 2009-02-20  0:54   ` Sitsofe Wheeler
  0 siblings, 0 replies; 8+ messages in thread
From: Sitsofe Wheeler @ 2009-02-20  0:54 UTC (permalink / raw)
  To: James Bottomley; +Cc: Alan Stern, linux-kernel, rjw, Ingo Molnar, linux-scsi

> From: James Bottomley <James.Bottomley@HansenPartnership.com>

> 
> Your specific behaviour change seems to be a bug in the way the rewrite
> is handling ABORTED_COMMAND.  Could you try the patch below (with or
> without the block patch, it shouldn't matter) and see if it gets you
> back to 2.6.28 behaviour?

Yup that patch makes things timeout quickly just like 2.6.28. The whole 
"it didn't used to cache failures" piece in the previous email seems to
have been a fabrication inside my own head - I checked and 2.6.28 caches
the failure until the cache is dropped too.

It might be worth turning your original patch into some sort of warning
stack trace trigger so that people understand it's just there for 
unwedging and isn't expected behaviour (it is useful for breaking out of
near lockups though).

Tested-by: Sitsofe Wheeler <sitsofe@yahoo.com>



      

^ permalink raw reply	[flat|nested] 8+ messages in thread

* Re: [SCSI][REGRESSION][BISECTED] Disk errors loop forever in 2.6.29
  2009-02-19 21:11 Sitsofe Wheeler
@ 2009-02-19 21:48 ` James Bottomley
  2009-02-20  0:54   ` Sitsofe Wheeler
  0 siblings, 1 reply; 8+ messages in thread
From: James Bottomley @ 2009-02-19 21:48 UTC (permalink / raw)
  To: Sitsofe Wheeler; +Cc: Alan Stern, linux-kernel, rjw, Ingo Molnar, linux-scsi

On Thu, 2009-02-19 at 13:11 -0800, Sitsofe Wheeler wrote:
> > From: James Bottomley <James.Bottomley@HansenPartnership.com>
> >
> > Can you try this patch ... it was something I meant to get into 2.6.29
> > but forgot about.  The key problem that you seem to be hitting is that
> > the requeue evades the timeout check.  Moving the timeout check to block
> > should fix that.
> 
> Even by itself this patch works although the behaviour is now different
> to that of 2.6.28.  Whereas in 2.6.28 it would timeout very quickly
> (after about 1 or 2 seconds) it now times out after 30 seconds
> (initially I hadn't realised that it would be so much longer). The
> other difference is that the failure becomes cached - trying to reread
> the same area using dd instantly fails from now on without any more disk
> IO/kernel error messages until echo 1 > /proc/sys/vm/drop_caches is
> issued. Before it would always go straight to the disk for the unread
> section and the kernel spew would be repeated before the failure.

Well, the block patch is more of a catch all:  without it apparently the
scsi_io_completion() rewrite has several cases where it will apparently
loop forever.

Your specific behaviour change seems to be a bug in the way the rewrite
is handling ABORTED_COMMAND.  Could you try the patch below (with or
without the block patch, it shouldn't matter) and see if it gets you
back to 2.6.28 behaviour?

Thanks,

James

---

diff --git a/drivers/scsi/scsi_lib.c b/drivers/scsi/scsi_lib.c
index c034841..4b13e36 100644
--- a/drivers/scsi/scsi_lib.c
+++ b/drivers/scsi/scsi_lib.c
@@ -850,12 +850,11 @@ void scsi_io_completion(struct scsi_cmnd *cmd, unsigned int good_bytes)
 				action = ACTION_FAIL;
 			break;
 		case ABORTED_COMMAND:
+			action = ACTION_FAIL;
 			if (sshdr.asc == 0x10) { /* DIF */
 				description = "Target Data Integrity Failure";
-				action = ACTION_FAIL;
 				error = -EILSEQ;
-			} else
-				action = ACTION_RETRY;
+			}
 			break;
 		case NOT_READY:
 			/* If the device is in the process of becoming



^ permalink raw reply related	[flat|nested] 8+ messages in thread

* Re: [SCSI][REGRESSION][BISECTED] Disk errors loop forever in 2.6.29
@ 2009-02-19 21:11 Sitsofe Wheeler
  2009-02-19 21:48 ` James Bottomley
  0 siblings, 1 reply; 8+ messages in thread
From: Sitsofe Wheeler @ 2009-02-19 21:11 UTC (permalink / raw)
  To: James Bottomley; +Cc: Alan Stern, linux-kernel, rjw, Ingo Molnar, linux-scsi

> From: James Bottomley <James.Bottomley@HansenPartnership.com>
>
> Can you try this patch ... it was something I meant to get into 2.6.29
> but forgot about.  The key problem that you seem to be hitting is that
> the requeue evades the timeout check.  Moving the timeout check to block
> should fix that.

Even by itself this patch works although the behaviour is now different
to that of 2.6.28.  Whereas in 2.6.28 it would timeout very quickly
(after about 1 or 2 seconds) it now times out after 30 seconds
(initially I hadn't realised that it would be so much longer). The
other difference is that the failure becomes cached - trying to reread
the same area using dd instantly fails from now on without any more disk
IO/kernel error messages until echo 1 > /proc/sys/vm/drop_caches is
issued. Before it would always go straight to the disk for the unread
section and the kernel spew would be repeated before the failure.

I guess if this is new intended behaviour then all is well - it's just
different and slower/faster :)

Tested-by: Sitsofe Wheeler <sitsofe@yahoo.com>



      

^ permalink raw reply	[flat|nested] 8+ messages in thread

end of thread, other threads:[~2009-02-20  0:54 UTC | newest]

Thread overview: 8+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2009-02-19 13:53 [SCSI][REGRESSION][BISECTED] Disk errors loop forever in 2.6.29 Sitsofe Wheeler
2009-02-19 14:58 ` Ingo Molnar
2009-02-19 15:02 ` Alan Stern
2009-02-19 16:52   ` Sitsofe Wheeler
2009-02-19 18:41     ` James Bottomley
2009-02-19 21:11 Sitsofe Wheeler
2009-02-19 21:48 ` James Bottomley
2009-02-20  0:54   ` Sitsofe Wheeler

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).