David Taylor
2005-Oct-26 09:30 UTC
ATA RAID problem in 6.0-RC1 (ata_alloc_request/ata_raid_init_request)
I've been seeing a number of strange messages in my log since
updating to 6.0-RC1. Usually they happen when some intense
disk access is happening (e.g. when /etc/periodic/security/100.chksetuid
is running at 03:01), but it doesn't happen _every_ morning, and
it doesn't always happen if I manually run the script.
It also occasionally happens at times where I wouldn't say I was doing
much with the disk.
I'm hoping nothing bad is happening to my data. At least, fsck
doesn't mention any problems, and I haven't noticed any corruption
yet...
I'm on an AMD64 system, with an MSI K8T-Neo2 motherboard.
ATA-related dmesg:
Copyright (c) 1992-2005 The FreeBSD Project.
Copyright (c) 1979, 1980, 1983, 1986, 1988, 1989, 1991, 1992, 1993, 1994
The Regents of the University of California. All rights reserved.
FreeBSD 6.0-RC1 #0: Wed Oct 12 21:05:06 BST 2005
davidt@outcold.yadt.co.uk:/usr/obj/repo/FreeBSD/FreeBSD-6.x/src/sys/OUTCOLD
ACPI APIC Table: <AMIINT VIA_K8 >
Timecounter "i8254" frequency 1193182 Hz quality 0
CPU: AMD Athlon(tm) 64 Processor 3500+ (2200.10-MHz K8-class CPU)
Origin = "AuthenticAMD" Id = 0x10ff0 Stepping = 0
Features=0x78bfbff<FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CLFLUSH,MMX,FXSR,SSE,SSE2>
AMD Features=0xe2500800<SYSCALL,NX,MMX+,<b25>,LM,3DNow+,3DNow>
real memory = 1073676288 (1023 MB)
avail memory = 1027952640 (980 MB)
ioapic0 <Version 0.3> irqs 0-23 on motherboard
acpi0: <AMIINT VIA_K8> on motherboard
acpi0: Power Button (fixed)
...
atapci0: <Promise PDC20579 SATA150 controller> port
0xec00-0xec7f,0xe800-0xe8ff mem 0xcfffb000-0xcfffbfff,0xcffc0000-0xcffdffff irq
17 at device 13.0 on pci0
ata2: <ATA channel 0> on atapci0
ata3: <ATA channel 1> on atapci0
ata4: <ATA channel 2> on atapci0
atapci1: <VIA 6420 SATA150 controller> port
0xc800-0xc807,0xc400-0xc403,0xc000-0xc007,0xbc00-0xbc03,0xb800-0xb80f,0xb400-0xb4ff
irq 20 at device 15.0 on pci0
ata5: <ATA channel 0> on atapci1
ata6: <ATA channel 1> on atapci1
atapci2: <VIA 8237 UDMA133 controller> port
0x1f0-0x1f7,0x3f6,0x170-0x177,0x376,0xfc00-0xfc0f at device 15.1 on pci0
ata0: <ATA channel 0> on atapci2
ata1: <ATA channel 1> on atapci2
...
ad0: 32634MB <IBM DPTA-373420 P71DA32A> at ata0-master UDMA66
acd0: DVDR <NEC DVD RW ND-3520A/1.04> at ata1-master UDMA33
ad4: 156334MB <Maxtor 6B160M0 BANC1B70> at ata2-master SATA150
ad6: 156334MB <Maxtor 6B160M0 BANC1B70> at ata3-master SATA150
ar0: 156334MB <Promise Fasttrak RAID1> status: READY
ar0: disk0 READY (master) using ad6 at ata3-master
ar0: disk1 READY (mirror) using ad4 at ata2-master
atacontrol output:
# atacontrol list
ATA channel 0:
Master: ad0 <IBM-DPTA-373420/P71DA32A> ATA/ATAPI revision 4
Slave: no device present
ATA channel 1:
Master: acd0 <NEC DVD RW ND-3520A/1.04> ATA/ATAPI revision 0
Slave: no device present
ATA channel 2:
Master: ad4 <Maxtor 6B160M0/BANC1B70> Serial ATA v1.0
Slave: no device present
ATA channel 3:
Master: ad6 <Maxtor 6B160M0/BANC1B70> Serial ATA v1.0
Slave: no device present
ATA channel 4:
Master: no device present
Slave: no device present
ATA channel 5:
Master: no device present
Slave: no device present
ATA channel 6:
Master: no device present
Slave: no device present
# atacontrol status ar0
ar0: ATA RAID1 subdisks: ad6 ad4 status: READY
A sample of the error messages follows:
Oct 25 21:20:21 outcold kernel: DOH! ata_alloc_request failed!
Oct 25 21:20:23 outcold kernel: FAILURE - out of memory in ata_raid_init_request
Oct 25 21:20:23 outcold last message repeated 131 times
Oct 25 21:20:23 outcold kernel: g_vfs_done():ar0s1f[WRITE(offset=34597617664,
length=16384)]error = 5
Oct 25 21:20:23 outcold kernel: g_vfs_done():ar0s1f[WRITE(offset=34597748736,
length=16384)]error = 5
Oct 25 21:20:23 outcold kernel: g_vfs_done():ar0s1f[WRITE(offset=34597961728,
length=16384)]error = 5
Oct 25 21:20:23 outcold kernel: g_vfs_done():ar0s1f[WRITE(offset=34598207488,
length=16384)]error = 5
Oct 25 21:20:23 outcold kernel: g_vfs_done():ar0s1f[WRITE(offset=34598453248,
length=16384)]error = 5
Oct 25 21:20:23 outcold kernel: g_vfs_done():ar0s1f[WRITE(offset=34598682624,
length=16384)]error = 5
Oct 25 21:20:23 outcold kernel: g_vfs_done():ar0s1f[WRITE(offset=34598895616,
length=16384)]error = 5
Oct 25 21:20:23 outcold kernel: g_vfs_done():ar0s1f[WRITE(offset=34599174144,
length=16384)]error = 5
Oct 25 21:20:23 outcold kernel: g_vfs_done():ar0s1f[WRITE(offset=34599452672,
length=16384)]error = 5
Oct 25 21:20:23 outcold kernel: g_vfs_done():ar0s1f[WRITE(offset=34599747584,
length=16384)]error = 5
...
...
Oct 25 21:20:23 outcold kernel: g_vfs_done():ar0s1f[WRITE(offset=34629107712,
length=16384)]error = 5
Oct 25 21:20:23 outcold kernel: g_vfs_done():ar0s1f[WRITE(offset=34629386240,
length=16384)]error = 5
Oct 25 21:20:23 outcold kernel: g_vfs_done():ar0s1f[WRITE(offset=34629648384,
length=16384)]error = 5
Oct 25 21:20:53 outcold kernel: DOH! ata_alloc_request failed!
Oct 25 21:20:53 outcold kernel: FAILURE - out of memory in ata_raid_init_request
Oct 25 21:20:53 outcold last message repeated 146 times
Oct 25 21:20:53 outcold kernel: g_vfs_done():ar0s1f[WRITE(offset=7635156992,
length=16384)]error = 5
Oct 25 21:20:53 outcold kernel: g_vfs_done():ar0s1f[WRITE(offset=7635533824,
length=16384)]error = 5
Oct 25 21:20:53 outcold kernel: g_vfs_done():ar0s1f[WRITE(offset=7635992576,
length=16384)]error = 5
...
...
etc
If you need any more deatils, please let me know.
--
David Taylor
David Taylor
2005-Nov-10 07:02 UTC
ATA RAID problem in 6.0-RC1 (ata_alloc_request/ata_raid_init_request)
On Wed, 26 Oct 2005, David Taylor wrote:> I've been seeing a number of strange messages in my log since > updating to 6.0-RC1. Usually they happen when some intense > disk access is happening (e.g. when /etc/periodic/security/100.chksetuid > is running at 03:01), but it doesn't happen _every_ morning, and > it doesn't always happen if I manually run the script. > It also occasionally happens at times where I wouldn't say I was doing > much with the disk.[snip] I'm still seeing (lots) of these messages (below) on 6.0-RELEASE. Should I just file a PR about it, and is there anything else that would be useful to track down what's causing them?> A sample of the error messages follows: > > Oct 25 21:20:21 outcold kernel: DOH! ata_alloc_request failed! > Oct 25 21:20:23 outcold kernel: FAILURE - out of memory in ata_raid_init_request > Oct 25 21:20:23 outcold last message repeated 131 times > Oct 25 21:20:23 outcold kernel: g_vfs_done():ar0s1f[WRITE(offset=34597617664, length=16384)]error = 5 > Oct 25 21:20:23 outcold kernel: g_vfs_done():ar0s1f[WRITE(offset=34597748736, length=16384)]error = 5 > Oct 25 21:20:23 outcold kernel: g_vfs_done():ar0s1f[WRITE(offset=34597961728, length=16384)]error = 5 > Oct 25 21:20:23 outcold kernel: g_vfs_done():ar0s1f[WRITE(offset=34598207488, length=16384)]error = 5 > Oct 25 21:20:23 outcold kernel: g_vfs_done():ar0s1f[WRITE(offset=34598453248, length=16384)]error = 5 > Oct 25 21:20:23 outcold kernel: g_vfs_done():ar0s1f[WRITE(offset=34598682624, length=16384)]error = 5 > Oct 25 21:20:23 outcold kernel: g_vfs_done():ar0s1f[WRITE(offset=34598895616, length=16384)]error = 5 > Oct 25 21:20:23 outcold kernel: g_vfs_done():ar0s1f[WRITE(offset=34599174144, length=16384)]error = 5 > Oct 25 21:20:23 outcold kernel: g_vfs_done():ar0s1f[WRITE(offset=34599452672, length=16384)]error = 5 > Oct 25 21:20:23 outcold kernel: g_vfs_done():ar0s1f[WRITE(offset=34599747584, length=16384)]error = 5 > ... > ... > Oct 25 21:20:23 outcold kernel: g_vfs_done():ar0s1f[WRITE(offset=34629107712, length=16384)]error = 5 > Oct 25 21:20:23 outcold kernel: g_vfs_done():ar0s1f[WRITE(offset=34629386240, length=16384)]error = 5 > Oct 25 21:20:23 outcold kernel: g_vfs_done():ar0s1f[WRITE(offset=34629648384, length=16384)]error = 5 > Oct 25 21:20:53 outcold kernel: DOH! ata_alloc_request failed! > Oct 25 21:20:53 outcold kernel: FAILURE - out of memory in ata_raid_init_request > Oct 25 21:20:53 outcold last message repeated 146 times > Oct 25 21:20:53 outcold kernel: g_vfs_done():ar0s1f[WRITE(offset=7635156992, length=16384)]error = 5 > Oct 25 21:20:53 outcold kernel: g_vfs_done():ar0s1f[WRITE(offset=7635533824, length=16384)]error = 5 > Oct 25 21:20:53 outcold kernel: g_vfs_done():ar0s1f[WRITE(offset=7635992576, length=16384)]error = 5 > ... > ... > etc-- David Taylor