LKML Archive on lore.kernel.org
help / color / mirror / Atom feed
* Oops caused by race between livepatch and ftrace
@ 2019-05-20 19:49 Johannes Erdfelt
  2019-05-20 20:46 ` Joe Lawrence
  0 siblings, 1 reply; 20+ messages in thread
From: Johannes Erdfelt @ 2019-05-20 19:49 UTC (permalink / raw)
  To: Josh Poimboeuf, Jessica Yu, Jiri Kosina, Miroslav Benes,
	Steven Rostedt, Ingo Molnar, live-patching, linux-kernel

There exists a race condition between livepatch and ftrace that can
cause an oops similar to this one:

  BUG: unable to handle page fault for address: ffffffffc005b1d9
  #PF: supervisor write access in kernel mode
  #PF: error_code(0x0003) - permissions violation
  PGD 3ea0c067 P4D 3ea0c067 PUD 3ea0e067 PMD 3cc13067 PTE 3b8a1061
  Oops: 0003 [#1] PREEMPT SMP PTI
  CPU: 1 PID: 453 Comm: insmod Tainted: G           O  K   5.2.0-rc1-a188339ca5 #1
  Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.12.0-20181126_142135-anatol 04/01/2014
  RIP: 0010:apply_relocate_add+0xbe/0x14c
  Code: fa 0b 74 21 48 83 fa 18 74 38 48 83 fa 0a 75 40 eb 08 48 83 38 00 74 33 eb 53 83 38 00 75 4e 89 08 89 c8 eb 0a 83 38 00 75 43 <89> 08 48 63 c1 48 39 c8 74 2e eb 48 83 38 00 75 32 48 29 c1 89 08
  RSP: 0018:ffffb223c00dbb10 EFLAGS: 00010246
  RAX: ffffffffc005b1d9 RBX: 0000000000000000 RCX: ffffffff8b200060
  RDX: 000000000000000b RSI: 0000004b0000000b RDI: ffff96bdfcd33000
  RBP: ffffb223c00dbb38 R08: ffffffffc005d040 R09: ffffffffc005c1f0
  R10: ffff96bdfcd33c40 R11: ffff96bdfcd33b80 R12: 0000000000000018
  R13: ffffffffc005c1f0 R14: ffffffffc005e708 R15: ffffffff8b2fbc74
  FS:  00007f5f447beba8(0000) GS:ffff96bdff900000(0000) knlGS:0000000000000000
  CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
  CR2: ffffffffc005b1d9 CR3: 000000003cedc002 CR4: 0000000000360ea0
  DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
  DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
  Call Trace:
   klp_init_object_loaded+0x10f/0x219
   ? preempt_latency_start+0x21/0x57
   klp_enable_patch+0x662/0x809
   ? virt_to_head_page+0x3a/0x3c
   ? kfree+0x8c/0x126
   patch_init+0x2ed/0x1000 [livepatch_test02]
   ? 0xffffffffc0060000
   do_one_initcall+0x9f/0x1c5
   ? kmem_cache_alloc_trace+0xc4/0xd4
   ? do_init_module+0x27/0x210
   do_init_module+0x5f/0x210
   load_module+0x1c41/0x2290
   ? fsnotify_path+0x3b/0x42
   ? strstarts+0x2b/0x2b
   ? kernel_read+0x58/0x65
   __do_sys_finit_module+0x9f/0xc3
   ? __do_sys_finit_module+0x9f/0xc3
   __x64_sys_finit_module+0x1a/0x1c
   do_syscall_64+0x52/0x61
   entry_SYSCALL_64_after_hwframe+0x44/0xa9
  RIP: 0033:0x7f5f44764881
  Code: 0e 4c 8b 44 24 10 4d 8d 48 08 4c 89 4c 24 10 44 8b 4c 24 08 4d 8b 00 4c 01 c9 41 83 f9 2f 76 05 48 8b 4c 24 10 4c 8b 09 0f 05 <48> 89 c7 e8 f7 e9 fd ff 48 83 c4 58 c3 56 31 d2 be 02 00 08 00 bf
  RSP: 002b:00007ffcf1e64b80 EFLAGS: 00000212 ORIG_RAX: 0000000000000139
  RAX: ffffffffffffffda RBX: 00000000006229a0 RCX: 00007f5f44764881
  RDX: 0000000000000000 RSI: 000000000041a506 RDI: 0000000000000003
  RBP: 000000000041a506 R08: 0000000000000000 R09: 00007ffcf1e64c48
  R10: 0000000000000003 R11: 0000000000000212 R12: 0000000000000000
  R13: 00000000006228c0 R14: 0000000000000000 R15: 0000000000000000
  Modules linked in: livepatch_test03(OK+) livepatch_test01(OK+) livepatch_test11(OK+) livepatch_test06(OK+) livepatch_test04(OK+) livepatch_test02(OK+) livepatch_test10(OK+) livepatch_test16(OK+) livepatch_test18(OK-) livepatch_test12(OK)
  CR2: ffffffffc005b1d9
  ---[ end trace 52fee0aa635dd5a1 ]---

The oops occurs because both livepatch and ftrace remap the module text
section at the same. After ftrace is done, it can leave the module text
text section mapped RO when the livepatch code is expecting it to be RW.

CPU A			CPU B
--------		--------
			set_all_modules_text_rw		(module is now RW)
module_disable_ro					(module is still RW)
			set_all_modules_text_ro		(module is now RO)
apply_relocate_add					(oops)

I've reproduced it from the latest code in git (a188339ca5a3), 5.0.17,
4.19.44, 4.14.120, 4.9.177 and some kernels in between. I haven't tried
reproducing on any kernel older than 4.9. From looking at the older
versions in git, it will likely be harder to reproduce since the kernel
switched in 4.5 to remapping RW once from remapping on every write.

The oops will only occur if CONFIG_STRICT_MODULE_RWX is enabled
(previously called CONFIG_DEBUG_SET_MODULE_RONX).

I've found two ways the race condition can be reproduced:
1) loading multiple livepatches at the same time
2) loading a livepatch at the same time ftrace is patching code

They are both ultimately the same root cause since livepatch uses ftrace
to perform the patching.

I have put together a test case that can reproduce the crash using
KVM. The tarball includes a minimal kernel and initramfs, along with
a script to run qemu and the .config used to build the kernel. By
default it will attempt to reproduce by loading multiple livepatches
at the same time. Passing 'test=ftrace' to the script will attempt to
reproduce by racing with ftrace.

My test setup reproduces the race and oops more reliably by loading
multiple livepatches at the same time than with the ftrace method. It's
not 100% reproducible, so the test case may need to be run multiple
times.

It can be found here (not attached because of its size):
http://johannes.erdfelt.com/5.2.0-rc1-a188339ca5-livepatch-race.tar.gz

The simple patch of extending the module_mutex lock over the entirety
of klp_init_object_loaded fixes it from the livepatch side. This
mostly works because set_all_modules_text_{rw,ro} acquires module_mutex
as well, but it still leaves a hole in the ftrace code. A lock should
probably be held over the entirety of remapping the text sections RW.

This is complicated by the fact that remapping the text section in
ftrace is handled by arch specific code. I'm not sure what a good
solution to this is yet.

JE


^ permalink raw reply	[flat|nested] 20+ messages in thread

* Re: Oops caused by race between livepatch and ftrace
  2019-05-20 19:49 Oops caused by race between livepatch and ftrace Johannes Erdfelt
@ 2019-05-20 20:46 ` Joe Lawrence
  2019-05-20 21:09   ` Johannes Erdfelt
  0 siblings, 1 reply; 20+ messages in thread
From: Joe Lawrence @ 2019-05-20 20:46 UTC (permalink / raw)
  To: Johannes Erdfelt, Josh Poimboeuf, Jessica Yu, Jiri Kosina,
	Miroslav Benes, Steven Rostedt, Ingo Molnar, live-patching,
	linux-kernel

[ fixed jeyu's email address ]

On 5/20/19 3:49 PM, Johannes Erdfelt wrote:
> [ ... snip ... ]
> 
> I have put together a test case that can reproduce the crash using
> KVM. The tarball includes a minimal kernel and initramfs, along with
> a script to run qemu and the .config used to build the kernel. By
> default it will attempt to reproduce by loading multiple livepatches
> at the same time. Passing 'test=ftrace' to the script will attempt to
> reproduce by racing with ftrace.
> 
> My test setup reproduces the race and oops more reliably by loading
> multiple livepatches at the same time than with the ftrace method. It's
> not 100% reproducible, so the test case may need to be run multiple
> times.
> 
> It can be found here (not attached because of its size):
> http://johannes.erdfelt.com/5.2.0-rc1-a188339ca5-livepatch-race.tar.gz

Hi Johannes,

This is cool way to distribute the repro kernel, modules, etc!

These two testing scenarios might be interesting to add to our selftests 
suite.  Can you post or add the source(s) to livepatch-test<n>.ko to the 
tarball?

> The simple patch of extending the module_mutex lock over the entirety
> of klp_init_object_loaded fixes it from the livepatch side. This
> mostly works because set_all_modules_text_{rw,ro} acquires module_mutex
> as well, but it still leaves a hole in the ftrace code. A lock should
> probably be held over the entirety of remapping the text sections RW.
> 
> This is complicated by the fact that remapping the text section in
> ftrace is handled by arch specific code. I'm not sure what a good
> solution to this is yet.

A lock or some kind of referencing count..  I'll let other folks comment 
on that side of the bug report.

Thanks,

-- Joe

^ permalink raw reply	[flat|nested] 20+ messages in thread

* Re: Oops caused by race between livepatch and ftrace
  2019-05-20 20:46 ` Joe Lawrence
@ 2019-05-20 21:09   ` Johannes Erdfelt
  2019-05-20 21:19     ` Josh Poimboeuf
  2019-05-20 21:19     ` Joe Lawrence
  0 siblings, 2 replies; 20+ messages in thread
From: Johannes Erdfelt @ 2019-05-20 21:09 UTC (permalink / raw)
  To: Joe Lawrence
  Cc: Josh Poimboeuf, Jessica Yu, Jiri Kosina, Miroslav Benes,
	Steven Rostedt, Ingo Molnar, live-patching, linux-kernel

On Mon, May 20, 2019, Joe Lawrence <joe.lawrence@redhat.com> wrote:
> [ fixed jeyu's email address ]

Thank you, the bounce message made it seem like my mail server was
blocked and not that the address didn't exist.

I think MAINTAINERS needs an update since it still has the @redhat.com
address.

> On 5/20/19 3:49 PM, Johannes Erdfelt wrote:
> > [ ... snip ... ]
> > 
> > I have put together a test case that can reproduce the crash using
> > KVM. The tarball includes a minimal kernel and initramfs, along with
> > a script to run qemu and the .config used to build the kernel. By
> > default it will attempt to reproduce by loading multiple livepatches
> > at the same time. Passing 'test=ftrace' to the script will attempt to
> > reproduce by racing with ftrace.
> > 
> > My test setup reproduces the race and oops more reliably by loading
> > multiple livepatches at the same time than with the ftrace method. It's
> > not 100% reproducible, so the test case may need to be run multiple
> > times.
> > 
> > It can be found here (not attached because of its size):
> > http://johannes.erdfelt.com/5.2.0-rc1-a188339ca5-livepatch-race.tar.gz
> 
> Hi Johannes,
> 
> This is cool way to distribute the repro kernel, modules, etc!

This oops was common in our production environment and was particularly
annoying since livepatches would load at boot and early enough to happen
before networking and SSH were started.

Unfortunately it was difficult to reproduce on other hardware (changing
the timing just enough) and our production environment is very
complicated.

I spent more time than I'd like to admit trying to reproduce this fairly
reliably. I knew that I needed to help make it as easy as possible to
reproduce to root cause it and for others to take a look at it as well.

> These two testing scenarios might be interesting to add to our selftests
> suite.  Can you post or add the source(s) to livepatch-test<n>.ko to the
> tarball?

I made the livepatches using kpatch-build and this simple patch:

diff --git a/fs/proc/version.c b/fs/proc/version.c
index 94901e8e700d..6b8a3449f455 100644
--- a/fs/proc/version.c
+++ b/fs/proc/version.c
@@ -12,6 +12,7 @@ static int version_proc_show(struct seq_file *m, void *v)
 		utsname()->sysname,
 		utsname()->release,
 		utsname()->version);
+	seq_printf(m, "example livepatch\n");
 	return 0;
 }

I just created enough livepatches with the same source patch so that I
could reproduce the issue somewhat reliably.

I'll see if I can make something that uses klp directly.

The rest of the userspace in the initramfs is really straight forward
with the only interesting parts being a couple of shell scripts.

JE
 

^ permalink raw reply	[flat|nested] 20+ messages in thread

* Re: Oops caused by race between livepatch and ftrace
  2019-05-20 21:09   ` Johannes Erdfelt
@ 2019-05-20 21:19     ` Josh Poimboeuf
  2019-05-20 21:39       ` Steven Rostedt
  2019-05-20 21:48       ` Johannes Erdfelt
  2019-05-20 21:19     ` Joe Lawrence
  1 sibling, 2 replies; 20+ messages in thread
From: Josh Poimboeuf @ 2019-05-20 21:19 UTC (permalink / raw)
  To: Johannes Erdfelt
  Cc: Joe Lawrence, Jessica Yu, Jiri Kosina, Miroslav Benes,
	Steven Rostedt, Ingo Molnar, live-patching, linux-kernel

On Mon, May 20, 2019 at 02:09:05PM -0700, Johannes Erdfelt wrote:
> On Mon, May 20, 2019, Joe Lawrence <joe.lawrence@redhat.com> wrote:
> > [ fixed jeyu's email address ]
> 
> Thank you, the bounce message made it seem like my mail server was
> blocked and not that the address didn't exist.
> 
> I think MAINTAINERS needs an update since it still has the @redhat.com
> address.

I think you must have been looking at an old version.

[(v5.2-rc1)] ~/git/linux $ grep jeyu MAINTAINERS
M:	Jessica Yu <jeyu@kernel.org>

> > On 5/20/19 3:49 PM, Johannes Erdfelt wrote:
> > > [ ... snip ... ]
> > > 
> > > I have put together a test case that can reproduce the crash using
> > > KVM. The tarball includes a minimal kernel and initramfs, along with
> > > a script to run qemu and the .config used to build the kernel. By
> > > default it will attempt to reproduce by loading multiple livepatches
> > > at the same time. Passing 'test=ftrace' to the script will attempt to
> > > reproduce by racing with ftrace.
> > > 
> > > My test setup reproduces the race and oops more reliably by loading
> > > multiple livepatches at the same time than with the ftrace method. It's
> > > not 100% reproducible, so the test case may need to be run multiple
> > > times.
> > > 
> > > It can be found here (not attached because of its size):
> > > http://johannes.erdfelt.com/5.2.0-rc1-a188339ca5-livepatch-race.tar.gz
> > 
> > Hi Johannes,
> > 
> > This is cool way to distribute the repro kernel, modules, etc!
> 
> This oops was common in our production environment and was particularly
> annoying since livepatches would load at boot and early enough to happen
> before networking and SSH were started.
> 
> Unfortunately it was difficult to reproduce on other hardware (changing
> the timing just enough) and our production environment is very
> complicated.
> 
> I spent more time than I'd like to admit trying to reproduce this fairly
> reliably. I knew that I needed to help make it as easy as possible to
> reproduce to root cause it and for others to take a look at it as well.

Can you try this patch (completely untested)?

diff --git a/kernel/livepatch/core.c b/kernel/livepatch/core.c
index 91cd519756d3..2d17e6e364b5 100644
--- a/kernel/livepatch/core.c
+++ b/kernel/livepatch/core.c
@@ -30,6 +30,7 @@
 #include <linux/elf.h>
 #include <linux/moduleloader.h>
 #include <linux/completion.h>
+#include <linux/memory.h>
 #include <asm/cacheflush.h>
 #include "core.h"
 #include "patch.h"
@@ -730,16 +731,21 @@ static int klp_init_object_loaded(struct klp_patch *patch,
 	struct klp_func *func;
 	int ret;
 
+	mutex_lock(&text_mutex);
+
 	module_disable_ro(patch->mod);
 	ret = klp_write_object_relocations(patch->mod, obj);
 	if (ret) {
 		module_enable_ro(patch->mod, true);
+		mutex_unlock(&text_mutex);
 		return ret;
 	}
 
 	arch_klp_init_object_loaded(patch, obj);
 	module_enable_ro(patch->mod, true);
 
+	mutex_unlock(&text_mutex);
+
 	klp_for_each_func(obj, func) {
 		ret = klp_find_object_symbol(obj->name, func->old_name,
 					     func->old_sympos,
diff --git a/kernel/trace/ftrace.c b/kernel/trace/ftrace.c
index a12aff849c04..8259d4ba8b00 100644
--- a/kernel/trace/ftrace.c
+++ b/kernel/trace/ftrace.c
@@ -34,6 +34,7 @@
 #include <linux/hash.h>
 #include <linux/rcupdate.h>
 #include <linux/kprobes.h>
+#include <linux/memory.h>
 
 #include <trace/events/sched.h>
 
@@ -2610,10 +2611,12 @@ static void ftrace_run_update_code(int command)
 {
 	int ret;
 
+	mutex_lock(&text_mutex);
+
 	ret = ftrace_arch_code_modify_prepare();
 	FTRACE_WARN_ON(ret);
 	if (ret)
-		return;
+		goto out_unlock;
 
 	/*
 	 * By default we use stop_machine() to modify the code.
@@ -2625,6 +2628,9 @@ static void ftrace_run_update_code(int command)
 
 	ret = ftrace_arch_code_modify_post_process();
 	FTRACE_WARN_ON(ret);
+
+out_unlock:
+	mutex_unlock(&text_mutex);
 }
 
 static void ftrace_run_modify_code(struct ftrace_ops *ops, int command,
@@ -5776,6 +5782,7 @@ void ftrace_module_enable(struct module *mod)
 	struct ftrace_page *pg;
 
 	mutex_lock(&ftrace_lock);
+	mutex_lock(&text_mutex);
 
 	if (ftrace_disabled)
 		goto out_unlock;
@@ -5837,6 +5844,7 @@ void ftrace_module_enable(struct module *mod)
 		ftrace_arch_code_modify_post_process();
 
  out_unlock:
+	mutex_unlock(&text_mutex);
 	mutex_unlock(&ftrace_lock);
 
 	process_cached_mods(mod->name);

^ permalink raw reply	[flat|nested] 20+ messages in thread

* Re: Oops caused by race between livepatch and ftrace
  2019-05-20 21:09   ` Johannes Erdfelt
  2019-05-20 21:19     ` Josh Poimboeuf
@ 2019-05-20 21:19     ` Joe Lawrence
  2019-05-21 19:27       ` Joe Lawrence
  1 sibling, 1 reply; 20+ messages in thread
From: Joe Lawrence @ 2019-05-20 21:19 UTC (permalink / raw)
  To: Johannes Erdfelt
  Cc: Josh Poimboeuf, Jessica Yu, Jiri Kosina, Miroslav Benes,
	Steven Rostedt, Ingo Molnar, live-patching, linux-kernel

On 5/20/19 5:09 PM, Johannes Erdfelt wrote:
> On Mon, May 20, 2019, Joe Lawrence <joe.lawrence@redhat.com> wrote:
>> [ fixed jeyu's email address ]
> 
> Thank you, the bounce message made it seem like my mail server was
> blocked and not that the address didn't exist.
> 
> I think MAINTAINERS needs an update since it still has the @redhat.com
> address.
> 

Here's how it looks on my end:

% git describe HEAD
v5.1-12317-ga6a4b66bd8f4

% grep M:.*jeyu MAINTAINERS
M:      Jessica Yu <jeyu@kernel.org>

>> On 5/20/19 3:49 PM, Johannes Erdfelt wrote:
>>> [ ... snip ... ]
>>>
>>> I have put together a test case that can reproduce the crash using
>>> KVM. The tarball includes a minimal kernel and initramfs, along with
>>> a script to run qemu and the .config used to build the kernel. By
>>> default it will attempt to reproduce by loading multiple livepatches
>>> at the same time. Passing 'test=ftrace' to the script will attempt to
>>> reproduce by racing with ftrace.
>>>
>>> My test setup reproduces the race and oops more reliably by loading
>>> multiple livepatches at the same time than with the ftrace method. It's
>>> not 100% reproducible, so the test case may need to be run multiple
>>> times.
>>>
>>> It can be found here (not attached because of its size):
>>> http://johannes.erdfelt.com/5.2.0-rc1-a188339ca5-livepatch-race.tar.gz
>>
>> Hi Johannes,
>>
>> This is cool way to distribute the repro kernel, modules, etc!
> 
> This oops was common in our production environment and was particularly
> annoying since livepatches would load at boot and early enough to happen
> before networking and SSH were started.
> 
> Unfortunately it was difficult to reproduce on other hardware (changing
> the timing just enough) and our production environment is very
> complicated.
> 
> I spent more time than I'd like to admit trying to reproduce this fairly
> reliably. I knew that I needed to help make it as easy as possible to
> reproduce to root cause it and for others to take a look at it as well.
> 

Thanks for building this test image -- it repro'd on the first try for me.

Hmmm, I wonder then how reproducible it would be if we simply extracted 
the .ko's and test scripts from out of your initramfs and ran it on 
arbitrary machines.

I think the rcutorture self-tests use qemu/kvm to fire up test VMs, but 
I dunno if livepatch self-tests are ready for level of sophistication 
yet :)  Will need to think on that a bit.

>> These two testing scenarios might be interesting to add to our selftests
>> suite.  Can you post or add the source(s) to livepatch-test<n>.ko to the
>> tarball?
> 
> I made the livepatches using kpatch-build and this simple patch:
> 
> diff --git a/fs/proc/version.c b/fs/proc/version.c
> index 94901e8e700d..6b8a3449f455 100644
> --- a/fs/proc/version.c
> +++ b/fs/proc/version.c
> @@ -12,6 +12,7 @@ static int version_proc_show(struct seq_file *m, void *v)
>   		utsname()->sysname,
>   		utsname()->release,
>   		utsname()->version);
> +	seq_printf(m, "example livepatch\n");
>   	return 0;
>   }
> 
> I just created enough livepatches with the same source patch so that I
> could reproduce the issue somewhat reliably.
> 
> I'll see if I can make something that uses klp directly.

Ah ok great, I was hoping it was a relatively simply livepatch.  We 
could probably reuse lib/livepatch/test_klp_livepatch.c to do this 
(patching cmdline_proc_show instead).

> The rest of the userspace in the initramfs is really straight forward
> with the only interesting parts being a couple of shell scripts.

Yup.  I'll be on PTO later this week, but I'll see about extracting the 
scripts and building a pile of livepatch .ko's to see how easily it 
reproduces without qemu.

Thanks,

-- Joe

^ permalink raw reply	[flat|nested] 20+ messages in thread

* Re: Oops caused by race between livepatch and ftrace
  2019-05-20 21:19     ` Josh Poimboeuf
@ 2019-05-20 21:39       ` Steven Rostedt
  2019-05-21 14:16         ` Josh Poimboeuf
  2019-05-20 21:48       ` Johannes Erdfelt
  1 sibling, 1 reply; 20+ messages in thread
From: Steven Rostedt @ 2019-05-20 21:39 UTC (permalink / raw)
  To: Josh Poimboeuf
  Cc: Johannes Erdfelt, Joe Lawrence, Jessica Yu, Jiri Kosina,
	Miroslav Benes, Ingo Molnar, live-patching, linux-kernel

On Mon, 20 May 2019 16:19:31 -0500
Josh Poimboeuf <jpoimboe@redhat.com> wrote:

> diff --git a/kernel/trace/ftrace.c b/kernel/trace/ftrace.c
> index a12aff849c04..8259d4ba8b00 100644
> --- a/kernel/trace/ftrace.c
> +++ b/kernel/trace/ftrace.c
> @@ -34,6 +34,7 @@
>  #include <linux/hash.h>
>  #include <linux/rcupdate.h>
>  #include <linux/kprobes.h>
> +#include <linux/memory.h>
>  
>  #include <trace/events/sched.h>
>  
> @@ -2610,10 +2611,12 @@ static void ftrace_run_update_code(int command)
>  {
>  	int ret;
>  
> +	mutex_lock(&text_mutex);
> +

Hmm, this may blow up with lockdep, as I believe we already have a
locking dependency of:

 text_mutex -> ftrace_lock

And this will reverses it. (kprobes appears to take the locks in this
order).

Perhaps have live kernel patching grab ftrace_lock?

-- Steve


>  	ret = ftrace_arch_code_modify_prepare();
>  	FTRACE_WARN_ON(ret);
>  	if (ret)
> -		return;
> +		goto out_unlock;
>  
>  	/*
>  	 * By default we use stop_machine() to modify the code.
> @@ -2625,6 +2628,9 @@ static void ftrace_run_update_code(int command)
>  
>  	ret = ftrace_arch_code_modify_post_process();
>  	FTRACE_WARN_ON(ret);
> +
> +out_unlock:
> +	mutex_unlock(&text_mutex);
>  }
>  
>  static void ftrace_run_modify_code(struct ftrace_ops *ops, int command,
> @@ -5776,6 +5782,7 @@ void ftrace_module_enable(struct module *mod)
>  	struct ftrace_page *pg;
>  
>  	mutex_lock(&ftrace_lock);
> +	mutex_lock(&text_mutex);
>  
>  	if (ftrace_disabled)
>  		goto out_unlock;
> @@ -5837,6 +5844,7 @@ void ftrace_module_enable(struct module *mod)
>  		ftrace_arch_code_modify_post_process();
>  
>   out_unlock:
> +	mutex_unlock(&text_mutex);
>  	mutex_unlock(&ftrace_lock);
>  
>  	process_cached_mods(mod->name);


^ permalink raw reply	[flat|nested] 20+ messages in thread

* Re: Oops caused by race between livepatch and ftrace
  2019-05-20 21:19     ` Josh Poimboeuf
  2019-05-20 21:39       ` Steven Rostedt
@ 2019-05-20 21:48       ` Johannes Erdfelt
  1 sibling, 0 replies; 20+ messages in thread
From: Johannes Erdfelt @ 2019-05-20 21:48 UTC (permalink / raw)
  To: Josh Poimboeuf
  Cc: Joe Lawrence, Jessica Yu, Jiri Kosina, Miroslav Benes,
	Steven Rostedt, Ingo Molnar, live-patching, linux-kernel

On Mon, May 20, 2019, Josh Poimboeuf <jpoimboe@redhat.com> wrote:
> I think you must have been looking at an old version.
> 
> [(v5.2-rc1)] ~/git/linux $ grep jeyu MAINTAINERS
> M:	Jessica Yu <jeyu@kernel.org>

Operator error on my part. I was looking at a different directory with
an old branch checked out. Sorry!

> Can you try this patch (completely untested)?

It seems to be working fine for me. No crashes in a loop for a few
minutes, when it would usually only take a couple of tries to reproduce
the issue for me.

I'll see if I can better reproduce the race from the ftrace side since
every crash I have seen for this issue has been in apply_relocate_add
on the livepatch side.

JE


^ permalink raw reply	[flat|nested] 20+ messages in thread

* Re: Oops caused by race between livepatch and ftrace
  2019-05-20 21:39       ` Steven Rostedt
@ 2019-05-21 14:16         ` Josh Poimboeuf
  2019-05-21 14:42           ` Steven Rostedt
  0 siblings, 1 reply; 20+ messages in thread
From: Josh Poimboeuf @ 2019-05-21 14:16 UTC (permalink / raw)
  To: Steven Rostedt
  Cc: Johannes Erdfelt, Joe Lawrence, Jessica Yu, Jiri Kosina,
	Miroslav Benes, Ingo Molnar, live-patching, linux-kernel

On Mon, May 20, 2019 at 05:39:10PM -0400, Steven Rostedt wrote:
> On Mon, 20 May 2019 16:19:31 -0500
> Josh Poimboeuf <jpoimboe@redhat.com> wrote:
> 
> > diff --git a/kernel/trace/ftrace.c b/kernel/trace/ftrace.c
> > index a12aff849c04..8259d4ba8b00 100644
> > --- a/kernel/trace/ftrace.c
> > +++ b/kernel/trace/ftrace.c
> > @@ -34,6 +34,7 @@
> >  #include <linux/hash.h>
> >  #include <linux/rcupdate.h>
> >  #include <linux/kprobes.h>
> > +#include <linux/memory.h>
> >  
> >  #include <trace/events/sched.h>
> >  
> > @@ -2610,10 +2611,12 @@ static void ftrace_run_update_code(int command)
> >  {
> >  	int ret;
> >  
> > +	mutex_lock(&text_mutex);
> > +
> 
> Hmm, this may blow up with lockdep, as I believe we already have a
> locking dependency of:
> 
>  text_mutex -> ftrace_lock
> 
> And this will reverses it. (kprobes appears to take the locks in this
> order).
> 
> Perhaps have live kernel patching grab ftrace_lock?

Where does kprobes call into ftrace with the text_mutex?  I couldn't
find it.

-- 
Josh

^ permalink raw reply	[flat|nested] 20+ messages in thread

* Re: Oops caused by race between livepatch and ftrace
  2019-05-21 14:16         ` Josh Poimboeuf
@ 2019-05-21 14:42           ` Steven Rostedt
  2019-05-21 16:42             ` Josh Poimboeuf
  0 siblings, 1 reply; 20+ messages in thread
From: Steven Rostedt @ 2019-05-21 14:42 UTC (permalink / raw)
  To: Josh Poimboeuf
  Cc: Johannes Erdfelt, Joe Lawrence, Jessica Yu, Jiri Kosina,
	Miroslav Benes, Ingo Molnar, live-patching, linux-kernel

On Tue, 21 May 2019 09:16:29 -0500
Josh Poimboeuf <jpoimboe@redhat.com> wrote:

> > Hmm, this may blow up with lockdep, as I believe we already have a
> > locking dependency of:
> > 
> >  text_mutex -> ftrace_lock
> > 
> > And this will reverses it. (kprobes appears to take the locks in this
> > order).
> > 
> > Perhaps have live kernel patching grab ftrace_lock?  
> 
> Where does kprobes call into ftrace with the text_mutex?  I couldn't
> find it.

Hmm, maybe it doesn't. I was looking at the arm_kprobe_ftrace() but
it doesn't call it with text_mutex().

Maybe it is fine, but we had better perform a lot of testing with
lockdep on to make sure.

-- Steve

^ permalink raw reply	[flat|nested] 20+ messages in thread

* Re: Oops caused by race between livepatch and ftrace
  2019-05-21 14:42           ` Steven Rostedt
@ 2019-05-21 16:42             ` Josh Poimboeuf
  2019-05-21 16:53               ` Steven Rostedt
                                 ` (2 more replies)
  0 siblings, 3 replies; 20+ messages in thread
From: Josh Poimboeuf @ 2019-05-21 16:42 UTC (permalink / raw)
  To: Steven Rostedt
  Cc: Johannes Erdfelt, Joe Lawrence, Jessica Yu, Jiri Kosina,
	Miroslav Benes, Ingo Molnar, live-patching, linux-kernel

On Tue, May 21, 2019 at 10:42:04AM -0400, Steven Rostedt wrote:
> On Tue, 21 May 2019 09:16:29 -0500
> Josh Poimboeuf <jpoimboe@redhat.com> wrote:
> 
> > > Hmm, this may blow up with lockdep, as I believe we already have a
> > > locking dependency of:
> > > 
> > >  text_mutex -> ftrace_lock
> > > 
> > > And this will reverses it. (kprobes appears to take the locks in this
> > > order).
> > > 
> > > Perhaps have live kernel patching grab ftrace_lock?  
> > 
> > Where does kprobes call into ftrace with the text_mutex?  I couldn't
> > find it.
> 
> Hmm, maybe it doesn't. I was looking at the arm_kprobe_ftrace() but
> it doesn't call it with text_mutex().
> 
> Maybe it is fine, but we had better perform a lot of testing with
> lockdep on to make sure.

Hm.  I suppose using ftrace_lock might be less risky since that lock is
only used internally by ftrace (up until now).  But I think it would
also make less sense because the text_mutex is supposed to protect code
patching.  And presumably ftrace_lock is supposed to be ftrace-specific.

Here's the latest patch, still using text_mutex.  I added some lockdep
assertions to ensure the permissions toggling functions are always
called with text_mutex.  It's running through 0-day right now.  I can
try to run it through various tests with CONFIG_LOCKDEP.


From: Josh Poimboeuf <jpoimboe@redhat.com>
Subject: [PATCH] livepatch: Fix ftrace module text permissions race

It's possible for livepatch and ftrace to be toggling a module's text
permissions at the same time, resulting in the following panic:

  BUG: unable to handle page fault for address: ffffffffc005b1d9
  #PF: supervisor write access in kernel mode
  #PF: error_code(0x0003) - permissions violation
  PGD 3ea0c067 P4D 3ea0c067 PUD 3ea0e067 PMD 3cc13067 PTE 3b8a1061
  Oops: 0003 [#1] PREEMPT SMP PTI
  CPU: 1 PID: 453 Comm: insmod Tainted: G           O  K   5.2.0-rc1-a188339ca5 #1
  Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.12.0-20181126_142135-anatol 04/01/2014
  RIP: 0010:apply_relocate_add+0xbe/0x14c
  Code: fa 0b 74 21 48 83 fa 18 74 38 48 83 fa 0a 75 40 eb 08 48 83 38 00 74 33 eb 53 83 38 00 75 4e 89 08 89 c8 eb 0a 83 38 00 75 43 <89> 08 48 63 c1 48 39 c8 74 2e eb 48 83 38 00 75 32 48 29 c1 89 08
  RSP: 0018:ffffb223c00dbb10 EFLAGS: 00010246
  RAX: ffffffffc005b1d9 RBX: 0000000000000000 RCX: ffffffff8b200060
  RDX: 000000000000000b RSI: 0000004b0000000b RDI: ffff96bdfcd33000
  RBP: ffffb223c00dbb38 R08: ffffffffc005d040 R09: ffffffffc005c1f0
  R10: ffff96bdfcd33c40 R11: ffff96bdfcd33b80 R12: 0000000000000018
  R13: ffffffffc005c1f0 R14: ffffffffc005e708 R15: ffffffff8b2fbc74
  FS:  00007f5f447beba8(0000) GS:ffff96bdff900000(0000) knlGS:0000000000000000
  CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
  CR2: ffffffffc005b1d9 CR3: 000000003cedc002 CR4: 0000000000360ea0
  DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
  DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
  Call Trace:
   klp_init_object_loaded+0x10f/0x219
   ? preempt_latency_start+0x21/0x57
   klp_enable_patch+0x662/0x809
   ? virt_to_head_page+0x3a/0x3c
   ? kfree+0x8c/0x126
   patch_init+0x2ed/0x1000 [livepatch_test02]
   ? 0xffffffffc0060000
   do_one_initcall+0x9f/0x1c5
   ? kmem_cache_alloc_trace+0xc4/0xd4
   ? do_init_module+0x27/0x210
   do_init_module+0x5f/0x210
   load_module+0x1c41/0x2290
   ? fsnotify_path+0x3b/0x42
   ? strstarts+0x2b/0x2b
   ? kernel_read+0x58/0x65
   __do_sys_finit_module+0x9f/0xc3
   ? __do_sys_finit_module+0x9f/0xc3
   __x64_sys_finit_module+0x1a/0x1c
   do_syscall_64+0x52/0x61
   entry_SYSCALL_64_after_hwframe+0x44/0xa9

The above panic occurs when loading two modules at the same time with
ftrace enabled, where at least one of the modules is a livepatch module:

CPU0					CPU1
klp_enable_patch()
  klp_init_object_loaded()
    module_disable_ro()
    					ftrace_module_enable()
					  ftrace_arch_code_modify_post_process()
				    	    set_all_modules_text_ro()
      klp_write_object_relocations()
        apply_relocate_add()
	  *patches read-only code* - BOOM

A similar race exists when toggling ftrace while loading a livepatch
module.

Fix it by ensuring that the livepatch and ftrace code patching
operations -- and their respective permissions changes -- are protected
by the text_mutex.

Reported-by: Johannes Erdfelt <johannes@erdfelt.com>
Signed-off-by: Josh Poimboeuf <jpoimboe@redhat.com>
---
 kernel/livepatch/core.c |  6 ++++++
 kernel/module.c         |  9 +++++++++
 kernel/trace/ftrace.c   | 10 +++++++++-
 3 files changed, 24 insertions(+), 1 deletion(-)

diff --git a/kernel/livepatch/core.c b/kernel/livepatch/core.c
index 91cd519756d3..2d17e6e364b5 100644
--- a/kernel/livepatch/core.c
+++ b/kernel/livepatch/core.c
@@ -30,6 +30,7 @@
 #include <linux/elf.h>
 #include <linux/moduleloader.h>
 #include <linux/completion.h>
+#include <linux/memory.h>
 #include <asm/cacheflush.h>
 #include "core.h"
 #include "patch.h"
@@ -730,16 +731,21 @@ static int klp_init_object_loaded(struct klp_patch *patch,
 	struct klp_func *func;
 	int ret;
 
+	mutex_lock(&text_mutex);
+
 	module_disable_ro(patch->mod);
 	ret = klp_write_object_relocations(patch->mod, obj);
 	if (ret) {
 		module_enable_ro(patch->mod, true);
+		mutex_unlock(&text_mutex);
 		return ret;
 	}
 
 	arch_klp_init_object_loaded(patch, obj);
 	module_enable_ro(patch->mod, true);
 
+	mutex_unlock(&text_mutex);
+
 	klp_for_each_func(obj, func) {
 		ret = klp_find_object_symbol(obj->name, func->old_name,
 					     func->old_sympos,
diff --git a/kernel/module.c b/kernel/module.c
index 6e6712b3aaf5..4d9f3281c0c5 100644
--- a/kernel/module.c
+++ b/kernel/module.c
@@ -64,6 +64,7 @@
 #include <linux/bsearch.h>
 #include <linux/dynamic_debug.h>
 #include <linux/audit.h>
+#include <linux/memory.h>
 #include <uapi/linux/module.h>
 #include "module-internal.h"
 
@@ -1943,6 +1944,8 @@ static void frob_writable_data(const struct module_layout *layout,
 /* livepatching wants to disable read-only so it can frob module. */
 void module_disable_ro(const struct module *mod)
 {
+	lockdep_assert_held(&text_mutex);
+
 	if (!rodata_enabled)
 		return;
 
@@ -1955,6 +1958,8 @@ void module_disable_ro(const struct module *mod)
 
 void module_enable_ro(const struct module *mod, bool after_init)
 {
+	lockdep_assert_held(&text_mutex);
+
 	if (!rodata_enabled)
 		return;
 
@@ -1988,6 +1993,8 @@ void set_all_modules_text_rw(void)
 {
 	struct module *mod;
 
+	lockdep_assert_held(&text_mutex);
+
 	if (!rodata_enabled)
 		return;
 
@@ -2007,6 +2014,8 @@ void set_all_modules_text_ro(void)
 {
 	struct module *mod;
 
+	lockdep_assert_held(&text_mutex);
+
 	if (!rodata_enabled)
 		return;
 
diff --git a/kernel/trace/ftrace.c b/kernel/trace/ftrace.c
index a12aff849c04..8259d4ba8b00 100644
--- a/kernel/trace/ftrace.c
+++ b/kernel/trace/ftrace.c
@@ -34,6 +34,7 @@
 #include <linux/hash.h>
 #include <linux/rcupdate.h>
 #include <linux/kprobes.h>
+#include <linux/memory.h>
 
 #include <trace/events/sched.h>
 
@@ -2610,10 +2611,12 @@ static void ftrace_run_update_code(int command)
 {
 	int ret;
 
+	mutex_lock(&text_mutex);
+
 	ret = ftrace_arch_code_modify_prepare();
 	FTRACE_WARN_ON(ret);
 	if (ret)
-		return;
+		goto out_unlock;
 
 	/*
 	 * By default we use stop_machine() to modify the code.
@@ -2625,6 +2628,9 @@ static void ftrace_run_update_code(int command)
 
 	ret = ftrace_arch_code_modify_post_process();
 	FTRACE_WARN_ON(ret);
+
+out_unlock:
+	mutex_unlock(&text_mutex);
 }
 
 static void ftrace_run_modify_code(struct ftrace_ops *ops, int command,
@@ -5776,6 +5782,7 @@ void ftrace_module_enable(struct module *mod)
 	struct ftrace_page *pg;
 
 	mutex_lock(&ftrace_lock);
+	mutex_lock(&text_mutex);
 
 	if (ftrace_disabled)
 		goto out_unlock;
@@ -5837,6 +5844,7 @@ void ftrace_module_enable(struct module *mod)
 		ftrace_arch_code_modify_post_process();
 
  out_unlock:
+	mutex_unlock(&text_mutex);
 	mutex_unlock(&ftrace_lock);
 
 	process_cached_mods(mod->name);
-- 
2.20.1


^ permalink raw reply	[flat|nested] 20+ messages in thread

* Re: Oops caused by race between livepatch and ftrace
  2019-05-21 16:42             ` Josh Poimboeuf
@ 2019-05-21 16:53               ` Steven Rostedt
  2019-05-29 11:17                 ` Jiri Kosina
  2019-05-22 13:00               ` Josh Poimboeuf
  2019-05-29 17:29               ` Jessica Yu
  2 siblings, 1 reply; 20+ messages in thread
From: Steven Rostedt @ 2019-05-21 16:53 UTC (permalink / raw)
  To: Josh Poimboeuf
  Cc: Johannes Erdfelt, Joe Lawrence, Jessica Yu, Jiri Kosina,
	Miroslav Benes, Ingo Molnar, live-patching, linux-kernel

On Tue, 21 May 2019 11:42:27 -0500
Josh Poimboeuf <jpoimboe@redhat.com> wrote:

> Hm.  I suppose using ftrace_lock might be less risky since that lock is
> only used internally by ftrace (up until now).  But I think it would
> also make less sense because the text_mutex is supposed to protect code
> patching.  And presumably ftrace_lock is supposed to be ftrace-specific.
> 
> Here's the latest patch, still using text_mutex.  I added some lockdep
> assertions to ensure the permissions toggling functions are always
> called with text_mutex.  It's running through 0-day right now.  I can
> try to run it through various tests with CONFIG_LOCKDEP.

Yeah, text_mutex probably does make more sense. ftrace_mutex was around
before text_mutex as ftrace was the first one to do the runtime
patching (after boot has finished). It wasn't until we introduced
text_poke that we decided to create the text_mutex locking as well.

> 
> 
> From: Josh Poimboeuf <jpoimboe@redhat.com>
> Subject: [PATCH] livepatch: Fix ftrace module text permissions race

Thanks,

I'll try to find some time to test this as well.

-- Steve

^ permalink raw reply	[flat|nested] 20+ messages in thread

* Re: Oops caused by race between livepatch and ftrace
  2019-05-20 21:19     ` Joe Lawrence
@ 2019-05-21 19:27       ` Joe Lawrence
  2019-05-21 21:00         ` Josh Poimboeuf
  0 siblings, 1 reply; 20+ messages in thread
From: Joe Lawrence @ 2019-05-21 19:27 UTC (permalink / raw)
  To: Johannes Erdfelt
  Cc: Josh Poimboeuf, Jessica Yu, Jiri Kosina, Miroslav Benes,
	Steven Rostedt, Ingo Molnar, live-patching, linux-kernel

On 5/20/19 5:19 PM, Joe Lawrence wrote:
> On 5/20/19 5:09 PM, Johannes Erdfelt wrote:
>> On Mon, May 20, 2019, Joe Lawrence <joe.lawrence@redhat.com> wrote:
>>> These two testing scenarios might be interesting to add to our selftests
>>> suite.  Can you post or add the source(s) to livepatch-test<n>.ko to the
>>> tarball?
>>
>> I made the livepatches using kpatch-build and this simple patch:
>>
>> diff --git a/fs/proc/version.c b/fs/proc/version.c
>> index 94901e8e700d..6b8a3449f455 100644
>> --- a/fs/proc/version.c
>> +++ b/fs/proc/version.c
>> @@ -12,6 +12,7 @@ static int version_proc_show(struct seq_file *m, void *v)
>>    		utsname()->sysname,
>>    		utsname()->release,
>>    		utsname()->version);
>> +	seq_printf(m, "example livepatch\n");
>>    	return 0;
>>    }
>>
>> I just created enough livepatches with the same source patch so that I
>> could reproduce the issue somewhat reliably.
>>
>> I'll see if I can make something that uses klp directly.
> 
> Ah ok great, I was hoping it was a relatively simply livepatch.  We
> could probably reuse lib/livepatch/test_klp_livepatch.c to do this
> (patching cmdline_proc_show instead).
> 
>> The rest of the userspace in the initramfs is really straight forward
>> with the only interesting parts being a couple of shell scripts.
> 
> Yup.  I'll be on PTO later this week, but I'll see about extracting the
> scripts and building a pile of livepatch .ko's to see how easily it
> reproduces without qemu.
> 

D'oh -- I just remembered that klp doesn't create those klp (arch) 
relocation sections just yet!  Without those, the window for module RO 
-> RW -> RO in klp_init_object_loaded is going to be really small... at 
least I can't reproduce it yet without those special sections.  So maybe 
such selftests need to wait post klp-convert.


BTW, livepatching folks -- speaking of this window, does it make sense 
for klp_init_object_loaded() to unconditionally frob the module section 
permissions?  Should it only bother iff it's going to apply 
relocations/alternatives/paravirt?

-- Joe

^ permalink raw reply	[flat|nested] 20+ messages in thread

* Re: Oops caused by race between livepatch and ftrace
  2019-05-21 19:27       ` Joe Lawrence
@ 2019-05-21 21:00         ` Josh Poimboeuf
  0 siblings, 0 replies; 20+ messages in thread
From: Josh Poimboeuf @ 2019-05-21 21:00 UTC (permalink / raw)
  To: Joe Lawrence
  Cc: Johannes Erdfelt, Jessica Yu, Jiri Kosina, Miroslav Benes,
	Steven Rostedt, Ingo Molnar, live-patching, linux-kernel

On Tue, May 21, 2019 at 03:27:47PM -0400, Joe Lawrence wrote:
> BTW, livepatching folks -- speaking of this window, does it make sense for
> klp_init_object_loaded() to unconditionally frob the module section
> permissions?  Should it only bother iff it's going to apply
> relocations/alternatives/paravirt?

Yeah, technically there shouldn't be a need to do the frobbing unless
there are .klp.rela or .klp.arch sections for the given object.  Though
I'm not sure it really matters all that much since loading a livepatch
is a pretty rare event.

-- 
Josh

^ permalink raw reply	[flat|nested] 20+ messages in thread

* Re: Oops caused by race between livepatch and ftrace
  2019-05-21 16:42             ` Josh Poimboeuf
  2019-05-21 16:53               ` Steven Rostedt
@ 2019-05-22 13:00               ` Josh Poimboeuf
  2019-05-29 17:29               ` Jessica Yu
  2 siblings, 0 replies; 20+ messages in thread
From: Josh Poimboeuf @ 2019-05-22 13:00 UTC (permalink / raw)
  To: Steven Rostedt
  Cc: Johannes Erdfelt, Joe Lawrence, Jessica Yu, Jiri Kosina,
	Miroslav Benes, Ingo Molnar, live-patching, linux-kernel

On Tue, May 21, 2019 at 11:42:27AM -0500, Josh Poimboeuf wrote:
>  void module_enable_ro(const struct module *mod, bool after_init)
>  {
> +	lockdep_assert_held(&text_mutex);
> +

This assertion fails, it turns out the module code also calls this
function (oops).  I may move the meat of this function to a
__module_enable_ro() which the module code can call.

-- 
Josh

^ permalink raw reply	[flat|nested] 20+ messages in thread

* Re: Oops caused by race between livepatch and ftrace
  2019-05-21 16:53               ` Steven Rostedt
@ 2019-05-29 11:17                 ` Jiri Kosina
  2019-05-29 12:06                   ` Steven Rostedt
  0 siblings, 1 reply; 20+ messages in thread
From: Jiri Kosina @ 2019-05-29 11:17 UTC (permalink / raw)
  To: Steven Rostedt
  Cc: Josh Poimboeuf, Johannes Erdfelt, Joe Lawrence, Jessica Yu,
	Miroslav Benes, Ingo Molnar, live-patching, linux-kernel

On Tue, 21 May 2019, Steven Rostedt wrote:

> > Hm.  I suppose using ftrace_lock might be less risky since that lock 
> > is only used internally by ftrace (up until now).  But I think it 
> > would also make less sense because the text_mutex is supposed to 
> > protect code patching.  And presumably ftrace_lock is supposed to be 
> > ftrace-specific.
> > 
> > Here's the latest patch, still using text_mutex.  I added some lockdep
> > assertions to ensure the permissions toggling functions are always
> > called with text_mutex.  It's running through 0-day right now.  I can
> > try to run it through various tests with CONFIG_LOCKDEP.
> 
> Yeah, text_mutex probably does make more sense. ftrace_mutex was around
> before text_mutex as ftrace was the first one to do the runtime
> patching (after boot has finished). It wasn't until we introduced
> text_poke that we decided to create the text_mutex locking as well.
> 
> > 
> > 
> > From: Josh Poimboeuf <jpoimboe@redhat.com>
> > Subject: [PATCH] livepatch: Fix ftrace module text permissions race
> 
> Thanks,
> 
> I'll try to find some time to test this as well.

Steve, Jessica, any final word on this?

Thanks,

-- 
Jiri Kosina
SUSE Labs


^ permalink raw reply	[flat|nested] 20+ messages in thread

* Re: Oops caused by race between livepatch and ftrace
  2019-05-29 11:17                 ` Jiri Kosina
@ 2019-05-29 12:06                   ` Steven Rostedt
  2019-05-29 12:30                     ` Josh Poimboeuf
  0 siblings, 1 reply; 20+ messages in thread
From: Steven Rostedt @ 2019-05-29 12:06 UTC (permalink / raw)
  To: Jiri Kosina
  Cc: Josh Poimboeuf, Johannes Erdfelt, Joe Lawrence, Jessica Yu,
	Miroslav Benes, Ingo Molnar, live-patching, linux-kernel

On Wed, 29 May 2019 13:17:21 +0200 (CEST)
Jiri Kosina <jikos@kernel.org> wrote:

> > > From: Josh Poimboeuf <jpoimboe@redhat.com>
> > > Subject: [PATCH] livepatch: Fix ftrace module text permissions race  
> > 
> > Thanks,
> > 
> > I'll try to find some time to test this as well.  
> 
> Steve, Jessica, any final word on this?

I was under the impression that Josh was going to send an updated
patch (and a properly sent one). Patches embedded in other emails don't
get flagged by my internal patchwork, so they usually get ignored.

-- Steve

^ permalink raw reply	[flat|nested] 20+ messages in thread

* Re: Oops caused by race between livepatch and ftrace
  2019-05-29 12:06                   ` Steven Rostedt
@ 2019-05-29 12:30                     ` Josh Poimboeuf
  0 siblings, 0 replies; 20+ messages in thread
From: Josh Poimboeuf @ 2019-05-29 12:30 UTC (permalink / raw)
  To: Steven Rostedt
  Cc: Jiri Kosina, Johannes Erdfelt, Joe Lawrence, Jessica Yu,
	Miroslav Benes, Ingo Molnar, live-patching, linux-kernel

On Wed, May 29, 2019 at 08:06:48AM -0400, Steven Rostedt wrote:
> On Wed, 29 May 2019 13:17:21 +0200 (CEST)
> Jiri Kosina <jikos@kernel.org> wrote:
> 
> > > > From: Josh Poimboeuf <jpoimboe@redhat.com>
> > > > Subject: [PATCH] livepatch: Fix ftrace module text permissions race  
> > > 
> > > Thanks,
> > > 
> > > I'll try to find some time to test this as well.  
> > 
> > Steve, Jessica, any final word on this?
> 
> I was under the impression that Josh was going to send an updated
> patch (and a properly sent one). Patches embedded in other emails don't
> get flagged by my internal patchwork, so they usually get ignored.

Yeah, I actually have a newer version of the patch in my queue.  I'll
try to send it out shortly.

-- 
Josh

^ permalink raw reply	[flat|nested] 20+ messages in thread

* Re: Oops caused by race between livepatch and ftrace
  2019-05-21 16:42             ` Josh Poimboeuf
  2019-05-21 16:53               ` Steven Rostedt
  2019-05-22 13:00               ` Josh Poimboeuf
@ 2019-05-29 17:29               ` Jessica Yu
  2019-05-29 17:39                 ` Josh Poimboeuf
  2 siblings, 1 reply; 20+ messages in thread
From: Jessica Yu @ 2019-05-29 17:29 UTC (permalink / raw)
  To: Josh Poimboeuf
  Cc: Steven Rostedt, Johannes Erdfelt, Joe Lawrence, Jiri Kosina,
	Miroslav Benes, Ingo Molnar, live-patching, linux-kernel

+++ Josh Poimboeuf [21/05/19 11:42 -0500]:
>On Tue, May 21, 2019 at 10:42:04AM -0400, Steven Rostedt wrote:
>> On Tue, 21 May 2019 09:16:29 -0500
>> Josh Poimboeuf <jpoimboe@redhat.com> wrote:
>>
>> > > Hmm, this may blow up with lockdep, as I believe we already have a
>> > > locking dependency of:
>> > >
>> > >  text_mutex -> ftrace_lock
>> > >
>> > > And this will reverses it. (kprobes appears to take the locks in this
>> > > order).
>> > >
>> > > Perhaps have live kernel patching grab ftrace_lock?
>> >
>> > Where does kprobes call into ftrace with the text_mutex?  I couldn't
>> > find it.
>>
>> Hmm, maybe it doesn't. I was looking at the arm_kprobe_ftrace() but
>> it doesn't call it with text_mutex().
>>
>> Maybe it is fine, but we had better perform a lot of testing with
>> lockdep on to make sure.
>
>Hm.  I suppose using ftrace_lock might be less risky since that lock is
>only used internally by ftrace (up until now).  But I think it would
>also make less sense because the text_mutex is supposed to protect code
>patching.  And presumably ftrace_lock is supposed to be ftrace-specific.
>
>Here's the latest patch, still using text_mutex.  I added some lockdep
>assertions to ensure the permissions toggling functions are always
>called with text_mutex.  It's running through 0-day right now.  I can
>try to run it through various tests with CONFIG_LOCKDEP.
>
>
>From: Josh Poimboeuf <jpoimboe@redhat.com>
>Subject: [PATCH] livepatch: Fix ftrace module text permissions race
>
>It's possible for livepatch and ftrace to be toggling a module's text
>permissions at the same time, resulting in the following panic:
>
>  BUG: unable to handle page fault for address: ffffffffc005b1d9
>  #PF: supervisor write access in kernel mode
>  #PF: error_code(0x0003) - permissions violation
>  PGD 3ea0c067 P4D 3ea0c067 PUD 3ea0e067 PMD 3cc13067 PTE 3b8a1061
>  Oops: 0003 [#1] PREEMPT SMP PTI
>  CPU: 1 PID: 453 Comm: insmod Tainted: G           O  K   5.2.0-rc1-a188339ca5 #1
>  Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.12.0-20181126_142135-anatol 04/01/2014
>  RIP: 0010:apply_relocate_add+0xbe/0x14c
>  Code: fa 0b 74 21 48 83 fa 18 74 38 48 83 fa 0a 75 40 eb 08 48 83 38 00 74 33 eb 53 83 38 00 75 4e 89 08 89 c8 eb 0a 83 38 00 75 43 <89> 08 48 63 c1 48 39 c8 74 2e eb 48 83 38 00 75 32 48 29 c1 89 08
>  RSP: 0018:ffffb223c00dbb10 EFLAGS: 00010246
>  RAX: ffffffffc005b1d9 RBX: 0000000000000000 RCX: ffffffff8b200060
>  RDX: 000000000000000b RSI: 0000004b0000000b RDI: ffff96bdfcd33000
>  RBP: ffffb223c00dbb38 R08: ffffffffc005d040 R09: ffffffffc005c1f0
>  R10: ffff96bdfcd33c40 R11: ffff96bdfcd33b80 R12: 0000000000000018
>  R13: ffffffffc005c1f0 R14: ffffffffc005e708 R15: ffffffff8b2fbc74
>  FS:  00007f5f447beba8(0000) GS:ffff96bdff900000(0000) knlGS:0000000000000000
>  CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
>  CR2: ffffffffc005b1d9 CR3: 000000003cedc002 CR4: 0000000000360ea0
>  DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
>  DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
>  Call Trace:
>   klp_init_object_loaded+0x10f/0x219
>   ? preempt_latency_start+0x21/0x57
>   klp_enable_patch+0x662/0x809
>   ? virt_to_head_page+0x3a/0x3c
>   ? kfree+0x8c/0x126
>   patch_init+0x2ed/0x1000 [livepatch_test02]
>   ? 0xffffffffc0060000
>   do_one_initcall+0x9f/0x1c5
>   ? kmem_cache_alloc_trace+0xc4/0xd4
>   ? do_init_module+0x27/0x210
>   do_init_module+0x5f/0x210
>   load_module+0x1c41/0x2290
>   ? fsnotify_path+0x3b/0x42
>   ? strstarts+0x2b/0x2b
>   ? kernel_read+0x58/0x65
>   __do_sys_finit_module+0x9f/0xc3
>   ? __do_sys_finit_module+0x9f/0xc3
>   __x64_sys_finit_module+0x1a/0x1c
>   do_syscall_64+0x52/0x61
>   entry_SYSCALL_64_after_hwframe+0x44/0xa9
>
>The above panic occurs when loading two modules at the same time with
>ftrace enabled, where at least one of the modules is a livepatch module:
>
>CPU0					CPU1
>klp_enable_patch()
>  klp_init_object_loaded()
>    module_disable_ro()
>    					ftrace_module_enable()
>					  ftrace_arch_code_modify_post_process()
>				    	    set_all_modules_text_ro()
>      klp_write_object_relocations()
>        apply_relocate_add()
>	  *patches read-only code* - BOOM
>
>A similar race exists when toggling ftrace while loading a livepatch
>module.
>
>Fix it by ensuring that the livepatch and ftrace code patching
>operations -- and their respective permissions changes -- are protected
>by the text_mutex.
>
>Reported-by: Johannes Erdfelt <johannes@erdfelt.com>
>Signed-off-by: Josh Poimboeuf <jpoimboe@redhat.com>
>---
> kernel/livepatch/core.c |  6 ++++++
> kernel/module.c         |  9 +++++++++
> kernel/trace/ftrace.c   | 10 +++++++++-
> 3 files changed, 24 insertions(+), 1 deletion(-)
>
>diff --git a/kernel/livepatch/core.c b/kernel/livepatch/core.c
>index 91cd519756d3..2d17e6e364b5 100644
>--- a/kernel/livepatch/core.c
>+++ b/kernel/livepatch/core.c
>@@ -30,6 +30,7 @@
> #include <linux/elf.h>
> #include <linux/moduleloader.h>
> #include <linux/completion.h>
>+#include <linux/memory.h>
> #include <asm/cacheflush.h>
> #include "core.h"
> #include "patch.h"
>@@ -730,16 +731,21 @@ static int klp_init_object_loaded(struct klp_patch *patch,
> 	struct klp_func *func;
> 	int ret;
>
>+	mutex_lock(&text_mutex);
>+
> 	module_disable_ro(patch->mod);
> 	ret = klp_write_object_relocations(patch->mod, obj);
> 	if (ret) {
> 		module_enable_ro(patch->mod, true);
>+		mutex_unlock(&text_mutex);
> 		return ret;
> 	}
>
> 	arch_klp_init_object_loaded(patch, obj);
> 	module_enable_ro(patch->mod, true);
>
>+	mutex_unlock(&text_mutex);
>+
> 	klp_for_each_func(obj, func) {
> 		ret = klp_find_object_symbol(obj->name, func->old_name,
> 					     func->old_sympos,
>diff --git a/kernel/module.c b/kernel/module.c
>index 6e6712b3aaf5..4d9f3281c0c5 100644
>--- a/kernel/module.c
>+++ b/kernel/module.c
>@@ -64,6 +64,7 @@
> #include <linux/bsearch.h>
> #include <linux/dynamic_debug.h>
> #include <linux/audit.h>
>+#include <linux/memory.h>
> #include <uapi/linux/module.h>
> #include "module-internal.h"
>
>@@ -1943,6 +1944,8 @@ static void frob_writable_data(const struct module_layout *layout,
> /* livepatching wants to disable read-only so it can frob module. */
> void module_disable_ro(const struct module *mod)
> {
>+	lockdep_assert_held(&text_mutex);
>+
> 	if (!rodata_enabled)
> 		return;
>
>@@ -1955,6 +1958,8 @@ void module_disable_ro(const struct module *mod)
>
> void module_enable_ro(const struct module *mod, bool after_init)
> {
>+	lockdep_assert_held(&text_mutex);

Hi Josh!

The lockdep WARN_ON triggers when loading a module under a lockdep enabled kernel:

[    6.139583] WARNING: CPU: 0 PID: 102 at /home/ppyu/jeyu-linux/kernel/module.c:1961 module_enable_ro+0x121/0x130
[    6.143641] Modules linked in:
[    6.144879] CPU: 0 PID: 102 Comm: insmod Not tainted 5.2.0-rc2+ #1
[    6.147325] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.11.0-0-g63451fc-prebuilt.qemu-project.org 04/01/2014
[    6.152046] RIP: 0010:module_enable_ro+0x121/0x130
[    6.153986] Code: 48 c7 c6 70 97 05 81 5d 41 5c 41 5d e9 b8 e2 ff ff be ff ff ff ff 48 c7 c7 40 b2 65 82 e8 a7 c7 fa ff 85 c0 0f 85 f8 fe ff ff <0f> 0b e9 f1 fe ff ff 0f 1f 84 00 00 00 00 00 8b 05 9e a5 66 01 55
[    6.161277] RSP: 0018:ffffc9000041fd18 EFLAGS: 00010246
[    6.162919] RAX: 0000000000000000 RBX: ffffffffc0002000 RCX: 000000000000000b
[    6.164783] RDX: ffff88803d793fc0 RSI: ffffffff8265b240 RDI: ffff88803d7947e8
[    6.166820] RBP: 0000000000000000 R08: 000000000007ade8 R09: ffffffff823989a6
[    6.168579] R10: ffffc9000049c8e8 R11: 0000000000000002 R12: ffffffffc00021c0
[    6.169994] R13: 0000000000000000 R14: 0000000000000030 R15: ffffc9000041fe78
[    6.171390] FS:  00007fdc49708700(0000) GS:ffff88803d800000(0000) knlGS:0000000000000000
[    6.173007] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[    6.174047] CR2: 00007fdc496c0000 CR3: 000000003fb84000 CR4: 00000000000006f0
[    6.175168] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[    6.176326] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[    6.177384] Call Trace:
[    6.177730]  load_module+0x1b96/0x2620
[    6.178231]  ? rcu_read_lock_sched_held+0x53/0x60
[    6.178865]  ? __alloc_pages_nodemask+0x2fa/0x350
[    6.179497]  ? __do_sys_init_module+0x135/0x170
[    6.180097]  ? _cond_resched+0x10/0x40
[    6.180594]  __do_sys_init_module+0x135/0x170
[    6.181177]  do_syscall_64+0x4b/0x1c0
[    6.181681]  entry_SYSCALL_64_after_hwframe+0x49/0xbe

It triggers since we call module_enable_ro() along the load_module()
path to prepare for a coming module. We don't take the text_mutex
there since we're not modifying any text, just memory protections.
Leaving the lockdep assert in module_disable_ro() and
set_all_modules_text_*() should be fine though, since I think
livepatch and ftrace are the only users of those functions.

Thanks,

Jessica


^ permalink raw reply	[flat|nested] 20+ messages in thread

* Re: Oops caused by race between livepatch and ftrace
  2019-05-29 17:29               ` Jessica Yu
@ 2019-05-29 17:39                 ` Josh Poimboeuf
  2019-05-29 18:34                   ` Jessica Yu
  0 siblings, 1 reply; 20+ messages in thread
From: Josh Poimboeuf @ 2019-05-29 17:39 UTC (permalink / raw)
  To: Jessica Yu
  Cc: Steven Rostedt, Johannes Erdfelt, Joe Lawrence, Jiri Kosina,
	Miroslav Benes, Ingo Molnar, live-patching, linux-kernel

On Wed, May 29, 2019 at 07:29:04PM +0200, Jessica Yu wrote:
> +++ Josh Poimboeuf [21/05/19 11:42 -0500]:
> > On Tue, May 21, 2019 at 10:42:04AM -0400, Steven Rostedt wrote:
> > > On Tue, 21 May 2019 09:16:29 -0500
> > > Josh Poimboeuf <jpoimboe@redhat.com> wrote:
> > > 
> > > > > Hmm, this may blow up with lockdep, as I believe we already have a
> > > > > locking dependency of:
> > > > >
> > > > >  text_mutex -> ftrace_lock
> > > > >
> > > > > And this will reverses it. (kprobes appears to take the locks in this
> > > > > order).
> > > > >
> > > > > Perhaps have live kernel patching grab ftrace_lock?
> > > >
> > > > Where does kprobes call into ftrace with the text_mutex?  I couldn't
> > > > find it.
> > > 
> > > Hmm, maybe it doesn't. I was looking at the arm_kprobe_ftrace() but
> > > it doesn't call it with text_mutex().
> > > 
> > > Maybe it is fine, but we had better perform a lot of testing with
> > > lockdep on to make sure.
> > 
> > Hm.  I suppose using ftrace_lock might be less risky since that lock is
> > only used internally by ftrace (up until now).  But I think it would
> > also make less sense because the text_mutex is supposed to protect code
> > patching.  And presumably ftrace_lock is supposed to be ftrace-specific.
> > 
> > Here's the latest patch, still using text_mutex.  I added some lockdep
> > assertions to ensure the permissions toggling functions are always
> > called with text_mutex.  It's running through 0-day right now.  I can
> > try to run it through various tests with CONFIG_LOCKDEP.
> > 
> > 
> > From: Josh Poimboeuf <jpoimboe@redhat.com>
> > Subject: [PATCH] livepatch: Fix ftrace module text permissions race
> > 
> > It's possible for livepatch and ftrace to be toggling a module's text
> > permissions at the same time, resulting in the following panic:
> > 
> >  BUG: unable to handle page fault for address: ffffffffc005b1d9
> >  #PF: supervisor write access in kernel mode
> >  #PF: error_code(0x0003) - permissions violation
> >  PGD 3ea0c067 P4D 3ea0c067 PUD 3ea0e067 PMD 3cc13067 PTE 3b8a1061
> >  Oops: 0003 [#1] PREEMPT SMP PTI
> >  CPU: 1 PID: 453 Comm: insmod Tainted: G           O  K   5.2.0-rc1-a188339ca5 #1
> >  Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.12.0-20181126_142135-anatol 04/01/2014
> >  RIP: 0010:apply_relocate_add+0xbe/0x14c
> >  Code: fa 0b 74 21 48 83 fa 18 74 38 48 83 fa 0a 75 40 eb 08 48 83 38 00 74 33 eb 53 83 38 00 75 4e 89 08 89 c8 eb 0a 83 38 00 75 43 <89> 08 48 63 c1 48 39 c8 74 2e eb 48 83 38 00 75 32 48 29 c1 89 08
> >  RSP: 0018:ffffb223c00dbb10 EFLAGS: 00010246
> >  RAX: ffffffffc005b1d9 RBX: 0000000000000000 RCX: ffffffff8b200060
> >  RDX: 000000000000000b RSI: 0000004b0000000b RDI: ffff96bdfcd33000
> >  RBP: ffffb223c00dbb38 R08: ffffffffc005d040 R09: ffffffffc005c1f0
> >  R10: ffff96bdfcd33c40 R11: ffff96bdfcd33b80 R12: 0000000000000018
> >  R13: ffffffffc005c1f0 R14: ffffffffc005e708 R15: ffffffff8b2fbc74
> >  FS:  00007f5f447beba8(0000) GS:ffff96bdff900000(0000) knlGS:0000000000000000
> >  CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> >  CR2: ffffffffc005b1d9 CR3: 000000003cedc002 CR4: 0000000000360ea0
> >  DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
> >  DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
> >  Call Trace:
> >   klp_init_object_loaded+0x10f/0x219
> >   ? preempt_latency_start+0x21/0x57
> >   klp_enable_patch+0x662/0x809
> >   ? virt_to_head_page+0x3a/0x3c
> >   ? kfree+0x8c/0x126
> >   patch_init+0x2ed/0x1000 [livepatch_test02]
> >   ? 0xffffffffc0060000
> >   do_one_initcall+0x9f/0x1c5
> >   ? kmem_cache_alloc_trace+0xc4/0xd4
> >   ? do_init_module+0x27/0x210
> >   do_init_module+0x5f/0x210
> >   load_module+0x1c41/0x2290
> >   ? fsnotify_path+0x3b/0x42
> >   ? strstarts+0x2b/0x2b
> >   ? kernel_read+0x58/0x65
> >   __do_sys_finit_module+0x9f/0xc3
> >   ? __do_sys_finit_module+0x9f/0xc3
> >   __x64_sys_finit_module+0x1a/0x1c
> >   do_syscall_64+0x52/0x61
> >   entry_SYSCALL_64_after_hwframe+0x44/0xa9
> > 
> > The above panic occurs when loading two modules at the same time with
> > ftrace enabled, where at least one of the modules is a livepatch module:
> > 
> > CPU0					CPU1
> > klp_enable_patch()
> >  klp_init_object_loaded()
> >    module_disable_ro()
> >    					ftrace_module_enable()
> > 					  ftrace_arch_code_modify_post_process()
> > 				    	    set_all_modules_text_ro()
> >      klp_write_object_relocations()
> >        apply_relocate_add()
> > 	  *patches read-only code* - BOOM
> > 
> > A similar race exists when toggling ftrace while loading a livepatch
> > module.
> > 
> > Fix it by ensuring that the livepatch and ftrace code patching
> > operations -- and their respective permissions changes -- are protected
> > by the text_mutex.
> > 
> > Reported-by: Johannes Erdfelt <johannes@erdfelt.com>
> > Signed-off-by: Josh Poimboeuf <jpoimboe@redhat.com>
> > ---
> > kernel/livepatch/core.c |  6 ++++++
> > kernel/module.c         |  9 +++++++++
> > kernel/trace/ftrace.c   | 10 +++++++++-
> > 3 files changed, 24 insertions(+), 1 deletion(-)
> > 
> > diff --git a/kernel/livepatch/core.c b/kernel/livepatch/core.c
> > index 91cd519756d3..2d17e6e364b5 100644
> > --- a/kernel/livepatch/core.c
> > +++ b/kernel/livepatch/core.c
> > @@ -30,6 +30,7 @@
> > #include <linux/elf.h>
> > #include <linux/moduleloader.h>
> > #include <linux/completion.h>
> > +#include <linux/memory.h>
> > #include <asm/cacheflush.h>
> > #include "core.h"
> > #include "patch.h"
> > @@ -730,16 +731,21 @@ static int klp_init_object_loaded(struct klp_patch *patch,
> > 	struct klp_func *func;
> > 	int ret;
> > 
> > +	mutex_lock(&text_mutex);
> > +
> > 	module_disable_ro(patch->mod);
> > 	ret = klp_write_object_relocations(patch->mod, obj);
> > 	if (ret) {
> > 		module_enable_ro(patch->mod, true);
> > +		mutex_unlock(&text_mutex);
> > 		return ret;
> > 	}
> > 
> > 	arch_klp_init_object_loaded(patch, obj);
> > 	module_enable_ro(patch->mod, true);
> > 
> > +	mutex_unlock(&text_mutex);
> > +
> > 	klp_for_each_func(obj, func) {
> > 		ret = klp_find_object_symbol(obj->name, func->old_name,
> > 					     func->old_sympos,
> > diff --git a/kernel/module.c b/kernel/module.c
> > index 6e6712b3aaf5..4d9f3281c0c5 100644
> > --- a/kernel/module.c
> > +++ b/kernel/module.c
> > @@ -64,6 +64,7 @@
> > #include <linux/bsearch.h>
> > #include <linux/dynamic_debug.h>
> > #include <linux/audit.h>
> > +#include <linux/memory.h>
> > #include <uapi/linux/module.h>
> > #include "module-internal.h"
> > 
> > @@ -1943,6 +1944,8 @@ static void frob_writable_data(const struct module_layout *layout,
> > /* livepatching wants to disable read-only so it can frob module. */
> > void module_disable_ro(const struct module *mod)
> > {
> > +	lockdep_assert_held(&text_mutex);
> > +
> > 	if (!rodata_enabled)
> > 		return;
> > 
> > @@ -1955,6 +1958,8 @@ void module_disable_ro(const struct module *mod)
> > 
> > void module_enable_ro(const struct module *mod, bool after_init)
> > {
> > +	lockdep_assert_held(&text_mutex);
> 
> Hi Josh!
> 
> The lockdep WARN_ON triggers when loading a module under a lockdep enabled kernel:
> 
> [    6.139583] WARNING: CPU: 0 PID: 102 at /home/ppyu/jeyu-linux/kernel/module.c:1961 module_enable_ro+0x121/0x130
> [    6.143641] Modules linked in:
> [    6.144879] CPU: 0 PID: 102 Comm: insmod Not tainted 5.2.0-rc2+ #1
> [    6.147325] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.11.0-0-g63451fc-prebuilt.qemu-project.org 04/01/2014
> [    6.152046] RIP: 0010:module_enable_ro+0x121/0x130
> [    6.153986] Code: 48 c7 c6 70 97 05 81 5d 41 5c 41 5d e9 b8 e2 ff ff be ff ff ff ff 48 c7 c7 40 b2 65 82 e8 a7 c7 fa ff 85 c0 0f 85 f8 fe ff ff <0f> 0b e9 f1 fe ff ff 0f 1f 84 00 00 00 00 00 8b 05 9e a5 66 01 55
> [    6.161277] RSP: 0018:ffffc9000041fd18 EFLAGS: 00010246
> [    6.162919] RAX: 0000000000000000 RBX: ffffffffc0002000 RCX: 000000000000000b
> [    6.164783] RDX: ffff88803d793fc0 RSI: ffffffff8265b240 RDI: ffff88803d7947e8
> [    6.166820] RBP: 0000000000000000 R08: 000000000007ade8 R09: ffffffff823989a6
> [    6.168579] R10: ffffc9000049c8e8 R11: 0000000000000002 R12: ffffffffc00021c0
> [    6.169994] R13: 0000000000000000 R14: 0000000000000030 R15: ffffc9000041fe78
> [    6.171390] FS:  00007fdc49708700(0000) GS:ffff88803d800000(0000) knlGS:0000000000000000
> [    6.173007] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [    6.174047] CR2: 00007fdc496c0000 CR3: 000000003fb84000 CR4: 00000000000006f0
> [    6.175168] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
> [    6.176326] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
> [    6.177384] Call Trace:
> [    6.177730]  load_module+0x1b96/0x2620
> [    6.178231]  ? rcu_read_lock_sched_held+0x53/0x60
> [    6.178865]  ? __alloc_pages_nodemask+0x2fa/0x350
> [    6.179497]  ? __do_sys_init_module+0x135/0x170
> [    6.180097]  ? _cond_resched+0x10/0x40
> [    6.180594]  __do_sys_init_module+0x135/0x170
> [    6.181177]  do_syscall_64+0x4b/0x1c0
> [    6.181681]  entry_SYSCALL_64_after_hwframe+0x49/0xbe
> 
> It triggers since we call module_enable_ro() along the load_module()
> path to prepare for a coming module. We don't take the text_mutex
> there since we're not modifying any text, just memory protections.
> Leaving the lockdep assert in module_disable_ro() and
> set_all_modules_text_*() should be fine though, since I think
> livepatch and ftrace are the only users of those functions.

Yeah, I discovered that already:

  https://lkml.kernel.org/r/20190522130014.yvkbio62meatqvwf@treble

The new patch (which I will hopefully be able to post soon) will fix
that up.

-- 
Josh

^ permalink raw reply	[flat|nested] 20+ messages in thread

* Re: Oops caused by race between livepatch and ftrace
  2019-05-29 17:39                 ` Josh Poimboeuf
@ 2019-05-29 18:34                   ` Jessica Yu
  0 siblings, 0 replies; 20+ messages in thread
From: Jessica Yu @ 2019-05-29 18:34 UTC (permalink / raw)
  To: Josh Poimboeuf
  Cc: Steven Rostedt, Johannes Erdfelt, Joe Lawrence, Jiri Kosina,
	Miroslav Benes, Ingo Molnar, live-patching, linux-kernel

+++ Josh Poimboeuf [29/05/19 12:39 -0500]:
>On Wed, May 29, 2019 at 07:29:04PM +0200, Jessica Yu wrote:
>> +++ Josh Poimboeuf [21/05/19 11:42 -0500]:
>> > On Tue, May 21, 2019 at 10:42:04AM -0400, Steven Rostedt wrote:
>> > > On Tue, 21 May 2019 09:16:29 -0500
>> > > Josh Poimboeuf <jpoimboe@redhat.com> wrote:
>> > >
>> > > > > Hmm, this may blow up with lockdep, as I believe we already have a
>> > > > > locking dependency of:
>> > > > >
>> > > > >  text_mutex -> ftrace_lock
>> > > > >
>> > > > > And this will reverses it. (kprobes appears to take the locks in this
>> > > > > order).
>> > > > >
>> > > > > Perhaps have live kernel patching grab ftrace_lock?
>> > > >
>> > > > Where does kprobes call into ftrace with the text_mutex?  I couldn't
>> > > > find it.
>> > >
>> > > Hmm, maybe it doesn't. I was looking at the arm_kprobe_ftrace() but
>> > > it doesn't call it with text_mutex().
>> > >
>> > > Maybe it is fine, but we had better perform a lot of testing with
>> > > lockdep on to make sure.
>> >
>> > Hm.  I suppose using ftrace_lock might be less risky since that lock is
>> > only used internally by ftrace (up until now).  But I think it would
>> > also make less sense because the text_mutex is supposed to protect code
>> > patching.  And presumably ftrace_lock is supposed to be ftrace-specific.
>> >
>> > Here's the latest patch, still using text_mutex.  I added some lockdep
>> > assertions to ensure the permissions toggling functions are always
>> > called with text_mutex.  It's running through 0-day right now.  I can
>> > try to run it through various tests with CONFIG_LOCKDEP.
>> >
>> >
>> > From: Josh Poimboeuf <jpoimboe@redhat.com>
>> > Subject: [PATCH] livepatch: Fix ftrace module text permissions race
>> >
>> > It's possible for livepatch and ftrace to be toggling a module's text
>> > permissions at the same time, resulting in the following panic:
>> >
>> >  BUG: unable to handle page fault for address: ffffffffc005b1d9
>> >  #PF: supervisor write access in kernel mode
>> >  #PF: error_code(0x0003) - permissions violation
>> >  PGD 3ea0c067 P4D 3ea0c067 PUD 3ea0e067 PMD 3cc13067 PTE 3b8a1061
>> >  Oops: 0003 [#1] PREEMPT SMP PTI
>> >  CPU: 1 PID: 453 Comm: insmod Tainted: G           O  K   5.2.0-rc1-a188339ca5 #1
>> >  Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.12.0-20181126_142135-anatol 04/01/2014
>> >  RIP: 0010:apply_relocate_add+0xbe/0x14c
>> >  Code: fa 0b 74 21 48 83 fa 18 74 38 48 83 fa 0a 75 40 eb 08 48 83 38 00 74 33 eb 53 83 38 00 75 4e 89 08 89 c8 eb 0a 83 38 00 75 43 <89> 08 48 63 c1 48 39 c8 74 2e eb 48 83 38 00 75 32 48 29 c1 89 08
>> >  RSP: 0018:ffffb223c00dbb10 EFLAGS: 00010246
>> >  RAX: ffffffffc005b1d9 RBX: 0000000000000000 RCX: ffffffff8b200060
>> >  RDX: 000000000000000b RSI: 0000004b0000000b RDI: ffff96bdfcd33000
>> >  RBP: ffffb223c00dbb38 R08: ffffffffc005d040 R09: ffffffffc005c1f0
>> >  R10: ffff96bdfcd33c40 R11: ffff96bdfcd33b80 R12: 0000000000000018
>> >  R13: ffffffffc005c1f0 R14: ffffffffc005e708 R15: ffffffff8b2fbc74
>> >  FS:  00007f5f447beba8(0000) GS:ffff96bdff900000(0000) knlGS:0000000000000000
>> >  CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
>> >  CR2: ffffffffc005b1d9 CR3: 000000003cedc002 CR4: 0000000000360ea0
>> >  DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
>> >  DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
>> >  Call Trace:
>> >   klp_init_object_loaded+0x10f/0x219
>> >   ? preempt_latency_start+0x21/0x57
>> >   klp_enable_patch+0x662/0x809
>> >   ? virt_to_head_page+0x3a/0x3c
>> >   ? kfree+0x8c/0x126
>> >   patch_init+0x2ed/0x1000 [livepatch_test02]
>> >   ? 0xffffffffc0060000
>> >   do_one_initcall+0x9f/0x1c5
>> >   ? kmem_cache_alloc_trace+0xc4/0xd4
>> >   ? do_init_module+0x27/0x210
>> >   do_init_module+0x5f/0x210
>> >   load_module+0x1c41/0x2290
>> >   ? fsnotify_path+0x3b/0x42
>> >   ? strstarts+0x2b/0x2b
>> >   ? kernel_read+0x58/0x65
>> >   __do_sys_finit_module+0x9f/0xc3
>> >   ? __do_sys_finit_module+0x9f/0xc3
>> >   __x64_sys_finit_module+0x1a/0x1c
>> >   do_syscall_64+0x52/0x61
>> >   entry_SYSCALL_64_after_hwframe+0x44/0xa9
>> >
>> > The above panic occurs when loading two modules at the same time with
>> > ftrace enabled, where at least one of the modules is a livepatch module:
>> >
>> > CPU0					CPU1
>> > klp_enable_patch()
>> >  klp_init_object_loaded()
>> >    module_disable_ro()
>> >    					ftrace_module_enable()
>> > 					  ftrace_arch_code_modify_post_process()
>> > 				    	    set_all_modules_text_ro()
>> >      klp_write_object_relocations()
>> >        apply_relocate_add()
>> > 	  *patches read-only code* - BOOM
>> >
>> > A similar race exists when toggling ftrace while loading a livepatch
>> > module.
>> >
>> > Fix it by ensuring that the livepatch and ftrace code patching
>> > operations -- and their respective permissions changes -- are protected
>> > by the text_mutex.
>> >
>> > Reported-by: Johannes Erdfelt <johannes@erdfelt.com>
>> > Signed-off-by: Josh Poimboeuf <jpoimboe@redhat.com>
>> > ---
>> > kernel/livepatch/core.c |  6 ++++++
>> > kernel/module.c         |  9 +++++++++
>> > kernel/trace/ftrace.c   | 10 +++++++++-
>> > 3 files changed, 24 insertions(+), 1 deletion(-)
>> >
>> > diff --git a/kernel/livepatch/core.c b/kernel/livepatch/core.c
>> > index 91cd519756d3..2d17e6e364b5 100644
>> > --- a/kernel/livepatch/core.c
>> > +++ b/kernel/livepatch/core.c
>> > @@ -30,6 +30,7 @@
>> > #include <linux/elf.h>
>> > #include <linux/moduleloader.h>
>> > #include <linux/completion.h>
>> > +#include <linux/memory.h>
>> > #include <asm/cacheflush.h>
>> > #include "core.h"
>> > #include "patch.h"
>> > @@ -730,16 +731,21 @@ static int klp_init_object_loaded(struct klp_patch *patch,
>> > 	struct klp_func *func;
>> > 	int ret;
>> >
>> > +	mutex_lock(&text_mutex);
>> > +
>> > 	module_disable_ro(patch->mod);
>> > 	ret = klp_write_object_relocations(patch->mod, obj);
>> > 	if (ret) {
>> > 		module_enable_ro(patch->mod, true);
>> > +		mutex_unlock(&text_mutex);
>> > 		return ret;
>> > 	}
>> >
>> > 	arch_klp_init_object_loaded(patch, obj);
>> > 	module_enable_ro(patch->mod, true);
>> >
>> > +	mutex_unlock(&text_mutex);
>> > +
>> > 	klp_for_each_func(obj, func) {
>> > 		ret = klp_find_object_symbol(obj->name, func->old_name,
>> > 					     func->old_sympos,
>> > diff --git a/kernel/module.c b/kernel/module.c
>> > index 6e6712b3aaf5..4d9f3281c0c5 100644
>> > --- a/kernel/module.c
>> > +++ b/kernel/module.c
>> > @@ -64,6 +64,7 @@
>> > #include <linux/bsearch.h>
>> > #include <linux/dynamic_debug.h>
>> > #include <linux/audit.h>
>> > +#include <linux/memory.h>
>> > #include <uapi/linux/module.h>
>> > #include "module-internal.h"
>> >
>> > @@ -1943,6 +1944,8 @@ static void frob_writable_data(const struct module_layout *layout,
>> > /* livepatching wants to disable read-only so it can frob module. */
>> > void module_disable_ro(const struct module *mod)
>> > {
>> > +	lockdep_assert_held(&text_mutex);
>> > +
>> > 	if (!rodata_enabled)
>> > 		return;
>> >
>> > @@ -1955,6 +1958,8 @@ void module_disable_ro(const struct module *mod)
>> >
>> > void module_enable_ro(const struct module *mod, bool after_init)
>> > {
>> > +	lockdep_assert_held(&text_mutex);
>>
>> Hi Josh!
>>
>> The lockdep WARN_ON triggers when loading a module under a lockdep enabled kernel:
>>
>> [    6.139583] WARNING: CPU: 0 PID: 102 at /home/ppyu/jeyu-linux/kernel/module.c:1961 module_enable_ro+0x121/0x130
>> [    6.143641] Modules linked in:
>> [    6.144879] CPU: 0 PID: 102 Comm: insmod Not tainted 5.2.0-rc2+ #1
>> [    6.147325] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.11.0-0-g63451fc-prebuilt.qemu-project.org 04/01/2014
>> [    6.152046] RIP: 0010:module_enable_ro+0x121/0x130
>> [    6.153986] Code: 48 c7 c6 70 97 05 81 5d 41 5c 41 5d e9 b8 e2 ff ff be ff ff ff ff 48 c7 c7 40 b2 65 82 e8 a7 c7 fa ff 85 c0 0f 85 f8 fe ff ff <0f> 0b e9 f1 fe ff ff 0f 1f 84 00 00 00 00 00 8b 05 9e a5 66 01 55
>> [    6.161277] RSP: 0018:ffffc9000041fd18 EFLAGS: 00010246
>> [    6.162919] RAX: 0000000000000000 RBX: ffffffffc0002000 RCX: 000000000000000b
>> [    6.164783] RDX: ffff88803d793fc0 RSI: ffffffff8265b240 RDI: ffff88803d7947e8
>> [    6.166820] RBP: 0000000000000000 R08: 000000000007ade8 R09: ffffffff823989a6
>> [    6.168579] R10: ffffc9000049c8e8 R11: 0000000000000002 R12: ffffffffc00021c0
>> [    6.169994] R13: 0000000000000000 R14: 0000000000000030 R15: ffffc9000041fe78
>> [    6.171390] FS:  00007fdc49708700(0000) GS:ffff88803d800000(0000) knlGS:0000000000000000
>> [    6.173007] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
>> [    6.174047] CR2: 00007fdc496c0000 CR3: 000000003fb84000 CR4: 00000000000006f0
>> [    6.175168] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
>> [    6.176326] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
>> [    6.177384] Call Trace:
>> [    6.177730]  load_module+0x1b96/0x2620
>> [    6.178231]  ? rcu_read_lock_sched_held+0x53/0x60
>> [    6.178865]  ? __alloc_pages_nodemask+0x2fa/0x350
>> [    6.179497]  ? __do_sys_init_module+0x135/0x170
>> [    6.180097]  ? _cond_resched+0x10/0x40
>> [    6.180594]  __do_sys_init_module+0x135/0x170
>> [    6.181177]  do_syscall_64+0x4b/0x1c0
>> [    6.181681]  entry_SYSCALL_64_after_hwframe+0x49/0xbe
>>
>> It triggers since we call module_enable_ro() along the load_module()
>> path to prepare for a coming module. We don't take the text_mutex
>> there since we're not modifying any text, just memory protections.
>> Leaving the lockdep assert in module_disable_ro() and
>> set_all_modules_text_*() should be fine though, since I think
>> livepatch and ftrace are the only users of those functions.
>
>Yeah, I discovered that already:
>
>  https://lkml.kernel.org/r/20190522130014.yvkbio62meatqvwf@treble

Whoops, I missed that in the thread /o\

>The new patch (which I will hopefully be able to post soon) will fix
>that up.

Sounds good, thanks!

Jessica

^ permalink raw reply	[flat|nested] 20+ messages in thread

end of thread, other threads:[~2019-05-29 18:34 UTC | newest]

Thread overview: 20+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2019-05-20 19:49 Oops caused by race between livepatch and ftrace Johannes Erdfelt
2019-05-20 20:46 ` Joe Lawrence
2019-05-20 21:09   ` Johannes Erdfelt
2019-05-20 21:19     ` Josh Poimboeuf
2019-05-20 21:39       ` Steven Rostedt
2019-05-21 14:16         ` Josh Poimboeuf
2019-05-21 14:42           ` Steven Rostedt
2019-05-21 16:42             ` Josh Poimboeuf
2019-05-21 16:53               ` Steven Rostedt
2019-05-29 11:17                 ` Jiri Kosina
2019-05-29 12:06                   ` Steven Rostedt
2019-05-29 12:30                     ` Josh Poimboeuf
2019-05-22 13:00               ` Josh Poimboeuf
2019-05-29 17:29               ` Jessica Yu
2019-05-29 17:39                 ` Josh Poimboeuf
2019-05-29 18:34                   ` Jessica Yu
2019-05-20 21:48       ` Johannes Erdfelt
2019-05-20 21:19     ` Joe Lawrence
2019-05-21 19:27       ` Joe Lawrence
2019-05-21 21:00         ` Josh Poimboeuf

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).