Re: [PATCH] perf: Fix missing SIGTRAPs

From: Marco Elver
Date: Fri Oct 07 2022 - 09:58:20 EST


On Fri, Oct 07, 2022 at 03:09PM +0200, Peter Zijlstra wrote:
> On Fri, Oct 07, 2022 at 11:37:34AM +0200, Marco Elver wrote:
>
> > That worked. In addition I had to disable the ctx->task != current check
> > if we're in task_work, because presumably the event might have already
> > been disabled/moved??
>
> Uhmmm... uhhh... damn. (wall-time was significantly longer)
>
> Does this help?

No unfortunately - still see:

[ 82.300827] ------------[ cut here ]------------
[ 82.301680] WARNING: CPU: 0 PID: 976 at kernel/events/core.c:6466 perf_sigtrap+0x60/0x70
[ 82.303069] Modules linked in:
[ 82.303524] CPU: 0 PID: 976 Comm: missed_breakpoi Not tainted 6.0.0-rc3-00017-g1472d7e42f41-dirty #68
[ 82.304825] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.16.0-debian-1.16.0-4 04/01/2014
[ 82.306204] RIP: 0010:perf_sigtrap+0x60/0x70
[ 82.306858] Code: e6 59 fa ff 48 8b 93 50 01 00 00 8b b3 d8 00 00 00 48 8b bb 30 04 00 00 e8 dd cf e8 ff 5b 5d e9 c6 59 fa ff e8 c1 59 fa ff 90 <0f> 0b 90 5b 5d e9 b6 59 fa ff 66 0f 1f 44 00 00 e8 ab 59 fa ff bf
[ 82.309515] RSP: 0000:ffffa52041cbbee0 EFLAGS: 00010293
[ 82.310295] RAX: 0000000000000000 RBX: ffff902fc966a228 RCX: ffffffffa761a53f
[ 82.311336] RDX: ffff902fca39c340 RSI: 0000000000000000 RDI: ffff902fc966a228
[ 82.312376] RBP: ffff902fca39c340 R08: 0000000000000001 R09: 0000000000000001
[ 82.313412] R10: 00000000ffffffff R11: 00000000ffffffff R12: ffff902fca39cbf0
[ 82.314456] R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000000
[ 82.315561] FS: 00007fbae0636700(0000) GS:ffff9032efc00000(0000) knlGS:0000000000000000
[ 82.316815] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 82.317708] CR2: 000000001082d318 CR3: 0000000109430002 CR4: 0000000000770ef0
[ 82.318839] DR0: 00000000008aca98 DR1: 00000000008acb38 DR2: 00000000008acae8
[ 82.319955] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000600
[ 82.321068] PKRU: 55555554
[ 82.321505] Call Trace:
[ 82.321913] <TASK>
[ 82.322267] perf_pending_task+0x7d/0xa0
[ 82.322900] task_work_run+0x73/0xc0
[ 82.323476] exit_to_user_mode_prepare+0x19d/0x1a0
[ 82.324209] irqentry_exit_to_user_mode+0x6/0x30
[ 82.324887] asm_sysvec_call_function_single+0x16/0x20
[ 82.325623] RIP: 0033:0x27d10b
[ 82.326092] Code: 43 08 48 8d 04 80 48 c1 e0 04 48 8d 0d 5e f9 62 00 48 01 c8 48 83 c0 08 b9 01 00 00 00 66 90 48 8b 10 48 39 ca 75 f8 88 48 41 <f0> 48 ff 40 08 48 8b 50 10 48 39 ca 75 f7 88 48 43 f0 48 ff 40 18
[ 82.328696] RSP: 002b:00007fbae0635a60 EFLAGS: 00000246
[ 82.329470] RAX: 00000000008acaa8 RBX: 000024073fc007d0 RCX: 0000000000001add
[ 82.330521] RDX: 0000000000001add RSI: 0000000000000070 RDI: 0000000000000007
[ 82.331557] RBP: 00007fbae0635a70 R08: 00007fbae0636700 R09: 00007fbae0636700
[ 82.332593] R10: 00007fbae06369d0 R11: 0000000000000202 R12: 00007fbae06369d0
[ 82.333630] R13: 00007ffe8139de16 R14: 00007fbae0636d1c R15: 00007fbae0635a80
[ 82.334713] </TASK>
[ 82.335093] irq event stamp: 546455
[ 82.335657] hardirqs last enabled at (546465): [<ffffffffa7513ef6>] __up_console_sem+0x66/0x70
[ 82.337032] hardirqs last disabled at (546476): [<ffffffffa7513edb>] __up_console_sem+0x4b/0x70
[ 82.338414] softirqs last enabled at (546084): [<ffffffffa8c0034f>] __do_softirq+0x34f/0x4d5
[ 82.339769] softirqs last disabled at (546079): [<ffffffffa7493821>] __irq_exit_rcu+0xb1/0x120
[ 82.341128] ---[ end trace 0000000000000000 ]---

I now have this on top:

diff --git a/kernel/events/core.c b/kernel/events/core.c
index 9319af6013f1..7de83c42d312 100644
--- a/kernel/events/core.c
+++ b/kernel/events/core.c
@@ -2285,9 +2285,10 @@ event_sched_out(struct perf_event *event,
*/
local_dec(&event->ctx->nr_pending);
} else {
- WARN_ON_ONCE(event->pending_work);
- event->pending_work = 1;
- task_work_add(current, &event->pending_task, TWA_RESUME);
+ if (!event->pending_work) {
+ event->pending_work = 1;
+ task_work_add(current, &event->pending_task, TWA_RESUME);
+ }
}
}

@@ -6466,7 +6467,8 @@ static void perf_sigtrap(struct perf_event *event)
return;

/*
- * perf_pending_irq() can race with the task exiting.
+ * Both perf_pending_task() and perf_pending_irq() can race with the
+ * task exiting.
*/
if (current->flags & PF_EXITING)
return;
@@ -6495,8 +6497,8 @@ static void __perf_pending_irq(struct perf_event *event)
if (cpu == smp_processor_id()) {
if (event->pending_sigtrap) {
event->pending_sigtrap = 0;
- local_dec(&event->ctx->nr_pending);
perf_sigtrap(event);
+ local_dec(&event->ctx->nr_pending);
}
if (event->pending_disable) {
event->pending_disable = 0;
@@ -6563,16 +6565,18 @@ static void perf_pending_task(struct callback_head *head)
* If we 'fail' here, that's OK, it means recursion is already disabled
* and we won't recurse 'further'.
*/
+ preempt_disable_notrace();
rctx = perf_swevent_get_recursion_context();

if (event->pending_work) {
event->pending_work = 0;
- local_dec(&event->ctx->nr_pending);
perf_sigtrap(event);
+ local_dec(&event->ctx->nr_pending);
}

if (rctx >= 0)
perf_swevent_put_recursion_context(rctx);
+ preempt_enable_notrace();
}

#ifdef CONFIG_GUEST_PERF_EVENTS

I'm throwing more WARN_ON()s at it to see what's going on...