Re: [PATCH] perf: Fix missing SIGTRAPs

[Marco Elver <elver@google.com>]

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...