Bug 7460

Created attachment 9404 [details]
dmesg

full dmesg output

changing subject cause same problem exists for Audio CD's also

Created attachment 9412 [details]
dmesg_with_audio_cd

Just dropping a note that most distributions are affected by this, as they are
all kernel 2.6.18. I have confirmed this on Slackware 11 (2.6.18 kernel), Fedora
Core 6, and openSUSE 10.2. All of them give the same error messages:

hdc: command error: status=0x51 { DriveReady SeekComplete Error }
hdc: command error: error=0x54 { AbortedCommand LastFailedSense=0x05 }
ide: failed opcode was: unknown
ATAPI device hdc:
  Error: Illegal request -- (Sense key=0x05)
  Illegal mode for this track or incompatible medium -- (asc=0x64, ascq=0x00)
  The failed "Read 10" packet command was: 
  "28 00 00 00 73 f2 00 00 01 00 00 00 00 00 00 00 "
end_request: I/O error, dev hdc, sector 118728
Buffer I/O error on device hdc, logical block 29682
hdc: command error: status=0x51 { DriveReady SeekComplete Error }
hdc: command error: error=0x54 { AbortedCommand LastFailedSense=0x05 }
ide: failed opcode was: unknown
ATAPI device hdc:
  Error: Illegal request -- (Sense key=0x05)
  Illegal mode for this track or incompatible medium -- (asc=0x64, ascq=0x00)
  The failed "Read 10" packet command was: 
  "28 00 00 00 73 f3 00 00 03 00 00 00 00 00 00 00 "
end_request: I/O error, dev hdc, sector 118732
Buffer I/O error on device hdc, logical block 29683
Buffer I/O error on device hdc, logical block 29684
Buffer I/O error on device hdc, logical block 29685
hdc: command error: status=0x51 { DriveReady SeekComplete Error }
hdc: command error: error=0x54 { AbortedCommand LastFailedSense=0x05 }
ide: failed opcode was: unknown
ATAPI device hdc:
  Error: Illegal request -- (Sense key=0x05)
  Illegal mode for this track or incompatible medium -- (asc=0x64, ascq=0x00)
  The failed "Read 10" packet command was: 
  "28 00 00 00 73 f2 00 00 02 00 00 00 00 00 00 00 "
end_request: I/O error, dev hdc, sector 118728
Buffer I/O error on device hdc, logical block 29682
Buffer I/O error on device hdc, logical block 29683
hdc: command error: status=0x51 { DriveReady SeekComplete Error }
hdc: command error: error=0x54 { AbortedCommand LastFailedSense=0x05 }
ide: failed opcode was: unknown
ATAPI device hdc:
  Error: Illegal request -- (Sense key=0x05)
  Illegal mode for this track or incompatible medium -- (asc=0x64, ascq=0x00)
  The failed "Read 10" packet command was: 
  "28 00 00 00 73 f2 00 00 02 00 00 00 00 00 00 00 "
end_request: I/O error, dev hdc, sector 118728
Buffer I/O error on device hdc, logical block 29682
Buffer I/O error on device hdc, logical block 29683
hdc: command error: status=0x51 { DriveReady SeekComplete Error }
hdc: command error: error=0x54 { AbortedCommand LastFailedSense=0x05 }

2.6.16 was the last kernel where this error did not occur. Have confirmed by
downgrading to 2.6.16.23 on Slackware 11. 

2.6.16 just forgets to print error messages when it should some of the time.
This is a user space bug. The error reporting fix is merely showing it up

Confirmed with 2.6.18, also applies on DVDs.

hdc: media error (bad sector): status=0x51 { DriveReady SeekComplete Error }
hdc: media error (bad sector): error=0x34 { AbortedCommand LastFailedSense=0x03 }
ide: failed opcode was: unknown
ATAPI device hdc:
  Error: Medium error -- (Sense key=0x03)
  Unrecovered read error -- (asc=0x11, ascq=0x00)
  The failed "Read 10" packet command was: 
  "28 00 00 08 04 b8 00 00 40 00 00 00 00 00 00 00 "
end_request: I/O error, dev hdc, sector 2101984
Buffer I/O error on device hdc, logical block 262748
Buffer I/O error on device hdc, logical block 262749
Buffer I/O error on device hdc, logical block 262750
Buffer I/O error on device hdc, logical block 262751
Buffer I/O error on device hdc, logical block 262752

I have been experiencing this bug for more than a 
year, any chance that this one is going to fixed in the foreseeable future?

Victor your report is different:

  Error: Medium error -- (Sense key=0x03)
  Unrecovered read error -- (asc=0x11, ascq=0x00)
  The failed "Read 10" packet command was: 
  "28 00 00 08 04 b8 00 00 40 00 00 00 00 00 00 00 "

"Unrecovered read error" is a dud disk or a dying drive. May just need cleaning,
but its the drive saying "Hey I can't read this", not an OS issue or any other
interaction.

I'm seeing this with a DVD as well on the Fedora version of 2.6.18
(2.6.18-1.2849.fc6):

hdb: command error: status=0x51 { DriveReady SeekComplete Error }
hdb: command error: error=0x50 { LastFailedSense=0x05 }
ide: failed opcode was: unknown
ATAPI device hdb:
  Error: Illegal request -- (Sense key=0x05)
  Illegal mode for this track or incompatible medium -- (asc=0x64, ascq=0x00)
  The failed "Read 10" packet command was: 
  "28 00 00 00 00 00 00 00 40 00 00 00 00 00 00 00 "
end_request: I/O error, dev hdb, sector 0
printk: 33 messages suppressed.
Buffer I/O error on device hdb, logical block 0
Buffer I/O error on device hdb, logical block 1
Buffer I/O error on device hdb, logical block 2
Buffer I/O error on device hdb, logical block 3
Buffer I/O error on device hdb, logical block 4
Buffer I/O error on device hdb, logical block 5
Buffer I/O error on device hdb, logical block 6
Buffer I/O error on device hdb, logical block 7
Buffer I/O error on device hdb, logical block 8
Buffer I/O error on device hdb, logical block 9

symptom is 'broken' read access to files the DVD.  I can get a directory listing
of it - the above happens when I try to read data from a file (cp, mplayer, dd,
etc.)   The last 2.6 kernel I can say actually worked was 2.6.9 - sorry,
probably not super helpful.  Hardware is:

ATIIXP: IDE controller at PCI slot 0000:00:14.1
hdb: HL-DT-STDVD-RAM GSA-H22N, ATAPI CD/DVD-ROM drive

I'm happy to post other config details if helpful.

Hi all,

OS: OpenSUSE 10.2

I'm new here and don't know if this is useful or not but here's my input:

It looks like I had the same issue with these errors but they only started
appearing after I backed up some work data to some DVD's and then tried to
verify the written data. Thats when i started seeing the following type of
errors in my dmesg and the DVD failed to mount.

----------------------------------------------
Apr 11 23:12:13 myones kernel: hdd: media error (bad sector): status=0x51 {
DriveReady SeekComplete Error }
Apr 11 23:12:13 myones kernel: hdd: media error (bad sector): error=0x30 {
LastFailedSense=0x03 }
Apr 11 23:12:13 myones kernel: ide: failed opcode was: unknown
Apr 11 23:12:13 myones kernel: ATAPI device hdd:
Apr 11 23:12:13 myones kernel:   Error: Medium error -- (Sense key=0x03)
Apr 11 23:12:13 myones kernel:   (reserved error code) -- (asc=0x11, ascq=0x05)
Apr 11 23:12:13 myones kernel:   The failed "Read 10" packet command was: 
Apr 11 23:12:13 myones kernel:   "28 00 00 00 00 00 00 00 02 00 00 00 00 00 00 00 "
Apr 11 23:12:13 myones kernel: end_request: I/O error, dev hdd, sector 0A
----------------------------
etc...

After creating about 5 coasters (or so I thought), I tried mounting the DVD
manually after the flood of messages stopped:

$mount -t iso9660 -v /dev/hdd tmp/workbackup
mount: block device /dev/hdd is write-protected, mounting read-only
/dev/hdd on /home/glagos/tmp/workbackup type iso9660 (ro)

and the following appeared in dmesg:
Apr 11 23:12:33 myones kernel: ISO 9660 Extensions: Microsoft Joliet Level 3
Apr 11 23:12:33 myones kernel: ISO 9660 Extensions: RRIP_1991A
---------------

A bit odd. I just burned a VCD using DeVeDe and when I tried loading it I got
the same type of errors again. The VCD played fine in our DVD player though.

BTW using "auto" as a parameter to mount also doesn't work. Same errors and
mount stops trying after a while:

(note I inserted the numbers!)
1.# mount -t auto -v /dev/hdd tmp/workbackup
2.mount: you didn't specify a filesystem type for /dev/hdd
3.       I will try all types mentioned in /etc/filesystems or /proc/filesystems
4.Trying vfat
5.mount: block device /dev/hdd is write-protected, mounting read-only
6.mount: you didn't specify a filesystem type for /dev/hdd
7.       I will try all types mentioned in /etc/filesystems or /proc/filesystems
8.Trying vfat
9.mount: /dev/hdd: can't read superblock
10.#

I was monitoring /var/log/messages with tail -f in a separate window and the
errors we all know and love appeared immediately after I pressed ENTER. dmesg
was flooded with a few hundred lines of errors (I wont quote them yet again) and
then stopped where line 2 and onwards appeared - it took ages before line 2
finally appeared.

Hope this helps somebody. :-)

Please disconsider my previous comment #8 for this bug as the root cause wound
up being a buggy Asus BIOS.  I was able to recable and re-jumper the drives into
an unorthodox but stable configuration based on others' similar experiences.

These problems with the dvd/cdrom media are present even in 2.6.21. The LiveDVD
that gives following errors was burnt with growisofs and the md5sum of the ISO
and the data on DVD were verified to be correct, meaning the burn was done fine.
Also note that the DVD boots fine. Commands like 'df', 'dir', 'fdisk' work fine.
And then, suddenly after a while they start giving read errors. And if I drop
caches enough number of times, I can run the commands fine again. Very funky stuff!!

--------------------------------------------------------------
May  9 17:45:55 livcd-amd-pc hdd: media error (bad sector):
status=0x51 { DriveReady SeekComplete Error }
May  9 17:45:55 livcd-amd-pc hdd: media error (bad sector): error=0x34
{ AbortedCommand LastFailedSense=0x03 }
May  9 17:45:55 livcd-amd-pc ide: failed opcode was: unknown
May  9 17:45:55 livcd-amd-pc ATAPI device hdd:
May  9 17:45:55 livcd-amd-pc Error: Medium error -- (Sense key=0x03)
May  9 17:45:55 livcd-amd-pc (reserved error code) -- (asc=0x02, ascq=0x00)
May  9 17:45:55 livcd-amd-pc The failed "Read 10" packet command was:
May  9 17:45:55 livcd-amd-pc "28 00 00 04 a9 ee 00 00 01 00 00 00 00 00 00 00 "
May  9 17:45:55 livcd-amd-pc end_request: I/O error, dev hdd, sector 1222584
May  9 17:45:55 livcd-amd-pc Buffer I/O error on device hdd, logical
block 305646

--------------------------------------------

The thing is that the sectors are readable. The commands which trigger
these have run during this session. And as you can see if I drop
caches enough number of times, I can eventually run the commands.

17:35:04 root@livcd-amd-pc /proc/sys/vm
# l /sbin/fdisk
/bin/ls: cannot access /sbin/fdisk: Input/output error

17:35:11 root@livcd-amd-pc /proc/sys/vm
# echo "3" > drop_caches

17:35:21 root@livcd-amd-pc /proc/sys/vm
# l /sbin/fdisk
-rwxr-xr-x 1 root root 76776 May  5 13:30 /sbin/fdisk*

17:47:48 root@livcd-amd-pc /proc/sys/vm
# top
-su: /usr/bin/top: Permission denied

17:47:56 root@livcd-amd-pc /proc/sys/vm
# echo "3" > drop_caches

17:48:06 root@livcd-amd-pc /proc/sys/vm
# dir
-su: /bin/more: Permission denied
-su: /bin/ls: Permission denied

17:48:10 root@livcd-amd-pc /proc/sys/vm
# echo "3" > drop_caches

17:48:12 root@livcd-amd-pc /proc/sys/vm
# echo "3" > drop_caches

17:48:59 root@livcd-amd-pc /proc/sys/vm
# echo "3" > drop_caches

17:49:01 root@livcd-amd-pc /proc/sys/vm
# dir
block_dump                 legacy_va_layout      page-cluster
dirty_background_ratio     lowmem_reserve_ratio  panic_on_oom
dirty_expire_centisecs     max_map_count         percpu_pagelist_fraction
dirty_ratio                min_free_kbytes       swappiness
dirty_writeback_centisecs  nr_pdflush_threads    vfs_cache_pressure
drop_caches                overcommit_memory
laptop_mode                overcommit_ratio

I also want to mention that it doesn't matter of I use the IDE driver (amd74xx)
or the new pata_amd driver (resulting in /dev/sr[01] for my drives), I
eventually see these errors.

cdrom/DVD read is broken for the longest time and nobody cares? ...:(

Almsot nobody is seeing these problems, half the stuff attached to this bug is a
"media error " trace which is a dud CD. Your system problem seems to be pretty
specific and I've seen only 2 or 3 other cases, all of which are fixed by
disabling HAL polling stuff in user space. I've passed those on to the HAL
package people and nothing has happened since. 

Talk to your distro people. Ask them how to disable HAL and see how the box then
behaves

I am running a livecd created by myself. No HALD is running. Even X is not
running. Just minimal stuff. And please read my comments again. You will find it
weird. There is something wrong in some layer in the kernel. The CD/DVD is not
DUD as you say. I have burned and verified the DVD using md5sum. It should not
happen that 'ls' works now and doesn't after some time because of bad sectors.
And suddenly works again.

I think I have figured the most likely explanation for this. It seems like linux
is doing some sort of readahead on the disc and hitting the bad sectors. It is
not very forgiving of the read errors. I know the written sectors (which have
valid data) are not bad because while burning I asked k3b to verify the data
written, and the disc doesn't give any problem in XP. I also verified that if I
filled the disc to full, Nero under xp couldn't verify the disc because it hit
read errors as well. I disabled the readahead (with either hdparm -a 0 /dev/hdd
or hdparm -A0 /dev/hdd), the errors are gone.

This clearly is a bug with readahead logic somewhere. Shouldn't the readahead be
limited by the actual size of the data on the disc, rather than the "128kb more
than the current location and whole 650MB is my playground", which may be
outside the 200MB that's written and verified? The thing with read errors is
that they put the drive in non-DMA mode after a while and slow down the whole
system. So, the readahead becomes a self-deprecating feature. 

The CD layer does issue reads only within the range of the CD device. That range
is imprecise for a CD-R or CD-RW by up to about 150K. When it gets an error near
the end of media it then (ide-scsi, and libata at least) trims the read back in
order to understand what really happened.

The only case it won't do this is if the medium error from the CD is wrong, and
the fact Nero in WinXP fails as you report makes it pretty clear the CD-ROM
drive is confusing things - probably by returning an invalid sense buffer:

What does the trace for a failure look like when using libata drivers instead of
ide-cd

Devsk, PING.

Apologies for not being able to update here. Basically, the issue hasn't reproduced again as yet because I haven't seriously spent any time on reproducing it. I have been busy with many things. I will update as soon as I can.

> What does the trace for a failure look like

What trace are we talking about? Is there a way to trigger back trace whenever I get "Input/Output error"?

devsk, any updates on this please, have you been able to reproduce it with recent kernel?
Thanks.

I am running 2.6.24. I haven't seen this problem for a while. Please close this report as far as I am concerned.

Great, thanks. Closing.