WARNING: at drivers/ata/libata-eh.c:664 (and others) with 2.6.27-05178

WARNING: at drivers/ata/libata-eh.c:664 (and others) with 2.6.27-05178

[Christian Borntraeger]

[-- Attachment #1: Type: text/plain, Size: 8853 bytes --]

Hello Jens,

while doing a backup on DVD+R I got the following warning (and a k3b hung).
the drive is a Plextor 716A on a jmicron PATA port.
I have never seen this with earlier kernels. I am a bit reluctant to
reproduce or bisect this problem, since it might kills my blank DVDs.
Could this be related to commit
e013e13bf605b9e6b702adffbe2853cfc60e7806 (libata: fix bug with non-ncq devices)?
Thank you for any idea.


Oct 24 19:49:15 Festrechner kernel: [21790.704070] ------------[ cut here ]------------
Oct 24 19:49:15 Festrechner kernel: [21790.704073] WARNING: at drivers/ata/libata-eh.c:664 ata_scsi_error+0x432/0x750()
Oct 24 19:49:15 Festrechner kernel: [21790.704075] Modules linked in: ehci_hcd uhci_hcd
Oct 24 19:49:15 Festrechner kernel: [21790.704079] Pid: 560, comm: scsi_eh_6 Not tainted 2.6.27-05178-g2e532d6-dirty #31
Oct 24 19:49:15 Festrechner kernel: [21790.704081] Call Trace:
Oct 24 19:49:15 Festrechner kernel: [21790.704085]  [<ffffffff8025e124>] warn_on_slowpath+0x64/0xa0
Oct 24 19:49:15 Festrechner kernel: [21790.704089]  [<ffffffff8041f5d9>] __next_cpu+0x19/0x30
Oct 24 19:49:15 Festrechner kernel: [21790.704093]  [<ffffffff806e09b5>] _spin_unlock_irq+0x5/0x40
Oct 24 19:49:15 Festrechner kernel: [21790.704096]  [<ffffffff802710bd>] __cancel_work_timer+0xad/0x190
Oct 24 19:49:15 Festrechner kernel: [21790.704098]  [<ffffffff806e09b5>] _spin_unlock_irq+0x5/0x40
Oct 24 19:49:15 Festrechner kernel: [21790.704100]  [<ffffffff80519725>] atapi_qc_complete+0x2b5/0x300
Oct 24 19:49:15 Festrechner kernel: [21790.704102]  [<ffffffff8051fda0>] __ata_eh_qc_complete+0x50/0x90
Oct 24 19:49:15 Festrechner kernel: [21790.704104]  [<ffffffff805235a0>] ata_sff_softreset+0x0/0x190
Oct 24 19:49:15 Festrechner kernel: [21790.704109]  [<ffffffff80246285>] default_spin_lock_flags+0x5/0x10
Oct 24 19:49:15 Festrechner kernel: [21790.704111]  [<ffffffff80520a82>] ata_scsi_error+0x432/0x750
Oct 24 19:49:15 Festrechner kernel: [21790.704114]  [<ffffffff804fc454>] scsi_error_handler+0xe4/0x390
Oct 24 19:49:15 Festrechner kernel: [21790.704116]  [<ffffffff804fc370>] scsi_error_handler+0x0/0x390
Oct 24 19:49:15 Festrechner kernel: [21790.704118]  [<ffffffff802749a7>] kthread+0x47/0x90
Oct 24 19:49:15 Festrechner kernel: [21790.704121]  [<ffffffff80255d67>] schedule_tail+0x27/0x70
Oct 24 19:49:15 Festrechner kernel: [21790.704124]  [<ffffffff8022a799>] child_rip+0xa/0x11
Oct 24 19:49:15 Festrechner kernel: [21790.704126]  [<ffffffff80274960>] kthread+0x0/0x90
Oct 24 19:49:15 Festrechner kernel: [21790.704128]  [<ffffffff8022a78f>] child_rip+0x0/0x11
Oct 24 19:49:15 Festrechner kernel: [21790.704129] ---[ end trace d8575dac2ce59ba0 ]---
Oct 24 19:49:15 Festrechner kernel: [21790.704216] ------------[ cut here ]------------
Oct 24 19:49:15 Festrechner kernel: [21790.704217] WARNING: at drivers/ata/libata-eh.c:3239 ata_eh_finish+0xc3/0xd0()
Oct 24 19:49:15 Festrechner kernel: [21790.704219] Modules linked in: ehci_hcd uhci_hcd
Oct 24 19:49:15 Festrechner kernel: [21790.704221] Pid: 560, comm: scsi_eh_6 Tainted: G        W 2.6.27-05178-g2e532d6-dirty #31
Oct 24 19:49:15 Festrechner kernel: [21790.704223] Call Trace:
Oct 24 19:49:15 Festrechner kernel: [21790.704224]  [<ffffffff8025e124>] warn_on_slowpath+0x64/0xa0
Oct 24 19:49:15 Festrechner kernel: [21790.704226]  [<ffffffff8051e355>] ata_eh_link_autopsy+0x115/0x770
Oct 24 19:49:15 Festrechner kernel: [21790.704229]  [<ffffffff804f8420>] scsi_done+0x0/0x10
Oct 24 19:49:15 Festrechner kernel: [21790.704231]  [<ffffffff806e06b4>] _spin_lock+0x14/0x20
Oct 24 19:49:15 Festrechner kernel: [21790.704233]  [<ffffffff8041f5d9>] __next_cpu+0x19/0x30
Oct 24 19:49:15 Festrechner kernel: [21790.704235]  [<ffffffff806e09b5>] _spin_unlock_irq+0x5/0x40
Oct 24 19:49:15 Festrechner kernel: [21790.704237]  [<ffffffff802710bd>] __cancel_work_timer+0xad/0x190
Oct 24 19:49:15 Festrechner kernel: [21790.704239]  [<ffffffff80246285>] default_spin_lock_flags+0x5/0x10
Oct 24 19:49:15 Festrechner kernel: [21790.704241]  [<ffffffff806e054d>] _spin_lock_irqsave+0x3d/0x50
Oct 24 19:49:15 Festrechner kernel: [21790.704243]  [<ffffffff805235a0>] ata_sff_softreset+0x0/0x190
Oct 24 19:49:15 Festrechner kernel: [21790.704245]  [<ffffffff805235a0>] ata_sff_softreset+0x0/0x190
Oct 24 19:49:15 Festrechner kernel: [21790.704248]  [<ffffffff8052abc0>] jmicron_pre_reset+0x0/0x180
Oct 24 19:49:15 Festrechner kernel: [21790.704250]  [<ffffffff8051fed3>] ata_eh_finish+0xc3/0xd0
Oct 24 19:49:15 Festrechner kernel: [21790.704252]  [<ffffffff805209ca>] ata_scsi_error+0x37a/0x750
Oct 24 19:49:15 Festrechner kernel: [21790.704254]  [<ffffffff804fc454>] scsi_error_handler+0xe4/0x390
Oct 24 19:49:15 Festrechner kernel: [21790.704256]  [<ffffffff804fc370>] scsi_error_handler+0x0/0x390
Oct 24 19:49:15 Festrechner kernel: [21790.704258]  [<ffffffff802749a7>] kthread+0x47/0x90
Oct 24 19:49:15 Festrechner kernel: [21790.704260]  [<ffffffff80255d67>] schedule_tail+0x27/0x70
Oct 24 19:49:15 Festrechner kernel: [21790.704262]  [<ffffffff8022a799>] child_rip+0xa/0x11
Oct 24 19:49:15 Festrechner kernel: [21790.704264]  [<ffffffff80274960>] kthread+0x0/0x90
Oct 24 19:49:15 Festrechner kernel: [21790.704265]  [<ffffffff8022a78f>] child_rip+0x0/0x11
Oct 24 19:49:15 Festrechner kernel: [21790.704266] ---[ end trace d8575dac2ce59ba0 ]---
Oct 24 19:49:15 Festrechner kernel: [21790.704273] ------------[ cut here ]------------
Oct 24 19:49:15 Festrechner kernel: [21790.704274] WARNING: at drivers/ata/libata-core.c:4851 ata_qc_issue+0x42/0x250()
Oct 24 19:49:15 Festrechner kernel: [21790.704275] Modules linked in: ehci_hcd uhci_hcd
Oct 24 19:49:15 Festrechner kernel: [21790.704278] Pid: 560, comm: scsi_eh_6 Tainted: G        W 2.6.27-05178-g2e532d6-dirty #31
Oct 24 19:49:15 Festrechner kernel: [21790.704279] Call Trace:
Oct 24 19:49:15 Festrechner kernel: [21790.704281]  [<ffffffff8025e124>] warn_on_slowpath+0x64/0xa0
Oct 24 19:49:15 Festrechner kernel: [21790.704283]  [<ffffffff80246285>] default_spin_lock_flags+0x5/0x10
Oct 24 19:49:15 Festrechner kernel: [21790.704285]  [<ffffffff806e054d>] _spin_lock_irqsave+0x3d/0x50
Oct 24 19:49:15 Festrechner kernel: [21790.704288]  [<ffffffff80279466>] up+0x16/0x50
Oct 24 19:49:15 Festrechner kernel: [21790.704290]  [<ffffffff806e054d>] _spin_lock_irqsave+0x3d/0x50
Oct 24 19:49:15 Festrechner kernel: [21790.704292]  [<ffffffff8025e92d>] release_console_sem+0x1ad/0x200
Oct 24 19:49:15 Festrechner kernel: [21790.704295]  [<ffffffff80231632>] read_tsc+0x12/0x40
Oct 24 19:49:15 Festrechner kernel: [21790.704297]  [<ffffffff80512322>] ata_qc_issue+0x42/0x250
Oct 24 19:49:15 Festrechner kernel: [21790.704299]  [<ffffffff80518b20>] ata_scsi_translate+0xa0/0x180
Oct 24 19:49:15 Festrechner kernel: [21790.704301]  [<ffffffff804f8420>] scsi_done+0x0/0x10
Oct 24 19:49:15 Festrechner kernel: [21790.704303]  [<ffffffff8051b606>] ata_scsi_queuecmd+0xb6/0x2e0
Oct 24 19:49:15 Festrechner kernel: [21790.704305]  [<ffffffff804f851f>] scsi_dispatch_cmd+0xef/0x220
Oct 24 19:49:15 Festrechner kernel: [21790.704308]  [<ffffffff804fefe8>] scsi_request_fn+0x2a8/0x3c0
Oct 24 19:49:15 Festrechner kernel: [21790.704310]  [<ffffffff8041122d>] blk_invoke_request_fn+0x3d/0x130
Oct 24 19:49:15 Festrechner kernel: [21790.704312]  [<ffffffff80411408>] blk_run_queue+0x28/0x50
Oct 24 19:49:15 Festrechner kernel: [21790.704314]  [<ffffffff804fe5fb>] scsi_next_command+0x3b/0x60
Oct 24 19:49:15 Festrechner kernel: [21790.704316]  [<ffffffff804fe6c3>] scsi_end_request+0xa3/0xb0
Oct 24 19:49:15 Festrechner kernel: [21790.704319]  [<ffffffff804fe7ed>] scsi_io_completion+0x11d/0x430
Oct 24 19:49:15 Festrechner kernel: [21790.704321]  [<ffffffff806e054d>] _spin_lock_irqsave+0x3d/0x50
Oct 24 19:49:15 Festrechner kernel: [21790.704323]  [<ffffffff804fdbb9>] scsi_device_unbusy+0x79/0xb0
Oct 24 19:49:15 Festrechner kernel: [21790.704325]  [<ffffffff804fb5d9>] scsi_eh_flush_done_q+0x49/0xc0
Oct 24 19:49:15 Festrechner kernel: [21790.704327]  [<ffffffff806e054d>] _spin_lock_irqsave+0x3d/0x50
Oct 24 19:49:15 Festrechner kernel: [21790.704329]  [<ffffffff80520a8b>] ata_scsi_error+0x43b/0x750
Oct 24 19:49:15 Festrechner kernel: [21790.704331]  [<ffffffff804fc454>] scsi_error_handler+0xe4/0x390
Oct 24 19:49:15 Festrechner kernel: [21790.704333]  [<ffffffff804fc370>] scsi_error_handler+0x0/0x390
Oct 24 19:49:15 Festrechner kernel: [21790.704335]  [<ffffffff802749a7>] kthread+0x47/0x90
Oct 24 19:49:15 Festrechner kernel: [21790.704336]  [<ffffffff80255d67>] schedule_tail+0x27/0x70
Oct 24 19:49:15 Festrechner kernel: [21790.704338]  [<ffffffff8022a799>] child_rip+0xa/0x11
Oct 24 19:49:15 Festrechner kernel: [21790.704340]  [<ffffffff80274960>] kthread+0x0/0x90
Oct 24 19:49:15 Festrechner kernel: [21790.704342]  [<ffffffff8022a78f>] child_rip+0x0/0x11
Oct 24 19:49:15 Festrechner kernel: [21790.704343] ---[ end trace d8575dac2ce59ba0 ]---


[-- Attachment #2: lspci --]
[-- Type: text/plain, Size: 2265 bytes --]

00:00.0 Host bridge: Intel Corporation 82G33/G31/P35/P31 Express DRAM Controller (rev 02)
00:01.0 PCI bridge: Intel Corporation 82G33/G31/P35/P31 Express PCI Express Root Port (rev 02)
00:1a.0 USB Controller: Intel Corporation 82801I (ICH9 Family) USB UHCI Controller #4 (rev 02)
00:1a.1 USB Controller: Intel Corporation 82801I (ICH9 Family) USB UHCI Controller #5 (rev 02)
00:1a.2 USB Controller: Intel Corporation 82801I (ICH9 Family) USB UHCI Controller #6 (rev 02)
00:1a.7 USB Controller: Intel Corporation 82801I (ICH9 Family) USB2 EHCI Controller #2 (rev 02)
00:1b.0 Audio device: Intel Corporation 82801I (ICH9 Family) HD Audio Controller (rev 02)
00:1c.0 PCI bridge: Intel Corporation 82801I (ICH9 Family) PCI Express Port 1 (rev 02)
00:1c.4 PCI bridge: Intel Corporation 82801I (ICH9 Family) PCI Express Port 5 (rev 02)
00:1c.5 PCI bridge: Intel Corporation 82801I (ICH9 Family) PCI Express Port 6 (rev 02)
00:1d.0 USB Controller: Intel Corporation 82801I (ICH9 Family) USB UHCI Controller #1 (rev 02)
00:1d.1 USB Controller: Intel Corporation 82801I (ICH9 Family) USB UHCI Controller #2 (rev 02)
00:1d.2 USB Controller: Intel Corporation 82801I (ICH9 Family) USB UHCI Controller #3 (rev 02)
00:1d.7 USB Controller: Intel Corporation 82801I (ICH9 Family) USB2 EHCI Controller #1 (rev 02)
00:1e.0 PCI bridge: Intel Corporation 82801 PCI Bridge (rev 92)
00:1f.0 ISA bridge: Intel Corporation 82801IB (ICH9) LPC Interface Controller (rev 02)
00:1f.2 IDE interface: Intel Corporation 82801IB (ICH9) 2 port SATA IDE Controller (rev 02)
00:1f.3 SMBus: Intel Corporation 82801I (ICH9 Family) SMBus Controller (rev 02)
00:1f.5 IDE interface: Intel Corporation 82801I (ICH9 Family) 2 port SATA IDE Controller (rev 02)
01:00.0 VGA compatible controller: ATI Technologies Inc RV505 CE [Radeon X1550 64-bit]
01:00.1 Display controller: ATI Technologies Inc Device 717f
02:00.0 Ethernet controller: Attansic Technology Corp. L1 Gigabit Ethernet Adapter (rev b0)
03:00.0 SATA controller: JMicron Technologies, Inc. JMicron 20360/20363 AHCI Controller (rev 03)
03:00.1 IDE interface: JMicron Technologies, Inc. JMicron 20360/20363 AHCI Controller (rev 03)
05:03.0 FireWire (IEEE 1394): VIA Technologies, Inc. VT6306 Fire II IEEE 1394 OHCI Link Layer Controller (rev c0)

[-- Attachment #3: config-2.6.27-05178-g2e532d6-dirty.gz --]
[-- Type: application/x-gzip, Size: 11296 bytes --]

Re: WARNING: at drivers/ata/libata-eh.c:664 (and others) with 2.6.27-05178

[Christian Borntraeger]

Am Samstag, 25. Oktober 2008 schrieb Christian Borntraeger:
> Hello Jens,
> 
> while doing a backup on DVD+R I got the following warning (and a k3b hung).
> the drive is a Plextor 716A on a jmicron PATA port.
> I have never seen this with earlier kernels. I am a bit reluctant to
> reproduce or bisect this problem, since it might kills my blank DVDs.
> Could this be related to commit
> e013e13bf605b9e6b702adffbe2853cfc60e7806 (libata: fix bug with non-ncq 
devices)?
> Thank you for any idea.

OK. Now it also fails on 2.6.26, so it looks like a hardware problem.
The only difference is, that 2.6.26 shows no WARN_ON.

Christian