Date: Sat, 12 May 2018 13:22:09 -0700 From: Matthew Macy <mmacy@freebsd.org> To: Peter Holm <peter@holm.cc> Cc: src-committers@freebsd.org, svn-src-all@freebsd.org, svn-src-head@freebsd.org Subject: Re: svn commit: r333509 - in head/sys: dev/hwpmc kern sys Message-ID: <CAPrugNquWXURs61yiGNZQjsuucHz2o3gatS=D%2B0E2FqASKfjyQ@mail.gmail.com> In-Reply-To: <20180512073516.GA68235@x2.osted.lan> References: <201805120126.w4C1QYMu097965@repo.freebsd.org> <20180512073516.GA68235@x2.osted.lan>
next in thread | previous in thread | raw e-mail | index | archive | help
Fixed in 333575. On Sat, May 12, 2018 at 00:35 Peter Holm <peter@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@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 >
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?CAPrugNquWXURs61yiGNZQjsuucHz2o3gatS=D%2B0E2FqASKfjyQ>