current #upstream bug?
I see this in current #upstream, on an x86-64 SMP box with sata_nv and sata_mv:
Quoted 38 lines
libata version 1.20 loaded.
sata_nv0000:00:07.0: version 0.8
ACPI: PCI Interrupt Link [LSA0] enabled at IRQ 23
GSI 18 sharing vector0xC1and IRQ 18
ACPI: PCI Interrupt 0000:00:07.0[A] -> Link [LSA0] -> GSI 23 (level, high) -> IRQ 193
PCI: Setting latency timer of device 0000:00:07.0 to 64
ata1: SATA max UDMA/133 cmd0x28D0ctl0x28FAbmdma0x28B0irq 193
ata2: SATA max UDMA/133 cmd0x28D8ctl0x28FEbmdma0x28B8irq 193
ata1: SATA link up 1.5 Gbps (SStatus 113)
ata1: dev 0 cfg 49:2f00 82:3469 83:7f61 84:4003 85:3469 86:3e41 87:4003 88:407f
ata1: dev 0 ATA-6, max UDMA/133, 488281250 sectors: LBA48nv_sata: Primary device addednv_sata: Primary device removednv_sata: Secondary device addednv_sata: Secondary device removed
ata1: dev 0 cfg 49:2f00 82:3469 83:7f61 84:4003 85:3469 86:3e41 87:4003 88:407f
ata1: dev 0 configured for UDMA/133
scsi2 :sata_nv
ata2: SATA link down (SStatus 0)
ata2: PIO error
ata2: dev 0 failed to IDENTIFY (I/O error)
scsi3 :sata_nv
Vendor: ATA Model: WDC WD2500JD-75H Rev: 08.0
Type: Direct-Access ANSI SCSI revision: 05
SCSI device sda: 488281250 512-byte hdwr sectors (250000 MB)
sda: Write Protect is off
sda: Mode Sense: 00 3a 00 00
SCSI device sda: drive cache: write back
SCSI device sda: 488281250 512-byte hdwr sectors (250000 MB)
sda: Write Protect is off
sda: Mode Sense: 00 3a 00 00
SCSI device sda: drive cache: write back
sda:<4>nv_sata: Primary device addednv_sata: Primary device removednv_sata: Secondary device addednv_sata: Secondary device removed
sda1 sda2 sda3 sda4 <<4>nv_sata: Primary device addednv_sata: Primary device removed
Quoted 8 lines
nv_sata: Secondary device addednv_sata: Secondary device removed
sda5<4>nv_sata: Primary device addednv_sata: Primary device removednv_sata: Secondary device addednv_sata: Secondary device removed
sda6 >
sd 2:0:0:0: Attached scsi disk sda
The problem is that it complains about a PIO error and that a device failed IDENTIFY, when clearly (SStatus==0) there is no device present.
Full dmesg attached. sata_mv stopped finding its ATA device, but I haven't even begun to look into that yet.
Jeff
PATCH 1/1 libata: fix class handling in ata_bus_probe()
ata_bus_probe() didn't set classes[] properly for port disabled case of ->phy_reset() compatibility path. This patch moves classes[] initialization and normalization out of ->probe_reset block such that it applies to both ->probe_reset and ->phy_reset paths.
---
Jeff, the sata_nv case is similar bug as what Jiri reported, except that this one is affecting ->phy_reset path.
This patch should fix sata_nv. For sata_mv, I have no idea at all.
libata-core.c | 24 +++++++++++------------- 1 file changed, 11 insertions(+), 13 deletions(-)
drivers/scsi/libata-core.c +11 -13
@@ -1344,32 +1344,30 @@ static int ata_bus_probe(struct ata_portata_port_probe (ap); -/* reset */ -if (ap->ops->probe_reset) { -for (i =0 ; i <ATA_MAX_DEVICES ; i++) - classes[i] =ATA_DEV_UNKNOWN ; +/* reset and determine device classes */ +for (i =0 ; i <ATA_MAX_DEVICES ; i++) + classes[i] =ATA_DEV_UNKNOWN ; +if (ap->ops->probe_reset) { rc = ap->ops->probe_reset (ap, classes);if (rc) {printk ("ata%u: reset failed (errno=%d)\n" , ap->id, rc);return rc; } - -for (i =0 ; i <ATA_MAX_DEVICES ; i++) -if (classes[i] ==ATA_DEV_UNKNOWN ) - classes[i] =ATA_DEV_NONE ; }else { ap->ops->phy_reset (ap); -for (i =0 ; i <ATA_MAX_DEVICES ; i++) { -if (!(ap->flags &ATA_FLAG_PORT_DISABLED )) +if (!(ap->flags &ATA_FLAG_PORT_DISABLED )) +for (i =0 ; i <ATA_MAX_DEVICES ; i++) classes[i] = ap->device[i].class; -else - ap->device[i].class =ATA_DEV_UNKNOWN ; - } +ata_port_probe (ap); } +for (i =0 ; i <ATA_MAX_DEVICES ; i++) +if (classes[i] ==ATA_DEV_UNKNOWN ) + classes[i] =ATA_DEV_NONE ; +/* read IDENTIFY page and configure devices */ for (i =0 ; i <ATA_MAX_DEVICES ; i++) {struct ata_device *dev = &ap->device[i];
Jeff Garzik
AppliedRe: [PATCH] libata: fix class handling in ata_bus_probe()
Quoted 6 lines · Tejun Heo
ata_bus_probe()didn't set classes[] properly for port disabled case of ->phy_reset() compatibility path. This patch moves classes[] initialization and normalization out of ->probe_reset block such that it applies to both ->probe_reset and ->phy_reset paths.Signed-off-by Tejun Heo <[email protected]>
applied
Re: [PATCH] libata: fix class handling in ata_bus_probe()
In reply to Tejun HeoQuoted 5 lines · Tejun Heo
ata_bus_probe()didn't set classes[] properly for port disabled case of ->phy_reset() compatibility path. This patch moves classes[] initialization and normalization out of ->probe_reset block such that it applies to both ->probe_reset and ->phy_reset paths.
Quoted 8 lines
Signed-off-by Tejun Heo <[email protected]>---
Jeff, the
sata_nvcase is similar bug as what Jiri reported, except that this one is affecting ->phy_reset path.This patch should fix
sata_nv. Forsata_mv, I have no idea at all.
Yep, that solves that bug. I spotted another minor one:
Quoted 9 lines
libata version 1.20 loaded.
sata_nv0000:00:07.0: version 0.8
ACPI: PCI Interrupt Link [LSA0] enabled at IRQ 23
GSI 18 sharing vector0xC1and IRQ 18
ACPI: PCI Interrupt 0000:00:07.0[A] -> Link [LSA0] -> GSI 23 (level, high) -> IRQ 193
PCI: Setting latency timer of device 0000:00:07.0 to 64
ata1: SATA max UDMA/133 cmd0x28D0ctl0x28FAbmdma0x28B0irq 193
ata2: SATA max UDMA/133 cmd0x28D8ctl0x28FEbmdma0x28B8irq 193
ata1: SATA link up 1.5 Gbps (SStatus 113)
Quoted 8 lines
ata1: dev 0 cfg 49:2f00 82:3469 83:7f61 84:4003 85:3469 86:3e41 87:4003 88:407f
ata1: dev 0 ATA-6, max UDMA/133, 488281250 sectors: LBA48nv_sata: Primary device addednv_sata: Primary device removednv_sata: Secondary device addednv_sata: Secondary device removed
ata1: dev 0 cfg 49:2f00 82:3469 83:7f61 84:4003 85:3469 86:3e41 87:4003 88:407f
ata1: dev 0 configured for UDMA/133
The dev 0 id words are printed twice, but should not be. Or, the second one should only be printed if something relevant changed.
Jeff
Re: [PATCH] libata: fix class handling in ata_bus_probe()
Quoted 39 lines · Jeff Garzik
Quoted 5 lines · Tejun Heo
ata_bus_probe()didn't set classes[] properly for port disabled case of ->phy_reset() compatibility path. This patch moves classes[] initialization and normalization out of ->probe_reset block such that it applies to both ->probe_reset and ->phy_reset paths.Quoted 8 lines
Signed-off-by Tejun Heo <[email protected]>---
Jeff, the
sata_nvcase is similar bug as what Jiri reported, except that this one is affecting ->phy_reset path.This patch should fix
sata_nv. Forsata_mv, I have no idea at all.Yep, that solves that bug. I spotted another minor one:
Quoted 9 lines
libata version 1.20 loaded.
sata_nv0000:00:07.0: version 0.8
ACPI: PCI Interrupt Link [LSA0] enabled at IRQ 23
GSI 18 sharing vector0xC1and IRQ 18
ACPI: PCI Interrupt 0000:00:07.0[A] -> Link [LSA0] -> GSI 23 (level, high) -> IRQ 193
PCI: Setting latency timer of device 0000:00:07.0 to 64
ata1: SATA max UDMA/133 cmd0x28D0ctl0x28FAbmdma0x28B0irq 193
ata2: SATA max UDMA/133 cmd0x28D8ctl0x28FEbmdma0x28B8irq 193
ata1: SATA link up 1.5 Gbps (SStatus 113)Quoted 8 lines
ata1: dev 0 cfg 49:2f00 82:3469 83:7f61 84:4003 85:3469 86:3e41 87:4003 88:407f
ata1: dev 0 ATA-6, max UDMA/133, 488281250 sectors: LBA48nv_sata: Primary device addednv_sata: Primary device removednv_sata: Secondary device addednv_sata: Secondary device removed
ata1: dev 0 cfg 49:2f00 82:3469 83:7f61 84:4003 85:3469 86:3e41 87:4003 88:407f
ata1: dev 0 configured for UDMA/133
Quoted 2 lines
The dev 0 id words are printed twice, but should not be. Or, the second one should only be printed if something relevant changed.
The duplicated messages are KERN_DEBUG messages which usually won't show up on the console. Still, yeah, annonying. I'll send a patch which changes the code such that the message isn't printed the second time (during revalidation) tomorrow. I gotta sleep now.
Good night.
Signature · 1 line
tejun
PATCH 1/1 libata: clean up IDENTIFY printing
In reply to Jeff GarzikPrinting info about IDENTIFY page used to be the responsibility of ata_dev_read_id(). As all devices are revalidated after xfer mode configuration, this resulted in two info messages about one device. This patch improves ata_dump_id() such that it can be generally useable and makes printing the responsibility of ata_dev_configure() which has better understanding of what's going on.
The IDENTIFY info printing now looks like the following.
ata2: dev 1 cfg 49:2f00 53:0007 63:0007 64:0003 75:001f 80:00fe 81:0000 82:346b
83:7d01 84:4023 85:3469 86:3c01 87:4023 88:207f 93:0000
---
libata-core.c | 61 +++++++++++++++++++++++----------------------------------- 1 file changed, 25 insertions(+), 36 deletions(-)
drivers/scsi/libata-core.c +25 -36
@@ -743,40 +743,33 @@ void ata_dev_select(struct ata_port *ap,/** * ata_dump_id - IDENTIFY DEVICE info debugging output * @id: IDENTIFY DEVICE page to dump +* @level: KERN_* message level +* @fmt: header format string +* @...: header string arguments * -* Dump selected 16-bit words from the given IDENTIFY DEVICE -* page. +* Dump selected 16-bit words from the given IDENTIFY DEVICE page +* with the specified header. * * LOCKING: * caller. */ - -static inline void ata_dump_id (const u16 *id) +static void ata_dump_id (const u16 *id,const char *level,const char *fmt, ...) { -DPRINTK ("49==0x%04x " -"53==0x%04x " -"63==0x%04x " -"64==0x%04x " -"75==0x%04x \n" , - id[49 ], - id[53 ], - id[63 ], - id[64 ], - id[75 ]); -DPRINTK ("80==0x%04x " -"81==0x%04x " -"82==0x%04x " -"83==0x%04x " -"84==0x%04x \n" , - id[80 ], - id[81 ], - id[82 ], - id[83 ], - id[84 ]); -DPRINTK ("88==0x%04x " -"93==0x%04x\n" , - id[88 ], - id[93 ]); +va_list ap; +char buf[24 ]; + +va_start (ap, fmt); +vscnprintf (buf,sizeof (buf), fmt, ap); +va_end (ap); + +printk ("%s%s49:%04x 53:%04x 63:%04x 64:%04x 75:%04x 80:%04x 81:%04x 82:%04x\n" , + level, buf, + id[49 ], id[53 ], id[63 ], id[64 ], id[75 ], id[80 ], id[81 ], id[82 ]); + +memset (buf,' ' ,strlen (buf)); +printk ("%s%s83:%04x 84:%04x 85:%04x 86:%04x 87:%04x 88:%04x 93:%04x\n" , + level, buf, + id[83 ], id[84 ], id[85 ], id[86 ], id[87 ], id[88 ], id[93 ]); }/**
@@ -1120,12 +1113,6 @@ static int ata_dev_read_id(struct ata_poswap_buf_le16 (id,ATA_ID_WORDS ); -/* print device capabilities */ -printk (KERN_DEBUG "ata%u: dev %u cfg " -"49:%04x 82:%04x 83:%04x 84:%04x 85:%04x 86:%04x 87:%04x 88:%04x\n" , - ap->id, dev->devno, - id[49 ], id[82 ], id[83 ], id[84 ], id[85 ], id[86 ], id[87 ], id[88 ]); -/* sanity check */ if ((class ==ATA_DEV_ATA ) !=ata_id_is_ata (id)) { rc = -EINVAL ;
@@ -1204,6 +1191,10 @@ static int ata_dev_configure(struct ata_DPRINTK ("ENTER, host %u, dev %u\n" , ap->id, dev->devno); +if (print_info) +ata_dump_id (dev->id,KERN_DEBUG ,"ata%u: dev %u cfg " , + ap->id, dev->devno); +/* initialize to-be-configured parameters */ dev->flags =0 ; dev->max_sectors =0 ;
@@ -1227,8 +1218,6 @@ static int ata_dev_configure(struct ata_/* find max transfer mode; for printk only */ xfer_mask =ata_id_xfermask (dev->id); -ata_dump_id (dev->id); -/* ATA-specific feature tests */ if (dev->class ==ATA_DEV_ATA ) { dev->n_sectors =ata_id_n_sectors (dev->id);
PATCH 1/1 libata: clean up IDENTIFY printing
Printing info about IDENTIFY page used to be the responsibility of ata_dev_read_id(). As all devices are revalidated after xfer mode configuration, this resulted in two info messages about one device. This patch improves ata_dump_id() such that it can be generally useable and makes printing the responsibility of ata_dev_configure() which has better understanding of what's going on.
The IDENTIFY info printing now looks like the following.
ata2: dev 1 cfg 49:2f00 53:0007 63:0007 64:0003 75:001f 80:00fe 81:0000 82:346b
83:7d01 84:4023 85:3469 86:3c01 87:4023 88:207f 93:0000
---
Jeff, this is slightly improved version which removes unnecessary strlen() in ata_dump_id() as vscnprintf() returns the same value.
libata-core.c | 62 ++++++++++++++++++++++++---------------------------------- 1 file changed, 26 insertions(+), 36 deletions(-)
drivers/scsi/libata-core.c +26 -36
@@ -743,40 +743,34 @@ void ata_dev_select(struct ata_port *ap,/** * ata_dump_id - IDENTIFY DEVICE info debugging output * @id: IDENTIFY DEVICE page to dump +* @level: KERN_* message level +* @fmt: header format string +* @...: header string arguments * -* Dump selected 16-bit words from the given IDENTIFY DEVICE -* page. +* Dump selected 16-bit words from the given IDENTIFY DEVICE page +* with the specified header. * * LOCKING: * caller. */ - -static inline void ata_dump_id (const u16 *id) +static void ata_dump_id (const u16 *id,const char *level,const char *fmt, ...) { -DPRINTK ("49==0x%04x " -"53==0x%04x " -"63==0x%04x " -"64==0x%04x " -"75==0x%04x \n" , - id[49 ], - id[53 ], - id[63 ], - id[64 ], - id[75 ]); -DPRINTK ("80==0x%04x " -"81==0x%04x " -"82==0x%04x " -"83==0x%04x " -"84==0x%04x \n" , - id[80 ], - id[81 ], - id[82 ], - id[83 ], - id[84 ]); -DPRINTK ("88==0x%04x " -"93==0x%04x\n" , - id[88 ], - id[93 ]); +va_list ap; +char buf[24 ]; +int len; + +va_start (ap, fmt); + len =vscnprintf (buf,sizeof (buf), fmt, ap); +va_end (ap); + +printk ("%s%s49:%04x 53:%04x 63:%04x 64:%04x 75:%04x 80:%04x 81:%04x 82:%04x\n" , + level, buf, + id[49 ], id[53 ], id[63 ], id[64 ], id[75 ], id[80 ], id[81 ], id[82 ]); + +memset (buf,' ' , len); +printk ("%s%s83:%04x 84:%04x 85:%04x 86:%04x 87:%04x 88:%04x 93:%04x\n" , + level, buf, + id[83 ], id[84 ], id[85 ], id[86 ], id[87 ], id[88 ], id[93 ]); }/**
@@ -1120,12 +1114,6 @@ static int ata_dev_read_id(struct ata_poswap_buf_le16 (id,ATA_ID_WORDS ); -/* print device capabilities */ -printk (KERN_DEBUG "ata%u: dev %u cfg " -"49:%04x 82:%04x 83:%04x 84:%04x 85:%04x 86:%04x 87:%04x 88:%04x\n" , - ap->id, dev->devno, - id[49 ], id[82 ], id[83 ], id[84 ], id[85 ], id[86 ], id[87 ], id[88 ]); -/* sanity check */ if ((class ==ATA_DEV_ATA ) !=ata_id_is_ata (id)) { rc = -EINVAL ;
@@ -1204,6 +1192,10 @@ static int ata_dev_configure(struct ata_DPRINTK ("ENTER, host %u, dev %u\n" , ap->id, dev->devno); +if (print_info) +ata_dump_id (dev->id,KERN_DEBUG ,"ata%u: dev %u cfg " , + ap->id, dev->devno); +/* initialize to-be-configured parameters */ dev->flags =0 ; dev->max_sectors =0 ;
@@ -1227,8 +1219,6 @@ static int ata_dev_configure(struct ata_/* find max transfer mode; for printk only */ xfer_mask =ata_id_xfermask (dev->id); -ata_dump_id (dev->id); -/* ATA-specific feature tests */ if (dev->class ==ATA_DEV_ATA ) { dev->n_sectors =ata_id_n_sectors (dev->id);
Re: [PATCH] libata: clean up IDENTIFY printing
Quoted 14 lines · Tejun Heo
drivers/scsi/libata-core.c +0
-6@@ -1120,12 +1114,6 @@ static int ata_dev_read_id(struct ata_poswap_buf_le16 (id,ATA_ID_WORDS ); -/* print device capabilities */ -printk (KERN_DEBUG "ata%u: dev %u cfg " -"49:%04x 82:%04x 83:%04x 84:%04x 85:%04x 86:%04x 87:%04x 88:%04x\n" , - ap->id, dev->devno, - id[49 ], id[82 ], id[83 ], id[84 ], id[85 ], id[86 ], id[87 ], id[88 ]); -/* sanity check */ if ((class ==ATA_DEV_ATA ) !=ata_id_is_ata (id)) { rc = -EINVAL ;
drivers/scsi/libata-core.c static int ata_dev_configure(struct ata_ · line 1198
Quoted 7 lines
drivers/scsi/libata-core.c +4
-0@@ -1204,6 +1192,10 @@ static int ata_dev_configure(struct ata_DPRINTK ("ENTER, host %u, dev %u\n" , ap->id, dev->devno); +if (print_info) +ata_dump_id (dev->id,KERN_DEBUG ,"ata%u: dev %u cfg " , + ap->id, dev->devno); +
Also, the use of vscnprintf() feels like overengineering. How many places really need to print out this stuff? Just one?
Jeff
A message that is not in the archive (sent off-list or not yet received): [email protected]
Re: [PATCH] libata: clean up IDENTIFY printing
Quoted 12 lines · Tejun Heo
Printing info about IDENTIFY page used to be the responsibility of
ata_dev_read_id(). As all devices are revalidated after xfer mode configuration, this resulted in two info messages about one device. Also,ata_dump_id()was called fromata_dev_configure()which prints some intersecting and some new information IDENTIFY page ifATA_DEBUGis enabled.This patch makes
ata_dev_configure()soley responsible for printing IDENTIFY info and kill all others.The IDENTIFY info printing now looks like the following.
Quoted 8 lines
ata2: dev 1 cfg 49:2f00 53:0007 63:0007 64:0003 75:001f 80:00fe 81:0000 82:346b
83:7d01 84:4023 85:3469 86:3c01 87:4023 88:207f 93:0000Signed-off-by Tejun Heo <[email protected]>---
How about this one? ata10's second line will be misaligned though. :-p
better, but
* I only want one line of dev->id printed, just like 2.6.15 etc. does now. If you want more verbose dump of additional registers, that's a job for ap->msg_enable.
* [you know this was coming :)] The use of new local 'id' should be split into a separate patch.
PATCH 2/2 libata: move IDENTIFY info printing from ata_dev_read_id() to ata_dev_configure()
Move IDENTIFY info printing from ata_dev_read_id() to ata_dev_configure() and print only if @print_info is non-zero. This kills duplicate IDENTIFY info printing during probing.
---
Jeff, I think ap->msg_enable conversion should happen as bombing raids. Such that we have either ATA_DEBUG or msg_enable. I'll leave ata_dump_id() alone for the time being.
libata-core.c | 13 +++++++------ 1 file changed, 7 insertions(+), 6 deletions(-)
drivers/scsi/libata-core.c +7 -6
@@ -1120,12 +1120,6 @@ static int ata_dev_read_id(struct ata_poswap_buf_le16 (id,ATA_ID_WORDS ); -/* print device capabilities */ -printk (KERN_DEBUG "ata%u: dev %u cfg " -"49:%04x 82:%04x 83:%04x 84:%04x 85:%04x 86:%04x 87:%04x 88:%04x\n" , - ap->id, dev->devno, - id[49 ], id[82 ], id[83 ], id[84 ], id[85 ], id[86 ], id[87 ], id[88 ]); -/* sanity check */ if ((class ==ATA_DEV_ATA ) !=ata_id_is_ata (id)) { rc = -EINVAL ;
@@ -1205,6 +1199,13 @@ static int ata_dev_configure(struct ata_DPRINTK ("ENTER, host %u, dev %u\n" , ap->id, dev->devno); +/* print device capabilities */ +if (print_info) +printk (KERN_DEBUG "ata%u: dev %u cfg 49:%04x 82:%04x 83:%04x " +"84:%04x 85:%04x 86:%04x 87:%04x 88:%04x\n" , + ap->id, dev->devno, id[49 ], id[82 ], id[83 ], + id[84 ], id[85 ], id[86 ], id[87 ], id[88 ]); +/* initialize to-be-configured parameters */ dev->flags =0 ; dev->max_sectors =0 ;
A message that is not in the archive (sent off-list or not yet received): [email protected]
Re: [PATCH 1/2] libata: use local *id instead of dev->id in ata_dev_configure()
Quoted 4 lines · Tejun Heo
dev->idis used many times inata_dev_configure(). Use local variable id instead for shorter notation.Signed-off-by Tejun Heo <[email protected]>
applied 1-2
Re: [PATCH] libata: clean up IDENTIFY printing
In reply to Tejun HeoQuoted 7 lines · Tejun Heo
Printing info about IDENTIFY page used to be the responsibility of
ata_dev_read_id(). As all devices are revalidated after xfer mode configuration, this resulted in two info messages about one device. This patch improvesata_dump_id()such that it can be generally useable and makes printing the responsibility ofata_dev_configure()which has better understanding of what's going on.
Quoted 6 lines
The IDENTIFY info printing now looks like the following.
ata2: dev 1 cfg 49:2f00 53:0007 63:0007 64:0003 75:001f 80:00fe 81:0000 82:346b
83:7d01 84:4023 85:3469 86:3c01 87:4023 88:207f 93:0000Signed-off-by Tejun Heo <[email protected]>
That doesn't address the issue of an increase in log spam :) When you read kernel messages with dmesg(8), KERN_DEBUG does nothing to decrease the visibility of any set of messages.
So, please just decrease the current output from a doubled line to a single line of data.
Anything more falls under the category of 'implement ap->msg_enable, and then use ata_msg_xxx()'.
Jeff