PIIX4: DMA timeout issue

DISCUSSION gshan 5 participants 15 messages Jul 29, 2008 – Oct 24, 2008 1 message not in the archive libata

Share & tools

gshan

author

2008-07-29 08:43 UTC #0 lore raw

Hello, I sent mails on this issue before, but nobody made response. There are 2 types of board for me. The hardware configuration for those 2 boards are almost same except that one of them has 100GB harddisk, and another type of board has 60GB harddisk. All harddisk was access through PIIX4. I found this issue on board with 60GB disk, but can't reproduce it on that with 100GB disk.

When I uncompressed a large file (600MB) to a logic partition with 8GB size, following errors was report on middle way (5 minutes about from start). Anybody has ideas?

hdc: dma_timer_expiry: dma status == 0x21
hdc: DMA timeout error
hdc: dma timeout error: status=0x58 { DriveReady SeekComplete DataRequest }
ide: failed opcode was: unknown
hdc: DMA disabled
ide1: reset: success

Output at booting as follows:
=====================
Uniform Multi-Platform E-IDE driver Revision: 7.00alpha2
ide: Assuming 33MHz system bus speed for PIO modes; override with idebus=xx
PIIX4: IDE controller at PCI slot 0001:00:03.1
PIIX4: chipset revision 1
PIIX4: not 100% native mode: will probe irqs later
ide0: BM-DMA at 0x1000-0x1007, BIOS settings: hda:pio, hdb:pio
ide1: BM-DMA at 0x1008-0x100f, BIOS settings: hdc:pio, hdd:pio
hdc: HTS726060M9ATX0, ATA DISK drive
ide1 at 0x170-0x177,0x376 on irq 47
hdc: max request size: 512KiB
hdc: 117210240 sectors (60011 MB) w/7877KiB Cache, CHS=16383/255/63, UDMA(33)
hdc: cache flushes supported
hdc: hdc1 hdc4 < hdc5 hdc6 hdc7 hdc8 >

More info from proc
==============
/proc/ide/ide1/hdc $ cat settings

name                    value           min             max             mode
----                    -----           ---             ---             ----
acoustic                0               0               254             rw
address                 1               0               2               rw
bios_cyl                16383           0               65535           rw
bios_head               255             0               255             rw
bios_sect               63              0               63              rw
bswap                   0               0               1               r
current_speed           66              0               70              rw
dma_timeout             20000           0               20000           rw
failures                0               0               65535           rw
init_speed              66              0               70              rw
io_32bit                0               0               3               rw
keepsettings            0               0               1               rw
lun                     0               0               7               rw
max_failures            1               0               65535           rw
multcount               0               0               16              rw
nice1                   1               0               1               rw
nowerr                  0               0               1               rw
number                  2               0               3               rw
pio_mode                write-only      0               255             w
unmaskirq               0               0               1               rw
using_dma               1               0               1               rw
wcache                  1               0               1               rw

Output from fdisk
=============
/proc/ide/ide1/hdc $ fdisk /dev/hdc

The number of cylinders for this disk is set to 7296. There is nothing wrong with that, but this is larger than 1024, and could in certain setups cause problems with:
1) software that runs at boot time (e.g., old versions of LILO)
2) booting and partitioning software from other OSs (e.g., DOS FDISK, OS/2 FDISK)

Command (m for help): p

Disk /dev/hdc: 60.0 GB, 60011642880 bytes
255 heads, 63 sectors/track, 7296 cylinders
Units = cylinders of 16065 * 512 = 8225280 bytes
Disk identifier: 0x488ea1c3

Device Boot Start End Blocks Id System

/dev/hdc1               1          17      136521   83  Linux
/dev/hdc4              18        7296    58468567+   5  Extended
/dev/hdc5              18        1014     8008371   83  Linux
/dev/hdc6            1015        2011     8008371   83  Linux
/dev/hdc7            2012        3008     8008371   83  Linux
/dev/hdc8            3009        4005     8008371   83  Linux

Regards,
Gavin

Jeff Garzik

2008-07-29 13:34 UTC #1 lore raw

Quoted 11 lines · gshan

Hello, I sent mails on this issue before, but nobody made response. There are 2 types of board for me. The hardware configuration for those 2 boards are almost same except that one of them has 100GB harddisk, and another type of board has 60GB harddisk. All harddisk was access through PIIX4. I found this issue on board with 60GB disk, but can't reproduce it on that with 100GB disk.
When I uncompressed a large file (600MB) to a logic partition with 8GB size, following errors was report on middle way (5 minutes about from start). Anybody has ideas?

Quoted 6 lines

hdc: dma_timer_expiry: dma status == 0x21
hdc: DMA timeout error
hdc: dma timeout error: status=0x58 { DriveReady SeekComplete DataRequest }
ide: failed opcode was: unknown
hdc: DMA disabled
ide1: reset: success

Can you try disabling the IDE driver (CONFIG_IDE) and enabling the newer libata driver? (CONFIG_ATA)

Jeff

gshan

author

2008-07-30 00:58 UTC #2 lore raw

Quoted 12 lines · Jeff Garzik

Quoted 11 lines · gshan
Hello, I sent mails on this issue before, but nobody made response. There are 2 types of board for me. The hardware configuration for those 2 boards are almost same except that one of them has 100GB harddisk, and another type of board has 60GB harddisk. All harddisk was access through PIIX4. I found this issue on board with 60GB disk, but can't reproduce it on that with 100GB disk.
When I uncompressed a large file (600MB) to a logic partition with 8GB size, following errors was report on middle way (5 minutes about from start). Anybody has ideas?

Quoted 8 lines

Quoted 6 lines
hdc: dma_timer_expiry: dma status == 0x21
hdc: DMA timeout error
hdc: dma timeout error: status=0x58 { DriveReady SeekComplete DataRequest }
ide: failed opcode was: unknown
hdc: DMA disabled
ide1: reset: success
Can you try disabling the IDE driver (CONFIG_IDE) and enabling the newer libata driver? (CONFIG_ATA)

Jeff, thanks a lot for your suggestions. I will try it if possible.

Quoted 6 lines

Jeff

A message that is not in the archive (sent off-list or not yet received): [email protected]

gshan

author

2008-07-30 01:08 UTC #4 lore raw

Quoted 4 lines

Hmmm?

Quoted 8 lines

Maciej was investigating this:
	http://lkml.org/lkml/2008/5/20/724
but you didn't follow up and started new thread with:
	http://lkml.org/lkml/2008/7/14/452

I'm sorry for this :-(

Quoted 4 lines

[ It could be that the original IRQ routing issue was fixed
(or wasn't really the source of problem) but you didn't tell us about it and ignored previous discussions. ]

The IRQ routing issue has been fixed. IRQ routing system
on my board is somewhat complicated: i8259->mlba (FPGA based PCI device)->MV64460(system controller). I forgot to set MV64460 IRQ pin to level sensitive and edge sensitive was used, which caused interrupt lost finally. After changing this to level sensitive, everything seems fine. Now, the problem isn't interrupt lost, but suspending DMA operations.

Quoted 5 lines

Also is the problem still present in 2.6.26 or 2.6.27-rc1?
[ I don't see an information about the kernel version that is
being used in either of threads? ]

Sorry, I'm using 2.6.21 kernel.

Quoted 22 lines

Quoted 22 lines
Quoted 11 lines
There are 2 types of board for me. The hardware configuration for those 2 boards are almost same except that one of them has 100GB harddisk, and another type of board has 60GB harddisk. All harddisk was access through PIIX4. I found this issue on board with 60GB disk, but can't reproduce it on that with 100GB disk.
When I uncompressed a large file (600MB) to a logic partition with 8GB size, following errors was report on middle way (5 minutes about from start). Anybody has ideas?
Quoted 7 lines
hdc: dma_timer_expiry: dma status == 0x21
hdc: DMA timeout error
hdc: dma timeout error: status=0x58 { DriveReady SeekComplete DataRequest }
ide: failed opcode was: unknown
hdc: DMA disabled
ide1: reset: success
Can you try disabling the IDE driver (CONFIG_IDE) and enabling the newer libata driver? (CONFIG_ATA)
Jeff

Bartlomiej Zolnierkiewicz

2008-07-30 19:46 UTC #5 lore raw

On Wednesday 30 July 2008, gshan wrote:

[...]

Quoted 7 lines

The IRQ routing issue has been fixed. IRQ routing system
on my board is somewhat complicated: i8259->mlba (FPGA based PCI device)->MV64460(system controller). I forgot to set MV64460 IRQ pin to level sensitive and edge sensitive was used, which caused interrupt lost finally. After changing this to level sensitive, everything seems fine. Now, the problem isn't interrupt lost, but suspending DMA operations.

Thanks for explaining this.

Quoted 6 lines

Quoted 5 lines
Also is the problem still present in 2.6.26 or 2.6.27-rc1?
[ I don't see an information about the kernel version that is
being used in either of threads? ]
Sorry, I'm using 2.6.21 kernel.

Would be great to try with some recent one, the issue may have been fixed already (which is quite likely given a number of bugfixes that went in recent kernels).

Thanks,
Bart

gshan

author

2008-07-31 01:21 UTC #6 lore raw

Quoted 23 lines · Bartlomiej Zolnierkiewicz

On Wednesday 30 July 2008, gshan wrote:
[...]
Quoted 8 lines
The IRQ routing issue has been fixed. IRQ routing system
on my board is somewhat complicated: i8259->mlba (FPGA based PCI device)->MV64460(system controller). I forgot to set MV64460 IRQ pin to level sensitive and edge sensitive was used, which caused interrupt lost finally. After changing this to level sensitive, everything seems fine. Now, the problem isn't interrupt lost, but suspending DMA operations.
Thanks for explaining this.
Quoted 6 lines
Quoted 6 lines
Also is the problem still present in 2.6.26 or 2.6.27-rc1?
[ I don't see an information about the kernel version that is
being used in either of threads? ]

Quoted 7 lines

Quoted 2 lines
Sorry, I'm using 2.6.21 kernel.
Would be great to try with some recent one, the issue may have been fixed already (which is quite likely given a number of bugfixes that went in recent kernels).

I tried to searched in bugzilla.kernel.org and didn't find there has fix on this issue. Yesterday, Jeff suggested me to turn to ata driver for PIIX4. I tried this yesterday but still have some problems to make PIIX4 workable under ata driver. I will continue working on this today.

Gavin

Quoted 3 lines

Thanks,
Bart

gshan

author

2008-07-30 09:36 UTC #7 lore raw

In reply to Jeff Garzik

Quoted 4 lines

Can you try disabling the IDE driver (CONFIG_IDE) and enabling the newer libata driver? (CONFIG_ATA)

Jeff, I tried moving to ATA driver for PIIX4 today and found ATA need to request 2 IRQ lines, each one of them belongs to primary and secondary channel. However, when I make PIIX4 worked under IDE driver, it also need to request one IRQ for "ide1". So it's necessary to disable secondary channel manually?

Another question is my PIIX4 chip has device ID + vendor ID of 0x71108086. But it finally was mapped to following ID of piix_pci_tbl[] array. Device of 0x7110 and 0x7010 should be quit different, right?

{ 0x8086, 0x7010, PCI_ANY_ID, PCI_ANY_ID, 0, 0, piix_pata_mwdma },

Gavin

Alan Cox

2008-07-30 11:07 UTC #8 lore raw

Quoted 7 lines

Jeff, I tried moving to ATA driver for PIIX4 today and found ATA need to request
2 IRQ lines, each one of them belongs to primary and secondary channel. However,
when I make PIIX4 worked under IDE driver, it also need to request one IRQ for "ide1".
So it's necessary to disable secondary channel manually?

If the controller is in legacy mode then libata will claim the interrupt lines for all channels which are enabled even if there are no devices on them. This is neccessary for device hot or warm plug support as new disks could appear on empty channels.

Quoted 6 lines

Another question is my PIIX4 chip has device ID + vendor ID of 0x71108086. But it finally
was mapped to following ID of piix_pci_tbl[] array. Device of 0x7110 and 0x7010 should
be quit different, right?

Yes - I find tht one very odd - you might need to debug a bit to see what is occuring if you think this is the case.

Alan

gshan

author

2008-07-31 04:31 UTC #9 lore raw

Quoted 11 lines

Quoted 5 lines
Another question is my PIIX4 chip has device ID + vendor ID of 0x71108086. But it finally was mapped to following ID of piix_pci_tbl[] array. Device of 0x7110 and 0x7010 should be quit different, right?
Yes - I find tht one very odd - you might need to debug a bit to see what is occuring if you think this is the case.
Alan

Alan/Jeff, I tried to install ATA driver on PIIX4. After fixing IRQ number to 143 for primary and secondary channel. I got following output and it seems the driver has been loaded sucessfully. However, I couldn't see any information from /proc/devices. Do you have any ideas?

piix_init: enter
piix_init_one: pci device: �[eh
piix_init_one: vendor=0x00008086, device=0x00007111
piix_init_one: piix_host_priv allocated
piix_init_one: ent->driver_data=0
ata_pci_init_one: n_ports=2
ata_pci_init_one: pci device enabled
ata_pci_init_one: pci device class=0x00010180
ata_pci_init_one: legacy_mode=8
ata_pci_init_one: DMA mode has been set
ata_pci_init_legacy_port: port_mask=0x0000000b
ata_pci_init_legacy_port: ATA_PRIMARY_CMD=0x000001f0, ATA_PRIMARY_CTL=0x000003f6
ata_pci_init_legacy_port: ATA_SECONDARY_CMD=0x00000170, ATA_SECONDARY_CTL=0x00000376
ata_pci_init_legacy_port: BMDMA=0xfbf00000
, phys=0x00001000, phys_end=0x0000100f
ata_pci_init_legacy_port: probe_ent initialized
ata_pci_init_legacy_port: IRQ line of primary channel is 143
ata_pci_init_legacy_port: IRQ line of secondary channel is 143
ata_pci_init_one: Master set
ata1: PATA max UDMA/33 cmd 0xfbeff1f0 ctl 0xfbeff3f6 bmdma 0xfbf00000 irq 143
ata2: PATA max UDMA/33 cmd 0xfbeff170 ctl 0xfbeff376 bmdma 0xfbf00008 irq 143 scsi0 : ata_piix
scsi1 : ata_piix
ata2.00: ATA-6: HTE721010G9AT00, MCZOA51A, max UDMA/100
ata2.00: 195371568 sectors, multi 0: LBA48
ata2.00: configured for UDMA/33
1:0:0:0: Direct-Access ATA HTE721010G9AT00 MCZO PQ: 0 ANSI: 5

/ $ cat /proc/devices
Character devices:
1 mem
2 pty
3 ttyp
4 /dev/vc/0
4 tty
5 /dev/tty
5 /dev/console
5 /dev/ptmx
7 vcs
10 misc
13 input
90 mtd
128 ptm
136 pts
204 ttyMM
205 ttyVC
206 ttySC
253 telica_sysinfo
254 mlba

Block devices:
1 ramdisk
7 loop
31 mtdblock

Gavin

Tejun Heo

2008-08-01 07:45 UTC #10 lore raw

Quoted 11 lines · gshan

Quoted 11 lines
Quoted 7 lines
Another question is my PIIX4 chip has device ID + vendor ID of 0x71108086. But it finally
was mapped to following ID of piix_pci_tbl[] array. Device of 0x7110 and 0x7010 should
be quit different, right?
Yes - I find tht one very odd - you might need to debug a bit to see what is occuring if you think this is the case.

Quoted 6 lines

Quoted 2 lines
Alan
Alan/Jeff, I tried to install ATA driver on PIIX4. After fixing IRQ number to 143 for primary and secondary channel. I got following output and it seems the driver has been loaded sucessfully. However, I couldn't see any information from /proc/devices. Do you have any ideas?

You need the SCSI disk driver - sd_mod.ko.

Signature · 1 line

tejun

gshan

author

2008-08-01 08:39 UTC #11 lore raw

Quoted 10 lines

Quoted 6 lines
Alan/Jeff, I tried to install ATA driver on PIIX4. After fixing IRQ number to 143 for primary and secondary channel. I got following output and it seems the driver has been loaded sucessfully. However, I couldn't see any information from /proc/devices. Do you have any ideas?
You need the SCSI disk driver - sd_mod.ko.

Thanks a lot. It seems it starts to work now.

piix_init: enter
piix_init_one: pci device: �\

piix_init_one: vendor=0x00008086, device=0x00007111
piix_init_one: piix_host_priv allocated
piix_init_one: ent->driver_data=0
ata_pci_init_one: n_ports=2
ata_pci_init_one: pci device enabled
ata_pci_init_one: pci device class=0x00010180
ata_pci_init_one: legacy_mode=8
ata_pci_init_one: DMA mode has been set
ata_pci_init_legacy_port: port_mask=0x0000000b
ata_pci_init_legacy_port: ATA_PRIMARY_CMD=0x000001f0, ATA_PRIMARY_CTL=0x000003f6
ata_pci_init_legacy_port: ATA_SECONDARY_CMD=0x00000170, ATA_SECONDARY_CTL=0x00000376
ata_pci_init_legacy_port: BMDMA=0xfbf00000
, phys=0x00001000, phys_end=0x0000100f
ata_pci_init_legacy_port: probe_ent initialized
ata_pci_init_legacy_port: IRQ line of primary channel is 143
ata_pci_init_legacy_port: IRQ line of secondary channel is 143
ata_pci_init_one: Master set
ata1: PATA max UDMA/33 cmd 0xfbeff1f0 ctl 0xfbeff3f6 bmdma 0xfbf00000 irq 143
ata2: PATA max UDMA/33 cmd 0xfbeff170 ctl 0xfbeff376 bmdma 0xfbf00008 irq 143 scsi0 : ata_piix
scsi1 : ata_piix
ata2.00: ATA-6: HTE721010G9AT00, MCZOA51A, max UDMA/100
ata2.00: 195371568 sectors, multi 0: LBA48
ata2.00: configured for UDMA/33
1:0:0:0: Direct-Access ATA HTE721010G9AT00 MCZO PQ: 0 ANSI: 5
SCSI device sda: 195371568 512-byte hdwr sectors (100030 MB)
sda: Write Protect is off
SCSI device sda: write cache: enabled, read cache: enabled, doesn't support DPO or FUA SCSI device sda: 195371568 512-byte hdwr sectors (100030 MB)
sda: Write Protect is off
SCSI device sda: write cache: enabled, read cache: enabled, doesn't support DPO or FUA
sda: sda1 sda4 < sda5 sda6 sda7 sda8 >
sd 1:0:0:0: Attached scsi disk sda
sd 1:0:0:0: Attached scsi generic sg0 type 0

Gavin

gshan

author

2008-08-01 08:55 UTC #12 lore raw

In reply to Tejun Heo

Quoted 10 lines

Quoted 6 lines
Alan/Jeff, I tried to install ATA driver on PIIX4. After fixing IRQ number to 143 for primary and secondary channel. I got following output and it seems the driver has been loaded sucessfully. However, I couldn't see any information from /proc/devices. Do you have any ideas?
You need the SCSI disk driver - sd_mod.ko.

Unfortunately, the timeout issue still happened on ATA driver as IDE.

Command (m for help): p

Disk /dev/sda: 60.0 GB, 60011642880 bytes
255 heads, 63 sectors/track, 7296 cylinders
Units = cylinders of 16065 * 512 = 8225280 bytes
Disk identifier: 0x4892c004

Device Boot Start End Blocks Id System

/dev/sda1               1          17      136521   83  Linux
/dev/sda4              18        7296    58468567+   5  Extended
/dev/sda5              18        7296    58468536   83  Linux

Command (m for help): w
The partition table has been altered!

Calling ioctl() to re-read partition table.
SCSI device sda: 117210240 512-byte hdwr sectors (60012 MB)
sda: Write Protect is off
SCSI device sda: write cache: enabled, read cache: enabled, doesn't support DPO or FUA
sda: sda1 sda4 < sda5 >
Syncing disks.
/ $ mkfs.ext3 -N 655360 /dev/sda5
mke2fs 1.40 (29-Jun-2007)
Filesystem label=
OS type: Linux
Block size=4096 (log=2)
Fragment size=4096 (log=2)
657984 inodes, 14617134 blocks
730856 blocks (5.00%) reserved for the super user
First data block=0
Maximum filesystem blocks=0
447 block groups
32768 blocks per group, 32768 fragments per group
1472 inodes per group
Superblock backups stored on blocks:

       32768, 98304, 163840, 229376, 294912, 819200, 884736, 1605632, 
2654208,
       4096000, 7962624, 11239424

Writing inode tables: done Creating journal (32768 blocks): done
Writing superblocks and filesystem accounting information: done

This filesystem will be automatically checked every 25 mounts or 180 days, whichever comes first. Use tune2fs -c or -i to override. / $ mkdir /aaa
/ $ ifconfig rep0 192.168.253.27
mv643xx_eth_if_start: register PHY interrupt rep0 port=1 sw=1 swport=2 / $ mount -o nolock 192.168.253.26:/home1 /aaa
/ $ cd /disk_root/
/disk_root $ ls
/disk_root $ cd /
/ $ mount /dev/sda5 /disk_root/
kjournald starting. Commit interval 5 seconds
EXT3 FS on sda5, internal journal
EXT3-fs: mounted filesystem with ordered data mode.
/ $ cd /disk_root/
/disk_root $ tar -zxf /aaa/target_7xx_cge5.2008-07-10.tgz

ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen ata2.00: cmd 35/00:00:18:ef:28/00:04:01:00:00/e0 tag 0 cdb 0x0 data 524288 out

        res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)

ata2: soft resetting port
ata2.00: configured for UDMA/33
ata2: EH complete
ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen ata2.00: cmd 35/00:00:18:ef:28/00:04:01:00:00/e0 tag 0 cdb 0x0 data 524288 out

        res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)

        res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)

ata2: soft resetting port
ata2.00: configured for UDMA/33
ata2: EH complete
ata2.00: limiting speed to UDMA/25:PIO4
ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen ata2.00: cmd 35/00:00:18:ef:28/00:04:01:00:00/e0 tag 0 cdb 0x0 data 524288 out

        res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)

ata2: soft resetting port
ata2.00: configured for UDMA/25
ata2: EH complete
ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen ata2.00: cmd 35/00:00:18:ef:28/00:04:01:00:00/e0 tag 0 cdb 0x0 data 524288 out

        res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)

        res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)

ata2: soft resetting port
ata2.00: configured for UDMA/25
sd 1:0:0:0: SCSI error: return code = 0x08000002
sda: Current [descriptor]: sense key=0xb
ASC=0x0 ASCQ=0x0
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

end_request: I/O error, dev sda, sector 19459864
Buffer I/O error on device sda5, logical block 2398337
lost page write due to I/O error on sda5
Buffer I/O error on device sda5, logical block 2398338
lost page write due to I/O error on sda5
Buffer I/O error on device sda5, logical block 2398339
lost page write due to I/O error on sda5
Buffer I/O error on device sda5, logical block 2398340
lost page write due to I/O error on sda5
Buffer I/O error on device sda5, logical block 2398341
lost page write due to I/O error on sda5
Buffer I/O error on device sda5, logical block 2398342
lost page write due to I/O error on sda5
Buffer I/O error on device sda5, logical block 2398343
lost page write due to I/O error on sda5
Buffer I/O error on device sda5, logical block 2398344
lost page write due to I/O error on sda5
Buffer I/O error on device sda5, logical block 2398345
lost page write due to I/O error on sda5
Buffer I/O error on device sda5, logical block 2398346
lost page write due to I/O error on sda5
ata2: EH complete
ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen ata2.00: cmd ca/00:f8:18:f3:28/00:00:00:00:00/e1 tag 0 cdb 0x0 data 126976 out

        res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)

ata2: soft resetting port
ata2.00: configured for UDMA/25
ata2: EH complete
ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen ata2.00: cmd ca/00:f8:18:f3:28/00:00:00:00:00/e1 tag 0 cdb 0x0 data 126976 out

        res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)

ata2: soft resetting port
ata2.00: configured for UDMA/25
ata2: EH complete

Gavin

Gavin Shan

author

2008-08-03 14:10 UTC #13 lore raw

Quoted 142 lines

Unfortunately, the timeout issue still happened on ATA driver as IDE.
Command (m for help): p
Disk /dev/sda: 60.0 GB, 60011642880 bytes
255 heads, 63 sectors/track, 7296 cylinders
Units = cylinders of 16065 * 512 = 8225280 bytes
Disk identifier: 0x4892c004
Device Boot Start End Blocks Id System
/dev/sda1               1          17      136521   83  Linux
/dev/sda4              18        7296    58468567+   5  Extended
/dev/sda5              18        7296    58468536   83  Linux
Command (m for help): w
The partition table has been altered!
Calling ioctl() to re-read partition table.
SCSI device sda: 117210240 512-byte hdwr sectors (60012 MB)
sda: Write Protect is off
SCSI device sda: write cache: enabled, read cache: enabled, doesn't support DPO or FUA
sda: sda1 sda4 < sda5 >
Syncing disks.
/ $ mkfs.ext3 -N 655360 /dev/sda5
mke2fs 1.40 (29-Jun-2007)
Filesystem label=
OS type: Linux
Block size=4096 (log=2)
Fragment size=4096 (log=2)
657984 inodes, 14617134 blocks
730856 blocks (5.00%) reserved for the super user
First data block=0
Maximum filesystem blocks=0
447 block groups
32768 blocks per group, 32768 fragments per group
1472 inodes per group
Superblock backups stored on blocks:
       32768, 98304, 163840, 229376, 294912, 819200, 884736, 1605632, 
2654208,
       4096000, 7962624, 11239424
Writing inode tables: done
Creating journal (32768 blocks): done
Writing superblocks and filesystem accounting information: done
This filesystem will be automatically checked every 25 mounts or 180 days, whichever comes first. Use tune2fs -c or -i to override. / $ mkdir /aaa
/ $ ifconfig rep0 192.168.253.27
mv643xx_eth_if_start: register PHY interrupt rep0 port=1 sw=1 swport=2 / $ mount -o nolock 192.168.253.26:/home1 /aaa
/ $ cd /disk_root/
/disk_root $ ls
/disk_root $ cd /
/ $ mount /dev/sda5 /disk_root/
kjournald starting. Commit interval 5 seconds
EXT3 FS on sda5, internal journal
EXT3-fs: mounted filesystem with ordered data mode.
/ $ cd /disk_root/
/disk_root $ tar -zxf /aaa/target_7xx_cge5.2008-07-10.tgz
ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen ata2.00: cmd 35/00:00:18:ef:28/00:04:01:00:00/e0 tag 0 cdb 0x0 data 524288 out
        res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
ata2: soft resetting port
ata2.00: configured for UDMA/33
ata2: EH complete
ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen ata2.00: cmd 35/00:00:18:ef:28/00:04:01:00:00/e0 tag 0 cdb 0x0 data 524288 out
        res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
ata2: soft resetting port
ata2.00: configured for UDMA/33
ata2: EH complete
ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen ata2.00: cmd 35/00:00:18:ef:28/00:04:01:00:00/e0 tag 0 cdb 0x0 data 524288 out
        res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
ata2: soft resetting port
ata2.00: configured for UDMA/33
ata2: EH complete
ata2.00: limiting speed to UDMA/25:PIO4
ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen ata2.00: cmd 35/00:00:18:ef:28/00:04:01:00:00/e0 tag 0 cdb 0x0 data 524288 out
        res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
ata2: soft resetting port
ata2.00: configured for UDMA/25
ata2: EH complete
ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen ata2.00: cmd 35/00:00:18:ef:28/00:04:01:00:00/e0 tag 0 cdb 0x0 data 524288 out
        res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
ata2: soft resetting port
ata2.00: configured for UDMA/25
ata2: EH complete
ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen ata2.00: cmd 35/00:00:18:ef:28/00:04:01:00:00/e0 tag 0 cdb 0x0 data 524288 out
        res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
ata2: soft resetting port
ata2.00: configured for UDMA/25
sd 1:0:0:0: SCSI error: return code = 0x08000002
sda: Current [descriptor]: sense key=0xb
ASC=0x0 ASCQ=0x0
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
end_request: I/O error, dev sda, sector 19459864
Buffer I/O error on device sda5, logical block 2398337 lost page write due to I/O error on sda5
Buffer I/O error on device sda5, logical block 2398338 lost page write due to I/O error on sda5
Buffer I/O error on device sda5, logical block 2398339 lost page write due to I/O error on sda5
Buffer I/O error on device sda5, logical block 2398340 lost page write due to I/O error on sda5
Buffer I/O error on device sda5, logical block 2398341 lost page write due to I/O error on sda5
Buffer I/O error on device sda5, logical block 2398342 lost page write due to I/O error on sda5
Buffer I/O error on device sda5, logical block 2398343 lost page write due to I/O error on sda5
Buffer I/O error on device sda5, logical block 2398344 lost page write due to I/O error on sda5
Buffer I/O error on device sda5, logical block 2398345 lost page write due to I/O error on sda5
Buffer I/O error on device sda5, logical block 2398346 lost page write due to I/O error on sda5
ata2: EH complete
ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen ata2.00: cmd ca/00:f8:18:f3:28/00:00:00:00:00/e1 tag 0 cdb 0x0 data 126976 out
        res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
ata2: soft resetting port
ata2.00: configured for UDMA/25
ata2: EH complete
ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen ata2.00: cmd ca/00:f8:18:f3:28/00:00:00:00:00/e1 tag 0 cdb 0x0 data 126976 out

Quoted 4 lines

        res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
ata2: soft resetting port
ata2.00: configured for UDMA/25
ata2: EH complete

Alan and Jeff, I didn't receive your reply till now. I'm not sure you are still intrested on this issue. If you would like to get more information, pls let me know.

I tested it for almost one day and found same issue on 100GB and 60GB disk. So I have to think about interrupt lost inside i8259. Then I changed code of i8259 for several time and tested it and unfortunately same issue was there. I don't have good ideas now. If you would like, I can show you the code about i8259 interrupt handling.

The suspecting point of mine on i8259 is: when multiple interrupts are asserted on slave controller. Non-specific EOI will clear all pending interrupts or just clear that one in ISR?

Gavin

gshan

author

2008-08-05 03:42 UTC #14 lore raw

Quoted 147 lines · Gavin Shan

Quoted 132 lines
Unfortunately, the timeout issue still happened on ATA driver as IDE.
Command (m for help): p
Disk /dev/sda: 60.0 GB, 60011642880 bytes
255 heads, 63 sectors/track, 7296 cylinders
Units = cylinders of 16065 * 512 = 8225280 bytes
Disk identifier: 0x4892c004
Device Boot Start End Blocks Id System
/dev/sda1               1          17      136521   83  Linux
/dev/sda4              18        7296    58468567+   5  Extended
/dev/sda5              18        7296    58468536   83  Linux
Command (m for help): w
The partition table has been altered!
Calling ioctl() to re-read partition table.
SCSI device sda: 117210240 512-byte hdwr sectors (60012 MB)
sda: Write Protect is off
SCSI device sda: write cache: enabled, read cache: enabled, doesn't support DPO or FUA
sda: sda1 sda4 < sda5 >
Syncing disks.
/ $ mkfs.ext3 -N 655360 /dev/sda5
mke2fs 1.40 (29-Jun-2007)
Filesystem label=
OS type: Linux
Block size=4096 (log=2)
Fragment size=4096 (log=2)
657984 inodes, 14617134 blocks
730856 blocks (5.00%) reserved for the super user
First data block=0
Maximum filesystem blocks=0
447 block groups
32768 blocks per group, 32768 fragments per group
1472 inodes per group
Superblock backups stored on blocks:
       32768, 98304, 163840, 229376, 294912, 819200, 884736, 1605632, 
2654208,
       4096000, 7962624, 11239424
Writing inode tables: done Creating journal (32768 blocks): done
Writing superblocks and filesystem accounting information: done
This filesystem will be automatically checked every 25 mounts or 180 days, whichever comes first. Use tune2fs -c or -i to override. / $ mkdir /aaa
/ $ ifconfig rep0 192.168.253.27
mv643xx_eth_if_start: register PHY interrupt rep0 port=1 sw=1 swport=2 / $ mount -o nolock 192.168.253.26:/home1 /aaa
/ $ cd /disk_root/
/disk_root $ ls
/disk_root $ cd /
/ $ mount /dev/sda5 /disk_root/
kjournald starting. Commit interval 5 seconds
EXT3 FS on sda5, internal journal
EXT3-fs: mounted filesystem with ordered data mode.
/ $ cd /disk_root/
/disk_root $ tar -zxf /aaa/target_7xx_cge5.2008-07-10.tgz
ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen ata2.00: cmd 35/00:00:18:ef:28/00:04:01:00:00/e0 tag 0 cdb 0x0 data 524288 out
        res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
ata2: soft resetting port
ata2.00: configured for UDMA/33
ata2: EH complete
ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen ata2.00: cmd 35/00:00:18:ef:28/00:04:01:00:00/e0 tag 0 cdb 0x0 data 524288 out
        res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
ata2: soft resetting port
ata2.00: configured for UDMA/33
ata2: EH complete
ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen ata2.00: cmd 35/00:00:18:ef:28/00:04:01:00:00/e0 tag 0 cdb 0x0 data 524288 out
        res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
ata2: soft resetting port
ata2.00: configured for UDMA/33
ata2: EH complete
ata2.00: limiting speed to UDMA/25:PIO4
ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen ata2.00: cmd 35/00:00:18:ef:28/00:04:01:00:00/e0 tag 0 cdb 0x0 data 524288 out
        res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
ata2: soft resetting port
ata2.00: configured for UDMA/25
ata2: EH complete
ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen ata2.00: cmd 35/00:00:18:ef:28/00:04:01:00:00/e0 tag 0 cdb 0x0 data 524288 out
        res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
ata2: soft resetting port
ata2.00: configured for UDMA/25
ata2: EH complete
ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen ata2.00: cmd 35/00:00:18:ef:28/00:04:01:00:00/e0 tag 0 cdb 0x0 data 524288 out
        res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
ata2: soft resetting port
ata2.00: configured for UDMA/25
sd 1:0:0:0: SCSI error: return code = 0x08000002
sda: Current [descriptor]: sense key=0xb
ASC=0x0 ASCQ=0x0
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
end_request: I/O error, dev sda, sector 19459864
Buffer I/O error on device sda5, logical block 2398337
lost page write due to I/O error on sda5
Buffer I/O error on device sda5, logical block 2398338
lost page write due to I/O error on sda5
Buffer I/O error on device sda5, logical block 2398339
lost page write due to I/O error on sda5
Buffer I/O error on device sda5, logical block 2398340
lost page write due to I/O error on sda5
Buffer I/O error on device sda5, logical block 2398341
lost page write due to I/O error on sda5
Buffer I/O error on device sda5, logical block 2398342
lost page write due to I/O error on sda5
Buffer I/O error on device sda5, logical block 2398343
lost page write due to I/O error on sda5
Buffer I/O error on device sda5, logical block 2398344
lost page write due to I/O error on sda5
Buffer I/O error on device sda5, logical block 2398345
lost page write due to I/O error on sda5
Buffer I/O error on device sda5, logical block 2398346
lost page write due to I/O error on sda5
ata2: EH complete
ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen ata2.00: cmd ca/00:f8:18:f3:28/00:00:00:00:00/e1 tag 0 cdb 0x0 data 126976 out
        res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
ata2: soft resetting port
ata2.00: configured for UDMA/25
ata2: EH complete
ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen ata2.00: cmd ca/00:f8:18:f3:28/00:00:00:00:00/e1 tag 0 cdb 0x0 data 126976 out
Quoted 5 lines
        res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
ata2: soft resetting port
ata2.00: configured for UDMA/25
ata2: EH complete
Alan and Jeff, I didn't receive your reply till now. I'm not sure you are still intrested on this issue. If you would like to get more information, pls let me know.
I tested it for almost one day and found same issue on 100GB and 60GB disk. So I have to think about interrupt lost inside i8259. Then I changed code of i8259 for several time and tested it and unfortunately same issue was there. I don't have good ideas now. If you would like, I can show you the code about i8259 interrupt handling.

Quoted 6 lines

The suspecting point of mine on i8259 is: when multiple interrupts are asserted on slave controller. Non-specific EOI will clear all pending interrupts or just clear that one in ISR?
Gavin

I also turned on the debugging options and got following output when timeout happened.

ata_scsi_translate: ENTER
scsi_10_lba_len: ten-byte command
ata_sg_setup: ENTER, ata2
ata_sg_setup: 101 sg elements mapped
ata_fill_sg: PRD[0] = (0x1BF7E000, 0x1000)
ata_fill_sg: PRD[1] = (0x1BDFB000, 0x1000)
ata_fill_sg: PRD[2] = (0x1BB05000, 0x1000)
ata_fill_sg: PRD[3] = (0x1B80C000, 0x1000)
ata_fill_sg: PRD[4] = (0x1C251000, 0x1000)
ata_fill_sg: PRD[5] = (0x1BB04000, 0x1000)
ata_fill_sg: PRD[6] = (0x1C289000, 0x1000)
ata_fill_sg: PRD[7] = (0x1C288000, 0x1000)
ata_fill_sg: PRD[8] = (0x1BE95000, 0x1000)
ata_fill_sg: PRD[9] = (0x1BE94000, 0x1000)
ata_fill_sg: PRD[10] = (0x1BE97000, 0x1000)
ata_fill_sg: PRD[11] = (0x1BE96000, 0x1000)
ata_fill_sg: PRD[12] = (0x1BF31000, 0x1000)
ata_fill_sg: PRD[13] = (0x1BF30000, 0x1000)
ata_fill_sg: PRD[14] = (0x1BF33000, 0x1000)
ata_fill_sg: PRD[15] = (0x1B80D000, 0x1000)
ata_fill_sg: PRD[16] = (0x1B803000, 0x1000)
ata_fill_sg: PRD[17] = (0x1B914000, 0x1000)
ata_fill_sg: PRD[18] = (0x1BF7D000, 0x1000)
ata_fill_sg: PRD[19] = (0x1B915000, 0x1000)
ata_fill_sg: PRD[20] = (0x1B80E000, 0x1000)
ata_fill_sg: PRD[21] = (0x1BF7C000, 0x1000)
ata_fill_sg: PRD[22] = (0x1B844000, 0x1000)
ata_fill_sg: PRD[23] = (0x1B80F000, 0x1000)
ata_fill_sg: PRD[24] = (0x1B846000, 0x1000)
ata_fill_sg: PRD[25] = (0x1B845000, 0x1000)
ata_fill_sg: PRD[26] = (0x1B874000, 0x1000)
ata_fill_sg: PRD[27] = (0x1B847000, 0x1000)
ata_fill_sg: PRD[28] = (0x1B876000, 0x1000)
ata_fill_sg: PRD[29] = (0x1B875000, 0x1000)
ata_fill_sg: PRD[30] = (0x1B800000, 0x1000)
ata_fill_sg: PRD[31] = (0x1B877000, 0x1000)
ata_fill_sg: PRD[32] = (0x1BAD2000, 0x2000)
ata_fill_sg: PRD[33] = (0x1B802000, 0x1000)
ata_fill_sg: PRD[34] = (0x1BAC4000, 0x1000)
ata_fill_sg: PRD[35] = (0x1B916000, 0x1000)
ata_fill_sg: PRD[36] = (0x1B801000, 0x1000)
ata_fill_sg: PRD[37] = (0x1B8F0000, 0x1000)
ata_fill_sg: PRD[38] = (0x1B917000, 0x1000)
ata_fill_sg: PRD[39] = (0x1B8F2000, 0x1000)
ata_fill_sg: PRD[40] = (0x1B8F1000, 0x1000)
ata_fill_sg: PRD[41] = (0x1B92C000, 0x1000)
ata_fill_sg: PRD[42] = (0x1B8F3000, 0x1000)
ata_fill_sg: PRD[43] = (0x1B92E000, 0x1000)
ata_fill_sg: PRD[44] = (0x1B92D000, 0x1000)
ata_fill_sg: PRD[45] = (0x1BA70000, 0x1000)
ata_fill_sg: PRD[46] = (0x1B92F000, 0x1000)
ata_fill_sg: PRD[47] = (0x1BAD1000, 0x1000)
ata_fill_sg: PRD[48] = (0x1BAD0000, 0x1000)
ata_fill_sg: PRD[49] = (0x1BAC5000, 0x1000)
ata_fill_sg: PRD[50] = (0x1C714000, 0x1000)
ata_fill_sg: PRD[51] = (0x1BAC7000, 0x1000)
ata_fill_sg: PRD[52] = (0x1BAC6000, 0x1000)
ata_fill_sg: PRD[53] = (0x1BAF1000, 0x1000)
ata_fill_sg: PRD[54] = (0x1BAF0000, 0x1000)
ata_fill_sg: PRD[55] = (0x1BAF3000, 0x1000)
ata_fill_sg: PRD[56] = (0x1BAF2000, 0x1000)
ata_fill_sg: PRD[57] = (0x1C765000, 0x1000)
ata_fill_sg: PRD[58] = (0x1C764000, 0x1000)
ata_fill_sg: PRD[59] = (0x1C767000, 0x1000)
ata_fill_sg: PRD[60] = (0x1C766000, 0x1000)
ata_fill_sg: PRD[61] = (0x1C719000, 0x1000)
ata_fill_sg: PRD[62] = (0x1C718000, 0x1000)
ata_fill_sg: PRD[63] = (0x1C6D2000, 0x1000)
ata_fill_sg: PRD[64] = (0x1BDF5000, 0x1000)
ata_fill_sg: PRD[65] = (0x1C6E9000, 0x2000)
ata_fill_sg: PRD[66] = (0x1BE70000, 0x1000)
ata_fill_sg: PRD[67] = (0x1BDF7000, 0x1000)
ata_fill_sg: PRD[68] = (0x1BE72000, 0x1000)
ata_fill_sg: PRD[69] = (0x1BE71000, 0x1000)
ata_fill_sg: PRD[70] = (0x1BE74000, 0x1000)
ata_fill_sg: PRD[71] = (0x1BE73000, 0x1000)
ata_fill_sg: PRD[72] = (0x1AF3C000, 0x1000)
ata_fill_sg: PRD[73] = (0x1AF43000, 0x1000)
ata_fill_sg: PRD[74] = (0x1B6E4000, 0x1000)
ata_fill_sg: PRD[75] = (0x1B6E3000, 0x1000)
ata_fill_sg: PRD[76] = (0x1B6E6000, 0x1000)
ata_fill_sg: PRD[77] = (0x1B7A2000, 0x1000)
ata_fill_sg: PRD[78] = (0x1B7A4000, 0x1000)
ata_fill_sg: PRD[79] = (0x1B678000, 0x1000)
ata_fill_sg: PRD[80] = (0x1B4C6000, 0x2000)
ata_fill_sg: PRD[81] = (0x1AEE4000, 0x1000)
ata_fill_sg: PRD[82] = (0x1B4F5000, 0x1000)
ata_fill_sg: PRD[83] = (0x1AF03000, 0x1000)
ata_fill_sg: PRD[84] = (0x1AEFC000, 0x1000)
ata_fill_sg: PRD[85] = (0x1B7A6000, 0x1000)
ata_fill_sg: PRD[86] = (0x1B0D5000, 0x1000)
ata_fill_sg: PRD[87] = (0x1B0D1000, 0x1000)
ata_fill_sg: PRD[88] = (0x1B118000, 0x1000)
ata_fill_sg: PRD[89] = (0x1B0D6000, 0x1000)
ata_fill_sg: PRD[90] = (0x1B11C000, 0x1000)
ata_fill_sg: PRD[91] = (0x1B11A000, 0x1000)
ata_fill_sg: PRD[92] = (0x1B11E000, 0x1000)
ata_fill_sg: PRD[93] = (0x1B0D2000, 0x1000)
ata_fill_sg: PRD[94] = (0x1AF21000, 0x1000)
ata_fill_sg: PRD[95] = (0x1AF4F000, 0x1000)
ata_fill_sg: PRD[96] = (0x1AF4D000, 0x1000)
ata_fill_sg: PRD[97] = (0x1AFE8000, 0x1000)
ata_fill_sg: PRD[98] = (0x1AFEA000, 0x1000)
ata_fill_sg: PRD[99] = (0x1AA8C000, 0x1000)
ata_fill_sg: PRD[100] = (0x1A840000, 0x1000)
ata2: ata_dev_select: ENTER, device 0, wait 1
ata_tf_load: hob: feat 0x0 nsect 0x3, lba 0x0 0x0 0x0
ata_tf_load: feat 0x0 nsect 0x40 lba 0xAD 0x75 0xEC
ata_tf_load: device 0xE0
ata_exec_command: ata2: cmd 0x35
ata_scsi_translate: EXIT

ata_scsi_timed_out: ENTER
ata_scsi_timed_out: EXIT, ret=0
ata_scsi_error: ENTER
ata_port_flush_task: ENTER
ata_port_flush_task: flush #1
__ata_port_freeze: ata2 port frozen
ata_eh_autopsy: ENTER
ata_eh_autopsy: EXIT
ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x2 frozen ata2.00: cmd 35/00:40:ad:75:ec/00:03:00:00:00/e0 tag 0 cdb 0x0 data 425984 out

        res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)

ata_eh_recover: ENTER __ata_port_freeze: ata2 port frozen
ata2: soft resetting port

gshan

author

2008-10-24 06:32 UTC #15 lore raw

In reply to Tejun Heo

Hi Alan & Jeff,

I have being struggled for this issue for long time, but have no ideas finally. So I have to write mail to you for suggestions again. Thanks in advance for your reply since you're busy.

I'm using IDE driver instead of ATA driver for my PIIX4 IDE controller. The experiment
is: 1)mount local directory (/aaa on ramdisk) to remote server via NFS; 2)copy a big file (about 600MB) from remote server to local disk, finally DMA timeout happened.

When DMA timeout happened, I have dumped out PRD table as follows, it seems the PRD table doesn't have any problem. Note that pls swap bytes for PRD entries (from big endian to little endian).

SP(27-A) $ mount /dev/hda1 /disk_root/
kjournald starting. Commit interval 5 seconds
EXT3 FS on hda1, internal journal
EXT3-fs: mounted filesystem with ordered data mode. SP(27-A) $ cd /disk_root/
SP(27-A) $ cp /aaa/Gavin/sp3m/target_7xx_cge5.2008-07-10.tgz ./
hda: dma_timer_expiry: dma status == 0x21
========IDE Register DUmp========
DMA start sector: 0x00169657
DMA sectors : 0x0100
Data Reg : 0x06
Error Reg : 0x00
Nsector Reg : 0xd5
Sector Reg : 0x82
LCYL Reg : 0x96
HCYL Reg : 0x16
Select Reg : 0xe0
Status Reg : 0x5a
Control Reg : 0x58
IRQ Reg : 0xff
======Physical Region Descriptor=======
Base_PRD: 0x0fec5000 Current_PRD: 0x0fec5018 Entries:7

index=0  base=0x00d0661c lengh=0x00300000
index=1  base=0x0000671c lengh=0x00200000
index=2  base=0x0000691c lengh=0x00800000
index=3  base=0x0080691c lengh=0x00800000
index=4  base=0x00006a1c lengh=0x00300000
index=5  base=0x0040e21d lengh=0x00100000
index=6  base=0x00306a1c lengh=0x00700080

If possible, could you tell me how IDE complete DMA transfer on PCI bus?

Thanks,
Gavin