svn commit: r333509 - in head/sys: dev/hwpmc kern sys
Matthew Macy
mmacy at freebsd.org
Sat May 12 20:22:21 UTC 2018
Fixed in 333575.
On Sat, May 12, 2018 at 00:35 Peter Holm <peter at holm.cc> wrote:
> On Sat, May 12, 2018 at 01:26:34AM +0000, Matt Macy wrote:
> > Author: mmacy
> > Date: Sat May 12 01:26:34 2018
> > New Revision: 333509
> > URL: https://svnweb.freebsd.org/changeset/base/333509
> >
> > Log:
> > hwpmc(9): Make pmclog buffer pcpu and update constants
> >
> > On non-trivial SMP systems the contention on the pmc_owner mutex leads
> > to a substantial number of samples captured being from the pmc process
> > itself. This change a) makes buffers larger to avoid contention on the
> > global list b) makes the working sample buffer per cpu.
> >
> > Run pmcstat in the background (default event rate of 64k):
> > pmcstat -S UNHALTED_CORE_CYCLES -O /dev/null sleep 600 &
> >
> > Before:
> > make -j96 buildkernel -s >&/dev/null 3336.68s user 24684.10s system
> 7442% cpu 6:16.50 total
> >
> > After:
> > make -j96 buildkernel -s >&/dev/null 2697.82s user 1347.35s system
> 6058% cpu 1:06.77 total
> >
> > For more realistic overhead measurement set the sample rate for ~2khz
> > on a 2.1Ghz processor:
> > pmcstat -n 1050000 -S UNHALTED_CORE_CYCLES -O /dev/null sleep 6000 &
> >
> > Collecting 10 samples of `make -j96 buildkernel` from each:
> >
> > x before
> > + after
> >
> > real time:
> > N Min Max Median Avg
> Stddev
> > x 10 76.4 127.62 84.845 88.577
> 15.100031
> > + 10 59.71 60.79 60.135 60.179
> 0.29957192
> > Difference at 95.0% confidence
> > -28.398 +/- 10.0344
> > -32.0602% +/- 7.69825%
> > (Student's t, pooled s = 10.6794)
> >
> > system time:
> > N Min Max Median Avg
> Stddev
> > x 10 2277.96 6948.53 2949.47 3341.492
> 1385.2677
> > + 10 1038.7 1081.06 1070.555 1064.017
> 15.85404
> > Difference at 95.0% confidence
> > -2277.47 +/- 920.425
> > -68.1574% +/- 8.77623%
> > (Student's t, pooled s = 979.596)
> >
> > x no pmc
> > + pmc running
> > real time:
> >
> > HEAD:
> > N Min Max Median Avg
> Stddev
> > x 10 58.38 59.15 58.86 58.847
> 0.22504567
> > + 10 76.4 127.62 84.845 88.577
> 15.100031
> > Difference at 95.0% confidence
> > 29.73 +/- 10.0335
> > 50.5208% +/- 17.0525%
> > (Student's t, pooled s = 10.6785)
> >
> > patched:
> > N Min Max Median Avg
> Stddev
> > x 10 58.38 59.15 58.86 58.847
> 0.22504567
> > + 10 59.71 60.79 60.135 60.179
> 0.29957192
> > Difference at 95.0% confidence
> > 1.332 +/- 0.248939
> > 2.2635% +/- 0.426506%
> > (Student's t, pooled s = 0.264942)
> >
> > system time:
> >
> > HEAD:
> > N Min Max Median Avg
> Stddev
> > x 10 1010.15 1073.31 1025.465 1031.524
> 18.135705
> > + 10 2277.96 6948.53 2949.47 3341.492
> 1385.2677
> > Difference at 95.0% confidence
> > 2309.97 +/- 920.443
> > 223.937% +/- 89.3039%
> > (Student's t, pooled s = 979.616)
> >
> > patched:
> > N Min Max Median Avg
> Stddev
> > x 10 1010.15 1073.31 1025.465 1031.524
> 18.135705
> > + 10 1038.7 1081.06 1070.555 1064.017
> 15.85404
> > Difference at 95.0% confidence
> > 32.493 +/- 16.0042
> > 3.15% +/- 1.5794%
> > (Student's t, pooled s = 17.0331)
> >
> > Reviewed by: jeff@
> > Approved by: sbruno@
> > Differential Revision: https://reviews.freebsd.org/D15155
> >
> > Modified:
> > head/sys/dev/hwpmc/hwpmc_amd.c
> > head/sys/dev/hwpmc/hwpmc_core.c
> > head/sys/dev/hwpmc/hwpmc_e500.c
> > head/sys/dev/hwpmc/hwpmc_intel.c
> > head/sys/dev/hwpmc/hwpmc_logging.c
> > head/sys/dev/hwpmc/hwpmc_mod.c
> > head/sys/dev/hwpmc/hwpmc_mpc7xxx.c
> > head/sys/dev/hwpmc/hwpmc_piv.c
> > head/sys/dev/hwpmc/hwpmc_ppc970.c
> > head/sys/dev/hwpmc/hwpmc_ppro.c
> > head/sys/dev/hwpmc/hwpmc_soft.c
> > head/sys/kern/kern_pmc.c
> > head/sys/sys/pmc.h
> > head/sys/sys/pmckern.h
> >
> > Modified: head/sys/dev/hwpmc/hwpmc_amd.c
> >
> ==============================================================================
> > --- head/sys/dev/hwpmc/hwpmc_amd.c Fri May 11 22:16:23 2018
> (r333508)
>
> Got this during boot:
>
> ada1: Serial Number 15150F3BC143
> ada1: 600.000MB/s transfers (SATA 3.x, UDMA6, PIO 8192bytes)
> ada1: Command Queueing enabled
> ada1: 976762MB (2000409264 512 byte sectors)
>
>
> Fatal trap 12: page fault while in kernel mode
> cpuid = 103; apic id = 7b
> fault virtual address = 0x38
> fault code = supervisor write data, page not present
> instruction pointer = 0x20:0xffffffff826d0a3e
> stack pointer = 0x28:0xffffffff827c62c0
> frame pointer = 0x28:0xffffffff827c62f0
> code segment = base 0x0, limit 0xfffff, type 0x1b
> = DPL 0, pres 1, long 1, def32 0, gran 1
> processor eflags = interrupt enabled, resume, IOPL = 0
> current process = 0 (swapper)
> [ thread pid 0 tid 100000 ]
> Stopped at pmclog_initialize+0x15e: addl $0x1,ll+0x17(%rax)
> db> bt
> Tracing pid 0 tid 100000 td 0xffffffff81ff1160
> pmclog_initialize() at pmclog_initialize+0x15e/frame 0xffffffff827c62f0
> load() at load+0x1097/frame 0xffffffff827c6350
> kern_syscall_module_handler() at kern_syscall_module_handler+0x2a1/frame
> 0xffffffff827c63a0
> module_register_init() at module_register_init+0xc0/frame
> 0xffffffff827c63d0
> mi_startup() at mi_startup+0x118/frame 0xffffffff827c63f0
> btext() at btext+0x2c
> db> x/s version
> version: FreeBSD 12.0-CURRENT #2 r333519: Sat May 12 09:14:17 CEST
> 2018\012 pho at flix1a.netperf.freebsd.org:
> /usr/obj/usr/src/amd64.amd64/sys/PHO\012
> db> show registers
> cs 0x20
> ds 0x3b ll+0x1a
> es 0x3b ll+0x1a
> fs 0x13
> gs 0x28 ll+0x7
> ss 0x28 ll+0x7
> rax 0
> rcx 0xffffffffffffffff
> rdx 0xffffffff826e0a21 ucp_events+0x2d81
> rbx 0x34 ll+0x13
> rsp 0xffffffff827c62c0
> rbp 0xffffffff827c62f0
> rsi 0xffffffff81b16340 lock_class_mtx_spin
> rdi 0x34 ll+0x13
> r8 0x20000
> r9 0x32 ll+0x11
> r10 0xfffff8183fd1f380
> r11 0
> r12 0x67 ll+0x46
> r13 0x67 ll+0x46
> r14 0x1
> r15 0x68 ll+0x47
> rip 0xffffffff826d0a3e pmclog_initialize+0x15e
> rflags 0x10247 _binary_t5fw_cfg_uwire_txt_size+0xac98
> pmclog_initialize+0x15e: addl $0x1,ll+0x17(%rax)
> db>
>
> - Peter
>
More information about the svn-src-all
mailing list