Interrupt/speed problems with 6.2 NFS server

[Doug Clements]

On 10/17/07, Doug Clements <dclements at gmail.com> wrote:
>
> Can you also send the output of ps -auxl?
> >
> > Also - do you notice this performance drop when running something like
> > one of the network performance tools? I'd like to isolate the disk
> > activity from the network activity for a clean test..
> >
>
> I tested this with iperf, and while I did see some nfs performance
> degradation, it did not bog the machine or delay the terminal in the same
> way. NFS requests were still processed in an acceptable fashion. It was
> still responsive to commands and ran processes just fine. I would have to
> say it performed as to be expected during iperf tests (on which I got about
> 85mbit/sec, which is also to be expected). Interrupts went down to about
> 2000/sec on em, but the machine did not hang.
>
> Something I've noticed is that running 'systat -vm' seems to be part of
> the problem. If I run the file copy by itself with rdist, it's fast and runs
> ok. If I run it with systat -vm going, this is when the interrupts jump way
> up and the machine starts to delay badly. Noticing this, I tried running
> 'sysctl -a' during the file copy, thinking there was some problem with
> polling the kernel for certain statistics. Sure enough, sysctl -a delays at
> 2 spots. Once right after " kern.random.sys.harvest.swi: 0" and once again
> after "debug.hashstat.nchash: 131072 61777 6 4713". While it is delayed
> here (for a couple seconds for each one) the machine is totally hung. Maybe
> this is a statistics polling issue? Maybe the machine is delayed just long
> enough in systat -vm to make the nfs clients retry, causing a storm of
> interrupts?
>
> Other systat modes do not seem to cause the same problem (pigs, icmp,
> ifstat).
>
> I do not think the ps or systat output is very accurate, since I can't get
> them to run when the machine is hung up. I type in the command, but it does
> not run until the machine springs back to life. I'm not sure how this will
> affect measurements.
>
> http://toric.loungenet.org/~doug/sysctl-a<http://toric.loungenet.org/%7Edoug/sysctl-a>
> http://toric.loungenet.org/~doug/psauxl<http://toric.loungenet.org/%7Edoug/psauxl>
> http://toric.loungenet.org/~doug/systat-vm<http://toric.loungenet.org/%7Edoug/systat-vm>
>
> My real confusion lies in why there are still em interrupts at all, with
> polling on.
>
> Thanks!
>
> --Doug
>

Well, I'm an idiot. I for some reason though SMP was default in GENERIC, and
didn't really think to check. This is a quad-core box, so on top of POLLING,
I enabled SMP. Now, polling seems to work great (I have no interrupts on the
em device), only the 2000 interrupts/sec on each CPU.

And my strange delay is gone. "systat -vm" runs great, "sysctl -a" can be
run over and over again with no lag and no slowness. I can even run
concurrent backups (da1 -> da2, and da2 -> da1).

Am I missing something in that SMP is a requirement for POLLING? I've never
come across that before.

--Doug

Copyright (c) 1992-2007 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 is a registered trademark of The FreeBSD Foundation.
FreeBSD 6.2-RELEASE-p8 #1: Tue Oct 16 16:45:43 PDT 2007
    admin at madonna.linkline.com:/usr/obj/usr/src/sys/MADONNA
ACPI APIC Table: <INTEL  S5000PSL>
Timecounter "i8254" frequency 1193182 Hz quality 0
CPU: Genuine Intel(R) CPU                  @ 2.66GHz (2670.65-MHz K8-class
CPU)
  Origin = "GenuineIntel"  Id = 0x6f4  Stepping = 4

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>

Features2=0x4e3bd<SSE3,RSVD2,MON,DS_CPL,VMX,EST,TM2,<b9>,CX16,<b14>,<b15>,<b18>>
  AMD Features=0x20100800<SYSCALL,NX,LM>
  AMD Features2=0x1<LAHF>
  Cores per package: 2
real memory  = 4831838208 (4608 MB)
avail memory = 4124962816 (3933 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 <Version 2.0> irqs 0-23 on motherboard
ioapic1 <Version 2.0> irqs 24-47 on motherboard
lapic0: Forcing LINT1 to edge trigger
kbd1 at kbdmux0
ath_hal: 0.9.17.2 (AR5210, AR5211, AR5212, RF5111, RF5112, RF2413, RF5413)
acpi0: <INTEL S5000PSL> on motherboard
acpi0: Power Button (fixed)
Timecounter "ACPI-fast" frequency 3579545 Hz quality 1000
acpi_timer0: <24-bit timer at 3.579545MHz> port 0x408-0x40b on acpi0
cpu0: <ACPI CPU> on acpi0
acpi_throttle0: <ACPI CPU Throttling> on cpu0
cpu1: <ACPI CPU> on acpi0
acpi_throttle1: <ACPI CPU Throttling> on cpu1
acpi_throttle1: failed to attach P_CNT
device_attach: acpi_throttle1 attach returned 6
cpu2: <ACPI CPU> on acpi0
acpi_throttle2: <ACPI CPU Throttling> on cpu2
acpi_throttle2: failed to attach P_CNT
device_attach: acpi_throttle2 attach returned 6
cpu3: <ACPI CPU> on acpi0
acpi_throttle3: <ACPI CPU Throttling> on cpu3
acpi_throttle3: failed to attach P_CNT
device_attach: acpi_throttle3 attach returned 6
acpi_button0: <Sleep Button> on acpi0
acpi_button1: <Power Button> on acpi0
pcib0: <ACPI Host-PCI bridge> port 0xca2,0xca3,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> irq 16 at device 0.0 on pci1
pci2: <ACPI PCI bus> on pcib2
pcib3: <ACPI PCI-PCI bridge> irq 16 at device 0.0 on pci2
pci3: <ACPI PCI bus> on pcib3
pcib4: <ACPI PCI-PCI bridge> irq 17 at device 1.0 on pci2
pci4: <ACPI PCI bus> on pcib4
pcib5: <ACPI PCI-PCI bridge> irq 18 at device 2.0 on pci2
pci5: <ACPI PCI bus> on pcib5
em0: <Intel(R) PRO/1000 Network Connection Version - 6.2.9> port
0x3020-0x303f mem 0xf8820000-0xf883ffff,0xf8400000-0xf87fffff irq 18 at
device 0.0 on pci5
em0: Ethernet address: 00:15:17:21:bf:30
em1: <Intel(R) PRO/1000 Network Connection Version - 6.2.9> port
0x3000-0x301f mem 0xf8800000-0xf881ffff,0xf8000000-0xf83fffff irq 19 at
device 0.1 on pci5
em1: Ethernet address: 00:15:17:21:bf:31
pcib6: <ACPI PCI-PCI bridge> at device 0.3 on pci1
pci6: <ACPI PCI bus> on pcib6
3ware device driver for 9000 series storage controllers, version:
3.60.02.012
twa0: <3ware 9000 series Storage Controller> port 0x2000-0x203f mem
0xfa000000-0xfbffffff,0xf8900000-0xf8900fff irq 26 at device 2.0 on pci6
twa0: [FAST]
twa0: INFO: (0x15: 0x1300): Controller details:: Model 9550SX-12, 12 ports,
Firmware FE9X 3.08.00.004, BIOS BE9X 3.08.00.002
pcib7: <PCI-PCI bridge> at device 3.0 on pci0
pci7: <PCI bus> on pcib7
pcib8: <ACPI PCI-PCI bridge> at device 4.0 on pci0
pci8: <ACPI PCI bus> on pcib8
pcib9: <ACPI PCI-PCI bridge> at device 5.0 on pci0
pci9: <ACPI PCI bus> on pcib9
pcib10: <ACPI PCI-PCI bridge> at device 6.0 on pci0
pci10: <ACPI PCI bus> on pcib10
pcib11: <PCI-PCI bridge> at device 7.0 on pci0
pci11: <PCI bus> on pcib11
pci0: <base peripheral> at device 8.0 (no driver attached)
pcib12: <ACPI PCI-PCI bridge> irq 16 at device 28.0 on pci0
pci12: <ACPI PCI bus> on pcib12
uhci0: <UHCI (generic) USB controller> port 0x4080-0x409f irq 23 at device
29.0 on pci0
uhci0: [GIANT-LOCKED]
usb0: <UHCI (generic) USB controller> 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: <UHCI (generic) USB controller> port 0x4060-0x407f irq 22 at device
29.1 on pci0
uhci1: [GIANT-LOCKED]
usb1: <UHCI (generic) USB controller> 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: <UHCI (generic) USB controller> port 0x4040-0x405f irq 23 at device
29.2 on pci0
uhci2: [GIANT-LOCKED]
usb2: <UHCI (generic) USB controller> 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
uhci3: <UHCI (generic) USB controller> port 0x4020-0x403f irq 22 at device
29.3 on pci0
uhci3: [GIANT-LOCKED]
usb3: <UHCI (generic) USB controller> on uhci3
usb3: USB revision 1.0
uhub3: Intel UHCI root hub, class 9/0, rev 1.00/1.00, addr 1
uhub3: 2 ports with 2 removable, self powered
ehci0: <EHCI (generic) USB 2.0 controller> mem 0xf8c00400-0xf8c007ff irq 23
at device 29.7 on pci0
ehci0: [GIANT-LOCKED]
usb4: EHCI version 1.0
usb4: companion controllers, 2 ports each: usb0 usb1 usb2 usb3
usb4: <EHCI (generic) USB 2.0 controller> on ehci0
usb4: USB revision 2.0
uhub4: Intel EHCI root hub, class 9/0, rev 2.00/1.00, addr 1
uhub4: 8 ports with 8 removable, self powered
pcib13: <ACPI PCI-PCI bridge> at device 30.0 on pci0
pci13: <ACPI PCI bus> on pcib13
pci13: <display, VGA> at device 12.0 (no driver attached)
isab0: <PCI-ISA bridge> at device 31.0 on pci0
isa0: <ISA bus> on isab0
atapci0: <Intel 63XXESB2 UDMA100 controller> port
0x1f0-0x1f7,0x3f6,0x170-0x177,0x376,0x40b0-0x40bf irq 20 at device 31.1 on
pci0
ata0: <ATA channel 0> on atapci0
ata1: <ATA channel 1> on atapci0
atapci1: <Intel 63XXESB2 SATA300 controller> port
0x40c8-0x40cf,0x40e4-0x40e7,0x40c0-0x40c7,0x40e0-0x40e3,0x40a0-0x40af mem
0xf8c00000-0xf8c003ff irq 20 at device 31.2 on pci0
ata2: <ATA channel 0> on atapci1
ata3: <ATA channel 1> on atapci1
pci0: <serial bus, SMBus> at device 31.3 (no driver attached)
atkbdc0: <Keyboard controller (i8042)> port 0x60,0x64 irq 1 on acpi0
atkbd0: <AT Keyboard> irq 1 on atkbdc0
kbd0 at atkbd0
atkbd0: [GIANT-LOCKED]
sio0: <16550A-compatible COM port> port 0x3f8-0x3ff irq 4 flags 0x10 on
acpi0
sio0: type 16550A
sio1: <16550A-compatible COM port> port 0x2f8-0x2ff irq 3 on acpi0
sio1: type 16550A
orm0: <ISA Option ROMs> at iomem
0xc0000-0xc8fff,0xc9000-0xcafff,0xcb000-0xcbfff,0xcc000-0xccfff on isa0
ppc0: cannot reserve I/O port range
sc0: <System console> at flags 0x100 on isa0
sc0: VGA <16 virtual consoles, flags=0x300>
vga0: <Generic ISA VGA> at port 0x3c0-0x3df iomem 0xa0000-0xbffff on isa0
Timecounters tick every 1.000 msec
acd0: CDRW <HL-DT-ST RW/DVD GCC-H21N/1.01> at ata0-master UDMA33
da0 at twa0 bus 0 target 0 lun 0
da0: <AMCC 9550SX-12  DISK 3.08> Fixed Direct Access SCSI-5 device
da0: 100.000MB/s transfers
da0: 238408MB (488259584 512 byte sectors: 255H 63S/T 30392C)
da1 at twa0 bus 0 target 1 lun 0
da1: <AMCC 9550SX-12  DISK 3.08> Fixed Direct Access SCSI-5 device
da1: 100.000MB/s transfers
da1: 476816MB (976519168 512 byte sectors: 255H 63S/T 60785C)
da2 at twa0 bus 0 target 2 lun 0
da2: <AMCC 9550SX-12  DISK 3.08> Fixed Direct Access SCSI-5 device
da2: 100.000MB/s transfers
da2: 476816MB (976519168 512 byte sectors: 255H 63S/T 60785C)
lapic1: Forcing LINT1 to edge trigger
SMP: AP CPU #1 Launched!
lapic6: Forcing LINT1 to edge trigger
SMP: AP CPU #2 Launched!
lapic7: Forcing LINT1 to edge trigger
SMP: AP CPU #3 Launched!
Trying to mount root from ufs:/dev/da0s1a
em1: link state changed to UP