Fedora Account System
Red Hat Associate
Red Hat Customer
Description of problem: Burning an ordinary data CD project (using either GNOME CD Creator or K3B) proceeds in a straightforward manner, until the finalizing stage. Then, the drive will repeatedly grunt, spin down and spin up again. Sometimes this process halts and the burn process completes. Other times, when using K3B and wodim, the latter gets stuck in uninterruptible sleep and the system must be forcibly rebooted. Nevertheless, the burnt CD is usable. Drive: /dev/scd0 Vendor : TSSTcorp Model : CDDVDW SN-S082H Revision : SB00 Version-Release number of selected component (if applicable): kernel-2.6.33.5-124.fc13.x86_64 wodim-1.1.10-1.fc13.x86_64 genisoimage-1.1.10-1.fc13.x86_64 How reproducible: Always. Steps to Reproduce: 1. Burn a disc. Actual results: Lots of grunting/never finished finalizing. Expected results: Finalizing finishes without fuss.
Do you see something in /var/log/messages?
(In reply to comment #1) > Do you see something in /var/log/messages? Nothing unusual (i.e., apart from the standard "This disc doesn't have any tracks I recognize!") from either the kernel or any tools.
Happened again after I burned an audio CD. The drive cycled and grunted fifteen times before I killed all instances of udevd. It was still locked. Then I noticed: 1372 ? D 0:10 hald-addon-storage: no polling because /dev/sr0 is locked via O_EXCL killed that, and the system recovered.
Following was in dmesg: INFO: task hald-addon-stor:1372 blocked for more than 120 seconds. "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. hald-addon-st D ffff880037579528 0 1372 1329 0x00000080 ffff88006aa4bbd8 0000000000000086 000000000000001b 0000000000000010 ffff88006aa4bb58 ffff88007bde8a20 ffff88006aa4bb58 ffff88006aa4a000 000000000000f970 0000000000014b80 ffff88006aaf2b48 00000000811c876c Call Trace: [<ffffffff81204195>] ? kobject_get+0x1a/0x22 [<ffffffff8142e93d>] __mutex_lock_common+0x17f/0x25e [<ffffffff811f7b7b>] ? exact_match+0x0/0xa [<ffffffff8142ea30>] __mutex_lock_slowpath+0x14/0x16 [<ffffffff8142eb28>] mutex_lock+0x2c/0x46 [<ffffffff811f80e1>] ? get_gendisk+0x2b/0xb8 [<ffffffff81127cc0>] __blkdev_get+0x89/0x391 [<ffffffff81127fd5>] ? blkdev_open+0x0/0xa7 [<ffffffff81127fd3>] blkdev_get+0xb/0xd [<ffffffff81128046>] blkdev_open+0x71/0xa7 [<ffffffff81100594>] __dentry_open+0x208/0x33f [<ffffffff811c3bd1>] ? security_inode_permission+0x1c/0x1e [<ffffffff81100790>] nameidata_to_filp+0x3a/0x4b [<ffffffff8110d6f4>] do_filp_open+0x571/0xaea [<ffffffff8120bb6d>] ? __strncpy_from_user+0x29/0x53 [<ffffffff8142fbb6>] ? _raw_spin_unlock+0x26/0x31 [<ffffffff811002a3>] do_sys_open+0x5e/0x10a [<ffffffff81100378>] sys_open+0x1b/0x1d [<ffffffff81009c02>] system_call_fastpath+0x16/0x1b INFO: task udisks-daemon:1918 blocked for more than 120 seconds. "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. udisks-daemon D 00000000ffffffff 0 1918 1905 0x00000080 ffff88005f961798 0000000000000082 ffff88005f961760 ffff88005f96175c ffff88005f961728 0000000000000000 0000000000000400 ffff88005f960000 000000000000f970 0000000000014b80 ffff88006333cb08 0000000101e2082a Call Trace: [<ffffffff8142e438>] schedule_timeout+0x31/0xde [<ffffffff81203efc>] ? kobject_put+0x47/0x4b [<ffffffff8142f971>] ? _raw_spin_lock_irq+0x1d/0x3c [<ffffffff812cbf30>] ? scsi_request_fn+0x403/0x4c6 [<ffffffff8142d82f>] wait_for_common+0xac/0xfd [<ffffffff8103ce52>] ? default_wake_function+0x0/0xf [<ffffffff811efdb1>] ? __generic_unplug_device+0x2d/0x31 [<ffffffff8142d90a>] wait_for_completion+0x18/0x1a [<ffffffff811f5ee0>] blk_execute_rq+0xa1/0xd1 [<ffffffff811f0c3e>] ? blk_get_request+0x3c/0x6c [<ffffffff812cd02a>] scsi_execute+0xf1/0x143 [<ffffffff812cd12f>] scsi_execute_req+0xb3/0xe5 [<ffffffff812d7dc2>] sr_test_unit_ready+0x60/0xc6 [<ffffffff812d80dc>] ? sr_media_change+0x39/0x2ad [<ffffffff812d8124>] sr_media_change+0x81/0x2ad [<ffffffff8142f9b5>] ? _raw_spin_lock_irqsave+0x25/0x47 [<ffffffff8142fbf4>] ? _raw_spin_unlock_irqrestore+0x33/0x3e [<ffffffff811c7f28>] ? rcu_read_unlock+0x23/0x2e [<ffffffff812f8742>] media_changed+0x4f/0x87 [<ffffffff812f87a6>] cdrom_media_changed+0x2c/0x32 [<ffffffff812d7e7b>] sr_block_media_changed+0x14/0x16 [<ffffffff811271bd>] check_disk_change+0x24/0x56 [<ffffffff812fbc93>] cdrom_open+0x427/0x49b [<ffffffff811f7fd2>] ? get_disk+0xec/0x110 [<ffffffff81204195>] ? kobject_get+0x1a/0x22 [<ffffffff812d7ff7>] sr_block_open+0x8b/0xa8 [<ffffffff81203efc>] ? kobject_put+0x47/0x4b [<ffffffff81127eb1>] __blkdev_get+0x27a/0x391 [<ffffffff81127fd5>] ? blkdev_open+0x0/0xa7 [<ffffffff81127fd3>] blkdev_get+0xb/0xd [<ffffffff81128046>] blkdev_open+0x71/0xa7 [<ffffffff81100594>] __dentry_open+0x208/0x33f [<ffffffff811c3bd1>] ? security_inode_permission+0x1c/0x1e [<ffffffff81100790>] nameidata_to_filp+0x3a/0x4b [<ffffffff8110d6f4>] do_filp_open+0x571/0xaea [<ffffffff8120bb6d>] ? __strncpy_from_user+0x29/0x53 [<ffffffff8142fbb6>] ? _raw_spin_unlock+0x26/0x31 [<ffffffff811002a3>] do_sys_open+0x5e/0x10a [<ffffffff81100378>] sys_open+0x1b/0x1d [<ffffffff81009c02>] system_call_fastpath+0x16/0x1b INFO: task cdrdao:25112 blocked for more than 120 seconds. "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. cdrdao D 0000000000000002 0 25112 20737 0x00000080 ffff880021f67978 0000000000000086 ffff880021f678e8 ffffffff8142f9ed ffff880021f678e8 ffff88003869c380 ffff880021f67938 ffff880021f66000 000000000000f970 0000000000014b80 ffff88004dfaab48 0000000000000000 Call Trace: [<ffffffff8142f9ed>] ? _raw_spin_lock+0x16/0x35 [<ffffffff81203efc>] ? kobject_put+0x47/0x4b [<ffffffff8142e438>] schedule_timeout+0x31/0xde [<ffffffff811efcc5>] ? __blk_run_queue+0x4a/0x70 [<ffffffff8142d82f>] wait_for_common+0xac/0xfd [<ffffffff8103ce52>] ? default_wake_function+0x0/0xf [<ffffffff811efd9e>] ? __generic_unplug_device+0x1a/0x31 [<ffffffff8142d90a>] wait_for_completion+0x18/0x1a [<ffffffff811f5ee0>] blk_execute_rq+0xa1/0xd1 [<ffffffff811ef789>] ? freed_request+0x26/0x43 [<ffffffff811ce30f>] ? selinux_capable+0x1c/0x3a [<ffffffff811c2ec1>] ? security_capable+0x25/0x27 [<ffffffff81052202>] ? capable+0x22/0x41 [<ffffffff811f9629>] sg_io+0x292/0x3dc [<ffffffff811f9ce4>] scsi_cmd_ioctl+0x240/0x430 [<ffffffff81110321>] ? pollwake+0x4d/0x4f [<ffffffff811c7f28>] ? rcu_read_unlock+0x23/0x2e [<ffffffff811c86ec>] ? avc_has_perm_noaudit+0x477/0x4a0 [<ffffffff812fc440>] cdrom_ioctl+0x3f/0xccf [<ffffffff811c876c>] ? avc_has_perm+0x57/0x69 [<ffffffff812d7ec8>] sr_block_ioctl+0x4b/0x81 [<ffffffff811f7195>] __blkdev_driver_ioctl+0x75/0x9e [<ffffffff811f7ae4>] blkdev_ioctl+0x66f/0x6a3 [<ffffffff81126f48>] block_ioctl+0x32/0x36 [<ffffffff8110eab6>] vfs_ioctl+0x2d/0xa1 [<ffffffff8110f026>] do_vfs_ioctl+0x485/0x4cb [<ffffffff8110f0bd>] sys_ioctl+0x51/0x74 [<ffffffff81009c02>] system_call_fastpath+0x16/0x1b ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen sr 1:0:0:0: [sr0] CDB: Synchronize Cache(10): 35 00 00 00 00 00 00 00 00 00 ata2.00: cmd a0/00:00:00:00:00/00:00:00:00:00/a0 tag 0 res 40/00:02:00:0c:00/00:00:00:00:00/a0 Emask 0x4 (timeout) ata2.00: status: { DRDY } ata2: link is slow to respond, please be patient (ready=0) ata2: device not ready (errno=-16), forcing hardreset ata2: soft resetting link ata2.00: configured for UDMA/33 ata2: EH complete
(In reply to comment #3) > Happened again after I burned an audio CD. The drive cycled and grunted fifteen > times before I killed all instances of udevd. It was still locked. Then I > noticed: > > 1372 ? D 0:10 hald-addon-storage: no polling because /dev/sr0 is > locked via O_EXCL > > killed that, and the system recovered. ...Could be a red-herring. The problem also happens when hal is completely killed and I burn a CD using Brasero. udisks-daemon gets stuck in D sleep. I only managed to get back normal operation having killed all of udev and udisks I could, and then kept pressing the eject button on the drive.
More info: I tried burning with no udev or udisks, just cdrdao, and the problem's still there: $ cdrdao write -v3 brasero.toc Cdrdao version 1.2.3 - (C) Andreas Mueller <andreas> Format converter enabled for extensions: ogg Detected SG driver version: 3.5.27 Detected SG driver version: 3.5.27 /dev/sr0: TSSTcorp CDDVDW SN-S082H Rev: SB00 Using driver: Generic SCSI-3/MMC - Version 2.0 (options 0x0000) /dev/sr0: SCSI command Rezero Unit (0x01) failed: Bad address. /dev/sr0: SCSI command Rezero Unit (0x01) failed: Bad address. Starting write at speed 24... Pausing 10 seconds - hit CTRL-C to abort. Process can be aborted with QUIT signal (usually CTRL-\). WARNING: No super user permission to setup real time scheduling. Waiting for reader process Buffer filled Awaken, will start writing Turning BURN-Proof on Enabling JustLink. Session format: 0 Drive accepted write parameter mode page variant 0. Executing power calibration... Power calibration successful. Cue Sheet (variant 0): CTL/ TNO INDEX DATA SCMS MIN SEC FRAME ADR FORM 01 00 00 01 00 00 00 00 01 01 00 00 00 00 00 00 01 01 01 00 00 00 02 00 01 02 00 00 00 26 42 10 01 02 01 00 00 26 42 22 01 aa 01 01 00 52 08 00 Drive accepted cue sheet variant 0. Writing track 01 (mode AUDIO/AUDIO )... Writing track 02 (mode AUDIO/AUDIO ).... Wrote 525 of 525 MB (Buffers 100% 100%). Wrote 234450 blocks. Buffer fill min 93%/max 100%. followed by a bunch of grunting from the drive, and then I eventually killed cdrdao. The following: ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen sr 1:0:0:0: [sr0] CDB: Synchronize Cache(10): 35 00 00 00 00 00 00 00 00 00 ata2.00: cmd a0/00:00:00:00:00/00:00:00:00:00/a0 tag 0 res 40/00:02:00:0c:00/00:00:00:00:00/a0 Emask 0x4 (timeout) ata2.00: status: { DRDY } ata2: link is slow to respond, please be patient (ready=0) showed up in dmesg. So I guess this rules out u(whatever) interfering... possible kernel bug?
Seems the drive was marginal/faulty/had compatibility issues. Replaced with an Optiarc AD-7590A and no longer have any problems.