kern/179827: [hwpmc] process-mode counters aren't correctly read on multi-core machines
hiren panchasara
hiren at FreeBSD.org
Sat Jun 22 09:40:02 UTC 2013
The following reply was made to PR kern/179827; it has been noted by GNATS.
From: hiren panchasara <hiren at FreeBSD.org>
To: bug-followup at FreeBSD.org, adrian at FreeBSD.org
Cc:
Subject: Re: kern/179827: [hwpmc] process-mode counters aren't correctly
read on multi-core machines
Date: Sat, 22 Jun 2013 02:35:55 -0700
This is what I am seeing on head:
-bash-4.2$ uname -a
FreeBSD head.box.some.com 10.0-CURRENT FreeBSD 10.0-CURRENT #0
r251604: Tue Jun 11 19:08:35 UTC 2013
hirenp at head.box.some.com:/home/hirenp/head/sys/amd64/compile/GENERIC
amd64
-bash-4.2$ sysctl hw.ncpu
hw.ncpu: 24
-bash-4.2$
-bash-4.2$ sysctl -a | grep hwpmc
kern.features.hwpmc_hooks: 1
kern.hwpmc.softevents: 16
kern.hwpmc.callchaindepth: 8
kern.hwpmc.debugflags: csw=swo,swi pmc=ops
kern.hwpmc.hashsize: 16
kern.hwpmc.nsamples: 512
kern.hwpmc.mtxpoolsize: 32
kern.hwpmc.logbuffersize: 4
kern.hwpmc.nbuffers: 64
-bash-4.2$
-bash-4.2$ cat count.c
#include <stdio.h>
#include <stdint.h>
#include <time.h>
int main() {
for (int i=0; i<60; i++) {
sleep(1);
}
return 0;
}
-bash-4.2$ pmcstat -p instructions -w 1 ./count
CSW:SWO:1: cpu=2 proc=0xfffffe0047ea6970 (2615, pmcstat) pp=0
PMC:OPS:1: start pmc=0xfffffe005d81e800 mode=3 ri=21
CSW:SWI:1: cpu=16 proc=0xfffffe0047afc970 (2616, pmcstat) pp=0xfffffe005dbd6c00
CSW:SWO:1: cpu=2 proc=0xfffffe0047ea6970 (2615, pmcstat) pp=0
CSW:SWI:1: cpu=16 ri=21 new=0
CSW:SWO:1: cpu=16 proc=0xfffffe0047afc970 (2616, pmcstat) pp=0xfffffe005dbd6c00
CSW:SWO:1: cpu=16 ri=21 tmp=6285116
CSW:SWI:1: cpu=20 proc=0xfffffe0047afc970 (2616, pmcstat) pp=0xfffffe005dbd6c00
CSW:SWI:1: cpu=20 ri=21 new=6285116
CSW:SWO:1: cpu=20 proc=0xfffffe0047afc970 (2616, pmcstat) pp=0xfffffe005dbd6c00
CSW:SWO:1: cpu=20 ri=21 tmp=6245302
CSW:SWI:1: cpu=1 proc=0xfffffe0047afc970 (2616, pmcstat) pp=0xfffffe005dbd6c00
CSW:SWI:1: cpu=1 ri=21 new=12530418
CSW:SWO:1: cpu=1 proc=0xfffffe0047afc970 (2616, count) pp=0xfffffe005dbd6c00
CSW:SWO:1: cpu=1 ri=21 tmp=11918927
# PMC:OPS:1: rw id=-16579051 flags=0x20
PMC:OPS:2: rw id=21 -> old 1751141
CSW:SWO:1: cpu=12 proc=0xfffffe0047ea6970 (2615, pmcstat) pp=0
CSWnstructions
244493:S45 WO:1: cpu=6 proc=0xfffffe0047ea6970 (2615, pmcstat) pp=0
CSW:SWI:1: cpu=1 proc=0xfffffe0047afc970 (2616, count) pp=0xfffffe005dbd6c00
CSW:SWI:1:
c# p/instructionpu=s
1 ri=21 new=24449345
PMC:OPS:1: rw id=-16579051 flags=0x20
CSW:SWO:1: cpu=1 proc=0xfffffe0047afc970 (2616, count) pp=0xfffffe005dbd6c00
PMC:OPS:2: rw id=21 -> old 1751141
C SW:0 SWO:1: cpu=1 ri=21 tmp=97027040
CSW:SWO:1: cpu=6 proc=0xfffffe0047ea6970 (2615, pmcstat) pp=0
PMC# p/instruction:Os
PS:1: rw id=-16579051 flags=0x20
CSW:SWI:1: cpu=16 proc=0xfffffe0047afc970 (2616, count) pp=0xfffffe005dbd6c00
PMC:OPS:2: rw id=21 -> old 73d9521
C 9702704SW:0 SWI:1: cpu=16 ri=21 new=121476385
CSW:SWO:1: cpu=6 proc=0xfffffe0047ea6970 (2615, pmcstat) pp=0
CSW:SWO:1: cpu=16 proc=0xfffffe0047afc970 (2616, count) pp=0xfffffe005dbd6c00
CSW:SWO:1: cpu=16 ri=21 tmp=121961432
PM# p/instructionC:Os
PS:1: rw id=-16579051 flags=0x20
PMC:OPS:2: rw id=21 -> old e8290f9
12196143CS2 W:SWO:1: cpu=6 proc=0xfffffe0047ea6970 (2615, pmcstat) pp=0
CSW:SWI:1: cpu=16 proc=0xfffffe0047afc970 (2616, count) pp=0xfffffe005dbd6c00
CSW:SWI:1: cpu=16 ri=21 new=243437817
CSW:SWO:1: cpu=16 proc=0xfffffe0047afc970 (2616, count) pp=0xfffffe005dbd6c00
CSW:SWO:1: cpu=16 ri=21 tmp=56320362
PM# p/instructionC:Os
PS:1: rw id=-16579051 flags=0x20
PMC:OPS:2: rw id=21 -> old 11ddf263
5632036CSW2 :SWO:1: cpu=6 proc=0xfffffe0047ea6970 (2615, pmcstat) pp=0
CSW:SWI:1: cpu=16 proc=0xfffffe0047afc970 (2616, count) pp=0xfffffe005dbd6c00
CSW:SWI:1: cpu=16 ri=21 new=299758179
CSW:SWO:1: cpu=16 proc=0xfffffe0047afc970 (2616, count) pp=0xfffffe005dbd6c00
CSW:SWO:1: cpu=16 ri=21 tmp=56408687
PM# p/instructionC:Os
PS:1: rw id=-16579051 flags=0x20
PMC:OPS:2: rw id=21 -> old 153aacd2
5640868CSW7 :SWO:1: cpu=6 proc=0xfffffe0047ea6970 (2615, pmcstat) pp=0
CSW:SWI:1: cpu=16 proc=0xfffffe0047afc970 (2616, count) pp=0xfffffe005dbd6c00
CSW:SWI:1: cpu=16 ri=21 new=356166866
CSW:SWO:1: cpu=16 proc=0xfffffe0047afc970 (2616, count) pp=0xfffffe005dbd6c00
CSW:SWO:1: cpu=16 ri=21 tmp=56364300
PM# p/instructionC:Os
PS:1: rw id=-16579051 flags=0x20
PMC:OPS:2: rw id=21 -> old 1896b9de
5636430CS0 W:SWO:1: cpu=6 proc=0xfffffe0047ea6970 (2615, pmcstat) pp=0
CSW:SWI:1: cpu=16 proc=0xfffffe0047afc970 (2616, count) pp=0xfffffe005dbd6c00
CSW:SWI:1: cpu=16 ri=21 new=412531166
CSW:SWO:1: cpu=16 proc=0xfffffe0047afc970 (2616, count) pp=0xfffffe005dbd6c00
CSW:SWO:1: cpu=16 ri=21 tmp=56239777
PM# p/instructionC:Os
PS:1: rw id=-16579051 flags=0x20
PMC:OPS:2: rw id=21 -> old 1bf0e07f
5623977CS7 W:SWO:1: cpu=6 proc=0xfffffe0047ea6970 (2615, pmcstat) pp=0
CSW:SWI:1: cpu=16 proc=0xfffffe0047afc970 (2616, count) pp=0xfffffe005dbd6c00
CSW:SWI:1: cpu=16 ri=21 new=468770943
CSW:SWO:1: cpu=16 proc=0xfffffe0047afc970 (2616, count) pp=0xfffffe005dbd6c00
CSW:SWO:1: cpu=16 ri=21
tm# p/instructionp=5s
6380282
PMC:OPS:1: rw id=-16579051 flags=0x20
PMC:OPS:2: rw id=21 -> old 1f4d2bf9
5638028CSW2 :SWO:1: cpu=6 proc=0xfffffe0047ea6970 (2615, pmcstat) pp=0
CSW:SWI:1: cpu=16 proc=0xfffffe0047afc970 (2616, count) pp=0xfffffe005dbd6c00
CSW:SWI:1: cpu=16 ri=21
ne# p/instructionw=s
525151225
PMC:OPS:1: rw id=-16579051 flags=0x20
CSW:SWO:1: cpu=16 proc=0xfffffe0047afc970 (2616, count) pp=0xfffffe005dbd6c00
PMC:OPS:2: rw id=21 -> old 1f4d2bf9
C SW:0 SWO:1: cpu=16 ri=21 tmp=96934506
CSW:SWO:1: cpu=6 proc=0xfffffe0047ea6970 (2615, pmcstat) pp=0
CSW:SWI:1: cpu=3
pr# p/instructionoc=s
0xfffffe0047afc970 (2616, count) pp=0xfffffe005dbd6c00
PMC:OPS:1: rw id=-16579051 flags=0x20
CSW:SWI:1: cpu=3 ri=21 new=622085731
PMC:OPS:2: rw id=21 -> old 25144663
C 9693450SW6 :SWO:1: cpu=3 proc=0xfffffe0047afc970 (2616,
count) pp=0xfffffe005dbd6c00
CSW:SWO:1: cpu=12 proc=0xfffffe0047ea6970 (2615, pmcstat) pp=0
CSW:SWO:1: cpu=3 ri=21 tmp=105656199
PM# p/instructionC:Os
PS:1: rw id=-16579051 flags=0x20
PMC:OPS:2: rw id=21 -> old 2b6075ea
10565619CSW9 :SWO:1: cpu=12 proc=0xfffffe0047ea6970 (2615, pmcstat) pp=0
CSW:SWI:1: cpu=3 proc=0xfffffe0047afc970 (2616, count) pp=0xfffffe005dbd6c00
CSW:SWI:1: cpu=3 ri=21 new=727741930
CSW:SWO:1: cpu=3 proc=0xfffffe0047afc970 (2616, count) pp=0xfffffe005dbd6c00
CSW:SWO:1: cpu=3 ri=21 tmp=56325090
PMC# p/instruction:Os
PS:1: rw id=-16579051 flags=0x20
PMC:OPS:2: rw id=21 -> old 2ebbe9cc
5632509CSW0 :SWO:1: cpu=12 proc=0xfffffe0047ea6970 (2615, pmcstat) pp=0
CSW:SWI:1: cpu=3 proc=0xfffffe0047afc970 (2616, count) pp=0xfffffe005dbd6c00
CSW:SWI:1: cpu=3 ri=21 new=784067020
CSW:SWO:1: cpu=3 proc=0xfffffe0047afc970 (2616, count) pp=0xfffffe005dbd6c00
CSW:SWO:1: cpu=3 ri=21 tmp=56354857
PMC# p/instruction:Os
PS:1: rw id=-16579051 flags=0x20
PMC:OPS:2: rw id=21 -> old 3217d1f5
5635485CSW7 :SWO:1: cpu=12 proc=0xfffffe0047ea6970 (2615, pmcstat) pp=0
CSW:SWI:1: cpu=3 proc=0xfffffe0047afc970 (2616, count) pp=0xfffffe005dbd6c00
CSW:SWI:1: cpu=3 ri=21 new=840421877
CSW:SWO:1: cpu=3 proc=0xfffffe0047afc970 (2616, count) pp=0xfffffe005dbd6c00
CSW:SWO:1: cpu=3 ri=21 tmp=56379009
PMC# p/instruction:OPs
S:1: rw id=-16579051 flags=0x20
PMC:OPS:2: rw id=21 -> old 35741876
5637900CSW9 :SWO:1: cpu=12 proc=0xfffffe0047ea6970 (2615, pmcstat) pp=0
CSW:SWI:1: cpu=3 proc=0xfffffe0047afc970 (2616, count) pp=0xfffffe005dbd6c00
CSW:SWI:1: cpu=3 ri=21 new=896800886
CSW:SWO:1: cpu=3 proc=0xfffffe0047afc970 (2616, count) pp=0xfffffe005dbd6c00
CSW:SWO:1: cpu=3 ri=21 tmp=56376678
PMC# p/instruction:Os
PS:1: rw id=-16579051 flags=0x20
PMC:OPS:2: rw id=21 -> old 38d055dc
5637667CSW8 :SWO:1: cpu=12 proc=0xfffffe0047ea6970 (2615, pmcstat) pp=0
CSW:SWI:1: cpu=3 proc=0xfffffe0047afc970 (2616, count) pp=0xfffffe005dbd6c00
CSW:SWI:1: cpu=3 ri=21 new=953177564
CSW:SWO:1: cpu=3 proc=0xfffffe0047afc970 (2616, count) pp=0xfffffe005dbd6c00
CSW:SWO:1: cpu=3 ri=21 tmp=56363010
PM# p/instructionC:Os
PS:1: rw id=-16579051 flags=0x20
PMC:OPS:2: rw id=21 -> old 3c2c5dde
5636301CS0 W:SWO:1: cpu=6 proc=0xfffffe0047ea6970 (2615, pmcstat) pp=0
CSW:SWI:1: cpu=3 proc=0xfffffe0047afc970 (2616, count) pp=0xfffffe005dbd6c00
C
SW# p/instruction:SWs
I:1: cpu=3 ri=21 new=1009540574
PMC:OPS:1: rw id=-16579051 flags=0x20
CSW:SWO:1: cpu=3 proc=0xfffffe0047afc970 (2616, count) pp=0xfffffe005dbd6c00
CSW:SWO:1: cpu=6 proc=0xfffffe0047ea6970 (2615, pmcstat) pp=0
CSW:SWO:1: cpu=3 ri=21 tmp=96981520
CSW:SWO:1: cpu=0 proc=0xfffffe0047ea6970 (2615, pmcstat) pp=0
PMC:OPS:2: rw id=21 -> old 3c2c5dde
CSW0 :SWO:1: cpu=0 proc=0xfffffe0047ea6970 (2615, pmcstat) pp=0
PM# p/instructionC:Os
PS:1: rw id=-16579051 flags=0x20
CSW:SWI:1: cpu=14 proc=0xfffffe0047afc970 (2616, count) pp=0xfffffe005dbd6c00
CSW:SWO:1: cpu=0 proc=0xfffffe0047ea6970 (2615, pmcstat) pp=0
CSW:SWI:1: cpu=14 ri=21 new=1106522094
PMC:OPS:2: rw id=21 -> old 41f42fee
C 9698152SW0 :SWO:1: cpu=14 proc=0xfffffe0047afc970 (2616,
count) pp=0xfffffe005dbd6c00
CSW:SWO:1: cpu=17 proc=0xfffffe0047ea6970 (2615, pmcstat) pp=0
CSW:SWO:1: cpu=14 ri=21 tmp=106788274
P# p/instructionMC:s
OPS:1: rw id=-16579051 flags=0x20
PMC:OPS:2: rw id=21 -> old 4851a5a0
10678827CS4 W:SWO:1: cpu=3 proc=0xfffffe0047ea6970 (2615, pmcstat) pp=0
CSW:SWI:1: cpu=10 proc=0xfffffe0047afc970 (2616, count) pp=0xfffffe005dbd6c00
CSW:SWI:1: cpu=10 ri=21 new=1213310368
CSW:SWO:1: cpu=10 proc=0xfffffe0047afc970 (2616, count) pp=0xfffffe005dbd6c00
CSW:SWO:1: cpu=10 ri=21 tmp=57088659
P# p/instructionMC:s
OPS:1: rw id=-16579051 flags=0x20
PMC:OPS:2: rw id=21 -> old 4bb8c033
5708865CSW9 :SWO:1: cpu=3 proc=0xfffffe0047ea6970 (2615, pmcstat) pp=0
CSW:SWI:1: cpu=10 proc=0xfffffe0047afc970 (2616, count) pp=0xfffffe005dbd6c00
CSW:SWI:1: cpu=10 ri=21 new=1270399027
CSW:SWO:1: cpu=10 proc=0xfffffe0047afc970 (2616, count) pp=0xfffffe005dbd6c00
CSW:SWO:1: cpu=10 ri=21 tmp=57123975
P# p/instructionMCs
:OPS:1: rw id=-16579051 flags=0x20
PMC:OPS:2: rw id=21 -> old 4f2064ba
5712397CSW5 :SWO:1: cpu=3 proc=0xfffffe0047ea6970 (2615, pmcstat) pp=0
CSW:SWI:1: cpu=10 proc=0xfffffe0047afc970 (2616, count) pp=0xfffffe005dbd6c00
CSW:SWI:1: cpu=10 ri=21 new=1327523002
CSW:SWO:1: cpu=10 proc=0xfffffe0047afc970 (2616, count) pp=0xfffffe005dbd6c00
CSW:SWO:1: cpu=10 ri=21 tmp=57119065
P# p/instructionMCs
:OPS:1: rw id=-16579051 flags=0x20
PMC:OPS:2: rw id=21 -> old 5287f613
5711906CSW5 :SWO:1: cpu=3 proc=0xfffffe0047ea6970 (2615, pmcstat) pp=0
CSW:SWI:1: cpu=10 proc=0xfffffe0047afc970 (2616, count) pp=0xfffffe005dbd6c00
CSW:SWI:1: cpu=10 ri=21 new=1384642067
CSW:SWO:1: cpu=10 proc=0xfffffe0047afc970 (2616, count) pp=0xfffffe005dbd6c00
CSW:SWO:1: cpu=10 ri=21 tmp=57119883
<truncated> as it was too long.
More information about the freebsd-bugs
mailing list