From owner-freebsd-stable@FreeBSD.ORG Sun Jul 31 19:20:54 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 6AA9716A41F for ; Sun, 31 Jul 2005 19:20:54 +0000 (GMT) (envelope-from cswiger@mac.com) Received: from pi.codefab.com (pi.codefab.com [199.103.21.227]) by mx1.FreeBSD.org (Postfix) with ESMTP id DE1BA43D45 for ; Sun, 31 Jul 2005 19:20:53 +0000 (GMT) (envelope-from cswiger@mac.com) Received: from localhost (localhost [127.0.0.1]) by pi.codefab.com (Postfix) with ESMTP id E29755CBA for ; Sun, 31 Jul 2005 15:20:52 -0400 (EDT) Received: from pi.codefab.com ([127.0.0.1]) by localhost (pi.codefab.com [127.0.0.1]) (amavisd-new, port 10024) with ESMTP id 89611-08 for ; Sun, 31 Jul 2005 15:20:49 -0400 (EDT) Received: from [192.168.1.3] (pool-68-161-54-113.ny325.east.verizon.net [68.161.54.113]) by pi.codefab.com (Postfix) with ESMTP id A41005C44 for ; Sun, 31 Jul 2005 15:20:48 -0400 (EDT) Message-ID: <42ED2496.7030801@mac.com> Date: Sun, 31 Jul 2005 15:20:54 -0400 From: Chuck Swiger Organization: The Courts of Chaos User-Agent: Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv:1.7.10) Gecko/20050716 X-Accept-Language: en-us, en MIME-Version: 1.0 To: Subscribers to FreeBSD-Stable Content-Type: text/plain; charset=us-ascii; format=flowed Content-Transfer-Encoding: 7bit X-Virus-Scanned: amavisd-new at codefab.com Cc: Subject: Odd I/O performance with 5-STABLE, "interrupt storm" against USB...? 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: Sun, 31 Jul 2005 19:20:54 -0000 Hi, all-- I am seeing lower-than-expected I/O performance on a Dell PowerEdge 2850, using two of these: > da0: Fixed Direct Access SCSI-3 device > da0: 320.000MB/s transfers (160.000MHz, offset 127, 16bit), Tagged Queueing Enabled > da0: 70007MB (143374650 512 byte sectors: 255H 63S/T 8924C) ...only in a RAID-1 mirror via a amr0: . The bare drive looks like this in "diskinfo -t": dev/da0s1 [ ... ] Seek times: Full stroke: 250 iter in 3.062608 sec = 12.250 msec Half stroke: 250 iter in 2.268513 sec = 9.074 msec Quarter stroke: 500 iter in 3.760458 sec = 7.521 msec Short forward: 400 iter in 1.953691 sec = 4.884 msec Short backward: 400 iter in 2.058626 sec = 5.147 msec Seq outer: 2048 iter in 1.881816 sec = 0.919 msec Seq inner: 2048 iter in 1.885653 sec = 0.921 msec Transfer rates: outside: 102400 kbytes in 1.193841 sec = 85774 kbytes/sec middle: 102400 kbytes in 1.389315 sec = 73705 kbytes/sec inside: 102400 kbytes in 2.225631 sec = 46009 kbytes/sec ...and via the RAID controller: /dev/amrd0s1 [ ... ] Seek times: Full stroke: 250 iter in 1.105103 sec = 4.420 msec Half stroke: 250 iter in 1.548077 sec = 6.192 msec Quarter stroke: 500 iter in 3.051026 sec = 6.102 msec Short forward: 400 iter in 1.949402 sec = 4.874 msec Short backward: 400 iter in 2.053033 sec = 5.133 msec Seq outer: 2048 iter in 1.862351 sec = 0.909 msec Seq inner: 2048 iter in 1.872068 sec = 0.914 msec Transfer rates: outside: 102400 kbytes in 2.143257 sec = 47778 kbytes/sec middle: 102400 kbytes in 7.043005 sec = 14539 kbytes/sec inside: 102400 kbytes in 7.211322 sec = 14200 kbytes/sec Something I've noticed is: 51-proxy# dmesg | grep 18 Timecounter "i8254" frequency 1193182 Hz quality 0 uhci2: port 0xbca0-0xbcbf irq 18 at device 29.2 on pci0 Interrupt storm detected on "irq18: uhci2"; throttling interrupt source 52-proxy# vmstat -i interrupt total rate irq8: rtc 293552 127 irq13: npx0 1 0 irq14: ata0 46 0 irq16: uhci0 16056 6 irq18: uhci2 124262 54 irq19: uhci1 3 0 irq46: amr0 120199 52 irq64: em0 16057 6 irq0: clk 2293697 999 Total 2863873 1247 Notice that interrupt rate for irq18 and irq46 are almost identical, yet this box is in a rack without any USB devices attached. I think my RAID IRQ might be being misrouted...? Reads feel "laggy", the system is running almost completely idle, and something like gstat shows only brief spurts of 30-50% utilization when it should be busier. I've even caught it claiming to be able to write faster than it can read (using iozone-21 and 1GB filesizes): [ ... ] Writing the 1024 Megabyte file, 'iozone.tmp'...23.062500 seconds Reading the file...51.664062 seconds IOZONE performance measurements: 46557911 bytes/second for writing the file 20783147 bytes/second for reading the file Full dmesg follows, machine is running close to a stock SMP kernel, HZ=1000, hyperthreading enabled (but disabled doesn't seem to make a difference): Thanks, -- -Chuck 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 5.4-STABLE #0: Sun Jul 31 14:05:13 EDT 2005 root@proxy.example.com:/usr/obj/usr/src/sys/EX ACPI APIC Table: Timecounter "i8254" frequency 1193182 Hz quality 0 CPU: Intel(R) Xeon(TM) CPU 3.00GHz (2992.71-MHz 686-class CPU) Origin = "GenuineIntel" Id = 0xf43 Stepping = 3 Features=0xbfebfbff Hyperthreading: 2 logical CPUs real memory = 1073479680 (1023 MB) avail memory = 1040928768 (992 MB) FreeBSD/SMP: Multiprocessor System Detected: 4 CPUs cpu0 (BSP): APIC ID: 0 cpu1 (AP): APIC ID: 1 cpu2 (AP): APIC ID: 6 cpu3 (AP): APIC ID: 7 ioapic0: Changing APIC ID to 8 ioapic1: Changing APIC ID to 9 ioapic1: WARNING: intbase 32 != expected base 24 ioapic2: Changing APIC ID to 10 ioapic2: WARNING: intbase 64 != expected base 56 ioapic3: Changing APIC ID to 11 ioapic3: WARNING: intbase 96 != expected base 88 ioapic0 irqs 0-23 on motherboard ioapic1 irqs 32-55 on motherboard ioapic2 irqs 64-87 on motherboard ioapic3 irqs 96-119 on motherboard npx0: on motherboard npx0: INT 16 interface acpi0: on motherboard acpi0: Power Button (fixed) Timecounter "ACPI-fast" frequency 3579545 Hz quality 1000 acpi_timer0: <24-bit timer at 3.579545MHz> port 0x808-0x80b on acpi0 cpu0: on acpi0 cpu1: on acpi0 cpu2: on acpi0 cpu3: on acpi0 pcib0: port 0xcf8-0xcff on acpi0 pci0: on pcib0 pcib1: at device 2.0 on pci0 pci1: on pcib1 pcib2: at device 0.0 on pci1 pci2: on pcib2 amr0: mem 0xdfdc0000-0xdfdfffff,0xd80f0000-0xd80fffff irq 46 at device 14.0 on pci2 amr0: Firmware 521S, BIOS H430, 256MB RAM pcib3: at device 0.2 on pci1 pci3: on pcib3 pcib4: at device 4.0 on pci0 pci4: on pcib4 pcib5: at device 5.0 on pci0 pci5: on pcib5 pcib6: at device 0.0 on pci5 pci6: on pcib6 em0: port 0xecc0-0xecff mem 0xdfae0000-0xdfafffff irq 64 at device 7.0 on pci6 em0: Ethernet address: 00:11:43:e9:34:04 em0: Speed:N/A Duplex:N/A pcib7: at device 0.2 on pci5 pci7: on pcib7 em1: port 0xdcc0-0xdcff mem 0xdf8e0000-0xdf8fffff irq 65 at device 8.0 on pci7 em1: Ethernet address: 00:11:43:e9:34:05 em1: Speed:N/A Duplex:N/A pcib8: at device 6.0 on pci0 pci8: on pcib8 pcib9: at device 0.0 on pci8 pci9: on pcib9 pcib10: at device 0.2 on pci8 pci10: on pcib10 uhci0: port 0xbce0-0xbcff irq 16 at device 29.0 on pci0 usb0: on uhci0 usb0: USB revision 1.0 uhub0: Intel UHCI root hub, class 9/0, rev 1.00/1.00, addr 1 uhub0: 2 ports with 2 removable, self powered uhci1: port 0xbcc0-0xbcdf irq 19 at device 29.1 on pci0 usb1: on uhci1 usb1: USB revision 1.0 uhub1: Intel UHCI root hub, class 9/0, rev 1.00/1.00, addr 1 uhub1: 2 ports with 2 removable, self powered uhci2: port 0xbca0-0xbcbf irq 18 at device 29.2 on pci0 usb2: on uhci2 usb2: USB revision 1.0 uhub2: Intel UHCI root hub, class 9/0, rev 1.00/1.00, addr 1 uhub2: 2 ports with 2 removable, self powered pci0: at device 29.7 (no driver attached) pcib11: at device 30.0 on pci0 pci11: on pcib11 pci11: at device 13.0 (no driver attached) isab0: at device 31.0 on pci0 isa0: on isab0 atapci0: port 0xfc00-0xfc0f,0x376,0x170-0x177,0x3f6,0x1f0-0x1f7 at device 31.1 on pci0 ata0: channel #0 on atapci0 ata1: channel #1 on atapci0 fdc0: port 0x3f7,0x3f0-0x3f5 irq 6 drq 2 on acpi0 sio0: <16550A-compatible COM port> port 0x3f8-0x3ff irq 4 flags 0x10 on acpi0 sio0: type 16550A orm0: at iomem 0xec000-0xeffff,0xce800-0xcf7ff,0xcb000-0xcbfff,0xc0000-0xcafff on isa0 pmtimer0 on isa0 atkbdc0: at port 0x64,0x60 on isa0 atkbd0: irq 1 on atkbdc0 kbd0 at atkbd0 ppc0: parallel port not found. sc0: at flags 0x100 on isa0 sc0: VGA <16 virtual consoles, flags=0x300> sio1: configured irq 3 not in bitmap of probed irqs 0 sio1: port may not be enabled vga0: at port 0x3c0-0x3df iomem 0xa0000-0xbffff on isa0 uhub3: Dell product 0xa001, class 9/0, rev 2.00/0.00, addr 2 uhub3: 2 ports with 2 removable, self powered Timecounters tick every 1.000 msec acd0: CDROM at ata0-master PIO4 amrd0: on amr0 amrd0: 69880MB (143114240 sectors) RAID 1 (optimal) Interrupt storm detected on "irq18: uhci2"; throttling interrupt source ses0 at amr0 bus 0 target 6 lun 0 ses0: Fixed Processor SCSI-2 device ses0: SAF-TE Compliant Device SMP: AP CPU #2 Launched! SMP: AP CPU #1 Launched! SMP: AP CPU #3 Launched! Mounting root from ufs:/dev/amrd0s1a