Bug 15757

Summary: CD-ROM repeated read failures during probing
Product: IO/Storage Reporter: James Ettle (james)
Component: OtherAssignee: Kay Sievers (kay)
Status: RESOLVED CODE_FIX    
Severity: normal CC: carlos, dthierbach, kay, kkp, tj
Priority: P1    
Hardware: All   
OS: Linux   
Kernel Version: 2.6.32 Subsystem:
Regression: No Bisected commit-id:

Description James Ettle 2010-04-11 09:40:10 UTC
(Following comment #20 of bug 15403:)

I see a number of read-failure error messages with a TSSTcorp CDDVDW SN-S082H (on Intel ICH8), and on another machine (with an ATI-IXP chipset) with a
HL-DT-STCD-RW/DVD DRIVE GCC-4241N drive, whenever I insert blank media or
an audio CD. It behaves itself with a data CD-ROM. The drive seems to work fine
reading data.


Buffer I/O error on device sr0, logical block 0
sr 3:0:0:0: [sr0] Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE
sr 3:0:0:0: [sr0] Sense Key : Illegal Request [current] 
sr 3:0:0:0: [sr0] Add. Sense: Logical block address out of range
sr 3:0:0:0: [sr0] CDB: Read(10): 28 00 00 00 00 00 00 00 01 00
end_request: I/O error, dev sr0, sector 0


and with an audio CD:


sr 3:0:0:0: [sr0] Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE
sr 3:0:0:0: [sr0] Sense Key : Illegal Request [current] 
sr 3:0:0:0: [sr0] Add. Sense: Illegal mode for this track
sr 3:0:0:0: [sr0] CDB: Read(10): 28 00 00 00 00 00 00 00 40 00
end_request: I/O error, dev sr0, sector 0
Buffer I/O error on device sr0, logical block 0
Buffer I/O error on device sr0, logical block 1
Buffer I/O error on device sr0, logical block 2
Buffer I/O error on device sr0, logical block 3
Buffer I/O error on device sr0, logical block 4
Buffer I/O error on device sr0, logical block 5
Buffer I/O error on device sr0, logical block 6
Buffer I/O error on device sr0, logical block 7
Buffer I/O error on device sr0, logical block 8
sr 3:0:0:0: [sr0] Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE
sr 3:0:0:0: [sr0] Sense Key : Illegal Request [current] 
sr 3:0:0:0: [sr0] Add. Sense: Illegal mode for this track
sr 3:0:0:0: [sr0] CDB: Read(10): 28 00 00 00 00 00 00 00 02 00
end_request: I/O error, dev sr0, sector 0


The drive's hdparm info:


/dev/sr0:

ATAPI CD-ROM, with removable media
    Model Number:       TSSTcorp CDDVDW SN-S082H                
    Serial Number:      
    Firmware Revision:  SB00    
Standards:
    Supported: CD-ROM ATAPI-3 -4 -5 -6 -7 
Configuration:
    DRQ response: 50us.
    Packet size: 12 bytes
    cache/buffer size  = unknown
Capabilities:
    LBA, IORDY(can be disabled)
    DMA: mdma0 mdma1 mdma2 udma0 udma1 *udma2 
         Cycle time: min=120ns recommended=120ns
    PIO: pio0 pio1 pio2 pio3 pio4 
         Cycle time: no flow control=383ns  IORDY flow control=120ns
Commands/features:
    Enabled    Supported:
       *    Power Management feature set
       *    PACKET command feature set
       *    DEVICE_RESET command
       *    NOP cmd
HW reset results:
    CBLID- below Vih
Comment 1 Tejun Heo 2010-04-13 22:00:35 UTC
Both blank media and audio CDs are unreadable as data CDs so when the userland issues commands to probe media type, those commands are expected to fail.  There are two problems tho.

1. Those messages are annoying.  It would be great if those messages can be suppressed for probing commands.

2. In some cases, some drives report errors in such a way that the driver retries those commands multiple times before giving up holding up the drive for too long and generating lots of scary messages.  Some way to tell the kernel that those commands are not supposed to be retried would be great.

(I'll be semi-offline for about ten days from now.  I'll work on this afterwards).

Thanks.
Comment 2 Tejun Heo 2010-05-19 16:58:12 UTC
cc'd Kay.  Okay, did some tracing today.  The failing reads come from blkid and only happens when hald is running.  For some reason, blkid tries to read the first sector (2048bytes @ 0) even when TOC indicates it's not a data CD.  When the drive behaves correctly, this produces those annoying error messages but of course some drives react badly at times and collapse badly.

Kay, is this expected behavior?  Is the problem gonna go away with hal?  At any rate, as this is affecting many current users, we probably better teach blkid not to issue READ on blank media and music CDs.

Thanks.
Comment 3 Kay Sievers 2010-05-19 17:02:53 UTC
On Wed, May 19, 2010 at 18:58,  <bugzilla-daemon@bugzilla.kernel.org> wrote:
> For some reason, blkid tries to read the
> first sector (2048bytes @ 0) even when TOC indicates it's not a data CD. 
> When
> the drive behaves correctly, this produces those annoying error messages but
> of
> course some drives react badly at times and collapse badly.
>
> Kay, is this expected behavior?  Is the problem gonna go away with hal?  At
> any
> rate, as this is affecting many current users, we probably better teach blkid
> not to issue READ on blank media and music CDs.

I'll check if we can export some property from cdrom_id which is
called before blkid, and let skip the call to blkid if we don't expect
data.
Comment 4 Kay Sievers 2010-05-21 15:36:46 UTC
On Wed, May 19, 2010 at 19:03,  <bugzilla-daemon@bugzilla.kernel.org> wrote:
> --- Comment #3 from Kay Sievers <kay.sievers@vrfy.org>  2010-05-19 17:02:53
> ---
> On Wed, May 19, 2010 at 18:58,  <bugzilla-daemon@bugzilla.kernel.org> wrote:
>> For some reason, blkid tries to read the
>> first sector (2048bytes @ 0) even when TOC indicates it's not a data CD. 
>> When
>> the drive behaves correctly, this produces those annoying error messages but
>> of
>> course some drives react badly at times and collapse badly.
>>
>> Kay, is this expected behavior?  Is the problem gonna go away with hal?  At
>> any
>> rate, as this is affecting many current users, we probably better teach
>> blkid
>> not to issue READ on blank media and music CDs.
>
> I'll check if we can export some property from cdrom_id which is
> called before blkid, and let skip the call to blkid if we don't expect
> data.

Ok, if we are lucky, we are very close already with udev's cdrom_id. :)

This is what cdrom_id prints for an empty CD:
  ID_CDROM_MEDIA=1
  ID_CDROM_MEDIA_CD_R=1
  ID_CDROM_MEDIA_STATE=blank
  ID_CDROM_MEDIA_SESSION_NEXT=1
  ID_CDROM_MEDIA_SESSION_COUNT=1
  ID_CDROM_MEDIA_TRACK_COUNT=1

This is what it prints for an audio-only CD:
  ID_CDROM_MEDIA=1
  ID_CDROM_MEDIA_CD_R=1
  ID_CDROM_MEDIA_STATE=complete
  ID_CDROM_MEDIA_SESSION_COUNT=1
  ID_CDROM_MEDIA_TRACK_COUNT=1
  ID_CDROM_MEDIA_TRACK_COUNT_AUDIO=1

This is what it prints for a Mixed audio/data CD:
  ID_CDROM_MEDIA=1
  ID_CDROM_MEDIA_CD=1
  ID_CDROM_MEDIA_SESSION_COUNT=2
  ID_CDROM_MEDIA_TRACK_COUNT=13
  ID_CDROM_MEDIA_TRACK_COUNT_AUDIO=12
  ID_CDROM_MEDIA_TRACK_COUNT_DATA=1
  ID_CDROM_MEDIA_SESSION_LAST_OFFSET=444508160

This is what it prints for a data-only CD:
  ID_CDROM_MEDIA=1
  ID_CDROM_MEDIA_CD=1
  ID_CDROM_MEDIA_SESSION_COUNT=1
  ID_CDROM_MEDIA_TRACK_COUNT=1
  ID_CDROM_MEDIA_TRACK_COUNT_DATA=1

That's a 3 sessions data CD:
  ID_CDROM_MEDIA_CD_R=1
  ID_CDROM_MEDIA_STATE=complete
  ID_CDROM_MEDIA_SESSION_COUNT=3
  ID_CDROM_MEDIA_TRACK_COUNT=3
  ID_CDROM_MEDIA_TRACK_COUNT_DATA=3
  ID_CDROM_MEDIA_SESSION_LAST_OFFSET=39329792

That's a video CD (iso9660):
  ID_CDROM_MEDIA=1
  ID_CDROM_MEDIA_CD_R=1
  ID_CDROM_MEDIA_STATE=complete
  ID_CDROM_MEDIA_SESSION_COUNT=1
  ID_CDROM_MEDIA_TRACK_COUNT=2
  ID_CDROM_MEDIA_TRACK_COUNT_DATA=2

This is an empty DVD:
  ID_CDROM_MEDIA=1
  ID_CDROM_MEDIA_DVD_R=1
  ID_CDROM_MEDIA_STATE=blank
  ID_CDROM_MEDIA_SESSION_NEXT=1
  ID_CDROM_MEDIA_SESSION_COUNT=1
  ID_CDROM_MEDIA_TRACK_COUNT=1

Seems we can key off of ID_CDROM_MEDIA_TRACK_COUNT_DATA if we should
call /sbin/blkid, or skip it.

James, can you run:
  /lib/udev/cdrom_id /dev/sr0
on your media and confirm that this works as expected?

If you like, you could also try to add:
  ENV{ID_CDROM_MEDIA_TRACK_COUNT_DATA}="?*"
to:
  /lib/udev/rules.d/60-persistent-storage.rules
to the lines which call /sbin/blkid for "sr*" devices, and check if
all still works as expected but without the errors.
Comment 6 Kay Sievers 2010-05-25 17:36:04 UTC
New udev released. Also a similar patch to udisks committed.
Comment 7 James Ettle 2010-06-03 10:59:50 UTC
(In reply to comment #4) Tried the suggestions. Made no different with udev-151-9.fc13.x86_64, udisks-1.0.1-1.fc13.x86_64, kernel-2.6.33.5-112.fc13.x86_64.

/lib/udev/cdrom_id /dev/sr0 with an audio-CD inserted produced:

ID_CDROM=1
ID_CDROM_CD=1
ID_CDROM_CD_R=1
ID_CDROM_CD_RW=1
ID_CDROM_DVD=1
ID_CDROM_DVD_R=1
ID_CDROM_DVD_RW=1
ID_CDROM_DVD_RAM=1
ID_CDROM_DVD_PLUS_R=1
ID_CDROM_DVD_PLUS_RW=1
ID_CDROM_DVD_PLUS_R_DL=1
ID_CDROM_MRW=1
ID_CDROM_MRW_W=1
ID_CDROM_MEDIA=1
ID_CDROM_MEDIA_CD=1
ID_CDROM_MEDIA_SESSION_COUNT=1
ID_CDROM_MEDIA_TRACK_COUNT=6
ID_CDROM_MEDIA_TRACK_COUNT_AUDIO=6

Same error messages in dmesg.
Comment 8 Kay Sievers 2010-06-03 11:29:00 UTC
On Thu, Jun 3, 2010 at 12:59,  <bugzilla-daemon@bugzilla.kernel.org> wrote:
> https://bugzilla.kernel.org/show_bug.cgi?id=15757

> --- Comment #7 from James Ettle <theholyettlz@googlemail.com>  2010-06-03
> 10:59:50 ---
> (In reply to comment #4) Tried the suggestions. Made no different with
> udev-151-9.fc13.x86_64, udisks-1.0.1-1.fc13.x86_64,
> kernel-2.6.33.5-112.fc13.x86_64.

the errors are gone here. udisks it not released, it still access your
audio cd. you need this:

http://cgit.freedesktop.org/udisks/commit/?id=c2464f7bf215cd17962e917b974c573378d4e58b

Kay
Comment 9 James Ettle 2010-06-05 18:25:57 UTC
(In reply to comment #8):

>
> http://cgit.freedesktop.org/udisks/commit/?id=c2464f7bf215cd17962e917b974c573378d4e58b
 
Making these changes (alone) seems to result in less grunting from the drive, but the error messages from the kernel still persist.
Comment 10 Kay Sievers 2010-06-05 19:07:18 UTC
On Sat, Jun 5, 2010 at 20:26,  <bugzilla-daemon@bugzilla.kernel.org> wrote:
> --- Comment #9 from James Ettle <theholyettlz@googlemail.com>  2010-06-05
> 18:25:57 ---
> (In reply to comment #8):
>
>>
>> http://cgit.freedesktop.org/udisks/commit/?id=c2464f7bf215cd17962e917b974c573378d4e58b
>
> Making these changes (alone) seems to result in less grunting from the drive,
> but the error messages from the kernel still persist.

Then you probably still have something that shouldn't be there.

You can check with:
  udevadm test /class/block/sr0
what is still called.
Comment 11 James Ettle 2010-06-05 19:41:59 UTC
Hang on... I've just applied both modifications, both to 60-persistent-storage.rules and 80-udisks.rules, and I no longer see any error messages with audio CDs. Thanks for all the help, Kay!
Comment 12 Kay Sievers 2010-06-05 20:20:01 UTC
On Sat, Jun 5, 2010 at 21:42,  <bugzilla-daemon@bugzilla.kernel.org> wrote:
> https://bugzilla.kernel.org/show_bug.cgi?id=15757
>
> --- Comment #11 from James Ettle <theholyettlz@googlemail.com>  2010-06-05
> 19:41:59 ---
> Hang on... I've just applied both modifications, both to
> 60-persistent-storage.rules and 80-udisks.rules, and I no longer see any
> error
> messages with audio CDs. Thanks for all the help, Kay!

Awesome. Thanks for the update and the testing. These errors should be
gone with the upcoming releases then.
Comment 13 Dirk Thierbach 2011-03-02 18:07:12 UTC
I'm still getting exactly the same bug on Debian Sid for my old IDE CD-Drives /dev/hd{c,d}. The reason is apparently that the fix

KERNEL=="sr*", ENV{ID_CDROM_MEDIA_TRACK_COUNT_DATA}=="", GOTO="probe_parttable_end"

in 80-udisks.rules obviously doesn't match KERNEL=="hd*", so I guess a similar line should be inserted in the "# probe ide-cd drives" section. I'm not sure if this also applies to 60-persistant-storage.rules; after modifying 80-udisks.rules, the log entries disappear on my system.

I couldn't find any information in the FAQ if in such cases it is preferred to reopen an old bug report or to file a new one. If I should file a new one, please tell me so.
Comment 14 Kay Sievers 2011-03-02 18:49:46 UTC
On Wed, Mar 2, 2011 at 19:07,  <bugzilla-daemon@bugzilla.kernel.org> wrote:
> https://bugzilla.kernel.org/show_bug.cgi?id=15757

 --- Comment #13 from Dirk Thierbach <dthierbach@gmx.de>  2011-03-02
18:07:12 ---
> I'm still getting exactly the same bug on Debian Sid for my old IDE CD-Drives
> /dev/hd{c,d}. The reason is apparently that the fix
>
> KERNEL=="sr*", ENV{ID_CDROM_MEDIA_TRACK_COUNT_DATA}=="",
> GOTO="probe_parttable_end"
>
> in 80-udisks.rules obviously doesn't match KERNEL=="hd*", so I guess a
> similar
> line should be inserted in the "# probe ide-cd drives" section. I'm not sure
> if
> this also applies to 60-persistant-storage.rules; after modifying
> 80-udisks.rules, the log entries disappear on my system.
>
> I couldn't find any information in the FAQ if in such cases it is preferred
> to
> reopen an old bug report or to file a new one. If I should file a new one,
> please tell me so.

None of the old IDE drivers with the hd* names are supported by recent
versions of udev and friends since a while. There are no additional
rules, symlinks, logic for hd* devices, only the plain device nodes
will be there. Please just use the new drivers with the new device
names, and all should work fine. Thanks!
Comment 15 Dirk Thierbach 2011-03-02 19:28:32 UTC
Then shouldn't the following lines 

# probe ide-cd drives

# probe filesystem metadata of optical drives which have a media inserted
KERNEL=="hd*", ENV{ID_CDROM_MEDIA}=="?*", \
        ENV{ID_CDROM_MEDIA_SESSION_LAST_OFFSET}=="?*", \
        IMPORT{program}="/sbin/blkid -o udev -p -u noraid -O $env{ID_CDROM_MEDIA_SESSION_LAST_OFFSET} $tempnode"
# single-session CDs do not have ID_CDROM_MEDIA_SESSION_LAST_OFFSET
KERNEL=="hd*", ENV{ID_CDROM_MEDIA}=="?*", \
        ENV{ID_CDROM_MEDIA_SESSION_LAST_OFFSET}=="", \
        IMPORT{program}="/sbin/blkid -o udev -p -u noraid $tempnode"

be removed from 80-udisks.rules? Either the hd* names are supported or not. If they are not supported, they shouldn't be matched at all, and certainly not in way that creates annoying log entries.
Comment 16 Kay Sievers 2011-03-02 19:32:49 UTC
On Wed, Mar 2, 2011 at 20:28,  <bugzilla-daemon@bugzilla.kernel.org> wrote:
> # probe filesystem metadata of optical drives which have a media inserted
> KERNEL=="hd*", ENV{ID_CDROM_MEDIA}=="?*", \
>        ENV{ID_CDROM_MEDIA_SESSION_LAST_OFFSET}=="?*", \
>        IMPORT{program}="/sbin/blkid -o udev -p -u noraid -O
> $env{ID_CDROM_MEDIA_SESSION_LAST_OFFSET} $tempnode"
> # single-session CDs do not have ID_CDROM_MEDIA_SESSION_LAST_OFFSET
> KERNEL=="hd*", ENV{ID_CDROM_MEDIA}=="?*", \
>        ENV{ID_CDROM_MEDIA_SESSION_LAST_OFFSET}=="", \
>        IMPORT{program}="/sbin/blkid -o udev -p -u noraid $tempnode"
>
> be removed from 80-udisks.rules? Either the hd* names are supported or not.
> If
> they are not supported, they shouldn't be matched at all, and certainly not
> in
> way that creates annoying log entries.

I don't see these, only a few rules to prevent scary loops which the
hd* stuff liked to do:
  http://cgit.freedesktop.org/udisks/tree/data/80-udisks.rules