tech-kern archive

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index][Old Index]

lockstat from pathological builds Re: high sys time, very very slow builds on new 24-core system



On Thu, Mar 24, 2011 at 12:04:02PM +0000, Andrew Doran wrote:
> 
> Try lockstat as suggested to see if something pathological is going on.  In
> addition to showing lock contention problems it can often highlight a code
> path being hit too frequently for some reason.

I have attached build.sh and lockstat output from 24-way and 8-way builds
of the amd64 GENERIC kernel on this system.  Also dmesg and mount -v output
so you can see what's mounted how, etc.

Some general observations from watching systat during these builds:

        1) For the -j 8 build, user time is about 20% and sys time is
           about 5% for most of the build -- a 4:1 user:sys ratio.

        2) For the -j 24 build, user time is about 20% and sys time is
           about 60% for most of the build: 1 1:3 user:sys ratio.

        3) The -j 8 build takes 87 seconds.

        4) The -j 24 build takes 88 seconds.

        5) I don't like stuff that sucks. (apologies to Beavis...)

Thor
Copyright (c) 1996, 1997, 1998, 1999, 2000, 2001, 2002, 2003, 2004, 2005,
    2006, 2007, 2008, 2009, 2010, 2011
    The NetBSD Foundation, Inc.  All rights reserved.
Copyright (c) 1982, 1986, 1989, 1991, 1993
    The Regents of the University of California.  All rights reserved.

NetBSD 5.99.48 (GENERIC) #0: Thu Mar 17 02:15:46 UTC 2011
        
builds%b8.netbsd.org@localhost:/home/builds/ab/HEAD/amd64/201103170100Z-obj/home/builds/ab/HEAD/src/sys/arch/amd64/compile/GENERIC
total memory = 32766 MB
avail memory = 31754 MB
timecounter: Timecounters tick every 10.000 msec
timecounter: Timecounter "i8254" frequency 1193182 Hz quality 100
Supermicro H8DGU (1234567890)
mainbus0 (root)
cpu0 at mainbus0 apid 16: AMD Opteron(tm) Processor 6168, id 0x100f91
cpu1 at mainbus0 apid 17: AMD Opteron(tm) Processor 6168, id 0x100f91
cpu2 at mainbus0 apid 18: AMD Opteron(tm) Processor 6168, id 0x100f91
cpu3 at mainbus0 apid 19: AMD Opteron(tm) Processor 6168, id 0x100f91
cpu4 at mainbus0 apid 20: AMD Opteron(tm) Processor 6168, id 0x100f91
cpu5 at mainbus0 apid 21: AMD Opteron(tm) Processor 6168, id 0x100f91
cpu6 at mainbus0 apid 22: AMD Opteron(tm) Processor 6168, id 0x100f91
cpu7 at mainbus0 apid 23: AMD Opteron(tm) Processor 6168, id 0x100f91
cpu8 at mainbus0 apid 24: AMD Opteron(tm) Processor 6168, id 0x100f91
cpu9 at mainbus0 apid 25: AMD Opteron(tm) Processor 6168, id 0x100f91
cpu10 at mainbus0 apid 26: AMD Opteron(tm) Processor 6168, id 0x100f91
cpu11 at mainbus0 apid 27: AMD Opteron(tm) Processor 6168, id 0x100f91
cpu12 at mainbus0 apid 32: AMD Opteron(tm) Processor 6168, id 0x100f91
cpu13 at mainbus0 apid 33: AMD Opteron(tm) Processor 6168, id 0x100f91
cpu14 at mainbus0 apid 34: AMD Opteron(tm) Processor 6168, id 0x100f91
cpu15 at mainbus0 apid 35: AMD Opteron(tm) Processor 6168, id 0x100f91
cpu16 at mainbus0 apid 36: AMD Opteron(tm) Processor 6168, id 0x100f91
cpu17 at mainbus0 apid 37: AMD Opteron(tm) Processor 6168, id 0x100f91
cpu18 at mainbus0 apid 38: AMD Opteron(tm) Processor 6168, id 0x100f91
cpu19 at mainbus0 apid 39: AMD Opteron(tm) Processor 6168, id 0x100f91
cpu20 at mainbus0 apid 40: AMD Opteron(tm) Processor 6168, id 0x100f91
cpu21 at mainbus0 apid 41: AMD Opteron(tm) Processor 6168, id 0x100f91
cpu22 at mainbus0 apid 42: AMD Opteron(tm) Processor 6168, id 0x100f91
cpu23 at mainbus0 apid 43: AMD Opteron(tm) Processor 6168, id 0x100f91
ioapic0 at mainbus0 apid 0: pa 0xfec00000, version 21, 24 pins
acpi0 at mainbus0: Intel ACPICA 20110211
acpi0: X/RSDT: OemId <SMCI  ,        ,20101210>, AslId <MSFT,00000097>
acpi0: SCI interrupting at int 9
timecounter: Timecounter "ACPI-Fast" frequency 3579545 Hz quality 1000
NMEM (PNP0C02) at acpi0 not configured
UMEM (PNP0C02) at acpi0 not configured
attimer1 at acpi0 (TMR, PNP0100): io 0x40-0x43 irq 0
pcppi1 at acpi0 (SPKR, PNP0800): io 0x61
midi0 at pcppi1: PC speaker
sysbeep0 at pcppi1
SIOR (PNP0C02) at acpi0 not configured
hpet0 at acpi0 (HPET, PNP0103): mem 0xfed00000-0xfed003ff
timecounter: Timecounter "hpet0" frequency 14318180 Hz quality 2000
OMSC (PNP0C02) at acpi0 not configured
RMSC (PNP0C02) at acpi0 not configured
UAR1 (PNP0501) at acpi0 not configured
UAR2 (PNP0501) at acpi0 not configured
PCIE (PNP0C02) at acpi0 not configured
RMEM (PNP0C01) at acpi0 not configured
acpibut0 at acpi0 (PWRB, PNP0C0C-170): ACPI Power Button
attimer1: attached to pcppi1
ipmi0 at mainbus0
pci0 at mainbus0 bus 0: configuration mode 1
pci0: i/o space, memory space enabled, rd/line, rd/mult, wr/inv ok
pchb0 at pci0 dev 0 function 0: vendor 0x1002 product 0x5a12 (rev. 0x02)
vendor 0x1002 product 0x5a23 (system, subclass 0x06) at pci0 dev 0 function 2 
not configured
ppb0 at pci0 dev 4 function 0: vendor 0x1002 product 0x5a18 (rev. 0x00)
ppb0: PCI Express 2.0 <Root Port of PCI-E Root Complex>
pci1 at ppb0 bus 2
pci1: i/o space, memory space enabled, rd/line, wr/inv ok
wm0 at pci1 dev 0 function 0: 82576 1000BaseT Ethernet, rev. 1
wm0: interrupting at ioapic0 pin 16
wm0: PCI-Express bus
wm0: 65536 word (16 address bits) SPI EEPROM
wm0: Ethernet address 00:30:48:f5:b5:ee
igphy0 at wm0 phy 1: i82566 10/100/1000 media interface, rev. 1
igphy0: 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, 1000baseT, 
1000baseT-FDX, auto
wm1 at pci1 dev 0 function 1: 82576 1000BaseT Ethernet, rev. 1
wm1: interrupting at ioapic0 pin 17
wm1: PCI-Express bus
wm1: 65536 word (16 address bits) SPI EEPROM
wm1: Ethernet address 00:30:48:f5:b5:ef
igphy1 at wm1 phy 1: i82566 10/100/1000 media interface, rev. 1
igphy1: 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, 1000baseT, 
1000baseT-FDX, auto
ahcisata0 at pci0 dev 17 function 0: vendor 0x1002 product 0x4391
ahcisata0: interrupting at ioapic0 pin 22
ahcisata0: 64-bit DMA
ahcisata0: AHCI revision 1.1, 6 ports, 32 command slots, features 0xf722e080
atabus0 at ahcisata0 channel 0
atabus1 at ahcisata0 channel 1
atabus2 at ahcisata0 channel 2
atabus3 at ahcisata0 channel 3
atabus4 at ahcisata0 channel 4
atabus5 at ahcisata0 channel 5
ohci0 at pci0 dev 18 function 0: vendor 0x1002 product 0x4397 (rev. 0x00)
ohci0: interrupting at ioapic0 pin 16
ohci0: OHCI version 1.0, legacy support
usb0 at ohci0: USB revision 1.0
ohci1 at pci0 dev 18 function 1: vendor 0x1002 product 0x4398 (rev. 0x00)
ohci1: interrupting at ioapic0 pin 16
ohci1: OHCI version 1.0, legacy support
usb1 at ohci1: USB revision 1.0
piixpm0 at pci0 dev 20 function 0
piixpm0: vendor 0x1002 product 0x4385 (rev. 0x3d)
piixpm0: interrupting at SMI, polling
iic0 at piixpm0: I2C bus
pcib0 at pci0 dev 20 function 3: vendor 0x1002 product 0x439d (rev. 0x00)
ppb1 at pci0 dev 20 function 4: vendor 0x1002 product 0x4384 (rev. 0x00)
pci2 at ppb1 bus 1
pci2: i/o space, memory space enabled
vga0 at pci2 dev 4 function 0: vendor 0x102b product 0x0532 (rev. 0x0a)
wsdisplay0 at vga0 kbdmux 1
wsmux1: connecting to wsdisplay0
drm at vga0 not configured
pchb1 at pci0 dev 24 function 0: vendor 0x1022 product 0x1200 (rev. 0x00)
pchb2 at pci0 dev 24 function 1: vendor 0x1022 product 0x1201 (rev. 0x00)
pchb3 at pci0 dev 24 function 2: vendor 0x1022 product 0x1202 (rev. 0x00)
amdtemp0 at pci0 dev 24 function 3: AMD CPU Temperature Sensors (Family10h / 
Family11h)
pchb4 at pci0 dev 24 function 4: vendor 0x1022 product 0x1204 (rev. 0x00)
pchb5 at pci0 dev 25 function 0: vendor 0x1022 product 0x1200 (rev. 0x00)
pchb6 at pci0 dev 25 function 1: vendor 0x1022 product 0x1201 (rev. 0x00)
pchb7 at pci0 dev 25 function 2: vendor 0x1022 product 0x1202 (rev. 0x00)
amdtemp1 at pci0 dev 25 function 3: AMD CPU Temperature Sensors (Family10h / 
Family11h)
pchb8 at pci0 dev 25 function 4: vendor 0x1022 product 0x1204 (rev. 0x00)
pchb9 at pci0 dev 26 function 0: vendor 0x1022 product 0x1200 (rev. 0x00)
pchb10 at pci0 dev 26 function 1: vendor 0x1022 product 0x1201 (rev. 0x00)
pchb11 at pci0 dev 26 function 2: vendor 0x1022 product 0x1202 (rev. 0x00)
amdtemp2 at pci0 dev 26 function 3: AMD CPU Temperature Sensors (Family10h / 
Family11h)
pchb12 at pci0 dev 26 function 4: vendor 0x1022 product 0x1204 (rev. 0x00)
pchb13 at pci0 dev 27 function 0: vendor 0x1022 product 0x1200 (rev. 0x00)
pchb14 at pci0 dev 27 function 1: vendor 0x1022 product 0x1201 (rev. 0x00)
pchb15 at pci0 dev 27 function 2: vendor 0x1022 product 0x1202 (rev. 0x00)
amdtemp3 at pci0 dev 27 function 3: AMD CPU Temperature Sensors (Family10h / 
Family11h)
pchb16 at pci0 dev 27 function 4: vendor 0x1022 product 0x1204 (rev. 0x00)
isa0 at pcib0
com0 at isa0 port 0x3f8-0x3ff irq 4: ns16550a, working fifo
com0: console
com1 at isa0 port 0x2f8-0x2ff irq 3: ns16550a, working fifo
pckbc0 at isa0 port 0x60-0x64
timecounter: Timecounter "clockinterrupt" frequency 100 Hz quality 0
timecounter: Timecounter "TSC" frequency 1900299050 Hz quality 3000
uhub0 at usb0: vendor 0x1002 OHCI root hub, class 9/0, rev 1.00/1.00, addr 1
uhub0: 3 ports with 3 removable, self powered
uhub1 at usb1: vendor 0x1002 OHCI root hub, class 9/0, rev 1.00/1.00, addr 1
uhub1: 3 ports with 3 removable, self powered
ahcisata0 port 0: device present, speed: 3.0Gb/s
wd0 at atabus0 drive 0
wd0: <OCZ-VERTEX2>
wd0: drive supports 16-sector PIO transfers, LBA48 addressing
wd0: 47703 MB, 96921 cyl, 16 head, 63 sec, 512 bytes/sect x 97696368 sectors
wd0: drive supports PIO mode 4, DMA mode 2, Ultra-DMA mode 6 (Ultra/133)
wd0(ahcisata0:0:0): using PIO mode 4, DMA mode 2, Ultra-DMA mode 6 (Ultra/133) 
(using DMA)
Kernelized RAIDframe activated
pad0: outputs: 44100Hz, 16-bit, stereo
audio0 at pad0: half duplex, playback, capture
boot device: wd0
root on wd0a dumps on wd0b
root file system type: ffs
WARNING: clock gained 13 days
wsdisplay0: screen 1 added (80x25, vt100 emulation)
wsdisplay0: screen 2 added (80x25, vt100 emulation)
wsdisplay0: screen 3 added (80x25, vt100 emulation)
wsdisplay0: screen 4 added (80x25, vt100 emulation)
ipmi0: version 2.0 interface KCS iobase 0xca2/2 spacing 1
ipmi0: warning under limit on 'System Temp1'
ipmi0: warning under limit on 'NB Temp'
ipmi0: warning under limit on 'VRD2 Temp'
ipmi0: warning under limit on 'VRD1 Temp'
ipmi0: warning under limit on 'Air Temp'
ipmi0: warning under limit on 'System Temp'
lockstat: 19946717 buffer allocations failed
lockstat: 1311 buffer allocations failed
/dev/wd0a on / type ffs (noatime, nodevmtime, local, root file system, fsid: 
0x0/0x78b, reads: sync 9910917 async 0, writes: sync 2241658 async 13843)
/dev/wd0e on /home type ffs (noatime, nodevmtime, local, fsid: 0x4/0x78b, 
reads: sync 19 async 0, writes: sync 2 async 0)
tmpfs on /home/autobuild/folsom-build type tmpfs (local, fsid: 0xab01/0x69ab, 
reads: sync 0 async 0, writes: sync 0 async 0)
tmpfs on /tmp type tmpfs (local, fsid: 0xab02/0x69ab, reads: sync 0 async 0, 
writes: sync 0 async 0)
kernfs on /kern type kernfs (local, fsid: 0x8b02/0x1d28b, reads: sync 0 async 
0, writes: sync 0 async 0)
ptyfs on /dev/pts type ptyfs (local, fsid: 0x7b02/0x6b7b, reads: sync 0 async 
0, writes: sync 0 async 0)
procfs on /proc type procfs (local, fsid: 0x1b02/0x1ae1b, reads: sync 0 async 
0, writes: sync 0 async 0)
procfs on /usr/pkg/emul/linux/proc type procfs (read-only, local, fsid: 
0x1b03/0x1ae1b, reads: sync 0 async 0, writes: sync 0 async 0)
tmpfs on /usr/pkg/emul/linux/dev/shm type tmpfs (local, fsid: 0xab03/0x69ab, 
reads: sync 0 async 0, writes: sync 0 async 0)

Attachment: out.24.gz
Description: application/gunzip

Attachment: out.8.gz
Description: application/gunzip

Attachment: l.24.gz
Description: application/gunzip

Attachment: l.8.gz
Description: application/gunzip



Home | Main Index | Thread Index | Old Index