[2.6.30-rc2] CD-R: wodim intermittent failures: [sr0] Add. Sense: Logical block address out of range, sector 0

[2.6.30-rc2] CD-R: wodim intermittent failures: [sr0] Add. Sense: Logical block address out of range, sector 0

[Andy Isaacson]

I'm running 2.6.30-rc2-00446-ga939b96 on a Dell E4300 with a
upgraded-to-Jaunty-mostly Ubuntu install.  Using 2.6.28 and 2.6.29.1,
I've successfully burned a dozen CDRs, but since updating to .30-rc1
I've noticed intermittent failures to burn CDRs using wodim at the Gnome
desktop.  (Switching back to .29.1 makes wodim reliable again.)  There
have been a few different failure modes, but all of them seem to be
associated with these messages in dmesg, which I haven't seen before:

[  360.740810] sr 1:0:0:0: [sr0] Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE
[  360.740816] sr 1:0:0:0: [sr0] Sense Key : Illegal Request [current] 
[  360.740820] sr 1:0:0:0: [sr0] Add. Sense: Logical block address out of range
[  360.740826] end_request: I/O error, dev sr0, sector 0
[  360.740830] Buffer I/O error on device sr0, logical block 0

(repeated a few dozen times).

I haven't been able to reproduce these messages running wodim at the
console (after "/etc/init.d/gdm stop") so I suspect there's some
interference between wodim and Gnome's desktop device detection.

I've seen the following behavior running wodim under gnome:

1. wodim blocked in D state for >10 minutes, system showing interactive
lagginess.  Unfortunately I've not been able to reproduce this to get
wchan info, but I *think* it was showing blk_execute_rq.

2. running wodim triggers DID_OK messages, but wodim seems to be able to
complete writing the ISO and the resulting CDR reads OK.

3. running wodim triggers DID_OK messages, and wodim fails:  (but I
think this is just due to the media having been partially written by a
previous iteration of wodim.)

% wodim ubuntu-9.04-rc-desktop-amd64.iso
wodim: No write mode specified.
wodim: Asuming -tao mode.
wodim: Future versions of wodim may have different drive dependent defaults.
wodim: Operation not permitted. Warning: Cannot raise RLIMIT_MEMLOCK limits.Device was not specified. Trying to find an appropriate drive...
Looking for a CD-R drive to store 698.17 MiB...
Detected CD-R drive: /dev/cdrw
Using /dev/cdrom of unknown capabilities
Device type    : Removable CD-ROM
Version        : 5
Response Format: 2
Capabilities   : 
Vendor_info    : 'TSSTcorp'
Identification : 'DVD+-RW TS-U633A'
Revision       : 'D200'
Device seems to be: Generic mmc2 DVD-R/DVD-RW.
Using generic SCSI-3/mmc   CD-R/CD-RW driver (mmc_cdr).
Driver flags   : MMC-3 SWABAUDIO BURNFREE 
Supported modes: TAO PACKET SAO SAO/R96P SAO/R96R RAW/R16 RAW/R96P RAW/R96R
Speed set to 4234 KB/s
Starting to write CD/DVD at speed  24.0 in real TAO mode for single session.
Last chance to quit, starting real write in    0 seconds. Operation starts.
Errno: 5 (Input/output error), write_g1 scsi sendcmd: no error
CDB:  2A 00 FF FF FF FF 00 00 1F 00
status: 0x2 (CHECK CONDITION)
Sense Bytes: 70 00 05 00 00 00 00 0A 00 00 00 00 21 00 00 00
Sense Key: 0x5 Illegal Request, Segment 0
Sense Code: 0x21 Qual 0x00 (logical block address out of range) Fru 0x0
Sense flags: Blk 0 (not valid) 
cmd finished after 0.003s timeout 40s
write track data: error after 0 bytes
wodim: The current problem looks like a buffer underrun.
wodim: It looks like 'driveropts=burnfree' does not work for this drive.
wodim: Please report.
wodim: Make sure that you are root, enable DMA and check your HW/OS set up.
Errno: 5 (Input/output error), close track/session scsi sendcmd: no error
CDB:  5B 00 02 00 00 00 00 00 00 00
status: 0x2 (CHECK CONDITION)
Sense Bytes: 70 00 05 00 00 00 00 0A 00 00 00 00 72 03 00 00
Sense Key: 0x5 Illegal Request, Segment 0
Sense Code: 0x72 Qual 0x03 (session fixation error - incomplete track in session) Fru 0x0
Sense flags: Blk 0 (not valid) 
cmd finished after 0.340s timeout 480s
cmd finished after 0.340s timeout 480s
wodim: Cannot fixate disk.

I'm running "wodim ubuntu-9.04-rc-desktop-amd64.iso" as a regular user
with group write permissions to /dev/sr0.

I've seen /lib/udev/vol_id running *after* wodim has opened the device,
so I wonder if there's some race condition there.

This is with udev 140-2 and wodim 9:1.1.9-1ubuntu1.  .config and
additional information available at:

http://web.hexapodia.org/~adi/sysinfo/1240274989_cvpe4300_2.6.30-rc2-00446-ga939b96/

-andy

Re: [2.6.30-rc2] CD-R: wodim intermittent failures: [sr0] Add. Sense: Logical block address out of range, sector 0

[Andrew Morton]

On Mon, 20 Apr 2009 18:52:34 -0700
Andy Isaacson <adi@hexapodia.org> wrote:

> I'm running 2.6.30-rc2-00446-ga939b96 on a Dell E4300 with a
> upgraded-to-Jaunty-mostly Ubuntu install.  Using 2.6.28 and 2.6.29.1,
> I've successfully burned a dozen CDRs, but since updating to .30-rc1
> I've noticed intermittent failures to burn CDRs using wodim at the Gnome
> desktop.  (Switching back to .29.1 makes wodim reliable again.)  There
> have been a few different failure modes, but all of them seem to be
> associated with these messages in dmesg, which I haven't seen before:
> 
> [  360.740810] sr 1:0:0:0: [sr0] Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE
> [  360.740816] sr 1:0:0:0: [sr0] Sense Key : Illegal Request [current] 
> [  360.740820] sr 1:0:0:0: [sr0] Add. Sense: Logical block address out of range
> [  360.740826] end_request: I/O error, dev sr0, sector 0
> [  360.740830] Buffer I/O error on device sr0, logical block 0
> 
> (repeated a few dozen times).
> 
> I haven't been able to reproduce these messages running wodim at the
> console (after "/etc/init.d/gdm stop") so I suspect there's some
> interference between wodim and Gnome's desktop device detection.
> 
> I've seen the following behavior running wodim under gnome:
> 
> 1. wodim blocked in D state for >10 minutes, system showing interactive
> lagginess.  Unfortunately I've not been able to reproduce this to get
> wchan info, but I *think* it was showing blk_execute_rq.
> 
> 2. running wodim triggers DID_OK messages, but wodim seems to be able to
> complete writing the ISO and the resulting CDR reads OK.
> 
> 3. running wodim triggers DID_OK messages, and wodim fails:  (but I
> think this is just due to the media having been partially written by a
> previous iteration of wodim.)
> 
> % wodim ubuntu-9.04-rc-desktop-amd64.iso
> wodim: No write mode specified.
> wodim: Asuming -tao mode.
> wodim: Future versions of wodim may have different drive dependent defaults.
> wodim: Operation not permitted. Warning: Cannot raise RLIMIT_MEMLOCK limits.Device was not specified. Trying to find an appropriate drive...
> Looking for a CD-R drive to store 698.17 MiB...
> Detected CD-R drive: /dev/cdrw
> Using /dev/cdrom of unknown capabilities
> Device type    : Removable CD-ROM
> Version        : 5
> Response Format: 2
> Capabilities   : 
> Vendor_info    : 'TSSTcorp'
> Identification : 'DVD+-RW TS-U633A'
> Revision       : 'D200'
> Device seems to be: Generic mmc2 DVD-R/DVD-RW.
> Using generic SCSI-3/mmc   CD-R/CD-RW driver (mmc_cdr).
> Driver flags   : MMC-3 SWABAUDIO BURNFREE 
> Supported modes: TAO PACKET SAO SAO/R96P SAO/R96R RAW/R16 RAW/R96P RAW/R96R
> Speed set to 4234 KB/s
> Starting to write CD/DVD at speed  24.0 in real TAO mode for single session.
> Last chance to quit, starting real write in    0 seconds. Operation starts.
> Errno: 5 (Input/output error), write_g1 scsi sendcmd: no error
> CDB:  2A 00 FF FF FF FF 00 00 1F 00
> status: 0x2 (CHECK CONDITION)
> Sense Bytes: 70 00 05 00 00 00 00 0A 00 00 00 00 21 00 00 00
> Sense Key: 0x5 Illegal Request, Segment 0
> Sense Code: 0x21 Qual 0x00 (logical block address out of range) Fru 0x0
> Sense flags: Blk 0 (not valid) 
> cmd finished after 0.003s timeout 40s
> write track data: error after 0 bytes
> wodim: The current problem looks like a buffer underrun.
> wodim: It looks like 'driveropts=burnfree' does not work for this drive.
> wodim: Please report.
> wodim: Make sure that you are root, enable DMA and check your HW/OS set up.
> Errno: 5 (Input/output error), close track/session scsi sendcmd: no error
> CDB:  5B 00 02 00 00 00 00 00 00 00
> status: 0x2 (CHECK CONDITION)
> Sense Bytes: 70 00 05 00 00 00 00 0A 00 00 00 00 72 03 00 00
> Sense Key: 0x5 Illegal Request, Segment 0
> Sense Code: 0x72 Qual 0x03 (session fixation error - incomplete track in session) Fru 0x0
> Sense flags: Blk 0 (not valid) 
> cmd finished after 0.340s timeout 480s
> cmd finished after 0.340s timeout 480s
> wodim: Cannot fixate disk.
> 
> I'm running "wodim ubuntu-9.04-rc-desktop-amd64.iso" as a regular user
> with group write permissions to /dev/sr0.
> 
> I've seen /lib/udev/vol_id running *after* wodim has opened the device,
> so I wonder if there's some race condition there.
> 
> This is with udev 140-2 and wodim 9:1.1.9-1ubuntu1.  .config and
> additional information available at:
> 
> http://web.hexapodia.org/~adi/sysinfo/1240274989_cvpe4300_2.6.30-rc2-00446-ga939b96/
> 

Is seems unreasonably hard (to me) to work out what low-level driver is
in use when we see bug reports like this.

Trolling your dmesg
(http://web.hexapodia.org/~adi/sysinfo/1240274989_cvpe4300_2.6.30-rc2-00446-ga939b96/dmesg.out)
I see 

[    2.184016] ata2: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
[    2.198709] ata2.00: ATAPI: TSSTcorp DVD+/-RW TS-U633A, D200, max UDMA/100, ATAPI AN
[    2.198774] ata2.00: applying bridge limits
[    2.214107] ata2.00: configured for UDMA/100
[    2.230305] scsi 1:0:0:0: CD-ROM            TSSTcorp DVD+-RW TS-U633A D200 PQ: 0 ANSI: 5
[    2.548015] ata5: SATA link down (SStatus 0 SControl 300)
[    2.884014] ata6: SATA link down (SStatus 0 SControl 300)

so I guess that it's serial ATA, at least.

But which lower-level ata driver is being used under that?

[    0.717960] ahci 0000:00:1f.2: version 3.0
[    0.717968] ahci 0000:00:1f.2: PCI INT D -> GSI 19 (level, low) -> IRQ 19
[    0.718057] ahci 0000:00:1f.2: irq 27 for MSI/MSI-X
[    0.718097] ahci: SSS flag set, parallel bus scan disabled
[    0.718176] ahci 0000:00:1f.2: AHCI 0001.0200 32 slots 4 ports 3 Gbps 0x33 impl RAID mode
[    0.718236] ahci 0000:00:1f.2: flags: 64bit ncq sntf stag pm led clo pmp pio slum part ems 
[    0.718298] ahci 0000:00:1f.2: setting latency timer to 64

ahci, I guess.


Probably this is all perfectly obvious to the initiated, but for those
whose life revolves around telling the initiated about their bugs, this
is all unreasonably hard :(

Oh well, let's tentatively assume that we have a post-2.6.29 regression
in the libata ahci driver.

Re: [2.6.30-rc2] CD-R: wodim intermittent failures: [sr0] Add. Sense: Logical block address out of range, sector 0

[Robert Hancock]

Andrew Morton wrote:
> On Mon, 20 Apr 2009 18:52:34 -0700
> Andy Isaacson <adi@hexapodia.org> wrote:
> 
>> I'm running 2.6.30-rc2-00446-ga939b96 on a Dell E4300 with a
>> upgraded-to-Jaunty-mostly Ubuntu install.  Using 2.6.28 and 2.6.29.1,
>> I've successfully burned a dozen CDRs, but since updating to .30-rc1
>> I've noticed intermittent failures to burn CDRs using wodim at the Gnome
>> desktop.  (Switching back to .29.1 makes wodim reliable again.)  There
>> have been a few different failure modes, but all of them seem to be
>> associated with these messages in dmesg, which I haven't seen before:
>>
>> [  360.740810] sr 1:0:0:0: [sr0] Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE
>> [  360.740816] sr 1:0:0:0: [sr0] Sense Key : Illegal Request [current] 
>> [  360.740820] sr 1:0:0:0: [sr0] Add. Sense: Logical block address out of range
>> [  360.740826] end_request: I/O error, dev sr0, sector 0
>> [  360.740830] Buffer I/O error on device sr0, logical block 0

...

> Oh well, let's tentatively assume that we have a post-2.6.29 regression
> in the libata ahci driver.

I tend to doubt it's a problem in ahci itself, I would guess it's higher 
up the stack. Or could be that it's not a kernel bug, just some change 
in timing that triggers the problem.

What's supposed to stop udev/hal from poking at the drive while wodim is 
writing to the disc, anyway?

Re: [2.6.30-rc2] CD-R: wodim intermittent failures: [sr0] Add. Sense: Logical block address out of range, sector 0

[Andy Isaacson]

On Thu, Apr 23, 2009 at 12:46:19AM -0600, Robert Hancock wrote:
> >Oh well, let's tentatively assume that we have a post-2.6.29 regression
> >in the libata ahci driver.
> 
> I tend to doubt it's a problem in ahci itself, I would guess it's higher 
> up the stack. Or could be that it's not a kernel bug, just some change 
> in timing that triggers the problem.
> 
> What's supposed to stop udev/hal from poking at the drive while wodim is 
> writing to the disc, anyway?

wodim opens O_EXCL, and it does occasionally complain about not being
able to open, then sleeping and retrying.

-andy

Re: [2.6.30-rc2] CD-R: wodim intermittent failures: [sr0] Add. Sense: Logical block address out of range, sector 0

[Andy Isaacson]

On Thu, Apr 23, 2009 at 12:07:13AM -0700, Andy Isaacson wrote:
> On Thu, Apr 23, 2009 at 12:46:19AM -0600, Robert Hancock wrote:
> > >Oh well, let's tentatively assume that we have a post-2.6.29 regression
> > >in the libata ahci driver.
> > 
> > I tend to doubt it's a problem in ahci itself, I would guess it's higher 
> > up the stack. Or could be that it's not a kernel bug, just some change 
> > in timing that triggers the problem.
> > 
> > What's supposed to stop udev/hal from poking at the drive while wodim is 
> > writing to the disc, anyway?
> 
> wodim opens O_EXCL, and it does occasionally complain about not being
> able to open, then sleeping and retrying.

I just saw this again with 2.6.30-rc5-00096-ga4d7749 and got some nice
stack traces, for both hald-addon-storage and wodim:

[ 2041.201084] INFO: task hald-addon-stor:3804 blocked for more than 120 seconds.
[ 2041.201108]  ffff8801145056f8 0000000000000086 ffff880118c66120 0000000000000086
[ 2041.201118]  00000000000110c0 000000000000c848 ffff8801144b2cc0 ffff8800d8008000
[ 2041.201127]  ffff8801144b3060 0000000118ddd460 ffff8801145056b8 ffffffff81296405
[ 2041.201135] Call Trace:
[ 2041.201153]  [<ffffffff81296405>] ? scsi_setup_blk_pc_cmnd+0x145/0x180
[ 2041.201162]  [<ffffffff8128f32c>] ? scsi_pool_alloc_command+0x2c/0x80
[ 2041.201171]  [<ffffffff812a70ad>] ? sr_prep_fn+0x4d/0x5b0
[ 2041.201180]  [<ffffffff81413ae9>] schedule+0x9/0x20
[ 2041.201187]  [<ffffffff81413fa5>] schedule_timeout+0x145/0x180
[ 2041.201196]  [<ffffffff811d32a7>] ? kobject_put+0x27/0x60
[ 2041.201203]  [<ffffffff81413d4d>] wait_for_common+0x14d/0x180
[ 2041.201214]  [<ffffffff81038e30>] ? default_wake_function+0x0/0x10
[ 2041.201224]  [<ffffffff811c02b3>] ? __generic_unplug_device+0x33/0x40
[ 2041.201231]  [<ffffffff81413e18>] wait_for_completion+0x18/0x20
[ 2041.201239]  [<ffffffff811c4cd5>] blk_execute_rq+0x65/0xb0
[ 2041.201246]  [<ffffffff811c0fd0>] ? freed_request+0x30/0x60
[ 2041.201255]  [<ffffffff81296f22>] scsi_execute+0xf2/0x150
[ 2041.201262]  [<ffffffff812971a8>] scsi_execute_req+0xd8/0x150
[ 2041.201271]  [<ffffffff812a6796>] sr_test_unit_ready+0x66/0x100
[ 2041.201280]  [<ffffffff810d6e49>] ? kmem_cache_alloc+0x79/0x110
[ 2041.201288]  [<ffffffff812a76ca>] sr_media_change+0xba/0x2f0
[ 2041.201298]  [<ffffffff8105d6dc>] ? lock_hrtimer_base+0x2c/0x60
[ 2041.201308]  [<ffffffff8130f3b8>] media_changed+0x68/0xb0
[ 2041.201316]  [<ffffffff8130f437>] cdrom_media_changed+0x37/0x40
[ 2041.201324]  [<ffffffff812a68a4>] sr_block_media_changed+0x14/0x20
[ 2041.201333]  [<ffffffff811090fe>] check_disk_change+0x2e/0x70
[ 2041.201341]  [<ffffffff81313ddb>] cdrom_open+0x1ab/0xb60
[ 2041.201349]  [<ffffffff8105a566>] ? remove_wait_queue+0x46/0x60
[ 2041.201357]  [<ffffffff810ee496>] ? poll_freewait+0x46/0xb0
[ 2041.201365]  [<ffffffff810ee8e9>] ? do_sys_poll+0x3e9/0x4c0
[ 2041.201372]  [<ffffffff810ef340>] ? __pollwait+0x0/0x100
[ 2041.201380]  [<ffffffff810ef440>] ? pollwake+0x0/0x50
[ 2041.201387]  [<ffffffff811d361a>] ? kobject_get+0x1a/0x30
[ 2041.201394]  [<ffffffff811c70bf>] ? get_disk+0x2f/0x90
[ 2041.201401]  [<ffffffff811d361a>] ? kobject_get+0x1a/0x30
[ 2041.201409]  [<ffffffff812a6a6a>] sr_block_open+0x7a/0xd0
[ 2041.201417]  [<ffffffff8110a24e>] __blkdev_get+0x21e/0x3a0
[ 2041.201426]  [<ffffffff810f761a>] ? mntput_no_expire+0x2a/0x140
[ 2041.201433]  [<ffffffff8110a3db>] blkdev_get+0xb/0x10
[ 2041.201440]  [<ffffffff8110a44c>] blkdev_open+0x6c/0xc0
[ 2041.201449]  [<ffffffff810dc5d6>] __dentry_open+0xe6/0x2e0
[ 2041.201456]  [<ffffffff8110a3e0>] ? blkdev_open+0x0/0xc0
[ 2041.201463]  [<ffffffff810dc8d7>] nameidata_to_filp+0x57/0x70
[ 2041.201471]  [<ffffffff810eb6f2>] do_filp_open+0x2a2/0x9d0
[ 2041.201479]  [<ffffffff810cb5ad>] ? free_pages_and_swap_cache+0x8d/0xb0
[ 2041.201489]  [<ffffffff810c2640>] ? unmap_region+0x140/0x160
[ 2041.201496]  [<ffffffff810f5c8a>] ? alloc_fd+0x4a/0x140
[ 2041.201503]  [<ffffffff810dc41b>] do_sys_open+0x7b/0x100
[ 2041.201510]  [<ffffffff810dc4cb>] sys_open+0x1b/0x20
[ 2041.201519]  [<ffffffff8100bf2b>] system_call_fastpath+0x16/0x1b
[ 2041.201542] INFO: task wodim:6398 blocked for more than 120 seconds.
[ 2041.201562] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 2041.201568] wodim         D 0000000000000000     0  6398   5313
[ 2041.201575]  ffff8800d805d868 0000000000000082 ffff880118ed40d0 0000000000000000
[ 2041.201584]  00000000000110c0 000000000000c848 ffff8800d4164320 ffff88011b884320
[ 2041.201593]  ffff8800d41646c0 0000000118ed5e48 000000010005d5b2 ffff880118ed4000
[ 2041.201602] Call Trace:
[ 2041.201610]  [<ffffffff81413ae9>] schedule+0x9/0x20
[ 2041.201617]  [<ffffffff81413fa5>] schedule_timeout+0x145/0x180
[ 2041.201625]  [<ffffffff81295590>] ? scsi_request_fn+0xd0/0x570
[ 2041.201632]  [<ffffffff81413d4d>] wait_for_common+0x14d/0x180
[ 2041.201641]  [<ffffffff81038e30>] ? default_wake_function+0x0/0x10
[ 2041.201649]  [<ffffffff811c029a>] ? __generic_unplug_device+0x1a/0x40
[ 2041.201656]  [<ffffffff81413e18>] wait_for_completion+0x18/0x20
[ 2041.201663]  [<ffffffff811c4cd5>] blk_execute_rq+0x65/0xb0
[ 2041.201669]  [<ffffffff811c4896>] ? blk_rq_append_bio+0x26/0x70
[ 2041.201676]  [<ffffffff811c4a8a>] ? blk_rq_map_user+0x1aa/0x2a0
[ 2041.201684]  [<ffffffff8104bc4e>] ? capable+0xe/0x50
[ 2041.201691]  [<ffffffff811c8734>] sg_io+0x1d4/0x400
[ 2041.201699]  [<ffffffff810a8cd2>] ? mempool_free_slab+0x12/0x20
[ 2041.201707]  [<ffffffff811c9015>] scsi_cmd_ioctl+0x2e5/0x4d0
[ 2041.201715]  [<ffffffff81038c48>] ? try_to_wake_up+0x148/0x330
[ 2041.201723]  [<ffffffff81038e3d>] ? default_wake_function+0xd/0x10
[ 2041.201732]  [<ffffffff81312add>] cdrom_ioctl+0x3d/0x1050
[ 2041.201741]  [<ffffffff8124d1f2>] ? n_tty_receive_buf+0x772/0x11e0
[ 2041.201750]  [<ffffffff812a690b>] sr_block_ioctl+0x5b/0xb0
[ 2041.201757]  [<ffffffff811c606e>] __blkdev_driver_ioctl+0x8e/0xa0
[ 2041.201765]  [<ffffffff811c616d>] blkdev_ioctl+0xad/0x9e0
[ 2041.201772]  [<ffffffff810a6df4>] ? filemap_fault+0x144/0x450
[ 2041.201778]  [<ffffffff810a68f2>] ? unlock_page+0x22/0x30
[ 2041.201786]  [<ffffffff810bc2bd>] ? __do_fault+0x42d/0x4e0
[ 2041.201795]  [<ffffffff81108eb5>] block_ioctl+0x35/0x40
[ 2041.201802]  [<ffffffff810ed0c1>] vfs_ioctl+0x31/0xa0
[ 2041.201809]  [<ffffffff810ed1ba>] do_vfs_ioctl+0x8a/0x570
[ 2041.201816]  [<ffffffff811d77b1>] ? __up_read+0x91/0xb0
[ 2041.201824]  [<ffffffff8105dff9>] ? up_read+0x9/0x10
[ 2041.201831]  [<ffffffff810ed739>] sys_ioctl+0x99/0xa0
[ 2041.201840]  [<ffffffff8100bf2b>] system_call_fastpath+0x16/0x1b

Looking at hald/linux/addons/addon-storage.c it does appear to
open(O_EXCL) as well, so perhaps the O_EXCL multiple-open logic broke
recently?

Complete dmesg, kconfig, and so on at

http://web.hexapodia.org/~adi/sysinfo/1242164411_cvpe4300_2.6.30-rc5-dmar-00096-ga4d7749/

-andy

Re: [2.6.30-rc2] CD-R: wodim intermittent failures: [sr0] Add. Sense: Logical block address out of range, sector 0

[Robert Hancock]

Andy Isaacson wrote:
> On Thu, Apr 23, 2009 at 12:07:13AM -0700, Andy Isaacson wrote:
>> On Thu, Apr 23, 2009 at 12:46:19AM -0600, Robert Hancock wrote:
>>>> Oh well, let's tentatively assume that we have a post-2.6.29 regression
>>>> in the libata ahci driver.
>>> I tend to doubt it's a problem in ahci itself, I would guess it's higher 
>>> up the stack. Or could be that it's not a kernel bug, just some change 
>>> in timing that triggers the problem.
>>>
>>> What's supposed to stop udev/hal from poking at the drive while wodim is 
>>> writing to the disc, anyway?
>> wodim opens O_EXCL, and it does occasionally complain about not being
>> able to open, then sleeping and retrying.
> 
> I just saw this again with 2.6.30-rc5-00096-ga4d7749 and got some nice
> stack traces, for both hald-addon-storage and wodim:
> 
> [ 2041.201084] INFO: task hald-addon-stor:3804 blocked for more than 120 seconds.
> [ 2041.201108]  ffff8801145056f8 0000000000000086 ffff880118c66120 0000000000000086
> [ 2041.201118]  00000000000110c0 000000000000c848 ffff8801144b2cc0 ffff8800d8008000
> [ 2041.201127]  ffff8801144b3060 0000000118ddd460 ffff8801145056b8 ffffffff81296405
> [ 2041.201135] Call Trace:
> [ 2041.201153]  [<ffffffff81296405>] ? scsi_setup_blk_pc_cmnd+0x145/0x180
> [ 2041.201162]  [<ffffffff8128f32c>] ? scsi_pool_alloc_command+0x2c/0x80
> [ 2041.201171]  [<ffffffff812a70ad>] ? sr_prep_fn+0x4d/0x5b0
> [ 2041.201180]  [<ffffffff81413ae9>] schedule+0x9/0x20
> [ 2041.201187]  [<ffffffff81413fa5>] schedule_timeout+0x145/0x180
> [ 2041.201196]  [<ffffffff811d32a7>] ? kobject_put+0x27/0x60
> [ 2041.201203]  [<ffffffff81413d4d>] wait_for_common+0x14d/0x180
> [ 2041.201214]  [<ffffffff81038e30>] ? default_wake_function+0x0/0x10
> [ 2041.201224]  [<ffffffff811c02b3>] ? __generic_unplug_device+0x33/0x40
> [ 2041.201231]  [<ffffffff81413e18>] wait_for_completion+0x18/0x20
> [ 2041.201239]  [<ffffffff811c4cd5>] blk_execute_rq+0x65/0xb0
> [ 2041.201246]  [<ffffffff811c0fd0>] ? freed_request+0x30/0x60
> [ 2041.201255]  [<ffffffff81296f22>] scsi_execute+0xf2/0x150
> [ 2041.201262]  [<ffffffff812971a8>] scsi_execute_req+0xd8/0x150
> [ 2041.201271]  [<ffffffff812a6796>] sr_test_unit_ready+0x66/0x100
> [ 2041.201280]  [<ffffffff810d6e49>] ? kmem_cache_alloc+0x79/0x110
> [ 2041.201288]  [<ffffffff812a76ca>] sr_media_change+0xba/0x2f0
> [ 2041.201298]  [<ffffffff8105d6dc>] ? lock_hrtimer_base+0x2c/0x60
> [ 2041.201308]  [<ffffffff8130f3b8>] media_changed+0x68/0xb0
> [ 2041.201316]  [<ffffffff8130f437>] cdrom_media_changed+0x37/0x40
> [ 2041.201324]  [<ffffffff812a68a4>] sr_block_media_changed+0x14/0x20
> [ 2041.201333]  [<ffffffff811090fe>] check_disk_change+0x2e/0x70
> [ 2041.201341]  [<ffffffff81313ddb>] cdrom_open+0x1ab/0xb60
> [ 2041.201349]  [<ffffffff8105a566>] ? remove_wait_queue+0x46/0x60
> [ 2041.201357]  [<ffffffff810ee496>] ? poll_freewait+0x46/0xb0
> [ 2041.201365]  [<ffffffff810ee8e9>] ? do_sys_poll+0x3e9/0x4c0
> [ 2041.201372]  [<ffffffff810ef340>] ? __pollwait+0x0/0x100
> [ 2041.201380]  [<ffffffff810ef440>] ? pollwake+0x0/0x50
> [ 2041.201387]  [<ffffffff811d361a>] ? kobject_get+0x1a/0x30
> [ 2041.201394]  [<ffffffff811c70bf>] ? get_disk+0x2f/0x90
> [ 2041.201401]  [<ffffffff811d361a>] ? kobject_get+0x1a/0x30
> [ 2041.201409]  [<ffffffff812a6a6a>] sr_block_open+0x7a/0xd0
> [ 2041.201417]  [<ffffffff8110a24e>] __blkdev_get+0x21e/0x3a0
> [ 2041.201426]  [<ffffffff810f761a>] ? mntput_no_expire+0x2a/0x140
> [ 2041.201433]  [<ffffffff8110a3db>] blkdev_get+0xb/0x10
> [ 2041.201440]  [<ffffffff8110a44c>] blkdev_open+0x6c/0xc0
> [ 2041.201449]  [<ffffffff810dc5d6>] __dentry_open+0xe6/0x2e0
> [ 2041.201456]  [<ffffffff8110a3e0>] ? blkdev_open+0x0/0xc0
> [ 2041.201463]  [<ffffffff810dc8d7>] nameidata_to_filp+0x57/0x70
> [ 2041.201471]  [<ffffffff810eb6f2>] do_filp_open+0x2a2/0x9d0
> [ 2041.201479]  [<ffffffff810cb5ad>] ? free_pages_and_swap_cache+0x8d/0xb0
> [ 2041.201489]  [<ffffffff810c2640>] ? unmap_region+0x140/0x160
> [ 2041.201496]  [<ffffffff810f5c8a>] ? alloc_fd+0x4a/0x140
> [ 2041.201503]  [<ffffffff810dc41b>] do_sys_open+0x7b/0x100
> [ 2041.201510]  [<ffffffff810dc4cb>] sys_open+0x1b/0x20
> [ 2041.201519]  [<ffffffff8100bf2b>] system_call_fastpath+0x16/0x1b
> [ 2041.201542] INFO: task wodim:6398 blocked for more than 120 seconds.
> [ 2041.201562] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> [ 2041.201568] wodim         D 0000000000000000     0  6398   5313
> [ 2041.201575]  ffff8800d805d868 0000000000000082 ffff880118ed40d0 0000000000000000
> [ 2041.201584]  00000000000110c0 000000000000c848 ffff8800d4164320 ffff88011b884320
> [ 2041.201593]  ffff8800d41646c0 0000000118ed5e48 000000010005d5b2 ffff880118ed4000
> [ 2041.201602] Call Trace:
> [ 2041.201610]  [<ffffffff81413ae9>] schedule+0x9/0x20
> [ 2041.201617]  [<ffffffff81413fa5>] schedule_timeout+0x145/0x180
> [ 2041.201625]  [<ffffffff81295590>] ? scsi_request_fn+0xd0/0x570
> [ 2041.201632]  [<ffffffff81413d4d>] wait_for_common+0x14d/0x180
> [ 2041.201641]  [<ffffffff81038e30>] ? default_wake_function+0x0/0x10
> [ 2041.201649]  [<ffffffff811c029a>] ? __generic_unplug_device+0x1a/0x40
> [ 2041.201656]  [<ffffffff81413e18>] wait_for_completion+0x18/0x20
> [ 2041.201663]  [<ffffffff811c4cd5>] blk_execute_rq+0x65/0xb0
> [ 2041.201669]  [<ffffffff811c4896>] ? blk_rq_append_bio+0x26/0x70
> [ 2041.201676]  [<ffffffff811c4a8a>] ? blk_rq_map_user+0x1aa/0x2a0
> [ 2041.201684]  [<ffffffff8104bc4e>] ? capable+0xe/0x50
> [ 2041.201691]  [<ffffffff811c8734>] sg_io+0x1d4/0x400
> [ 2041.201699]  [<ffffffff810a8cd2>] ? mempool_free_slab+0x12/0x20
> [ 2041.201707]  [<ffffffff811c9015>] scsi_cmd_ioctl+0x2e5/0x4d0
> [ 2041.201715]  [<ffffffff81038c48>] ? try_to_wake_up+0x148/0x330
> [ 2041.201723]  [<ffffffff81038e3d>] ? default_wake_function+0xd/0x10
> [ 2041.201732]  [<ffffffff81312add>] cdrom_ioctl+0x3d/0x1050
> [ 2041.201741]  [<ffffffff8124d1f2>] ? n_tty_receive_buf+0x772/0x11e0
> [ 2041.201750]  [<ffffffff812a690b>] sr_block_ioctl+0x5b/0xb0
> [ 2041.201757]  [<ffffffff811c606e>] __blkdev_driver_ioctl+0x8e/0xa0
> [ 2041.201765]  [<ffffffff811c616d>] blkdev_ioctl+0xad/0x9e0
> [ 2041.201772]  [<ffffffff810a6df4>] ? filemap_fault+0x144/0x450
> [ 2041.201778]  [<ffffffff810a68f2>] ? unlock_page+0x22/0x30
> [ 2041.201786]  [<ffffffff810bc2bd>] ? __do_fault+0x42d/0x4e0
> [ 2041.201795]  [<ffffffff81108eb5>] block_ioctl+0x35/0x40
> [ 2041.201802]  [<ffffffff810ed0c1>] vfs_ioctl+0x31/0xa0
> [ 2041.201809]  [<ffffffff810ed1ba>] do_vfs_ioctl+0x8a/0x570
> [ 2041.201816]  [<ffffffff811d77b1>] ? __up_read+0x91/0xb0
> [ 2041.201824]  [<ffffffff8105dff9>] ? up_read+0x9/0x10
> [ 2041.201831]  [<ffffffff810ed739>] sys_ioctl+0x99/0xa0
> [ 2041.201840]  [<ffffffff8100bf2b>] system_call_fastpath+0x16/0x1b
> 
> Looking at hald/linux/addons/addon-storage.c it does appear to
> open(O_EXCL) as well, so perhaps the O_EXCL multiple-open logic broke
> recently?
> 
> Complete dmesg, kconfig, and so on at
> 
> http://web.hexapodia.org/~adi/sysinfo/1242164411_cvpe4300_2.6.30-rc5-dmar-00096-ga4d7749/
> 
> -andy

I'm not sure how this is supposed to work. The only place I can see any 
O_EXCL handling is in the sg driver. But if you access the sr device 
directly, it doesn't seem like that would have any effect.

CCing linux-scsi. Could be there's a bad user-space assumption here, or 
something.

Re: [2.6.30-rc2] CD-R: wodim intermittent failures: [sr0] Add. Sense: Logical block address out of range, sector 0

[Andy Isaacson]

On Tue, May 12, 2009 at 05:23:57PM -0600, Robert Hancock wrote:
> >Looking at hald/linux/addons/addon-storage.c it does appear to
> >open(O_EXCL) as well, so perhaps the O_EXCL multiple-open logic broke
> >recently?
> >
> >Complete dmesg, kconfig, and so on at
> >
> >http://web.hexapodia.org/~adi/sysinfo/1242164411_cvpe4300_2.6.30-rc5-dmar-00096-ga4d7749/
> 
> I'm not sure how this is supposed to work. The only place I can see any 
> O_EXCL handling is in the sg driver. But if you access the sr device 
> directly, it doesn't seem like that would have any effect.
> 
> CCing linux-scsi. Could be there's a bad user-space assumption here, or 
> something.

Perhaps, I haven't tracked down exactly what the difference in behavior
between working 2.6.29 and broken 2.6.30-rc2 is.  It seems like the disk
spins up more often (in response to hal background probes presumably)
with 30-rc2 than it did before, and running "udevadm monitor" I do see
the following repeated "change" events happening, even on an idle
system:

KERNEL[1242175547.793029] change   /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0 (scsi)
KERNEL[1242175547.794669] change   /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0/block/sr0 (block)
UDEV  [1242175547.794912] change   /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0 (scsi)
UDEV  [1242175547.888539] change   /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0/block/sr0 (block)
KERNEL[1242175673.309129] change   /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0 (scsi)
KERNEL[1242175673.310775] change   /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0/block/sr0 (block)
UDEV  [1242175673.311013] change   /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0 (scsi)
UDEV  [1242175674.658718] change   /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0/block/sr0 (block)
KERNEL[1242175690.227604] change   /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0 (scsi)
KERNEL[1242175690.229730] change   /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0/block/sr0 (block)
UDEV  [1242175690.229960] change   /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0 (scsi)
UDEV  [1242175714.060440] change   /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0/block/sr0 (block)
KERNEL[1242175727.909819] change   /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0 (scsi)
KERNEL[1242175727.911356] change   /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0/block/sr0 (block)
UDEV  [1242175727.911690] change   /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0 (scsi)
UDEV  [1242175727.987747] change   /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0/block/sr0 (block)
KERNEL[1242175731.591853] change   /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0 (scsi)
KERNEL[1242175731.593541] change   /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0/block/sr0 (block)

I've verified that O_EXCL works at least with a trivial test program, so
it's not simply that EXCL broke.

Also I've verified with strace that hald-addon-storage and wodim are
both using O_EXCL, and that hald-addon-storage gets EBUSY while wodim is
writing the disk.  (The straced run didn't fail, unfortunately.)

-andy

Re: [2.6.30-rc2] CD-R: wodim intermittent failures: [sr0] Add. Sense: Logical block address out of range, sector 0

[Robert Hancock]

On Tue, May 12, 2009 at 7:00 PM, Andy Isaacson <adi@hexapodia.org> wrote:
> On Tue, May 12, 2009 at 05:23:57PM -0600, Robert Hancock wrote:
>> >Looking at hald/linux/addons/addon-storage.c it does appear to
>> >open(O_EXCL) as well, so perhaps the O_EXCL multiple-open logic broke
>> >recently?
>> >
>> >Complete dmesg, kconfig, and so on at
>> >
>> >http://web.hexapodia.org/~adi/sysinfo/1242164411_cvpe4300_2.6.30-rc5-dmar-00096-ga4d7749/
>>
>> I'm not sure how this is supposed to work. The only place I can see any
>> O_EXCL handling is in the sg driver. But if you access the sr device
>> directly, it doesn't seem like that would have any effect.
>>
>> CCing linux-scsi. Could be there's a bad user-space assumption here, or
>> something.
>
> Perhaps, I haven't tracked down exactly what the difference in behavior
> between working 2.6.29 and broken 2.6.30-rc2 is.  It seems like the disk
> spins up more often (in response to hal background probes presumably)
> with 30-rc2 than it did before, and running "udevadm monitor" I do see
> the following repeated "change" events happening, even on an idle
> system:
>
> KERNEL[1242175547.793029] change   /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0 (scsi)
> KERNEL[1242175547.794669] change   /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0/block/sr0 (block)
> UDEV  [1242175547.794912] change   /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0 (scsi)
> UDEV  [1242175547.888539] change   /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0/block/sr0 (block)
> KERNEL[1242175673.309129] change   /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0 (scsi)
> KERNEL[1242175673.310775] change   /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0/block/sr0 (block)
> UDEV  [1242175673.311013] change   /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0 (scsi)
> UDEV  [1242175674.658718] change   /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0/block/sr0 (block)
> KERNEL[1242175690.227604] change   /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0 (scsi)
> KERNEL[1242175690.229730] change   /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0/block/sr0 (block)
> UDEV  [1242175690.229960] change   /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0 (scsi)
> UDEV  [1242175714.060440] change   /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0/block/sr0 (block)
> KERNEL[1242175727.909819] change   /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0 (scsi)
> KERNEL[1242175727.911356] change   /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0/block/sr0 (block)
> UDEV  [1242175727.911690] change   /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0 (scsi)
> UDEV  [1242175727.987747] change   /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0/block/sr0 (block)
> KERNEL[1242175731.591853] change   /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0 (scsi)
> KERNEL[1242175731.593541] change   /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0/block/sr0 (block)
>
> I've verified that O_EXCL works at least with a trivial test program, so
> it's not simply that EXCL broke.
>
> Also I've verified with strace that hald-addon-storage and wodim are
> both using O_EXCL, and that hald-addon-storage gets EBUSY while wodim is
> writing the disk.  (The straced run didn't fail, unfortunately.)

Those events seem rather suspicious. Hmm:

[    2.770959] ata2.00: ATAPI: TSSTcorp DVD+/-RW TS-U633A, D200, max
UDMA/100, ATAPI AN

Did libata report it was using ATAPI AN in 2.6.29?

You could try bisecting to see if you can find which patch started
triggering those spurious events..

Re: [2.6.30-rc2] CD-R: wodim intermittent failures: [sr0] Add. Sense: Logical block address out of range, sector 0

[Robert Hancock]

On Tue, May 12, 2009 at 7:00 PM, Andy Isaacson <adi@hexapodia.org> wrote:
> On Tue, May 12, 2009 at 05:23:57PM -0600, Robert Hancock wrote:
>> >Looking at hald/linux/addons/addon-storage.c it does appear to
>> >open(O_EXCL) as well, so perhaps the O_EXCL multiple-open logic broke
>> >recently?
>> >
>> >Complete dmesg, kconfig, and so on at
>> >
>> >http://web.hexapodia.org/~adi/sysinfo/1242164411_cvpe4300_2.6.30-rc5-dmar-00096-ga4d7749/
>>
>> I'm not sure how this is supposed to work. The only place I can see any
>> O_EXCL handling is in the sg driver. But if you access the sr device
>> directly, it doesn't seem like that would have any effect.
>>
>> CCing linux-scsi. Could be there's a bad user-space assumption here, or
>> something.
>
> Perhaps, I haven't tracked down exactly what the difference in behavior
> between working 2.6.29 and broken 2.6.30-rc2 is.  It seems like the disk
> spins up more often (in response to hal background probes presumably)
> with 30-rc2 than it did before, and running "udevadm monitor" I do see
> the following repeated "change" events happening, even on an idle
> system:
>
> KERNEL[1242175547.793029] change   /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0 (scsi)
> KERNEL[1242175547.794669] change   /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0/block/sr0 (block)
> UDEV  [1242175547.794912] change   /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0 (scsi)
> UDEV  [1242175547.888539] change   /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0/block/sr0 (block)
> KERNEL[1242175673.309129] change   /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0 (scsi)
> KERNEL[1242175673.310775] change   /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0/block/sr0 (block)
> UDEV  [1242175673.311013] change   /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0 (scsi)
> UDEV  [1242175674.658718] change   /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0/block/sr0 (block)
> KERNEL[1242175690.227604] change   /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0 (scsi)
> KERNEL[1242175690.229730] change   /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0/block/sr0 (block)
> UDEV  [1242175690.229960] change   /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0 (scsi)
> UDEV  [1242175714.060440] change   /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0/block/sr0 (block)
> KERNEL[1242175727.909819] change   /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0 (scsi)
> KERNEL[1242175727.911356] change   /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0/block/sr0 (block)
> UDEV  [1242175727.911690] change   /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0 (scsi)
> UDEV  [1242175727.987747] change   /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0/block/sr0 (block)
> KERNEL[1242175731.591853] change   /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0 (scsi)
> KERNEL[1242175731.593541] change   /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0/block/sr0 (block)
>
> I've verified that O_EXCL works at least with a trivial test program, so
> it's not simply that EXCL broke.
>
> Also I've verified with strace that hald-addon-storage and wodim are
> both using O_EXCL, and that hald-addon-storage gets EBUSY while wodim is
> writing the disk.  (The straced run didn't fail, unfortunately.)

Those events seem rather suspicious. Hmm:

[    2.770959] ata2.00: ATAPI: TSSTcorp DVD+/-RW TS-U633A, D200, max
UDMA/100, ATAPI AN

Did libata report it was using ATAPI AN in 2.6.29?

You could try bisecting to see if you can find which patch started
triggering those spurious events..

Re: [2.6.30-rc2] CD-R: wodim intermittent failures: [sr0] Add. Sense: Logical block address out of range, sector 0

[Andy Isaacson]

On Tue, May 12, 2009 at 07:08:54PM -0600, Robert Hancock wrote:
> On Tue, May 12, 2009 at 7:00 PM, Andy Isaacson <adi@hexapodia.org> wrote:
> > Perhaps, I haven't tracked down exactly what the difference in behavior
> > between working 2.6.29 and broken 2.6.30-rc2 is. ?It seems like the disk
> > spins up more often (in response to hal background probes presumably)
> > with 30-rc2 than it did before, and running "udevadm monitor" I do see
> > the following repeated "change" events happening, even on an idle
> > system:
> >
> > KERNEL[1242175547.793029] change ? /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0 (scsi)
> > KERNEL[1242175547.794669] change ? /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0/block/sr0 (block)
[snip]
> Those events seem rather suspicious. Hmm:
> 
> [    2.770959] ata2.00: ATAPI: TSSTcorp DVD+/-RW TS-U633A, D200, max
> UDMA/100, ATAPI AN
> 
> Did libata report it was using ATAPI AN in 2.6.29?

Yes, AN is present in every log I have for that device (back to
2.6.28.1).

> You could try bisecting to see if you can find which patch started
> triggering those spurious events..

Heh, I was dreading a bisect where each step burned a coaster, but just
looking for events is easy.  I'll try that tomorrow.

-andy

Re: [2.6.30-rc2] CD-R: wodim intermittent failures: [sr0] Add. Sense: Logical block address out of range, sector 0

[Joerg Schilling]

I see two possible problems that should be first resolved.

1)	You are using "wodim" instead of cdrecord.
	"wodim" is a very old version (4+ years) of cdrecord with
	additional bugs. Due to Copyright & GPL violations, it cannot
	even be legally distributed.

2)	You may be using the linux hald version

I recommend to first get a recent original cdrtools package from

ftp://ftp.berlios.de/pub/cdrecord/alpha/

and to try with this after running "make install" as root.
As Linux requires root privileges for many SCSI commands, you need to 
install cdreord suid root which is automatically done via "make install"
as root.

If your problem persists, try to kill hald. Hald on Linux has many problems:

-	It looks for the wrong state transitions on the CD drive 
	and thus distrurbes CD/DVD/BD writing. It may e.g. try to mount a CD 
	that has not yet been fully written.

-	The O_EXCL metod it believes on just cannot ever work correctly:

	-	You would not be able to read out written media CD-DA or CD-ROM

	-	You would not be able to deal with multi-session media

	-	As Linux offers to access CD/DVD/BD-drives vie more than one
		device driver and as these device drivers don't know each other
		O_EXCL cannot work anyway.

If your problem still persists, you may have a Linux kernel problem.

BTW: please keep me on CC:

Jörg

-- 
 EMail:joerg@schily.isdn.cs.tu-berlin.de (home) Jörg Schilling D-13353 Berlin
       js@cs.tu-berlin.de                (uni)  
       joerg.schilling@fokus.fraunhofer.de (work) Blog: http://schily.blogspot.com/
 URL:  http://cdrecord.berlios.de/private/ ftp://ftp.berlios.de/pub/schily

Re: [2.6.30-rc2] CD-R: wodim intermittent failures: [sr0] Add. Sense: Logical block address out of range, sector 0

[Bill Davidsen]

Joerg Schilling wrote:
> I see two possible problems that should be first resolved.
> 
> 1)	You are using "wodim" instead of cdrecord.
> 	"wodim" is a very old version (4+ years) of cdrecord with
> 	additional bugs. Due to Copyright & GPL violations, it cannot
> 	even be legally distributed.
> 
> 2)	You may be using the linux hald version
> 
> I recommend to first get a recent original cdrtools package from
> 
> ftp://ftp.berlios.de/pub/cdrecord/alpha/
> 
> and to try with this after running "make install" as root.
> As Linux requires root privileges for many SCSI commands, you need to 
> install cdreord suid root which is automatically done via "make install"
> as root.
> 
> If your problem persists, try to kill hald. Hald on Linux has many problems:
> 
> -	It looks for the wrong state transitions on the CD drive 
> 	and thus distrurbes CD/DVD/BD writing. It may e.g. try to mount a CD 
> 	that has not yet been fully written.
> 
Appears to be true, but that's not a kernel problem, it's a hald problem, the 
fix belongs there.

> -	The O_EXCL metod it believes on just cannot ever work correctly:
> 
> 	-	You would not be able to read out written media CD-DA or CD-ROM
> 
> 	-	You would not be able to deal with multi-session media
> 
I don't quite see how these two follow from using O-EXCL, assuming the device is 
released after writing, but see next:

> 	-	As Linux offers to access CD/DVD/BD-drives vie more than one
> 		device driver and as these device drivers don't know each other
> 		O_EXCL cannot work anyway.
> 
And that is a kernel problem, allowing multiple access paths which don't share 
exclusion is a dubious design decision. O_EXCL really should work.

> If your problem still persists, you may have a Linux kernel problem.
> 
The usual solution is to tell hald and your window manager of choice not to 
mount things automatically, or at least not while they are opened. But that's a 
fudge, not a fix, O_EXCL should positively prevent this problem.

> BTW: please keep me on CC:
> 
> Jörg
> 


-- 
Bill Davidsen <davidsen@tmr.com>
   "We have more to fear from the bungling of the incompetent than from
the machinations of the wicked."  - from Slashdot

Re: [2.6.30-rc2] CD-R: wodim intermittent failures: [sr0] Add. Sense: Logical block address out of range, sector 0

[Kyle Moffett]

On Thu, Apr 23, 2009 at 10:48 AM, Joerg Schilling
<Joerg.Schilling@fokus.fraunhofer.de> wrote:
> I see two possible problems that should be first resolved.
>
> 1)      You are using "wodim" instead of cdrecord.
>        "wodim" is a very old version (4+ years) of cdrecord with
>        additional bugs. Due to Copyright & GPL violations, it cannot
>        even be legally distributed.

Not to get into a flamewar on this, but multiple sources disagree with
you on this point.  Just so it is clear... I do not expect a reply to
this message and I will not read one if it is sent.  I simply wish to
exercise my free speech rights and provide potentially useful
information.

Since you released cdrtools under the GPL, you cannot possibly expect
to claim that someone else distributing a copy under the same license
is violating your copyright.  You also cannot claim trademark
violations as the maintainers of "wodim" intentionally changed the
names of all of the programs.  Debian-based systems no longer even
install the "compatibility symlinks" that you claim to have a problem
with, and have not for some time.  Furthermore, you have certainly
never held a patent on the cdrecord design.

References:
http://lwn.net/Articles/195167/
http://en.wikipedia.org/wiki/Cdrkit
http://www.cdrkit.org/

If you would like to contest specifics of GPL compliance, please also
reference a rather extensive body of other GPL work (incl. the Linux
kernel) which does *NOT* require the following (this list partially
taken from your webpage at
http://cdrecord.berlios.de/new/private/linux-dist.html):

  *  Tracking the author and date for every individual change in every
file.  If this was true, the Linux kernel source (for example) would
be roughly 95% changelogs.

  *  Displaying the copyright messages exactly the same way the
original author does.  The GPL requires that you must preserve the
contents of the copyrights and attribution and make them easily
accessible to the user.

  *  Including source code beyond what was used to produce a specific
binary version.  If I delete code for specific kernel modules from a
kernel tarball and distribute the resulting kernel binary I am legally
*required* to distribute the modified sources (as opposed to the
original sources).

I cannot comment on German legal code as I am neither fluent in German
nor well-versed in that particular legal code.  On the other hand, I
can state that neither of the restrictions you specify apply to
distribution of GPLed binaries within the US.  This is especially true
as the GPL contains the statement that "this software comes without
any warranty whatsoever".

It would be very difficult for someone to prove tangible harm to
reputation from software distributed by a third party under the
original author's terms of "no warranty whatsoever, not even including
the implied warranties of merchantability or fitness for a particular
purpose".


And back to something vaguely resembling the original topic:
> As Linux requires root privileges for many SCSI commands, you need to
> install cdreord suid root which is automatically done via "make install"
> as root.

If you discover that you need root privileges to burn a CD or DVD,
that is a kernel bug and we would very much appreciate a bugreport.

Cheers,
Kyle Moffett

Re: [2.6.30-rc2] CD-R: wodim intermittent failures: [sr0] Add. Sense: Logical block address out of range, sector 0

[Joerg Schilling]

Kyle Moffett <kyle@moffetthome.net> wrote:

> On Thu, Apr 23, 2009 at 10:48 AM, Joerg Schilling
> <Joerg.Schilling@fokus.fraunhofer.de> wrote:
> > I see two possible problems that should be first resolved.
> >
> > 1)      You are using "wodim" instead of cdrecord.
> >        "wodim" is a very old version (4+ years) of cdrecord with
> >        additional bugs. Due to Copyright & GPL violations, it cannot
> >        even be legally distributed.
>
> Not to get into a flamewar on this, but multiple sources disagree with
> you on this point.  Just so it is clear... I do not expect a reply to
> this message and I will not read one if it is sent.  I simply wish to
> exercise my free speech rights and provide potentially useful
> information.

I cannot speak for other parts of the world (e.g. USA) but in Europe, 
Free Speech ends in case you try to you distribute incorrect claims.

> Since you released cdrtools under the GPL, you cannot possibly expect
> to claim that someone else distributing a copy under the same license
> is violating your copyright.  You also cannot claim trademark

It seems that you are not well informed about the Copyright law.
The Copyrigfht law has a higher precedence than a private contract like the GPL.
For specifc terms, the GPL text is irrelevent and the Copyright law applies.

> References:
> http://lwn.net/Articles/195167/
> http://en.wikipedia.org/wiki/Cdrkit
> http://www.cdrkit.org/

Why do you quote FUD?


> If you would like to contest specifics of GPL compliance, please also
> reference a rather extensive body of other GPL work (incl. the Linux
> kernel) which does *NOT* require the following (this list partially
> taken from your webpage at
> http://cdrecord.berlios.de/new/private/linux-dist.html):
>
>   *  Tracking the author and date for every individual change in every
> file.  If this was true, the Linux kernel source (for example) would
> be roughly 95% changelogs.

This is a requirement from the GPL and nobody usually care about this 
unless you have an extremely hostile downdstream like "Eduard Bloch"
who mainly spreads personal insults against the authors of an OSS project and 
who is not interested in the OSS project itself. If there is such a hostile
downstream, you start looking at the "official regulations".

>   *  Displaying the copyright messages exactly the same way the
> original author does.  The GPL requires that you must preserve the
> contents of the copyrights and attribution and make them easily
> accessible to the user.

This is a result of the Copyright law. Bloch ignores the Copyright law by 
removing Copyright signs that I consider important. So far this is the first 
time I see that a downstream did remove Copyright signs.....

As you quoted http://cdrecord.berlios.de/private/linux-dist.html, you know that
the fork is full of bugs and dead since more than 2 years. Some of the bugs 
have been in the very outdated original software many others have been added by
the initiators of the fork. 

The original software however is under constant development, fixed a lot of 
bugs during the past 3 years and added many interesting new features. Why 
should people care about a fork that was not created in favor of the users but 
just as a specifc way to attack a popular OSS project?


> And back to something vaguely resembling the original topic:
> > As Linux requires root privileges for many SCSI commands, you need to
> > install cdreord suid root which is automatically done via "make install"
> > as root.
>
> If you discover that you need root privileges to burn a CD or DVD,
> that is a kernel bug and we would very much appreciate a bugreport.

You need root privileges on Linux in order to write CDs/DVDs as long as Linux 
exists. If you consider this to be a bug, then you seem to consider security a
bug. 

Jörg

-- 
 EMail:joerg@schily.isdn.cs.tu-berlin.de (home) Jörg Schilling D-13353 Berlin
       js@cs.tu-berlin.de                (uni)  
       joerg.schilling@fokus.fraunhofer.de (work) Blog: http://schily.blogspot.com/
 URL:  http://cdrecord.berlios.de/private/ ftp://ftp.berlios.de/pub/schily