Bug 230985

Summary: pmcstat triggers assertion "pmcval outside of expected range"
Product: Base System Reporter: Mark Johnston <markj>
Component: kernAssignee: freebsd-bugs (Nobody) <bugs>
Status: Closed FIXED    
Severity: Affects Some People CC: cem, emaste, mmacy
Priority: --- Keywords: regression
Version: CURRENT   
Hardware: amd64   
OS: Any   
Bug Depends on:    
Bug Blocks: 228911    

Description Mark Johnston freebsd_committer freebsd_triage 2018-08-28 19:20:40 UTC
Using the new event names (from "pmc list-events") with pmcstat immediately triggers a panic:

# pmcstat -P inst_retired.any -- find -x / -name foo
...
panic: [pmc,1469] pmcval outside of expected range cpu=0 ri=21 pmcval=0 pm_reloadcount=0
cpuid = 0
time = 1535482305
Uptime: 55s
Dumping 1025 out of 16233 MB:..2%..11%..21%..32%..41%..52%..61%..71%..82%..91%

__curthread () at ./machine/pcpu.h:230
230             __asm("movq %%gs:%1,%0" : "=r" (td)
(kgdb) #0  __curthread () at ./machine/pcpu.h:230
#1  doadump (textdump=1)
    at /usr/home/markj/src/freebsd-dev/sys/kern/kern_shutdown.c:366
#2  0xffffffff8070e680 in kern_reboot (howto=260)
    at /usr/home/markj/src/freebsd-dev/sys/kern/kern_shutdown.c:446
#3  0xffffffff8070ead3 in vpanic (fmt=<optimized out>, ap=0xfffffe008e0bd470)
    at /usr/home/markj/src/freebsd-dev/sys/kern/kern_shutdown.c:872
#4  0xffffffff8070e833 in panic (fmt=<unavailable>)
    at /usr/home/markj/src/freebsd-dev/sys/kern/kern_shutdown.c:799
#5  0xffffffff81c259f5 in pmc_process_csw_in (td=<optimized out>)
    at /usr/home/markj/src/freebsd-dev/sys/dev/hwpmc/hwpmc_mod.c:1466
#6  pmc_hook_handler (td=<optimized out>, function=<optimized out>,
    arg=<optimized out>)
    at /usr/home/markj/src/freebsd-dev/sys/dev/hwpmc/hwpmc_mod.c:2207
#7  0xffffffff8073bbb4 in sched_switch (td=0xfffff80015608580,
    newtd=<optimized out>, flags=<optimized out>)
    at /usr/home/markj/src/freebsd-dev/sys/kern/sched_ule.c:2120
#8  0xffffffff8071a11f in mi_switch (flags=260, newtd=0x0)
    at /usr/home/markj/src/freebsd-dev/sys/kern/kern_synch.c:439
#9  0xffffffff80764b1d in sleepq_switch (wchan=0xfffff80181aa6c0c, pri=104)
    at /usr/home/markj/src/freebsd-dev/sys/kern/subr_sleepqueue.c:613
#10 0xffffffff807650f7 in sleepq_catch_signals (wchan=0xfffff80181aa6c0c,
    pri=104) at /usr/home/markj/src/freebsd-dev/sys/kern/subr_sleepqueue.c:515
#11 0xffffffff80764c6f in sleepq_wait_sig (wchan=<unavailable>,
    pri=<unavailable>)
    at /usr/home/markj/src/freebsd-dev/sys/kern/subr_sleepqueue.c:706
#12 0xffffffff807199de in _sleep (ident=0xfffff80181aa6c0c,
    lock=<optimized out>, priority=360, wmesg=0xffffffff80b3e05a "sbwait",
    sbt=<optimized out>, pr=0, flags=0)
    at /usr/home/markj/src/freebsd-dev/sys/kern/kern_synch.c:215
#13 0xffffffff807a3228 in sbwait (sb=0xfffff80181aa6b90)
    at /usr/home/markj/src/freebsd-dev/sys/kern/uipc_sockbuf.c:267
#14 0xffffffff807a8792 in soreceive_generic (so=0xfffff80181aa6a38, psa=0x0,
    uio=0xfffffe008e0bd940, mp0=0x0, controlp=0x0, flagsp=0x0)
    at /usr/home/markj/src/freebsd-dev/sys/kern/uipc_socket.c:1809
#15 0xffffffff807aa5d9 in soreceive (so=<unavailable>, psa=<unavailable>,
    uio=<unavailable>, mp0=<unavailable>, controlp=<unavailable>,
    flagsp=<unavailable>)
    at /usr/home/markj/src/freebsd-dev/sys/kern/uipc_socket.c:2559
#16 0xffffffff8077a4f5 in fo_read (fp=<optimized out>, uio=<optimized out>,
    active_cred=<unavailable>, flags=<optimized out>, td=<optimized out>)
    at /usr/home/markj/src/freebsd-dev/sys/sys/file.h:306
#17 dofileread (td=<optimized out>, fd=7, fp=<optimized out>,
    auio=0xfffffe008e0bd940, offset=7, flags=<optimized out>)
    at /usr/home/markj/src/freebsd-dev/sys/kern/sys_generic.c:368
#18 0xffffffff8077a11a in kern_readv (td=0xfffff80015608580, fd=7,
    auio=0xfffffe008e0bd940)
    at /usr/home/markj/src/freebsd-dev/sys/kern/sys_generic.c:289
#19 0xffffffff8077a0c6 in sys_read (td=<unavailable>, uap=<optimized out>)
    at /usr/home/markj/src/freebsd-dev/sys/kern/sys_generic.c:205
#20 0xffffffff80aa91bc in syscallenter (td=0xfffff80015608580)
    at /usr/home/markj/src/freebsd-dev/sys/amd64/amd64/../../kern/subr_syscall.c:135
#21 amd64_syscall (td=0xfffff80015608580, traced=0)
    at /usr/home/markj/src/freebsd-dev/sys/amd64/amd64/trap.c:1043
Comment 1 commit-hook freebsd_committer freebsd_triage 2018-09-14 01:30:26 UTC
A commit references this bug:

Author: mmacy
Date: Fri Sep 14 01:30:06 UTC 2018
New revision: 338677
URL: https://svnweb.freebsd.org/changeset/base/338677

Log:
  hwpmc: set default rate if event description lacks one / filter rate against misuse

  Not all event descriptions have a sample rate (such as inst_retired.any)
  this will restore the legacy behavior of using 65536 in that case. It also
  prevents accidental API misuse that could lead to panic.

  PR:	230985
  Reported by:	markj
  Reviewed by:	markj
  Approved by:	re (gjb)
  Sponsored by:	Limelight Networks
  Differential Revision:	https://reviews.freebsd.org/D16958

Changes:
  head/lib/libpmc/libpmc_pmu_util.c
  head/sys/dev/hwpmc/hwpmc_mod.c