BUG in "perf: Suppress AUX/OVERWRITE records"?

BUG in "perf: Suppress AUX/OVERWRITE records"?

[Ben Gainey]

Hi all

Regarding commit 1627314fb54a33ebd23bd08f2e215eaed0f44712 "perf:
Suppress AUX/OVERWRITE records", I have found that I no longer receive
PERF_RECORD_AUX on context switch when collecting data from the arm_spe
PMU driver. This is because, on context switch, the arm_spe driver
calls perf_aux_output_end with `handle->aux_flags == 0`, failing the
test added in this commit.

This is a problem as it means when capturing data for multiple threads
(using perf_event_open) where AUX data is written to a per-cpu buffer,
I can no longer accurately attribute SPE AUX data to an individual
thread.

If I read the intent of the commit as to remove OVERWRITE AUX records,
then it seems the added if condition is incorrect and should probably
be formulated as:

    if ((handle->aux_flags & ~(u64)PERF_AUX_FLAG_OVERWRITE) || !handle-
>aux_flags)

Is this correct (and would you like a patch?), or is my use of
PERF_RECORD_AUX incorrect in this case?

Thanks

Ben


IMPORTANT NOTICE: The contents of this email and any attachments are confidential and may also be privileged. If you are not the intended recipient, please notify the sender immediately and do not disclose the contents to any other person, use it for any purpose, or store or copy the information in any medium. Thank you.

Re: BUG in "perf: Suppress AUX/OVERWRITE records"?

[Alexander Shishkin]

Ben Gainey <Ben.Gainey@arm.com> writes:

> Hi all
>
> Regarding commit 1627314fb54a33ebd23bd08f2e215eaed0f44712 "perf:
> Suppress AUX/OVERWRITE records", I have found that I no longer receive
> PERF_RECORD_AUX on context switch when collecting data from the arm_spe
> PMU driver. This is because, on context switch, the arm_spe driver
> calls perf_aux_output_end with `handle->aux_flags == 0`, failing the
> test added in this commit.
>
> This is a problem as it means when capturing data for multiple threads
> (using perf_event_open) where AUX data is written to a per-cpu buffer,
> I can no longer accurately attribute SPE AUX data to an individual
> thread.

Sounds like PERF_RECORD_SWITCH should be sufficient for your purposes,
have you considered that?

> If I read the intent of the commit as to remove OVERWRITE AUX records,
> then it seems the added if condition is incorrect and should probably
> be formulated as:
>
>     if ((handle->aux_flags & ~(u64)PERF_AUX_FLAG_OVERWRITE) || !handle-
>>aux_flags)
>
> Is this correct (and would you like a patch?), or is my use of
> PERF_RECORD_AUX incorrect in this case?

No, the point of AUX records is to communicate useful things about the
data in AUX buffer. It was an unintentional side effect that it also
happened to coincide with context switches in the overwrite mode.

Thanks,
--
Alex

Re: BUG in "perf: Suppress AUX/OVERWRITE records"?

[Ben Gainey]

On Tue, 2019-03-26 at 09:02 +0200, Alexander Shishkin wrote:
> Ben Gainey <Ben.Gainey@arm.com> writes:
>
> > Hi all
> >
> > Regarding commit 1627314fb54a33ebd23bd08f2e215eaed0f44712 "perf:
> > Suppress AUX/OVERWRITE records", I have found that I no longer
> > receive
> > PERF_RECORD_AUX on context switch when collecting data from the
> > arm_spe
> > PMU driver. This is because, on context switch, the arm_spe driver
> > calls perf_aux_output_end with `handle->aux_flags == 0`, failing
> > the
> > test added in this commit.
> >
> > This is a problem as it means when capturing data for multiple
> > threads
> > (using perf_event_open) where AUX data is written to a per-cpu
> > buffer,
> > I can no longer accurately attribute SPE AUX data to an individual
> > thread.
>
> Sounds like PERF_RECORD_SWITCH should be sufficient for your
> purposes,
> have you considered that?


I'm not trying to track the context switch its self. I want know which
chunks of AUX data were associated with a given thread.

Consider:

Thread A executes
 ... context switch    [WRITES AUX DATA FROM OFFSET n...n+l]
Thread B executes
 ... context switch    [WRITES AUX DATA FROM OFFSET n+l...n+l+m]

From the point of view of someone reading back the ring buffer data in
userspace, depending on when the consumer wakes whilst waiting on the
ring buffer, it may only see aux_head/tail covering the range
[n...n+l+m]. Prior to this change I would see two AUX records, one with
offset n, length l, and the second offset n+l, length m. After the
change, there are no AUX records.


>
> > If I read the intent of the commit as to remove OVERWRITE AUX
> > records,
> > then it seems the added if condition is incorrect and should
> > probably
> > be formulated as:
> >
> >     if ((handle->aux_flags & ~(u64)PERF_AUX_FLAG_OVERWRITE) ||
> > !handle-
> > > aux_flags)
> >
> > Is this correct (and would you like a patch?), or is my use of
> > PERF_RECORD_AUX incorrect in this case?
>
> No, the point of AUX records is to communicate useful things about
> the
> data in AUX buffer.

Sure, and knowing when the end of the AUX data for one thread ends and
the next starts is useful, surely?

Additionally the change introduced is preventing writing an
PERF_RECORD_AUX when flags does not contain PERF_AUX_FLAG_OVERWRITE
(flags==0) which seems to not be the intention of the commit?

> It was an unintentional side effect that it also
> happened to coincide with context switches in the overwrite mode.

I'm not using overwrite mode, I'm opening the mmap with PROT_WRITE
(i.e. in truncate mode).

Regards
Ben


>
> Thanks,
> --
> Alex
IMPORTANT NOTICE: The contents of this email and any attachments are confidential and may also be privileged. If you are not the intended recipient, please notify the sender immediately and do not disclose the contents to any other person, use it for any purpose, or store or copy the information in any medium. Thank you.

Re: BUG in "perf: Suppress AUX/OVERWRITE records"?

[Alexander Shishkin]

Ben Gainey <Ben.Gainey@arm.com> writes:

>> It was an unintentional side effect that it also
>> happened to coincide with context switches in the overwrite mode.
>
> I'm not using overwrite mode, I'm opening the mmap with PROT_WRITE
> (i.e. in truncate mode).

Now I get it. Does the below fix the problem for you?

From bf52320cce0e74a2c0d987db7bd571f7687b4f4f Mon Sep 17 00:00:00 2001
From: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Date: Wed, 27 Mar 2019 11:05:53 +0200
Subject: [PATCH] perf: Fix AUX record suppression

Commit 1627314fb54a33e ("perf: Suppress AUX/OVERWRITE records") has an
unintended side-effect of also suppressing all AUX records with no flags
and non-zero size, so all the regular records in the full trace mode.
This breaks some use cases for people.

Fix this by restoring "regular" AUX records to their former glory.

Signed-off-by: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Fixes: 1627314fb54a33e ("perf: Suppress AUX/OVERWRITE records")
Reported-by: Ben Gainey <Ben.Gainey@arm.com>
CC: stable@vger.kernel.org # v4.20+
---
 kernel/events/ring_buffer.c | 33 +++++++++++++++------------------
 1 file changed, 15 insertions(+), 18 deletions(-)

diff --git a/kernel/events/ring_buffer.c b/kernel/events/ring_buffer.c
index 678ccec60d8f..626256dc26c1 100644
--- a/kernel/events/ring_buffer.c
+++ b/kernel/events/ring_buffer.c
@@ -455,24 +455,21 @@ void perf_aux_output_end(struct perf_output_handle *handle, unsigned long size)
 		rb->aux_head += size;
 	}
 
-	if (size || handle->aux_flags) {
-		/*
-		 * Only send RECORD_AUX if we have something useful to communicate
-		 *
-		 * Note: the OVERWRITE records by themselves are not considered
-		 * useful, as they don't communicate any *new* information,
-		 * aside from the short-lived offset, that becomes history at
-		 * the next event sched-in and therefore isn't useful.
-		 * The userspace that needs to copy out AUX data in overwrite
-		 * mode should know to use user_page::aux_head for the actual
-		 * offset. So, from now on we don't output AUX records that
-		 * have *only* OVERWRITE flag set.
-		 */
-
-		if (handle->aux_flags & ~(u64)PERF_AUX_FLAG_OVERWRITE)
-			perf_event_aux_event(handle->event, aux_head, size,
-			                     handle->aux_flags);
-	}
+	/*
+	 * Only send RECORD_AUX if we have something useful to communicate
+	 *
+	 * Note: the OVERWRITE records by themselves are not considered
+	 * useful, as they don't communicate any *new* information,
+	 * aside from the short-lived offset, that becomes history at
+	 * the next event sched-in and therefore isn't useful.
+	 * The userspace that needs to copy out AUX data in overwrite
+	 * mode should know to use user_page::aux_head for the actual
+	 * offset. So, from now on we don't output AUX records that
+	 * have *only* OVERWRITE flag set.
+	 */
+	if (size || (handle->aux_flags & ~(u64)PERF_AUX_FLAG_OVERWRITE))
+		perf_event_aux_event(handle->event, aux_head, size,
+				     handle->aux_flags);
 
 	rb->user_page->aux_head = rb->aux_head;
 	if (rb_need_aux_wakeup(rb))
-- 
2.20.1

Re: BUG in "perf: Suppress AUX/OVERWRITE records"?

[Ben Gainey]

On Wed, 2019-03-27 at 11:17 +0200, Alexander Shishkin wrote:
> Ben Gainey <Ben.Gainey@arm.com> writes:
>
> > > It was an unintentional side effect that it also
> > > happened to coincide with context switches in the overwrite mode.
> >
> > I'm not using overwrite mode, I'm opening the mmap with PROT_WRITE
> > (i.e. in truncate mode).
>
> Now I get it. Does the below fix the problem for you?

Yes I guess I should have mentioned that in the first place.
Tested, working now as expected; I see regular PERF_RECORD_AUX, that
coincide with the context switch.

Thanks!
Ben

>
> From bf52320cce0e74a2c0d987db7bd571f7687b4f4f Mon Sep 17 00:00:00
> 2001
> From: Alexander Shishkin <alexander.shishkin@linux.intel.com>
> Date: Wed, 27 Mar 2019 11:05:53 +0200
> Subject: [PATCH] perf: Fix AUX record suppression
>
> Commit 1627314fb54a33e ("perf: Suppress AUX/OVERWRITE records") has
> an
> unintended side-effect of also suppressing all AUX records with no
> flags
> and non-zero size, so all the regular records in the full trace mode.
> This breaks some use cases for people.
>
> Fix this by restoring "regular" AUX records to their former glory.
>
> Signed-off-by: Alexander Shishkin <alexander.shishkin@linux.intel.com
> >
> Fixes: 1627314fb54a33e ("perf: Suppress AUX/OVERWRITE records")
> Reported-by: Ben Gainey <Ben.Gainey@arm.com>
> CC: stable@vger.kernel.org # v4.20+
> ---
>  kernel/events/ring_buffer.c | 33 +++++++++++++++------------------
>  1 file changed, 15 insertions(+), 18 deletions(-)
>
> diff --git a/kernel/events/ring_buffer.c
> b/kernel/events/ring_buffer.c
> index 678ccec60d8f..626256dc26c1 100644
> --- a/kernel/events/ring_buffer.c
> +++ b/kernel/events/ring_buffer.c
> @@ -455,24 +455,21 @@ void perf_aux_output_end(struct
> perf_output_handle *handle, unsigned long size)
>  rb->aux_head += size;
>  }
>
> -if (size || handle->aux_flags) {
> -/*
> - * Only send RECORD_AUX if we have something useful to
> communicate
> - *
> - * Note: the OVERWRITE records by themselves are not
> considered
> - * useful, as they don't communicate any *new*
> information,
> - * aside from the short-lived offset, that becomes
> history at
> - * the next event sched-in and therefore isn't useful.
> - * The userspace that needs to copy out AUX data in
> overwrite
> - * mode should know to use user_page::aux_head for the
> actual
> - * offset. So, from now on we don't output AUX records
> that
> - * have *only* OVERWRITE flag set.
> - */
> -
> -if (handle->aux_flags & ~(u64)PERF_AUX_FLAG_OVERWRITE)
> -perf_event_aux_event(handle->event, aux_head,
> size,
> -                     handle->aux_flags);
> -}
> +/*
> + * Only send RECORD_AUX if we have something useful to
> communicate
> + *
> + * Note: the OVERWRITE records by themselves are not considered
> + * useful, as they don't communicate any *new* information,
> + * aside from the short-lived offset, that becomes history at
> + * the next event sched-in and therefore isn't useful.
> + * The userspace that needs to copy out AUX data in overwrite
> + * mode should know to use user_page::aux_head for the actual
> + * offset. So, from now on we don't output AUX records that
> + * have *only* OVERWRITE flag set.
> + */
> +if (size || (handle->aux_flags &
> ~(u64)PERF_AUX_FLAG_OVERWRITE))
> +perf_event_aux_event(handle->event, aux_head, size,
> +     handle->aux_flags);
>
>  rb->user_page->aux_head = rb->aux_head;
>  if (rb_need_aux_wakeup(rb))
IMPORTANT NOTICE: The contents of this email and any attachments are confidential and may also be privileged. If you are not the intended recipient, please notify the sender immediately and do not disclose the contents to any other person, use it for any purpose, or store or copy the information in any medium. Thank you.

Re: BUG in "perf: Suppress AUX/OVERWRITE records"?

[Will Deacon]

On Wed, Mar 27, 2019 at 11:17:43AM +0200, Alexander Shishkin wrote:
> Ben Gainey <Ben.Gainey@arm.com> writes:
> 
> >> It was an unintentional side effect that it also
> >> happened to coincide with context switches in the overwrite mode.
> >
> > I'm not using overwrite mode, I'm opening the mmap with PROT_WRITE
> > (i.e. in truncate mode).
> 
> Now I get it. Does the below fix the problem for you?
> 
> From bf52320cce0e74a2c0d987db7bd571f7687b4f4f Mon Sep 17 00:00:00 2001
> From: Alexander Shishkin <alexander.shishkin@linux.intel.com>
> Date: Wed, 27 Mar 2019 11:05:53 +0200
> Subject: [PATCH] perf: Fix AUX record suppression
> 
> Commit 1627314fb54a33e ("perf: Suppress AUX/OVERWRITE records") has an
> unintended side-effect of also suppressing all AUX records with no flags
> and non-zero size, so all the regular records in the full trace mode.
> This breaks some use cases for people.
> 
> Fix this by restoring "regular" AUX records to their former glory.
> 
> Signed-off-by: Alexander Shishkin <alexander.shishkin@linux.intel.com>
> Fixes: 1627314fb54a33e ("perf: Suppress AUX/OVERWRITE records")
> Reported-by: Ben Gainey <Ben.Gainey@arm.com>
> CC: stable@vger.kernel.org # v4.20+
> ---
>  kernel/events/ring_buffer.c | 33 +++++++++++++++------------------
>  1 file changed, 15 insertions(+), 18 deletions(-)
> 
> diff --git a/kernel/events/ring_buffer.c b/kernel/events/ring_buffer.c
> index 678ccec60d8f..626256dc26c1 100644
> --- a/kernel/events/ring_buffer.c
> +++ b/kernel/events/ring_buffer.c
> @@ -455,24 +455,21 @@ void perf_aux_output_end(struct perf_output_handle *handle, unsigned long size)
>  		rb->aux_head += size;
>  	}
>  
> -	if (size || handle->aux_flags) {
> -		/*
> -		 * Only send RECORD_AUX if we have something useful to communicate
> -		 *
> -		 * Note: the OVERWRITE records by themselves are not considered
> -		 * useful, as they don't communicate any *new* information,
> -		 * aside from the short-lived offset, that becomes history at
> -		 * the next event sched-in and therefore isn't useful.
> -		 * The userspace that needs to copy out AUX data in overwrite
> -		 * mode should know to use user_page::aux_head for the actual
> -		 * offset. So, from now on we don't output AUX records that
> -		 * have *only* OVERWRITE flag set.
> -		 */
> -
> -		if (handle->aux_flags & ~(u64)PERF_AUX_FLAG_OVERWRITE)
> -			perf_event_aux_event(handle->event, aux_head, size,
> -			                     handle->aux_flags);
> -	}
> +	/*
> +	 * Only send RECORD_AUX if we have something useful to communicate
> +	 *
> +	 * Note: the OVERWRITE records by themselves are not considered
> +	 * useful, as they don't communicate any *new* information,
> +	 * aside from the short-lived offset, that becomes history at
> +	 * the next event sched-in and therefore isn't useful.
> +	 * The userspace that needs to copy out AUX data in overwrite
> +	 * mode should know to use user_page::aux_head for the actual
> +	 * offset. So, from now on we don't output AUX records that
> +	 * have *only* OVERWRITE flag set.
> +	 */
> +	if (size || (handle->aux_flags & ~(u64)PERF_AUX_FLAG_OVERWRITE))
> +		perf_event_aux_event(handle->event, aux_head, size,
> +				     handle->aux_flags);

Acked-by: Will Deacon <will.deacon@arm.com>

Assuming this will make it into 5.1 as a fix?

Will