[BUG] perf/x86/intel/pebs: PEBS timestamps overwritten

From: Stephane Eranian <eranian@google.com>
To: LKML <linux-kernel@vger.kernel.org>
Cc: Peter Zijlstra <peterz@infradead.org>,
	"Liang, Kan" <kan.liang@intel.com>,
	Andi Kleen <ak@linux.intel.com>,
	andreas.kogler.0x@gmail.com
Subject: [BUG] perf/x86/intel/pebs: PEBS timestamps overwritten
Date: Fri, 5 Aug 2022 13:49:40 +0300	[thread overview]
Message-ID: <CABPqkBTqQaaYH+ySu3reLm5i+X6P4BsqKycp8NBOP1gW3ZV4QA@mail.gmail.com> (raw)

Hi,

I was alerted by an internal user that the PEBS TSC-based timestamps
do not appear
correctly in the final perf.data output file from perf record.

After some investigation, I came to the conclusion that indeed the
data->time field setup
by PEBS in the setup_pebs_fixed_sample_data() is later overwritten by
perf_events generic
code in perf_prepare_sample(). There is an ordering problem here.

Looking around we found that this problem had been uncovered back in
May 2020 and a
patch had been posted then:
https://lore.kernel.org/lkml/e754b625-bf14-8f5f-bd1a-71d774057005@gmail.com/T/

However this patch was never commented upon or committed.

The problem is still present in the upstream code today.

1. perf_sample_data_init()
2. setup_pebs_fixed_sample_data(): data->time =
native_sched_clock_from_tsc(pebs->tsc);
3. perf_prepare_sample(): data->time = perf_event_clock(event);

The patch from 2020 (Andreas Kogler) fixes the problem by making the
assignment in 3.
conditioned to the value of data->time being 0. Andreas also suggested
an alternative which
would break up the call to perf_event_ouput() like this is done in the
BTS code allowing
the prepare_sample() call to be made before PEBS samples are
extracted. That would
generate some code duplication. Although this approach appears more
robust, the one
issue I see is that prepare_sample may need data that would be filled
by PEBS and
therefore it would  need to be called afterwards.

Any better ideas?
Thanks.