lists.openwall.net   lists  /  announce  owl-users  owl-dev  john-users  john-dev  passwdqc-users  yescrypt  popa3d-users  /  oss-security  kernel-hardening  musl  sabotage  tlsify  passwords  /  crypt-dev  xvendor  /  Bugtraq  Full-Disclosure  linux-kernel  linux-netdev  linux-ext4  linux-hardening  linux-cve-announce  PHC 
Open Source and information security mailing list archives
 
Hash Suite: Windows password security audit tool. GUI, reports in PDF.
[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Date:	Mon, 19 May 2008 21:50:47 +0200
From:	"Alessandro Suardi" <alessandro.suardi@...il.com>
To:	"Robert Hancock" <hancockr@...w.ca>
Cc:	"Jeff Garzik" <jgarzik@...ox.com>,
	LKML <linux-kernel@...r.kernel.org>
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@...w.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')

Download attachment "messages.gz" of type "application/x-gzip" (17483 bytes)

Powered by blists - more mailing lists

Powered by Openwall GNU/*/Linux Powered by OpenVZ