WARNING at arch/x86/kernel/alternative.c:707 text_poke+0x25d/0x270

From: Steven Rostedt <rostedt@goodmis.org>
To: Masami Hiramatsu <mhiramat@kernel.org>
Cc: LKML <linux-kernel@vger.kernel.org>,
	Thomas Gleixner <tglx@linutronix.de>
Subject: WARNING at arch/x86/kernel/alternative.c:707 text_poke+0x25d/0x270
Date: Tue, 16 May 2017 09:48:02 -0400	[thread overview]
Message-ID: <20170516094802.76a468bb@gandalf.local.home> (raw)

Hi Masami,

Thomas hit the following bug:

[  169.795937] trace_kprobe: Testing kprobe tracing: OK
[  169.833031] rtc_cmos 00:00: setting system clock to 2017-05-16 13:19:26 UTC (1494940766)
[  169.833986] PM: Hibernation image not present or could not be loaded.
[  169.836222] Freeing unused kernel memory: 1376K
[  169.836793] ------------[ cut here ]------------
[  169.836802] WARNING: CPU: 1 PID: 240 at /home/tglx/work/kernel/linus/linux/arch/x86/kernel/alternative.c:707 text_poke+0x25d/0x270
[  169.836803] Modules linked in:
[  169.836806] CPU: 1 PID: 240 Comm: kworker/1:1 Not tainted 4.12.0-rc1+ #138
[  169.836808] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
[  169.836812] Workqueue: events kprobe_optimizer
[  169.836819] task: ffff8802344e28c0 task.stack: ffffc90001cac000
[  169.836821] RIP: 0010:text_poke+0x25d/0x270
[  169.836822] RSP: 0000:ffffc90001cafd38 EFLAGS: 00010246
[  169.836825] RAX: 0100000000000000 RBX: ffffffff81d9daeb RCX: ffffffffa0008000
[  169.836826] RDX: 0000000000000000 RSI: ffffc90001cafd87 RDI: ffffffff81d9daeb
[  169.836827] RBP: ffffc90001cafd70 R08: 0000000000000001 R09: 0000000000000000
[  169.836828] R10: ffffc90001cafe08 R11: 0000000000000008 R12: 0000000000000001
[  169.836829] R13: ffffc90001cafd87 R14: ffffffff81d9daec R15: ffffea0000067a58
[  169.836831] FS:  0000000000000000(0000) GS:ffff88023ec40000(0000) knlGS:0000000000000000
[  169.836832] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  169.836833] CR2: ffffc9000146c000 CR3: 0000000001c0f000 CR4: 00000000003406e0
[  169.836837] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[  169.836838] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[  169.836839] Call Trace:
[  169.836845]  ? init_kprobe_trace+0x96/0x96
[  169.836848]  ? kprobe_trace_selftest_target+0x1/0x13
[  169.836851]  text_poke_bp+0x57/0xf0
[  169.836857]  arch_unoptimize_kprobe+0x42/0x60
[  169.836860]  arch_unoptimize_kprobes+0x35/0x90
[  169.836865]  kprobe_optimizer+0x63/0x2a0
[  169.836870]  process_one_work+0x1ed/0x630
[  169.836877]  worker_thread+0x69/0x3c0
[  169.836884]  kthread+0x138/0x170
[  169.836886]  ? process_one_work+0x630/0x630
[  169.836888]  ? kthread_create_on_node+0x70/0x70
[  169.836893]  ret_from_fork+0x31/0x40
[  169.836903] Code: e8 f9 5d 35 00 31 d2 31 f6 bf 86 02 00 00 ff 15 2a fc a2 00 e9 3d ff ff ff 48 8b 7d c8 57 9d 0f 1f 44 00 00 e8 25 95 09 00 eb ad <0f> ff e9 12 fe ff ff 66 66 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 
[  169.836955] ---[ end trace 3d393a48ed109eb0 ]---
[  169.837103] ------------[ cut here ]------------

It appears that the kprobe_optimizer work thread call happened after
the init pages were freed, causing alternative.c to give the above
warning because the text that is being unoptimized happens to no longer
exist.

This doesn't always happen, but it may have been something that's been
there for a while. Can you take a look at it, and perhaps find a way to
flush the work queue before exiting the kprobe test?

Thanks!

-- Steve