Bug 52474

Created attachment 64651 [details]
output of "udevadm info --export-db"

Created attachment 64652 [details]
contents of /proc/self/mountinfo

Created attachment 64653 [details]
contents of /etc/fstab

Created attachment 64654 [details]
output of "gvfs-mount -oi"

Created attachment 64655 [details]
output of "udevadm monitor --udev --property"

Created attachment 64656 [details]
contents of /proc/self/mountinfo

Created attachment 64657 [details]
output of "gvfs-mount -li"

Created attachment 64658 [details]
output of "gvfs-mount -oi"

Created attachment 64659 [details]
output of "udevadm info --export-db"

Created attachment 64660 [details]
output of "udevadm monitor --udev --property"

Created attachment 64662 [details]
"udisks --monitor-details" output

Created attachment 64663 [details]
output of "udisks --dump"

First of all, I've seen this problem with Sandisk Cruzer USB sticks as well.

It's actually not a udisks problem - from comment 9 you can see that the ID_FS* properties are not set in the udev database.

So why's that? It's because blkid never runs on the device. Why? Because of this udev rule

 KERNEL=="sr*", ENV{DISK_EJECT_REQUEST}!="?*",  \
   ENV{ID_CDROM_MEDIA_TRACK_COUNT_DATA}=="?*",  \
   ENV{ID_CDROM_MEDIA_SESSION_LAST_OFFSET}=="", \
   IMPORT{builtin}="blkid --noraid"

in /lib/udev/rules.d/60-persistent-storage.rules. As you can see from comment 9, ID_CDROM_MEDIA_TRACK_COUNT_DATA is not set.

But why do we require ID_CDROM_MEDIA_TRACK_COUNT_DATA to be set? Because some optical discs may not have data on them (they may have audio) and we don't want to read data from such discs (it causes the sr driver to spew errors).

As I said, I have the same "problem" with my Sandisk Cruzer USB stick, see

 # /lib/udev/cdrom_id /dev/sr1
 ID_CDROM=1
 ID_CDROM_CD_R=1
 ID_CDROM_MRW=1
 ID_CDROM_MRW_W=1
 ID_CDROM_MEDIA=1

that also lacks the ID_CDROM_MEDIA_TRACK_COUNT_DATA property. (Only it's not really a problem as the "CD-ROM" only has Windows drivers/apps on it which are pretty useless on Linux anyway.)

So this is either a) a bug in cdrom_id; or b) a firwmare bug in the device. I think it's the latter... maybe cdrom_id can add a workaround/quirk, I don't don't.

Either way it's not a udisks bug... I'm reassigning to systemd (and fixing up the bug title) since that's where udev lives nowadays. Kay: any thoughts on this?

I agree, I've JUST a single UDF that have this problem fixed (actually only devices having a recent firmware).
so actually I think that is a firmware problem, but since almost ALL UDF chipset have the same "odd" behavior I think that udev/systemd should fix this also because on Windows and OSX the problem does not exists.

Anyway, since I'm not sure this fix will be possible and to try to support also older systemd versions, if I would like to make a bug report to the UDF controller supplier and make they fix the problem, what actually I've to tell them?

What components sets the "ID_CDROM_MEDIA_TRACK_COUNT_DATA" variable and using information coming from where?

It seems to work all fine here:

$ cdrom_id --debug /dev/sr0
probing: '/dev/sr0'
INQUIRY: [SanDisk ][U3 Cruzer Micro ][8.02]
current profile 0x08
profile 0x08 media_cd_rom
GET CONFIGURATION: size of features buffer 0x0044
GET CONFIGURATION: size of features buffer 0x0044
GET CONFIGURATION: feature 'profiles', with 1 entries
profile 0x08 cd_rom
GET CONFIGURATION: feature 0x0001 <ignored>, with 0x08 bytes
GET CONFIGURATION: feature 0x0200 <ignored>, with 0x00 bytes
GET CONFIGURATION: feature 0x0003 <ignored>, with 0x04 bytes
GET CONFIGURATION: feature 0x0010 <ignored>, with 0x08 bytes
GET CONFIGURATION: feature 0x001e <ignored>, with 0x04 bytes
GET CONFIGURATION: feature 0x0100 <ignored>, with 0x00 bytes
READ TOC: len: 20, start track: 1, end track: 1
track=1 info=0x4(data) start_block=0
last track 1 starts at block 0
disk type 00
hardware reported media status: complete
ID_CDROM=1
ID_CDROM_CD=1
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

(In reply to comment #14)
> What components sets the "ID_CDROM_MEDIA_TRACK_COUNT_DATA" variable and using
> information coming from where?

See the output above, it's all SG_IO from cdrom_id. There was a bug in
systemd, that would not print the --debug output. Just fixed that in
systemd git:
  http://cgit.freedesktop.org/systemd/systemd/commit/?id=e239cd8de06a62c9adc71ff1329a1ce76e8735a5

Created attachment 64720 [details]
bugged response to the GET CONFIGURATION command

the log of one of the controllers I've tested:

main: probing: '/dev/sr1'
cd_inquiry: INQUIRY: [Generic ][Autorun Disk    ][8.00]
cd_profiles: no current profile, assuming no media
cd_profiles: GET CONFIGURATION: size of features buffer 0x0000
cd_profiles: GET CONFIGURATION: size of features buffer 0x0000
ID_CDROM=1
ID_CDROM_MRW=1
ID_CDROM_MRW_W=1
ID_CDROM_MEDIA=1


Another (bugged) controller responds to the GET CONFIGURATION command with an "apparently" malformed response, since the "len" fields is decoded to 0x5800202 (actually it may vary), so cdrom_id truncates it; then in the parsing procedure most of the features is just junk (see the cdrom_id_bugged.log attachment)

And another one respond with status error to GET CONFIGURATION, so the "old mmc" code is activated and it correctly detect a data cdrom media type and sets the ID_CDROM_MEDIA_TRACK_COUNT_DATA=1 value:


main: probing: '/dev/sr2'
cd_inquiry: INQUIRY: [GENERIC ][                ][0.00]
info_scsi_cmd_err: GET CONFIGURATION failed with SK=5h/ASC=20h/ACQ=00h
cd_profiles: drive is pre-MMC2 and does not support 46h get configuration command
cd_profiles: trying to work around the problem
info_scsi_cmd_err: READ DISC INFORMATION failed with SK=5h/ASC=20h/ACQ=00h
cd_profiles_old_mmc: no current profile, but disc is present; assuming CD-ROM
cd_media_toc: READ TOC: len: 20, start track: 1, end track: 1
cd_media_toc: track=1 info=0x4(data) start_block=0
cd_media_toc: last track 1 starts at block 0
info_scsi_cmd_err: READ DISC INFORMATION failed with SK=5h/ASC=20h/ACQ=00h
ID_CDROM=1
ID_CDROM_MEDIA=1
ID_CDROM_MEDIA_CD=1
ID_CDROM_MEDIA_TRACK_COUNT_DATA=1



As I expected, each vendor did some mistake and the possible responses are very different.

What do you think, it would be possible to patch cdrom_id so the tcase of zero len response to "GET CONFIGURATION" would be treated as "GET CONFIGURATION" returning a status error?

(In reply to comment #17)
> What do you think, it would be possible to patch cdrom_id so the tcase of zero
> len response to "GET CONFIGURATION" would be treated as "GET CONFIGURATION"
> returning a status error?


Sure, we can try that.

Ok, adding following code after GET CONFIGURATION command solved the problem completely:

----------------------------------------------------------------
        /* parse the length once more, in case the drive decided to have other features suddenly :) */
        len = features[0] << 24 | features[1] << 16 | features[2] << 8 | features[3];
        log_debug("GET CONFIGURATION: size of features buffer 0x%04x\n", len);
+	if (len == 0)
+	{
+		log_debug("GET CONFIGURATION: returned ZERO length feature buffer: trying to work around the problem\n");
+		ret = cd_profiles_old_mmc(udev, fd);
+		goto out;
+	}
----------------------------------------------------------------


Now this is the output of cdrom_id with that bogus controller:

probing: '/dev/sr1'
INQUIRY: [Generic ][Autorun Disk    ][8.00]
no current profile, assuming no media
GET CONFIGURATION: size of features buffer 0x0000
GET CONFIGURATION: size of features buffer 0x0000
GET CONFIGURATION: returned ZERO length feature buffer: trying to work around the problem
profile 0x08 media_cd_rom
READ TOC: len: 12, start track: 1, end track: 1
last track 1 starts at block 0
disk type 00
hardware reported media status: complete
ID_CDROM=1
ID_CDROM_MEDIA=1
ID_CDROM_MEDIA_CD=1
ID_CDROM_MEDIA_SESSION_COUNT=1
ID_CDROM_MEDIA_TRACK_COUNT=1


what do you think, is that patch OK?

(In reply to comment #19)
> +    if (len == 0)
> +    {
> +        log_debug("GET CONFIGURATION: returned ZERO length feature buffer:
> trying to work around the problem\n");
> +        ret = cd_profiles_old_mmc(udev, fd);
> +        goto out;
> +    }

> what do you think, is that patch OK?

I would suggest

 - opening brace should be on same line as if (always a good idea to follow existing code formatting conventions)
 - "trying to work around the problem" is a bit vague - suggest to be more specific

See [1] for the output from my Sandisk Cruzer which suggest that the hardware is still lying.

I think the best thing (to be as closely compatible with Windows as possible) is to just run blkid(8) on the device without regard to what the device says the disc looks like (looks to me like this is what Windows is doing). In patch form it's this simple:

--- 60-persistent-storage.rules.orig	2012-07-26 13:50:45.997199462 -0400
+++ 60-persistent-storage.rules	2012-07-26 13:51:59.408832982 -0400
@@ -65,7 +65,7 @@
 KERNEL=="sr*", ENV{DISK_EJECT_REQUEST}!="?*", ENV{ID_CDROM_MEDIA_TRACK_COUNT_DATA}=="?*", ENV{ID_CDROM_MEDIA_SESSION_LAST_OFFSET}=="?*", \
   IMPORT{builtin}="blkid --offset=$env{ID_CDROM_MEDIA_SESSION_LAST_OFFSET}"
 # single-session CDs do not have ID_CDROM_MEDIA_SESSION_LAST_OFFSET
-KERNEL=="sr*", ENV{DISK_EJECT_REQUEST}!="?*", ENV{ID_CDROM_MEDIA_TRACK_COUNT_DATA}=="?*", ENV{ID_CDROM_MEDIA_SESSION_LAST_OFFSET}=="", \
+KERNEL=="sr*", ENV{DISK_EJECT_REQUEST}!="?*", ENV{ID_CDROM_MEDIA_SESSION_LAST_OFFSET}=="", \
   IMPORT{builtin}="blkid --noraid"

Yes, this makes the sr driver spew error messages or audio or blank CDs but I'd argue we just need to fix the sr driver for that. Kay, what do you think?

[1] :

 $ ./cdrom_id --debug /dev/sr1
 probing: '/dev/sr1'
 INQUIRY: [SanDisk ][Cruzer          ][4.05]
 no current profile, assuming no media
 GET CONFIGURATION: size of features buffer 0x0000
 GET CONFIGURATION: returned ZERO length feature buffer: trying to work around the problem
 profile 0x09 media_cd_r
 READ TOC failed with SK=5h/ASC=26h/ACQ=02h
 disk type 00
 hardware reported media status: blank
 ID_CDROM=1
 ID_CDROM_CD_R=1
 ID_CDROM_MRW=1
 ID_CDROM_MRW_W=1
 ID_CDROM_MEDIA=1
 ID_CDROM_MEDIA_CD_R=1
 ID_CDROM_MEDIA_STATE=blank

(In reply to comment #15)
> It seems to work all fine here:

Kay: I've now blacklisted SanDisk Cruzer so it won't appear in desktop (except for GNOME Disks of course)

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

(In reply to comment #20)
> -KERNEL=="sr*", ENV{DISK_EJECT_REQUEST}!="?*",
> ENV{ID_CDROM_MEDIA_TRACK_COUNT_DATA}=="?*",
> ENV{ID_CDROM_MEDIA_SESSION_LAST_OFFSET}=="", \
> +KERNEL=="sr*", ENV{DISK_EJECT_REQUEST}!="?*",
> ENV{ID_CDROM_MEDIA_SESSION_LAST_OFFSET}=="", \
>    IMPORT{builtin}="blkid --noraid"

That patch is perfectly working with all bogus controllers I have here.

also I'm not having roblems with our P-ATA and S-ATA cd/dvd burners:
CDROMs and DVDs are mounted correctly
blank CDROMs and DVDs are correctly recognized by the desktop environment

So what do you think, it is possible to apply that patch in the "60-persistent-storage.rules" file?

We cannot do that before the kernel would be changed not to log every access
that will fail with non-data optical drive media (like audio CDs).

We added the rule that time, to avoid that, and I doubt the kernel changed
this behaviour in the meantime.

Closing, requires changes to the kernel (which I am not sure are really a good idea). Please reopen after those are made.