Odd I/O performance with 5-STABLE, "interrupt storm" against USB...?

Chuck Swiger cswiger at mac.com
Sun Jul 31 19:20:54 GMT 2005


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 at 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



More information about the freebsd-stable mailing list