Chuck Swiger
2005-Jul-31 19:20 UTC
Odd I/O performance with 5-STABLE, "interrupt storm" against USB...?
Hi, all-- I am seeing lower-than-expected I/O performance on a Dell PowerEdge 2850, using two of these:> da0: <MAXTOR ATLAS10K5_73SCA JNZM> 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: <LSILogic PERC 4e/Di>. 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: <Intel 82801EB (ICH5) USB controller USB-C> 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: <DELL PE BKC > 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<FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA, CMOV,PAT,PSE36,CLFLUSH,DTS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,PBE> 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 <Version 2.0> irqs 0-23 on motherboard ioapic1 <Version 2.0> irqs 32-55 on motherboard ioapic2 <Version 2.0> irqs 64-87 on motherboard ioapic3 <Version 2.0> irqs 96-119 on motherboard npx0: <math processor> on motherboard npx0: INT 16 interface acpi0: <DELL PE BKC> 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: <ACPI CPU> on acpi0 cpu1: <ACPI CPU> on acpi0 cpu2: <ACPI CPU> on acpi0 cpu3: <ACPI CPU> on acpi0 pcib0: <ACPI Host-PCI bridge> port 0xcf8-0xcff on acpi0 pci0: <ACPI PCI bus> on pcib0 pcib1: <ACPI PCI-PCI bridge> at device 2.0 on pci0 pci1: <ACPI PCI bus> on pcib1 pcib2: <ACPI PCI-PCI bridge> at device 0.0 on pci1 pci2: <ACPI PCI bus> on pcib2 amr0: <LSILogic MegaRAID 1.51> mem 0xdfdc0000-0xdfdfffff,0xd80f0000-0xd80fffff irq 46 at device 14.0 on pci2 amr0: <LSILogic PERC 4e/Di> Firmware 521S, BIOS H430, 256MB RAM pcib3: <ACPI PCI-PCI bridge> at device 0.2 on pci1 pci3: <ACPI PCI bus> on pcib3 pcib4: <ACPI PCI-PCI bridge> at device 4.0 on pci0 pci4: <ACPI PCI bus> on pcib4 pcib5: <ACPI PCI-PCI bridge> at device 5.0 on pci0 pci5: <ACPI PCI bus> on pcib5 pcib6: <ACPI PCI-PCI bridge> at device 0.0 on pci5 pci6: <ACPI PCI bus> on pcib6 em0: <Intel(R) PRO/1000 Network Connection, Version - 1.7.35> 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: <ACPI PCI-PCI bridge> at device 0.2 on pci5 pci7: <ACPI PCI bus> on pcib7 em1: <Intel(R) PRO/1000 Network Connection, Version - 1.7.35> 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: <ACPI PCI-PCI bridge> at device 6.0 on pci0 pci8: <ACPI PCI bus> on pcib8 pcib9: <ACPI PCI-PCI bridge> at device 0.0 on pci8 pci9: <ACPI PCI bus> on pcib9 pcib10: <ACPI PCI-PCI bridge> at device 0.2 on pci8 pci10: <ACPI PCI bus> on pcib10 uhci0: <Intel 82801EB (ICH5) USB controller USB-A> port 0xbce0-0xbcff irq 16 at device 29.0 on pci0 usb0: <Intel 82801EB (ICH5) USB controller USB-A> 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: <Intel 82801EB (ICH5) USB controller USB-B> port 0xbcc0-0xbcdf irq 19 at device 29.1 on pci0 usb1: <Intel 82801EB (ICH5) USB controller USB-B> 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: <Intel 82801EB (ICH5) USB controller USB-C> port 0xbca0-0xbcbf irq 18 at device 29.2 on pci0 usb2: <Intel 82801EB (ICH5) USB controller USB-C> 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: <serial bus, USB> at device 29.7 (no driver attached) pcib11: <ACPI PCI-PCI bridge> at device 30.0 on pci0 pci11: <ACPI PCI bus> on pcib11 pci11: <display, VGA> at device 13.0 (no driver attached) isab0: <PCI-ISA bridge> at device 31.0 on pci0 isa0: <ISA bus> on isab0 atapci0: <Intel ICH5 UDMA100 controller> 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: <floppy drive controller> 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: <ISA Option ROMs> at iomem 0xec000-0xeffff,0xce800-0xcf7ff,0xcb000-0xcbfff,0xc0000-0xcafff on isa0 pmtimer0 on isa0 atkbdc0: <Keyboard controller (i8042)> at port 0x64,0x60 on isa0 atkbd0: <AT Keyboard> irq 1 on atkbdc0 kbd0 at atkbd0 ppc0: parallel port not found. sc0: <System console> 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: <Generic ISA VGA> 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 <TEAC CD-ROM CD-224E/K.9A> at ata0-master PIO4 amrd0: <LSILogic MegaRAID logical drive> 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: <PE/PV 1x6 SCSI BP 1.0> 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