linux-kernel - [Syzkaller & bisect] There is "register_kprobe" WARNING in v6.2-rc3 mainline kernel

lists.openwall.net		lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC
Open Source and information security mailing list archives
Hash Suite: Windows password security audit tool. GUI, reports in PDF.
[<prev] [next>] [thread-next>] [day] [month] [year] [list]
Date:   Mon, 16 Jan 2023 16:57:24 +0800
From:   Pengfei Xu <pengfei.xu@...el.com>
To:     <mhiramat@...nel.org>, <linux-kernel@...r.kernel.org>
CC:     <peterz@...radead.org>, <heng.su@...el.com>, <pengfei.xu@...el.com>
Subject: [Syzkaller & bisect] There is "register_kprobe" WARNING in v6.2-rc3
 mainline kernel

Hi Masami Hiramatsu,

There is "register_kprobe" WARNING in v6.2-rc3 in guest.
[  120.736243] ------------[ cut here ]------------
[  120.736691] WARNING: CPU: 0 PID: 366 at kernel/kprobes.c:589 kprobe_optimizer+0x26b/0x400
[  120.737161] Modules linked in:
[  120.737339] CPU: 0 PID: 366 Comm: kworker/0:7 Not tainted 6.2.0-rc3-b7bfaa761d76 #1
[  120.737831] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.14.0-0-g155821a1990b-prebuilt.qemu.org 04/01/2014
[  120.738416] Workqueue: events kprobe_optimizer
[  120.738683] RIP: 0010:kprobe_optimizer+0x26b/0x400
[  120.739026] Code: c3 ff ff 4c 8b 25 25 28 b5 02 4d 8b 2c 24 49 8d 5c 24 80 4d 8d 75 80 49 81 fc f0 7e e1 83 75 2f e9 a9 00 00 00 e8 75 c3 ff ff <0f> 0b e8 6e c
[  120.740035] RSP: 0018:ffffc90000ebfe10 EFLAGS: 00010246
[  120.740394] RAX: 0000000000000000 RBX: ffff88800d094180 RCX: ffffffff812c5752
[  120.740763] RDX: 0000000000000000 RSI: ffff88800eed8000 RDI: 0000000000000002
[  120.741129] RBP: ffffc90000ebfe38 R08: 0000000000000001 R09: 0000000000000001
[  120.741552] R10: 0000000000000000 R11: 0000000000000001 R12: 0000000000000000
[  120.741953] R13: ffffffff83e17ef0 R14: ffffffff83e17e70 R15: ffff88807dc3a400
[  120.742319] FS:  0000000000000000(0000) GS:ffff88807dc00000(0000) knlGS:0000000000000000
[  120.742778] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  120.743125] CR2: 00007ffff951d3f8 CR3: 00000000131bc006 CR4: 0000000000770ef0
[  120.743503] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[  120.743868] DR3: 0000000000000000 DR6: 00000000ffff07f0 DR7: 0000000000000400
[  120.744339] PKRU: 55555554
[  120.744495] Call Trace:
[  120.744633]  <TASK>
[  120.744764]  process_one_work+0x3b1/0x960
[  120.745002]  worker_thread+0x52/0x660
[  120.745228]  ? __pfx_worker_thread+0x10/0x10
[  120.745536]  kthread+0x161/0x1a0
[  120.745748]  ? __pfx_kthread+0x10/0x10
[  120.745968]  ret_from_fork+0x29/0x50
[  120.746192]  </TASK>
[  120.746321] irq event stamp: 71069
[  120.746523] hardirqs last  enabled at (71077): [<ffffffff811d4891>] __up_console_sem+0x91/0xb0
[  120.747078] hardirqs last disabled at (71084): [<ffffffff811d4876>] __up_console_sem+0x76/0xb0
[  120.747529] softirqs last  enabled at (70986): [<ffffffff82f9d213>] __do_softirq+0x323/0x48a
[  120.748051] softirqs last disabled at (71101): [<ffffffff81123142>] irq_exit_rcu+0xd2/0x100
[  120.748562] ---[ end trace 0000000000000000 ]---
[  149.825325] ------------[ cut here ]------------
[  149.825894] WARNING: CPU: 0 PID: 2872 at kernel/kprobes.c:777 register_kprobe+0x9a2/0x9b0
[  149.826370] Modules linked in:
[  149.826548] CPU: 0 PID: 2872 Comm: repro Tainted: G        W          6.2.0-rc3-b7bfaa761d76 #1
[  149.827010] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.14.0-0-g155821a1990b-prebuilt.qemu.org 04/01/2014
[  149.827602] RIP: 0010:register_kprobe+0x9a2/0x9b0
[  149.827874] Code: 4d 89 74 24 08 e8 de 91 ff ff 45 89 ec 48 b8 22 01 00 00 00 00 ad de 48 89 43 08 e8 48 e4 f3 ff e9 d2 fd ff ff e8 be 91 ff ff <0f> 0b e9 4e 0
[  149.828872] RSP: 0018:ffffc90001aafc40 EFLAGS: 00010246
[  149.829162] RAX: 0000000000000000 RBX: ffff88800cefeb18 RCX: ffffffff812c86ba
[  149.829541] RDX: 0000000000000000 RSI: ffff88801324a340 RDI: 0000000000000002
[  149.829924] RBP: ffffc90001aafc88 R08: 0000000000000001 R09: 0000000000000001
[  149.830311] R10: ffffc90001aafc30 R11: 0000000000000001 R12: 0000000000000000
[  149.830697] R13: ffff88800d0949c0 R14: ffff88800cefeb28 R15: 0000000000000002
[  149.831089] FS:  00007fdc0d3c9740(0000) GS:ffff88807dc00000(0000) knlGS:0000000000000000
[  149.831525] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  149.831844] CR2: 00007fdc0d5841d3 CR3: 000000000d70c006 CR4: 0000000000770ef0
[  149.832260] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[  149.832637] DR3: 0000000000000000 DR6: 00000000ffff07f0 DR7: 0000000000000400
[  149.833021] PKRU: 55555554
[  149.833179] Call Trace:
[  149.833323]  <TASK>
[  149.833458]  ? knl_uncore_pci_init+0x9/0x90
[  149.833712]  ? knl_uncore_pci_init+0x9/0x90
[  149.833959]  __register_trace_kprobe+0x183/0x190
[  149.834241]  create_local_trace_kprobe+0x107/0x190
[  149.834519]  perf_kprobe_init+0xa7/0x160
[  149.834753]  perf_kprobe_event_init+0x98/0x120
[  149.835024]  perf_try_init_event+0x88/0x280
[  149.835274]  perf_event_alloc+0xf0a/0x1c50
[  149.835514]  ? __do_sys_perf_event_open+0x9ca/0x1870
[  149.835805]  ? __this_cpu_preempt_check+0x20/0x30
[  149.836102]  __do_sys_perf_event_open+0x3b6/0x1870
[  149.836388]  ? knl_uncore_pci_init+0x9/0x90
[  149.836636]  __x64_sys_perf_event_open+0x2f/0x40
[  149.836905]  do_syscall_64+0x3b/0x90
[  149.837115]  entry_SYSCALL_64_after_hwframe+0x72/0xdc
[  149.837417] RIP: 0033:0x7fdc0d4ee59d
[  149.837630] Code: 00 c3 66 2e 0f 1f 84 00 00 00 00 00 90 f3 0f 1e fa 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 8
[  149.838602] RSP: 002b:00007ffff951d3f8 EFLAGS: 00000246 ORIG_RAX: 000000000000012a
[  149.839036] RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 00007fdc0d4ee59d
[  149.839420] RDX: 0000000000000000 RSI: 0000000000000000 RDI: 00000000200002c0
[  149.839800] RBP: 00007ffff951d410 R08: 0000000000000000 R09: 00007ffff951d410
[  149.840203] R10: 00000000ffffffff R11: 0000000000000246 R12: 00000000004011a0
[  149.840593] R13: 00007ffff951d530 R14: 0000000000000000 R15: 0000000000000000
[  149.840984]  </TASK>
[  149.841120] irq event stamp: 1631
[  149.841303] hardirqs last  enabled at (1639): [<ffffffff811d4891>] __up_console_sem+0x91/0xb0
[  149.841825] hardirqs last disabled at (1646): [<ffffffff811d4876>] __up_console_sem+0x76/0xb0
[  149.842279] softirqs last  enabled at (1304): [<ffffffff82f9d213>] __do_softirq+0x323/0x48a
[  149.842723] softirqs last disabled at (1295): [<ffffffff81123142>] irq_exit_rcu+0xd2/0x100
[  149.843179] ---[ end trace 0000000000000000 ]---

Bisect and found that bad commit is:
63dc6325ff41ee9e570bde705ac34a39c5dbeb44
x86/kprobes: Fix optprobe optimization check with CONFIG_RETHUNK

After reverted the above commit on top of v6.2-rc3 kernel, this issue was gone.

The reproduced code, kconfig, bisect info, and v6.2-rc3 reproduced log are in
attached email.

And all the detailed logs are in link:
https://github.com/xupengfe/syzkaller_logs/tree/main/230113_100005_register_kprobe

I hope it's helpful.

Thanks!
BR.

View attachment "repro.c" of type "text/plain" (10679 bytes)

View attachment "bisect_info.log" of type "text/plain" (5572 bytes)

View attachment "kconfig" of type "text/plain" (279042 bytes)

View attachment "b7bfaa761d760e72a969d116517eaa12e404c262_dmesg.log" of type "text/plain" (46729 bytes)