Re: [PATCH 1/1] events/core: fix error run/enable ratio display

[Mark Rutland]

Hi Peter, Levi,

On Wed, Dec 18, 2024 at 11:42:55AM +0100, Peter Zijlstra wrote:
> 
> git log --oneline kernel/events/core.c 
> 
> Compare result with your subject.
> 
> On Wed, Dec 18, 2024 at 08:46:56AM +0000, Yeoreum Yun wrote:
> > when runs below command (with core pmu) sometime perf prints error
> > ratio for each perf.
> > 
> > sudo ./perf stat -vvv -e armv8_pmuv3_0/event=0x08/ -e armv8_pmuv3_1/event=0x08/ -- stress-ng --pthread=2 -t 2s
> > ...
> > armv8_pmuv3_0/event=0x08/: -1: 1081702126 2289429840 2174835740
> > armv8_pmuv3_1/event=0x08/: -1: 794080238 1950025700 847648440
> > armv8_pmuv3_0/event=0x08/: 1138698008 2289429840 2174835740
> > armv8_pmuv3_1/event=0x08/: 1826791390 1950025700 847648440
> > 
> >  Performance counter stats for 'stress-ng --pthread=2 -t 2s':
> > 
> >      1,138,698,008      armv8_pmuv3_0/event=0x08/                                               (94.99%)
> >      1,826,791,390      armv8_pmuv3_1/event=0x08/                                               (43.47%)
> 
> At this point I've no idea what the error is. You start by saying there
> is an error, but then give no clue.

I *think* what this was trying to say is along the lines of:

  The perf core code fails to account for some time that an event is
  inactive. This can be seen by opening two mutually-exclusive events,
  whose active ratios should add to at most 100%, e.g.

  | sudo ./perf stat -vvv -e armv8_pmuv3_0/event=0x08/ -e armv8_pmuv3_1/event=0x08/ -- stress-ng --pthread=2 -t 2s
  |   ...
  |   armv8_pmuv3_0/event=0x08/: -1: 1081702126 2289429840 2174835740
  |   armv8_pmuv3_1/event=0x08/: -1: 794080238 1950025700 847648440
  |   armv8_pmuv3_0/event=0x08/: 1138698008 2289429840 2174835740
  |   armv8_pmuv3_1/event=0x08/: 1826791390 1950025700 847648440
  |   
  |    Performance counter stats for 'stress-ng --pthread=2 -t 2s':
  |   
  |        1,138,698,008      armv8_pmuv3_0/event=0x08/                                               (94.99%)
  |        1,826,791,390      armv8_pmuv3_1/event=0x08/                                               (43.47%)
  | 
  | ... where the active ratios add to 138.46%, which is clearly wrong.
  | 
  | [ explanation of the reason for this, etc ]

Note: I haven't looked into the code in detail, so the above might be
wrong.

Levi, how about we have a chat offline about how to make this a bit
clearer? I'll be in the office later today.

Mark.

> > This happens because of missing total_enable_time of inactivate event.
> > it's enabled time doesn't update at the event_sched_out() because state
> > isn't PERF_EVENT_STATE_ACTIVE but PERF_EVENT_STATE_INACTIVE.
> 
> time tracking doesn't happen at sched calls -- you'll find a grand total
> of 0 perf_event_update_time() calls in them.
> 
> Also, things like group_sched_out() don't even call into
> event_sched_out() when !ACTIVE.
> 
> So why is event_sched_out() the right place to change here?
> 
> Also, I've still no clue under what condition all this is supposed to
> have happened :/
> 
> > For example, Suppose there're two events:
> >     e0: with pmu0 which supports only cpu0
> >     e1: with pmu1 which supports only cpu1.
> > then
> > 
> >                CPU0                  CPU1                     CPU0
> >           |  in | out |       | in | out     |       | in      | out (exit)   |
> > ------------------------------------------------------------------------------
> > ctx->time |  0  | t1  |       | t1 | t1 + t2 |       | t1 + t2 | t1 + t2 + t3 |
> > ------------------------------------------------------------------------------
> > e0->ena   |  0  | t1  |       | t1 | t1      |       | t1 + t2 | t1 + t2 + t3 |
> > ------------------------------------------------------------------------------
> > e0->run   |  0  | t1  |       | t1 | t1 + t2 |       | t1 + t2 | t1 + t3      |
> > ------------------------------------------------------------------------------
> > e1->ena   |  0  | 0   |       | t1 | t1 + t2 |       | t1 + t2 | t1 + t2      |
> > ------------------------------------------------------------------------------
> > e1->run   |  0  | 0   |       | 0  | t2      |       | t1 + t2 | t2           |
> > ------------------------------------------------------------------------------
> > 
> > at the CPU0, state of e1 is PERF_EVENT_STATE_INACTIVE since it doesn't
> > support on CPU0. So when event_sched_out() it failed to update its
> > total_enable_time and it makes error print of run/ena ratio.
> 
> Sorry, I have no idea what you're saying. I can't relate the table to
> the text in any meaningful way.
>