I was burning a data Blu-ray disc last night using k3b and cdrecord on Kubuntu 14.04.
The disc burned fine, but the second disc stalled. The drive spun up, but k3b never showed more than 0%. Eventually it errored out. The drive itself did not want to eject the disc. It took over a minute and several presses of the eject button to eject the failed disc.
After this, I could not get the system to acknowledge any other disc. I tried another blank disc, but nothing happened - k3b would not recognize it, and the shell did not notify me of an empty disc. I tried a movie, a data Blu-ray, a DVD, nothing. It was as if Linux did not even know the drive was there.
When I rebooted, everything was fine. I was able to continue burning, and burned two Blu-ray discs with no errors.
How do I troubleshoot the cause of this problem?
This is the relevant section from the kern.log but I am not sure what this means or what else I can inspect to figure out what happened. (note: I removed the hostname for privacy as well as brevity)
Jun 22 20:59:44 kernel: [14979.713419] warning: `/usr/bin/cdrecord' has both setuid-root and effective capabilities. Therefore not raising all capabilities.
Jun 22 22:45:54 kernel: [21345.680364] ata6.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
Jun 22 22:45:54 kernel: [21345.680373] sr 5:0:0:0: [sr0] CDB:
Jun 22 22:45:54 kernel: [21345.680375] Synchronize Cache(10): 35 00 00 00 00 00 00 00 00 00
Jun 22 22:45:54 kernel: [21345.680387] ata6.00: cmd a0/00:00:00:00:00/00:00:00:00:00/a0 tag 30
Jun 22 22:45:54 kernel: [21345.680387] res 40/00:03:00:00:00/00:00:00:00:00/a0 Emask 0x4 (timeout)
Jun 22 22:45:54 kernel: [21345.680390] ata6.00: status: { DRDY }
Jun 22 22:45:54 kernel: [21345.680395] ata6: hard resetting link
Jun 22 22:45:57 kernel: [21348.222922] INFO: task cdrecord:8295 blocked for more than 120 seconds.
Jun 22 22:45:57 kernel: [21348.222928] Not tainted 3.13.0-85-generic #129-Ubuntu
Jun 22 22:45:57 kernel: [21348.222929] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Jun 22 22:45:57 kernel: [21348.222931] cdrecord D ffff88041f313180 0 8295 6418 0x00000000
Jun 22 22:45:57 kernel: [21348.222936] ffff880402b23da0 0000000000000086 ffff8803bcbf8000 ffff880402b23fd8
Jun 22 22:45:57 kernel: [21348.222941] 0000000000013180 0000000000013180 ffff8803bcbf8000 ffffffff81cc4700
Jun 22 22:45:57 kernel: [21348.222944] ffffffff81cc4704 ffff8803bcbf8000 00000000ffffffff ffffffff81cc4708
Jun 22 22:45:57 kernel: [21348.222948] Call Trace:
Jun 22 22:45:57 kernel: [21348.222957] [<ffffffff81730089>] schedule_preempt_disabled+0x29/0x70
Jun 22 22:45:57 kernel: [21348.222961] [<ffffffff81731ef5>] __mutex_lock_slowpath+0x135/0x1b0
Jun 22 22:45:57 kernel: [21348.222966] [<ffffffff814ac12c>] ? __pm_runtime_resume+0x5c/0x80
Jun 22 22:45:57 kernel: [21348.222970] [<ffffffff81731f8f>] mutex_lock+0x1f/0x2f
Jun 22 22:45:57 kernel: [21348.222975] [<ffffffff814fee98>] sr_block_ioctl+0x48/0xd0
Jun 22 22:45:57 kernel: [21348.222979] [<ffffffff8134d39c>] blkdev_ioctl+0x21c/0x7b0
Jun 22 22:45:57 kernel: [21348.222984] [<ffffffff811fb8d1>] block_ioctl+0x41/0x50
Jun 22 22:45:57 kernel: [21348.222988] [<ffffffff811d5050>] do_vfs_ioctl+0x2e0/0x4c0
Jun 22 22:45:57 kernel: [21348.222993] [<ffffffff81090ea0>] ? hrtimer_get_res+0x50/0x50
Jun 22 22:45:57 kernel: [21348.222996] [<ffffffff8172ef01>] ? do_nanosleep+0x71/0x130
Jun 22 22:45:57 kernel: [21348.222999] [<ffffffff811d52b1>] SyS_ioctl+0x81/0xa0
Jun 22 22:45:57 kernel: [21348.223003] [<ffffffff8173c39d>] system_call_fastpath+0x1a/0x1f
Jun 22 22:45:59 kernel: [21351.037245] ata6: link is slow to respond, please be patient (ready=0)
Jun 22 22:46:04 kernel: [21355.682613] ata6: COMRESET failed (errno=-16)
Jun 22 22:46:04 kernel: [21355.682629] ata6: hard resetting link
Jun 22 22:46:09 kernel: [21361.039441] ata6: link is slow to respond, please be patient (ready=0)
Jun 22 22:46:14 kernel: [21365.684755] ata6: COMRESET failed (errno=-16)
Jun 22 22:46:14 kernel: [21365.684764] ata6: hard resetting link
Jun 22 22:46:19 kernel: [21371.041649] ata6: link is slow to respond, please be patient (ready=0)
Jun 22 22:46:49 kernel: [21400.708520] ata6: COMRESET failed (errno=-16)
Jun 22 22:46:49 kernel: [21400.708526] ata6: limiting SATA link speed to 1.5 Gbps
Jun 22 22:46:49 kernel: [21400.708527] ata6: hard resetting link
Jun 22 22:46:54 kernel: [21405.729548] ata6: COMRESET failed (errno=-16)
Jun 22 22:46:54 kernel: [21405.729557] ata6: reset failed, giving up
Jun 22 22:46:54 kernel: [21405.729560] ata6.00: disabled
Jun 22 22:46:54 kernel: [21405.729583] ata6: EH complete
The only entries after this are from the subsequent startup.
cdrecord version:
user@host:/var/log# cdrecord --version
Cdrecord-ProDVD-ProBD-Clone 3.02a06 (x86_64-unknown-linux-gnu) Copyright (C) 1995-2016 Joerg Schilling
k3b version:
user@host:/var/log# apt list k3b
Listing... Done
k3b/trusty,now 2.0.2-7ubuntu1 amd64 [installed]
This drive has worked fine up until now, both reading and writing, both DVD and Blu-ray. I doubt this is a hardware failure because the drive worked fine after a reboot. My best guess is an error in a driver, but I am not sure what to look at next. So far my searches have pulled up plenty of articles and SE questions about getting the hardware to work in the first place, or how to install the correct version of cdrecord for Blu-ray compatibility. Obviously, I am already past that stage and can (usually) burn discs just fine.
What do my next steps need to be to diagnose this error so I can identify a fix?