Comment 51 for bug 231575

I found this bug report while searching for a solution to the same problem as I've been noticing similar behaviour in Ubuntu 10.04 Beta (amd64). My DVD drives worked for a short time after rebooting but would always fail after a short time, with dmesg containing lots of "TEST_UNIT_READY failed" messages.

The relevant messages in dmesg seemed to occur shortly after the VirtualBox vboxdrv driver is initialised

[ 630.250055] UDF-fs: No VRS found
[ 630.250059] UDF-fs: No partition found (1)
[ 632.742430] ISO 9660 Extensions: Microsoft Joliet Level 3
[ 632.844831] ISO 9660 Extensions: RRIP_1991A
[ 1321.639348] vboxdrv: Trying to deactivate the NMI watchdog permanently...
[ 1321.639352] vboxdrv: Successfully done.
[ 1321.639354] vboxdrv: Found 4 processor cores.
[ 1321.639671] VBoxDrv: dbg - g_abExecMemory=ffffffffa0373a20
[ 1321.639736] vboxdrv: fAsync=0 offMin=0x5b4 offMax=0x2e86
[ 1321.640051] vboxdrv: TSC mode is 'synchronous', kernel timer mode is 'normal'.
[ 1321.640051] vboxdrv: Successfully loaded version 3.1.6 (interface 0x00100001).
[ 1623.197066] warning: `VirtualBox' uses 32-bit capabilities (legacy support in use)
[ 1671.050022] ata5: lost interrupt (Status 0x58)
[ 1671.050049] ata5.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
[ 1671.050054] sr 4:0:0:0: [sr0] CDB: Get event status notification: 4a 01 00 00 10 00 00 00 08 00
[ 1671.050064] ata5.00: cmd a0/00:00:00:08:00/00:00:00:00:00/a0 tag 0 pio 16392 in
[ 1671.050065] res 58/00:02:00:08:00/00:00:00:00:00/a0 Emask 0x6 (timeout)
[ 1671.050067] ata5.00: status: { DRDY DRQ }
[ 1671.110022] ata5: soft resetting link
[ 1671.304629] ata5: nv_mode_filter: 0x1f39f&0x1f39f->0x1f39f, BIOS=0x1f000 (0xc5c00000) ACPI=0x1f01f (30:60:0x1f)
[ 1671.304634] ata5: nv_mode_filter: 0x739f&0x739f->0x739f, BIOS=0x7000 (0xc5c00000) ACPI=0x701f (30:60:0x1f)
[ 1671.344627] ata5.00: configured for UDMA/66
[ 1671.384617] ata5.01: configured for UDMA/33
[ 1676.380051] ata5.00: qc timeout (cmd 0xa0)
[ 1676.380057] ata5.00: TEST_UNIT_READY failed (err_mask=0x5)
[ 1676.380078] ata5: soft resetting link
[ 1676.586320] ata5: nv_mode_filter: 0x1f39f&0x1f39f->0x1f39f, BIOS=0x1f000 (0xc5c00000) ACPI=0x1f01f (30:60:0x1f)
[ 1676.586325] ata5: nv_mode_filter: 0x739f&0x739f->0x739f, BIOS=0x7000 (0xc5c00000) ACPI=0x701f (30:60:0x1f)
[ 1676.630323] ata5.00: configured for UDMA/66
[ 1676.671552] ata5.01: configured for UDMA/33
[ 1681.674829] ata5.00: qc timeout (cmd 0xa0)
[ 1681.674835] ata5.00: TEST_UNIT_READY failed (err_mask=0x5)
[ 1681.674838] ata5.00: limiting speed to UDMA/66:PIO3
[ 1681.674857] ata5: soft resetting link
[ 1681.880427] ata5: nv_mode_filter: 0x1f38f&0x1f39f->0x1f38f, BIOS=0x1f000 (0xc5c00000) ACPI=0x1f01f (30:60:0x1f)
[ 1681.880431] ata5: nv_mode_filter: 0x739f&0x739f->0x739f, BIOS=0x7000 (0xc5c00000) ACPI=0x701f (30:60:0x1f)
[ 1681.910346] ata5.00: configured for UDMA/66
[ 1681.953579] ata5.01: configured for UDMA/33
[ 1686.951368] ata5.00: qc timeout (cmd 0xa0)
[ 1686.951377] ata5.00: TEST_UNIT_READY failed (err_mask=0x5)
[ 1686.951380] ata5.00: disabled
[ 1686.951388] ata5.01: TEST_UNIT_READY failed (err_mask=0x40)
[ 1686.951416] ata5: soft resetting link
[ 1687.131795] ata5: nv_mode_filter: 0x739f&0x739f->0x739f, BIOS=0x7000 (0xc5c00000) ACPI=0x701f (30:60:0x1f)
[ 1687.171797] ata5.01: configured for UDMA/33
[ 1692.174887] ata5.01: qc timeout (cmd 0xa0)
[ 1692.174895] ata5.01: TEST_UNIT_READY failed (err_mask=0x5)
[ 1692.174900] ata5.01: limiting speed to UDMA/33:PIO3
[ 1692.174924] ata5: soft resetting link
[ 1692.354816] ata5: nv_mode_filter: 0x738f&0x739f->0x738f, BIOS=0x7000 (0xc5c00000) ACPI=0x701f (30:60:0x1f)
[ 1692.395374] ata5.01: configured for UDMA/33
[ 1697.400030] ata5.01: qc timeout (cmd 0xa0)
[ 1697.400037] ata5.01: TEST_UNIT_READY failed (err_mask=0x4)
[ 1697.400041] ata5.01: disabled
[ 1697.400073] ata5: soft resetting link
[ 1697.551480] ata5: EH complete
[ 1697.564362] VFS: busy inodes on changed media or resized disk sr0
[ 1697.564487] VFS: busy inodes on changed media or resized disk sr1
[ 1697.564506] VFS: busy inodes on changed media or resized disk sr0
[ 1697.564600] VFS: busy inodes on changed media or resized disk sr0
[ 1697.564726] VFS: busy inodes on changed media or resized disk sr1
[ 1697.565029] VFS: busy inodes on changed media or resized disk sr0
[ 1697.565607] VFS: busy inodes on changed media or resized disk sr1
[ 1697.566413] VFS: busy inodes on changed media or resized disk sr0
[ 1697.567038] VFS: busy inodes on changed media or resized disk sr1
[ 1697.568599] VFS: busy inodes on changed media or resized disk sr1
[ 1697.577876] VFS: busy inodes on changed media or resized disk sr1
[ 1697.577956] VFS: busy inodes on changed media or resized disk sr1
[ 1697.582538] VFS: busy inodes on changed media or resized disk sr1
[ 1697.582576] VFS: busy inodes on changed media or resized disk sr1
[ 1697.582661] VFS: busy inodes on changed media or resized disk sr1
[ 1697.582782] VFS: busy inodes on changed media or resized disk sr1
[ 1697.582915] VFS: busy inodes on changed media or resized disk sr1

I first upgraded VirtualBox from 3.14 to 3.16. This did not resolve the problem, so I then uninstalled VirtualBox completely and this caused my DVD drives to work perfectly again. Reinstalling and running VirtualBox caused the DVDs to become disabled once more in the same way as before. In the dmesg extract above, the ata errors started to occur after about 1670 seconds, while VirtualBox was reinstalled at around 1320 seconds and run for the first time at 1623 seconds. Before uninstalling Vbox the first time, the ata errors began much sooner.

I don't remember noticing the problem before upgrading to Ubuntu 10.04 Beta from 9.10, and it has occurred with both VirtualBox 3.1.4 and 3.1.6.

I will uninstall Vbox for a few days and see if the problem 'goes away' more permanently.

Running uname -a returns the following:
2.6.32-18-generic #27-Ubuntu SMP Fri Mar 26 21:13:44 UTC 2010 x86_64 GNU/Linux