Improper configuration of events using cmask/edge

There appears to be some cases where ocount/operf are not setting up
the event configuration incorrectly.  On Ivy Bridge machine have the following event:

event:0xd counters:cpuid um:int_misc minimum:2000000 name:int_misc : Instruction decoder events

And unit masks:

name:int_misc type:exclusive default:recovery_cycles
	0x3 extra:cmask=1 recovery_cycles Number of cycles waiting for the checkpoints in Resource Allocation Table (RAT) to be recovered after Nuke due to all other cases except JEClear (e.g. whenever a ucode assist is needed like SSE exception, memory disambiguation, etc...)
	0x3 extra:cmask=1,edge recovery_stalls_count Number of occurences waiting for the checkpoints in Resource Allocation Table (RAT) to be recovered after Nuke due to all other cases except JEClear (e.g. whenever a ucode assist is needed like SSE exception, memory disambiguation, etc...)

ophelp provides the following for the int_misc event:

int_misc: (counter: all)
	Instruction decoder events (min count: 2000000)
	Unit masks (default recovery_cycles)
	----------
	0x03: (name=recovery_cycles) Number of cycles waiting for the checkpoints in Resource 
              Allocation Table (RAT) to be recovered after Nuke due to all other cases except 
              JEClear (e.g. whenever a ucode assist is needed like SSE exception, memory 
              disambiguation, etc...)
	0x03: (name=recovery_stalls_count) Number of occurences waiting for the checkpoints in 
              Resource Allocation Table (RAT) to be recovered after Nuke due to all other cases 
              except JEClear (e.g. whenever a ucode assist is needed like SSE exception, memory 
              disambiguation, etc...)


Based on the events and unit_mask info running both of these events
should translate to following perf stat command and that works:

$ perf stat -e cpu/event=0xd,umask=0x3,cmask=1/ -e cpu/event=0xd,umask=0x3,cmask=1,edge=1/ ls
 Performance counter stats for 'ls':

            72,477      cpu/event=0xd,umask=0x3,cmask=1/                                   
            15,430      cpu/event=0xd,umask=0x3,cmask=1,edge=1/                                   

       0.002052602 seconds time elapsed


However, the ocount is returning 0 for the counts of both events:

$  ocount  -e int_misc:recovery_cycles -e int_misc:recovery_stalls_count ls

Events were actively counted for 1317554 nanoseconds.
Event counts (actual) for /usr/bin/ls:
	Event                                 Count                    % time counted
	int_misc:recovery_cycles              0                        100.00
	int_misc:recovery_stalls_count        0                        100.00



According to the " Intel® 64 and IA-32 Architectures Software
Developer’s Manual Volume 3 (3A, 3B & 3C): System Programming Guide"
have the following bit fields

bits	      int_misc:recovery_cycles  int_isc:recovery_stalls_count
31-24 cmask   0x01			0x01
23    invert  0				0
22    enable
20    int
19    pin
18    edge    0				1
17    os      0				0
16    usr     0				0
15-8  umask   0x03			0x03
7-0   event   0x0d			0x0d
expect events 0x0100030d		0x0104030d


Using gdb on perf and running the "perf stat" command above setting
breakpoint on perf_evsel__open_per_thread see that events numbers match up:

(gdb) print/x evsel->attr.config
$4 = 0x100030d
,,,
(gdb) print/x evsel->attr.config
$5 = 0x104030d


The verbose output shows the events set incorrectly (zero unit-mask and enable bit being set):

$  ocount --verbose -e int_misc:recovery_cycles -e int_misc:recovery_stalls_count ls
Final event code is 140000d
Final event code is 144000d
Number of events passed is 2
Exec args are: ls 
telling child to start app
parent says start app /usr/bin/ls
calling perf_event_open for pid 240d
perf_event_open returning fd 9
perf_event_open returning fd a
perf counter setup complete
app 240d is running
going into waitpid on monitored app 240d
app process ended normally.
Reading counter data for event int_misc
Reading counter data for event int_misc

Events were actively counted for 1070382 nanoseconds.
Event counts (actual) for /usr/bin/ls:
	Event                                 Count                    % time counted
	int_misc:recovery_cycles              0                        100.00
	int_misc:recovery_stalls_count        0                        100.00


Digging through the code find that ocount gets the information from ophelp.
It looks like ophelp is returning the wrong value for the --extra-mask option:

$ /usr/local/bin/ophelp --extra-mask int_misc:0:recovery_cycles
20971520
$ /usr/local/bin/ophelp --extra-mask int_misc:0:recovery_stalls_count
21233664

(gdb) print/x 20971520
$1 = 0x1400000
(gdb) print/x 21233664
$2 = 0x1440000


Andi, any ideas of where things are going wrong in ophelp?

-Will

------------------------------------------------------------------------------
Dive into the World of Parallel Programming The Go Parallel Website, sponsored
by Intel and developed in partnership with Slashdot Media, is your hub for all
things parallel software development, from weekly thought leadership blogs to
news, videos, case studies, tutorials and more. Take a look and join the 
conversation now. http://goparallel.sourceforge.net/
_______________________________________________
oprofile-list mailing list
[email protected]
https://lists.sourceforge.net/lists/listinfo/oprofile-list