[Debburn-devel] udev link vanishes if burn programs load the drive tray on Debian 6.0.2 amd64

[Thomas Schmitt]

Hi,

Nicolas George wrote:
> You may try to use udevadm to raise the log level of udevd, it is possible
> that some helpful information will end up in daemon.log. But it is usually
> rather unreadable.

Looks like this yields a trace that will help me to discuss the problem
with Linux people.
A vanishing link is accompanied by these messages:
------------------------------------------------------------------

Sep  9 22:00:41 debian2 udevd[435]: seq 1274 queued, 'change' 'scsi'
[...]
Sep  9 22:00:41 debian2 udevd-work[21697]: 'cdrom_id --export /dev/sr0' started
Sep  9 22:00:41 debian2 cdrom_id[21698]: custom logging function 0x7f17909c9010 registered
Sep  9 22:00:47 debian2 cdrom_id[21698]: unable to open '/dev/sr0'
Sep  9 22:00:47 debian2 udevd-work[21697]: '/lib/udev/cdrom_id' (stderr) 'unable to open '/dev/sr0''
Sep  9 22:00:47 debian2 udevd-work[21697]: 'cdrom_id --export /dev/sr0' returned with exitcode 1
[...]
Sep  9 22:00:48 debian2 udevd-work[21697]: update old name, '/dev/dvdrw' no longer belonging to '/devices/pci0000:00/0000:00:11.0/host2/target2:0:0/2:0:0:0/block/sr0'
Sep  9 22:00:48 debian2 udevd-work[21697]: no reference left, remove '/dev/dvdrw'
[... no attempt to create a new /dev/dvdrw ...]
Sep  9 22:00:48 debian2 udevd[435]: seq 1275 done with 0

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

The subsequent repair by accessing the drive by SCSI information inquiry
commands and by READ commands reports:
------------------------------------------------------------------

Sep  9 22:01:06 debian2 udevd[435]: seq 1276 queued, 'change' 'scsi'
[...]
Sep  9 22:01:06 debian2 udevd-work[21697]: 'cdrom_id --export /dev/sr0' started
Sep  9 22:01:06 debian2 cdrom_id[22669]: custom logging function 0x7f3e72142010 registered
Sep  9 22:01:10 debian2 cdrom_id[22669]: probing: '/dev/sr0'
Sep  9 22:01:10 debian2 cdrom_id[22669]: INQUIRY: [TSSTcorp][CDDVDW SH-S223B ][SB02]
[... many other SCSI inquiry command results ...]
Sep  9 22:01:16 debian2 udevd-work[21697]: LINK 'dvdrw' /etc/udev/rules.d/70-persistent-cd.rules:11
[...]
Sep  9 22:01:16 debian2 udevd-work[21697]: creating link '/dev/dvdrw' to '/dev/sr0'
Sep  9 22:01:16 debian2 udevd-work[21697]: creating symlink '/dev/dvdrw' to 'sr0'
[...]
Sep  9 22:01:16 debian2 udevd[435]: seq 1277 done with 0

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

It looks as if xorriso's activities block the drive while udev is trying
to get access to it in the time between 22:00:41 and 22:00:47.
It then cancelled link (re-)creation.

wodim seems a bit less problematic, because it does not perform READ
commands. xorriso does this to learn about possible ISO 9660 fileystems.
I assume they add a few extra seconds to the drive occupation.


Have a nice day :)

Thomas