From owner-freebsd-stable@FreeBSD.ORG Wed Oct 26 16:30:11 2005 Return-Path: X-Original-To: freebsd-stable@freebsd.org Delivered-To: freebsd-stable@freebsd.org Received: from mx1.FreeBSD.org (mx1.freebsd.org [216.136.204.125]) by hub.freebsd.org (Postfix) with ESMTP id 987F616A41F; Wed, 26 Oct 2005 16:30:11 +0000 (GMT) (envelope-from davidt@yadt.co.uk) Received: from outcold.yadt.co.uk (outcold.yadt.co.uk [81.187.204.178]) by mx1.FreeBSD.org (Postfix) with ESMTP id EA9CE43D53; Wed, 26 Oct 2005 16:30:10 +0000 (GMT) (envelope-from davidt@yadt.co.uk) Received: from localhost (localhost [127.0.0.1]) by outcold.yadt.co.uk (Postfix) with ESMTP id DFEAB1DD4A7; Wed, 26 Oct 2005 17:30:15 +0100 (BST) Received: from outcold.yadt.co.uk ([127.0.0.1]) by localhost (outcold.yadt.co.uk [127.0.0.1]) (amavisd-new, port 10024) with ESMTP id 90063-10; Wed, 26 Oct 2005 17:30:15 +0100 (BST) Received: by outcold.yadt.co.uk (Postfix, from userid 1001) id 3A2991DD4A4; Wed, 26 Oct 2005 17:30:15 +0100 (BST) Date: Wed, 26 Oct 2005 17:30:15 +0100 From: David Taylor To: freebsd-stable@freebsd.org Message-ID: <20051026163015.GA98346@outcold.yadt.co.uk> Mail-Followup-To: freebsd-stable@freebsd.org, sos@freebsd.org Mime-Version: 1.0 Content-Type: text/plain; charset=iso-8859-15 Content-Disposition: inline User-Agent: Mutt/1.4.2.1i X-Virus-Scanned: amavisd-new 2.3.3 (20050822) at yadt.co.uk Cc: sos@freebsd.org Subject: ATA RAID problem in 6.0-RC1 (ata_alloc_request/ata_raid_init_request) X-BeenThere: freebsd-stable@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: Production branch of FreeBSD source code List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Wed, 26 Oct 2005 16:30:11 -0000 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: 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 AMD Features=0xe2500800,LM,3DNow+,3DNow> real memory = 1073676288 (1023 MB) avail memory = 1027952640 (980 MB) ioapic0 irqs 0-23 on motherboard acpi0: on motherboard acpi0: Power Button (fixed) ... atapci0: port 0xec00-0xec7f,0xe800-0xe8ff mem 0xcfffb000-0xcfffbfff,0xcffc0000-0xcffdffff irq 17 at device 13.0 on pci0 ata2: on atapci0 ata3: on atapci0 ata4: on atapci0 atapci1: port 0xc800-0xc807,0xc400-0xc403,0xc000-0xc007,0xbc00-0xbc03,0xb800-0xb80f,0xb400-0xb4ff irq 20 at device 15.0 on pci0 ata5: on atapci1 ata6: on atapci1 atapci2: port 0x1f0-0x1f7,0x3f6,0x170-0x177,0x376,0xfc00-0xfc0f at device 15.1 on pci0 ata0: on atapci2 ata1: on atapci2 ... ad0: 32634MB at ata0-master UDMA66 acd0: DVDR at ata1-master UDMA33 ad4: 156334MB at ata2-master SATA150 ad6: 156334MB at ata3-master SATA150 ar0: 156334MB 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 ATA/ATAPI revision 4 Slave: no device present ATA channel 1: Master: acd0 ATA/ATAPI revision 0 Slave: no device present ATA channel 2: Master: ad4 Serial ATA v1.0 Slave: no device present ATA channel 3: Master: ad6 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