Zoltan Boszormenyi írta: > Hi, > > Peer Chen írta: >> Zoltan, >> What's your board's model number? Could you post the pci dump using >> 'lspci -xxx'? Thanks. >> >> >> BRs >> Peer Chen >> >> -----Original Message----- >> From: Robert Hancock [mailto:hancockr@shaw.ca] Sent: Thursday, May >> 31, 2007 10:31 PM >> To: Zoltan Boszormenyi >> Cc: linux-kernel; Peer Chen; Kuan Luo >> Subject: Re: MCP55 NCQ problem? >> >> CCing Peer Chen and Kuan Luo from NVIDIA.. >> >> Looks like there were some unrecognized FIS errors from the >> controller in there? >> >> Zoltan Boszormenyi wrote: >> >>> Hi, >>> >>> I just got this with 2.6.22-rc2 + cfs-v13 + swncq patch: >>> >>> ata2.00: exception Emask 0x0 SAct 0x6 SErr 0x0 action 0x2 frozen >>> ata2.00: cmd 61/18:08:0f:b7:68/00:00:16:00:00/40 tag 1 cdb 0x0 data >>> 12288 out >>> res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout) >>> ata2.00: cmd 61/18:10:7f:b7:68/00:00:16:00:00/40 tag 2 cdb 0x0 data >>> 12288 out >>> res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout) >>> ata2: hard resetting port >>> ata2: SATA link up 1.5 Gbps (SStatus 113 SControl 300) >>> ata2.00: ata_hpa_resize 1: sectors = 625142448, hpa_sectors = 625142448 >>> ata2.00: ata_hpa_resize 1: sectors = 625142448, hpa_sectors = 625142448 >>> ata2.00: configured for UDMA/133 >>> ata2: EH pending after completion, repeating EH (cnt=4) >>> ata2: EH complete >>> sd 1:0:0:0: [sdb] 625142448 512-byte hardware sectors (320073 MB) >>> sd 1:0:0:0: [sdb] Write Protect is off >>> sd 1:0:0:0: [sdb] Mode Sense: 00 3a 00 00 >>> sd 1:0:0:0: [sdb] Write cache: enabled, read cache: enabled, doesn't >>> support DPO or FUA >>> >>> At the time I was creating a DVD ISO image (reads and writes went to >>> the disk >>> that was resetted), browsing mail in thunderbird which also >>> exercised the same >>> disk and I was downloading another ISO with about 400-450 kB/sec to >>> another disk. Here are the disks in question: >>> >>> scsi 0:0:0:0: Direct-Access ATA SAMSUNG HD160JJ WU10 PQ: 0 >>> ANSI: 5 >>> scsi 1:0:0:0: Direct-Access ATA ST3320620AS 3.AA PQ: 0 >>> ANSI: 5 >>> >>> I got almost the same yesterday with 2.6.22-rc2-mm1: >>> >>> May 29 12:44:20 localhost kernel: ata2.00: exception Emask 0x0 SAct >>> 0x6 SErr 0x0 action 0x2 frozen >>> May 29 12:44:20 localhost kernel: ata2.00: cmd >>> 61/10:08:2f:41:e9/00:00:07:00:00/40 tag 1 cdb 0x0 data 8192 out >>> May 29 12:44:20 localhost kernel: res >>> 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout) >>> May 29 12:44:20 localhost kernel: ata2.00: status: {DRDY } >>> May 29 12:44:20 localhost kernel: ata2.00: cmd >>> 61/30:10:8f:42:e9/00:00:07:00:00/40 tag 2 cdb 0x0 data 24576 out >>> May 29 12:44:20 localhost kernel: res >>> 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout) >>> May 29 12:44:20 localhost kernel: ata2.00: status: {DRDY } >>> May 29 12:44:20 localhost kernel: ata2: hard resetting port >>> May 29 12:44:21 localhost kernel: ata2: SATA link up 1.5 Gbps >>> (SStatus 113 SControl 300) >>> May 29 12:44:21 localhost kernel: ata2.00: ata_hpa_resize: sectors = >>> 625142448, hpa_sectors = 625142448 >>> May 29 12:44:21 localhost kernel: ata2.00: ata_hpa_resize: sectors = >>> 625142448, hpa_sectors = 625142448 >>> May 29 12:44:21 localhost kernel: ata2.00: configured for UDMA/133 >>> May 29 12:44:21 localhost kernel: ata2: EH pending after completion, >>> repeating EH (cnt=4) >>> May 29 12:44:21 localhost kernel: ata2: EH complete >>> May 29 12:44:21 localhost kernel: sd 1:0:0:0: [sdb] 625142448 >>> 512-byte hardware sectors (320073 MB) >>> May 29 12:44:21 localhost kernel: sd 1:0:0:0: [sdb] Write Protect is >>> off >>> May 29 12:44:21 localhost kernel: sd 1:0:0:0: [sdb] Write cache: >>> enabled, read cache: enabled, doesn't support DPO or FUA >>> .. >>> May 29 12:47:46 localhost kernel: ata2.00: exception Emask 0x0 SAct >>> 0x7 SErr 0x0 action 0x2 frozen >>> May 29 12:47:46 localhost kernel: ata2.00: cmd >>> 61/08:00:27:5a:eb/00:00:07:00:00/40 tag 0 cdb 0x0 data 4096 out >>> May 29 12:47:46 localhost kernel: res >>> 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout) >>> May 29 12:47:46 localhost kernel: ata2.00: status: {DRDY } >>> May 29 12:47:46 localhost kernel: ata2.00: cmd >>> 61/08:08:bf:61:9e/00:00:0f:00:00/40 tag 1 cdb 0x0 data 4096 out >>> May 29 12:47:46 localhost kernel: res >>> 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout) >>> May 29 12:47:46 localhost kernel: ata2.00: status: {DRDY } >>> May 29 12:47:46 localhost kernel: ata2.00: cmd >>> 61/20:10:97:5a:eb/00:00:07:00:00/40 tag 2 cdb 0x0 data 16384 out >>> May 29 12:47:46 localhost kernel: res >>> 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout) >>> May 29 12:47:46 localhost kernel: ata2.00: status: {DRDY } >>> May 29 12:47:46 localhost kernel: ata2: hard resetting port >>> May 29 12:47:46 localhost kernel: ata2: SATA link up 1.5 Gbps >>> (SStatus 113 SControl 300) >>> May 29 12:47:46 localhost kernel: ata2.00: ata_hpa_resize: sectors = >>> 625142448, hpa_sectors = 625142448 >>> May 29 12:47:46 localhost kernel: ata2.00: ata_hpa_resize: sectors = >>> 625142448, hpa_sectors = 625142448 >>> May 29 12:47:47 localhost kernel: ata2.00: configured for UDMA/133 >>> May 29 12:47:47 localhost kernel: ata2: EH pending after completion, >>> repeating EH (cnt=4) >>> May 29 12:47:47 localhost kernel: ata2: EH complete >>> May 29 12:47:47 localhost kernel: sd 1:0:0:0: [sdb] 625142448 >>> 512-byte hardware sectors (320073 MB) >>> May 29 12:47:47 localhost kernel: sd 1:0:0:0: [sdb] Write Protect is >>> off >>> May 29 12:47:47 localhost kernel: sd 1:0:0:0: [sdb] Write cache: >>> enabled, read cache: enabled, doesn't support DPO or FUA >>> May 29 12:49:23 localhost kernel: ata2.00: exception Emask 0x0 SAct >>> 0x6 SErr 0x2000000 action 0x2 frozen >>> May 29 12:49:23 localhost kernel: ata2: SError: {UnrecFIS } >>> May 29 12:49:23 localhost kernel: ata2.00: cmd >>> 61/40:08:3f:71:fa/00:00:07:00:00/40 tag 1 cdb 0x0 data 32768 out >>> May 29 12:49:23 localhost kernel: res >>> 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout) >>> May 29 12:49:23 localhost kernel: ata2.00: status: {DRDY } >>> May 29 12:49:23 localhost kernel: ata2.00: cmd >>> 61/10:10:7f:e7:fa/00:00:07:00:00/40 tag 2 cdb 0x0 data 8192 out >>> May 29 12:49:23 localhost kernel: res >>> 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout) >>> May 29 12:49:23 localhost kernel: ata2.00: status: {DRDY } >>> May 29 12:49:23 localhost kernel: ata2: hard resetting port >>> May 29 12:49:24 localhost kernel: ata2: SATA link up 1.5 Gbps >>> (SStatus 113 SControl 300) >>> May 29 12:49:24 localhost kernel: ata2.00: ata_hpa_resize: sectors = >>> 625142448, hpa_sectors = 625142448 >>> May 29 12:49:24 localhost kernel: ata2.00: ata_hpa_resize: sectors = >>> 625142448, hpa_sectors = 625142448 >>> May 29 12:49:24 localhost kernel: ata2.00: configured for UDMA/133 >>> May 29 12:49:24 localhost kernel: ata2: EH pending after completion, >>> repeating EH (cnt=4) >>> May 29 12:49:24 localhost kernel: ata2: EH complete >>> May 29 12:49:24 localhost kernel: sd 1:0:0:0: [sdb] 625142448 >>> 512-byte hardware sectors (320073 MB) >>> May 29 12:49:24 localhost kernel: sd 1:0:0:0: [sdb] Write Protect is >>> off >>> May 29 12:49:24 localhost kernel: sd 1:0:0:0: [sdb] Write cache: >>> enabled, read cache: enabled, doesn't support DPO or FUA >>> May 29 12:50:24 localhost kernel: ata2.00: NCQ disabled due to >>> excessive errors >>> May 29 12:50:24 localhost kernel: ata2.00: exception Emask 0x0 SAct >>> 0x6 SErr 0x0 action 0x2 frozen >>> May 29 12:50:24 localhost kernel: ata2.00: cmd >>> 61/10:08:c7:88:b8/00:00:0f:00:00/40 tag 1 cdb 0x0 data 8192 out >>> May 29 12:50:24 localhost kernel: res >>> 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout) >>> May 29 12:50:24 localhost kernel: ata2.00: status: {DRDY } >>> May 29 12:50:24 localhost kernel: ata2.00: cmd >>> 61/10:10:9f:8a:b8/00:00:0f:00:00/40 tag 2 cdb 0x0 data 8192 out >>> May 29 12:50:24 localhost kernel: res >>> 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout) >>> May 29 12:50:24 localhost kernel: ata2.00: status: {DRDY } >>> May 29 12:50:24 localhost kernel: ata2: hard resetting port >>> May 29 12:50:25 localhost kernel: ata2: SATA link up 1.5 Gbps >>> (SStatus 113 SControl 300) >>> May 29 12:50:25 localhost kernel: ata2.00: ata_hpa_resize: sectors = >>> 625142448, hpa_sectors = 625142448 >>> May 29 12:50:25 localhost kernel: ata2.00: ata_hpa_resize: sectors = >>> 625142448, hpa_sectors = 625142448 >>> May 29 12:50:25 localhost kernel: ata2.00: configured for UDMA/133 >>> May 29 12:50:25 localhost kernel: ata2: EH pending after completion, >>> repeating EH (cnt=4) >>> May 29 12:50:25 localhost kernel: ata2: EH complete >>> May 29 12:50:25 localhost kernel: sd 1:0:0:0: [sdb] 625142448 >>> 512-byte hardware sectors (320073 MB) >>> May 29 12:50:25 localhost kernel: sd 1:0:0:0: [sdb] Write Protect is >>> off >>> May 29 12:50:25 localhost kernel: sd 1:0:0:0: [sdb] Write cache: >>> enabled, read cache: enabled, doesn't support DPO or FUA >>> >>> After the system disabled NCQ there weren't any more more ata resets >>> and the disks were working OK. >>> >>> Strange thing is, when I have run PostgreSQL pgbench with 25 clients >>> on 2.6.22-rc2 + cfs-v13 + swncq (which clearly showed advanced >>> transfer rate) >>> I had no such problems. The PostgreSQL DB was also on ata2.00. >>> >>> Best regards, >>> Zoltán Böszörményi >>> >>> - >>> To unsubscribe from this list: send the line "unsubscribe >>> linux-kernel" in >>> the body of a message to majordomo@vger.kernel.org >>> More majordomo info at http://vger.kernel.org/majordomo-info.html >>> Please read the FAQ at http://www.tux.org/lkml/ >>> >> >> >> > > it's an ABIT KN9 SLI. lspci output is below. Here's a newer one for BIOS v20, attached. The previous lspci output was with BIOS v18. Yesterday I got this with 2.6.22-rc4-mm2: ... Jun 17 11:19:02 localhost kernel: ata1.00: exception Emask 0x0 SAct 0xff SErr 0x2400000 action 0x2 frozen Jun 17 11:19:02 localhost kernel: ata1: SError: {Handshk UnrecFIS } Jun 17 11:19:02 localhost kernel: ata1.00: cmd 61/c0:00:65:1d:18/00:00:09:00:00/40 tag 0 cdb 0x0 data 98304 out Jun 17 11:19:02 localhost kernel: res 40/00:0c:45:59:32/00:00:00:00:00/00 Emask 0x4 (timeout) Jun 17 11:19:02 localhost kernel: ata1.00: status: {DRDY } Jun 17 11:19:02 localhost kernel: ata1.00: cmd 61/30:08:35:e6:0b/01:00:05:00:00/40 tag 1 cdb 0x0 data 155648 out Jun 17 11:19:02 localhost kernel: res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout) Jun 17 11:19:02 localhost kernel: ata1.00: status: {DRDY } Jun 17 11:19:02 localhost kernel: ata1.00: cmd 61/a0:10:1d:cc:0d/00:00:05:00:00/40 tag 2 cdb 0x0 data 81920 out Jun 17 11:19:02 localhost kernel: res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout) Jun 17 11:19:02 localhost kernel: ata1.00: status: {DRDY } Jun 17 11:19:02 localhost kernel: ata1.00: cmd 61/08:18:e5:81:43/00:00:05:00:00/40 tag 3 cdb 0x0 data 4096 out Jun 17 11:19:02 localhost kernel: res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout) Jun 17 11:19:03 localhost kernel: ata1.00: status: {DRDY } Jun 17 11:19:03 localhost kernel: ata1.00: cmd 61/08:20:ed:81:43/00:00:05:00:00/40 tag 4 cdb 0x0 data 4096 out Jun 17 11:19:03 localhost kernel: res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout) Jun 17 11:19:03 localhost kernel: ata1.00: status: {DRDY } Jun 17 11:19:03 localhost kernel: ata1.00: cmd 61/40:28:25:1e:18/00:00:09:00:00/40 tag 5 cdb 0x0 data 32768 out Jun 17 11:19:03 localhost kernel: res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout) Jun 17 11:19:03 localhost kernel: ata1.00: status: {DRDY } Jun 17 11:19:03 localhost kernel: ata1.00: cmd 61/40:30:65:e7:0b/00:00:05:00:00/40 tag 6 cdb 0x0 data 32768 out Jun 17 11:19:03 localhost kernel: res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout) Jun 17 11:19:03 localhost kernel: ata1.00: status: {DRDY } Jun 17 11:19:03 localhost kernel: ata1.00: cmd 61/08:38:bd:cc:0d/00:00:05:00:00/40 tag 7 cdb 0x0 data 4096 out Jun 17 11:19:03 localhost kernel: res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout) Jun 17 11:19:03 localhost kernel: ata1.00: status: {DRDY } Jun 17 11:19:03 localhost kernel: ata1: hard resetting port Jun 17 11:19:03 localhost kernel: ata1: SATA link up 3.0 Gbps (SStatus 123 SControl 300) Jun 17 11:19:03 localhost kernel: ata1.00: ata_hpa_resize 1: sectors = 312581808, hpa_sectors = 312581808 Jun 17 11:19:03 localhost kernel: ata1.00: ata_hpa_resize 1: sectors = 312581808, hpa_sectors = 312581808 Jun 17 11:19:03 localhost kernel: ata1.00: configured for UDMA/133 Jun 17 11:19:03 localhost kernel: ata1: EH pending after completion, repeating EH (cnt=4) Jun 17 11:19:03 localhost kernel: ata1: EH complete Jun 17 11:19:03 localhost kernel: sd 0:0:0:0: [sda] 312581808 512-byte hardware sectors (160042 MB) Jun 17 11:19:03 localhost kernel: sd 0:0:0:0: [sda] Write Protect is off Jun 17 11:19:03 localhost kernel: sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA ... Jun 17 14:20:29 localhost kernel: ata2.00: exception Emask 0x0 SAct 0x7 SErr 0x0 action 0x2 frozen Jun 17 14:20:29 localhost kernel: ata2.00: cmd 61/08:00:4f:3f:03/00:00:00:00:00/40 tag 0 cdb 0x0 data 4096 out Jun 17 14:20:29 localhost kernel: res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout) Jun 17 14:20:29 localhost kernel: ata2.00: status: {DRDY } Jun 17 14:20:29 localhost kernel: ata2.00: cmd 61/08:08:bf:01:74/00:00:04:00:00/40 tag 1 cdb 0x0 data 4096 out Jun 17 14:20:29 localhost kernel: res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout) Jun 17 14:20:29 localhost kernel: ata2.00: status: {DRDY } Jun 17 14:20:29 localhost kernel: ata2.00: cmd 61/08:10:cf:92:4b/00:00:04:00:00/40 tag 2 cdb 0x0 data 4096 out Jun 17 14:20:29 localhost kernel: res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout) Jun 17 14:20:29 localhost kernel: ata2.00: status: {DRDY } Jun 17 14:20:29 localhost kernel: ata2: hard resetting port Jun 17 14:20:29 localhost kernel: ata2: SATA link up 1.5 Gbps (SStatus 113 SControl 300) Jun 17 14:20:29 localhost kernel: ata2.00: ata_hpa_resize 1: sectors = 625142448, hpa_sectors = 625142448 Jun 17 14:20:29 localhost kernel: ata2.00: ata_hpa_resize 1: sectors = 625142448, hpa_sectors = 625142448 Jun 17 14:20:29 localhost kernel: ata2.00: configured for UDMA/133 Jun 17 14:20:29 localhost kernel: ata2: EH pending after completion, repeating EH (cnt=4) Jun 17 14:20:29 localhost kernel: ata2: EH complete Jun 17 14:20:29 localhost kernel: sd 1:0:0:0: [sdb] 625142448 512-byte hardware sectors (320073 MB) Jun 17 14:20:29 localhost kernel: sd 1:0:0:0: [sdb] Write Protect is off Jun 17 14:20:29 localhost kernel: sd 1:0:0:0: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA ... Jun 17 18:44:52 localhost kernel: ata2.00: exception Emask 0x0 SAct 0x6 SErr 0x0 action 0x2 frozen Jun 17 18:44:52 localhost kernel: ata2.00: cmd 61/08:08:bf:01:00/00:00:00:00:00/40 tag 1 cdb 0x0 data 4096 out Jun 17 18:44:52 localhost kernel: res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout) Jun 17 18:44:52 localhost kernel: ata2.00: status: {DRDY } Jun 17 18:44:52 localhost kernel: ata2.00: cmd 61/08:10:cf:01:00/00:00:00:00:00/40 tag 2 cdb 0x0 data 4096 out Jun 17 18:44:52 localhost kernel: res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout) Jun 17 18:44:52 localhost kernel: ata2.00: status: {DRDY } Jun 17 18:44:52 localhost kernel: ata2: hard resetting port Jun 17 18:44:52 localhost kernel: ata2: SATA link up 1.5 Gbps (SStatus 113 SControl 300) Jun 17 18:44:53 localhost kernel: ata2.00: ata_hpa_resize 1: sectors = 625142448, hpa_sectors = 625142448 Jun 17 18:44:53 localhost kernel: ata2.00: ata_hpa_resize 1: sectors = 625142448, hpa_sectors = 625142448 Jun 17 18:44:53 localhost kernel: ata2.00: configured for UDMA/133 Jun 17 18:44:53 localhost kernel: ata2: EH pending after completion, repeating EH (cnt=4) Jun 17 18:44:53 localhost kernel: ata2: EH complete Jun 17 18:44:53 localhost kernel: sd 1:0:0:0: [sdb] 625142448 512-byte hardware sectors (320073 MB) Jun 17 18:44:53 localhost kernel: sd 1:0:0:0: [sdb] Write Protect is off Jun 17 18:44:53 localhost kernel: sd 1:0:0:0: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA But otherwise it worked OK. Best regards, Zoltán Böszörményi