[PATCH libata-dev#upstream 2/2] libata: move EH repeat reporting into ata_eh_report()

[PATCH libata-dev#upstream 2/2] libata: move EH repeat reporting into ata_eh_report()

[Tejun Heo]

EH is sometimes repeated without any error or action.  For example,
this happens when probing IDENTIFY fails because of a phantom device.
In these cases, all the repeated EH does is making sure there is no
unhandled error or pending action and return.  This repeation is
necessary to avoid losing any event which occurred while EH was in
progress.

Unfortunately, this dry run causes annonying "EH pending after
completion" message.  This patch moves the repeat reporting into
ata_eh_report() such that it's more compact and skipped on dry runs.

Signed-off-by: Tejun Heo <htejun@gmail.com>
Cc: Mikael Pettersson <mikep@it.uu.se>
---
Mikael, please verify this removes the annonying message you're
seeing.

Thanks.

 drivers/ata/libata-eh.c |   26 ++++++++++++++++----------
 include/linux/libata.h  |    5 +++--
 2 files changed, 19 insertions(+), 12 deletions(-)

Index: work/drivers/ata/libata-eh.c
===================================================================
--- work.orig/drivers/ata/libata-eh.c
+++ work/drivers/ata/libata-eh.c
@@ -290,7 +290,7 @@ enum scsi_eh_timer_return ata_scsi_timed
 void ata_scsi_error(struct Scsi_Host *host)
 {
 	struct ata_port *ap = ata_shost_to_port(host);
-	int i, repeat_cnt = ATA_EH_MAX_REPEAT;
+	int i;
 	unsigned long flags;
 
 	DPRINTK("ENTER\n");
@@ -356,6 +356,9 @@ void ata_scsi_error(struct Scsi_Host *ho
 			__ata_port_freeze(ap);
 
 		spin_unlock_irqrestore(ap->lock, flags);
+
+		/* initialize eh_tries */
+		ap->eh_tries = ATA_EH_MAX_TRIES;
 	} else
 		spin_unlock_wait(ap->lock);
 
@@ -396,15 +399,12 @@ void ata_scsi_error(struct Scsi_Host *ho
 		spin_lock_irqsave(ap->lock, flags);
 
 		if (ap->pflags & ATA_PFLAG_EH_PENDING) {
-			if (--repeat_cnt) {
-				ata_port_printk(ap, KERN_INFO,
-					"EH pending after completion, "
-					"repeating EH (cnt=%d)\n", repeat_cnt);
+			if (--ap->eh_tries) {
 				spin_unlock_irqrestore(ap->lock, flags);
 				goto repeat;
 			}
 			ata_port_printk(ap, KERN_ERR, "EH pending after %d "
-					"tries, giving up\n", ATA_EH_MAX_REPEAT);
+					"tries, giving up\n", ATA_EH_MAX_TRIES);
 			ap->pflags &= ~ATA_PFLAG_EH_PENDING;
 		}
 
@@ -1658,6 +1658,7 @@ static void ata_eh_report(struct ata_por
 {
 	struct ata_eh_context *ehc = &ap->eh_context;
 	const char *frozen, *desc;
+	char tries_buf[6];
 	int tag, nr_failed = 0;
 
 	desc = NULL;
@@ -1682,18 +1683,23 @@ static void ata_eh_report(struct ata_por
 	if (ap->pflags & ATA_PFLAG_FROZEN)
 		frozen = " frozen";
 
+	memset(tries_buf, 0, sizeof(tries_buf));
+	if (ap->eh_tries < ATA_EH_MAX_TRIES)
+		snprintf(tries_buf, sizeof(tries_buf) - 1, " t%d",
+			 ap->eh_tries);
+
 	if (ehc->i.dev) {
 		ata_dev_printk(ehc->i.dev, KERN_ERR, "exception Emask 0x%x "
-			       "SAct 0x%x SErr 0x%x action 0x%x%s\n",
+			       "SAct 0x%x SErr 0x%x action 0x%x%s%s\n",
 			       ehc->i.err_mask, ap->sactive, ehc->i.serror,
-			       ehc->i.action, frozen);
+			       ehc->i.action, frozen, tries_buf);
 		if (desc)
 			ata_dev_printk(ehc->i.dev, KERN_ERR, "%s\n", desc);
 	} else {
 		ata_port_printk(ap, KERN_ERR, "exception Emask 0x%x "
-				"SAct 0x%x SErr 0x%x action 0x%x%s\n",
+				"SAct 0x%x SErr 0x%x action 0x%x%s%s\n",
 				ehc->i.err_mask, ap->sactive, ehc->i.serror,
-				ehc->i.action, frozen);
+				ehc->i.action, frozen, tries_buf);
 		if (desc)
 			ata_port_printk(ap, KERN_ERR, "%s\n", desc);
 	}
Index: work/include/linux/libata.h
===================================================================
--- work.orig/include/linux/libata.h
+++ work/include/linux/libata.h
@@ -287,8 +287,8 @@ enum {
 	ATA_EHI_DID_RESET	= ATA_EHI_DID_SOFTRESET | ATA_EHI_DID_HARDRESET,
 	ATA_EHI_RESET_MODIFIER_MASK = ATA_EHI_RESUME_LINK,
 
-	/* max repeat if error condition is still set after ->error_handler */
-	ATA_EH_MAX_REPEAT	= 5,
+	/* max tries if error condition is still set after ->error_handler */
+	ATA_EH_MAX_TRIES	= 5,
 
 	/* how hard are we gonna try to probe/recover devices */
 	ATA_PROBE_MAX_TRIES	= 3,
@@ -537,6 +537,7 @@ struct ata_port {
 	struct ata_eh_info	eh_info;
 	/* EH context owned by EH */
 	struct ata_eh_context	eh_context;
+	int			eh_tries;
 
 	struct ata_device	device[ATA_MAX_DEVICES];
 

Re: [PATCH libata-dev#upstream 2/2] libata: move EH repeat reporting into ata_eh_report()

[Mikael Pettersson]

On Tue, 31 Jul 2007 16:51:00 +0900, Tejun Heo wrote:
> EH is sometimes repeated without any error or action.  For example,
> this happens when probing IDENTIFY fails because of a phantom device.
> In these cases, all the repeated EH does is making sure there is no
> unhandled error or pending action and return.  This repeation is
> necessary to avoid losing any event which occurred while EH was in
> progress.
> 
> Unfortunately, this dry run causes annonying "EH pending after
> completion" message.  This patch moves the repeat reporting into
> ata_eh_report() such that it's more compact and skipped on dry runs.
> 
> Signed-off-by: Tejun Heo <htejun@gmail.com>
> Cc: Mikael Pettersson <mikep@it.uu.se>
> ---
> Mikael, please verify this removes the annonying message you're
> seeing.

Yes, this patch eliminates the "EH pending after completion" message
I've been getting.

However, patch 1/2 in this set, "don't skip EH report if action is 
pending", causes a bunch of new "exception ... frozen" messages:

--- dmesg-2.6.23-rc1	2007-07-23 12:30:12.000000000 +0200
+++ -	2007-07-31 23:19:21.162137100 +0200
@@ -1,44 +1,44 @@
...
-pata_pdc2027x 0000:04:02.0: PLL input clock 16660 kHz
+pata_pdc2027x 0000:04:02.0: PLL input clock 16651 kHz
 scsi0 : pata_pdc2027x
 scsi1 : pata_pdc2027x
 ata1: PATA max UDMA/133 cmd 0xf88297c0 ctl 0xf8829fda bmdma 0xf8829000 irq 18
 ata2: PATA max UDMA/133 cmd 0xf88295c0 ctl 0xf8829dda bmdma 0xf8829008 irq 18
+ata1: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
 ata1.00: ATA-7: ST3320620A, 3.AAD, max UDMA/100
 ata1.00: 625142448 sectors, multi 16: LBA48 
 ata1.00: configured for UDMA/100
+ata2: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
 scsi 0:0:0:0: Direct-Access     ATA      ST3320620A       3.AA PQ: 0 ANSI: 5
 sd 0:0:0:0: [sda] 625142448 512-byte hardware sectors (320073 MB)
 sd 0:0:0:0: [sda] Write Protect is off
@@ -255,10 +256,11 @@
 scsi3 : ata_piix
 ata3: SATA max UDMA/133 cmd 0x0001ec00 ctl 0x0001e882 bmdma 0x0001e400 irq 19
 ata4: SATA max UDMA/133 cmd 0x0001e800 ctl 0x0001e482 bmdma 0x0001e408 irq 19
+ata3: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
+ata4: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
 ata4.00: ATAPI: TSSTcorpCD/DVDW SH-S183A, SB00, max UDMA/33
 ata4.00: applying bridge limits
 ata4.00: configured for UDMA/33
-ata4: EH pending after completion, repeating EH (cnt=4)
 scsi 3:0:0:0: CD-ROM            TSSTcorp CD/DVDW SH-S183A SB00 PQ: 0 ANSI: 5
 ata_piix 0000:00:1f.5: MAP [ P0 P2 P1 P3 ]
 ACPI: PCI Interrupt 0000:00:1f.5[B] -> GSI 19 (level, low) -> IRQ 19
@@ -267,6 +269,8 @@
 scsi5 : ata_piix
 ata5: SATA max UDMA/133 cmd 0x0001d400 ctl 0x0001d082 bmdma 0x0001c880 irq 19
 ata6: SATA max UDMA/133 cmd 0x0001d000 ctl 0x0001cc02 bmdma 0x0001c888 irq 19
+ata5: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
+ata6: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen
 kjournald starting.  Commit interval 5 seconds
 EXT3-fs: mounted filesystem with ordered data mode.
 usbcore: registered new interface driver usbfs

This is with both 1/2 and 2/2 applied, with only 2/2 applied the
"EH pending ..." is gone and the new "exception ... frozen" don't appear.

/Mikael

Re: [PATCH libata-dev#upstream 2/2] libata: move EH repeat reporting into ata_eh_report()

[Tejun Heo]

Mikael Pettersson wrote:
> This is with both 1/2 and 2/2 applied, with only 2/2 applied the
> "EH pending ..." is gone and the new "exception ... frozen" don't appear.

Thanks.  Right, I'll drop the first patch.

-- 
tejun

Re: [PATCH libata-dev#upstream 2/2] libata: move EH repeat reporting into ata_eh_report()

[Jeff Garzik]

Tejun Heo wrote:
> EH is sometimes repeated without any error or action.  For example,
> this happens when probing IDENTIFY fails because of a phantom device.
> In these cases, all the repeated EH does is making sure there is no
> unhandled error or pending action and return.  This repeation is
> necessary to avoid losing any event which occurred while EH was in
> progress.
> 
> Unfortunately, this dry run causes annonying "EH pending after
> completion" message.  This patch moves the repeat reporting into
> ata_eh_report() such that it's more compact and skipped on dry runs.
> 
> Signed-off-by: Tejun Heo <htejun@gmail.com>
> Cc: Mikael Pettersson <mikep@it.uu.se>
> ---
> Mikael, please verify this removes the annonying message you're
> seeing.
> 
> Thanks.
> 
>  drivers/ata/libata-eh.c |   26 ++++++++++++++++----------
>  include/linux/libata.h  |    5 +++--
>  2 files changed, 19 insertions(+), 12 deletions(-)

this will want a rediff too, but looks OK to me