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

[Yeoreum Yun <yeoreum.yun@arm.com>]

Hi Mark.

> 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.

Thanks. I'll be also in the office later today..!

> > > 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.
> >