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 -- To unsubscribe from this list: send the line "unsubscribe linux-ide" in the body of a message to majordomo@xxxxxxxxxxxxxxx More majordomo info at http://vger.kernel.org/majordomo-info.html
