Bug#382711: linux-image-2.6.16-2-xen-amd64-k8: sata assertion failure and kernel oops
Package: linux-image-2.6.16-2-xen-amd64-k8
Version: 2.6.16-17
Severity: normal
A few minutes ago, one of our amd64 machines fell over with the errors
below. It has two Maxtor disks attached to an nVidia controller,
running as a raid1 pair: the boot-time messages look like this:
libata version 1.20 loaded.
sata_nv 0000:00:0e.0: version 0.8
PCI: Setting latency timer of device 0000:00:0e.0 to 64
ata1: SATA max UDMA/133 cmd 0xE800 ctl 0xE482 bmdma 0xE000 irq 11
ata2: SATA max UDMA/133 cmd 0xE400 ctl 0xE082 bmdma 0xE008 irq 11
ata1: SATA link up 3.0 Gbps (SStatus 123)
ata1: dev 0 cfg 49:2f00 82:7c6b 83:7f09 84:4773 85:7c69 86:3e01 87:4763
88:407f
ata1: dev 0 ATA-7, max UDMA/133, 160086528 sectors: LBA48
ata1: dev 0 configured for UDMA/133
scsi0 : sata_nv
ata2: SATA link down (SStatus 0)
scsi1 : sata_nv
Vendor: ATA Model: Maxtor 6V080E0 Rev: VA11
Type: Direct-Access ANSI SCSI revision: 05
PCI: Setting latency timer of device 0000:00:0f.0 to 64
ata3: SATA max UDMA/133 cmd 0xDC00 ctl 0xD882 bmdma 0xD400 irq 10
ata4: SATA max UDMA/133 cmd 0xD800 ctl 0xD482 bmdma 0xD408 irq 10
ata3: SATA link up 3.0 Gbps (SStatus 123)
ata3: dev 0 cfg 49:2f00 82:7c6b 83:7f69 84:4773 85:7c69 86:3e01 87:4763
88:407f
ata3: dev 0 ATA-7, max UDMA/133, 160086528 sectors: LBA48
ata3: dev 0 configured for UDMA/133
scsi2 : sata_nv
ata4: SATA link down (SStatus 0)
scsi3 : sata_nv
Vendor: ATA Model: Maxtor 6V080E0 Rev: VA11
Type: Direct-Access ANSI SCSI revision: 05
Here's the log of the crash:
--
Aug 12 20:14:03 uebercounty kernel: ata1: translated ATA stat/err
0x37/00 to SCSI SK/ASC/ASCQ 0x4/00/00
Aug 12 20:17:03 uebercounty kernel: ata1: status=0x37 { DeviceFault
SeekComplete CorrectedError Index Error }
Aug 12 20:17:03 uebercounty kernel: ata1: command 0x35 timeout, stat
0xb7 host_stat 0x21
Aug 12 20:17:03 uebercounty kernel: ata1: translated ATA stat/err
0xb7/00 to SCSI SK/ASC/ASCQ 0xb/47/00
Aug 12 20:17:03 uebercounty kernel: ata1: status=0xb7 { Busy }
Aug 12 20:17:03 uebercounty kernel: sd 0:0:0:0: SCSI error: return code
= 0x8000002
Aug 12 20:17:03 uebercounty kernel: sda: Current: sense key: Aborted
Command
Aug 12 20:17:03 uebercounty kernel: Additional sense: Scsi parity
error
Aug 12 20:17:03 uebercounty kernel: end_request: I/O error, dev sda,
sector 4096967
Aug 12 20:17:03 uebercounty kernel: raid1: Disk failure on sda3,
disabling device.
Aug 12 20:17:03 uebercounty kernel: ^IOperation continuing on 1 devices
Aug 12 20:17:03 uebercounty kernel: ATA: abnormal status 0xB7 on port
0xE807
Aug 12 20:17:03 uebercounty kernel: ATA: abnormal status 0xB7 on port
0xE807
Aug 12 20:17:33 uebercounty kernel: ATA: abnormal status 0xB7 on port
0xE807
Aug 12 20:17:33 uebercounty kernel: ata1: command 0x35 timeout, stat
0xb7 host_stat 0x21
Aug 12 20:17:33 uebercounty kernel: ata1: translated ATA stat/err
0xb7/00 to SCSI SK/ASC/ASCQ 0xb/47/00
Aug 12 20:17:33 uebercounty kernel: ata1: status=0xb7 { Busy }
Aug 12 20:17:33 uebercounty kernel: sd 0:0:0:0: SCSI error: return code
= 0x8000002
Aug 12 20:17:33 uebercounty kernel: sda: Current: sense key: Aborted
Command
Aug 12 20:17:33 uebercounty kernel: Additional sense: Scsi parity
error
Aug 12 20:17:33 uebercounty kernel: end_request: I/O error, dev sda,
sector 5243841
Aug 12 20:17:33 uebercounty kernel: ATA: abnormal status 0xB7 on port
0xE807
Aug 12 20:17:33 uebercounty kernel: ATA: abnormal status 0xB7 on port
0xE807
Aug 12 20:17:33 uebercounty /USR/SBIN/CRON[12579]: (root) CMD (
run-parts --report /etc/cron.hourly)
Aug 12 20:17:33 uebercounty kernel: ATA: abnormal status 0xB7 on port
0xE807
Aug 12 20:17:33 uebercounty kernel: ata1: command 0x35 timeout, stat
0xb7 host_stat 0x21
Aug 12 20:17:33 uebercounty kernel: ata1: translated ATA stat/err
0xb7/00 to SCSI SK/ASC/ASCQ 0xb/47/00
Aug 12 20:17:33 uebercounty kernel: ata1: status=0xb7 { Busy }
Aug 12 20:17:33 uebercounty kernel: sd 0:0:0:0: SCSI error: return code
= 0x8000002
Aug 12 20:17:33 uebercounty kernel: sda: Current: sense key: Aborted
Command
Aug 12 20:17:33 uebercounty kernel: Additional sense: Scsi parity
error
Aug 12 20:17:33 uebercounty kernel: end_request: I/O error, dev sda,
sector 5257775
Aug 12 20:17:33 uebercounty kernel: ATA: abnormal status 0xB7 on port
0xE807
Aug 12 20:17:33 uebercounty last message repeated 2 times
[...]
Aug 12 20:31:05 uebercounty kernel: ata1: command 0xa1 timeout, stat
0xb7 host_stat 0x0
Aug 12 20:31:05 uebercounty kernel: ata1: translated ATA stat/err
0xb7/00 to SCSI SK/ASC/ASCQ 0xb/47/00
Aug 12 20:31:05 uebercounty kernel: ata1: status=0xb7 { Busy }
Aug 12 20:31:05 uebercounty kernel: Assertion failed! qc !=
NULL,drivers/scsi/libata-core.c,ata_pio_poll,line=2897
Aug 12 20:31:20 uebercounty last message repeated 911 times
Aug 12 20:31:20 uebercounty kernel: Assertion failed! qc !=
NULL,drivers/scsi/libata-core.c,ata_pio_poll,line=2897
Aug 12 20:31:23 uebercounty last message repeated 182 times
Aug 12 20:31:23 uebercounty kernel: Assertion failed! qc !=
NULL,drivers/scsi/libata-core.c,ata_pio_poll,line=2897
Aug 12 20:31:26 uebercounty last message repeated 158 times
Aug 12 20:31:26 uebercounty kernel: Unable to handle kernel NULL pointer
dereference at 00000000000000d0 RIP:
Aug 12 20:31:26 uebercounty kernel:
<ffffffff880e3954>{:libata:ata_pio_task+1520}
Aug 12 20:31:26 uebercounty kernel: PGD ed7af067 PUD eed9c067 PMD 0
Aug 12 20:31:26 uebercounty kernel: Oops: 0002 [1] SMP
Aug 12 20:31:26 uebercounty kernel: CPU 0
Aug 12 20:31:26 uebercounty kernel: Modules linked in: ipt_LOG xt_state
ip_conntrack nfnetlink xt_physdev iptable_filter ip_tables x_tables
bridge ipv6 loop w83627ehf i2c_isa i2c_core sbp2 eth1394 snd_hda_intel
snd_hda_codec snd_pcm snd_timer snd soundcore psmouse snd_page_alloc
serio_raw ext3 jbd mbcache dm_mirror dm_snapshot dm_mod raid1 md_mod
ide_generic ide_disk sd_mod sata_nv libata scsi_mod ehci_hcd amd74xx
ohci_hcd generic ide_core ohci1394 forcedeth ieee1394 processor
Aug 12 20:31:26 uebercounty kernel: Pid: 1597, comm: ata/0 Not tainted
2.6.16-2-xen-amd64-k8 #1
Aug 12 20:31:26 uebercounty kernel: RIP: e030:[<ffffffff880e3954>]
<ffffffff880e3954>{:libata:ata_pio_task+1520}
Aug 12 20:31:26 uebercounty kernel: RSP: e02b:ffff8800ee375e18 EFLAGS:
00010287
Aug 12 20:31:26 uebercounty kernel: RAX: 0000000105754df0 RBX:
0000000000000004 RCX: ffffffff8032c328
Aug 12 20:31:26 uebercounty kernel: RDX: 000000000000e807 RSI:
0000000000000000 RDI: ffff8800007c0480
Aug 12 20:31:26 uebercounty kernel: RBP: ffff8800007c0480 R08:
ffffffff8032c328 R09: ffff880000f1d3c0
Aug 12 20:31:26 uebercounty kernel: R10: 0000000000000019 R11:
0000000000000000 R12: 0000000000000002
Aug 12 20:31:26 uebercounty kernel: R13: 0000000000000000 R14:
ffff8800007c0480 R15: ffffffff880e3364
Aug 12 20:31:26 uebercounty kernel: FS: 00002b4e695156d0(0000)
GS:ffffffff80402000(0000) knlGS:0000000000000000
Aug 12 20:31:26 uebercounty kernel: CS: e033 DS: 0000 ES: 0000
Aug 12 20:31:26 uebercounty kernel: Process ata/0 (pid: 1597, threadinfo
ffff8800ee374000, task ffff8800ee3ae080)
Aug 12 20:31:26 uebercounty kernel: Stack: ffff8800ee375e58
ffffffff0000000f 0000000000049acd ffff8800007c0b30
Aug 12 20:31:26 uebercounty kernel: ffff8800007c0b38
ffff8800ee3da940 0000000000000000 ffff8800007c0480
Aug 12 20:31:26 uebercounty kernel: ffffffff880e3364
ffffffff80139555
Aug 12 20:31:26 uebercounty kernel: Call Trace:
<ffffffff880e3364>{:libata:ata_pio_task+0}
Aug 12 20:31:26 uebercounty kernel:
<ffffffff80139555>{run_workqueue+146} <ffffffff8013969d>{worker_thread
+0}
Aug 12 20:31:26 uebercounty kernel:
<ffffffff8013c57c>{keventd_create_kthread+0}
<ffffffff8013978d>{worker_thread+240}
Aug 12 20:31:26 uebercounty kernel:
<ffffffff801246d2>{default_wake_function+0}
<ffffffff8013c57c>{keventd_create_kthread+0}
Aug 12 20:31:26 uebercounty kernel:
<ffffffff8013c57c>{keventd_create_kthread+0} <ffffffff8013c6e7>{kthread
+203}
Aug 12 20:31:26 uebercounty kernel: <ffffffff8010b71a>{child_rip
+8} <ffffffff8013c57c>{keventd_create_kthread+0}
Aug 12 20:31:26 uebercounty kernel: <ffffffff8013c61c>{kthread+0}
<ffffffff8010b712>{child_rip+0}
Aug 12 20:31:26 uebercounty kernel:
Aug 12 20:31:26 uebercounty kernel: Code: 41 83 8d d0 00 00 00 04 c7 85
10 07 00 00 03 00 00 00 e9 0a
Aug 12 20:31:26 uebercounty kernel: RIP
<ffffffff880e3954>{:libata:ata_pio_task+1520} RSP <ffff8800ee375e18>
Aug 12 20:31:26 uebercounty kernel: CR2: 00000000000000d0
--
p.
Reply to: