Messages in this thread | | | Date | Mon, 19 May 2008 21:50:47 +0200 | From | "Alessandro Suardi" <> | Subject | Re: SATA disk reports DRDY and goes to PIO0 eventually. noapic fixes it |
| |
On Mon, May 19, 2008 at 4:08 AM, Robert Hancock <hancockr@shaw.ca> wrote: > Alessandro Suardi wrote: >> >> Since some time I noticed my nephew's Fedora 8 box would have >> some noise in /var/log/messages with timeouts reported by the >> SATA layer, with the drive in DRDY state. Flux is like this (from >> the base Fedora 9 kernel installed today): >> >> May 17 17:18:39 rospo kernel: ata4.00: exception Emask 0x0 SAct 0x0 >> SErr 0x0 action 0x2 frozen >> May 17 17:18:39 rospo kernel: ata4.00: cmd >> a0/00:00:00:08:00/00:00:00:00:00/a0 tag 0 pio 16392 in >> May 17 17:18:39 rospo kernel: cdb 4a 01 00 00 10 00 00 00 08 >> 00 00 00 00 00 00 00 >> May 17 17:18:39 rospo kernel: res >> 40/00:03:00:00:00/00:00:00:00:00/a0 Emask 0x4 (timeout) >> May 17 17:18:39 rospo kernel: ata4.00: status: { DRDY } >> May 17 17:18:39 rospo kernel: ata4: soft resetting link >> May 17 17:18:39 rospo kernel: ata4.00: configured for UDMA/33 >> May 17 17:18:39 rospo kernel: ata4: EH complete >> May 17 17:18:40 rospo kernel: ALSA sound/usb/usbaudio.c:1353: setting >> usb interface 1:1 >> May 17 17:18:40 rospo kernel: ALSA sound/usb/usbaudio.c:1353: setting >> usb interface 1:1 >> May 17 17:18:46 rospo kernel: ata4.00: exception Emask 0x0 SAct 0x0 >> SErr 0x0 action 0x2 frozen >> May 17 17:18:46 rospo kernel: ata4.00: cmd >> a0/00:00:00:08:00/00:00:00:00:00/a0 tag 0 pio 16392 in >> May 17 17:18:46 rospo kernel: cdb 4a 01 00 00 10 00 00 00 08 >> 00 00 00 00 00 00 00 >> May 17 17:18:46 rospo kernel: res >> 40/00:03:00:00:00/00:00:00:00:00/a0 Emask 0x4 (timeout) >> May 17 17:18:46 rospo kernel: ata4.00: status: { DRDY } >> May 17 17:18:46 rospo kernel: ata4: soft resetting link >> May 17 17:18:46 rospo kernel: ata4.00: configured for UDMA/33 >> May 17 17:18:46 rospo kernel: ata4: EH complete >> May 17 17:18:53 rospo kernel: ata4.00: exception Emask 0x0 SAct 0x0 >> SErr 0x0 action 0x2 frozen >> May 17 17:18:53 rospo kernel: ata4.00: cmd >> a0/00:00:00:08:00/00:00:00:00:00/a0 tag 0 pio 16392 in >> May 17 17:18:53 rospo kernel: cdb 4a 01 00 00 10 00 00 00 08 >> 00 00 00 00 00 00 00 >> May 17 17:18:53 rospo kernel: res >> 40/00:03:00:00:00/00:00:00:00:00/a0 Emask 0x4 (timeout) >> May 17 17:18:53 rospo kernel: ata4.00: status: { DRDY } >> May 17 17:18:53 rospo kernel: ata4: soft resetting link >> May 17 17:18:54 rospo kernel: ata4.00: configured for UDMA/33 >> May 17 17:18:54 rospo kernel: ata4: EH complete >> May 17 17:19:01 rospo kernel: ata4.00: limiting speed to UDMA/25:PIO4 >> May 17 17:19:01 rospo kernel: ata4.00: exception Emask 0x0 SAct 0x0 >> SErr 0x0 action 0x2 frozen >> May 17 17:19:01 rospo kernel: ata4.00: cmd >> a0/00:00:00:08:00/00:00:00:00:00/a0 tag 0 pio 16392 in >> May 17 17:19:01 rospo kernel: cdb 4a 01 00 00 10 00 00 00 08 >> 00 00 00 00 00 00 00 >> May 17 17:19:01 rospo kernel: res >> 40/00:03:00:00:00/00:00:00:00:00/a0 Emask 0x4 (timeout) >> May 17 17:19:01 rospo kernel: ata4.00: status: { DRDY } >> May 17 17:19:01 rospo kernel: ata4: soft resetting link >> May 17 17:19:01 rospo kernel: ata4.00: configured for UDMA/25 >> May 17 17:19:01 rospo kernel: ata4: EH complete >> May 17 17:19:01 rospo kernel: sr0: CDROM (ioctl) error, command: Get >> event status notification 4a 01 00 00 10 00 00 00 08 00 >> May 17 17:19:01 rospo kernel: sr: Sense Key : Aborted Command >> [current] [descriptor] >> May 17 17:19:01 rospo kernel: sr: Add. Sense: No additional sense >> information >> May 17 17:19:06 rospo kernel: ALSA sound/usb/usbaudio.c:1353: setting >> usb interface 1:1 >> May 17 17:19:06 rospo kernel: ALSA sound/usb/usbaudio.c:1353: setting >> usb interface 1:1 >> May 17 17:19:11 rospo kernel: ata4.00: exception Emask 0x0 SAct 0x0 >> SErr 0x0 action 0x2 frozen >> May 17 17:19:11 rospo kernel: ata4.00: cmd >> a0/00:00:00:00:00/00:00:00:00:00/a0 tag 0 >> May 17 17:19:11 rospo kernel: cdb 1e 00 00 00 00 00 00 00 00 >> 00 00 00 00 00 00 00 >> May 17 17:19:11 rospo kernel: res >> 40/00:03:00:00:00/00:00:00:00:00/a0 Emask 0x4 (timeout) >> May 17 17:19:11 rospo kernel: ata4.00: status: { DRDY } >> May 17 17:19:11 rospo kernel: ata4: soft resetting link >> May 17 17:19:12 rospo kernel: ata4.00: configured for UDMA/25 >> May 17 17:19:12 rospo kernel: ata4: EH complete >> May 17 17:19:22 rospo kernel: ata4.00: limiting speed to PIO4 >> May 17 17:19:22 rospo kernel: ata4.00: exception Emask 0x0 SAct 0x0 >> SErr 0x0 action 0x2 frozen >> May 17 17:19:22 rospo kernel: ata4.00: cmd >> a0/00:00:00:00:00/00:00:00:00:00/a0 tag 0 >> May 17 17:19:22 rospo kernel: cdb 1e 00 00 00 00 00 00 00 00 >> 00 00 00 00 00 00 00 >> May 17 17:19:22 rospo kernel: res >> 40/00:03:00:00:00/00:00:00:00:00/a0 Emask 0x4 (timeout) >> May 17 17:19:22 rospo kernel: ata4.00: status: { DRDY } >> May 17 17:19:22 rospo kernel: ata4: soft resetting link >> May 17 17:19:22 rospo kernel: ata4.00: configured for PIO4 >> May 17 17:19:22 rospo kernel: ata4: EH complete >> May 17 17:19:32 rospo kernel: ata4.00: limiting speed to PIO3 >> May 17 17:19:32 rospo kernel: ata4.00: exception Emask 0x0 SAct 0x0 >> SErr 0x0 action 0x2 frozen >> May 17 17:19:32 rospo kernel: ata4.00: cmd >> a0/00:00:00:00:00/00:00:00:00:00/a0 tag 0 >> May 17 17:19:32 rospo kernel: cdb 1e 00 00 00 00 00 00 00 00 >> 00 00 00 00 00 00 00 >> May 17 17:19:32 rospo kernel: res >> 40/00:03:00:00:00/00:00:00:00:00/a0 Emask 0x4 (timeout) >> May 17 17:19:32 rospo kernel: ata4.00: status: { DRDY } >> May 17 17:19:32 rospo kernel: ata4: soft resetting link >> May 17 17:19:33 rospo kernel: ata4.00: configured for PIO3 >> May 17 17:19:33 rospo kernel: ata4: EH complete >> May 17 17:19:43 rospo kernel: ata4.00: limiting speed to PIO0 >> May 17 17:19:43 rospo kernel: ata4.00: exception Emask 0x0 SAct 0x0 >> SErr 0x0 action 0x2 frozen >> May 17 17:19:43 rospo kernel: ata4.00: cmd >> a0/00:00:00:00:00/00:00:00:00:00/a0 tag 0 >> May 17 17:19:43 rospo kernel: cdb 1e 00 00 00 00 00 00 00 00 >> 00 00 00 00 00 00 00 >> May 17 17:19:43 rospo kernel: res >> 40/00:03:00:00:00/00:00:00:00:00/a0 Emask 0x4 (timeout) >> May 17 17:19:43 rospo kernel: ata4.00: status: { DRDY } >> May 17 17:19:43 rospo kernel: ata4: soft resetting link >> May 17 17:19:43 rospo kernel: ata4.00: configured for PIO0 >> May 17 17:19:43 rospo kernel: ata4: EH complete >> May 17 17:19:50 rospo kernel: ALSA sound/usb/usbaudio.c:1353: setting >> usb interface 1:1 >> May 17 17:19:50 rospo kernel: ALSA sound/usb/usbaudio.c:1353: setting >> usb interface 1:1 >> May 17 17:19:53 rospo kernel: ata4.00: exception Emask 0x0 SAct 0x0 >> SErr 0x0 action 0x2 frozen >> May 17 17:19:53 rospo kernel: ata4.00: cmd >> a0/00:00:00:00:00/00:00:00:00:00/a0 tag 0 >> May 17 17:19:53 rospo kernel: cdb 1e 00 00 00 00 00 00 00 00 >> 00 00 00 00 00 00 00 >> May 17 17:19:53 rospo kernel: res >> 40/00:03:00:00:00/00:00:00:00:00/a0 Emask 0x4 (timeout) >> May 17 17:19:53 rospo kernel: ata4.00: status: { DRDY } >> May 17 17:19:53 rospo kernel: ata4: soft resetting link >> May 17 17:19:54 rospo kernel: ata4.00: configured for PIO0 >> May 17 17:19:54 rospo kernel: ata4: EH complete >> May 17 17:20:01 rospo kernel: ALSA sound/usb/usbaudio.c:1353: setting >> usb interface 1:1 >> May 17 17:20:04 rospo kernel: ata4.00: exception Emask 0x0 SAct 0x0 >> SErr 0x0 action 0x2 frozen >> May 17 17:20:04 rospo kernel: ata4.00: cmd >> a0/00:00:00:00:00/00:00:00:00:00/a0 tag 0 >> May 17 17:20:04 rospo kernel: cdb 1e 00 00 00 00 00 00 00 00 >> 00 00 00 00 00 00 00 >> May 17 17:20:04 rospo kernel: res >> 40/00:03:00:00:00/00:00:00:00:00/a0 Emask 0x4 (timeout) >> May 17 17:20:04 rospo kernel: ata4.00: status: { DRDY } >> May 17 17:20:04 rospo kernel: ata4: soft resetting link >> May 17 17:20:04 rospo kernel: ata4.00: configured for PIO0 >> May 17 17:20:04 rospo kernel: ata4: EH complete >> May 17 17:20:04 rospo kernel: sr 3:0:0:0: ioctl_internal_command >> return code = 8000002 >> May 17 17:20:04 rospo kernel: : Sense Key : Aborted Command >> [current] [descriptor] >> May 17 17:20:04 rospo kernel: : Add. Sense: No additional sense >> information >> May 17 17:20:34 rospo kernel: ata4.00: exception Emask 0x0 SAct 0x0 >> SErr 0x0 action 0x2 frozen >> May 17 17:20:34 rospo kernel: ata4.00: cmd >> a0/00:00:00:00:00/00:00:00:00:00/a0 tag 0 >> May 17 17:20:34 rospo kernel: cdb 00 00 00 00 00 00 00 00 00 >> 00 00 00 00 00 00 00 >> May 17 17:20:34 rospo kernel: res >> 40/00:03:00:00:00/00:00:00:00:00/a0 Emask 0x4 (timeout) >> May 17 17:20:34 rospo kernel: ata4.00: status: { DRDY } >> May 17 17:20:34 rospo kernel: ata4: soft resetting link >> May 17 17:20:35 rospo kernel: ata4.00: configured for PIO0 >> May 17 17:20:35 rospo kernel: ata4: EH complete >> >> ..and on and on and on. >> >> Reading another report on lkml I turned to the ATA wiki @ kernel.org >> today, as even the newest Fedora 9 update (2.6.25.3-18) was still >> behaving the same way - pci=nomsi wasn't useful, acpi=off was >> also not useful, noapic did instead get rid of the messages, even >> under 'find /' (which would usually turn up the ATA resets in less >> than 10 seconds). >> >> Is there anything more useful than simply booting noapic that >> can be done here, or is that it ? > > Please post the full dmesg output from bootup. We can't see what controller > type this is, etc.
Robert,
thanks for replying. Of course now that I look a bit more into the messages file, I notice that ATA 4.00 is the DVD drive, not the disk <blush>
Funny as there is nothing in the DVD drive... oh well.
/var/log/messages attached as a .gz file since I'm not sure it's small enough to avoid being bounced by vger.
thanks a lot,
--alessandro
"Give me love / Or give me hate Give me anything that's not just ok"
(Sophia, 'Weightless') [unhandled content-type:application/x-gzip] | |