Date:   Fri, 10 Dec 2021 11:33:41 +0100
From:   Peter Zijlstra <peterz@infradead.org>
To:     Namhyung Kim <namhyung@kernel.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>
Subject: Re: [PATCH v3] perf/core: Set event shadow time for inactive events
 too
Message-ID: <20211210103341.GS16608@worktop.programming.kicks-ass.net>
References: <20211205224843.1503081-1-namhyung@kernel.org>
 <YbHn6JaaOo3b5GLO@hirez.programming.kicks-ass.net>
 <CAM9d7ciJTJB1rumzmxGeJrAdeE9R4eXhtJRUQGj9y6DBN-ovig@mail.gmail.com>
MIME-Version: 1.0
Content-Type: text/plain; charset=us-ascii
Content-Disposition: inline
In-Reply-To: <CAM9d7ciJTJB1rumzmxGeJrAdeE9R4eXhtJRUQGj9y6DBN-ovig@mail.gmail.com>
Precedence: bulk

On Thu, Dec 09, 2021 at 01:35:11PM -0800, Namhyung Kim wrote:
> 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.

I'm thinking this is a cgroup specific thing. Normally the shadow_time
thing is simply a relative displacement between event-time and the
global clock. That displacement never changes, except when you do
IOC_DISABLE/IOC_ENABLE.

However, for cgroup things are different, since the cgroup events aren't
unconditionally runnable, that is, the enabled time should only count
when the cgroup is active, right?

So perhaps perf_event_read_local() should use a cgroup clock instead of
perf_clock() for cgroup events.

Let me think about that some more...