Groups | Search | Server Info | Keyboard shortcuts | Login | Register [http] [https] [nntp] [nntps]

Groups > linux.kernel > #1340788 > unrolled thread

Re: [RFC][PATCH 4/7] perf: Fix scaling vs enable_on_exec

Back to article view | Back to linux.kernel

This discussion starts older than the indexed window; earlier articles aren't shown. The article labeled Started by below is the oldest one visible, not the original post.

Contents

  Re: [RFC][PATCH 4/7] perf: Fix scaling vs enable_on_exec Peter Zijlstra <peterz@infradead.org> - 2016-02-23 16:30 +0100
    Re: [RFC][PATCH 4/7] perf: Fix scaling vs enable_on_exec Jiri Olsa <jolsa@redhat.com> - 2016-02-23 16:50 +0100
      Re: [RFC][PATCH 4/7] perf: Fix scaling vs enable_on_exec Pratyush Anand <panand@redhat.com> - 2016-02-23 17:40 +0100
        Re: [RFC][PATCH 4/7] perf: Fix scaling vs enable_on_exec Peter Zijlstra <peterz@infradead.org> - 2016-02-23 18:50 +0100
          Re: [RFC][PATCH 4/7] perf: Fix scaling vs enable_on_exec Peter Zijlstra <peterz@infradead.org> - 2016-02-24 13:00 +0100
            Re: [RFC][PATCH 4/7] perf: Fix scaling vs enable_on_exec Peter Zijlstra <peterz@infradead.org> - 2016-02-24 15:10 +0100
              Re: [RFC][PATCH 4/7] perf: Fix scaling vs enable_on_exec Peter Zijlstra <peterz@infradead.org> - 2016-02-24 17:10 +0100
                Re: [RFC][PATCH 4/7] perf: Fix scaling vs enable_on_exec Pratyush Anand <panand@redhat.com> - 2016-02-25 05:10 +0100
      Re: [RFC][PATCH 4/7] perf: Fix scaling vs enable_on_exec Jiri Olsa <jolsa@redhat.com> - 2016-02-23 22:50 +0100
        Re: [RFC][PATCH 4/7] perf: Fix scaling vs enable_on_exec Oleg Nesterov <oleg@redhat.com> - 2016-02-26 03:30 +0100

#1340788 — Re: [RFC][PATCH 4/7] perf: Fix scaling vs enable_on_exec

On Fri, Feb 19, 2016 at 03:37:47PM +0100, Peter Zijlstra wrote:
> Oleg reported that enable_on_exec results in weird scale factors.
> 
> The recent commit 3e349507d12d ("perf: Fix perf_enable_on_exec() event
> scheduling") caused this by moving task_ctx_sched_out() from before
> __perf_event_mask_enable() to after it.
> 
> The overlooked concequence of that change is that task_ctx_sched_out()
> would update the ctx time fields, and now __perf_event_mask_enable()
> uses stale time.
> 
> Fix this by adding an explicit time update.
> 
> While looking at this, I also found that we need an ctx->is_active
> check in perf_install_in_context().
> 
> XXX: does this actually fix the reported issue? I'm not sure what the
> reproduction case is. Also an earlier version made Jiri's machine
> explode -- something I've not managed to reproduce either.

Jiri, can you have a look at this and perhaps share the reproducer?

> Fixes: 3e349507d12d ("perf: Fix perf_enable_on_exec() event scheduling")
> Reported-by: Oleg Nesterov <oleg@redhat.com>
> Signed-off-by: Peter Zijlstra (Intel) <peterz@infradead.org>
> ---
>  kernel/events/core.c |   18 ++++++++++++------
>  1 file changed, 12 insertions(+), 6 deletions(-)
> 
> --- a/kernel/events/core.c
> +++ b/kernel/events/core.c
> @@ -2170,12 +2170,12 @@ perf_install_in_context(struct perf_even
>  		raw_spin_unlock_irq(&ctx->lock);
>  		return;
>  	}
> -	update_context_time(ctx);
> -	/*
> -	 * Update cgrp time only if current cgrp matches event->cgrp.
> -	 * Must be done before calling add_event_to_ctx().
> -	 */
> -	update_cgrp_time_from_event(event);
> +
> +	if (ctx->is_active) {
> +		update_context_time(ctx);
> +		update_cgrp_time_from_event(event);
> +	}
> +
>  	add_event_to_ctx(event, ctx);
>  	raw_spin_unlock_irq(&ctx->lock);
>  
> @@ -3122,6 +3122,12 @@ static void perf_event_enable_on_exec(in
>  
>  	cpuctx = __get_cpu_context(ctx);
>  	perf_ctx_lock(cpuctx, ctx);
> +
> +	if (ctx->is_active) {
> +		update_context_time(ctx);
> +		update_cgrp_time_from_cpuctx(cpuctx);
> +	}
> +
>  	list_for_each_entry(event, &ctx->event_list, event_entry)
>  		enabled |= event_enable_on_exec(event, ctx);
>  
> 
> 

[toc] | [next] | [standalone]

#1340803

On Tue, Feb 23, 2016 at 04:27:29PM +0100, Peter Zijlstra wrote:
> On Fri, Feb 19, 2016 at 03:37:47PM +0100, Peter Zijlstra wrote:
> > Oleg reported that enable_on_exec results in weird scale factors.
> > 
> > The recent commit 3e349507d12d ("perf: Fix perf_enable_on_exec() event
> > scheduling") caused this by moving task_ctx_sched_out() from before
> > __perf_event_mask_enable() to after it.
> > 
> > The overlooked concequence of that change is that task_ctx_sched_out()
> > would update the ctx time fields, and now __perf_event_mask_enable()
> > uses stale time.
> > 
> > Fix this by adding an explicit time update.
> > 
> > While looking at this, I also found that we need an ctx->is_active
> > check in perf_install_in_context().
> > 
> > XXX: does this actually fix the reported issue? I'm not sure what the
> > reproduction case is. Also an earlier version made Jiri's machine
> > explode -- something I've not managed to reproduce either.
> 
> Jiri, can you have a look at this and perhaps share the reproducer?

yep, I'm testing this patchset, but got stuck with 'crash' tool to get
some reasonable output.. got stuck on unrelated sched deadlock ;-)

the reproducer is described in this email:
http://marc.info/?l=linux-kernel&m=145568006709552&w=2

CC-ing Pratyush

jjirka

[toc] | [prev] | [next] | [standalone]

#1340845

Hi Peter/Jiri,

On 23/02/2016:04:48:49 PM, Jiri Olsa wrote:
> On Tue, Feb 23, 2016 at 04:27:29PM +0100, Peter Zijlstra wrote:
> > On Fri, Feb 19, 2016 at 03:37:47PM +0100, Peter Zijlstra wrote:
> > > Oleg reported that enable_on_exec results in weird scale factors.
> > > 
> > > The recent commit 3e349507d12d ("perf: Fix perf_enable_on_exec() event
> > > scheduling") caused this by moving task_ctx_sched_out() from before
> > > __perf_event_mask_enable() to after it.
> > > 
> > > The overlooked concequence of that change is that task_ctx_sched_out()
> > > would update the ctx time fields, and now __perf_event_mask_enable()
> > > uses stale time.
> > > 
> > > Fix this by adding an explicit time update.
> > > 
> > > While looking at this, I also found that we need an ctx->is_active
> > > check in perf_install_in_context().
> > > 
> > > XXX: does this actually fix the reported issue? I'm not sure what the
> > > reproduction case is. Also an earlier version made Jiri's machine
> > > explode -- something I've not managed to reproduce either.
> > 
> > Jiri, can you have a look at this and perhaps share the reproducer?
> 
> yep, I'm testing this patchset, but got stuck with 'crash' tool to get
> some reasonable output.. got stuck on unrelated sched deadlock ;-)
> 
> the reproducer is described in this email:
> http://marc.info/?l=linux-kernel&m=145568006709552&w=2
> 
> CC-ing Pratyush

Thanks for CCing.

Its better with this patch, still count is 1 more in case of higher probe hits (
like 65535 times).

Reproducer is:
---------------------------------------------------------
git clone https://github.com/rfmvh/perftool-testsuite.git
cd perftool-testsuite/base_probe/
./setup.sh 
for i in 1 2 3 103 997 65535; do
perf probe -x examples/exact_counts --add f_${i}x
done
perf stat -x';' -e 'probe_exact:*' examples/exact_counts
---------------------------------------------------------

I see following with above code:

65536;;probe_exact:f_65535x;84476560;100.00
997;;probe_exact:f_997x;84476560;100.00
103;;probe_exact:f_103x;84476560;100.00
3;;probe_exact:f_3x;84476560;100.00
2;;probe_exact:f_2x;84476560;100.00
1;;probe_exact:f_1x;84476560;100.00

~Pratyush

PS: Do I need to take all patches of series? Currently I have taken only this.

[toc] | [prev] | [next] | [standalone]

#1340905

On Tue, Feb 23, 2016 at 10:05:50PM +0530, Pratyush Anand wrote:
> Its better with this patch, still count is 1 more in case of higher probe hits (
> like 65535 times).

Ah, ok, I'll go try again.

> PS: Do I need to take all patches of series? Currently I have taken only this.

No, they're all quite independent.

[toc] | [prev] | [next] | [standalone]

#1341930

On Tue, Feb 23, 2016 at 06:47:41PM +0100, Peter Zijlstra wrote:
> On Tue, Feb 23, 2016 at 10:05:50PM +0530, Pratyush Anand wrote:
> > Its better with this patch, still count is 1 more in case of higher probe hits (
> > like 65535 times).
> 
> Ah, ok, I'll go try again.

OK, so the below seems to cure this for me, but now I'm hurting my head
to make the same true for perf_install_in_context(), because 'tricky' :/

(the below is a fold of 2 patches, I'll send out a new series once I get
my head around the install_in_context muck :/)

---
 kernel/events/core.c | 84 +++++++++++++++++++++++++++++++++-------------------
 1 file changed, 53 insertions(+), 31 deletions(-)

diff --git a/kernel/events/core.c b/kernel/events/core.c
index 94c47e3f9a0a..8326a7f5729c 100644
--- a/kernel/events/core.c
+++ b/kernel/events/core.c
@@ -314,7 +314,8 @@ static void event_function_call(struct perf_event *event, event_f func, void *da
 enum event_type_t {
 	EVENT_FLEXIBLE = 0x1,
 	EVENT_PINNED = 0x2,
-	EVENT_ALL = EVENT_FLEXIBLE | EVENT_PINNED,
+	EVENT_TIME = 0x4,
+	EVENT_ALL = EVENT_FLEXIBLE | EVENT_PINNED | EVENT_TIME,
 };
 
 /*
@@ -1288,16 +1289,18 @@ static u64 perf_event_time(struct perf_event *event)
 
 /*
  * Update the total_time_enabled and total_time_running fields for a event.
- * The caller of this function needs to hold the ctx->lock.
  */
 static void update_event_times(struct perf_event *event)
 {
 	struct perf_event_context *ctx = event->ctx;
 	u64 run_end;
 
+	lockdep_assert_held(&ctx->lock);
+
 	if (event->state < PERF_EVENT_STATE_INACTIVE ||
 	    event->group_leader->state < PERF_EVENT_STATE_INACTIVE)
 		return;
+
 	/*
 	 * in cgroup mode, time_enabled represents
 	 * the time the event was enabled AND active
@@ -2063,14 +2066,27 @@ static void add_event_to_ctx(struct perf_event *event,
 	event->tstamp_stopped = tstamp;
 }
 
-static void task_ctx_sched_out(struct perf_cpu_context *cpuctx,
-			       struct perf_event_context *ctx);
+static void ctx_sched_out(struct perf_event_context *ctx,
+			  struct perf_cpu_context *cpuctx,
+			  enum event_type_t event_type);
 static void
 ctx_sched_in(struct perf_event_context *ctx,
 	     struct perf_cpu_context *cpuctx,
 	     enum event_type_t event_type,
 	     struct task_struct *task);
 
+static void task_ctx_sched_out(struct perf_cpu_context *cpuctx,
+			       struct perf_event_context *ctx)
+{
+	if (!cpuctx->task_ctx)
+		return;
+
+	if (WARN_ON_ONCE(ctx != cpuctx->task_ctx))
+		return;
+
+	ctx_sched_out(ctx, cpuctx, EVENT_ALL);
+}
+
 static void perf_event_sched_in(struct perf_cpu_context *cpuctx,
 				struct perf_event_context *ctx,
 				struct task_struct *task)
@@ -2219,17 +2235,17 @@ static void __perf_event_enable(struct perf_event *event,
 	    event->state <= PERF_EVENT_STATE_ERROR)
 		return;
 
-	update_context_time(ctx);
+	ctx_sched_out(ctx, cpuctx, EVENT_TIME);
+
 	__perf_event_mark_enabled(event);
 
 	if (!ctx->is_active)
 		return;
 
 	if (!event_filter_match(event)) {
-		if (is_cgroup_event(event)) {
-			perf_cgroup_set_timestamp(current, ctx); // XXX ?
+		if (is_cgroup_event(event))
 			perf_cgroup_defer_enabled(event);
-		}
+		ctx_sched_in(ctx, cpuctx, EVENT_TIME, current);
 		return;
 	}
 
@@ -2237,8 +2253,10 @@ static void __perf_event_enable(struct perf_event *event,
 	 * If the event is in a group and isn't the group leader,
 	 * then don't put it on unless the group is on.
 	 */
-	if (leader != event && leader->state != PERF_EVENT_STATE_ACTIVE)
+	if (leader != event && leader->state != PERF_EVENT_STATE_ACTIVE) {
+		ctx_sched_in(ctx, cpuctx, EVENT_TIME, current);
 		return;
+	}
 
 	task_ctx = cpuctx->task_ctx;
 	if (ctx->task)
@@ -2344,24 +2362,33 @@ static void ctx_sched_out(struct perf_event_context *ctx,
 	}
 
 	ctx->is_active &= ~event_type;
+	if (!(ctx->is_active & (EVENT_FLEXIBLE | EVENT_PINNED)))
+		ctx->is_active = 0;
+
 	if (ctx->task) {
 		WARN_ON_ONCE(cpuctx->task_ctx != ctx);
 		if (!ctx->is_active)
 			cpuctx->task_ctx = NULL;
 	}
 
-	update_context_time(ctx);
-	update_cgrp_time_from_cpuctx(cpuctx);
+	is_active ^= ctx->is_active; /* changed bits */
+
+	if (is_active & EVENT_TIME) {
+		/* update (and stop) ctx time */
+		update_context_time(ctx);
+		update_cgrp_time_from_cpuctx(cpuctx);
+	}
+
 	if (!ctx->nr_active)
 		return;
 
 	perf_pmu_disable(ctx->pmu);
-	if ((is_active & EVENT_PINNED) && (event_type & EVENT_PINNED)) {
+	if (is_active & EVENT_PINNED) {
 		list_for_each_entry(event, &ctx->pinned_groups, group_entry)
 			group_sched_out(event, cpuctx, ctx);
 	}
 
-	if ((is_active & EVENT_FLEXIBLE) && (event_type & EVENT_FLEXIBLE)) {
+	if (is_active & EVENT_FLEXIBLE) {
 		list_for_each_entry(event, &ctx->flexible_groups, group_entry)
 			group_sched_out(event, cpuctx, ctx);
 	}
@@ -2641,18 +2668,6 @@ void __perf_event_task_sched_out(struct task_struct *task,
 		perf_cgroup_sched_out(task, next);
 }
 
-static void task_ctx_sched_out(struct perf_cpu_context *cpuctx,
-			       struct perf_event_context *ctx)
-{
-	if (!cpuctx->task_ctx)
-		return;
-
-	if (WARN_ON_ONCE(ctx != cpuctx->task_ctx))
-		return;
-
-	ctx_sched_out(ctx, cpuctx, EVENT_ALL);
-}
-
 /*
  * Called with IRQs disabled
  */
@@ -2735,7 +2750,7 @@ ctx_sched_in(struct perf_event_context *ctx,
 	if (likely(!ctx->nr_events))
 		return;
 
-	ctx->is_active |= event_type;
+	ctx->is_active |= (event_type | EVENT_TIME);
 	if (ctx->task) {
 		if (!is_active)
 			cpuctx->task_ctx = ctx;
@@ -2743,18 +2758,24 @@ ctx_sched_in(struct perf_event_context *ctx,
 			WARN_ON_ONCE(cpuctx->task_ctx != ctx);
 	}
 
-	now = perf_clock();
-	ctx->timestamp = now;
-	perf_cgroup_set_timestamp(task, ctx);
+	is_active ^= ctx->is_active; /* changed bits */
+
+	if (is_active & EVENT_TIME) {
+		/* start ctx time */
+		now = perf_clock();
+		ctx->timestamp = now;
+		perf_cgroup_set_timestamp(task, ctx);
+	}
+
 	/*
 	 * First go through the list and put on any pinned groups
 	 * in order to give them the best chance of going on.
 	 */
-	if (!(is_active & EVENT_PINNED) && (event_type & EVENT_PINNED))
+	if (is_active & EVENT_PINNED)
 		ctx_pinned_sched_in(ctx, cpuctx);
 
 	/* Then walk through the lower prio flexible groups */
-	if (!(is_active & EVENT_FLEXIBLE) && (event_type & EVENT_FLEXIBLE))
+	if (is_active & EVENT_FLEXIBLE)
 		ctx_flexible_sched_in(ctx, cpuctx);
 }
 
@@ -3120,6 +3141,7 @@ static void perf_event_enable_on_exec(int ctxn)
 
 	cpuctx = __get_cpu_context(ctx);
 	perf_ctx_lock(cpuctx, ctx);
+	ctx_sched_out(ctx, cpuctx, EVENT_TIME);
 	list_for_each_entry(event, &ctx->event_list, event_entry)
 		enabled |= event_enable_on_exec(event, ctx);
 

[toc] | [prev] | [next] | [standalone]

#1342050

On Wed, Feb 24, 2016 at 12:53:51PM +0100, Peter Zijlstra wrote:
> On Tue, Feb 23, 2016 at 06:47:41PM +0100, Peter Zijlstra wrote:
> > On Tue, Feb 23, 2016 at 10:05:50PM +0530, Pratyush Anand wrote:
> > > Its better with this patch, still count is 1 more in case of higher probe hits (
> > > like 65535 times).
> > 
> > Ah, ok, I'll go try again.
> 
> OK, so the below seems to cure this for me, but now I'm hurting my head
> to make the same true for perf_install_in_context(), because 'tricky' :/
> 

FWIW, it would be nice to have a similar test for:

	attr = {
		.disabled = true;
	}

	sys_perf_event_open(&attr, .pid = self);

	if (attr.disabled)
		ioctl(ENABLE);

	/* generate N events */

	ioctl(DISABLE);

	read();

	/* print event cnt and scale factors */

and one that has .disabled = false.

[toc] | [prev] | [next] | [standalone]

#1342161

On Wed, Feb 24, 2016 at 03:02:39PM +0100, Peter Zijlstra wrote:
> FWIW, it would be nice to have a similar test for:
> 
> 	attr = {
> 		.disabled = true;
> 	}
> 
> 	sys_perf_event_open(&attr, .pid = self);
> 
> 	if (attr.disabled)
> 		ioctl(ENABLE);
> 
> 	/* generate N events */
> 
> 	ioctl(DISABLE);
> 
> 	read();
> 
> 	/* print event cnt and scale factors */
> 
> and one that has .disabled = false.


root@ivb-ep:~/perf# ./main 
1000000903 218851613 218851613
root@ivb-ep:~/perf# ./main 1
1000000235 218981231 218981231


Appears to work...

---

#define _GNU_SOURCE
#include <unistd.h>
#include <stdio.h>
#include <stdlib.h>
#include <stdarg.h>

#include "perf.h"

static struct perf_event_attr perf_attr = {
	.type = PERF_TYPE_HARDWARE,
	.config = PERF_COUNT_HW_INSTRUCTIONS,
	.read_format = PERF_FORMAT_TOTAL_TIME_ENABLED |
		       PERF_FORMAT_TOTAL_TIME_RUNNING,
	.exclude_kernel = 1,
	.pinned = 1,
};

void die(const char *err, ...)
{
	va_list params;

	va_start(params, err);
	vfprintf(stderr, err, params);
	va_end(params);

	exit(-1);
}

int main (int argc, char **argv)
{
	u64 val[3];
	int i, fd;

	perf_attr.disabled = argc > 1;

	fd = sys_perf_event_open(&perf_attr, 0, -1, -1, 0);
	if (fd < 0)
		die("failed to create perf_event");

	if (perf_attr.disabled)
		ioctl(fd, PERF_EVENT_IOC_ENABLE, 0);

	for (i = 0; i < 100000000; i++) {
		asm volatile ("nop\n\r"
			      "nop\n\r"
			      "nop\n\r"
			      "nop\n\r"
			      "nop\n\r"
			      "nop\n\r"
			      "nop\n\r");
	}

	ioctl(fd, PERF_EVENT_IOC_DISABLE, 0);

	read(fd, &val, sizeof(val));

	printf("%Lu %Lu %Lu\n", val[0], val[1], val[2]);

	return 0;
}

[toc] | [prev] | [next] | [standalone]

#1342786

Hi Peter,

On 24/02/2016:05:02:41 PM, Peter Zijlstra wrote:
> On Wed, Feb 24, 2016 at 03:02:39PM +0100, Peter Zijlstra wrote:
> > FWIW, it would be nice to have a similar test for:

+ Michael, (C Test case for following proposed test case is at the end)

> > 
> > 	attr = {
> > 		.disabled = true;
> > 	}
> > 
> > 	sys_perf_event_open(&attr, .pid = self);
> > 
> > 	if (attr.disabled)
> > 		ioctl(ENABLE);
> > 
> > 	/* generate N events */
> > 
> > 	ioctl(DISABLE);
> > 
> > 	read();
> > 
> > 	/* print event cnt and scale factors */
> > 
> > and one that has .disabled = false.
> 
> 
> root@ivb-ep:~/perf# ./main 
> 1000000903 218851613 218851613
> root@ivb-ep:~/perf# ./main 1
> 1000000235 218981231 218981231
> 
> 
> Appears to work...

Thanks, Picked patches from your new series and it worked :-)

# perf stat -x';' -e 'probe_exact:*' examples/exact_counts  
65535;;probe_exact:f_65535x;85984820;100.00
997;;probe_exact:f_997x;85984820;100.00
103;;probe_exact:f_103x;85984820;100.00
3;;probe_exact:f_3x;85984820;100.00
2;;probe_exact:f_2x;85984820;100.00
1;;probe_exact:f_1x;85984820;100.00

~Pratyush

> 
> ---
> 
> #define _GNU_SOURCE
> #include <unistd.h>
> #include <stdio.h>
> #include <stdlib.h>
> #include <stdarg.h>
> 
> #include "perf.h"
> 
> static struct perf_event_attr perf_attr = {
> 	.type = PERF_TYPE_HARDWARE,
> 	.config = PERF_COUNT_HW_INSTRUCTIONS,
> 	.read_format = PERF_FORMAT_TOTAL_TIME_ENABLED |
> 		       PERF_FORMAT_TOTAL_TIME_RUNNING,
> 	.exclude_kernel = 1,
> 	.pinned = 1,
> };
> 
> void die(const char *err, ...)
> {
> 	va_list params;
> 
> 	va_start(params, err);
> 	vfprintf(stderr, err, params);
> 	va_end(params);
> 
> 	exit(-1);
> }
> 
> int main (int argc, char **argv)
> {
> 	u64 val[3];
> 	int i, fd;
> 
> 	perf_attr.disabled = argc > 1;
> 
> 	fd = sys_perf_event_open(&perf_attr, 0, -1, -1, 0);
> 	if (fd < 0)
> 		die("failed to create perf_event");
> 
> 	if (perf_attr.disabled)
> 		ioctl(fd, PERF_EVENT_IOC_ENABLE, 0);
> 
> 	for (i = 0; i < 100000000; i++) {
> 		asm volatile ("nop\n\r"
> 			      "nop\n\r"
> 			      "nop\n\r"
> 			      "nop\n\r"
> 			      "nop\n\r"
> 			      "nop\n\r"
> 			      "nop\n\r");
> 	}
> 
> 	ioctl(fd, PERF_EVENT_IOC_DISABLE, 0);
> 
> 	read(fd, &val, sizeof(val));
> 
> 	printf("%Lu %Lu %Lu\n", val[0], val[1], val[2]);
> 
> 	return 0;
> }

[toc] | [prev] | [next] | [standalone]

#1341065

On Tue, Feb 23, 2016 at 04:48:49PM +0100, Jiri Olsa wrote:
> On Tue, Feb 23, 2016 at 04:27:29PM +0100, Peter Zijlstra wrote:
> > On Fri, Feb 19, 2016 at 03:37:47PM +0100, Peter Zijlstra wrote:
> > > Oleg reported that enable_on_exec results in weird scale factors.
> > > 
> > > The recent commit 3e349507d12d ("perf: Fix perf_enable_on_exec() event
> > > scheduling") caused this by moving task_ctx_sched_out() from before
> > > __perf_event_mask_enable() to after it.
> > > 
> > > The overlooked concequence of that change is that task_ctx_sched_out()
> > > would update the ctx time fields, and now __perf_event_mask_enable()
> > > uses stale time.
> > > 
> > > Fix this by adding an explicit time update.
> > > 
> > > While looking at this, I also found that we need an ctx->is_active
> > > check in perf_install_in_context().
> > > 
> > > XXX: does this actually fix the reported issue? I'm not sure what the
> > > reproduction case is. Also an earlier version made Jiri's machine
> > > explode -- something I've not managed to reproduce either.
> > 
> > Jiri, can you have a look at this and perhaps share the reproducer?
> 
> yep, I'm testing this patchset, but got stuck with 'crash' tool to get
> some reasonable output.. got stuck on unrelated sched deadlock ;-)
> 
> the reproducer is described in this email:
> http://marc.info/?l=linux-kernel&m=145568006709552&w=2

so I finally got some reasonable backtrace and figured that crash finally:

 #7 [ffff8802751afcd0] general_protection at ffffffff817a69e8
    [exception RIP: special_mapping_fault+47]
    RIP: ffffffff811e40df  RSP: ffff8802751afd88  RFLAGS: 00010282
    RAX: ffff8802747e8b68  RBX: 00007fffffffe080  RCX: c4712d0070657267
    RDX: ffff8802751afd98  RSI: ffff8802742c4f00  RDI: ffff8802747e8b68
    RBP: ffff8802751afd88   R8: 0000000000000000   R9: ffff8802751afe58
    R10: 00000000000001fe  R11: 00003fffffe00000  R12: ffff8802742c4f00
    R13: ffff8802751afe58  R14: 0000000000000000  R15: ffff880273f59ff8
    ORIG_RAX: ffffffffffffffff  CS: 0010  SS: 0000
 #8 [ffff8802751afd90] __do_fault at ffffffff811db505
 #9 [ffff8802751afdf8] handle_mm_fault at ffffffff811e0b03
#10 [ffff8802751afec8] __do_page_fault at ffffffff8106734a
#11 [ffff8802751aff20] do_page_fault at ffffffff810675df
#12 [ffff8802751aff50] page_fault at ffffffff817a6a48


it was caused by:
  - f872f5400cc0 mm: Add a vm_special_mapping.fault() method
    that added call of vm_special_mapping::fault if it's defined

  - and uprobes code not initializing this fault pointer properly,
    attached patch fixed the issue for me,
    Oleg, I'm not sure this is how you want to fix this though..


however I still see the off by 1 as Pratyush said:
  65536;;probe_exact:f_65535x;132185462;100.00

I have another patch making the ena/run times equal for software
events in read syscal, and that obviously works.. but I'm not sure
how fix this otherwise ATM

thanks,
jirka


---
diff --git a/kernel/events/uprobes.c b/kernel/events/uprobes.c
index 0167679182c0..0c045aad28a2 100644
--- a/kernel/events/uprobes.c
+++ b/kernel/events/uprobes.c
@@ -1169,7 +1169,7 @@ static struct xol_area *__create_xol_area(unsigned long vaddr)
 	uprobe_opcode_t insn = UPROBE_SWBP_INSN;
 	struct xol_area *area;
 
-	area = kmalloc(sizeof(*area), GFP_KERNEL);
+	area = kzalloc(sizeof(*area), GFP_KERNEL);
 	if (unlikely(!area))
 		goto out;
 

[toc] | [prev] | [next] | [standalone]

#1343733

On 02/23, Jiri Olsa wrote:
>
> so I finally got some reasonable backtrace and figured that crash finally:
>
>  #7 [ffff8802751afcd0] general_protection at ffffffff817a69e8
>     [exception RIP: special_mapping_fault+47]
>     RIP: ffffffff811e40df  RSP: ffff8802751afd88  RFLAGS: 00010282
>     RAX: ffff8802747e8b68  RBX: 00007fffffffe080  RCX: c4712d0070657267
>     RDX: ffff8802751afd98  RSI: ffff8802742c4f00  RDI: ffff8802747e8b68
>     RBP: ffff8802751afd88   R8: 0000000000000000   R9: ffff8802751afe58
>     R10: 00000000000001fe  R11: 00003fffffe00000  R12: ffff8802742c4f00
>     R13: ffff8802751afe58  R14: 0000000000000000  R15: ffff880273f59ff8
>     ORIG_RAX: ffffffffffffffff  CS: 0010  SS: 0000
>  #8 [ffff8802751afd90] __do_fault at ffffffff811db505
>  #9 [ffff8802751afdf8] handle_mm_fault at ffffffff811e0b03
> #10 [ffff8802751afec8] __do_page_fault at ffffffff8106734a
> #11 [ffff8802751aff20] do_page_fault at ffffffff810675df
> #12 [ffff8802751aff50] page_fault at ffffffff817a6a48
>
>
> it was caused by:
>   - f872f5400cc0 mm: Add a vm_special_mapping.fault() method
>     that added call of vm_special_mapping::fault if it's defined

I guess it came from tip/x86...

>   - and uprobes code not initializing this fault pointer properly,
>     attached patch fixed the issue for me,
>     Oleg, I'm not sure this is how you want to fix this though..

Thanks! I'll send a simple fix tomorrow.

Oleg.

[toc] | [prev] | [standalone]

Back to top | Article view | linux.kernel

csiph-web