ad0: TIMEOUT - READ_DMA retrying ... on a 5.4-RELEASE system

[Dr. Gary E. RAFE]

I had a bit of a scare last week when my
Toshiba Satellite Pro 6100 running 5.4-RELEASE
(since May 2005 without any major difficulties)
resumed from an APM suspend with some odd disk
behavior, and the rather scary error message:
"ad0: TIMEOUT - READ_DMA retrying (2 retries left) LBA=12578911".

Relevent messages from /var/log/message follow:

[Power button actuated following overnight APM suspend]
Jan 17 09:16:56 MyHost kernel: pir0: ROUTE_INTERRUPT on resume for link 0x62 failed.
Jan 17 09:16:56 MyHost kernel: pir0: ROUTE_INTERRUPT on resume for link 0x61 failed.
Jan 17 09:16:56 MyHost kernel: pir0: ROUTE_INTERRUPT on resume for link 0x63 failed.
Jan 17 09:16:56 MyHost kernel: wakeup from sleeping state (slept 08:22:31)
Jan 17 09:16:55 MyHost apmd[324]: apmevent 0003 index 24
Jan 17 09:17:05 MyHost kernel: ad0: TIMEOUT - READ_DMA retrying (2 retries left) LBA=12578911
Jan 17 09:17:05 MyHost apmd: resumed at 20060117 09:17:05
Jan 17 09:17:05 MyHost kernel: uhci0: <Intel 82801CA/CAM (ICH3) USB controller USB-A> port 0xefe0-0xefff irq 11 at device 29.0 on pci0
Jan 17 09:17:05 MyHost kernel: usb0: <Intel 82801CA/CAM (ICH3) USB controller USB-A> on uhci0
Jan 17 09:17:05 MyHost kernel: usb0: USB revision 1.0
Jan 17 09:17:05 MyHost kernel: uhub0: Intel UHCI root hub, class 9/0, rev 1.00/1.00, addr 1
Jan 17 09:17:05 MyHost kernel: uhub0: 2 ports with 2 removable, self powered  
Jan 17 09:17:06 MyHost kernel: uhci1: <Intel 82801CA/CAM (ICH3) USB controller USB-B> port 0xef80-0xef9f irq 11 at device 29.1 on pci0
Jan 17 09:17:06 MyHost kernel: usb1: <Intel 82801CA/CAM (ICH3) USB controller USB-B> on uhci1
Jan 17 09:17:06 MyHost kernel: usb1: USB revision 1.0
Jan 17 09:17:06 MyHost kernel: uhub1: Intel UHCI root hub, class 9/0, rev 1.00/1.00, addr 1
Jan 17 09:17:06 MyHost kernel: uhub1: 2 ports with 2 removable, self powered  
Jan 17 09:17:06 MyHost kernel: uhci2: <Intel 82801CA/CAM (ICH3) USB controller USB-C> port 0xef60-0xef7f irq 11 at device 29.2 on pci0
Jan 17 09:17:06 MyHost kernel: usb2: <Intel 82801CA/CAM (ICH3) USB controller USB-C> on uhci2
Jan 17 09:17:06 MyHost kernel: usb2: USB revision 1.0
Jan 17 09:17:06 MyHost kernel: uhub2: Intel UHCI root hub, class 9/0, rev 1.00/1.00, addr 1
Jan 17 09:17:06 MyHost kernel: uhub2: 2 ports with 2 removable, self powered
Jan 17 09:17:08 MyHost kernel: uhub3: Atmel Standard USB Hub, class 9/0, rev 1.10/3.00, addr 2
Jan 17 09:17:08 MyHost kernel: uhub3: 4 ports with 4 removable, bus powered
Jan 17 09:17:09 MyHost kernel: ums0: Logitech USB-PS/2 Optical Mouse, rev 2.00/11.10, addr 3, iclass 3/1
Jan 17 09:17:09 MyHost kernel: ums0: 3 buttons and Z dir.
Jan 17 09:17:24 MyHost kernel: ad0: TIMEOUT - READ_DMA retrying (2 retries left) LBA=52265546
Jan 17 09:17:24 MyHost kernel: ad0: TIMEOUT - READ_DMA retrying (1 retry left) LBA=52265546
Jan 17 09:17:24 MyHost kernel: ad0: FAILURE - READ_DMA timed out
Jan 17 09:18:56 MyHost kernel: ad0: TIMEOUT - READ_DMA retrying (2 retries left) LBA=53769542
Jan 17 09:19:06 MyHost kernel: ad0: TIMEOUT - READ_DMA retrying (1 retry left) LBA=53769542
Jan 17 09:19:06 MyHost kernel: ad0: FAILURE - READ_DMA timed out
...

When the system was "stable",
I ran "shutdown -p now" for a hard boot.
Subsequent /var/log/messages from this boot follow:

Jan 17 09:21:34 MyHost syslogd: kernel boot file is /boot/kernel/kernel
Jan 17 09:21:34 MyHost kernel: Copyright (c) 1992-2005 The FreeBSD Project.
Jan 17 09:21:34 MyHost kernel: Copyright (c) 1979, 1980, 1983, 1986, 1988, 1989, 1991, 1992, 1993, 1994
Jan 17 09:21:34 MyHost kernel: The Regents of the University of California. All rights reserved.
Jan 17 09:21:34 MyHost kernel: FreeBSD 5.4-RELEASE #6: Sat Dec 31 22:59:00 EST 2005
Jan 17 09:21:34 MyHost kernel: root at MyHost:/usr/src/sys/i386/compile/TSP6100B
Jan 17 09:21:34 MyHost kernel: Timecounter "i8254" frequency 1193182 Hz quality 0
Jan 17 09:21:34 MyHost kernel: CPU: Intel(R) Pentium(R) 4 Mobile CPU 2.00GHz (1993.54-MHz 686-class CPU)
Jan 17 09:21:34 MyHost kernel: Origin = "GenuineIntel"  Id = 0xf24  Stepping = 4
Jan 17 09:21:34 MyHost kernel: Features=0x3febf9ff<FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CLFLUSH,DTS,ACPI,MMX,FXSR,SSE,SSE2,SS,HT
T,TM>
Jan 17 09:21:34 MyHost kernel: real memory  = 536084480 (511 MB)
Jan 17 09:21:34 MyHost kernel: avail memory = 519127040 (495 MB)
Jan 17 09:21:34 MyHost kernel: npx0: <math processor> on motherboard
Jan 17 09:21:34 MyHost kernel: npx0: INT 16 interface
Jan 17 09:21:34 MyHost kernel: cpu0 on motherboard
Jan 17 09:21:34 MyHost kernel: apm0: <APM BIOS> on motherboard
Jan 17 09:21:34 MyHost kernel: apm0: found APM BIOS v1.2, connected at v1.2
Jan 17 09:21:34 MyHost kernel: pcib0: <Host to PCI bridge> pcibus 0 on motherboard
Jan 17 09:21:34 MyHost kernel: pir0: <PCI Interrupt Routing Table: 7 Entries> on motherboard
Jan 17 09:21:34 MyHost kernel: pci0: <PCI bus> on pcib0
Jan 17 09:21:34 MyHost kernel: pcib1: <PCIBIOS PCI-PCI bridge> at device 1.0 on pci0
Jan 17 09:21:34 MyHost kernel: pci1: <PCI bus> on pcib1
Jan 17 09:21:34 MyHost kernel: pci1: <display, VGA> at device 0.0 (no driver attached)
Jan 17 09:21:34 MyHost kernel: pci0: <serial bus, USB> at device 29.0 (no driver attached)
Jan 17 09:21:34 MyHost kernel: pci0: <serial bus, USB> at device 29.1 (no driver attached)
Jan 17 09:21:34 MyHost kernel: pci0: <serial bus, USB> at device 29.2 (no driver attached)
Jan 17 09:21:34 MyHost kernel: pcib2: <PCIBIOS PCI-PCI bridge> at device 30.0 on pci0
Jan 17 09:21:34 MyHost kernel: pci2: <PCI bus> on pcib2
Jan 17 09:21:34 MyHost kernel: fxp0: <Intel 82801CAM (ICH3) Pro/100 VE Ethernet> port 0xdf40-0xdf7f mem 0xfceff000-0xfcefffff irq 11 at device 8.0 on pci2
Jan 17 09:21:34 MyHost kernel: miibus0: <MII bus> on fxp0
Jan 17 09:21:34 MyHost kernel: inphy0: <i82562ET 10/100 media interface> on miibus0
Jan 17 09:21:34 MyHost kernel: inphy0:  10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, auto
Jan 17 09:21:34 MyHost kernel: fxp0: Ethernet address: 00:00:39:xx:xx:xx
Jan 17 09:21:34 MyHost kernel: wi0: <Intersil Prism2.5> mem 0xdbdff000-0xdbdfffff irq 11 at device 10.0 on pci2
Jan 17 09:21:34 MyHost kernel: wi0: using RF:PRISM2.5 MAC:ISL3874A(Mini-PCI)
Jan 17 09:21:34 MyHost kernel: wi0: Intersil Firmware: Primary (1.1.0), Station (1.4.9)
Jan 17 09:21:34 MyHost kernel: wi0: Ethernet address: 00:02:6f:xx:xx:xx
Jan 17 09:21:34 MyHost kernel: wi0: 11b rates: 1Mbps 2Mbps 5.5Mbps 11Mbps
Jan 17 09:21:34 MyHost kernel: cbb0: <ToPIC95B PCI-CardBus Bridge> irq 11 at device 11.0 on pci2
Jan 17 09:21:34 MyHost kernel: cardbus0: <CardBus bus> on cbb0
Jan 17 09:21:34 MyHost kernel: pccard0: <16-bit PCCard bus> on cbb0
Jan 17 09:21:34 MyHost kernel: cbb1: <ToPIC95B PCI-CardBus Bridge> irq 11 at device 11.1 on pci2
Jan 17 09:21:34 MyHost kernel: cardbus1: <CardBus bus> on cbb1
Jan 17 09:21:34 MyHost kernel: pccard1: <16-bit PCCard bus> on cbb1
Jan 17 09:21:34 MyHost kernel: pci2: <base peripheral> at device 13.0 (no driver attached)
Jan 17 09:21:34 MyHost kernel: isab0: <PCI-ISA bridge> at device 31.0 on pci0
Jan 17 09:21:34 MyHost kernel: isa0: <ISA bus> on isab0
Jan 17 09:21:34 MyHost kernel: atapci0: <Intel ICH3 UDMA100 controller> port 0xcfa0-0xcfaf,0x376,0x170-0x177,0x3f6,0x1f0-0x1f7 irq 11 at device 31.1 on pci0
Jan 17 09:21:34 MyHost kernel: ata0: channel #0 on atapci0
Jan 17 09:21:34 MyHost kernel: ata1: channel #1 on atapci0
Jan 17 09:21:34 MyHost kernel: pcm0: <Intel ICH3 (82801CA)> port 0xcdc0-0xcdff,0xce00-0xceff irq 11 at device 31.5 on pci0
Jan 17 09:21:34 MyHost kernel: pcm0: <Yamaha YMF753 AC97 Codec>
Jan 17 09:21:34 MyHost kernel: pci0: <simple comms, generic modem> at device 31.6 (no driver attached)
Jan 17 09:21:34 MyHost kernel: orm0: <ISA Option ROMs> at iomem 0xe0000-0xeffff,0xc0000-0xcffff on isa0
Jan 17 09:21:34 MyHost kernel: pmtimer0 on isa0
Jan 17 09:21:34 MyHost kernel: atkbdc0: <Keyboard controller (i8042)> at port 0x64,0x60 on isa0
Jan 17 09:21:34 MyHost kernel: atkbd0: <AT Keyboard> irq 1 on atkbdc0
Jan 17 09:21:34 MyHost kernel: kbd0 at atkbd0
Jan 17 09:21:34 MyHost kernel: psm0: <PS/2 Mouse> irq 12 on atkbdc0
Jan 17 09:21:34 MyHost kernel: psm0: model IntelliMouse, device ID 3
Jan 17 09:21:34 MyHost kernel: sc0: <System console> at flags 0x100 on isa0
Jan 17 09:21:34 MyHost kernel: sc0: VGA <16 virtual consoles, flags=0x300>
Jan 17 09:21:34 MyHost kernel: sio0 at port 0x3f8-0x3ff irq 4 flags 0x10 on isa0
Jan 17 09:21:34 MyHost kernel: sio0: type 16550A
Jan 17 09:21:34 MyHost kernel: vga0: <Generic ISA VGA> at port 0x3c0-0x3df iomem 0xa0000-0xbffff on isa0
Jan 17 09:21:34 MyHost kernel: unknown: <PNP0c01> can't assign resources (memory)
Jan 17 09:21:34 MyHost kernel: speaker0: <PC speaker> at port 0x61 on isa0
Jan 17 09:21:34 MyHost kernel: unknown: <PNP0303> can't assign resources (port)
Jan 17 09:21:34 MyHost kernel: unknown: <PNP0f13> can't assign resources (irq)
Jan 17 09:21:34 MyHost kernel: unknown: <PNP0501> can't assign resources (port)
Jan 17 09:21:34 MyHost kernel: Timecounters tick every 10.000 msec
Jan 17 09:21:34 MyHost kernel: ad0: 57231MB <TOSHIBA MK6021GAS/GA023A> [116280/16/63] at ata0-master UDMA100
Jan 17 09:21:34 MyHost kernel: acd0: CDRW <DW-28E/7.0A> at ata1-master PIO4
Jan 17 09:21:34 MyHost kernel: cd0 at ata1 bus 0 target 0 lun 0
Jan 17 09:21:34 MyHost kernel: cd0: <TEAC DW-28E 7.0A> Removable CD-ROM SCSI-0 device
Jan 17 09:21:34 MyHost kernel: cd0: 16.000MB/s transfers
Jan 17 09:21:34 MyHost kernel: cd0: Attempt to query device size failed: NOT READY, Medium not present
Jan 17 09:21:34 MyHost kernel: Mounting root from ufs:/dev/ad0s3a
Jan 17 09:21:35 MyHost apmd[319]: start
Jan 17 09:21:36 MyHost kernel: uhci0: <Intel 82801CA/CAM (ICH3) USB controller USB-A> port 0xefe0-0xefff irq 11 at device 29.0 on pci0
Jan 17 09:21:36 MyHost kernel: usb0: <Intel 82801CA/CAM (ICH3) USB controller USB-A> on uhci0
Jan 17 09:21:36 MyHost kernel: usb0: USB revision 1.0
Jan 17 09:21:36 MyHost kernel: uhub0: Intel UHCI root hub, class 9/0, rev 1.00/1.00, addr 1
Jan 17 09:21:36 MyHost kernel: uhub0: 2 ports with 2 removable, self powered
Jan 17 09:21:37 MyHost kernel: uhci1: <Intel 82801CA/CAM (ICH3) USB controller USB-B> port 0xef80-0xef9f irq 11 at device 29.1 on pci0
Jan 17 09:21:37 MyHost kernel: usb1: <Intel 82801CA/CAM (ICH3) USB controller USB-B> on uhci1
Jan 17 09:21:37 MyHost kernel: usb1: USB revision 1.0
Jan 17 09:21:37 MyHost kernel: uhub1: Intel UHCI root hub, class 9/0, rev 1.00/1.00, addr 1
Jan 17 09:21:37 MyHost kernel: uhub1: 2 ports with 2 removable, self powered
Jan 17 09:21:37 MyHost kernel: uhci2: <Intel 82801CA/CAM (ICH3) USB controller USB-C> port 0xef60-0xef7f irq 11 at device 29.2 on pci0
Jan 17 09:21:37 MyHost kernel: usb2: <Intel 82801CA/CAM (ICH3) USB controller USB-C> on uhci2
Jan 17 09:21:37 MyHost kernel: usb2: USB revision 1.0
Jan 17 09:21:37 MyHost kernel: uhub2: Intel UHCI root hub, class 9/0, rev 1.00/1.00, addr 1
Jan 17 09:21:37 MyHost kernel: uhub2: 2 ports with 2 removable, self powered
Jan 17 09:21:39 MyHost kernel: uhub3: Atmel Standard USB Hub, class 9/0, rev 1.10/3.00, addr 2
Jan 17 09:21:39 MyHost kernel: uhub3: 4 ports with 4 removable, bus powered
Jan 17 09:21:40 MyHost kernel: ums0: Logitech USB-PS/2 Optical Mouse, rev 2.00/11.10, addr 3, iclass 3/1
Jan 17 09:21:40 MyHost kernel: ums0: 3 buttons and Z dir.
Jan 17 09:22:12 MyHost kernel: ad0: TIMEOUT - READ_DMA retrying (2 retries left) LBA=50817898
Jan 17 09:22:36 MyHost kernel: ad0: TIMEOUT - READ_DMA retrying (2 retries left) LBA=50819690
Jan 17 09:22:36 MyHost kernel: ad0: TIMEOUT - READ_DMA retrying (1 retry left) LBA=50817898
Jan 17 09:22:36 MyHost kernel: ad0: TIMEOUT - READ_DMA retrying (1 retry left) LBA=50819690
Jan 17 09:22:36 MyHost kernel: ad0: FAILURE - READ_DMA timed out
Jan 17 09:22:43 MyHost kernel: ad0: TIMEOUT - READ_DMA retrying (2 retries left) LBA=50807210
Jan 17 09:22:53 MyHost kernel: ad0: TIMEOUT - READ_DMA retrying (2 retries left) LBA=50803050
Jan 17 09:23:02 MyHost kernel: ad0: TIMEOUT - READ_DMA retrying (2 retries left) LBA=50803082
Jan 17 09:23:22 MyHost kernel: ad0: TIMEOUT - READ_DMA retrying (2 retries left) LBA=54088010
Jan 17 09:23:32 MyHost kernel: ad0: TIMEOUT - READ_DMA retrying (1 retry left) LBA=54088010
Jan 17 09:23:32 MyHost kernel: ad0: FAILURE - READ_DMA timed out
Jan 17 09:23:39 MyHost kernel: ad0: TIMEOUT - READ_DMA retrying (2 retries left) LBA=54088130
Jan 17 09:23:44 MyHost kernel: ad0: TIMEOUT - READ_DMA retrying (2 retries left) LBA=54087850
Jan 17 09:24:08 MyHost login: ROOT LOGIN (root) ON ttyv0
Jan 17 09:28:32 MyHost kernel: ad0: TIMEOUT - READ_DMA retrying (2 retries left) LBA=99169729
[system suspended here with "apm -z"]

The "ad0: TIMEOUT - READ_DMA retrying" errors came back
following a reboot later that evening.

Since then, the system has behaved more-or-less flawlessly,
as though nothing had happened...

I'm at a loss to explain what might have happened.

If anyone can offer any insight into this
(sporadic hiccough, impending hardware failure, etc.),
I, and possibly other list readers, will be grateful.
--
Dr Gary E RAFE: drgerlists at gmail dot com