SATA / DVD-RW: recovering from write errors without rebooting
From: Sami Farin <hidden>
Date: 2008-12-23 01:26:26
I'd like to know one thing: Is this a hardware bug or a software bug.
When I write a DVD-RW with growisofs and there's some (media) error,
I get some ata errors and DVD's led stays green, and I can't
reset the drive, eject disk with software or by pressing
drive's eject button. It does not matter if I open the drive
door and put in some other disc.
I have SATA drive HL-DT-ST DVD-RAM GH22NS30 1.01,
one SATA hard disk, one PATA hard disk, Intel motherboard
DQ965GF version CO96510J.86A.6079.2008.0727.2220,
Linux x86_64 2.6.27.10.
I already wrote to LG (manufacturer of DVD drive) a couple
of weeks ago but I have not heard back.
At around 01:57:08.431689628 I opened case and replugged power
cable from the DVD drive. Kernel detected it, but then after
some seconds I got something like "hda: command timed out"
and then hard freeze (had to power cycle).
No kernel messages were available after 01:57:55.999123925.
2008-12-23 01:44:55.656343805 <3>[17524.249147] ata4.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
2008-12-23 01:44:55.656346265 <3>[17524.249158] ata4.00: cmd a0/00:00:00:00:00/00:00:00:00:00/a0 tag 0
2008-12-23 01:44:55.656347206 <3>[17524.249159] cdb 54 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2008-12-23 01:44:55.656348135 <3>[17524.249161] res 40/00:03:00:18:00/00:00:00:00:00/a0 Emask 0x4 (timeout)
2008-12-23 01:44:55.656349088 <3>[17524.249164] ata4.00: status: { DRDY }
2008-12-23 01:44:55.656349714 <6>[17524.249171] ata4: hard resetting link
2008-12-23 01:44:55.961280094 <6>[17524.554144] ata4: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
2008-12-23 01:44:55.964089698 <6>[17524.556852] ata4.00: configured for UDMA/100
2008-12-23 01:44:55.964091029 <6>[17524.556875] ata4: EH complete
2008-12-23 01:45:55.966348828 <3>[17584.559149] ata4.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
2008-12-23 01:45:55.966351426 <3>[17584.559161] ata4.00: cmd a0/01:00:00:00:80/00:00:00:00:00/a0 tag 0 dma 32768 out
2008-12-23 01:45:55.966352479 <3>[17584.559163] cdb 2a 00 00 00 00 00 00 00 10 00 00 00 00 00 00 00
2008-12-23 01:45:55.966353405 <3>[17584.559164] res 40/00:03:00:18:00/00:00:00:00:00/a0 Emask 0x4 (timeout)
2008-12-23 01:45:55.966354339 <3>[17584.559167] ata4.00: status: { DRDY }
2008-12-23 01:45:55.966354962 <6>[17584.559174] ata4: hard resetting link
2008-12-23 01:45:56.271288460 <6>[17584.864145] ata4: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
2008-12-23 01:45:56.275602728 <6>[17584.866809] ata4.00: configured for UDMA/100
2008-12-23 01:45:56.275606194 <6>[17584.866831] ata4: EH complete
2008-12-23 01:49:58.286330148 <4>[17826.879146] ata4: limiting SATA link speed to 1.5 Gbps
2008-12-23 01:49:58.286366841 <3>[17826.879154] ata4.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
2008-12-23 01:49:58.286390100 <3>[17826.879162] ata4.00: cmd a0/00:00:00:00:00/00:00:00:00:00/a0 tag 0
2008-12-23 01:49:58.286412270 <3>[17826.879163] cdb 1b 00 00 00 03 00 00 00 00 00 00 00 00 00 00 00
2008-12-23 01:49:58.286434918 <3>[17826.879165] res 40/00:03:00:00:00/00:00:00:00:00/a0 Emask 0x4 (timeout)
2008-12-23 01:49:58.286456553 <3>[17826.879168] ata4.00: status: { DRDY }
2008-12-23 01:49:58.286477612 <6>[17826.879174] ata4: hard resetting link
2008-12-23 01:49:58.591286039 <6>[17827.184144] ata4: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
2008-12-23 01:49:58.593975535 <6>[17827.186848] ata4.00: configured for UDMA/100
2008-12-23 01:49:58.593998258 <6>[17827.186861] ata4: EH complete
2008-12-23 01:50:28.593347236 <3>[17857.186147] ata4.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
2008-12-23 01:50:28.593349616 <3>[17857.186159] ata4.00: cmd a0/00:00:00:00:00/00:00:00:00:00/a0 tag 0
2008-12-23 01:50:28.593350529 <3>[17857.186160] cdb 1b 00 00 00 03 00 00 00 00 00 00 00 00 00 00 00
2008-12-23 01:50:28.593351407 <3>[17857.186162] res 40/00:03:00:00:00/00:00:00:00:00/a0 Emask 0x4 (timeout)
2008-12-23 01:50:28.593352291 <3>[17857.186165] ata4.00: status: { DRDY }
2008-12-23 01:50:28.593352886 <6>[17857.186172] ata4: hard resetting link
2008-12-23 01:50:28.898286191 <6>[17857.491144] ata4: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
2008-12-23 01:50:28.901031752 <6>[17857.493899] ata4.00: configured for UDMA/100
2008-12-23 01:50:28.901032973 <6>[17857.493913] ata4: EH complete
2008-12-23 01:50:58.900353887 <3>[17887.493149] ata4.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
2008-12-23 01:50:58.900356575 <3>[17887.493161] ata4.00: cmd a0/00:00:00:00:00/00:00:00:00:00/a0 tag 0
2008-12-23 01:50:58.900357474 <3>[17887.493162] cdb 1b 00 00 00 03 00 00 00 00 00 00 00 00 00 00 00
2008-12-23 01:50:58.900358367 <3>[17887.493163] res 40/00:03:00:00:00/00:00:00:00:00/a0 Emask 0x4 (timeout)
2008-12-23 01:50:58.900359250 <3>[17887.493167] ata4.00: status: { DRDY }
2008-12-23 01:50:58.900359846 <6>[17887.493173] ata4: hard resetting link
2008-12-23 01:50:59.205287636 <6>[17887.798145] ata4: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
2008-12-23 01:50:59.208045366 <6>[17887.800847] ata4.00: configured for UDMA/100
2008-12-23 01:50:59.208046752 <6>[17887.800867] ata4: EH complete
2008-12-23 01:50:59.208047308 <3>[17887.800878] sr0: CDROM (ioctl) error, command: Start/Stop Unit 1b 00 00 00 03 00
2008-12-23 01:50:59.208048206 <6>[17887.800888] sr: Sense Key : Aborted Command [current] [descriptor]
2008-12-23 01:50:59.208049019 <6>[17887.800894] sr: Add. Sense: No additional sense information
2008-12-23 01:57:08.431689628 <4>[18257.024504] ata4.00: limiting speed to UDMA/66:PIO4
2008-12-23 01:57:08.431691932 <3>[18257.024511] ata4: exception Emask 0x10 SAct 0x0 SErr 0x10000 action 0xe frozen
2008-12-23 01:57:08.431692873 <3>[18257.024514] ata4: irq_stat 0x00400000, PHY RDY changed
2008-12-23 01:57:08.431693654 <3>[18257.024518] ata4: SError: { PHYRdyChg }
2008-12-23 01:57:08.431694295 <6>[18257.024525] ata4: hard resetting link
2008-12-23 01:57:09.154282182 <6>[18257.747142] ata4: SATA link down (SStatus 0 SControl 310)
2008-12-23 01:57:14.154273371 <6>[18262.747136] ata4: hard resetting link
2008-12-23 01:57:14.459278255 <6>[18263.052141] ata4: SATA link down (SStatus 0 SControl 310)
2008-12-23 01:57:19.459276252 <6>[18268.052136] ata4: hard resetting link
2008-12-23 01:57:19.766261425 <6>[18268.357141] ata4: SATA link down (SStatus 0 SControl 310)
2008-12-23 01:57:19.766264578 <4>[18268.357150] ata4.00: disabled
2008-12-23 01:57:19.766265221 <6>[18268.357161] ata4: EH complete
2008-12-23 01:57:19.766265872 <6>[18268.357173] ata4.00: detaching (SCSI 3:0:0:0)
here I gave the stupid drive some power
2008-12-23 01:57:55.266490475 <3>[18303.859302] ata4: exception Emask 0x10 SAct 0x0 SErr 0x4050002 action 0xe frozen
2008-12-23 01:57:55.266493160 <3>[18303.859309] ata4: irq_stat 0x00000040, connection status changed
2008-12-23 01:57:55.266494069 <3>[18303.859313] ata4: SError: { RecovComm PHYRdyChg CommWake DevExch }
2008-12-23 01:57:55.266494925 <6>[18303.859322] ata4: hard resetting link
2008-12-23 01:57:55.989291809 <6>[18304.582144] ata4: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
2008-12-23 01:57:55.990426641 <6>[18304.583305] ata4.00: ATAPI: HL-DT-STDVD-RAM GH22NS30, 1.01, max UDMA/100
2008-12-23 01:57:55.991877936 <6>[18304.584755] ata4.00: configured for UDMA/100
2008-12-23 01:57:55.991879143 <6>[18304.584765] ata4: EH complete
2008-12-23 01:57:55.993043771 <5>[18304.585931] scsi 3:0:0:0: CD-ROM HL-DT-ST DVD-RAM GH22NS30 1.01 PQ: 0 ANSI: 5
2008-12-23 01:57:55.998279657 <4>[18304.591138] sr0: scsi3-mmc drive: 48x/48x writer dvd-ram cd/rw xa/form2 cdda tray
2008-12-23 01:57:55.998469034 <7>[18304.591361] sr 3:0:0:0: Attached scsi CD-ROM sr0
2008-12-23 01:57:55.999123925 <5>[18304.592000] sr 3:0:0:0: Attached scsi generic sg1 type 5
CPU0 CPU1
0: 29 0 IO-APIC-edge timer
1: 2 0 IO-APIC-edge i8042
4: 2 0 IO-APIC-edge
7: 0 0 IO-APIC-edge parport0
8: 1 0 IO-APIC-edge rtc0
9: 0 0 IO-APIC-fasteoi acpi
12: 7 0 IO-APIC-edge i8042
14: 0 0 IO-APIC-edge ide2
15: 0 0 IO-APIC-edge ide3
16: 255281 38243 IO-APIC-fasteoi uhci_hcd:usb1, i915@pci:0000:00:02.0
17: 802 3089 IO-APIC-fasteoi ide0, ide1
18: 2 0 IO-APIC-fasteoi ehci_hcd:usb3, uhci_hcd:usb6
19: 15804 10247 IO-APIC-fasteoi uhci_hcd:usb5, ohci1394
21: 48 0 IO-APIC-fasteoi uhci_hcd:usb2
23: 3 0 IO-APIC-fasteoi uhci_hcd:usb4, ehci_hcd:usb7
504: 3109 12186 PCI-MSI-edge HDA Intel
505: 70 7239 PCI-MSI-edge eth0
506: 11427 24155 PCI-MSI-edge ahci
NMI: 0 0 Non-maskable interrupts
LOC: 2097539 2126841 Local timer interrupts
RES: 4740 3811 Rescheduling interrupts
CAL: 31978 737 function call interrupts
TLB: 669 831 TLB shootdowns
TRM: 0 0 Thermal event interrupts
THR: 0 0 Threshold APIC interrupts
SPU: 0 0 Spurious interrupts
ERR: 0
--
"If it bleeds, we can kill it." - Arnold Schwarzenegger