MIME-Version: 1.0
References: <20211205224843.1503081-1-namhyung@kernel.org> <YbHn6JaaOo3b5GLO@hirez.programming.kicks-ass.net>
In-Reply-To: <YbHn6JaaOo3b5GLO@hirez.programming.kicks-ass.net>
From:   Namhyung Kim <namhyung@kernel.org>
Date:   Thu, 9 Dec 2021 13:35:11 -0800
Message-ID: <CAM9d7ciJTJB1rumzmxGeJrAdeE9R4eXhtJRUQGj9y6DBN-ovig@mail.gmail.com>
Subject: Re: [PATCH v3] perf/core: Set event shadow time for inactive events too
To:     Peter Zijlstra <peterz@infradead.org>
Cc:     Ingo Molnar <mingo@kernel.org>,
        Arnaldo Carvalho de Melo <acme@kernel.org>,
        Jiri Olsa <jolsa@redhat.com>,
        Mark Rutland <mark.rutland@arm.com>,
        Alexander Shishkin <alexander.shishkin@linux.intel.com>,
        LKML <linux-kernel@vger.kernel.org>,
        Stephane Eranian <eranian@google.com>,
        Andi Kleen <ak@linux.intel.com>,
        Ian Rogers <irogers@google.com>,
        Song Liu <songliubraving@fb.com>
Content-Type: text/plain; charset="UTF-8"
Precedence: bulk

On Thu, Dec 9, 2021 at 3:26 AM Peter Zijlstra <peterz@infradead.org> wrote:
>
> On Sun, Dec 05, 2021 at 02:48:43PM -0800, Namhyung Kim wrote:
>
> > Actually 18446744069443110306 is 0xffffffff01b345a2 so it seems to
> > have a negative enabled time.  In fact, bperf keeps values returned by
> > bpf_perf_event_read_value() which calls perf_event_read_local(), and
> > accumulates delta between two calls.  When event->shadow_ctx_time is
> > not set, it'd return invalid enabled time which is bigger than normal.
>
> *that*, how does it happen that shadow_time isn't set? It should be last
> set when the event switches to INACTIVE, no?

As you can see, perf_event_set_state() doesn't set the shadow time.
It's called from event_sched_in() which might result in ACTIVE or
INACTIVE.  But the problem is that there's a case that event_sched_in
was not called at all - when group_can_go_on() returns false.

> At which point the logic in
> perf_event_read_local() should make @enabled move forward while @running
> stays put.

It's not about updating event->total_time_enabled, it only
afftects the returned value of @enabled.

I'd say the time calculation is broken so it'd break @running
as well.  But this case can only happen on INACTIVE -
otherwise it'd call event_sched_in() and update the shadow
time properly, so no issue there.  And then we can see
the broken value of enabled time only.

>
> Let me go rummage around a bit... either I'm missing something obvious
> or something's smelly.

Thank you for doing that!

Thanks,
Namhyung