Skip site navigation (1)Skip section navigation (2)
Date:      Sun, 26 Oct 2008 13:17:49 +0100
From:      "Marco Trillo" <marcotrillo@gmail.com>
To:        "FreeBSD PowerPC ML" <freebsd-ppc@freebsd.org>
Subject:   ATA DMA problems with recent -current
Message-ID:  <b9c23c9f0810260517j61587dc6gd91f35a49d4b9e38@mail.gmail.com>

next in thread | raw e-mail | index | archive | help
Hi all,

I just updated my -current kernel to today sources -- the previous
kernel was from Oct 11. With the new kernel I'm getting ad0 ATA DMA
timeouts, which get worse when I stress the drive.

The timeouts look like this:
ad0: TIMEOUT - READ_DMA retrying (1 retry left) LBA=3952128
ad0: TIMEOUT - READ_DMA retrying (0 retries left) LBA=3952128
ad0: FAILURE - READ_DMA timed out
g_vfs_done(): ad0s4 [READ(offset=1746108416, length=65536)] error=5
vnode_pager_getpages: I/O read error

At first, they are occasional and only happen sometimes -- in fact I
didn't notice them when booting the first time.
However, I then tried to unpack the ports.tar.gz file, like this:
$ gzcat ports.tar.gz | tar xf - -C /usr
... which, after unpacking a couple of files, hanged, getting
WRITE_DMA timeouts from the kernel.
All write attempts to the drive from that point failed. I rebooted the
system, and the filesystem appeared dirty to fsck the next boot.

Some information from the new kernel -- the full dmesg is at the end
of the message:

Copyright (c) 1992-2008 The FreeBSD Project.
Copyright (c) 1979, 1980, 1983, 1986, 1988, 1989, 1991, 1992, 1993, 1994
        The Regents of the University of California. All rights reserved.
FreeBSD is a registered trademark of The FreeBSD Foundation.
FreeBSD 8.0-CURRENT #57: Sun Oct 26 10:31:37 UTC 2008
    mtrillo@emac6:/usr/src/sys/powerpc/compile/GENERIC

$ dmesg | grep ata
ata0 mem 0x20000-0x20fff,0x8800-0x88ff irq 24,12 on macio0
ata0: [ITHREAD]
ata1: <Intrepid Kauai ATA Controller> mem 0xf5004000-0xf5007fff irq 39
at device 13.0 on pci2
ata1: [ITHREAD]
acd0: DVDR <HL-DT-ST RW/DVD GCC-4481B/2.05> at ata0-master WDMA2
ad0: 38166MB <Seagate ST340015A 3.01> at ata1-master UDMA100

$ vmstat -i
interrupt                          total       rate
irq1: pcm0                             1          0
irq61: pcm0                            1          0
irq24: ata0                           35          0
irq29: ohci0                           1          0
irq63: ohci1 ohci+                    59          0
irq39: ata1                          943          5
irq40: fwohci0                         2          0
irq41: gem0                          119          0
Total                               1161          6

In contrast, my previous kernel, compiled Oct 11, works perfectly with
ATA DMA. The same tests that fail badly on the new kernel (like
unpacking ports.tar.gz) complete without any problems on the Oct 11
kernel.

Some information from the Oct 11 kernel :

Copyright (c) 1992-2008 The FreeBSD Project.
Copyright (c) 1979, 1980, 1983, 1986, 1988, 1989, 1991, 1992, 1993, 1994
        The Regents of the University of California. All rights reserved.
FreeBSD is a registered trademark of The FreeBSD Foundation.
FreeBSD 8.0-CURRENT #56: Sat Oct 11 15:57:13 UTC 2008
    mtrillo@emac6:/usr/src/sys/powerpc/compile/GENERIC

$ dmesg | grep ata
ata0 mem 0x20000-0x20fff,0x8800-0x88ff irq 24,12 on macio0
ata0: [ITHREAD]
ata1: <Intrepid Kauai ATA Controller> mem 0xf5004000-0xf5007fff irq
39,1 at device 13.0 on pci2
ata1: [ITHREAD]
acd0: DVDR <HL-DT-ST RW/DVD GCC-4481B/2.05> at ata0-master WDMA2
ad0: 38166MB <Seagate ST340015A 3.01> at ata1-master UDMA100

$ vmstat -i
interrupt                          total       rate
irq1: pcm0                             1          0
irq61: pcm0                            1          0
irq24: ata0                           35          0
irq29: ohci2                           1          0
irq63: ohci3 ohci+                     6          0
irq39: ata1                          915         10
irq40: fwohci0                         2          0
irq41: gem0                          364          4
Total                               1325         15

Here is a full dmesg of the new kernel. In both this kernel and the
working Oct 11 kernel, my "aoa" driver for sound is enabled. This is
the only modification with respect to a CVS GENERIC kernel.

Oct 26 11:39:20 emac6 syslogd: kernel boot file is /boot/kernel/kernel
Oct 26 11:39:20 emac6 kernel: Copyright (c) 1992-2008 The FreeBSD Project.
Oct 26 11:39:20 emac6 kernel: Copyright (c) 1979, 1980, 1983, 1986,
1988, 1989, 1991, 1992, 1993, 1994
Oct 26 11:39:20 emac6 kernel: The Regents of the University of
California. All rights reserved.
Oct 26 11:39:20 emac6 kernel: FreeBSD is a registered trademark of The
FreeBSD Foundation.
Oct 26 11:39:20 emac6 kernel: FreeBSD 8.0-CURRENT #57: Sun Oct 26
10:31:37 UTC 2008
Oct 26 11:39:20 emac6 kernel: mtrillo@emac6:/usr/src/sys/powerpc/compile/GENERIC
Oct 26 11:39:20 emac6 kernel: WARNING: WITNESS option enabled, expect
reduced performance.
Oct 26 11:39:20 emac6 kernel: cpu0: Motorola PowerPC 7447A revision
1.1, 1250.00 MHz
Oct 26 11:39:20 emac6 kernel: cpu0: HID0
8450c0bc<EMCP,TBEN,NAP,DPM,ICE,DCE,SGE,BTIC,LRSTK,FOLD,BHT>
Oct 26 11:39:20 emac6 kernel: real memory  = 792965120 (756 MB)
Oct 26 11:39:20 emac6 kernel: avail memory = 762540032 (727 MB)
Oct 26 11:39:20 emac6 kernel: kbd0 at kbdmux0
Oct 26 11:39:20 emac6 kernel: nexus0: <Open Firmware Nexus device>
Oct 26 11:39:20 emac6 kernel: unin0: <Apple UniNorth System
Controller> on nexus0
Oct 26 11:39:20 emac6 kernel: unin0: Version 210
Oct 26 11:39:20 emac6 kernel: pcib0: <Apple UniNorth Host-PCI bridge> on nexus0
Oct 26 11:39:20 emac6 kernel: pci0: <OFW PCI bus> on pcib0
Oct 26 11:39:20 emac6 kernel: vgapci0: <VGA-compatible display> port
0x400-0x4ff mem 0x98000000-0x9fffffff,0x90000000-0x9000ffff irq 48 at
device 16.0 on pci0
Oct 26 11:39:20 emac6 kernel: pcib1: <Apple UniNorth Host-PCI bridge> on nexus0
Oct 26 11:39:20 emac6 kernel: pci1: <OFW PCI bus> on pcib1
Oct 26 11:39:20 emac6 kernel: macio0: <Intrepid I/O Controller> mem
0x80000000-0x8007ffff at device 23.0 on pci1
Oct 26 11:39:20 emac6 kernel: openpic0: <OpenPIC Interrupt Controller>
mem 0x40000-0x7ffff on macio0
Oct 26 11:39:20 emac6 kernel: scc0: <Zilog Z8530 dual channel SCC> mem
0x13000-0x13fff,0x8400-0x84ff,0x8500-0x85ff,0x8600-0x86ff,0x8700-0x87ff
irq 22,5,6,23,7,8 on macio0
Oct 26 11:39:20 emac6 kernel: scc0: [FILTER]
Oct 26 11:39:20 emac6 kernel: scc0: [FILTER]
Oct 26 11:39:20 emac6 kernel: uart0: <z8530, channel A> on scc0
Oct 26 11:39:20 emac6 kernel: uart0: [FILTER]
Oct 26 11:39:20 emac6 kernel: uart1: <z8530, channel B> on scc0
Oct 26 11:39:20 emac6 kernel: uart1: [FILTER]
Oct 26 11:39:20 emac6 kernel: pcm0: <i2s> mem
0x10000-0x10fff,0x8000-0x80ff,0x8100-0x81ff irq 30,1,2,31,3,4 on
macio0
Oct 26 11:39:20 emac6 kernel: interrupting at irq 1
Oct 26 11:39:20 emac6 kernel: pcm0: [ITHREAD]
Oct 26 11:39:20 emac6 kernel: GPIO <headphone-mute>: addr 0x6f
Oct 26 11:39:20 emac6 kernel: GPIO <amp-mute>: addr 0x70
Oct 26 11:39:20 emac6 kernel: GPIO <audio-hw-reset>: addr 0x75
Oct 26 11:39:20 emac6 kernel: interrupting at irq 61
Oct 26 11:39:20 emac6 kernel: pcm0: [ITHREAD]
Oct 26 11:39:20 emac6 kernel: GPIO <headphone-detect>: addr 0x67
Oct 26 11:39:20 emac6 kernel: enabled outputs: HEADPHONE
Oct 26 11:39:20 emac6 kernel: resetting codec
Oct 26 11:39:20 emac6 kernel: tumbler_write called without I2C?
Oct 26 11:39:20 emac6 kernel: pcm_getbuffersize returned 65536
Oct 26 11:39:20 emac6 kernel: aoa_dma_setprd: addr = 13434880, 32 slots
Oct 26 11:39:20 emac6 kernel: aoa_chan_setformat: format = 268435488
Oct 26 11:39:20 emac6 kernel: aoa_chan_setspeed: speed = 44100
Oct 26 11:39:20 emac6 kernel: aoa_chan_setformat: format = 268435488
Oct 26 11:39:20 emac6 kernel: aoa_chan_setblocksize: blocksz = 2048,
dma->blksz = 2048
Oct 26 11:39:20 emac6 kernel: aoa_chan_setspeed: speed = 44100
Oct 26 11:39:20 emac6 kernel: aoa_chan_setformat: format = 268435488
Oct 26 11:39:20 emac6 kernel: aoa_chan_setblocksize: blocksz = 2048,
dma->blksz = 2048
Oct 26 11:39:20 emac6 kernel: aoa_chan_setblocksize: blocksz = 2048,
dma->blksz = 2048
Oct 26 11:39:20 emac6 kernel: aoa_chan_setspeed: speed = 44100
Oct 26 11:39:20 emac6 kernel: aoa_chan_setformat: format = 268435488
Oct 26 11:39:20 emac6 kernel: aoa_chan_setblocksize: blocksz = 2048,
dma->blksz = 2048
Oct 26 11:39:20 emac6 kernel: kiic0: <Keywest I2C controller> mem
0x18000-0x18fff irq 26 on macio0
Oct 26 11:39:20 emac6 kernel: ata0 mem 0x20000-0x20fff,0x8800-0x88ff
irq 24,12 on macio0
Oct 26 11:39:20 emac6 kernel: ata0: [ITHREAD]
Oct 26 11:39:20 emac6 kernel: ohci0: <OHCI (generic) USB controller>
mem 0x80083000-0x80083fff irq 29 at device 26.0 on pci1
Oct 26 11:39:20 emac6 kernel: ohci0: [GIANT-LOCKED]
Oct 26 11:39:20 emac6 kernel: ohci0: [ITHREAD]
Oct 26 11:39:20 emac6 kernel: usb0: OHCI version 1.0, legacy support
Oct 26 11:39:20 emac6 kernel: usb0: <OHCI (generic) USB controller> on ohci0
Oct 26 11:39:20 emac6 kernel: usb0: USB revision 1.0
Oct 26 11:39:20 emac6 kernel: uhub0: <Apple OHCI root hub, class 9/0,
rev 1.00/1.00, addr 1> on usb0
Oct 26 11:39:20 emac6 kernel: uhub0: 2 ports with 2 removable, self powered
Oct 26 11:39:20 emac6 kernel: ohci1: <NEC uPD 9210 USB controller> mem
0x80082000-0x80082fff irq 63 at device 27.0 on pci1
Oct 26 11:39:20 emac6 kernel: ohci1: [GIANT-LOCKED]
Oct 26 11:39:20 emac6 kernel: ohci1: [ITHREAD]
Oct 26 11:39:20 emac6 kernel: usb1: OHCI version 1.0
Oct 26 11:39:20 emac6 kernel: usb1: <NEC uPD 9210 USB controller> on ohci1
Oct 26 11:39:20 emac6 kernel: usb1: USB revision 1.0
Oct 26 11:39:20 emac6 kernel: uhub1: <NEC OHCI root hub, class 9/0,
rev 1.00/1.00, addr 1> on usb1
Oct 26 11:39:20 emac6 kernel: uhub1: 3 ports with 3 removable, self powered
Oct 26 11:39:20 emac6 kernel: ohci2: <NEC uPD 9210 USB controller> mem
0x80081000-0x80081fff irq 63 at device 27.1 on pci1
Oct 26 11:39:20 emac6 kernel: ohci2: [GIANT-LOCKED]
Oct 26 11:39:20 emac6 kernel: ohci2: [ITHREAD]
Oct 26 11:39:20 emac6 kernel: usb2: OHCI version 1.0
Oct 26 11:39:20 emac6 kernel: usb2: <NEC uPD 9210 USB controller> on ohci2
Oct 26 11:39:20 emac6 kernel: usb2: USB revision 1.0
Oct 26 11:39:20 emac6 kernel: uhub2: <NEC OHCI root hub, class 9/0,
rev 1.00/1.00, addr 1> on usb2
Oct 26 11:39:20 emac6 kernel: uhub2: 2 ports with 2 removable, self powered
Oct 26 11:39:20 emac6 kernel: ehci0: <NEC uPD 720100 USB 2.0
controller> mem 0x80080000-0x800800ff irq 63 at device 27.2 on pci1
Oct 26 11:39:20 emac6 kernel: ehci0: [GIANT-LOCKED]
Oct 26 11:39:20 emac6 kernel: ehci0: [ITHREAD]
Oct 26 11:39:20 emac6 kernel: usb3: EHCI version 1.0
Oct 26 11:39:20 emac6 kernel: usb3: companion controllers, 3 ports
each: usb1 usb2
Oct 26 11:39:20 emac6 kernel: usb3: <NEC uPD 720100 USB 2.0 controller> on ehci0
Oct 26 11:39:20 emac6 kernel: usb3: USB revision 2.0
Oct 26 11:39:20 emac6 kernel: uhub3: <NEC EHCI root hub, class 9/0,
rev 2.00/1.00, addr 1> on usb3
Oct 26 11:39:20 emac6 kernel: uhub3: 5 ports with 5 removable, self powered
Oct 26 11:39:20 emac6 kernel: pcib2: <Apple UniNorth Host-PCI bridge> on nexus0
Oct 26 11:39:20 emac6 kernel: pci2: <OFW PCI bus> on pcib2
Oct 26 11:39:20 emac6 kernel: ata1: <Intrepid Kauai ATA Controller>
mem 0xf5004000-0xf5007fff irq 39 at device 13.0 on pci2
Oct 26 11:39:20 emac6 kernel: ata1: [ITHREAD]
Oct 26 11:39:20 emac6 kernel: fwohci0: <Apple UniNorth> mem
0xf5000000-0xf5000fff irq 40 at device 14.0 on pci2
Oct 26 11:39:20 emac6 kernel: fwohci0: [FILTER]
Oct 26 11:39:20 emac6 kernel: fwohci0: OHCI version 1.10 (ROM=0)
Oct 26 11:39:20 emac6 kernel: fwohci0: No. of Isochronous channels is 8.
Oct 26 11:39:20 emac6 kernel: fwohci0: EUI64 00:0d:93:ff:fe:57:39:60
Oct 26 11:39:20 emac6 kernel: fwohci0: Phy 1394a available S400, 2 ports.
Oct 26 11:39:20 emac6 kernel: fwohci0: Link S400, max_rec 2048 bytes.
Oct 26 11:39:20 emac6 kernel: firewire0: <IEEE1394(FireWire) bus> on fwohci0
Oct 26 11:39:20 emac6 kernel: fwe0: <Ethernet over FireWire> on firewire0
Oct 26 11:39:20 emac6 kernel: if_fwe0: Fake Ethernet address: 02:0d:93:57:39:60
Oct 26 11:39:20 emac6 kernel: fwe0: Ethernet address: 02:0d:93:57:39:60
Oct 26 11:39:20 emac6 kernel: sbp0: <SBP-2/SCSI over FireWire> on firewire0
Oct 26 11:39:20 emac6 kernel: fwohci0: Initiate bus reset
Oct 26 11:39:20 emac6 kernel: fwohci0: BUS reset
Oct 26 11:39:20 emac6 kernel: fwohci0: node_id=0xc800ffc0, gen=2,
CYCLEMASTER mode
Oct 26 11:39:20 emac6 kernel: gem0: <Apple UniNorth2 GMAC Ethernet>
mem 0xf5200000-0xf53fffff irq 41 at device 15.0 on pci2
Oct 26 11:39:20 emac6 kernel: miibus0: <MII bus> on gem0
Oct 26 11:39:20 emac6 kernel: bmtphy0: <BCM5221 10/100baseTX PHY> PHY
0 on miibus0
Oct 26 11:39:20 emac6 kernel: bmtphy0:  10baseT, 10baseT-FDX,
100baseTX, 100baseTX-FDX, auto
Oct 26 11:39:20 emac6 kernel: gem0: 10kB RX FIFO, 4kB TX FIFO
Oct 26 11:39:20 emac6 kernel: gem0: Ethernet address: 00:0d:93:57:39:60
Oct 26 11:39:20 emac6 kernel: gem0: [ITHREAD]
Oct 26 11:39:20 emac6 kernel: sc0: <System console> on nexus0
Oct 26 11:39:20 emac6 kernel: sc0: Unknown <16 virtual consoles, flags=0x300>
Oct 26 11:39:20 emac6 kernel: uhub4: <Mitsumi Electric Hub in Apple
Extended USB Keyboard, class 9/0, rev 1.10/4.10, addr 2> on uhub1
Oct 26 11:39:20 emac6 kernel: uhub4: 3 ports with 2 removable, bus powered
Oct 26 11:39:20 emac6 kernel: ums0: <Logitech Apple Optical USB Mouse,
class 0/0, rev 2.00/3.40, addr 3> on uhub4
Oct 26 11:39:20 emac6 kernel: ums0: 1 buttons.
Oct 26 11:39:20 emac6 kernel: ukbd0: <Mitsumi Electric Apple Extended
USB Keyboard, class 0/0, rev 1.10/4.10, addr 4> on uhub4
Oct 26 11:39:20 emac6 kernel: kbd1 at ukbd0
Oct 26 11:39:20 emac6 kernel: uhid0: <Mitsumi Electric Apple Extended
USB Keyboard, class 0/0, rev 1.10/4.10, addr 4> on uhub4
Oct 26 11:39:20 emac6 kernel: Timecounter "decrementer" frequency
41620997 Hz quality 0
Oct 26 11:39:20 emac6 kernel: Timecounters tick every 10.000 msec
Oct 26 11:39:20 emac6 kernel: firewire0: 1 nodes, maxhop <= 0, cable
IRM = 0 (me)
Oct 26 11:39:20 emac6 kernel: firewire0: bus manager 0 (me)
Oct 26 11:39:20 emac6 kernel: acd0: DVDR <HL-DT-ST RW/DVD
GCC-4481B/2.05> at ata0-master WDMA2
Oct 26 11:39:20 emac6 kernel: ad0: 38166MB <Seagate ST340015A 3.01> at
ata1-master UDMA100
Oct 26 11:39:20 emac6 kernel: pcm0: codec: <snapper> at address 6Ah on kiic0
Oct 26 11:39:20 emac6 kernel: WARNING: WITNESS option enabled, expect
reduced performance.
Oct 26 11:39:20 emac6 kernel: Trying to mount root from ufs:/dev/ad0s4
Oct 26 11:39:20 emac6 kernel: lock order reversal:
Oct 26 11:39:20 emac6 kernel: 1st 0xc41048 user map (user map) @
vm/vm_map.c:3115
Oct 26 11:39:20 emac6 kernel: 2nd 0xe1d7cc ufs (ufs) @ kern/vfs_subr.c:2049
Oct 26 11:39:20 emac6 kernel: KDB: stack backtrace:
Oct 26 11:39:20 emac6 kernel: 0xdebaf930: at kdb_backtrace+0x4c
Oct 26 11:39:20 emac6 kernel: 0xdebaf950: at _witness_debugger+0x3c
Oct 26 11:39:20 emac6 kernel: 0xdebaf970: at witness_checkorder+0x8d0
Oct 26 11:39:20 emac6 kernel: 0xdebaf9d0: at __lockmgr_args+0x23c
Oct 26 11:39:20 emac6 kernel: 0xdebafa50: at ffs_lock+0x9c
Oct 26 11:39:20 emac6 kernel: 0xdebafa80: at VOP_LOCK1_APV+0xec
Oct 26 11:39:20 emac6 kernel: 0xdebafaa0: at _vn_lock+0x84
Oct 26 11:39:20 emac6 kernel: 0xdebafaf0: at vget+0xdc
Oct 26 11:39:20 emac6 kernel: 0xdebafb30: at vnode_pager_lock+0x20c
Oct 26 11:39:20 emac6 kernel: 0xdebafb90: at vm_fault+0x218
Oct 26 11:39:20 emac6 kernel: 0xdebafca0: at trap_pfault+0x128
Oct 26 11:39:20 emac6 kernel: 0xdebafce0: at trap+0x1ac
Oct 26 11:39:20 emac6 kernel: 0xdebafda0: at powerpc_interrupt+0x15c
Oct 26 11:39:20 emac6 kernel: 0xdebafdd0: user ISI trap by 0x1815a04:
srr1=0x4000d032
Oct 26 11:39:20 emac6 kernel: r1=0x7fffdee0 cr=0x24000048 xer=0 ctr=0
Oct 26 11:39:20 emac6 root: /etc/rc: WARNING: Dump device does not
exist.  Savecore not run.
Oct 26 11:39:27 emac6 kernel: ad0: TIMEOUT - READ_DMA retrying (1
retry left) LBA=3950368
Oct 26 11:39:37 emac6 kernel: ad0: TIMEOUT - READ_DMA retrying (0
retries left) LBA=3950368
Oct 26 11:39:37 emac6 kernel: ad0: FAILURE - READ_DMA timed out LBA=3950368
Oct 26 11:39:37 emac6 kernel:
g_vfs_done():ad0s4[READ(offset=1745207296, length=114688)]error = 5

Thanks!

Marco



Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?b9c23c9f0810260517j61587dc6gd91f35a49d4b9e38>