Re: pmu::read() called erroneously in v4.13-rc{3,4}

From: Mark Rutland
Date: Fri Aug 11 2017 - 05:34:04 EST


On Thu, Aug 10, 2017 at 12:03:55PM -0700, Andi Kleen wrote:
> > [ 230.909172] ------------[ cut here ]------------
> > [ 230.913796] WARNING: CPU: 1 PID: 3637 at arch/x86/events/core.c:75 x86_perf_event_update+0xbd/0xd0
> > [ 230.922739] Modules linked in:
> > [ 230.925798] CPU: 1 PID: 3637 Comm: wrong-counter Tainted: G W 4.13.0-rc4+ #230
> > [ 230.934132] Hardware name: LENOVO 7484A3G/LENOVO, BIOS 5CKT54AUS 09/07/2009
> > [ 230.941080] task: ffff9ad5b0232640 task.stack: ffffb2f001aac000
> > [ 230.946989] RIP: 0010:x86_perf_event_update+0xbd/0xd0
> > [ 230.952038] RSP: 0018:ffffb2f001aaf978 EFLAGS: 00010282
> > [ 230.957257] RAX: 0000000000000020 RBX: ffffb2f001aafa48 RCX: 0000000000000000
> > [ 230.964378] RDX: 0000000000000001 RSI: ffff9ad5a9d33400 RDI: ffff9ad5a9d32800
> > [ 230.971498] RBP: ffffb2f001aaf9a0 R08: 0000000000000000 R09: 0000000000000028
> > [ 230.978622] R10: ffff9ad5b0232640 R11: ffff9ad5a9cd4840 R12: 0000000000000002
> > [ 230.985745] R13: 0000000000000018 R14: 0000000000000001 R15: ffff9ad5a9d32800
> > [ 230.992866] FS: 0000000000000000(0000) GS:ffff9ad5bec80000(0000) knlGS:0000000000000000
> > [ 231.000939] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> > [ 231.006680] CR2: 00007f26cba069d0 CR3: 0000000085a0a000 CR4: 00000000000406e0
> > [ 231.013802] Call Trace:
> > [ 231.016254] x86_pmu_read+0x9/0x10
> > [ 231.019656] perf_output_read+0x19f/0x410
> > [ 231.023665] ? __alloc_pages_nodemask+0xe8/0x1f0
> > [ 231.028274] perf_event_read_event+0xd2/0x110
> > [ 231.032628] ? x86_pmu_del+0x3e/0x130
> > [ 231.036290] ? __intel_pmu_enable_all.isra.12+0x27/0x90
> > [ 231.041512] ? intel_pmu_enable_all+0xb/0x10
> > [ 231.045779] ? x86_pmu_enable+0x25e/0x2f0
> > [ 231.049787] ? group_sched_out+0x8c/0xd0
> > [ 231.053708] ? perf_pmu_enable+0x22/0x30
> > [ 231.057629] ? update_group_times+0x13/0x40
> > [ 231.061812] ? list_del_event+0x66/0xc0
> > [ 231.065647] perf_event_exit_task+0x2fa/0x380
>
> I suspect the problem is that exit schedules before it calls
> perf_event_exit_task.

I'm not sure I follow; could you elaborate?

> We could just move it up to the beginning of exit. Untested
> patch here. Does that help?

I see the same behaviour with the patch below applied.

Thanks,
Mark.

> diff --git a/kernel/exit.c b/kernel/exit.c
> index 516acdb0e0ec..9a6f5f299588 100644
> --- a/kernel/exit.c
> +++ b/kernel/exit.c
> @@ -779,6 +779,14 @@ void __noreturn do_exit(long code)
> int group_dead;
> TASKS_RCU(int tasks_rcu_i);
>
> + /*
> + * Flush inherited counters to the parent - before the parent
> + * gets woken up by child-exit notifications.
> + *
> + * because of cgroup mode, must be called before cgroup_exit()
> + */
> + perf_event_exit_task(tsk);
> +
> profile_task_exit(tsk);
> kcov_task_exit(tsk);
>
> @@ -878,14 +886,6 @@ void __noreturn do_exit(long code)
> exit_task_work(tsk);
> exit_thread(tsk);
>
> - /*
> - * Flush inherited counters to the parent - before the parent
> - * gets woken up by child-exit notifications.
> - *
> - * because of cgroup mode, must be called before cgroup_exit()
> - */
> - perf_event_exit_task(tsk);
> -
> sched_autogroup_exit_task(tsk);
> cgroup_exit(tsk);
>
>