From owner-cvs-all@FreeBSD.ORG Wed May 2 16:37:05 2007 Return-Path: X-Original-To: cvs-all@freebsd.org Delivered-To: cvs-all@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [69.147.83.52]) by hub.freebsd.org (Postfix) with ESMTP id 5547F16A403 for ; Wed, 2 May 2007 16:37:05 +0000 (UTC) (envelope-from nate@root.org) Received: from root.org (root.org [67.118.192.226]) by mx1.freebsd.org (Postfix) with ESMTP id 2601D13C448 for ; Wed, 2 May 2007 16:37:05 +0000 (UTC) (envelope-from nate@root.org) Received: (qmail 96979 invoked from network); 2 May 2007 16:37:04 -0000 Received: from ppp-71-139-7-60.dsl.snfc21.pacbell.net (HELO ?10.0.0.235?) (nate-mail@71.139.7.60) by root.org with ESMTPA; 2 May 2007 16:37:04 -0000 Message-ID: <4638BE29.1020505@root.org> Date: Wed, 02 May 2007 09:36:57 -0700 From: Nate Lawson User-Agent: Thunderbird 2.0.0.0 (X11/20070424) MIME-Version: 1.0 To: John Baldwin References: <200705020615.l426FDo7015874@repoman.freebsd.org> <20070502070707.GA68774@hub.freebsd.org> <200705021056.34887.jhb@freebsd.org> <4638BAC9.7000603@root.org> In-Reply-To: <4638BAC9.7000603@root.org> X-Enigmail-Version: 0.95.0 Content-Type: text/plain; charset=ISO-8859-1 Content-Transfer-Encoding: 7bit Cc: cvs-src@freebsd.org, Darren Reed , src-committers@freebsd.org, cvs-all@freebsd.org Subject: Re: cvs commit: src/sys/kern kern_intr.c src/sys/sys interrupt.h X-BeenThere: cvs-all@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: CVS commit messages for the entire tree List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Wed, 02 May 2007 16:37:05 -0000 Nate Lawson wrote: > John Baldwin wrote: >> On Wednesday 02 May 2007 03:07:07 am Darren Reed wrote: >>> On Wed, May 02, 2007 at 06:15:13AM +0000, Nate Lawson wrote: >>>> njl 2007-05-02 06:15:13 UTC >>>> >>>> FreeBSD src repository >>>> >>>> Modified files: (Branch: RELENG_6) >>>> sys/kern kern_intr.c >>>> sys/sys interrupt.h >>>> Log: >>>> MFC: rate-check the interrupt storm message and bump the counter 500 -> >> 1000 >>> Is this number, "500" or "1000" somehow "magical" for modern hardware? >>> >>> If I had a 500MHZ, 1GHz, 1.5GHz, 2GHz, 2.5GHz machines, each with the >>> appropriate architecture, what would the correct value for this be? >>> Is i always 1000 or should it be calculated? >> It's a SWAG and tunable for machines where it doesn't work. In practice the >> old setting seemed to be a bit too trigger-happy as I know my printer always >> triggered it, for example. >> > > There's more to it than just your Ghz number. It's a counter of the > number of times an interrupt has triggered while the previous one was > being serviced. The faster your kernel, the lower the number could be. > > I have a slow early SMP Celeron system with a dc(4) adapter with 4 ports > sharing an irq with my ata. At 3 am, the nightly script kicks off > enough IO that it triggers a bug in my dc(4) card that causes it to mask > the interrupt too long. Then, the irq storm suppression logic kicked > in, causing ata to timeout the request. The drive is on a mirror so I'd > lose half the mirror, then rebuild in the morning. With this value > bumped, I don't have that problem any more but the real issue is why > dc(4) is being so quirky under heavy shared irq load. > This is on 6.x btw. Is there any reason why our retries is so low? sys/dev/ata/ata-disk.c: request->retries = 2; Here are the dc(4) and ata devices, note that they're sharing irq 18: dc0: port 0xc000-0xc07f mem 0xd5000000-0xd50003ff irq 19 at device 4.0 on pci2 miibus0: on dc0 ukphy0: on miibus0 ukphy0: 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, auto dc0: Ethernet address: 00:80:c8:cd:36:85 dc1: port 0xc400-0xc47f mem 0xd5001000-0xd50013ff irq 16 at device 5.0 on pci2 miibus1: on dc1 ukphy1: on miibus1 ukphy1: 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, auto dc1: Ethernet address: 00:80:c8:cd:36:86 dc2: port 0xc800-0xc87f mem 0xd5002000-0xd50023ff irq 17 at device 6.0 on pci2 miibus2: on dc2 ukphy2: on miibus2 ukphy2: 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, auto dc2: Ethernet address: 00:80:c8:cd:36:87 dc3: port 0xcc00-0xcc7f mem 0xd5003000-0xd50033ff irq 18 at device 7.0 on pci2 miibus3: on dc3 ukphy3: on miibus3 ukphy3: 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, auto dc3: Ethernet address: 00:80:c8:cd:36:88 pci0: at device 15.0 (no driver attached) atapci1: port 0xd400-0xd407,0xd800-0xd803,0xdc00-0xdcff irq 18 at device 19.0 on pci0 ata2: on atapci1 atapci2: port 0xe000-0xe007,0xe400-0xe403,0xe800-0xe8ff irq 18 at device 19.1 on pci0 ata3: on atapci2 And here are the error messages: Apr 27 03:03:56 bento kernel: dc0: TX underrun -- increasing TX threshold Apr 27 03:05:01 bento kernel: Interrupt storm detected on "irq18:"; throttling interrupt source Apr 27 03:05:16 bento kernel: ad6: TIMEOUT - READ_DMA48 retrying (1 retry left) LBA=294226271 Apr 27 03:05:16 bento kernel: ad6: TIMEOUT - READ_DMA48 retrying (0 retries left) LBA=294226271 Apr 27 03:05:16 bento kernel: ad6: FAILURE - READ_DMA48 timed out LBA=294226271 Apr 27 03:05:16 bento kernel: GEOM_MIRROR: Request failed (error=5). ad6[READ(offset=150643850752, length=8192)] Apr 27 03:05:16 bento kernel: GEOM_MIRROR: Device gm0: provider ad6 disconnected. There appears to be no delay between resubmitting the requests each time the TIMEOUT message occurs. It all happens in 1 second. Would it be possible to schedule retries from a callout or thread to allow more delay before failing them a second time? I then rebuilt the array: Apr 27 17:25:43 bento kernel: GEOM_MIRROR: Device gm0: provider ad6 detected. Apr 27 17:25:43 bento kernel: GEOM_MIRROR: Device gm0: rebuilding provider ad6. Apr 27 17:36:58 bento kernel: dc0: TX underrun -- increasing TX threshold Apr 27 18:12:25 bento kernel: dc0: TX underrun -- increasing TX threshold Apr 27 18:20:59 bento kernel: dc1: TX underrun -- increasing TX threshold Apr 27 19:41:32 bento kernel: GEOM_MIRROR: Device gm0: rebuilding provider ad6 finished. Apr 27 19:41:32 bento kernel: GEOM_MIRROR: Device gm0: provider ad6 activated. Apr 28 04:22:04 bento kernel: ad6: TIMEOUT - READ_DMA retrying (1 retry left) LBA=9894431 Note that I still got a timeout but it succeeded without error. I think this is a combination of the dc(4) and highpoint hpt366 driver interaction. dc(4) is probably holding Giant or something too long and ata is being too sensitive to the slow hw. Comments? -- Nate