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>